Re: Raven Ridge xhci_hcd not working: "Refused to change power state, currently in D3"

Re: Raven Ridge xhci_hcd not working: "Refused to change power state, currently in D3"

[Adam Gausmann]

It has been several months since I last posted on this thread, and the issue still persists. However, I have made a discovery!

The issue is nonexistent on fresh installs of Linux. I've tried multiple distributions and haven't been able to reproduce - until I install and activate laptop-mode-tools.

Any advice as to where to go from here?

- Adam

On May 22, 2019 07:23, Greg KH <gregkh@linuxfoundation.org> wrote:
>
> On Wed, May 22, 2019 at 05:54:20AM -0500, Adam Gausmann wrote: 
> > On Wed, May 22, 2019, at 00:51, Greg KH wrote: 
> > > On Tue, May 21, 2019 at 04:49:14PM -0500, Adam Gausmann wrote: 
> > > > On my ThinkPad E585, with a Ryzen 5 2500U, my XHCI driver crashes when plugging in a device after switching power states, or during switching itself. 
> > > > 
> > > > Steps to Reproduce: 
> > > > 
> > > > - Unplug the AC power, or start the computer with AC unplugged. If the computer has AC power at boot, it will work properly, but plugging it in after running unplugged will not. 
> > > > 
> > > > The xhci_hcd and xhci_pci modules remain loaded after the error. Reloading them appears to reset it, and the scenarios above still apply as if the computer was just started. 
> > > > 
> > > > These tests were performed with laptop_mode disabled; enabling it alters the behavior. I will test that more later. 
> > > > 
> > > > Results: 
> > > > 
> > > > The USB device fails to register, and `lsusb` remains unchanged. No other errors will appear after the first one occurs. 
> > > > One of two error messages will appear in kernel logs: 
> > > > 
> > > > [   51.276650] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3 
> > > > [   51.276658] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3 
> > > > [   51.277051] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002) 
> > > > [   51.277074] xhci_hcd 0000:05:00.3: WARN: xHC restore state timeout 
> > > > [   51.277077] xhci_hcd 0000:05:00.3: PCI post-resume error -110! 
> > > > [   51.279316] xhci_hcd 0000:05:00.3: HC died; cleaning up 
> > > > [   51.288669] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002) 
> > > > 
> > > > [ 5258.438021] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3 
> > > > [ 5258.438328] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3 
> > > > [ 5258.450026] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002) 
> > > > [ 5258.450511] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002) 
> > > > [ 5266.112941] xhci_hcd 0000:05:00.3: Error while assigning device slot ID 
> > > > [ 5266.112952] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64. 
> > > > [ 5266.112963] usb usb1-port2: couldn't allocate usb_device 
> > > > [ 5280.960968] xhci_hcd 0000:05:00.3: Error while assigning device slot ID 
> > > > [ 5280.960979] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64. 
> > > > [ 5280.960993] usb usb1-port2: couldn't allocate usb_device 
> > > > 
> > > > Expected results: 
> > > > 
> > > > Device connects, powers on, and registers properly, showing up in `lsusb`. 
> > > > 
> > > > Build: 
> > > > 
> > > > Linux 4.19.44_1 #1 SMP PREEMPT Wed Mar 27 20:41:38 UTC 2019 x86_64 GNU/Linux, with firmware 20181218 
> > > 
> > > 4.19 is pretty old for xhci and normal desktop systems.  Can you please 
> > > try 5.1 and see if that resolves the issue or not? 
> > > 
> > > thanks, 
> > > 
> > > greg k-h 
> > > 
> > 
> > Hi Greg, thanks for your feedback. 
> > 
> > I've just tested this on 5.1.3_1 with the same results as before. I 
> > should also note that I am using the kernel and firmware as packaged 
> > by Void Linux, and these appear to be the latest available from them. 
> > Should I try the latest firmware release from git.kernel.org as well? 
>
> I doubt you have any firmware here, this looks like an xhci issue. 
>
> Can you provide the log messages from 5.1.3?  They might be a bit 
> different. 
>
> thanks, 
>
> greg k-h 

Re: Raven Ridge xhci_hcd not working: "Refused to change power state, currently in D3"

[Greg KH]

On Wed, May 22, 2019 at 05:54:20AM -0500, Adam Gausmann wrote:
> On Wed, May 22, 2019, at 00:51, Greg KH wrote:
> > On Tue, May 21, 2019 at 04:49:14PM -0500, Adam Gausmann wrote:
> > > On my ThinkPad E585, with a Ryzen 5 2500U, my XHCI driver crashes when plugging in a device after switching power states, or during switching itself.
> > > 
> > > Steps to Reproduce: 
> > > 
> > > - Unplug the AC power, or start the computer with AC unplugged. If the computer has AC power at boot, it will work properly, but plugging it in after running unplugged will not.
> > > 
> > > The xhci_hcd and xhci_pci modules remain loaded after the error. Reloading them appears to reset it, and the scenarios above still apply as if the computer was just started.
> > > 
> > > These tests were performed with laptop_mode disabled; enabling it alters the behavior. I will test that more later.
> > > 
> > > Results:
> > > 
> > > The USB device fails to register, and `lsusb` remains unchanged. No other errors will appear after the first one occurs.
> > > One of two error messages will appear in kernel logs:
> > > 
> > > [   51.276650] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
> > > [   51.276658] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
> > > [   51.277051] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
> > > [   51.277074] xhci_hcd 0000:05:00.3: WARN: xHC restore state timeout
> > > [   51.277077] xhci_hcd 0000:05:00.3: PCI post-resume error -110!
> > > [   51.279316] xhci_hcd 0000:05:00.3: HC died; cleaning up
> > > [   51.288669] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)
> > > 
> > > [ 5258.438021] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
> > > [ 5258.438328] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
> > > [ 5258.450026] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
> > > [ 5258.450511] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)
> > > [ 5266.112941] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
> > > [ 5266.112952] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
> > > [ 5266.112963] usb usb1-port2: couldn't allocate usb_device
> > > [ 5280.960968] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
> > > [ 5280.960979] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
> > > [ 5280.960993] usb usb1-port2: couldn't allocate usb_device
> > > 
> > > Expected results: 
> > > 
> > > Device connects, powers on, and registers properly, showing up in `lsusb`.
> > > 
> > > Build: 
> > > 
> > > Linux 4.19.44_1 #1 SMP PREEMPT Wed Mar 27 20:41:38 UTC 2019 x86_64 GNU/Linux, with firmware 20181218
> > 
> > 4.19 is pretty old for xhci and normal desktop systems.  Can you please
> > try 5.1 and see if that resolves the issue or not?
> > 
> > thanks,
> > 
> > greg k-h
> >
> 
> Hi Greg, thanks for your feedback.
> 
> I've just tested this on 5.1.3_1 with the same results as before. I
> should also note that I am using the kernel and firmware as packaged
> by Void Linux, and these appear to be the latest available from them.
> Should I try the latest firmware release from git.kernel.org as well?

I doubt you have any firmware here, this looks like an xhci issue.

Can you provide the log messages from 5.1.3?  They might be a bit
different.

thanks,

greg k-h

Re: Raven Ridge xhci_hcd not working: "Refused to change power state, currently in D3"

[Adam Gausmann]

On Wed, May 22, 2019, at 00:51, Greg KH wrote:
> On Tue, May 21, 2019 at 04:49:14PM -0500, Adam Gausmann wrote:
> > On my ThinkPad E585, with a Ryzen 5 2500U, my XHCI driver crashes when plugging in a device after switching power states, or during switching itself.
> > 
> > Steps to Reproduce: 
> > 
> > - Unplug the AC power, or start the computer with AC unplugged. If the computer has AC power at boot, it will work properly, but plugging it in after running unplugged will not.
> > 
> > The xhci_hcd and xhci_pci modules remain loaded after the error. Reloading them appears to reset it, and the scenarios above still apply as if the computer was just started.
> > 
> > These tests were performed with laptop_mode disabled; enabling it alters the behavior. I will test that more later.
> > 
> > Results:
> > 
> > The USB device fails to register, and `lsusb` remains unchanged. No other errors will appear after the first one occurs.
> > One of two error messages will appear in kernel logs:
> > 
> > [   51.276650] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
> > [   51.276658] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
> > [   51.277051] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
> > [   51.277074] xhci_hcd 0000:05:00.3: WARN: xHC restore state timeout
> > [   51.277077] xhci_hcd 0000:05:00.3: PCI post-resume error -110!
> > [   51.279316] xhci_hcd 0000:05:00.3: HC died; cleaning up
> > [   51.288669] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)
> > 
> > [ 5258.438021] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
> > [ 5258.438328] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
> > [ 5258.450026] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
> > [ 5258.450511] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)
> > [ 5266.112941] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
> > [ 5266.112952] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
> > [ 5266.112963] usb usb1-port2: couldn't allocate usb_device
> > [ 5280.960968] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
> > [ 5280.960979] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
> > [ 5280.960993] usb usb1-port2: couldn't allocate usb_device
> > 
> > Expected results: 
> > 
> > Device connects, powers on, and registers properly, showing up in `lsusb`.
> > 
> > Build: 
> > 
> > Linux 4.19.44_1 #1 SMP PREEMPT Wed Mar 27 20:41:38 UTC 2019 x86_64 GNU/Linux, with firmware 20181218
> 
> 4.19 is pretty old for xhci and normal desktop systems.  Can you please
> try 5.1 and see if that resolves the issue or not?
> 
> thanks,
> 
> greg k-h
>

Hi Greg, thanks for your feedback.

I've just tested this on 5.1.3_1 with the same results as before. I should also note that I am using the kernel and firmware as packaged by Void Linux, and these appear to be the latest available from them.  Should I try the latest firmware release from git.kernel.org as well?

-- 
  Adam Gausmann
  agausmann@fastmail.com

Re: Raven Ridge xhci_hcd not working: "Refused to change power state, currently in D3"

[Greg KH]

On Tue, May 21, 2019 at 04:49:14PM -0500, Adam Gausmann wrote:
> On my ThinkPad E585, with a Ryzen 5 2500U, my XHCI driver crashes when plugging in a device after switching power states, or during switching itself.
> 
> Steps to Reproduce: 
> 
> - Unplug the AC power, or start the computer with AC unplugged. If the computer has AC power at boot, it will work properly, but plugging it in after running unplugged will not.
> 
> The xhci_hcd and xhci_pci modules remain loaded after the error. Reloading them appears to reset it, and the scenarios above still apply as if the computer was just started.
> 
> These tests were performed with laptop_mode disabled; enabling it alters the behavior. I will test that more later.
> 
> Results:
> 
> The USB device fails to register, and `lsusb` remains unchanged. No other errors will appear after the first one occurs.
> One of two error messages will appear in kernel logs:
> 
> [   51.276650] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
> [   51.276658] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
> [   51.277051] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
> [   51.277074] xhci_hcd 0000:05:00.3: WARN: xHC restore state timeout
> [   51.277077] xhci_hcd 0000:05:00.3: PCI post-resume error -110!
> [   51.279316] xhci_hcd 0000:05:00.3: HC died; cleaning up
> [   51.288669] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)
> 
> [ 5258.438021] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
> [ 5258.438328] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
> [ 5258.450026] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
> [ 5258.450511] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)
> [ 5266.112941] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
> [ 5266.112952] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
> [ 5266.112963] usb usb1-port2: couldn't allocate usb_device
> [ 5280.960968] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
> [ 5280.960979] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
> [ 5280.960993] usb usb1-port2: couldn't allocate usb_device
> 
> Expected results: 
> 
> Device connects, powers on, and registers properly, showing up in `lsusb`.
> 
> Build: 
> 
> Linux 4.19.44_1 #1 SMP PREEMPT Wed Mar 27 20:41:38 UTC 2019 x86_64 GNU/Linux, with firmware 20181218

4.19 is pretty old for xhci and normal desktop systems.  Can you please
try 5.1 and see if that resolves the issue or not?

thanks,

greg k-h

Raven Ridge xhci_hcd not working: "Refused to change power state, currently in D3"

[Adam Gausmann]

On my ThinkPad E585, with a Ryzen 5 2500U, my XHCI driver crashes when plugging in a device after switching power states, or during switching itself.

Steps to Reproduce: 

- Unplug the AC power, or start the computer with AC unplugged. If the computer has AC power at boot, it will work properly, but plugging it in after running unplugged will not.

The xhci_hcd and xhci_pci modules remain loaded after the error. Reloading them appears to reset it, and the scenarios above still apply as if the computer was just started.

These tests were performed with laptop_mode disabled; enabling it alters the behavior. I will test that more later.

Results:

The USB device fails to register, and `lsusb` remains unchanged. No other errors will appear after the first one occurs.
One of two error messages will appear in kernel logs:

[   51.276650] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
[   51.276658] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
[   51.277051] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
[   51.277074] xhci_hcd 0000:05:00.3: WARN: xHC restore state timeout
[   51.277077] xhci_hcd 0000:05:00.3: PCI post-resume error -110!
[   51.279316] xhci_hcd 0000:05:00.3: HC died; cleaning up
[   51.288669] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)

[ 5258.438021] xhci_hcd 0000:05:00.3: Refused to change power state, currently in D3
[ 5258.438328] xhci_hcd 0000:05:00.4: Refused to change power state, currently in D3
[ 5258.450026] xhci_hcd 0000:05:00.3: enabling device (0000 -> 0002)
[ 5258.450511] xhci_hcd 0000:05:00.4: enabling device (0000 -> 0002)
[ 5266.112941] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
[ 5266.112952] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
[ 5266.112963] usb usb1-port2: couldn't allocate usb_device
[ 5280.960968] xhci_hcd 0000:05:00.3: Error while assigning device slot ID
[ 5280.960979] xhci_hcd 0000:05:00.3: Max number of devices this xHCI host supports is 64.
[ 5280.960993] usb usb1-port2: couldn't allocate usb_device

Expected results: 

Device connects, powers on, and registers properly, showing up in `lsusb`.

Build: 

Linux 4.19.44_1 #1 SMP PREEMPT Wed Mar 27 20:41:38 UTC 2019 x86_64 GNU/Linux, with firmware 20181218

Has been an issue since 4.19.28 and possibly earlier.

-- 
  Adam Gausmann
  agausmann@fastmail.com