From b97c024cbff4699b570cdfeca11031f9af3465df Mon Sep 17 00:00:00 2001 From: Taylor R Campbell Date: Sun, 16 Feb 2020 21:53:45 +0000 Subject: [PATCH 1/6] Abort default pipe too on detach before detaching children. This ensures that pending xfers on the default pipe will be aborted before we wait for children, which, in the case of scsibus -> sd, means waiting for pending xfers to complete -- xfers that may never complete if something is wedged. --- sys/dev/usb/umass.c | 1 + 1 file changed, 1 insertion(+) diff --git a/sys/dev/usb/umass.c b/sys/dev/usb/umass.c index d06c7bf5434e..e06e53375b75 100644 --- a/sys/dev/usb/umass.c +++ b/sys/dev/usb/umass.c @@ -809,6 +809,7 @@ umass_detach(device_t self, int flags) if (sc->sc_pipe[i] != NULL) usbd_abort_pipe(sc->sc_pipe[i]); } + usbd_abort_default_pipe(sc->sc_udev); /* Do we really need reference counting? Perhaps in ioctl() */ mutex_enter(&sc->sc_lock); From ff8ffc5b40c06d00c012e3a78464171205bdf4c7 Mon Sep 17 00:00:00 2001 From: Taylor R Campbell Date: Sun, 16 Feb 2020 21:56:12 +0000 Subject: [PATCH 2/6] Gracefully handle completion interrupt when ep->xfer is NULL. --- sys/dev/usb/motg.c | 58 ++++++++++++++++++++++++++++------------------ 1 file changed, 35 insertions(+), 23 deletions(-) diff --git a/sys/dev/usb/motg.c b/sys/dev/usb/motg.c index db014c87c7b3..e0892271ec79 100644 --- a/sys/dev/usb/motg.c +++ b/sys/dev/usb/motg.c @@ -1428,12 +1428,15 @@ motg_device_ctrl_intr_rx(struct motg_softc *sc) KASSERT(mutex_owned(&sc->sc_lock)); - /* - * Try to claim this xfer for completion. If it has already - * completed or aborted, drop it on the floor. - */ - if (!usbd_xfer_trycomplete(xfer)) - return; + if (xfer) { + /* + * Try to claim this xfer for completion. If it has + * already completed or aborted, drop it on the floor. + */ + if (!usbd_xfer_trycomplete(xfer)) + return; + KASSERT(xfer->ux_status == USBD_IN_PROGRESS); + } KASSERT(ep->phase == DATA_IN || ep->phase == STATUS_IN); /* select endpoint 0 */ @@ -1466,7 +1469,7 @@ motg_device_ctrl_intr_rx(struct motg_softc *sc) if ((csr & MUSB2_MASK_CSR0L_RXPKTRDY) == 0) return; /* no data yet */ - if (xfer == NULL || xfer->ux_status != USBD_IN_PROGRESS) + if (xfer == NULL) goto complete; if (ep->phase == STATUS_IN) { @@ -1528,7 +1531,8 @@ motg_device_ctrl_intr_rx(struct motg_softc *sc) complete: ep->phase = IDLE; ep->xfer = NULL; - if (xfer && xfer->ux_status == USBD_IN_PROGRESS) { + if (xfer) { + KASSERT(xfer->ux_status == USBD_IN_PROGRESS); KASSERT(new_status != USBD_IN_PROGRESS); xfer->ux_status = new_status; usb_transfer_complete(xfer); @@ -1550,12 +1554,15 @@ motg_device_ctrl_intr_tx(struct motg_softc *sc) KASSERT(mutex_owned(&sc->sc_lock)); - /* - * Try to claim this xfer for completion. If it has already - * completed or aborted, drop it on the floor. - */ - if (!usbd_xfer_trycomplete(xfer)) - return; + if (xfer) { + /* + * Try to claim this xfer for completion. If it has + * already completed or aborted, drop it on the floor. + */ + if (!usbd_xfer_trycomplete(xfer)) + return; + KASSERT(xfer->ux_status == USBD_IN_PROGRESS); + } if (ep->phase == DATA_IN || ep->phase == STATUS_IN) { motg_device_ctrl_intr_rx(sc); @@ -1675,7 +1682,8 @@ motg_device_ctrl_intr_tx(struct motg_softc *sc) complete: ep->phase = IDLE; ep->xfer = NULL; - if (xfer && xfer->ux_status == USBD_IN_PROGRESS) { + if (xfer) { + KASSERT(xfer->ux_status == USBD_IN_PROGRESS); KASSERT(new_status != USBD_IN_PROGRESS); xfer->ux_status = new_status; usb_transfer_complete(xfer); @@ -2076,12 +2084,15 @@ motg_device_intr_tx(struct motg_softc *sc, int epnumber) KASSERT(mutex_owned(&sc->sc_lock)); - /* - * Try to claim this xfer for completion. If it has already - * completed or aborted, drop it on the floor. - */ - if (!usbd_xfer_trycomplete(xfer)) - return; + if (xfer) { + /* + * Try to claim this xfer for completion. If it has + * already completed or aborted, drop it on the floor. + */ + if (!usbd_xfer_trycomplete(xfer)) + return; + KASSERT(xfer->ux_status == USBD_IN_PROGRESS); + } KASSERT(ep->ep_number == epnumber); @@ -2122,7 +2133,7 @@ motg_device_intr_tx(struct motg_softc *sc, int epnumber) /* data still not sent */ return; } - if (xfer == NULL || xfer->ux_status != USBD_IN_PROGRESS) + if (xfer == NULL) goto complete; KASSERT(ep->phase == DATA_OUT); @@ -2149,7 +2160,8 @@ complete: xfer, xfer->ux_status, ep->phase); ep->phase = IDLE; ep->xfer = NULL; - if (xfer && xfer->ux_status == USBD_IN_PROGRESS) { + if (xfer) { + KASSERT(xfer->ux_status == USBD_IN_PROGRESS); KASSERT(new_status != USBD_IN_PROGRESS); xfer->ux_status = new_status; usb_transfer_complete(xfer); From ca9ffecf2a2f53e7744b944472e5c5c41f3564b1 Mon Sep 17 00:00:00 2001 From: Taylor R Campbell Date: Sun, 16 Feb 2020 22:01:53 +0000 Subject: [PATCH 3/6] Consolidate logic to call the transfer callback. No functional change intended. --- sys/dev/usb/umass.c | 83 +++++++++++++++++++++------------------------ 1 file changed, 39 insertions(+), 44 deletions(-) diff --git a/sys/dev/usb/umass.c b/sys/dev/usb/umass.c index e06e53375b75..36a8c710e329 100644 --- a/sys/dev/usb/umass.c +++ b/sys/dev/usb/umass.c @@ -236,6 +236,8 @@ Static usbd_status umass_setup_ctrl_transfer(struct umass_softc *, struct usbd_xfer *); Static void umass_clear_endpoint_stall(struct umass_softc *, int, struct usbd_xfer *); +Static void umass_transfer_done(struct umass_softc *, int, int); +Static void umass_transfer_reset(struct umass_softc *); #if 0 Static void umass_reset(struct umass_softc *, transfer_cb_f, void *); #endif @@ -1009,6 +1011,26 @@ umass_clear_endpoint_stall(struct umass_softc *sc, int endpt, umass_setup_ctrl_transfer(sc, &sc->sc_req, NULL, 0, 0, xfer); } +Static void +umass_transfer_done(struct umass_softc *sc, int residue, int status) +{ + UMASSHIST_FUNC(); UMASSHIST_CALLED(); + + sc->transfer_state = TSTATE_IDLE; + sc->transfer_cb(sc, sc->transfer_priv, residue, status); +} + +Static void +umass_transfer_reset(struct umass_softc *sc) +{ + UMASSHIST_FUNC(); UMASSHIST_CALLED(); + + sc->transfer_state = TSTATE_IDLE; + if (sc->transfer_priv) + sc->transfer_cb(sc, sc->transfer_priv, sc->transfer_datalen, + sc->transfer_status); +} + #if 0 Static void umass_reset(struct umass_softc *sc, transfer_cb_f cb, void *priv) @@ -1217,8 +1239,7 @@ umass_bbb_state(struct usbd_xfer *xfer, void *priv, DPRINTFM(UDMASS_BBB, "sc %#jx xfer %#jx cancelled", (uintptr_t)sc, (uintptr_t)xfer, 0, 0); - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, 0, STATUS_TIMEOUT); + umass_transfer_done(sc, 0, STATUS_TIMEOUT); return; } @@ -1454,17 +1475,11 @@ umass_bbb_state(struct usbd_xfer *xfer, void *priv, "res = %jd", (uintptr_t)sc, residue, 0, 0); /* SCSI command failed but transfer was succesful */ - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, residue, - STATUS_CMD_FAILED); - + umass_transfer_done(sc, residue, STATUS_CMD_FAILED); return; } else { /* success */ - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, residue, - STATUS_CMD_OK); - + umass_transfer_done(sc, residue, STATUS_CMD_OK); return; } @@ -1496,12 +1511,7 @@ umass_bbb_state(struct usbd_xfer *xfer, void *priv, device_xname(sc->sc_dev), usbd_errstr(err)); /* no error recovery, otherwise we end up in a loop */ - sc->transfer_state = TSTATE_IDLE; - if (sc->transfer_priv) { - sc->transfer_cb(sc, sc->transfer_priv, - sc->transfer_datalen, - sc->transfer_status); - } + umass_transfer_reset(sc); return; @@ -1669,8 +1679,7 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, if (err == USBD_CANCELLED) { DPRINTFM(UDMASS_BBB, "sc %#jx xfer %#jx cancelled", (uintptr_t)sc, (uintptr_t)xfer, 0, 0); - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, 0, STATUS_TIMEOUT); + umass_transfer_done(sc, 0, STATUS_TIMEOUT); return; } @@ -1700,12 +1709,8 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, * Section 2.4.3.1.1 states that the bulk in endpoints * should not stalled at this point. */ - - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, - sc->transfer_datalen, - STATUS_CMD_FAILED); - + umass_transfer_done(sc, sc->transfer_datalen, + STATUS_CMD_FAILED); return; } else if (err) { DPRINTFM(UDMASS_CBI, "sc %#jx: failed to send ADSC", @@ -1794,10 +1799,9 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, /* No command completion interrupt. Request * sense to get status of command. */ - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, - sc->transfer_datalen - sc->transfer_actlen, - STATUS_CMD_UNKNOWN); + umass_transfer_done(sc, + sc->transfer_datalen - sc->transfer_actlen, + STATUS_CMD_UNKNOWN); } return; @@ -1848,9 +1852,9 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, status = STATUS_CMD_FAILED; /* No autosense, command successful */ - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, - sc->transfer_datalen - sc->transfer_actlen, status); + umass_transfer_done(sc, + sc->transfer_datalen - sc->transfer_actlen, + status); } else { int status; @@ -1875,8 +1879,7 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, break; } - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, + umass_transfer_done(sc, sc->transfer_datalen - sc->transfer_actlen, status); } @@ -1891,8 +1894,7 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, usbd_errstr(err)); umass_cbi_reset(sc, STATUS_WIRE_FAILED); } else { - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, + umass_transfer_done(sc, sc->transfer_datalen, STATUS_CMD_FAILED); } return; @@ -1903,8 +1905,7 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, device_xname(sc->sc_dev), usbd_errstr(err)); umass_cbi_reset(sc, STATUS_WIRE_FAILED); } else { - sc->transfer_state = TSTATE_IDLE; - sc->transfer_cb(sc, sc->transfer_priv, + umass_transfer_done(sc, sc->transfer_datalen, STATUS_CMD_FAILED); } return; @@ -1937,13 +1938,7 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, device_xname(sc->sc_dev), usbd_errstr(err)); /* no error recovery, otherwise we end up in a loop */ - sc->transfer_state = TSTATE_IDLE; - if (sc->transfer_priv) { - sc->transfer_cb(sc, sc->transfer_priv, - sc->transfer_datalen, - sc->transfer_status); - } - + umass_transfer_reset(sc); return; From 53c512a19bae0d2697b7803daa8cbc0f921de2f8 Mon Sep 17 00:00:00 2001 From: Taylor R Campbell Date: Sun, 16 Feb 2020 22:07:29 +0000 Subject: [PATCH 4/6] Make sure the umass transfer callback is run in error branches. --- sys/dev/usb/umass.c | 49 ++++++++++++++++++++++++++++++++++----------- 1 file changed, 37 insertions(+), 12 deletions(-) diff --git a/sys/dev/usb/umass.c b/sys/dev/usb/umass.c index 36a8c710e329..280c76b5f082 100644 --- a/sys/dev/usb/umass.c +++ b/sys/dev/usb/umass.c @@ -995,8 +995,11 @@ umass_clear_endpoint_stall(struct umass_softc *sc, int endpt, { UMASSHIST_FUNC(); UMASSHIST_CALLED(); - if (sc->sc_dying) + if (sc->sc_dying) { + umass_transfer_done(sc, sc->transfer_datalen, + STATUS_WIRE_FAILED); return; + } DPRINTFM(UDMASS_BBB, "Clear endpoint 0x%02jx stall", sc->sc_epaddr[endpt], 0, 0, 0); @@ -1008,7 +1011,9 @@ umass_clear_endpoint_stall(struct umass_softc *sc, int endpt, USETW(sc->sc_req.wValue, UF_ENDPOINT_HALT); USETW(sc->sc_req.wIndex, sc->sc_epaddr[endpt]); USETW(sc->sc_req.wLength, 0); - umass_setup_ctrl_transfer(sc, &sc->sc_req, NULL, 0, 0, xfer); + if (umass_setup_ctrl_transfer(sc, &sc->sc_req, NULL, 0, 0, xfer)) + umass_transfer_done(sc, sc->transfer_datalen, + STATUS_WIRE_FAILED); } Static void @@ -1055,8 +1060,10 @@ umass_bbb_reset(struct umass_softc *sc, int status) "sc->sc_wire == 0x%02x wrong for umass_bbb_reset\n", sc->sc_wire); - if (sc->sc_dying) + if (sc->sc_dying) { + umass_transfer_done(sc, sc->transfer_datalen, status); return; + } /* * Reset recovery (5.3.4 in Universal Serial Bus Mass Storage Class) @@ -1085,8 +1092,9 @@ umass_bbb_reset(struct umass_softc *sc, int status) USETW(sc->sc_req.wValue, 0); USETW(sc->sc_req.wIndex, sc->sc_ifaceno); USETW(sc->sc_req.wLength, 0); - umass_setup_ctrl_transfer(sc, &sc->sc_req, NULL, 0, 0, - sc->transfer_xfer[XFER_BBB_RESET1]); + if (umass_setup_ctrl_transfer(sc, &sc->sc_req, NULL, 0, 0, + sc->transfer_xfer[XFER_BBB_RESET1])) + umass_transfer_done(sc, sc->transfer_datalen, status); } Static void @@ -1104,8 +1112,10 @@ umass_bbb_transfer(struct umass_softc *sc, int lun, void *cmd, int cmdlen, "sc->sc_wire == 0x%02x wrong for umass_bbb_transfer\n", sc->sc_wire); - if (sc->sc_dying) + if (sc->sc_dying) { + cb(sc, priv, datalen, STATUS_WIRE_FAILED); return; + } /* Be a little generous. */ sc->timeout = timeout + USBD_DEFAULT_TIMEOUT; @@ -1243,8 +1253,11 @@ umass_bbb_state(struct usbd_xfer *xfer, void *priv, return; } - if (sc->sc_dying) + if (sc->sc_dying) { + umass_transfer_done(sc, sc->transfer_datalen, + STATUS_WIRE_FAILED); return; + } switch (sc->transfer_state) { @@ -1561,8 +1574,10 @@ umass_cbi_reset(struct umass_softc *sc, int status) "sc->sc_wire == 0x%02x wrong for umass_cbi_reset\n", sc->sc_wire); - if (sc->sc_dying) + if (sc->sc_dying) { + umass_transfer_done(sc, sc->transfer_datalen, status); return; + } /* * Command Block Reset Protocol @@ -1598,8 +1613,9 @@ umass_cbi_reset(struct umass_softc *sc, int status) for (i = 2; i < SEND_DIAGNOSTIC_CMDLEN; i++) sc->cbl[i] = 0xff; - umass_cbi_adsc(sc, sc->cbl, SEND_DIAGNOSTIC_CMDLEN, 0, - sc->transfer_xfer[XFER_CBI_RESET1]); + if (umass_cbi_adsc(sc, sc->cbl, SEND_DIAGNOSTIC_CMDLEN, 0, + sc->transfer_xfer[XFER_CBI_RESET1])) + umass_transfer_done(sc, sc->transfer_datalen, status); /* XXX if the command fails we should reset the port on the bub */ } @@ -1617,8 +1633,10 @@ umass_cbi_transfer(struct umass_softc *sc, int lun, "sc->sc_wire == 0x%02x wrong for umass_cbi_transfer\n", sc->sc_wire); - if (sc->sc_dying) + if (sc->sc_dying) { + cb(sc, priv, datalen, STATUS_WIRE_FAILED); return; + } /* Be a little generous. */ sc->timeout = timeout + USBD_DEFAULT_TIMEOUT; @@ -1683,8 +1701,11 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, return; } - if (sc->sc_dying) + if (sc->sc_dying) { + umass_transfer_done(sc, sc->transfer_datalen, + STATUS_WIRE_FAILED); return; + } /* * State handling for CBI transfers. @@ -1882,6 +1903,10 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, umass_transfer_done(sc, sc->transfer_datalen - sc->transfer_actlen, status); + } else { + /* XXX What to do? */ + umass_transfer_done(sc, sc->transfer_datalen, + STATUS_WIRE_FAILED); } } return; From ef76063ec969cd0be523a80bdb7db8334912df9c Mon Sep 17 00:00:00 2001 From: Taylor R Campbell Date: Sun, 16 Feb 2020 22:09:01 +0000 Subject: [PATCH 5/6] New dtrace usb provider, with a handful of probes in usb.c. --- sys/dev/usb/usb.c | 76 ++++++++++++++++++++++++++++++++++++++++++- sys/dev/usb/usb_sdt.h | 36 ++++++++++++++++++++ 2 files changed, 111 insertions(+), 1 deletion(-) create mode 100644 sys/dev/usb/usb_sdt.h diff --git a/sys/dev/usb/usb.c b/sys/dev/usb/usb.c index a5c89006d8b1..2d29edafedf5 100644 --- a/sys/dev/usb/usb.c +++ b/sys/dev/usb/usb.c @@ -65,6 +65,7 @@ __KERNEL_RCSID(0, "$NetBSD: usb.c,v 1.182 2020/02/12 15:59:44 riastradh Exp $"); #include #include #include +#include #include #include @@ -73,6 +74,7 @@ __KERNEL_RCSID(0, "$NetBSD: usb.c,v 1.182 2020/02/12 15:59:44 riastradh Exp $"); #include #include #include +#include #include "ioconf.h" @@ -155,6 +157,54 @@ struct usb_taskq { static struct usb_taskq usb_taskq[USB_NUM_TASKQS]; +/* XXX wrong place */ +#ifdef KDTRACE_HOOKS +#define __dtrace_used +#else +#define __dtrace_used __unused +#endif + +SDT_PROVIDER_DEFINE(usb); + +SDT_PROBE_DEFINE3(usb, kernel, task, add, + "struct usbd_device *"/*dev*/, "struct usb_task *"/*task*/, "int"/*q*/); +SDT_PROBE_DEFINE2(usb, kernel, task, rem__start, + "struct usbd_device *"/*dev*/, "struct usb_task *"/*task*/); +SDT_PROBE_DEFINE3(usb, kernel, task, rem__done, + "struct usbd_device *"/*dev*/, + "struct usb_task *"/*task*/, + "bool"/*removed*/); +SDT_PROBE_DEFINE4(usb, kernel, task, rem__wait__start, + "struct usbd_device *"/*dev*/, + "struct usb_task *"/*task*/, + "int"/*queue*/, + "kmutex_t *"/*interlock*/); +SDT_PROBE_DEFINE5(usb, kernel, task, rem__wait__done, + "struct usbd_device *"/*dev*/, + "struct usb_task *"/*task*/, + "int"/*queue*/, + "kmutex_t *"/*interlock*/, + "bool"/*done*/); + +SDT_PROBE_DEFINE1(usb, kernel, task, start, "struct usb_task *"/*task*/); +SDT_PROBE_DEFINE1(usb, kernel, task, done, "struct usb_task *"/*task*/); + +SDT_PROBE_DEFINE1(usb, kernel, bus, needs__explore, + "struct usbd_bus *"/*bus*/); +SDT_PROBE_DEFINE1(usb, kernel, bus, needs__reattach, + "struct usbd_bus *"/*bus*/); +SDT_PROBE_DEFINE1(usb, kernel, bus, discover__start, + "struct usbd_bus *"/*bus*/); +SDT_PROBE_DEFINE1(usb, kernel, bus, discover__done, + "struct usbd_bus *"/*bus*/); +SDT_PROBE_DEFINE1(usb, kernel, bus, explore__start, + "struct usbd_bus *"/*bus*/); +SDT_PROBE_DEFINE1(usb, kernel, bus, explore__done, + "struct usbd_bus *"/*bus*/); + +SDT_PROBE_DEFINE1(usb, kernel, event, add, "struct usb_event *"/*uep*/); +SDT_PROBE_DEFINE1(usb, kernel, event, drop, "struct usb_event *"/*uep*/); + dev_type_open(usbopen); dev_type_close(usbclose); dev_type_read(usbread); @@ -412,6 +462,7 @@ usb_add_task(struct usbd_device *dev, struct usb_task *task, int queue) struct usb_taskq *taskq; USBHIST_FUNC(); USBHIST_CALLED(usbdebug); + SDT_PROBE3(usb, kernel, task, add, dev, task, queue); KASSERT(0 <= queue); KASSERT(queue < USB_NUM_TASKQS); @@ -446,6 +497,7 @@ usb_rem_task(struct usbd_device *dev, struct usb_task *task) unsigned queue; USBHIST_FUNC(); USBHIST_CALLED(usbdebug); + SDT_PROBE2(usb, kernel, task, rem__start, dev, task); while ((queue = task->queue) != USB_NUM_TASKQS) { struct usb_taskq *taskq = &usb_taskq[queue]; @@ -454,11 +506,14 @@ usb_rem_task(struct usbd_device *dev, struct usb_task *task) TAILQ_REMOVE(&taskq->tasks, task, next); task->queue = USB_NUM_TASKQS; mutex_exit(&taskq->lock); + SDT_PROBE3(usb, kernel, task, rem__done, + dev, task, true); return true; /* removed from the queue */ } mutex_exit(&taskq->lock); } + SDT_PROBE3(usb, kernel, task, rem__done, dev, task, false); return false; /* was not removed from the queue */ } @@ -489,6 +544,8 @@ usb_rem_task_wait(struct usbd_device *dev, struct usb_task *task, int queue, bool removed; USBHIST_FUNC(); USBHIST_CALLED(usbdebug); + SDT_PROBE4(usb, kernel, task, rem__wait__start, + dev, task, queue, interlock); ASSERT_SLEEPABLE(); KASSERT(0 <= queue); KASSERT(queue < USB_NUM_TASKQS); @@ -527,6 +584,8 @@ usb_rem_task_wait(struct usbd_device *dev, struct usb_task *task, int queue, if (interlock && !removed) mutex_enter(interlock); + SDT_PROBE5(usb, kernel, task, rem__wait__done, + dev, task, queue, interlock, removed); return removed; } @@ -629,8 +688,10 @@ usb_task_thread(void *arg) if (!mpsafe) KERNEL_LOCK(1, curlwp); + SDT_PROBE1(usb, kernel, task, start, task); task->fun(task->arg); /* Can't dereference task after this point. */ + SDT_PROBE1(usb, kernel, task, done, task); if (!mpsafe) KERNEL_UNLOCK_ONE(curlwp); @@ -1021,12 +1082,16 @@ usb_discover(struct usb_softc *sc) * Also, we now have bus->ub_lock held, and in combination * with ub_exploring, avoids interferring with polling. */ + SDT_PROBE1(usb, kernel, bus, discover__start, bus); while (bus->ub_needsexplore && !sc->sc_dying) { bus->ub_needsexplore = 0; mutex_exit(sc->sc_bus->ub_lock); + SDT_PROBE1(usb, kernel, bus, explore__start, bus); bus->ub_roothub->ud_hub->uh_explore(bus->ub_roothub); + SDT_PROBE1(usb, kernel, bus, explore__done, bus); mutex_enter(bus->ub_lock); } + SDT_PROBE1(usb, kernel, bus, discover__done, bus); } void @@ -1034,6 +1099,7 @@ usb_needs_explore(struct usbd_device *dev) { USBHIST_FUNC(); USBHIST_CALLED(usbdebug); + SDT_PROBE1(usb, kernel, bus, needs__explore, dev->ud_bus); mutex_enter(dev->ud_bus->ub_lock); dev->ud_bus->ub_needsexplore = 1; @@ -1046,6 +1112,7 @@ usb_needs_reattach(struct usbd_device *dev) { USBHIST_FUNC(); USBHIST_CALLED(usbdebug); + SDT_PROBE1(usb, kernel, bus, needs__reattach, dev->ud_bus); mutex_enter(dev->ud_bus->ub_lock); dev->ud_powersrc->up_reattach = 1; @@ -1127,12 +1194,19 @@ usb_add_event(int type, struct usb_event *uep) ueq->ue = *uep; ueq->ue.ue_type = type; TIMEVAL_TO_TIMESPEC(&thetime, &ueq->ue.ue_time); + SDT_PROBE1(usb, kernel, event, add, uep); mutex_enter(&usb_event_lock); if (++usb_nevents >= USB_MAX_EVENTS) { /* Too many queued events, drop an old one. */ DPRINTF("event dropped", 0, 0, 0, 0); - (void)usb_get_next_event(0); +#ifdef KDTRACE_HOOKS + struct usb_event oue; + if (usb_get_next_event(&oue)) + SDT_PROBE1(usb, kernel, event, drop, &oue); +#else + usb_get_next_event(NULL); +#endif } SIMPLEQ_INSERT_TAIL(&usb_events, ueq, next); cv_signal(&usb_event_cv); diff --git a/sys/dev/usb/usb_sdt.h b/sys/dev/usb/usb_sdt.h new file mode 100644 index 000000000000..4d01f091c799 --- /dev/null +++ b/sys/dev/usb/usb_sdt.h @@ -0,0 +1,36 @@ +/* $NetBSD$ */ + +/*- + * Copyright (c) 2020 The NetBSD Foundation, Inc. + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE NETBSD FOUNDATION, INC. AND CONTRIBUTORS + * ``AS IS'' AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED + * TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR + * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE FOUNDATION OR CONTRIBUTORS + * BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR + * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF + * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS + * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN + * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) + * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE + * POSSIBILITY OF SUCH DAMAGE. + */ + +#ifndef _USB_SDT_H_ +#define _USB_SDT_H_ + +#include + +SDT_PROVIDER_DECLARE(usb); + +#endif /* _USB_SDT_H_ */ From e7950cb5abf5a7241c196418725f63006563ed87 Mon Sep 17 00:00:00 2001 From: Taylor R Campbell Date: Sun, 16 Feb 2020 22:09:11 +0000 Subject: [PATCH 6/6] umass dtrace probes --- sys/dev/usb/umass.c | 107 ++++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 104 insertions(+), 3 deletions(-) diff --git a/sys/dev/usb/umass.c b/sys/dev/usb/umass.c index 280c76b5f082..75b52c4f044a 100644 --- a/sys/dev/usb/umass.c +++ b/sys/dev/usb/umass.c @@ -144,6 +144,7 @@ __KERNEL_RCSID(0, "$NetBSD: umass.c,v 1.176 2019/12/06 07:12:39 maxv Exp $"); #include #include +#include #include #include #include @@ -157,6 +158,56 @@ __KERNEL_RCSID(0, "$NetBSD: umass.c,v 1.176 2019/12/06 07:12:39 maxv Exp $"); #include #include +SDT_PROBE_DEFINE1(usb, umass, device, attach__start, + "struct umass_softc *"/*sc*/); +SDT_PROBE_DEFINE2(usb, umass, device, attach__done, + "struct umass_softc *"/*sc*/, "usbd_status"/*err*/); +SDT_PROBE_DEFINE1(usb, umass, device, detach__start, + "struct umass_softc *"/*sc*/); +SDT_PROBE_DEFINE2(usb, umass, device, detach__done, + "struct umass_softc *"/*sc*/, "int"/*error*/); + +SDT_PROBE_DEFINE7(usb, umass, transfer, start__bbb, + "struct umass_softc *"/*sc*/, + "transfer_cb_f"/*cb*/, + "void *"/*priv*/, + "void *"/*data*/, + "int"/*datalen*/, + "int"/*dir*/, + "int"/*timeout*/); +SDT_PROBE_DEFINE7(usb, umass, transfer, start__cbi, + "struct umass_softc *"/*sc*/, + "transfer_cb_f"/*cb*/, + "void *"/*priv*/, + "void *"/*data*/, + "int"/*datalen*/, + "int"/*dir*/, + "int"/*timeout*/); +SDT_PROBE_DEFINE7(usb, umass, transfer, done, + "struct umass_softc *"/*sc*/, + "transfer_cb_f"/*cb*/, + "void *"/*priv*/, + "void *"/*data*/, + "int"/*datalen*/, + "int"/*resid*/, + "int"/*status*/); /* STATUS_* */ + +SDT_PROBE_DEFINE3(usb, umass, bbb, state, + "struct umass_softc *"/*sc*/, + "struct usbd_xfer *"/*xfer*/, + "usbd_status"/*err*/); +SDT_PROBE_DEFINE2(usb, umass, bbb, reset, + "struct umass_softc *"/*sc*/, + "int"/*status*/); + +SDT_PROBE_DEFINE3(usb, umass, cbi, state, + "struct umass_softc *"/*sc*/, + "struct usbd_xfer *"/*xfer*/, + "usbd_status"/*err*/); +SDT_PROBE_DEFINE2(usb, umass, cbi, reset, + "struct umass_softc *"/*sc*/, + "int"/*status*/); + #ifdef USB_DEBUG #ifdef UMASS_DEBUG int umassdebug = 0; @@ -335,6 +386,8 @@ umass_attach(device_t parent, device_t self, void *aux) usbd_status err; int i, error; + SDT_PROBE1(usb, umass, device, attach__start, sc); + sc->sc_dev = self; aprint_naive("\n"); @@ -382,6 +435,8 @@ umass_attach(device_t parent, device_t self, void *aux) default: DPRINTFM(UDMASS_GEN, "Unsupported wire protocol %ju", uiaa->uiaa_proto, 0, 0, 0); + SDT_PROBE2(usb, umass, device, attach__done, + sc, USBD_IOERROR); return; } } @@ -405,6 +460,8 @@ umass_attach(device_t parent, device_t self, void *aux) default: DPRINTFM(UDMASS_GEN, "Unsupported command protocol %ju", uiaa->uiaa_subclass, 0, 0, 0); + SDT_PROBE2(usb, umass, device, attach__done, + sc, USBD_IOERROR); return; } } @@ -451,6 +508,7 @@ umass_attach(device_t parent, device_t self, void *aux) err = (*quirk->uq_init)(sc); if (err) { aprint_error_dev(self, "quirk init failed\n"); + SDT_PROBE2(usb, umass, device, attach__done, sc, err); umass_disco(sc); return; } @@ -473,6 +531,8 @@ umass_attach(device_t parent, device_t self, void *aux) if (ed == NULL) { aprint_error_dev(self, "could not read endpoint descriptor\n"); + SDT_PROBE2(usb, umass, device, attach__done, + sc, USBD_IOERROR); return; } if (UE_GET_DIR(ed->bEndpointAddress) == UE_DIR_IN @@ -515,6 +575,7 @@ umass_attach(device_t parent, device_t self, void *aux) if (err) { aprint_error_dev(self, "unable to get Max Lun: %s\n", usbd_errstr(err)); + SDT_PROBE2(usb, umass, device, attach__done, sc, err); return; } if (sc->maxlun > 0) @@ -532,6 +593,7 @@ umass_attach(device_t parent, device_t self, void *aux) if (err) { aprint_error_dev(self, "cannot open %u-out pipe (bulk)\n", sc->sc_epaddr[UMASS_BULKOUT]); + SDT_PROBE2(usb, umass, device, attach__done, sc, err); umass_disco(sc); return; } @@ -543,6 +605,7 @@ umass_attach(device_t parent, device_t self, void *aux) if (err) { aprint_error_dev(self, "could not open %u-in pipe (bulk)\n", sc->sc_epaddr[UMASS_BULKIN]); + SDT_PROBE2(usb, umass, device, attach__done, sc, err); umass_disco(sc); return; } @@ -568,6 +631,7 @@ umass_attach(device_t parent, device_t self, void *aux) if (err) { aprint_error_dev(self, "couldn't open %u-in (intr)\n", sc->sc_epaddr[UMASS_INTRIN]); + SDT_PROBE2(usb, umass, device, attach__done, sc, err); umass_disco(sc); return; } @@ -677,6 +741,7 @@ umass_attach(device_t parent, device_t self, void *aux) default: fail_create: aprint_error_dev(self, "failed to create xfers\n"); + SDT_PROBE2(usb, umass, device, attach__done, sc, err); umass_disco(sc); return; } @@ -765,6 +830,8 @@ umass_attach(device_t parent, device_t self, void *aux) } if (error) { aprint_error_dev(self, "bus attach failed\n"); + SDT_PROBE2(usb, umass, device, attach__done, + sc, USBD_IOERROR); umass_disco(sc); return; } @@ -777,6 +844,7 @@ umass_attach(device_t parent, device_t self, void *aux) DPRINTFM(UDMASS_GEN, "sc %#jx: Attach finished", (uintptr_t)sc, 0, 0, 0); + SDT_PROBE2(usb, umass, device, attach__done, sc, 0); return; } @@ -799,6 +867,7 @@ umass_detach(device_t self, int flags) int rv = 0, i; DPRINTFM(UDMASS_USB, "sc %#jx detached", (uintptr_t)sc, 0, 0, 0); + SDT_PROBE1(usb, umass, device, detach__start, sc); mutex_enter(&sc->sc_lock); sc->sc_dying = true; @@ -866,8 +935,8 @@ umass_detach(device_t self, int flags) KASSERT(sc->bus == NULL); } - if (rv != 0) - return rv; + if (rv) + goto out; umass_disco(sc); @@ -876,6 +945,7 @@ umass_detach(device_t self, int flags) mutex_destroy(&sc->sc_lock); cv_destroy(&sc->sc_detach_cv); +out: SDT_PROBE2(usb, umass, device, detach__done, sc, rv); return rv; } @@ -1022,6 +1092,14 @@ umass_transfer_done(struct umass_softc *sc, int residue, int status) UMASSHIST_FUNC(); UMASSHIST_CALLED(); sc->transfer_state = TSTATE_IDLE; + SDT_PROBE7(usb, umass, transfer, done, + sc, + sc->transfer_cb, + sc->transfer_priv, + sc->transfer_data, + sc->transfer_datalen, + residue, + status); sc->transfer_cb(sc, sc->transfer_priv, residue, status); } @@ -1031,9 +1109,18 @@ umass_transfer_reset(struct umass_softc *sc) UMASSHIST_FUNC(); UMASSHIST_CALLED(); sc->transfer_state = TSTATE_IDLE; - if (sc->transfer_priv) + if (sc->transfer_priv) { + SDT_PROBE7(usb, umass, transfer, done, + sc, + sc->transfer_cb, + sc->transfer_priv, + sc->transfer_data, + sc->transfer_datalen, + sc->transfer_datalen, + sc->transfer_status); sc->transfer_cb(sc, sc->transfer_priv, sc->transfer_datalen, sc->transfer_status); + } } #if 0 @@ -1056,6 +1143,7 @@ Static void umass_bbb_reset(struct umass_softc *sc, int status) { UMASSHIST_FUNC(); UMASSHIST_CALLED(); + SDT_PROBE2(usb, umass, bbb, reset, sc, status); KASSERTMSG(sc->sc_wire & UMASS_WPROTO_BBB, "sc->sc_wire == 0x%02x wrong for umass_bbb_reset\n", sc->sc_wire); @@ -1103,6 +1191,8 @@ umass_bbb_transfer(struct umass_softc *sc, int lun, void *cmd, int cmdlen, int flags, umass_callback cb, void *priv) { UMASSHIST_FUNC(); UMASSHIST_CALLED(); + SDT_PROBE7(usb, umass, transfer, start__bbb, + sc, cb, priv, data, datalen, dir, timeout); static int dCBWtag = 42; /* unique for CBW of transfer */ DPRINTFM(UDMASS_BBB, "sc %#jx cmd=0x%02jx", (uintptr_t)sc, @@ -1113,6 +1203,8 @@ umass_bbb_transfer(struct umass_softc *sc, int lun, void *cmd, int cmdlen, sc->sc_wire); if (sc->sc_dying) { + SDT_PROBE7(usb, umass, transfer, done, + sc, cb, priv, data, datalen, datalen, STATUS_WIRE_FAILED); cb(sc, priv, datalen, STATUS_WIRE_FAILED); return; } @@ -1226,6 +1318,8 @@ umass_bbb_state(struct usbd_xfer *xfer, void *priv, struct usbd_xfer *next_xfer; int residue; + SDT_PROBE3(usb, umass, bbb, state, sc, xfer, err); + KASSERTMSG(sc->sc_wire & UMASS_WPROTO_BBB, "sc->sc_wire == 0x%02x wrong for umass_bbb_state\n", sc->sc_wire); @@ -1567,6 +1661,7 @@ Static void umass_cbi_reset(struct umass_softc *sc, int status) { UMASSHIST_FUNC(); UMASSHIST_CALLED(); + SDT_PROBE2(usb, umass, bbb, reset, sc, status); int i; # define SEND_DIAGNOSTIC_CMDLEN 12 @@ -1625,6 +1720,8 @@ umass_cbi_transfer(struct umass_softc *sc, int lun, u_int timeout, int flags, umass_callback cb, void *priv) { UMASSHIST_FUNC(); UMASSHIST_CALLED(); + SDT_PROBE7(usb, umass, transfer, start__cbi, + sc, cb, priv, data, datalen, dir, timeout); DPRINTFM(UDMASS_CBI, "sc %#jx: cmd=0x%02jx, len=%jd", (uintptr_t)sc, *(u_char *)cmd, datalen, 0); @@ -1634,6 +1731,8 @@ umass_cbi_transfer(struct umass_softc *sc, int lun, sc->sc_wire); if (sc->sc_dying) { + SDT_PROBE7(usb, umass, transfer, done, + sc, cb, priv, data, datalen, datalen, STATUS_WIRE_FAILED); cb(sc, priv, datalen, STATUS_WIRE_FAILED); return; } @@ -1690,6 +1789,8 @@ umass_cbi_state(struct usbd_xfer *xfer, void *priv, UMASSHIST_FUNC(); UMASSHIST_CALLED(); struct umass_softc *sc = (struct umass_softc *) priv; + SDT_PROBE3(usb, umass, bbb, state, sc, xfer, err); + KASSERTMSG(sc->sc_wire & (UMASS_WPROTO_CBI|UMASS_WPROTO_CBI_I), "sc->sc_wire == 0x%02x wrong for umass_cbi_state\n", sc->sc_wire);