Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1614324 > unrolled thread

Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors?

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? John Stultz <john.stultz@linaro.org> - 2017-04-01 01:10 +0200
    Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? John Youn <John.Youn@synopsys.com> - 2017-04-03 07:30 +0200
      Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? Minas Harutyunyan <Minas.Harutyunyan@synopsys.com> - 2017-04-03 15:00 +0200
        Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? John Stultz <john.stultz@linaro.org> - 2017-04-04 05:10 +0200
          Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? Minas Harutyunyan <Minas.Harutyunyan@synopsys.com> - 2017-04-04 09:20 +0200
            Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? Felipe Balbi <felipe.balbi@linux.intel.com> - 2017-04-04 09:40 +0200
              Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? Minas Harutyunyan <Minas.Harutyunyan@synopsys.com> - 2017-04-05 15:20 +0200
                Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? Minas Harutyunyan <Minas.Harutyunyan@synopsys.com> - 2017-04-06 09:50 +0200
                  Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? Felipe Balbi <felipe.balbi@linux.intel.com> - 2017-04-07 10:20 +0200
                    Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors? Minas Harutyunyan <Minas.Harutyunyan@synopsys.com> - 2017-04-07 15:00 +0200

#1614324 — Re: dwc2_hc_chhltd_intr_dma - ChHltd set errors?

On Thu, Mar 2, 2017 at 12:00 PM, John Stultz <john.stultz@linaro.org> wrote:
> Hey John,
>   We've noticed that when using usb ethernet adapters on HiKey, we
> occasionally see errors like:
>
> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 0 - ChHltd set,
> but reason is unknown
> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>
> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set,
> but reason is unknown
> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04200029
>
> Sometimes followed up by a usb error in the driver, something like:
> asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length 0x36000807, offset 68
>
> Curious if you've seen any reports like this?

Hey John,
  Just wanted to check in again on this to see if you've seen anything
like it? I've not had too much time to debug it, but my attempts so
far haven't been productive.

thanks
-john

[toc] | [next] | [standalone]

#1614891

On 03/31/2017 04:04 PM, John Stultz wrote:
> On Thu, Mar 2, 2017 at 12:00 PM, John Stultz <john.stultz@linaro.org> wrote:
>> Hey John,
>>   We've noticed that when using usb ethernet adapters on HiKey, we
>> occasionally see errors like:
>>
>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 0 - ChHltd set,
>> but reason is unknown
>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>
>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set,
>> but reason is unknown
>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04200029
>>
>> Sometimes followed up by a usb error in the driver, something like:
>> asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length 0x36000807, offset 68
>>
>> Curious if you've seen any reports like this?
>
> Hey John,
>   Just wanted to check in again on this to see if you've seen anything
> like it? I've not had too much time to debug it, but my attempts so
> far haven't been productive.
>

I don't think I've seen that.

We'll try to take a look this week.

Thanks,
John

[toc] | [prev] | [next] | [standalone]

#1615181

Hi,

On 4/3/2017 9:23 AM, John Youn wrote:
> On 03/31/2017 04:04 PM, John Stultz wrote:
>> On Thu, Mar 2, 2017 at 12:00 PM, John Stultz <john.stultz@linaro.org> wrote:
>>> Hey John,
>>>   We've noticed that when using usb ethernet adapters on HiKey, we
>>> occasionally see errors like:
>>>
>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 0 - ChHltd set,
>>> but reason is unknown
>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>>
>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set,
>>> but reason is unknown
>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04200029
>>>
>>> Sometimes followed up by a usb error in the driver, something like:
>>> asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length 0x36000807, offset 68
>>>
>>> Curious if you've seen any reports like this?
>>
>> Hey John,
>>   Just wanted to check in again on this to see if you've seen anything
>> like it? I've not had too much time to debug it, but my attempts so
>> far haven't been productive.
>>
>
> I don't think I've seen that.
>
> We'll try to take a look this week.
>
> Thanks,
> John
>
>
>

The core version is less than 2.71a, am I right?
Please send full debug log to do more investigation.
Also send us regdump after connecting ethernet adapter.

Thanks,
Minas

[toc] | [prev] | [next] | [standalone]

#1615675

On Mon, Apr 3, 2017 at 5:54 AM, Minas Harutyunyan
<Minas.Harutyunyan@synopsys.com> wrote:
> On 4/3/2017 9:23 AM, John Youn wrote:
>> On 03/31/2017 04:04 PM, John Stultz wrote:
>>> On Thu, Mar 2, 2017 at 12:00 PM, John Stultz <john.stultz@linaro.org> wrote:
>>>> Hey John,
>>>>   We've noticed that when using usb ethernet adapters on HiKey, we
>>>> occasionally see errors like:
>>>>
>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 0 - ChHltd set,
>>>> but reason is unknown
>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>>>
>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set,
>>>> but reason is unknown
>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04200029
>>>>
>>>> Sometimes followed up by a usb error in the driver, something like:
>>>> asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length 0x36000807, offset 68
>>>>
>>>> Curious if you've seen any reports like this?
>
> The core version is less than 2.71a, am I right?

So it looks like its reporting 0x4f54300a for hsotg->regs + GSNPSID
which looks like DWC2_CORE_REV_3_00a

> Please send full debug log to do more investigation.

Full dmesg, or is there special debugging you want me to enable?

> Also send us regdump after connecting ethernet adapter.

Sorry, can you clarify how to generate this?

thanks
-john

[toc] | [prev] | [next] | [standalone]

#1615741

Hi,

On 4/4/2017 7:04 AM, John Stultz wrote:
> On Mon, Apr 3, 2017 at 5:54 AM, Minas Harutyunyan
> <Minas.Harutyunyan@synopsys.com> wrote:
>> On 4/3/2017 9:23 AM, John Youn wrote:
>>> On 03/31/2017 04:04 PM, John Stultz wrote:
>>>> On Thu, Mar 2, 2017 at 12:00 PM, John Stultz <john.stultz@linaro.org> wrote:
>>>>> Hey John,
>>>>>   We've noticed that when using usb ethernet adapters on HiKey, we
>>>>> occasionally see errors like:
>>>>>
>>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 0 - ChHltd set,
>>>>> but reason is unknown
>>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>>>>
>>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set,
>>>>> but reason is unknown
>>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04200029
>>>>>
>>>>> Sometimes followed up by a usb error in the driver, something like:
>>>>> asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length 0x36000807, offset 68
>>>>>
>>>>> Curious if you've seen any reports like this?
>>
>> The core version is less than 2.71a, am I right?
>
> So it looks like its reporting 0x4f54300a for hsotg->regs + GSNPSID
> which looks like DWC2_CORE_REV_3_00a
>
>> Please send full debug log to do more investigation.
>
> Full dmesg, or is there special debugging you want me to enable?

Full dmesg around issue.
>
>> Also send us regdump after connecting ethernet adapter.
>
> Sorry, can you clarify how to generate this?

cat regdump. To locate dwc2 regdump file: cd /; find -name regdump

>
> thanks
> -john
>

Thanks,
Minas

[toc] | [prev] | [next] | [standalone]

#1615748

[Multipart message — attachments visible in raw view] — view raw

Hi,

Minas Harutyunyan <Minas.Harutyunyan@synopsys.com> writes:
>>>>>>   We've noticed that when using usb ethernet adapters on HiKey, we
>>>>>> occasionally see errors like:
>>>>>>
>>>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 0 - ChHltd set,
>>>>>> but reason is unknown
>>>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>>>>>
>>>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set,
>>>>>> but reason is unknown
>>>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04200029
>>>>>>
>>>>>> Sometimes followed up by a usb error in the driver, something like:
>>>>>> asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length 0x36000807, offset 68
>>>>>>
>>>>>> Curious if you've seen any reports like this?
>>>
>>> The core version is less than 2.71a, am I right?
>>
>> So it looks like its reporting 0x4f54300a for hsotg->regs + GSNPSID
>> which looks like DWC2_CORE_REV_3_00a
>>
>>> Please send full debug log to do more investigation.
>>
>> Full dmesg, or is there special debugging you want me to enable?
>
> Full dmesg around issue.
>>
>>> Also send us regdump after connecting ethernet adapter.
>>
>> Sorry, can you clarify how to generate this?
>
> cat regdump. To locate dwc2 regdump file: cd /; find -name regdump

this won't work if his distro doesn't mount debugfs. Please give
complete instructions ;-)

# mkdir -p /d
# mount -t debugfs none /d
# cd /d
# find . -name regdump

The directory name is the same name as the dwc2 device name, AFAICT. So,
check your DTS for the name of the device.

-- 
balbi

[toc] | [prev] | [next] | [standalone]

#1616915

[Multipart message — attachments visible in raw view] — view raw

Hi,

On 4/4/2017 11:03 PM, John Stultz wrote:
> On Tue, Apr 4, 2017 at 12:38 AM, Felipe Balbi
> <felipe.balbi@linux.intel.com> wrote:
>>
>> Hi,
>>
>> Minas Harutyunyan <Minas.Harutyunyan@synopsys.com> writes:
>>>>>>>>   We've noticed that when using usb ethernet adapters on HiKey, we
>>>>>>>> occasionally see errors like:
>>>>>>>>
>>>>>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 0 - ChHltd set,
>>>>>>>> but reason is unknown
>>>>>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>>>>>>>
>>>>>>>> dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set,
>>>>>>>> but reason is unknown
>>>>>>>> dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04200029
>>>>>>>>
>>>>>>>> Sometimes followed up by a usb error in the driver, something like:
>>>>>>>> asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length 0x36000807, offset 68
>>>>>>>>
>>>>>>>> Curious if you've seen any reports like this?
>>>>>
>>>>> The core version is less than 2.71a, am I right?
>>>>
>>>> So it looks like its reporting 0x4f54300a for hsotg->regs + GSNPSID
>>>> which looks like DWC2_CORE_REV_3_00a
>>>>
>>>>> Please send full debug log to do more investigation.
>>>>
>>>> Full dmesg, or is there special debugging you want me to enable?
>>>
>>> Full dmesg around issue.
>>>>
>>>>> Also send us regdump after connecting ethernet adapter.
>>>>
>>>> Sorry, can you clarify how to generate this?
>>>
>>> cat regdump. To locate dwc2 regdump file: cd /; find -name regdump
>>
>> this won't work if his distro doesn't mount debugfs. Please give
>> complete instructions ;-)
>>
>> # mkdir -p /d
>> # mount -t debugfs none /d
>> # cd /d
>> # find . -name regdump
>>
>> The directory name is the same name as the dwc2 device name, AFAICT. So,
>> check your DTS for the name of the device.
>
> Thanks for the extra details! I didn't have DEBUG_FS built in, so this
> helped clue me in.
>
> Attached are dmesg including the issue and the regdump.
>
> I did notice when cating the regdump file, I saw:
> dwc2 f72c0000.usb: Mode Mismatch Interrupt: currently in Host mode
> twice. (You'll see it 4 times in the dmesg around 1077 as I cat'ed
> regdump again to verify it wasn't just chance).
>
> Let me know if there is anything else you need!
>
> thanks
> -john
>

Could you please apply attached patch and try again.

Thanks,
Minas

[toc] | [prev] | [next] | [standalone]

#1617573

On 4/6/2017 1:03 AM, John Stultz wrote:
>
>
> On Wed, Apr 5, 2017 at 5:58 AM, Minas Harutyunyan
> <Minas.Harutyunyan@synopsys.com <mailto:Minas.Harutyunyan@synopsys.com>>
> wrote:
>> On 4/4/2017 11:03 PM, John Stultz wrote:
>>>
>>> I did notice when cating the regdump file, I saw:
>>> dwc2 f72c0000.usb: Mode Mismatch Interrupt: currently in Host mode
>>> twice. (You'll see it 4 times in the dmesg around 1077 as I cat'ed
>>> regdump again to verify it wasn't just chance).
>>>
>>> Let me know if there is anything else you need!
>>>
>>
>> Could you please apply attached patch and try again.
>
> Thanks for sending this out!
>
> So it didn't build against mainline, but I tweaked it a bit:
> -       if ((hsotg->core_params->dma_enable > 0 &&
> -            hsotg->core_params->dma_desc_enable <= 0) ||
> +       if ((hsotg->params.host_dma > 0 &&
> +            hsotg->params.dma_desc_enable <= 0) ||
>
>
> But I'm still seeing similar behavior:
> [   91.517417] dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 5 -
> ChHltd set, but reason is unknown
> [   91.526693] dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04000029
> [   91.533613] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
> 0x8003a0cc, offset 1302
> [   91.534102] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
> 0x73ff5a7d, offset 4
> [  169.116866] dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 1 -
> ChHltd set, but reason is unknown
> [  169.126146] dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
> [  170.699334] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
> 0x36000807, offset 68
>
> And I'm not seeing the "Channel can't be halted" error from the new logic.
>
> Full dmesg and regdump attached.
>
> Let me know if there is something else I should try.
>
> thanks
> -john
Ok. To enable full dwc2 debug messages, please set USB_DWC2_DEBUG and 
USB_DWC2_VERBOSE in Kernel configuration file.
Also provide the topology of connected devices(class, speed) to dwc2
root hub.
Thanks,
Minas

[toc] | [prev] | [next] | [standalone]

#1618573

[Multipart message — attachments visible in raw view] — view raw

Hi,

John Stultz <john.stultz@linaro.org> writes:
>>>> <Minas.Harutyunyan@synopsys.com <mailto:Minas.Harutyunyan@synopsys.com>>
>>>> wrote:
>>>>> On 4/4/2017 11:03 PM, John Stultz wrote:
>>>>>>
>>>>>> I did notice when cating the regdump file, I saw:
>>>>>> dwc2 f72c0000.usb: Mode Mismatch Interrupt: currently in Host mode
>>>>>> twice. (You'll see it 4 times in the dmesg around 1077 as I cat'ed
>>>>>> regdump again to verify it wasn't just chance).
>>>>>>
>>>>>> Let me know if there is anything else you need!
>>>>>>
>>>>>
>>>>> Could you please apply attached patch and try again.
>>>>
>>>> Thanks for sending this out!
>>>>
>>>> So it didn't build against mainline, but I tweaked it a bit:
>>>> -       if ((hsotg->core_params->dma_enable > 0 &&
>>>> -            hsotg->core_params->dma_desc_enable <= 0) ||
>>>> +       if ((hsotg->params.host_dma > 0 &&
>>>> +            hsotg->params.dma_desc_enable <= 0) ||
>>>>
>>>>
>>>> But I'm still seeing similar behavior:
>>>> [   91.517417] dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 5 -
>>>> ChHltd set, but reason is unknown
>>>> [   91.526693] dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04000029
>>>> [   91.533613] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
>>>> 0x8003a0cc, offset 1302
>>>> [   91.534102] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
>>>> 0x73ff5a7d, offset 4
>>>> [  169.116866] dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 1 -
>>>> ChHltd set, but reason is unknown
>>>> [  169.126146] dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>>> [  170.699334] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
>>>> 0x36000807, offset 68
>>>>
>>>> And I'm not seeing the "Channel can't be halted" error from the new logic.
>>>>
>>>> Full dmesg and regdump attached.
>>>>
>>>> Let me know if there is something else I should try.
>>>>
>>>> thanks
>>>> -john
>>> Ok. To enable full dwc2 debug messages, please set USB_DWC2_DEBUG and
>>> USB_DWC2_VERBOSE in Kernel configuration file.
>>
>> Huh. So interestingly adding USB_DWC2_VERBOSE changes some behavior,
>> which suggests some racy logic somewhere.
>>
>> In the dmesg logs provided earlier, I would unplug the micro-B cable,
>> and the hub would be enabled, detect the mouse, reset to slow-speed,
>> and then both mouse and eth would be detected (see below for topology
>> and quirkiness here).
>>
>> [  609.726186] dwc2 f72c0000.usb: Set speed to high-speed
>> [  609.731529] usb 1-1: new high-speed USB device number 26 using dwc2
>> [  609.921447] dwc2 f72c0000.usb: Set speed to high-speed
>> [  609.949694] hub 1-1:1.0: USB hub found
>> [  609.954067] hub 1-1:1.0: 3 ports detected
>> [  610.246008] dwc2 f72c0000.usb: Set speed to full-speed
>> [  610.251388] usb 1-1.1: new low-speed USB device number 27 using dwc2
>> [  610.486571] usb 1-1: USB disconnect, device number 26
>> [  615.722267] dwc2 f72c0000.usb: Set speed to full-speed
>> [  615.727580] usb 1-1: new full-speed USB device number 31 using dwc2
>> [  615.914674] dwc2 f72c0000.usb: Set speed to full-speed
>> [  615.939233] usb 1-1: not running at top speed; connect to a high speed hub
>> [  615.949500] hub 1-1:1.0: USB hub found
>> [  615.953815] hub 1-1:1.0: 3 ports detected
>> [  616.246178] dwc2 f72c0000.usb: Set speed to full-speed
>> [  616.251539] usb 1-1.1: new low-speed USB device number 32 using dwc2
>> [  616.342042] dwc2 f72c0000.usb: Set speed to full-speed
>> [  616.393609] input: Logitech USB Optical Mouse as
>> /devices/platform/soc/f72c0000.usb/usb1/1-1/1-1.1/1-1.1:1.0/0003:046D:C058.0004/input/in4
>> [  616.408426] hid-generic 0003:046D:C058.0004: input,hidraw0: USB HID
>> v1.11 Mouse [Logitech USB Optical Mouse] on usb-f72c0000.usb-1.1/inpu0
>> [  616.506057] dwc2 f72c0000.usb: Set speed to full-speed
>> [  616.511449] usb 1-1.2: new full-speed USB device number 33 using dwc2
>> [  616.598037] dwc2 f72c0000.usb: Set speed to full-speed
>> [  616.626890] usb 1-1.2: not running at top speed; connect to a high speed hub
>> [  617.098791] asix 1-1.2:1.0 eth0: register 'asix' at
>> usb-f72c0000.usb-1.2, ASIX AX88772B USB 2.0 Ethernet,
>> 00:50:b6:18:82:98
>> [  617.112147] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
>> [  618.660076] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
>> [  618.682072] asix 1-1.2:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1
>>
>>
>> But with DWC2_VERBOSE enabled, I'm usually seeing the following (this
>> is what hit the console, not from the full dmesg output):
>>
>> [   83.658545] dwc2 f72c0000.usb: Set speed to high-speed
>> [   83.663897] usb 1-1: new high-speed USB device number 2 using dwc2
>> [   83.854516] dwc2 f72c0000.usb: Set speed to high-speed
>> [   83.901097] hub 1-1:1.0: USB hub found
>> [   83.910054] hub 1-1:1.0: 3 ports detected
>> [   84.241753] dwc2 f72c0000.usb: Set speed to full-speed
>> [   84.247008] usb 1-1.1: new low-speed USB device number 3 using dwc2
>> [   84.479943] usb 1-1: USB disconnect, device number 2
>> [   89.646499] dwc2 f72c0000.usb: Set speed to full-speed
>> [   89.651849] usb 1-1: new full-speed USB device number 7 using dwc2
>> [   89.842541] dwc2 f72c0000.usb: Set speed to full-speed
>> [   89.879490] usb 1-1: not running at top speed; connect to a high speed hub
>> [   89.906483] hub 1-1:1.0: USB hub found
>> [   89.915009] hub 1-1:1.0: 3 ports detected
>> [   90.245919] dwc2 f72c0000.usb: Set speed to full-speed
>> [   90.251114] usb 1-1.1: new low-speed USB device number 8 using dwc2
>> [   90.337866] dwc2 f72c0000.usb: Set speed to full-speed
>> [   90.385747] input: Logitech USB Optical Mouse as
>> /devices/platform/soc/f72c0000.usb/usb1/1-1/1-1.1/1-1.1:1.0/0003:046D:C058.0001/input/in1
>> [   90.398904] hid-generic 0003:046D:C058.0001: input,hidraw0: USB HID
>> v1.11 Mouse [Logitech USB Optical Mouse] on usb-f72c0000.usb-1.1/inpu0
>> [   90.414011] hub 1-1:1.0: hub_ext_port_status failed (err = -71)
>>
>> And the eth adapter doesn't seem to be detected.
>>
>> So I've attached the dmesg w/ VERBOSE off, but with DEBUG on.
>
> I went ahead and collected the VERBOSE logs too around the
> "dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set, but reason is
> unknown" message.  That VERBOSE flag generates a lot of data! I set my
> kernel dmesg buffer to 16M and managed save dmesg quickly after I
> noticed the error message, but I only got ~25 seconds around the
> event.

you can replace all dev_*() messages with trace_printk() and use the
ftrace buffer for logging. I generally use 100MiB trace buffer without
any issues :-)

-- 
balbi

[toc] | [prev] | [next] | [standalone]

#1618756

Hi,

On 4/7/2017 12:18 PM, Felipe Balbi wrote:
>
> Hi,
>
> John Stultz <john.stultz@linaro.org> writes:
>>>>> <Minas.Harutyunyan@synopsys.com <mailto:Minas.Harutyunyan@synopsys.com>>
>>>>> wrote:
>>>>>> On 4/4/2017 11:03 PM, John Stultz wrote:
>>>>>>>
>>>>>>> I did notice when cating the regdump file, I saw:
>>>>>>> dwc2 f72c0000.usb: Mode Mismatch Interrupt: currently in Host mode
>>>>>>> twice. (You'll see it 4 times in the dmesg around 1077 as I cat'ed
>>>>>>> regdump again to verify it wasn't just chance).
>>>>>>>
>>>>>>> Let me know if there is anything else you need!
>>>>>>>
>>>>>>
>>>>>> Could you please apply attached patch and try again.
>>>>>
>>>>> Thanks for sending this out!
>>>>>
>>>>> So it didn't build against mainline, but I tweaked it a bit:
>>>>> -       if ((hsotg->core_params->dma_enable > 0 &&
>>>>> -            hsotg->core_params->dma_desc_enable <= 0) ||
>>>>> +       if ((hsotg->params.host_dma > 0 &&
>>>>> +            hsotg->params.dma_desc_enable <= 0) ||
>>>>>
>>>>>
>>>>> But I'm still seeing similar behavior:
>>>>> [   91.517417] dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 5 -
>>>>> ChHltd set, but reason is unknown
>>>>> [   91.526693] dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x04000029
>>>>> [   91.533613] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
>>>>> 0x8003a0cc, offset 1302
>>>>> [   91.534102] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
>>>>> 0x73ff5a7d, offset 4
>>>>> [  169.116866] dwc2 f72c0000.usb: dwc2_hc_chhltd_intr_dma: Channel 1 -
>>>>> ChHltd set, but reason is unknown
>>>>> [  169.126146] dwc2 f72c0000.usb: hcint 0x00000002, intsts 0x06200029
>>>>> [  170.699334] asix 1-1.2:1.0 eth0: asix_rx_fixup() Bad Header Length
>>>>> 0x36000807, offset 68
>>>>>
>>>>> And I'm not seeing the "Channel can't be halted" error from the new logic.
>>>>>
>>>>> Full dmesg and regdump attached.
>>>>>
>>>>> Let me know if there is something else I should try.
>>>>>
>>>>> thanks
>>>>> -john
>>>> Ok. To enable full dwc2 debug messages, please set USB_DWC2_DEBUG and
>>>> USB_DWC2_VERBOSE in Kernel configuration file.
>>>
>>> Huh. So interestingly adding USB_DWC2_VERBOSE changes some behavior,
>>> which suggests some racy logic somewhere.
>>>
>>> In the dmesg logs provided earlier, I would unplug the micro-B cable,
>>> and the hub would be enabled, detect the mouse, reset to slow-speed,
>>> and then both mouse and eth would be detected (see below for topology
>>> and quirkiness here).
>>>
>>> [  609.726186] dwc2 f72c0000.usb: Set speed to high-speed
>>> [  609.731529] usb 1-1: new high-speed USB device number 26 using dwc2
>>> [  609.921447] dwc2 f72c0000.usb: Set speed to high-speed
>>> [  609.949694] hub 1-1:1.0: USB hub found
>>> [  609.954067] hub 1-1:1.0: 3 ports detected
>>> [  610.246008] dwc2 f72c0000.usb: Set speed to full-speed
>>> [  610.251388] usb 1-1.1: new low-speed USB device number 27 using dwc2
>>> [  610.486571] usb 1-1: USB disconnect, device number 26
>>> [  615.722267] dwc2 f72c0000.usb: Set speed to full-speed
>>> [  615.727580] usb 1-1: new full-speed USB device number 31 using dwc2
>>> [  615.914674] dwc2 f72c0000.usb: Set speed to full-speed
>>> [  615.939233] usb 1-1: not running at top speed; connect to a high speed hub
>>> [  615.949500] hub 1-1:1.0: USB hub found
>>> [  615.953815] hub 1-1:1.0: 3 ports detected
>>> [  616.246178] dwc2 f72c0000.usb: Set speed to full-speed
>>> [  616.251539] usb 1-1.1: new low-speed USB device number 32 using dwc2
>>> [  616.342042] dwc2 f72c0000.usb: Set speed to full-speed
>>> [  616.393609] input: Logitech USB Optical Mouse as
>>> /devices/platform/soc/f72c0000.usb/usb1/1-1/1-1.1/1-1.1:1.0/0003:046D:C058.0004/input/in4
>>> [  616.408426] hid-generic 0003:046D:C058.0004: input,hidraw0: USB HID
>>> v1.11 Mouse [Logitech USB Optical Mouse] on usb-f72c0000.usb-1.1/inpu0
>>> [  616.506057] dwc2 f72c0000.usb: Set speed to full-speed
>>> [  616.511449] usb 1-1.2: new full-speed USB device number 33 using dwc2
>>> [  616.598037] dwc2 f72c0000.usb: Set speed to full-speed
>>> [  616.626890] usb 1-1.2: not running at top speed; connect to a high speed hub
>>> [  617.098791] asix 1-1.2:1.0 eth0: register 'asix' at
>>> usb-f72c0000.usb-1.2, ASIX AX88772B USB 2.0 Ethernet,
>>> 00:50:b6:18:82:98
>>> [  617.112147] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
>>> [  618.660076] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
>>> [  618.682072] asix 1-1.2:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1
>>>
>>>
>>> But with DWC2_VERBOSE enabled, I'm usually seeing the following (this
>>> is what hit the console, not from the full dmesg output):
>>>
>>> [   83.658545] dwc2 f72c0000.usb: Set speed to high-speed
>>> [   83.663897] usb 1-1: new high-speed USB device number 2 using dwc2
>>> [   83.854516] dwc2 f72c0000.usb: Set speed to high-speed
>>> [   83.901097] hub 1-1:1.0: USB hub found
>>> [   83.910054] hub 1-1:1.0: 3 ports detected
>>> [   84.241753] dwc2 f72c0000.usb: Set speed to full-speed
>>> [   84.247008] usb 1-1.1: new low-speed USB device number 3 using dwc2
>>> [   84.479943] usb 1-1: USB disconnect, device number 2
>>> [   89.646499] dwc2 f72c0000.usb: Set speed to full-speed
>>> [   89.651849] usb 1-1: new full-speed USB device number 7 using dwc2
>>> [   89.842541] dwc2 f72c0000.usb: Set speed to full-speed
>>> [   89.879490] usb 1-1: not running at top speed; connect to a high speed hub
>>> [   89.906483] hub 1-1:1.0: USB hub found
>>> [   89.915009] hub 1-1:1.0: 3 ports detected
>>> [   90.245919] dwc2 f72c0000.usb: Set speed to full-speed
>>> [   90.251114] usb 1-1.1: new low-speed USB device number 8 using dwc2
>>> [   90.337866] dwc2 f72c0000.usb: Set speed to full-speed
>>> [   90.385747] input: Logitech USB Optical Mouse as
>>> /devices/platform/soc/f72c0000.usb/usb1/1-1/1-1.1/1-1.1:1.0/0003:046D:C058.0001/input/in1
>>> [   90.398904] hid-generic 0003:046D:C058.0001: input,hidraw0: USB HID
>>> v1.11 Mouse [Logitech USB Optical Mouse] on usb-f72c0000.usb-1.1/inpu0
>>> [   90.414011] hub 1-1:1.0: hub_ext_port_status failed (err = -71)
>>>
>>> And the eth adapter doesn't seem to be detected.
>>>
>>> So I've attached the dmesg w/ VERBOSE off, but with DEBUG on.
>>
>> I went ahead and collected the VERBOSE logs too around the
>> "dwc2_hc_chhltd_intr_dma: Channel 11 - ChHltd set, but reason is
>> unknown" message.  That VERBOSE flag generates a lot of data! I set my
>> kernel dmesg buffer to 16M and managed save dmesg quickly after I
>> noticed the error message, but I only got ~25 seconds around the
>> event.
>
> you can replace all dev_*() messages with trace_printk() and use the
> ftrace buffer for logging. I generally use 100MiB trace buffer without
> any issues :-)
>

Based on HiKey data book, to USB ports (typeA) can be connected devices
only with same speed. In your case mouse is Low speed and Ethernet
dongle connected as Full speed. It can be cause of issue.
Did you tested Ethernet dongle (in High and Full speed modes) without
connecting mouse? If it work (in Full speed) then connect mouse and see
how it affect on Ethernet.
Thanks,
Minas

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web