Message-ID: <56F19C6C.7000203@synopsys.com>
Date:	Tue, 22 Mar 2016 12:26:36 -0700
From:	John Youn <John.Youn@...opsys.com>
To:	Doug Anderson <dianders@...omium.org>,
	John Youn <John.Youn@...opsys.com>
CC:	Stefan Wahren <stefan.wahren@...e.com>,
	Michael Niewoehner <linux@...ewoehner.de>,
	Tao Huang <huangtao@...k-chips.com>,
	Julius Werner <jwerner@...omium.org>,
	Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
	"linux-kernel@...r.kernel.org" <linux-kernel@...r.kernel.org>,
	"linux-usb@...r.kernel.org" <linux-usb@...r.kernel.org>,
	Caesar Wang <caesar.upstream@...il.com>,
	Heiko Stuebner <heiko@...ech.de>,
	Felipe Balbi <balbi@...nel.org>,
	Remi Pommarel <repk@...plefau.lt>,
	Kever Yang <kever.yang@...k-chips.com>
Subject: Re: [RFT PATCH 2/2] Revert "usb: dwc2: Fix probe problem on bcm2835"

On 3/18/2016 10:21 PM, Doug Anderson wrote:
> Hi,
> 
> On Wed, Mar 16, 2016 at 11:28 AM, John Youn <John.Youn@...opsys.com> wrote:
>> On 3/10/2016 11:14 AM, John Youn wrote:
>>> On 3/9/2016 11:06 AM, Doug Anderson wrote:
>>>> Stefan,
>>>>
>>>> On Wed, Mar 9, 2016 at 11:01 AM, Stefan Wahren <stefan.wahren@...e.com> wrote:
>>>>>
>>>>>> Doug Anderson <dianders@...omium.org> hat am 7. März 2016 um 22:30
>>>>>> geschrieben:
>>>>>>
>>>>>>
>>>>>> Stefan,
>>>>>>
>>>>>> On Mon, Mar 7, 2016 at 10:40 AM, Stefan Wahren <stefan.wahren@...e.com> wrote:
>>>>>>> Hi Doug,
>>>>>>>
>>>>>>>> Douglas Anderson <dianders@...omium.org> hat am 4. März 2016 um 19:23
>>>>>>>> geschrieben:
>>>>>>>>
>>>>>>>>
>>>>>>>> This reverts commit 192cb07f7928 ("usb: dwc2: Fix probe problem on
>>>>>>>> bcm2835") now that we've found the root cause. See the change
>>>>>>>> titled ("usb: dwc2: Add a 10 ms delay to dwc2_core_reset()").
>>>>>>>
>>>>>>> adding a delay of 10 ms after a core reset might be a idea, but applying
>>>>>>> both
>>>>>>> patches breaks USB support on RPi :-(
>>>>>>>
>>>>>>> I'm getting the wrong register values ...
>>>>>>
>>>>>> Ugh. :(
>>>>>>
>>>>>> Just out of curiosity, if you loop and time long it takes for the
>>>>>> registers to get to the right state after reset, what do you get?
>>>>>> AKA, pick:
>>>>>>
>>>>>> https://chromium-review.googlesource.com/331260
>>>>>>
>>>>>> ...and let me know what it prints out.
>>>>>
>>>>> On my Raspberry Pi B i get the following:
>>>>>
>>>>> [    2.084411] dwc2 20980000.usb: mapped PA 20980000 to VA cc880000
>>>>> [    2.084461] dwc2 20980000.usb: cannot get otg clock
>>>>> [    2.084549] dwc2 20980000.usb: registering common handler for irq33
>>>>> [    2.084713] dwc2 20980000.usb: Configuration mismatch. dr_mode forced to host
>>>>> [    2.153965] dwc2 20980000.usb: Waited 49996 us, 0x00201000 => 0x01001000,
>>>>> 0x00000000 => 0x02002000
>>>>> [    2.174930] dwc2 20980000.usb: Forcing mode to host
>>>>>
>>>>> So i changed the delay in patch #1 to msleep(50) and then both patches work like
>>>>> a charm.
>>>>
>>>> Great news!  :-)
>>>>
>>>> John: it's pretty clear that there's something taking almost exactly
>>>> 10ms on my system and almost exactly 50ms on Stefan's system.  Is
>>>> there some register we could poll to see when this process is done?
>>>> ...or can we look at the dwc2 revision number / feature register and
>>>> detect how long to delay?
>>>>
>>>
>>> Hi Doug,
>>>
>>> I'll have to ask around to see if anyone knows about this. And I'll
>>> run some tests on the platforms I have available to me as well.
>>>
>>
>> There's still nothing definitive on our end as to why this is
>> happening. Also I don't think there is any other way to poll the
>> reset.
> 
> One thing I noticed is that the delay was only needed on my OTG port
> (not my host-only port).  ...I also noticed that while waiting the
> HPTXFSIZ was temporarily 0x00000000 while I was delaying.  That seems
> to match Stephan.
> 
> I wonder if perhaps the delay has to do with how long it took to
> detect that it needed to go into host mode?
> 
> Ah, interesting.  It looks as if "GOTGCTL" changes during this time
> too.  To summarize:
> 
> HOST-only (ff540000.usb): needs no delay:
>   GNPTXFSIZ: 0x04000400
>   HPTXFSIZ: 0x02000800
>   GOTGCTL: 0x002d0000
> 
> OTG (ff580000): needs 10ms delay.  Before delay:
>   GNPTXFSIZ: 0x00100400
>   HPTXFSIZ: 0x00000000
>   GOTGCTL: 0x00010000
> After delay:
>   GNPTXFSIZ: 0x04000400
>   HPTXFSIZ: 0x02000800
>   GOTGCTL: 0x002c0000
> 
> Could we loop until either BSesVld or ASesVld is set?  Don't know much
> about OTG, but seems like that might be something sane?
> 
>> Our hardware engineers asked for some more information to look
>> into it further. Doug, Stefan, Caesar, and anyone else with a related
>> platform, do you know the answers to the following:
>>
>> 1. What is the AHB Clock frequency? Is the AHB Clock gated during
>> Reset?
> 
> According to commit 20bde643434d ("usb: dwc2: reduce dwc2 driver probe
> time"), our AHB clock is 150MHz.  I'm nearly certain it is not gated.
> 
> 
>> 2. Also is the PHY clock stopped during the reset or is the PHY PLL
>> lock times high in the order of ms?
> 
> I don't think so.
> 
> 
>> 3. In these cases, is the PHY actually an FS Transceiver and not a
>> UTMI/ULPI PHY?
> 
> I don't think so.  Should be answered by debug info spew below...
> 
> 
>> 4. Which version of the controller is being used in these cases?
> 
> There are two controllers in my case and they behave differently.  OTG
> takes 10ms and the host-only 0ms.
> 
> Here is debug info:
> 
> [    1.752005] dwc2 ff540000.usb: Core Release: 3.10a (snpsid=4f54310a)
> [    1.758350] dwc2 ff540000.usb: hwcfg1=00000000
> [    1.762807] dwc2 ff540000.usb: hwcfg2=228fc856
> [    1.767245] dwc2 ff540000.usb: hwcfg3=03c0c068
> [    1.771693] dwc2 ff540000.usb: hwcfg4=c8004030
> [    1.776149] dwc2 ff540000.usb: grxfsiz=00000400
> [    1.780687] dwc2 ff540000.usb: gnptxfsiz=04000400
> [    1.785402] dwc2 ff540000.usb: hptxfsiz=02000800
> [    1.790024] dwc2 ff540000.usb: Detected values from hardware:
> [    1.795781] dwc2 ff540000.usb:   op_mode=6
> [    1.799872] dwc2 ff540000.usb:   arch=2
> [    1.817620] dwc2 ff540000.usb:   dma_desc_enable=1
> [    1.955925] dwc2 ff540000.usb:   power_optimized=1
> [    2.022862] dwc2 ff540000.usb:   i2c_enable=0
> [    2.027220] dwc2 ff540000.usb:   hs_phy_type=1
> [    2.031657] dwc2 ff540000.usb:   fs_phy_type=0
> [    2.036101] dwc2 ff540000.usb:   utmi_phy_data_wdith=1
> [    2.041231] dwc2 ff540000.usb:   num_dev_ep=2
> [    2.045586] dwc2 ff540000.usb:   num_dev_perio_in_ep=0
> [    2.050717] dwc2 ff540000.usb:   host_channels=16
> [    2.055420] dwc2 ff540000.usb:   max_transfer_size=524287
> [    2.060811] dwc2 ff540000.usb:   max_packet_count=1023
> [    2.065946] dwc2 ff540000.usb:   nperio_tx_q_depth=0x4
> [    2.071076] dwc2 ff540000.usb:   host_perio_tx_q_depth=0x4
> [    2.076556] dwc2 ff540000.usb:   dev_token_q_depth=0x8
> [    2.081686] dwc2 ff540000.usb:   enable_dynamic_fifo=1
> [    2.086824] dwc2 ff540000.usb:   en_multiple_tx_fifo=0
> [    2.099436] dwc2 ff540000.usb:   total_fifo_size=960
> [    2.204560] dwc2 ff540000.usb:   host_rx_fifo_size=1024
> [    2.209780] dwc2 ff540000.usb:   host_nperio_tx_fifo_size=1024
> [    2.712045] dwc2 ff540000.usb:   host_perio_tx_fifo_size=512
> 
> [    2.872149] dwc2 ff580000.usb: Core Release: 3.10a (snpsid=4f54310a)
> [    2.872153] dwc2 ff580000.usb: hwcfg1=00006664
> [    2.872156] dwc2 ff580000.usb: hwcfg2=228e2450
> [    2.872158] dwc2 ff580000.usb: hwcfg3=03cc90e8
> [    2.872160] dwc2 ff580000.usb: hwcfg4=dbf04030
> [    2.872163] dwc2 ff580000.usb: grxfsiz=00000400
> [    2.872166] dwc2 ff580000.usb: gnptxfsiz=04000400
> [    2.872168] dwc2 ff580000.usb: hptxfsiz=02000800
> [    2.872171] dwc2 ff580000.usb: Detected values from hardware:
> [    2.872173] dwc2 ff580000.usb:   op_mode=0
> [    2.872175] dwc2 ff580000.usb:   arch=2
> [    2.872177] dwc2 ff580000.usb:   dma_desc_enable=1
> [    2.872179] dwc2 ff580000.usb:   power_optimized=1
> [    2.872181] dwc2 ff580000.usb:   i2c_enable=0
> [    2.872183] dwc2 ff580000.usb:   hs_phy_type=1
> [    2.872186] dwc2 ff580000.usb:   fs_phy_type=0
> [    2.872188] dwc2 ff580000.usb:   utmi_phy_data_wdith=1
> [    2.872190] dwc2 ff580000.usb:   num_dev_ep=9
> [    2.872192] dwc2 ff580000.usb:   num_dev_perio_in_ep=0
> [    2.872194] dwc2 ff580000.usb:   host_channels=9
> [    2.872196] dwc2 ff580000.usb:   max_transfer_size=524287
> [    2.872198] dwc2 ff580000.usb:   max_packet_count=1023
> [    2.872201] dwc2 ff580000.usb:   nperio_tx_q_depth=0x4
> [    2.872203] dwc2 ff580000.usb:   host_perio_tx_q_depth=0x4
> [    2.872205] dwc2 ff580000.usb:   dev_token_q_depth=0x8
> [    2.872207] dwc2 ff580000.usb:   enable_dynamic_fifo=1
> [    2.872209] dwc2 ff580000.usb:   en_multiple_tx_fifo=1
> [    2.872211] dwc2 ff580000.usb:   total_fifo_size=972
> [    2.872213] dwc2 ff580000.usb:   host_rx_fifo_size=1024
> [    2.872215] dwc2 ff580000.usb:   host_nperio_tx_fifo_size=1024
> [    2.872217] dwc2 ff580000.usb:   host_perio_tx_fifo_size=512
> 

Thanks for the debug logs and everyones help.

After reviewing with our hardware engineers, it seems this is likely
to do with the IDDIG debounce filtering when switching between
modes. You can see if this is enabled in your core by checking
GHWCFG4.IddgFltr.

>From the databook:

    OTG_EN_IDDIG_FILTER

    Specifies whether to add a filter on the "iddig" input from the
    PHY. If your PHY already has a filter on iddig for de-bounce, then
    it is not necessary to enable the one in the DWC_otg.  The filter
    is implemented in the DWC_otg_wpc module as a 20-bit counter that
    works on the PHY clock. In the case of the UTMI+ PHY, this pin is
    from the PHY. In the case of the ULPI PHY, this signal is
    generated by the ULPI Wrapper inside the core.


This only affects OTG cores and the delay is 10ms for 30MHz PHY clock
and 50ms with a 6MHz PHY clock.

The reason we see this after a reset is that by default the IDDIG
indicates device mode. But if the id pin is set to host the core will
immediately detect it after the reset and trigger the filtering delay
before changing to host mode.

This delay is also triggered by force mode. This is the origin of the
25 ms delay specified in the databook. The databook did not take into
account that there might be a 6MHz clock so this delay could actually
be up to 50 ms. So we aren't delaying enough time for those cases.

I think this explains all the problems and platform differences we are
seeing related to this.

I think we can just add an IDDIG delay after a force mode, a clear
force mode, and any time after reset where we don't do either a force
or clear force mode immediately afterwards. Maybe set the delay time
via a core parameter or measure it once on probe. Or we can probably
just poll for the mode change in all of the above conditions.

Doug,

Are you able to continue looking into this? If not, I can take it up.

Regards,
John

Powered by blists - more mailing lists