Re: INFO: task hung in blkdev_fsync

2018-02-14 Thread Dmitry Vyukov 
On Wed, Feb 7, 2018 at 8:46 AM, syzbot
 wrote:
> Hello,
>
> syzbot hit the following crash on upstream commit
> e237f98a9c134c3d600353f21e07db915516875b (Mon Feb 5 21:35:56 2018 +)
> Merge tag 'xfs-4.16-merge-5' of
> git://git.kernel.org/pub/scm/fs/xfs/xfs-linux
>
> Unfortunately, I don't have any reproducer for this crash yet.
> Raw console output is attached.
> compiler: gcc (GCC) 7.1.1 20170620
> .config is attached.


Looks similar to this one:

#syz dup: INFO: task hung in sync_blockdev


> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+2c56c0ca42f9e7bf1...@syzkaller.appspotmail.com
> It will help syzbot understand when the bug is fixed. See footer for
> details.
> If you forward the report, please keep this part and the footer.
>
> Buffer I/O error on dev loop0, logical block 3, lost async page write
> INFO: task syz-executor1:13412 blocked for more than 120 seconds.
>   Not tainted 4.15.0+ #299
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> syz-executor1   D22160 13412  13284 0x0004
> Call Trace:
>  context_switch kernel/sched/core.c:2845 [inline]
>  __schedule+0x8eb/0x2060 kernel/sched/core.c:3421
>  schedule+0xf5/0x430 kernel/sched/core.c:3480
>  io_schedule+0x1c/0x70 kernel/sched/core.c:5096
>  wait_on_page_bit_common+0x4b3/0x770 mm/filemap.c:1099
>  wait_on_page_bit mm/filemap.c:1132 [inline]
>  wait_on_page_writeback include/linux/pagemap.h:546 [inline]
>  __filemap_fdatawait_range+0x282/0x430 mm/filemap.c:533
>  file_write_and_wait_range+0xd7/0x100 mm/filemap.c:756
>  blkdev_fsync+0x67/0xb0 fs/block_dev.c:623
>  vfs_fsync_range+0x110/0x260 fs/sync.c:196
>  generic_write_sync include/linux/fs.h:2679 [inline]
>  blkdev_write_iter+0x2e6/0x3e0 fs/block_dev.c:1895
>  call_write_iter include/linux/fs.h:1781 [inline]
>  do_iter_readv_writev+0x55c/0x830 fs/read_write.c:653
>  do_iter_write+0x154/0x540 fs/read_write.c:932
>  vfs_iter_write+0x77/0xb0 fs/read_write.c:945
>  iter_file_splice_write+0x7db/0xf30 fs/splice.c:749
>  do_splice_from fs/splice.c:851 [inline]
>  direct_splice_actor+0x125/0x180 fs/splice.c:1018
>  splice_direct_to_actor+0x2c1/0x820 fs/splice.c:973
>  do_splice_direct+0x29b/0x3c0 fs/splice.c:1061
>  do_sendfile+0x5c9/0xe80 fs/read_write.c:1413
>  SYSC_sendfile64 fs/read_write.c:1468 [inline]
>  SyS_sendfile64+0xbd/0x160 fs/read_write.c:1460
>  do_syscall_64+0x282/0x940 arch/x86/entry/common.c:287
>  entry_SYSCALL_64_after_hwframe+0x26/0x9b
> RIP: 0033:0x453299
> RSP: 002b:7faff6e0dc58 EFLAGS: 0212 ORIG_RAX: 0028
> RAX: ffda RBX: 0071bea0 RCX: 00453299
> RDX: 200ddff8 RSI: 0016 RDI: 0013
> RBP: 04a0 R08:  R09: 
> R10: 00010001 R11: 0212 R12: 006f5fa0
> R13:  R14: 7faff6e0e6d4 R15: 
>
> Showing all locks held in the system:
> 3 locks held by kworker/u4:2/69:
>  #0:  ((wq_completion)"writeback"){+.+.}, at: [<30bfda85>]
> process_one_work+0xaaf/0x1af0 kernel/workqueue.c:2084
>  #1:  ((work_completion)(&(>dwork)->work)){+.+.}, at:
> [<49257d79>] process_one_work+0xb01/0x1af0 kernel/workqueue.c:2088
>  #2:  (>s_umount_key#27){.+.+}, at: [<626952c2>]
> trylock_super+0x20/0x100 fs/super.c:395
> 2 locks held by khungtaskd/758:
>  #0:  (rcu_read_lock){}, at: [<9948c30a>]
> check_hung_uninterruptible_tasks kernel/hung_task.c:175 [inline]
>  #0:  (rcu_read_lock){}, at: [<9948c30a>] watchdog+0x1c5/0xd60
> kernel/hung_task.c:249
>  #1:  (tasklist_lock){.+.+}, at: []
> debug_show_all_locks+0xd3/0x3d0 kernel/locking/lockdep.c:4470
> 2 locks held by getty/4127:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4128:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4129:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4130:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4131:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at:

Re: INFO: task hung in blkdev_fsync

2018-02-14 Thread Dmitry Vyukov 
On Wed, Feb 7, 2018 at 8:46 AM, syzbot
 wrote:
> Hello,
>
> syzbot hit the following crash on upstream commit
> e237f98a9c134c3d600353f21e07db915516875b (Mon Feb 5 21:35:56 2018 +)
> Merge tag 'xfs-4.16-merge-5' of
> git://git.kernel.org/pub/scm/fs/xfs/xfs-linux
>
> Unfortunately, I don't have any reproducer for this crash yet.
> Raw console output is attached.
> compiler: gcc (GCC) 7.1.1 20170620
> .config is attached.


Looks similar to this one:

#syz dup: INFO: task hung in sync_blockdev


> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+2c56c0ca42f9e7bf1...@syzkaller.appspotmail.com
> It will help syzbot understand when the bug is fixed. See footer for
> details.
> If you forward the report, please keep this part and the footer.
>
> Buffer I/O error on dev loop0, logical block 3, lost async page write
> INFO: task syz-executor1:13412 blocked for more than 120 seconds.
>   Not tainted 4.15.0+ #299
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> syz-executor1   D22160 13412  13284 0x0004
> Call Trace:
>  context_switch kernel/sched/core.c:2845 [inline]
>  __schedule+0x8eb/0x2060 kernel/sched/core.c:3421
>  schedule+0xf5/0x430 kernel/sched/core.c:3480
>  io_schedule+0x1c/0x70 kernel/sched/core.c:5096
>  wait_on_page_bit_common+0x4b3/0x770 mm/filemap.c:1099
>  wait_on_page_bit mm/filemap.c:1132 [inline]
>  wait_on_page_writeback include/linux/pagemap.h:546 [inline]
>  __filemap_fdatawait_range+0x282/0x430 mm/filemap.c:533
>  file_write_and_wait_range+0xd7/0x100 mm/filemap.c:756
>  blkdev_fsync+0x67/0xb0 fs/block_dev.c:623
>  vfs_fsync_range+0x110/0x260 fs/sync.c:196
>  generic_write_sync include/linux/fs.h:2679 [inline]
>  blkdev_write_iter+0x2e6/0x3e0 fs/block_dev.c:1895
>  call_write_iter include/linux/fs.h:1781 [inline]
>  do_iter_readv_writev+0x55c/0x830 fs/read_write.c:653
>  do_iter_write+0x154/0x540 fs/read_write.c:932
>  vfs_iter_write+0x77/0xb0 fs/read_write.c:945
>  iter_file_splice_write+0x7db/0xf30 fs/splice.c:749
>  do_splice_from fs/splice.c:851 [inline]
>  direct_splice_actor+0x125/0x180 fs/splice.c:1018
>  splice_direct_to_actor+0x2c1/0x820 fs/splice.c:973
>  do_splice_direct+0x29b/0x3c0 fs/splice.c:1061
>  do_sendfile+0x5c9/0xe80 fs/read_write.c:1413
>  SYSC_sendfile64 fs/read_write.c:1468 [inline]
>  SyS_sendfile64+0xbd/0x160 fs/read_write.c:1460
>  do_syscall_64+0x282/0x940 arch/x86/entry/common.c:287
>  entry_SYSCALL_64_after_hwframe+0x26/0x9b
> RIP: 0033:0x453299
> RSP: 002b:7faff6e0dc58 EFLAGS: 0212 ORIG_RAX: 0028
> RAX: ffda RBX: 0071bea0 RCX: 00453299
> RDX: 200ddff8 RSI: 0016 RDI: 0013
> RBP: 04a0 R08:  R09: 
> R10: 00010001 R11: 0212 R12: 006f5fa0
> R13:  R14: 7faff6e0e6d4 R15: 
>
> Showing all locks held in the system:
> 3 locks held by kworker/u4:2/69:
>  #0:  ((wq_completion)"writeback"){+.+.}, at: [<30bfda85>]
> process_one_work+0xaaf/0x1af0 kernel/workqueue.c:2084
>  #1:  ((work_completion)(&(>dwork)->work)){+.+.}, at:
> [<49257d79>] process_one_work+0xb01/0x1af0 kernel/workqueue.c:2088
>  #2:  (>s_umount_key#27){.+.+}, at: [<626952c2>]
> trylock_super+0x20/0x100 fs/super.c:395
> 2 locks held by khungtaskd/758:
>  #0:  (rcu_read_lock){}, at: [<9948c30a>]
> check_hung_uninterruptible_tasks kernel/hung_task.c:175 [inline]
>  #0:  (rcu_read_lock){}, at: [<9948c30a>] watchdog+0x1c5/0xd60
> kernel/hung_task.c:249
>  #1:  (tasklist_lock){.+.+}, at: []
> debug_show_all_locks+0xd3/0x3d0 kernel/locking/lockdep.c:4470
> 2 locks held by getty/4127:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4128:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4129:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4130:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131
> 2 locks held by getty/4131:
>  #0:  (>ldisc_sem){}, at: []
> ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
>  #1:  (>atomic_read_lock){+.+.}, at: [<426efef1>]
> n_tty_read+0x2ef/0x1a00 drivers/tty/n_tty.c:2131