/* * DF-5456 KLD harness -- production-code demonstration of the umoscom * (MosChip MCS7703) cfg-chain synchronous-request stall. * * WHAT IT PROVES (with the real in-kernel u4b usb_process machinery, the * same taskqueue ucom's cfg callbacks run on): * * Every umoscom cfg callback step is a synchronous EP0 vendor control * request through ucom_cfg_do_request() (usb_serial.h:220-221 -> * usbd_do_request_proc) carrying a 1000 ms timeout, and the usb_error_t * result is DISCARDED at every call site (umoscom_cfg_write/umoscom_cfg_read * return void / a byte, umoscom.c:524-557), so no chain step ever aborts. * * First-open chain (all queued on sc_super_ucom.sc_tq by ucom_open(), * usb_serial.c:801-903): * usb_serial.c:842 ucom_param() -> umoscom_cfg_param() 4 x write * (umoscom.c:454 LCR divlatch, :457 BAUDLO, * :460 BAUDHI, :492 LCR) + hz/10 pause * (usb_serial.c:1636) * usb_serial.c:865 -> umoscom_cfg_open() 5 x write * (umoscom.c:368 FIFO purge, :371 FIFO enable, * :377 INT enable, :380 magic 0x01, :383 magic 0x00) * + hz/10 pause (usb_serial.c:777) * usb_serial.c:874-878 DTR+RTS+ring-off+break-off line-state task * -> 3 x write (umoscom.c:415 set_dtr, :428 set_rts, * :402 set_break; core coalescing 1384-1420) * usb_serial.c:880 ucom_status_change() -> umoscom_cfg_get_status() * 2 x read (umoscom.c:506 LSR, :507 MSR) * => 14 sequential 1000 ms-timeout EP0 requests + 2 x hz/10 pauses * ~= 14.2 s of uninterruptible per-adapter taskqueue occupancy for * ONE open(2) of an evil/silent MCS7703. * * Every later tcsetattr of the open tty re-queues the param task * (double-buffered, usb_serial.c:1691-1693): +4 x 1000 ms + pause * ~= 4.1 s each -- unprivileged-user amplification. * * close(2) is SYNCHRONOUS against that queue: ucom_close() -> * ucom_queue_command(ucom_cfg_close) -> usb_proc_mwait() * (usb_serial.c:671-672, 955-957), uninterruptible cv_wait * (usb_process.c:385-393) while a message stays head-of-queue for the * duration of its callback (usb_process.c:146-158). umoscom_cfg_close() * is a no-op (umoscom.c:386-390) -- 0 requests -- so the closer purely * waits out whatever the user/device queued in front of it. * Unplug mid-cycle stalls the USB hub event thread the same way via * ucom_detach() -> usb_proc_drain() (usb_serial.c:394) -- the DF-5367 * mechanism, umoscom instance. * * A control transfer's data/status stage may be NAK'd by the device for * as long as it likes: a silent evil MCS7703 makes each request eat its * full 1000 ms timeout (usb_request.c:642-644 WXFER loop, 699-704 * timeout) and the chain marches on anyway; a slow-but-answer-at-999 ms * evil device makes every request *succeed* with no error at all. * * PHASE A (baseline first-open + close): queue param+open+line+status * (14 x 1000 ms + 2 pauses), then what ucom_close() does: queue * cfg_close (0 requests) + usb_proc_mwait(). EXPECT ~14100 ms. * PHASE A2 (amplification): first-open chain + ONE extra user tcsetattr * queued behind it (production double-buffer shape) then the closer. * EXPECT ~18200 ms. * PHASE B (fix.diff mechanism #1: abort each cfg chain on its first * failed request, timeout unchanged): each task costs 1 x 1000 ms. * EXPECT ~4100 ms. * PHASE C (fix.diff mechanism #1+#2: abort + bound the cfg-path control * timeout 1000 -> 250 ms): EXPECT ~1100 ms. */ #include #include #include #include #include #include #include #include #include #include #include #include #define MO_PARAM_REQS 4 /* umoscom.c:454,457,460,492 per-tcsetattr chain */ #define MO_OPEN_REQS 5 /* umoscom.c:368,371,377,380,383 first-open chain */ #define MO_LINE_REQS 3 /* umoscom.c:415,428,402 DTR+RTS+BREAK-off task */ #define MO_STATUS_REQS 2 /* umoscom.c:506,507 LSR+MSR status reads */ #define MO_REQ_MS 1000 /* umoscom.c production cfg timeout */ static struct lock mo_lock; /* stands in for sc->sc_lock */ static struct usb_process mo_tq; /* sc_super_ucom.sc_tq (usb_serial.c:322) */ struct mo_msg { struct usb_proc_msg hdr; }; static struct mo_msg mo_param[2]; /* ucom sc_param_task[2] double buffer */ static struct mo_msg mo_open_msg[2]; /* ucom sc_open_task[2] */ static struct mo_msg mo_line[2]; /* ucom sc_line_state_task[2] */ static struct mo_msg mo_status[2]; /* ucom sc_status_task[2] */ static struct mo_msg mo_close[2]; /* ucom sc_close_task[2] */ static int mo_fixed; /* fix mechanism #1: abort on error */ static int mo_req_ms = MO_REQ_MS; /* fix mechanism #2: bounded timeout */ static int mo_aborted; static int64_t mo_ms(struct timeval *t0, struct timeval *t1) { return ((int64_t)(t1->tv_sec - t0->tv_sec) * 1000 + (t1->tv_usec - t0->tv_usec) / 1000); } /* * One umoscom vendor request against the silent evil MCS7703: the device * never answers the data/status stage, so the requester sleeps in the * "WXFER" loop until the timeout fires (usb_request.c:642-644, 699-704) * and the request returns USB_ERR_TIMEOUT -- which production umoscom * discards at every call site (umoscom.c:535-536, 551-552). */ static int mo_one_request(void) { lksleep(&mo_lock, &mo_lock, 0, "WXFER", USB_MS_TO_TICKS(mo_req_ms)); return (0); /* production: even a timeout is ignored */ } /* umoscom_cfg_param()'s 4-request chain (umoscom.c:441-493), runs on sc_tq */ static void mo_cfg_param(struct usb_proc_msg *pm) { int i; kprintf("MO5456: cfg-param task: enter, %d x %d ms sync EP0 requests%s\n", MO_PARAM_REQS, mo_req_ms, mo_fixed ? " (fix: abort on first error)" : ""); mo_aborted = 0; for (i = 0; i < MO_PARAM_REQS; ++i) { mo_one_request(); /* the request that times out */ if (mo_fixed) { /* * fix.diff mechanism: requests propagate the error, * cfg chain bails on first failure. With the silent * device request #1 fails after its timeout. */ kprintf("MO5456: cfg-param: request %d/%d failed " "(USB_ERR_TIMEOUT) -> abort chain (fixed)\n", i + 1, MO_PARAM_REQS); mo_aborted = 1; break; } } /* ucom_cfg_param()'s trailing pause, usb_serial.c:1636 */ usb_pause_mtx(&mo_lock, hz / 10); kprintf("MO5456: cfg-param task: leave (%d/%d requests issued)\n", mo_aborted ? 1 : MO_PARAM_REQS, MO_PARAM_REQS); } /* umoscom_cfg_open()'s 5-request chain (umoscom.c:361-384), runs on sc_tq */ static void mo_cfg_open(struct usb_proc_msg *pm) { int i; kprintf("MO5456: cfg-open task: enter, %d x %d ms sync EP0 requests%s\n", MO_OPEN_REQS, mo_req_ms, mo_fixed ? " (fix: abort on first error)" : ""); for (i = 0; i < MO_OPEN_REQS; ++i) { mo_one_request(); /* the request that times out */ if (mo_fixed) { kprintf("MO5456: cfg-open: request %d/%d failed " "(USB_ERR_TIMEOUT) -> abort chain (fixed)\n", i + 1, MO_OPEN_REQS); break; } } /* ucom_cfg_open()'s trailing pause, usb_serial.c:777 */ usb_pause_mtx(&mo_lock, hz / 10); kprintf("MO5456: cfg-open task: leave\n"); } /* * The first-open line-state task (usb_serial.c:874-878 coalesced via * 1384-1420): DTR=1, RTS=1, BREAK=0 -> 3 x umoscom_cfg_write. */ static void mo_cfg_line(struct usb_proc_msg *pm) { int i; kprintf("MO5456: line-state task: enter, %d x %d ms sync EP0 requests " "(DTR, RTS, BREAK-off)\n", MO_LINE_REQS, mo_req_ms); for (i = 0; i < MO_LINE_REQS; ++i) { mo_one_request(); if (mo_fixed) { kprintf("MO5456: line-state: request %d/%d failed " "(USB_ERR_TIMEOUT) -> abort chain (fixed)\n", i + 1, MO_LINE_REQS); break; } } kprintf("MO5456: line-state task: leave (no core pause)\n"); } /* umoscom_cfg_get_status()'s 2-request read chain (umoscom.c:495-522) */ static void mo_cfg_status(struct usb_proc_msg *pm) { int i; kprintf("MO5456: cfg-status task: enter, %d x %d ms sync EP0 requests " "(LSR, MSR reads)\n", MO_STATUS_REQS, mo_req_ms); for (i = 0; i < MO_STATUS_REQS; ++i) { mo_one_request(); if (mo_fixed) { kprintf("MO5456: cfg-status: request %d/%d failed " "(USB_ERR_TIMEOUT) -> abort chain (fixed)\n", i + 1, MO_STATUS_REQS); break; } } kprintf("MO5456: cfg-status task: leave (no core pause)\n"); } /* umoscom_cfg_close(): a no-op (umoscom.c:386-390) -- the closer waits * out whatever is queued in front of it, nothing else. */ static void mo_cfg_close(struct usb_proc_msg *pm) { kprintf("MO5456: cfg-close task: enter/leave (umoscom_cfg_close is a " "no-op: 0 requests)\n"); } /* * Exactly ucom_close()'s synchronous close (usb_serial.c:671-672 + * 955-957): queue cfg_close behind the running/queued cfg tasks and mwait * uninterruptibly (usb_process.c:385-393). */ static int64_t mo_closer_thread(int phase, int nparam) { struct timeval t0, t1; char tag = phase == 2 ? 'B' : (phase == 3 ? 'C' : (nparam > 1 ? '2' : 'A')); /* the open chain tasks are running; the first starts immediately */ tsleep(&mo_tq, 0, "molead", hz / 10); /* 100 ms into the chain */ kprintf("MO5456[%c]: closer: queue cfg_close + usb_proc_mwait() " "(uninterruptible, usb_serial.c:671-672) behind first-open chain" "%s\n", tag, nparam > 1 ? " + 1 extra tcsetattr" : ""); microtime(&t0); lockmgr(&mo_lock, LK_EXCLUSIVE); if (!usb_proc_is_gone(&mo_tq)) { struct mo_msg *m; m = usb_proc_msignal(&mo_tq, &mo_close[0], &mo_close[1]); m->hdr.pm_callback = &mo_cfg_close; /* usb_serial.c:671-672 */ usb_proc_mwait(&mo_tq, &mo_close[0], &mo_close[1]); } lockmgr(&mo_lock, LK_RELEASE); microtime(&t1); kprintf("MO5456[%c]: closer: unblocked ELAPSED=%jd ms\n", tag, (intmax_t)mo_ms(&t0, &t1)); return (mo_ms(&t0, &t1)); } /* * The open(2) path, production queueing order (usb_serial.c:842 param, * 865 cfg_open, 874-878 line-state, 880 status-change). */ static void mo_open_chain(int extra_params) { struct mo_msg *m; lockmgr(&mo_lock, LK_EXCLUSIVE); /* ucom_open():842 -> ucom_param() queues cfg_param first */ m = usb_proc_msignal(&mo_tq, &mo_param[0], &mo_param[1]); m->hdr.pm_callback = &mo_cfg_param; /* :865 cfg_open */ m = usb_proc_msignal(&mo_tq, &mo_open_msg[0], &mo_open_msg[1]); m->hdr.pm_callback = &mo_cfg_open; /* :874-878 DTR|RTS + ring-off + break-off -> one line-state task */ m = usb_proc_msignal(&mo_tq, &mo_line[0], &mo_line[1]); m->hdr.pm_callback = &mo_cfg_line; /* :880 ucom_status_change() */ m = usb_proc_msignal(&mo_tq, &mo_status[0], &mo_status[1]); m->hdr.pm_callback = &mo_cfg_status; /* the local user's extra tcsetattr(s) queue behind the open chain */ while (extra_params--) { m = usb_proc_msignal(&mo_tq, &mo_param[0], &mo_param[1]); m->hdr.pm_callback = &mo_cfg_param; } lockmgr(&mo_lock, LK_RELEASE); } static int mo_phase(int phase, int nparam) { int error; memset(&mo_tq, 0, sizeof(mo_tq)); error = usb_proc_create(&mo_tq, &mo_lock, phase == 2 ? "mo5456b" : (phase == 3 ? "mo5456c" : "mo5456a"), USB_PRI_MED); if (error) { kprintf("MO5456: usb_proc_create failed: %d\n", error); return (error); } mo_fixed = (phase >= 2); mo_req_ms = (phase == 3) ? 250 : MO_REQ_MS; /* the user opens the tty (queues param+open+line+status) */ mo_open_chain(nparam - 1); /* the closing thread (or the hub event thread on unplug) */ mo_closer_thread(phase, nparam); usb_proc_free(&mo_tq); return (0); } static int mo_modevent(module_t mod, int type, void *data) { int error = 0; switch (type) { case MOD_LOAD: lockinit(&mo_lock, "mo5456", 0, LK_CANRECURSE); kprintf("MO5456: DF-5456 umoscom cfg-chain stall harness, " "hz=%d, %d reqs/param-task, %d reqs/open-task, " "%d reqs/line-task, %d reqs/status-task, 0 reqs/close-task" " (no-op), %d ms/request (production timeout)\n", hz, MO_PARAM_REQS, MO_OPEN_REQS, MO_LINE_REQS, MO_STATUS_REQS, MO_REQ_MS); mo_phase(0, 1); /* A : first-open + close ~14.1 s */ mo_phase(1, 2); /* A2: + 1 extra tcsetattr ~18.2 s */ mo_phase(2, 1); /* B : fix #1 (abort) ~4.1 s */ mo_phase(3, 1); /* C : fix #1+#2 (abort+250ms) ~1.1 s */ lockuninit(&mo_lock); kprintf("MO5456: harness complete\n"); break; case MOD_UNLOAD: break; default: error = EOPNOTSUPP; break; } return (error); } static moduledata_t mo_mod = { "umoscomcfgstall", mo_modevent, 0 }; DECLARE_MODULE(umoscomcfgstall, mo_mod, SI_SUB_DRIVERS, SI_ORDER_MIDDLE); MODULE_DEPEND(umoscomcfgstall, usb, 1, 1, 1);