Source-Changes-HG archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

[src/trunk]: src/sys/dev/usb introduce and use XHCIHIST_CALLARGS(). reduces ...



details:   https://anonhg.NetBSD.org/src/rev/6ca8147b69ba
branches:  trunk
changeset: 1003053:6ca8147b69ba
user:      mrg <mrg%NetBSD.org@localhost>
date:      Wed Aug 28 07:09:52 2019 +0000

description:
introduce and use XHCIHIST_CALLARGS().  reduces lots of double logs,
and includes useful info in all cases instead of just "called".

add a couple of more logs that i've wanted while debugging ryzen3
vs USB issues.

diffstat:

 sys/dev/usb/xhci.c |  186 ++++++++++++++++++++++++++++------------------------
 1 files changed, 99 insertions(+), 87 deletions(-)

diffs (truncated from 533 to 300 lines):

diff -r 3af70c5904bd -r 6ca8147b69ba sys/dev/usb/xhci.c
--- a/sys/dev/usb/xhci.c        Wed Aug 28 06:07:21 2019 +0000
+++ b/sys/dev/usb/xhci.c        Wed Aug 28 07:09:52 2019 +0000
@@ -1,4 +1,4 @@
-/*     $NetBSD: xhci.c,v 1.110 2019/08/23 04:34:01 mrg Exp $   */
+/*     $NetBSD: xhci.c,v 1.111 2019/08/28 07:09:52 mrg Exp $   */
 
 /*
  * Copyright (c) 2013 Jonathan A. Kollasch
@@ -34,7 +34,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: xhci.c,v 1.110 2019/08/23 04:34:01 mrg Exp $");
+__KERNEL_RCSID(0, "$NetBSD: xhci.c,v 1.111 2019/08/28 07:09:52 mrg Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_usb.h"
@@ -114,9 +114,12 @@
 #define HEXDUMP(a, b, c)
 #endif
 
-#define DPRINTFN(N,FMT,A,B,C,D) USBHIST_LOGN(xhcidebug,N,FMT,A,B,C,D)
-#define XHCIHIST_FUNC() USBHIST_FUNC()
-#define XHCIHIST_CALLED(name) USBHIST_CALLED(xhcidebug)
+#define DPRINTF(FMT,A,B,C,D)   USBHIST_LOG(xhcidebug,FMT,A,B,C,D)
+#define DPRINTFN(N,FMT,A,B,C,D)        USBHIST_LOGN(xhcidebug,N,FMT,A,B,C,D)
+#define XHCIHIST_FUNC()                USBHIST_FUNC()
+#define XHCIHIST_CALLED(name)  USBHIST_CALLED(xhcidebug)
+#define XHCIHIST_CALLARGS(FMT,A,B,C,D) \
+                               USBHIST_CALLARGS(xhcidebug,FMT,A,B,C,D)
 
 #define XHCI_DCI_SLOT 0
 #define XHCI_DCI_EP_CONTROL 1
@@ -1297,10 +1300,10 @@
        uint32_t usbsts;
        uint32_t iman;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
+       XHCIHIST_FUNC();
 
        usbsts = xhci_op_read_4(sc, XHCI_USBSTS);
-       DPRINTFN(16, "USBSTS %08jx", usbsts, 0, 0, 0);
+       XHCIHIST_CALLARGS("USBSTS %08jx", usbsts, 0, 0, 0);
        if ((usbsts & (XHCI_STS_HSE | XHCI_STS_EINT | XHCI_STS_PCD |
            XHCI_STS_HCE)) == 0) {
                DPRINTFN(16, "ignored intr not for %s",
@@ -1411,8 +1414,8 @@
        struct xhci_soft_trb trb;
        usbd_status err;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "slot %ju dci %ju epaddr 0x%02jx attr 0x%02jx",
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("slot %ju dci %ju epaddr 0x%02jx attr 0x%02jx",
            xs->xs_idx, dci, pipe->up_endpoint->ue_edesc->bEndpointAddress,
            pipe->up_endpoint->ue_edesc->bmAttributes);
 
@@ -1450,8 +1453,8 @@
        struct xhci_slot * const xs = pipe->up_dev->ud_hcpriv;
 #endif
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "slot %ju", xs->xs_idx, 0, 0, 0);
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("slot %ju", xs->xs_idx, 0, 0, 0);
 
        return USBD_NORMAL_COMPLETION;
 }
@@ -1467,8 +1470,8 @@
        struct xhci_soft_trb trb;
        usbd_status err;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "slot %ju dci %ju", xs->xs_idx, dci, 0, 0);
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("slot %ju dci %ju", xs->xs_idx, dci, 0, 0);
 
        KASSERT(mutex_owned(&sc->sc_lock));
 
@@ -1509,8 +1512,8 @@
        usbd_status err;
        const u_int dci = xhci_ep_get_dci(pipe->up_endpoint->ue_edesc);
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "slot %ju dci %ju", xs->xs_idx, dci, 0, 0);
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("slot %ju dci %ju", xs->xs_idx, dci, 0, 0);
 
        KASSERT(mutex_owned(&sc->sc_lock));
 
@@ -1543,8 +1546,8 @@
        struct xhci_soft_trb trb;
        usbd_status err;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "slot %ju dci %ju", xs->xs_idx, dci, 0, 0);
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("slot %ju dci %ju", xs->xs_idx, dci, 0, 0);
 
        KASSERT(mutex_owned(&sc->sc_lock));
 
@@ -1587,8 +1590,8 @@
        usb_endpoint_descriptor_t * const ed = pipe->up_endpoint->ue_edesc;
        const uint8_t xfertype = UE_GET_XFERTYPE(ed->bmAttributes);
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(1, "addr %jd depth %jd port %jd speed %jd", dev->ud_addr,
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("addr %jd depth %jd port %jd speed %jd", dev->ud_addr,
            dev->ud_depth, dev->ud_powersrc->up_portno, dev->ud_speed);
        DPRINTFN(1, " dci %ju type 0x%02jx epaddr 0x%02jx attr 0x%02jx",
            xhci_ep_get_dci(ed), ed->bDescriptorType, ed->bEndpointAddress,
@@ -1657,7 +1660,7 @@
        struct xhci_soft_trb trb;
        uint32_t *cp;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
+       XHCIHIST_FUNC();
 
        if (sc->sc_dying)
                return;
@@ -1666,8 +1669,8 @@
        if (xs == NULL || xs->xs_idx == 0)
                return;
 
-       DPRINTFN(4, "pipe %#jx slot %ju dci %ju", (uintptr_t)pipe, xs->xs_idx,
-           dci, 0);
+       XHCIHIST_CALLARGS("pipe %#jx slot %ju dci %ju",
+           (uintptr_t)pipe, xs->xs_idx, dci, 0);
 
        KASSERTMSG(!cpu_intr_p() && !cpu_softintr_p(), "called from intr ctx");
        KASSERT(mutex_owned(&sc->sc_lock));
@@ -1719,7 +1722,7 @@
 static void
 xhci_abort_xfer(struct usbd_xfer *xfer, usbd_status status)
 {
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
+       XHCIHIST_FUNC();
        struct xhci_softc * const sc = XHCI_XFER2SC(xfer);
        struct xhci_slot * const xs = xfer->ux_pipe->up_dev->ud_hcpriv;
        const u_int dci = xhci_ep_get_dci(xfer->ux_pipe->up_endpoint->ue_edesc);
@@ -1727,7 +1730,7 @@
        KASSERTMSG((status == USBD_CANCELLED || status == USBD_TIMEOUT),
            "invalid status for abort: %d", (int)status);
 
-       DPRINTFN(4, "xfer %#jx pipe %#jx status %jd",
+       XHCIHIST_CALLARGS("xfer %#jx pipe %#jx status %jd",
            (uintptr_t)xfer, (uintptr_t)xfer->ux_pipe, status, 0);
 
        KASSERT(mutex_owned(&sc->sc_lock));
@@ -1838,8 +1841,8 @@
        const u_int dci = xhci_ep_get_dci(xfer->ux_pipe->up_endpoint->ue_edesc);
        struct xhci_ring * const tr = &xs->xs_ep[dci].xe_tr;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "xfer %#jx slot %ju dci %ju", (uintptr_t)xfer, xs->xs_idx,
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("xfer %#jx slot %ju dci %ju", (uintptr_t)xfer, xs->xs_idx,
            dci, 0);
 
        /*
@@ -1871,8 +1874,8 @@
        struct xhci_softc * const sc = XHCI_XFER2SC(xfer);
        struct xhci_pipe * const xp = (struct xhci_pipe *)xfer->ux_pipe;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "xfer %#jx", (uintptr_t)xfer, 0, 0, 0);
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("xfer %#jx", (uintptr_t)xfer, 0, 0, 0);
 
        if (sc->sc_dying) {
                return USBD_IOERROR;
@@ -1890,9 +1893,9 @@
 static void
 xhci_rhpsc(struct xhci_softc * const sc, u_int ctlrport)
 {
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "xhci%jd: port %ju status change", device_unit(sc->sc_dev),
-          ctlrport, 0, 0);
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("xhci%jd: port %ju status change",
+          device_unit(sc->sc_dev), ctlrport, 0, 0);
 
        if (ctlrport > sc->sc_maxports)
                return;
@@ -2167,13 +2170,13 @@
        uint64_t trb_0;
        uint32_t trb_2, trb_3;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
+       XHCIHIST_FUNC();
 
        trb_0 = le64toh(trb->trb_0);
        trb_2 = le32toh(trb->trb_2);
        trb_3 = le32toh(trb->trb_3);
 
-       DPRINTFN(14, "event: %#jx 0x%016jx 0x%08jx 0x%08jx",
+       XHCIHIST_CALLARGS("event: %#jx 0x%016jx 0x%08jx 0x%08jx",
            (uintptr_t)trb, trb_0, trb_2, trb_3);
 
        /*
@@ -2216,14 +2219,14 @@
        struct xhci_trb *trb;
        int i, j, k;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
+       XHCIHIST_FUNC();
 
        KASSERT(xhci_polling_p(sc) || mutex_owned(&sc->sc_lock));
 
        i = er->xr_ep;
        j = er->xr_cs;
 
-       DPRINTFN(16, "er: xr_ep %jd xr_cs %jd", i, j, 0, 0);
+       XHCIHIST_CALLARGS("er: xr_ep %jd xr_cs %jd", i, j, 0, 0);
 
        while (1) {
                usb_syncmem(&er->xr_dma, XHCI_TRB_SIZE * i, XHCI_TRB_SIZE,
@@ -2346,8 +2349,8 @@
        struct xhci_slot *xs;
        uint32_t *cp;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(4, "port %ju depth %ju speed %ju up %#jx",
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("port %ju depth %ju speed %ju up %#jx",
            port, depth, speed, (uintptr_t)up);
 
        dev = kmem_zalloc(sizeof(*dev), KM_SLEEP);
@@ -2448,7 +2451,7 @@
                /* 4.3.4 Address Assignment */
                err = xhci_set_address(dev, slot, false);
                if (err) {
-                       DPRINTFN(1, "set address w/o bsr %ju", err, 0, 0, 0);
+                       DPRINTFN(1, "failed! to set address: %ju", err, 0, 0, 0);
                        goto bad;
                }
 
@@ -2544,7 +2547,9 @@
        usbd_status err;
        size_t size = ntrb * XHCI_TRB_SIZE;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("xr %#jx ntrb %#jx align %#jx",
+           (uintptr_t)xr, ntrb, align, 0);
 
        err = usb_allocmem(&sc->sc_bus, size, align, &xr->xr_dma);
        if (err)
@@ -2578,7 +2583,9 @@
        uint32_t status;
        uint32_t control;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("%#jx xr_ep 0x%jx xr_cs %ju",
+           (uintptr_t)xr, xr->xr_ep, xr->xr_cs, 0);
 
        KASSERTMSG(ntrbs <= XHCI_XFER_NTRB, "ntrbs %zu", ntrbs);
        for (i = 0; i < ntrbs; i++) {
@@ -2590,9 +2597,6 @@
                    XHCI_TRB_TYPE_LINK, "trbs[%zu].trb3 %#x", i, trbs[i].trb_3);
        }
 
-       DPRINTFN(12, "%#jx xr_ep 0x%jx xr_cs %ju", (uintptr_t)xr, xr->xr_ep,
-           xr->xr_cs, 0);
-
        ri = xr->xr_ep;
        cs = xr->xr_cs;
 
@@ -2686,8 +2690,8 @@
        uint64_t crcr;
        int i;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(14, "command %#jx timeout, aborting",
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("command %#jx timeout, aborting",
            sc->sc_command_addr, 0, 0, 0);
 
        mutex_enter(&cr->xr_lock);
@@ -2729,8 +2733,8 @@
        struct xhci_ring * const cr = &sc->sc_cr;
        usbd_status err;
 
-       XHCIHIST_FUNC(); XHCIHIST_CALLED();
-       DPRINTFN(12, "input: 0x%016jx 0x%08jx 0x%08jx",
+       XHCIHIST_FUNC();
+       XHCIHIST_CALLARGS("input: 0x%016jx 0x%08jx 0x%08jx",
            trb->trb_0, trb->trb_2, trb->trb_3, 0);
 
        KASSERTMSG(!cpu_intr_p() && !cpu_softintr_p(), "called from intr ctx");
@@ -2778,6 +2782,8 @@
                break;
        default:
        case 192 ... 223:
+               DPRINTFN(5, "error %x",
+                   XHCI_TRB_2_ERROR_GET(trb->trb_2), 0, 0, 0);
                err = USBD_IOERROR;



Home | Main Index | Thread Index | Old Index