INFO: task hung in truncate_inode_pages_range

30 views
Skip to first unread message

syzbot

unread,
Feb 3, 2021, 2:50:13 AM2/3/21
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 811218ec Linux 4.19.172
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1779aac4d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=c1cb1d27398c8808
dashboard link: https://syzkaller.appspot.com/bug?extid=18932b8b4c779deb37ea
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=157a5ac4d00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=155b33d8d00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+18932b...@syzkaller.appspotmail.com

Dev nbd0: unable to read RDB block 0
nbd0: unable to read partition table
ldm_validate_partition_table(): Disk read failed.
Dev nbd0: unable to read RDB block 0
nbd0: unable to read partition table
INFO: task systemd-udevd:8104 blocked for more than 140 seconds.
Not tainted 4.19.172-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
systemd-udevd D28184 8104 4700 0x80000106
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
io_schedule+0xb5/0x120 kernel/sched/core.c:5181
wait_on_page_bit_common mm/filemap.c:1123 [inline]
__lock_page+0x316/0x460 mm/filemap.c:1296
lock_page include/linux/pagemap.h:483 [inline]
truncate_inode_pages_range+0x1289/0x1b10 mm/truncate.c:448
kill_bdev fs/block_dev.c:86 [inline]
__blkdev_put+0x2a8/0x870 fs/block_dev.c:1813
blkdev_close+0x86/0xb0 fs/block_dev.c:1888
__fput+0x2ce/0x890 fs/file_table.c:278
task_work_run+0x148/0x1c0 kernel/task_work.c:113
exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0xbf3/0x2be0 kernel/exit.c:870
do_group_exit+0x125/0x310 kernel/exit.c:967
get_signal+0x3f2/0x1f70 kernel/signal.c:2589
do_signal+0x8f/0x1670 arch/x86/kernel/signal.c:821
exit_to_usermode_loop+0x204/0x2a0 arch/x86/entry/common.c:163
prepare_exit_to_usermode arch/x86/entry/common.c:198 [inline]
syscall_return_slowpath arch/x86/entry/common.c:271 [inline]
do_syscall_64+0x538/0x620 arch/x86/entry/common.c:296
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7feaf5a1f210
Code: Bad RIP value.
RSP: 002b:00007fff471fed08 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: fffffffffffffffc RBX: 000055c94a792dd0 RCX: 00007feaf5a1f210
RDX: 0000000000000040 RSI: 000055c94a792df8 RDI: 000000000000000f
RBP: 000055c94a7a7a10 R08: 00007feaf5a09be8 R09: 0000000000000070
R10: 000000000000006d R11: 0000000000000246 R12: 008fffffffff0000
R13: 008fffffffff0040 R14: 000055c94a7a7a60 R15: 0000000000000040
INFO: task syz-executor512:13621 blocked for more than 140 seconds.
Not tainted 4.19.172-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor512 D29160 13621 8095 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
__blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
blkdev_get+0xb0/0x940 fs/block_dev.c:1627
blkdev_open+0x202/0x290 fs/block_dev.c:1788
do_dentry_open+0x4aa/0x1160 fs/open.c:796
do_last fs/namei.c:3421 [inline]
path_openat+0x793/0x2df0 fs/namei.c:3537
do_filp_open+0x18c/0x3f0 fs/namei.c:3567
do_sys_open+0x3b3/0x520 fs/open.c:1085
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x406954
Code: Bad RIP value.
RSP: 002b:00007fbc5bc63e70 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000406954
RDX: 0000000000000000 RSI: 00007fbc5bc63ef0 RDI: 00000000ffffff9c
RBP: 00007fbc5bc63ef0 R08: 0000000000000000 R09: 002364626e2f7665
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 000000000049a074 R14: 64626e2f7665642f R15: 0000000000022000
INFO: task syz-executor512:13622 blocked for more than 140 seconds.
Not tainted 4.19.172-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor512 D29160 13622 8095 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
__blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
blkdev_get+0xb0/0x940 fs/block_dev.c:1627
blkdev_open+0x202/0x290 fs/block_dev.c:1788
do_dentry_open+0x4aa/0x1160 fs/open.c:796
do_last fs/namei.c:3421 [inline]
path_openat+0x793/0x2df0 fs/namei.c:3537
do_filp_open+0x18c/0x3f0 fs/namei.c:3567
do_sys_open+0x3b3/0x520 fs/open.c:1085
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x406954
Code: Bad RIP value.
RSP: 002b:00007fbc5bc42e70 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000406954
RDX: 0000000000000000 RSI: 00007fbc5bc42ef0 RDI: 00000000ffffff9c
RBP: 00007fbc5bc42ef0 R08: 0000000000000000 R09: 002364626e2f7665
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 000000000049a074 R14: 64626e2f7665642f R15: 0000000000022000
INFO: task syz-executor512:13623 blocked for more than 140 seconds.
Not tainted 4.19.172-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor512 D29160 13623 8095 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
__blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
blkdev_get+0xb0/0x940 fs/block_dev.c:1627
blkdev_open+0x202/0x290 fs/block_dev.c:1788
do_dentry_open+0x4aa/0x1160 fs/open.c:796
do_last fs/namei.c:3421 [inline]
path_openat+0x793/0x2df0 fs/namei.c:3537
do_filp_open+0x18c/0x3f0 fs/namei.c:3567
do_sys_open+0x3b3/0x520 fs/open.c:1085
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x406954
Code: Bad RIP value.
RSP: 002b:00007fbc5bc21e70 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000406954
RDX: 0000000000000000 RSI: 00007fbc5bc21ef0 RDI: 00000000ffffff9c
RBP: 00007fbc5bc21ef0 R08: 0000000000000000 R09: 002364626e2f7665
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 000000000049a074 R14: 64626e2f7665642f R15: 0000000000022000
INFO: task syz-executor512:13624 blocked for more than 140 seconds.
Not tainted 4.19.172-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor512 D29160 13624 8095 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x887/0x2040 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
__mutex_lock_common kernel/locking/mutex.c:1002 [inline]
__mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
__blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
blkdev_get+0xb0/0x940 fs/block_dev.c:1627
blkdev_open+0x202/0x290 fs/block_dev.c:1788
do_dentry_open+0x4aa/0x1160 fs/open.c:796
do_last fs/namei.c:3421 [inline]
path_openat+0x793/0x2df0 fs/namei.c:3537
do_filp_open+0x18c/0x3f0 fs/namei.c:3567
do_sys_open+0x3b3/0x520 fs/open.c:1085
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x406954
Code: Bad RIP value.
RSP: 002b:00007fbc5bc00e70 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000406954
RDX: 0000000000000000 RSI: 00007fbc5bc00ef0 RDI: 00000000ffffff9c
RBP: 00007fbc5bc00ef0 R08: 0000000000000000 R09: 002364626e2f7665
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 000000000049a074 R14: 64626e2f7665642f R15: 0000000000022000

Showing all locks held in the system:
1 lock held by khungtaskd/1566:
#0: 000000002909c861 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4440
1 lock held by in:imklog/7780:
#0: 00000000afdb9db1 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
1 lock held by systemd-udevd/8104:
#0: 00000000b136dbaa (&bdev->bd_mutex){+.+.}, at: __blkdev_put+0xfc/0x870 fs/block_dev.c:1806
1 lock held by syz-executor512/13621:
#0: 00000000b136dbaa (&bdev->bd_mutex){+.+.}, at: __blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
1 lock held by syz-executor512/13622:
#0: 00000000b136dbaa (&bdev->bd_mutex){+.+.}, at: __blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
1 lock held by syz-executor512/13623:
#0: 00000000b136dbaa (&bdev->bd_mutex){+.+.}, at: __blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478
1 lock held by syz-executor512/13624:
#0: 00000000b136dbaa (&bdev->bd_mutex){+.+.}, at: __blkdev_get+0x1d0/0x1480 fs/block_dev.c:1478

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 1566 Comm: khungtaskd Not tainted 4.19.172-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+0x1fc/0x2ef lib/dump_stack.c:118
nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1a6/0x1f0 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
watchdog+0x991/0xe60 kernel/hung_task.c:287
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 4691 Comm: systemd-journal Not tainted 4.19.172-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:unwind_next_frame+0x450/0x1c60 arch/x86/kernel/unwind_orc.c:427
Code: b8 00 00 00 00 00 fc ff df 4c 89 c2 48 c1 ea 03 0f b6 04 02 4c 89 c2 83 e2 07 38 d0 7f 08 84 c0 0f 85 80 10 00 00 0f b6 41 04 <a8> 0f 0f 85 a9 00 00 00 48 8d 79 05 48 b8 00 00 00 00 00 fc ff df
RSP: 0018:ffff8880a0fb7970 EFLAGS: 00000246
RAX: 0000000000000014 RBX: 1ffff110141f6f36 RCX: ffffffff8b8f8afa
RDX: 0000000000000006 RSI: ffffffff8b8f8ae2 RDI: ffffffff8b3226a4
RBP: 0000000000000001 R08: ffffffff8b8f8afe R09: ffffffff8b8f8ae2
R10: 0000000000074071 R11: 0000000000008163 R12: ffff8880a0fb7b58
R13: ffff8880a0fb7b45 R14: ffff8880a0fb7b48 R15: ffff8880a0fb7b10
FS: 00007fe530fda8c0(0000) GS:ffff8880ba000000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fb3e002f110 CR3: 00000000a08db000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
__unwind_start+0x5b8/0x960 arch/x86/kernel/unwind_orc.c:667
unwind_start arch/x86/include/asm/unwind.h:60 [inline]
__save_stack_trace+0x72/0x190 arch/x86/kernel/stacktrace.c:43
save_stack mm/kasan/kasan.c:448 [inline]
set_track mm/kasan/kasan.c:460 [inline]
kasan_kmalloc+0xeb/0x160 mm/kasan/kasan.c:553
slab_post_alloc_hook mm/slab.h:445 [inline]
slab_alloc mm/slab.c:3397 [inline]
kmem_cache_alloc+0x110/0x370 mm/slab.c:3557
getname_flags+0xce/0x590 fs/namei.c:140
getname fs/namei.c:211 [inline]
user_path_create fs/namei.c:3696 [inline]
do_mkdirat+0x8d/0x2d0 fs/namei.c:3834
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe530296687
Code: 00 b8 ff ff ff ff c3 0f 1f 40 00 48 8b 05 09 d8 2b 00 64 c7 00 5f 00 00 00 b8 ff ff ff ff c3 0f 1f 40 00 b8 53 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d e1 d7 2b 00 f7 d8 64 89 01 48
RSP: 002b:00007ffc5dceb1b8 EFLAGS: 00000293 ORIG_RAX: 0000000000000053
RAX: ffffffffffffffda RBX: 00007ffc5dcee220 RCX: 00007fe530296687
RDX: 0000000000000000 RSI: 00000000000001ed RDI: 0000564f68f898a0
RBP: 00007ffc5dceb1f0 R08: 0000564f684103e5 R09: 0000000000000018
R10: 0000000000000069 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000001 R14: 0000564f68f898a0 R15: 00007ffc5dceb830


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches
Reply all
Reply to author
Forward
0 new messages