bisecting fixing commit since 7e96bf476270aecea66740a083e51b38c1371cd2 building syzkaller on c585c7b0ea16dc4326bf5e8f2f00cc6638e2feb1 testing commit 7e96bf476270aecea66740a083e51b38c1371cd2 compiler: gcc (GCC) 10.2.1 20210217, GNU ld (GNU Binutils for Debian) 2.35.2 kernel signature: 7135110cc54110305d1293c4c638b36319897e25d62f2d3f7b594842115c2fba run #0: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor936698068" "root@10.128.1.72:./syz-executor936698068"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.1.72 port 22 timed out lost connection run #1: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor632715299" "root@10.128.1.117:./syz-executor632715299"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.1.117 port 22 timed out lost connection run #2: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor724854566" "root@10.128.10.9:./syz-executor724854566"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.9 port 22 timed out lost connection run #3: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor429913928" "root@10.128.10.15:./syz-executor429913928"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.15 port 22 timed out lost connection run #4: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor049118650" "root@10.128.10.16:./syz-executor049118650"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.16 port 22 timed out lost connection run #5: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor071849425" "root@10.128.10.14:./syz-executor071849425"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.14 port 22 timed out lost connection run #6: OK run #7: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor435461794" "root@10.128.0.126:./syz-executor435461794"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.0.126 port 22 timed out lost connection run #8: OK run #9: OK run #10: OK run #11: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor325909750" "root@10.128.10.22:./syz-executor325909750"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.22 port 22 timed out lost connection run #12: OK run #13: OK run #14: OK run #15: crashed: INFO: task hung in synchronize_rcu run #16: OK run #17: crashed: INFO: task hung in process_one_work run #18: crashed: INFO: task hung in process_one_work run #19: crashed: INFO: task hung in synchronize_rcu reproducer seems to be flaky testing current HEAD 0513e464f9007b70b96740271a948ca5ab6e7dd7 testing commit 0513e464f9007b70b96740271a948ca5ab6e7dd7 compiler: gcc (GCC) 10.2.1 20210217, GNU ld (GNU Binutils for Debian) 2.35.2 kernel signature: 5bf0bb78642f23cefc56ea51961bc8309462fa2661709843ceec515b18a9570c run #0: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor036786981" "root@10.128.10.8:./syz-executor036786981"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.8 port 22 timed out lost connection run #1: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor188842866" "root@10.128.10.5:./syz-executor188842866"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.5 port 22 timed out lost connection run #2: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor469246531" "root@10.128.10.3:./syz-executor469246531"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.3 port 22 timed out lost connection run #3: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor267901638" "root@10.128.10.1:./syz-executor267901638"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.1 port 22 timed out lost connection run #4: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor014006760" "root@10.128.10.11:./syz-executor014006760"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.11 port 22 timed out lost connection run #5: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor200615665" "root@10.128.10.21:./syz-executor200615665"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.21 port 22 timed out lost connection run #6: basic kernel testing failed: failed to copy test binary to VM: failed to run ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor225892252" "root@10.128.10.16:./syz-executor225892252"]: exit status 1 Connection timed out during banner exchange Connection to 10.128.10.16 port 22 timed out lost connection run #7: OK run #8: OK run #9: OK run #10: OK run #11: OK run #12: OK run #13: crashed: INFO: task hung in synchronize_rcu 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: 29m45.723524761s (build: 13m22.440569171s, test: 15m49.202810785s) the crash still happens on HEAD commit msg: Merge tag 'perf-tools-fixes-for-v5.15-2021-09-27' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux crash: INFO: task hung in synchronize_rcu INFO: task kworker/u4:5:7575 blocked for more than 143 seconds. Not tainted 5.15.0-rc3-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. task:kworker/u4:5 state:D stack:24872 pid: 7575 ppid: 2 flags:0x00004000 Workqueue: events_unbound fsnotify_mark_destroy_workfn Call Trace: context_switch kernel/sched/core.c:4940 [inline] __schedule+0x90d/0x26c0 kernel/sched/core.c:6287 schedule+0xd3/0x270 kernel/sched/core.c:6366 schedule_timeout+0x19d/0x250 kernel/time/timer.c:1857 do_wait_for_common kernel/sched/completion.c:85 [inline] __wait_for_common kernel/sched/completion.c:106 [inline] wait_for_common kernel/sched/completion.c:117 [inline] wait_for_completion+0x176/0x280 kernel/sched/completion.c:138 __synchronize_srcu+0x1f4/0x290 kernel/rcu/srcutree.c:930 fsnotify_mark_destroy_workfn+0xeb/0x330 fs/notify/mark.c:861 process_one_work+0x87f/0x1450 kernel/workqueue.c:2297 worker_thread+0x598/0x1040 kernel/workqueue.c:2444 kthread+0x38b/0x460 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295 Showing all locks held in the system: 1 lock held by khungtaskd/27: #0: ffffffff8ab76840 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6446 1 lock held by khugepaged/33: #0: ffffffff8ac536a8 (lock#5){+.+.}-{3:3}, at: __lru_add_drain_all+0x5a/0x6e0 mm/swap.c:782 2 locks held by kworker/1:3/2968: 1 lock held by in:imklog/6206: #0: ffff8880194f5770 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x9c/0xb0 fs/file.c:990 3 locks held by kworker/0:5/6865: 4 locks held by syz-executor.2/7015: #0: ffff88807e498ff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0xa8/0xef0 net/bluetooth/hci_core.c:1735 #1: ffff88807e498078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_do_close+0x215/0xef0 net/bluetooth/hci_core.c:1780 #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1515 [inline] #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb9/0x210 net/bluetooth/hci_conn.c:1608 #3: ffffffff8ab7fba8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:322 [inline] #3: ffffffff8ab7fba8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x2d5/0x620 kernel/rcu/tree_exp.h:837 3 locks held by syz-executor.0/7017: #0: ffff88807d21cff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0xa8/0xef0 net/bluetooth/hci_core.c:1735 #1: ffff88807d21c078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_do_close+0x215/0xef0 net/bluetooth/hci_core.c:1780 #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1515 [inline] #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb9/0x210 net/bluetooth/hci_conn.c:1608 3 locks held by syz-executor.3/7019: #0: ffff88807bd14ff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0xa8/0xef0 net/bluetooth/hci_core.c:1735 #1: ffff88807bd14078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_do_close+0x215/0xef0 net/bluetooth/hci_core.c:1780 #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1515 [inline] #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb9/0x210 net/bluetooth/hci_conn.c:1608 3 locks held by syz-executor.4/7022: #0: ffff88807bd10ff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0xa8/0xef0 net/bluetooth/hci_core.c:1735 #1: ffff88807bd10078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_do_close+0x215/0xef0 net/bluetooth/hci_core.c:1780 #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1515 [inline] #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb9/0x210 net/bluetooth/hci_conn.c:1608 3 locks held by syz-executor.5/7023: #0: ffff88807dfe0ff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0xa8/0xef0 net/bluetooth/hci_core.c:1735 #1: ffff88807dfe0078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_do_close+0x215/0xef0 net/bluetooth/hci_core.c:1780 #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1515 [inline] #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb9/0x210 net/bluetooth/hci_conn.c:1608 3 locks held by syz-executor.1/7024: #0: ffff88807d594ff0 (&hdev->req_lock){+.+.}-{3:3}, at: hci_dev_do_close+0xa8/0xef0 net/bluetooth/hci_core.c:1735 #1: ffff88807d594078 (&hdev->lock){+.+.}-{3:3}, at: hci_dev_do_close+0x215/0xef0 net/bluetooth/hci_core.c:1780 #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_disconn_cfm include/net/bluetooth/hci_core.h:1515 [inline] #2: ffffffff8c420008 (hci_cb_list_lock){+.+.}-{3:3}, at: hci_conn_hash_flush+0xb9/0x210 net/bluetooth/hci_conn.c:1608 2 locks held by kworker/u4:5/7575: #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:1198 [inline] #0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:634 [inline] #0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:661 [inline] #0: ffff88800fc69138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x7a4/0x1450 kernel/workqueue.c:2268 #1: ffffc9000433fdb8 ((reaper_work).work){+.+.}-{0:0}, at: process_one_work+0x7d1/0x1450 kernel/workqueue.c:2272 1 lock held by syz-executor615/9214: #0: ffffffff8ac92be8 (pcpu_drain_mutex){+.+.}-{3:3}, at: __drain_all_pages+0x4f/0x6c0 mm/page_alloc.c:3187 ============================================= NMI backtrace for cpu 1 CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.15.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:105 nmi_trigger_cpumask_backtrace+0x11a/0x160 lib/nmi_backtrace.c:62 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline] check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline] watchdog+0x88c/0xbf0 kernel/hung_task.c:295 kthread+0x38b/0x460 kernel/kthread.c:319 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: 8798 Comm: kworker/u4:6 Not tainted 5.15.0-rc3-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: bat_events batadv_nc_worker RIP: 0010:__lock_release kernel/locking/lockdep.c:5313 [inline] RIP: 0010:lock_release+0x250/0x720 kernel/locking/lockdep.c:5645 Code: 0f 85 94 04 00 00 8b 73 24 85 f6 0f 85 28 04 00 00 48 8d 7b 22 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 0f b6 14 02 <48> 89 f8 83 e0 07 83 c0 01 38 d0 7c 08 84 d2 0f 85 47 04 00 00 66 RSP: 0018:ffffc9000cb1fbc0 EFLAGS: 00000012 RAX: dffffc0000000000 RBX: ffff888061105f08 RCX: ffffc9000cb1fc10 RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff888061105f2a RBP: 1ffff92001963f7a R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000001 R11: 0000000000000001 R12: ffffffff8ab76840 R13: 0000000000000003 R14: ffff888061105eb0 R15: ffff8880611054c0 FS: 0000000000000000(0000) GS:ffff8880b9e00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007f095cc96000 CR3: 000000001b945000 CR4: 0000000000350ef0 Call Trace: rcu_lock_release include/linux/rcupdate.h:272 [inline] rcu_read_unlock include/linux/rcupdate.h:720 [inline] batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:414 [inline] batadv_nc_worker+0x668/0xd70 net/batman-adv/network-coding.c:721 process_one_work+0x87f/0x1450 kernel/workqueue.c:2297 worker_thread+0x598/0x1040 kernel/workqueue.c:2444 kthread+0x38b/0x460 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295 ---------------- Code disassembly (best guess): 0: 0f 85 94 04 00 00 jne 0x49a 6: 8b 73 24 mov 0x24(%rbx),%esi 9: 85 f6 test %esi,%esi b: 0f 85 28 04 00 00 jne 0x439 11: 48 8d 7b 22 lea 0x22(%rbx),%rdi 15: 48 b8 00 00 00 00 00 movabs $0xdffffc0000000000,%rax 1c: fc ff df 1f: 48 89 fa mov %rdi,%rdx 22: 48 c1 ea 03 shr $0x3,%rdx 26: 0f b6 14 02 movzbl (%rdx,%rax,1),%edx * 2a: 48 89 f8 mov %rdi,%rax <-- trapping instruction 2d: 83 e0 07 and $0x7,%eax 30: 83 c0 01 add $0x1,%eax 33: 38 d0 cmp %dl,%al 35: 7c 08 jl 0x3f 37: 84 d2 test %dl,%dl 39: 0f 85 47 04 00 00 jne 0x486 3f: 66 data16