Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Wed, 21 Sep 2016, Ritesh Raj Sarraf wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
> 
> Hi Alan,
> 
> On Tue, 2016-09-20 at 10:16 -0400, Alan Stern wrote:
> > This is a lot better.  No more I/O errors.
> > 
> > We still have irregular suspends and resumes, but that's to be 
> > expected.  More worrying are the spontaneous disconnects.  They don't 
> > seem to be related to the suspend/resume activity.
> > 
> > You can disable suspend for this device entirely by doing:
> > 
> > echo on >/sys/bus/usb/devices/2-4/power/control
> > 
> > I'm afraid that this won't prevent the device from disconnecting
> > itself, though.  This appears to be some sort of hardware bug that
> > can't be fixed in software.
> 
> I'm not sure what you were referring to when you said "No more I/O errors".

I was referring to the attempts at I/O while the device was suspended.  
They didn't occur in your most recent test.

> But I still got these errors today, with all patches applied.
> 
> Sep 21 14:58:11 learner kernel: usb 2-4: new high-speed USB device number 98
> using xhci_hcd
> Sep 21 14:58:18 learner kernel: usb 2-4: new high-speed USB device number 102
> using xhci_hcd
> Sep 21 14:58:24 learner kernel: usb 2-4: new high-speed USB device number 106
> using xhci_hcd
> Sep 21 14:58:31 learner kernel: usb 2-4: new high-speed USB device number 114
> using xhci_hcd
> Sep 21 14:58:41 learner kernel: usb 2-4: new high-speed USB device number 12
> using xhci_hcd
> Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 14:58:41 learner kernel: usb 2-4: new high-speed USB device number 13
> using xhci_hcd

These are a completely different kind of error.  They occurred during a 
reset, which followed one of those spontaneous disconnects.  Probably 
the cause of the disconnect is also the cause of these errors.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Ulf,

On Wed, 2016-09-21 at 13:17 +0200, Ulf Hansson wrote:
> 
> I am pretty sure the memstick driver causes additional access to the
> usb device without first calling pm_runtime_get_sync(). To eliminate
> those cases from causing the issues, could you try disable the
> memstick driver all-together?

I'm assuming you are referring to the rtsx_usb_ms driver ?

What is the oddest thing right now, is that none of the rtsx modules are
reported loaded.

rrs@learner:~$ lsmod | grep -i rts
2016-09-21 / 17:07:08 ♒♒♒  ☹  => 1  

where as the module was built for the kernel, and does load when asked manually.

rrs@learner:~$ less /boot/config-4.8.0-rc7alxb+ 
2016-09-21 / 17:07:54 ♒♒♒  ☺  
rrs@learner:~$ find /lib/modules/4.8.0-rc7alxb+/ | grep rtsx
/lib/modules/4.8.0-rc7alxb+/kernel/drivers/mmc/host/rtsx_usb_sdmmc.ko
/lib/modules/4.8.0-rc7alxb+/kernel/drivers/mmc/host/rtsx_pci_sdmmc.ko
/lib/modules/4.8.0-rc7alxb+/kernel/drivers/mfd/rtsx_usb.ko
/lib/modules/4.8.0-rc7alxb+/kernel/drivers/mfd/rtsx_pci.ko
/lib/modules/4.8.0-rc7alxb+/kernel/drivers/memstick/host/rtsx_pci_ms.ko
/lib/modules/4.8.0-rc7alxb+/kernel/drivers/memstick/host/rtsx_usb_ms.ko
2016-09-21 / 17:08:09 ♒♒♒  ☺  

rrs@learner:~$ sudo modprobe rtsx-usb-sdmmc
2016-09-21 / 17:08:46 ♒♒♒  ☺  

rrs@learner:~$ dmesg | tail -n 5
[ 6870.017311] usb 2-4: Device not responding to setup address.
[ 6870.223471] usb 2-4: device not accepting address 19, error -71
[ 6870.223536] usb usb2-port4: unable to enumerate USB device
[ 7958.474543] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure
on pipe A (start=166356 end=166357) time 3 us, min 1073, max 1079, scanline
start 1088, end 1080
[ 9814.785241] usbcore: registered new interface driver rtsx_usb
2016-09-21 / 17:10:07 ♒♒♒  ☺  



- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX4nIMAAoJEKY6WKPy4XVpg4gP/Rkp5Wje2vTUHwnrJZzAKd65
V1VWkTyCfpbCTw4nAyMbzDevyoXJf3P+ktrcyQonvoZr/dsd/LOmjSXcjNJaFX0z
Vj+1lGOZeN1mr6vKMbh2y188oU4RyHkeCfg7SNdo1VuhVST/m2jOecCznXuEtpiS
TI66lmre0SNRusKHRQNDtaP4hFW0KDBmtXvc8pnNOL5781qua0pF12VIP5SsqriP
3d/DcqlVR0Lqh7X7wdt5Knp9ilSvsrCgGbimBarRUYnrOrhklJH9UwKXcHWVypzt
M0XvjO7R6JrBUoM6s8EA6gKmNxwlsIrjKFUFlTT6HPLb52fjpYkbYqCRUmqyIJZB
t3uA0hNKcqLav+Fg7ugT6ePAPeVkANDnbrPE+g69KOtM/CEJHbHkLxqznb/0lpMU
+SAp/Jz1CmDLt8M3s8gS9iCUWVrWy1oyDpMQsYIrTYOG6oOEOoTYEf/g5D6PBtY0
r1tD5bU/cZJV61YKer2xRDNu1YbAYkvX3XskFD7DFsnZpCyBXKGZ7gWpWety9kJJ
iBiqvn5Rk7jvL6EhIb/TQ867QLmhQCzZumPClFM4z7b8G2E440vykw5D5sKv91+H
qu9Abcxe0R0T9pxCFRz+//DYlxGvDDlUSyNBkrv6aGS1rNeDY/e4FWbNuEz9UoGn
LNiunOtwzBndajfEFETk
=tEAz
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ulf Hansson]

On 21 September 2016 at 13:10, Ritesh Raj Sarraf  wrote:
> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
>
> Hi Alan,
>
> On Tue, 2016-09-20 at 10:16 -0400, Alan Stern wrote:
>> This is a lot better.  No more I/O errors.
>>
>> We still have irregular suspends and resumes, but that's to be
>> expected.  More worrying are the spontaneous disconnects.  They don't
>> seem to be related to the suspend/resume activity.
>>
>> You can disable suspend for this device entirely by doing:
>>
>> echo on >/sys/bus/usb/devices/2-4/power/control
>>
>> I'm afraid that this won't prevent the device from disconnecting
>> itself, though.  This appears to be some sort of hardware bug that
>> can't be fixed in software.
>
> I'm not sure what you were referring to when you said "No more I/O errors".
> But I still got these errors today, with all patches applied.
>
> Sep 21 14:58:11 learner kernel: usb 2-4: new high-speed USB device number 98
> using xhci_hcd
> Sep 21 14:58:18 learner kernel: usb 2-4: new high-speed USB device number 102
> using xhci_hcd
> Sep 21 14:58:24 learner kernel: usb 2-4: new high-speed USB device number 106
> using xhci_hcd
> Sep 21 14:58:31 learner kernel: usb 2-4: new high-speed USB device number 114
> using xhci_hcd
> Sep 21 14:58:41 learner kernel: usb 2-4: new high-speed USB device number 12
> using xhci_hcd
> Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 14:58:41 learner kernel: usb 2-4: new high-speed USB device number 13
> using xhci_hcd
> Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 14:58:42 learner kernel: usb 2-4: new high-speed USB device number 14
> using xhci_hcd
> Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup 
> address.
> Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup 
> address.
> Sep 21 14:58:42 learner kernel: usb 2-4: device not accepting address 14, 
> error
> - -71
> Sep 21 14:58:42 learner kernel: usb 2-4: new high-speed USB device number 15
> using xhci_hcd
> Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup 
> address.
> Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup 
> address.
> Sep 21 14:58:43 learner kernel: usb 2-4: device not accepting address 15, 
> error
> - -71
> Sep 21 14:58:43 learner kernel: usb usb2-port4: unable to enumerate USB device
> Sep 21 16:19:39 learner kernel: ahci :00:1f.2: port does not support 
> device
> sleep
> Sep 21 16:19:39 learner kernel: NMI watchdog: enabled on all CPUs, permanently
> consumes one hw-
> Sep 21 16:19:39 learner kernel: EXT4-fs (dm-0): re-mounted. Opts:
> errors=remount-ro,data=ordere
> Sep 21 16:19:39 learner kernel: EXT4-fs (sda6): re-mounted. Opts:
> data=ordered,commit=0
> Sep 21 16:19:39 learner kernel: EXT4-fs (dm-3): re-mounted. Opts:
> errors=remount-ro,data=writeb
> Sep 21 16:19:39 learner kernel: usb 2-4: new high-speed USB device number 16
> using xhci_hcd
> Sep 21 16:19:39 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 16:19:40 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 16:19:40 learner kernel: usb 2-4: new high-speed USB device number 17
> using xhci_hcd
> Sep 21 16:19:40 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 16:19:40 learner kernel: usb 2-4: device descriptor read/64, error -71
> Sep 21 16:19:40 learner kernel: usb 2-4: new high-speed USB device number 18
> using xhci_hcd
> Sep 21 16:19:40 learner kernel: usb 2-4: Device not responding to setup 
> address.
> Sep 21 16:19:41 learner kernel: usb 2-4: Device not responding to setup 
> address.
> Sep 21 16:19:41 learner kernel: usb 2-4: device not accepting address 18, 
> error
> - -71
> Sep 21 16:19:41 learner kernel: usb 2-4: new high-speed USB device number 19
> using xhci_hcd
>

I am pretty sure the memstick driver causes additional access to the
usb device without first calling pm_runtime_get_sync(). To eliminate
those cases from causing the issues, could you try disable the
memstick driver all-together?

Kind regards
Uffe
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hi Alan,

On Tue, 2016-09-20 at 10:16 -0400, Alan Stern wrote:
> This is a lot better.  No more I/O errors.
> 
> We still have irregular suspends and resumes, but that's to be 
> expected.  More worrying are the spontaneous disconnects.  They don't 
> seem to be related to the suspend/resume activity.
> 
> You can disable suspend for this device entirely by doing:
> 
> echo on >/sys/bus/usb/devices/2-4/power/control
> 
> I'm afraid that this won't prevent the device from disconnecting
> itself, though.  This appears to be some sort of hardware bug that
> can't be fixed in software.

I'm not sure what you were referring to when you said "No more I/O errors".
But I still got these errors today, with all patches applied.

Sep 21 14:58:11 learner kernel: usb 2-4: new high-speed USB device number 98
using xhci_hcd
Sep 21 14:58:18 learner kernel: usb 2-4: new high-speed USB device number 102
using xhci_hcd
Sep 21 14:58:24 learner kernel: usb 2-4: new high-speed USB device number 106
using xhci_hcd
Sep 21 14:58:31 learner kernel: usb 2-4: new high-speed USB device number 114
using xhci_hcd
Sep 21 14:58:41 learner kernel: usb 2-4: new high-speed USB device number 12
using xhci_hcd
Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 14:58:41 learner kernel: usb 2-4: new high-speed USB device number 13
using xhci_hcd
Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 14:58:41 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 14:58:42 learner kernel: usb 2-4: new high-speed USB device number 14
using xhci_hcd
Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup address.
Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup address.
Sep 21 14:58:42 learner kernel: usb 2-4: device not accepting address 14, error
- -71
Sep 21 14:58:42 learner kernel: usb 2-4: new high-speed USB device number 15
using xhci_hcd
Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup address.
Sep 21 14:58:42 learner kernel: usb 2-4: Device not responding to setup address.
Sep 21 14:58:43 learner kernel: usb 2-4: device not accepting address 15, error
- -71
Sep 21 14:58:43 learner kernel: usb usb2-port4: unable to enumerate USB device
Sep 21 16:19:39 learner kernel: ahci :00:1f.2: port does not support device
sleep
Sep 21 16:19:39 learner kernel: NMI watchdog: enabled on all CPUs, permanently
consumes one hw-
Sep 21 16:19:39 learner kernel: EXT4-fs (dm-0): re-mounted. Opts:
errors=remount-ro,data=ordere
Sep 21 16:19:39 learner kernel: EXT4-fs (sda6): re-mounted. Opts:
data=ordered,commit=0
Sep 21 16:19:39 learner kernel: EXT4-fs (dm-3): re-mounted. Opts:
errors=remount-ro,data=writeb
Sep 21 16:19:39 learner kernel: usb 2-4: new high-speed USB device number 16
using xhci_hcd
Sep 21 16:19:39 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 16:19:40 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 16:19:40 learner kernel: usb 2-4: new high-speed USB device number 17
using xhci_hcd
Sep 21 16:19:40 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 16:19:40 learner kernel: usb 2-4: device descriptor read/64, error -71
Sep 21 16:19:40 learner kernel: usb 2-4: new high-speed USB device number 18
using xhci_hcd
Sep 21 16:19:40 learner kernel: usb 2-4: Device not responding to setup address.
Sep 21 16:19:41 learner kernel: usb 2-4: Device not responding to setup address.
Sep 21 16:19:41 learner kernel: usb 2-4: device not accepting address 18, error
- -71
Sep 21 16:19:41 learner kernel: usb 2-4: new high-speed USB device number 19
using xhci_hcd


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX4mqUAAoJEKY6WKPy4XVpEHMP/RhcDQXxt3LTOpGhJizyqZ4z
7Sm1tcBe/4NKP80nUpiI0geQYHYfRTR93hGKFayp48ULstn8xJ8T3ItZIS0WmZDK
TJcdxXzrkWMGNAGQFjNd9Lk1C7h1IIuo2D5xDuhrpHGMc5y4UVmpPixQRwEnbzG9
zX+PabvummAmlzT1+cRyO10uwpGFzsJ3SDkokjkxZ/aViL+vBU58/qiXIFH1D1hX
KTY8ABZjh4Hnkw07EcQh0xKztEbE/v2wJWPSx4RCPbsRdO5vdKUtOtWB7+1WVAY3
noSrvNWjj0Ntnm0+t4XIid1fDmNumK0EcYe8fDb/GqAuYDTqjcIZ5ANCaVSM/joq
suY7KTXVe44Pol1Bb89lERR49QAkxyKJViNc0bNSkp0+F4u4cDW9o0q6s0X6xw5b
LdAQHQek92IRNmT7v4gYO9bUKUBurqgHuUdi3iYlylbvs8UAzHmOL3nrFBz2GIcG
KQvqmvENy31VIlIMx+k3SipyedG77LIAmxX8bG7Xlu8lSZz3sPkMz7RJYeW0QwQ6
lC2cWiF2cn5K/0eTQPW3MX5H9m5qlq0QGaDrf8kGX6XpRKR3Qsu98L+R+AAmViQ9
kd2eBFzL4JdNVhXgNWrNk5mr0R0D9RB/58YWize3sASPg75zCFQCNOoFTPNZGN1q
edPs8uwkN5O2cy+0ur8n
=uZvc
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Tue, 2016-09-20 at 11:43 -0400, Alan Stern wrote:
> > Yes. But that'd also mean to write that value upon every suspend/resume
> cycle
> > because the rtsx usb driver still declares support for autosuspend.
> > Should that be dropped ?
> 
> No, the value doesn't change across a suspend/resume cycle.
> 

I just verified, and yes, you are right. The value doesn't change.

> > > I'm afraid that this won't prevent the device from disconnecting
> > > itself, though.  This appears to be some sort of hardware bug that
> > > can't be fixed in software.
> > 
> > And that'd mean that upon every reset, the driver will again enable
> autosuspend
> > for that driver.
> 
> Yes, that's true.  I'm curious to see if preventing autosuspends will 
> get rid of the resets.  My guess is that it won't.

No. We tried it in the beginning. And the resets were still seen.

Thanks.

- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX4Vr/AAoJEKY6WKPy4XVpqSoP/jimRbblWfR56HM3RuK6jLTp
XHm2lJj6LopxC7BDPVF+SIMULlTyPh2hjbF2MVw9yNwsv1nruGQspzZ5VrBWlTsK
8Fs2sJif7Y8tWVFEMZczghrEoHN0KLe5vW4W6rX8xjjH5nL6ljtUeBDT6DyvD7yT
WymQWfObwp6VnjoR3nZ1SzB4DN/oGH10NaMjkk234mTkhU9Pl+UXFmesDdWn8Y64
3l5SpemMbNQaCaa/jyFQBJXu3+OTYVQafHjcl0bb3aRt4sHq5neS5zc/EIjz+Cpo
kqQwpQ6FslvSvamlwwB8mqDalPQZHeIvUNFMjlldpiAs8iCVeMHpolWI/CXCfo+1
BwVv8Kc1VnoMsjZ7uEUQJY9F1Q7YJ+4gFK6WSAhz7B9Na/0ztPJgq0tFYnVQgrwx
zUnLL7jPZZ4Wt8if9UayPtCUCdqHBSIfeoJ7+HMkC6FPt5GGCsrhtZX0u0Onop7F
Ka/VNgpMUNccgPvdqq3zYKyNIaAIUPf0jSyFbwxVXGbCLSZi8f4QmSw7k3BvkqNN
lR+pyqjKbImTpzqk0QT22SGT+4MeQgclbEUkpfA8PaPyb+9uLjgtZgp1ucTlMzOV
c3mXaTzRtSihagSW4hNyqYOINtBnvZp3n2fWDPgjJu+LWGOhpqY7P8mq8gFj77Fp
G49mKNuDiOkPWH3qHJgA
=bGWs
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Tue, 20 Sep 2016, Ritesh Raj Sarraf wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
> 
> Hello Alan,
> 
> On Tue, 2016-09-20 at 10:16 -0400, Alan Stern wrote:
> > This is a lot better.  No more I/O errors.
> > 
> > We still have irregular suspends and resumes, but that's to be 
> > expected.  More worrying are the spontaneous disconnects.  They don't 
> > seem to be related to the suspend/resume activity.
> > 
> > You can disable suspend for this device entirely by doing:
> > 
> > echo on >/sys/bus/usb/devices/2-4/power/control
> > 
> 
> Yes. But that'd also mean to write that value upon every suspend/resume cycle
> because the rtsx usb driver still declares support for autosuspend.
> Should that be dropped ?

No, the value doesn't change across a suspend/resume cycle.

> > I'm afraid that this won't prevent the device from disconnecting
> > itself, though.  This appears to be some sort of hardware bug that
> > can't be fixed in software.
> 
> And that'd mean that upon every reset, the driver will again enable 
> autosuspend
> for that driver.

Yes, that's true.  I'm curious to see if preventing autosuspends will 
get rid of the resets.  My guess is that it won't.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Alan,

On Tue, 2016-09-20 at 10:16 -0400, Alan Stern wrote:
> This is a lot better.  No more I/O errors.
> 
> We still have irregular suspends and resumes, but that's to be 
> expected.  More worrying are the spontaneous disconnects.  They don't 
> seem to be related to the suspend/resume activity.
> 
> You can disable suspend for this device entirely by doing:
> 
> echo on >/sys/bus/usb/devices/2-4/power/control
> 

Yes. But that'd also mean to write that value upon every suspend/resume cycle
because the rtsx usb driver still declares support for autosuspend.
Should that be dropped ?

> I'm afraid that this won't prevent the device from disconnecting
> itself, though.  This appears to be some sort of hardware bug that
> can't be fixed in software.

And that'd mean that upon every reset, the driver will again enable autosuspend
for that driver.


It is an upsetting state for this device but thank you, to all of you, for
helping debug this problem.

- -- 
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX4VLyAAoJEKY6WKPy4XVprEgQAKdYcFIF1ICNGHkF+oyDe1VY
DqyxTa0vLPbXWsG6GaV4Jdwld+gVKiWIVNKxbLpboBHj/vj0bkzoPJ0z4xI+Oc8p
bu6T5Io6nAaegdGa6XvYIAXk1fIlXEehBFVM6OyzC1EUJAjgYhIDVlG8mqZKxqVp
GGsX1e5UFdS0vCqjYqSxI5IHrqsm1M4lXuwr8ia66qyuSfpg8trizLiWrdiEa7hv
hRtI81XxITvVJ4+2ernO6Y+RO/z6WQLs1SAhXvDEH3RlYh/RoEBpolqMIO8LVWMK
jd4GSsYmMKiG1eJJq3UYM+iPDANIIi4gdO0hf/24vNcsVa8eF5kcKT+bxufRaiB/
5TzZS0RARBdq1+N6bK/wF8lDL4bWy4Sl1mts/dXJaCOlOoLeQ/u/J55K58mDJb2O
gdvEvzD/S9NNeawL2ow4sxaM8EBpeyJtBTyVIbLJVFmetauVs+ClI0uLoNMW/N+u
qMDE8yhiey4ClXa0WmVZHN4qjfNAnW4OSMtrq8+TLa1yhVj/ONNBo8QkfjuKBHwE
ELDrX3/N9JsZo6ZX0CPNVhodvck8ZVKrk8w3jAlcqQ0FlJy5MMFoqGEvqJ1EIfNv
IQ5FKrI08RIA7yw6keTy3nybzyY3MhepLJWxiEVyKRCopiHk96DmEGJmOmor7VIQ
hjgbpCikJ7sXPcn0n97u
=DBja
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Mon, 2016-09-19 at 13:48 -0400, Alan Stern wrote:
> 
> This ought to help.  Ritesh, please apply this patch on top of the 
> two earlier ones and let's see what happens.
> 
> Alan Stern
> 
> 

Please find the logs at the following links. On this boot, I did not see any
kernel stack being printed.

https://people.debian.org/~rrs/tmp/4.8.0-rc7ulf1alan2+.kern.log
https://people.debian.org/~rrs/tmp/usb-4.8.0-rc7ulf1alan2+.log


> 
> Index: usb-4.x/drivers/memstick/host/rtsx_usb_ms.c
> ===
> --- usb-4.x.orig/drivers/memstick/host/rtsx_usb_ms.c
> +++ usb-4.x/drivers/memstick/host/rtsx_usb_ms.c
> @@ -681,6 +681,7 @@ static int rtsx_usb_detect_ms_card(void
> int err;
>  
> for (;;) {
> +   pm_runtime_get_sync(ms_dev(host));
> mutex_lock(>dev_mutex);
>  
> /* Check pending MS card changes */
> @@ -703,6 +704,7 @@ static int rtsx_usb_detect_ms_card(void
> }
>  
>  poll_again:
> +   pm_runtime_put(ms_dev(host));
> if (host->eject)
> break;
>  
- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX4S1BAAoJEKY6WKPy4XVprAUP/jPnuxUAZ+6qKiCVx6qB69d+
wHQDkFOxmlTwTh5GyMa+oxEqvi0shvOKZ/ef7Oz0NA9DSiLonFw4aqSzF7jBRbee
UTKIgnNxHmJC6pdMPXWo5HVLBn6qYtX4pJFX6g1MwmjEDa9pjYWK9p7QzHkrx1GB
Z3X7TcWYk3DJS04GbFO9pMDl0P1phLR2VtnfzQwqtgF/g2fy7USpft1bYIQLQzxb
oOSAEDnTCtpurdAfLWq8OVQbL3rrf+HD3InVtdCZa+lwNSNwNfUZWnKKkS1S1tq+
hgKxvGOTEGunhm6Px6iQUCE9yxsvfmDK2GBxc/a3Tqpcy5ndZv/5laKFhXTt27pa
OuGksYgHCf2vWGHFuYHJH6cQKxgdsnnE7yGwbC8zYnrCT9O3hcLPxbVbzJorWFU0
YMNKt7RYZXrNQss9J4ufkTSLvzbUqsiYJwWH27LbQ5zHC7b9/ebgnMW6JIb1x+2p
iuz6MERvyxVxorG3R260GWSz/5SM/VVnTqzlRUnMHcVAyUHNGPGoqLu5LkrmI2VT
Zwcikip9G3fE79786eKF50X7dp2kU2p+W2bBmcJEWpWV9Vz5PiQdibsiu3CQilKc
QGxrKLp0OSsUvtwb4ceD/RWu7F99F7VCu3f/ohYYS2iciux5sFky+27GfY0fEJ2u
ikPpuK6xNWWSDgaNVVHD
=Nq4a
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Mon, 19 Sep 2016, Ulf Hansson wrote:

> On 18 September 2016 at 03:42, Alan Stern  wrote:

> > Well, this is pretty clear:
> >
> > Sep 17 15:55:52 learner kernel: CPU: 1 PID: 535 Comm: rtsx_usb_ms_1 
> > Tainted: G U  4.8.0-rc6ulf1alan1+ #19
> > Sep 17 15:55:52 learner kernel: Hardware name: LENOVO 20344/INVALID, BIOS 
> > 96CN31WW(V1.17) 07/21/2015
> > Sep 17 15:55:52 learner kernel:   81314be5 
> > 8802476746c0 0240
> > Sep 17 15:55:52 learner kernel:  a016f719 523bec00 
> > 88025f255780 88024feff600
> > Sep 17 15:55:52 learner kernel:  00018080  
> > 88025f258080 815a0e60
> > Sep 17 15:55:52 learner kernel: Call Trace:
> > Sep 17 15:55:52 learner kernel:  [] ? dump_stack+0x7d/0xb8
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > usb_hcd_submit_urb+0x3c9/0xad0 [usbcore]
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > _raw_spin_lock_irqsave+0x20/0x47
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > lock_timer_base.isra.24+0x7b/0xa0
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > try_to_del_timer_sync+0x49/0x60
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > usb_start_wait_urb+0x5d/0x140 [usbcore]
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > rtsx_usb_send_cmd+0x5e/0x80 [rtsx_usb]
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > rtsx_usb_read_register+0x67/0xb0 [rtsx_usb]
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > rtsx_usb_detect_ms_card+0x61/0xe0 [rtsx_usb_ms]
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > rtsx_usb_ms_set_param+0x770/0x770 [rtsx_usb_ms]
> > Sep 17 15:55:52 learner kernel:  [] ? kthread+0xbd/0xe0
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > __switch_to+0x2b1/0x6a0
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > ret_from_fork+0x1f/0x40
> > Sep 17 15:55:52 learner kernel:  [] ? 
> > kthread_create_on_node+0x180/0x180
> >
> > This is the rtsx_usb_detect_ms_card() routine in
> > drivers/memstick/host/rtsx_usb_ms.c, which runs as a kthread.  It
> > doesn't do any runtime PM.  So it looks like the bug is present in both
> > the MMC and MemoryStick interfaces.
> 
> I think the problem is even worse in the MemoryStick case, as the
> memstick core doesn't help with runtime PM. I am pretty sure there are
> other cases when the MemoryStick driver accesses the usb device
> without first runtime resuming it.

Maybe we should get a MemoryStick maintainer involved in this thread.  
I CC'ed Alex Dubov.

Alex, the problem here is that drivers/memstick/host/rtsx_usb_ms.c
tries to communicate with the host USB device while it is runtime
suspended.

> Of course we could start simple an fix the bug observed above and see
> if that solves the reported problem. Alan, do you want to post to
> patch or you want me?

This ought to help.  Ritesh, please apply this patch on top of the 
two earlier ones and let's see what happens.

Alan Stern



Index: usb-4.x/drivers/memstick/host/rtsx_usb_ms.c
===
--- usb-4.x.orig/drivers/memstick/host/rtsx_usb_ms.c
+++ usb-4.x/drivers/memstick/host/rtsx_usb_ms.c
@@ -681,6 +681,7 @@ static int rtsx_usb_detect_ms_card(void
int err;
 
for (;;) {
+   pm_runtime_get_sync(ms_dev(host));
mutex_lock(>dev_mutex);
 
/* Check pending MS card changes */
@@ -703,6 +704,7 @@ static int rtsx_usb_detect_ms_card(void
}
 
 poll_again:
+   pm_runtime_put(ms_dev(host));
if (host->eject)
break;
 

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ulf Hansson]

On 18 September 2016 at 03:42, Alan Stern  wrote:
> On Sat, 17 Sep 2016, Ritesh Raj Sarraf wrote:
>
>> -BEGIN PGP SIGNED MESSAGE-
>> Hash: SHA512
>>
>> Hello Alan,
>>
>>
>> On Fri, 2016-09-16 at 17:40 -0400, Alan Stern wrote:
>> > We're still getting runtime suspends, but now at 2-second intervals.
>> > This is partly because the driver isn't calling
>> > pm_runtime_mark_last_busy(), but there may be more to it.  The 2-second
>> > period is the default autosuspend timeout for USB devices.  However, I
>> > don't see the activity that rtsx_usb_get_card_status() should produce
>> > when rtsx_usb_suspend() runs; I don't know why not.
>> >
>> > We're also getting occasional I/O attempts while the device is
>> > suspended.  They must be on some other pathway, not the one fixed by
>> > the patch above.  Let's see if we can find out just where they come
>> > from.
>> >
>> > Ritesh, please try applying this patch on top of the previous one.  It
>> > will produce output in the kernel log whenever these bad I/O attempts
>> > occur.  Also, enable dynamic debugging for the rtsx_usb driver:
>> >
>>
>> Please find links to the usbmon trace and the kernel trace.
>>
>> https://people.debian.org/~rrs/tmp/4.8.0-rc6ulf1alan1+.kern.log
>> https://people.debian.org/~rrs/tmp/usb-4.8.0-rc6ulf1alan1+.log.gz
>
> Well, this is pretty clear:
>
> Sep 17 15:55:52 learner kernel: CPU: 1 PID: 535 Comm: rtsx_usb_ms_1 Tainted: 
> G U  4.8.0-rc6ulf1alan1+ #19
> Sep 17 15:55:52 learner kernel: Hardware name: LENOVO 20344/INVALID, BIOS 
> 96CN31WW(V1.17) 07/21/2015
> Sep 17 15:55:52 learner kernel:   81314be5 
> 8802476746c0 0240
> Sep 17 15:55:52 learner kernel:  a016f719 523bec00 
> 88025f255780 88024feff600
> Sep 17 15:55:52 learner kernel:  00018080  
> 88025f258080 815a0e60
> Sep 17 15:55:52 learner kernel: Call Trace:
> Sep 17 15:55:52 learner kernel:  [] ? dump_stack+0x7d/0xb8
> Sep 17 15:55:52 learner kernel:  [] ? 
> usb_hcd_submit_urb+0x3c9/0xad0 [usbcore]
> Sep 17 15:55:52 learner kernel:  [] ? 
> _raw_spin_lock_irqsave+0x20/0x47
> Sep 17 15:55:52 learner kernel:  [] ? 
> lock_timer_base.isra.24+0x7b/0xa0
> Sep 17 15:55:52 learner kernel:  [] ? 
> try_to_del_timer_sync+0x49/0x60
> Sep 17 15:55:52 learner kernel:  [] ? 
> usb_start_wait_urb+0x5d/0x140 [usbcore]
> Sep 17 15:55:52 learner kernel:  [] ? 
> rtsx_usb_send_cmd+0x5e/0x80 [rtsx_usb]
> Sep 17 15:55:52 learner kernel:  [] ? 
> rtsx_usb_read_register+0x67/0xb0 [rtsx_usb]
> Sep 17 15:55:52 learner kernel:  [] ? 
> rtsx_usb_detect_ms_card+0x61/0xe0 [rtsx_usb_ms]
> Sep 17 15:55:52 learner kernel:  [] ? 
> rtsx_usb_ms_set_param+0x770/0x770 [rtsx_usb_ms]
> Sep 17 15:55:52 learner kernel:  [] ? kthread+0xbd/0xe0
> Sep 17 15:55:52 learner kernel:  [] ? 
> __switch_to+0x2b1/0x6a0
> Sep 17 15:55:52 learner kernel:  [] ? 
> ret_from_fork+0x1f/0x40
> Sep 17 15:55:52 learner kernel:  [] ? 
> kthread_create_on_node+0x180/0x180
>
> This is the rtsx_usb_detect_ms_card() routine in
> drivers/memstick/host/rtsx_usb_ms.c, which runs as a kthread.  It
> doesn't do any runtime PM.  So it looks like the bug is present in both
> the MMC and MemoryStick interfaces.

I think the problem is even worse in the MemoryStick case, as the
memstick core doesn't help with runtime PM. I am pretty sure there are
other cases when the MemoryStick driver accesses the usb device
without first runtime resuming it.

Of course we could start simple an fix the bug observed above and see
if that solves the reported problem. Alan, do you want to post to
patch or you want me?

Kind regards
Uffe
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Sat, 17 Sep 2016, Ritesh Raj Sarraf wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
> 
> Hello Alan,
> 
> 
> On Fri, 2016-09-16 at 17:40 -0400, Alan Stern wrote:
> > We're still getting runtime suspends, but now at 2-second intervals.   
> > This is partly because the driver isn't calling
> > pm_runtime_mark_last_busy(), but there may be more to it.  The 2-second 
> > period is the default autosuspend timeout for USB devices.  However, I 
> > don't see the activity that rtsx_usb_get_card_status() should produce 
> > when rtsx_usb_suspend() runs; I don't know why not.
> > 
> > We're also getting occasional I/O attempts while the device is
> > suspended.  They must be on some other pathway, not the one fixed by
> > the patch above.  Let's see if we can find out just where they come
> > from.
> > 
> > Ritesh, please try applying this patch on top of the previous one.  It 
> > will produce output in the kernel log whenever these bad I/O attempts 
> > occur.  Also, enable dynamic debugging for the rtsx_usb driver:
> > 
> 
> Please find links to the usbmon trace and the kernel trace.
> 
> https://people.debian.org/~rrs/tmp/4.8.0-rc6ulf1alan1+.kern.log
> https://people.debian.org/~rrs/tmp/usb-4.8.0-rc6ulf1alan1+.log.gz

Well, this is pretty clear:

Sep 17 15:55:52 learner kernel: CPU: 1 PID: 535 Comm: rtsx_usb_ms_1 Tainted: G  
   U  4.8.0-rc6ulf1alan1+ #19
Sep 17 15:55:52 learner kernel: Hardware name: LENOVO 20344/INVALID, BIOS 
96CN31WW(V1.17) 07/21/2015
Sep 17 15:55:52 learner kernel:   81314be5 
8802476746c0 0240
Sep 17 15:55:52 learner kernel:  a016f719 523bec00 
88025f255780 88024feff600
Sep 17 15:55:52 learner kernel:  00018080  
88025f258080 815a0e60
Sep 17 15:55:52 learner kernel: Call Trace:
Sep 17 15:55:52 learner kernel:  [] ? dump_stack+0x7d/0xb8
Sep 17 15:55:52 learner kernel:  [] ? 
usb_hcd_submit_urb+0x3c9/0xad0 [usbcore]
Sep 17 15:55:52 learner kernel:  [] ? 
_raw_spin_lock_irqsave+0x20/0x47
Sep 17 15:55:52 learner kernel:  [] ? 
lock_timer_base.isra.24+0x7b/0xa0
Sep 17 15:55:52 learner kernel:  [] ? 
try_to_del_timer_sync+0x49/0x60
Sep 17 15:55:52 learner kernel:  [] ? 
usb_start_wait_urb+0x5d/0x140 [usbcore]
Sep 17 15:55:52 learner kernel:  [] ? 
rtsx_usb_send_cmd+0x5e/0x80 [rtsx_usb]
Sep 17 15:55:52 learner kernel:  [] ? 
rtsx_usb_read_register+0x67/0xb0 [rtsx_usb]
Sep 17 15:55:52 learner kernel:  [] ? 
rtsx_usb_detect_ms_card+0x61/0xe0 [rtsx_usb_ms]
Sep 17 15:55:52 learner kernel:  [] ? 
rtsx_usb_ms_set_param+0x770/0x770 [rtsx_usb_ms]
Sep 17 15:55:52 learner kernel:  [] ? kthread+0xbd/0xe0
Sep 17 15:55:52 learner kernel:  [] ? __switch_to+0x2b1/0x6a0
Sep 17 15:55:52 learner kernel:  [] ? ret_from_fork+0x1f/0x40
Sep 17 15:55:52 learner kernel:  [] ? 
kthread_create_on_node+0x180/0x180

This is the rtsx_usb_detect_ms_card() routine in
drivers/memstick/host/rtsx_usb_ms.c, which runs as a kthread.  It 
doesn't do any runtime PM.  So it looks like the bug is present in both 
the MMC and MemoryStick interfaces.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Alan,


On Fri, 2016-09-16 at 17:40 -0400, Alan Stern wrote:
> We're still getting runtime suspends, but now at 2-second intervals.   
> This is partly because the driver isn't calling
> pm_runtime_mark_last_busy(), but there may be more to it.  The 2-second 
> period is the default autosuspend timeout for USB devices.  However, I 
> don't see the activity that rtsx_usb_get_card_status() should produce 
> when rtsx_usb_suspend() runs; I don't know why not.
> 
> We're also getting occasional I/O attempts while the device is
> suspended.  They must be on some other pathway, not the one fixed by
> the patch above.  Let's see if we can find out just where they come
> from.
> 
> Ritesh, please try applying this patch on top of the previous one.  It 
> will produce output in the kernel log whenever these bad I/O attempts 
> occur.  Also, enable dynamic debugging for the rtsx_usb driver:
> 

Please find links to the usbmon trace and the kernel trace.

https://people.debian.org/~rrs/tmp/4.8.0-rc6ulf1alan1+.kern.log
https://people.debian.org/~rrs/tmp/usb-4.8.0-rc6ulf1alan1+.log.gz

Thanks.

> echo 'module rtsx_usb =p' >/sys/kernel/debug/dynamic_debug/control
> 
> before starting the test.  (You may need to mount a debugfs filesystem 
> on /sys/kernel/debug first.)
> 
> Alan Stern
> 
> 
> 
> Index: usb-4.x/drivers/usb/core/hcd.c
> ===
> --- usb-4.x.orig/drivers/usb/core/hcd.c
> +++ usb-4.x/drivers/usb/core/hcd.c
> @@ -1647,6 +1647,8 @@ int usb_hcd_submit_urb (struct urb *urb,
> status = map_urb_for_dma(hcd, urb, mem_flags);
> if (likely(status == 0)) {
> status = hcd->driver->urb_enqueue(hcd, urb,
> mem_flags);
> +   if (status == -EHOSTUNREACH)
> +   dump_stack();
> if (unlikely(status))
> unmap_urb_for_dma(hcd, urb);
> }
> 
- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX3SwNAAoJEKY6WKPy4XVpMaYQAK3p/meduq2SLRKjcLuher/+
U6W0+6t1MJmNLZgArqEYLprGQs8dboDUVuYdOkpDyjsL3oRVc2RFRhKP4n5uyeqf
UOyyJC/Dn8JpW5abQPdQOi8/zeY019P1MPKd/lAvjs+MXOdRvOluwne3KGeVJzrc
nWNt9YMZCvxscbXjJVqNWFh8utg6BVVoJ72sqkHYL6N+cWKwKb4QphgNXbhoPQq3
K7KwsBywQHty/Wf4TXB6n8z/6zR6uNHQjaveboUvidkMhWXYFSVag6ba6ZOsAyoL
nPWvowTTKO3snKh2AzHhJEzgky2EXMoxG5+GzA3nBA9suAapxuS7tTSt5YAShupv
at1FASeb8kyZ7vt3Srq7WQN7OIlER9zvVvapENJHwqATnHAQ+35h+7o1CrZLjDyF
UB5qKWOOQlFmiEfjjs15bLumBQqA4vX7JvYqJxNX7AtOPUXZHvs85eX7S4s18TZ7
OYO5JkS0xcLD6HMvuxzwO+UDS5DYknwma8gAPvHg1mX8QQMOPNkbnd7Igt9kjhMR
ZioeP0xLyyUGwjGErQpzgQwHlk5bMQhQ4iiOxi4nz4aCWLCs2YwzojfwtfDxSYnV
rCSjWEAanG3eRP7iPBtbdrbFmWsjSsavopXXlLPNYDjBjnpm2/IcyIlC/dTKKYJz
0rkc0hreSRuSDMPxbkfV
=d/iL
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Fri, 16 Sep 2016, Ritesh Raj Sarraf wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
> 
> Hello Ulf and Alan,
> 
> On Thu, 2016-09-15 at 10:16 -0400, Alan Stern wrote:
> > > ---
> > >  drivers/mmc/host/rtsx_usb_sdmmc.c | 2 ++
> > >  1 file changed, 2 insertions(+)
> > > 
> > > diff --git a/drivers/mmc/host/rtsx_usb_sdmmc.c
> > > b/drivers/mmc/host/rtsx_usb_sdmmc.c
> > > index 6c71fc9..a59c7fa 100644
> > > --- a/drivers/mmc/host/rtsx_usb_sdmmc.c
> > > +++ b/drivers/mmc/host/rtsx_usb_sdmmc.c
> > > @@ -1314,6 +1314,7 @@ static void rtsx_usb_update_led(struct work_struct
> > *work)
> > > container_of(work, struct rtsx_usb_sdmmc, led_work);
> > > struct rtsx_ucr *ucr = host->ucr;
> > > 
> > > +   pm_runtime_get_sync(sdmmc_dev(host));
> > > mutex_lock(>dev_mutex);
> > > 
> > > if (host->led.brightness == LED_OFF)
> > > @@ -1322,6 +1323,7 @@ static void rtsx_usb_update_led(struct work_struct
> > *work)
> > > rtsx_usb_turn_on_led(ucr);
> > > 
> > > mutex_unlock(>dev_mutex);
> > > +   pm_runtime_put(sdmmc_dev(host));
> > >  }
> > >  #endif
> > > 
> > > -- 
> > > 
> > > Although, I doubt the above is the main reason to the issues we see.
> > 
> > I don't know -- it could well be the reason.  The symptoms are 
> > definitely what you would expect to see if some thread was doing I/O 
> > without calling the pm_runtime_* routines.

> I was able to hit it again. Please find the usbmon trace at:
> https://people.debian.org/~rrs/tmp/usb-4.8.0-rc6ulf1+.log.gz

 
We're still getting runtime suspends, but now at 2-second intervals.   
This is partly because the driver isn't calling
pm_runtime_mark_last_busy(), but there may be more to it.  The 2-second 
period is the default autosuspend timeout for USB devices.  However, I 
don't see the activity that rtsx_usb_get_card_status() should produce 
when rtsx_usb_suspend() runs; I don't know why not.

We're also getting occasional I/O attempts while the device is
suspended.  They must be on some other pathway, not the one fixed by
the patch above.  Let's see if we can find out just where they come
from.

Ritesh, please try applying this patch on top of the previous one.  It 
will produce output in the kernel log whenever these bad I/O attempts 
occur.  Also, enable dynamic debugging for the rtsx_usb driver:

echo 'module rtsx_usb =p' >/sys/kernel/debug/dynamic_debug/control

before starting the test.  (You may need to mount a debugfs filesystem 
on /sys/kernel/debug first.)

Alan Stern



Index: usb-4.x/drivers/usb/core/hcd.c
===
--- usb-4.x.orig/drivers/usb/core/hcd.c
+++ usb-4.x/drivers/usb/core/hcd.c
@@ -1647,6 +1647,8 @@ int usb_hcd_submit_urb (struct urb *urb,
status = map_urb_for_dma(hcd, urb, mem_flags);
if (likely(status == 0)) {
status = hcd->driver->urb_enqueue(hcd, urb, mem_flags);
+   if (status == -EHOSTUNREACH)
+   dump_stack();
if (unlikely(status))
unmap_urb_for_dma(hcd, urb);
}


--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Ulf and Alan,

On Thu, 2016-09-15 at 10:16 -0400, Alan Stern wrote:
> > ---
> >  drivers/mmc/host/rtsx_usb_sdmmc.c | 2 ++
> >  1 file changed, 2 insertions(+)
> > 
> > diff --git a/drivers/mmc/host/rtsx_usb_sdmmc.c
> > b/drivers/mmc/host/rtsx_usb_sdmmc.c
> > index 6c71fc9..a59c7fa 100644
> > --- a/drivers/mmc/host/rtsx_usb_sdmmc.c
> > +++ b/drivers/mmc/host/rtsx_usb_sdmmc.c
> > @@ -1314,6 +1314,7 @@ static void rtsx_usb_update_led(struct work_struct
> *work)
> > container_of(work, struct rtsx_usb_sdmmc, led_work);
> > struct rtsx_ucr *ucr = host->ucr;
> > 
> > +   pm_runtime_get_sync(sdmmc_dev(host));
> > mutex_lock(>dev_mutex);
> > 
> > if (host->led.brightness == LED_OFF)
> > @@ -1322,6 +1323,7 @@ static void rtsx_usb_update_led(struct work_struct
> *work)
> > rtsx_usb_turn_on_led(ucr);
> > 
> > mutex_unlock(>dev_mutex);
> > +   pm_runtime_put(sdmmc_dev(host));
> >  }
> >  #endif
> > 
> > -- 
> > 
> > Although, I doubt the above is the main reason to the issues we see.
> 
> I don't know -- it could well be the reason.  The symptoms are 
> definitely what you would expect to see if some thread was doing I/O 
> without calling the pm_runtime_* routines.
> 
> > Instead I think somehow the parent device (usb device) isn't being
> > properly managed through runtime PM, but not due to wrong deployment
> > in the mmc core nor in the rtsx_usb_driver, but at some place else.
> > :-)
> > 
> > I started looking for calls to pm_suspend_ignore_children(dev, true),
> > which would decouple the usb device from the mmc platform device from
> > a runtime PM point of view. I found one suspicious case!
> > 
> > drivers/usb/storage/realtek_cr.c:
> > pm_suspend_ignore_children(>pusb_intf->dev, true);
> > 
> > As I am not so familiar with USB, I can't really tell why the above
> > exists, although perhaps just removing that line would be worth a
> > try!?
> 
> No, the realtek_cr driver has no connection with this.  It's a
> sub-module of the usb_storage driver; it uses the SCSI interface,
> not the MMC interface.
> 
> > If neither of the above works, the next step could be to start
> > checking error codes in the mmc core and in the rtsx_usb_sdmmc driver,
> > from the calls to pm_runtime_get|put() and pm_runtime_enable().
> 
> Let's see what this patch does.

I was able to hit it again. Please find the usbmon trace at:
https://people.debian.org/~rrs/tmp/usb-4.8.0-rc6ulf1+.log.gz


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX3BLOAAoJEKY6WKPy4XVpXMgP/jTyKOX/SYCPTU9twYldY7LQ
f64hpiWqXOUs+jFYM+BcrF5B5DuXiB1Wm4F3+Xm/QBN3grJD7yBq1nrhv/mAhCr3
y1gFRIbeKfZsEp1vdBov9m1jQCZzzIZlFXPmRGT/8uC/GZTHlgIeSLqBntpq9+yL
MQSE91tLVayVgaOQxpPz+uZ4PTAom19sU21Haa90ECHLKAUTJ9WncQFecjPLHMjb
4SUvgq53V2s1Yo1E85RhtgR6Nrk/Bh7qZEC1NyeganLazGbbsz9YnRcGy58x9Jiq
xmfURTtvG834CnGcGuzcRU09FGPMtXx/u57EYC6mdEMWhSglo0h6YhVxcUOtAhRD
s1gs+a6ToKTDLn6qr0cnIwG27ALyLh41QmzxEpiaZiugIEBzZ/uK3TBjzcul4Huj
v0+x2fSC0SXwGo4P3GAOnHuWUjgj3C1wElP1R3brXfO0aayESUNKzE8V7RbQIWiC
mHewSlKTiPwCr/lchaINTt2TyFcHJWOx90iV10GO5TpMyqho4AzpBpoimItrbx2t
qQJCvGzDLPjr0tPvpeWyJSfBnqCDqbJ44CY3nCFgKhTd3BXp4fDj09eBtNmSiuvu
UdZZxm84FD3BDSNX8k2W9CF81jML/4lzwliJge3uIPrXNDqGSZMxDSpd0u1EFNHf
rEQ/kP1WlArvqButQ5ZN
=fiWV
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Thu, 15 Sep 2016, Ulf Hansson wrote:

> > The situation isn't any better.  At the start of the trace,
> > the device is in runtime suspend but there are many attempts to
> > communicate with it, all of which fail.
> 
> It's really weird. Have this driver ever worked!? :-)

Probably not.  Or at least, not with runtime PM.

> > Then a little less than an hour after the trace started, the device was
> > resumed.  At that point it started working okay.  Until there was a
> > spontaneous disconnect.
> >
> > The device reconnected, but after 3 seconds it was runtime suspended
> > again -- and the I/O attempts continued.  Some time later there was
> > another runtime resume, and the device began working again.  Until
> > another spontaneous disconnect occurred.  And so on...
> >
> > Ulf, we really need to figure out why the autosuspends are occurring
> > and why the I/O doesn't stop while the device is suspended.
> 
> Okay, let's see.
> 
> I had another look in the rtsx_usb_sdmmc driver. Apparently it
> registers a led classdev. Updating the led is done from a work, by
> calling rtsx_usb_turn_on|off_led(), which do access the usb device.
> These calls are not properly managed by runtime PM, so I have fixed
> those according to below change:
> 
> ---
>  drivers/mmc/host/rtsx_usb_sdmmc.c | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/drivers/mmc/host/rtsx_usb_sdmmc.c
> b/drivers/mmc/host/rtsx_usb_sdmmc.c
> index 6c71fc9..a59c7fa 100644
> --- a/drivers/mmc/host/rtsx_usb_sdmmc.c
> +++ b/drivers/mmc/host/rtsx_usb_sdmmc.c
> @@ -1314,6 +1314,7 @@ static void rtsx_usb_update_led(struct work_struct 
> *work)
> container_of(work, struct rtsx_usb_sdmmc, led_work);
> struct rtsx_ucr *ucr = host->ucr;
> 
> +   pm_runtime_get_sync(sdmmc_dev(host));
> mutex_lock(>dev_mutex);
> 
> if (host->led.brightness == LED_OFF)
> @@ -1322,6 +1323,7 @@ static void rtsx_usb_update_led(struct work_struct 
> *work)
> rtsx_usb_turn_on_led(ucr);
> 
> mutex_unlock(>dev_mutex);
> +   pm_runtime_put(sdmmc_dev(host));
>  }
>  #endif
> 
> -- 
> 
> Although, I doubt the above is the main reason to the issues we see.

I don't know -- it could well be the reason.  The symptoms are 
definitely what you would expect to see if some thread was doing I/O 
without calling the pm_runtime_* routines.

> Instead I think somehow the parent device (usb device) isn't being
> properly managed through runtime PM, but not due to wrong deployment
> in the mmc core nor in the rtsx_usb_driver, but at some place else.
> :-)
> 
> I started looking for calls to pm_suspend_ignore_children(dev, true),
> which would decouple the usb device from the mmc platform device from
> a runtime PM point of view. I found one suspicious case!
> 
> drivers/usb/storage/realtek_cr.c:
> pm_suspend_ignore_children(>pusb_intf->dev, true);
> 
> As I am not so familiar with USB, I can't really tell why the above
> exists, although perhaps just removing that line would be worth a
> try!?

No, the realtek_cr driver has no connection with this.  It's a
sub-module of the usb_storage driver; it uses the SCSI interface,
not the MMC interface.

> If neither of the above works, the next step could be to start
> checking error codes in the mmc core and in the rtsx_usb_sdmmc driver,
> from the calls to pm_runtime_get|put() and pm_runtime_enable().

Let's see what this patch does.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ulf Hansson]

On 14 September 2016 at 17:19, Alan Stern  wrote:
> On Wed, 14 Sep 2016, Ritesh Raj Sarraf wrote:
>
>> -BEGIN PGP SIGNED MESSAGE-
>> Hash: SHA512
>>
>> Hello Ulf and Alan,
>>
>> On Fri, 2016-09-09 at 19:34 +0530, Ritesh Raj Sarraf wrote:
>> > For #2, I'm building the 4.8-rc5 kernel with the following change. This 
>> > build
>> > does not include the previous change you had suggested (related to
>> > POWER_CYCLE)
>> >
>> > Date:   Fri Sep 9 19:28:03 2016 +0530
>> >
>> > Disable pm runtime in mmc core
>> >
>> > diff --git a/drivers/mmc/core/core.c b/drivers/mmc/core/core.c
>> > index e55cde6..32388d5 100644
>> > --- a/drivers/mmc/core/core.c
>> > +++ b/drivers/mmc/core/core.c
>> > @@ -970,9 +970,6 @@ int __mmc_claim_host(struct mmc_host *host, atomic_t
>> > *abort)
>> > spin_unlock_irqrestore(>lock, flags);
>> > remove_wait_queue(>wq, );
>> >
>> > -   if (pm)
>> > -   pm_runtime_get_sync(mmc_dev(host));
>> > -
>> > return stop;
>> >  }
>> >  EXPORT_SYMBOL(__mmc_claim_host);
>> > @@ -1000,7 +997,6 @@ void mmc_release_host(struct mmc_host *host)
>> > spin_unlock_irqrestore(>lock, flags);
>> > wake_up(>wq);
>> > pm_runtime_mark_last_busy(mmc_dev(host));
>> > -   pm_runtime_put_autosuspend(mmc_dev(host));
>> > }
>> >  }
>> >  EXPORT_SYMBOL(mmc_release_host);
>>
>> I tried with these changes on 4.8-rc6 and I only saw 2 resets so far.
>> I captured the usb trace [1], just in case if you need it.
>>
>> [1] https://people.debian.org/~rrs/tmp/4.8-rc6-ulf.txt.gz
>
> The situation isn't any better.  At the start of the trace,
> the device is in runtime suspend but there are many attempts to
> communicate with it, all of which fail.

It's really weird. Have this driver ever worked!? :-)

>
> Then a little less than an hour after the trace started, the device was
> resumed.  At that point it started working okay.  Until there was a
> spontaneous disconnect.
>
> The device reconnected, but after 3 seconds it was runtime suspended
> again -- and the I/O attempts continued.  Some time later there was
> another runtime resume, and the device began working again.  Until
> another spontaneous disconnect occurred.  And so on...
>
> Ulf, we really need to figure out why the autosuspends are occurring
> and why the I/O doesn't stop while the device is suspended.

Okay, let's see.

I had another look in the rtsx_usb_sdmmc driver. Apparently it
registers a led classdev. Updating the led is done from a work, by
calling rtsx_usb_turn_on|off_led(), which do access the usb device.
These calls are not properly managed by runtime PM, so I have fixed
those according to below change:

---
 drivers/mmc/host/rtsx_usb_sdmmc.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/drivers/mmc/host/rtsx_usb_sdmmc.c
b/drivers/mmc/host/rtsx_usb_sdmmc.c
index 6c71fc9..a59c7fa 100644
--- a/drivers/mmc/host/rtsx_usb_sdmmc.c
+++ b/drivers/mmc/host/rtsx_usb_sdmmc.c
@@ -1314,6 +1314,7 @@ static void rtsx_usb_update_led(struct work_struct *work)
container_of(work, struct rtsx_usb_sdmmc, led_work);
struct rtsx_ucr *ucr = host->ucr;

+   pm_runtime_get_sync(sdmmc_dev(host));
mutex_lock(>dev_mutex);

if (host->led.brightness == LED_OFF)
@@ -1322,6 +1323,7 @@ static void rtsx_usb_update_led(struct work_struct *work)
rtsx_usb_turn_on_led(ucr);

mutex_unlock(>dev_mutex);
+   pm_runtime_put(sdmmc_dev(host));
 }
 #endif

-- 

Although, I doubt the above is the main reason to the issues we see.
Instead I think somehow the parent device (usb device) isn't being
properly managed through runtime PM, but not due to wrong deployment
in the mmc core nor in the rtsx_usb_driver, but at some place else.
:-)

I started looking for calls to pm_suspend_ignore_children(dev, true),
which would decouple the usb device from the mmc platform device from
a runtime PM point of view. I found one suspicious case!

drivers/usb/storage/realtek_cr.c:
pm_suspend_ignore_children(>pusb_intf->dev, true);

As I am not so familiar with USB, I can't really tell why the above
exists, although perhaps just removing that line would be worth a
try!?

If neither of the above works, the next step could be to start
checking error codes in the mmc core and in the rtsx_usb_sdmmc driver,
from the calls to pm_runtime_get|put() and pm_runtime_enable().

Kind regards
Uffe
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Wed, 14 Sep 2016, Ritesh Raj Sarraf wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
> 
> Hello Ulf and Alan,
> 
> On Fri, 2016-09-09 at 19:34 +0530, Ritesh Raj Sarraf wrote:
> > For #2, I'm building the 4.8-rc5 kernel with the following change. This 
> > build
> > does not include the previous change you had suggested (related to
> > POWER_CYCLE)
> > 
> > Date:   Fri Sep 9 19:28:03 2016 +0530
> > 
> > Disable pm runtime in mmc core
> > 
> > diff --git a/drivers/mmc/core/core.c b/drivers/mmc/core/core.c
> > index e55cde6..32388d5 100644
> > --- a/drivers/mmc/core/core.c
> > +++ b/drivers/mmc/core/core.c
> > @@ -970,9 +970,6 @@ int __mmc_claim_host(struct mmc_host *host, atomic_t
> > *abort)
> > spin_unlock_irqrestore(>lock, flags);
> > remove_wait_queue(>wq, );
> >  
> > -   if (pm)
> > -   pm_runtime_get_sync(mmc_dev(host));
> > -
> > return stop;
> >  }
> >  EXPORT_SYMBOL(__mmc_claim_host);
> > @@ -1000,7 +997,6 @@ void mmc_release_host(struct mmc_host *host)
> > spin_unlock_irqrestore(>lock, flags);
> > wake_up(>wq);
> > pm_runtime_mark_last_busy(mmc_dev(host));
> > -   pm_runtime_put_autosuspend(mmc_dev(host));
> > }
> >  }
> >  EXPORT_SYMBOL(mmc_release_host);
> 
> I tried with these changes on 4.8-rc6 and I only saw 2 resets so far.
> I captured the usb trace [1], just in case if you need it.
> 
> [1] https://people.debian.org/~rrs/tmp/4.8-rc6-ulf.txt.gz

The situation isn't any better.  At the start of the trace, 
the device is in runtime suspend but there are many attempts to 
communicate with it, all of which fail.

Then a little less than an hour after the trace started, the device was 
resumed.  At that point it started working okay.  Until there was a 
spontaneous disconnect.

The device reconnected, but after 3 seconds it was runtime suspended 
again -- and the I/O attempts continued.  Some time later there was 
another runtime resume, and the device began working again.  Until 
another spontaneous disconnect occurred.  And so on...

Ulf, we really need to figure out why the autosuspends are occurring 
and why the I/O doesn't stop while the device is suspended.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Ulf and Alan,

On Fri, 2016-09-09 at 19:34 +0530, Ritesh Raj Sarraf wrote:
> For #2, I'm building the 4.8-rc5 kernel with the following change. This build
> does not include the previous change you had suggested (related to
> POWER_CYCLE)
> 
> Date:   Fri Sep 9 19:28:03 2016 +0530
> 
> Disable pm runtime in mmc core
> 
> diff --git a/drivers/mmc/core/core.c b/drivers/mmc/core/core.c
> index e55cde6..32388d5 100644
> --- a/drivers/mmc/core/core.c
> +++ b/drivers/mmc/core/core.c
> @@ -970,9 +970,6 @@ int __mmc_claim_host(struct mmc_host *host, atomic_t
> *abort)
> spin_unlock_irqrestore(>lock, flags);
> remove_wait_queue(>wq, );
>  
> -   if (pm)
> -   pm_runtime_get_sync(mmc_dev(host));
> -
> return stop;
>  }
>  EXPORT_SYMBOL(__mmc_claim_host);
> @@ -1000,7 +997,6 @@ void mmc_release_host(struct mmc_host *host)
> spin_unlock_irqrestore(>lock, flags);
> wake_up(>wq);
> pm_runtime_mark_last_busy(mmc_dev(host));
> -   pm_runtime_put_autosuspend(mmc_dev(host));
> }
>  }
>  EXPORT_SYMBOL(mmc_release_host);

I tried with these changes on 4.8-rc6 and I only saw 2 resets so far.
I captured the usb trace [1], just in case if you need it.

[1] https://people.debian.org/~rrs/tmp/4.8-rc6-ulf.txt.gz

- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX2WO6AAoJEKY6WKPy4XVpfx4P/3VOWgHw87iZxuHlw+vHUVOR
BB8cdQidh6nVba2UcDXb8uw/oYYYEJZ0FYvvdgKwt/14QNaL1L3jwrLpayUC7AAM
wZA8bhESANx/KoJiZH4GuasnkXfmjXVz2XPOIz/b8qfp4jfreFZfZQHgkIY7cEtE
gO9JArpM/e6FZY/5mEYy1bFnvuuyTfI4Wu5Cm6HmyidT1mfhTM7xvyMTLfM+QRUm
VT7pRhS6oujWO7K2KDMTrcZqgs2AVmjCqZW13F4AnMU/owxvRYTpGyW3hDbi9oIg
Z8ZJ5sHT7jpJ4I/FZJxwaSthIN5aF4wG8UjTFr2EIc+W5Xx/xzYpZP3Qm+HkFnej
n8Uyo0ZMN9+CV6VI2Qgzr+pB5LAfYHjIMobGAzaCzN81MWCVmb/GfiLQhpcgOnoK
TMHVqCqWlkF8W0V5ap+Tc4Ce4Wqj/V+RlQpE01GeOg15DUtgqWXCGbYKspnwwRD2
u2Ivso9G4xDd0VOp9x4zpIdfbAqaSP+DuZZ7EnGVfd30j4ENWsrRTDXdWf63uAx6
GMOpAephwUOZo7WFxwd/q19181YM/emSg+weOMcGxwHvpQ+vTEN+JELD0B0Z6PpI
OvaPROIL8bb5SuPKzKJ55ZRLpv40sjWOglZC1oOhtSg2IMFJwjPcqzaO4frIxl4t
3OCttIZYgpp5kIiW8qV1
=KNnj
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Fri, 9 Sep 2016, Ritesh Raj Sarraf wrote:

> On Fri, 2016-09-09 at 18:44 +0530, Ritesh Raj Sarraf wrote:
> > On Fri, 2016-09-09 at 12:54 +0200, Ulf Hansson wrote:
> > > This affects the way the core calls the host driver's ->set_ios()
> > > callback. Earlier it was invoked first to do power off then power up.
> > > With this change it starts with power up instead.
> > > I wanted to try this because I suspected the initial state could be wrong.
> > > 
> > > So here are some other ideas on how to move forward.
> > > 1. Run with CONFIG_PM unset to see if we can reproduce the problem.
> > > 2. Revert back the state in the mmc core we had in 3.16 around how it
> > > deals with runtime PM for host devices. That's actually very easy as
> > > we only need to remove the pm_runtime_put|get() calls in
> > > mmc_claim|release_host().
> > > 
> > > Ritesh, can you try these options?
> > > 
> > 
> > Yes. I can try the above ones now. I'm building the kernel for it.
> 
> For #1, menuconfig doesn't allow me to disable CONFIG_PM in 4.8. I checked it
> back up till 4.0, and it still doesn't allow disabling CONFIG_PM.

You can do it, but it would require some pretty far-reaching changes.  
Besides, there's really no point.  If CONFIG_PM isn't enabled then the 
kernel doesn't do any runtime PM at all.

Alan Stern


> For #2, I'm building the 4.8-rc5 kernel with the following change. This build
> does not include the previous change you had suggested (related to 
> POWER_CYCLE)
> 
> Date:   Fri Sep 9 19:28:03 2016 +0530
> 
> Disable pm runtime in mmc core
> 
> diff --git a/drivers/mmc/core/core.c b/drivers/mmc/core/core.c
> index e55cde6..32388d5 100644
> - --- a/drivers/mmc/core/core.c
> +++ b/drivers/mmc/core/core.c
> @@ -970,9 +970,6 @@ int __mmc_claim_host(struct mmc_host *host, atomic_t 
> *abort)
> spin_unlock_irqrestore(>lock, flags);
> remove_wait_queue(>wq, );
>  
> - -   if (pm)
> - -   pm_runtime_get_sync(mmc_dev(host));
> - -
> return stop;
>  }
>  EXPORT_SYMBOL(__mmc_claim_host);
> @@ -1000,7 +997,6 @@ void mmc_release_host(struct mmc_host *host)
> spin_unlock_irqrestore(>lock, flags);
> wake_up(>wq);
> pm_runtime_mark_last_busy(mmc_dev(host));
> - -   pm_runtime_put_autosuspend(mmc_dev(host));
> }
>  }
>  EXPORT_SYMBOL(mmc_release_host);

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Fri, 2016-09-09 at 18:44 +0530, Ritesh Raj Sarraf wrote:
> On Fri, 2016-09-09 at 12:54 +0200, Ulf Hansson wrote:
> > This affects the way the core calls the host driver's ->set_ios()
> > callback. Earlier it was invoked first to do power off then power up.
> > With this change it starts with power up instead.
> > I wanted to try this because I suspected the initial state could be wrong.
> > 
> > So here are some other ideas on how to move forward.
> > 1. Run with CONFIG_PM unset to see if we can reproduce the problem.
> > 2. Revert back the state in the mmc core we had in 3.16 around how it
> > deals with runtime PM for host devices. That's actually very easy as
> > we only need to remove the pm_runtime_put|get() calls in
> > mmc_claim|release_host().
> > 
> > Ritesh, can you try these options?
> > 
> 
> Yes. I can try the above ones now. I'm building the kernel for it.

For #1, menuconfig doesn't allow me to disable CONFIG_PM in 4.8. I checked it
back up till 4.0, and it still doesn't allow disabling CONFIG_PM.

For #2, I'm building the 4.8-rc5 kernel with the following change. This build
does not include the previous change you had suggested (related to POWER_CYCLE)

Date:   Fri Sep 9 19:28:03 2016 +0530

Disable pm runtime in mmc core

diff --git a/drivers/mmc/core/core.c b/drivers/mmc/core/core.c
index e55cde6..32388d5 100644
- --- a/drivers/mmc/core/core.c
+++ b/drivers/mmc/core/core.c
@@ -970,9 +970,6 @@ int __mmc_claim_host(struct mmc_host *host, atomic_t *abort)
spin_unlock_irqrestore(>lock, flags);
remove_wait_queue(>wq, );
 
- -   if (pm)
- -   pm_runtime_get_sync(mmc_dev(host));
- -
return stop;
 }
 EXPORT_SYMBOL(__mmc_claim_host);
@@ -1000,7 +997,6 @@ void mmc_release_host(struct mmc_host *host)
spin_unlock_irqrestore(>lock, flags);
wake_up(>wq);
pm_runtime_mark_last_busy(mmc_dev(host));
- -   pm_runtime_put_autosuspend(mmc_dev(host));
}
 }
 EXPORT_SYMBOL(mmc_release_host);


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX0sF8AAoJEKY6WKPy4XVpmDQQAKPpzuw4QaaYdGuoEdZs9tvL
ZIVXOp81QVFg/VC+k8b5JmxcVmyaRrAmlKwKSBUrQqLsRIDROKHz7kAZmABvvmMo
8PC+haslv6o+M/xTd2kZMgYRk0Xj11+Ucr6mTd0BVbTqzD86WZhSmdufeiFWhzjB
aMloMDJ3cYABMIHqPQH5S/+knNhuffKqEEZ1O7jgcc10c/JpwpxaAlefNLh9Qotk
bsb+ptpBE0ggk8gD/tGSx6JZLNFy15JyzE8yuL8LfrZzzW2KU8M4kv94+6BNMqpE
sJ1mapW3zu52Hev9cDpUeTgyVVEOEXJKu9AM626voyxVYrCEwrE4usUcLVsdJH17
p7Rm5gBiEK/Wx+f10CBiFW2HwdE0KmeBgxweprv+E6VXaWFkjoXSJY5DDX5zuxlf
we9onx87IaGVTLN0I7dEcVse/3T3zT8URM/HwFyR6K+PWD0Ioiyoi4GIE96OCIJn
oUahrupOppgUZbr+qn+HULHLXJONWBslZmbS3gjQG282+koy00wquAou+4HznA5z
DBLPaljAaIuIPKxKrIDOcJ3nxBh5eBf0RHXsn9Ho6iWrcpPqYtN2XuDWNhOA/wJB
eEm1TQAMmi83FATZ0qf0n70E1/mv2wrV4nSzHPqeIgtexABWLqhS8fLCEuMW6ESt
zMRmOrou7dzaXfwkGzhC
=2dkl
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Fri, 2016-09-09 at 12:54 +0200, Ulf Hansson wrote:
> This affects the way the core calls the host driver's ->set_ios()
> callback. Earlier it was invoked first to do power off then power up.
> With this change it starts with power up instead.
> I wanted to try this because I suspected the initial state could be wrong.
> 
> So here are some other ideas on how to move forward.
> 1. Run with CONFIG_PM unset to see if we can reproduce the problem.
> 2. Revert back the state in the mmc core we had in 3.16 around how it
> deals with runtime PM for host devices. That's actually very easy as
> we only need to remove the pm_runtime_put|get() calls in
> mmc_claim|release_host().
> 
> Ritesh, can you try these options?
> 

Yes. I can try the above ones now. I'm building the kernel for it.


> Neither of the above will actually solve the problem, so I guess we
> anyway need take a closer look to understand why the usb device is
> accessed when it is actually runtime suspended.
> 
> BTW, Ritesh you could also run a git bisect to find out if/when this
> became broken.

What starting point do you want me to use ? 4.0 ?

- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJX0rWtAAoJEKY6WKPy4XVpgeYP/3FCabIWEOvKeVJK52B5gviF
+CFz00vNVddMDQjUlbN/JzaA8h5HiLMBaTp/7nBvaMYKYKZjjo8iiNQ/3jjwPUu8
S/XrWPvMUVJUhF42OMKTl4uUpVPo3fI18SYIw4XFt5pNaUFrmBPjZ6S23BhqfLN3
x2BSw9rwZrCmxH4aMpfWmDFzjWvkuJ6grpxPfbz2lx4t7BWGs4wWdTc0yfQgzWDR
SLD/CpPCkVFjnpjRnrYZei3nNo0tS0+qSv1SsRwy8GchRbOo9bK1W8YKnLH/AFLb
kCYcVKCc4mq8iq5e05vjPvdppXpbzKKlhpxxtlqzLjAYx9FbESRN89D9c7V1Ng0q
c40b+lQV7AGYUxaf+tOcErflDvzRquR1dcwcjJizgeO/pOI6uXGWE+/T5j+4q4UJ
cypkxjzPIz8SbipNEPGf2nSMppXC1RRcBGo4247vFZ0QYTC7RAViL6ErRS67kfM9
5eX2iBtO3qNZMxIMqBPu97rLoLHSZ3nFEwNbyyFnNHERZuvLUZrZY208tZYUfZKZ
X18QJKPrqfbb9n+KyyLNTaESm6jhW2yYFdiRs/4LQWniOlLLPa+6GOD7E81044nB
t8LAKtSSxK+qvFVcfqrZSfaivRKQZbYwuk+x3O4vAUDgTpTgmugNaDTYendN3v1B
R809X7cWC6V1kzTaBkK9
=o1rL
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ulf Hansson]

On 7 September 2016 at 22:48, Alan Stern  wrote:
> On Tue, 6 Sep 2016, Ulf Hansson wrote:
>
>> On 5 September 2016 at 17:58, Alan Stern  wrote:
>> > On Mon, 5 Sep 2016, Ritesh Raj Sarraf wrote:
>> >
>> >> -BEGIN PGP SIGNED MESSAGE-
>> >> Hash: SHA512
>> >>
>> >> On Sun, 2016-09-04 at 15:46 -0400, Alan Stern wrote:
>> >> >
>> >> > This is not the problem I was discussing with Ulf.  The problem was why
>> >> > the device kept going into and out of runtime suspend every three
>> >> > seconds.  The kernel log above does not say whether this was happening.
>> >> > One way to tell is to look at a usbmon trace (like we did before).
>> >>
>> >> https://people.debian.org/~rrs/tmp/usbmon.txt.gz
>> >>
>> >> This should have the logs you asked for, running on 4.8-rc4.
>> >
>> > Confirmed, the runtime suspends and resumes are still happening.
>> >
>> > Ulf, any insights?
>>
>> Alan, Ritesh,
>>
>> Yes, I am starting to understand more about what goes on here.
>> Although I need help to test as I don't have the HW.
>> As you already guessed, I suspect the problem is within the runtime PM
>> deployment in the drivers/mmc/host/rtsx_usb_sdmmc.c.
>>
>> Let me start by first give you some background to how the mmc core
>> deals with runtime PM.
>>
>> *)
>> The mmc core manages most of the calls to the pm_runtime_get|put*()
>> and pm_runtime_mark_last_busy() for the mmc host device. The gets/puts
>> are done when the core is about to access the mmc host device, via the
>> mmc host ops driver interface. You may search for calls to the
>> mmc_claim|release_host() functions to find out when the gets/puts are
>> done.
>
> Since mmc_claim_host() does call pm_runtime_get_sync(), these runtime
> suspends would not occur if the host was claimed.  So we can conclude
> that rtsx_usb_sdmmc.c must be doing I/O to the device without claiming
> the host.

Yes.

So to be clear, it's the responsible of the mmc core to deal with
mmc_claim_release() host, not the mmc host driver.

Although, under special circumstances the mmc host driver may still
need to access its device. In these cases it explicitly needs to deal
with pm_runtime_get|put*() itself.

Now, what puzzles me here, is that the rtsx_usb_sdmmc driver was
introduced in kernel v3.16.
At that point (and not until v4.1) the mmc core did *not* deal with
runtime PM for mmc host devices via mmc_claim_release_host.

So how could the driver work at that point? :-) Maybe runtime PM has
never worked for this driver!?

>
>> **)
>> The mmc core have also deployed runtime PM for the mmc *card* device
>> and which has the runtime PM autosuspend feature enabled with a 3s
>> default timeout. One important point is that the mmc card device has
>> the mmc host device assigned as being its parent device. I guessing
>> the reason to why you are encountering strange 3s intervals of runtime
>> PM suspend/resume is related to this.
>
> That sounds likely.
>
>> Now, in this case, the rtsx_usb_sdmmc driver seems to need a bit of
>> special runtime PM deployment, as the calls to pm_runtime_get|put*()
>> also controls the power to the usb device and thus also the power to
>> the card. I am guessing that's done via the usb device being assigned
>> as parent for the mmc host's platform device!?
>
> Yes, in drivers/mfd/mfd-core.c's mfd_add_device() routine, which is
> called indirectly by drivers/mfd/rtsx_usb.c's probe routine.
>
>> By reviewing the code of the rtsx_usb_sdmmc driver, particularly how
>> it calls pm_runtime_get|put() I am guessing those calls may not be
>> properly deployed. Perhaps rtsx_usb_sdmmc should convert to use the
>> usb_autopm_put|get_interface() and friends, although I didn't want to
>> make that change at this point so instead I have cooked a patch that
>> might fixes the behaviour.
>
> The usb_autopm_* calls are mostly just convenience wrappers around the
> pm_runtime_* functions, meant for use with USB drivers.  In fact, you
> can't use them with a platform_device.

Okay.

>
> It seems odd that rtsx_usb_sdmmc calls pm_runtime_put() and
> pm_runtime_get_sync() directly instead of using
> mmc_claim|release_host().

Those calls is done when the mmc core calls mmc host driver's
->set_ios() callback and to power up/off the mmc *card*. It's has
nothing to do with the mmc host device as such.

If I understand the original author's intent, was that because of
these runtime PM calls he wanted to control the power to the mmc card.

>
>> Ritesh, can you please try it out to see what happens?
>>
>> ---
>>  drivers/mmc/host/rtsx_usb_sdmmc.c | 7 +--
>>  1 file changed, 1 insertion(+), 6 deletions(-)
>>
>> diff --git a/drivers/mmc/host/rtsx_usb_sdmmc.c
>> b/drivers/mmc/host/rtsx_usb_sdmmc.c
>> index 6c71fc9..3d6fe51 100644
>> --- a/drivers/mmc/host/rtsx_usb_sdmmc.c
>> +++ b/drivers/mmc/host/rtsx_usb_sdmmc.c
>> @@ -1138,11 +1138,6 @@ static void sdmmc_set_ios(struct mmc_host *mmc,
>> struct mmc_ios *ios)
>> 

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Tue, 6 Sep 2016, Ulf Hansson wrote:

> On 5 September 2016 at 17:58, Alan Stern  wrote:
> > On Mon, 5 Sep 2016, Ritesh Raj Sarraf wrote:
> >
> >> -BEGIN PGP SIGNED MESSAGE-
> >> Hash: SHA512
> >>
> >> On Sun, 2016-09-04 at 15:46 -0400, Alan Stern wrote:
> >> >
> >> > This is not the problem I was discussing with Ulf.  The problem was why
> >> > the device kept going into and out of runtime suspend every three
> >> > seconds.  The kernel log above does not say whether this was happening.
> >> > One way to tell is to look at a usbmon trace (like we did before).
> >>
> >> https://people.debian.org/~rrs/tmp/usbmon.txt.gz
> >>
> >> This should have the logs you asked for, running on 4.8-rc4.
> >
> > Confirmed, the runtime suspends and resumes are still happening.
> >
> > Ulf, any insights?
> 
> Alan, Ritesh,
> 
> Yes, I am starting to understand more about what goes on here.
> Although I need help to test as I don't have the HW.
> As you already guessed, I suspect the problem is within the runtime PM
> deployment in the drivers/mmc/host/rtsx_usb_sdmmc.c.
> 
> Let me start by first give you some background to how the mmc core
> deals with runtime PM.
> 
> *)
> The mmc core manages most of the calls to the pm_runtime_get|put*()
> and pm_runtime_mark_last_busy() for the mmc host device. The gets/puts
> are done when the core is about to access the mmc host device, via the
> mmc host ops driver interface. You may search for calls to the
> mmc_claim|release_host() functions to find out when the gets/puts are
> done.

Since mmc_claim_host() does call pm_runtime_get_sync(), these runtime
suspends would not occur if the host was claimed.  So we can conclude
that rtsx_usb_sdmmc.c must be doing I/O to the device without claiming
the host.

> **)
> The mmc core have also deployed runtime PM for the mmc *card* device
> and which has the runtime PM autosuspend feature enabled with a 3s
> default timeout. One important point is that the mmc card device has
> the mmc host device assigned as being its parent device. I guessing
> the reason to why you are encountering strange 3s intervals of runtime
> PM suspend/resume is related to this.

That sounds likely.

> Now, in this case, the rtsx_usb_sdmmc driver seems to need a bit of
> special runtime PM deployment, as the calls to pm_runtime_get|put*()
> also controls the power to the usb device and thus also the power to
> the card. I am guessing that's done via the usb device being assigned
> as parent for the mmc host's platform device!?

Yes, in drivers/mfd/mfd-core.c's mfd_add_device() routine, which is 
called indirectly by drivers/mfd/rtsx_usb.c's probe routine.

> By reviewing the code of the rtsx_usb_sdmmc driver, particularly how
> it calls pm_runtime_get|put() I am guessing those calls may not be
> properly deployed. Perhaps rtsx_usb_sdmmc should convert to use the
> usb_autopm_put|get_interface() and friends, although I didn't want to
> make that change at this point so instead I have cooked a patch that
> might fixes the behaviour.

The usb_autopm_* calls are mostly just convenience wrappers around the
pm_runtime_* functions, meant for use with USB drivers.  In fact, you
can't use them with a platform_device.

It seems odd that rtsx_usb_sdmmc calls pm_runtime_put() and
pm_runtime_get_sync() directly instead of using
mmc_claim|release_host().

> Ritesh, can you please try it out to see what happens?
> 
> ---
>  drivers/mmc/host/rtsx_usb_sdmmc.c | 7 +--
>  1 file changed, 1 insertion(+), 6 deletions(-)
> 
> diff --git a/drivers/mmc/host/rtsx_usb_sdmmc.c
> b/drivers/mmc/host/rtsx_usb_sdmmc.c
> index 6c71fc9..3d6fe51 100644
> --- a/drivers/mmc/host/rtsx_usb_sdmmc.c
> +++ b/drivers/mmc/host/rtsx_usb_sdmmc.c
> @@ -1138,11 +1138,6 @@ static void sdmmc_set_ios(struct mmc_host *mmc,
> struct mmc_ios *ios)
> dev_dbg(sdmmc_dev(host), "%s\n", __func__);
> mutex_lock(>dev_mutex);
> 
> -   if (rtsx_usb_card_exclusive_check(ucr, RTSX_USB_SD_CARD)) {
> -   mutex_unlock(>dev_mutex);
> -   return;
> -   }
> -
> sd_set_power_mode(host, ios->power_mode);
> sd_set_bus_width(host, ios->bus_width);
> sd_set_timing(host, ios->timing, >ddr_mode);
> @@ -1336,7 +1331,7 @@ static void rtsx_usb_init_host(struct
> rtsx_usb_sdmmc *host)
> MMC_CAP_MMC_HIGHSPEED | MMC_CAP_BUS_WIDTH_TEST |
> MMC_CAP_UHS_SDR12 | MMC_CAP_UHS_SDR25 | MMC_CAP_UHS_SDR50 |
> MMC_CAP_NEEDS_POLL;
> -   mmc->caps2 = MMC_CAP2_NO_PRESCAN_POWERUP | MMC_CAP2_FULL_PWR_CYCLE;
> +   mmc->caps2 = MMC_CAP2_FULL_PWR_CYCLE;
> 
> mmc->max_current_330 = 400;
> mmc->max_current_180 = 800;

These changes don't seem to affect the way rtsx_usb_sdmmc.c handles 
runtime PM.  In particular, the driver doesn't call 
pm_runtime_mark_last_busy() anywhere.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to 

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Ulf,

On Tue, 2016-09-06 at 11:42 +0200, Ulf Hansson wrote:
> 
> By reviewing the code of the rtsx_usb_sdmmc driver, particularly how
> it calls pm_runtime_get|put() I am guessing those calls may not be
> properly deployed. Perhaps rtsx_usb_sdmmc should convert to use the
> usb_autopm_put|get_interface() and friends, although I didn't want to
> make that change at this point so instead I have cooked a patch that
> might fixes the behaviour.
> 
> Ritesh, can you please try it out to see what happens?

I was able to hit the issue again, with your patch applied. I tried it on top of
the 4.8-rc5 kernel.

I ensured to capture usbmon trace.
https://people.debian.org/~rrs/tmp/usbmon-ulf.txt.gz


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXzvgmAAoJEKY6WKPy4XVpJ/oQAIR/bC82KdqD3xuQpq8r62RT
fV8DSduNhr394GIDO5PBDSKUAFDKCHL9SyCBx9I5zx1U7OF+IfvhgpRji+XcBsQ5
TOtDAhiiTatKfWl/zLGbVqukNS8QLzyU26w0HRabvK3RZ0lGxBugQ8KneUC8wA/Q
NYWAgio5gN5jpD6BgGEZXo6cdzcdI1HM5kyNxcs4VfhD0zDor4wlrW024458a3Fs
02QAkmyV1aBwR4w/Ntw7D9DXb8sVujGgeEOr+KukzdFOPW+w4JOANv3gregDnKSc
EgIYmtTE95d0jWyJuS5sbZlbf4QOcrv9eVwn86TOdhZHU1XlaqaIEbRPzu15ZtZF
B+zYbWg+TgTYFgTYJoaB8T+CUJMMnNh62IC72LXa5K/C0kjgjlHUzis04XdFmT2q
jYC767M1utXi7a4LcXxw8V8uoV0nnmuvxWzhrcdBxi6+a85BLL8bPKT+nrGxkxB0
Hg7Wmnc9moohpjYD3KlAYR3bW56dDYrGgsj8xRUnplBkUp10g2vhix7bk/q+eUwU
gJghnI/WgEE5hBQabtuqCTCsvMdTXmZVjzMg1k43V5v+UR0a7mKVW0uBWu5cU38p
Ga9ZrNmPEzxOVmeXH3XCB8fCXRgce8ieu/KEPHpvbegia0nX4X7BcCHhK2KGsqnX
Y4f+TvpJw2idUe/cvdtw
=/aP1
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ulf Hansson]

On 5 September 2016 at 17:58, Alan Stern  wrote:
> On Mon, 5 Sep 2016, Ritesh Raj Sarraf wrote:
>
>> -BEGIN PGP SIGNED MESSAGE-
>> Hash: SHA512
>>
>> On Sun, 2016-09-04 at 15:46 -0400, Alan Stern wrote:
>> >
>> > This is not the problem I was discussing with Ulf.  The problem was why
>> > the device kept going into and out of runtime suspend every three
>> > seconds.  The kernel log above does not say whether this was happening.
>> > One way to tell is to look at a usbmon trace (like we did before).
>>
>> https://people.debian.org/~rrs/tmp/usbmon.txt.gz
>>
>> This should have the logs you asked for, running on 4.8-rc4.
>
> Confirmed, the runtime suspends and resumes are still happening.
>
> Ulf, any insights?

Alan, Ritesh,

Yes, I am starting to understand more about what goes on here.
Although I need help to test as I don't have the HW.
As you already guessed, I suspect the problem is within the runtime PM
deployment in the drivers/mmc/host/rtsx_usb_sdmmc.c.

Let me start by first give you some background to how the mmc core
deals with runtime PM.

*)
The mmc core manages most of the calls to the pm_runtime_get|put*()
and pm_runtime_mark_last_busy() for the mmc host device. The gets/puts
are done when the core is about to access the mmc host device, via the
mmc host ops driver interface. You may search for calls to the
mmc_claim|release_host() functions to find out when the gets/puts are
done.

**)
The mmc core have also deployed runtime PM for the mmc *card* device
and which has the runtime PM autosuspend feature enabled with a 3s
default timeout. One important point is that the mmc card device has
the mmc host device assigned as being its parent device. I guessing
the reason to why you are encountering strange 3s intervals of runtime
PM suspend/resume is related to this.

Now, in this case, the rtsx_usb_sdmmc driver seems to need a bit of
special runtime PM deployment, as the calls to pm_runtime_get|put*()
also controls the power to the usb device and thus also the power to
the card. I am guessing that's done via the usb device being assigned
as parent for the mmc host's platform device!?

By reviewing the code of the rtsx_usb_sdmmc driver, particularly how
it calls pm_runtime_get|put() I am guessing those calls may not be
properly deployed. Perhaps rtsx_usb_sdmmc should convert to use the
usb_autopm_put|get_interface() and friends, although I didn't want to
make that change at this point so instead I have cooked a patch that
might fixes the behaviour.

Ritesh, can you please try it out to see what happens?

---
 drivers/mmc/host/rtsx_usb_sdmmc.c | 7 +--
 1 file changed, 1 insertion(+), 6 deletions(-)

diff --git a/drivers/mmc/host/rtsx_usb_sdmmc.c
b/drivers/mmc/host/rtsx_usb_sdmmc.c
index 6c71fc9..3d6fe51 100644
--- a/drivers/mmc/host/rtsx_usb_sdmmc.c
+++ b/drivers/mmc/host/rtsx_usb_sdmmc.c
@@ -1138,11 +1138,6 @@ static void sdmmc_set_ios(struct mmc_host *mmc,
struct mmc_ios *ios)
dev_dbg(sdmmc_dev(host), "%s\n", __func__);
mutex_lock(>dev_mutex);

-   if (rtsx_usb_card_exclusive_check(ucr, RTSX_USB_SD_CARD)) {
-   mutex_unlock(>dev_mutex);
-   return;
-   }
-
sd_set_power_mode(host, ios->power_mode);
sd_set_bus_width(host, ios->bus_width);
sd_set_timing(host, ios->timing, >ddr_mode);
@@ -1336,7 +1331,7 @@ static void rtsx_usb_init_host(struct
rtsx_usb_sdmmc *host)
MMC_CAP_MMC_HIGHSPEED | MMC_CAP_BUS_WIDTH_TEST |
MMC_CAP_UHS_SDR12 | MMC_CAP_UHS_SDR25 | MMC_CAP_UHS_SDR50 |
MMC_CAP_NEEDS_POLL;
-   mmc->caps2 = MMC_CAP2_NO_PRESCAN_POWERUP | MMC_CAP2_FULL_PWR_CYCLE;
+   mmc->caps2 = MMC_CAP2_FULL_PWR_CYCLE;

mmc->max_current_330 = 400;
mmc->max_current_180 = 800;
-- 

Kind regards
Uffe
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Mon, 5 Sep 2016, Ritesh Raj Sarraf wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
> 
> On Sun, 2016-09-04 at 15:46 -0400, Alan Stern wrote:
> > 
> > This is not the problem I was discussing with Ulf.  The problem was why
> > the device kept going into and out of runtime suspend every three
> > seconds.  The kernel log above does not say whether this was happening.
> > One way to tell is to look at a usbmon trace (like we did before).
> 
> https://people.debian.org/~rrs/tmp/usbmon.txt.gz
> 
> This should have the logs you asked for, running on 4.8-rc4.

Confirmed, the runtime suspends and resumes are still happening.

Ulf, any insights?

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Sun, 2016-09-04 at 15:46 -0400, Alan Stern wrote:
> 
> This is not the problem I was discussing with Ulf.  The problem was why
> the device kept going into and out of runtime suspend every three
> seconds.  The kernel log above does not say whether this was happening.
> One way to tell is to look at a usbmon trace (like we did before).

https://people.debian.org/~rrs/tmp/usbmon.txt.gz

This should have the logs you asked for, running on 4.8-rc4.


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXzWwYAAoJEKY6WKPy4XVpFKgP/i76Ek/1e1CYqStgakQUtmPb
eeGuSPFVqvQt4PEvGNvMtXcLMx5IKIEpKbqua7N4/ZfKmf5EA00wUCXzm85MnyAp
fIN9K1uOW1ZepnsViJ/U1bNZvHVDXy/LEfd5me+7JzWsPqaR/KjyZmZ8VSlu+aov
CvBDrt41x9plf1xJBYffHc2KvdM0lYFJjft2Gop9qr/hMhIy8RcJdbylPpnf4rtU
cbm3Ti3DdA+r86MLCKagq50Iow3xcfBEEYZLnn+ucnpTOWz56TyO3+44sjgLgrpy
IDRBlCbgk2RZkm8lpj+d052ssk3MjLBupBFkoRfXfXfear3zLrut2Q51xjeJIINz
oZdmAxozsvGxCtgC6dIb/79clruL8kqdr/TqF/YtwzB6JnFvZEgzBcpAlxFBxTlK
RtvAyPVs4Np1vtTli/Uv1O+odoR0FPhzpV+nDSsea7im6/oMav40UpXvgs72EEUS
cr5SwY8xClfNeemCHFZ/wFeYwPfjPfNU5Lgm/Hkpx6oaOABCnfacF1nWxbIRbuoh
gP9vW/Z0LI4azo940xlWfRiDck5W9IQXeI3v2wXVVIE8TDwxraQzyBXKKPBFxmfX
jTKWLRDDqyOWGcWxLJpMHMOa9rNtAZeiBI7TMbnqZKj6eLsdjuOW76zDhEHnMAtb
dUCOFYRG24arYTUpIVnB
=YG3r
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Sun, 4 Sep 2016, Ritesh Raj Sarraf wrote:

> > This issue has been around with previous kernels too.
> > 
> > > Perhaps you can run a test on a 4.8 rc4 kernel, just to double check.
> > > The 4.8 rc4, contains the following fixes in the mmc block layer.
> > > 
> > > commit 7afafc8a44bf ("block: Fix secure erase")
> > > commit 869c554808cc ("mmc: fix use-after-free of struct request")
> > 
> > I'll share my 4.8-rc4 results soon.
> 
> As I hoped, I was able to reproduce this with 4.8-rc4 too.
> 
> [  857.999547] systemd[1]: apt-daily.timer: Adding 10h 21min 53.234725s random
> time.
> [13071.615285] usb 2-4: USB disconnect, device number 2
> [13072.794802] usb 2-4: new high-speed USB device number 7 using xhci_hcd
> [13072.925092] usb 2-4: New USB device found, idVendor=0bda, idProduct=0129
> [13072.925094] usb 2-4: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=3
> [13072.925095] usb 2-4: Product: USB2.0-CRW
> [13072.925096] usb 2-4: Manufacturer: Generic
> [13072.925097] usb 2-4: SerialNumber: 2010020139600
> [13093.499011] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
> [13093.612239] usb 2-4: Device not responding to setup address.
> [13093.818896] usb 2-4: Device not responding to setup address.
> [13094.025491] usb 2-4: device not accepting address 7, error -71
> [13094.138844] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
> [13094.252178] usb 2-4: device descriptor read/64, error -71
> [13094.489037] usb 2-4: device descriptor read/all, error -71
> [13094.602374] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
> [13094.602453] usb 2-4: Device not responding to setup address.
> [13094.808929] usb 2-4: Device not responding to setup address.
> [13095.015523] usb 2-4: device not accepting address 7, error -71
> [13095.128879] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
> [13095.145799] usb 2-4: device descriptor read/all, error 8
> [13095.145842] usb 2-4: USB disconnect, device number 7
> [13095.492216] usb 2-4: new high-speed USB device number 8 using xhci_hcd
> [13095.605642] usb 2-4: Device not responding to setup address.
> [13095.812294] usb 2-4: Device not responding to setup address.

This is not the problem I was discussing with Ulf.  The problem was why
the device kept going into and out of runtime suspend every three
seconds.  The kernel log above does not say whether this was happening.
One way to tell is to look at a usbmon trace (like we did before).

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Sun, 2016-09-04 at 17:02 +0530, Ritesh Raj Sarraf wrote:
> > Sorry for the delay! We have had some regressions for 4.8 rc1 in the
> > mmc block layer. Those problem should be resolved by now.
> > 
> > By reading from the runtime PM issues you have, the problems could
> > very well be related. Although I don't believe the issues was present
> > in a 4.7 kernel.
> > 
> 
> This issue has been around with previous kernels too.
> 
> > Perhaps you can run a test on a 4.8 rc4 kernel, just to double check.
> > The 4.8 rc4, contains the following fixes in the mmc block layer.
> > 
> > commit 7afafc8a44bf ("block: Fix secure erase")
> > commit 869c554808cc ("mmc: fix use-after-free of struct request")
> 
> I'll share my 4.8-rc4 results soon.

As I hoped, I was able to reproduce this with 4.8-rc4 too.

[  857.999547] systemd[1]: apt-daily.timer: Adding 10h 21min 53.234725s random
time.
[13071.615285] usb 2-4: USB disconnect, device number 2
[13072.794802] usb 2-4: new high-speed USB device number 7 using xhci_hcd
[13072.925092] usb 2-4: New USB device found, idVendor=0bda, idProduct=0129
[13072.925094] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[13072.925095] usb 2-4: Product: USB2.0-CRW
[13072.925096] usb 2-4: Manufacturer: Generic
[13072.925097] usb 2-4: SerialNumber: 2010020139600
[13093.499011] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
[13093.612239] usb 2-4: Device not responding to setup address.
[13093.818896] usb 2-4: Device not responding to setup address.
[13094.025491] usb 2-4: device not accepting address 7, error -71
[13094.138844] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
[13094.252178] usb 2-4: device descriptor read/64, error -71
[13094.489037] usb 2-4: device descriptor read/all, error -71
[13094.602374] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
[13094.602453] usb 2-4: Device not responding to setup address.
[13094.808929] usb 2-4: Device not responding to setup address.
[13095.015523] usb 2-4: device not accepting address 7, error -71
[13095.128879] usb 2-4: reset high-speed USB device number 7 using xhci_hcd
[13095.145799] usb 2-4: device descriptor read/all, error 8
[13095.145842] usb 2-4: USB disconnect, device number 7
[13095.492216] usb 2-4: new high-speed USB device number 8 using xhci_hcd
[13095.605642] usb 2-4: Device not responding to setup address.
[13095.812294] usb 2-4: Device not responding to setup address.


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXzGFqAAoJEKY6WKPy4XVpZzcP/jCzROd3+k0oF+cgK4WqKKEN
Wb/LOHezZlyNXnZ4/UxT0ox9Agc9AMQEvx4+77Itm5khQ+H3ZMEQNQg0jSENZ6aT
KjPSC3fUZ93PBGyCzec+CTj4UY49WJ1hZ4dvv7WW7WEuR8gxZxV+Z0VcG7kD8h0E
aOwJ5PVbyNSY7ZCH8NNRPnx5v74C/b+1OlFbRV1SNTUBU06ekeImy5IuvGwF45Gq
cLbKMIjJmUsg/jSol/pqUg1Sewj+z1part7sF5ZeAYM/ntwb4JAWwYvcWNI7VMxW
skT7HqyQ/qKk++UShxGsHYqV8Ec5Rx5tAUTgEH68Y7y4i9YDSTOnqXDgjTANz5RL
yaZS856dGoIs96/mHCjzMV+1NYpTo2aMPO1/JDs6nvKfBtyIVDbTsB8qbdP5vqnb
x1GmzB6j8wDHBTAtJIifkB8XGQfcxbDto2LG6/OnPPN3/aiTMCKB6ZND2HISNGfr
IeN39Ay35zn9epq6D3usdd1TAlF5xqo1djHyFDYfXE0gZsJZiCCs9GC2NaP46ZYp
G7a4O1UpbPKhRq7peyh2f/GzHg+3k1J+PD+I1Us/w2Dj1ObCr7M4ToF70AQ2xISE
DFBuP7dWue6waQup7S3zNLqyP5K101NkKQbSrXJHEhxIaqNFbEZg1D8MuC4I0gHA
i4uloGV6oSg973dwyTiU
=q0wG
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Alan, Ulf.

Sorry for the delayed reply. Last week was a sickly week for me.

On Tue, 2016-08-30 at 10:14 +0200, Ulf Hansson wrote:
> On 25 August 2016 at 19:17, Alan Stern  wrote:
> > Ulf:
> >
> > Ritesh has collected logs showing that his Realtek RTS5129 USB card
> > reader (drivers/mfd/rtsx_usb.c, drivers/mmc/host/rtsx_usb_sdmmc.c) goes
> > into runtime autosuspend every 3 seconds and then immediately resumes.
> > This sounds like something is failing to call
> > pm_runtime_mark_last_busy().  He's using a 4.7 kernel.
> >
> > In addition, the device gets disconnected from the USB bus from time to
> > time.  This appears to be a completely separate issue.
> >
> > For now, I'd like to fix the runtime PM problem.  But I don't know
> > anything about the mmc core, so perhaps you can help.
> >
> 

@Alan,

I noticed that, even with the 1-line patch that disabled autosuspend attribute
for this driver, I still occasionally hit the driver error messages.

[19608.533058] usb 1-4: reset high-speed USB device number 13 using xhci_hcd
[19608.692846] usb 1-4: Device not responding to setup address.
[19608.898254] usb 1-4: Device not responding to setup address.
[19609.099553] usb 1-4: device not accepting address 13, error -71
[19609.259474] usb 1-4: reset high-speed USB device number 13 using xhci_hcd
[19609.420221] usb 1-4: device descriptor read/64, error -71
[19609.699656] usb 1-4: device descriptor read/all, error -71
[19609.859678] usb 1-4: reset high-speed USB device number 13 using xhci_hcd
[19609.859768] usb 1-4: Device not responding to setup address.
[19610.062891] usb 1-4: Device not responding to setup address.
[19610.266148] usb 1-4: device not accepting address 13, error -71
[19610.426157] usb 1-4: reset high-speed USB device number 13 using xhci_hcd
[19610.426252] usb 1-4: Device not responding to setup address.
[19610.629533] usb 1-4: Device not responding to setup address.
[19610.832791] usb 1-4: device not accepting address 13, error -71
[19610.833374] usb 1-4: USB disconnect, device number 13
[19611.506151] usb 1-4: new high-speed USB device number 14 using xhci_hcd
[19611.666770] usb 1-4: device descriptor read/64, error -71
[19611.929563] usb 1-4: Device not responding to setup address.
[19612.136298] usb 1-4: Device not responding to setup address.
[19612.342800] usb 1-4: device not accepting address 14, error -71
[19612.502791] usb 1-4: new high-speed USB device number 15 using xhci_hcd
[19612.662829] usb 1-4: device descriptor read/64, error -71
[19612.929561] usb 1-4: Device not responding to setup address.
[19613.132883] usb 1-4: Device not responding to setup address.
[19613.336162] usb 1-4: device not accepting address 15, error -71
[19613.496165] usb 1-4: new high-speed USB device number 16 using xhci_hcd
[19613.509674] usb 1-4: device descriptor read/8, error -71
[19613.626406] usb 1-4: device descriptor read/8, error -71
[19613.889528] usb 1-4: new high-speed USB device number 17 using xhci_hcd
[19613.889639] usb 1-4: Device not responding to setup address.
[19614.092899] usb 1-4: Device not responding to setup address.
[19614.296169] usb 1-4: device not accepting address 17, error -71
[19614.296216] usb usb1-port4: unable to enumerate USB device
[20357.431911] SGI XFS with ACLs, security attributes, realtime, no debug
enabled


Earlier, only the device resets error was seen. But I was able to see this once
again.

> Sorry for the delay! We have had some regressions for 4.8 rc1 in the
> mmc block layer. Those problem should be resolved by now.
> 
> By reading from the runtime PM issues you have, the problems could
> very well be related. Although I don't believe the issues was present
> in a 4.7 kernel.
> 

This issue has been around with previous kernels too.

> Perhaps you can run a test on a 4.8 rc4 kernel, just to double check.
> The 4.8 rc4, contains the following fixes in the mmc block layer.
> 
> commit 7afafc8a44bf ("block: Fix secure erase")
> commit 869c554808cc ("mmc: fix use-after-free of struct request")

I'll share my 4.8-rc4 results soon.

Thanks,
Ritesh

- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXzAZBAAoJEKY6WKPy4XVpKk4P/0lwMRmZYVhUf19s6yqviMzB
5YPMKCahz5KyPEBP5bdfDW6TCi83UI34yn/FCUj0l4kRRb41zL7JUZ/PYjyFfq3c
2d6viAx4+Qjqn26sZ+PDciEaBKHAQWEu1SYgGfxk+5fmXUc/aLQpY9h+DAHB30xU
H80FQz5Ct6rFwp5TkHmFALSk0Ue1bF/ZJy9AvsOkGZCN+1lYekEh8Ry26RvKsIEc
2i5wJ5CDJXQT1AiV5Jwy6WfiEy8a8FKlxRuo767e9Ftp/sZhUaulhYXsBaJOm6ZT
ckBbib9HEtfKM/nL/Cp3kjBqR7PHWdxeFER9x+r/KWCQYalD1MlbtP48oekFGr7U
h/XqLNuHdaKdfLFctHx4HZ/vQCBQ8XW0dYfpXSnoNOzm7I8qxp5icUZGad5BTxSE
QDbg8A6vW1gZ8dxRVG39+JHVHUxx2AXvUM720aUpRdik8c6+kz/pcIwXPLvboPsY
WGKDiI1Q8EE7/8910+g/qghOI97o0dgasdVY9FZGhYL427BzanAPcXm5aGXeyFJk
5mA+TNASC8gviYC5z7hc0lOouoprNyt1ssp6hZFPmkEsOyKpy6rQrf2VJcJuoYdH
PHsfJFUkM7/t2PygEhRBV266DVCzOR1Ut968T++ErnHmEVkHse94cRNvbXZVYkHJ

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ulf Hansson]

On 25 August 2016 at 19:17, Alan Stern  wrote:
> Ulf:
>
> Ritesh has collected logs showing that his Realtek RTS5129 USB card
> reader (drivers/mfd/rtsx_usb.c, drivers/mmc/host/rtsx_usb_sdmmc.c) goes
> into runtime autosuspend every 3 seconds and then immediately resumes.
> This sounds like something is failing to call
> pm_runtime_mark_last_busy().  He's using a 4.7 kernel.
>
> In addition, the device gets disconnected from the USB bus from time to
> time.  This appears to be a completely separate issue.
>
> For now, I'd like to fix the runtime PM problem.  But I don't know
> anything about the mmc core, so perhaps you can help.
>

Sorry for the delay! We have had some regressions for 4.8 rc1 in the
mmc block layer. Those problem should be resolved by now.

By reading from the runtime PM issues you have, the problems could
very well be related. Although I don't believe the issues was present
in a 4.7 kernel.

Perhaps you can run a test on a 4.8 rc4 kernel, just to double check.
The 4.8 rc4, contains the following fixes in the mmc block layer.

commit 7afafc8a44bf ("block: Fix secure erase")
commit 869c554808cc ("mmc: fix use-after-free of struct request")

Kind regards
Uffe

>
> On Thu, 25 Aug 2016, Ritesh Raj Sarraf wrote:
>
>> > Do you happen to know which driver is being used: the memstick
>> > (rtsx_usb_ms) or mmc (rtsx_usb_sdmmc) driver?  I suppose this may
>> > depend on what type of card you insert in the reader.
>> >
>>
>>
>> I think it is the rtsx_usb_sdmmc which is in use. I removed the rtsx_usb_ms
>> kernel module and still was able to access the sdcard.
>>
>> rrs@learner:~$ lsmod | grep usb_ms
>> 2016-08-25 / 18:45:52 ♒♒♒  ☹  => 1
>>
>> rrs@learner:~$ lsmod | grep usb_sd
>> rtsx_usb_sdmmc 24576  0
>> rtsx_usb   24576  1 rtsx_usb_sdmmc
>> mmc_core  135168  4 mmc_block,sdhci,sdhci_acpi,rtsx_usb_sdmmc
>> 2016-08-25 / 18:45:55 ♒♒♒  ☺
>>
>>
>> The interesting bit is that when I enter the adapter into the reader, I get 
>> the
>> following error 5 times, and then it can access the card.
>>
>> [  496.822613] mmc0: tuning execution failed: -22
>> [  496.822629] mmc0: error -22 whilst initialising SD card
>> [  501.980908] mmc0: tuning execution failed: -22
>> [  501.980922] mmc0: error -22 whilst initialising SD card
>> [  507.119953] mmc0: tuning execution failed: -22
>> [  507.119968] mmc0: error -22 whilst initialising SD card
>> [  513.148143] mmc0: tuning execution failed: -22
>> [  513.148157] mmc0: error -22 whilst initialising SD card
>> [  518.702215] mmc0: tuning execution failed: -22
>> [  518.70] mmc0: error -22 whilst initialising SD card
>> [  524.081122] mmc0: new ultra high speed SDR50 SDHC card at address 0002
>> [  524.082596] mmcblk0: mmc0:0002 NCard 14.9 GiB
>> [  524.084240]  mmcblk0: p1
>> [  524.306434] FAT-fs (mmcblk0p1): utf8 is not a recommended IO charset for 
>> FAT
>> filesystems, filesystem will be case sensitive!
>
> I can't tell why those errors occur.  It would require more debugging.
> At least they don't seem to cause any serious problems.
>
>> With your patch applied, the initial errors messages (xhci_hcd :00:14.0: 
>> dev
>> 4 ep1out scatterlist error -104/-110) are not seen so far.
>
> This is because those errors occur when the device goes into runtime
> autosuspend and the computer tries to communicate with it while it is
> suspended.  Both things (the autosuspend and the communication attempt)
> are bugs in the drivers.
>
>> The device does reset (as you had mentioned), but it doesn't seem to have any
>> power drain related negative effects.
>>
>>
>> rrs@learner:~$ less /var/tmp/dmesg-post-patch.txt  | tail -n 25
>> [11922.283067] wlan0: RX AssocResp from 00:40:77:bb:55:12 (capab=0x411 
>> status=0
>> aid=1)
>> [11922.283743] wlan0: associated
>> [11922.283801] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
>> [11922.883849] systemd[1]: apt-daily.timer: Adding 8h 36min 18.323966s random
>> time.
>> [11923.081426] systemd[1]: apt-daily.timer: Adding 2h 23min 22.221062s random
>> time.
>> [13799.616838] atkbd serio0: Unknown key pressed (translated set 2, code 
>> 0xbe on
>> isa0060/serio0).
>> [13799.616843] atkbd serio0: Use 'setkeycodes e03e ' to make it 
>> known.
>> [13799.625901] atkbd serio0: Unknown key released (translated set 2, code 
>> 0xbe
>> on isa0060/serio0).
>> [13799.625905] atkbd serio0: Use 'setkeycodes e03e ' to make it 
>> known.
>> [13800.547966] usb 1-4: USB disconnect, device number 15
>
> Spontaneous disconnect followed by reconnect a little later...
>
>> [13801.707137] usb 1-4: new high-speed USB device number 16 using xhci_hcd
>> [13801.880788] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
>> [13801.880791] usb 1-4: New USB device strings: Mfr=1, Product=2, 
>> SerialNumber=3
>> [13801.880792] usb 1-4: Product: USB2.0-CRW
>> [13801.880793] usb 1-4: Manufacturer: Generic
>> [13801.880794] usb 1-4: SerialNumber: 2010020139600
>> 

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Alan,

On Fri, 2016-08-26 at 10:14 -0400, Alan Stern wrote:
> > [ 8758.487792] usb 1-4: USB disconnect, device number 13
> > [ 8759.711773] usb 1-4: new high-speed USB device number 16 using xhci_hcd
> > [ 8759.885543] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
> > [ 8759.885552] usb 1-4: New USB device strings: Mfr=1, Product=2,
> SerialNumber=3
> > [ 8759.885557] usb 1-4: Product: USB2.0-CRW
> > [ 8759.885560] usb 1-4: Manufacturer: Generic
> > [ 8759.885563] usb 1-4: SerialNumber: 2010020139600
> > 2016-08-26 / 14:39:39 ♒♒♒  ☺  
> 
> Okay, I guess that's not too surprising.  Most high-speed devices do 
> not use LPM at all.  So there must be some other cause.
> 

Cool. Is there anything else you want me to try ?
Or, I guess, we'll wait for Ulf to respond.

> > rrs@learner:~$ uptime
> >  14:41:20 up 15:53,  1 user,  load average: 0.54, 0.31, 0.38
> > 2016-08-26 / 14:41:20 ♒♒♒  ☺  
> > 
> > This time there's also another device resetting.
> > 
> > Bus 001 Device 015: ID 048d:8350 Integrated Technology Express, Inc.
> 
> It's hard to tell what that means.
> 
> There's a small possibility that the xhci-hcd debugging information 
> might help, if you have it enabled when a reset occurs.  But I won't be 
> able to interpret it; you'll need help from Mathias.

I haven't noticed this reset that often. But yes, if it starts hindering, I'll
capture the necessary debugging information.

 
- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXwFzJAAoJEKY6WKPy4XVp26oP/jmIMDpdbP4Q3+EsHp0Mv8eR
tT7KJhcnslQV9UJdNitdLv2MgsDRVk6XLGINQ7stAiePwdwoVFG5DxQjSy1zJXEn
iK6+wYgHxyVT98NYmcZi2vCuWm0xEpVRpmme7vlb/hnNYOfAKa6bFOLgEzcRtu8f
pvJgdWnB+EUhvuJlzdmHHAK03RtCvSKoiVDluiXUHeC8M2gyXH0LUvYKrq0dGbxm
wOeVmbVDqmuUjO4BbaYINWskgMCC3o7WuYcNl6ECINm7EUOtDpr3/ffrd8kvyNmW
ZdFfG2ZiIQRUTPiZyjf/erZz9IHhHjCL5fV/sMxg3ooLBE3eL2rTuHdbRHHaFz8J
rOrqtOXyNpyP8cmJ6T0HKlhaLuq8xUv+wWn3VWWbfOUdBchTiHfiwGyxF8wbreTB
/LGg3ZeWlU0giRrmBSuviW8P5Y9CvbCK0dicEfzfgme/2j/VmTdQSqWkGlbw2HWs
MThEJE44yIbhKHc5PJ/i8SFVm3URU+S6+5OBH1cLKDFRYVLYuU/B28HcjBjGN5Mh
ceH5DXmeJUNMHroJ3gc+Eu4AGLlNwuPukah3diSYkJNMvgSOFRYVzPM+zPeQ7WWx
C76ftCy8AQASdTZLqPZ+Q9JmCsBJOwZqeG+2zg9c894nZNF+HzludcMqQtvS4D/u
JY8SIsJuYjlt7he68E5H
=WjPh
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Fri, 26 Aug 2016, Ritesh Raj Sarraf wrote:

> I was able to reproduce the resets after disabling LPM too.
> 
> [ 5026.849192] systemd[1]: apt-daily.timer: Adding 6h 13min 53.496331s random
> time.
> [ 5027.078155] systemd[1]: apt-daily.timer: Adding 5h 55min 19.813619s random
> time.
> [ 7375.350630] usb 1-4: USB disconnect, device number 11
> [ 7375.670070] usb 1-4: new high-speed USB device number 12 using xhci_hcd
> [ 7375.843822] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
> [ 7375.843831] usb 1-4: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=3
> [ 7375.843835] usb 1-4: Product: USB2.0-CRW
> [ 7375.843839] usb 1-4: Manufacturer: Generic
> [ 7375.843842] usb 1-4: SerialNumber: 2010020139600
> [ 7379.920027] usb 1-4: USB disconnect, device number 12
> [ 7381.127199] usb 1-4: new high-speed USB device number 13 using xhci_hcd
> [ 7381.300936] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
> [ 7381.300945] usb 1-4: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=3
> [ 7381.300950] usb 1-4: Product: USB2.0-CRW
> [ 7381.300953] usb 1-4: Manufacturer: Generic
> [ 7381.300956] usb 1-4: SerialNumber: 2010020139600
> [ 8596.938587] usb 1-8: USB disconnect, device number 6
> [ 8597.328597] usb 1-8: new full-speed USB device number 15 using xhci_hcd
> [ 8597.513108] usb 1-8: New USB device found, idVendor=048d, idProduct=8350
> [ 8597.513116] usb 1-8: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=0
> [ 8597.513121] usb 1-8: Product: ITE Device(8350)
> [ 8597.513124] usb 1-8: Manufacturer: ITE Tech. Inc.
> [ 8758.487792] usb 1-4: USB disconnect, device number 13
> [ 8759.711773] usb 1-4: new high-speed USB device number 16 using xhci_hcd
> [ 8759.885543] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
> [ 8759.885552] usb 1-4: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=3
> [ 8759.885557] usb 1-4: Product: USB2.0-CRW
> [ 8759.885560] usb 1-4: Manufacturer: Generic
> [ 8759.885563] usb 1-4: SerialNumber: 2010020139600
> 2016-08-26 / 14:39:39 ♒♒♒  ☺  

Okay, I guess that's not too surprising.  Most high-speed devices do 
not use LPM at all.  So there must be some other cause.

> rrs@learner:~$ uptime
>  14:41:20 up 15:53,  1 user,  load average: 0.54, 0.31, 0.38
> 2016-08-26 / 14:41:20 ♒♒♒  ☺  
> 
> This time there's also another device resetting.
> 
> Bus 001 Device 015: ID 048d:8350 Integrated Technology Express, Inc.

It's hard to tell what that means.

There's a small possibility that the xhci-hcd debugging information 
might help, if you have it enabled when a reset occurs.  But I won't be 
able to interpret it; you'll need help from Mathias.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Alan,

On Thu, 2016-08-25 at 19:04 +0530, Ritesh Raj Sarraf wrote:
> > As you mentioned above, there's another aspect to power management 
> > besides runtime PM, namely Link Power Management.  Perhaps the device 
> > can't handle LPM.
> > 
> > You can test this by editing the usb_device_supports_lpm() routine in 
> > drivers/usb/core/hub.c.  If you make it always return 0 immediately, 
> > that will disable LPM for all USB devices.  If the spontaneous 
> > disconnects don't reappear, we'll have the answer.
> > 
> > Alan Stern
> > 
> 
> 
> I'll try this out on a new build and share my results again on this thread.

I was able to reproduce the resets after disabling LPM too.

[ 5026.849192] systemd[1]: apt-daily.timer: Adding 6h 13min 53.496331s random
time.
[ 5027.078155] systemd[1]: apt-daily.timer: Adding 5h 55min 19.813619s random
time.
[ 7375.350630] usb 1-4: USB disconnect, device number 11
[ 7375.670070] usb 1-4: new high-speed USB device number 12 using xhci_hcd
[ 7375.843822] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
[ 7375.843831] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 7375.843835] usb 1-4: Product: USB2.0-CRW
[ 7375.843839] usb 1-4: Manufacturer: Generic
[ 7375.843842] usb 1-4: SerialNumber: 2010020139600
[ 7379.920027] usb 1-4: USB disconnect, device number 12
[ 7381.127199] usb 1-4: new high-speed USB device number 13 using xhci_hcd
[ 7381.300936] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
[ 7381.300945] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 7381.300950] usb 1-4: Product: USB2.0-CRW
[ 7381.300953] usb 1-4: Manufacturer: Generic
[ 7381.300956] usb 1-4: SerialNumber: 2010020139600
[ 8596.938587] usb 1-8: USB disconnect, device number 6
[ 8597.328597] usb 1-8: new full-speed USB device number 15 using xhci_hcd
[ 8597.513108] usb 1-8: New USB device found, idVendor=048d, idProduct=8350
[ 8597.513116] usb 1-8: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 8597.513121] usb 1-8: Product: ITE Device(8350)
[ 8597.513124] usb 1-8: Manufacturer: ITE Tech. Inc.
[ 8758.487792] usb 1-4: USB disconnect, device number 13
[ 8759.711773] usb 1-4: new high-speed USB device number 16 using xhci_hcd
[ 8759.885543] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
[ 8759.885552] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 8759.885557] usb 1-4: Product: USB2.0-CRW
[ 8759.885560] usb 1-4: Manufacturer: Generic
[ 8759.885563] usb 1-4: SerialNumber: 2010020139600
2016-08-26 / 14:39:39 ♒♒♒  ☺  

rrs@learner:~$ uptime
 14:41:20 up 15:53,  1 user,  load average: 0.54, 0.31, 0.38
2016-08-26 / 14:41:20 ♒♒♒  ☺  

This time there's also another device resetting.

Bus 001 Device 015: ID 048d:8350 Integrated Technology Express, Inc.


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXwAi6AAoJEKY6WKPy4XVpcpoP/RxPvuy47nbXNRs3ffC3Z71l
bFYbsnL/JtifWdNzEhO6Ff0aefLmqjBh/jXeTA3GicLObrA41EZ55VUz672UZmd3
i8s0GrCtrZcZi6DuNA5OulcSgmEj/PP2WXSWNsuivlhrdg8Xoi3WGqgyNWu/FJoe
IRnht/o+injTxKNsXnpJbr/QGGK9Rt7lzQeIiJcUPHwis19ISNgVQqcS9pQhBTKF
hAg4XHSIPi+83VOJbgsZTIzHfmQn8fKRKPUf3iUzDQS0ivfculhDaahPRCd/Apnb
H157oEW3Is1fOxZEYIMwu21qWQLOJg0ScLb2Y+sanFiEbjgbkZl7J2bbZGCoQTkx
P/FHFJWXDXwguUcPP6ygNUCI+YeTwmy1Ff/0uj9hsPj+NH1BXObWZKt4x5NXib2N
IChDQXFvh6tFktVoLuoxyRv2sv2XZV6DrrmgdzxYC/PfGm5LAqlHbibdOpL8ZBNL
KgJKprltrcxivdRT/kHoGgYu1dM0uNeUvmrCcCeWDeqVdC5AuZtfiWSjsCCJ6dMD
oGIB1RR/0ouV2ABtCs3TL9spfJ1QXZPH+hU5Qq3/IFikCACkpmjQlGM0o0DUYHzT
pmSIkByTYdp5ob5YSwUPR0u6IaxAFIFR18DGXADqPt5o4Hdwov2sgX26GqDHdIRm
pYfd8+bFySNaR2AFxU6i
=cD7h
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

Ulf:

Ritesh has collected logs showing that his Realtek RTS5129 USB card
reader (drivers/mfd/rtsx_usb.c, drivers/mmc/host/rtsx_usb_sdmmc.c) goes
into runtime autosuspend every 3 seconds and then immediately resumes.  
This sounds like something is failing to call
pm_runtime_mark_last_busy().  He's using a 4.7 kernel.

In addition, the device gets disconnected from the USB bus from time to 
time.  This appears to be a completely separate issue.

For now, I'd like to fix the runtime PM problem.  But I don't know
anything about the mmc core, so perhaps you can help.


On Thu, 25 Aug 2016, Ritesh Raj Sarraf wrote:

> > Do you happen to know which driver is being used: the memstick
> > (rtsx_usb_ms) or mmc (rtsx_usb_sdmmc) driver?  I suppose this may 
> > depend on what type of card you insert in the reader.
> > 
> 
> 
> I think it is the rtsx_usb_sdmmc which is in use. I removed the rtsx_usb_ms
> kernel module and still was able to access the sdcard.
> 
> rrs@learner:~$ lsmod | grep usb_ms
> 2016-08-25 / 18:45:52 ♒♒♒  ☹  => 1  
> 
> rrs@learner:~$ lsmod | grep usb_sd
> rtsx_usb_sdmmc 24576  0
> rtsx_usb   24576  1 rtsx_usb_sdmmc
> mmc_core  135168  4 mmc_block,sdhci,sdhci_acpi,rtsx_usb_sdmmc
> 2016-08-25 / 18:45:55 ♒♒♒  ☺  
> 
> 
> The interesting bit is that when I enter the adapter into the reader, I get 
> the
> following error 5 times, and then it can access the card.
> 
> [  496.822613] mmc0: tuning execution failed: -22
> [  496.822629] mmc0: error -22 whilst initialising SD card
> [  501.980908] mmc0: tuning execution failed: -22
> [  501.980922] mmc0: error -22 whilst initialising SD card
> [  507.119953] mmc0: tuning execution failed: -22
> [  507.119968] mmc0: error -22 whilst initialising SD card
> [  513.148143] mmc0: tuning execution failed: -22
> [  513.148157] mmc0: error -22 whilst initialising SD card
> [  518.702215] mmc0: tuning execution failed: -22
> [  518.70] mmc0: error -22 whilst initialising SD card
> [  524.081122] mmc0: new ultra high speed SDR50 SDHC card at address 0002
> [  524.082596] mmcblk0: mmc0:0002 NCard 14.9 GiB 
> [  524.084240]  mmcblk0: p1
> [  524.306434] FAT-fs (mmcblk0p1): utf8 is not a recommended IO charset for 
> FAT
> filesystems, filesystem will be case sensitive!

I can't tell why those errors occur.  It would require more debugging.  
At least they don't seem to cause any serious problems.

> With your patch applied, the initial errors messages (xhci_hcd :00:14.0: 
> dev
> 4 ep1out scatterlist error -104/-110) are not seen so far.

This is because those errors occur when the device goes into runtime
autosuspend and the computer tries to communicate with it while it is
suspended.  Both things (the autosuspend and the communication attempt)  
are bugs in the drivers.

> The device does reset (as you had mentioned), but it doesn't seem to have any
> power drain related negative effects.
> 
> 
> rrs@learner:~$ less /var/tmp/dmesg-post-patch.txt  | tail -n 25
> [11922.283067] wlan0: RX AssocResp from 00:40:77:bb:55:12 (capab=0x411 
> status=0
> aid=1)
> [11922.283743] wlan0: associated
> [11922.283801] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
> [11922.883849] systemd[1]: apt-daily.timer: Adding 8h 36min 18.323966s random
> time.
> [11923.081426] systemd[1]: apt-daily.timer: Adding 2h 23min 22.221062s random
> time.
> [13799.616838] atkbd serio0: Unknown key pressed (translated set 2, code 0xbe 
> on
> isa0060/serio0).
> [13799.616843] atkbd serio0: Use 'setkeycodes e03e ' to make it 
> known.
> [13799.625901] atkbd serio0: Unknown key released (translated set 2, code 0xbe
> on isa0060/serio0).
> [13799.625905] atkbd serio0: Use 'setkeycodes e03e ' to make it 
> known.
> [13800.547966] usb 1-4: USB disconnect, device number 15

Spontaneous disconnect followed by reconnect a little later...

> [13801.707137] usb 1-4: new high-speed USB device number 16 using xhci_hcd
> [13801.880788] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
> [13801.880791] usb 1-4: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=3
> [13801.880792] usb 1-4: Product: USB2.0-CRW
> [13801.880793] usb 1-4: Manufacturer: Generic
> [13801.880794] usb 1-4: SerialNumber: 2010020139600
> [13802.809031] usb 1-4: USB disconnect, device number 16
> [13803.390459] usb 1-4: new high-speed USB device number 18 using xhci_hcd
> [13808.807084] usb 1-4: new high-speed USB device number 19 using xhci_hcd
> [13808.980827] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
> [13808.980831] usb 1-4: New USB device strings: Mfr=1, Product=2, 
> SerialNumber=3
> [13808.980833] usb 1-4: Product: USB2.0-CRW
> [13808.980834] usb 1-4: Manufacturer: Generic
> [13808.980835] usb 1-4: SerialNumber: 2010020139600
> [14367.255033] usb 1-7: reset full-speed USB device number 5 using xhci_hcd
> 2016-08-25 / 18:53:16 ♒♒♒  ☺  
> 
> Note: These resets are seen without any card/adapter in the reader.

The computer probably still wants 

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Alan,


On Wed, 2016-08-24 at 10:10 -0400, Alan Stern wrote:
> On Wed, 24 Aug 2016, Ritesh Raj Sarraf wrote:
> 
> > -BEGIN PGP SIGNED MESSAGE-
> > Hash: SHA512
> > 
> > On Tue, 2016-08-23 at 15:14 -0400, Alan Stern wrote:
> > > Okay, good.  The "Driver=rtsx_usb" is what I wanted to see.  Something
> > > funny is going on with that driver -- it claims to support autosuspend 
> > > but it doesn't ever call usb_mark_last_busy() or 
> > > usb_autopm_get_interface().
> > > 
> > > In the meantime, can you post the output from "lsmod"?
> > > 
> > > Also, I'd like to see the output from the following (do this before 
> > > the device disappears):
> > > 
> > > cd /sys/bus/pci/devices/:00:14.0/usb?/usb?-4/
> > > ls -lR
> > > 
> > 
> > Please find the asked output at the following links:
> > 
> > https://people.debian.org/~rrs/tmp/usb-ls-lR.txt
> > https://people.debian.org/~rrs/tmp/lsmod-usb.txt
> 
> Do you happen to know which driver is being used: the memstick
> (rtsx_usb_ms) or mmc (rtsx_usb_sdmmc) driver?  I suppose this may 
> depend on what type of card you insert in the reader.
> 


I think it is the rtsx_usb_sdmmc which is in use. I removed the rtsx_usb_ms
kernel module and still was able to access the sdcard.

rrs@learner:~$ lsmod | grep usb_ms
2016-08-25 / 18:45:52 ♒♒♒  ☹  => 1  

rrs@learner:~$ lsmod | grep usb_sd
rtsx_usb_sdmmc 24576  0
rtsx_usb   24576  1 rtsx_usb_sdmmc
mmc_core  135168  4 mmc_block,sdhci,sdhci_acpi,rtsx_usb_sdmmc
2016-08-25 / 18:45:55 ♒♒♒  ☺  


The interesting bit is that when I enter the adapter into the reader, I get the
following error 5 times, and then it can access the card.

[  496.822613] mmc0: tuning execution failed: -22
[  496.822629] mmc0: error -22 whilst initialising SD card
[  501.980908] mmc0: tuning execution failed: -22
[  501.980922] mmc0: error -22 whilst initialising SD card
[  507.119953] mmc0: tuning execution failed: -22
[  507.119968] mmc0: error -22 whilst initialising SD card
[  513.148143] mmc0: tuning execution failed: -22
[  513.148157] mmc0: error -22 whilst initialising SD card
[  518.702215] mmc0: tuning execution failed: -22
[  518.70] mmc0: error -22 whilst initialising SD card
[  524.081122] mmc0: new ultra high speed SDR50 SDHC card at address 0002
[  524.082596] mmcblk0: mmc0:0002 NCard 14.9 GiB 
[  524.084240]  mmcblk0: p1
[  524.306434] FAT-fs (mmcblk0p1): utf8 is not a recommended IO charset for FAT
filesystems, filesystem will be case sensitive!
[  584.89] mmc0: card 0002 removed
[  623.662587] mmc0: tuning execution failed: -22
[  623.662603] mmc0: error -22 whilst initialising SD card
[  629.373424] mmc0: tuning execution failed: -22
[  629.373439] mmc0: error -22 whilst initialising SD card
[  634.544907] mmc0: tuning execution failed: -22
[  634.544914] mmc0: error -22 whilst initialising SD card
[  641.375119] mmc0: tuning execution failed: -22
[  641.375134] mmc0: error -22 whilst initialising SD card
[  646.725767] mmc0: tuning execution failed: -22
[  646.725782] mmc0: error -22 whilst initialising SD card
[  651.305528] mmc0: new ultra high speed SDR50 SDHC card at address 0002
[  651.306491] mmcblk0: mmc0:0002 NCard 14.9 GiB 
[  651.307906]  mmcblk0: p1
[  651.536923] FAT-fs (mmcblk0p1): utf8 is not a recommended IO charset for FAT
filesystems, filesystem will be case sensitive!
2016-08-25 / 18:45:04 ♒♒♒  ☺  

> > I have a question though. For power saving, I use Laptop Mode Tools. Based
> on
> > power state (AC or BATT), it enables/disables power saving knobs.
> > 
> > https://github.com/rickysarraf/laptop-mode-tools
> > 
> > Since I suspected the same problem (incapable of LPM) I have had this device
> > blacklisted in Laptop Mode Tools. Here are the attributes for this
> particular
> > device, while on battery.
> > 
> > rrs@learner:/sys/bus/usb/devices/1-4$ cat power/autosuspend
> > 0
> > 2016-08-24 / 14:47:07 ♒♒♒  ☺  
> > rrs@learner:/sys/bus/usb/devices/1-4$ cat power/control 
> > on
> > 2016-08-24 / 14:47:34 ♒♒♒  ☺  
> > rrs@learner:/sys/bus/usb/devices/1-4$ cat power/level 
> > on
> > 2016-08-24 / 14:47:38 ♒♒♒  ☺  
> > 
> > 
> > While I write this, the bug hasn't triggered again. I think what may have
> > happened is this:
> > 
> > * OS Boots
> > * Goes on battery
> > * LMT sets OS to power saving mode, but blacklists device 1-4
> > * Eventually, the device resets (device/driver bug?)
> > * Upon reset, driver re-initializes the power saving values to default (?).
> >   At this time LMT will not re-apply any settings, because it only gets
> invoked
> > when a power_supply state change is sensed, i.e. ON_BATT or ON_AC.
> 
> That sounds like a bug in LMT.  It ought to handle hotplug events.  You 
> could report that to the authors.
> 

LMT does handle the events. But given that this device was troubling a lot, I
had the device blacklisted for any power savings.


With your patch applied, the initial errors 

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Wed, 24 Aug 2016, Ritesh Raj Sarraf wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA512
> 
> On Tue, 2016-08-23 at 15:14 -0400, Alan Stern wrote:
> > Okay, good.  The "Driver=rtsx_usb" is what I wanted to see.  Something
> > funny is going on with that driver -- it claims to support autosuspend 
> > but it doesn't ever call usb_mark_last_busy() or 
> > usb_autopm_get_interface().
> > 
> > In the meantime, can you post the output from "lsmod"?
> > 
> > Also, I'd like to see the output from the following (do this before 
> > the device disappears):
> > 
> > cd /sys/bus/pci/devices/:00:14.0/usb?/usb?-4/
> > ls -lR
> > 
> 
> Please find the asked output at the following links:
> 
> https://people.debian.org/~rrs/tmp/usb-ls-lR.txt
> https://people.debian.org/~rrs/tmp/lsmod-usb.txt

Do you happen to know which driver is being used: the memstick
(rtsx_usb_ms) or mmc (rtsx_usb_sdmmc) driver?  I suppose this may 
depend on what type of card you insert in the reader.

> I have a question though. For power saving, I use Laptop Mode Tools. Based on
> power state (AC or BATT), it enables/disables power saving knobs.
> 
> https://github.com/rickysarraf/laptop-mode-tools
> 
> Since I suspected the same problem (incapable of LPM) I have had this device
> blacklisted in Laptop Mode Tools. Here are the attributes for this particular
> device, while on battery.
> 
> rrs@learner:/sys/bus/usb/devices/1-4$ cat power/autosuspend
> 0
> 2016-08-24 / 14:47:07 ♒♒♒  ☺  
> rrs@learner:/sys/bus/usb/devices/1-4$ cat power/control 
> on
> 2016-08-24 / 14:47:34 ♒♒♒  ☺  
> rrs@learner:/sys/bus/usb/devices/1-4$ cat power/level 
> on
> 2016-08-24 / 14:47:38 ♒♒♒  ☺  
> 
> 
> While I write this, the bug hasn't triggered again. I think what may have
> happened is this:
> 
> * OS Boots
> * Goes on battery
> * LMT sets OS to power saving mode, but blacklists device 1-4
> * Eventually, the device resets (device/driver bug?)
> * Upon reset, driver re-initializes the power saving values to default (?).
>   At this time LMT will not re-apply any settings, because it only gets 
> invoked
> when a power_supply state change is sensed, i.e. ON_BATT or ON_AC.

That sounds like a bug in LMT.  It ought to handle hotplug events.  You 
could report that to the authors.

As you mentioned above, there's another aspect to power management 
besides runtime PM, namely Link Power Management.  Perhaps the device 
can't handle LPM.

You can test this by editing the usb_device_supports_lpm() routine in 
drivers/usb/core/hub.c.  If you make it always return 0 immediately, 
that will disable LPM for all USB devices.  If the spontaneous 
disconnects don't reappear, we'll have the answer.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Alan,

Please find some findings below.

On Wed, 2016-08-24 at 15:01 +0530, Ritesh Raj Sarraf wrote:
> I have a question though. For power saving, I use Laptop Mode Tools. Based on
> power state (AC or BATT), it enables/disables power saving knobs.
> 
> https://github.com/rickysarraf/laptop-mode-tools
> 
> Since I suspected the same problem (incapable of LPM) I have had this device
> blacklisted in Laptop Mode Tools. Here are the attributes for this particular
> device, while on battery.
> 
> rrs@learner:/sys/bus/usb/devices/1-4$ cat power/autosuspend
> 0
> 2016-08-24 / 14:47:07 ♒♒♒  ☺  
> rrs@learner:/sys/bus/usb/devices/1-4$ cat power/control 
> on
> 2016-08-24 / 14:47:34 ♒♒♒  ☺  
> rrs@learner:/sys/bus/usb/devices/1-4$ cat power/level 
> on
> 2016-08-24 / 14:47:38 ♒♒♒  ☺  
> 
> 
> While I write this, the bug hasn't triggered again. I think what may have
> happened is this:
> 
> * OS Boots
> * Goes on battery
> * LMT sets OS to power saving mode, but blacklists device 1-4
> * Eventually, the device resets (device/driver bug?)
> * Upon reset, driver re-initializes the power saving values to default (?).
>   At this time LMT will not re-apply any settings, because it only gets
> invoked
> when a power_supply state change is sensed, i.e. ON_BATT or ON_AC.

As I had suspected, that is exactly what happened.


rrs@learner:/sys/bus/usb/devices/1-4$ cat power/autosuspend
2
2016-08-24 / 15:44:08 ♒♒♒  ☺  

rrs@learner:/sys/bus/usb/devices/1-4$ cat power/control 
auto
2016-08-24 / 15:44:17 ♒♒♒  ☺  

rrs@learner:/sys/bus/usb/devices/1-4$ cat power/level 
auto
2016-08-24 / 15:44:25 ♒♒♒  ☺  


I picked these values after I noticed the device reset.

rrs@learner:/sys/bus/usb/devices/1-4$ dmesg | tail -n 20
[ 1730.712177] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 1731.434646] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 1731.523118] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 1733.983893] wlan0: authenticate with c4:6e:1f:d0:67:26
[ 1734.006873] wlan0: send auth to c4:6e:1f:d0:67:26 (try 1/3)
[ 1734.011307] wlan0: authenticated
[ 1734.012745] wlan0: associate with c4:6e:1f:d0:67:26 (try 1/3)
[ 1734.017849] wlan0: RX AssocResp from c4:6e:1f:d0:67:26 (capab=0x411 status=0
aid=4)
[ 1734.018228] wlan0: associated
[ 1734.018237] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1734.316964] systemd[1]: apt-daily.timer: Adding 1h 3min 47.910780s random
time.
[ 1734.455413] systemd[1]: apt-daily.timer: Adding 2h 14min 54.292999s random
time.
[ 3183.459386] WARNING! power/level is deprecated; use power/control instead
[ 6516.374635] usb 1-4: USB disconnect, device number 2
[ 6516.832012] usb 1-4: new high-speed USB device number 7 using xhci_hcd
[ 6517.005736] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
[ 6517.005740] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 6517.005742] usb 1-4: Product: USB2.0-CRW
[ 6517.005743] usb 1-4: Manufacturer: Generic
[ 6517.005745] usb 1-4: SerialNumber: 2010020139600
2016-08-24 / 15:46:57 ♒♒♒  ☺  


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXvXRwAAoJEKY6WKPy4XVpmqQQAKMsDyX1iWLueQtiQOfId7l8
L3ah4BzTz027714URMzaM3WD0AfrjQy81AjMDp6cO9HEhqbTRwNhSk/uY4dyr0hz
uwmpm1hnMCtLEk6knvB5zsBN1JLd7vKGl1fGs+WG9+JyeNP/sWD7zumqTDhL8OD7
47ueP2xsV+j2PIB1cLCFPvTFdcLaAwK1oPh8+7lN/EBWkSr9deFS06gV09GAFQqB
5olbKSQDb8zo6n25VAHLxUAOIjJ5frEjT/GJMF6RfVuL4gCcc9mfYc7ZgVueDnVw
hHrNQK7dPRdH0kCZw/kTOpePafgbgYqX43F7j8T1REHVmC20fYhnYYpBAOqR+XZ9
Ynb9A4CDA3+wcHarL/th/BQXNsVlQeYm4NXn8yLCtf6jUTEjJgUSqIyw7yto4owv
3zOX3kCx2+LCdg7WwJu4aCJEjwozOI+3n9A2F1A4P6c578JV1pAsZybl1HB4ivZ9
+Wz2mW2yjPkh3/D8w0zdTFa/0nOlg2W0klPsHJJzNcyKUGP0ka4ygym0FH8N+IzQ
PVfLlsIOHVPabLkW/1WZvJTVyWwX29FoQ7Pq0ffeQc9aXp08+tyY8q7HbjmUKZYy
wArb0/eajDIb1D0nwcVtVNKCgNTqB2+xlvk5SqtvT1N/t1yQUdiJktMDLh4mIigc
4DV1MXqR9pxzzLXl8/VD
=rkLp
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Tue, 2016-08-23 at 15:14 -0400, Alan Stern wrote:
> Okay, good.  The "Driver=rtsx_usb" is what I wanted to see.  Something
> funny is going on with that driver -- it claims to support autosuspend 
> but it doesn't ever call usb_mark_last_busy() or 
> usb_autopm_get_interface().
> 
> In the meantime, can you post the output from "lsmod"?
> 
> Also, I'd like to see the output from the following (do this before 
> the device disappears):
> 
> cd /sys/bus/pci/devices/:00:14.0/usb?/usb?-4/
> ls -lR
> 

Please find the asked output at the following links:

https://people.debian.org/~rrs/tmp/usb-ls-lR.txt
https://people.debian.org/~rrs/tmp/lsmod-usb.txt


> Finally, you can try applying this patch.  It should prevent the 
> constant runtime suspend & resume cycling, but it is not the proper 
> solution to your problem.  And it may not prevent the occasional 
> spontaneous disconnect.
> 

I am building the kernel right now. I'll post back results after trying out the
new kernel. 

I have a question though. For power saving, I use Laptop Mode Tools. Based on
power state (AC or BATT), it enables/disables power saving knobs.

https://github.com/rickysarraf/laptop-mode-tools

Since I suspected the same problem (incapable of LPM) I have had this device
blacklisted in Laptop Mode Tools. Here are the attributes for this particular
device, while on battery.

rrs@learner:/sys/bus/usb/devices/1-4$ cat power/autosuspend
0
2016-08-24 / 14:47:07 ♒♒♒  ☺  
rrs@learner:/sys/bus/usb/devices/1-4$ cat power/control 
on
2016-08-24 / 14:47:34 ♒♒♒  ☺  
rrs@learner:/sys/bus/usb/devices/1-4$ cat power/level 
on
2016-08-24 / 14:47:38 ♒♒♒  ☺  


While I write this, the bug hasn't triggered again. I think what may have
happened is this:

* OS Boots
* Goes on battery
* LMT sets OS to power saving mode, but blacklists device 1-4
* Eventually, the device resets (device/driver bug?)
* Upon reset, driver re-initializes the power saving values to default (?).
  At this time LMT will not re-apply any settings, because it only gets invoked
when a power_supply state change is sensed, i.e. ON_BATT or ON_AC.


I think your patch will clarify this once I've booted into it.

Thank you very much.

Ritesh

> Alan Stern
> 
> 
> 
> Index: usb-4.x/drivers/mfd/rtsx_usb.c
> ===
> --- usb-4.x.orig/drivers/mfd/rtsx_usb.c
> +++ usb-4.x/drivers/mfd/rtsx_usb.c
> @@ -780,7 +780,6 @@ static struct usb_driver rtsx_usb_driver
> .pre_reset  = rtsx_usb_pre_reset,
> .post_reset = rtsx_usb_post_reset,
> .id_table   = rtsx_usb_usb_ids,
> -   .supports_autosuspend   = 1,
> .soft_unbind= 1,
>  };
>  
- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXvWmNAAoJEKY6WKPy4XVpQacP/Rcdtp010vEsOMibrn0RJbJM
J7uJ/dIUgYSJXTW138BcsRmkZ+D4+OVjaPYeIDNLd9+X1gw4GDozERoVPj9BzwJ5
rCNgIY8VhtrXOScrbqzJ3rJwngqCH5rYqZgAHhSxzZJGocWlHuMvhV893toRxMd0
A97PNZAWQv9GAyquIyQDqoKm1Tu6XdB2sP+jUtbh5l6GBA/G15InxqPtj/bYHq0a
PQ8me9WFxDvFnF6wF/pCDCJbCYkv+Z4HOYvj0sD3+/HaAL1RolZG4UbO0DYEYY4j
g9eqbtcTvs0OaFD/sUZj3rT6m488byenstnDqLHtkB+8hjYdTs/Cbt7HB5/AMjd+
Fo8i/4Tru1DpkNas6iQa9RsfH/0y0c4se98RCoPmuhxyYefdFHpRspgqw61lpdmo
hnac2fa1PfvT96Pywr6gv4haFBZc3vZQS1Xs8RceXB7ZBVeaLNEWNcL1IuqHP6yn
7F2J7bUYVOinmbVzEnc1VnbaMsQlXy7cWvVrAYRgf8hkQBgs6VkBjG4YEVo82jeR
T4qk34SFpqpSWO/3OAlu2GEY+JTHQ8VrUqS5lK+0ZbI4oA1IENnTI4HPE291yNyF
f5JCZ+Nip7WlXEK1tQ8WqyVrEGhxAcPaGKvr70mgten5MATo6fCSVpevn7aemA8k
OumrBZa1Wj8r7EG5xTuv
=CkGL
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Tue, 23 Aug 2016, Ritesh Raj Sarraf wrote:

> This one is after a fresh boot.
> 
> T:  Bus=02 Lev=01 Prnt=01 Port=03 Cnt=01 Dev#=  9 Spd=480  MxCh= 0
> D:  Ver= 2.00 Cls=ff(vend.) Sub=ff Prot=ff MxPS=64 #Cfgs=  1
> P:  Vendor=0bda ProdID=0129 Rev=39.60
> S:  Manufacturer=Generic
> S:  Product=USB2.0-CRW
> S:  SerialNumber=2010020139600
> C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=500mA
> I:* If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=06 Prot=50 Driver=rtsx_usb
> E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
> E:  Ad=82(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
> E:  Ad=83(I) Atr=03(Int.) MxPS=   3 Ivl=64ms
> 
> 
> Here it got enumerated as Bus 02.

Okay, good.  The "Driver=rtsx_usb" is what I wanted to see.  Something
funny is going on with that driver -- it claims to support autosuspend 
but it doesn't ever call usb_mark_last_busy() or 
usb_autopm_get_interface().

In the meantime, can you post the output from "lsmod"?

Also, I'd like to see the output from the following (do this before 
the device disappears):

cd /sys/bus/pci/devices/:00:14.0/usb?/usb?-4/
ls -lR

Finally, you can try applying this patch.  It should prevent the 
constant runtime suspend & resume cycling, but it is not the proper 
solution to your problem.  And it may not prevent the occasional 
spontaneous disconnect.

Alan Stern



Index: usb-4.x/drivers/mfd/rtsx_usb.c
===
--- usb-4.x.orig/drivers/mfd/rtsx_usb.c
+++ usb-4.x/drivers/mfd/rtsx_usb.c
@@ -780,7 +780,6 @@ static struct usb_driver rtsx_usb_driver
.pre_reset  = rtsx_usb_pre_reset,
.post_reset = rtsx_usb_post_reset,
.id_table   = rtsx_usb_usb_ids,
-   .supports_autosuspend   = 1,
.soft_unbind= 1,
 };
 

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Tue, 2016-08-23 at 14:21 +0530, Ritesh Raj Sarraf wrote:
> In one of yesterday's email, I have shared the output of
> /sys/kernel/debug/usb/devices before the bug is triggered. The same I've
> pasted
> below.
> 
> T:  Bus=01 Lev=01 Prnt=01 Port=03 Cnt=01 Dev#=  2 Spd=480  MxCh= 0
> D:  Ver= 2.00 Cls=ff(vend.) Sub=ff Prot=ff MxPS=64 #Cfgs=  1
> P:  Vendor=0bda ProdID=0129 Rev=39.60
> S:  Manufacturer=Generic
> S:  Product=USB2.0-CRW
> S:  SerialNumber=2010020139600
> C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=500mA
> I:* If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=06 Prot=50 Driver=rtsx_usb
> E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
> E:  Ad=82(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
> E:  Ad=83(I) Atr=03(Int.) MxPS=   3 Ivl=64ms
> 
> 
> I'll pick the same again when I reboot.

This one is after a fresh boot.

T:  Bus=02 Lev=01 Prnt=01 Port=03 Cnt=01 Dev#=  9 Spd=480  MxCh= 0
D:  Ver= 2.00 Cls=ff(vend.) Sub=ff Prot=ff MxPS=64 #Cfgs=  1
P:  Vendor=0bda ProdID=0129 Rev=39.60
S:  Manufacturer=Generic
S:  Product=USB2.0-CRW
S:  SerialNumber=2010020139600
C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=500mA
I:* If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=06 Prot=50 Driver=rtsx_usb
E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=82(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=83(I) Atr=03(Int.) MxPS=   3 Ivl=64ms


Here it got enumerated as Bus 02.

- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXvC8YAAoJEKY6WKPy4XVpWqsP/2RSUu/gB7ntEtK8K4J0fJJ9
dngnktH8ijM3qSuzOn8Brl28fBp6jOlyEjNcD+hjq1UrZKz02EG3yDp7nWDjHqqG
PTcK/i2lPu73TsRiBpCSF4kiupnCYyUClnyPbVRX/+4sPqzNWBzIk/wzF0ebn9/i
m5NP9OkMWuEK2c/L+Doe99FrFfImoJweqBqzZAgoK0L+UCQ4u2NYdGOzUudUBZGO
/xRwNwWebQ9fPKYLn3armXKVo5NH1bf96+ti6+AQDfPr0O2CcWg8JyiHOqZzUHEg
VNNyNdw1T0E7QxBnNtaoVP2+NvZ8n4eiXpDm/Mu+rwMEg+KtN9W3qKMsgTyjBqJN
92eDp/HiS2rIZOnrmUOhziAIrdV00cAmt6ihjEwirU0hiULllHoBZ468wa3rf7Ju
2xUCtW/KpW1e/Emw5CngOfXUQyDb2jgxAf2u/m7axhN3TOt1RFKumpJKf/EyhB5E
qFZlTfozShQP9Txu+0/lnc2zGS2Rh8E/7i1tj3QuYAZV8xaQJQ96MO6X+YPdnUkr
nbOpFRAjf18E2rTasShA3d7WrMtpZzTY2/OpEUzAM/R5wieLuZ4DY4kgNs5ofWYj
bK0vmlhqKPDjeCv+9YBttOZBkoRkxfk5QehMls/wBTWxCawgroYhilp1koc8oEs/
p8usFkJFKSCBfCo3jCOC
=4CGy
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Thank you Alan for confirming the bug.

On Mon, 2016-08-22 at 15:09 -0400, Alan Stern wrote:
> > https://people.debian.org/~rrs/tmp/usb_1u-usbmon.txt.gz
> > 
> > https://people.debian.org/~rrs/tmp/dmesg-usbmon.txt
> 
> The usbmon trace shows two separate issues, one in software and one in 
> hardware.  The two issues may or may not be related.
> 
> The software bug is in the driver for this device.  Every 3 seconds it 
> does a runtime suspend followed immediately by a resume, for no 
> apparent reason.  Even worse, it tries to communicate with the device 
> during the time that it is suspended!
> 
> The hardware bug is a series of spontaneous disconnections.  Again, 
> there's no obvious reason for this, although it's possible that the 
> device doesn't like going into and out of suspend very often.  (But 
> there are a lot more suspends than disconnects.)  It's also possible 
> that the USB cable isn't making a firm connection.
> 
> The final blow came when the driver tried to communicate with the
> device _as_ it was being suspended.  That seemed to mess up the
> hardware so badly that it was unable to recover, and from that point it
> stopped working entirely.
> 
> The timing may explain why it takes so long for the device to stop 
> working.  That doesn't happen until, by chance, the driver tries to 
> communicate with the device as it is being suspended.
> 
> Try doing this: Reboot.  Then before the problem occurs, mount a 
> debugfs filesystem on /sys/kernel/debug and make a copy of 
> /sys/kernel/debug/usb/devices.  Let's see what it says about the faulty 
> card reader.

Upon resume today morning, surprisingly, I get the lsusb output reporting the
device. Earlier, it used to knockoff the device from the list.

rrs@learner:/var/tmp$ lsusb 
Bus 003 Device 002: ID 8087:8000 Intel Corp. 
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 006: ID 048d:8350 Integrated Technology Express, Inc. 
Bus 001 Device 005: ID 0bda:b728 Realtek Semiconductor Corp. 
Bus 001 Device 004: ID 04f2:b40f Chicony Electronics Co., Ltd 
Bus 001 Device 003: ID 04f3:0303 Elan Microelectronics Corp. 
Bus 001 Device 013: ID 0bda:0129 Realtek Semiconductor Corp. RTS5129 Card Reader
Controller
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
2016-08-23 / 14:08:05 ♒♒♒  ☺  

And dmesg reported it detected and then, like you've analyzed so far,
disconnected.

[ 1904.885366] usb 1-4: USB disconnect, device number 50
[ 1906.123534] usb 1-4: new high-speed USB device number 51 using xhci_hcd
[ 1912.870405] usb 1-4: new high-speed USB device number 57 using xhci_hcd
[ 1920.370643] usb 1-4: new high-speed USB device number 66 using xhci_hcd
[ 1987.822768] usb 1-4: new high-speed USB device number 71 using xhci_hcd
[ 1994.799738] usb 1-4: new high-speed USB device number 78 using xhci_hcd
[ 2002.373323] usb 1-4: new high-speed USB device number 88 using xhci_hcd
[ 2002.547056] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
[ 2002.547059] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 2002.547061] usb 1-4: Product: USB2.0-CRW
[ 2002.547062] usb 1-4: Manufacturer: Generic
[ 2002.547064] usb 1-4: SerialNumber: 2010020139600
[ 2005.804225] usb 1-4: reset high-speed USB device number 88 using xhci_hcd
[ 3052.573655] usb 1-4: USB disconnect, device number 88
[ 3053.854647] usb 1-4: new high-speed USB device number 89 using xhci_hcd
[ 3054.028343] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
[ 3054.028347] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 3054.028349] usb 1-4: Product: USB2.0-CRW
[ 3054.028351] usb 1-4: Manufacturer: Generic
[ 3054.028352] usb 1-4: SerialNumber: 2010020139600
[ 6376.220631] usb 1-4: USB disconnect, device number 89
[ 6377.469613] usb 1-4: new high-speed USB device number 90 using xhci_hcd
[ 6377.643178] usb 1-4: New USB device found, idVendor=0bda, idProduct=0129
[ 6377.643182] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 6377.643184] usb 1-4: Product: USB2.0-CRW
[ 6377.643186] usb 1-4: Manufacturer: Generic
[ 6377.643188] usb 1-4: SerialNumber: 2010020139600
[ 7166.914656] usb 1-4: reset high-speed USB device number 90 using xhci_hcd
[ 7167.074275] usb 1-4: Device not responding to setup address.
[ 7167.277738] usb 1-4: Device not responding to setup address.
[ 7167.480937] usb 1-4: device not accepting address 90, error -71
[ 7167.641011] usb 1-4: reset high-speed USB device number 90 using xhci_hcd


Trying to read the /sys/kernel/debug/usb/devices led to a hung process. The
process is in uninterruptible sleep. I'm seeing this for the very first time for
a USB (Non Storage) device. Perhaps it has to do with the frequent resets.

rrs@learner:/var/tmp$ ps aux | grep "cat devices"
root 18453  0.0  0.0   6004   772 pts/0D+   13:56   0:00 cat devices

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Alan Stern]

On Mon, 22 Aug 2016, Ritesh Raj Sarraf wrote:

> Hello Mathias,
> 
> I finally reproduced the bug. So the linked usbmon log should have it. But 
> its a
> whopping 22 MiB. It seems it takes a couple of hours of the OS running to
> trigger the bug.
> 
> https://people.debian.org/~rrs/tmp/usb_1u-usbmon.txt.gz
> 
> https://people.debian.org/~rrs/tmp/dmesg-usbmon.txt

The usbmon trace shows two separate issues, one in software and one in 
hardware.  The two issues may or may not be related.

The software bug is in the driver for this device.  Every 3 seconds it 
does a runtime suspend followed immediately by a resume, for no 
apparent reason.  Even worse, it tries to communicate with the device 
during the time that it is suspended!

The hardware bug is a series of spontaneous disconnections.  Again, 
there's no obvious reason for this, although it's possible that the 
device doesn't like going into and out of suspend very often.  (But 
there are a lot more suspends than disconnects.)  It's also possible 
that the USB cable isn't making a firm connection.

The final blow came when the driver tried to communicate with the
device _as_ it was being suspended.  That seemed to mess up the
hardware so badly that it was unable to recover, and from that point it
stopped working entirely.

The timing may explain why it takes so long for the device to stop 
working.  That doesn't happen until, by chance, the driver tries to 
communicate with the device as it is being suspended.

Try doing this: Reboot.  Then before the problem occurs, mount a 
debugfs filesystem on /sys/kernel/debug and make a copy of 
/sys/kernel/debug/usb/devices.  Let's see what it says about the faulty 
card reader.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Mon, 2016-08-22 at 21:01 +0530, Ritesh Raj Sarraf wrote:
> > 
> > Even after fresh unload/load, the acutal problematic devid "0bda:0129", does
> > not appear. I'll report back again after a fresh reboot.
> > 
> 
> https://people.debian.org/~rrs/tmp/usb_1u-usbmon-only-resets.txt.gz
> 
> This one only has the usbmon output with just the device reset, which I
> understand is okay given the suspend/resume cycle.
> 
> I'm still running it and hope to trigger the full bug soon.

Hello Mathias,

I finally reproduced the bug. So the linked usbmon log should have it. But its a
whopping 22 MiB. It seems it takes a couple of hours of the OS running to
trigger the bug.

https://people.debian.org/~rrs/tmp/usb_1u-usbmon.txt.gz

https://people.debian.org/~rrs/tmp/dmesg-usbmon.txt

- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXuz2iAAoJEKY6WKPy4XVpjR0QAI/JAKO8qPK7kPUsMSHrnE/2
OUKkKJUkfRi5X/3FSGLwcXDfqVEE/OUjmGyFEjRe2PGjQojNb4Qy+Ka7UjDgC6rS
6lgGV0gAIHp7jFU9/67DV2TP5nP4Eg6ybZmr1qsTNk2ggn6InBid8x3yd69EGJuS
actVRksKbzNp9qxXb6x8oOUflr9ruwfIvYdDmg7IPWlIIHmxJBR+yPBWIJZhA0s/
zIhsD/TBkb81n/oAB+wuQjkrh2U/Dl0ox44Amb24rvmNwYTy6x7BQ+sGoR2/tRny
jZ2nYB+DnIrq987rTH5SgTTai84SKfMJGQh3zibU6P46h+awVH2NIeThcz4wPLi6
wqArkMLU4uo2wCzNyZ/EZIeBBDtjkXXK5Wz3YBRAqrs6bLmRC4a2PWwvB509dmSy
/2EflGp/Kpn0OWhhZy1ZNFUWBRRuG+obTVzb+Esop6wqF/2/WfJnKqBHhS7547Wp
iIveCiW5T1UPapbClnvQgMr5aV7F08it+EhFhOCWNZo+wCARrQ0Ca3Xaduy0Jtvs
LcJORrfK8OXgr21xpUefJEyFGPJgiGklhIRL7yZTd9K+fIk93Ye7iIXLYbBamkHN
GzGFQLaCZtWu0Gy47Qtr/251KX3PG/Fa3K5+RRxZjh+aHlAvwEkbAQLdbCv0rrbl
iHgVYVzKjItcBR3QF4eH
=2R0w
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Dropping Alan from To list.

On Mon, 2016-08-22 at 20:09 +0530, Ritesh Raj Sarraf wrote:
> On Mon, 2016-08-22 at 18:11 +0530, Ritesh Raj Sarraf wrote:
> > 
> > 
> > I'll post back again once I have captured the relevant logs.
> > 
> > Thank you for looking into this.
> 
> It got more tricky to pick the logs.
> 
> When the bug is hit, the device vanishes from USB listings.
> 
> rrs@learner:~/.rrs-home/Community/fitbit-googlefit (master)$ sudo lsusb 
> Bus 003 Device 002: ID 8087:8000 Intel Corp. 
> Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
> Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
> Bus 001 Device 009: ID 048d:8350 Integrated Technology Express, Inc. 
> Bus 001 Device 008: ID 0bda:b728 Realtek Semiconductor Corp. 
> Bus 001 Device 007: ID 04f2:b40f Chicony Electronics Co., Ltd 
> Bus 001 Device 006: ID 04f3:0303 Elan Microelectronics Corp. 
> Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
> 2016-08-22 / 20:02:54 ♒♒♒  ☺  
> 
> So I couldn't find it in /sys/kernel/debug/usb/devices either.
> 


On a fresh boot, I get the following output.

rrs@learner:~$ lsusb 
Bus 003 Device 002: ID 8087:8000 Intel Corp. 
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 006: ID 048d:8350 Integrated Technology Express, Inc. 
Bus 001 Device 005: ID 0bda:b728 Realtek Semiconductor Corp. 
Bus 001 Device 004: ID 04f2:b40f Chicony Electronics Co., Ltd 
Bus 001 Device 003: ID 04f3:0303 Elan Microelectronics Corp. 
Bus 001 Device 002: ID 0bda:0129 Realtek Semiconductor Corp. RTS5129 Card Reader
Controller
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
2016-08-22 / 20:20:00 ♒♒♒  ☺  

And /sys/kernel/debug/usb/devices also lists it

T:  Bus=01 Lev=01 Prnt=01 Port=03 Cnt=01 Dev#=  2 Spd=480  MxCh= 0
D:  Ver= 2.00 Cls=ff(vend.) Sub=ff Prot=ff MxPS=64 #Cfgs=  1
P:  Vendor=0bda ProdID=0129 Rev=39.60
S:  Manufacturer=Generic
S:  Product=USB2.0-CRW
S:  SerialNumber=2010020139600
C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=500mA
I:* If#= 0 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=06 Prot=50 Driver=rtsx_usb
E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=82(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=83(I) Atr=03(Int.) MxPS=   3 Ivl=64ms


> 
> 
> 
> Even after fresh unload/load, the acutal problematic devid "0bda:0129", does
> not appear. I'll report back again after a fresh reboot.
> 

https://people.debian.org/~rrs/tmp/usb_1u-usbmon-only-resets.txt.gz

This one only has the usbmon output with just the device reset, which I
understand is okay given the suspend/resume cycle.

I'm still running it and hope to trigger the full bug soon.


- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXuxrgAAoJEKY6WKPy4XVpZWoP/0IVbaMdWKIGriOVfBTxnEfL
V2clm/U1i16g+003Eq5yRtyJL5HmCLzDsHcpN3jGLYf8TTuSvZ/B/8UeUUSjVjQo
jTkGqYkpt5BuMgvBJjQhld+/r5XYpWflF1HBb0o5vwArPGa2twODTEiPASJEn+xO
bqWyBDe0J3Cj4K19Z52OKJet99HXoKGFBwQNoJ1ssZ6Wjb63qZRsa8NAvyPAzsNd
Vx9jMUE64D1PIF6sKrdMxDF4lAAUpTTrlhbGdSJdQoPNLuMKB280FuY4aJrIKhWZ
k6ClDlmmWHq7FxFn9nsu/pTKerJ5OVVK1Va7XRoNXzHjLZWUBJbi1N6iODQccIrQ
BdmNeNQLd9ohcq7xH6uUgZsMkQWPgwfPZl6HhHQ6hrL7J/YAP/LlPxZQJYVpidqp
Yul7Man9NVMrRxbciWf9T0rN0D8Oax/QBRsEW5qGNKjr5X5IIndX9iUIdvSh+iZw
rj94g52j49GFM39VNqDAaJy1bK+jNMgAUi2TWqwahaO9PB4LS03Yv7WBBeCeyEvJ
LrBZKwXSj22BHiv+oAHumo/yt4Z1grPGo3iOeKNwq8MPDRi/01OR9SlxqKWG0Tvd
INADNDJiN6N5V6gG7RGTifoqc2WMWwz50iTazH02dYiK4QSLrgxChOu3NN/CoGWM
4HxgPquyqKjhlygKjMZS
=9RyD
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Mon, 2016-08-22 at 18:11 +0530, Ritesh Raj Sarraf wrote:
> 
> I'll post back again once I have captured the relevant logs.
> 
> Thank you for looking into this.

It got more tricky to pick the logs.

When the bug is hit, the device vanishes from USB listings.

rrs@learner:~/.rrs-home/Community/fitbit-googlefit (master)$ sudo lsusb 
Bus 003 Device 002: ID 8087:8000 Intel Corp. 
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 009: ID 048d:8350 Integrated Technology Express, Inc. 
Bus 001 Device 008: ID 0bda:b728 Realtek Semiconductor Corp. 
Bus 001 Device 007: ID 04f2:b40f Chicony Electronics Co., Ltd 
Bus 001 Device 006: ID 04f3:0303 Elan Microelectronics Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
2016-08-22 / 20:02:54 ♒♒♒  ☺  

So I couldn't find it in /sys/kernel/debug/usb/devices either.


So I removed the xhci-hcd module, and also the xhci-pci module which was using 
xhci-hcd
Then I loaded the xhci-hcd module and dmesg looked clean. But the moment I 
loaded the xhci-pci module,
I ran into the same dmesg logs again.


[ 2683.800573] usb 1-4: new high-speed USB device number 91 using xhci_hcd
[ 2683.960580] usb 1-4: device descriptor read/64, error -71
[ 2684.223934] usb 1-4: device descriptor read/64, error -71
[ 2684.487185] usb 1-4: new high-speed USB device number 92 using xhci_hcd
[ 2684.647203] usb 1-4: device descriptor read/64, error -71
[ 2684.910565] usb 1-4: device descriptor read/64, error -71
[ 2685.173865] usb 1-4: new high-speed USB device number 93 using xhci_hcd
[ 2685.174001] usb 1-4: Device not responding to setup address.
[ 2685.377380] usb 1-4: Device not responding to setup address.
[ 2685.580539] usb 1-4: device not accepting address 93, error -71
[ 2685.740529] usb 1-4: new high-speed USB device number 94 using xhci_hcd
[ 2685.740653] usb 1-4: Device not responding to setup address.
[ 2685.944023] usb 1-4: Device not responding to setup address.
[ 2686.147197] usb 1-4: device not accepting address 94, error -71
[ 2686.147247] usb usb1-port4: unable to enumerate USB device
[ 2694.34] xhci_hcd :00:14.0: remove, state 4
[ 2694.341128] usb usb2: USB disconnect, device number 1
[ 2694.343465] xhci_hcd :00:14.0: USB bus 2 deregistered
[ 2694.343806] xhci_hcd :00:14.0: remove, state 1
[ 2694.343824] usb usb1: USB disconnect, device number 1
[ 2694.393961] usb usb1-port4: couldn't allocate usb_device
[ 2694.394005] usb 1-5: USB disconnect, device number 3
[ 2694.427673] usb 1-6: USB disconnect, device number 4
[ 2694.470996] usb 1-7: USB disconnect, device number 5
[ 2694.472724] usb 1-8: USB disconnect, device number 6
[ 2694.473976] xhci_hcd :00:14.0: USB bus 1 deregistered
[ 2753.757692] xhci_hcd :00:14.0: xHCI Host Controller
[ 2753.75] xhci_hcd :00:14.0: new USB bus registered, assigned bus 
number 1
[ 2753.758899] xhci_hcd :00:14.0: hcc params 0x200077c1 hci version 0x100 
quirks 0x0004b810
[ 2753.758908] xhci_hcd :00:14.0: cache line size of 64 is not supported
[ 2753.759016] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 2753.759017] usb usb1: New USB device strings: Mfr=3, Product=2, 
SerialNumber=1
[ 2753.759019] usb usb1: Product: xHCI Host Controller
[ 2753.759020] usb usb1: Manufacturer: Linux 4.7.2bfqv8r2+ xhci-hcd
[ 2753.759022] usb usb1: SerialNumber: :00:14.0
[ 2753.759176] hub 1-0:1.0: USB hub found
[ 2753.759195] hub 1-0:1.0: 9 ports detected
[ 2753.776246] xhci_hcd :00:14.0: xHCI Host Controller
[ 2753.776342] xhci_hcd :00:14.0: new USB bus registered, assigned bus 
number 2
[ 2753.776403] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
[ 2753.776406] usb usb2: New USB device strings: Mfr=3, Product=2, 
SerialNumber=1
[ 2753.776409] usb usb2: Product: xHCI Host Controller
[ 2753.776411] usb usb2: Manufacturer: Linux 4.7.2bfqv8r2+ xhci-hcd
[ 2753.776413] usb usb2: SerialNumber: :00:14.0
[ 2753.776631] hub 2-0:1.0: USB hub found
[ 2753.776650] hub 2-0:1.0: 4 ports detected
[ 2754.119629] usb 1-4: new high-speed USB device number 2 using xhci_hcd
[ 2754.279636] usb 1-4: device descriptor read/64, error -71
[ 2754.542997] usb 1-4: device descriptor read/64, error -71
[ 2754.806280] usb 1-4: new high-speed USB device number 3 using xhci_hcd
[ 2754.966418] usb 1-4: device descriptor read/64, error -71
[ 2755.229714] usb 1-4: device descriptor read/64, error -71
[ 2755.492943] usb 1-4: new high-speed USB device number 4 using xhci_hcd
[ 2755.493065] usb 1-4: Device not responding to setup address.
[ 2755.696537] usb 1-4: Device not responding to setup address.
[ 2755.899766] usb 1-4: device not accepting address 4, error -71
2016-08-22 / 20:00:44 ♒♒♒  ☺  


Even after fresh unload/load, the acutal problematic devid "0bda:0129", does 
not appear. I'll report back again after a fresh reboot.

- -- 
Ritesh Raj Sarraf

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Mon, 2016-08-22 at 11:24 +0300, Mathias Nyman wrote:
> * A few disconnects, were these real disconnects done by you?:

No. Nothing was even plugged into the USB ports. And the resets keep recurring.

>   Aug 18 23:55:57 learner kernel: usb 1-4: USB disconnect, device number 27
>   Aug 18 23:55:58 learner kernel: usb 1-4: new high-speed USB device number 28
> using xhci_hcd
>   ..
>   Aug 18 23:56:18 learner kernel: usb 1-4: USB disconnect, device number 28
>   Aug 18 23:56:20 learner kernel: usb 1-4: new high-speed USB device number 32
> using xhci_hcd
>   ..
>   Aug 18 23:56:21 learner kernel: usb 1-4: USB disconnect, device number 32
>   Aug 18 23:56:21 learner kernel: usb 1-4: new high-speed USB device number 34
> using xhci_hcd
> 
> * A bit unclean resume for some of the devices:
> 

The only thing I have enabled is Runtime PM. When this device started reporting
problems (happens occasionally), I even blacklisted the particular device USB ID
to not enable power savings. But that hasn't helped much.

>   Aug 19 14:22:32 learner kernel: xhci_hcd :00:14.0: port 7 resume PLC
> timeout
>   Aug 19 14:22:32 learner kernel: xhci_hcd :00:14.0: port 4 resume PLC
> timeout
>   Aug 19 14:22:32 learner kernel: xhci_hcd :00:14.0: port 3 resume PLC
> timeout
>   Aug 19 14:22:32 learner kernel: rtc_cmos 00:01: System wakeup disabled by
> ACPI
> 
> * Problems in reading device descriptors and addressing the device:
> 
> Aug 19 14:22:37 learner kernel: usb 1-4: device descriptor read/64, error -71
> Aug 19 14:22:37 learner kernel: usb 1-4: device descriptor read/64, error -71
> Aug 19 14:22:37 learner kernel: usb 1-4: new high-speed USB device number 48
> using xhci_hcd
> Aug 19 14:22:37 learner kernel: usb 1-4: device descriptor read/64, error -71
> Aug 19 14:22:38 learner kernel: usb 1-4: device descriptor read/64, error -71
> Aug 19 14:22:38 learner kernel: usb 1-4: new high-speed USB device number 49
> using xhci_hcd
> Aug 19 14:22:38 learner kernel: usb 1-4: Device not responding to setup
> address.
> Aug 19 14:22:38 learner kernel: usb 1-4: Device not responding to setup
> address.
> Aug 19 14:22:38 learner kernel: usb 1-4: device not accepting address 49,
> error -71
> Aug 19 14:22:38 learner kernel: usb 1-4: new high-speed USB device number 50
> using xhci_hcd
> Aug 19 14:22:38 learner kernel: usb 1-4: Device not responding to setup
> address.
> Aug 19 14:22:39 learner kernel: usb 1-4: Device not responding to setup
> address.
> Aug 19 14:22:39 learner kernel: usb 1-4: device not accepting address 50,
> error -71
> Aug 19 14:22:39 learner kernel: usb usb1-port4: unable to enumerate USB device
> 
> * And at the end we it looks like we get stuck at a halted endpoint. Every URB
> to that endpoint
>    is canceled. Either we fail at noticing and clearing the halt, or then the
> endpoint halts again
>    at every transfer.
> 
> Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: Cancel URB
> 88020bb4b000, dev 4, ep 0x1, starting at offset 0x9a2b2830
> Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: // Ding dong!
> Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: Removing canceled TD
> starting at 0x9a2b2830 (dma).
> Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: TRB to noop at offset
> 0x9a2b2830
> Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: WARN halted endpoint,
> queueing URB anyway.
> Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: ep 0x81 - asked for 37
> bytes, 27 bytes untransferred
> Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: Cancel URB
> 880182e41180, dev 4, ep 0x1, starting at offset 0x9a2b2840
> Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: // Ding dong!
> Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: Removing canceled TD
> starting at 0x9a2b2840 (dma).
> 
> A usbmon log (together with a dmesg) could give some more clues
> see Documentation/usb/usbmon.txt
> 

I'll post back again once I have captured the relevant logs.

Thank you for looking into this.

Ritesh
- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXuvLmAAoJEKY6WKPy4XVp6GMP/1ZdsyKUtckHSfwKhQ1Z1H9P
rXZ7c/OkcKqI7ZO6TXCqpaFuHyZQ3P7QkXpGz3vjhngTpuzbc/IMbrRYjacXp4dJ
RZS8DWfGcF9PDV/w6aiM1wnT/yPCOkMGm7Q3XU1rKbwm0oSjpqRRXGcw+n9qiCwy
ItTvoqEz2RWgOPNXEtNGPHgdaUZQlnM7fTiwP+DCYrNUNbnVeRpSo4KKK/J4dp9f
7rWqMkZZt14v3XItB+W/DKpUfWs7ex9Cufxe0ChkjxjLdqwggkYM8vpkoxbel1gA
kc1IfOHAgDy27dcZ5pMVmrXrjSPgYMroYZ7lGDeG1TAfMzJOeBTpxyp7lLiGx70k
WRZqwvTUZfed6/lX/B2OoSBNnHSSDZhEkUiW/8vkCIvDw5p6ubcAS99TXIV5Id+Z
niIQ1cWOo6cHq9phps5ApV5+EPaV1blSQAQVY6icg+3aM6shH4srPiI6jEFyeK4B
FAAKafA85E31ZYaZ9U3Dm9Gv9ZCf8VzGOqJNDgQsxXUeoXN9sDR0NWj3GukKxPwD
9AMNaQeACCqoUEgURbeb681HMCb9X/nC0mPJjb5mfz2B+kn2HH17HgFRjLgPeMES
QfAPhsRPBQWM0mRvGegUzk0SG4/+aX93Ii4DVXeYJdzjvhmNeQ0+hlUDlf2MyJn/
grz6gg4im5fJ4dnXp8b5
=J8Y/
-END PGP SIGNATURE-

--
To unsubscribe 

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Mathias Nyman]

On 19.08.2016 13:26, Ritesh Raj Sarraf wrote:

Hello Mathia,

On Fri, 2016-08-19 at 11:42 +0300, Mathias Nyman wrote:


It'd help to know if it really is a bug or something else.


Could you add xhci debugging?. The current logs mainly show usb core
reporting errors on urbs returned (or timeout) from xhci.

xhci debugging can be added with
echo -n 'module xhci_hcd =p' > /sys/kernel/debug/dynamic_debug/control
Make sure debugfs is mounted before.



There's a lot of debugging output. I've attached the dmesg output in this email.


There is a scattergather fix in 4.8-rc1, but it has another regression, so
waiting for 4.8-rc3 and retrying with it could make sense.
Not sure if that fix is related, but should be fairly easy to try before
digging too
deep into this





Okay! I'll try out rc3 when it is out. Meanwhile, if there is anything
interesting in the logs, please let me know.



* A few disconnects, were these real disconnects done by you?:
 Aug 18 23:55:57 learner kernel: usb 1-4: USB disconnect, device number 27
 Aug 18 23:55:58 learner kernel: usb 1-4: new high-speed USB device number 28 
using xhci_hcd
 ..
 Aug 18 23:56:18 learner kernel: usb 1-4: USB disconnect, device number 28
 Aug 18 23:56:20 learner kernel: usb 1-4: new high-speed USB device number 32 
using xhci_hcd
 ..
 Aug 18 23:56:21 learner kernel: usb 1-4: USB disconnect, device number 32
 Aug 18 23:56:21 learner kernel: usb 1-4: new high-speed USB device number 34 
using xhci_hcd

* A bit unclean resume for some of the devices:

 Aug 19 14:22:32 learner kernel: xhci_hcd :00:14.0: port 7 resume PLC 
timeout
 Aug 19 14:22:32 learner kernel: xhci_hcd :00:14.0: port 4 resume PLC 
timeout
 Aug 19 14:22:32 learner kernel: xhci_hcd :00:14.0: port 3 resume PLC 
timeout
 Aug 19 14:22:32 learner kernel: rtc_cmos 00:01: System wakeup disabled by ACPI

* Problems in reading device descriptors and addressing the device:

Aug 19 14:22:37 learner kernel: usb 1-4: device descriptor read/64, error -71
Aug 19 14:22:37 learner kernel: usb 1-4: device descriptor read/64, error -71
Aug 19 14:22:37 learner kernel: usb 1-4: new high-speed USB device number 48 
using xhci_hcd
Aug 19 14:22:37 learner kernel: usb 1-4: device descriptor read/64, error -71
Aug 19 14:22:38 learner kernel: usb 1-4: device descriptor read/64, error -71
Aug 19 14:22:38 learner kernel: usb 1-4: new high-speed USB device number 49 
using xhci_hcd
Aug 19 14:22:38 learner kernel: usb 1-4: Device not responding to setup address.
Aug 19 14:22:38 learner kernel: usb 1-4: Device not responding to setup address.
Aug 19 14:22:38 learner kernel: usb 1-4: device not accepting address 49, error 
-71
Aug 19 14:22:38 learner kernel: usb 1-4: new high-speed USB device number 50 
using xhci_hcd
Aug 19 14:22:38 learner kernel: usb 1-4: Device not responding to setup address.
Aug 19 14:22:39 learner kernel: usb 1-4: Device not responding to setup address.
Aug 19 14:22:39 learner kernel: usb 1-4: device not accepting address 50, error 
-71
Aug 19 14:22:39 learner kernel: usb usb1-port4: unable to enumerate USB device

* And at the end we it looks like we get stuck at a halted endpoint. Every URB 
to that endpoint
  is canceled. Either we fail at noticing and clearing the halt, or then the 
endpoint halts again
  at every transfer.

Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: Cancel URB 
88020bb4b000, dev 4, ep 0x1, starting at offset 0x9a2b2830
Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: // Ding dong!
Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: Removing canceled TD 
starting at 0x9a2b2830 (dma).
Aug 19 15:46:11 learner kernel: xhci_hcd :00:14.0: TRB to noop at offset 
0x9a2b2830
Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: WARN halted endpoint, 
queueing URB anyway.
Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: ep 0x81 - asked for 37 
bytes, 27 bytes untransferred
Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: Cancel URB 
880182e41180, dev 4, ep 0x1, starting at offset 0x9a2b2840
Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: // Ding dong!
Aug 19 15:46:12 learner kernel: xhci_hcd :00:14.0: Removing canceled TD 
starting at 0x9a2b2840 (dma).

A usbmon log (together with a dmesg) could give some more clues
see Documentation/usb/usbmon.txt

-Mathias


--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

I am not sure if the logs ever reached the list. I've uploaded the logs here [1]
for convenience.

[1] https://people.debian.org/~rrs/tmp/usb-xhci-dmesg.txt.gz



On Fri, 2016-08-19 at 15:56 +0530, Ritesh Raj Sarraf wrote:
> Hello Mathia,
> 
> On Fri, 2016-08-19 at 11:42 +0300, Mathias Nyman wrote:
> > 
> > > 
> > > 
> > > It'd help to know if it really is a bug or something else.
> > 
> > Could you add xhci debugging?. The current logs mainly show usb core
> > reporting errors on urbs returned (or timeout) from xhci.
> > 
> > xhci debugging can be added with
> > echo -n 'module xhci_hcd =p' > /sys/kernel/debug/dynamic_debug/control
> > Make sure debugfs is mounted before.
> > 
> 
> There's a lot of debugging output. I've attached the dmesg output in this
> email.
> 
> > 
> > There is a scattergather fix in 4.8-rc1, but it has another regression, so
> > waiting for 4.8-rc3 and retrying with it could make sense.
> > Not sure if that fix is related, but should be fairly easy to try before
> > digging too
> > deep into this
> 
> Okay! I'll try out rc3 when it is out. Meanwhile, if there is anything
> interesting in the logs, please let me know.
> 
> 
> PS: The logs are from a 4.7.1 stable kernel.
> 
> 
> Thanks,
> Ritesh
> 
- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXuCa5AAoJEKY6WKPy4XVpG78P/2MBf+empHBc47ULY9zewIqA
t3Us1TN3GA+U1Me0oAyYUh3LRq6tbzCHE9+RlaH6T7BCqbwdEqNcJG6g90GHjG++
A2arXqucA4UdaaGG1NoT4pae+0UiiMjHRwsYJiAmyeHwlRFJ0ZgDrGzarPCbz1tP
O3xtShILcIa00arjQvKlCCzEUGvpxsjK2YehFZ04pJD+SEKctKNYI4iPjOfwqH+9
1ZL/qhydEojs1iSEMXpS61al7m7JkdmfRg8E7jHe6BUxF5rx3L12/jbQ8A11udJq
EtkboOjsJXK5gZ7aHt+gJ11PCWpiIXkFqu1oTUb6QkyRLDLD/oioGVrYqTS/o42F
cug8YpA/a9Za/7IrT1WfhHm0vlfurBpQkqz3HkSuJdJPqwSLN02I5WFrcWEOZbm9
qElDk2s7hd8m/Xz80JSxFSVPCn/k3VzNKOUI4la3RA89OWjAusxQ/hzd+q0R7DqH
AEQxuXQ4QpLinTuuhtaaoOxa0L9czm9HcIO6IB9a9iaaF9RjFo+hXs9jEaNhAbaF
iLwPzArG5oMjt9BxXoJmGFBAaxyuMlKHjUkKwZDI4f7Vvc6QJkhlLq8fWW45Fp9m
9spf5oUUse7tbIPGsuuJ3O19jY1P1HzslecA+eK2lSDC1OiyBx/KGNWSue7Q73Q9
kcDeMBr9T9y27jXuV6NJ
=bVZK
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Mathias Nyman]

On 18.08.2016 17:33, Ritesh Raj Sarraf wrote:

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Hello Mathias,


Hi



Can you please confirm of the erratic behavior we've discussed so far, on this
thread ?

It'd help to know if it really is a bug or something else.


Could you add xhci debugging?. The current logs mainly show usb core
reporting errors on urbs returned (or timeout) from xhci.

xhci debugging can be added with
echo -n 'module xhci_hcd =p' > /sys/kernel/debug/dynamic_debug/control
Make sure debugfs is mounted before.

There is a scattergather fix in 4.8-rc1, but it has another regression, so
waiting for 4.8-rc3 and retrying with it could make sense.
Not sure if that fix is related, but should be fairly easy to try before 
digging too
deep into this

-Mathias
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: xHCI problem? [was Re: Erratic USB device behavior and device loss]

[Ritesh Raj Sarraf]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

On Fri, 2016-08-12 at 11:48 -0400, Alan Stern wrote:
> 
> These could indicate some sort of problem with the driver for the xHCI
> controller.  However, I'm not an expert on xhci-hcd.  Mathias is the
> maintainer for that driver.

Okay! So I'll wait for Mathias' comment on this thread, hoping he can triage it
if a bug or not.

In case more information is required, please let me know on my email.

Thanks,
Ritesh

- -- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."
-BEGIN PGP SIGNATURE-

iQIcBAEBCgAGBQJXrgduAAoJEKY6WKPy4XVpk/kQALkEuk9CG1TESeLJCPIsWfmh
hnk8hfpvBu1JFvQBk/oIAhmo3k2v+r9YvAIgn0JMz0qmQK1dIsXQ+6vT3QzeN/M8
5jhy2v1NWVIaEtQUEzjg60tvSps91xmmxYhq+L2eb2AUpIv5AC1VneP0SUONzWE5
FxSdramLjV2/X1ax9you7GxcEjEhU2T3HTDHmsS+d4+MygDOFi61pqXP1f7iZx6w
20QIp/jsnMwo7mIpkhFxRMWlFaeKG2nWwPiqoxiUDOlYeEoNAHIBaNtZ//VcKnYX
JqBpwhlJM+1MO/2XKfekJG+7Rmhk6vXEejHeK5ZQirdnPDsPFF+IZOPWF0szti9v
PuZrW5za4YWqcjtCKTF6lOuThQ2IXA564hl0aJSO5S4okmeH3KHgs7fc+r4rxd/t
0HKuwpecbWMO8jxw3jOgtUaKNPUUbJFK6R+ZAx4LyUqxJB0lZKVCZLc1IECfUrd/
kqZUp2H6xq1a+LAyhobfvy4BYi5VG+Vk5aqUFWG0WmZhTgs+U2aKtlyzWuOyWTCh
xWtqjTTkr/vc3lXEAOOlLoRBhwD0xhC71TusBEBEdeufYWV8qFpxDqTUGWgYT/aK
6ldbykaftjwFAAGTGYsiPfRqc+dvyW4NF+3vK5DHuk767HfPY2Vl/LVrDoZLX926
TVaml4ICxrUU/hdzgYqk
=nCk9
-END PGP SIGNATURE-

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html