bisecting fixing commit since 811218eceeaa7618652e1b8d11caeff67ab42072 building syzkaller on a52ee10ae11c1342cfca60cf3957619bcf92bd1a testing commit 811218eceeaa7618652e1b8d11caeff67ab42072 compiler: gcc version 8.4.1 20210217 (GCC) kernel signature: 6bf27d00d4682956ceb11695735767d83f5607d7539fde15f41394494d2588b3 all runs: crashed: INFO: task hung in acct testing current HEAD 59456c9cc40c8f75b5a7efa0fe1f211d9c6fcaf1 testing commit 59456c9cc40c8f75b5a7efa0fe1f211d9c6fcaf1 compiler: gcc version 8.4.1 20210217 (GCC) kernel signature: 32fdc5fb4eb14ab9db7156f046baae1d829e6487d5bda525fb158720388ea969 all runs: crashed: INFO: task hung in acct revisions tested: 2, total time: 41m21.907421393s (build: 21m47.297174129s, test: 18m50.466389415s) the crash still happens on HEAD commit msg: Linux 4.19.204 crash: INFO: task hung in acct Bluetooth: hci3: command 0x0406 tx timeout Bluetooth: hci5: command 0x0406 tx timeout Bluetooth: hci1: command 0x0406 tx timeout Bluetooth: hci2: command 0x0406 tx timeout Bluetooth: hci4: command 0x0406 tx timeout INFO: task syz-executor.2:11012 blocked for more than 140 seconds. Not tainted 4.19.204-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.2 D28904 11012 10153 0x00000004 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 __do_sys_acct kernel/acct.c:285 [inline] __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 __x64_sys_acct+0x2c/0x40 kernel/acct.c:273 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465b09 Code: Bad RIP value. RSP: 002b:00007f90ec1ef188 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3 RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465b09 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000200001c0 RBP: 00000000004b069f R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60 R13: 00007ffd80e895df R14: 00007f90ec1ef300 R15: 0000000000022000 INFO: task syz-executor.4:11015 blocked for more than 140 seconds. Not tainted 4.19.204-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.4 D29784 11015 10156 0x00000000 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 __do_sys_acct kernel/acct.c:285 [inline] __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 __x64_sys_acct+0x2c/0x40 kernel/acct.c:273 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465b09 Code: Bad RIP value. RSP: 002b:00007f0702ca6188 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3 RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465b09 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000200001c0 RBP: 00000000004b069f R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60 R13: 00007ffeb9ade99f R14: 00007f0702ca6300 R15: 0000000000022000 INFO: task syz-executor.5:11033 blocked for more than 140 seconds. Not tainted 4.19.204-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.5 D29784 11033 10133 0x00000000 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 __do_sys_acct kernel/acct.c:285 [inline] __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 __x64_sys_acct+0x2c/0x40 kernel/acct.c:273 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465b09 Code: Bad RIP value. RSP: 002b:00007fb65765d188 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3 RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465b09 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000200001c0 RBP: 00000000004b069f R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60 R13: 00007ffc01327c5f R14: 00007fb65765d300 R15: 0000000000022000 INFO: task syz-executor.5:11044 blocked for more than 140 seconds. Not tainted 4.19.204-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.5 D29784 11044 10133 0x00000000 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 __do_sys_acct kernel/acct.c:285 [inline] __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 __x64_sys_acct+0x2c/0x40 kernel/acct.c:273 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465b09 Code: Bad RIP value. RSP: 002b:00007fb65765d188 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3 RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465b09 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000200001c0 RBP: 00000000004b069f R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60 R13: 00007ffc01327c5f R14: 00007fb65765d300 R15: 0000000000022000 INFO: task syz-executor.3:11823 blocked for more than 140 seconds. Not tainted 4.19.204-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D29784 11823 11032 0x00000000 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 __do_sys_acct kernel/acct.c:285 [inline] __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 __x64_sys_acct+0x2c/0x40 kernel/acct.c:273 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465b09 Code: 00 e9 30 ff ff ff 83 f9 77 75 26 48 83 b8 d8 00 00 00 00 7c e2 83 f9 72 75 10 80 78 19 00 74 0a b9 03 00 00 00 e9 0c ff ff ff <31> c9 e9 05 ff ff ff 83 f9 72 eb e2 e8 c6 35 00 00 e9 c1 fe ff ff RSP: 002b:00007f5dd2ceb188 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3 RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465b09 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000200001c0 RBP: 00000000004b069f R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60 R13: 00007ffc5c0057bf R14: 00007f5dd2ceb300 R15: 0000000000022000 INFO: task syz-executor.3:11826 blocked for more than 140 seconds. Not tainted 4.19.204-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D29256 11826 11032 0x00000000 Call Trace: context_switch kernel/sched/core.c:2828 [inline] __schedule+0x80c/0x1f70 kernel/sched/core.c:3517 schedule+0x7f/0x1b0 kernel/sched/core.c:3561 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3619 __mutex_lock_common kernel/locking/mutex.c:1015 [inline] __mutex_lock+0x4ba/0x1190 kernel/locking/mutex.c:1083 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1098 __do_sys_acct kernel/acct.c:285 [inline] __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 __x64_sys_acct+0x2c/0x40 kernel/acct.c:273 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x465b09 Code: 00 e9 30 ff ff ff 83 f9 77 75 26 48 83 b8 d8 00 00 00 00 7c e2 83 f9 72 75 10 80 78 19 00 74 0a b9 03 00 00 00 e9 0c ff ff ff <31> c9 e9 05 ff ff ff 83 f9 72 eb e2 e8 c6 35 00 00 e9 c1 fe ff ff RSP: 002b:00007f5dd2ceb188 EFLAGS: 00000246 ORIG_RAX: 00000000000000a3 RAX: ffffffffffffffda RBX: 000000000056bf60 RCX: 0000000000465b09 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000200001c0 RBP: 00000000004b069f R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 000000000056bf60 R13: 00007ffc5c0057bf R14: 00007f5dd2ceb300 R15: 0000000000022000 Showing all locks held in the system: 1 lock held by khungtaskd/1550: #0: 000000002dc319a9 (rcu_read_lock){....}, at: debug_show_all_locks+0x5b/0x27a kernel/locking/lockdep.c:4443 1 lock held by syz-executor.2/11012: #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.5/11011: #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.4/11015: #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.5/11033: #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.5/11044: #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.3/11823: #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.3/11826: #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000003d7df07b (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 ============================================= NMI backtrace for cpu 1 CPU: 1 PID: 1550 Comm: khungtaskd Not tainted 4.19.204-syzkaller #0 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+0x17c/0x226 lib/dump_stack.c:118 nmi_cpu_backtrace.cold.0+0x3c/0x78 lib/nmi_backtrace.c:101 nmi_trigger_cpumask_backtrace+0xf6/0x120 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:203 [inline] watchdog+0x5c3/0xb40 kernel/hung_task.c:287 kthread+0x347/0x410 kernel/kthread.c:259 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415 Sending NMI from CPU 1 to CPUs 0: NMI backtrace for cpu 0 CPU: 0 PID: 9784 Comm: kworker/u4:7 Not tainted 4.19.204-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: bat_events batadv_iv_send_outstanding_bat_ogm_packet RIP: 0010:separate_irq_context kernel/locking/lockdep.c:3059 [inline] RIP: 0010:__lock_acquire+0x8d5/0x47c0 kernel/locking/lockdep.c:3407 Code: 89 fa 48 c1 ea 03 0f b6 04 02 48 89 fa 83 e2 07 38 d0 7f 08 84 c0 0f 85 8d 2b 00 00 45 32 7a 21 41 83 e7 60 0f 85 28 07 00 00 <4c> 89 ea 44 89 e8 48 c1 ea 20 41 89 d4 29 d3 41 01 d5 41 c1 c4 04 RSP: 0018:ffff88809987f950 EFLAGS: 00000046 RAX: 0000000000000000 RBX: 000000000000002e RCX: 1ffff110132d05d4 RDX: 0000000000000001 RSI: ffff888099682e08 RDI: ffff888099682ea1 RBP: ffff88809987fb38 R08: ffff888099682ea0 R09: 0000000000000003 R10: ffff888099682e80 R11: 0000000000000000 R12: 000000000000002e R13: dd0ccedaf5ec6762 R14: ffff888099682580 R15: 0000000000000000 FS: 0000000000000000(0000) GS:ffff8880ba200000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007fda920f7000 CR3: 000000009474a000 CR4: 00000000001406f0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: lock_acquire+0x180/0x3a0 kernel/locking/lockdep.c:3908 rcu_lock_acquire include/linux/rcupdate.h:242 [inline] rcu_read_lock include/linux/rcupdate.h:627 [inline] batadv_iv_ogm_slide_own_bcast_window net/batman-adv/bat_iv_ogm.c:942 [inline] batadv_iv_ogm_schedule_buff+0x4fa/0xfd0 net/batman-adv/bat_iv_ogm.c:1008 batadv_iv_ogm_schedule net/batman-adv/bat_iv_ogm.c:1052 [inline] batadv_iv_ogm_schedule net/batman-adv/bat_iv_ogm.c:1045 [inline] batadv_iv_send_outstanding_bat_ogm_packet+0x59e/0x810 net/batman-adv/bat_iv_ogm.c:1871 process_one_work+0x7b9/0x15a0 kernel/workqueue.c:2153 worker_thread+0x85/0xb60 kernel/workqueue.c:2296 kthread+0x347/0x410 kernel/kthread.c:259 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415 ---------------- Code disassembly (best guess): 0: 89 fa mov %edi,%edx 2: 48 c1 ea 03 shr $0x3,%rdx 6: 0f b6 04 02 movzbl (%rdx,%rax,1),%eax a: 48 89 fa mov %rdi,%rdx d: 83 e2 07 and $0x7,%edx 10: 38 d0 cmp %dl,%al 12: 7f 08 jg 0x1c 14: 84 c0 test %al,%al 16: 0f 85 8d 2b 00 00 jne 0x2ba9 1c: 45 32 7a 21 xor 0x21(%r10),%r15b 20: 41 83 e7 60 and $0x60,%r15d 24: 0f 85 28 07 00 00 jne 0x752 * 2a: 4c 89 ea mov %r13,%rdx <-- trapping instruction 2d: 44 89 e8 mov %r13d,%eax 30: 48 c1 ea 20 shr $0x20,%rdx 34: 41 89 d4 mov %edx,%r12d 37: 29 d3 sub %edx,%ebx 39: 41 01 d5 add %edx,%r13d 3c: 41 c1 c4 04 rol $0x4,%r12d