INFO: task hung in __io_uring

INFO: task hung in __io_uring_register
Status: fixed on 2019/05/27 12:48
Reported-by: syzbot+16dc03452dee970a0c3e@syzkaller.appspotmail.com
Fix commit: b19062a56726 io_uring: fix possible deadlock between io_uring_{enter,register}
First crash: 1130d, last: 1121d

Cause bisection: introduced by (bisect log) :
commit 6c271ce2f1d572f7fa225700a13cfe7ced492434
Author: Jens Axboe <axboe@kernel.dk>
Date: Thu Jan 10 18:22:30 2019 +0000

io_uring: add submission polling

Crash: INFO: task hung in __io_uring_register (log)
Repro: C syz .config

Sample crash report:

INFO: task syz-executor294:7495 blocked for more than 143 seconds.
      Not tainted 5.1.0-rc5 #70
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor294 D29208  7495   7492 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2877 [inline]
 __schedule+0x813/0x1cc0 kernel/sched/core.c:3518
 schedule+0x92/0x180 kernel/sched/core.c:3562
 schedule_timeout+0x8ca/0xfd0 kernel/time/timer.c:1779
 do_wait_for_common kernel/sched/completion.c:83 [inline]
 __wait_for_common kernel/sched/completion.c:104 [inline]
 wait_for_common kernel/sched/completion.c:115 [inline]
 wait_for_completion+0x29c/0x440 kernel/sched/completion.c:136
 __io_uring_register+0xb6/0x1fd0 fs/io_uring.c:2929
 __do_sys_io_uring_register fs/io_uring.c:2979 [inline]
 __se_sys_io_uring_register fs/io_uring.c:2961 [inline]
 __x64_sys_io_uring_register+0x193/0x1f0 fs/io_uring.c:2961
 do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x445999
Code: e8 ec bc 02 00 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 cb 11 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007fa97a70edb8 EFLAGS: 00000246 ORIG_RAX: 00000000000001ab
RAX: ffffffffffffffda RBX: 00000000006dbc28 RCX: 0000000000445999
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000003
RBP: 00000000006dbc20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006dbc2c
R13: 00007ffca279299f R14: 00007fa97a70f9c0 R15: 0000000000000000
INFO: task syz-executor294:7496 blocked for more than 143 seconds.
      Not tainted 5.1.0-rc5 #70
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor294 D30336  7496   7492 0x00000004
Call Trace:
 context_switch kernel/sched/core.c:2877 [inline]
 __schedule+0x813/0x1cc0 kernel/sched/core.c:3518
 schedule+0x92/0x180 kernel/sched/core.c:3562
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3620
 __mutex_lock_common kernel/locking/mutex.c:1002 [inline]
 __mutex_lock+0x726/0x1310 kernel/locking/mutex.c:1072
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
 __do_sys_io_uring_enter fs/io_uring.c:2678 [inline]
 __se_sys_io_uring_enter fs/io_uring.c:2637 [inline]
 __x64_sys_io_uring_enter+0x67f/0xac0 fs/io_uring.c:2637
 do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x445999
Code: e8 ec bc 02 00 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 cb 11 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007fa97a6edda8 EFLAGS: 00000246 ORIG_RAX: 00000000000001aa
RAX: ffffffffffffffda RBX: 00000000006dbc38 RCX: 0000000000445999
RDX: 0000000000000002 RSI: 0000000000010005 RDI: 0000000000000003
RBP: 00000000006dbc30 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000003 R11: 0000000000000246 R12: 00000000006dbc3c
R13: 00007ffca279299f R14: 00007fa97a6ee9c0 R15: 0000000000000002

Showing all locks held in the system:
1 lock held by khungtaskd/1042:
 #0: 00000000b5a861ba (rcu_read_lock){....}, at: debug_show_all_locks+0x5f/0x27e kernel/locking/lockdep.c:5056
1 lock held by rsyslogd/7378:
 #0: 0000000007d2b1d3 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xee/0x110 fs/file.c:801
2 locks held by getty/7468:
 #0: 000000009b3d70d7 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 0000000017139965 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x232/0x1b70 drivers/tty/n_tty.c:2156
2 locks held by getty/7469:
 #0: 000000001cc2b0a0 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 00000000cea7d2be (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x232/0x1b70 drivers/tty/n_tty.c:2156
2 locks held by getty/7470:
 #0: 00000000b87ea74b (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 000000006ba52ac7 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x232/0x1b70 drivers/tty/n_tty.c:2156
2 locks held by getty/7471:
 #0: 00000000dffafc50 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 000000002e1535bf (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x232/0x1b70 drivers/tty/n_tty.c:2156
2 locks held by getty/7472:
 #0: 00000000f9c6525d (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 00000000a676d4cd (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x232/0x1b70 drivers/tty/n_tty.c:2156
2 locks held by getty/7473:
 #0: 00000000225242bf (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 00000000a095b648 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x232/0x1b70 drivers/tty/n_tty.c:2156
2 locks held by getty/7474:
 #0: 00000000bb203c70 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 00000000661a9df8 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x232/0x1b70 drivers/tty/n_tty.c:2156
1 lock held by syz-executor294/7495:
 #0: 0000000041a2a57a (&ctx->uring_lock){+.+.}, at: __do_sys_io_uring_register fs/io_uring.c:2978 [inline]
 #0: 0000000041a2a57a (&ctx->uring_lock){+.+.}, at: __se_sys_io_uring_register fs/io_uring.c:2961 [inline]
 #0: 0000000041a2a57a (&ctx->uring_lock){+.+.}, at: __x64_sys_io_uring_register+0x182/0x1f0 fs/io_uring.c:2961
1 lock held by syz-executor294/7496:
 #0: 0000000041a2a57a (&ctx->uring_lock){+.+.}, at: __do_sys_io_uring_enter fs/io_uring.c:2678 [inline]
 #0: 0000000041a2a57a (&ctx->uring_lock){+.+.}, at: __se_sys_io_uring_enter fs/io_uring.c:2637 [inline]
 #0: 0000000041a2a57a (&ctx->uring_lock){+.+.}, at: __x64_sys_io_uring_enter+0x67f/0xac0 fs/io_uring.c:2637

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 1042 Comm: khungtaskd Not tainted 5.1.0-rc5 #70
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x172/0x1f0 lib/dump_stack.c:113
 nmi_cpu_backtrace.cold+0x63/0xa4 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x1be/0x236 lib/nmi_backtrace.c:62
 arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
 watchdog+0x9b7/0xec0 kernel/hung_task.c:288
 kthread+0x357/0x430 kernel/kthread.c:253
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 1 to CPUs 0:

Crashes (51):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro
ci-upstream-kasan-gce	2019/04/15 18:50	upstream	dc4060a5dc25	505ab413	.config	log	report	syz	C
ci-upstream-kasan-gce-386	2019/04/15 13:51	upstream	dc4060a5dc25	505ab413	.config	log	report	syz	C
ci-upstream-kasan-gce-root	2019/04/20 20:38	upstream	371dd432ab39	b0e8efcb	.config	log	report
ci-upstream-kasan-gce-root	2019/04/20 10:49	upstream	371dd432ab39	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/20 01:05	upstream	3ecafda911f4	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/20 00:38	upstream	3ecafda911f4	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/19 15:34	upstream	6d906f998179	b0e8efcb	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/19 06:20	upstream	6d906f998179	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/18 15:10	upstream	e53f31bffe1d	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/18 07:25	upstream	fe5cdef29e41	b0e8efcb	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/18 02:53	upstream	fe5cdef29e41	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/17 13:38	upstream	444fe9913539	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/17 11:32	upstream	444fe9913539	b0e8efcb	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/17 06:07	upstream	444fe9913539	b0e8efcb	.config	log	report
ci-upstream-kasan-gce	2019/04/16 16:41	upstream	618d919cae2f	505ab413	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/15 21:10	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/15 20:20	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce-selinux-root	2019/04/15 18:53	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce-root	2019/04/15 12:06	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce-selinux-root	2019/04/15 11:59	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce	2019/04/15 11:59	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce	2019/04/15 10:38	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce	2019/04/15 10:21	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/15 07:10	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce	2019/04/15 01:02	upstream	4443f8e6ac77	505ab413	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/14 10:01	upstream	4443f8e6ac77	c402d8f1	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/13 09:29	upstream	8ee15f324866	c402d8f1	.config	log	report
ci-upstream-kasan-gce-smack-root	2019/04/13 06:56	upstream	8ee15f324866	c402d8f1	.config	log	report
ci-upstream-kasan-gce-386	2019/04/15 12:02	upstream	dc4060a5dc25	505ab413	.config	log	report
ci-upstream-kasan-gce-386	2019/04/14 15:53	upstream	4443f8e6ac77	505ab413	.config	log	report
ci-upstream-kasan-gce-386	2019/04/14 10:01	upstream	b60bc0665e6a	c402d8f1	.config	log	report
ci-upstream-kasan-gce-386	2019/04/13 04:56	upstream	8ee15f324866	c402d8f1	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/22 01:56	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/21 14:04	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/20 15:12	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/20 01:20	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/20 00:54	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/19 14:02	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/19 06:59	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/19 02:08	linux-next	3f018f4a019a	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/18 05:26	linux-next	a74942526152	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/17 18:26	linux-next	a74942526152	b0e8efcb	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/16 16:57	linux-next	de3c659c83ce	505ab413	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/15 12:02	linux-next	f9221a7a1014	505ab413	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/15 09:23	linux-next	bcb67f0fbce9	505ab413	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2019/04/13 09:09	linux-next	bcb67f0fbce9	c402d8f1	.config	log	report