Re: port-i386/57662: StarTech ICUSB23208FD 8-Port USB-to-Serial Adapter Hub fails on Alix with NetBSD/i386 9.3

[Alexander Schreiber <als%thangorodrim.ch@localhost>]

On Thu, Oct 26, 2023 at 08:45:34AM +1100, matthew green wrote:
> > Did that. Interestingly, what I did this time:
> >  - did one cu session, terminated it normally
> >  - got distracted for at least an hour
> >  - did another cu session, that promptly hung
> >
> > invoked crash:
> >
> > console# crash
> > Crash version 10.0_BETA, image version 10.0_BETA.
> > Kernel compiled without options LOCKDEBUG.
> > Output from a running system is unreliable.
> > crash> ps|grep cu
> > 1524  1524 3   0   1000000           c260c640                 cu usbxfer
> > 0       17 3   0       200           c1eaa100           lnxrcugc lnxrcugc
> > crash> bt/a c260c640
> > trace: pid 1524 lid 1524 at 0xce80ab18
> > sleepq_block(0,0,c14afda4,c14afda4,0,c1d43100,c1ec1808,c1d43100,c1f0ce80,c1d43100) at sleepq_block+0x138
> > cv_wait(c1edbe84,c1ec1808,c1edbe78,1ee4c25,0,2,23d6c,0,ce80abf8,ce80abf8) at cv_wait+0xc6
> > usbd_transfer(c1edbe78,0,0,0,ce80abb0,0,8,8,8,c1edbe78) at usbd_transfer+0x15c
> > usbd_do_request_len(c1f0ce00,ce80abf8,0,0,0,0,1388,ce80ac3c,c03ed0df,c1f0ce00) at usbd_do_request_len+0xad
> > usbd_do_request(c1f0ce00,ce80abf8,0,40,1,0,4af,c1eaf00c,dd313180,ce80ac70) at usbd_do_request+0x3f
> > uftdi_open(c1f14340,1,0,c1ef5c00,0,0,4200,1841,0,c1ef5c00) at uftdi_open+0x4e
> > ucomopen(4200,0,7,2000,c260c640,c0d28fe2,c22d17c0,0,c1f153c0,100) at ucomopen+0x307
> [ ... ]
> >
> > I hope that is helpful. Let me know what else I can do to help.
> 
> OK, so seems like a transfer isn't completing like it should.
> 
> can you build a kernel with USB_DEBUG, UFTDI_DEBUG, which ever of
> XHCI_DEBUG / UHCI_DEBUG / OHCI_DEBUG / EHCI_DEBUG the ufdti is
> attached to, reboot without them plugged in, set the various
> sysctl that will be eg hw.usb.debug / hw.xhci.debug / etc, to 1,
> plug the devies in and try to trigger a hang.  when it hangs, use
> "vmstat -u usbhist" to obtain the usb history which should provide
> a bunch of useful data to what has happened.
> 
> usbd_xfer_schedule_timeout() should have setup a timeout for this,
> the default would be 5 i think with this via usbd_do_request().

Ok, done.

This time it managed to get stuck right at the second connection attempt:
 - establish first connection: cu -l /dev/ttyU0 -s 115200
   --> I get the expected "Connected" and can interact with the
       attached serial console, then I disconnect 
 - establish second connection: cu -l /dev/ttyU1 -s 115200
   --> no output from cu, no response to the ~. disconnect sequence
   --> wait a minute or so, then vmstat -u usbhist output dumped to file

diff -urN ./sys/arch/i386/conf/GENERIC ./sys/arch/i386/conf/CONSOLE
--- ./sys/arch/i386/conf/GENERIC        2023-10-09 23:33:46.000000000 +0000
+++ ./sys/arch/i386/conf/CONSOLE        2023-10-26 12:50:55.582874835 +0000
@@ -1519,3 +1519,12 @@
 options        PAX_MPROTECT=1          # PaX mprotect(2) restrictions
 options        PAX_MPROTECT_DEBUG=1    # PaX mprotect debug
 options        PAX_ASLR=1              # PaX Address Space Layout Randomization
+
+options         USB_DEBUG
+options         UFTDI_DEBUG
+options         UHCI_DEBUG
+options         XHCI_DEBUG
+options         OHCI_DEBUG
+options         EHCI_DEBUG
+

sysctl -a|grep debug|grep hw|grep -E '(usb|hci)'
hw.usb.debug = 1
hw.uhci.debug = 1
hw.ohci.debug = 1
hw.ehci.debug = 1
hw.xhci.debug = 1

dmesg when the device was plugged in:

Oct 27 19:31:36 console /netbsd: [ 339.2244729] uhub2 at uhub1 port 1: Terminus Technology (0x1a40) USB 2.0 Hub [MTT] (0x0101), class 9/0, rev 2.00/1.00, addr 2
Oct 27 19:31:36 console /netbsd: [ 339.2397117] uhub2: multiple transaction translators
Oct 27 19:31:36 console /netbsd: [ 339.2445789] uhub2: 4 ports with 4 removable, self powered
Oct 27 19:31:37 console /netbsd: [ 340.0845023] uftdi0 at uhub2 port 2 configuration 1 interface 0
Oct 27 19:31:37 console /netbsd: [ 340.0845023] uftdi0: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 3
Oct 27 19:31:37 console /netbsd: [ 340.1002791] ucom0 at uftdi0 portno 1
Oct 27 19:31:37 console /netbsd: [ 340.1044987] uftdi1 at uhub2 port 2 configuration 1 interface 1
Oct 27 19:31:37 console /netbsd: [ 340.1044987] uftdi1: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 3
Oct 27 19:31:37 console /netbsd: [ 340.1183381] ucom1 at uftdi1 portno 2
Oct 27 19:31:37 console /netbsd: [ 340.1183381] uftdi2 at uhub2 port 2 configuration 1 interface 2
Oct 27 19:31:37 console /netbsd: [ 340.1253221] uftdi2: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 3
Oct 27 19:31:37 console /netbsd: [ 340.1364119] ucom2 at uftdi2 portno 3
Oct 27 19:31:37 console /netbsd: [ 340.1364119] uftdi3 at uhub2 port 2 configuration 1 interface 3
Oct 27 19:31:37 console /netbsd: [ 340.1453230] uftdi3: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 3
Oct 27 19:31:37 console /netbsd: [ 340.1544997] ucom3 at uftdi3 portno 4
Oct 27 19:31:37 console /netbsd: [ 340.6545175] uftdi4 at uhub2 port 3 configuration 1 interface 0
Oct 27 19:31:37 console /netbsd: [ 340.6545175] uftdi4: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 4
Oct 27 19:31:37 console /netbsd: [ 340.6710667] ucom4 at uftdi4 portno 1
Oct 27 19:31:37 console /netbsd: [ 340.6746100] uftdi5 at uhub2 port 3 configuration 1 interface 1
Oct 27 19:31:37 console /netbsd: [ 340.6746100] uftdi5: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 4
Oct 27 19:31:37 console /netbsd: [ 340.6891425] ucom5 at uftdi5 portno 2
Oct 27 19:31:37 console /netbsd: [ 340.6891425] uftdi6 at uhub2 port 3 configuration 1 interface 2
Oct 27 19:31:37 console /netbsd: [ 340.6961357] uftdi6: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 4
Oct 27 19:31:37 console /netbsd: [ 340.7072252] ucom6 at uftdi6 portno 3
Oct 27 19:31:37 console /netbsd: [ 340.7072252] uftdi7 at uhub2 port 3 configuration 1 interface 3
Oct 27 19:31:37 console /netbsd: [ 340.7147651] uftdi7: FTDI (0x0403) USB <-> Serial Cable (0x6011), rev 2.00/8.00, addr 4
Oct 27 19:31:37 console /netbsd: [ 340.7252493] ucom7 at uftdi7 portno 4

The output of "vmstat -u usbhist" is about 2.2M, and I'm not sure how gnats
deals with either attachments or hilariously long emails, so I've parked
that here: https://www.thangorodrim.ch/tmp/NetBSD10BETA_serial_vmstat-usbhist

Kind regards,
           Alex.
-- 
"Opportunity is missed by most people because it is dressed in overalls and
 looks like work."                                      -- Thomas A. Edison