Message-ID: <20250502155308.11a991d4@booty>
Date: Fri, 2 May 2025 15:53:08 +0200
From: Luca Ceresoli <luca.ceresoli@...tlin.com>
To: Alan Stern <stern@...land.harvard.edu>
Cc: Minas Harutyunyan <Minas.Harutyunyan@...opsys.com>,
 "linux-usb@...r.kernel.org" <linux-usb@...r.kernel.org>, Kever Yang
 <kever.yang@...k-chips.com>, Greg Kroah-Hartman
 <gregkh@...uxfoundation.org>, "linux-kernel@...r.kernel.org"
 <linux-kernel@...r.kernel.org>, Hervé Codina
 <herve.codina@...tlin.com>, Thomas Petazzoni
 <thomas.petazzoni@...tlin.com>, Stefan Wahren <wahrenst@....net>, Fabrice
 Gasnier <fabrice.gasnier@...s.st.com>
Subject: Re: DWC2 gadget: unexpected device reenumeration on Rockchip RK3308

Hello Alan,

thanks for your continued support!

On Tue, 15 Apr 2025 12:14:58 -0400
Alan Stern <stern@...land.harvard.edu> wrote:

[...]

> > > > It's quite possible that you're getting messed up by link power
> > > > management (LPM).  But that's just a guess.  
> > 
> > What would be a symptom, if that happened?  
> 
> The debugging log wouldn't show much unless something went wrong.  You 
> could see if there are any files containing "lpm" in their names in the 
> /sys/bus/usb/devices/3-3.4/ directory (while the device is connected) 
> and what they contain.  Also, there's a way to disable LPM on the host 
> by setting a usbcore quirks module parameter:
> 
> 	echo 1209:0001:k >/sys/module/usbcore/parameters/quirks

Tried this. There is no file with 'lpm' in the name in
/sys/bus/usb/devices/3-3.4/, and adding the quirk did not change the
result: still a disconnect and reconnect in ~6 seconds.

> You could also try connecting a usbmon trace for bus 3, showing what 
> happens during the initial connection and ensuing disconnection.  Any 
> LPM transitions would show up in the trace.

Tried this, and here are the few lines before and after the 5~6 seconds
delay.

ffff99621e768840 4009009102 C Bi:1:009:3 0 2 = 696e
ffff99621e768840 4009009104 S Bi:1:009:3 -115 256 <
ffff99621e768300 4009009115 S Bi:1:009:3 -115 256 <
ffff99621e768840 4009009144 C Bi:1:009:3 0 6 = 3a383534 2033
ffff99621e768300 4009009155 C Bi:1:009:3 0 1 = 37
ffff99621e768840 4009009178 C Bi:1:009:3 0 2 = 0d0a
ffff99621e768840 4009009180 S Bi:1:009:3 -115 256 <
ffff996080f11900 4009009361 C Ci:1:014:0 0 26 = 1a034300 44004300 20004100 43004d00 20004400 61007400 6100
ffff99621e768300 4009009615 C Bi:1:009:3 0 3 = 5b2020
ffff99621e768300 4009009624 S Bi:1:009:3 -115 256 <
ffff99621e768840 4009009645 C Bi:1:009:3 0 3 = 203233
ffff99621e768840 4009009646 S Bi:1:009:3 -115 256 <
ffff99621e768300 4009009692 C Bi:1:009:3 0 4 = 2e383738
ffff99621e768300 4009009694 S Bi:1:009:3 -115 256 <
ffff99621e768840 4009009703 C Bi:1:009:3 0 2 = 3731
ffff99621e768840 4009009722 S Bi:1:009:3 -115 256 <
ffff99621e768840 4009009933 C Bi:1:009:3 0 2 = 7472

<<< 6 seconds delay >>>

ffff9960828e9540 4014796128 C Ii:1:001:1 0:2048 2 = 1000
ffff9960828e9540 4014796145 S Ii:1:001:1 -115:2048 4 <
ffff996080f11900 4014796162 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff996080f11900 4014796189 C Ci:1:001:0 0 4 = 00010100
ffff996080f11900 4014796201 S Co:1:001:0 s 23 01 0010 0004 0000 0
ffff996080f11900 4014796219 C Co:1:001:0 0 0
ffff996080f11000 4014799627 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff996080f11000 4014799679 C Ci:1:001:0 0 4 = 00010000
ffff996080f11000 4014826132 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff996080f11000 4014826166 C Ci:1:001:0 0 4 = 00010000
ffff996080f11000 4014852075 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff996080f11000 4014852122 C Ci:1:001:0 0 4 = 00010000
ffff996080f11000 4014878210 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff996080f11000 4014878253 C Ci:1:001:0 0 4 = 00010000
ffff996080f11000 4014904049 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff996080f11000 4014904088 C Ci:1:001:0 0 4 = 00010000
ffff9960828e9540 4014948427 C Ii:1:001:1 0:2048 2 = 1000
ffff9960828e9540 4014948456 S Ii:1:001:1 -115:2048 4 <
ffff99621e768300 4014948461 C Bi:1:009:3 0 2 = 5b20
ffff99621e768300 4014948472 S Bi:1:009:3 -115 256 <
ffff99621e768840 4014948488 C Bi:1:009:3 0 2 = 2020
ffff99621e768840 4014948489 S Bi:1:009:3 -115 256 <
ffff996080f11000 4014948522 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff99621e768300 4014948545 C Bi:1:009:3 0 58 = 32392e38 31373337 325d203e 3e3e2064 7763325f 68616e64 6c655f63 6f6d6d6f
ffff99621e768300 4014948560 S Bi:1:009:3 -115 256 <
ffff996080f11000 4014948607 C Ci:1:001:0 0 4 = 01010100
ffff99621e768840 4014948639 C Bi:1:009:3 0 10 = 37395d20 3e3e3e20 6477
ffff99621e768840 4014948644 S Bi:1:009:3 -115 256 <
ffff99621e768300 4014948657 C Bi:1:009:3 0 3 = 63325f
ffff99621e768300 4014948663 S Bi:1:009:3 -115 256 <
ffff99621e768840 4014948689 C Bi:1:009:3 0 5 = 68736f74 67
ffff99621e768840 4014948693 S Bi:1:009:3 -115 256 <
ffff99621e768300 4014948718 C Bi:1:009:3 0 2 = 5f69
ffff99621e768300 4014948720 S Bi:1:009:3 -115 256 <
ffff99621e768840 4014948759 C Bi:1:009:3 0 4 = 72713a33

Does this give you any hints?

I'm afraid it's going to take time before I'm able to decipher these
hieroglyphs. :-|

Full log is available, if needed.

However I suspect using Wireshark to capture the USB traffic should
produce the same content. If it is the case, I have available a
Wireshark capture as well. The first logged event I see in Wireshark
after the delay is a "URB_INTERRUPT in", which is possibly matching the
"Ii" in the log above.

However IIUC both the usbmon debugfs interface and Wireshark are unable
to capture disconnection events because that's handled by the hardware.
Correct?

I hope useful hints can be found here. Otherwise I guess the only way
out will be comparing the behaviour of the 4.4 Rockchip kernel (which
works correctly) against mainline. I expect this to be a long and
painful process, though.

Best regards,
Luca

-- 
Luca Ceresoli, Bootlin
Embedded Linux and Kernel engineering
https://bootlin.com

Powered by blists - more mailing lists