/* * DF-5540 KLD harness -- production-code demonstration of the uark * (Arkmicro ARK3116 USB-RS232, ucom core) cfg-chain synchronous-request * stall. Same rig family as DF-5476 ubsa / DF-5425 uslcom / DF-5424 * uftdi / DF-5449 uvscom / DF-5456 umoscom / DF-5487 uvisor / DF-5496 * umct. * * WHAT IT PROVES (with the real in-kernel u4b usb_process machinery, * the same taskqueue ucom's cfg callbacks run on): * * Every uark cfg callback step is a synchronous EP0 vendor control * write (UARK_WRITE 0x40, wLength 0) through ucom_cfg_do_request() * (usb_serial.h:220-221 -> usbd_do_request_proc, usb_request.c: * 759-790) carrying a 1000 ms timeout (uark.c:429-430), and the * usb_error_t result is DISCARDED at the only site there is * (uark_cfg_write(), uark.c:431-434 "(ignored)"), so no chain step * ever aborts. A silent evil adapter makes each request eat its * full 1000 ms timeout (usb_request.c:561 max_ticks, :643 "WXFER" * sleep, :700-704 USB_ERR_TIMEOUT) and the chain marches on; a * slow-but-answer-at-999 ms evil adapter makes every request * *succeed*. * * Production chain accounting (pass-2 precision, LL_READY-gated): * * FIRST open(2) of /dev/ttyUx (ucom_open, usb_serial.c:801-903) * queues param(:842 via ucom_param -> :1691), start(:870), cfg_open * (:865), start(:870), line-state (:874-878: ucom_modem DTR|RTS + * ucom_ring + ucom_break(0) coalesce into ONE line-state task), * status (:880). The first param task runs BEFORE the cfg_open * task and BAILS (ucom_cfg_param, usb_serial.c:1626-1628: * !UCOM_FLAG_LL_READY) -- uark's first-open param is a NO-OP. * uark registers NO ucom_cfg_open callback (uark.c:138-148), so * cfg_open only sets LL_READY with NO hz/10 pause (pause is inside * the callback-if, usb_serial.c:771-778). The line-state task * (usb_serial.c:1357-1420) computes its callback mask from what is * REGISTERED (:1374-1381): uark registers only ucom_cfg_set_break * among the line callbacks (uark.c:140 -- no set_dtr, no set_rts, * no set_ring), so first-open DTR+RTS+BREAK-off collapses to * 1 x uark_cfg_set_break(sc,0) -> 1 x uark_cfg_write(sc,4,0x00) * (uark.c:414) -> 1 x 1000 ms EP0. * uark_cfg_get_status reads cached bytes that nothing ever writes * (sc_msr/sc_lsr declared uark.c:91-92, read uark.c:403-404, NO * interrupt endpoint, NO status writer) -> 0 requests; uark issues * NO control-IN reads anywhere (uark_cfg_write is the only request * helper and it is write-only, uark.c:423-427 -- the DF-1062/2342/ * 5448/5455 uninit-read class cannot exist in this driver). * => first open = 1 x 1000 ms ~= 1.0 s of per-adapter taskqueue * occupancy. * * EVERY later tcsetattr of the open tty re-queues the param task * (double-buffered, usb_serial.c:1691-1693; LL_READY now set) and * uark_cfg_param (uark.c:348-396) chains SIX synchronous writes: * ANY rate in [300,115200] (uark_pre_param, uark.c:343 -- B0/0 * and >115200 are rejected with EINVAL; there is no B0 branch): * reg3=0x83 (uark.c:361) * reg0=div (uark.c:362) * reg1=div>>8(uark.c:363) * reg3=0x03 (uark.c:364) * reg3=0x00 (uark.c:394) * reg3=LCR (uark.c:395) = 6 x 1000 ms * + core hz/10 pause (usb_serial.c:1636) ~= 6.1 s * TIOCSBRK/TIOCCBRK -> line-state task -> uark_cfg_set_break * (uark.c:407-415) -> 1 x 1000 ms per toggle. * The double buffer COALESCES a rapid tcsetattr burst to at most 2 * queued instances (usb_proc_msignal t==3 branch, usb_process.c: * 259-331): a burst of 5 executes 2 full chains; a PACED or * sustained loop keeps the tq busy ~6.1 s per instance for as long * as the abuser keeps queueing. uark's per-tcsetattr chain is 3x * umct's (DF-5496, 2 reqs) -- the heaviest single-rate chain in * the audited family short of umcs' 28-request open/close pair * (DF-5383). * * close(2) is SYNCHRONOUS against that queue: ucom_close() -> * ucom_shutdown() (HUPCL default: TTYDEF_CFLAG) queues a DTR drop * (usb_serial.c:694-696) which the line-state mask DROPS for uark * (set_dtr NULL, usb_serial.c:1374-1375) -> 0 requests, then * ucom_queue_command(ucom_cfg_close) -> usb_proc_mwait() * (usb_serial.c:671-672 + 955-957), uninterruptible cv_wait * (usb_process.c:364-393) while messages queued in front run to * completion. uark registers no ucom_cfg_close (uark.c:138-148), * so the closer purely waits out whatever the user/device queued * ahead -- 0 requests of its own. * Unplug mid-cycle stalls the USB hub event thread identically via * ucom_detach() -> usb_proc_drain() (usb_serial.c:394). * * PHASE A (first open + close): 1 x 1000 ms break-off line task; * closer queues 100 ms in and owns 0 requests. EXPECT ~900 ms. * PHASE A2 (open + 1 user tcsetattr@9600 + close): + 6 x 1000 ms + * 100 ms pause. EXPECT ~7000 ms. * PHASE A3 (open + burst of 5 tcsetattr + close): coalesced to 2 * param executions -> + 2 x 6100 ms. EXPECT ~13100 ms (burst * ceiling; a paced/sustained loop extends without bound until the * abuser stops, because usb_proc_mwait cv_wait drops sc_lock while * asleep). * PHASE B (fix.diff mechanism #1: abort each cfg chain on its first * failed request, timeout unchanged): line 1 x 1000 ms, param 1 x * 1000 ms + pause. EXPECT ~2000 ms. * PHASE C (fix.diff mechanism #1+#2: abort + bound the cfg-path * control timeout 1000 -> 250 ms): EXPECT ~500 ms. */ #include #include #include #include #include #include #include #include #include #include #include #include #define UA_LINE_REQS 1 /* uark.c:414 first-open break-off only */ #define UA_PARAM_REQS 6 /* uark.c:361,362,363,364,394,395 */ #define UA_CLOSE_DTR 0 /* set_dtr NULL -> HUPCL masked, usb_serial.c:1374-1375 */ #define UA_BREAK_REQS 1 /* uark.c:414 per TIOCSBRK/TIOCCBRK toggle */ #define UA_REQ_MS 1000 /* uark.c:429-430 production cfg timeout */ static struct lock ua_lock; /* stands in for sc->sc_lock */ static struct usb_process ua_tq; /* sc_super_ucom.sc_tq (usb_serial.c:322) */ struct ua_msg { struct usb_proc_msg hdr; }; static struct ua_msg ua_param[2]; /* ucom sc_param_task[2] double buffer */ static struct ua_msg ua_start[2]; /* ucom sc_start_task[2] */ static struct ua_msg ua_open_msg[2]; /* ucom sc_open_task[2] */ static struct ua_msg ua_line[2]; /* ucom sc_line_state_task[2] */ static struct ua_msg ua_status[2]; /* ucom sc_status_task[2] */ static struct ua_msg ua_close[2]; /* ucom sc_close_task[2] */ static int ua_ll_ready; /* UCOM_FLAG_LL_READY, set by cfg_open task */ static int ua_fixed; /* fix mechanism #1: abort on first error */ static int ua_req_ms = UA_REQ_MS;/* fix mechanism #2: bounded timeout */ static int ua_param_execs; /* coalescing instrumentation (A3) */ static struct timeval ua_t0; /* phase start, absolute */ static int64_t ua_ms(struct timeval *t0, struct timeval *t1) { return ((int64_t)(t1->tv_sec - t0->tv_sec) * 1000 + (t1->tv_usec - t0->tv_usec) / 1000); } static int64_t ua_abs_ms(void) { struct timeval now; microtime(&now); return (ua_ms(&ua_t0, &now)); } /* * One uark vendor request (UARK_WRITE 0x40 / UARK_REQUEST 0xfe / * wLength 0) against the silent evil adapter: the device never * answers the data/status stage, so the requester sleeps in the * "WXFER" loop until the timeout fires (usb_request.c:643, :700-704) * and the request returns USB_ERR_TIMEOUT -- which production uark * discards (uark.c:431-434). The sleep ident must be UNIQUE per * request like the production "xfer" pointer is: sleeping on the * lock address would let unrelated lockmgr handoffs wake the request * early (harness v1 bug family, caught by absolute-timestamp * instrumentation in DF-5476; same fix carried here). */ static char ua_req_wchan[16]; /* per-request wait channel */ static int ua_one_request(const char *what, int i, int n) { kprintf("UA5540[%dms]: request %d/%d (%s) START: EP0 vendor write, " "%d ms timeout, silent device\n", (int)ua_abs_ms(), i, n, what, ua_req_ms); lksleep(&ua_req_wchan[i & 15], &ua_lock, 0, "WXFER", USB_MS_TO_TICKS(ua_req_ms)); if (ua_fixed) { /* fix.diff mechanism: the error now propagates and the * cfg chain bails on first failure. */ kprintf("UA5540: request %d/%d (%s) FAILED " "(USB_ERR_TIMEOUT) -> abort chain (fixed)\n", i, n, what); return (1); } return (0); } /* * ucom_cfg_param() (usb_serial.c:1619-1637) wrapping uark_cfg_param() * (uark.c:348-396). NOTE the production LL_READY gate at 1626-1628: * the first-open instance (queued at usb_serial.c:842, BEFORE cfg_open * at :865) runs first and BAILS -- modelled here. uark chains the * same six writes for ANY accepted rate (300..115200, uark.c:343; * B0/0 and >115200 are rejected in pre_param -- there is no B0 * branch). */ static void ua_cfg_param(struct usb_proc_msg *pm) { static const char *regs[UA_PARAM_REQS] = { "reg3=0x83", "reg0=div LSB", "reg1=div MSB", "reg3=0x03", "reg3=0x00", "reg3=LCR" }; int i, n; if (!ua_ll_ready) { kprintf("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)\n"); return; } n = UA_PARAM_REQS; ua_param_execs++; kprintf("UA5540: cfg-param task: enter (#%d), tcsetattr chain " "(any rate 300..115200, no B0 branch in uark.c:348-396), " "%d x %d ms sync EP0 writes%s\n", ua_param_execs, n, ua_req_ms, ua_fixed ? " (fix: abort on first error)" : ""); for (i = 0; i < n; ++i) { if (ua_one_request(regs[i], i + 1, n)) break; } /* ucom_cfg_param()'s trailing pause, usb_serial.c:1636 */ usb_pause_mtx(&ua_lock, hz / 10); kprintf("UA5540: cfg-param task: leave\n"); } /* ucom_cfg_start_transfers() -- no EP0, no occupancy (no-op here) */ static void ua_cfg_start(struct usb_proc_msg *pm) { kprintf("UA5540: start-transfers task: async bulk only, " "0 EP0 requests\n"); } /* * ucom_cfg_open() (usb_serial.c:757-779): uark registers NO * ucom_cfg_open callback (uark.c:138-148) -> just sets LL_READY, * 0 requests and NO hz/10 pause (the pause at :777 is inside the * callback-if). */ static void ua_cfg_open(struct usb_proc_msg *pm) { kprintf("UA5540: cfg-open task: no ucom_cfg_open callback in uark " "-> set LL_READY only, 0 requests, no pause " "(usb_serial.c:771-778)\n"); ua_ll_ready = 1; } /* * The first-open line-state task (usb_serial.c:874-878 -> 1357-1420 * coalesced): ucom_modem(DTR|RTS) + ucom_ring(0) + ucom_break(0). * The callback mask at :1374-1381 only contains UCOM_LS_BREAK for * uark (uark.c:140 registers set_break; set_dtr/set_rts/set_ring are * NULL) -> 1 x uark_cfg_set_break(sc,0) (uark.c:407-415) -> 1 x * uark_cfg_write(sc,4,0x00) (uark.c:414). */ static void ua_cfg_line(struct usb_proc_msg *pm) { int i; if (!ua_ll_ready) return; /* usb_serial.c:1368-1370 */ kprintf("UA5540: line-state task: enter, mask=BREAK only (no " "set_dtr/set_rts/set_ring registered, uark.c:138-148) -> " "1 x %d ms sync EP0 write (set_break(0), uark.c:414)%s\n", ua_req_ms, ua_fixed ? " (fix: abort on first error)" : ""); for (i = 0; i < UA_LINE_REQS; ++i) { if (ua_one_request("set_break(0)", i + 1, UA_LINE_REQS)) break; } kprintf("UA5540: line-state task: leave (no core pause)\n"); } /* * ucom_cfg_status_change() -> uark_cfg_get_status() (uark.c:398-405): * reads CACHED sc_lsr/sc_msr bytes that NO code path ever writes * (declared uark.c:91-92; no interrupt endpoint; uark never calls * ucom_status_change with device data) -> 0 EP0 requests, constant * zero modem/line status (functional only, softc is zeroed -- no * uninit leak). uark never issues control-IN reads anywhere (the * DF-1062/2342/5448/5455 uninit-read class cannot exist here). */ static void ua_cfg_status(struct usb_proc_msg *pm) { kprintf("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\n"); } /* uark registers no ucom_cfg_close -> ucom_cfg_close() core calls * nothing (usb_serial.c:907-921); the closer's own HUPCL DTR drop is * masked out by the line-state callback mask (set_dtr NULL, * usb_serial.c:1374-1375) -> 0 requests of its own. */ static void ua_cfg_close(struct usb_proc_msg *pm) { kprintf("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)\n"); } /* * Exactly ucom_close()'s synchronous close (usb_serial.c:939-957): * ucom_shutdown()'s HUPCL ucom_modem(tp,0,SER_DTR) is dropped by the * line-state mask for uark (0 requests), then * ucom_queue_command(ucom_cfg_close) -> usb_proc_mwait() * uninterruptibly (usb_serial.c:671-672; usb_process.c:364-393). */ static int64_t ua_closer_thread(char tag) { struct timeval t0, t1; /* the open chain tasks are running; the first starts immediately */ tsleep(&ua_tq, 0, "ualead", hz / 10); /* 100 ms into the chain */ kprintf("UA5540[%c][%dms]: closer: HUPCL DTR drop MASKED (0 reqs), " "cfg_close + usb_proc_mwait() (uninterruptible, " "usb_serial.c:671-672) behind the queue\n", tag, (int)ua_abs_ms()); microtime(&t0); lockmgr(&ua_lock, LK_EXCLUSIVE); if (!usb_proc_is_gone(&ua_tq)) { struct ua_msg *m; /* ucom_close(): queue cfg_close and wait synchronously */ m = usb_proc_msignal(&ua_tq, &ua_close[0], &ua_close[1]); m->hdr.pm_callback = &ua_cfg_close; usb_proc_mwait(&ua_tq, &ua_close[0], &ua_close[1]); } lockmgr(&ua_lock, LK_RELEASE); microtime(&t1); kprintf("UA5540[%c][%dms]: closer: unblocked ELAPSED=%jd ms\n", tag, (int)ua_abs_ms(), (intmax_t)ua_ms(&t0, &t1)); return (ua_ms(&t0, &t1)); } /* * The open(2) path, production queueing order (usb_serial.c:842 param, * :870 start, :865 cfg_open, :870 start again via :874-878 context, * :874-878 line-state, :880 status-change), then the local user's * tcsetattr burst(s) queue behind the open chain. */ static void ua_open_chain(int extra_params) { struct ua_msg *m; lockmgr(&ua_lock, LK_EXCLUSIVE); /* ucom_open():842 -> ucom_param() queues cfg_param first */ m = usb_proc_msignal(&ua_tq, &ua_param[0], &ua_param[1]); m->hdr.pm_callback = &ua_cfg_param; /* :870 queue transfer enable command last (from ucom_param :1696) */ m = usb_proc_msignal(&ua_tq, &ua_start[0], &ua_start[1]); m->hdr.pm_callback = &ua_cfg_start; /* :865 cfg_open */ m = usb_proc_msignal(&ua_tq, &ua_open_msg[0], &ua_open_msg[1]); m->hdr.pm_callback = &ua_cfg_open; /* :870 queue transfer enable command last */ m = usb_proc_msignal(&ua_tq, &ua_start[0], &ua_start[1]); m->hdr.pm_callback = &ua_cfg_start; /* :874-878 DTR|RTS + ring-off + break-off -> one line-state task */ m = usb_proc_msignal(&ua_tq, &ua_line[0], &ua_line[1]); m->hdr.pm_callback = &ua_cfg_line; /* :880 ucom_status_change() */ m = usb_proc_msignal(&ua_tq, &ua_status[0], &ua_status[1]); m->hdr.pm_callback = &ua_cfg_status; lockmgr(&ua_lock, LK_RELEASE); /* * The user's tcsetattr burst comes after open(2) returned; give * the tq thread a moment so the (instantly-bailing) first param * task has completed and the re-used double buffer enqueues * fresh. The msignal t==3 branch coalesces a burst of 5 down to * 2 queued instances -- production behavior, instrumented. */ tsleep(&ua_tq, 0, "uatset", hz / 20); while (extra_params--) { lockmgr(&ua_lock, LK_EXCLUSIVE); m = usb_proc_msignal(&ua_tq, &ua_param[0], &ua_param[1]); m->hdr.pm_callback = &ua_cfg_param; lockmgr(&ua_lock, LK_RELEASE); } } static int ua_phase(const char *name, char tag, int extra_params, int fixed, int req_ms) { int error; memset(&ua_tq, 0, sizeof(ua_tq)); error = usb_proc_create(&ua_tq, &ua_lock, name, USB_PRI_MED); if (error) { kprintf("UA5540: usb_proc_create failed: %d\n", error); return (error); } ua_ll_ready = 0; ua_param_execs = 0; ua_fixed = fixed; ua_req_ms = req_ms; microtime(&ua_t0); kprintf("UA5540[%c]: --- phase %s: first open + %d tcsetattr " "burst + close --- (t=0)\n", tag, name, extra_params); /* the user opens the tty */ ua_open_chain(extra_params); /* the closing thread (or the hub event thread on unplug) */ ua_closer_thread(tag); usb_proc_free(&ua_tq); return (0); } static int ua_modevent(module_t mod, int type, void *data) { int error = 0; switch (type) { case MOD_LOAD: lockinit(&ua_lock, "ua5540", 0, LK_CANRECURSE); kprintf("UA5540: DF-5540 uark cfg-chain stall harness, hz=%d, " "%d reqs/first-open-line-task, %d reqs/tcsetattr " "(any rate 300..115200, B0 rejected), %d reqs/HUPCL-" "close, %d reqs/break-toggle, %d reqs/open-task, %d " "reqs/status-task, 0 reqs/close-task, %d ms/request " "(production timeout uark.c:429-430)\n", hz, UA_LINE_REQS, UA_PARAM_REQS, UA_CLOSE_DTR, UA_BREAK_REQS, 0, 0, UA_REQ_MS); ua_phase("A first-open + close", 'A', 0, 0, UA_REQ_MS); ua_phase("A2 open + 1 tcsetattr + close", '2', 1, 0, UA_REQ_MS); ua_phase("A3 open + burst of 5 tcsetattr + close", '3', 5, 0, UA_REQ_MS); ua_phase("B fix#1 abort-on-error", 'B', 1, 1, UA_REQ_MS); ua_phase("C fix#1+#2 abort+250ms", 'C', 1, 1, 250); lockuninit(&ua_lock); kprintf("UA5540: harness complete\n"); break; case MOD_UNLOAD: break; default: error = EOPNOTSUPP; break; } return (error); } static moduledata_t ua_mod = { "uark5540stall", ua_modevent, 0 }; DECLARE_MODULE(uark5540stall, ua_mod, SI_SUB_DRIVERS, SI_ORDER_MIDDLE); MODULE_DEPEND(uark5540stall, usb, 1, 1, 1);