DF-5540 / run.log
UA5540: DF-5540 uark cfg-chain stall harness, hz=100, 1 reqs/first-open-line-task, 6 reqs/tcsetattr (any rate 300..115200, B0 rejected), 0 reqs/HUPCL-close, 1 reqs/break-toggle, 0 reqs/open-task, 0 reqs/status-task, 0 reqs/close-task, 1000 ms/request (production timeout uark.c:429-430) UA5540[A]: --- phase A first-open + close: first open + 0 tcsetattr burst + close --- (t=0) UA5540: 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) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: cfg-open task: no ucom_cfg_open callback in uark -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: line-state task: enter, mask=BREAK only (no set_dtr/set_rts/set_ring registered, uark.c:138-148) -> 1 x 1000 ms sync EP0 write (set_break(0), uark.c:414) UA5540[56ms]: request 1/1 (set_break(0)) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[A][151ms]: closer: HUPCL DTR drop MASKED (0 reqs), cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue UA5540: line-state task: leave (no core pause) UA5540: cfg-status task: cached sc_lsr/sc_msr only (uark.c:403-404; never written anywhere -> constant 0), 0 EP0 requests, no control-IN anywhere UA5540: cfg-close task: no ucom_cfg_close callback in uark -> 0 requests; HUPCL DTR drop masked (no set_dtr) -> closer owns 0 requests (usb_serial.c:1374-1375) UA5540[A][1081ms]: closer: unblocked ELAPSED=921 ms UA5540[2]: --- phase A2 open + 1 tcsetattr + close: first open + 1 tcsetattr burst + close --- (t=0) UA5540: 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) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: cfg-open task: no ucom_cfg_open callback in uark -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: line-state task: enter, mask=BREAK only (no set_dtr/set_rts/set_ring registered, uark.c:138-148) -> 1 x 1000 ms sync EP0 write (set_break(0), uark.c:414) UA5540[54ms]: request 1/1 (set_break(0)) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[2][157ms]: closer: HUPCL DTR drop MASKED (0 reqs), cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue UA5540: line-state task: leave (no core pause) UA5540: cfg-status task: cached sc_lsr/sc_msr only (uark.c:403-404; never written anywhere -> constant 0), 0 EP0 requests, no control-IN anywhere UA5540: cfg-param task: enter (#1), tcsetattr chain (any rate 300..115200, no B0 branch in uark.c:348-396), 6 x 1000 ms sync EP0 writes UA5540[1088ms]: request 1/6 (reg3=0x83) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[2070ms]: request 2/6 (reg0=div LSB) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[3061ms]: request 3/6 (reg1=div MSB) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[4061ms]: request 4/6 (reg3=0x03) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[5061ms]: request 5/6 (reg3=0x00) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[6050ms]: request 6/6 (reg3=LCR) START: EP0 vendor write, 1000 ms timeout, silent device UA5540: cfg-param task: leave UA5540: cfg-close task: no ucom_cfg_close callback in uark -> 0 requests; HUPCL DTR drop masked (no set_dtr) -> closer owns 0 requests (usb_serial.c:1374-1375) UA5540[2][7158ms]: closer: unblocked ELAPSED=6995 ms UA5540[3]: --- phase A3 open + burst of 5 tcsetattr + close: first open + 5 tcsetattr burst + close --- (t=0) UA5540: 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) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: cfg-open task: no ucom_cfg_open callback in uark -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: line-state task: enter, mask=BREAK only (no set_dtr/set_rts/set_ring registered, uark.c:138-148) -> 1 x 1000 ms sync EP0 write (set_break(0), uark.c:414) UA5540[56ms]: request 1/1 (set_break(0)) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[3][157ms]: closer: HUPCL DTR drop MASKED (0 reqs), cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue UA5540: line-state task: leave (no core pause) UA5540: cfg-status task: cached sc_lsr/sc_msr only (uark.c:403-404; never written anywhere -> constant 0), 0 EP0 requests, no control-IN anywhere UA5540: cfg-param task: enter (#1), tcsetattr chain (any rate 300..115200, no B0 branch in uark.c:348-396), 6 x 1000 ms sync EP0 writes UA5540[1071ms]: request 1/6 (reg3=0x83) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[2052ms]: request 2/6 (reg0=div LSB) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[3042ms]: request 3/6 (reg1=div MSB) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[4032ms]: request 4/6 (reg3=0x03) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[5022ms]: request 5/6 (reg3=0x00) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[6002ms]: request 6/6 (reg3=LCR) START: EP0 vendor write, 1000 ms timeout, silent device UA5540: cfg-param task: leave UA5540: cfg-param task: enter (#2), tcsetattr chain (any rate 300..115200, no B0 branch in uark.c:348-396), 6 x 1000 ms sync EP0 writes UA5540[7123ms]: request 1/6 (reg3=0x83) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[8102ms]: request 2/6 (reg0=div LSB) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[9082ms]: request 3/6 (reg1=div MSB) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[10072ms]: request 4/6 (reg3=0x03) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[11052ms]: request 5/6 (reg3=0x00) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[12042ms]: request 6/6 (reg3=LCR) START: EP0 vendor write, 1000 ms timeout, silent device UA5540: cfg-param task: leave UA5540: cfg-close task: no ucom_cfg_close callback in uark -> 0 requests; HUPCL DTR drop masked (no set_dtr) -> closer owns 0 requests (usb_serial.c:1374-1375) UA5540[3][13175ms]: closer: unblocked ELAPSED=13012 ms UA5540[B]: --- phase B fix#1 abort-on-error: first open + 1 tcsetattr burst + close --- (t=0) UA5540: 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) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: cfg-open task: no ucom_cfg_open callback in uark -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: line-state task: enter, mask=BREAK only (no set_dtr/set_rts/set_ring registered, uark.c:138-148) -> 1 x 1000 ms sync EP0 write (set_break(0), uark.c:414) (fix: abort on first error) UA5540[60ms]: request 1/1 (set_break(0)) START: EP0 vendor write, 1000 ms timeout, silent device UA5540[B][169ms]: closer: HUPCL DTR drop MASKED (0 reqs), cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue UA5540: request 1/1 (set_break(0)) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed) UA5540: line-state task: leave (no core pause) UA5540: cfg-status task: cached sc_lsr/sc_msr only (uark.c:403-404; never written anywhere -> constant 0), 0 EP0 requests, no control-IN anywhere UA5540: cfg-param task: enter (#1), tcsetattr chain (any rate 300..115200, no B0 branch in uark.c:348-396), 6 x 1000 ms sync EP0 writes (fix: abort on first error) UA5540[1096ms]: request 1/6 (reg3=0x83) START: EP0 vendor write, 1000 ms timeout, silent device UA5540: request 1/6 (reg3=0x83) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed) UA5540: cfg-param task: leave UA5540: cfg-close task: no ucom_cfg_close callback in uark -> 0 requests; HUPCL DTR drop masked (no set_dtr) -> closer owns 0 requests (usb_serial.c:1374-1375) UA5540[B][2215ms]: closer: unblocked ELAPSED=2029 ms UA5540[C]: --- phase C fix#1+#2 abort+250ms: first open + 1 tcsetattr burst + close --- (t=0) UA5540: 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) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: cfg-open task: no ucom_cfg_open callback in uark -> set LL_READY only, 0 requests, no pause (usb_serial.c:771-778) UA5540: start-transfers task: async bulk only, 0 EP0 requests UA5540: line-state task: enter, mask=BREAK only (no set_dtr/set_rts/set_ring registered, uark.c:138-148) -> 1 x 250 ms sync EP0 write (set_break(0), uark.c:414) (fix: abort on first error) UA5540[58ms]: request 1/1 (set_break(0)) START: EP0 vendor write, 250 ms timeout, silent device UA5540[C][161ms]: closer: HUPCL DTR drop MASKED (0 reqs), cfg_close + usb_proc_mwait() (uninterruptible, usb_serial.c:671-672) behind the queue UA5540: request 1/1 (set_break(0)) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed) UA5540: line-state task: leave (no core pause) UA5540: cfg-status task: cached sc_lsr/sc_msr only (uark.c:403-404; never written anywhere -> constant 0), 0 EP0 requests, no control-IN anywhere UA5540: cfg-param task: enter (#1), tcsetattr chain (any rate 300..115200, no B0 branch in uark.c:348-396), 6 x 250 ms sync EP0 writes (fix: abort on first error) UA5540[350ms]: request 1/6 (reg3=0x83) START: EP0 vendor write, 250 ms timeout, silent device UA5540: request 1/6 (reg3=0x83) FAILED (USB_ERR_TIMEOUT) -> abort chain (fixed) UA5540: cfg-param task: leave UA5540: cfg-close task: no ucom_cfg_close callback in uark -> 0 requests; HUPCL DTR drop masked (no set_dtr) -> closer owns 0 requests (usb_serial.c:1374-1375) UA5540[C][729ms]: closer: unblocked ELAPSED=561 ms UA5540: harness complete