linux-kernel - Re: [syzbot] [exfat?] INFO: task hung in do_new

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives
Hash Suite for Android: free password hash cracker in your pocket
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <0000000000004eb4c4061462a246@google.com>
Date: Sun, 24 Mar 2024 00:02:02 -0700
From: syzbot <syzbot+f59c2feaf7cb5988e877@...kaller.appspotmail.com>
To: eadavis@...com, linux-kernel@...r.kernel.org, 
	syzkaller-bugs@...glegroups.com
Subject: Re: [syzbot] [exfat?] INFO: task hung in do_new_mount (2)

Hello,

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

INFO: task syz-executor.2:5529 blocked for more than 143 seconds.
      Not tainted 6.5.0-rc4-syzkaller-00229-g0a2c2baafa31 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2  state:D stack:28792 pid:5529  ppid:5388   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5381 [inline]
 __schedule+0x187f/0x4970 kernel/sched/core.c:6710
 schedule+0xc3/0x180 kernel/sched/core.c:6786
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6845
 __mutex_lock_common+0xe6b/0x2380 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x1b/0x30 kernel/locking/mutex.c:799
 __fdget_pos+0x2c1/0x370 fs/file.c:1062
 fdget_pos include/linux/file.h:74 [inline]
 __do_sys_getdents64 fs/readdir.c:365 [inline]
 __se_sys_getdents64+0x1dc/0x4f0 fs/readdir.c:354
 do_syscall_64+0x46/0xc0
 entry_SYSCALL_64_after_hwframe+0x6f/0xd9
RIP: 0033:0x7f7b1747dda9
RSP: 002b:00007f7b1812d0c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000d9
RAX: ffffffffffffffda RBX: 00007f7b175ac050 RCX: 00007f7b1747dda9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000005
RBP: 00007f7b174ca47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f7b175ac050 R15: 00007ffe0719f878
 </TASK>
INFO: task syz-executor.1:5544 blocked for more than 144 seconds.
      Not tainted 6.5.0-rc4-syzkaller-00229-g0a2c2baafa31 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:29360 pid:5544  ppid:5389   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5381 [inline]
 __schedule+0x187f/0x4970 kernel/sched/core.c:6710
 schedule+0xc3/0x180 kernel/sched/core.c:6786
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6845
 __mutex_lock_common+0xe6b/0x2380 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x1b/0x30 kernel/locking/mutex.c:799
 __fdget_pos+0x2c1/0x370 fs/file.c:1062
 fdget_pos include/linux/file.h:74 [inline]
 __do_sys_getdents64 fs/readdir.c:365 [inline]
 __se_sys_getdents64+0x1dc/0x4f0 fs/readdir.c:354
 do_syscall_64+0x46/0xc0
 entry_SYSCALL_64_after_hwframe+0x6f/0xd9
RIP: 0033:0x7f85ae47dda9
RSP: 002b:00007f85ad7fe0c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000d9
RAX: ffffffffffffffda RBX: 00007f85ae5ac050 RCX: 00007f85ae47dda9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000005
RBP: 00007f85ae4ca47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f85ae5ac050 R15: 00007fff4f482218
 </TASK>
INFO: task syz-executor.4:5547 blocked for more than 145 seconds.
      Not tainted 6.5.0-rc4-syzkaller-00229-g0a2c2baafa31 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.4  state:D stack:29360 pid:5547  ppid:5394   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5381 [inline]
 __schedule+0x187f/0x4970 kernel/sched/core.c:6710
 schedule+0xc3/0x180 kernel/sched/core.c:6786
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6845
 __mutex_lock_common+0xe6b/0x2380 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x1b/0x30 kernel/locking/mutex.c:799
 __fdget_pos+0x2c1/0x370 fs/file.c:1062
 fdget_pos include/linux/file.h:74 [inline]
 __do_sys_getdents64 fs/readdir.c:365 [inline]
 __se_sys_getdents64+0x1dc/0x4f0 fs/readdir.c:354
 do_syscall_64+0x46/0xc0
 entry_SYSCALL_64_after_hwframe+0x6f/0xd9
RIP: 0033:0x7f3a6fa7dda9
RSP: 002b:00007f3a707b90c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000d9
RAX: ffffffffffffffda RBX: 00007f3a6fbac050 RCX: 00007f3a6fa7dda9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000005
RBP: 00007f3a6faca47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f3a6fbac050 R15: 00007ffc33ae2ae8
 </TASK>
INFO: task syz-executor.3:5555 blocked for more than 146 seconds.
      Not tainted 6.5.0-rc4-syzkaller-00229-g0a2c2baafa31 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.3  state:D stack:29360 pid:5555  ppid:5387   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5381 [inline]
 __schedule+0x187f/0x4970 kernel/sched/core.c:6710
 schedule+0xc3/0x180 kernel/sched/core.c:6786
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6845
 __mutex_lock_common+0xe6b/0x2380 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x1b/0x30 kernel/locking/mutex.c:799
 __fdget_pos+0x2c1/0x370 fs/file.c:1062
 fdget_pos include/linux/file.h:74 [inline]
 __do_sys_getdents64 fs/readdir.c:365 [inline]
 __se_sys_getdents64+0x1dc/0x4f0 fs/readdir.c:354
 do_syscall_64+0x46/0xc0
 entry_SYSCALL_64_after_hwframe+0x6f/0xd9
RIP: 0033:0x7fc6b007dda9
RSP: 002b:00007fc6b0e5c0c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000d9
RAX: ffffffffffffffda RBX: 00007fc6b01ac050 RCX: 00007fc6b007dda9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000005
RBP: 00007fc6b00ca47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007fc6b01ac050 R15: 00007fff5c668248
 </TASK>
INFO: task syz-executor.0:5556 blocked for more than 146 seconds.
      Not tainted 6.5.0-rc4-syzkaller-00229-g0a2c2baafa31 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0  state:D stack:29360 pid:5556  ppid:5393   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5381 [inline]
 __schedule+0x187f/0x4970 kernel/sched/core.c:6710
 schedule+0xc3/0x180 kernel/sched/core.c:6786
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6845
 __mutex_lock_common+0xe6b/0x2380 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x1b/0x30 kernel/locking/mutex.c:799
 __fdget_pos+0x2c1/0x370 fs/file.c:1062
 fdget_pos include/linux/file.h:74 [inline]
 __do_sys_getdents64 fs/readdir.c:365 [inline]
 __se_sys_getdents64+0x1dc/0x4f0 fs/readdir.c:354
 do_syscall_64+0x46/0xc0
 entry_SYSCALL_64_after_hwframe+0x6f/0xd9
RIP: 0033:0x7ff50387dda9
RSP: 002b:00007ff5045a70c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000d9
RAX: ffffffffffffffda RBX: 00007ff5039ac050 RCX: 00007ff50387dda9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000005
RBP: 00007ff5038ca47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007ff5039ac050 R15: 00007ffeb4f70208
 </TASK>

Showing all locks held in the system:
1 lock held by rcu_tasks_kthre/13:
 #0: ffffffff8d72b470 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x29/0xd30 kernel/rcu/tasks.h:522
1 lock held by rcu_tasks_trace/14:
 #0: ffffffff8d72b830 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x29/0xd30 kernel/rcu/tasks.h:522
1 lock held by khungtaskd/28:
 #0: ffffffff8d72b2a0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
2 locks held by kworker/u4:2/29:
1 lock held by udevd/4478:
2 locks held by getty/4775:
 #0: ffff88814b316098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x80 drivers/tty/tty_ldisc.c:243
 #1: ffffc900015902f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6b1/0x1dc0 drivers/tty/n_tty.c:2187
3 locks held by syz-executor.2/5525:
1 lock held by syz-executor.2/5529:
 #0: ffff88802ba85c48 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2c1/0x370 fs/file.c:1062
3 locks held by syz-executor.1/5537:
1 lock held by syz-executor.1/5544:
 #0: ffff88802bd45248 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2c1/0x370 fs/file.c:1062
3 locks held by syz-executor.4/5541:
1 lock held by syz-executor.4/5547:
 #0: ffff8880294525c8 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2c1/0x370 fs/file.c:1062
3 locks held by syz-executor.3/5550:
1 lock held by syz-executor.3/5555:
 #0: ffff88802d6f8348 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2c1/0x370 fs/file.c:1062
3 locks held by syz-executor.0/5552:
1 lock held by syz-executor.0/5556:
 #0: ffff88802288a848 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2c1/0x370 fs/file.c:1062
1 lock held by syz-executor.1/5838:

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

NMI backtrace for cpu 1
CPU: 1 PID: 28 Comm: khungtaskd Not tainted 6.5.0-rc4-syzkaller-00229-g0a2c2baafa31 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e7/0x2e0 lib/dump_stack.c:106
 nmi_cpu_backtrace+0x49c/0x4d0 lib/nmi_backtrace.c:113
 nmi_trigger_cpumask_backtrace+0x187/0x310 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:222 [inline]
 watchdog+0xec8/0xf10 kernel/hung_task.c:379
 kthread+0x2ec/0x390 kernel/kthread.c:389
 ret_from_fork+0x32/0x60 arch/x86/kernel/process.c:145
 ret_from_fork_asm+0x1b/0x30 arch/x86/entry/entry_64.S:304
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 12278 Comm: syz-executor.1 Not tainted 6.5.0-rc4-syzkaller-00229-g0a2c2baafa31 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
RIP: 0010:smk_access_entry security/smack/smack_access.c:86 [inline]
RIP: 0010:smk_tskacc+0x223/0x360 security/smack/smack_access.c:234
Code: e8 12 bb ee fd 49 8b 36 bf 20 00 00 00 e8 75 1b 00 00 84 c0 74 1e e8 dc 4b 94 fd e9 81 00 00 00 e8 d2 4b 94 fd 45 31 e4 eb 77 <e8> c8 4b 94 fd 45 31 e4 eb 6d e8 be 4b 94 fd 45 89 ec eb 63 48 83
RSP: 0018:ffffc9000392f648 EFLAGS: 00000246
RAX: 1ffff11005d742c4 RBX: ffffffff8dd06320 RCX: ffff88801ab8bb80
RDX: ffff88801ab8bb80 RSI: 0000000000000000 RDI: 00000000ffffffff
RBP: ffff88802eba1620 R08: ffffffff83fbda6b R09: 0000000000000000
R10: ffffc9000392f708 R11: fffff52000725ee5 R12: ffffffff8b7195c0
R13: ffffffff8b7195c0 R14: ffff88802eba1620 R15: dffffc0000000000
FS:  00007fa55a5076c0(0000) GS:ffff8880b9600000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000555557549788 CR3: 000000002b9f4000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 smack_inode_permission+0x2dc/0x380 security/smack/smack_lsm.c:1158
 security_inode_permission+0xa5/0x100 security/security.c:2072
 may_lookup fs/namei.c:1720 [inline]
 link_path_walk+0x2da/0xe80 fs/namei.c:2267
 path_openat+0x249/0x31e0 fs/namei.c:3789
 do_filp_open+0x234/0x490 fs/namei.c:3820
 do_sys_openat2+0x13e/0x1d0 fs/open.c:1407
 do_sys_open fs/open.c:1422 [inline]
 __do_sys_openat fs/open.c:1438 [inline]
 __se_sys_openat fs/open.c:1433 [inline]
 __x64_sys_openat+0x247/0x2a0 fs/open.c:1433
 do_syscall_64+0x46/0xc0
 entry_SYSCALL_64_after_hwframe+0x6f/0xd9
RIP: 0033:0x7fa55987c9a0
Code: 48 89 44 24 20 75 93 44 89 54 24 0c e8 09 82 02 00 44 8b 54 24 0c 89 da 48 89 ee 41 89 c0 bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 77 38 44 89 c7 89 44 24 0c e8 5c 82 02 00 8b 44
RSP: 002b:00007fa55a506e30 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007fa55987c9a0
RDX: 0000000000000002 RSI: 00007fa55a506f40 RDI: 00000000ffffff9c
RBP: 00007fa55a506f40 R08: 0000000000000000 R09: 00000000000014f8
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000004
R13: 00007fa55a506f80 R14: 00007fa55a506f40 R15: 00007fa5507ff000
 </TASK>


Tested on:

commit:         0a2c2baa proc: fix missing conversion to 'iterate_shar..
git tree:       https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=116e4711180000
kernel config:  https://syzkaller.appspot.com/x/.config?x=52460339570262b2
dashboard link: https://syzkaller.appspot.com/bug?extid=f59c2feaf7cb5988e877
compiler:       Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

Note: no patches were applied.