[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <8c6d3196-66db-42cf-aa70-b69e8a210cc1@gmx.com>
Date: Tue, 12 Aug 2025 07:45:17 +0930
From: Qu Wenruo <quwenruo.btrfs@....com>
To: Tejun Heo <tj@...nel.org>, Qu Wenruo <wqu@...e.com>
Cc: syzbot <syzbot+ead9101689c4ca30dbe8@...kaller.appspotmail.com>,
anna-maria@...utronix.de, clm@...com, dsterba@...e.com, frederic@...nel.org,
josef@...icpanda.com, linux-btrfs@...r.kernel.org,
linux-kernel@...r.kernel.org, syzkaller-bugs@...glegroups.com,
tglx@...utronix.de, jiangshanlai@...il.com
Subject: Re: [syzbot] [btrfs?] INFO: task hung in __alloc_workqueue (2)
在 2025/8/12 03:45, Tejun Heo 写道:
> Hello,
>
> On Mon, Aug 11, 2025 at 08:02:40AM +0930, Qu Wenruo wrote:
> ...
>>> Call Trace:
>>> <TASK>
>>> context_switch kernel/sched/core.c:5357 [inline]
>>> __schedule+0x16f3/0x4c20 kernel/sched/core.c:6961
>>> __schedule_loop kernel/sched/core.c:7043 [inline]
>>> schedule+0x165/0x360 kernel/sched/core.c:7058
>>> schedule_timeout+0x9a/0x270 kernel/time/sleep_timeout.c:75
>>> do_wait_for_common kernel/sched/completion.c:100 [inline]
>>> __wait_for_common kernel/sched/completion.c:121 [inline]
>>> wait_for_common kernel/sched/completion.c:132 [inline]
>>> wait_for_completion+0x2bf/0x5d0 kernel/sched/completion.c:153
>>> kthread_flush_worker+0x1c6/0x240 kernel/kthread.c:1563
>>
>> This is flushing pwq_release_worker during error handling, and I didn't see
>> anything btrfs specific except btrfs is allocating an ordered workqueue
>> which utilizes WQ_UNBOUND flag.
>>
>> And that WQ_UNBOUND flag is pretty widely used among other filesystems,
>> maybe it's just btrfs have too many workqueues triggering this?
>>
>> Adding workqueue maintainers.
>
> That flush stall likely is a secondary effect of another failure. The
> kthread worker is already spun up and running and the work function
> pwq_release_workfn() grabs several locks. Maybe someone else is stalling on
> those unless the kthread is somehow not allowed to run? Continued below.
>
>>> Showing all locks held in the system:
>>> 1 lock held by khungtaskd/38:
>>> #0: ffffffff8d9a8b80 (rcu_read_lock){....}-{1:3}, at: rcu_lock_acquire include/linux/rcupdate.h:331 [inline]
>>> #0: ffffffff8d9a8b80 (rcu_read_lock){....}-{1:3}, at: rcu_read_lock include/linux/rcupdate.h:841 [inline]
>>> #0: ffffffff8d9a8b80 (rcu_read_lock){....}-{1:3}, at: debug_show_all_locks+0x2e/0x180 kernel/locking/lockdep.c:6775
>>> 1 lock held by udevd/5207:
>>> #0: ffff8880358bfa18 (&ep->lock){++++}-{3:3}, at: write_lock_irq include/linux/rwlock_rt.h:104 [inline]
>>> #0: ffff8880358bfa18 (&ep->lock){++++}-{3:3}, at: ep_poll fs/eventpoll.c:2127 [inline]
>>> #0: ffff8880358bfa18 (&ep->lock){++++}-{3:3}, at: do_epoll_wait+0x84d/0xbb0 fs/eventpoll.c:2560
>>> 2 locks held by getty/5598:
>>> #0: ffff88823bfae8a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:243
>>> #1: ffffc90003e8b2e0 (&ldata->atomic_read_lock){+.+.}-{4:4}, at: n_tty_read+0x444/0x1410 drivers/tty/n_tty.c:2222
>>> 3 locks held by kworker/u8:3/5911:
>>> 3 locks held by kworker/u8:7/5942:
>>> 6 locks held by udevd/6060:
>>> 1 lock held by udevd/6069:
>>> 1 lock held by udevd/6190:
>>> 6 locks held by udevd/6237:
> ~~~trimmed~~~
>
> That's a lot of locks to be held, so something's not going right for sure.
>
>>> Sending NMI from CPU 1 to CPUs 0:
>>> NMI backtrace for cpu 0
>>> CPU: 0 UID: 0 PID: 5911 Comm: kworker/u8:3 Tainted: G W 6.16.0-syzkaller-11852-g479058002c32 #0 PREEMPT_{RT,(full)}
>>> Tainted: [W]=WARN
>>> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/12/2025
>>> Workqueue: bat_events batadv_iv_send_outstanding_bat_ogm_packet
>>> RIP: 0010:get_timer_this_cpu_base kernel/time/timer.c:939 [inline]
>>> RIP: 0010:__mod_timer+0x81c/0xf60 kernel/time/timer.c:1101
>>> Code: 01 00 00 00 48 8b 5c 24 20 41 0f b6 44 2d 00 84 c0 0f 85 72 06 00 00 8b 2b e8 f0 bb 49 09 41 89 c5 89 c3 bf 08 00 00 00 89 c6 <e8> 0f c1 12 00 41 83 fd 07 44 89 34 24 0f 87 69 06 00 00 e8 4c bc
>>> RSP: 0018:ffffc90004fff680 EFLAGS: 00000082
>>> RAX: 0000000000000000 RBX: 0000000000000000 RCX: f9fab87ca5ec6a00
>>> RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000008
>>> RBP: 0000000000200000 R08: 0000000000000000 R09: 0000000000000000
>>> R10: dffffc0000000000 R11: fffff520009ffeac R12: ffff8880b8825a80
>>> R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000802
>>> FS: 0000000000000000(0000) GS:ffff8881268cd000(0000) knlGS:0000000000000000
>>> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> CR2: 00007f46b6524000 CR3: 000000003afb2000 CR4: 00000000003526f0
>>> Call Trace:
>>> <TASK>
>>> queue_delayed_work_on+0x18b/0x280 kernel/workqueue.c:2559
>>> queue_delayed_work include/linux/workqueue.h:684 [inline]
>>> batadv_forw_packet_queue+0x239/0x2a0 net/batman-adv/send.c:691
>>> batadv_iv_ogm_schedule_buff net/batman-adv/bat_iv_ogm.c:842 [inline]
>>> batadv_iv_ogm_schedule+0x892/0xf00 net/batman-adv/bat_iv_ogm.c:874
>>> batadv_iv_send_outstanding_bat_ogm_packet+0x6c6/0x7e0 net/batman-adv/bat_iv_ogm.c:1714
>>> process_one_work kernel/workqueue.c:3236 [inline]
>>> process_scheduled_works+0xae1/0x17b0 kernel/workqueue.c:3319
>>> worker_thread+0x8a0/0xda0 kernel/workqueue.c:3400
>>> kthread+0x711/0x8a0 kernel/kthread.c:463
>>> ret_from_fork+0x3f9/0x770 arch/x86/kernel/process.c:148
>>> ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245
>>> </TASK>
>
> So, task hung watchdog triggered and making all cpus dump their backtraces
> and it's only one CPU. Is this a two CPU setup in a live lockup? I don't see
> anything apparent and these are time based conditions that can be triggered
> by severely overloading the system too. If you can reproduce the conditions,
That's the problem, it looks like I'm either cursed or really unlucky, I
have a very low chance of reproducibility of syzbot bugs.
And it's the same failed-to-reproduce here.
Thanks,
Qu
> seeing how the system is doing in general and whether the system can unwind
> itself after killing the workload may be useful.
>
> Thanks.
>
Powered by blists - more mailing lists