[PATCH] xhci: Make debug message consistent with bus and port number

[PATCH] xhci: Make debug message consistent with bus and port number

[Kai-Heng Feng]

Current xhci debug message doesn't always output bus number, so it's
hard to figure out it's from USB2 or USB3 root hub.

In addition to that, some port numbers are offset to 0 and others are
offset to 1. Use the latter to match the USB core.

So use "bus number - port index + 1" to make debug message consistent.

Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
---
 drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
 1 file changed, 23 insertions(+), 18 deletions(-)

diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
index f37316d2c8fa..83088c262cc4 100644
--- a/drivers/usb/host/xhci-hub.c
+++ b/drivers/usb/host/xhci-hub.c
@@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
 			temp = readl(ports[wIndex]->addr);
 			/* Disable port */
 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
-				xhci_dbg(xhci, "Disable port %d\n", wIndex);
+				xhci_dbg(xhci, "Disable port %d-%d\n",
+					 hcd->self.busnum, wIndex + 1);
 				temp = xhci_port_state_to_neutral(temp);
 				/*
 				 * Clear all change bits, so that we get a new
@@ -1257,7 +1258,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
 
 			/* Put link in RxDetect (enable port) */
 			if (link_state == USB_SS_PORT_LS_RX_DETECT) {
-				xhci_dbg(xhci, "Enable port %d\n", wIndex);
+				xhci_dbg(xhci, "Enable port %d-%d\n",
+					 hcd->self.busnum, wIndex + 1);
 				xhci_set_link_state(xhci, ports[wIndex],
 							link_state);
 				temp = readl(ports[wIndex]->addr);
@@ -1289,8 +1291,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
 					goto error;
 				}
 
-				xhci_dbg(xhci, "Enable compliance mode transition for port %d\n",
-						wIndex);
+				xhci_dbg(xhci, "Enable compliance mode transition for port %d-%d\n",
+					 hcd->self.busnum, wIndex + 1);
 				xhci_set_link_state(xhci, ports[wIndex],
 						link_state);
 
@@ -1304,8 +1306,9 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
 			}
 			/* Can't set port link state above '3' (U3) */
 			if (link_state > USB_SS_PORT_LS_U3) {
-				xhci_warn(xhci, "Cannot set port %d link state %d\n",
-					 wIndex, link_state);
+				xhci_warn(xhci, "Cannot set port %d-%d link state %d\n",
+					  hcd->self.busnum, wIndex + 1,
+					  link_state);
 				goto error;
 			}
 
@@ -1340,8 +1343,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
 				spin_unlock_irqrestore(&xhci->lock, flags);
 				if (!wait_for_completion_timeout(&bus_state->u3exit_done[wIndex],
 								 msecs_to_jiffies(100)))
-					xhci_dbg(xhci, "missing U0 port change event for port %d\n",
-						 wIndex);
+					xhci_dbg(xhci, "missing U0 port change event for port %d-%d\n",
+						 hcd->self.busnum, wIndex + 1);
 				spin_lock_irqsave(&xhci->lock, flags);
 				temp = readl(ports[wIndex]->addr);
 				break;
@@ -1386,15 +1389,15 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
 			writel(temp, ports[wIndex]->addr);
 
 			temp = readl(ports[wIndex]->addr);
-			xhci_dbg(xhci, "set port reset, actual port %d status  = 0x%x\n", wIndex, temp);
+			xhci_dbg(xhci, "set port reset, actual port %d-%d status  = 0x%x\n",
+				 hcd->self.busnum, wIndex + 1, temp);
 			break;
 		case USB_PORT_FEAT_REMOTE_WAKE_MASK:
 			xhci_set_remote_wake_mask(xhci, ports[wIndex],
 						  wake_mask);
 			temp = readl(ports[wIndex]->addr);
-			xhci_dbg(xhci, "set port remote wake mask, "
-					"actual port %d status  = 0x%x\n",
-					wIndex, temp);
+			xhci_dbg(xhci, "set port remote wake mask, actual port %d-%d status  = 0x%x\n",
+				 hcd->self.busnum, wIndex + 1, temp);
 			break;
 		case USB_PORT_FEAT_BH_PORT_RESET:
 			temp |= PORT_WR;
@@ -1634,8 +1637,8 @@ int xhci_bus_suspend(struct usb_hcd *hcd)
 			spin_unlock_irqrestore(&xhci->lock, flags);
 			msleep(XHCI_PORT_POLLING_LFPS_TIME);
 			spin_lock_irqsave(&xhci->lock, flags);
-			xhci_dbg(xhci, "port %d polling in bus suspend, waiting\n",
-				 port_index);
+			xhci_dbg(xhci, "port %d-%d polling in bus suspend, waiting\n",
+				 hcd->self.busnum, port_index + 1);
 			goto retry;
 		}
 		/* bail out if port detected a over-current condition */
@@ -1653,7 +1656,8 @@ int xhci_bus_suspend(struct usb_hcd *hcd)
 				xhci_dbg(xhci, "Bus suspend bailout, port connect change\n");
 				return -EBUSY;
 			}
-			xhci_dbg(xhci, "port %d not suspended\n", port_index);
+			xhci_dbg(xhci, "port %d-%d not suspended\n",
+				 hcd->self.busnum, port_index + 1);
 			t2 &= ~PORT_PLS_MASK;
 			t2 |= PORT_LINK_STROBE | XDEV_U3;
 			set_bit(port_index, &bus_state->bus_suspended);
@@ -1783,7 +1787,8 @@ int xhci_bus_resume(struct usb_hcd *hcd)
 		if ((xhci->quirks & XHCI_MISSING_CAS) &&
 		    (hcd->speed >= HCD_USB3) &&
 		    xhci_port_missing_cas_quirk(ports[port_index])) {
-			xhci_dbg(xhci, "reset stuck port %d\n", port_index);
+			xhci_dbg(xhci, "reset stuck port %d-%d\n",
+				 hcd->self.busnum, port_index + 1);
 			clear_bit(port_index, &bus_state->bus_suspended);
 			continue;
 		}
@@ -1830,8 +1835,8 @@ int xhci_bus_resume(struct usb_hcd *hcd)
 		sret = xhci_handshake(ports[port_index]->addr, PORT_PLC,
 				      PORT_PLC, 10 * 1000);
 		if (sret) {
-			xhci_warn(xhci, "port %d resume PLC timeout\n",
-				  port_index);
+			xhci_warn(xhci, "port %d-%d resume PLC timeout\n",
+				  hcd->self.busnum, port_index + 1);
 			continue;
 		}
 		xhci_test_and_clear_bit(xhci, ports[port_index], PORT_PLC);
-- 
2.17.1

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Greg Kroah-Hartman]

On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
> Current xhci debug message doesn't always output bus number, so it's
> hard to figure out it's from USB2 or USB3 root hub.
> 
> In addition to that, some port numbers are offset to 0 and others are
> offset to 1. Use the latter to match the USB core.
> 
> So use "bus number - port index + 1" to make debug message consistent.
> 
> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
> ---
>  drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
>  1 file changed, 23 insertions(+), 18 deletions(-)
> 
> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
> index f37316d2c8fa..83088c262cc4 100644
> --- a/drivers/usb/host/xhci-hub.c
> +++ b/drivers/usb/host/xhci-hub.c
> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
>  			temp = readl(ports[wIndex]->addr);
>  			/* Disable port */
>  			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
> +				xhci_dbg(xhci, "Disable port %d-%d\n",
> +					 hcd->self.busnum, wIndex + 1);

Shouldn't xhci_dbg() show the bus number already?  If not, please fix
that up there instead of having to add it to all messages "by hand".

thanks,

greg k-h

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Kai-Heng Feng]

> On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
> 
> On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
>> Current xhci debug message doesn't always output bus number, so it's
>> hard to figure out it's from USB2 or USB3 root hub.
>> 
>> In addition to that, some port numbers are offset to 0 and others are
>> offset to 1. Use the latter to match the USB core.
>> 
>> So use "bus number - port index + 1" to make debug message consistent.
>> 
>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>> ---
>> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
>> 1 file changed, 23 insertions(+), 18 deletions(-)
>> 
>> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
>> index f37316d2c8fa..83088c262cc4 100644
>> --- a/drivers/usb/host/xhci-hub.c
>> +++ b/drivers/usb/host/xhci-hub.c
>> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
>> 			temp = readl(ports[wIndex]->addr);
>> 			/* Disable port */
>> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
>> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
>> +				xhci_dbg(xhci, "Disable port %d-%d\n",
>> +					 hcd->self.busnum, wIndex + 1);
> 
> Shouldn't xhci_dbg() show the bus number already?  

It's the PCI bus number, different to USB2/USB3 root hub bus number...

> If not, please fix
> that up there instead of having to add it to all messages "by hand".

Not all xhci debug messages need roothub number in it.

Kai-Heng

> 
> thanks,
> 
> greg k-h

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Greg Kroah-Hartman]

On Thu, May 07, 2020 at 03:15:01PM +0800, Kai-Heng Feng wrote:
> 
> 
> > On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
> > 
> > On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
> >> Current xhci debug message doesn't always output bus number, so it's
> >> hard to figure out it's from USB2 or USB3 root hub.
> >> 
> >> In addition to that, some port numbers are offset to 0 and others are
> >> offset to 1. Use the latter to match the USB core.
> >> 
> >> So use "bus number - port index + 1" to make debug message consistent.
> >> 
> >> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
> >> ---
> >> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
> >> 1 file changed, 23 insertions(+), 18 deletions(-)
> >> 
> >> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
> >> index f37316d2c8fa..83088c262cc4 100644
> >> --- a/drivers/usb/host/xhci-hub.c
> >> +++ b/drivers/usb/host/xhci-hub.c
> >> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
> >> 			temp = readl(ports[wIndex]->addr);
> >> 			/* Disable port */
> >> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
> >> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
> >> +				xhci_dbg(xhci, "Disable port %d-%d\n",
> >> +					 hcd->self.busnum, wIndex + 1);
> > 
> > Shouldn't xhci_dbg() show the bus number already?  
> 
> It's the PCI bus number, different to USB2/USB3 root hub bus number...

But if this is using dev_dbg(), and it is, then you know how to look
that up by seeing where that device is in sysfs at that point in time.

So why add this again?

> > If not, please fix
> > that up there instead of having to add it to all messages "by hand".
> 
> Not all xhci debug messages need roothub number in it.

Why pick these random ones?  What makes these different?

Either all or none, be consistant please.

greg k-h

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Kai-Heng Feng]

> On May 7, 2020, at 15:31, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
> 
> On Thu, May 07, 2020 at 03:15:01PM +0800, Kai-Heng Feng wrote:
>> 
>> 
>>> On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>> 
>>> On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
>>>> Current xhci debug message doesn't always output bus number, so it's
>>>> hard to figure out it's from USB2 or USB3 root hub.
>>>> 
>>>> In addition to that, some port numbers are offset to 0 and others are
>>>> offset to 1. Use the latter to match the USB core.
>>>> 
>>>> So use "bus number - port index + 1" to make debug message consistent.
>>>> 
>>>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>>>> ---
>>>> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
>>>> 1 file changed, 23 insertions(+), 18 deletions(-)
>>>> 
>>>> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
>>>> index f37316d2c8fa..83088c262cc4 100644
>>>> --- a/drivers/usb/host/xhci-hub.c
>>>> +++ b/drivers/usb/host/xhci-hub.c
>>>> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
>>>> 			temp = readl(ports[wIndex]->addr);
>>>> 			/* Disable port */
>>>> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
>>>> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
>>>> +				xhci_dbg(xhci, "Disable port %d-%d\n",
>>>> +					 hcd->self.busnum, wIndex + 1);
>>> 
>>> Shouldn't xhci_dbg() show the bus number already?  
>> 
>> It's the PCI bus number, different to USB2/USB3 root hub bus number...
> 
> But if this is using dev_dbg(), and it is, then you know how to look
> that up by seeing where that device is in sysfs at that point in time.
> 
> So why add this again?

xHCI has two HCD, one for USB2 and one for USB3.
If both of their port with same number are in use, for instance, port 1, then they are port 1-1 and port 2-1.
Right now the debug message only show "Port 1", we still can't find the corresponding port via sysfs with insufficient info.

> 
>>> If not, please fix
>>> that up there instead of having to add it to all messages "by hand".
>> 
>> Not all xhci debug messages need roothub number in it.
> 
> Why pick these random ones?  What makes these different?

It's not random. We do it when there's a port in message.
Being able to know the exact port like "port 1-1" or "port 2-1", instead of just "port 1", can be really helpful.

Kai-Heng

> 
> Either all or none, be consistant please.
> 
> greg k-h

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Greg Kroah-Hartman]

On Thu, May 07, 2020 at 03:58:36PM +0800, Kai-Heng Feng wrote:
> 
> 
> > On May 7, 2020, at 15:31, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
> > 
> > On Thu, May 07, 2020 at 03:15:01PM +0800, Kai-Heng Feng wrote:
> >> 
> >> 
> >>> On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
> >>> 
> >>> On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
> >>>> Current xhci debug message doesn't always output bus number, so it's
> >>>> hard to figure out it's from USB2 or USB3 root hub.
> >>>> 
> >>>> In addition to that, some port numbers are offset to 0 and others are
> >>>> offset to 1. Use the latter to match the USB core.
> >>>> 
> >>>> So use "bus number - port index + 1" to make debug message consistent.
> >>>> 
> >>>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
> >>>> ---
> >>>> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
> >>>> 1 file changed, 23 insertions(+), 18 deletions(-)
> >>>> 
> >>>> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
> >>>> index f37316d2c8fa..83088c262cc4 100644
> >>>> --- a/drivers/usb/host/xhci-hub.c
> >>>> +++ b/drivers/usb/host/xhci-hub.c
> >>>> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
> >>>> 			temp = readl(ports[wIndex]->addr);
> >>>> 			/* Disable port */
> >>>> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
> >>>> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
> >>>> +				xhci_dbg(xhci, "Disable port %d-%d\n",
> >>>> +					 hcd->self.busnum, wIndex + 1);
> >>> 
> >>> Shouldn't xhci_dbg() show the bus number already?  
> >> 
> >> It's the PCI bus number, different to USB2/USB3 root hub bus number...
> > 
> > But if this is using dev_dbg(), and it is, then you know how to look
> > that up by seeing where that device is in sysfs at that point in time.
> > 
> > So why add this again?
> 
> xHCI has two HCD, one for USB2 and one for USB3.
> If both of their port with same number are in use, for instance, port 1, then they are port 1-1 and port 2-1.
> Right now the debug message only show "Port 1", we still can't find the corresponding port via sysfs with insufficient info.

Look at the full kernel log line, the xhci hcd device should be showing
you unique information.  If not, something else is wrong.

What does a full line look like today for you?

thanks,

greg k-h

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Mathias Nyman]

On 7.5.2020 11.21, Greg Kroah-Hartman wrote:
> On Thu, May 07, 2020 at 03:58:36PM +0800, Kai-Heng Feng wrote:
>>
>>
>>> On May 7, 2020, at 15:31, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>
>>> On Thu, May 07, 2020 at 03:15:01PM +0800, Kai-Heng Feng wrote:
>>>>
>>>>
>>>>> On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>>>
>>>>> On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
>>>>>> Current xhci debug message doesn't always output bus number, so it's
>>>>>> hard to figure out it's from USB2 or USB3 root hub.
>>>>>>
>>>>>> In addition to that, some port numbers are offset to 0 and others are
>>>>>> offset to 1. Use the latter to match the USB core.
>>>>>>
>>>>>> So use "bus number - port index + 1" to make debug message consistent.
>>>>>>
>>>>>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>>>>>> ---
>>>>>> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
>>>>>> 1 file changed, 23 insertions(+), 18 deletions(-)
>>>>>>
>>>>>> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
>>>>>> index f37316d2c8fa..83088c262cc4 100644
>>>>>> --- a/drivers/usb/host/xhci-hub.c
>>>>>> +++ b/drivers/usb/host/xhci-hub.c
>>>>>> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
>>>>>> 			temp = readl(ports[wIndex]->addr);
>>>>>> 			/* Disable port */
>>>>>> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
>>>>>> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
>>>>>> +				xhci_dbg(xhci, "Disable port %d-%d\n",
>>>>>> +					 hcd->self.busnum, wIndex + 1);
>>>>>
>>>>> Shouldn't xhci_dbg() show the bus number already?  
>>>>
>>>> It's the PCI bus number, different to USB2/USB3 root hub bus number...
>>>
>>> But if this is using dev_dbg(), and it is, then you know how to look
>>> that up by seeing where that device is in sysfs at that point in time.
>>>
>>> So why add this again?
>>
>> xHCI has two HCD, one for USB2 and one for USB3.
>> If both of their port with same number are in use, for instance, port 1, then they are port 1-1 and port 2-1.
>> Right now the debug message only show "Port 1", we still can't find the corresponding port via sysfs with insufficient info.
> 
> Look at the full kernel log line, the xhci hcd device should be showing
> you unique information.  If not, something else is wrong.
> 

What Kai-Heng suggest here makes sense, and is useful.
We use similar style debugging in other places, and it is helpful as it matches
usb core debugging style.

This might seem odd but reason is that the xHC controller is one device which
doesn't really separate USB2 and USB3.
All ports are for example in one long array.

On the xhci driver side things look very different. We register two HCD's,
one for usb 2 and one for USB 3. In many cases the debugging is not tied to a HCD
in any way,  (starting, stopping controller, command completion interrupts etc),
other cases the debugging is very much tied to a specific hcd,
for example when we are handling a port requsts for the roothub.

Thanks
-Mathias

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Kai-Heng Feng]

> On May 7, 2020, at 18:35, Mathias Nyman <mathias.nyman@linux.intel.com> wrote:
> 
> On 7.5.2020 11.21, Greg Kroah-Hartman wrote:
>> On Thu, May 07, 2020 at 03:58:36PM +0800, Kai-Heng Feng wrote:
>>> 
>>> 
>>>> On May 7, 2020, at 15:31, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>> 
>>>> On Thu, May 07, 2020 at 03:15:01PM +0800, Kai-Heng Feng wrote:
>>>>> 
>>>>> 
>>>>>> On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>>>> 
>>>>>> On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
>>>>>>> Current xhci debug message doesn't always output bus number, so it's
>>>>>>> hard to figure out it's from USB2 or USB3 root hub.
>>>>>>> 
>>>>>>> In addition to that, some port numbers are offset to 0 and others are
>>>>>>> offset to 1. Use the latter to match the USB core.
>>>>>>> 
>>>>>>> So use "bus number - port index + 1" to make debug message consistent.
>>>>>>> 
>>>>>>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>>>>>>> ---
>>>>>>> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
>>>>>>> 1 file changed, 23 insertions(+), 18 deletions(-)
>>>>>>> 
>>>>>>> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
>>>>>>> index f37316d2c8fa..83088c262cc4 100644
>>>>>>> --- a/drivers/usb/host/xhci-hub.c
>>>>>>> +++ b/drivers/usb/host/xhci-hub.c
>>>>>>> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
>>>>>>> 			temp = readl(ports[wIndex]->addr);
>>>>>>> 			/* Disable port */
>>>>>>> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
>>>>>>> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
>>>>>>> +				xhci_dbg(xhci, "Disable port %d-%d\n",
>>>>>>> +					 hcd->self.busnum, wIndex + 1);
>>>>>> 
>>>>>> Shouldn't xhci_dbg() show the bus number already?  
>>>>> 
>>>>> It's the PCI bus number, different to USB2/USB3 root hub bus number...
>>>> 
>>>> But if this is using dev_dbg(), and it is, then you know how to look
>>>> that up by seeing where that device is in sysfs at that point in time.
>>>> 
>>>> So why add this again?
>>> 
>>> xHCI has two HCD, one for USB2 and one for USB3.
>>> If both of their port with same number are in use, for instance, port 1, then they are port 1-1 and port 2-1.
>>> Right now the debug message only show "Port 1", we still can't find the corresponding port via sysfs with insufficient info.
>> 
>> Look at the full kernel log line, the xhci hcd device should be showing
>> you unique information.  If not, something else is wrong.
>> 
> 
> What Kai-Heng suggest here makes sense, and is useful.
> We use similar style debugging in other places, and it is helpful as it matches
> usb core debugging style.
> 
> This might seem odd but reason is that the xHC controller is one device which
> doesn't really separate USB2 and USB3.
> All ports are for example in one long array.
> 
> On the xhci driver side things look very different. We register two HCD's,
> one for usb 2 and one for USB 3. In many cases the debugging is not tied to a HCD
> in any way,  (starting, stopping controller, command completion interrupts etc),
> other cases the debugging is very much tied to a specific hcd,
> for example when we are handling a port requsts for the roothub.

A gentle ping...

> 
> Thanks
> -Mathias

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Mathias Nyman]

On 8.6.2020 6.57, Kai-Heng Feng wrote:
> 
> 
>> On May 7, 2020, at 18:35, Mathias Nyman <mathias.nyman@linux.intel.com> wrote:
>>
>> On 7.5.2020 11.21, Greg Kroah-Hartman wrote:
>>> On Thu, May 07, 2020 at 03:58:36PM +0800, Kai-Heng Feng wrote:
>>>>
>>>>
>>>>> On May 7, 2020, at 15:31, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>>>
>>>>> On Thu, May 07, 2020 at 03:15:01PM +0800, Kai-Heng Feng wrote:
>>>>>>
>>>>>>
>>>>>>> On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>>>>>
>>>>>>> On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
>>>>>>>> Current xhci debug message doesn't always output bus number, so it's
>>>>>>>> hard to figure out it's from USB2 or USB3 root hub.
>>>>>>>>
>>>>>>>> In addition to that, some port numbers are offset to 0 and others are
>>>>>>>> offset to 1. Use the latter to match the USB core.
>>>>>>>>
>>>>>>>> So use "bus number - port index + 1" to make debug message consistent.
>>>>>>>>
>>>>>>>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>>>>>>>> ---
>>>>>>>> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
>>>>>>>> 1 file changed, 23 insertions(+), 18 deletions(-)
>>>>>>>>
>>>>>>>> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
>>>>>>>> index f37316d2c8fa..83088c262cc4 100644
>>>>>>>> --- a/drivers/usb/host/xhci-hub.c
>>>>>>>> +++ b/drivers/usb/host/xhci-hub.c
>>>>>>>> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
>>>>>>>> 			temp = readl(ports[wIndex]->addr);
>>>>>>>> 			/* Disable port */
>>>>>>>> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
>>>>>>>> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
>>>>>>>> +				xhci_dbg(xhci, "Disable port %d-%d\n",
>>>>>>>> +					 hcd->self.busnum, wIndex + 1);
>>>>>>>
>>>>>>> Shouldn't xhci_dbg() show the bus number already?  
>>>>>>
>>>>>> It's the PCI bus number, different to USB2/USB3 root hub bus number...
>>>>>
>>>>> But if this is using dev_dbg(), and it is, then you know how to look
>>>>> that up by seeing where that device is in sysfs at that point in time.
>>>>>
>>>>> So why add this again?
>>>>
>>>> xHCI has two HCD, one for USB2 and one for USB3.
>>>> If both of their port with same number are in use, for instance, port 1, then they are port 1-1 and port 2-1.
>>>> Right now the debug message only show "Port 1", we still can't find the corresponding port via sysfs with insufficient info.
>>>
>>> Look at the full kernel log line, the xhci hcd device should be showing
>>> you unique information.  If not, something else is wrong.
>>>
>>
>> What Kai-Heng suggest here makes sense, and is useful.
>> We use similar style debugging in other places, and it is helpful as it matches
>> usb core debugging style.
>>
>> This might seem odd but reason is that the xHC controller is one device which
>> doesn't really separate USB2 and USB3.
>> All ports are for example in one long array.
>>
>> On the xhci driver side things look very different. We register two HCD's,
>> one for usb 2 and one for USB 3. In many cases the debugging is not tied to a HCD
>> in any way,  (starting, stopping controller, command completion interrupts etc),
>> other cases the debugging is very much tied to a specific hcd,
>> for example when we are handling a port requsts for the roothub.
> 
> A gentle ping...
> 

Added to my for-usb-next branch, (which I'll need to rebase on 5.8-rc1 once released)

-Mathias

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Kai-Heng Feng]

> On Jun 8, 2020, at 17:29, Mathias Nyman <mathias.nyman@linux.intel.com> wrote:
> 
> On 8.6.2020 6.57, Kai-Heng Feng wrote:
>> 
>> 
>>> On May 7, 2020, at 18:35, Mathias Nyman <mathias.nyman@linux.intel.com> wrote:
>>> 
>>> On 7.5.2020 11.21, Greg Kroah-Hartman wrote:
>>>> On Thu, May 07, 2020 at 03:58:36PM +0800, Kai-Heng Feng wrote:
>>>>> 
>>>>> 
>>>>>> On May 7, 2020, at 15:31, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>>>> 
>>>>>> On Thu, May 07, 2020 at 03:15:01PM +0800, Kai-Heng Feng wrote:
>>>>>>> 
>>>>>>> 
>>>>>>>> On May 7, 2020, at 14:45, Greg Kroah-Hartman <gregkh@linuxfoundation.org> wrote:
>>>>>>>> 
>>>>>>>> On Thu, May 07, 2020 at 02:17:55PM +0800, Kai-Heng Feng wrote:
>>>>>>>>> Current xhci debug message doesn't always output bus number, so it's
>>>>>>>>> hard to figure out it's from USB2 or USB3 root hub.
>>>>>>>>> 
>>>>>>>>> In addition to that, some port numbers are offset to 0 and others are
>>>>>>>>> offset to 1. Use the latter to match the USB core.
>>>>>>>>> 
>>>>>>>>> So use "bus number - port index + 1" to make debug message consistent.
>>>>>>>>> 
>>>>>>>>> Signed-off-by: Kai-Heng Feng <kai.heng.feng@canonical.com>
>>>>>>>>> ---
>>>>>>>>> drivers/usb/host/xhci-hub.c | 41 +++++++++++++++++++++----------------
>>>>>>>>> 1 file changed, 23 insertions(+), 18 deletions(-)
>>>>>>>>> 
>>>>>>>>> diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
>>>>>>>>> index f37316d2c8fa..83088c262cc4 100644
>>>>>>>>> --- a/drivers/usb/host/xhci-hub.c
>>>>>>>>> +++ b/drivers/usb/host/xhci-hub.c
>>>>>>>>> @@ -1241,7 +1241,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
>>>>>>>>> 			temp = readl(ports[wIndex]->addr);
>>>>>>>>> 			/* Disable port */
>>>>>>>>> 			if (link_state == USB_SS_PORT_LS_SS_DISABLED) {
>>>>>>>>> -				xhci_dbg(xhci, "Disable port %d\n", wIndex);
>>>>>>>>> +				xhci_dbg(xhci, "Disable port %d-%d\n",
>>>>>>>>> +					 hcd->self.busnum, wIndex + 1);
>>>>>>>> 
>>>>>>>> Shouldn't xhci_dbg() show the bus number already?  
>>>>>>> 
>>>>>>> It's the PCI bus number, different to USB2/USB3 root hub bus number...
>>>>>> 
>>>>>> But if this is using dev_dbg(), and it is, then you know how to look
>>>>>> that up by seeing where that device is in sysfs at that point in time.
>>>>>> 
>>>>>> So why add this again?
>>>>> 
>>>>> xHCI has two HCD, one for USB2 and one for USB3.
>>>>> If both of their port with same number are in use, for instance, port 1, then they are port 1-1 and port 2-1.
>>>>> Right now the debug message only show "Port 1", we still can't find the corresponding port via sysfs with insufficient info.
>>>> 
>>>> Look at the full kernel log line, the xhci hcd device should be showing
>>>> you unique information.  If not, something else is wrong.
>>>> 
>>> 
>>> What Kai-Heng suggest here makes sense, and is useful.
>>> We use similar style debugging in other places, and it is helpful as it matches
>>> usb core debugging style.
>>> 
>>> This might seem odd but reason is that the xHC controller is one device which
>>> doesn't really separate USB2 and USB3.
>>> All ports are for example in one long array.
>>> 
>>> On the xhci driver side things look very different. We register two HCD's,
>>> one for usb 2 and one for USB 3. In many cases the debugging is not tied to a HCD
>>> in any way,  (starting, stopping controller, command completion interrupts etc),
>>> other cases the debugging is very much tied to a specific hcd,
>>> for example when we are handling a port requsts for the roothub.
>> 
>> A gentle ping...
>> 
> 
> Added to my for-usb-next branch, (which I'll need to rebase on 5.8-rc1 once released)

Hmm, not seeing this patch from mainline, next or xhci tree..

Kai-Heng
> 
> -Mathias
> 

Re: [PATCH] xhci: Make debug message consistent with bus and port number

[Mathias Nyman]

On 30.6.2020 14.46, Kai-Heng Feng wrote:
> 
>>
>> Added to my for-usb-next branch, (which I'll need to rebase on 5.8-rc1 once released)
> 
> Hmm, not seeing this patch from mainline, next or xhci tree..
> 

Apparently I never pushed it to kernel.org, now it should be in my for-usb-next branch

-Mathias