Module Name:    src
Committed By:   mrg
Date:           Wed Aug 21 10:48:37 UTC 2019

Modified Files:
        src/sys/dev/usb: uhub.c usb.c usb_mem.c usb_subr.c usbdi.c usbdi_util.c
            usbroothub.c

Log Message:
convert pairs of USBHIST_CALLED()+USBHIST_LOG*() into
USBHIST_CALLARGS() calls.  this reduces the number of
kernel history lines consumed by these callers, and
for the +LOGN versions, add useful log info to a
message that just says "called!".

reduces the line spam which means the total info in a
full log is significantly increased.


To generate a diff of this commit:
cvs rdiff -u -r1.142 -r1.143 src/sys/dev/usb/uhub.c
cvs rdiff -u -r1.179 -r1.180 src/sys/dev/usb/usb.c
cvs rdiff -u -r1.70 -r1.71 src/sys/dev/usb/usb_mem.c
cvs rdiff -u -r1.237 -r1.238 src/sys/dev/usb/usb_subr.c
cvs rdiff -u -r1.182 -r1.183 src/sys/dev/usb/usbdi.c
cvs rdiff -u -r1.74 -r1.75 src/sys/dev/usb/usbdi_util.c
cvs rdiff -u -r1.8 -r1.9 src/sys/dev/usb/usbroothub.c

Please note that diffs are not public domain; they are subject to the
copyright notices on the relevant files.

Modified files:

Index: src/sys/dev/usb/uhub.c
diff -u src/sys/dev/usb/uhub.c:1.142 src/sys/dev/usb/uhub.c:1.143
--- src/sys/dev/usb/uhub.c:1.142	Sun May  5 03:17:54 2019
+++ src/sys/dev/usb/uhub.c	Wed Aug 21 10:48:37 2019
@@ -1,4 +1,4 @@
-/*	$NetBSD: uhub.c,v 1.142 2019/05/05 03:17:54 mrg Exp $	*/
+/*	$NetBSD: uhub.c,v 1.143 2019/08/21 10:48:37 mrg Exp $	*/
 /*	$FreeBSD: src/sys/dev/usb/uhub.c,v 1.18 1999/11/17 22:33:43 n_hibma Exp $	*/
 /*	$OpenBSD: uhub.c,v 1.86 2015/06/29 18:27:40 mpi Exp $ */
 
@@ -37,7 +37,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: uhub.c,v 1.142 2019/05/05 03:17:54 mrg Exp $");
+__KERNEL_RCSID(0, "$NetBSD: uhub.c,v 1.143 2019/08/21 10:48:37 mrg Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_usb.h"
@@ -98,8 +98,10 @@ fail:
 
 #define DPRINTF(FMT,A,B,C,D)	USBHIST_LOGN(uhubdebug,1,FMT,A,B,C,D)
 #define DPRINTFN(N,FMT,A,B,C,D)	USBHIST_LOGN(uhubdebug,N,FMT,A,B,C,D)
-#define UHUBHIST_FUNC() USBHIST_FUNC()
-#define UHUBHIST_CALLED(name) USBHIST_CALLED(uhubdebug)
+#define UHUBHIST_FUNC()		USBHIST_FUNC()
+#define UHUBHIST_CALLED(name)	USBHIST_CALLED(uhubdebug)
+#define UHUBHIST_CALLARGS(FMT,A,B,C,D) \
+				USBHIST_CALLARGS(uhubdebug,FMT,A,B,C,D)
 
 struct uhub_softc {
 	device_t		 sc_dev;	/* base device */
@@ -486,9 +488,8 @@ uhub_explore(struct usbd_device *dev)
 	int port;
 	int change, status, reconnect;
 
-	UHUBHIST_FUNC(); UHUBHIST_CALLED();
-
-	DPRINTFN(10, "uhub%jd dev=%#jx addr=%jd speed=%ju",
+	UHUBHIST_FUNC();
+	UHUBHIST_CALLARGS("uhub%jd dev=%#jx addr=%jd speed=%ju",
 	    device_unit(sc->sc_dev), (uintptr_t)dev, dev->ud_addr,
 	    dev->ud_speed);
 
@@ -759,8 +760,8 @@ uhub_explore(struct usbd_device *dev)
 			  dev->ud_depth + 1, speed, port, up);
 		/* XXX retry a few times? */
 		if (err) {
-			DPRINTF("usbd_new_device failed, error %jd", err, 0, 0,
-			    0);
+			DPRINTF("uhub%jd: usbd_new_device failed, error %jd",
+			    device_unit(sc->sc_dev), err, 0, 0);
 			/* Avoid addressing problems by disabling. */
 			/* usbd_reset_port(dev, port, &up->status); */
 
@@ -927,9 +928,8 @@ uhub_intr(struct usbd_xfer *xfer, void *
 {
 	struct uhub_softc *sc = addr;
 
-	UHUBHIST_FUNC(); UHUBHIST_CALLED();
-
-	DPRINTFN(5, "uhub%jd", device_unit(sc->sc_dev), 0, 0, 0);
+	UHUBHIST_FUNC(); UHUBHIST_CALLARGS("called! uhub%jd status=%jx",
+	    device_unit(sc->sc_dev), status, 0, 0);
 
 	if (status == USBD_STALLED)
 		usbd_clear_endpoint_stall_async(sc->sc_ipipe);

Index: src/sys/dev/usb/usb.c
diff -u src/sys/dev/usb/usb.c:1.179 src/sys/dev/usb/usb.c:1.180
--- src/sys/dev/usb/usb.c:1.179	Sun May  5 03:17:54 2019
+++ src/sys/dev/usb/usb.c	Wed Aug 21 10:48:37 2019
@@ -1,4 +1,4 @@
-/*	$NetBSD: usb.c,v 1.179 2019/05/05 03:17:54 mrg Exp $	*/
+/*	$NetBSD: usb.c,v 1.180 2019/08/21 10:48:37 mrg Exp $	*/
 
 /*
  * Copyright (c) 1998, 2002, 2008, 2012 The NetBSD Foundation, Inc.
@@ -37,7 +37,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: usb.c,v 1.179 2019/05/05 03:17:54 mrg Exp $");
+__KERNEL_RCSID(0, "$NetBSD: usb.c,v 1.180 2019/08/21 10:48:37 mrg Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_usb.h"
@@ -585,10 +585,11 @@ usb_task_thread(void *arg)
 	struct usb_taskq *taskq;
 	bool mpsafe;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
 	taskq = arg;
-	DPRINTF("start taskq %#jx", (uintptr_t)taskq, 0, 0, 0);
+
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "start taskq %#jx",
+	    (uintptr_t)taskq, 0, 0, 0);
 
 	mutex_enter(&taskq->lock);
 	for (;;) {
@@ -737,7 +738,7 @@ usbioctl(dev_t devt, u_long cmd, void *d
 	struct usb_softc *sc;
 	int unit = minor(devt);
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug, "cmd %#jx", cmd, 0, 0, 0);
 
 	if (unit == USB_DEV_MINOR) {
 		switch (cmd) {
@@ -765,7 +766,6 @@ usbioctl(dev_t devt, u_long cmd, void *d
 		return EIO;
 
 	int error = 0;
-	DPRINTF("cmd %#jx", cmd, 0, 0, 0);
 	switch (cmd) {
 #ifdef USB_DEBUG
 	case USB_SETDEBUG:
@@ -1149,9 +1149,8 @@ void
 usb_schedsoftintr(struct usbd_bus *bus)
 {
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	DPRINTFN(10, "polling=%jd", bus->ub_usepolling, 0, 0, 0);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "polling=%jd", bus->ub_usepolling, 0, 0, 0);
 
 	/* In case the bus never finished setting up. */
 	if (__predict_false(bus->ub_soft == NULL))

Index: src/sys/dev/usb/usb_mem.c
diff -u src/sys/dev/usb/usb_mem.c:1.70 src/sys/dev/usb/usb_mem.c:1.71
--- src/sys/dev/usb/usb_mem.c:1.70	Sat Oct 28 00:37:12 2017
+++ src/sys/dev/usb/usb_mem.c	Wed Aug 21 10:48:37 2019
@@ -1,4 +1,4 @@
-/*	$NetBSD: usb_mem.c,v 1.70 2017/10/28 00:37:12 pgoyette Exp $	*/
+/*	$NetBSD: usb_mem.c,v 1.71 2019/08/21 10:48:37 mrg Exp $	*/
 
 /*
  * Copyright (c) 1998 The NetBSD Foundation, Inc.
@@ -38,7 +38,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: usb_mem.c,v 1.70 2017/10/28 00:37:12 pgoyette Exp $");
+__KERNEL_RCSID(0, "$NetBSD: usb_mem.c,v 1.71 2019/08/21 10:48:37 mrg Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_usb.h"
@@ -115,8 +115,8 @@ usb_block_allocmem(bus_dma_tag_t tag, si
 	usb_dma_block_t *b;
 	int error;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-	DPRINTFN(5, "size=%ju align=%ju", size, align, 0, 0);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "size=%ju align=%ju", size, align, 0, 0);
 
 	ASSERT_SLEEPABLE();
 	KASSERT(size != 0);
@@ -236,11 +236,11 @@ usb_valid_block_p(usb_dma_block_t *b, st
 Static void
 usb_block_freemem(usb_dma_block_t *b)
 {
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "size=%ju", b->size, 0, 0, 0);
 
 	KASSERT(mutex_owned(&usb_blk_lock));
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-	DPRINTFN(6, "size=%ju", b->size, 0, 0, 0);
 #ifdef DEBUG
 	LIST_REMOVE(b, next);
 #endif

Index: src/sys/dev/usb/usb_subr.c
diff -u src/sys/dev/usb/usb_subr.c:1.237 src/sys/dev/usb/usb_subr.c:1.238
--- src/sys/dev/usb/usb_subr.c:1.237	Wed Aug  7 08:47:09 2019
+++ src/sys/dev/usb/usb_subr.c	Wed Aug 21 10:48:37 2019
@@ -1,4 +1,4 @@
-/*	$NetBSD: usb_subr.c,v 1.237 2019/08/07 08:47:09 maxv Exp $	*/
+/*	$NetBSD: usb_subr.c,v 1.238 2019/08/21 10:48:37 mrg Exp $	*/
 /*	$FreeBSD: src/sys/dev/usb/usb_subr.c,v 1.18 1999/11/17 22:33:47 n_hibma Exp $	*/
 
 /*
@@ -32,7 +32,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: usb_subr.c,v 1.237 2019/08/07 08:47:09 maxv Exp $");
+__KERNEL_RCSID(0, "$NetBSD: usb_subr.c,v 1.238 2019/08/21 10:48:37 mrg Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_compat_netbsd.h"
@@ -313,7 +313,7 @@ usbd_delay_ms(struct usbd_device *dev, u
 usbd_status
 usbd_reset_port(struct usbd_device *dev, int port, usb_port_status_t *ps)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug, "port %jd", port, 0, 0, 0);
 	usb_device_request_t req;
 	usbd_status err;
 	int n;
@@ -356,7 +356,9 @@ usbd_reset_port(struct usbd_device *dev,
 usb_interface_descriptor_t *
 usbd_find_idesc(usb_config_descriptor_t *cd, int ifaceidx, int altidx)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "iface/alt idx %jd/%jd",
+	    ifaceidx, altidx, 0, 0);
 	char *p = (char *)cd;
 	char *end = p + UGETW(cd->wTotalLength);
 	usb_descriptor_t *desc;
@@ -443,13 +445,14 @@ usbd_find_edesc(usb_config_descriptor_t 
 usbd_status
 usbd_fill_iface_data(struct usbd_device *dev, int ifaceidx, int altidx)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "ifaceidx=%jd altidx=%jd",
+	    ifaceidx, altidx, 0, 0);
 	struct usbd_interface *ifc = &dev->ud_ifaces[ifaceidx];
 	usb_interface_descriptor_t *idesc;
 	char *p, *end;
 	int endpt, nendpt;
 
-	DPRINTFN(4, "ifaceidx=%jd altidx=%jd", ifaceidx, altidx, 0, 0);
 	idesc = usbd_find_idesc(dev->ud_cdesc, ifaceidx, altidx);
 	if (idesc == NULL)
 		return USBD_INVAL;
@@ -542,10 +545,11 @@ usbd_free_iface_data(struct usbd_device 
 Static usbd_status
 usbd_set_config(struct usbd_device *dev, int conf)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
 	usb_device_request_t req;
 
-	DPRINTFN(5, "dev %#jx conf %jd", (uintptr_t)dev, conf, 0, 0);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx conf %jd",
+	    (uintptr_t)dev, conf, 0, 0);
 
 	req.bmRequestType = UT_WRITE_DEVICE;
 	req.bRequest = UR_SET_CONFIG;
@@ -558,7 +562,7 @@ usbd_set_config(struct usbd_device *dev,
 usbd_status
 usbd_set_config_no(struct usbd_device *dev, int no, int msg)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug, "%jd", no, 0, 0, 0);
 	usb_config_descriptor_t cd;
 	usbd_status err;
 	int index;
@@ -566,7 +570,6 @@ usbd_set_config_no(struct usbd_device *d
 	if (no == USB_UNCONFIG_NO)
 		return usbd_set_config_index(dev, USB_UNCONFIG_INDEX, msg);
 
-	DPRINTFN(5, "%jd", no, 0, 0, 0);
 	/* Figure out what config index to use. */
 	for (index = 0; index < dev->ud_ddesc.bNumConfigurations; index++) {
 		err = usbd_get_config_desc(dev, index, &cd);
@@ -581,13 +584,14 @@ usbd_set_config_no(struct usbd_device *d
 usbd_status
 usbd_set_config_index(struct usbd_device *dev, int index, int msg)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev=%#jx index=%jd",
+	    (uintptr_t)dev, index, 0, 0);
 	usb_config_descriptor_t cd, *cdp;
 	usb_bos_descriptor_t *bdp = NULL;
 	usbd_status err;
 	int i, ifcidx, nifc, len, selfpowered, power;
 
-	DPRINTFN(5, "dev=%#jx index=%jd", (uintptr_t)dev, index, 0, 0);
 
 	if (index >= dev->ud_ddesc.bNumConfigurations &&
 	    index != USB_UNCONFIG_INDEX) {
@@ -806,13 +810,13 @@ usbd_status
 usbd_setup_pipe_flags(struct usbd_device *dev, struct usbd_interface *iface,
     struct usbd_endpoint *ep, int ival, struct usbd_pipe **pipe, uint8_t flags)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev=%#jx addr=%jd iface=%#jx ep=%#jx",
+	    (uintptr_t)dev, dev->ud_addr, (uintptr_t)iface, (uintptr_t)ep);
 	struct usbd_pipe *p;
 	usbd_status err;
 
 	p = kmem_alloc(dev->ud_bus->ub_pipesize, KM_SLEEP);
-	DPRINTFN(1, "dev=%#jx addr=%jd iface=%#jx ep=%#jx",
-	    (uintptr_t)dev, dev->ud_addr, (uintptr_t)iface, (uintptr_t)ep);
 	DPRINTFN(1, "pipe=%#jx", (uintptr_t)p, 0, 0, 0);
 	p->up_dev = dev;
 	p->up_iface = iface;
@@ -1044,13 +1048,13 @@ usbd_status
 usbd_probe_and_attach(device_t parent, struct usbd_device *dev,
                       int port, int addr)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "trying device specific drivers", 0, 0, 0, 0);
 	usb_device_descriptor_t *dd = &dev->ud_ddesc;
 	int confi, nifaces;
 	usbd_status err;
 
 	/* First try with device specific drivers. */
-	DPRINTF("trying device specific drivers", 0, 0, 0, 0);
 	err = usbd_attachwholedevice(parent, dev, port, 0);
 	if (dev->ud_nifaces_claimed || err)
 		return err;
@@ -1161,13 +1165,12 @@ usbd_reattach_device(device_t parent, st
 usbd_status
 usbd_get_initial_ddesc(struct usbd_device *dev, usb_device_descriptor_t *desc)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx", (uintptr_t)dev, 0, 0, 0);
 	usb_device_request_t req;
 	char buf[64];
 	int res, actlen;
 
-	DPRINTFN(5, "dev %#jx", (uintptr_t)dev, 0, 0, 0);
-
 	req.bmRequestType = UT_READ_DEVICE;
 	req.bRequest = UR_GET_DESCRIPTOR;
 	USETW2(req.wValue, UDESC_DEVICE, 0);
@@ -1193,7 +1196,9 @@ usbd_status
 usbd_new_device(device_t parent, struct usbd_bus *bus, int depth, int speed,
     int port, struct usbd_port *up)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "bus=%#jx port=%jd depth=%jd speed=%jd",
+	    (uintptr_t)bus, port, depth, speed);
 	struct usbd_device *dev, *adev;
 	struct usbd_device *hub;
 	usb_device_descriptor_t *dd;
@@ -1203,9 +1208,6 @@ usbd_new_device(device_t parent, struct 
 	int i;
 	int p;
 
-	DPRINTF("bus=%#jx port=%jd depth=%jd speed=%jd",
-	    (uintptr_t)bus, port, depth, speed);
-
 	if (bus->ub_methods->ubm_newdev != NULL)
 		return (bus->ub_methods->ubm_newdev)(parent, bus, depth, speed,
 		    port, up);
@@ -1455,9 +1457,9 @@ void
 usbd_remove_device(struct usbd_device *dev, struct usbd_port *up)
 {
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	DPRINTF("dev %#jx up %#jx", (uintptr_t)dev, (uintptr_t)up, 0, 0);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx up %#jx",
+	    (uintptr_t)dev, (uintptr_t)up, 0, 0);
 
 	if (dev->ud_pipe0 != NULL)
 		usbd_kill_pipe(dev->ud_pipe0);
@@ -1670,15 +1672,15 @@ usb_free_device(struct usbd_device *dev)
 int
 usb_disconnect_port(struct usbd_port *up, device_t parent, int flags)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
 	struct usbd_device *dev = up->up_dev;
 	device_t subdev;
 	char subdevname[16];
 	const char *hubname = device_xname(parent);
 	int i, rc;
 
-	DPRINTFN(3, "up=%#jx dev=%#jx port=%jd", (uintptr_t)up, (uintptr_t)dev,
-	    up->up_portno, 0);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "up=%#jx dev=%#jx port=%jd",
+	    (uintptr_t)up, (uintptr_t)dev, up->up_portno, 0);
 
 	if (dev == NULL) {
 		return 0;

Index: src/sys/dev/usb/usbdi.c
diff -u src/sys/dev/usb/usbdi.c:1.182 src/sys/dev/usb/usbdi.c:1.183
--- src/sys/dev/usb/usbdi.c:1.182	Sun Feb 17 04:17:31 2019
+++ src/sys/dev/usb/usbdi.c	Wed Aug 21 10:48:37 2019
@@ -1,4 +1,4 @@
-/*	$NetBSD: usbdi.c,v 1.182 2019/02/17 04:17:31 rin Exp $	*/
+/*	$NetBSD: usbdi.c,v 1.183 2019/08/21 10:48:37 mrg Exp $	*/
 
 /*
  * Copyright (c) 1998, 2012, 2015 The NetBSD Foundation, Inc.
@@ -32,7 +32,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: usbdi.c,v 1.182 2019/02/17 04:17:31 rin Exp $");
+__KERNEL_RCSID(0, "$NetBSD: usbdi.c,v 1.183 2019/08/21 10:48:37 mrg Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_usb.h"
@@ -76,9 +76,9 @@ static void usbd_request_async_cb(struct
 void
 usbd_dump_iface(struct usbd_interface *iface)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "iface %#jx", (uintptr_t)iface, 0, 0, 0);
 
-	USBHIST_LOG(usbdebug, "iface %#jx", (uintptr_t)iface, 0, 0, 0);
 	if (iface == NULL)
 		return;
 	USBHIST_LOG(usbdebug, "     device = %#jx idesc = %#jx index = %d",
@@ -91,9 +91,9 @@ usbd_dump_iface(struct usbd_interface *i
 void
 usbd_dump_device(struct usbd_device *dev)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev = %#jx", (uintptr_t)dev, 0, 0, 0);
 
-	USBHIST_LOG(usbdebug, "dev = %#jx", (uintptr_t)dev, 0, 0, 0);
 	if (dev == NULL)
 		return;
 	USBHIST_LOG(usbdebug, "     bus = %#jx default_pipe = %#jx",
@@ -108,9 +108,9 @@ usbd_dump_device(struct usbd_device *dev
 void
 usbd_dump_endpoint(struct usbd_endpoint *endp)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "endp = %#jx", (uintptr_t)endp, 0, 0, 0);
 
-	USBHIST_LOG(usbdebug, "endp = %#jx", (uintptr_t)endp, 0, 0, 0);
 	if (endp == NULL)
 		return;
 	USBHIST_LOG(usbdebug, "    edesc = %#jx refcnt = %jd",
@@ -125,9 +125,9 @@ usbd_dump_queue(struct usbd_pipe *pipe)
 {
 	struct usbd_xfer *xfer;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "pipe = %#jx", (uintptr_t)pipe, 0, 0, 0);
 
-	USBHIST_LOG(usbdebug, "pipe = %#jx", (uintptr_t)pipe, 0, 0, 0);
 	SIMPLEQ_FOREACH(xfer, &pipe->up_queue, ux_next) {
 		USBHIST_LOG(usbdebug, "     xfer = %#jx", (uintptr_t)xfer,
 		    0, 0, 0);
@@ -137,9 +137,9 @@ usbd_dump_queue(struct usbd_pipe *pipe)
 void
 usbd_dump_pipe(struct usbd_pipe *pipe)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "pipe = %#jx", (uintptr_t)pipe, 0, 0, 0);
 
-	USBHIST_LOG(usbdebug, "pipe = %#jx", (uintptr_t)pipe, 0, 0, 0);
 	if (pipe == NULL)
 		return;
 	usbd_dump_iface(pipe->up_iface);
@@ -171,9 +171,8 @@ usbd_open_pipe_ival(struct usbd_interfac
 	usbd_status err;
 	int i;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	USBHIST_LOG(usbdebug, "iface = %#jx address = 0x%jx flags = 0x%jx",
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "iface = %#jx address = 0x%jx flags = 0x%jx",
 	    (uintptr_t)iface, address, flags, 0);
 
 	for (i = 0; i < iface->ui_idesc->bNumEndpoints; i++) {
@@ -205,9 +204,8 @@ usbd_open_pipe_intr(struct usbd_interfac
 	struct usbd_xfer *xfer;
 	struct usbd_pipe *ipipe;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	USBHIST_LOG(usbdebug, "address = 0x%jx flags = 0x%jx len = %jd",
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "address = 0x%jx flags = 0x%jx len = %jd",
 	    address, flags, len, 0);
 
 	err = usbd_open_pipe_ival(iface, address,
@@ -279,9 +277,7 @@ usbd_transfer(struct usbd_xfer *xfer)
 	usbd_status err;
 	unsigned int size, flags;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	USBHIST_LOG(usbdebug,
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug,
 	    "xfer = %#jx, flags = %#jx, pipe = %#jx, running = %jd",
 	    (uintptr_t)xfer, xfer->ux_flags, (uintptr_t)pipe, pipe->up_running);
 	KASSERT(xfer->ux_status == USBD_NOT_STARTED);
@@ -469,18 +465,19 @@ usbd_alloc_xfer(struct usbd_device *dev,
 {
 	struct usbd_xfer *xfer;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
 
 	ASSERT_SLEEPABLE();
 
 	xfer = dev->ud_bus->ub_methods->ubm_allocx(dev->ud_bus, nframes);
 	if (xfer == NULL)
-		return NULL;
+		goto out;
 	xfer->ux_bus = dev->ud_bus;
 	callout_init(&xfer->ux_callout, CALLOUT_MPSAFE);
 	cv_init(&xfer->ux_cv, "usbxfer");
 
-	USBHIST_LOG(usbdebug, "returns %#jx", (uintptr_t)xfer, 0, 0, 0);
+out:
+	USBHIST_CALLARGS(usbdebug, "returns %#jx", (uintptr_t)xfer, 0, 0, 0);
 
 	return xfer;
 }
@@ -488,9 +485,9 @@ usbd_alloc_xfer(struct usbd_device *dev,
 static usbd_status
 usbd_free_xfer(struct usbd_xfer *xfer)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "%#jx", (uintptr_t)xfer, 0, 0, 0);
 
-	USBHIST_LOG(usbdebug, "%#jx", (uintptr_t)xfer, 0, 0, 0);
 	if (xfer->ux_buf) {
 		usbd_free_buffer(xfer);
 	}
@@ -794,14 +791,14 @@ usbd_set_interface(struct usbd_interface
 	usbd_status err;
 	void *endpoints;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
 
 	if (LIST_FIRST(&iface->ui_pipes) != NULL)
 		return USBD_IN_USE;
 
 	endpoints = iface->ui_endpoints;
 	int nendpt = iface->ui_idesc->bNumEndpoints;
-	USBHIST_LOG(usbdebug, "iface %#jx endpoints = %#jx nendpt %jd",
+	USBHIST_CALLARGS(usbdebug, "iface %#jx endpoints = %#jx nendpt %jd",
 	    (uintptr_t)iface, (uintptr_t)endpoints,
 	    iface->ui_idesc->bNumEndpoints, 0);
 	err = usbd_fill_iface_data(iface->ui_dev, iface->ui_index, altidx);
@@ -869,11 +866,11 @@ usbd_ar_pipe(struct usbd_pipe *pipe)
 {
 	struct usbd_xfer *xfer;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "pipe = %#jx", (uintptr_t)pipe, 0, 0, 0);
 
 	KASSERT(mutex_owned(pipe->up_dev->ud_bus->ub_lock));
 
-	USBHIST_LOG(usbdebug, "pipe = %#jx", (uintptr_t)pipe, 0, 0, 0);
 #ifdef USB_DEBUG
 	if (usbdebug > 5)
 		usbd_dump_queue(pipe);
@@ -907,9 +904,8 @@ usb_transfer_complete(struct usbd_xfer *
 	int polling = bus->ub_usepolling;
 	int repeat = pipe->up_repeat;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	USBHIST_LOG(usbdebug, "pipe = %#jx xfer = %#jx status = %jd "
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "pipe = %#jx xfer = %#jx status = %jd "
 	    "actlen = %jd", (uintptr_t)pipe, (uintptr_t)xfer, xfer->ux_status,
 	    xfer->ux_actlen);
 
@@ -1028,10 +1024,9 @@ usb_insert_transfer(struct usbd_xfer *xf
 	struct usbd_pipe *pipe = xfer->ux_pipe;
 	usbd_status err;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	USBHIST_LOG(usbdebug, "xfer = %#jx pipe = %#jx running = %jd "
-	    "timeout = %jd", (uintptr_t)xfer, (uintptr_t)pipe,
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug,
+	    "xfer = %#jx pipe = %#jx running = %jd timeout = %jd",
+	    (uintptr_t)xfer, (uintptr_t)pipe,
 	    pipe->up_running, xfer->ux_timeout);
 
 	KASSERT(mutex_owned(pipe->up_dev->ud_bus->ub_lock));
@@ -1060,7 +1055,7 @@ usbd_start_next(struct usbd_pipe *pipe)
 	struct usbd_xfer *xfer;
 	usbd_status err;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
 
 	KASSERT(pipe != NULL);
 	KASSERT(pipe->up_methods != NULL);
@@ -1072,7 +1067,7 @@ usbd_start_next(struct usbd_pipe *pipe)
 
 	/* Get next request in queue. */
 	xfer = SIMPLEQ_FIRST(&pipe->up_queue);
-	USBHIST_LOG(usbdebug, "pipe = %#jx, xfer = %#jx", (uintptr_t)pipe,
+	USBHIST_CALLARGS(usbdebug, "pipe = %#jx, xfer = %#jx", (uintptr_t)pipe,
 	    (uintptr_t)xfer, 0, 0);
 	if (xfer == NULL) {
 		pipe->up_running = 0;
@@ -1105,10 +1100,13 @@ usbd_status
 usbd_do_request_flags(struct usbd_device *dev, usb_device_request_t *req,
     void *data, uint16_t flags, int *actlen, uint32_t timeout)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
 	struct usbd_xfer *xfer;
 	usbd_status err;
 
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev=%#jx req=%jx flgas=%jx len=%jx",
+	    (uintptr_t)dev, (uintptr_t)req, flags, actlen);
+
 	ASSERT_SLEEPABLE();
 
 	size_t len = UGETW(req->wLength);

Index: src/sys/dev/usb/usbdi_util.c
diff -u src/sys/dev/usb/usbdi_util.c:1.74 src/sys/dev/usb/usbdi_util.c:1.75
--- src/sys/dev/usb/usbdi_util.c:1.74	Wed Jul 31 19:40:59 2019
+++ src/sys/dev/usb/usbdi_util.c	Wed Aug 21 10:48:37 2019
@@ -1,4 +1,4 @@
-/*	$NetBSD: usbdi_util.c,v 1.74 2019/07/31 19:40:59 maxv Exp $	*/
+/*	$NetBSD: usbdi_util.c,v 1.75 2019/08/21 10:48:37 mrg Exp $	*/
 
 /*
  * Copyright (c) 1998, 2012 The NetBSD Foundation, Inc.
@@ -31,7 +31,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: usbdi_util.c,v 1.74 2019/07/31 19:40:59 maxv Exp $");
+__KERNEL_RCSID(0, "$NetBSD: usbdi_util.c,v 1.75 2019/08/21 10:48:37 mrg Exp $");
 
 #ifdef _KERNEL_OPT
 #include "opt_usb.h"
@@ -62,9 +62,9 @@ usbd_get_desc(struct usbd_device *dev, i
 	usb_device_request_t req;
 	usbd_status err;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
-
-	DPRINTFN(3,"type=%jd, index=%jd, len=%jd", type, index, len, 0);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "type=%jd, index=%jd, len=%jd",
+	    type, index, len, 0);
 
 	/*
 	 * Provide hard-coded configuration descriptors
@@ -93,10 +93,10 @@ usbd_status
 usbd_get_config_desc(struct usbd_device *dev, int confidx,
 		     usb_config_descriptor_t *d)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "confidx=%jd", confidx, 0, 0, 0);
 	usbd_status err;
 
-	DPRINTFN(3, "confidx=%jd", confidx, 0, 0, 0);
 	err = usbd_get_desc(dev, UDESC_CONFIG, confidx,
 			    USB_CONFIG_DESCRIPTOR_SIZE, d);
 	if (err)
@@ -112,9 +112,8 @@ usbd_get_config_desc(struct usbd_device 
 usbd_status
 usbd_get_config_desc_full(struct usbd_device *dev, int conf, void *d, int size)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug, "conf=%jd", conf, 0, 0, 0);
 
-	DPRINTFN(3, "conf=%jd", conf, 0, 0, 0);
 	return usbd_get_desc(dev, UDESC_CONFIG, conf, size, d);
 }
 
@@ -122,10 +121,10 @@ usbd_status
 usbd_get_bos_desc(struct usbd_device *dev, int confidx,
 		     usb_bos_descriptor_t *d)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "confidx=%jd", confidx, 0, 0, 0);
 	usbd_status err;
 
-	DPRINTFN(3, "confidx=%jd", confidx, 0, 0, 0);
 	err = usbd_get_desc(dev, UDESC_BOS, confidx,
 			    USB_BOS_DESCRIPTOR_SIZE, d);
 	if (err)
@@ -141,9 +140,8 @@ usbd_get_bos_desc(struct usbd_device *de
 usbd_status
 usbd_get_bos_desc_full(struct usbd_device *dev, int conf, void *d, int size)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug, "conf=%jd", conf, 0, 0, 0);
 
-	DPRINTFN(3, "conf=%jd", conf, 0, 0, 0);
 	return usbd_get_desc(dev, UDESC_BOS, conf, size, d);
 }
 
@@ -173,10 +171,10 @@ usbd_get_device_status(struct usbd_devic
 usbd_status
 usbd_get_hub_status(struct usbd_device *dev, usb_hub_status_t *st)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx", (uintptr_t)dev, 0, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx", (uintptr_t)dev, 0, 0, 0);
 	req.bmRequestType = UT_READ_CLASS_DEVICE;
 	req.bRequest = UR_GET_STATUS;
 	USETW(req.wValue, 0);
@@ -188,10 +186,11 @@ usbd_get_hub_status(struct usbd_device *
 usbd_status
 usbd_set_address(struct usbd_device *dev, int addr)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx addr %jd",
+	    (uintptr_t)dev, addr, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx addr %jd", (uintptr_t)dev, addr, 0, 0);
 	req.bmRequestType = UT_WRITE_DEVICE;
 	req.bRequest = UR_SET_ADDRESS;
 	USETW(req.wValue, addr);
@@ -203,10 +202,11 @@ usbd_set_address(struct usbd_device *dev
 usbd_status
 usbd_get_port_status(struct usbd_device *dev, int port, usb_port_status_t *ps)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx port %jd",
+	    (uintptr_t)dev, port, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx port %jd", (uintptr_t)dev, port, 0, 0);
 	req.bmRequestType = UT_READ_CLASS_OTHER;
 	req.bRequest = UR_GET_STATUS;
 	USETW(req.wValue, 0);
@@ -220,10 +220,11 @@ usbd_status
 usbd_get_port_status_ext(struct usbd_device *dev, int port,
     usb_port_status_ext_t *pse)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx port %jd",
+	    (uintptr_t)dev, port, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx port %jd", (uintptr_t)dev, port, 0, 0);
 	req.bmRequestType = UT_READ_CLASS_OTHER;
 	req.bRequest = UR_GET_STATUS;
 	USETW2(req.wValue, 0, UR_PST_EXT_PORT_STATUS);
@@ -235,10 +236,11 @@ usbd_get_port_status_ext(struct usbd_dev
 usbd_status
 usbd_clear_hub_feature(struct usbd_device *dev, int sel)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx sel %jd",
+	    (uintptr_t)dev, sel, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx sel %jd", (uintptr_t)dev, sel, 0, 0);
 	req.bmRequestType = UT_WRITE_CLASS_DEVICE;
 	req.bRequest = UR_CLEAR_FEATURE;
 	USETW(req.wValue, sel);
@@ -250,10 +252,11 @@ usbd_clear_hub_feature(struct usbd_devic
 usbd_status
 usbd_set_hub_feature(struct usbd_device *dev, int sel)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug,
+	    "dev %#jx sel %jd", (uintptr_t)dev, sel, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx sel %jd", (uintptr_t)dev, sel, 0, 0);
 	req.bmRequestType = UT_WRITE_CLASS_DEVICE;
 	req.bRequest = UR_SET_FEATURE;
 	USETW(req.wValue, sel);
@@ -265,10 +268,11 @@ usbd_set_hub_feature(struct usbd_device 
 usbd_status
 usbd_clear_port_feature(struct usbd_device *dev, int port, int sel)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx port %jd sel %jd",
+	    (uintptr_t)dev, port, sel, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx port %jd sel %jd", (uintptr_t)dev, port, sel, 0);
 	req.bmRequestType = UT_WRITE_CLASS_OTHER;
 	req.bRequest = UR_CLEAR_FEATURE;
 	USETW(req.wValue, sel);
@@ -280,10 +284,11 @@ usbd_clear_port_feature(struct usbd_devi
 usbd_status
 usbd_set_port_feature(struct usbd_device *dev, int port, int sel)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx port %jd sel %.d",
+	    (uintptr_t)dev, sel, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx port %jd sel %.d", (uintptr_t)dev, sel, 0, 0);
 	req.bmRequestType = UT_WRITE_CLASS_OTHER;
 	req.bRequest = UR_SET_FEATURE;
 	USETW(req.wValue, sel);
@@ -295,11 +300,11 @@ usbd_set_port_feature(struct usbd_device
 usbd_status
 usbd_set_port_u1_timeout(struct usbd_device *dev, int port, int timeout)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx port %jd timeout %.d",
+	    (uintptr_t)dev, port, timeout, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx port %jd timeout %.d", (uintptr_t)dev, port,
-	    timeout, 0);
 	req.bmRequestType = UT_WRITE_CLASS_OTHER;
 	req.bRequest = UR_SET_FEATURE;
 	USETW(req.wValue, UHF_PORT_U1_TIMEOUT);
@@ -311,11 +316,11 @@ usbd_set_port_u1_timeout(struct usbd_dev
 usbd_status
 usbd_set_port_u2_timeout(struct usbd_device *dev, int port, int timeout)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx port %jd timeout %jd",
+	    (uintptr_t)dev, port, timeout, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx port %jd timeout %jd", (uintptr_t)dev, port,
-	    timeout, 0);
 	req.bmRequestType = UT_WRITE_CLASS_OTHER;
 	req.bRequest = UR_SET_FEATURE;
 	USETW(req.wValue, UHF_PORT_U2_TIMEOUT);
@@ -331,12 +336,12 @@ usbd_get_protocol(struct usbd_interface 
 	struct usbd_device *dev;
 	usb_device_request_t req;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "iface=%#jx, endpt=%jd",
+	    (uintptr_t)iface, id->bInterfaceNumber, 0, 0);
 
 	if (id == NULL)
 		return USBD_IOERROR;
-	DPRINTFN(4, "iface=%#jx, endpt=%jd", (uintptr_t)iface,
-	    id->bInterfaceNumber, 0, 0);
 
 	usbd_interface2device_handle(iface, &dev);
 	req.bmRequestType = UT_READ_CLASS_INTERFACE;
@@ -354,12 +359,12 @@ usbd_set_protocol(struct usbd_interface 
 	struct usbd_device *dev;
 	usb_device_request_t req;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "iface=%#jx, report=%jd, endpt=%jd",
+	    (uintptr_t)iface, report, id->bInterfaceNumber, 0);
 
 	if (id == NULL)
 		return USBD_IOERROR;
-	DPRINTFN(4, "iface=%#jx, report=%jd, endpt=%jd", (uintptr_t)iface,
-	    report, id->bInterfaceNumber, 0);
 
 	usbd_interface2device_handle(iface, &dev);
 	req.bmRequestType = UT_WRITE_CLASS_INTERFACE;
@@ -378,9 +383,9 @@ usbd_set_report(struct usbd_interface *i
 	struct usbd_device *dev;
 	usb_device_request_t req;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "len=%jd", len, 0, 0, 0);
 
-	DPRINTFN(4, "len=%jd", len, 0, 0, 0);
 	if (ifd == NULL)
 		return USBD_IOERROR;
 	usbd_interface2device_handle(iface, &dev);
@@ -400,9 +405,8 @@ usbd_get_report(struct usbd_interface *i
 	struct usbd_device *dev;
 	usb_device_request_t req;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC(); USBHIST_CALLARGS(usbdebug, "len=%jd", len, 0, 0, 0);
 
-	DPRINTFN(4, "len=%jd", len, 0, 0, 0);
 	if (ifd == NULL)
 		return USBD_IOERROR;
 	usbd_interface2device_handle(iface, &dev);
@@ -421,9 +425,9 @@ usbd_set_idle(struct usbd_interface *ifa
 	struct usbd_device *dev;
 	usb_device_request_t req;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "duration %jd id %jd", duration, id, 0, 0);
 
-	DPRINTFN(4, "duration %jd id %jd", duration, id, 0, 0);
 	if (ifd == NULL)
 		return USBD_IOERROR;
 	usbd_interface2device_handle(iface, &dev);
@@ -439,10 +443,11 @@ usbd_status
 usbd_get_report_descriptor(struct usbd_device *dev, int ifcno,
 			   int size, void *d)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx ifcno %jd size %jd",
+	    (uintptr_t)dev, ifcno, size, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx ifcno %jd size %jd", (uintptr_t)dev, ifcno, size, 0);
 	req.bmRequestType = UT_READ_INTERFACE;
 	req.bRequest = UR_GET_DESCRIPTOR;
 	USETW2(req.wValue, UDESC_REPORT, 0); /* report id should be 0 */
@@ -512,10 +517,10 @@ usbd_read_report_desc(struct usbd_interf
 usbd_status
 usbd_get_config(struct usbd_device *dev, uint8_t *conf)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "dev %#jx", (uintptr_t)dev, 0, 0, 0);
 	usb_device_request_t req;
 
-	DPRINTF("dev %#jx", (uintptr_t)dev, 0, 0, 0);
 	req.bmRequestType = UT_READ_DEVICE;
 	req.bRequest = UR_GET_CONFIG;
 	USETW(req.wValue, 0);
@@ -530,10 +535,10 @@ usbd_bulk_transfer(struct usbd_xfer *xfe
 {
 	usbd_status err;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "start transfer %jd bytes", *size, 0, 0, 0);
 
 	usbd_setup_xfer(xfer, 0, buf, *size, flags, timeout, NULL);
-	DPRINTFN(1, "start transfer %jd bytes", *size, 0, 0, 0);
 	err = usbd_sync_transfer_sig(xfer);
 
 	usbd_get_xfer_status(xfer, NULL, NULL, size, NULL);
@@ -553,11 +558,11 @@ usbd_intr_transfer(struct usbd_xfer *xfe
 {
 	usbd_status err;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "start transfer %jd bytes", *size, 0, 0, 0);
 
 	usbd_setup_xfer(xfer, 0, buf, *size, flags, timeout, NULL);
 
-	DPRINTFN(1, "start transfer %jd bytes", *size, 0, 0, 0);
 	err = usbd_sync_transfer_sig(xfer);
 
 	usbd_get_xfer_status(xfer, NULL, NULL, size, NULL);
@@ -575,9 +580,10 @@ usbd_intr_transfer(struct usbd_xfer *xfe
 void
 usb_detach_waitold(device_t dv)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "waiting for dv %#jx",
+	    (uintptr_t)dv, 0, 0, 0);
 
-	DPRINTFN(1, "waiting for dv %#jx", (uintptr_t)dv, 0, 0, 0);
 	if (tsleep(dv, PZERO, "usbdet", hz * 60)) /* XXXSMP ok */
 		aprint_error_dev(dv, "usb_detach_waitold: didn't detach\n");
 	DPRINTFN(1, "done", 0, 0, 0, 0);
@@ -586,9 +592,9 @@ usb_detach_waitold(device_t dv)
 void
 usb_detach_wakeupold(device_t dv)
 {
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
+	USBHIST_CALLARGS(usbdebug, "for dv %#jx", (uintptr_t)dv, 0, 0, 0);
 
-	DPRINTFN(1, "for dv %#jx", (uintptr_t)dv, 0, 0, 0);
 	wakeup(dv); /* XXXSMP ok */
 }
 

Index: src/sys/dev/usb/usbroothub.c
diff -u src/sys/dev/usb/usbroothub.c:1.8 src/sys/dev/usb/usbroothub.c:1.9
--- src/sys/dev/usb/usbroothub.c:1.8	Sun Jan 27 02:08:42 2019
+++ src/sys/dev/usb/usbroothub.c	Wed Aug 21 10:48:37 2019
@@ -1,4 +1,4 @@
-/* $NetBSD: usbroothub.c,v 1.8 2019/01/27 02:08:42 pgoyette Exp $ */
+/* $NetBSD: usbroothub.c,v 1.9 2019/08/21 10:48:37 mrg Exp $ */
 
 /*-
  * Copyright (c) 1998, 2004, 2011, 2012 The NetBSD Foundation, Inc.
@@ -58,7 +58,7 @@
  */
 
 #include <sys/cdefs.h>
-__KERNEL_RCSID(0, "$NetBSD: usbroothub.c,v 1.8 2019/01/27 02:08:42 pgoyette Exp $");
+__KERNEL_RCSID(0, "$NetBSD: usbroothub.c,v 1.9 2019/08/21 10:48:37 mrg Exp $");
 
 #include <dev/usb/usb.h>
 #include <dev/usb/usbdi.h>
@@ -366,20 +366,20 @@ roothub_ctrl_start(struct usbd_xfer *xfe
 	usb_device_request_t *req;
 	usbd_status err = USBD_IOERROR;		/* XXX STALL? */
 	uint16_t len, value;
-	int buflen, actlen;
+	int buflen, actlen = -1;
 	void *buf;
 
-	USBHIST_FUNC(); USBHIST_CALLED(usbdebug);
+	USBHIST_FUNC();
 
 	KASSERT(xfer->ux_rqflags & URQ_REQUEST);
 	req = &xfer->ux_request;
 
-	USBHIST_LOG(usbdebug, "type=%#2jx request=%#2jx", req->bmRequestType,
-	    req->bRequest, 0, 0);
-
 	len = UGETW(req->wLength);
 	value = UGETW(req->wValue);
 
+	USBHIST_CALLARGS(usbdebug, "type=%#jx request=%#jx len=%#jx value=%#jx",
+	    req->bmRequestType, req->bRequest, len, value);
+
 	buf = len ? usbd_get_buffer(xfer) : NULL;
 	buflen = 0;
 
@@ -553,8 +553,6 @@ roothub_ctrl_start(struct usbd_xfer *xfe
 	}
 
 	actlen = bus->ub_methods->ubm_rhctrl(bus, req, buf, buflen);
-	USBHIST_LOG(usbdebug, "xfer %#jx buflen %jd actlen %jd",
-	    (uintptr_t)xfer, buflen, actlen, 0);
 	if (actlen < 0)
 		goto fail;
 
@@ -562,7 +560,8 @@ roothub_ctrl_start(struct usbd_xfer *xfe
 	err = USBD_NORMAL_COMPLETION;
 
  fail:
-	USBHIST_LOG(usbdebug, "xfer %#jx err %jd", (uintptr_t)xfer, err, 0, 0);
+	USBHIST_LOG(usbdebug, "xfer %#jx buflen %jd actlen %jd err %jd",
+	    (uintptr_t)xfer, buflen, actlen, err);
 
 	xfer->ux_status = err;
 	mutex_enter(bus->ub_lock);

Reply via email to