bisecting fixing commit since 811218eceeaa7618652e1b8d11caeff67ab42072 building syzkaller on a52ee10ae11c1342cfca60cf3957619bcf92bd1a testing commit 811218eceeaa7618652e1b8d11caeff67ab42072 compiler: gcc version 8.4.1 20210217 (GCC) kernel signature: 3eb0c06dae12d6563450a4b6837c33e7c4c6506b9602fa01540373e943425442 all runs: crashed: INFO: task hung in acct testing current HEAD 4938296e03bd227e5020d63d418956fe52baf97c testing commit 4938296e03bd227e5020d63d418956fe52baf97c compiler: gcc version 8.4.1 20210217 (GCC) kernel signature: 660811190e4132eab40d37380f8b72e38bdf7aa7ecc2fcf6d1565f5df2a128a8 all runs: crashed: INFO: task hung in acct revisions tested: 2, total time: 34m4.332441911s (build: 16m15.679842133s, test: 17m20.315169607s) the crash still happens on HEAD commit msg: Linux 4.19.198 crash: INFO: task hung in acct Bluetooth: hci4: command 0x0406 tx timeout Bluetooth: hci0: command 0x0406 tx timeout Bluetooth: hci3: command 0x0406 tx timeout Bluetooth: hci1: command 0x0406 tx timeout Bluetooth: hci5: command 0x0406 tx timeout INFO: task syz-executor.4:11754 blocked for more than 140 seconds. Not tainted 4.19.198-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.4 D29000 11754 10523 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: 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:00007fa28a1c1188 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: 00007ffe2d00dabf R14: 00007fa28a1c1300 R15: 0000000000022000 INFO: task syz-executor.4:11763 blocked for more than 140 seconds. Not tainted 4.19.198-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.4 D29432 11763 11756 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: 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:00007fa28a1c1188 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: 00007ffe2d00dabf R14: 00007fa28a1c1300 R15: 0000000000022000 INFO: task syz-executor.0:11770 blocked for more than 140 seconds. Not tainted 4.19.198-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.0 D29784 11770 11413 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:00007f8f4f854188 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: 00007ffdb2d8b52f R14: 00007f8f4f854300 R15: 0000000000022000 INFO: task syz-executor.0:11772 blocked for more than 140 seconds. Not tainted 4.19.198-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.0 D29448 11772 11413 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:00007f8f4f854188 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: 00007ffdb2d8b52f R14: 00007f8f4f854300 R15: 0000000000022000 Showing all locks held in the system: 2 locks held by kworker/u4:1/23: #0: 000000001a452f80 (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1824 [inline] #0: 000000001a452f80 (&rq->lock){-.-.}, at: __schedule+0x1f6/0x1f70 kernel/sched/core.c:3455 #1: 00000000fccbf537 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline] #1: 00000000fccbf537 (rcu_read_lock){....}, at: update_curr+0x2cf/0x870 kernel/sched/fair.c:857 1 lock held by khungtaskd/1568: #0: 00000000fccbf537 (rcu_read_lock){....}, at: debug_show_all_locks+0x5b/0x27a kernel/locking/lockdep.c:4443 1 lock held by syz-executor.4/11754: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.0/11755: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.4/11763: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.0/11770: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.0/11772: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.5/12778: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.2/12780: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.3/12795: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 1 lock held by syz-executor.1/12829: #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __do_sys_acct kernel/acct.c:285 [inline] #0: 000000005b1df1fc (acct_on_mutex){+.+.}, at: __se_sys_acct+0x65/0x7d0 kernel/acct.c:273 ============================================= NMI backtrace for cpu 0 CPU: 0 PID: 1568 Comm: khungtaskd Not tainted 4.19.198-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 0 to CPUs 1: NMI backtrace for cpu 1 CPU: 1 PID: 10480 Comm: kworker/1:8 Not tainted 4.19.198-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: events cache_reap RIP: 0010:reap_alien mm/slab.c:760 [inline] RIP: 0010:cache_reap+0xbd/0x270 mm/slab.c:4066 Code: 4c 89 4b 8b 9c f4 08 01 00 00 e8 be c7 bb 01 65 48 8b 15 a6 0a 77 7e 48 8b 83 90 00 00 00 48 85 c0 74 75 48 63 ca 4c 8b 3c c8 <4d> 85 ff 74 69 41 8b 4f 38 85 c9 74 61 48 83 3d 4e ab 05 08 00 0f RSP: 0018:ffff888093247d08 EFLAGS: 00000286 RAX: ffff88813be74a00 RBX: ffff88813be77600 RCX: 0000000000000001 RDX: 0000000000000001 RSI: ffffffff894cc3c8 RDI: ffff8880a34d64e8 RBP: ffff888093247d58 R08: 1ffff1101469ad40 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000000 R12: ffff88823b847200 R13: 0000000000000000 R14: 0000000000000000 R15: ffff88813be77700 FS: 0000000000000000(0000) GS:ffff8880ba300000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007fbab5098000 CR3: 00000000b46aa000 CR4: 00000000001406e0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: 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