INFO: task hung in deactivate_super

15 views
Skip to first unread message

syzbot

unread,
Nov 16, 2022, 5:48:37 AM11/16/22
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 3f8a27f9e27b Linux 4.19.211
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=141bd49e880000
kernel config: https://syzkaller.appspot.com/x/.config?x=9b9277b418617afe
dashboard link: https://syzkaller.appspot.com/bug?extid=326904e69945b150ac08
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/98c0bdb4abb3/disk-3f8a27f9.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/ea228ff02669/vmlinux-3f8a27f9.xz

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

F2FS-fs (loop4): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
F2FS-fs (loop2): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
F2FS-fs (loop4): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
INFO: task syz-executor.2:8142 blocked for more than 140 seconds.
Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2 D24216 8142 1 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
__rwsem_down_write_failed_common kernel/locking/rwsem-xadd.c:589 [inline]
rwsem_down_write_failed+0x3aa/0x760 kernel/locking/rwsem-xadd.c:618
call_rwsem_down_write_failed+0x13/0x20 arch/x86/lib/rwsem.S:117
__down_write arch/x86/include/asm/rwsem.h:142 [inline]
down_write+0x4f/0x90 kernel/locking/rwsem.c:72
deactivate_super+0x16c/0x1a0 fs/super.c:359
cleanup_mnt+0x1a8/0x290 fs/namespace.c:1098
task_work_run+0x148/0x1c0 kernel/task_work.c:113
tracehook_notify_resume include/linux/tracehook.h:193 [inline]
exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
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:0x7f941d460aa7
Code: Bad RIP value.
RSP: 002b:00007ffc979b28c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a6
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f941d460aa7
RDX: 00007ffc979b299a RSI: 000000000000000a RDI: 00007ffc979b2990
RBP: 00007ffc979b2990 R08: 00000000ffffffff R09: 00007ffc979b2760
R10: 000055555673b903 R11: 0000000000000246 R12: 00007f941d4b9b2e
R13: 00007ffc979b3a50 R14: 000055555673b810 R15: 00007ffc979b3a90
INFO: task syz-executor.4:8208 blocked for more than 140 seconds.
Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4 D24128 8208 1 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
__rwsem_down_write_failed_common kernel/locking/rwsem-xadd.c:589 [inline]
rwsem_down_write_failed+0x3aa/0x760 kernel/locking/rwsem-xadd.c:618
call_rwsem_down_write_failed+0x13/0x20 arch/x86/lib/rwsem.S:117
__down_write arch/x86/include/asm/rwsem.h:142 [inline]
down_write+0x4f/0x90 kernel/locking/rwsem.c:72
deactivate_super+0x16c/0x1a0 fs/super.c:359
f2fs_msg: 11301 callbacks suppressed
F2FS-fs (loop4): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
F2FS-fs (loop2): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
F2FS-fs (loop2): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
cleanup_mnt+0x1a8/0x290 fs/namespace.c:1098
F2FS-fs (loop4): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
task_work_run+0x148/0x1c0 kernel/task_work.c:113
F2FS-fs (loop4): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
tracehook_notify_resume include/linux/tracehook.h:193 [inline]
exit_to_usermode_loop+0x251/0x2a0 arch/x86/entry/common.c:167
F2FS-fs (loop4): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
F2FS-fs (loop2): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
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
F2FS-fs (loop2): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
F2FS-fs (loop4): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
F2FS-fs (loop2): sanity_check_inode: inode (ino=8) has corrupted i_extra_isize: 36, max: 24
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fc7009b6aa7
Code: Bad RIP value.
RSP: 002b:00007ffebed4e0e8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a6
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007fc7009b6aa7
RDX: 00007ffebed4e1ba RSI: 000000000000000a RDI: 00007ffebed4e1b0
RBP: 00007ffebed4e1b0 R08: 00000000ffffffff R09: 00007ffebed4df80
R10: 00005555557a9903 R11: 0000000000000246 R12: 00007fc700a0fb2e
R13: 00007ffebed4f270 R14: 00005555557a9810 R15: 00007ffebed4f2b0
INFO: task syz-executor.3:11608 blocked for more than 140 seconds.
Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.3 D29472 11608 8196 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
wb_wait_for_completion+0x175/0x1f0 fs/fs-writeback.c:222
sync_inodes_sb+0x19d/0x9a0 fs/fs-writeback.c:2459
sync_inodes_one_sb+0x4d/0x60 fs/sync.c:74
iterate_supers+0x13c/0x290 fs/super.c:633
ksys_sync+0x86/0x150 fs/sync.c:113
__ia32_sys_sync+0xa/0x10 fs/sync.c:124
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7f18569c6639
Code: Bad RIP value.
RSP: 002b:00007f1854f18168 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00007f1856ae7050 RCX: 00007f18569c6639
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00007f1856a21ae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff9d26d84f R14: 00007f1854f18300 R15: 0000000000022000
INFO: task syz-executor.1:11616 blocked for more than 140 seconds.
Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.1 D27368 11616 8175 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
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:292 [inline]
rwsem_down_read_failed+0x20a/0x390 kernel/locking/rwsem-xadd.c:309
call_rwsem_down_read_failed+0x14/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0x44/0x80 kernel/locking/rwsem.c:26
iterate_supers+0xdb/0x290 fs/super.c:631
ksys_sync+0x86/0x150 fs/sync.c:113
__ia32_sys_sync+0xa/0x10 fs/sync.c:124
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe6c18d6639
Code: Bad RIP value.
RSP: 002b:00007fe6bfe49168 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00007fe6c19f6f80 RCX: 00007fe6c18d6639
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00007fe6c1931ae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe55c1ee8f R14: 00007fe6bfe49300 R15: 0000000000022000
INFO: task syz-executor.1:11621 blocked for more than 140 seconds.
Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.1 D30024 11621 8175 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
__rwsem_down_read_failed_common kernel/locking/rwsem-xadd.c:292 [inline]
rwsem_down_read_failed+0x20a/0x390 kernel/locking/rwsem-xadd.c:309
call_rwsem_down_read_failed+0x14/0x30 arch/x86/lib/rwsem.S:94
__down_read arch/x86/include/asm/rwsem.h:83 [inline]
down_read+0x44/0x80 kernel/locking/rwsem.c:26
iterate_supers+0xdb/0x290 fs/super.c:631
ksys_sync+0x86/0x150 fs/sync.c:113
__ia32_sys_sync+0xa/0x10 fs/sync.c:124
do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe6c18d6639
Code: Bad RIP value.
RSP: 002b:00007fe6bfe28168 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00007fe6c19f7050 RCX: 00007fe6c18d6639
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00007fe6c1931ae9 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe55c1ee8f R14: 00007fe6bfe28300 R15: 0000000000022000

Showing all locks held in the system:
6 locks held by kworker/u4:2/163:
1 lock held by khungtaskd/1570:
#0: 00000000357dc059 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4441
1 lock held by in:imklog/7801:
#0: 0000000040d75616 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
1 lock held by syz-executor.2/8142:
#0: 000000004ca28b89 (&type->s_umount_key#65){++++}, at: deactivate_super+0x16c/0x1a0 fs/super.c:359
1 lock held by syz-executor.4/8208:
#0: 0000000077e45286 (&type->s_umount_key#65){++++}, at: deactivate_super+0x16c/0x1a0 fs/super.c:359
4 locks held by kworker/u4:7/9527:
2 locks held by syz-executor.3/11608:
#0: 0000000077e45286 (&type->s_umount_key#65){++++}, at: iterate_supers+0xdb/0x290 fs/super.c:631
#1: 000000004a3329b0 (&bdi->wb_switch_rwsem){+.+.}, at: bdi_down_write_wb_switch_rwsem fs/fs-writeback.c:338 [inline]
#1: 000000004a3329b0 (&bdi->wb_switch_rwsem){+.+.}, at: sync_inodes_sb+0x180/0x9a0 fs/fs-writeback.c:2457
1 lock held by syz-executor.1/11616:
#0: 0000000077e45286 (&type->s_umount_key#65){++++}, at: iterate_supers+0xdb/0x290 fs/super.c:631
1 lock held by syz-executor.1/11621:
#0: 0000000077e45286 (&type->s_umount_key#65){++++}, at: iterate_supers+0xdb/0x290 fs/super.c:631

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

NMI backtrace for cpu 0
CPU: 0 PID: 1570 Comm: khungtaskd Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
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 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 163 Comm: kworker/u4:2 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Workqueue: writeback wb_workfn (flush-7:2)
RIP: 0010:preempt_count_equals kernel/sched/core.c:6126 [inline]
RIP: 0010:___might_sleep+0x70/0x2b0 kernel/sched/core.c:6159
Code: 8b 34 25 c0 df 01 00 49 8d be 70 03 00 00 41 81 e5 ff ff ff 7f 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 0f b6 04 02 <84> c0 74 08 3c 03 0f 8e e8 01 00 00 45 03 ae 70 03 00 00 44 39 eb
RSP: 0018:ffff8880b4c96e20 EFLAGS: 00000a06
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
RDX: 1ffff1101699147e RSI: 00000000ffffffff RDI: ffff8880b4c8a3f0
RBP: ffffffff886a0dc0 R08: ffff8880a3157ac8 R09: 0000000000000000
R10: 0000000000000005 R11: 0000000000000000 R12: 0000000000000017
R13: 0000000000000000 R14: ffff8880b4c8a080 R15: ffff88804cd8c700
FS: 0000000000000000(0000) GS:ffff8880ba100000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f0037557000 CR3: 000000009cd4c000 CR4: 00000000003406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
down_read+0x17/0x80 kernel/locking/rwsem.c:23
check_valid_map fs/f2fs/gc.c:454 [inline]
gc_data_segment fs/f2fs/gc.c:929 [inline]
do_garbage_collect fs/f2fs/gc.c:1109 [inline]
f2fs_gc+0x1cf3/0x8c90 fs/f2fs/gc.c:1196
f2fs_balance_fs+0x71a/0xd80 fs/f2fs/segment.c:513
__write_data_page+0xab8/0x22d0 fs/f2fs/data.c:1975
f2fs_write_cache_pages+0x96e/0x13e0 fs/f2fs/data.c:2107
__f2fs_write_data_pages fs/f2fs/data.c:2217 [inline]
f2fs_write_data_pages+0x498/0x1060 fs/f2fs/data.c:2244
do_writepages+0xe5/0x290 mm/page-writeback.c:2344
__writeback_single_inode+0x10c/0x11d0 fs/fs-writeback.c:1385
writeback_sb_inodes+0x537/0xef0 fs/fs-writeback.c:1647
__writeback_inodes_wb+0xc6/0x280 fs/fs-writeback.c:1716
wb_writeback+0x841/0xcc0 fs/fs-writeback.c:1822
wb_check_start_all fs/fs-writeback.c:1946 [inline]
wb_do_writeback fs/fs-writeback.c:1972 [inline]
wb_workfn+0xbf4/0x1250 fs/fs-writeback.c:2006
process_one_work+0x864/0x1570 kernel/workqueue.c:2153
worker_thread+0x64c/0x1130 kernel/workqueue.c:2296
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415


---
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.
Reply all
Reply to author
Forward
0 new messages