USB Stack Issue still unsolved...

A forum for general AmigaOS 4.x support questions that are not platform-specific
Lio
Posts: 46
Joined: Tue Sep 13, 2011 8:07 pm

Re: USB Stack Issue still unsolved...

Post 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

TomSoniq
Posts: 9
Joined: Sun Jun 19, 2011 2:03 pm

Re: USB Stack Issue still unsolved...

Post 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?

TomSoniq
Posts: 9
Joined: Sun Jun 19, 2011 2:03 pm

Re: USB Stack Issue still unsolved...

Post 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.

Belxjander
Posts: 292
Joined: Mon May 14, 2012 10:26 pm
Location: 日本千葉県松戸市 / Matsudo City, Chiba, Japan
Contact:

Re: USB Stack Issue still unsolved...

Post by Belxjander »

I've actually run into this problem myself... however I did find a solution...if this may work for you as well?

The issue is kind of a heisenbug in that it will and will not show as it is technically NOT a bug in either the OS or the HW that I could determine,
My personal workaround was to actually re-order the Kickstart modules in my Sys:Kickstart/KickLayout file and this actually resolved the issue completely.

The major indicator here is entirely that it only *sometimes* happens... the only fault I could determine this to be was a race condition specifically at the time the USB stack modules for the bootkeyboard and bootmouse get launched,
if this is the actual problem or not I can't say for certain, All I know is the KickLayout changes (as following) that I made to my own system appeared to resolve the problem ( apparently due to changing the timings at Kickstart modules being launched at startup )

I don't know if this will have any other subtle effects on the OS itself as I have not run into the USB Keyboard/Mouse issues after changing the KickLayout order.

Belxjander
; $VER: Kicklayout-Sam440ep 53.8 (12.10.2014)
;
LABEL Amiga4.1FE[U1]
EXEC Kickstart/loader
;
MODULE Kickstart/kernel
MODULE Kickstart/bootmenu.kmod
MODULE Kickstart/bootimage
MODULE Kickstart/diskboot.kmod
MODULE Kickstart/diskboot.config
MODULE Kickstart/ramlib.kmod
MODULE Kickstart/shell.kmod
MODULE Kickstart/strap.kmod
;
MODULE Kickstart/battclock.resource.kmod
MODULE Kickstart/biosversion.resource.kmod
MODULE Kickstart/FileSystem.resource.kmod
MODULE Kickstart/i2c.resource.kmod
MODULE Kickstart/nvram.resource.kmod
MODULE Kickstart/fpga.resource.kmod
;
MODULE Kickstart/newlib.library.kmod
MODULE Kickstart/nonvolatile.library.kmod
MODULE Kickstart/keymap.library.kmod
MODULE Kickstart/mounter.library
MODULE Kickstart/dos.library.kmod
MODULE Kickstart/elf.library.kmod
MODULE Kickstart/hunk.library.kmod
MODULE Kickstart/diskcache.library.kmod
MODULE Kickstart/graphics.library.kmod
MODULE Kickstart/intuition.library.kmod
MODULE Kickstart/gadtools.library.kmod
MODULE Kickstart/petunia.library.kmod
MODULE Kickstart/usbresource.library
;
MODULE Kickstart/PCIGraphics.card
MODULE Kickstart/ATIRadeon.chip
MODULE Kickstart/3dfxVoodoo.chip
;
MODULE Kickstart/ramdrive.device.kmod
MODULE Kickstart/keyboard.device.kmod
MODULE Kickstart/input.device.kmod
MODULE Kickstart/console.device.kmod
MODULE Kickstart/timer.device.kmod
MODULE Kickstart/sii0680ide.device.kmod
MODULE Kickstart/sii3114ide.device.kmod
MODULE Kickstart/sii3512ide.device.kmod
MODULE Kickstart/it8212ide.device.kmod
MODULE Kickstart/lsi53c8xx.device.kmod
MODULE Kickstart/usbsys.device
;
MODULE Kickstart/con-handler.kmod
MODULE Kickstart/env-handler.kmod
MODULE Kickstart/ram-handler.kmod
;
MODULE Kickstart/SmartFilesystem
MODULE Kickstart/FastFileSystem
MODULE Kickstart/CDFileSystem
;
MODULE Kickstart/hub.usbfd
MODULE Kickstart/bootmouse.usbfd
MODULE Kickstart/bootkeyboard.usbfd
MODULE Kickstart/massstorage.usbfd
MODULE Kickstart/uhci.usbhcd
MODULE Kickstart/ohci.usbhcd
MODULE Kickstart/ehci.usbhcd
;

graff
AmigaOS Core Developer
AmigaOS Core Developer
Posts: 4
Joined: Thu May 25, 2017 9:14 pm

Re: USB Stack Issue still unsolved...

Post by graff »

@Belxjander
Which modules have you changed the order of?
The kernel modules are loaded to mem and Exec then initializes them in order of their internal hardcoded priority. But, ofcourse, swapping two modules of same priority may have Exec encounter them in a different order since having the same priority there must some other factor ordering the initialization, which *could* be the kicklayout order (I don't know).
So knowing exactly what you changed in the kicklayout may give some vague indication of an area for investigation.

Regards,
Thomas

Belxjander
Posts: 292
Joined: Mon May 14, 2012 10:26 pm
Location: 日本千葉県松戸市 / Matsudo City, Chiba, Japan
Contact:

Re: USB Stack Issue still unsolved...

Post by Belxjander »

@Belxjander
Which modules have you changed the order of?
The kernel modules are loaded to mem and Exec then initializes them in order of their internal hardcoded priority. But, ofcourse, swapping two modules of same priority may have Exec encounter them in a different order since having the same priority there must some other factor ordering the initialization, which *could* be the kicklayout order (I don't know).
So knowing exactly what you changed in the kicklayout may give some vague indication of an area for investigation.

Regards,
Thomas
Specifically changed from an alphabetical list (as given by the default installation).

Basically I re-arranged on a basis of what modules are in the Kicklayout (order of ROMtag finding and which devices get created dynamically first really)

I did NOT modify any of the Kick Modules themselves on the order in the KickLayout listing.

graff
AmigaOS Core Developer
AmigaOS Core Developer
Posts: 4
Joined: Thu May 25, 2017 9:14 pm

Re: USB Stack Issue still unsolved...

Post by graff »

@Belxjander
Thanks, I'll take note of it and see if it can help point me in a general direction when looking at the attachment issues mentioned in this thread.
The biggest problem for me in finding a cause and fix is probably that I generally don't experience any such problems myself on my SAM460. I have an X5000 on its way (now at the end of my 2nd month of waiting for it to be delivered :roll: ) so maybe I will be able to reproduce some of the problems once it arrives.

Regards,
Thomas

Belxjander
Posts: 292
Joined: Mon May 14, 2012 10:26 pm
Location: 日本千葉県松戸市 / Matsudo City, Chiba, Japan
Contact:

Re: USB Stack Issue still unsolved...

Post by Belxjander »

by graff » Thu Apr 30, 2020 12:16 am

@Belxjander
Thanks, I'll take note of it and see if it can help point me in a general direction when looking at the attachment issues mentioned in this thread.
The biggest problem for me in finding a cause and fix is probably that I generally don't experience any such problems myself on my SAM460. I have an X5000 on its way (now at the end of my 2nd month of waiting for it to be delivered :roll: ) so maybe I will be able to reproduce some of the problems once it arrives.

Regards,
Thomas
My own system is a SAM 440 Flex with 3 PCI cards ( ATI Radeon 9x00 Graphics, Broadcom Wifi Network and USB3 XHCI controller )

My own USB stack issue is entirely different in that I have a USB3 XHCI controller that the OS can see but ignores,
with a partially written (mostly skeleton) xhci.usbhcd that needs more work to become something actually usable.

Post Reply