* Re: [syzbot] [gfs2?] INFO: task hung in freeze_super (3)
2023-01-04 4:01 ` [syzbot] INFO: task hung in freeze_super (3) Hillf Danton
@ 2023-01-04 7:45 ` syzbot
2023-01-08 11:11 ` [syzbot] " Tetsuo Handa
1 sibling, 0 replies; 4+ messages in thread
From: syzbot @ 2023-01-04 7:45 UTC (permalink / raw)
To: agruenba, hdanton, linux-kernel, linux-mm, longman,
penguin-kernel, rpeterso, syzkaller-bugs
Hello,
syzbot has tested the proposed patch but the reproducer is still triggering an issue:
possible deadlock in freeze_super
======================================================
WARNING: possible circular locking dependency detected
6.2.0-rc2-syzkaller-00127-g69b41ac87e4a-dirty #0 Not tainted
------------------------------------------------------
kworker/1:1H/93 is trying to acquire lock:
ffff88802666e0e0 (&type->s_umount_key#50){+.+.}-{3:3}, at: freeze_super+0x45/0x420 fs/super.c:1655
but task is already holding lock:
ffffc90002587d00 ((work_completion)(&(&gl->gl_work)->work)){+.+.}-{0:0}, at: process_one_work+0x831/0xdb0 kernel/workqueue.c:2264
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #2 ((work_completion)(&(&gl->gl_work)->work)){+.+.}-{0:0}:
lock_acquire+0x182/0x3c0 kernel/locking/lockdep.c:5668
process_one_work+0x852/0xdb0 kernel/workqueue.c:2265
worker_thread+0xb14/0x1330 kernel/workqueue.c:2436
kthread+0x266/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
-> #1 ((wq_completion)glock_workqueue){+.+.}-{0:0}:
lock_acquire+0x182/0x3c0 kernel/locking/lockdep.c:5668
__flush_workqueue+0x17c/0x16d0 kernel/workqueue.c:2809
gfs2_gl_hash_clear+0xa3/0x300 fs/gfs2/glock.c:2191
gfs2_put_super+0x862/0x8d0 fs/gfs2/super.c:627
generic_shutdown_super+0x130/0x310 fs/super.c:492
kill_block_super+0x79/0xd0 fs/super.c:1386
deactivate_locked_super+0xa7/0xf0 fs/super.c:332
cleanup_mnt+0x494/0x520 fs/namespace.c:1291
task_work_run+0x243/0x300 kernel/task_work.c:179
resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
exit_to_user_mode_loop+0x124/0x150 kernel/entry/common.c:171
exit_to_user_mode_prepare+0xb2/0x140 kernel/entry/common.c:203
__syscall_exit_to_user_mode_work kernel/entry/common.c:285 [inline]
syscall_exit_to_user_mode+0x26/0x60 kernel/entry/common.c:296
do_syscall_64+0x49/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x63/0xcd
-> #0 (&type->s_umount_key#50){+.+.}-{3:3}:
check_prev_add kernel/locking/lockdep.c:3097 [inline]
check_prevs_add kernel/locking/lockdep.c:3216 [inline]
validate_chain+0x1898/0x6ae0 kernel/locking/lockdep.c:3831
__lock_acquire+0x1292/0x1f60 kernel/locking/lockdep.c:5055
lock_acquire+0x182/0x3c0 kernel/locking/lockdep.c:5668
down_write+0x9c/0x270 kernel/locking/rwsem.c:1562
freeze_super+0x45/0x420 fs/super.c:1655
freeze_go_sync+0x178/0x340 fs/gfs2/glops.c:577
do_xmote+0x34d/0x13d0 fs/gfs2/glock.c:708
glock_work_func+0x2c2/0x450 fs/gfs2/glock.c:1056
process_one_work+0x877/0xdb0 kernel/workqueue.c:2289
worker_thread+0xb14/0x1330 kernel/workqueue.c:2436
kthread+0x266/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
other info that might help us debug this:
Chain exists of:
&type->s_umount_key#50 --> (wq_completion)glock_workqueue --> (work_completion)(&(&gl->gl_work)->work)
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock((work_completion)(&(&gl->gl_work)->work));
lock((wq_completion)glock_workqueue);
lock((work_completion)(&(&gl->gl_work)->work));
lock(&type->s_umount_key#50);
*** DEADLOCK ***
2 locks held by kworker/1:1H/93:
#0: ffff888012bf7d38 ((wq_completion)glock_workqueue){+.+.}-{0:0}, at: process_one_work+0x7f2/0xdb0
#1: ffffc90002587d00 ((work_completion)(&(&gl->gl_work)->work)){+.+.}-{0:0}, at: process_one_work+0x831/0xdb0 kernel/workqueue.c:2264
stack backtrace:
CPU: 1 PID: 93 Comm: kworker/1:1H Not tainted 6.2.0-rc2-syzkaller-00127-g69b41ac87e4a-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 10/26/2022
Workqueue: glock_workqueue glock_work_func
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x1b1/0x290 lib/dump_stack.c:106
check_noncircular+0x2cc/0x390 kernel/locking/lockdep.c:2177
check_prev_add kernel/locking/lockdep.c:3097 [inline]
check_prevs_add kernel/locking/lockdep.c:3216 [inline]
validate_chain+0x1898/0x6ae0 kernel/locking/lockdep.c:3831
__lock_acquire+0x1292/0x1f60 kernel/locking/lockdep.c:5055
lock_acquire+0x182/0x3c0 kernel/locking/lockdep.c:5668
down_write+0x9c/0x270 kernel/locking/rwsem.c:1562
freeze_super+0x45/0x420 fs/super.c:1655
freeze_go_sync+0x178/0x340 fs/gfs2/glops.c:577
do_xmote+0x34d/0x13d0 fs/gfs2/glock.c:708
glock_work_func+0x2c2/0x450 fs/gfs2/glock.c:1056
process_one_work+0x877/0xdb0 kernel/workqueue.c:2289
worker_thread+0xb14/0x1330 kernel/workqueue.c:2436
kthread+0x266/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:308
</TASK>
Tested on:
commit: 69b41ac8 Merge tag 'for-6.2-rc2-tag' of git://git.kern..
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=154506dc480000
kernel config: https://syzkaller.appspot.com/x/.config?x=9babfdc3dd4772d0
dashboard link: https://syzkaller.appspot.com/bug?extid=f51cb4b9afbd87ec06f2
compiler: Debian clang version 13.0.1-++20220126092033+75e33f71c2da-1~exp1~20220126212112.63, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=11d59a52480000
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: [syzbot] INFO: task hung in freeze_super (3)
2023-01-04 4:01 ` [syzbot] INFO: task hung in freeze_super (3) Hillf Danton
2023-01-04 7:45 ` [syzbot] [gfs2?] " syzbot
@ 2023-01-08 11:11 ` Tetsuo Handa
2023-01-08 12:07 ` Hillf Danton
1 sibling, 1 reply; 4+ messages in thread
From: Tetsuo Handa @ 2023-01-08 11:11 UTC (permalink / raw)
To: Hillf Danton, Tejun Heo
Cc: agruenba, linux-mm, Waiman Long, linux-kernel, rpeterso,
syzkaller-bugs, syzbot
On 2023/01/04 13:01, Hillf Danton wrote:
> On 09 Dec 2022 01:08:38 -0800
>> syzbot found the following issue on:
>>
>> HEAD commit: f3e8416619ce Merge tag 'soc-fixes-6.1-5' of git://git.kern..
>> git tree: upstream
>> console+strace: https://syzkaller.appspot.com/x/log.txt?x=12fb534d880000
>> kernel config: https://syzkaller.appspot.com/x/.config?x=d58e7fe7f9cf5e24
>> dashboard link: https://syzkaller.appspot.com/bug?extid=f51cb4b9afbd87ec06f2
>> compiler: Debian clang version 13.0.1-++20220126092033+75e33f71c2da-1~exp1~20220126212112.63, GNU ld (GNU Binutils for Debian) 2.35.2
>> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=123d216b880000
>> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=16e46f5b880000
>>
>> Downloadable assets:
>> disk image: https://storage.googleapis.com/syzbot-assets/628abc27cbe7/disk-f3e84166.raw.xz
>> vmlinux: https://storage.googleapis.com/syzbot-assets/2f19ea836174/vmlinux-f3e84166.xz
>> kernel image: https://storage.googleapis.com/syzbot-assets/f2e1347e85a5/bzImage-f3e84166.xz
>> mounted in repro: https://storage.googleapis.com/syzbot-assets/c239a19c8749/mount_0.gz
>>
>> IMPORTANT: if you fix the issue, please add the following tag to the commit:
>> Reported-by: syzbot+f51cb4b9afbd87ec06f2@syzkaller.appspotmail.com
>>
>> INFO: task kworker/0:1H:120 blocked for more than 143 seconds.
>> Not tainted 6.1.0-rc8-syzkaller-00035-gf3e8416619ce #0
>> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>> task:kworker/0:1H state:D stack:23480 pid:120 ppid:2 flags:0x00004000
>> Workqueue: glock_workqueue glock_work_func
>> Call Trace:
>> <TASK>
>> context_switch kernel/sched/core.c:5209 [inline]
>> __schedule+0x8c9/0xd70 kernel/sched/core.c:6521
>> schedule+0xcb/0x190 kernel/sched/core.c:6597
>> rwsem_down_write_slowpath+0xfc1/0x1480 kernel/locking/rwsem.c:1190
>> __down_write_common kernel/locking/rwsem.c:1305 [inline]
>> __down_write kernel/locking/rwsem.c:1314 [inline]
>> down_write+0x231/0x270 kernel/locking/rwsem.c:1563
>> freeze_super+0x45/0x420 fs/super.c:1697
>> freeze_go_sync+0x178/0x340 fs/gfs2/glops.c:573
>> do_xmote+0x34d/0x13d0 fs/gfs2/glock.c:776
>> glock_work_func+0x2c2/0x450 fs/gfs2/glock.c:1082
>> process_one_work+0x877/0xdb0 kernel/workqueue.c:2289
>> worker_thread+0xb14/0x1330 kernel/workqueue.c:2436
>> kthread+0x266/0x300 kernel/kthread.c:376
>> ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
>> </TASK>
>> INFO: task syz-executor330:3631 blocked for more than 143 seconds.
>> Not tainted 6.1.0-rc8-syzkaller-00035-gf3e8416619ce #0
>> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>> task:syz-executor330 state:D stack:20176 pid:3631 ppid:3630 flags:0x00004004
>> Call Trace:
>> <TASK>
>> context_switch kernel/sched/core.c:5209 [inline]
>> __schedule+0x8c9/0xd70 kernel/sched/core.c:6521
>> schedule+0xcb/0x190 kernel/sched/core.c:6597
>> schedule_timeout+0x98/0x2f0 kernel/time/timer.c:1911
>> do_wait_for_common+0x3ea/0x560 kernel/sched/completion.c:85
>> __wait_for_common kernel/sched/completion.c:106 [inline]
>> wait_for_common kernel/sched/completion.c:117 [inline]
>> wait_for_completion+0x46/0x60 kernel/sched/completion.c:138
>> __flush_workqueue+0x74a/0x1680 kernel/workqueue.c:2861
>> gfs2_gl_hash_clear+0xbe/0x300 fs/gfs2/glock.c:2262
>> gfs2_fill_super+0x2202/0x2700 fs/gfs2/ops_fstype.c:1307
>> get_tree_bdev+0x400/0x620 fs/super.c:1324
>> gfs2_get_tree+0x50/0x210 fs/gfs2/ops_fstype.c:1330
>> vfs_get_tree+0x88/0x270 fs/super.c:1531
>> do_new_mount+0x289/0xad0 fs/namespace.c:3040
>> do_mount fs/namespace.c:3383 [inline]
>> __do_sys_mount fs/namespace.c:3591 [inline]
>> __se_sys_mount+0x2d3/0x3c0 fs/namespace.c:3568
>> do_syscall_x64 arch/x86/entry/common.c:50 [inline]
>> do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
>> entry_SYSCALL_64_after_hwframe+0x63/0xcd
>> RIP: 0033:0x7f19da3f458a
>> RSP: 002b:00007ffd6b2d69e8 EFLAGS: 00000282 ORIG_RAX: 00000000000000a5
>> RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007f19da3f458a
>> RDX: 0000000020000040 RSI: 000000002003b300 RDI: 00007ffd6b2d6a00
>> RBP: 00007ffd6b2d6a00 R08: 00007ffd6b2d6a40 R09: 0000000000000002
>> R10: 0000000000000000 R11: 0000000000000282 R12: 0000000000000004
>> R13: 0000555556b0d2c0 R14: 0000000000000000 R15: 00007ffd6b2d6a40
>> </TASK>
>>
>> Showing all locks held in the system:
>> 1 lock held by rcu_tasks_kthre/12:
>> #0: ffffffff8d127330 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x30/0xd00 kernel/rcu/tasks.h:507
>> 1 lock held by rcu_tasks_trace/13:
>> #0: ffffffff8d127b30 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x30/0xd00 kernel/rcu/tasks.h:507
>> 1 lock held by khungtaskd/28:
>> #0: ffffffff8d127160 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
>> 3 locks held by kworker/0:1H/120:
>> #0: ffff8880194f5d38 ((wq_completion)glock_workqueue){+.+.}-{0:0}, at: process_one_work+0x7f2/0xdb0
>> #1: ffffc90002587d00 ((work_completion)(&(&gl->gl_work)->work)){+.+.}-{0:0}, at: process_one_work+0x831/0xdb0 kernel/workqueue.c:2264
>> #2: ffff888026c2c0e0 (&type->s_umount_key#42){+.+.}-{3:3}, at: freeze_super+0x45/0x420 fs/super.c:1697
>> 2 locks held by getty/3308:
>> #0: ffff888028211098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:244
>> #1: ffffc900031262f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x53b/0x1650 drivers/tty/n_tty.c:2177
>> 1 lock held by syz-executor330/3631:
>> #0: ffff888026c2c0e0 (&type->s_umount_key#41/1){+.+.}-{3:3}, at: alloc_super+0x212/0x920 fs/super.c:228
>>
>
> syz-executor330/3631 kworker/0:1H/120
> --- ---
> down_write_nested(&s->s_umount);
> glock_work_func()
> down_write(&sb->s_umount);
> flush_workqueue(glock_workqueue);
>
>
> No deadlock is reported yet. Whyyy?
> See if extending the aperture of wq->lockdep_map can catch it.
As far as I tested, this patch did not change likeliness of hitting lockdep warning.
I feel that it was just by chance that this test request was able to hit lockdep warning.
>
> #syz test https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
>
> --- x/kernel/workqueue.c
> +++ y/kernel/workqueue.c
> @@ -2807,7 +2807,6 @@ void __flush_workqueue(struct workqueue_
> return;
>
> lock_map_acquire(&wq->lockdep_map);
> - lock_map_release(&wq->lockdep_map);
>
> mutex_lock(&wq->mutex);
>
> @@ -2867,7 +2866,7 @@ void __flush_workqueue(struct workqueue_
> * handling overflow. Non-first flushers can simply return.
> */
> if (READ_ONCE(wq->first_flusher) != &this_flusher)
> - return;
> + goto out;
>
> mutex_lock(&wq->mutex);
>
> @@ -2942,6 +2941,8 @@ void __flush_workqueue(struct workqueue_
>
> out_unlock:
> mutex_unlock(&wq->mutex);
> +out:
> + lock_map_release(&wq->lockdep_map);
> }
> EXPORT_SYMBOL(__flush_workqueue);
>
> --
^ permalink raw reply [flat|nested] 4+ messages in thread