Re: [syzbot] [usb?] INFO: task hung in wdm_release

[Greg KH <gregkh@linuxfoundation.org>]

On Thu, Jun 20, 2024 at 08:47:03PM +0900, Tetsuo Handa wrote:
> On 2024/06/20 19:38, Hillf Danton wrote:
> > On Thu, 20 Jun 2024 02:08:21 -0700
> >> Showing all locks held in the system:
> >> 3 locks held by kworker/u8:0/11:
> >>  #0: ffff8880b953e7d8 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2a/0x140 kernel/sched/core.c:559
> >>  #1: ffff8880b9528948 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x441/0x770 kernel/sched/psi.c:988
> >>  #2: ffff8880754f0768 (&rdev->wiphy.mtx){+.+.}-{3:3}, at: wiphy_lock include/net/cfg80211.h:5966 [inline]
> >>  #2: ffff8880754f0768 (&rdev->wiphy.mtx){+.+.}-{3:3}, at: cfg80211_wiphy_work+0x35/0x260 net/wireless/core.c:424
> > 
> > The info looks bogus given acquiring mutex with runqueue lock held.
> 
> Nothing wrong. Printing the backtrace and/or locks held is not atomic.
> That is, locks held by a non current thread can change at any moment.
> 
> For example, the former block starting with
> "INFO: task syz-executor320:7035 blocked for more than 142 seconds."
> says that pid 7035 is blocked at "mutex_lock(&wdm_mutex)", but the latter
> block starting with "Showing all locks held in the system:" says that
> pid 7035 was holding (or trying to hold) no lock.
> 
> Threads were making progress slowly. Though, printk() flooding by
> 
>   cdc_wdm 5-1:1.0: nonzero urb status received: -71
>   cdc_wdm 5-1:1.0: wdm_int_callback - 0 bytes
> 
> should be avoided. We need to persuade Greg to let these noisy messages reduced.

Please see:
	22f008128625 ("USB: class: cdc-wdm: Fix CPU lockup caused by excessive log messages")
it should have fixed this already.