On the Librem 5 imx8mq system we've seen the stop endpoint command
time out regularly which results in the hub dying.
While on the one hand we see "Port resume timed out, port 1-1: 0xfe3"
before this and on the other hand driver-comments suggest that the driver
might be able to recover instead of dying here, Sarah seemed to have a
workaround for this particulator problem in mind already:
Make it a module parameter. So while it might not be the root cause for
the problem, do this to give users a workaround.
Signed-off-by: Martin Kepplinger <[email protected]>
---
drivers/usb/host/xhci-ring.c | 2 +-
drivers/usb/host/xhci.c | 8 +++++++-
drivers/usb/host/xhci.h | 3 +--
3 files changed, 9 insertions(+), 4 deletions(-)
diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index d0b6806275e0..e631d408e6b2 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -1133,7 +1133,7 @@ static void xhci_handle_cmd_stop_ep(struct xhci_hcd *xhci, int slot_id,
xhci_stop_watchdog_timer_in_irq(xhci, ep);
mod_timer(&ep->stop_cmd_timer,
- jiffies + XHCI_STOP_EP_CMD_TIMEOUT * HZ);
+ jiffies + xhci->stop_ep_cmd_timeout * HZ);
xhci_queue_stop_endpoint(xhci, command, slot_id, ep_index, 0);
xhci_ring_cmd_db(xhci);
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index a1c781f70d02..37fd05e75dcf 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -37,6 +37,11 @@ static unsigned long long quirks;
module_param(quirks, ullong, S_IRUGO);
MODULE_PARM_DESC(quirks, "Bit flags for quirks to be enabled as default");
+static unsigned int stop_ep_cmd_timeout = 5;
+module_param(stop_ep_cmd_timeout, uint, S_IRUGO | S_IWUSR);
+MODULE_PARM_DESC(stop_ep_cmd_timeout,
+ "Stop endpoint command timeout (secs) for URB cancel watchdog. default=5");
+
static bool td_on_ring(struct xhci_td *td, struct xhci_ring *ring)
{
struct xhci_segment *seg = ring->first_seg;
@@ -1849,7 +1854,7 @@ static int xhci_urb_dequeue(struct usb_hcd *hcd, struct urb *urb, int status)
}
ep->ep_state |= EP_STOP_CMD_PENDING;
ep->stop_cmd_timer.expires = jiffies +
- XHCI_STOP_EP_CMD_TIMEOUT * HZ;
+ xhci->stop_ep_cmd_timeout * HZ;
add_timer(&ep->stop_cmd_timer);
xhci_queue_stop_endpoint(xhci, command, urb->dev->slot_id,
ep_index, 0);
@@ -5288,6 +5293,7 @@ int xhci_gen_setup(struct usb_hcd *hcd, xhci_get_quirks_t get_quirks)
xhci->hcc_params2 = readl(&xhci->cap_regs->hcc_params2);
xhci->quirks |= quirks;
+ xhci->stop_ep_cmd_timeout = stop_ep_cmd_timeout;
get_quirks(dev, xhci);
diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h
index 8a0026ee9524..80c9ced4a276 100644
--- a/drivers/usb/host/xhci.h
+++ b/drivers/usb/host/xhci.h
@@ -1674,8 +1674,6 @@ struct urb_priv {
#define ERST_NUM_SEGS 1
/* Poll every 60 seconds */
#define POLL_TIMEOUT 60
-/* Stop endpoint command timeout (secs) for URB cancellation watchdog timer */
-#define XHCI_STOP_EP_CMD_TIMEOUT 5
/* XXX: Make these module parameters */
struct s3_save {
@@ -1899,6 +1897,7 @@ struct xhci_hcd {
#define XHCI_BROKEN_D3COLD BIT_ULL(41)
#define XHCI_EP_CTX_BROKEN_DCS BIT_ULL(42)
+ unsigned int stop_ep_cmd_timeout;
unsigned int num_active_eps;
unsigned int limit_active_eps;
struct xhci_port *hw_ports;
--
2.30.2
Am Freitag, dem 04.03.2022 um 12:30 +0100 schrieb Martin Kepplinger:
> On the Librem 5 imx8mq system we've seen the stop endpoint command
> time out regularly which results in the hub dying.
sorry this is pretty useless information. We see this on an internal
USB2642 USB 2.0 Hub by Microchip.
>
> While on the one hand we see "Port resume timed out, port 1-1: 0xfe3"
> before this and on the other hand driver-comments suggest that the
> driver
> might be able to recover instead of dying here, Sarah seemed to have
> a
> workaround for this particulator problem in mind already:
>
> Make it a module parameter. So while it might not be the root cause
> for
> the problem, do this to give users a workaround.
>
> Signed-off-by: Martin Kepplinger <[email protected]>
> ---
> drivers/usb/host/xhci-ring.c | 2 +-
> drivers/usb/host/xhci.c | 8 +++++++-
> drivers/usb/host/xhci.h | 3 +--
> 3 files changed, 9 insertions(+), 4 deletions(-)
>
> diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-
> ring.c
> index d0b6806275e0..e631d408e6b2 100644
> --- a/drivers/usb/host/xhci-ring.c
> +++ b/drivers/usb/host/xhci-ring.c
> @@ -1133,7 +1133,7 @@ static void xhci_handle_cmd_stop_ep(struct
> xhci_hcd *xhci, int slot_id,
> xhci_stop_watchdog_timer_in_irq(xhci,
> ep);
>
> mod_timer(&ep->stop_cmd_timer,
> - jiffies + XHCI_STOP_EP_CMD_TIMEOUT
> * HZ);
> + jiffies + xhci->stop_ep_cmd_timeout
> * HZ);
> xhci_queue_stop_endpoint(xhci, command,
> slot_id, ep_index, 0);
> xhci_ring_cmd_db(xhci);
>
> diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
> index a1c781f70d02..37fd05e75dcf 100644
> --- a/drivers/usb/host/xhci.c
> +++ b/drivers/usb/host/xhci.c
> @@ -37,6 +37,11 @@ static unsigned long long quirks;
> module_param(quirks, ullong, S_IRUGO);
> MODULE_PARM_DESC(quirks, "Bit flags for quirks to be enabled as
> default");
>
> +static unsigned int stop_ep_cmd_timeout = 5;
> +module_param(stop_ep_cmd_timeout, uint, S_IRUGO | S_IWUSR);
> +MODULE_PARM_DESC(stop_ep_cmd_timeout,
> + "Stop endpoint command timeout (secs) for URB cancel
> watchdog. default=5");
> +
> static bool td_on_ring(struct xhci_td *td, struct xhci_ring *ring)
> {
> struct xhci_segment *seg = ring->first_seg;
> @@ -1849,7 +1854,7 @@ static int xhci_urb_dequeue(struct usb_hcd
> *hcd, struct urb *urb, int status)
> }
> ep->ep_state |= EP_STOP_CMD_PENDING;
> ep->stop_cmd_timer.expires = jiffies +
> - XHCI_STOP_EP_CMD_TIMEOUT * HZ;
> + xhci->stop_ep_cmd_timeout * HZ;
> add_timer(&ep->stop_cmd_timer);
> xhci_queue_stop_endpoint(xhci, command, urb->dev-
> >slot_id,
> ep_index, 0);
> @@ -5288,6 +5293,7 @@ int xhci_gen_setup(struct usb_hcd *hcd,
> xhci_get_quirks_t get_quirks)
> xhci->hcc_params2 = readl(&xhci->cap_regs-
> >hcc_params2);
>
> xhci->quirks |= quirks;
> + xhci->stop_ep_cmd_timeout = stop_ep_cmd_timeout;
>
> get_quirks(dev, xhci);
>
> diff --git a/drivers/usb/host/xhci.h b/drivers/usb/host/xhci.h
> index 8a0026ee9524..80c9ced4a276 100644
> --- a/drivers/usb/host/xhci.h
> +++ b/drivers/usb/host/xhci.h
> @@ -1674,8 +1674,6 @@ struct urb_priv {
> #define ERST_NUM_SEGS 1
> /* Poll every 60 seconds */
> #define POLL_TIMEOUT 60
> -/* Stop endpoint command timeout (secs) for URB cancellation
> watchdog timer */
> -#define XHCI_STOP_EP_CMD_TIMEOUT 5
> /* XXX: Make these module parameters */
>
> struct s3_save {
> @@ -1899,6 +1897,7 @@ struct xhci_hcd {
> #define XHCI_BROKEN_D3COLD BIT_ULL(41)
> #define XHCI_EP_CTX_BROKEN_DCS BIT_ULL(42)
>
> + unsigned int stop_ep_cmd_timeout;
> unsigned int num_active_eps;
> unsigned int limit_active_eps;
> struct xhci_port *hw_ports;
On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger wrote:
> On the Librem 5 imx8mq system we've seen the stop endpoint command
> time out regularly which results in the hub dying.
>
> While on the one hand we see "Port resume timed out, port 1-1: 0xfe3"
> before this and on the other hand driver-comments suggest that the driver
> might be able to recover instead of dying here, Sarah seemed to have a
> workaround for this particulator problem in mind already:
>
> Make it a module parameter. So while it might not be the root cause for
> the problem, do this to give users a workaround.
This is not the 1990's, sorry, please do not add new module parameters.
They modify code, when you want to modify an individual device.
thanks,
greg k-h
On 4.3.2022 16.17, Greg KH wrote:
> On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger wrote:
>> On the Librem 5 imx8mq system we've seen the stop endpoint command
>> time out regularly which results in the hub dying.
>>
>> While on the one hand we see "Port resume timed out, port 1-1: 0xfe3"
>> before this and on the other hand driver-comments suggest that the driver
>> might be able to recover instead of dying here, Sarah seemed to have a
>> workaround for this particulator problem in mind already:
>>
>> Make it a module parameter. So while it might not be the root cause for
>> the problem, do this to give users a workaround.
>
> This is not the 1990's, sorry, please do not add new module parameters.
> They modify code, when you want to modify an individual device.
>
Agree, I think we really need to find the rootcause here.
There's a known problem with this stop endpoint timeout timer.
For all other commands we start the timer when the controller starts processing the
command, but the stop endpoint timer is started immediately when command is queued.
So it might timeout if some other commend before it failed.
I have a patchseries for this. It's still work in progress but should be testable.
Pushed to a branch named stop_endpoint_fixes
git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git stop_endpoint_fixes
https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes
Can you try it out and see if it helps?
Thanks
-Mathias
Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman:
> On 4.3.2022 16.17, Greg KH wrote:
> > On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger wrote:
> > > On the Librem 5 imx8mq system we've seen the stop endpoint
> > > command
> > > time out regularly which results in the hub dying.
> > >
> > > While on the one hand we see "Port resume timed out, port 1-1:
> > > 0xfe3"
> > > before this and on the other hand driver-comments suggest that
> > > the driver
> > > might be able to recover instead of dying here, Sarah seemed to
> > > have a
> > > workaround for this particulator problem in mind already:
> > >
> > > Make it a module parameter. So while it might not be the root
> > > cause for
> > > the problem, do this to give users a workaround.
> >
> > This is not the 1990's, sorry, please do not add new module
> > parameters.
> > They modify code, when you want to modify an individual device.
> >
>
> Agree, I think we really need to find the rootcause here.
>
> There's a known problem with this stop endpoint timeout timer.
>
> For all other commands we start the timer when the controller starts
> processing the
> command, but the stop endpoint timer is started immediately when
> command is queued.
> So it might timeout if some other commend before it failed.
>
> I have a patchseries for this. It's still work in progress but should
> be testable.
> Pushed to a branch named stop_endpoint_fixes
>
> git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git
> stop_endpoint_fixes
> https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes
>
> Can you try it out and see if it helps?
>
thanks a lot Mathias, I'm running these now. The timeout has not been
easy to reproduce (or I'm just lazy) but in a few days I should be able
to tell whether that helps.
So this thread has been about
[14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, port 1-
1: 0xfe3
[14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding to
stop endpoint command.
that I previously tried to work around by increasing
XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT.
These patches can't help with the following, right?
readl_poll_timeout_atomic() with a fixed timeout is called in this
case:
xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110
I see that too from time to time. It results in the HC dying as well.
thanks,
martin
Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin Kepplinger:
> Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman:
> > On 4.3.2022 16.17, Greg KH wrote:
> > > On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger
> > > wrote:
> > > > On the Librem 5 imx8mq system we've seen the stop endpoint
> > > > command
> > > > time out regularly which results in the hub dying.
> > > >
> > > > While on the one hand we see "Port resume timed out, port 1-1:
> > > > 0xfe3"
> > > > before this and on the other hand driver-comments suggest that
> > > > the driver
> > > > might be able to recover instead of dying here, Sarah seemed to
> > > > have a
> > > > workaround for this particulator problem in mind already:
> > > >
> > > > Make it a module parameter. So while it might not be the root
> > > > cause for
> > > > the problem, do this to give users a workaround.
> > >
> > > This is not the 1990's, sorry, please do not add new module
> > > parameters.
> > > They modify code, when you want to modify an individual device.
> > >
> >
> > Agree, I think we really need to find the rootcause here.
> >
> > There's a known problem with this stop endpoint timeout timer.
> >
> > For all other commands we start the timer when the controller
> > starts
> > processing the
> > command, but the stop endpoint timer is started immediately when
> > command is queued.
> > So it might timeout if some other commend before it failed.
> >
> > I have a patchseries for this. It's still work in progress but
> > should
> > be testable.
> > Pushed to a branch named stop_endpoint_fixes
> >
> > git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git
> > stop_endpoint_fixes
> > https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes
> >
> > Can you try it out and see if it helps?
> >
>
> thanks a lot Mathias, I'm running these now. The timeout has not been
> easy to reproduce (or I'm just lazy) but in a few days I should be
> able
> to tell whether that helps.
>
> So this thread has been about
>
> [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, port
> 1-
> 1: 0xfe3
> [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding to
> stop endpoint command.
>
> that I previously tried to work around by increasing
> XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT.
>
>
> These patches can't help with the following, right?
> readl_poll_timeout_atomic() with a fixed timeout is called in this
> case:
>
> xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110
>
> I see that too from time to time. It results in the HC dying as well.
>
> thanks,
> martin
>
hi Mathias,
I already saw "Port resume timed out" and the HC dying running your
patches. I append the logs.
So for now I saw more success with increasing
XHCI_MAX_REXIT_TIMEOUT_MS.
thank you,
martin
On 9.3.2022 9.56, Martin Kepplinger wrote:
> Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin Kepplinger:
>> Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman:
>>> On 4.3.2022 16.17, Greg KH wrote:
>>>> On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger
>>>> wrote:
>>>>> On the Librem 5 imx8mq system we've seen the stop endpoint
>>>>> command
>>>>> time out regularly which results in the hub dying.
>>>>>
>>>>> While on the one hand we see "Port resume timed out, port 1-1:
>>>>> 0xfe3"
>>>>> before this and on the other hand driver-comments suggest that
>>>>> the driver
>>>>> might be able to recover instead of dying here, Sarah seemed to
>>>>> have a
>>>>> workaround for this particulator problem in mind already:
>>>>>
>>>>> Make it a module parameter. So while it might not be the root
>>>>> cause for
>>>>> the problem, do this to give users a workaround.
>>>>
>>>> This is not the 1990's, sorry, please do not add new module
>>>> parameters.
>>>> They modify code, when you want to modify an individual device.
>>>>
>>>
>>> Agree, I think we really need to find the rootcause here.
>>>
>>> There's a known problem with this stop endpoint timeout timer.
>>>
>>> For all other commands we start the timer when the controller
>>> starts
>>> processing the
>>> command, but the stop endpoint timer is started immediately when
>>> command is queued.
>>> So it might timeout if some other commend before it failed.
>>>
>>> I have a patchseries for this. It's still work in progress but
>>> should
>>> be testable.
>>> Pushed to a branch named stop_endpoint_fixes
>>>
>>> git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git
>>> stop_endpoint_fixes
>>> https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes
>>>
>>> Can you try it out and see if it helps?
>>>
>>
>> thanks a lot Mathias, I'm running these now. The timeout has not been
>> easy to reproduce (or I'm just lazy) but in a few days I should be
>> able
>> to tell whether that helps.
>>
>> So this thread has been about
>>
>> [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out, port
>> 1-
>> 1: 0xfe3
>> [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding to
>> stop endpoint command.
>>
>> that I previously tried to work around by increasing
>> XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT.
>>
>>
>> These patches can't help with the following, right?
>> readl_poll_timeout_atomic() with a fixed timeout is called in this
>> case:
>>
>> xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110
>>
>> I see that too from time to time. It results in the HC dying as well.
>>
>> thanks,
>> martin
>>
>
> hi Mathias,
>
> I already saw "Port resume timed out" and the HC dying running your
> patches. I append the logs.
>
> So for now I saw more success with increasing
> XHCI_MAX_REXIT_TIMEOUT_MS.
>
XHCI_MAX_REXIT_TIMEOUT_MS is only 20ms, that we can probably change.
Is 40ms enough?
"Port resume timed out, port 1-1: 0xfe3" means port link state is still in
resume even if we asked link to go to U0 20ms ago.
Maybe this hw combination just resumes slowly.
Thanks
Mathias
Am Mittwoch, dem 09.03.2022 um 11:29 +0200 schrieb Mathias Nyman:
> On 9.3.2022 9.56, Martin Kepplinger wrote:
> > Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin
> > Kepplinger:
> > > Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman:
> > > > On 4.3.2022 16.17, Greg KH wrote:
> > > > > On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger
> > > > > wrote:
> > > > > > On the Librem 5 imx8mq system we've seen the stop endpoint
> > > > > > command
> > > > > > time out regularly which results in the hub dying.
> > > > > >
> > > > > > While on the one hand we see "Port resume timed out, port
> > > > > > 1-1:
> > > > > > 0xfe3"
> > > > > > before this and on the other hand driver-comments suggest
> > > > > > that
> > > > > > the driver
> > > > > > might be able to recover instead of dying here, Sarah
> > > > > > seemed to
> > > > > > have a
> > > > > > workaround for this particulator problem in mind already:
> > > > > >
> > > > > > Make it a module parameter. So while it might not be the
> > > > > > root
> > > > > > cause for
> > > > > > the problem, do this to give users a workaround.
> > > > >
> > > > > This is not the 1990's, sorry, please do not add new module
> > > > > parameters.
> > > > > They modify code, when you want to modify an individual
> > > > > device.
> > > > >
> > > >
> > > > Agree, I think we really need to find the rootcause here.
> > > >
> > > > There's a known problem with this stop endpoint timeout timer.
> > > >
> > > > For all other commands we start the timer when the controller
> > > > starts
> > > > processing the
> > > > command, but the stop endpoint timer is started immediately
> > > > when
> > > > command is queued.
> > > > So it might timeout if some other commend before it failed.
> > > >
> > > > I have a patchseries for this. It's still work in progress but
> > > > should
> > > > be testable.
> > > > Pushed to a branch named stop_endpoint_fixes
> > > >
> > > > git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git
> > > > stop_endpoint_fixes
> > > > https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes
> > > >
> > > > Can you try it out and see if it helps?
> > > >
> > >
> > > thanks a lot Mathias, I'm running these now. The timeout has not
> > > been
> > > easy to reproduce (or I'm just lazy) but in a few days I should
> > > be
> > > able
> > > to tell whether that helps.
> > >
> > > So this thread has been about
> > >
> > > [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out,
> > > port
> > > 1-
> > > 1: 0xfe3
> > > [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding
> > > to
> > > stop endpoint command.
> > >
> > > that I previously tried to work around by increasing
> > > XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT.
> > >
> > >
> > > These patches can't help with the following, right?
> > > readl_poll_timeout_atomic() with a fixed timeout is called in
> > > this
> > > case:
> > >
> > > xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110
> > >
> > > I see that too from time to time. It results in the HC dying as
> > > well.
> > >
> > > thanks,
> > > martin
> > >
> >
> > hi Mathias,
> >
> > I already saw "Port resume timed out" and the HC dying running your
> > patches. I append the logs.
> >
> > So for now I saw more success with increasing
> > XHCI_MAX_REXIT_TIMEOUT_MS.
> >
>
> XHCI_MAX_REXIT_TIMEOUT_MS is only 20ms, that we can probably change.
>
> Is 40ms enough?
>
> "Port resume timed out, port 1-1: 0xfe3" means port link state is
> still in
> resume even if we asked link to go to U0 20ms ago.
>
> Maybe this hw combination just resumes slowly.
>
> Thanks
> Mathias
hi Mathias, sorry for not responding until now. I'm currently testing
whether QUIRK_HUB_SLOW_RESET will work too to avoid the HC dying due to
the command timeouts:
{ USB_DEVICE(0x0424, 0x2640), .driver_info = USB_QUIRK_HUB_SLOW_RESET
},
But these timeouts usually happen after a port is reset (not just
runtime-resumed without resetting, which happens very often).
And exactly *that* is what I now want to try to avoid now. I *never*
want ports on the Hub in question to be reset. (it causes enough other
hick-ups even *if* the reset would be successful and not result in the
HC die, so all resets need to go away).
Normally, on successful runtime resume (without any reset), the hub
port status is:
Mär 15 08:24:44.748852 pureos kernel: usb 1-1-port2: status 0503 change
0004
Mär 15 08:24:44.747863 pureos kernel: usb 1-1-port1: status 0507 change
0000
But when the following happens:
Mär 15 08:24:52.660348 pureos kernel: usb 1-1-port2: status 0101 change
0005
Mär 15 08:24:52.656107 pureos kernel: usb 1-1-port1: status 0507 change
0000
then hub_activate() sets "reset_resume" (persist is enabled) and it's
too late :)
Do you have an idea about what could be the cause for "status 0101"
here? (it basically means ENABLE and HIGH_SPEED is not set, but why?)
I know this is a bit of a different area now, but it's all about
avoiding problems on that hub at runtime.
thanks,
martin
On 15.3.2022 10.43, Martin Kepplinger wrote:
> Am Mittwoch, dem 09.03.2022 um 11:29 +0200 schrieb Mathias Nyman:
>> On 9.3.2022 9.56, Martin Kepplinger wrote:
>>> Am Dienstag, dem 08.03.2022 um 17:17 +0100 schrieb Martin
>>> Kepplinger:
>>>> Am Montag, dem 07.03.2022 um 10:49 +0200 schrieb Mathias Nyman:
>>>>> On 4.3.2022 16.17, Greg KH wrote:
>>>>>> On Fri, Mar 04, 2022 at 12:30:57PM +0100, Martin Kepplinger
>>>>>> wrote:
>>>>>>> On the Librem 5 imx8mq system we've seen the stop endpoint
>>>>>>> command
>>>>>>> time out regularly which results in the hub dying.
>>>>>>>
>>>>>>> While on the one hand we see "Port resume timed out, port
>>>>>>> 1-1:
>>>>>>> 0xfe3"
>>>>>>> before this and on the other hand driver-comments suggest
>>>>>>> that
>>>>>>> the driver
>>>>>>> might be able to recover instead of dying here, Sarah
>>>>>>> seemed to
>>>>>>> have a
>>>>>>> workaround for this particulator problem in mind already:
>>>>>>>
>>>>>>> Make it a module parameter. So while it might not be the
>>>>>>> root
>>>>>>> cause for
>>>>>>> the problem, do this to give users a workaround.
>>>>>>
>>>>>> This is not the 1990's, sorry, please do not add new module
>>>>>> parameters.
>>>>>> They modify code, when you want to modify an individual
>>>>>> device.
>>>>>>
>>>>>
>>>>> Agree, I think we really need to find the rootcause here.
>>>>>
>>>>> There's a known problem with this stop endpoint timeout timer.
>>>>>
>>>>> For all other commands we start the timer when the controller
>>>>> starts
>>>>> processing the
>>>>> command, but the stop endpoint timer is started immediately
>>>>> when
>>>>> command is queued.
>>>>> So it might timeout if some other commend before it failed.
>>>>>
>>>>> I have a patchseries for this. It's still work in progress but
>>>>> should
>>>>> be testable.
>>>>> Pushed to a branch named stop_endpoint_fixes
>>>>>
>>>>> git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git
>>>>> stop_endpoint_fixes
>>>>> https://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git/log/?h=stop_endpoint_fixes
>>>>>
>>>>> Can you try it out and see if it helps?
>>>>>
>>>>
>>>> thanks a lot Mathias, I'm running these now. The timeout has not
>>>> been
>>>> easy to reproduce (or I'm just lazy) but in a few days I should
>>>> be
>>>> able
>>>> to tell whether that helps.
>>>>
>>>> So this thread has been about
>>>>
>>>> [14145.960512] xhci-hcd xhci-hcd.4.auto: Port resume timed out,
>>>> port
>>>> 1-
>>>> 1: 0xfe3
>>>> [14156.308511] xhci-hcd xhci-hcd.4.auto: xHCI host not responding
>>>> to
>>>> stop endpoint command.
>>>>
>>>> that I previously tried to work around by increasing
>>>> XHCI_MAX_REXIT_TIMEOUT_MS and XHCI_STOP_EP_CMD_TIMEOUT.
>>>>
>>>>
>>>> These patches can't help with the following, right?
>>>> readl_poll_timeout_atomic() with a fixed timeout is called in
>>>> this
>>>> case:
>>>>
>>>> xhci-hcd xhci-hcd.4.auto: Abort failed to stop command ring: -110
>>>>
>>>> I see that too from time to time. It results in the HC dying as
>>>> well.
>>>>
>>>> thanks,
>>>> martin
>>>>
>>>
>>> hi Mathias,
>>>
>>> I already saw "Port resume timed out" and the HC dying running your
>>> patches. I append the logs.
>>>
>>> So for now I saw more success with increasing
>>> XHCI_MAX_REXIT_TIMEOUT_MS.
>>>
>>
>> XHCI_MAX_REXIT_TIMEOUT_MS is only 20ms, that we can probably change.
>>
>> Is 40ms enough?
>>
>> "Port resume timed out, port 1-1: 0xfe3" means port link state is
>> still in
>> resume even if we asked link to go to U0 20ms ago.
>>
>> Maybe this hw combination just resumes slowly.
>>
>> Thanks
>> Mathias
>
>
> hi Mathias, sorry for not responding until now. I'm currently testing
> whether QUIRK_HUB_SLOW_RESET will work too to avoid the HC dying due to
> the command timeouts:
>
> { USB_DEVICE(0x0424, 0x2640), .driver_info = USB_QUIRK_HUB_SLOW_RESET
> },
>
> But these timeouts usually happen after a port is reset (not just
> runtime-resumed without resetting, which happens very often).
>
> And exactly *that* is what I now want to try to avoid now. I *never*
> want ports on the Hub in question to be reset. (it causes enough other
> hick-ups even *if* the reset would be successful and not result in the
> HC die, so all resets need to go away).
>
> Normally, on successful runtime resume (without any reset), the hub
> port status is:
>
> Mär 15 08:24:44.748852 pureos kernel: usb 1-1-port2: status 0503 change
> 0004
> Mär 15 08:24:44.747863 pureos kernel: usb 1-1-port1: status 0507 change
> 0000
>
> But when the following happens:
>
> Mär 15 08:24:52.660348 pureos kernel: usb 1-1-port2: status 0101 change
> 0005
> Mär 15 08:24:52.656107 pureos kernel: usb 1-1-port1: status 0507 change
> 0000
>
> then hub_activate() sets "reset_resume" (persist is enabled) and it's
> too late :)
>
> Do you have an idea about what could be the cause for "status 0101"
> here? (it basically means ENABLE and HIGH_SPEED is not set, but why?)
>
> I know this is a bit of a different area now, but it's all about
> avoiding problems on that hub at runtime.
>
> thanks,
>
> martin
Not sure about this.
The failing case has change 0005, meaning the connect status change bit is
set. Also HIGH_SPEED bit in status is only relevant when ENABLE bit is set.
If there was a connect change detected then I guess port reset is needed to
get the USB 2 port back to enable state.
-Mathias