bisecting fixing commit since a1b977b49b66c75e6c51a515f6700371ae720217 building syzkaller on 4a77ae0bdc5cd75ebe88ce7c896aae6bbf457a29 testing commit a1b977b49b66c75e6c51a515f6700371ae720217 with gcc (GCC) 8.1.0 kernel signature: 4efec690665a3a68e20f45d30add070c5cd7b77c8c71d18918dc7c35b85d1a88 all runs: crashed: INFO: task hung in __sync_dirty_buffer testing current HEAD 4abf26854aade9732a215a168205fa9fecd6149a testing commit 4abf26854aade9732a215a168205fa9fecd6149a with gcc (GCC) 8.1.0 kernel signature: 54ca9c75a0dde65de51133b120a9b90d80c1a5fbb916c560620451f22a7dcf51 all runs: crashed: INFO: task hung in __sync_dirty_buffer revisions tested: 2, total time: 35m45.928059431s (build: 21m23.319741291s, test: 13m37.897610964s) the crash still happens on HEAD commit msg: Linux 4.19.162 crash: INFO: task hung in __sync_dirty_buffer Bluetooth: hci1: command 0x0406 tx timeout Bluetooth: hci5: command 0x0406 tx timeout Bluetooth: hci4: command 0x0406 tx timeout Bluetooth: hci3: command 0x0406 tx timeout Bluetooth: hci0: command 0x0406 tx timeout INFO: task syz-executor.1:7490 blocked for more than 140 seconds. Not tainted 4.19.162-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.1 D25488 7490 5984 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:2027 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:00007f413b47bc78 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: 00007ffe55069eef R14: 00007f413b47c9c0 R15: 000000000118bf2c INFO: task syz-executor.5:7496 blocked for more than 140 seconds. Not tainted 4.19.162-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.5 D25656 7496 5985 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:2027 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:00007f8a480d7c78 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: 00007fffbf8062af R14: 00007f8a480d89c0 R15: 000000000118bf2c INFO: task syz-executor.2:7510 blocked for more than 140 seconds. Not tainted 4.19.162-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.2 D25656 7510 5986 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:2027 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:00007fba920e9c78 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: 00007ffc21fd8c0f R14: 00007fba920ea9c0 R15: 000000000118bf2c INFO: task syz-executor.0:7516 blocked for more than 140 seconds. Not tainted 4.19.162-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.0 D25656 7516 5979 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:2027 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:00007fbe30a50c78 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: 00007ffe1aae38bf R14: 00007fbe30a519c0 R15: 000000000118bf2c INFO: task syz-executor.4:7522 blocked for more than 140 seconds. Not tainted 4.19.162-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.4 D25656 7522 5980 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:2027 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:00007f2d84120c78 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: 00007fffd5bfceff R14: 00007f2d841219c0 R15: 000000000118bf2c INFO: task syz-executor.3:7531 blocked for more than 140 seconds. Not tainted 4.19.162-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.3 D25656 7531 5976 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:2027 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:00007f88f00d7c78 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: 00007ffe4b78433f R14: 00007f88f00d89c0 R15: 000000000118bf2c Showing all locks held in the system: 1 lock held by khungtaskd/1030: #0: 0000000082fafced (rcu_read_lock){....}, at: debug_show_all_locks+0x5b/0x27a kernel/locking/lockdep.c:4442 1 lock held by in:imklog/5568: #0: 000000002fa54041 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xa7/0xd0 fs/file.c:767 3 locks held by kworker/u4:7/7282: 4 locks held by kworker/u4:8/7383: 2 locks held by syz-executor.1/7490: #0: 00000000b59fbe29 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000b59fbe29 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 0000000067cc21f0 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 0000000067cc21f0 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2025 2 locks held by syz-executor.5/7496: #0: 000000004857ba1a (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 000000004857ba1a (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000c39b8111 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000c39b8111 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2025 2 locks held by syz-executor.2/7510: #0: 00000000fd529d20 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000fd529d20 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000ff8e715b (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000ff8e715b (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2025 2 locks held by syz-executor.0/7516: #0: 0000000086181c0d (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 0000000086181c0d (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000bf08b412 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000bf08b412 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2025 2 locks held by syz-executor.4/7522: #0: 00000000bbd19b67 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 00000000bbd19b67 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 00000000999649e6 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 00000000999649e6 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2025 2 locks held by syz-executor.3/7531: #0: 000000003f432c74 (sb_writers#3){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline] #0: 000000003f432c74 (sb_writers#3){.+.+}, at: vfs_fallocate+0x4df/0x7c0 fs/open.c:307 #1: 0000000097b5d0e8 (&ei->xattr_sem){++++}, at: ext4_write_lock_xattr fs/ext4/xattr.h:141 [inline] #1: 0000000097b5d0e8 (&ei->xattr_sem){++++}, at: ext4_convert_inline_data+0x1dc/0x3b1 fs/ext4/inline.c:2025 ============================================= NMI backtrace for cpu 0 CPU: 0 PID: 1030 Comm: khungtaskd Not tainted 4.19.162-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