⬢ DragonFlyBSD Kernel Audit
DF-5367 / ufoma_drain_harness.c
← back to finding ↓ download raw
/*
 * DF-5367 KLD harness -- production-code demonstration of the ufoma
 * detach-stall mechanism.
 *
 * WHAT IT PROVES (with the real in-kernel u4b usb_process machinery, the
 * same code ufoma_detach() goes through):
 *
 *   ufoma.c:846  ufoma_cfg_close()
 *     -> ufoma.c:534 ufoma_cfg_activate_state()
 *        -> ufoma.c:549-550  cv_timedwait(&sc->sc_cv, &sc->sc_lock,
 *                                          UFOMA_MAX_TIMEOUT * hz)   [15 s]
 *   with the device gone: the only cv_signal() source is
 *   ufoma_intr_callback() (ufoma.c:696) and on unplug the intr xfer is
 *   merely cancelled (ufoma.c:601/647/759) -- nobody signals sc_cv.
 *
 *   unplug -> ufoma_detach() (ufoma.c:476)
 *     -> ucom_detach()  (usb_serial.c:367) -> usb_proc_drain() at
 *        usb_serial.c:394 -> usb_process.c:406-452: drain sets up_gone and
 *        sleeps on up_cv until the process *thread exits*; the thread
 *        (usb_process.c:146-170) cannot observe up_gone while blocked
 *        inside the callback's cv_timedwait -- so the detach path (the USB
 *        hub event thread) is stalled for the remainder of the 15 s.
 *
 * PHASE A (baseline): queue a cfg task that does exactly
 *   cv_timedwait(cv, lock, 15*hz)  -- ufoma.c:549 verbatim pattern --
 *   wait 2 s (the "unplug"), then call usb_proc_drain() and measure.
 *   EXPECT: drain blocks ~13 s (the remainder of the 15 s wait).
 *
 * PHASE B (fix mechanism, mirrors fix.diff): the task slices the wait into
 *   1 s chunks and aborts on a dying flag; the "detach" path broadcasts the
 *   cv before draining.  EXPECT: drain returns in ~0 s.
 */
#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/usb_process.h>

#define HX_WAIT_S	15		/* == UFOMA_MAX_TIMEOUT, ufoma.c:141 */
#define HX_LEADIN_S	2		/* unplug this many seconds into the wait */

static struct lock hx_lock;		/* stands in for sc->sc_lock */
static struct cv hx_cv;			/* stands in for sc->sc_cv */
static struct usb_process hx_tq;	/* stands in for sc_super_ucom.sc_tq */
static uint8_t hx_dying;		/* stands in for the fix's sc_dying */

struct hx_msg {
	struct usb_proc_msg hdr;
};
static struct hx_msg hx_msgs[2];

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

/* exactly ufoma_cfg_activate_state()'s wait (ufoma.c:549-550) */
static void
hx_cfg_task(struct usb_proc_msg *pm)
{
	kprintf("HX[A] cfg-task: enter t=%jd, cv_timedwait(%d*hz), "
	    "no abort on gone\n", (intmax_t)time_second, HX_WAIT_S);
	cv_timedwait(&hx_cv, &hx_lock, HX_WAIT_S * hz);
	kprintf("HX[A] cfg-task: leave t=%jd\n", (intmax_t)time_second);
}

/* the fixed pattern: 1 s slices + dying abort (fix.diff) */
static void
hx_cfg_task_fixed(struct usb_proc_msg *pm)
{
	int i;

	kprintf("HX[B] cfg-task(fixed): enter t=%jd, 1s slices + dying\n",
	    (intmax_t)time_second);
	for (i = 0; (i < HX_WAIT_S) && !hx_dying; i++) {
		if (cv_timedwait(&hx_cv, &hx_lock, hz) == 0)
			break;			/* woken (ACK or detach) */
	}
	kprintf("HX[B] cfg-task(fixed): leave t=%jd dying=%d\n",
	    (intmax_t)time_second, hx_dying);
}

static void
hx_queue(usb_proc_callback_t *fn)
{
	struct hx_msg *m;

	lockmgr(&hx_lock, LK_EXCLUSIVE);
	if (usb_proc_is_gone(&hx_tq)) {
		lockmgr(&hx_lock, LK_RELEASE);
		kprintf("HX: proc already gone?!\n");
		return;
	}
	/* same pattern as ucom_queue_command() (usb_serial.c:635-659) */
	m = usb_proc_msignal(&hx_tq, &hx_msgs[0], &hx_msgs[1]);
	m->hdr.pm_callback = fn;
	lockmgr(&hx_lock, LK_RELEASE);
}

static void
hx_phase(int fixed)
{
	struct timeval t0, t1;
	int error;

	memset(&hx_tq, 0, sizeof(hx_tq));
	error = usb_proc_create(&hx_tq, &hx_lock, fixed ? "hxfix" : "hxbase",
	    USB_PRI_MED);
	if (error) {
		kprintf("HX: usb_proc_create failed: %d\n", error);
		return;
	}
	hx_dying = 0;

	if (fixed)
		hx_queue(hx_cfg_task_fixed);
	else
		hx_queue(hx_cfg_task);

	/* the device is unplugged HX_LEADIN_S seconds into the wait */
	tsleep(&hx_tq, 0, "hxlead", HX_LEADIN_S * hz);

	if (fixed) {
		/* fixed ufoma_detach(): wake cfg waiters first */
		lockmgr(&hx_lock, LK_EXCLUSIVE);
		hx_dying = 1;
		cv_broadcast(&hx_cv);
		lockmgr(&hx_lock, LK_RELEASE);
	}

	kprintf("HX[%c] unplug done, usb_proc_drain() begin t=%jd\n",
	    fixed ? 'B' : 'A', (intmax_t)time_second);
	microtime(&t0);
	usb_proc_drain(&hx_tq);		/* == ucom_detach() usb_serial.c:394 */
	microtime(&t1);
	kprintf("HX[%c] usb_proc_drain() done t=%jd  ELAPSED=%jd ms "
	    "(expected ~%d000 ms baseline / ~0 ms fixed)\n",
	    fixed ? 'B' : 'A', (intmax_t)time_second,
	    hx_ms(&t0, &t1), HX_WAIT_S - HX_LEADIN_S);

	usb_proc_free(&hx_tq);
}

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

	switch (type) {
	case MOD_LOAD:
		lockinit(&hx_lock, "hxlk", 0, LK_CANRECURSE);
		cv_init(&hx_cv, "hxcv");

		kprintf("HX: DF-5367 ufoma detach-stall harness, hz=%d\n", hz);
		hx_phase(0);		/* A: baseline stall */
		hx_phase(1);		/* B: fix mechanism */

		cv_destroy(&hx_cv);
		lockuninit(&hx_lock);
		kprintf("HX: harness complete\n");
		break;
	case MOD_UNLOAD:
		break;
	default:
		error = EOPNOTSUPP;
		break;
	}
	return (error);
}

static moduledata_t hx_mod = { "ufoharness", hx_modevent, 0 };
DECLARE_MODULE(ufoharness, hx_mod, SI_SUB_DRIVERS, SI_ORDER_MIDDLE);
MODULE_DEPEND(ufoharness, usb, 1, 1, 1);