Page 4 of 4

Re: USB Stack Issue still unsolved...

PostPosted: Fri Feb 08, 2019 11:45 pm
by Lio
On my X-5000 I also get my mouse moving too fast from time to time (maybe 1 out of 5 reset) ! really annoying and a pity.

The only thing I can do is reset or disconnect/reconnect. Since I dont want to go behind the tower each time, I decided to plug a USB hub and connect the mouse to it, easier to disconnect on the desk rather than behind the tower laying on the ground under the desk...

how can you show how nice and shiny is your Amiga to someone when something like that happens ?

The mouse is a logitech laser M500 (in case it would help) and the event log are the following :
I: [22:43:20] hub.usbfd | HUB | Device found on port 4 of hub "".
I: [22:43:20] hub.usbfd | Hub port | Device at port 4 of hub "" is low-speed.
I: [22:43:20] USB stack | New Fkt | Fkt 0x6ec63b70 at level 3
I: [22:43:21] hub.usbfd | HUB | Device on hub port 4 successfully added.
I: [22:43:21] USB Fkt Init | Init Fkt | Fkt 0x6ec63b70 is {Vendor: 0x046D, Product: 0xC069, Class: 00.00}
I: [22:43:21] USB Fkt Init | Init Fkt | Fkt 0x6ec63b70 ("Logitech","USB Laser Mouse","") initialized
I: [22:43:21] hid.usbfd | HID driver | USB Interface bound

Re: USB Stack Issue still unsolved...

PostPosted: Wed May 08, 2019 10:10 am
by TomSoniq
I've got a new KVM switch which features transparent keyboard/mouse emulation. This means all connected hosts see a permanently connected keyboard and mouse behind a USB hub.
This works perfectly fine with one connected Windows10 and one connected Ubuntu 18.04.2 LTS machine.
OS4.1FE Update 1 on the SAM440 is still unreliable. :roll:
In about five out of 10 system startups either the keyboard or the mouse doesn't respond. I can get it to work by pulling the USB and plugging it back in a couple of times. But even then it sometimes looses the keyboard connection after half an hour or so.
So I tried the debian-testing-sam440ep-CD from ACube's web site. Works like a charm! :D Booted 20 times in a row and each time the keyboard worked right from the start.
This doesn't sound like a hardware issue to me. ;)

So the question is: What's to blame? The OS4 low level driver or the rest of the protocol stack? And how can I find out?

Can I become involved in debugging that thing? Maybe compile it myself and try some fixes?

Re: USB Stack Issue still unsolved...

PostPosted: Wed May 08, 2019 7:44 pm
by TomSoniq
Found out the following:
Both the mouse and the keyboard always show up in the USB inspector. But in the case one of them is not working it's because no driver was assigned to it.
"Driver: none"
If I pull the USB plug (the one to the hub/KVM) a couple of times then sooner or later both of them will be assigned hid.usbfd
This sounds like a race condition and or timing issue to me.

EDIT: I grabbed the USB logs now.
If the mouse fails then I get:
Code: Select all
I: [18:40:10]                      hub.usbfd |                            HUB | Device found on port 2 of hub "Rear Roothub (ehci.usbhcd/0)".
I: [18:40:11]                      hub.usbfd |                       Hub port | Device at port 2 of hub "Rear Roothub (ehci.usbhcd/0)" is high-speed.
I: [18:40:11]                      USB stack |                        New Fkt | Fkt 0x5982a340 at level 1
I: [18:40:11]                      hub.usbfd |                            HUB | Device on hub port 2 successfully added.
I: [18:40:11]    EHCI Controller Task Unit 0 |                           EHCI | Port 1 is not in reset state.
I: [18:40:11]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a340 is {Vendor: 0x0451, Product: 0x8142, Class: 09.00}
I: [18:40:11]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a340 initialized
I: [18:40:11]                      hub.usbfd |                            HUB | Now configured to use multiple TTs
I: [18:40:11]                      hub.usbfd |                            HUB | Hub "" has TT thinktime of 8 full speed bittimes and protocol 2
I: [18:40:11]                      hub.usbfd |                            HUB | Device found on port 1 of hub "".
I: [18:40:11]                      hub.usbfd |                       Hub port | Device at port 1 of hub "" is full-speed.
I: [18:40:11]                      USB stack |                        New Fkt | Fkt 0x5982a480 at level 2
I: [18:40:11]                      hub.usbfd |                            HUB | Device on hub port 1 successfully added.
I: [18:40:11]                      hub.usbfd |                            HUB | Driver Running
I: [18:40:11]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a480 is {Vendor: 0x10D5, Product: 0x1234, Class: 09.00}
I: [18:40:11]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a480 initialized
I: [18:40:11]                      hub.usbfd |                            HUB | Hub "" has TT thinktime of 8 full speed bittimes and protocol 0
I: [18:40:12]                      hub.usbfd |                            HUB | Device found on port 1 of hub "".
I: [18:40:12]                      hub.usbfd |                       Hub port | Device at port 1 of hub "" is full-speed.
I: [18:40:12]                      USB stack |                        New Fkt | Fkt 0x5982a5c0 at level 3
I: [18:40:12]                      hub.usbfd |                            HUB | Device on hub port 1 successfully added.
I: [18:40:12]                      hub.usbfd |                            HUB | Device found on port 2 of hub "".
I: [18:40:12]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a5c0 is {Vendor: 0x046D, Product: 0xC016, Class: 00.00}
I: [18:40:12]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a5c0 initialized
W: [18:40:12]               USB FD fkt start |        USBFktGetCfgDescriptors | Error reading config dsc from Fkt 0x5982A5C0
E: [18:40:12]               USB FD fkt start |        USBFktGetCfgDescriptors | Failed to read config from Fkt 0x5982a5c0 - error -33
E: [18:40:12]               USB FD fkt start |                    FD launcher | Failed to read CfgDsc
I: [18:40:12]                      hub.usbfd |                       Hub port | Device at port 2 of hub "" is full-speed.
I: [18:40:12]                      USB stack |                        New Fkt | Fkt 0x5982a660 at level 3
I: [18:40:12]                      hub.usbfd |                            HUB | Device on hub port 2 successfully added.
I: [18:40:12]                      hub.usbfd |                            HUB | Driver Running
I: [18:40:12]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a660 is {Vendor: 0x413C, Product: 0x2110, Class: 00.00}
I: [18:40:12]                   USB Fkt Init |                       Init Fkt | Fkt 0x5982a660 initialized
I: [18:40:12]                      hid.usbfd |                     HID driver | USB Interface bound
I: [18:40:12]                      hid.usbfd |                     HID driver | USB Interface bound


If the keyboard fails then I get:
Code: Select all
I: [18:42:03]                      hub.usbfd |                            HUB | Device found on port 2 of hub "Rear Roothub (ehci.usbhcd/0)".
I: [18:42:04]                      hub.usbfd |                       Hub port | Device at port 2 of hub "Rear Roothub (ehci.usbhcd/0)" is high-speed.
I: [18:42:04]                      USB stack |                        New Fkt | Fkt 0x5FE26330 at level 1
I: [18:42:04]                      hub.usbfd |                            HUB | Device on hub port 2 successfully added.
I: [18:42:04]    EHCI Controller Task Unit 0 |                           EHCI | Port 1 is not in reset state.
I: [18:42:04]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE26330 is {Vendor: 0x0451, Product: 0x8142, Class: 09.00}
I: [18:42:04]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE26330 initialized
I: [18:42:04]                      hub.usbfd |                            HUB | Now configured to use multiple TTs
I: [18:42:04]                      hub.usbfd |                            HUB | Hub "" has TT thinktime of 8 full speed bittimes and protocol 2
I: [18:42:04]                      hub.usbfd |                            HUB | Device found on port 1 of hub "".
I: [18:42:04]                      hub.usbfd |                       Hub port | Device at port 1 of hub "" is full-speed.
I: [18:42:04]                      USB stack |                        New Fkt | Fkt 0x5FE26470 at level 2
I: [18:42:04]                      hub.usbfd |                            HUB | Device on hub port 1 successfully added.
I: [18:42:04]                      hub.usbfd |                            HUB | Driver Running
I: [18:42:04]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE26470 is {Vendor: 0x10D5, Product: 0x1234, Class: 09.00}
I: [18:42:04]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE26470 initialized
I: [18:42:04]                      hub.usbfd |                            HUB | Hub "" has TT thinktime of 8 full speed bittimes and protocol 0
I: [18:42:05]                      hub.usbfd |                            HUB | Device found on port 1 of hub "".
I: [18:42:05]                      hub.usbfd |                       Hub port | Device at port 1 of hub "" is full-speed.
I: [18:42:05]                      USB stack |                        New Fkt | Fkt 0x5FE266F0 at level 3
I: [18:42:05]                      hub.usbfd |                            HUB | Device on hub port 1 successfully added.
I: [18:42:05]                      hub.usbfd |                            HUB | Device found on port 2 of hub "".
I: [18:42:05]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE266F0 is {Vendor: 0x046D, Product: 0xC016, Class: 00.00}
I: [18:42:05]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE266F0 initialized
W: [18:42:05]               USB FD fkt start |            BindInterfaceDriver | No interface driver of fkt 0x5FE266F0/ifc 0x5C5E0350 {Class 03.01} has been found
W: [18:42:05]               USB FD fkt start |                    FD launcher | Could not bind any suitable interface driver for fkt 0x5FE266F0
I: [18:42:05]                      hub.usbfd |                       Hub port | Device at port 2 of hub "" is full-speed.
I: [18:42:05]                      USB stack |                        New Fkt | Fkt 0x5FE26830 at level 3
I: [18:42:05]                      hub.usbfd |                            HUB | Device on hub port 2 successfully added.
I: [18:42:05]                      hub.usbfd |                            HUB | Driver Running
I: [18:42:05]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE26830 is {Vendor: 0x413C, Product: 0x2110, Class: 00.00}
I: [18:42:05]                   USB Fkt Init |                       Init Fkt | Fkt 0x5FE26830 initialized
W: [18:42:05]               USB FD fkt start |        USBFktGetCfgDescriptors | Error reading config dsc from Fkt 0x5FE26830
E: [18:42:05]               USB FD fkt start |        USBFktGetCfgDescriptors | Failed to read config from Fkt 0x5FE26830 - error -33
E: [18:42:05]               USB FD fkt start |                    FD launcher | Failed to read CfgDsc
I: [18:42:06]              USB stack Process |                                | USB System Software Process started.
I: [18:42:06]              USB stack Process |                                | Reading FD descriptors...
I: [18:42:06]              USB stack Process |                                | ...FD infos read
I: [18:42:06]              USB stack Process |                                | Starting HCDs...
I: [18:42:06]              USB stack Process |                                | ...HCDs started.
I: [18:42:06]              USB stack Process |                                | USB stack fullbooted
I: [18:42:06]               USB FD fkt start |  Sys_EndInitialAttachmentPhase | Initial USB Attachment Phase terminated
I: [18:42:07]                      hid.usbfd |                     HID driver | USB Interface bound


If I replug until finally both work then I get:
Code: Select all
I: [18:54:20]                      hub.usbfd |                            HUB | Device found on port 2 of hub "Rear Roothub (ehci.usbhcd/0)".
I: [18:54:20]                      hub.usbfd |                       Hub port | Device at port 2 of hub "Rear Roothub (ehci.usbhcd/0)" is high-speed.
I: [18:54:20]                      USB stack |                        New Fkt | Fkt 0x5fe26330 at level 1
I: [18:54:20]                      hub.usbfd |                            HUB | Device on hub port 2 successfully added.
I: [18:54:20]    EHCI Controller Task Unit 0 |                           EHCI | Port 1 is not in reset state.
I: [18:54:20]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe26330 is {Vendor: 0x0451, Product: 0x8142, Class: 09.00}
I: [18:54:20]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe26330 initialized
I: [18:54:20]                      hub.usbfd |                            HUB | Now configured to use multiple TTs
I: [18:54:20]                      hub.usbfd |                            HUB | Hub "" has TT thinktime of 8 full speed bittimes and protocol 2
I: [18:54:21]                      hub.usbfd |                            HUB | Device found on port 1 of hub "".
I: [18:54:21]                      hub.usbfd |                       Hub port | Device at port 1 of hub "" is full-speed.
I: [18:54:21]                      USB stack |                        New Fkt | Fkt 0x5fe26470 at level 2
I: [18:54:21]                      hub.usbfd |                            HUB | Device on hub port 1 successfully added.
I: [18:54:21]                      hub.usbfd |                            HUB | Driver Running
I: [18:54:21]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe26470 is {Vendor: 0x10D5, Product: 0x1234, Class: 09.00}
I: [18:54:21]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe26470 initialized
I: [18:54:21]                      hub.usbfd |                            HUB | Hub "" has TT thinktime of 8 full speed bittimes and protocol 0
I: [18:54:21]                      hub.usbfd |                            HUB | Device found on port 1 of hub "".
I: [18:54:21]                      hub.usbfd |                       Hub port | Device at port 1 of hub "" is full-speed.
I: [18:54:21]                      USB stack |                        New Fkt | Fkt 0x5fe26650 at level 3
I: [18:54:21]                      hub.usbfd |                            HUB | Device on hub port 1 successfully added.
I: [18:54:21]                      hub.usbfd |                            HUB | Device found on port 2 of hub "".
I: [18:54:21]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe26650 is {Vendor: 0x046D, Product: 0xC016, Class: 00.00}
I: [18:54:21]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe26650 initialized
I: [18:54:22]                      hub.usbfd |                       Hub port | Device at port 2 of hub "" is full-speed.
I: [18:54:22]                      USB stack |                        New Fkt | Fkt 0x5fe265b0 at level 3
I: [18:54:22]                      hub.usbfd |                            HUB | Device on hub port 2 successfully added.
I: [18:54:22]                      hub.usbfd |                            HUB | Driver Running
I: [18:54:22]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe265b0 is {Vendor: 0x413C, Product: 0x2110, Class: 00.00}
I: [18:54:22]                      hid.usbfd |                     HID driver | USB Interface bound
I: [18:54:22]                   USB Fkt Init |                       Init Fkt | Fkt 0x5fe265b0 initialized
I: [18:54:22]                      hid.usbfd |                     HID driver | USB Interface bound
I: [18:54:22]                      hid.usbfd |                     HID driver | USB Interface bound


So it seems it fails to read the config dsc from time to time.