Message-ID: <CAJg=8jyC1+s80etZgWteps0Q0yEsR2NE23+Bf+Daa7zgJ2qKBA@mail.gmail.com>
Date: Sat, 20 Apr 2024 18:19:01 -0700
From: Marius Fleischer <fleischermarius@...il.com>
To: Jens Axboe <axboe@...nel.dk>, linux-block@...r.kernel.org, 
	linux-kernel@...r.kernel.org
Cc: syzkaller@...glegroups.com, harrisonmichaelgreen@...il.com
Subject: INFO: task hung in bdev_open

Hi,

We would like to report the following bug which has been found by our
modified version of syzkaller.

======================================================
description: INFO: task hung in bdev_open
affected file: block/bdev.c
kernel version: 6.9-rc4
kernel commit: 0bbac3facb5d6cc0171c45c9873a2dc96bea9680
git tree: upstream
kernel config: attached
crash reproducer: attached
======================================================
Crash log:
INFO: task systemd-udevd:20128 blocked for more than 143 seconds.
   Not tainted 6.9.0-rc4-dirty #3
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-udevd   state:D stack:26384 pid:20128 tgid:20128
ppid:4546   flags:0x00000000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5409 [inline]
 __schedule+0xd23/0x5bc0 kernel/sched/core.c:6746
 __schedule_loop kernel/sched/core.c:6823 [inline]
 schedule+0xe7/0x350 kernel/sched/core.c:6838
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6895
 __mutex_lock_common kernel/locking/mutex.c:684 [inline]
 __mutex_lock+0x508/0x930 kernel/locking/mutex.c:752
 bdev_open+0x414/0xe90 block/bdev.c:868
 blkdev_open+0x181/0x200 block/fops.c:620
 do_dentry_open+0x6d3/0x18e0 fs/open.c:955
 do_open fs/namei.c:3642 [inline]
 path_openat+0x1b23/0x2670 fs/namei.c:3799
 do_filp_open+0x1c7/0x410 fs/namei.c:3826
 do_sys_openat2+0x164/0x1d0 fs/open.c:1406
 do_sys_open fs/open.c:1421 [inline]
 __do_sys_openat fs/open.c:1437 [inline]
 __se_sys_openat fs/open.c:1432 [inline]
 __x64_sys_openat+0x140/0x1f0 fs/open.c:1432
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xce/0x250 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7fd9bba3e767
RSP: 002b:00007fffd5da4040 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 00007fffd5da4174 RCX: 00007fd9bba3e767
RDX: 00000000000a0800 RSI: 00005593e06cf0c0 RDI: 00000000ffffff9c
RBP: 00005593e06cf0c0 R08: 00005593b8b95720 R09: 00007fd9bbaf8080
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000000a0800
R13: 0000000000000000 R14: 00007fffd5da40d0 R15: 00007fffd5da4174
 </TASK>
INFO: task syz-executor.2:32417 blocked for more than 143 seconds.
   Not tainted 6.9.0-rc4-dirty #3
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2  state:D stack:27248 pid:32417 tgid:32417
ppid:8232   flags:0x00000006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5409 [inline]
 __schedule+0xd23/0x5bc0 kernel/sched/core.c:6746
 __schedule_loop kernel/sched/core.c:6823 [inline]
 schedule+0xe7/0x350 kernel/sched/core.c:6838
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6895
 __mutex_lock_common kernel/locking/mutex.c:684 [inline]
 __mutex_lock+0x508/0x930 kernel/locking/mutex.c:752
 bdev_release+0x161/0x720 block/bdev.c:1050
 blkdev_release+0x15/0x20 block/fops.c:628
 __fput+0x282/0xbc0 fs/file_table.c:422
 __fput_sync+0x45/0x50 fs/file_table.c:507
 __do_sys_close fs/open.c:1556 [inline]
 __se_sys_close fs/open.c:1541 [inline]
 __x64_sys_close+0x8a/0x120 fs/open.c:1541
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xce/0x250 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f18ba68dc0b
RSP: 002b:00007ffc5ea89990 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: ffffffffffffffda RBX: 0000000000000007 RCX: 00007f18ba68dc0b
RDX: 0000000000000000 RSI: 000000000000d8e4 RDI: 0000000000000006
RBP: 00007f18ba7cd980 R08: 0000000000000000 R09: 000000008ac21002
R10: 0000000000000001 R11: 0000000000000293 R12: 00000000000adc9f
R13: 00007ffc5ea89a90 R14: 00007f18ba200dd0 R15: 00007f18ba200dc8
 </TASK>
INFO: task syz-executor.2:32420 blocked for more than 143 seconds.
   Not tainted 6.9.0-rc4-dirty #3
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2  state:D stack:28096 pid:32420 tgid:32417
ppid:8232   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5409 [inline]
 __schedule+0xd23/0x5bc0 kernel/sched/core.c:6746
 __schedule_loop kernel/sched/core.c:6823 [inline]
 schedule+0xe7/0x350 kernel/sched/core.c:6838
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6895
 __mutex_lock_common kernel/locking/mutex.c:684 [inline]
 __mutex_lock+0x508/0x930 kernel/locking/mutex.c:752
 bdev_release+0x161/0x720 block/bdev.c:1050
 blkdev_release+0x15/0x20 block/fops.c:628
 __fput+0x282/0xbc0 fs/file_table.c:422
 task_work_run+0x169/0x260 kernel/task_work.c:180
 resume_user_mode_work include/linux/resume_user_mode.h:50 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:114 [inline]
 exit_to_user_mode_prepare include/linux/entry-common.h:328 [inline]
 __syscall_exit_to_user_mode_work kernel/entry/common.c:207 [inline]
 syscall_exit_to_user_mode+0x278/0x2a0 kernel/entry/common.c:218
 do_syscall_64+0xdb/0x250 arch/x86/entry/common.c:89
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f18ba68ed2d
RSP: 002b:00007f18bb4e3028 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: 0000000000000000 RBX: 00007f18ba7cbf80 RCX: 00007f18ba68ed2d
RDX: 0000000000000000 RSI: 000000000000ab03 RDI: 0000000000000003
RBP: 00007f18ba6f04a6 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000000b R14: 00007f18ba7cbf80 R15: 00007f18bb4c3000
 </TASK>
INFO: task syz-executor.2:32444 blocked for more than 143 seconds.
   Not tainted 6.9.0-rc4-dirty #3
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2  state:D stack:25264 pid:32444 tgid:32417
ppid:8232   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5409 [inline]
 __schedule+0xd23/0x5bc0 kernel/sched/core.c:6746
 __schedule_loop kernel/sched/core.c:6823 [inline]
 schedule+0xe7/0x350 kernel/sched/core.c:6838
 io_schedule+0xbf/0x130 kernel/sched/core.c:9044
 folio_wait_bit_common+0x397/0x9c0 mm/filemap.c:1283
 folio_put_wait_locked mm/filemap.c:1447 [inline]
 do_read_cache_folio+0x2db/0x520 mm/filemap.c:3729
 read_mapping_folio include/linux/pagemap.h:894 [inline]
 read_part_sector+0xf7/0x440 block/partitions/core.c:715
 adfspart_check_POWERTEC+0x82/0x710 block/partitions/acorn.c:454
 check_partition block/partitions/core.c:138 [inline]
 blk_add_partitions block/partitions/core.c:582 [inline]
 bdev_disk_changed+0x891/0x15f0 block/partitions/core.c:686
 blkdev_get_whole+0x18b/0x260 block/bdev.c:667
 bdev_open+0x2eb/0xe90 block/bdev.c:880
 blkdev_open+0x181/0x200 block/fops.c:620
 do_dentry_open+0x6d3/0x18e0 fs/open.c:955
 do_open fs/namei.c:3642 [inline]
 path_openat+0x1b23/0x2670 fs/namei.c:3799
 do_filp_open+0x1c7/0x410 fs/namei.c:3826
 do_sys_openat2+0x164/0x1d0 fs/open.c:1406
 do_sys_open fs/open.c:1421 [inline]
 __do_sys_openat fs/open.c:1437 [inline]
 __se_sys_openat fs/open.c:1432 [inline]
 __x64_sys_openat+0x140/0x1f0 fs/open.c:1432
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xce/0x250 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f18ba68d904
RSP: 002b:00007f18bb4c1b50 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 00007f18ba68d904
RDX: 0000000000000000 RSI: 00007f18bb4c1bf0 RDI: 00000000ffffff9c
RBP: 00007f18bb4c1bf0 R08: 0000000000000000 R09: 002364626e2f7665
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 000000000000006e R14: 00007f18ba7cc050 R15: 00007f18bb4a2000
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/33:
 #0: ffffffff8d7b0560 (rcu_read_lock){....}-{1:2}, at:
rcu_lock_acquire include/linux/rcupdate.h:329 [inline]
 #0: ffffffff8d7b0560 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock
include/linux/rcupdate.h:781 [inline]
 #0: ffffffff8d7b0560 (rcu_read_lock){....}-{1:2}, at:
debug_show_all_locks+0x75/0x340 kernel/locking/lockdep.c:6614
4 locks held by systemd-journal/4534:
2 locks held by in:imklog/7643:
5 locks held by rs:main Q:Reg/7644:
2 locks held by agetty/7994:
 #0: ffff888108f780a0 (&tty->ldisc_sem){++++}-{0:0}, at:
tty_ldisc_ref_wait+0x26/0x80 drivers/tty/tty_ldisc.c:243
 #1: ffffc900024cc2f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at:
n_tty_read+0xf1d/0x1410 drivers/tty/n_tty.c:2201
1 lock held by systemd-udevd/20128:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_open+0x414/0xe90 block/bdev.c:868
1 lock held by syz-executor.2/32417:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_release+0x161/0x720 block/bdev.c:1050
1 lock held by syz-executor.2/32420:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_release+0x161/0x720 block/bdev.c:1050
1 lock held by syz-executor.2/32444:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_open+0x414/0xe90 block/bdev.c:868
1 lock held by syz-executor.2/33109:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_open+0x414/0xe90 block/bdev.c:868
1 lock held by syz-executor.2/33111:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_open+0x414/0xe90 block/bdev.c:868
1 lock held by syz-executor.2/33112:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_open+0x414/0xe90 block/bdev.c:868
1 lock held by syz-executor.2/33594:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_open+0x414/0xe90 block/bdev.c:868
1 lock held by syz-executor.2/33595:
 #0: ffff88801da594c8 (&disk->open_mutex){+.+.}-{3:3}, at:
bdev_open+0x414/0xe90 block/bdev.c:868
=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 33 Comm: khungtaskd Not tainted 6.9.0-rc4-dirty #3
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x116/0x1b0 lib/dump_stack.c:114
 nmi_cpu_backtrace+0x2a0/0x350 lib/nmi_backtrace.c:113
 nmi_trigger_cpumask_backtrace+0x29c/0x300 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:223 [inline]
 watchdog+0xe79/0x1130 kernel/hung_task.c:380
 kthread+0x2c7/0x3b0 kernel/kthread.c:388
 ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 7644 Comm: rs:main Q:Reg Not tainted 6.9.0-rc4-dirty #3
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
RIP: 0010:arch_atomic_read arch/x86/include/asm/atomic.h:23 [inline]
RIP: 0010:raw_atomic_read
include/linux/atomic/atomic-arch-fallback.h:457 [inline]
RIP: 0010:atomic_read include/linux/atomic/atomic-instrumented.h:33 [inline]
RIP: 0010:page_table_check_clear mm/page_table_check.c:81 [inline]
RIP: 0010:page_table_check_clear+0x441/0xc50 mm/page_table_check.c:61
Code: b5 19 f5 ff 48 8b 7c 24 08 48 89 f8 48 c1 e8 03 42 0f b6 14 38
48 89 f8 83 e0 07 83 c0 03 38 d0 7c 08 84 d2 0f 85 0c 07 00 00 <8b> 43
04 31 ff 89 c6 89 44 24 08 e8 df 69 9b ff 8b 44 24 08 85 c0
RSP: 0018:ffffc9000e3a78a8 EFLAGS: 00010246
RAX: 0000000000000007 RBX: ffff888101c7e678 RCX: ffffffff81f0d92b
RDX: 0000000000000000 RSI: 0000000000000004 RDI: ffff888101c7e67c
RBP: 0000000000000001 R08: 0000000000000000 R09: ffffed102038fccf
R10: ffff888101c7e67f R11: 0000000000000000 R12: 0000000000000000
R13: ffff888101c7e630 R14: 0000000000000001 R15: dffffc0000000000
FS:  00007f0b23200700(0000) GS:ffff888063600000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ff21622aee0 CR3: 00000001065f6000 CR4: 0000000000750ef0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe07f0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 __page_table_check_pte_clear+0xfc/0x110 mm/page_table_check.c:158
 page_table_check_pte_clear include/linux/page_table_check.h:49 [inline]
 ptep_get_and_clear arch/x86/include/asm/pgtable.h:1279 [inline]
 __ptep_modify_prot_start include/linux/pgtable.h:1199 [inline]
 ptep_modify_prot_start include/linux/pgtable.h:1232 [inline]
 change_pte_range mm/mprotect.c:166 [inline]
 change_pmd_range mm/mprotect.c:422 [inline]
 change_pud_range mm/mprotect.c:455 [inline]
 change_p4d_range mm/mprotect.c:478 [inline]
 change_protection_range mm/mprotect.c:506 [inline]
 change_protection+0x1d1a/0x2f40 mm/mprotect.c:540
 change_prot_numa+0xaf/0x140 mm/mempolicy.c:679
 task_numa_work+0x878/0x14d0 kernel/sched/fair.c:3375
 task_work_run+0x169/0x260 kernel/task_work.c:180
 resume_user_mode_work include/linux/resume_user_mode.h:50 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:114 [inline]
 exit_to_user_mode_prepare include/linux/entry-common.h:328 [inline]
 __syscall_exit_to_user_mode_work kernel/entry/common.c:207 [inline]
 syscall_exit_to_user_mode+0x278/0x2a0 kernel/entry/common.c:218
 do_syscall_64+0xdb/0x250 arch/x86/entry/common.c:89
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f0b2458cfef
Code: 89 54 24 18 48 89 74 24 10 89 7c 24 08 e8 29 fd ff ff 48 8b 54
24 18 48 8b 74 24 10 41 89 c0 8b 7c 24 08 b8 01 00 00 00 0f 05 <48> 3d
00 f0 ff ff 77 31 44 89 c7 48 89 44 24 08 e8 5c fd ff ff 48
RSP: 002b:00007f0b231ff830 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
RAX: 0000000000001000 RBX: 0000000000001000 RCX: 00007f0b2458cfef
RDX: 0000000000001000 RSI: 00007f0b1002bee0 RDI: 000000000000000b
RBP: 0000000000001000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 00007f0b1002bee0
R13: 0000000000000000 R14: 0000000000000037 R15: 00007f0b1002bc20
 </TASK>
======================================================

Wishing you a nice day!

Best,
Marius

View attachment "repro.c" of type "text/x-csrc" (10386 bytes)

Download attachment "repro.syz" of type "application/octet-stream" (283 bytes)

Download attachment "config-6.9-rc4" of type "application/octet-stream" (258818 bytes)

Powered by blists - more mailing lists