New: [Bisected] [Regression] xhci_hcd: Resuming from hibernation fails with "Not enough host resources"

https://bugzilla.kernel.org/show_bug.cgi?id=222071

Bug ID: 222071
Summary: [Bisected] [Regression] xhci_hcd: Resuming from
hibernation fails with "Not enough host resources"
Product: Drivers
Version: 2.5
Hardware: All
OS: Linux
Status: NEW
Severity: normal
Priority: P3
Component: USB
Assignee: [email protected]
Reporter: [email protected]
Regression: No

Created attachment 310955
--> https://bugzilla.kernel.org/attachment.cgi?id=310955&action=edit
dmesg-7.2.6.bz2

Commit 2a70e5dc0301ad961b198f086a39e2479f6b8933 "usb: xhci: optimize resuming from S4 (suspend-to-disk)" causes hibernate/resume cycles to fail.
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=2a70e5dc0301ad961b198f086a39e2479f6b8933
Reverting it seems to make it good again.

dmesg excerpt:
usb 2-1.1.2: device descriptor read/64, error -32
xhci_hcd 0000:00:14.0: Not enough host resources, active endpoint contexts = 63 usb 2-1.1.2: Busted HC? Not enough HCD resources for old configuration. OOM killer enabled.
Restarting tasks: Starting
usb 2-1.1.2: USB disconnect, device number 5
Restarting tasks: Done
PM: hibernation: hibernation exit
usb 2-1.1.2: new full-speed USB device number 6 using xhci_hcd
usb 2-1.1.2: device descriptor read/64, error -32
xhci_hcd 0000:00:14.0: Not enough host resources, active endpoint contexts = 63 usb 2-1.1.2: can't set config #1, error -12

I will of course attach the full logs (one from today with kernel 7.2.6 and an older one with kernel 7.1.1).

Maybe something does not get cleaned up properly, because it starts happen after a few cycles?

I will later also attach a dmesg with the commit reverted.

lsusb -tv after failure:
/: Bus 001.Port 001: Dev 001, Class=root_hub, Driver=ehci-pci/2p, 480M
ID 1d6b:0002 Linux Foundation 2.0 root hub
|__ Port 001: Dev 002, If 0, Class=Hub, Driver=hub/8p, 480M
ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
/: Bus 002.Port 001: Dev 001, Class=root_hub, Driver=xhci_hcd/4p, 480M
ID 1d6b:0002 Linux Foundation 2.0 root hub
|__ Port 001: Dev 007, 480M
ID 0bda:5411 Realtek Semiconductor Corp. RTS5411 Hub
/: Bus 003.Port 001: Dev 001, Class=root_hub, Driver=ehci-pci/2p, 480M
ID 1d6b:0002 Linux Foundation 2.0 root hub
|__ Port 001: Dev 002, If 0, Class=Hub, Driver=hub/6p, 480M
ID 8087:0024 Intel Corp. Integrated Rate Matching Hub |__ Port 002: Dev 003, If 0, Class=Human Interface Device,
Driver=usbhid, 12M

            ID 258a:002f  
        |__ Port 002: Dev 003, If 1, Class=Human Interface Device,
Driver=usbhid, 12M
            ID 258a:002f  
        |__ Port 004: Dev 004, If 0, Class=Mass Storage, Driver=usb-storage,

480M
ID 058f:6366 Alcor Micro Corp. Multi Flash Reader
/: Bus 004.Port 001: Dev 001, Class=root_hub, Driver=xhci_hcd/4p, 5000M
ID 1d6b:0003 Linux Foundation 3.0 root hub
/: Bus 005.Port 001: Dev 001, Class=root_hub, Driver=xhci_hcd/2p, 480M
ID 1d6b:0002 Linux Foundation 2.0 root hub
/: Bus 006.Port 001: Dev 001, Class=root_hub, Driver=xhci_hcd/2p, 5000M
ID 1d6b:0003 Linux Foundation 3.0 root hub

Interestingly, the Realtek Semiconductor Corp. RTS5411 Hub still gets recognized, but no devices.
/: Bus 002.Port 001: Dev 001, Class=root_hub, Driver=xhci_hcd/4p, 480M
ID 1d6b:0002 Linux Foundation 2.0 root hub
|__ Port 001: Dev 009, 480M
ID 0bda:5411 Realtek Semiconductor Corp. RTS5411 Hub

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

Harald Judt ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #1 from Harald Judt ([email protected]) ---
Created attachment 310956
--> https://bugzilla.kernel.org/attachment.cgi?id=310956&action=edit
dmesg-7.1.1.bz2

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #2 from Harald Judt ([email protected]) ---
Created attachment 310962
--> https://bugzilla.kernel.org/attachment.cgi?id=310962&action=edit
dmesg-7.2.8-commit-reverted.bz2

For comparison, only one hibernate/resume cycle. I know its not the same kernel version, but as far as I can tell, this does not make any difference.

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

Lovekesh Solanki ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #3 from Lovekesh Solanki ([email protected]) --- Seems like num_active_eps present in xhci_hcd does not get reset and accumulates. You'd have to do at least 3 resume cycles to reproduce it I think.. Could you test the patch I'm attaching. Try like 4-5 cycles.

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #4 from Lovekesh Solanki ([email protected]) --- Created attachment 310970
--> https://bugzilla.kernel.org/attachment.cgi?id=310970&action=edit
Set num_active_eps = 0 in xhci_resume()

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #5 from Harald Judt ([email protected]) ---
Thanks for the patch, I've gave it a quick test and after 4-5 hibernate/resume cycles it looked good at first, but then similar symptoms. Though, the error message changed, so something else might still be missing?

Also note the Suspend Save Error, I believe I have already seen this in dmesg-7.1.1.

[  487.224692] Freezing remaining freezable tasks
[  487.225435] Freezing remaining freezable tasks completed (elapsed 0.000
seconds)
[  490.706989] PM: hibernation: Preallocating image memory
[  491.227735] PM: hibernation: Allocated 1677392 pages for snapshot
[  491.227739] PM: hibernation: Allocated 6709568 kbytes in 0.52 seconds
(12903.01 MB/s)
[  491.227742] printk: Suspending console(s) (use no_console_suspend to debug)
[  491.230837] serial 00:00: disabled
[  491.249637] xhci_hcd 0000:09:00.0: Suspend Save Error (SRE), USBSTS
0x00000401
[  491.620480] amdgpu 0000:03:00.0: MODE1 reset
[  491.620485] amdgpu 0000:03:00.0: GPU mode1 reset
[  491.620532] amdgpu 0000:03:00.0: GPU smu mode1 reset
[  492.125327] Disabling non-boot CPUs ...
[  492.126636] smpboot: CPU 7 is now offline
[  492.128437] smpboot: CPU 6 is now offline
[  492.130144] smpboot: CPU 5 is now offline
[  492.132100] smpboot: CPU 4 is now offline

[...]

Now the new messages:

[  493.491022] xhci_hcd 0000:00:14.0: Not enough bandwidth on HS bus for newly
activated TT.
[  493.491024] xhci_hcd 0000:00:14.0: Not enough bandwidth
[  493.491027] usb 2-1.1.1: Busted HC?  Not enough HCD resources for old
configuration.
[  493.563490] usb 2-1.1.2: reset full-speed USB device number 5 using xhci_hcd
[  493.637648] usb 2-1.1.2: device descriptor read/64, error -32
[  493.823352] xhci_hcd 0000:00:14.0: Not enough bandwidth on HS bus for newly
activated TT.
[  493.823354] xhci_hcd 0000:00:14.0: Not enough bandwidth
[  493.823357] usb 2-1.1.2: Busted HC?  Not enough HCD resources for old
configuration.
[  493.827971] OOM killer enabled.
[  493.827973] Restarting tasks: Starting
[  493.829006] Restarting tasks: Done
[  493.829020] PM: hibernation: hibernation exit
[  493.829329] usb 2-1.1.1: USB disconnect, device number 4
[  494.005427] usb 2-1.1.1: new full-speed USB device number 6 using xhci_hcd
[  494.091135] xhci_hcd 0000:00:14.0: Not enough bandwidth on HS bus for newly
activated TT.
[  494.091139] xhci_hcd 0000:00:14.0: Not enough bandwidth
[  494.091142] usb 2-1.1.1: can't set config #1, error -12
[  494.091830] usb 2-1.1.2: USB disconnect, device number 5
[  494.172431] usb 2-1.1.2: new full-speed USB device number 7 using xhci_hcd
[  494.245591] usb 2-1.1.2: device descriptor read/64, error -32
[  494.431958] xhci_hcd 0000:00:14.0: Not enough bandwidth on HS bus for newly
activated TT.
[  494.431963] xhci_hcd 0000:00:14.0: Not enough bandwidth
[  494.431967] usb 2-1.1.2: can't set config #1, error -12
[  494.619736] ntfs: volume version 3.1, dev sdc1, cluster size 4096

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #6 from Harald Judt ([email protected]) ---
I also wonder why I do not see this on my 3 other systems. Could it be related to the USB hub attached to this machine?

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

Michał Pecio ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #7 from Michał Pecio ([email protected]) --- Some old Intel chipsets can't calculate bandwidth allocation themselves and need babysitting by the driver. You seem to have one of those. The bug(s) can likely be reproduced on any hardware by specifying xhci_hcd.quirks=0x120.

With quirks=0x1a0 one may not even need hibernation, only suspend.

The other controller is ASM1042, one of the oldest and buggiest. Mine does the same, even with zero connected devices. Maybe they just don't support this.

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #8 from Harald Judt ([email protected]) ---
Thanks for the explanation. It is indeed an old mainboard with old chipsets, but it still serves me well, and when I replace it it will probably have its place somewhere else until it dies. Is there some quirk that makes these controllers reset themselves like they did before that commit? Reverting the patch helps now, but is not very future-proof.

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #9 from Michał Pecio ([email protected]) ---

The problem is not with HW but with SW - "optimize resuming from S4" broke bandwidth calculations which the driver performs for old HW that cannot do them itself. That's why new HW works without issues.

The driver obviously needs to be fixed, maybe Lovekesh will find the remaining issues (already found one), or if not, I am alerting the original culprits right now.

IMHO reverting this in mainline would be fine too - the "optimization" is negligible while it costs bugs and copy-pasted code.

Regards,
Michal

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

Niklas Neronin ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #10 from Niklas Neronin ([email protected]) --- I have found a other issues related to XHCI_EP_LIMIT_QUIRK, so I'll try to come up with a permanent fix for all of them.

IIRC the reason behind the original "optimization" was to prepare the driver for secondary interrupter support. There was an issue where the secondary interrupters would be lost after resume. The patch was intended to prevent that by keeping the 'xhci->interrupters' array intact.

Thanks,
Niklas

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #11 from Niklas Neronin ([email protected]) --- Created attachment 310987
--> https://bugzilla.kernel.org/attachment.cgi?id=310987&action=edit
Test patch to fix S4 resume failures when using software tracked bandwidth

Could someone with the relevant HW please give this patch a try and run a few suspend/resume cycles?
For convenience, I included the fix from Lovekesh Solanki for testing.

Thanks,
Niklas

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #12 from Harald Judt ([email protected]) ---
Thanks, with this test patch applied, 7 hibernate/resume cycles in a row have been successful.

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

Niklas Neronin ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

 Attachment #310987|0                           |1

is obsolete| |

--- Comment #13 from Niklas Neronin ([email protected]) --- Created attachment 311006
--> https://bugzilla.kernel.org/attachment.cgi?id=311006&action=edit
V2 fix S4 resume failures when using software tracked bandwidth

@Harald Judt, could you please give the v2 patch a try? If it works as expected, I hope to submit it before next merge window.

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.kernel.org/show_bug.cgi?id=222071

--- Comment #14 from Harald Judt ([email protected]) --- Successfully tested 8 hibernate/resume cycles with v2 of the patch on linux-stable-7.2.9. Additionally I did some tests with an USB stick and a bluetooth adapter and all seems fine.

You may reply to this email to add a comment.

You are receiving this mail because:
You are watching the assignee of the bug.