Re: INFO: task hung in grab_super

[Dmitry Vyukov]

On Wed, Jul 18, 2018 at 1:02 PM, Dmitry Vyukov <dvyukov@xxxxxxxxxx> wrote:
> On Wed, Jul 18, 2018 at 12:49 PM, Tetsuo Handa
> <penguin-kernel@xxxxxxxxxxxxxxxxxxx> wrote:
>> Dmitry,
>>
>> this is yet another example of stalling inside __bread_gfp().
>>
>> Can you find all reports where NMI backtrace contains __bread_gfp ?
>>
>> I need to wget all reports if I try to do that on my side.
>> If you can locally grep on your side, it will be nice.
>
>
> No, I don't have grep. But here are some of the matches:
>
> https://groups.google.com/forum/#!searchin/syzkaller-bugs/__bread_gfp%7Csort:date
> https://groups.google.com/forum/#!searchin/syzkaller-upstream-moderation/__bread_gfp%7Csort:date
>
>
>
>> On 2018/07/18 19:38, syzbot wrote:
>>> CPU: 1 PID: 19991 Comm: syz-executor1 Not tainted 4.18.0-rc5+ #152
>>> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
>>> RIP: 0010:__lock_is_held+0x76/0x140 kernel/locking/lockdep.c:3741
>>> Code: 00 00 4c 8b 6d c8 4d 8d b4 24 38 08 00 00 45 31 ff 48 b8 00 00 00 00 00 fc ff df 49 c1 ed 03 49 01 c5 41 8b 84 24 30 08 00 00 <85> c0 7f 24 e9 85 00 00 00 41 0f b6 45 00 41 83 c7 01 84 c0 74 08
>>> RSP: 0018:ffff88018ea3eed8 EFLAGS: 00000086
>>> RAX: 0000000000000001 RBX: 0000000000000286 RCX: ffffc9000443f000
>>> RDX: 1ffff10031c245de RSI: 00000000ffffffff RDI: ffffffff88f925e0
>>> RBP: ffff88018ea3ef18 R08: ffff88018e1226c0 R09: ffffed003b5e46d6
>>> R10: 0000000000000003 R11: 0000000000000001 R12: ffff88018e1226c0
>>> R13: ffffed0031c245de R14: ffff88018e122ef8 R15: 0000000000000000
>>> FS:  00007f243a415700(0000) GS:ffff8801daf00000(0000) knlGS:0000000000000000
>>> CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> CR2: ffffffffff600400 CR3: 00000001d8749000 CR4: 00000000001406e0
>>> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>>> DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>>> Call Trace:
>>>  lock_is_held_type+0x121/0x210 kernel/locking/lockdep.c:3962
>>>  lock_is_held include/linux/lockdep.h:344 [inline]
>>>  ___might_sleep+0x295/0x330 kernel/sched/core.c:6152
>>>  __might_sleep+0x95/0x190 kernel/sched/core.c:6140
>>>  lock_page include/linux/pagemap.h:481 [inline]
>>>  pagecache_get_page+0x787/0xe40 mm/filemap.c:1554
>>>  find_or_create_page include/linux/pagemap.h:322 [inline]
>>>  grow_dev_page fs/buffer.c:940 [inline]
>>>  grow_buffers fs/buffer.c:1009 [inline]
>>>  __getblk_slow fs/buffer.c:1036 [inline]
>>>  __getblk_gfp+0x3bb/0xb10 fs/buffer.c:1313
>>>  __bread_gfp+0x2d/0x310 fs/buffer.c:1347
>>>  sb_bread_unmovable include/linux/buffer_head.h:313 [inline]
>>>  ext4_fill_super+0x6de/0xda80 fs/ext4/super.c:3541
>>>  mount_bdev+0x30c/0x3e0 fs/super.c:1174
>>>  ext4_mount+0x34/0x40 fs/ext4/super.c:5844
>>>  mount_fs+0xae/0x328 fs/super.c:1277
>>>  vfs_kern_mount.part.34+0xdc/0x4e0 fs/namespace.c:1037
>>>  vfs_kern_mount fs/namespace.c:1027 [inline]
>>>  do_new_mount fs/namespace.c:2518 [inline]
>>>  do_mount+0x581/0x30e0 fs/namespace.c:2848
>>>  ksys_mount+0x12d/0x140 fs/namespace.c:3064
>>>  __do_sys_mount fs/namespace.c:3078 [inline]
>>>  __se_sys_mount fs/namespace.c:3075 [inline]
>>>  __x64_sys_mount+0xbe/0x150 fs/namespace.c:3075
>>>  do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
>>>  entry_SYSCALL_64_after_hwframe+0x49/0xbe


This seems to be related to 9p. After rerunning the log I got:

root@syzkaller:~# ps afxu | grep syz
root     18253  0.0  0.0      0     0 ttyS0    Zl   10:16   0:00  \_
[syz-executor] <defunct>
root@syzkaller:~# cat /proc/18253/task/*/stack
[<0>] p9_client_rpc+0x3a2/0x1400
[<0>] p9_client_flush+0x134/0x2a0
[<0>] p9_client_rpc+0x122c/0x1400
[<0>] p9_client_create+0xc56/0x16af
[<0>] v9fs_session_init+0x21a/0x1a80
[<0>] v9fs_mount+0x7c/0x900
[<0>] mount_fs+0xae/0x328
[<0>] vfs_kern_mount.part.34+0xdc/0x4e0
[<0>] do_mount+0x581/0x30e0
[<0>] ksys_mount+0x12d/0x140
[<0>] __x64_sys_mount+0xbe/0x150
[<0>] do_syscall_64+0x1b9/0x820
[<0>] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[<0>] 0xffffffffffffffff

There is a bunch of hangs in 9p, so let's do:

#syz dup: INFO: task hung in flush_work