[syzbot] INFO: task hung in do_read_cache_folio

46 views
Skip to first unread message

syzbot

unread,
Feb 7, 2022, 12:19:24 AM2/7/22
to ak...@linux-foundation.org, linux-...@vger.kernel.org, linu...@kvack.org, syzkall...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 27bb0b18c208 Merge tag 'linux-kselftest-kunit-fixes-5.17-r..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=13c4f1cc700000
kernel config: https://syzkaller.appspot.com/x/.config?x=3e56c9b92aaaee24
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=154c5624700000

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

INFO: task udevd:3663 blocked for more than 143 seconds.
Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:udevd state:D stack:26280 pid: 3663 ppid: 2964 flags:0x00004000
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4db0 kernel/sched/core.c:6295
schedule+0xd2/0x260 kernel/sched/core.c:6368
io_schedule+0xee/0x170 kernel/sched/core.c:8407
folio_wait_bit_common+0x4f2/0xa90 mm/filemap.c:1322
folio_wait_bit mm/filemap.c:1471 [inline]
folio_wait_locked include/linux/pagemap.h:847 [inline]
folio_wait_locked include/linux/pagemap.h:844 [inline]
do_read_cache_folio+0x506/0x760 mm/filemap.c:3495
do_read_cache_page mm/filemap.c:3567 [inline]
read_cache_page+0x59/0x1c0 mm/filemap.c:3576
read_mapping_page include/linux/pagemap.h:641 [inline]
read_part_sector+0xf6/0x5b0 block/partitions/core.c:724
adfspart_check_ICS+0x9d/0xc90 block/partitions/acorn.c:360
check_partition block/partitions/core.c:148 [inline]
blk_add_partitions block/partitions/core.c:609 [inline]
bdev_disk_changed+0x629/0xf60 block/partitions/core.c:695
blkdev_get_whole+0x206/0x2d0 block/bdev.c:679
blkdev_get_by_dev.part.0+0x5c6/0xc70 block/bdev.c:813
blkdev_get_by_dev+0x6b/0x80 block/bdev.c:847
blkdev_open+0x154/0x2e0 block/fops.c:501
do_dentry_open+0x4b9/0x1240 fs/open.c:824
do_open fs/namei.c:3476 [inline]
path_openat+0x1c9e/0x2940 fs/namei.c:3609
do_filp_open+0x1aa/0x400 fs/namei.c:3636
do_sys_openat2+0x16d/0x4d0 fs/open.c:1214
do_sys_open fs/open.c:1230 [inline]
__do_sys_openat fs/open.c:1246 [inline]
__se_sys_openat fs/open.c:1241 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1241
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f27d7675697
RSP: 002b:00007ffc91e0e6e0 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007f27d8f5d4a0 RCX: 00007f27d7675697
RDX: 00000000000a0800 RSI: 00007f27d8f3f370 RDI: 00000000ffffff9c
RBP: 00007f27d8f3f370 R08: 0000000000000001 R09: 00007ffc91fcb080
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000000a0800
R13: 00007f27d8f30940 R14: 0000000000000001 R15: 00007f27d8f222c0
</TASK>
INFO: task syz-executor.0:3687 blocked for more than 143 seconds.
Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0 state:D stack:28288 pid: 3687 ppid: 3667 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:4986 [inline]
__schedule+0xab2/0x4db0 kernel/sched/core.c:6295
schedule+0xd2/0x260 kernel/sched/core.c:6368
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6427
__mutex_lock_common kernel/locking/mutex.c:673 [inline]
__mutex_lock+0xa32/0x12f0 kernel/locking/mutex.c:733
blkdev_put+0x99/0x950 block/bdev.c:902
blkdev_close+0x6a/0x80 block/fops.c:515
__fput+0x286/0x9f0 fs/file_table.c:311
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
tracehook_notify_resume include/linux/tracehook.h:188 [inline]
exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7efd9b888c9b
RSP: 002b:00007ffd940a8da0 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000004 RCX: 00007efd9b888c9b
RDX: 0000001b30d20000 RSI: 0000000000000000 RDI: 0000000000000003
RBP: 00007efd9b9ea960 R08: 0000000000000000 R09: 00007ffd941ec080
R10: 00007ffd941ec090 R11: 0000000000000293 R12: 00000000001274c9
R13: 00007ffd940a8ea0 R14: 00007efd9b9e9030 R15: 0000000000000032
</TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
#0: ffffffff8bb81120 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6460
5 locks held by kworker/u4:2/44:
2 locks held by getty/3273:
#0: ffff88807f6b9098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002b5b2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2077
1 lock held by udevd/3663:
#0: ffff88801b222118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev.part.0+0x9b/0xc70 block/bdev.c:804
1 lock held by syz-executor.0/3687:
#0: ffff88801b222118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0x99/0x950 block/bdev.c:902

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x1b3/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 1154 Comm: kworker/0:3 Not tainted 5.17.0-rc2-syzkaller-00054-g27bb0b18c208 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events nsim_dev_trap_report_work
RIP: 0010:prep_new_page mm/page_alloc.c:2436 [inline]
RIP: 0010:get_page_from_freelist+0xa8d/0x2f50 mm/page_alloc.c:4165
Code: 00 00 48 8b 7c 24 28 44 89 fe e8 6e 8d ff ff 8b 5c 24 14 83 e3 04 45 85 ff 0f 84 bd 18 00 00 f7 84 24 84 00 00 00 00 00 04 00 <0f> 85 76 19 00 00 85 db 0f 85 22 1a 00 00 48 8b 44 24 28 48 8d 78
RSP: 0018:ffffc900047c7838 EFLAGS: 00000006
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: ffff88801d5c00c0 RSI: ffffffff81b4ee92 RDI: 0000000000000003
RBP: 000000000003d5f8 R08: 0000000000000002 R09: 0000000000000001
R10: ffffffff81c58582 R11: 000000000000001f R12: 0000000000000000
R13: dffffc0000000000 R14: ffff88813fffa700 R15: 0000000000000001
FS: 0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f46530a1600 CR3: 000000000b88e000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
__alloc_pages+0x1b2/0x500 mm/page_alloc.c:5389
__alloc_pages_node include/linux/gfp.h:572 [inline]
kmem_getpages mm/slab.c:1378 [inline]
cache_grow_begin+0x75/0x350 mm/slab.c:2584
cache_alloc_refill+0x27f/0x380 mm/slab.c:2957
____cache_alloc mm/slab.c:3040 [inline]
____cache_alloc mm/slab.c:3023 [inline]
slab_alloc_node mm/slab.c:3241 [inline]
kmem_cache_alloc_node_trace+0x49c/0x5b0 mm/slab.c:3609
__do_kmalloc_node mm/slab.c:3631 [inline]
__kmalloc_node_track_caller+0x38/0x60 mm/slab.c:3646
kmalloc_reserve net/core/skbuff.c:354 [inline]
__alloc_skb+0xde/0x340 net/core/skbuff.c:426
alloc_skb include/linux/skbuff.h:1158 [inline]
nsim_dev_trap_skb_build drivers/net/netdevsim/dev.c:745 [inline]
nsim_dev_trap_report drivers/net/netdevsim/dev.c:802 [inline]
nsim_dev_trap_report_work+0x29a/0xbc0 drivers/net/netdevsim/dev.c:843
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
----------------
Code disassembly (best guess):
0: 00 00 add %al,(%rax)
2: 48 8b 7c 24 28 mov 0x28(%rsp),%rdi
7: 44 89 fe mov %r15d,%esi
a: e8 6e 8d ff ff callq 0xffff8d7d
f: 8b 5c 24 14 mov 0x14(%rsp),%ebx
13: 83 e3 04 and $0x4,%ebx
16: 45 85 ff test %r15d,%r15d
19: 0f 84 bd 18 00 00 je 0x18dc
1f: f7 84 24 84 00 00 00 testl $0x40000,0x84(%rsp)
26: 00 00 04 00
* 2a: 0f 85 76 19 00 00 jne 0x19a6 <-- trapping instruction
30: 85 db test %ebx,%ebx
32: 0f 85 22 1a 00 00 jne 0x1a5a
38: 48 8b 44 24 28 mov 0x28(%rsp),%rax
3d: 48 rex.W
3e: 8d .byte 0x8d
3f: 78 .byte 0x78


---
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

syzbot

unread,
Jul 2, 2022, 4:05:20 PM7/2/22
to ak...@linux-foundation.org, linux-...@vger.kernel.org, linux-...@vger.kernel.org, linu...@kvack.org, syzkall...@googlegroups.com, wi...@infradead.org
syzbot has found a reproducer for the following issue on:

HEAD commit: 089866061428 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: upstream
console+strace: https://syzkaller.appspot.com/x/log.txt?x=13b60400080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=116c61f4080000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13805fd4080000

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

INFO: task udevd:3614 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:udevd state:D stack:26160 pid: 3614 ppid: 2974 flags:0x00004004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
io_schedule+0xba/0x130 kernel/sched/core.c:8645
folio_wait_bit_common+0x4f2/0xa90 mm/filemap.c:1324
folio_wait_bit mm/filemap.c:1473 [inline]
folio_wait_locked include/linux/pagemap.h:1028 [inline]
folio_wait_locked include/linux/pagemap.h:1025 [inline]
do_read_cache_folio+0x4ff/0x760 mm/filemap.c:3530
do_read_cache_page mm/filemap.c:3602 [inline]
read_cache_page+0x59/0x2a0 mm/filemap.c:3611
read_mapping_page include/linux/pagemap.h:759 [inline]
read_part_sector+0xf6/0x920 block/partitions/core.c:715
adfspart_check_ICS+0x9a/0x690 block/partitions/acorn.c:360
check_partition block/partitions/core.c:147 [inline]
blk_add_partitions block/partitions/core.c:600 [inline]
bdev_disk_changed block/partitions/core.c:686 [inline]
bdev_disk_changed+0x629/0xf60 block/partitions/core.c:653
blkdev_get_whole+0x18a/0x2d0 block/bdev.c:686
blkdev_get_by_dev.part.0+0x5ec/0xb90 block/bdev.c:823
blkdev_get_by_dev+0x6b/0x80 block/bdev.c:857
blkdev_open+0x13c/0x2c0 block/fops.c:481
do_dentry_open+0x4a1/0x11f0 fs/open.c:848
do_open fs/namei.c:3520 [inline]
path_openat+0x1c71/0x2910 fs/namei.c:3653
do_filp_open+0x1aa/0x400 fs/namei.c:3680
do_sys_openat2+0x16d/0x4c0 fs/open.c:1278
do_sys_open fs/open.c:1294 [inline]
__do_sys_openat fs/open.c:1310 [inline]
__se_sys_openat fs/open.c:1305 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1305
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f2cc1991697
RSP: 002b:00007fff60a9cbc0 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000056135a372c20 RCX: 00007f2cc1991697
RDX: 00000000000a0800 RSI: 000056135a36ab20 RDI: 00000000ffffff9c
RBP: 000056135a36ab20 R08: 0000000000000001 R09: 00007fff60ba0080
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000000a0800
R13: 000056135a368130 R14: 0000000000000001 R15: 000056135a347910
</TASK>
INFO: task syz-executor325:3615 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor325 state:D stack:27272 pid: 3615 ppid: 3613 flags:0x00004006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
blkdev_put+0xbc/0x770 block/bdev.c:912
blkdev_close+0x64/0x80 block/fops.c:495
__fput+0x277/0x9d0 fs/file_table.c:317
task_work_run+0xdd/0x1a0 kernel/task_work.c:177
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xaff/0x2a00 kernel/exit.c:795
do_group_exit+0xd2/0x2f0 kernel/exit.c:925
get_signal+0x2542/0x2600 kernel/signal.c:2857
arch_do_signal_or_restart+0x82/0x2300 arch/x86/kernel/signal.c:869
exit_to_user_mode_loop kernel/entry/common.c:166 [inline]
exit_to_user_mode_prepare+0x15f/0x250 kernel/entry/common.c:201
__syscall_exit_to_user_mode_work kernel/entry/common.c:283 [inline]
syscall_exit_to_user_mode+0x19/0x50 kernel/entry/common.c:294
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f38c3b625e9
RSP: 002b:00007ffe69332538 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: fffffffffffffe00 RBX: 0000000000000003 RCX: 00007f38c3b625e9
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000006
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 000000000000ffff R11: 0000000000000246 R12: 00007ffe693325b0
R13: 00007ffe693325a0 R14: 00007ffe69332590 R15: 000000000000000c
</TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
2 locks held by getty/3288:
#0: ffff888025b35098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
1 lock held by udevd/3614:
#0: ffff8881472ee118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev.part.0+0x9b/0xb90 block/bdev.c:814
1 lock held by syz-executor325/3615:
#0: ffff8881472ee118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xbc/0x770 block/bdev.c:912

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 11 Comm: kworker/u4:1 Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
Workqueue: events_unbound toggle_allocation_gate
RIP: 0010:check_preemption_disabled+0x3e/0x170 lib/smp_processor_id.c:56
Code: 44 8b 25 c5 b6 8a 76 65 8b 1d 2e 0c 8b 76 81 e3 ff ff ff 7f 31 ff 89 de 0f 1f 44 00 00 85 db 74 11 0f 1f 44 00 00 44 89 e0 5b <5d> 41 5c 41 5d 41 5e c3 0f 1f 44 00 00 9c 5b 81 e3 00 02 00 00 31
RSP: 0018:ffffc90000107850 EFLAGS: 00000206
RAX: 0000000000000001 RBX: 1ffff92000020f16 RCX: ffffffff815e59a8
RDX: 0000000000000001 RSI: 0000000000000003 RDI: 0000000000000000
RBP: ffffffff8a285700 R08: 0000000000000000 R09: ffffffff8dbb9157
R10: fffffbfff1b7722a R11: 0000000000000001 R12: 0000000000000001
R13: ffffffff8a2856c0 R14: ffff8880119c1138 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000055f2dd4a4680 CR3: 000000000ba8e000 CR4: 0000000000350ee0
Call Trace:
<TASK>
rcu_lockdep_current_cpu_online kernel/rcu/tree.c:1185 [inline]
rcu_lockdep_current_cpu_online+0x2d/0x140 kernel/rcu/tree.c:1177
rcu_read_lock_held_common kernel/rcu/update.c:112 [inline]
rcu_read_lock_held_common kernel/rcu/update.c:102 [inline]
rcu_read_lock_sched_held+0x25/0x70 kernel/rcu/update.c:123
trace_lock_acquire include/trace/events/lock.h:24 [inline]
lock_acquire+0x480/0x570 kernel/locking/lockdep.c:5636
__raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
_raw_spin_lock+0x2a/0x40 kernel/locking/spinlock.c:154
spin_lock include/linux/spinlock.h:349 [inline]
__get_locked_pte+0x154/0x270 mm/memory.c:1830
get_locked_pte include/linux/mm.h:2132 [inline]
__text_poke+0x1b3/0x8e0 arch/x86/kernel/alternative.c:1052
text_poke arch/x86/kernel/alternative.c:1137 [inline]
text_poke_bp_batch+0x44a/0x6c0 arch/x86/kernel/alternative.c:1483
text_poke_flush arch/x86/kernel/alternative.c:1589 [inline]
text_poke_flush arch/x86/kernel/alternative.c:1586 [inline]
text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1596
arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
jump_label_update+0x32f/0x410 kernel/jump_label.c:830
static_key_enable_cpuslocked+0x1b1/0x260 kernel/jump_label.c:177
static_key_enable+0x16/0x20 kernel/jump_label.c:190
toggle_allocation_gate mm/kfence/core.c:811 [inline]
toggle_allocation_gate+0x100/0x390 mm/kfence/core.c:803
process_one_work+0x996/0x1610 kernel/workqueue.c:2289
worker_thread+0x665/0x1080 kernel/workqueue.c:2436
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
----------------
Code disassembly (best guess):
0: 44 8b 25 c5 b6 8a 76 mov 0x768ab6c5(%rip),%r12d # 0x768ab6cc
7: 65 8b 1d 2e 0c 8b 76 mov %gs:0x768b0c2e(%rip),%ebx # 0x768b0c3c
e: 81 e3 ff ff ff 7f and $0x7fffffff,%ebx
14: 31 ff xor %edi,%edi
16: 89 de mov %ebx,%esi
18: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
1d: 85 db test %ebx,%ebx
1f: 74 11 je 0x32
21: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
26: 44 89 e0 mov %r12d,%eax
29: 5b pop %rbx
* 2a: 5d pop %rbp <-- trapping instruction
2b: 41 5c pop %r12
2d: 41 5d pop %r13
2f: 41 5e pop %r14
31: c3 retq
32: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
37: 9c pushfq
38: 5b pop %rbx
39: 81 e3 00 02 00 00 and $0x200,%ebx
3f: 31 .byte 0x31

Hillf Danton

unread,
Jul 2, 2022, 8:40:08 PM7/2/22
to syzbot, linux-...@vger.kernel.org, syzkall...@googlegroups.com
On Sat, 02 Jul 2022 13:05:19 -0700
See if it is due to the lock mess in do_read_cache_folio().

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git 089866061428

--- y/mm/filemap.c
+++ f/mm/filemap.c
@@ -3502,10 +3502,12 @@ static struct folio *do_read_cache_folio
{
struct folio *folio;
int err;
+ bool self_locked;

if (!filler)
filler = mapping->a_ops->read_folio;
repeat:
+ self_locked = false;
folio = filemap_get_folio(mapping, index);
if (!folio) {
folio = filemap_alloc_folio(gfp, 0);
@@ -3519,6 +3521,7 @@ repeat:
/* Presumably ENOMEM for xarray node */
return ERR_PTR(err);
}
+ self_locked = folio_test_locked(folio);

filler:
err = filler(file, folio);
@@ -3527,7 +3530,11 @@ filler:
return ERR_PTR(err);
}

- folio_wait_locked(folio);
+ if (self_locked)
+ folio_unlock(folio);
+ else
+ folio_wait_locked(folio);
+
if (!folio_test_uptodate(folio)) {
folio_put(folio);
return ERR_PTR(-EIO);
@@ -3563,6 +3570,7 @@ filler:
* set again if read page fails.
*/
folio_clear_error(folio);
+ self_locked = folio_test_locked(folio);
goto filler;

out:
--

syzbot

unread,
Jul 3, 2022, 2:25:09 AM7/3/22
to hda...@sina.com, linux-...@vger.kernel.org, syzkall...@googlegroups.com
Hello,

syzbot tried to test the proposed patch but the build/boot failed:

77][ T1] UDP-Lite hash table entries: 4096 (order: 7, 655360 bytes, vmalloc)
[ 2.362158][ T1] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 2.364873][ T1] RPC: Registered named UNIX socket transport module.
[ 2.365877][ T1] RPC: Registered udp transport module.
[ 2.366631][ T1] RPC: Registered tcp transport module.
[ 2.367410][ T1] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 2.370320][ T1] NET: Registered PF_XDP protocol family
[ 2.371131][ T1] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
[ 2.372238][ T1] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
[ 2.373216][ T1] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[ 2.374290][ T1] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfefff window]
[ 2.376304][ T1] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 2.377453][ T1] PCI: CLS 0 bytes, default 64
[ 2.383304][ T1] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 2.384474][ T1] software IO TLB: mapped [mem 0x00000000b5a00000-0x00000000b9a00000] (64MB)
[ 2.385755][ T1] ACPI: bus type thunderbolt registered
[ 2.394707][ T1] kvm: no hardware support for 'kvm_intel'
[ 2.395523][ T1] has_svm: svm not available
[ 2.396210][ T1] kvm: no hardware support for 'kvm_amd'
[ 2.397006][ T1] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x206eb2111f5, max_idle_ns: 440795222471 ns
[ 2.399479][ T56] kworker/u4:1 (56) used greatest stack depth: 27744 bytes left
[ 2.401142][ T1] clocksource: Switched to clocksource tsc
[ 2.414938][ T61] kworker/u4:1 (61) used greatest stack depth: 26920 bytes left
[ 5.312580][ T1] Initialise system trusted keyrings
[ 5.314897][ T1] workingset: timestamp_bits=40 max_order=21 bucket_order=0
[ 5.348172][ T1] zbud: loaded
[ 5.355655][ T1] DLM installed
[ 5.361452][ T1] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 5.370982][ T1] NFS: Registering the id_resolver key type
[ 5.372080][ T1] Key type id_resolver registered
[ 5.372815][ T1] Key type id_legacy registered
[ 5.373771][ T1] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 5.374910][ T1] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 5.376045][ T1] Installing knfsd (copyright (C) 1996 ok...@monad.swb.de).
[ 5.383700][ T1] Key type cifs.spnego registered
[ 5.384564][ T1] Key type cifs.idmap registered
[ 5.385712][ T1] ntfs: driver 2.1.32 [Flags: R/W].
[ 5.387534][ T1] ntfs3: Max link count 4000
[ 5.388172][ T1] ntfs3: Enabled Linux POSIX ACLs support
[ 5.388984][ T1] ntfs3: Read-only LZX/Xpress compression included
[ 5.391202][ T1] efs: 1.0a - http://aeschi.ch.eu.org/efs/
[ 5.392215][ T1] jffs2: version 2.2. (NAND) (SUMMARY) © 2001-2006 Red Hat, Inc.
[ 5.396546][ T1] romfs: ROMFS MTD (C) 2007 Red Hat, Inc.
[ 5.397834][ T1] QNX4 filesystem 0.2.3 registered.
[ 5.398847][ T1] qnx6: QNX6 filesystem 1.0.0 registered.
[ 5.400490][ T1] fuse: init (API version 7.36)
[ 5.404181][ T1] orangefs_debugfs_init: called with debug mask: :none: :0:
[ 5.405575][ T1] orangefs_init: module version upstream loaded
[ 5.407203][ T1] JFS: nTxBlock = 8192, nTxLock = 65536
[ 5.419901][ T1] SGI XFS with ACLs, security attributes, realtime, quota, fatal assert, debug enabled
[ 5.431399][ T1] 9p: Installing v9fs 9p2000 file system support
[ 5.433445][ T1] NILFS version 2 loaded
[ 5.434036][ T1] befs: version: 0.9.3
[ 5.436837][ T1] ocfs2: Registered cluster interface o2cb
[ 5.437963][ T1] ocfs2: Registered cluster interface user
[ 5.439235][ T1] OCFS2 User DLM kernel interface loaded
[ 5.448869][ T1] gfs2: GFS2 installed
[ 5.460150][ T1] ceph: loaded (mds proto 32)
[ 5.471273][ T1] NET: Registered PF_ALG protocol family
[ 5.472216][ T1] xor: automatically using best checksumming function avx
[ 5.473484][ T1] async_tx: api initialized (async)
[ 5.474262][ T1] Key type asymmetric registered
[ 5.475158][ T1] Asymmetric key parser 'x509' registered
[ 5.475957][ T1] Asymmetric key parser 'pkcs8' registered
[ 5.476750][ T1] Key type pkcs7_test registered
[ 5.480210][ T1] alg: self-tests for CTR-KDF (hmac(sha256)) passed
[ 5.483969][ T1] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 240)
[ 5.484917][ T137] kworker/u4:2 (137) used greatest stack depth: 26816 bytes left
[ 5.486472][ T1] io scheduler mq-deadline registered
[ 5.489234][ T1] io scheduler kyber registered
[ 5.490614][ T1] io scheduler bfq registered
[ 5.503834][ T1] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 5.545233][ T1] ACPI: button: Power Button [PWRF]
[ 5.546867][ T1] input: Sleep Button as /devices/LNXSYSTM:00/LNXSLPBN:00/input/input1
[ 5.548614][ T1] ACPI: button: Sleep Button [SLPF]
[ 5.566119][ T1] ACPI: \_SB_.LNKC: Enabled at IRQ 11
[ 5.566992][ T1] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
[ 5.579637][ T1] ACPI: \_SB_.LNKD: Enabled at IRQ 10
[ 5.580460][ T1] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[ 5.593843][ T1] ACPI: \_SB_.LNKB: Enabled at IRQ 10
[ 5.595120][ T1] virtio-pci 0000:00:06.0: virtio_pci: leaving for legacy driver
[ 5.887643][ T1] N_HDLC line discipline registered with maxframe=4096
[ 5.888706][ T1] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[ 5.890475][ T1] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[ 5.896315][ T1] 00:04: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[ 5.900856][ T1] 00:05: ttyS2 at I/O 0x3e8 (irq = 6, base_baud = 115200) is a 16550A
[ 5.906084][ T1] 00:06: ttyS3 at I/O 0x2e8 (irq = 7, base_baud = 115200) is a 16550A
[ 5.920797][ T1] Non-volatile memory driver v1.3
[ 5.930201][ T1] Linux agpgart interface v0.103
[ 5.933661][ T1] ACPI: bus type drm_connector registered
[ 5.937360][ T1] [drm] Initialized vgem 1.0.0 20120112 for vgem on minor 0
[ 5.941912][ T1] [drm] Initialized vkms 1.0.0 20180514 for vkms on minor 1
[ 5.997414][ T1] Console: switching to colour frame buffer device 128x48
[ 6.015050][ T1] platform vkms: [drm] fb0: vkmsdrmfb frame buffer device
[ 6.016246][ T1] usbcore: registered new interface driver udl
[ 6.025204][ T1] page:ffffea0000736380 refcount:4 mapcount:0 mapping:ffff888140c812f8 index:0x0 pfn:0x1cd8e
[ 6.026731][ T1] memcg:ffff888140150000
[ 6.027762][ T1] aops:def_blk_aops ino:100000
[ 6.029614][ T1] flags: 0xfff00000002004(uptodate|private|node=0|zone=1|lastcpupid=0x7ff)
[ 6.031393][ T1] raw: 00fff00000002004 0000000000000000 dead000000000122 ffff888140c812f8
[ 6.032603][ T1] raw: 0000000000000000 ffff888011fae000 00000004ffffffff ffff888140150000
[ 6.033757][ T1] page dumped because: VM_BUG_ON_FOLIO(!folio_test_locked(folio))
[ 6.035031][ T1] page_owner tracks the page as allocated
[ 6.035852][ T1] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x140cc0(GFP_USER|__GFP_COMP), pid 1, tgid 1 (swapper/0), ts 6025000746, free_ts 5976256083
[ 6.037962][ T1] get_page_from_freelist+0x1290/0x3b70
[ 6.038738][ T1] __alloc_pages+0x1c7/0x510
[ 6.039361][ T1] alloc_page_interleave+0x1e/0x200
[ 6.040066][ T1] alloc_pages+0x2b1/0x310
[ 6.040709][ T1] folio_alloc+0x1c/0x70
[ 6.041292][ T1] do_read_cache_folio+0x3e6/0x800
[ 6.042022][ T1] read_cache_page+0x59/0x2a0
[ 6.042703][ T1] read_part_sector+0xf6/0x920
[ 6.043380][ T1] adfspart_check_ICS+0x9a/0x690
[ 6.044052][ T1] bdev_disk_changed+0x629/0xf60
[ 6.044790][ T1] blkdev_get_whole+0x18a/0x2d0
[ 6.045456][ T1] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 6.046205][ T1] blkdev_get_by_dev+0x6b/0x80
[ 6.046854][ T1] disk_scan_partitions+0x16a/0x200
[ 6.047561][ T1] device_add_disk+0xc3e/0xe20
[ 6.048211][ T1] brd_alloc.part.0+0x4db/0x7a0
[ 6.048884][ T1] page last free stack trace:
[ 6.049552][ T1] free_pcp_prepare+0x549/0xd20
[ 6.050208][ T1] free_unref_page+0x19/0x6a0
[ 6.050881][ T1] __vunmap+0x85d/0xd30
[ 6.051451][ T1] free_work+0x58/0x70
[ 6.052008][ T1] process_one_work+0x996/0x1610
[ 6.052690][ T1] worker_thread+0x665/0x1080
[ 6.053325][ T1] kthread+0x2e9/0x3a0
[ 6.053882][ T1] ret_from_fork+0x1f/0x30
[ 6.054558][ T1] ------------[ cut here ]------------
[ 6.055297][ T1] kernel BUG at mm/filemap.c:1557!
[ 6.055992][ T1] invalid opcode: 0000 [#1] PREEMPT SMP KASAN
[ 6.056802][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
[ 6.058413][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
[ 6.059746][ T1] RIP: 0010:folio_unlock+0xae/0xc0
[ 6.060438][ T1] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 72 69 0f 00 <0f> 0b 48 89 df e8 b8 fd 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 6.063239][ T1] RSP: 0018:ffffc900000678e0 EFLAGS: 00010293
[ 6.064086][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 6.064499][ T1] RDX: ffff888140170000 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 6.064499][ T1] RBP: ffffea0000736380 R08: 0000000000000003 R09: 000000000000ffff
[ 6.064499][ T1] R10: 000000000000ffff R11: 0000000000000001 R12: 0000000000000000
[ 6.064499][ T1] R13: dffffc0000000000 R14: 0000000000000000 R15: ffff88801cdbc180
[ 6.064499][ T1] FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
[ 6.064499][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.064499][ T1] CR2: ffff88823ffff000 CR3: 000000000ba8e000 CR4: 0000000000350ef0
[ 6.064499][ T1] Call Trace:
[ 6.064499][ T1] <TASK>
[ 6.064499][ T1] do_read_cache_folio+0x2f7/0x800
[ 6.064499][ T1] ? blkdev_writepages+0x20/0x20
[ 6.064499][ T1] read_cache_page+0x59/0x2a0
[ 6.064499][ T1] read_part_sector+0xf6/0x920
[ 6.064499][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.064499][ T1] adfspart_check_ICS+0x9a/0x690
[ 6.064499][ T1] ? __alloc_pages_slowpath.constprop.0+0x2160/0x2160
[ 6.064499][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.064499][ T1] ? snprintf+0xbb/0xf0
[ 6.064499][ T1] ? vsprintf+0x30/0x30
[ 6.064499][ T1] ? preempt_count_add+0x74/0x140
[ 6.064499][ T1] ? alloc_page_interleave+0x89/0x200
[ 6.064499][ T1] ? alloc_pages+0x1b2/0x310
[ 6.064499][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.064499][ T1] bdev_disk_changed+0x629/0xf60
[ 6.064499][ T1] ? iput.part.0+0x73/0x820
[ 6.064499][ T1] blkdev_get_whole+0x18a/0x2d0
[ 6.064499][ T1] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 6.064499][ T1] ? devcgroup_check_permission+0x1ab/0x440
[ 6.064499][ T1] blkdev_get_by_dev+0x6b/0x80
[ 6.064499][ T1] disk_scan_partitions+0x16a/0x200
[ 6.064499][ T1] device_add_disk+0xc3e/0xe20
[ 6.064499][ T1] brd_alloc.part.0+0x4db/0x7a0
[ 6.064499][ T1] ? brd_lookup_page+0x1d0/0x1d0
[ 6.064499][ T1] ? up_write+0x148/0x470
[ 6.064499][ T1] ? ramdisk_size+0x23/0x23
[ 6.064499][ T1] brd_init+0x1b8/0x24b
[ 6.064499][ T1] ? ramdisk_size+0x23/0x23
[ 6.064499][ T1] do_one_initcall+0x103/0x650
[ 6.064499][ T1] ? trace_event_raw_event_initcall_level+0x1f0/0x1f0
[ 6.064499][ T1] ? parameq+0xe0/0x170
[ 6.064499][ T1] kernel_init_freeable+0x6b1/0x73a
[ 6.064499][ T1] ? rest_init+0x270/0x270
[ 6.064499][ T1] kernel_init+0x1a/0x1d0
[ 6.064499][ T1] ? rest_init+0x270/0x270
[ 6.064499][ T1] ret_from_fork+0x1f/0x30
[ 6.064499][ T1] </TASK>
[ 6.064499][ T1] Modules linked in:
[ 6.064499][ C0] vkms_vblank_simulate: vblank timer overrun
[ 6.103289][ T1] ---[ end trace 0000000000000000 ]---
[ 6.104053][ T1] RIP: 0010:folio_unlock+0xae/0xc0
[ 6.104844][ T1] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 72 69 0f 00 <0f> 0b 48 89 df e8 b8 fd 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 6.107744][ T1] RSP: 0018:ffffc900000678e0 EFLAGS: 00010293
[ 6.108625][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 6.109722][ T1] RDX: ffff888140170000 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 6.110787][ T1] RBP: ffffea0000736380 R08: 0000000000000003 R09: 000000000000ffff
[ 6.111842][ T1] R10: 000000000000ffff R11: 0000000000000001 R12: 0000000000000000
[ 6.112892][ T1] R13: dffffc0000000000 R14: 0000000000000000 R15: ffff88801cdbc180
[ 6.113946][ T1] FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
[ 6.115160][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.116058][ T1] CR2: ffff88823ffff000 CR3: 000000000ba8e000 CR4: 0000000000350ef0
[ 6.117115][ T1] Kernel panic - not syncing: Fatal exception
[ 6.118428][ T1] Kernel Offset: disabled
[ 6.119019][ T1] Rebooting in 86400 seconds..


syzkaller build log:
go env (err=<nil>)
GO111MODULE="auto"
GOARCH="amd64"
GOBIN=""
GOCACHE="/syzkaller/.cache/go-build"
GOENV="/syzkaller/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/syzkaller/jobs/linux/gopath/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/syzkaller/jobs/linux/gopath"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.17"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/syzkaller/jobs/linux/gopath/src/github.com/google/syzkaller/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build2307476033=/tmp/go-build -gno-record-gcc-switches"

git status (err=<nil>)
HEAD detached at 1434eec0b
nothing to commit, working tree clean


go list -f '{{.Stale}}' ./sys/syz-sysgen | grep -q false || go install ./sys/syz-sysgen
make .descriptions
bin/syz-sysgen
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-fuzzer github.com/google/syzkaller/syz-fuzzer
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-stress github.com/google/syzkaller/tools/syz-stress
mkdir -p ./bin/linux_amd64
gcc -o ./bin/linux_amd64/syz-executor executor/executor.cc \
-m64 -O2 -pthread -Wall -Werror -Wparentheses -Wunused-const-variable -Wframe-larger-than=16384 -Wno-stringop-overflow -Wno-array-bounds -Wno-format-overflow -static-pie -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"1434eec0b84075b7246560cfa89f20cdb3d8077f\"


Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=1523de50080000


Tested on:

commit: 08986606 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=13810a58080000

Hillf Danton

unread,
Jul 3, 2022, 2:55:21 AM7/3/22
to syzbot, linux-...@vger.kernel.org, syzkall...@googlegroups.com
On Sat, 02 Jul 2022 13:05:19 -0700
v1, See if it is due to the lock mess in do_read_cache_folio().
v2, See if it is due to folio not locked.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git 089866061428

--- y/mm/filemap.c
+++ f/mm/filemap.c
@@ -3527,7 +3527,6 @@ filler:
return ERR_PTR(err);
}

- folio_wait_locked(folio);
if (!folio_test_uptodate(folio)) {
folio_put(folio);
return ERR_PTR(-EIO);
--

syzbot

unread,
Jul 3, 2022, 3:21:08 AM7/3/22
to hda...@sina.com, linux-...@vger.kernel.org, syzkall...@googlegroups.com
Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in do_read_cache_folio

INFO: task udevd:4021 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:udevd state:D stack:26160 pid: 4021 ppid: 2974 flags:0x00004000
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
io_schedule+0xba/0x130 kernel/sched/core.c:8645
folio_wait_bit_common+0x4f2/0xa90 mm/filemap.c:1324
folio_put_wait_locked mm/filemap.c:1498 [inline]
do_read_cache_folio+0x3a4/0x6e0 mm/filemap.c:3541
do_read_cache_page mm/filemap.c:3601 [inline]
read_cache_page+0x59/0x2a0 mm/filemap.c:3610
read_mapping_page include/linux/pagemap.h:759 [inline]
read_part_sector+0xf6/0x920 block/partitions/core.c:715
adfspart_check_POWERTEC+0x93/0x530 block/partitions/acorn.c:454
check_partition block/partitions/core.c:147 [inline]
blk_add_partitions block/partitions/core.c:600 [inline]
bdev_disk_changed block/partitions/core.c:686 [inline]
bdev_disk_changed+0x629/0xf60 block/partitions/core.c:653
blkdev_get_whole+0x18a/0x2d0 block/bdev.c:686
blkdev_get_by_dev.part.0+0x5ec/0xb90 block/bdev.c:823
blkdev_get_by_dev+0x6b/0x80 block/bdev.c:857
blkdev_open+0x13c/0x2c0 block/fops.c:481
do_dentry_open+0x4a1/0x11f0 fs/open.c:848
do_open fs/namei.c:3520 [inline]
path_openat+0x1c71/0x2910 fs/namei.c:3653
do_filp_open+0x1aa/0x400 fs/namei.c:3680
do_sys_openat2+0x16d/0x4c0 fs/open.c:1278
do_sys_open fs/open.c:1294 [inline]
__do_sys_openat fs/open.c:1310 [inline]
__se_sys_openat fs/open.c:1305 [inline]
__x64_sys_openat+0x13f/0x1f0 fs/open.c:1305
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f9721b25697
RSP: 002b:00007fff782335e0 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 000055f98610efe0 RCX: 00007f9721b25697
RDX: 00000000000a0800 RSI: 000055f98610d320 RDI: 00000000ffffff9c
RBP: 000055f98610d320 R08: 0000000000000001 R09: 00007fff7830b080
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000000a0800
R13: 000055f9860f2b80 R14: 0000000000000001 R15: 000055f9860e9910
</TASK>
INFO: task syz-executor.0:4090 blocked for more than 143 seconds.
Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0 state:D stack:27904 pid: 4090 ppid: 4026 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
blkdev_put+0xbc/0x770 block/bdev.c:912
blkdev_close+0x64/0x80 block/fops.c:495
__fput+0x277/0x9d0 fs/file_table.c:317
task_work_run+0xdd/0x1a0 kernel/task_work.c:177
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
exit_to_user_mode_loop kernel/entry/common.c:169 [inline]
exit_to_user_mode_prepare+0x23c/0x250 kernel/entry/common.c:201
__syscall_exit_to_user_mode_work kernel/entry/common.c:283 [inline]
syscall_exit_to_user_mode+0x19/0x50 kernel/entry/common.c:294
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f7d9a23bd4b
RSP: 002b:00007ffdef987890 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000006 RCX: 00007f7d9a23bd4b
RDX: 0000001b2f220000 RSI: 0000000000000000 RDI: 0000000000000005
RBP: 00007f7d9a39d960 R08: 0000000000000000 R09: 00007ffdef9d7080
R10: 00007ffdef9d7090 R11: 0000000000000293 R12: 000000000000f504
R13: 00007ffdef987990 R14: 00007ffdef9879b0 R15: 0000000000000032
</TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
2 locks held by getty/3282:
#0: ffff8880263ab098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d162e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
1 lock held by udevd/4021:
#0: ffff88801dafb118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev.part.0+0x9b/0xb90 block/bdev.c:814
1 lock held by syz-executor.0/4090:
#0: ffff88801dafb118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xbc/0x770 block/bdev.c:912

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 14 Comm: kworker/0:1 Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
Workqueue: events kfree_rcu_work
RIP: 0010:preempt_count_add+0x26/0x140 kernel/sched/core.c:5602
Code: 00 00 00 00 48 c7 c0 40 f8 f4 90 55 48 ba 00 00 00 00 00 fc ff df 48 89 c1 53 83 e0 07 89 fb 48 c1 e9 03 83 c0 03 0f b6 14 11 <38> d0 7c 08 84 d2 0f 85 e1 00 00 00 8b 15 18 05 a3 0f 65 01 1d 11
RSP: 0018:ffffc90000137cf0 EFLAGS: 00000006
RAX: 0000000000000003 RBX: 0000000000000001 RCX: 1ffffffff21e9f08
RDX: 0000000000000004 RSI: 0000000000000000 RDI: 0000000000000001
RBP: ffff8880b9a39700 R08: 0000000000000005 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000001
R13: ffffc90000137da8 R14: ffff8880119b7d00 R15: ffff8880b9a39700
FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000055ab85f0c600 CR3: 000000000ba8e000 CR4: 0000000000350ef0
Call Trace:
<TASK>
__raw_spin_lock_irq include/linux/spinlock_api_smp.h:118 [inline]
_raw_spin_lock_irq+0x16/0x50 kernel/locking/spinlock.c:170
process_one_work+0xae0/0x1610 kernel/workqueue.c:2317
worker_thread+0x665/0x1080 kernel/workqueue.c:2436
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
----------------
Code disassembly (best guess):
0: 00 00 add %al,(%rax)
2: 00 00 add %al,(%rax)
4: 48 c7 c0 40 f8 f4 90 mov $0xffffffff90f4f840,%rax
b: 55 push %rbp
c: 48 ba 00 00 00 00 00 movabs $0xdffffc0000000000,%rdx
13: fc ff df
16: 48 89 c1 mov %rax,%rcx
19: 53 push %rbx
1a: 83 e0 07 and $0x7,%eax
1d: 89 fb mov %edi,%ebx
1f: 48 c1 e9 03 shr $0x3,%rcx
23: 83 c0 03 add $0x3,%eax
26: 0f b6 14 11 movzbl (%rcx,%rdx,1),%edx
* 2a: 38 d0 cmp %dl,%al <-- trapping instruction
2c: 7c 08 jl 0x36
2e: 84 d2 test %dl,%dl
30: 0f 85 e1 00 00 00 jne 0x117
36: 8b 15 18 05 a3 0f mov 0xfa30518(%rip),%edx # 0xfa30554
3c: 65 gs
3d: 01 .byte 0x1
3e: 1d .byte 0x1d
3f: 11 .byte 0x11


Tested on:

commit: 08986606 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=13817a50080000
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=16817a50080000

Hillf Danton

unread,
Jul 3, 2022, 3:51:46 AM7/3/22
to syzbot, linux-...@vger.kernel.org, syzkall...@googlegroups.com
On Sat, 02 Jul 2022 13:05:19 -0700
v1, See if it is due to the lock mess in do_read_cache_folio().
v2, See if it is due to folio not locked.
v3, unlock folio tested uptodate.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git 089866061428

--- y/mm/filemap.c
+++ f/mm/filemap.c
@@ -3527,12 +3527,12 @@ filler:
return ERR_PTR(err);
}

- folio_wait_locked(folio);
if (!folio_test_uptodate(folio)) {
folio_put(folio);
return ERR_PTR(-EIO);
}

+ folio_unlock(folio);
goto out;
}
if (folio_test_uptodate(folio))
--

syzbot

unread,
Jul 3, 2022, 4:14:10 AM7/3/22
to hda...@sina.com, linux-...@vger.kernel.org, syzkall...@googlegroups.com
Hello,

syzbot tried to test the proposed patch but the build/boot failed:

4718592 bytes, vmalloc hugepage)
[ 2.322234][ T1] TCP: Hash tables configured (established 65536 bind 65536)
[ 2.326043][ T1] MPTCP token hash table entries: 8192 (order: 7, 720896 bytes, vmalloc)
[ 2.329335][ T1] UDP hash table entries: 4096 (order: 7, 655360 bytes, vmalloc)
[ 2.333054][ T1] UDP-Lite hash table entries: 4096 (order: 7, 655360 bytes, vmalloc)
[ 2.335795][ T1] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 2.352398][ T1] RPC: Registered named UNIX socket transport module.
[ 2.353401][ T1] RPC: Registered udp transport module.
[ 2.354175][ T1] RPC: Registered tcp transport module.
[ 2.354988][ T1] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 2.357912][ T1] NET: Registered PF_XDP protocol family
[ 2.358762][ T1] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
[ 2.359898][ T1] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
[ 2.360891][ T1] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[ 2.362063][ T1] pci_bus 0000:00: resource 7 [mem 0xc0000000-0xfebfefff window]
[ 2.364036][ T1] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 2.365261][ T1] PCI: CLS 0 bytes, default 64
[ 2.371979][ T1] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 2.373330][ T1] software IO TLB: mapped [mem 0x00000000b5a00000-0x00000000b9a00000] (64MB)
[ 2.374625][ T1] ACPI: bus type thunderbolt registered
[ 2.382753][ T55] kworker/u4:1 (55) used greatest stack depth: 27744 bytes left
[ 2.384489][ T56] kworker/u4:1 (56) used greatest stack depth: 26816 bytes left
[ 2.385745][ T1] kvm: no hardware support for 'kvm_intel'
[ 2.386574][ T1] has_svm: svm not available
[ 2.387205][ T1] kvm: no hardware support for 'kvm_amd'
[ 2.388102][ T1] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x206eb2111f5, max_idle_ns: 440795222471 ns
[ 2.389685][ T1] clocksource: Switched to clocksource tsc
[ 5.331539][ T1] Initialise system trusted keyrings
[ 5.334630][ T1] workingset: timestamp_bits=40 max_order=21 bucket_order=0
[ 5.367718][ T1] zbud: loaded
[ 5.375195][ T1] DLM installed
[ 5.381549][ T1] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 5.391078][ T1] NFS: Registering the id_resolver key type
[ 5.392334][ T1] Key type id_resolver registered
[ 5.393106][ T1] Key type id_legacy registered
[ 5.394034][ T1] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 5.395176][ T1] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 5.396352][ T1] Installing knfsd (copyright (C) 1996 ok...@monad.swb.de).
[ 5.404662][ T1] Key type cifs.spnego registered
[ 5.405623][ T1] Key type cifs.idmap registered
[ 5.406779][ T1] ntfs: driver 2.1.32 [Flags: R/W].
[ 5.408631][ T1] ntfs3: Max link count 4000
[ 5.409306][ T1] ntfs3: Enabled Linux POSIX ACLs support
[ 5.410080][ T1] ntfs3: Read-only LZX/Xpress compression included
[ 5.412415][ T1] efs: 1.0a - http://aeschi.ch.eu.org/efs/
[ 5.413548][ T1] jffs2: version 2.2. (NAND) (SUMMARY) © 2001-2006 Red Hat, Inc.
[ 5.417826][ T1] romfs: ROMFS MTD (C) 2007 Red Hat, Inc.
[ 5.419095][ T1] QNX4 filesystem 0.2.3 registered.
[ 5.420047][ T1] qnx6: QNX6 filesystem 1.0.0 registered.
[ 5.421657][ T1] fuse: init (API version 7.36)
[ 5.425790][ T1] orangefs_debugfs_init: called with debug mask: :none: :0:
[ 5.427252][ T1] orangefs_init: module version upstream loaded
[ 5.428886][ T1] JFS: nTxBlock = 8192, nTxLock = 65536
[ 5.441655][ T1] SGI XFS with ACLs, security attributes, realtime, quota, fatal assert, debug enabled
[ 5.453130][ T1] 9p: Installing v9fs 9p2000 file system support
[ 5.455322][ T1] NILFS version 2 loaded
[ 5.455901][ T1] befs: version: 0.9.3
[ 5.457712][ T1] ocfs2: Registered cluster interface o2cb
[ 5.458859][ T1] ocfs2: Registered cluster interface user
[ 5.460156][ T1] OCFS2 User DLM kernel interface loaded
[ 5.470566][ T1] gfs2: GFS2 installed
[ 5.480575][ T1] ceph: loaded (mds proto 32)
[ 5.492050][ T1] NET: Registered PF_ALG protocol family
[ 5.493786][ T1] xor: automatically using best checksumming function avx
[ 5.494902][ T1] async_tx: api initialized (async)
[ 5.495606][ T1] Key type asymmetric registered
[ 5.496297][ T1] Asymmetric key parser 'x509' registered
[ 5.497180][ T1] Asymmetric key parser 'pkcs8' registered
[ 5.497954][ T1] Key type pkcs7_test registered
[ 5.501835][ T1] alg: self-tests for CTR-KDF (hmac(sha256)) passed
[ 5.503011][ T1] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 240)
[ 5.504646][ T1] io scheduler mq-deadline registered
[ 5.505375][ T1] io scheduler kyber registered
[ 5.506584][ T1] io scheduler bfq registered
[ 5.524713][ T1] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 5.582467][ T1] ACPI: button: Power Button [PWRF]
[ 5.584162][ T1] input: Sleep Button as /devices/LNXSYSTM:00/LNXSLPBN:00/input/input1
[ 5.585792][ T1] ACPI: button: Sleep Button [SLPF]
[ 5.604164][ T1] ACPI: \_SB_.LNKC: Enabled at IRQ 11
[ 5.605274][ T1] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
[ 5.617602][ T1] ACPI: \_SB_.LNKD: Enabled at IRQ 10
[ 5.618451][ T1] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[ 5.633443][ T1] ACPI: \_SB_.LNKB: Enabled at IRQ 10
[ 5.634294][ T1] virtio-pci 0000:00:06.0: virtio_pci: leaving for legacy driver
[ 5.738993][ T374] kworker/u4:0 (374) used greatest stack depth: 26584 bytes left
[ 5.861970][ T598] kworker/u4:3 (598) used greatest stack depth: 25088 bytes left
[ 5.926092][ T1] N_HDLC line discipline registered with maxframe=4096
[ 5.927083][ T1] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[ 5.928498][ T1] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[ 5.934966][ T1] 00:04: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[ 5.939708][ T1] 00:05: ttyS2 at I/O 0x3e8 (irq = 6, base_baud = 115200) is a 16550A
[ 5.944810][ T1] 00:06: ttyS3 at I/O 0x2e8 (irq = 7, base_baud = 115200) is a 16550A
[ 5.958949][ T1] Non-volatile memory driver v1.3
[ 5.969216][ T1] Linux agpgart interface v0.103
[ 5.971601][ T1] ACPI: bus type drm_connector registered
[ 5.976161][ T1] [drm] Initialized vgem 1.0.0 20120112 for vgem on minor 0
[ 5.981233][ T1] [drm] Initialized vkms 1.0.0 20180514 for vkms on minor 1
[ 6.037932][ T1] Console: switching to colour frame buffer device 128x48
[ 6.056445][ T1] platform vkms: [drm] fb0: vkmsdrmfb frame buffer device
[ 6.057601][ T1] usbcore: registered new interface driver udl
[ 6.067563][ T1] page:ffffea00051bb0c0 refcount:4 mapcount:0 mapping:ffff888011c812f8 index:0x0 pfn:0x146ec3
[ 6.070088][ T1] memcg:ffff88813fe58000
[ 6.070798][ T1] aops:def_blk_aops ino:100000
[ 6.071497][ T1] flags: 0x57ff00000002004(uptodate|private|node=1|zone=2|lastcpupid=0x7ff)
[ 6.072654][ T1] raw: 057ff00000002004 0000000000000000 dead000000000122 ffff888011c812f8
[ 6.073791][ T1] raw: 0000000000000000 ffff888144d30000 00000004ffffffff ffff88813fe58000
[ 6.074919][ T1] page dumped because: VM_BUG_ON_FOLIO(!folio_test_locked(folio))
[ 6.075961][ T1] page_owner tracks the page as allocated
[ 6.076737][ T1] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x140cc0(GFP_USER|__GFP_COMP), pid 1, tgid 1 (swapper/0), ts 6067264109, free_ts 0
[ 6.078729][ T1] get_page_from_freelist+0x1290/0x3b70
[ 6.079478][ T1] __alloc_pages+0x1c7/0x510
[ 6.080101][ T1] alloc_page_interleave+0x1e/0x200
[ 6.080806][ T1] alloc_pages+0x2b1/0x310
[ 6.081426][ T1] folio_alloc+0x1c/0x70
[ 6.082010][ T1] do_read_cache_folio+0x309/0x6e0
[ 6.082708][ T1] read_cache_page+0x59/0x2a0
[ 6.083342][ T1] read_part_sector+0xf6/0x920
[ 6.083988][ T1] adfspart_check_ICS+0x9a/0x690
[ 6.084678][ T1] bdev_disk_changed+0x629/0xf60
[ 6.085350][ T1] blkdev_get_whole+0x18a/0x2d0
[ 6.086026][ T1] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 6.086769][ T1] blkdev_get_by_dev+0x6b/0x80
[ 6.087413][ T1] disk_scan_partitions+0x16a/0x200
[ 6.088114][ T1] device_add_disk+0xc3e/0xe20
[ 6.088760][ T1] brd_alloc.part.0+0x4db/0x7a0
[ 6.089415][ T1] page_owner free stack trace missing
[ 6.090180][ T1] ------------[ cut here ]------------
[ 6.090907][ T1] kernel BUG at mm/filemap.c:1557!
[ 6.091621][ T1] invalid opcode: 0000 [#1] PREEMPT SMP KASAN
[ 6.092432][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
[ 6.093777][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
[ 6.095094][ T1] RIP: 0010:folio_unlock+0xae/0xc0
[ 6.095782][ T1] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 52 68 0f 00 <0f> 0b 48 89 df e8 98 fc 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 6.098369][ T1] RSP: 0018:ffffc900000678e0 EFLAGS: 00010293
[ 6.099195][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 6.100243][ T1] RDX: ffff88813fe68000 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 6.101298][ T1] RBP: ffffea00051bb0c0 R08: 0000000000000003 R09: 000000000000ffff
[ 6.101603][ T1] R10: 000000000000ffff R11: 0000000000000001 R12: ffff888011c812f8
[ 6.101603][ T1] R13: dffffc0000000000 R14: 0000000000000000 R15: ffff88801d57b180
[ 6.101603][ T1] FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
[ 6.101603][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.101603][ T1] CR2: ffff88823ffff000 CR3: 000000000ba8e000 CR4: 0000000000350ef0
[ 6.101603][ T1] Call Trace:
[ 6.101603][ T1] <TASK>
[ 6.101603][ T1] do_read_cache_folio+0x2f4/0x6e0
[ 6.101603][ T1] ? blkdev_writepages+0x20/0x20
[ 6.101603][ T1] read_cache_page+0x59/0x2a0
[ 6.101603][ T1] read_part_sector+0xf6/0x920
[ 6.101603][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.101603][ T1] adfspart_check_ICS+0x9a/0x690
[ 6.101603][ T1] ? __alloc_pages_slowpath.constprop.0+0x2160/0x2160
[ 6.101603][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.101603][ T1] ? snprintf+0xbb/0xf0
[ 6.101603][ T1] ? vsprintf+0x30/0x30
[ 6.101603][ T1] ? preempt_count_add+0x74/0x140
[ 6.101603][ T1] ? alloc_page_interleave+0x89/0x200
[ 6.101603][ T1] ? alloc_pages+0x1b2/0x310
[ 6.101603][ T1] ? adfspart_check_ADFS+0x410/0x410
[ 6.101603][ T1] bdev_disk_changed+0x629/0xf60
[ 6.101603][ T1] ? iput.part.0+0x73/0x820
[ 6.101603][ T1] blkdev_get_whole+0x18a/0x2d0
[ 6.101603][ T1] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 6.101603][ T1] ? devcgroup_check_permission+0x1ab/0x440
[ 6.101603][ T1] blkdev_get_by_dev+0x6b/0x80
[ 6.101603][ T1] disk_scan_partitions+0x16a/0x200
[ 6.101603][ T1] device_add_disk+0xc3e/0xe20
[ 6.101603][ T1] brd_alloc.part.0+0x4db/0x7a0
[ 6.101603][ T1] ? brd_lookup_page+0x1d0/0x1d0
[ 6.101603][ T1] ? up_write+0x148/0x470
[ 6.101603][ T1] ? ramdisk_size+0x23/0x23
[ 6.101603][ T1] brd_init+0x1b8/0x24b
[ 6.101603][ T1] ? ramdisk_size+0x23/0x23
[ 6.101603][ T1] do_one_initcall+0x103/0x650
[ 6.101603][ T1] ? trace_event_raw_event_initcall_level+0x1f0/0x1f0
[ 6.101603][ T1] ? parameq+0xe0/0x170
[ 6.101603][ T1] kernel_init_freeable+0x6b1/0x73a
[ 6.101603][ T1] ? rest_init+0x270/0x270
[ 6.101603][ T1] kernel_init+0x1a/0x1d0
[ 6.101603][ T1] ? rest_init+0x270/0x270
[ 6.101603][ T1] ret_from_fork+0x1f/0x30
[ 6.101603][ T1] </TASK>
[ 6.101603][ T1] Modules linked in:
[ 6.101603][ C0] vkms_vblank_simulate: vblank timer overrun
[ 6.134624][ T1] ---[ end trace 0000000000000000 ]---
[ 6.135360][ T1] RIP: 0010:folio_unlock+0xae/0xc0
[ 6.136067][ T1] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 52 68 0f 00 <0f> 0b 48 89 df e8 98 fc 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 6.138717][ T1] RSP: 0018:ffffc900000678e0 EFLAGS: 00010293
[ 6.139527][ T1] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 6.140598][ T1] RDX: ffff88813fe68000 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 6.141792][ T1] RBP: ffffea00051bb0c0 R08: 0000000000000003 R09: 000000000000ffff
[ 6.143041][ T1] R10: 000000000000ffff R11: 0000000000000001 R12: ffff888011c812f8
[ 6.144190][ T1] R13: dffffc0000000000 R14: 0000000000000000 R15: ffff88801d57b180
[ 6.145244][ T1] FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
[ 6.146421][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6.147313][ T1] CR2: ffff88823ffff000 CR3: 000000000ba8e000 CR4: 0000000000350ef0
[ 6.148391][ T1] Kernel panic - not syncing: Fatal exception
[ 6.149291][ T1] Kernel Offset: disabled
[ 6.149877][ T1] Rebooting in 86400 seconds..
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build4013857466=/tmp/go-build -gno-record-gcc-switches"

git status (err=<nil>)
HEAD detached at 1434eec0b
nothing to commit, working tree clean


go list -f '{{.Stale}}' ./sys/syz-sysgen | grep -q false || go install ./sys/syz-sysgen
make .descriptions
bin/syz-sysgen
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-fuzzer github.com/google/syzkaller/syz-fuzzer
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-stress github.com/google/syzkaller/tools/syz-stress
mkdir -p ./bin/linux_amd64
gcc -o ./bin/linux_amd64/syz-executor executor/executor.cc \
-m64 -O2 -pthread -Wall -Werror -Wparentheses -Wunused-const-variable -Wframe-larger-than=16384 -Wno-stringop-overflow -Wno-array-bounds -Wno-format-overflow -static-pie -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"1434eec0b84075b7246560cfa89f20cdb3d8077f\"


Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=17a10a58080000


Tested on:

commit: 08986606 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=1179f7fff00000

Hillf Danton

unread,
Jul 3, 2022, 4:28:52 AM7/3/22
to syzbot, linux-...@vger.kernel.org, syzkall...@googlegroups.com
On Sat, 02 Jul 2022 13:05:19 -0700
v1, See if it is due to the lock mess in do_read_cache_folio().
v2, See if it is due to folio not locked.
v3, unlock folio tested uptodate.
v4, unlock folio in erro branch.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git 089866061428

--- y/mm/filemap.c
+++ f/mm/filemap.c
@@ -3523,16 +3523,21 @@ repeat:
filler:
err = filler(file, folio);
if (err < 0) {
+ if (folio_test_locked(folio))
+ folio_unlock(folio);
folio_put(folio);
return ERR_PTR(err);
}

- folio_wait_locked(folio);
if (!folio_test_uptodate(folio)) {
+ if (folio_test_locked(folio))
+ folio_unlock(folio);
folio_put(folio);
return ERR_PTR(-EIO);
}

+ if (folio_test_locked(folio))

syzbot

unread,
Jul 3, 2022, 4:49:14 AM7/3/22
to hda...@sina.com, linux-...@vger.kernel.org, syzkall...@googlegroups.com
Hello,

syzbot tried to test the proposed patch but the build/boot failed:

carl9170
[ 7.224316][ T1] usbcore: registered new interface driver ath6kl_usb
[ 7.226176][ T1] usbcore: registered new interface driver ar5523
[ 7.228878][ T1] usbcore: registered new interface driver ath10k_usb
[ 7.231158][ T1] usbcore: registered new interface driver rndis_wlan
[ 7.235186][ T1] mac80211_hwsim: initializing netlink
[ 7.275724][ T1] usbcore: registered new interface driver atusb
[ 7.284965][ T51] sd 0:0:1:0: Attached scsi generic sg0 type 0
[ 7.285442][ T11] sd 0:0:1:0: [sda] 4194304 512-byte logical blocks: (2.15 GB/2.00 GiB)
[ 7.288346][ T11] sd 0:0:1:0: [sda] 4096-byte physical blocks
[ 7.289973][ T11] sd 0:0:1:0: [sda] Write Protect is off
[ 7.292209][ T1] mac802154_hwsim mac802154_hwsim: Added 2 mac802154 hwsim hardware radios
[ 7.294503][ T1] VMware vmxnet3 virtual NIC driver - version 1.6.0.0-k-NAPI
[ 7.295182][ T11] sd 0:0:1:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 7.296592][ T1] usbcore: registered new interface driver catc
[ 7.299610][ T1] usbcore: registered new interface driver kaweth
[ 7.300913][ T1] pegasus: Pegasus/Pegasus II USB Ethernet driver
[ 7.302324][ T1] usbcore: registered new interface driver pegasus
[ 7.305788][ T1] usbcore: registered new interface driver rtl8150
[ 7.306978][ T1] usbcore: registered new interface driver r8152
[ 7.308016][ T1] hso: drivers/net/usb/hso.c: Option Wireless
[ 7.309652][ T1] usbcore: registered new interface driver hso
[ 7.311109][ T1] usbcore: registered new interface driver lan78xx
[ 7.314468][ T1] usbcore: registered new interface driver asix
[ 7.315877][ T1] usbcore: registered new interface driver ax88179_178a
[ 7.317274][ T1] usbcore: registered new interface driver cdc_ether
[ 7.319460][ T1] usbcore: registered new interface driver cdc_eem
[ 7.320991][ T1] usbcore: registered new interface driver dm9601
[ 7.322286][ T1] usbcore: registered new interface driver sr9700
[ 7.323786][ T1] usbcore: registered new interface driver CoreChips
[ 7.325414][ T1] usbcore: registered new interface driver smsc75xx
[ 7.327102][ T1] usbcore: registered new interface driver smsc95xx
[ 7.328468][ T1] usbcore: registered new interface driver gl620a
[ 7.329625][ T1] usbcore: registered new interface driver net1080
[ 7.330779][ T1] usbcore: registered new interface driver plusb
[ 7.332015][ T1] usbcore: registered new interface driver rndis_host
[ 7.333236][ T1] usbcore: registered new interface driver cdc_subset
[ 7.334659][ T1] usbcore: registered new interface driver zaurus
[ 7.335954][ T1] usbcore: registered new interface driver MOSCHIP usb-ethernet driver
[ 7.337391][ T1] usbcore: registered new interface driver int51x1
[ 7.338668][ T1] usbcore: registered new interface driver cdc_phonet
[ 7.339366][ T11] page:ffffea00007d6d80 refcount:3 mapcount:0 mapping:ffff88801afbeaf8 index:0x0 pfn:0x1f5b6
[ 7.340015][ T1] usbcore: registered new interface driver kalmia
[ 7.341525][ T11] memcg:ffff888140150000
[ 7.342649][ T1] usbcore: registered new interface driver ipheth
[ 7.343799][ T11] aops:def_blk_aops ino:800000
[ 7.344581][ T1] usbcore: registered new interface driver sierra_net
[ 7.345438][ T11] flags: 0xfff00000022014(uptodate|lru|private|mappedtodisk|node=0|zone=1|lastcpupid=0x7ff)
[ 7.346374][ T1] usbcore: registered new interface driver cx82310_eth
[ 7.348215][ T11] raw: 00fff00000022014 ffff88801187b020 ffff88801187b020 ffff88801afbeaf8
[ 7.349448][ T1] usbcore: registered new interface driver cdc_ncm
[ 7.350993][ T11] raw: 0000000000000000 ffff888140d0ed98 00000003ffffffff ffff888140150000
[ 7.352159][ T1] usbcore: registered new interface driver huawei_cdc_ncm
[ 7.355065][ T11] page dumped because: VM_BUG_ON_FOLIO(!folio_test_locked(folio))
[ 7.355279][ T1] usbcore: registered new interface driver lg-vl600
[ 7.356618][ T11] page_owner tracks the page as allocated
[ 7.357693][ T1] usbcore: registered new interface driver qmi_wwan
[ 7.358917][ T11] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x140cc0(GFP_USER|__GFP_COMP), pid 11, tgid 11 (kworker/u4:1), ts 7321931379, free_ts 7056384385
[ 7.359590][ T1] usbcore: registered new interface driver cdc_mbim
[ 7.362475][ T11] get_page_from_freelist+0x1290/0x3b70
[ 7.364001][ T1] usbcore: registered new interface driver ch9200
[ 7.365293][ T11] __alloc_pages+0x1c7/0x510
[ 7.368392][ T11] alloc_pages+0x1aa/0x310
[ 7.369706][ T11] folio_alloc+0x1c/0x70
[ 7.370739][ T11] do_read_cache_folio+0x358/0x830
[ 7.371915][ T11] read_cache_page+0x59/0x2a0
[ 7.372204][ T1] VFIO - User Level meta-driver version: 0.3
[ 7.373726][ T11] read_part_sector+0xf6/0x920
[ 7.375164][ T11] adfspart_check_ICS+0x9a/0x690
[ 7.376164][ T11] bdev_disk_changed+0x629/0xf60
[ 7.377277][ T11] blkdev_get_whole+0x18a/0x2d0
[ 7.378416][ T11] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 7.379331][ T11] blkdev_get_by_dev+0x6b/0x80
[ 7.380230][ T11] disk_scan_partitions+0x16a/0x200
[ 7.381171][ T11] device_add_disk+0xc3e/0xe20
[ 7.382093][ T11] sd_probe+0xa70/0xfe0
[ 7.384040][ T11] really_probe+0x23e/0xb90
[ 7.384708][ T1] aoe: AoE v85 initialised.
[ 7.385335][ T11] page last free stack trace:
[ 7.388222][ T11] free_pcp_prepare+0x549/0xd20
[ 7.389573][ T11] free_unref_page+0x19/0x6a0
[ 7.390530][ T11] __vunmap+0x85d/0xd30
[ 7.391942][ T1] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 7.392495][ T11] free_work+0x58/0x70
[ 7.395154][ T11] process_one_work+0x996/0x1610
[ 7.395550][ T1] ehci-pci: EHCI PCI platform driver
[ 7.395989][ T11] worker_thread+0x665/0x1080
[ 7.397309][ T1] ehci-platform: EHCI generic platform driver
[ 7.397849][ T11] kthread+0x2e9/0x3a0
[ 7.399759][ T1] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 7.401056][ T1] ohci-pci: OHCI PCI platform driver
[ 7.401214][ T11] ret_from_fork+0x1f/0x30
[ 7.405495][ T11] ------------[ cut here ]------------
[ 7.405849][ T1] ohci-platform: OHCI generic platform driver
[ 7.406732][ T11] kernel BUG at mm/filemap.c:1557!
[ 7.408179][ T1] uhci_hcd: USB Universal Host Controller Interface driver
[ 7.408749][ T11] invalid opcode: 0000 [#1] PREEMPT SMP KASAN
[ 7.411418][ T11] CPU: 0 PID: 11 Comm: kworker/u4:1 Not tainted 5.19.0-rc4-syzkaller-00187-g089866061428-dirty #0
[ 7.411796][ T1] driver u132_hcd
[ 7.412861][ T11] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
[ 7.412861][ T11] Workqueue: events_unbound async_run_entry_fn
[ 7.412861][ T11] RIP: 0010:folio_unlock+0xae/0xc0
[ 7.412861][ T11] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 a2 69 0f 00 <0f> 0b 48 89 df e8 e8 fd 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 7.412861][ T11] RSP: 0018:ffffc900001074d0 EFLAGS: 00010293
[ 7.412861][ T11] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 7.412861][ T11] RDX: ffff88813fec3b00 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 7.412861][ T11] RBP: ffffea00007d6d80 R08: 0000000000000003 R09: 000000000000ffff
[ 7.412861][ T11] R10: 000000000000ffff R11: 0000000000000001 R12: 0000000000000000
[ 7.412861][ T11] R13: dffffc0000000000 R14: 0000000000000001 R15: 0000000000000000
[ 7.412861][ T11] FS: 0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
[ 7.412861][ T11] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 7.412861][ T11] CR2: ffff88823ffff000 CR3: 000000000ba8e000 CR4: 0000000000350ef0
[ 7.412861][ T11] Call Trace:
[ 7.412861][ T11] <TASK>
[ 7.412861][ T11] end_buffer_async_read+0x6fe/0xf00
[ 7.412861][ T11] block_read_full_folio+0x687/0xa60
[ 7.412861][ T11] ? blkdev_write_begin+0x40/0x40
[ 7.412861][ T11] ? end_buffer_async_read_io+0x300/0x300
[ 7.412861][ T11] ? folio_flags.constprop.0+0x58/0x150
[ 7.412861][ T11] do_read_cache_folio+0x281/0x830
[ 7.412861][ T11] ? blkdev_writepages+0x20/0x20
[ 7.412861][ T11] read_cache_page+0x59/0x2a0
[ 7.412861][ T11] read_part_sector+0xf6/0x920
[ 7.412861][ T11] ? adfspart_check_ICS+0x690/0x690
[ 7.412861][ T11] adfspart_check_POWERTEC+0x93/0x530
[ 7.412861][ T11] ? __alloc_pages_slowpath.constprop.0+0x2160/0x2160
[ 7.412861][ T11] ? adfspart_check_ADFS+0x410/0x410
[ 7.412861][ T11] ? adfspart_check_ICS+0x690/0x690
[ 7.412861][ T11] ? vsprintf+0x30/0x30
[ 7.412861][ T11] ? alloc_pages+0x1b2/0x310
[ 7.412861][ T11] ? adfspart_check_ICS+0x690/0x690
[ 7.412861][ T11] bdev_disk_changed+0x629/0xf60
[ 7.412861][ T11] blkdev_get_whole+0x18a/0x2d0
[ 7.412861][ T11] blkdev_get_by_dev.part.0+0x5ec/0xb90
[ 7.412861][ T11] ? devcgroup_check_permission+0x1ab/0x440
[ 7.412861][ T11] blkdev_get_by_dev+0x6b/0x80
[ 7.412861][ T11] disk_scan_partitions+0x16a/0x200
[ 7.412861][ T11] device_add_disk+0xc3e/0xe20
[ 7.412861][ T11] sd_probe+0xa70/0xfe0
[ 7.412861][ T11] ? sd_open+0x6d0/0x6d0
[ 7.412861][ T11] really_probe+0x23e/0xb90
[ 7.412861][ T11] __driver_probe_device+0x338/0x4d0
[ 7.412861][ T11] driver_probe_device+0x4c/0x1a0
[ 7.412861][ T11] __device_attach_driver+0x20b/0x2f0
[ 7.412861][ T11] ? driver_allows_async_probing+0x170/0x170
[ 7.412861][ T11] bus_for_each_drv+0x15f/0x1e0
[ 7.412861][ T11] ? bus_for_each_dev+0x1d0/0x1d0
[ 7.412861][ T11] ? _raw_spin_unlock_irqrestore+0x50/0x70
[ 7.412861][ T11] ? lockdep_hardirqs_on+0x79/0x100
[ 7.412861][ T11] ? _raw_spin_unlock_irqrestore+0x3d/0x70
[ 7.412861][ T11] ? device_unbind_cleanup+0x1b0/0x1b0
[ 7.412861][ T11] __device_attach_async_helper+0x1c9/0x280
[ 7.412861][ T11] ? device_unbind_cleanup+0x1b0/0x1b0
[ 7.412861][ T11] ? lockdep_hardirqs_on+0x79/0x100
[ 7.412861][ T11] ? ktime_get+0x38a/0x470
[ 7.412861][ T11] ? ktime_get+0x30b/0x470
[ 7.412861][ T11] async_run_entry_fn+0x9d/0x550
[ 7.412861][ T11] process_one_work+0x996/0x1610
[ 7.412861][ T11] ? pwq_dec_nr_in_flight+0x2a0/0x2a0
[ 7.412861][ T11] ? rwlock_bug.part.0+0x90/0x90
[ 7.412861][ T11] ? _raw_spin_lock_irq+0x41/0x50
[ 7.412861][ T11] worker_thread+0x665/0x1080
[ 7.412861][ T11] ? process_one_work+0x1610/0x1610
[ 7.412861][ T11] kthread+0x2e9/0x3a0
[ 7.412861][ T11] ? kthread_complete_and_exit+0x40/0x40
[ 7.412861][ T11] ret_from_fork+0x1f/0x30
[ 7.412861][ T11] </TASK>
[ 7.412861][ T11] Modules linked in:
[ 7.412861][ C0] vkms_vblank_simulate: vblank timer overrun
[ 7.494800][ T11] ---[ end trace 0000000000000000 ]---
[ 7.495791][ T1] fotg210_hcd: FOTG210 Host Controller (EHCI) Driver
[ 7.496256][ T11] RIP: 0010:folio_unlock+0xae/0xc0
[ 7.497087][ T1] Warning! fotg210_hcd should always be loaded before uhci_hcd and ohci_hcd, not after
[ 7.497213][ T1] SPI driver max3421-hcd has no spi_device_id for maxim,max3421
[ 7.498252][ T11] Code: e8 e7 38 d9 ff 48 89 ef 31 f6 e8 0d f9 ff ff 5b 5d e9 d6 38 d9 ff e8 d1 38 d9 ff 48 c7 c6 20 75 d6 89 48 89 ef e8 a2 69 0f 00 <0f> 0b 48 89 df e8 e8 fd 25 00 e9 7c ff ff ff 0f 1f 00 41 57 41 56
[ 7.500298][ T1] usbcore: registered new interface driver cdc_acm
[ 7.501805][ T11] RSP: 0018:ffffc900001074d0 EFLAGS: 00010293
[ 7.505447][ T1] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[ 7.507369][ T11]
[ 7.507695][ T1] usbcore: registered new interface driver usblp
[ 7.509590][ T11] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 7.510306][ T1] usbcore: registered new interface driver cdc_wdm
[ 7.511851][ T11] RDX: ffff88813fec3b00 RSI: ffffffff81a12dee RDI: 0000000000000003
[ 7.513320][ T1] usbcore: registered new interface driver usbtmc
[ 7.515918][ T1] usbcore: registered new interface driver uas
[ 7.516095][ T11] RBP: ffffea00007d6d80 R08: 0000000000000003 R09: 000000000000ffff
[ 7.517558][ T1] usbcore: registered new interface driver usb-storage
[ 7.518868][ T11] R10: 000000000000ffff R11: 0000000000000001 R12: 0000000000000000
[ 7.520464][ T1] usbcore: registered new interface driver ums-alauda
[ 7.521492][ T11] R13: dffffc0000000000 R14: 0000000000000001 R15: 0000000000000000
[ 7.523238][ T1] usbcore: registered new interface driver ums-cypress
[ 7.525495][ T11] FS: 0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
[ 7.526115][ T1] usbcore: registered new interface driver ums-datafab
[ 7.527788][ T11] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 7.529454][ T1] usbcore: registered new interface driver ums_eneub6250
[ 7.531502][ T11] CR2: 0000000000000000 CR3: 000000000ba8e000 CR4: 0000000000350ee0
[ 7.531663][ T1] usbcore: registered new interface driver ums-freecom
[ 7.533961][ T11] Kernel panic - not syncing: Fatal exception
[ 7.535233][ T11] Kernel Offset: disabled
[ 7.537875][ T11] Rebooting in 86400 seconds..
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1074279953=/tmp/go-build -gno-record-gcc-switches"

git status (err=<nil>)
HEAD detached at 1434eec0b
nothing to commit, working tree clean


go list -f '{{.Stale}}' ./sys/syz-sysgen | grep -q false || go install ./sys/syz-sysgen
make .descriptions
bin/syz-sysgen
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-fuzzer github.com/google/syzkaller/syz-fuzzer
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-stress github.com/google/syzkaller/tools/syz-stress
mkdir -p ./bin/linux_amd64
gcc -o ./bin/linux_amd64/syz-executor executor/executor.cc \
-m64 -O2 -pthread -Wall -Werror -Wparentheses -Wunused-const-variable -Wframe-larger-than=16384 -Wno-stringop-overflow -Wno-array-bounds -Wno-format-overflow -static-pie -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"1434eec0b84075b7246560cfa89f20cdb3d8077f\"


Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=12cf8297f00000


Tested on:

commit: 08986606 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=16c005cc080000

Hillf Danton

unread,
Jul 3, 2022, 11:42:46 PM7/3/22
to syzbot, linux-...@vger.kernel.org, syzkall...@googlegroups.com
On Sat, 02 Jul 2022 13:05:19 -0700
v1, See if it is due to the lock mess in do_read_cache_folio().
v2, See if it is due to folio not locked.
v3, unlock folio tested uptodate.
v4, unlock folio in erro branch.
v5, see if it is due to IO timeout.

#syz test http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git 089866061428

--- y/mm/filemap.c
+++ f/mm/filemap.c
@@ -3527,7 +3527,12 @@ filler:
return ERR_PTR(err);
}

- folio_wait_locked(folio);
+ for (;;) {
+ if (folio_test_locked(folio))
+ schedule_timeout_idle(2 * HZ);
+ else
+ break;
+ }
if (!folio_test_uptodate(folio)) {
folio_put(folio);
return ERR_PTR(-EIO);
--

syzbot

unread,
Jul 3, 2022, 11:51:08 PM7/3/22
to hda...@sina.com, linux-...@vger.kernel.org, syzkall...@googlegroups.com
Hello,

syzbot tried to test the proposed patch but the build/boot failed:

failed to create VM pool: failed to create GCE image: create image operation failed: &{Code:PERMISSIONS_ERROR Location: Message:Required 'read' permission for 'disks/ci-upstream-kasan-gce-root-test-job-test-job-image.tar.gz' ForceSendFields:[] NullFields:[]}.
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1089749838=/tmp/go-build -gno-record-gcc-switches"

git status (err=<nil>)
HEAD detached at 1434eec0b
nothing to commit, working tree clean


go list -f '{{.Stale}}' ./sys/syz-sysgen | grep -q false || go install ./sys/syz-sysgen
make .descriptions
bin/syz-sysgen
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-fuzzer github.com/google/syzkaller/syz-fuzzer
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=1434eec0b84075b7246560cfa89f20cdb3d8077f -X 'github.com/google/syzkaller/prog.gitRevisionDate=20220629-111539'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-stress github.com/google/syzkaller/tools/syz-stress
mkdir -p ./bin/linux_amd64
gcc -o ./bin/linux_amd64/syz-executor executor/executor.cc \
-m64 -O2 -pthread -Wall -Werror -Wparentheses -Wunused-const-variable -Wframe-larger-than=16384 -Wno-stringop-overflow -Wno-array-bounds -Wno-format-overflow -static-pie -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"1434eec0b84075b7246560cfa89f20cdb3d8077f\"



Tested on:

commit: 08986606 Merge tag 'libnvdimm-fixes-5.19-rc5' of git:/..
git tree: http://kernel.source.codeaurora.cn/pub/scm/linux/kernel/git/torvalds/linux.git
kernel config: https://syzkaller.appspot.com/x/.config?x=833001d0819ddbc9
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=11871248080000

Hillf Danton

unread,
Jul 7, 2022, 7:07:00 AM7/7/22
to syzbot, linux-...@vger.kernel.org, syzkall...@googlegroups.com
On Sat, 02 Jul 2022 13:05:19 -0700
v1, See if it is due to the lock mess in do_read_cache_folio().
v2, See if it is due to folio not locked.
v3, unlock folio tested uptodate.
v4, unlock folio in erro branch.
v5, see if it is due to IO timeout.

#syz test https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master

syzbot

unread,
Jul 7, 2022, 9:28:09 AM7/7/22
to hda...@sina.com, linux-...@vger.kernel.org, syzkall...@googlegroups.com
Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in blkdev_put

INFO: task syz-executor.0:4094 blocked for more than 143 seconds.
Not tainted 5.19.0-rc5-syzkaller-00105-g9f09069cde34-dirty #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0 state:D stack:27904 pid: 4094 ppid: 4052 flags:0x00000004
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5146 [inline]
__schedule+0xa00/0x4b50 kernel/sched/core.c:6458
schedule+0xd2/0x1f0 kernel/sched/core.c:6530
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0xa70/0x1350 kernel/locking/mutex.c:747
blkdev_put+0xbc/0x770 block/bdev.c:912
blkdev_close+0x64/0x80 block/fops.c:495
__fput+0x277/0x9d0 fs/file_table.c:317
task_work_run+0xdd/0x1a0 kernel/task_work.c:177
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
exit_to_user_mode_loop kernel/entry/common.c:169 [inline]
exit_to_user_mode_prepare+0x23c/0x250 kernel/entry/common.c:201
__syscall_exit_to_user_mode_work kernel/entry/common.c:283 [inline]
syscall_exit_to_user_mode+0x19/0x50 kernel/entry/common.c:294
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f6efd23bd4b
RSP: 002b:00007ffe1bd4ccd0 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000006 RCX: 00007f6efd23bd4b
RDX: 0000001b30e20000 RSI: 0000000000000000 RDI: 0000000000000005
RBP: 00007f6efd39d960 R08: 0000000000000000 R09: 00007ffe1bde5080
R10: 00007ffe1bde5090 R11: 0000000000000293 R12: 000000000000e2d4
R13: 00007ffe1bd4cdd0 R14: 00007ffe1bd4cdf0 R15: 0000000000000032
</TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
#0: ffffffff8bd86660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
2 locks held by getty/3283:
#0: ffff88814b128098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
#1: ffffc90002d232e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
1 lock held by udevd/4048:
#0: ffff88801d9b3118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev.part.0+0x9b/0xb90 block/bdev.c:814
1 lock held by syz-executor.0/4094:
#0: ffff88801d9b3118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xbc/0x770 block/bdev.c:912

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.19.0-rc5-syzkaller-00105-g9f09069cde34-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/29/2022
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x1e6/0x230 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:212 [inline]
watchdog+0xc1d/0xf50 kernel/hung_task.c:369
kthread+0x2e9/0x3a0 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
</TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1 skipped: idling at native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
NMI backtrace for cpu 1 skipped: idling at arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
NMI backtrace for cpu 1 skipped: idling at acpi_safe_halt drivers/acpi/processor_idle.c:111 [inline]
NMI backtrace for cpu 1 skipped: idling at acpi_idle_do_entry+0x1c9/0x240 drivers/acpi/processor_idle.c:554


Tested on:

commit: 9f09069c Merge tag 'for-linus' of https://github.com/o..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
console output: https://syzkaller.appspot.com/x/log.txt?x=12d44d84080000
kernel config: https://syzkaller.appspot.com/x/.config?x=fa95f12403a2e0d2
dashboard link: https://syzkaller.appspot.com/bug?extid=be946efe33b2d9664348
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=15dad724080000

Reply all
Reply to author
Forward
0 new messages