bisecting fixing commit since a1b977b49b66c75e6c51a515f6700371ae720217 building syzkaller on 4a77ae0bdc5cd75ebe88ce7c896aae6bbf457a29 testing commit a1b977b49b66c75e6c51a515f6700371ae720217 with gcc (GCC) 8.1.0 kernel signature: 2d55fbc9ca98d07b7ee3fee13b04eb1bf89d901d59ec539c8e18095fb3e9b009 all runs: crashed: INFO: task hung in __sync_dirty_buffer testing current HEAD b94de4d19498b454645b72d08a05d32fa9074fb5 testing commit b94de4d19498b454645b72d08a05d32fa9074fb5 with gcc (GCC) 8.1.0 kernel signature: 5c7e2f90afa18e51c84f5ad38a2f850a0535f10def970ccb89fec2b304e10717 all runs: crashed: INFO: task hung in __sync_dirty_buffer revisions tested: 2, total time: 29m25.526333763s (build: 18m0.288473049s, test: 10m44.815332403s) the crash still happens on HEAD commit msg: Linux 4.19.155 crash: INFO: task hung in __sync_dirty_buffer Bluetooth: hci0: command 0x0406 tx timeout Bluetooth: hci2: command 0x0406 tx timeout Bluetooth: hci3: command 0x0406 tx timeout Bluetooth: hci1: command 0x0406 tx timeout Bluetooth: hci4: command 0x0406 tx timeout INFO: task syz-executor.1:8039 blocked for more than 140 seconds. Not tainted 4.19.155-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.1 D25488 8039 6647 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 io_schedule+0x1c/0x70 kernel/sched/core.c:5185 bit_wait_io+0xf/0x90 kernel/sched/wait_bit.c:207 __wait_on_bit_lock+0xbb/0x160 kernel/sched/wait_bit.c:89 out_of_line_wait_on_bit_lock+0xde/0x110 kernel/sched/wait_bit.c:116 wait_on_bit_lock_io include/linux/wait_bit.h:208 [inline] __lock_buffer+0x3c/0x40 fs/buffer.c:65 lock_buffer include/linux/buffer_head.h:374 [inline] __sync_dirty_buffer+0x180/0x1f0 fs/buffer.c:3178 sync_dirty_buffer+0xe/0x10 fs/buffer.c:3204 __ext4_handle_dirty_metadata+0x17a/0x520 fs/ext4/ext4_jbd2.c:300 ext4_convert_inline_data_nolock+0x4f8/0xc40 fs/ext4/inline.c:1240 ext4_convert_inline_data+0x299/0x3b1 fs/ext4/inline.c:2026 ext4_fallocate+0xdb/0x1920 fs/ext4/extents.c:4960 vfs_fallocate+0x2b5/0x7c0 fs/open.c:308 ksys_fallocate+0x3c/0x80 fs/open.c:331 __do_sys_fallocate fs/open.c:339 [inline] __se_sys_fallocate fs/open.c:337 [inline] __x64_sys_fallocate+0x92/0xf0 fs/open.c:337 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x45de59 Code: de 68 48 89 da 4c 8b 44 24 58 49 89 ca 48 89 c3 48 89 f0 48 8b 4c 24 40 e9 54 ff ff ff 48 8b 7c 24 60 e8 ba 3e 00 00 eb d9 48 <8d> 3c cb 48 89 c3 4c 89 c8 e8 a9 3e 00 00 49 8d 78 28 31 c0 e8 9e RSP: 002b:00007fbf78cf5c78 EFLAGS: 00000246 ORIG_RAX: 000000000000011d RAX: ffffffffffffffda RBX: 0000000000002ec0 RCX: 000000000045de59 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003 RBP: 000000000118bf68 R08: 0000000000000000 R09: 0000000000000000 R10: 000000000000ffe0 R11: 0000000000000246 R12: 000000000118bf2c R13: 00007ffd47d8f71f R14: 00007fbf78cf69c0 R15: 000000000118bf2c INFO: task syz-executor.3:8042 blocked for more than 140 seconds. Not tainted 4.19.155-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D25656 8042 6644 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 io_schedule+0x1c/0x70 kernel/sched/core.c:5185 bit_wait_io+0xf/0x90 kernel/sched/wait_bit.c:207 __wait_on_bit_lock+0xbb/0x160 kernel/sched/wait_bit.c:89 out_of_line_wait_on_bit_lock+0xde/0x110 kernel/sched/wait_bit.c:116 wait_on_bit_lock_io include/linux/wait_bit.h:208 [inline] __lock_buffer+0x3c/0x40 fs/buffer.c:65 lock_buffer include/linux/buffer_head.h:374 [inline] __sync_dirty_buffer+0x180/0x1f0 fs/buffer.c:3178 sync_dirty_buffer+0xe/0x10 fs/buffer.c:3204 __ext4_handle_dirty_metadata+0x17a/0x520 fs/ext4/ext4_jbd2.c:300 ext4_convert_inline_data_nolock+0x4f8/0xc40 fs/ext4/inline.c:1240 ext4_convert_inline_data+0x299/0x3b1 fs/ext4/inline.c:2026 ext4_fallocate+0xdb/0x1920 fs/ext4/extents.c:4960 vfs_fallocate+0x2b5/0x7c0 fs/open.c:308 ksys_fallocate+0x3c/0x80 fs/open.c:331 __do_sys_fallocate fs/open.c:339 [inline] __se_sys_fallocate fs/open.c:337 [inline] __x64_sys_fallocate+0x92/0xf0 fs/open.c:337 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x45de59 Code: Bad RIP value. RSP: 002b:00007f7cfaf5cc78 EFLAGS: 00000246 ORIG_RAX: 000000000000011d RAX: ffffffffffffffda RBX: 0000000000002ec0 RCX: 000000000045de59 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003 RBP: 000000000118bf68 R08: 0000000000000000 R09: 0000000000000000 R10: 000000000000ffe0 R11: 0000000000000246 R12: 000000000118bf2c R13: 00007ffdb1975eff R14: 00007f7cfaf5d9c0 R15: 000000000118bf2c INFO: task syz-executor.4:8113 blocked for more than 140 seconds. Not tainted 4.19.155-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.4 D25656 8113 6651 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 io_schedule+0x1c/0x70 kernel/sched/core.c:5185 bit_wait_io+0xf/0x90 kernel/sched/wait_bit.c:207 __wait_on_bit_lock+0xbb/0x160 kernel/sched/wait_bit.c:89 out_of_line_wait_on_bit_lock+0xde/0x110 kernel/sched/wait_bit.c:116 wait_on_bit_lock_io include/linux/wait_bit.h:208 [inline] __lock_buffer+0x3c/0x40 fs/buffer.c:65 lock_buffer include/linux/buffer_head.h:374 [inline] __sync_dirty_buffer+0x180/0x1f0 fs/buffer.c:3178 sync_dirty_buffer+0xe/0x10 fs/buffer.c:3204 __ext4_handle_dirty_metadata+0x17a/0x520 fs/ext4/ext4_jbd2.c:300 ext4_convert_inline_data_nolock+0x4f8/0xc40 fs/ext4/inline.c:1240 ext4_convert_inline_data+0x299/0x3b1 fs/ext4/inline.c:2026 ext4_fallocate+0xdb/0x1920 fs/ext4/extents.c:4960 vfs_fallocate+0x2b5/0x7c0 fs/open.c:308 ksys_fallocate+0x3c/0x80 fs/open.c:331 __do_sys_fallocate fs/open.c:339 [inline] __se_sys_fallocate fs/open.c:337 [inline] __x64_sys_fallocate+0x92/0xf0 fs/open.c:337 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x45de59 Code: Bad RIP value. RSP: 002b:00007f1f9b6c3c78 EFLAGS: 00000246 ORIG_RAX: 000000000000011d RAX: ffffffffffffffda RBX: 0000000000002ec0 RCX: 000000000045de59 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003 RBP: 000000000118bf68 R08: 0000000000000000 R09: 0000000000000000 R10: 000000000000ffe0 R11: 0000000000000246 R12: 000000000118bf2c R13: 00007ffffec8135f R14: 00007f1f9b6c49c0 R15: 000000000118bf2c INFO: task syz-executor.5:8151 blocked for more than 140 seconds. Not tainted 4.19.155-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.5 D25656 8151 6654 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 io_schedule+0x1c/0x70 kernel/sched/core.c:5185 bit_wait_io+0xf/0x90 kernel/sched/wait_bit.c:207 __wait_on_bit_lock+0xbb/0x160 kernel/sched/wait_bit.c:89 out_of_line_wait_on_bit_lock+0xde/0x110 kernel/sched/wait_bit.c:116 wait_on_bit_lock_io include/linux/wait_bit.h:208 [inline] __lock_buffer+0x3c/0x40 fs/buffer.c:65 lock_buffer include/linux/buffer_head.h:374 [inline] __sync_dirty_buffer+0x180/0x1f0 fs/buffer.c:3178 sync_dirty_buffer+0xe/0x10 fs/buffer.c:3204 __ext4_handle_dirty_metadata+0x17a/0x520 fs/ext4/ext4_jbd2.c:300 ext4_convert_inline_data_nolock+0x4f8/0xc40 fs/ext4/inline.c:1240 ext4_convert_inline_data+0x299/0x3b1 fs/ext4/inline.c:2026 ext4_fallocate+0xdb/0x1920 fs/ext4/extents.c:4960 vfs_fallocate+0x2b5/0x7c0 fs/open.c:308 ksys_fallocate+0x3c/0x80 fs/open.c:331 __do_sys_fallocate fs/open.c:339 [inline] __se_sys_fallocate fs/open.c:337 [inline] __x64_sys_fallocate+0x92/0xf0 fs/open.c:337 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x45de59 Code: Bad RIP value. RSP: 002b:00007f469fa7dc78 EFLAGS: 00000246 ORIG_RAX: 000000000000011d RAX: ffffffffffffffda RBX: 0000000000002ec0 RCX: 000000000045de59 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003 RBP: 000000000118bf68 R08: 0000000000000000 R09: 0000000000000000 R10: 000000000000ffe0 R11: 0000000000000246 R12: 000000000118bf2c R13: 00007ffdf42aa2cf R14: 00007f469fa7e9c0 R15: 000000000118bf2c INFO: task syz-executor.2:8160 blocked for more than 140 seconds. Not tainted 4.19.155-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.2 D25656 8160 6652 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 io_schedule+0x1c/0x70 kernel/sched/core.c:5185 bit_wait_io+0xf/0x90 kernel/sched/wait_bit.c:207 __wait_on_bit_lock+0xbb/0x160 kernel/sched/wait_bit.c:89 out_of_line_wait_on_bit_lock+0xde/0x110 kernel/sched/wait_bit.c:116 wait_on_bit_lock_io include/linux/wait_bit.h:208 [inline] __lock_buffer+0x3c/0x40 fs/buffer.c:65 lock_buffer include/linux/buffer_head.h:374 [inline] __sync_dirty_buffer+0x180/0x1f0 fs/buffer.c:3178 sync_dirty_buffer+0xe/0x10 fs/buffer.c:3204 __ext4_handle_dirty_metadata+0x17a/0x520 fs/ext4/ext4_jbd2.c:300 ext4_convert_inline_data_nolock+0x4f8/0xc40 fs/ext4/inline.c:1240 ext4_convert_inline_data+0x299/0x3b1 fs/ext4/inline.c:2026 ext4_fallocate+0xdb/0x1920 fs/ext4/extents.c:4960 vfs_fallocate+0x2b5/0x7c0 fs/open.c:308 ksys_fallocate+0x3c/0x80 fs/open.c:331 __do_sys_fallocate fs/open.c:339 [inline] __se_sys_fallocate fs/open.c:337 [inline] __x64_sys_fallocate+0x92/0xf0 fs/open.c:337 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x45de59 Code: Bad RIP value. RSP: 002b:00007f97f6206c78 EFLAGS: 00000246 ORIG_RAX: 000000000000011d RAX: ffffffffffffffda RBX: 0000000000002ec0 RCX: 000000000045de59 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003 RBP: 000000000118bf68 R08: 0000000000000000 R09: 0000000000000000 R10: 000000000000ffe0 R11: 0000000000000246 R12: 000000000118bf2c R13: 00007ffdf6611e3f R14: 00007f97f62079c0 R15: 000000000118bf2c INFO: task syz-executor.0:8162 blocked for more than 140 seconds. Not tainted 4.19.155-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.0 D25656 8162 6650 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 io_schedule+0x1c/0x70 kernel/sched/core.c:5185 bit_wait_io+0xf/0x90 kernel/sched/wait_bit.c:207 __wait_on_bit_lock+0xbb/0x160 kernel/sched/wait_bit.c:89 out_of_line_wait_on_bit_lock+0xde/0x110 kernel/sched/wait_bit.c:116 wait_on_bit_lock_io include/linux/wait_bit.h:208 [inline] __lock_buffer+0x3c/0x40 fs/buffer.c:65 lock_buffer include/linux/buffer_head.h:374 [inline] __sync_dirty_buffer+0x180/0x1f0 fs/buffer.c:3178 sync_dirty_buffer+0xe/0x10 fs/buffer.c:3204 __ext4_handle_dirty_metadata+0x17a/0x520 fs/ext4/ext4_jbd2.c:300 ext4_convert_inline_data_nolock+0x4f8/0xc40 fs/ext4/inline.c:1240 ext4_convert_inline_data+0x299/0x3b1 fs/ext4/inline.c:2026 ext4_fallocate+0xdb/0x1920 fs/ext4/extents.c:4960 vfs_fallocate+0x2b5/0x7c0 fs/open.c:308 ksys_fallocate+0x3c/0x80 fs/open.c:331 __do_sys_fallocate fs/open.c:339 [inline] __se_sys_fallocate fs/open.c:337 [inline] __x64_sys_fallocate+0x92/0xf0 fs/open.c:337 do_syscall_64+0xd0/0x4e0 arch/x86/entry/common.c:293 entry_SYSCALL_64_after_hwframe+0x49/0xbe RIP: 0033:0x45de59 Code: Bad RIP value. RSP: 002b:00007f1b970f6c78 EFLAGS: 00000246 ORIG_RAX: 000000000000011d RAX: ffffffffffffffda RBX: 0000000000002ec0 RCX: 000000000045de59 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003 RBP: 000000000118bf68 R08: 0000000000000000 R09: 0000000000000000 R10: 000000000000ffe0 R11: 0000000000000246 R12: 000000000118bf2c R13: 00007ffd8fa7833f R14: 00007f1b970f79c0 R15: 000000000118bf2c Showing all locks held in the system: 3 locks held by kworker/u4:0/7: 1 lock held by khungtaskd/1093: #0: 00000000d6f9ebfc (rcu_read_lock){....}, at: debug_show_all_locks+0x5b/0x27a kernel/locking/lockdep.c:4442 1 lock held by in:imklog/6123: #0: 000000001c7c0df0 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xa7/0xd0 fs/file.c:767 2 locks held by syz-executor.1/8039: #0: 00000000477a9dd4 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000477a9dd4 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 0000000082c757f1 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 0000000082c757f1 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2024 2 locks held by syz-executor.3/8042: #0: 000000008585d5c9 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 000000008585d5c9 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000408da503 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000408da503 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2024 2 locks held by syz-executor.4/8113: #0: 00000000854a2c71 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000854a2c71 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000319a38e1 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000319a38e1 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2024 2 locks held by syz-executor.5/8151: #0: 00000000fdf6e680 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000fdf6e680 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 000000004929d63c (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 000000004929d63c (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2024 2 locks held by syz-executor.2/8160: #0: 00000000fe0eeec3 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000fe0eeec3 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000a1678704 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000a1678704 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2024 2 locks held by syz-executor.0/8162: #0: 00000000fa43dee7 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000fa43dee7 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000ef2c3d06 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000ef2c3d06 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2024 ============================================= NMI backtrace for cpu 0 CPU: 0 PID: 1093 Comm: khungtaskd Not tainted 4.19.155-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/0x22a lib/dump_stack.c:118 nmi_cpu_backtrace.cold.0+0x3c/0x78 lib/nmi_backtrace.c:101 nmi_trigger_cpumask_backtrace+0xf5/0x119 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 skipped: idling at native_safe_halt+0x12/0x20 arch/x86/include/asm/irqflags.h:60