DMARC-Filter: OpenDMARC Filter v1.3.2 mx1.redhat.com 1B8C3C02C738
Subject: Re: USB disk speed regression WD Elements - with bisect result
 22547c4cc4fe20698a6a85a55b8788859134b8e4
To: Alan Stern <stern@rowland.harvard.edu>,
        Guenter Roeck <linux@roeck-us.net>
Cc: LKML <linux-kernel@vger.kernel.org>, dianders@chromium.org,
        gregkh@linuxfoundation.org
References: <Pine.LNX.4.44L0.1707261022050.1965-100000@iolanthe.rowland.org>
From: Zdenek Kabelac <zkabelac@redhat.com>
Organization: Red Hat
Message-ID: <da0cd128-4ed6-fd7a-37a9-2fe49afb4fa9@redhat.com>
Date: Wed, 26 Jul 2017 16:36:36 +0200
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101
 Thunderbird/52.2.0
MIME-Version: 1.0
In-Reply-To: <Pine.LNX.4.44L0.1707261022050.1965-100000@iolanthe.rowland.org>
Content-Type: text/plain; charset=iso-8859-2; format=flowed
Content-Language: en-US
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
Content-Length: 2635
Lines: 68

Dne 26.7.2017 v 16:28 Alan Stern napsal(a):
> On Tue, 25 Jul 2017, Guenter Roeck wrote:
> 
>> On 07/25/2017 12:50 PM, Alan Stern wrote:
>>> On Tue, 25 Jul 2017, Zdenek Kabelac wrote:
>>>
>>>> Dne 25.7.2017 v 19:02 Alan Stern napsal(a):
>>>>> On Tue, 25 Jul 2017, Zdenek Kabelac wrote:
>>>>>
>>>>>> And in fact it's the very same commit - which adds this message
>>>>>> (just check current 4.13 with and without this commit reverted)
>>>>>>
>>>>>> So here goes usbmon trace (aka  'cat /sys/kernel/debug/usb/usbmon/0u')
>>>>>> no other usb device has been touch so should not hopefully interfere here.
>>>>>>
>>>>>> Trace is from 4.12 kernel - so it has reported  "not running at top speed"
>>>>>
>>>>> Can you collect an equivalent trace under 4.8?
>>>>>
>>>>> Alan Stern
>>>>>
>>>>
>>>> Hi
>>>>
>>>>
>>>> Sure - no pb.
>>>>
>>>> Just attached & detached  USB disk in this trace
>>>
>>> This is really peculiar.  The only difference is that the 4.12 trace
>>> shows an extra 250 ms delay (including two extra Get-Port-Status
>>
>> Most likely we are now catching the long reset timeout. HUB_LONG_RESET_TIME
>> is 200 ms. It looks like the code is catching exactly the condition
>> addressed in my patch, ie USB_PORT_STAT_RESET is cleared but
>> USB_PORT_STAT_CONNECTION is not yet set. hub_port_wait_reset() will
>> now wait for USB_PORT_STAT_CONNECTION, which it didn't do before.
>>
>>> requests) compared to the 4.8 trace.  I honestly can't tell what could
>>> be causing the switch from high speed to full speed, or why it would
>>> happen in one case but not the other.
>>>
>>
>> We talked about this today. What is causing the switch from high speed to
>> full speed ? Is this triggered by the kernel, or by the USB controller ?
> 
> A little of both.  When a reset completes, if the device does not
> follow the high-speed chirp protocol, the EHCI status registers show
> that the port is not enabled.  When the driver sees that, it sets a bit
> that causes the connection to be moved over from the high-speed EHCI
> controller to the companion full-speed UHCI controller.  The code that
> does this is in check_reset_complete() in ehci-hub.c.


Well I do have 4.13-rc1 kernel - where the only difference is the revert
of mentioned patched - so I can provide probably traces from this one if that
helps anything.

What is not quite clear to me - why T440 works.

Could this be in some way related to the fact that T61 is USB2 only old lenovo 
machine while T440 works with  USB3 (new SuperSpeed USB device number...)

So maybe there is some time-sensitive logic - where WD Elements
decides to be USB2 or USB3 device ???


Zdenek