bisecting fixing commit since d25f27432f80a800a3592db128254c8140bd71bf
building syzkaller on 373bf66b937eaca190e5972cb9fea9a2b4b1c70d
testing commit d25f27432f80a800a3592db128254c8140bd71bf
compiler: gcc (GCC) 10.2.1 20210217, GNU ld (GNU Binutils for Debian) 2.35.2
kernel signature: 2f917dca446b149da9050fc35083dceaed727c8a914908d0bcdb67ea08e66b86
run #0: crashed: INFO: task hung in io_uring_try_cancel_requests
run #1: crashed: INFO: task hung in io_uring_release
run #2: crashed: INFO: task hung in io_uring_try_cancel_requests
run #3: crashed: INFO: task hung in io_uring_try_cancel_requests
run #4: crashed: INFO: task hung in io_uring_try_cancel_requests
run #5: crashed: INFO: task hung in io_uring_try_cancel_requests
run #6: crashed: INFO: task hung in io_uring_try_cancel_requests
run #7: crashed: INFO: task hung in io_uring_try_cancel_requests
run #8: crashed: INFO: task hung in io_uring_try_cancel_requests
run #9: OK
run #10: OK
run #11: OK
run #12: OK
run #13: OK
run #14: OK
run #15: OK
run #16: OK
run #17: OK
run #18: OK
run #19: OK
reproducer seems to be flaky
testing current HEAD f1baf68e1383f6ed93eb9cff2866d46562607a43
testing commit f1baf68e1383f6ed93eb9cff2866d46562607a43
compiler: gcc (GCC) 10.2.1 20210217, GNU ld (GNU Binutils for Debian) 2.35.2
kernel signature: b6784c01e5d271991109a78e792d2b0d72e78536c4fc7837d53e818287289344
run #0: basic kernel testing failed: BUG: program execution failed: executor NUM: EOF
run #1: crashed: INFO: task hung in io_uring_try_cancel_requests
run #2: crashed: INFO: task hung in io_uring_try_cancel_requests
run #3: crashed: INFO: task hung in io_uring_try_cancel_requests
run #4: crashed: INFO: task hung in io_uring_try_cancel_requests
run #5: crashed: INFO: task hung in io_uring_try_cancel_requests
run #6: OK
run #7: OK
run #8: OK
run #9: OK
run #10: OK
run #11: OK
run #12: OK
run #13: OK
run #14: OK
run #15: OK
run #16: OK
run #17: OK
run #18: OK
run #19: OK
Reproducer flagged being flaky
revisions tested: 2, total time: 36m45.453251819s (build: 12m47.136277687s, test: 23m5.505787951s)
the crash still happens on HEAD
commit msg: Merge tag 'net-5.17-rc4' of git://git.kernel.org/pub/scm/linux/kernel/git/netdev/net
crash: INFO: task hung in io_uring_try_cancel_requests
INFO: task kworker/u4:3:55 blocked for more than 143 seconds.
Not tainted 5.17.0-rc3-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u4:3 state:D stack:27680 pid: 55 ppid: 2 flags:0x00004000
Workqueue: events_unbound io_ring_exit_work
Call Trace:
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xa72/0x4d70 kernel/sched/core.c:6295
schedule+0xd2/0x260 kernel/sched/core.c:6368
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6427
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
io_uring_try_cancel_iowq fs/io_uring.c:9734 [inline]
io_uring_try_cancel_requests+0x107/0x5e0 fs/io_uring.c:9764
io_ring_exit_work+0xf1/0xa01 fs/io_uring.c:9573
process_one_work+0x879/0x1410 kernel/workqueue.c:2307
worker_thread+0x5a0/0xf60 kernel/workqueue.c:2454
kthread+0x299/0x340 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
Showing all locks held in the system:
1 lock held by khungtaskd/26:
#0: ffffffff8ad7a2e0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6460
3 locks held by kworker/u4:3/55:
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:631 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:658 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x79e/0x1410 kernel/workqueue.c:2278
#1: ffffc90001a3fdc0 ((work_completion)(&ctx->exit_work)){+.+.}-{0:0}, at: process_one_work+0x7cb/0x1410 kernel/workqueue.c:2282
#2: ffff88807d0430a8 (&ctx->uring_lock){+.+.}-{3:3}, at: io_uring_try_cancel_iowq fs/io_uring.c:9734 [inline]
#2: ffff88807d0430a8 (&ctx->uring_lock){+.+.}-{3:3}, at: io_uring_try_cancel_requests+0x107/0x5e0 fs/io_uring.c:9764
2 locks held by getty/3305:
#0: ffff88807ece3098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x1f/0x70 drivers/tty/tty_ldisc.c:244
#1: ffffc900027662e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x9dd/0xed0 drivers/tty/n_tty.c:2077
2 locks held by kworker/1:5/3960:
#0: ffff88800fc66538 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88800fc66538 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff88800fc66538 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff88800fc66538 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:631 [inline]
#0: ffff88800fc66538 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:658 [inline]
#0: ffff88800fc66538 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x79e/0x1410 kernel/workqueue.c:2278
#1: ffffc9000281fdc0 ((work_completion)(&rew.rew_work)){+.+.}-{0:0}, at: process_one_work+0x7cb/0x1410 kernel/workqueue.c:2282
2 locks held by kworker/u4:8/4216:
2 locks held by kworker/u4:11/4355:
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1280 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:631 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:658 [inline]
#0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x79e/0x1410 kernel/workqueue.c:2278
#1: ffffc900032dfdc0 ((work_completion)(&ctx->exit_work)){+.+.}-{0:0}, at: process_one_work+0x7cb/0x1410 kernel/workqueue.c:2282
2 locks held by kworker/u4:12/4357:
1 lock held by syz-executor.4/5561:
#0: ffffffff8ad83f28 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:290 [inline]
#0: ffffffff8ad83f28 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x4fa/0x620 kernel/rcu/tree_exp.h:840
1 lock held by syz-executor289/6224:
=============================================
NMI backtrace for cpu 1
CPU: 1 PID: 26 Comm: khungtaskd Not tainted 5.17.0-rc3-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x57/0x7d lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x30/0xc0 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x11f/0x170 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0x88c/0xbf0 kernel/hung_task.c:369
kthread+0x299/0x340 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 4216 Comm: kworker/u4:8 Not tainted 5.17.0-rc3-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events_unbound io_ring_exit_work
RIP: 0010:match_held_lock+0x82/0xc0 kernel/locking/lockdep.c:5117
Code: 0f 94 c0 48 83 c4 08 0f b6 c0 5b c3 31 f6 e8 c5 fe ff ff 48 85 c0 75 b2 31 c0 48 83 c4 08 5b c3 48 83 c4 08 b8 01 00 00 00 5b e8 58 2f 08 fb 85 c0 74 e4 8b 05 f6 19 25 04 85 c0 75 da 48 c7
RSP: 0018:ffffc90002e1f930 EFLAGS: 00000086
RAX: 0000000000000001 RBX: 0000000000000003 RCX: ffffc90002e1f9c0
RDX: 0000000000000003 RSI: ffffffff8f7d4a90 RDI: ffff88807c0044b0
RBP: 1ffff920005c3f30 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000001 R12: ffff88807c0044b0
R13: ffffffff8f7d4a90 R14: ffffc90002e1f9c0 R15: 0000000000000002
FS: 0000000000000000(0000) GS:ffff8880b9e00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f4170a90160 CR3: 0000000053723000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
find_held_lock+0x2d/0x110 kernel/locking/lockdep.c:5130
__lock_release kernel/locking/lockdep.c:5314 [inline]
lock_release+0x1f2/0x720 kernel/locking/lockdep.c:5659
__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:149 [inline]
_raw_spin_unlock_irqrestore+0x16/0x70 kernel/locking/spinlock.c:194
__debug_check_no_obj_freed lib/debugobjects.c:1002 [inline]
debug_check_no_obj_freed+0x20c/0x420 lib/debugobjects.c:1023
slab_free_hook mm/slub.c:1703 [inline]
slab_free_freelist_hook+0xeb/0x1c0 mm/slub.c:1754
slab_free mm/slub.c:3509 [inline]
kfree+0xcb/0x280 mm/slub.c:4562
__io_remove_buffers.part.0+0x141/0x250 fs/io_uring.c:4476
__io_remove_buffers fs/io_uring.c:9393 [inline]
io_destroy_buffers fs/io_uring.c:9393 [inline]
io_ring_ctx_free fs/io_uring.c:9447 [inline]
io_ring_exit_work+0x655/0xa01 fs/io_uring.c:9623
process_one_work+0x879/0x1410 kernel/workqueue.c:2307
worker_thread+0x5a0/0xf60 kernel/workqueue.c:2454
kthread+0x299/0x340 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
----------------
Code disassembly (best guess):
0: 0f 94 c0 sete %al
3: 48 83 c4 08 add $0x8,%rsp
7: 0f b6 c0 movzbl %al,%eax
a: 5b pop %rbx
b: c3 retq
c: 31 f6 xor %esi,%esi
e: e8 c5 fe ff ff callq 0xfffffed8
13: 48 85 c0 test %rax,%rax
16: 75 b2 jne 0xffffffca
18: 31 c0 xor %eax,%eax
1a: 48 83 c4 08 add $0x8,%rsp
1e: 5b pop %rbx
1f: c3 retq
20: 48 83 c4 08 add $0x8,%rsp
24: b8 01 00 00 00 mov $0x1,%eax
29: 5b pop %rbx
* 2a: c3 retq <-- trapping instruction
2b: e8 58 2f 08 fb callq 0xfb082f88
30: 85 c0 test %eax,%eax
32: 74 e4 je 0x18
34: 8b 05 f6 19 25 04 mov 0x42519f6(%rip),%eax # 0x4251a30
3a: 85 c0 test %eax,%eax
3c: 75 da jne 0x18
3e: 48 rex.W
3f: c7 .byte 0xc7