UM5496: DF-5496 umct cfg-chain stall harness, hz=100, 3 reqs/first-open-line-task, 2 reqs/tcsetattr (any rate incl. B0 -- no branch), 1 reqs/HUPCL-close, 0 reqs/open-task, 0 reqs/status-task, 0 reqs/close-task, 1000 ms/request (production timeout umct.c:333)
UM5496[A]: --- phase A  first-open + close: first open + 0 tcsetattr burst + close --- (t=0)
UM5496: cfg-param task: !LL_READY -> early return, 0 requests (usb_serial.c:1626-1628; first-open param is a no-op for every ucom driver)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: cfg-open task: no ucom_cfg_open callback in umct -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: line-state task: enter, 3 x 1000 ms sync EP0 writes (DTR=1 SET_MCR, RTS=1 SET_MCR, BREAK=0 SET_LCR)
UM5496[57ms]: request 1/3 (set_dtr) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[A][158ms]: closer: ucom_shutdown HUPCL queues set_dtr(0), then cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue
UM5496[1038ms]: request 2/3 (set_rts) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[2028ms]: request 3/3 (set_break(0)) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: line-state task: leave (no core pause)
UM5496: cfg-status task: cached sc_lsr/sc_msr only (umct.c:386-387), 0 EP0 requests, no control-IN anywhere
UM5496: line-state task (HUPCL): enter, 1 x 1000 ms sync EP0 write (DTR=0 SET_MCR)
UM5496[3049ms]: request 1/1 (HUPCL set_dtr(0)) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: line-state task (HUPCL): leave
UM5496: cfg-close task: no ucom_cfg_close callback in umct -> 0 requests (usb_serial.c:915-921)
UM5496[A][4058ms]: closer: unblocked  ELAPSED=3885 ms
UM5496[2]: --- phase A2 open + 1 tcsetattr + close: first open + 1 tcsetattr burst + close --- (t=0)
UM5496: cfg-param task: !LL_READY -> early return, 0 requests (usb_serial.c:1626-1628; first-open param is a no-op for every ucom driver)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: cfg-open task: no ucom_cfg_open callback in umct -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: line-state task: enter, 3 x 1000 ms sync EP0 writes (DTR=1 SET_MCR, RTS=1 SET_MCR, BREAK=0 SET_LCR)
UM5496[56ms]: request 1/3 (set_dtr) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[2][164ms]: closer: ucom_shutdown HUPCL queues set_dtr(0), then cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue
UM5496[1035ms]: request 2/3 (set_rts) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[2015ms]: request 3/3 (set_break(0)) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: line-state task: leave (no core pause)
UM5496: cfg-status task: cached sc_lsr/sc_msr only (umct.c:386-387), 0 EP0 requests, no control-IN anywhere
UM5496: cfg-param task: enter (#1), tcsetattr chain (any rate, no B0 branch in umct.c:465-504), 2 x 1000 ms sync EP0 writes
UM5496[3030ms]: request 1/2 (SET_BAUD divisor) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[4015ms]: request 2/2 (SET_LCR) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: cfg-param task: leave
UM5496: line-state task (HUPCL): enter, 1 x 1000 ms sync EP0 write (DTR=0 SET_MCR)
UM5496[5126ms]: request 1/1 (HUPCL set_dtr(0)) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: line-state task (HUPCL): leave
UM5496: cfg-close task: no ucom_cfg_close callback in umct -> 0 requests (usb_serial.c:915-921)
UM5496[2][6130ms]: closer: unblocked  ELAPSED=5952 ms
UM5496[3]: --- phase A3 open + burst of 5 tcsetattr + close: first open + 5 tcsetattr burst + close --- (t=0)
UM5496: cfg-param task: !LL_READY -> early return, 0 requests (usb_serial.c:1626-1628; first-open param is a no-op for every ucom driver)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: cfg-open task: no ucom_cfg_open callback in umct -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: line-state task: enter, 3 x 1000 ms sync EP0 writes (DTR=1 SET_MCR, RTS=1 SET_MCR, BREAK=0 SET_LCR)
UM5496[61ms]: request 1/3 (set_dtr) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[3][169ms]: closer: ucom_shutdown HUPCL queues set_dtr(0), then cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue
UM5496[1042ms]: request 2/3 (set_rts) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[2032ms]: request 3/3 (set_break(0)) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: line-state task: leave (no core pause)
UM5496: cfg-status task: cached sc_lsr/sc_msr only (umct.c:386-387), 0 EP0 requests, no control-IN anywhere
UM5496: cfg-param task: enter (#1), tcsetattr chain (any rate, no B0 branch in umct.c:465-504), 2 x 1000 ms sync EP0 writes
UM5496[3049ms]: request 1/2 (SET_BAUD divisor) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[4032ms]: request 2/2 (SET_LCR) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: cfg-param task: leave
UM5496: cfg-param task: enter (#2), tcsetattr chain (any rate, no B0 branch in umct.c:465-504), 2 x 1000 ms sync EP0 writes
UM5496[5148ms]: request 1/2 (SET_BAUD divisor) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[6132ms]: request 2/2 (SET_LCR) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: cfg-param task: leave
UM5496: line-state task (HUPCL): enter, 1 x 1000 ms sync EP0 write (DTR=0 SET_MCR)
UM5496[7242ms]: request 1/1 (HUPCL set_dtr(0)) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496: line-state task (HUPCL): leave
UM5496: cfg-close task: no ucom_cfg_close callback in umct -> 0 requests (usb_serial.c:915-921)
UM5496[3][8234ms]: closer: unblocked  ELAPSED=8049 ms
UM5496[B]: --- phase B  fix#1 abort-on-error: first open + 1 tcsetattr burst + close --- (t=0)
UM5496: cfg-param task: !LL_READY -> early return, 0 requests (usb_serial.c:1626-1628; first-open param is a no-op for every ucom driver)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: cfg-open task: no ucom_cfg_open callback in umct -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: line-state task: enter, 3 x 1000 ms sync EP0 writes (DTR=1 SET_MCR, RTS=1 SET_MCR, BREAK=0 SET_LCR) (fix: abort on first error)
UM5496[61ms]: request 1/3 (set_dtr) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496[B][160ms]: closer: ucom_shutdown HUPCL queues set_dtr(0), then cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue
UM5496:   request 1/3 (set_dtr) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed)
UM5496: line-state task: leave (no core pause)
UM5496: cfg-status task: cached sc_lsr/sc_msr only (umct.c:386-387), 0 EP0 requests, no control-IN anywhere
UM5496: cfg-param task: enter (#1), tcsetattr chain (any rate, no B0 branch in umct.c:465-504), 2 x 1000 ms sync EP0 writes (fix: abort on first error)
UM5496[1090ms]: request 1/2 (SET_BAUD divisor) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496:   request 1/2 (SET_BAUD divisor) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed)
UM5496: cfg-param task: leave
UM5496: line-state task (HUPCL): enter, 1 x 1000 ms sync EP0 write (DTR=0 SET_MCR) (fix: abort on first error)
UM5496[2198ms]: request 1/1 (HUPCL set_dtr(0)) START: EP0 vendor write, 1000 ms timeout, silent device
UM5496:   request 1/1 (HUPCL set_dtr(0)) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed)
UM5496: line-state task (HUPCL): leave
UM5496: cfg-close task: no ucom_cfg_close callback in umct -> 0 requests (usb_serial.c:915-921)
UM5496[B][3209ms]: closer: unblocked  ELAPSED=3033 ms
UM5496[C]: --- phase C  fix#1+#2 abort+250ms: first open + 1 tcsetattr burst + close --- (t=0)
UM5496: cfg-param task: !LL_READY -> early return, 0 requests (usb_serial.c:1626-1628; first-open param is a no-op for every ucom driver)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: cfg-open task: no ucom_cfg_open callback in umct -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778)
UM5496: start-transfers task: async bulk/intr only, 0 EP0 requests
UM5496: line-state task: enter, 3 x 250 ms sync EP0 writes (DTR=1 SET_MCR, RTS=1 SET_MCR, BREAK=0 SET_LCR) (fix: abort on first error)
UM5496[61ms]: request 1/3 (set_dtr) START: EP0 vendor write, 250 ms timeout, silent device
UM5496[C][164ms]: closer: ucom_shutdown HUPCL queues set_dtr(0), then cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue
UM5496:   request 1/3 (set_dtr) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed)
UM5496: line-state task: leave (no core pause)
UM5496: cfg-status task: cached sc_lsr/sc_msr only (umct.c:386-387), 0 EP0 requests, no control-IN anywhere
UM5496: cfg-param task: enter (#1), tcsetattr chain (any rate, no B0 branch in umct.c:465-504), 2 x 250 ms sync EP0 writes (fix: abort on first error)
UM5496[346ms]: request 1/2 (SET_BAUD divisor) START: EP0 vendor write, 250 ms timeout, silent device
UM5496:   request 1/2 (SET_BAUD divisor) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed)
UM5496: cfg-param task: leave
UM5496: line-state task (HUPCL): enter, 1 x 250 ms sync EP0 write (DTR=0 SET_MCR) (fix: abort on first error)
UM5496[734ms]: request 1/1 (HUPCL set_dtr(0)) START: EP0 vendor write, 250 ms timeout, silent device
UM5496:   request 1/1 (HUPCL set_dtr(0)) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed)
UM5496: line-state task (HUPCL): leave
UM5496: cfg-close task: no ucom_cfg_close callback in umct -> 0 requests (usb_serial.c:915-921)
UM5496[C][1014ms]: closer: unblocked  ELAPSED=834 ms
UM5496: harness complete