Source-Changes-HG archive

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

[src/trunk]: src/sys Improve USB debugging with USBHIST based on KERNHIST.



details:   https://anonhg.NetBSD.org/src/rev/662325eb0586
branches:  trunk
changeset: 802374:662325eb0586
user:      skrll <skrll%NetBSD.org@localhost>
date:      Fri Sep 12 16:40:38 2014 +0000

description:
Improve USB debugging with USBHIST based on KERNHIST.

Convert some DPRINTFs to USBHIST_LOG and allow usbdebug, ehcidebug and
umassdebug to be changed via sysctl.

Remove the #define mess in usb.h.

This was started by mrg@ and updated by reinoud@

diffstat:

 sys/dev/usb/ehci.c                    |  851 ++++++++++++++++++++-------------
 sys/dev/usb/files.usb                 |   91 +++-
 sys/dev/usb/if_smsc.c                 |    3 +-
 sys/dev/usb/umass.c                   |   47 +-
 sys/dev/usb/umass_isdata.c            |    8 +-
 sys/dev/usb/umass_quirks.c            |    8 +-
 sys/dev/usb/umass_scsipi.c            |    6 +-
 sys/dev/usb/usb.c                     |   46 +-
 sys/dev/usb/usb.h                     |   78 +---
 sys/dev/usb/usb_mem.c                 |    8 +-
 sys/dev/usb/usb_quirks.c              |    8 +-
 sys/dev/usb/usb_subr.c                |    5 +-
 sys/dev/usb/usbdi.c                   |  204 +++++--
 sys/dev/usb/usbdi_util.c              |   18 +-
 sys/dev/usb/usbhist.h                 |   83 +++
 sys/dev/usb/uvideo.c                  |    6 +-
 sys/external/bsd/dwc2/conf/files.dwc2 |    4 +-
 17 files changed, 948 insertions(+), 526 deletions(-)

diffs (truncated from 3121 to 300 lines):

diff -r 921bc4cb2515 -r 662325eb0586 sys/dev/usb/ehci.c
--- a/sys/dev/usb/ehci.c        Fri Sep 12 16:25:55 2014 +0000
+++ b/sys/dev/usb/ehci.c        Fri Sep 12 16:40:38 2014 +0000
@@ -1,4 +1,4 @@
-/*     $NetBSD: ehci.c,v 1.228 2014/08/05 10:33:46 skrll Exp $ */
+/*     $NetBSD: ehci.c,v 1.229 2014/09/12 16:40:38 skrll Exp $ */
 
 /*
  * Copyright (c) 2004-2012 The NetBSD Foundation, Inc.
@@ -53,53 +53,70 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: ehci.c,v 1.228 2014/08/05 10:33:46 skrll Exp $");
+__KERNEL_RCSID(0, "$NetBSD: ehci.c,v 1.229 2014/09/12 16:40:38 skrll Exp $");
 
 #include "ohci.h"
 #include "uhci.h"
+#include "opt_usb.h"
 
 #include <sys/param.h>
-#include <sys/systm.h>
+
+#include <sys/bus.h>
+#include <sys/cpu.h>
+#include <sys/device.h>
 #include <sys/kernel.h>
 #include <sys/kmem.h>
-#include <sys/device.h>
-#include <sys/select.h>
+#include <sys/mutex.h>
 #include <sys/proc.h>
 #include <sys/queue.h>
-#include <sys/mutex.h>
-#include <sys/bus.h>
-#include <sys/cpu.h>
+#include <sys/select.h>
+#include <sys/sysctl.h>
+#include <sys/systm.h>
 
 #include <machine/endian.h>
 
 #include <dev/usb/usb.h>
 #include <dev/usb/usbdi.h>
 #include <dev/usb/usbdivar.h>
+#include <dev/usb/usbhist.h>
 #include <dev/usb/usb_mem.h>
 #include <dev/usb/usb_quirks.h>
+#include <dev/usb/usbroothub_subr.h>
 
 #include <dev/usb/ehcireg.h>
 #include <dev/usb/ehcivar.h>
-#include <dev/usb/usbroothub_subr.h>
 
 #ifdef EHCI_DEBUG
-static void __printflike(1, 2)
-ehciprintf(const char *fmt, ...)
+static int ehcidebug = 0;
+
+SYSCTL_SETUP(sysctl_hw_ehci_setup, "sysctl hw.ehci setup")
 {
-       va_list ap;
-
-       va_start(ap, fmt);
-       vprintf(fmt, ap);
-       va_end(ap);
+       int err;
+       const struct sysctlnode *rnode;
+       const struct sysctlnode *cnode;
+
+       err = sysctl_createv(clog, 0, NULL, &rnode,
+           CTLFLAG_PERMANENT, CTLTYPE_NODE, "ehci",
+           SYSCTL_DESCR("ehci global controls"),
+           NULL, 0, NULL, 0, CTL_HW, CTL_CREATE, CTL_EOL);
+
+       if (err)
+               goto fail;
+
+       /* control debugging printfs */
+       err = sysctl_createv(clog, 0, &rnode, &cnode,
+           CTLFLAG_PERMANENT|CTLFLAG_READWRITE, CTLTYPE_INT,
+           "debug", SYSCTL_DESCR("Enable debugging output"),
+           NULL, 0, &ehcidebug, sizeof(ehcidebug), CTL_CREATE, CTL_EOL);
+       if (err)
+               goto fail;
+
+       return;
+fail:
+       aprint_error("%s: sysctl_createv failed (err = %d)\n", __func__, err);
 }
 
-#define DPRINTF(x)     do { if (ehcidebug) ehciprintf x; } while(0)
-#define DPRINTFN(n,x)  do { if (ehcidebug>(n)) ehciprintf x; } while (0)
-int ehcidebug = 0;
-#else
-#define DPRINTF(x)
-#define DPRINTFN(n,x)
-#endif
+#endif /* EHCI_DEBUG */
 
 struct ehci_pipe {
        struct usbd_pipe pipe;
@@ -228,22 +245,20 @@
 Static void            ehci_abort_xfer(usbd_xfer_handle, usbd_status);
 
 #ifdef EHCI_DEBUG
-Static void            ehci_dump_regs(ehci_softc_t *);
+Static ehci_softc_t    *theehci;
 void                   ehci_dump(void);
-Static ehci_softc_t    *theehci;
-Static void            ehci_dump_link(ehci_link_t, int);
+#endif
+
+#ifdef EHCI_DEBUG
+Static void            ehci_dump_regs(ehci_softc_t *);
 Static void            ehci_dump_sqtds(ehci_soft_qtd_t *);
 Static void            ehci_dump_sqtd(ehci_soft_qtd_t *);
 Static void            ehci_dump_qtd(ehci_qtd_t *);
 Static void            ehci_dump_sqh(ehci_soft_qh_t *);
-#if notyet
 Static void            ehci_dump_sitd(struct ehci_soft_itd *itd);
 Static void            ehci_dump_itd(struct ehci_soft_itd *);
-#endif
-#ifdef DIAGNOSTIC
 Static void            ehci_dump_exfer(struct ehci_xfer *);
 #endif
-#endif
 
 #define EHCI_NULL htole32(EHCI_LINK_TERMINATE)
 
@@ -344,7 +359,7 @@
        ehci_soft_qh_t *sqh;
        u_int ncomp;
 
-       DPRINTF(("ehci_init: start\n"));
+       USBHIST_FUNC(); USBHIST_CALLED(ehcidebug);
 #ifdef EHCI_DEBUG
        theehci = sc;
 #endif
@@ -371,7 +386,7 @@
               vers >> 8, vers & 0xff);
 
        sparams = EREAD4(sc, EHCI_HCSPARAMS);
-       DPRINTF(("ehci_init: sparams=0x%x\n", sparams));
+       USBHIST_LOG(ehcidebug, "sparams=%#x", sparams, 0, 0, 0);
        sc->sc_npcomp = EHCI_HCS_N_PCC(sparams);
        ncomp = EHCI_HCS_N_CC(sparams);
        if (ncomp != sc->sc_ncomp) {
@@ -396,7 +411,7 @@
        }
        sc->sc_noport = EHCI_HCS_N_PORTS(sparams);
        cparams = EREAD4(sc, EHCI_HCCPARAMS);
-       DPRINTF(("ehci_init: cparams=0x%x\n", cparams));
+       USBHIST_LOG(ehcidebug, "cparams=%#x", cparams, 0, 0, 0);
        sc->sc_hasppc = EHCI_HCS_PPC(sparams);
 
        if (EHCI_HCC_64BIT(cparams)) {
@@ -410,7 +425,7 @@
            USB_MEM_RESERVE);
 
        /* Reset the controller */
-       DPRINTF(("%s: resetting\n", device_xname(sc->sc_dev)));
+       USBHIST_LOG(ehcidebug, "resetting", 0, 0, 0, 0);
        EOWRITE4(sc, EHCI_USBCMD, 0);   /* Halt controller */
        usb_delay_ms(&sc->sc_bus, 1);
        EOWRITE4(sc, EHCI_USBCMD, EHCI_CMD_HCRESET);
@@ -452,7 +467,7 @@
            EHCI_FLALIGN_ALIGN, &sc->sc_fldma);
        if (err)
                return (err);
-       DPRINTF(("%s: flsize=%d\n", device_xname(sc->sc_dev),sc->sc_flsize));
+       USBHIST_LOG(ehcidebug, "flsize=%d", sc->sc_flsize, 0, 0, 0);
        sc->sc_flist = KERNADDR(&sc->sc_fldma, 0);
 
        for (i = 0; i < sc->sc_flsize; i++) {
@@ -542,9 +557,7 @@
        usb_syncmem(&sqh->dma, sqh->offs, sizeof(sqh->qh),
            BUS_DMASYNC_PREWRITE | BUS_DMASYNC_PREREAD);
 #ifdef EHCI_DEBUG
-       if (ehcidebug) {
-               ehci_dump_sqh(sqh);
-       }
+       ehci_dump_sqh(sqh);
 #endif
 
        /* Point to async list */
@@ -576,7 +589,7 @@
        }
 
        /* Enable interrupts */
-       DPRINTFN(1,("ehci_init: enabling\n"));
+       USBHIST_LOG(ehcidebug, "enabling interupts", 0, 0, 0, 0);
        EOWRITE4(sc, EHCI_USBINTR, sc->sc_eintrs);
 
        return (USBD_NORMAL_COMPLETION);
@@ -596,6 +609,8 @@
        ehci_softc_t *sc = v;
        int ret = 0;
 
+       USBHIST_FUNC(); USBHIST_CALLED(ehcidebug);
+
        if (sc == NULL)
                return 0;
 
@@ -611,7 +626,8 @@
                if (intrs)
                        EOWRITE4(sc, EHCI_USBSTS, intrs); /* Acknowledge */
 #ifdef DIAGNOSTIC
-               DPRINTFN(16, ("ehci_intr: ignored interrupt while polling\n"));
+               USBHIST_LOGN(ehcidebug, 16,
+                   "ignored interrupt while polling", 0, 0, 0, 0);
 #endif
                goto done;
        }
@@ -628,7 +644,7 @@
 {
        u_int32_t intrs, eintrs;
 
-       DPRINTFN(20,("ehci_intr1: enter\n"));
+       USBHIST_FUNC(); USBHIST_CALLED(ehcidebug);
 
        /* In case the interrupt occurs before initialization has completed. */
        if (sc == NULL) {
@@ -645,16 +661,15 @@
                return (0);
 
        eintrs = intrs & sc->sc_eintrs;
-       DPRINTFN(7, ("ehci_intr1: sc=%p intrs=0x%x(0x%x) eintrs=0x%x\n",
-                    sc, (u_int)intrs, EOREAD4(sc, EHCI_USBSTS),
-                    (u_int)eintrs));
+       USBHIST_LOG(ehcidebug, "sc=%p intrs=%#x(%#x) eintrs=%#x",
+           sc, intrs, EOREAD4(sc, EHCI_USBSTS), eintrs);
        if (!eintrs)
                return (0);
 
        EOWRITE4(sc, EHCI_USBSTS, intrs); /* Acknowledge */
        sc->sc_bus.no_intrs++;
        if (eintrs & EHCI_STS_IAA) {
-               DPRINTF(("ehci_intr1: door bell\n"));
+               USBHIST_LOG(ehcidebug, "door bell", 0, 0, 0, 0);
                kpreempt_disable();
                KASSERT(sc->sc_doorbell_si != NULL);
                softint_schedule(sc->sc_doorbell_si);
@@ -662,9 +677,9 @@
                eintrs &= ~EHCI_STS_IAA;
        }
        if (eintrs & (EHCI_STS_INT | EHCI_STS_ERRINT)) {
-               DPRINTFN(5,("ehci_intr1: %s %s\n",
-                           eintrs & EHCI_STS_INT ? "INT" : "",
-                           eintrs & EHCI_STS_ERRINT ? "ERRINT" : ""));
+               USBHIST_LOG(ehcidebug, "INT=%d  ERRINT=%d",
+                   eintrs & EHCI_STS_INT ? 1 : 0,
+                   eintrs & EHCI_STS_ERRINT ? 1 : 0, 0, 0);
                usb_schedsoftintr(&sc->sc_bus);
                eintrs &= ~(EHCI_STS_INT | EHCI_STS_ERRINT);
        }
@@ -710,6 +725,8 @@
        u_char *p;
        int i, m;
 
+       USBHIST_FUNC(); USBHIST_CALLED(ehcidebug);
+
        mutex_enter(&sc->sc_lock);
        xfer = sc->sc_intrxfer;
 
@@ -725,8 +742,10 @@
                /* Pick out CHANGE bits from the status reg. */
                if (EOREAD4(sc, EHCI_PORTSC(i)) & EHCI_PS_CLEAR)
                        p[i/8] |= 1 << (i%8);
+               if (i % 8 == 7)
+                       USBHIST_LOG(ehcidebug, "change(%d)=0x%02x", i / 8,
+                           p[i/8], 0, 0);
        }
-       DPRINTF(("ehci_pcd: change=0x%02x\n", *p));
        xfer->actlen = xfer->length;
        xfer->status = USBD_NORMAL_COMPLETION;
 
@@ -745,7 +764,7 @@
 
        KASSERT(sc->sc_bus.use_polling || mutex_owned(&sc->sc_lock));
 
-       DPRINTFN(10,("%s: ehci_softintr\n", device_xname(sc->sc_dev)));
+       USBHIST_FUNC(); USBHIST_CALLED(ehcidebug);
 
        /*
         * The only explanation I can think of for why EHCI is as brain dead
@@ -776,7 +795,8 @@
 {
        int attr;
 
-       DPRINTFN(/*15*/2, ("ehci_check_intr: ex=%p\n", ex));
+       USBHIST_FUNC(); USBHIST_CALLED(ehcidebug);
+       USBHIST_LOG(ehcidebug, "ex = %p", ex, 0, 0, 0);
 
        KASSERT(sc->sc_bus.use_polling || mutex_owned(&sc->sc_lock));
 
@@ -795,6 +815,8 @@
        ehci_soft_qtd_t *sqtd, *lsqtd;
        __uint32_t status;
 



Home | Main Index | Thread Index | Old Index