syzbot


INFO: task hung in inode_sleep_on_writeback

Status: closed as dup on 2019/02/06 13:32
Subsystems: exfat
[Documentation on labels]
Reported-by: syzbot+c5c8b1d5d0cf2b64e632@syzkaller.appspotmail.com
First crash: 2219d, last: 1931d
Duplicate of
Title Repro Cause bisect Fix bisect Count Last Reported
INFO: task hung in generic_file_write_iter fs mm 7 1971d 2109d
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in inode_sleep_on_writeback (2) fs 1 901d 901d 0/26 auto-closed as invalid on 2022/02/05 13:28

Sample crash report:
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
INFO: task kworker/u4:2:32 blocked for more than 140 seconds.
__find_get_block_slow() failed. block=1, b_blocknr=8
      Not tainted 5.0.0-rc1+ #20
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
b_state=0x00000029, b_size=512
kworker/u4:2    D19576    32      2 0x80000000
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
Workqueue: writeback wb_workfn (flush-7:0)
b_state=0x00000029, b_size=512
Call Trace:
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
 context_switch kernel/sched/core.c:2831 [inline]
 __schedule+0x897/0x1e60 kernel/sched/core.c:3472
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
 schedule+0xfe/0x350 kernel/sched/core.c:3516
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
 inode_sleep_on_writeback+0x203/0x250 fs/fs-writeback.c:1229
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
 wb_writeback+0x4b8/0xf70 fs/fs-writeback.c:1788
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
 wb_check_old_data_flush fs/fs-writeback.c:1860 [inline]
 wb_do_writeback fs/fs-writeback.c:1913 [inline]
 wb_workfn+0xf7f/0x16f0 fs/fs-writeback.c:1942
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
 process_one_work+0xd0c/0x1ce0 kernel/workqueue.c:2153
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
 worker_thread+0x143/0x14a0 kernel/workqueue.c:2296
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
 kthread+0x357/0x430 kernel/kthread.c:246
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352

Showing all locks held in the system:
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
2 locks held by kworker/u4:2/32:
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
 #0: 00000000fd2d6fbd ((wq_completion)"writeback"){+.+.}, at: __write_once_size include/linux/compiler.h:218 [inline]
 #0: 00000000fd2d6fbd ((wq_completion)"writeback"){+.+.}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: 00000000fd2d6fbd ((wq_completion)"writeback"){+.+.}, at: atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
 #0: 00000000fd2d6fbd ((wq_completion)"writeback"){+.+.}, at: atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
 #0: 00000000fd2d6fbd ((wq_completion)"writeback"){+.+.}, at: set_work_data kernel/workqueue.c:617 [inline]
 #0: 00000000fd2d6fbd ((wq_completion)"writeback"){+.+.}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
 #0: 00000000fd2d6fbd ((wq_completion)"writeback"){+.+.}, at: process_one_work+0xbc7/0x1ce0 kernel/workqueue.c:2124
b_state=0x00000029, b_size=512
 #1: 00000000907482f4 ((work_completion)(&(&wb->dwork)->work)){+.+.}, at: process_one_work+0xc1d/0x1ce0 kernel/workqueue.c:2128
device loop0 blocksize: 4096
1 lock held by khungtaskd/1040:
__find_get_block_slow() failed. block=1, b_blocknr=8
 #0: 000000005a1679b2 (rcu_read_lock){....}, at: debug_show_all_locks+0xc6/0x41d kernel/locking/lockdep.c:4389
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
1 lock held by rsyslogd/7598:
b_state=0x00000029, b_size=512
2 locks held by getty/7688:
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
 #0: 000000000e6176dc (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
 #1: 00000000ee2d422b (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x30a/0x1eb0 drivers/tty/n_tty.c:2154
b_state=0x00000029, b_size=512
2 locks held by getty/7689:
device loop0 blocksize: 4096
 #0: 00000000f0fde980 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 00000000da3af52c (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x30a/0x1eb0 drivers/tty/n_tty.c:2154
__find_get_block_slow() failed. block=1, b_blocknr=8
2 locks held by getty/7690:
b_state=0x00000029, b_size=512
 #0: 000000006298a026 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
device loop0 blocksize: 4096
 #1: 00000000180289ec (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x30a/0x1eb0 drivers/tty/n_tty.c:2154
__find_get_block_slow() failed. block=1, b_blocknr=8
2 locks held by getty/7691:
b_state=0x00000029, b_size=512
 #0: 00000000a0ea55ee (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
device loop0 blocksize: 4096
 #1: 000000001fb448f0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x30a/0x1eb0 drivers/tty/n_tty.c:2154
__find_get_block_slow() failed. block=1, b_blocknr=8
2 locks held by getty/7692:
b_state=0x00000029, b_size=512
 #0: 00000000c57d1af8 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
device loop0 blocksize: 4096
 #1: 000000008894be7a (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x30a/0x1eb0 drivers/tty/n_tty.c:2154
2 locks held by getty/7693:
__find_get_block_slow() failed. block=1, b_blocknr=8
 #0: 0000000029d04c52 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
b_state=0x00000029, b_size=512
 #1: 00000000594b95fb (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x30a/0x1eb0 drivers/tty/n_tty.c:2154
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
2 locks held by getty/7694:
b_state=0x00000029, b_size=512
 #0: 000000006b2b1021 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:341
 #1: 000000006dc249a5 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x30a/0x1eb0 drivers/tty/n_tty.c:2154
device loop0 blocksize: 4096
1 lock held by syz-executor4/7849:
__find_get_block_slow() failed. block=1, b_blocknr=8
 #0: 0000000089ba492d (&sig->cred_guard_mutex){+.+.}, at: prepare_bprm_creds fs/exec.c:1407 [inline]
 #0: 0000000089ba492d (&sig->cred_guard_mutex){+.+.}, at: __do_execve_file.isra.0+0x45d/0x2700 fs/exec.c:1750
b_state=0x00000029, b_size=512
1 lock held by syz-executor4/7867:
device loop0 blocksize: 4096
 #0: 000000006add4c0c (&sig->cred_guard_mutex){+.+.}, at: prepare_bprm_creds fs/exec.c:1407 [inline]
 #0: 000000006add4c0c (&sig->cred_guard_mutex){+.+.}, at: __do_execve_file.isra.0+0x45d/0x2700 fs/exec.c:1750
__find_get_block_slow() failed. block=1, b_blocknr=8
6 locks held by syz-executor0/28598:
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8

b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
=============================================

b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
NMI backtrace for cpu 0
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
CPU: 0 PID: 1040 Comm: khungtaskd Not tainted 5.0.0-rc1+ #20
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__find_get_block_slow() failed. block=1, b_blocknr=8
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1db/0x2d0 lib/dump_stack.c:113
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
 nmi_cpu_backtrace.cold+0x63/0xa4 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x1be/0x236 lib/nmi_backtrace.c:62
__find_get_block_slow() failed. block=1, b_blocknr=8
 arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
b_state=0x00000029, b_size=512
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
 watchdog+0xbbb/0x1170 kernel/hung_task.c:287
device loop0 blocksize: 4096
__find_get_block_slow() failed. block=1, b_blocknr=8
b_state=0x00000029, b_size=512
device loop0 blocksize: 4096
 kthread+0x357/0x430 kernel/kthread.c:246
__find_get_block_slow() failed. block=1, b_blocknr=8
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
b_state=0x00000029, b_size=512
Sending NMI from CPU 0 to CPUs 1:
device loop0 blocksize: 4096
NMI backtrace for cpu 1
CPU: 1 PID: 28598 Comm: syz-executor0 Not tainted 5.0.0-rc1+ #20
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:io_serial_out+0x73/0x90 drivers/tty/serial/8250/8250_port.c:456
Code: 00 49 8d 7c 24 38 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 d3 e3 80 3c 02 00 75 19 41 03 5c 24 38 44 89 e8 89 da ee <5b> 41 5c 41 5d 5d c3 e8 a1 4f e4 fd eb c0 e8 fa 4f e4 fd eb e0 0f
RSP: 0018:ffff888055b9e768 EFLAGS: 00000006
RAX: 0000000000000000 RBX: 00000000000003f9 RCX: 0000000000000000
RDX: 00000000000003f9 RSI: ffffffff83e19246 RDI: ffffffff8bf721f8
RBP: ffff888055b9e780 R08: ffff8880a4b32340 R09: ffffed100ab73cdf
R10: ffffed100ab73cde R11: 0000000000000003 R12: ffffffff8bf721c0
R13: 0000000000000000 R14: ffff888055b9e878 R15: ffffffff8bf72208
FS:  00007f4634436700(0000) GS:ffff8880ae700000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000001d98af0 CR3: 00000000a8b31000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 serial_port_out include/linux/serial_core.h:278 [inline]
 serial8250_console_write+0x31e/0xab0 drivers/tty/serial/8250/8250_port.c:3255
 univ8250_console_write+0x5f/0x70 drivers/tty/serial/8250/8250_core.c:586
 call_console_drivers kernel/printk/printk.c:1737 [inline]
 console_unlock+0xcff/0x11e0 kernel/printk/printk.c:2408
 vprintk_emit+0x370/0x960 kernel/printk/printk.c:1931
 vprintk_default+0x28/0x30 kernel/printk/printk.c:1958
 vprintk_func+0x7e/0x189 kernel/printk/printk_safe.c:398
 printk+0xba/0xed kernel/printk/printk.c:1991
 __find_get_block_slow fs/buffer.c:237 [inline]
 __find_get_block fs/buffer.c:1294 [inline]
 __find_get_block.cold+0xd4/0xfb fs/buffer.c:1288
 __getblk_slow fs/buffer.c:1039 [inline]
 __getblk_gfp+0x295/0xd20 fs/buffer.c:1320
 __bread_gfp+0x2f/0x300 fs/buffer.c:1354
 sb_bread include/linux/buffer_head.h:307 [inline]
 __fat_write_inode+0x33a/0xb70 fs/fat/inode.c:859
 fat_write_inode+0x96/0x190 fs/fat/inode.c:908
 write_inode fs/fs-writeback.c:1176 [inline]
 __writeback_single_inode+0xef1/0x1620 fs/fs-writeback.c:1375
 writeback_single_inode+0x3b2/0x590 fs/fs-writeback.c:1429
 sync_inode fs/fs-writeback.c:2463 [inline]
 sync_inode_metadata+0x11c/0x180 fs/fs-writeback.c:2483
 __generic_file_fsync+0x169/0x200 fs/libfs.c:988
 generic_file_fsync+0x78/0x120 fs/libfs.c:1018
 fat_file_fsync+0x78/0x170 fs/fat/file.c:198
 vfs_fsync_range+0x144/0x230 fs/sync.c:197
 generic_write_sync include/linux/fs.h:2786 [inline]
 generic_file_write_iter+0x500/0x6a0 mm/filemap.c:3365
 call_write_iter include/linux/fs.h:1862 [inline]
 new_sync_write fs/read_write.c:474 [inline]
 __vfs_write+0x764/0xb40 fs/read_write.c:487
 __kernel_write+0x110/0x3b0 fs/read_write.c:506
 write_pipe_buf+0x180/0x240 fs/splice.c:797
 splice_from_pipe_feed fs/splice.c:503 [inline]
 __splice_from_pipe+0x39a/0x7e0 fs/splice.c:627
 splice_from_pipe+0x1ea/0x310 fs/splice.c:662
 default_file_splice_write+0x3c/0x90 fs/splice.c:809
 do_splice_from fs/splice.c:851 [inline]
 direct_splice_actor+0x126/0x1a0 fs/splice.c:1023
 splice_direct_to_actor+0x3be/0x9d0 fs/splice.c:978
 do_splice_direct+0x2c7/0x420 fs/splice.c:1066
 do_sendfile+0x61a/0xe60 fs/read_write.c:1436
 __do_sys_sendfile64 fs/read_write.c:1491 [inline]
 __se_sys_sendfile64 fs/read_write.c:1483 [inline]
 __x64_sys_sendfile64+0x15a/0x240 fs/read_write.c:1483
 do_syscall_64+0x1a3/0x800 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x457ec9
Code: 6d b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 3b b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f4634435c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 0000000000457ec9
RDX: 0000000020000000 RSI: 0000000000000007 RDI: 0000000000000007
RBP: 000000000073bfa0 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 00007f46344366d4
R13: 00000000004c4cdc R14: 00000000004d85c0 R15: 00000000ffffffff
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.360 msecs

Crashes (8):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/01/12 05:56 upstream de6629eb262e c3f3344c .config console log report ci-upstream-kasan-gce-smack-root
2018/12/11 12:51 upstream f5d582777bcb 7795ae03 .config console log report ci-upstream-kasan-gce-selinux-root
2018/12/08 13:26 upstream 5f179793f0a7 60562a1d .config console log report ci-upstream-kasan-gce-smack-root
2018/12/06 15:27 upstream cf76c364a1e1 3ab38479 .config console log report ci-upstream-kasan-gce-smack-root
2018/11/30 01:02 upstream f92a2ebb3d55 66071e27 .config console log report ci-upstream-kasan-gce-root
2018/07/15 02:22 upstream c31496dbacc2 92a49505 .config console log report ci-upstream-kasan-gce-root
2018/06/23 13:38 upstream 894b8c000ae6 2064fc5c .config console log report ci-upstream-kasan-gce-root
2018/03/29 21:30 upstream 0b412605ef5f d47f0ed6 .config console log report ci-upstream-kasan-gce-386
* Struck through repros no longer work on HEAD.