⬢ DragonFlyBSD Kernel Audit
DF-5504 / ucycom_cfgstall_harness.c
← back to finding ↓ download raw
/*
 * DF-5504 KLD harness -- production-code demonstration of the ucycom
 * (Cypress CY7C63743/CY7C64013, DeLorme Earthmate) cfg-path
 * synchronous-request stall.
 *
 * EVIDENCE CLASS: KLD-harness-with-production-code (no Cypress device
 * model exists on the guest).  Every function between the ucom taskqueue
 * and the EP0 sink is VERBATIM production code, extracted at build time
 * by build.sh from the guest's own /usr/src tree (md5-gated), with the
 * single EP0 entry point (usbd_do_request_proc, the expansion target of
 * the ucom_cfg_do_request macro, usb_serial.h:220-221) replaced by an
 * evil-device model.
 *
 * WHAT IT PROVES (verbatim code paths, real usb_process machinery):
 *
 *   ucycom_cfg_open()  (ucycom.c:299-306)  -> ucycom_cfg_write()
 *   ucycom_cfg_param() (ucycom.c:474-507)  -> ucycom_cfg_write()
 *   ucycom_cfg_write() (ucycom.c:412-444) issues ONE synchronous EP0
 *   SET_REPORT(feature) via
 *       ucom_cfg_do_request(sc->sc_udev, ..., 0, 1000)   (ucycom.c:438)
 *   -- 1000 ms timeout -- and DISCARDS the usb_error_t result
 *   ("device request failed, err=%s (ignored)", ucycom.c:440-443).
 *
 *   The core task wrappers add hz/10 after each callback
 *   (usb_serial.c:777 for cfg_open, :1636 for cfg_param), so:
 *       first open(2)   ~= 1000 + 100 ms of sc_tq occupancy
 *       each tcsetattr  ~= 1000 + 100 ms of sc_tq occupancy
 *       close(2)        issues ZERO EP0 requests for ucycom (no
 *                       ucom_cfg_close callback) but is SYNCHRONOUS:
 *                       ucom_close -> ucom_queue_command(ucom_cfg_close)
 *                       -> usb_proc_mwait() (usb_serial.c:671-672,
 *                       955-957) blocks uninterruptibly
 *                       (usb_process.c:385-393) behind every queued
 *                       cfg_open/cfg_param task.
 *   Unplug mid-cycle stalls the USB hub event thread identically via
 *   ucom_detach() -> usb_proc_drain() (usb_serial.c:394).
 *
 *   An evil Earthmate (only VID:PID in the table, ucycom.c:177-179) that
 *   never answers the control data/status stage makes each request eat
 *   its full 1000 ms (usb_request.c WXFER loop + timeout); a device that
 *   answers at 950 ms makes every request SUCCEED -- so propagating the
 *   error (the DF-5425 "abort chain" fix) is USELESS for ucycom: there
 *   is only one request per task and it may not even fail.  The only
 *   in-file lever is bounding the timeout (UCYCOM_CFG_TIMEOUT 250,
 *   modeled here from the sed-fixed extraction, phase C).
 *
 * PHASES (closer thread leads 100 ms into the chain, DF-5425 pattern):
 *   A  first-open + 1 tcsetattr + close, silent device
 *      tasks: cfg_param(no-op, LL_READY not yet set, usb_serial.c:1626)
 *             + cfg_open(1100ms) + cfg_param(1100ms) + cfg_close(0)
 *      EXPECT closer ELAPSED ~= 2100 ms
 *   2  first-open + 2 tcsetattr + close, silent device
 *      EXPECT ~= 3200 ms
 *   S  first-open + 1 tcsetattr + close, device answers at 950 ms
 *      (all requests SUCCEED -> no error to propagate)
 *      EXPECT ~= 2000 ms (occupancy unchanged by any abort-on-error fix)
 *   C  fix modeled: extraction of ucycom_cfg_write/cfg_open/cfg_param
 *      with `0, 1000' -> `0, UCYCOM_CFG_TIMEOUT(250)', silent device
 *      EXPECT ~= 600 ms
 */

#include <sys/param.h>
#include <sys/systm.h>
#include <sys/kernel.h>
#include <sys/module.h>
#include <sys/lock.h>
#include <sys/condvar.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/bus.h>

#include <bus/u4b/usb.h>
#include <bus/u4b/usbdi.h>
#include <bus/u4b/usbdi_util.h>		/* usbd_do_request_proc proto */
#include <bus/u4b/usbhid.h>		/* UHID_*_REPORT, UR_SET_REPORT */
#define	USB_DEBUG_VAR usb_debug
#include <bus/u4b/usb_debug.h>
#include <bus/u4b/usb_process.h>
#include <bus/u4b/serial/usb_serial.h>

/*=====================================================================
 * VERBATIM production code, extracted by build.sh from the guest's
 * /usr/src tree (see extract.sh): see block comment above for ranges.
 *=====================================================================*/
/*
 * The one core wrapper the verbatim ucom_queue_command references but
 * this harness does not run: usb_serial.c:712-736 ucom_cfg_start_transfers
 * only flips UCOM_FLAG_GP_DATA and calls the start_read/start_write
 * callbacks (real USB xfers) -- zero EP0 requests, zero pauses, zero
 * occupancy; the symbol must exist for the fn == comparison at
 * usb_serial.c:678.
 */
static void	ucom_cfg_start_transfers(struct usb_proc_msg *_task);

#include "uc5504_ucycom.inc"		/* ucycom.c verbatim */
#include "uc5504_fixed.inc"		/* fix-modeled extraction (250 ms) */
#include "uc5504_core.inc"		/* usb_serial.c verbatim wrappers */

static void
ucom_cfg_start_transfers(struct usb_proc_msg *_task)
{
	/* not reached by the harness (start task never queued) */
}

/*=====================================================================
 * Evil-device model for the single interposed EP0 entry point.
 * ucom_cfg_do_request(udev, com, req, ptr, flags, timo) expands to
 * usbd_do_request_proc(udev, &com->sc_super->sc_tq, req, ptr, flags,
 * NULL, timo) -- usb_serial.h:220-221.  The real implementation lives at
 * usb_request.c:760; the request it forwards carries the 1000 ms timeout
 * the driver passed, and its usb_error_t return is discarded by the
 * verbatim ucycom_cfg_write (ucycom.c:440-443).
 *=====================================================================*/
static int uc_slowanswer;	/* 0: silent (timeout), 1: answers at timo-50 */
static int uc_reqs;
static struct ucycom_softc uc_sc;	/* declared early: the sink sleeps on its lock */

usb_error_t
usbd_do_request_proc(struct usb_device *udev, struct usb_process *pproc,
    struct usb_device_request *req, void *data, uint16_t flags,
    uint16_t *actlen, usb_timeout_t timeout)
{
	int slp;

	uc_reqs++;
	kprintf("UC5504:   EP0 -> bmRequestType=0x%02x bRequest=0x%02x "
	    "(UR_SET_REPORT) wValue=0x%02x%02x wIndex=%d wLength=%d, "
	    "timo=%d ms, evil=%s\n",
	    req->bmRequestType, req->bRequest,
	    req->wValue[1], req->wValue[0],
	    req->wIndex[0],
	    (req->wLength[1] << 8) | req->wLength[0],
	    timeout,
	    uc_slowanswer ? "answers at timo-50 (SUCCESS)" :
	    "silent -> USB_ERR_TIMEOUT (discarded, ucycom.c:440-443)");

	/* the real requester sleeps in the WXFER loop for the timeout */
	slp = uc_slowanswer ? (timeout - 50) : timeout;
	if (slp > 0)
		lksleep(&uc_reqs, &uc_sc.sc_lock, 0, "WXFER",
		    USB_MS_TO_TICKS(slp));

	/*
	 * Silent device: timeout fires (usb_request.c timeout path).
	 * The verbatim ucycom_cfg_write ignores it and the taskqueue
	 * marches on.
	 */
	return (uc_slowanswer ? 0 : USB_ERR_TIMEOUT);
}

/*=====================================================================
 * Harness glue.  sc_softc is zeroed like the M_ZERO newbus softc
 * (subr_bus.c:1953); sc_lock is initialized exactly like
 * ucycom_attach (ucycom.c:214).
 *=====================================================================*/
/*
 * ucycom.c:143-152 callback table, cfg-relevant members only: the
 * transfer-lifecycle callbacks (start/stop read/write, poll) are what
 * the omitted ucom_cfg_start_transfers task would invoke on real USB
 * xfers; they contribute no EP0 request and no occupancy, so the start
 * task is not queued by this harness (noted where it would be).
 */
static const struct ucom_callback uc_cb_base = {
	.ucom_cfg_param = &ucycom_cfg_param,
	.ucom_cfg_open = &ucycom_cfg_open,
	.ucom_pre_param = &ucycom_pre_param,
};

static const struct ucom_callback uc_cb_fixed = {
	.ucom_cfg_param = &ucycom_cfg_param_f,
	.ucom_cfg_open = &ucycom_cfg_open_f,
	.ucom_pre_param = &ucycom_pre_param,
};

static int64_t
uc_ms(struct timeval *t0, struct timeval *t1)
{
	return ((int64_t)(t1->tv_sec - t0->tv_sec) * 1000 +
	    (t1->tv_usec - t0->tv_usec) / 1000);
}

/*
 * The user activity: first open(2) (usb_serial.c:829-872 shape: queues
 * cfg_param from the line-842 ucom_param call, then cfg_open at
 * 865-867; the start task at 870-872 is omitted, see above) followed by
 * n_ts tcsetattr(2)s (usb_serial.c:1690-1693 shape).  All of it goes
 * through the VERBATIM ucom_queue_command with the production
 * double-buffered task slots.
 */
static void
uc_user_activity(int n_ts, int fixed)
{
	struct termios t;
	const struct ucom_callback *cb = fixed ? &uc_cb_fixed : &uc_cb_base;

	memset(&t, 0, sizeof(t));
	t.c_ospeed = 4800;			/* UCYCOM_DEFAULT_RATE */
	t.c_cflag = CS8;			/* N-8-1 */

	lockmgr(&uc_sc.sc_lock, LK_EXCLUSIVE);
	uc_sc.sc_ucom.sc_callback = cb;
	uc_sc.sc_ucom.sc_flag |= UCOM_FLAG_HL_READY;	/* usb_serial.c:829 */

	/* usb_serial.c:842 -> ucom_param tail (1678-1693), pre_param verbatim */
	KKASSERT(ucycom_pre_param(&uc_sc.sc_ucom, &t) == 0);
	ucom_queue_command(&uc_sc.sc_ucom, ucom_cfg_param, &t,
	    &uc_sc.sc_ucom.sc_param_task[0].hdr,
	    &uc_sc.sc_ucom.sc_param_task[1].hdr);

	/* usb_serial.c:865-867 */
	ucom_queue_command(&uc_sc.sc_ucom, ucom_cfg_open, NULL,
	    &uc_sc.sc_ucom.sc_open_task[0].hdr,
	    &uc_sc.sc_ucom.sc_open_task[1].hdr);

	/* usb_serial.c:870-872 would queue ucom_cfg_start_transfers here:
	 * zero EP0 requests, zero pauses -- omitted (it touches xfers). */

	while (n_ts--)				/* the user's tcsetattr(s) */
		ucom_queue_command(&uc_sc.sc_ucom, ucom_cfg_param, &t,
		    &uc_sc.sc_ucom.sc_param_task[0].hdr,
		    &uc_sc.sc_ucom.sc_param_task[1].hdr);
	lockmgr(&uc_sc.sc_lock, LK_RELEASE);
}

/*
 * close(2): the VERBATIM ucom_queue_command(ucom_cfg_close) performs the
 * synchronous uninterruptible usb_proc_mwait at usb_serial.c:671-672.
 */
static int64_t
uc_closer(char tag)
{
	struct timeval t0, t1;

	/* lead 100 ms into the first task (DF-5425 harness pattern) */
	tsleep(&uc_sc, 0, "uclead", hz / 10);

	kprintf("UC5504[%c]: closer: queue cfg_close + usb_proc_mwait() "
	    "(uninterruptible, usb_serial.c:671-672)\n", tag);
	microtime(&t0);
	lockmgr(&uc_sc.sc_lock, LK_EXCLUSIVE);
	if (!usb_proc_is_gone(&uc_sc.sc_super_ucom.sc_tq)) {
		ucom_queue_command(&uc_sc.sc_ucom, ucom_cfg_close, NULL,
		    &uc_sc.sc_ucom.sc_close_task[0].hdr,
		    &uc_sc.sc_ucom.sc_close_task[1].hdr);
	}
	lockmgr(&uc_sc.sc_lock, LK_RELEASE);
	microtime(&t1);
	kprintf("UC5504[%c]: closer: unblocked  ELAPSED=%jd ms "
	    "(%d EP0 requests burned)\n", tag, (intmax_t)uc_ms(&t0, &t1),
	    uc_reqs);
	return (uc_ms(&t0, &t1));
}

static int
uc_phase(char tag, const char *name, int n_ts, int fixed, int slowanswer)
{
	char tqname[8];

	/* fresh softc, exactly like the zeroed newbus softc (subr_bus.c:1953) */
	memset(&uc_sc, 0, sizeof(uc_sc));
	ksnprintf(tqname, sizeof(tqname), "uc4%c", tag);
	lockinit(&uc_sc.sc_lock, tqname, 0, LK_CANRECURSE);	/* ucycom.c:214 */

	/* Earthmate: MODEL_CY7C64013 (ucycom.c:178), 32B-class reports */
	uc_sc.sc_model = MODEL_CY7C64013;
	uc_sc.sc_ilen = 32;
	uc_sc.sc_olen = 32;
	uc_sc.sc_flen = 32;		/* -> cfg_write sends min(32,32)=32B */
	uc_sc.sc_fid = 0;
	uc_sc.sc_iface_no = 0;

	/* ucom_attach (usb_serial.c:310,322) shape */
	uc_sc.sc_ucom.sc_lock = &uc_sc.sc_lock;
	uc_sc.sc_ucom.sc_super = &uc_sc.sc_super_ucom;
	uc_sc.sc_ucom.sc_parent = &uc_sc;
	if (usb_proc_create(&uc_sc.sc_super_ucom.sc_tq, &uc_sc.sc_lock,
	    tqname, USB_PRI_MED)) {
		kprintf("UC5504: usb_proc_create failed\n");
		lockuninit(&uc_sc.sc_lock);
		return (-1);
	}
	uc_slowanswer = slowanswer;
	uc_reqs = 0;

	kprintf("UC5504[%c]: === phase %s: first open + %d tcsetattr(s) + "
	    "close, %s device%s\n", tag, name, n_ts,
	    slowanswer ? "answers-at-950ms" : "silent",
	    fixed ? ", UCYCOM_CFG_TIMEOUT=250 fix modeled" : "");

	uc_user_activity(n_ts, fixed);
	uc_closer(tag);

	usb_proc_free(&uc_sc.sc_super_ucom.sc_tq);
	lockuninit(&uc_sc.sc_lock);
	return (0);
}

static int
uc_modevent(module_t mod, int type, void *data)
{
	int error = 0;

	switch (type) {
	case MOD_LOAD:
		kprintf("UC5504: DF-5504 ucycom cfg-stall harness (verbatim "
		    "extraction, hz=%d); ucycom chain shape: 1x1000ms EP0 per "
		    "cfg_open/cfg_param task + hz/10 core pause\n", hz);

		uc_phase('A', "A (baseline)", 1, 0, 0);	/* ~2.1 s */
		uc_phase('2', "A2 (2 tcsetattrs)", 2, 0, 0);	/* ~3.2 s */
		uc_phase('S', "S (slow-answer: no error to propagate)",
		    1, 0, 1);				/* ~2.0 s */
		uc_phase('C', "C (fix: 250 ms cfg timeout)", 1, 1, 0);
							/* ~0.6 s */
		kprintf("UC5504: harness complete\n");
		break;
	case MOD_UNLOAD:
		break;
	default:
		error = EOPNOTSUPP;
		break;
	}
	return (error);
}

static moduledata_t uc_mod = { "ucycomcfgstall", uc_modevent, 0 };
DECLARE_MODULE(ucycomcfgstall, uc_mod, SI_SUB_DRIVERS, SI_ORDER_MIDDLE);
MODULE_DEPEND(ucycomcfgstall, usb, 1, 1, 1);