USB: usbtest displays diagnostics again

Minor cleanup to the "usbtest" driver, mostly to resolve a regression:
all the important diagnostics were at KERN_DEBUG, so that when the
"#define DEBUG" was removed from the top of that file it stopped
providing diagnostics.  Fix by using KERN_ERROR.  Also:

 - Stop using the legacy dbg() calls
 - Simplify the internal debug macros
 - Correct some test descriptions:
	* Test #10 subcase 7 should *always* stall
	* Test #10 subcase 8 *may* stall
 - Diagnostic about control queue test failures is more informative
 - Fix some whitespace "bugs"

And add a warning about the rude interaction between usbfs ioctl()
and khubd during device disconnect ... don't unplug a device under
test, that will wedge.

Signed-off-by: David Brownell <dbrownell@users.sourceforge.net>
Signed-off-by: Greg Kroah-Hartman <gregkh@suse.de>

1 files changed, 133 insertions, 143 deletions

diff --git a/drivers/usb/misc/usbtest.c b/drivers/usb/misc/usbtest.c
index a51983854ca0..742be3c35947 100644
--- a/drivers/usb/misc/usbtest.c
+++ b/drivers/usb/misc/usbtest.c
@@ -79,30 +79,10 @@ static struct usb_device *testdev_to_usbdev (struct usbtest_dev *test)
 /* set up all urbs so they can be used with either bulk or interrupt */
 #define INTERRUPT_RATE          1       /* msec/transfer */
 
-#define xprintk(tdev,level,fmt,args...) \
-        dev_printk(level ,  &(tdev)->intf->dev ,  fmt ,  ## args)
-
-#ifdef DEBUG
-#define DBG(dev,fmt,args...) \
-        xprintk(dev , KERN_DEBUG , fmt , ## args)
-#else
-#define DBG(dev,fmt,args...) \
-        do { } while (0)
-#endif /* DEBUG */
-
-#ifdef VERBOSE
-#define VDBG DBG
-#else
-#define VDBG(dev,fmt,args...) \
-        do { } while (0)
-#endif  /* VERBOSE */
-
-#define ERROR(dev,fmt,args...) \
-        xprintk(dev , KERN_ERR , fmt , ## args)
-#define WARN(dev,fmt,args...) \
-        xprintk(dev , KERN_WARNING , fmt , ## args)
-#define INFO(dev,fmt,args...) \
-        xprintk(dev , KERN_INFO , fmt , ## args)
+#define ERROR(tdev, fmt, args...) \
+        dev_err(&(tdev)->intf->dev , fmt , ## args)
+#define WARN(tdev, fmt, args...) \
+        dev_warn(&(tdev)->intf->dev , fmt , ## args)
 
 /*-------------------------------------------------------------------------*/
 
@@ -236,7 +216,7 @@ static struct urb *simple_alloc_urb (
 
 static unsigned pattern = 0;
 module_param (pattern, uint, S_IRUGO);
-// MODULE_PARM_DESC (pattern, "i/o pattern (0 == zeroes)");
+MODULE_PARM_DESC(pattern, "i/o pattern (0 == zeroes)");
 
 static inline void simple_fill_buf (struct urb *urb)
 {
@@ -257,7 +237,7 @@ static inline void simple_fill_buf (struct urb *urb)
         }
 }
 
-static inline int simple_check_buf (struct urb *urb)
+static inline int simple_check_buf(struct usbtest_dev *tdev, struct urb *urb)
 {
         unsigned        i;
         u8              expected;
@@ -285,7 +265,7 @@ static inline int simple_check_buf (struct urb *urb)
                 }
                 if (*buf == expected)
                         continue;
-                dbg ("buf[%d] = %d (not %d)", i, *buf, expected);
+                ERROR(tdev, "buf[%d] = %d (not %d)\n", i, *buf, expected);
                 return -EINVAL;
         }
         return 0;
@@ -299,6 +279,7 @@ static void simple_free_urb (struct urb *urb)
 }
 
 static int simple_io (
+        struct usbtest_dev      *tdev,
         struct urb              *urb,
         int                     iterations,
         int                     vary,
@@ -324,7 +305,7 @@ static int simple_io (
                 retval = urb->status;
                 urb->dev = udev;
                 if (retval == 0 && usb_pipein (urb->pipe))
-                        retval = simple_check_buf (urb);
+                        retval = simple_check_buf(tdev, urb);
 
                 if (vary) {
                         int     len = urb->transfer_buffer_length;
@@ -341,7 +322,7 @@ static int simple_io (
         urb->transfer_buffer_length = max;
 
         if (expected != retval)
-                dev_dbg (&udev->dev,
+                dev_err(&udev->dev,
                         "%s failed, iterations left %d, status %d (not %d)\n",
                                 label, iterations, retval, expected);
         return retval;
@@ -357,7 +338,7 @@ static int simple_io (
 static void free_sglist (struct scatterlist *sg, int nents)
 {
         unsigned                i;
-        
+
         if (!sg)
                 return;
         for (i = 0; i < nents; i++) {
@@ -415,7 +396,7 @@ alloc_sglist (int nents, int max, int vary)
 }
 
 static int perform_sglist (
-        struct usb_device       *udev,
+        struct usbtest_dev      *tdev,
         unsigned                iterations,
         int                     pipe,
         struct usb_sg_request   *req,
@@ -423,6 +404,7 @@ static int perform_sglist (
         int                     nents
 )
 {
+        struct usb_device       *udev = testdev_to_usbdev(tdev);
         int                     retval = 0;
 
         while (retval == 0 && iterations-- > 0) {
@@ -431,7 +413,7 @@ static int perform_sglist (
                                         ? (INTERRUPT_RATE << 3)
                                         : INTERRUPT_RATE,
                                 sg, nents, 0, GFP_KERNEL);
-                
+
                 if (retval)
                         break;
                 usb_sg_wait (req);
@@ -446,7 +428,8 @@ static int perform_sglist (
         // failure if retval is as we expected ...
 
         if (retval)
-                dbg ("perform_sglist failed, iterations left %d, status %d",
+                ERROR(tdev, "perform_sglist failed, "
+                                "iterations left %d, status %d\n",
                                 iterations, retval);
         return retval;
 }
@@ -505,28 +488,28 @@ static int set_altsetting (struct usbtest_dev *dev, int alternate)
                         alternate);
 }
 
-static int is_good_config (char *buf, int len)
+static int is_good_config(struct usbtest_dev *tdev, int len)
 {
         struct usb_config_descriptor    *config;
-        
+
         if (len < sizeof *config)
                 return 0;
-        config = (struct usb_config_descriptor *) buf;
+        config = (struct usb_config_descriptor *) tdev->buf;
 
         switch (config->bDescriptorType) {
         case USB_DT_CONFIG:
         case USB_DT_OTHER_SPEED_CONFIG:
                 if (config->bLength != 9) {
-                        dbg ("bogus config descriptor length");
+                        ERROR(tdev, "bogus config descriptor length\n");
                         return 0;
                 }
                 /* this bit 'must be 1' but often isn't */
                 if (!realworld && !(config->bmAttributes & 0x80)) {
-                        dbg ("high bit of config attributes not set");
+                        ERROR(tdev, "high bit of config attributes not set\n");
                         return 0;
                 }
                 if (config->bmAttributes & 0x1f) {      /* reserved == 0 */
-                        dbg ("reserved config bits set");
+                        ERROR(tdev, "reserved config bits set\n");
                         return 0;
                 }
                 break;
@@ -538,7 +521,7 @@ static int is_good_config (char *buf, int len)
                 return 1;
         if (le16_to_cpu(config->wTotalLength) >= TBUF_SIZE)             /* max partial read */
                 return 1;
-        dbg ("bogus config descriptor read size");
+        ERROR(tdev, "bogus config descriptor read size\n");
         return 0;
 }
 
@@ -571,7 +554,7 @@ static int ch9_postconfig (struct usbtest_dev *dev)
                 /* 9.2.3 constrains the range here */
                 alt = iface->altsetting [i].desc.bAlternateSetting;
                 if (alt < 0 || alt >= iface->num_altsetting) {
-                        dev_dbg (&iface->dev,
+                        dev_err(&iface->dev,
                                         "invalid alt [%d].bAltSetting = %d\n",
                                         i, alt);
                 }
@@ -583,7 +566,7 @@ static int ch9_postconfig (struct usbtest_dev *dev)
                 /* [9.4.10] set_interface */
                 retval = set_altsetting (dev, alt);
                 if (retval) {
-                        dev_dbg (&iface->dev, "can't set_interface = %d, %d\n",
+                        dev_err(&iface->dev, "can't set_interface = %d, %d\n",
                                         alt, retval);
                         return retval;
                 }
@@ -591,7 +574,7 @@ static int ch9_postconfig (struct usbtest_dev *dev)
                 /* [9.4.4] get_interface always works */
                 retval = get_altsetting (dev);
                 if (retval != alt) {
-                        dev_dbg (&iface->dev, "get alt should be %d, was %d\n",
+                        dev_err(&iface->dev, "get alt should be %d, was %d\n",
                                         alt, retval);
                         return (retval < 0) ? retval : -EDOM;
                 }
@@ -611,7 +594,7 @@ static int ch9_postconfig (struct usbtest_dev *dev)
                                 USB_DIR_IN | USB_RECIP_DEVICE,
                                 0, 0, dev->buf, 1, USB_CTRL_GET_TIMEOUT);
                 if (retval != 1 || dev->buf [0] != expected) {
-                        dev_dbg (&iface->dev, "get config --> %d %d (1 %d)\n",
+                        dev_err(&iface->dev, "get config --> %d %d (1 %d)\n",
                                 retval, dev->buf[0], expected);
                         return (retval < 0) ? retval : -EDOM;
                 }
@@ -621,7 +604,7 @@ static int ch9_postconfig (struct usbtest_dev *dev)
         retval = usb_get_descriptor (udev, USB_DT_DEVICE, 0,
                         dev->buf, sizeof udev->descriptor);
         if (retval != sizeof udev->descriptor) {
-                dev_dbg (&iface->dev, "dev descriptor --> %d\n", retval);
+                dev_err(&iface->dev, "dev descriptor --> %d\n", retval);
                 return (retval < 0) ? retval : -EDOM;
         }
 
@@ -629,8 +612,8 @@ static int ch9_postconfig (struct usbtest_dev *dev)
         for (i = 0; i < udev->descriptor.bNumConfigurations; i++) {
                 retval = usb_get_descriptor (udev, USB_DT_CONFIG, i,
                                 dev->buf, TBUF_SIZE);
-                if (!is_good_config (dev->buf, retval)) {
-                        dev_dbg (&iface->dev,
+                if (!is_good_config(dev, retval)) {
+                        dev_err(&iface->dev,
                                         "config [%d] descriptor --> %d\n",
                                         i, retval);
                         return (retval < 0) ? retval : -EDOM;
@@ -650,14 +633,14 @@ static int ch9_postconfig (struct usbtest_dev *dev)
                                 sizeof (struct usb_qualifier_descriptor));
                 if (retval == -EPIPE) {
                         if (udev->speed == USB_SPEED_HIGH) {
-                                dev_dbg (&iface->dev,
+                                dev_err(&iface->dev,
                                                 "hs dev qualifier --> %d\n",
                                                 retval);
                                 return (retval < 0) ? retval : -EDOM;
                         }
                         /* usb2.0 but not high-speed capable; fine */
                 } else if (retval != sizeof (struct usb_qualifier_descriptor)) {
-                        dev_dbg (&iface->dev, "dev qualifier --> %d\n", retval);
+                        dev_err(&iface->dev, "dev qualifier --> %d\n", retval);
                         return (retval < 0) ? retval : -EDOM;
                 } else
                         d = (struct usb_qualifier_descriptor *) dev->buf;
@@ -669,8 +652,8 @@ static int ch9_postconfig (struct usbtest_dev *dev)
                                 retval = usb_get_descriptor (udev,
                                         USB_DT_OTHER_SPEED_CONFIG, i,
                                         dev->buf, TBUF_SIZE);
-                                if (!is_good_config (dev->buf, retval)) {
-                                        dev_dbg (&iface->dev,
+                                if (!is_good_config(dev, retval)) {
+                                        dev_err(&iface->dev,
                                                 "other speed config --> %d\n",
                                                 retval);
                                         return (retval < 0) ? retval : -EDOM;
@@ -683,7 +666,7 @@ static int ch9_postconfig (struct usbtest_dev *dev)
         /* [9.4.5] get_status always works */
         retval = usb_get_status (udev, USB_RECIP_DEVICE, 0, dev->buf);
         if (retval != 2) {
-                dev_dbg (&iface->dev, "get dev status --> %d\n", retval);
+                dev_err(&iface->dev, "get dev status --> %d\n", retval);
                 return (retval < 0) ? retval : -EDOM;
         }
 
@@ -693,11 +676,11 @@ static int ch9_postconfig (struct usbtest_dev *dev)
         retval = usb_get_status (udev, USB_RECIP_INTERFACE,
                         iface->altsetting [0].desc.bInterfaceNumber, dev->buf);
         if (retval != 2) {
-                dev_dbg (&iface->dev, "get interface status --> %d\n", retval);
+                dev_err(&iface->dev, "get interface status --> %d\n", retval);
                 return (retval < 0) ? retval : -EDOM;
         }
         // FIXME get status for each endpoint in the interface
-        
+
         return 0;
 }
 
@@ -752,8 +735,9 @@ static void ctrl_complete (struct urb *urb)
          */
         if (subcase->number > 0) {
                 if ((subcase->number - ctx->last) != 1) {
-                        dbg ("subcase %d completed out of order, last %d",
-                                        subcase->number, ctx->last);
+                        ERROR(ctx->dev,
+                                "subcase %d completed out of order, last %d\n",
+                                subcase->number, ctx->last);
                         status = -EDOM;
                         ctx->last = subcase->number;
                         goto error;
@@ -777,7 +761,7 @@ static void ctrl_complete (struct urb *urb)
                 else if (subcase->number == 12 && status == -EPIPE)
                         status = 0;
                 else
-                        dbg ("subtest %d error, status %d",
+                        ERROR(ctx->dev, "subtest %d error, status %d\n",
                                         subcase->number, status);
         }
 
@@ -788,9 +772,12 @@ error:
                         int             i;
 
                         ctx->status = status;
-                        info ("control queue %02x.%02x, err %d, %d left",
+                        ERROR(ctx->dev, "control queue %02x.%02x, err %d, "
+                                        "%d left, subcase %d, len %d/%d\n",
                                         reqp->bRequestType, reqp->bRequest,
-                                        status, ctx->count);
+                                        status, ctx->count, subcase->number,
+                                        urb->actual_length,
+                                        urb->transfer_buffer_length);
 
                         /* FIXME this "unlink everything" exit route should
                          * be a separate test case.
@@ -799,7 +786,8 @@ error:
                         /* unlink whatever's still pending */
                         for (i = 1; i < ctx->param->sglen; i++) {
                                 struct urb      *u = ctx->urb [
-        (i + subcase->number) % ctx->param->sglen];
+                                                (i + subcase->number)
+                                                % ctx->param->sglen];
 
                                 if (u == urb || !u->dev)
                                         continue;
@@ -812,7 +800,8 @@ error:
                                 case -EIDRM:
                                         continue;
                                 default:
-                                        dbg ("urb unlink --> %d", status);
+                                        ERROR(ctx->dev, "urb unlink --> %d\n",
+                                                        status);
                                 }
                         }
                         status = ctx->status;
@@ -822,14 +811,15 @@ error:
         /* resubmit if we need to, else mark this as done */
         if ((status == 0) && (ctx->pending < ctx->count)) {
                 if ((status = usb_submit_urb (urb, GFP_ATOMIC)) != 0) {
-                        dbg ("can't resubmit ctrl %02x.%02x, err %d",
+                        ERROR(ctx->dev,
+                                "can't resubmit ctrl %02x.%02x, err %d\n",
                                 reqp->bRequestType, reqp->bRequest, status);
                         urb->dev = NULL;
                 } else
                         ctx->pending++;
         } else
                 urb->dev = NULL;
-        
+
         /* signal completion when nothing's queued */
         if (ctx->pending == 0)
                 complete (&ctx->complete);
@@ -918,11 +908,11 @@ test_ctrl_queue (struct usbtest_dev *dev, struct usbtest_param *param)
                         req.wValue = cpu_to_le16 (USB_DT_INTERFACE << 8);
                         // interface == 0
                         len = sizeof (struct usb_interface_descriptor);
-                        expected = EPIPE;
+                        expected = -EPIPE;
                         break;
                 // NOTE: two consecutive stalls in the queue here.
                 // that tests fault recovery a bit more aggressively.
-                case 8:         // clear endpoint halt (USUALLY STALLS)
+                case 8:         // clear endpoint halt (MAY STALL)
                         req.bRequest = USB_REQ_CLEAR_FEATURE;
                         req.bRequestType = USB_RECIP_ENDPOINT;
                         // wValue 0 == ep halt
@@ -965,7 +955,7 @@ test_ctrl_queue (struct usbtest_dev *dev, struct usbtest_param *param)
                         break;
                 case 14:        // short read; try to fill the last packet
                         req.wValue = cpu_to_le16 ((USB_DT_DEVICE << 8) | 0);
-                        // device descriptor size == 18 bytes 
+                        /* device descriptor size == 18 bytes */
                         len = udev->descriptor.bMaxPacketSize0;
                         switch (len) {
                         case 8:         len = 24; break;
@@ -974,7 +964,7 @@ test_ctrl_queue (struct usbtest_dev *dev, struct usbtest_param *param)
                         expected = -EREMOTEIO;
                         break;
                 default:
-                        err ("bogus number of ctrl queue testcases!");
+                        ERROR(dev, "bogus number of ctrl queue testcases!\n");
                         context.status = -EINVAL;
                         goto cleanup;
                 }
@@ -1003,7 +993,7 @@ test_ctrl_queue (struct usbtest_dev *dev, struct usbtest_param *param)
         for (i = 0; i < param->sglen; i++) {
                 context.status = usb_submit_urb (urb [i], GFP_ATOMIC);
                 if (context.status != 0) {
-                        dbg ("can't submit urb[%d], status %d",
+                        ERROR(dev, "can't submit urb[%d], status %d\n",
                                         i, context.status);
                         context.count = context.pending;
                         break;
@@ -1070,7 +1060,7 @@ static int unlink1 (struct usbtest_dev *dev, int pipe, int size, int async)
          * due to errors, or is just NAKing requests.
          */
         if ((retval = usb_submit_urb (urb, GFP_KERNEL)) != 0) {
-                dev_dbg (&dev->intf->dev, "submit fail %d\n", retval);
+                dev_err(&dev->intf->dev, "submit fail %d\n", retval);
                 return retval;
         }
 
@@ -1087,13 +1077,13 @@ retry:
                          * "normal" drivers would prevent resubmission, but
                          * since we're testing unlink paths, we can't.
                          */
-                        dev_dbg (&dev->intf->dev, "unlink retry\n");
+                        ERROR(dev,  "unlink retry\n");
                         goto retry;
                 }
         } else
                 usb_kill_urb (urb);
         if (!(retval == 0 || retval == -EINPROGRESS)) {
-                dev_dbg (&dev->intf->dev, "unlink fail %d\n", retval);
+                dev_err(&dev->intf->dev, "unlink fail %d\n", retval);
                 return retval;
         }
 
@@ -1121,7 +1111,7 @@ static int unlink_simple (struct usbtest_dev *dev, int pipe, int len)
 
 /*-------------------------------------------------------------------------*/
 
-static int verify_not_halted (int ep, struct urb *urb)
+static int verify_not_halted(struct usbtest_dev *tdev, int ep, struct urb *urb)
 {
         int     retval;
         u16     status;
@@ -1129,20 +1119,21 @@ static int verify_not_halted (int ep, struct urb *urb)
         /* shouldn't look or act halted */
         retval = usb_get_status (urb->dev, USB_RECIP_ENDPOINT, ep, &status);
         if (retval < 0) {
-                dbg ("ep %02x couldn't get no-halt status, %d", ep, retval);
+                ERROR(tdev, "ep %02x couldn't get no-halt status, %d\n",
+                                ep, retval);
                 return retval;
         }
         if (status != 0) {
-                dbg ("ep %02x bogus status: %04x != 0", ep, status);
+                ERROR(tdev, "ep %02x bogus status: %04x != 0\n", ep, status);
                 return -EINVAL;
         }
-        retval = simple_io (urb, 1, 0, 0, __func__);
+        retval = simple_io(tdev, urb, 1, 0, 0, __func__);
         if (retval != 0)
                 return -EINVAL;
         return 0;
 }
 
-static int verify_halted (int ep, struct urb *urb)
+static int verify_halted(struct usbtest_dev *tdev, int ep, struct urb *urb)
 {
         int     retval;
         u16     status;
@@ -1150,29 +1141,30 @@ static int verify_halted (int ep, struct urb *urb)
         /* should look and act halted */
         retval = usb_get_status (urb->dev, USB_RECIP_ENDPOINT, ep, &status);
         if (retval < 0) {
-                dbg ("ep %02x couldn't get halt status, %d", ep, retval);
+                ERROR(tdev, "ep %02x couldn't get halt status, %d\n",
+                                ep, retval);
                 return retval;
         }
         le16_to_cpus(&status);
         if (status != 1) {
-                dbg ("ep %02x bogus status: %04x != 1", ep, status);
+                ERROR(tdev, "ep %02x bogus status: %04x != 1\n", ep, status);
                 return -EINVAL;
         }
-        retval = simple_io (urb, 1, 0, -EPIPE, __func__);
+        retval = simple_io(tdev, urb, 1, 0, -EPIPE, __func__);
         if (retval != -EPIPE)
                 return -EINVAL;
-        retval = simple_io (urb, 1, 0, -EPIPE, "verify_still_halted");
+        retval = simple_io(tdev, urb, 1, 0, -EPIPE, "verify_still_halted");
         if (retval != -EPIPE)
                 return -EINVAL;
         return 0;
 }
 
-static int test_halt (int ep, struct urb *urb)
+static int test_halt(struct usbtest_dev *tdev, int ep, struct urb *urb)
 {
         int     retval;
 
         /* shouldn't look or act halted now */
-        retval = verify_not_halted (ep, urb);
+        retval = verify_not_halted(tdev, ep, urb);
         if (retval < 0)
                 return retval;
 
@@ -1182,20 +1174,20 @@ static int test_halt (int ep, struct urb *urb)
                         USB_ENDPOINT_HALT, ep,
                         NULL, 0, USB_CTRL_SET_TIMEOUT);
         if (retval < 0) {
-                dbg ("ep %02x couldn't set halt, %d", ep, retval);
+                ERROR(tdev, "ep %02x couldn't set halt, %d\n", ep, retval);
                 return retval;
         }
-        retval = verify_halted (ep, urb);
+        retval = verify_halted(tdev, ep, urb);
         if (retval < 0)
                 return retval;
 
         /* clear halt (tests API + protocol), verify it worked */
         retval = usb_clear_halt (urb->dev, urb->pipe);
         if (retval < 0) {
-                dbg ("ep %02x couldn't clear halt, %d", ep, retval);
+                ERROR(tdev, "ep %02x couldn't clear halt, %d\n", ep, retval);
                 return retval;
         }
-        retval = verify_not_halted (ep, urb);
+        retval = verify_not_halted(tdev, ep, urb);
         if (retval < 0)
                 return retval;
 
@@ -1217,7 +1209,7 @@ static int halt_simple (struct usbtest_dev *dev)
         if (dev->in_pipe) {
                 ep = usb_pipeendpoint (dev->in_pipe) | USB_DIR_IN;
                 urb->pipe = dev->in_pipe;
-                retval = test_halt (ep, urb);
+                retval = test_halt(dev, ep, urb);
                 if (retval < 0)
                         goto done;
         }
@@ -1225,7 +1217,7 @@ static int halt_simple (struct usbtest_dev *dev)
         if (dev->out_pipe) {
                 ep = usb_pipeendpoint (dev->out_pipe);
                 urb->pipe = dev->out_pipe;
-                retval = test_halt (ep, urb);
+                retval = test_halt(dev, ep, urb);
         }
 done:
         simple_free_urb (urb);
@@ -1275,7 +1267,7 @@ static int ctrl_out (struct usbtest_dev *dev,
                 if (retval != len) {
                         what = "write";
                         if (retval >= 0) {
-                                INFO(dev, "ctrl_out, wlen %d (expected %d)\n",
+                                ERROR(dev, "ctrl_out, wlen %d (expected %d)\n",
                                                 retval, len);
                                 retval = -EBADMSG;
                         }
@@ -1289,7 +1281,7 @@ static int ctrl_out (struct usbtest_dev *dev,
                 if (retval != len) {
                         what = "read";
                         if (retval >= 0) {
-                                INFO(dev, "ctrl_out, rlen %d (expected %d)\n",
+                                ERROR(dev, "ctrl_out, rlen %d (expected %d)\n",
                                                 retval, len);
                                 retval = -EBADMSG;
                         }
@@ -1299,7 +1291,7 @@ static int ctrl_out (struct usbtest_dev *dev,
                 /* fail if we can't verify */
                 for (j = 0; j < len; j++) {
                         if (buf [j] != (u8) (i + j)) {
-                                INFO (dev, "ctrl_out, byte %d is %d not %d\n",
+                                ERROR(dev, "ctrl_out, byte %d is %d not %d\n",
                                         j, buf [j], (u8) i + j);
                                 retval = -EBADMSG;
                                 break;
@@ -1321,7 +1313,7 @@ static int ctrl_out (struct usbtest_dev *dev,
         }
 
         if (retval < 0)
-                INFO (dev, "ctrl_out %s failed, code %d, count %d\n",
+                ERROR (dev, "ctrl_out %s failed, code %d, count %d\n",
                         what, retval, i);
 
         kfree (buf);
@@ -1366,7 +1358,7 @@ static void iso_callback (struct urb *urb)
                 case 0:
                         goto done;
                 default:
-                        dev_dbg (&ctx->dev->intf->dev,
+                        dev_err(&ctx->dev->intf->dev,
                                         "iso resubmit err %d\n",
                                         status);
                         /* FALLTHROUGH */
@@ -1381,7 +1373,7 @@ static void iso_callback (struct urb *urb)
         ctx->pending--;
         if (ctx->pending == 0) {
                 if (ctx->errors)
-                        dev_dbg (&ctx->dev->intf->dev,
+                        dev_err(&ctx->dev->intf->dev,
                                 "iso test, %lu errors out of %lu\n",
                                 ctx->errors, ctx->packet_count);
                 complete (&ctx->done);
@@ -1458,7 +1450,7 @@ test_iso_queue (struct usbtest_dev *dev, struct usbtest_param *param,
 
         memset (urbs, 0, sizeof urbs);
         udev = testdev_to_usbdev (dev);
-        dev_dbg (&dev->intf->dev,
+        dev_info(&dev->intf->dev,
                 "... iso period %d %sframes, wMaxPacket %04x\n",
                 1 << (desc->bInterval - 1),
                 (udev->speed == USB_SPEED_HIGH) ? "micro" : "",
@@ -1475,7 +1467,7 @@ test_iso_queue (struct usbtest_dev *dev, struct usbtest_param *param,
                 urbs [i]->context = &context;
         }
         packets *= param->iterations;
-        dev_dbg (&dev->intf->dev,
+        dev_info(&dev->intf->dev,
                 "... total %lu msec (%lu packets)\n",
                 (packets * (1 << (desc->bInterval - 1)))
                         / ((udev->speed == USB_SPEED_HIGH) ? 8 : 1),
@@ -1537,6 +1529,13 @@ fail:
  * except indirectly by consuming USB bandwidth and CPU resources for test
  * threads and request completion.  But the only way to know that for sure
  * is to test when HC queues are in use by many devices.
+ *
+ * WARNING:  Because usbfs grabs udev->dev.sem before calling this ioctl(),
+ * it locks out usbcore in certain code paths.  Notably, if you disconnect
+ * the device-under-test, khubd will wait block forever waiting for the
+ * ioctl to complete ... so that usb_disconnect() can abort the pending
+ * urbs and then call usbtest_disconnect().  To abort a test, you're best
+ * off just killing the userspace task and waiting for it to exit.
  */
 
 static int
@@ -1575,7 +1574,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
          * altsettings; force a default so most tests don't need to check.
          */
         if (dev->info->alt >= 0) {
-                int     res;
+                int     res;
 
                 if (intf->altsetting->desc.bInterfaceNumber) {
                         mutex_unlock(&dev->lock);
@@ -1604,7 +1603,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
         switch (param->test_num) {
 
         case 0:
-                dev_dbg (&intf->dev, "TEST 0:  NOP\n");
+                dev_info(&intf->dev, "TEST 0:  NOP\n");
                 retval = 0;
                 break;
 
@@ -1612,7 +1611,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
         case 1:
                 if (dev->out_pipe == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                                 "TEST 1:  write %d bytes %u times\n",
                                 param->length, param->iterations);
                 urb = simple_alloc_urb (udev, dev->out_pipe, param->length);
@@ -1621,13 +1620,13 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk sink (maybe accepts short writes)
-                retval = simple_io (urb, param->iterations, 0, 0, "test1");
+                retval = simple_io(dev, urb, param->iterations, 0, 0, "test1");
                 simple_free_urb (urb);
                 break;
         case 2:
                 if (dev->in_pipe == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                                 "TEST 2:  read %d bytes %u times\n",
                                 param->length, param->iterations);
                 urb = simple_alloc_urb (udev, dev->in_pipe, param->length);
@@ -1636,13 +1635,13 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk source (maybe generates short writes)
-                retval = simple_io (urb, param->iterations, 0, 0, "test2");
+                retval = simple_io(dev, urb, param->iterations, 0, 0, "test2");
                 simple_free_urb (urb);
                 break;
         case 3:
                 if (dev->out_pipe == 0 || param->vary == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                                 "TEST 3:  write/%d 0..%d bytes %u times\n",
                                 param->vary, param->length, param->iterations);
                 urb = simple_alloc_urb (udev, dev->out_pipe, param->length);
@@ -1651,14 +1650,14 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk sink (maybe accepts short writes)
-                retval = simple_io (urb, param->iterations, param->vary,
+                retval = simple_io(dev, urb, param->iterations, param->vary,
                                         0, "test3");
                 simple_free_urb (urb);
                 break;
         case 4:
                 if (dev->in_pipe == 0 || param->vary == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                                 "TEST 4:  read/%d 0..%d bytes %u times\n",
                                 param->vary, param->length, param->iterations);
                 urb = simple_alloc_urb (udev, dev->in_pipe, param->length);
@@ -1667,7 +1666,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk source (maybe generates short writes)
-                retval = simple_io (urb, param->iterations, param->vary,
+                retval = simple_io(dev, urb, param->iterations, param->vary,
                                         0, "test4");
                 simple_free_urb (urb);
                 break;
@@ -1676,7 +1675,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
         case 5:
                 if (dev->out_pipe == 0 || param->sglen == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                         "TEST 5:  write %d sglists %d entries of %d bytes\n",
                                 param->iterations,
                                 param->sglen, param->length);
@@ -1686,7 +1685,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk sink (maybe accepts short writes)
-                retval = perform_sglist (udev, param->iterations, dev->out_pipe,
+                retval = perform_sglist(dev, param->iterations, dev->out_pipe,
                                 &req, sg, param->sglen);
                 free_sglist (sg, param->sglen);
                 break;
@@ -1694,7 +1693,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
         case 6:
                 if (dev->in_pipe == 0 || param->sglen == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                         "TEST 6:  read %d sglists %d entries of %d bytes\n",
                                 param->iterations,
                                 param->sglen, param->length);
@@ -1704,14 +1703,14 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk source (maybe generates short writes)
-                retval = perform_sglist (udev, param->iterations, dev->in_pipe,
+                retval = perform_sglist(dev, param->iterations, dev->in_pipe,
                                 &req, sg, param->sglen);
                 free_sglist (sg, param->sglen);
                 break;
         case 7:
                 if (dev->out_pipe == 0 || param->sglen == 0 || param->vary == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                         "TEST 7:  write/%d %d sglists %d entries 0..%d bytes\n",
                                 param->vary, param->iterations,
                                 param->sglen, param->length);
@@ -1721,14 +1720,14 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk sink (maybe accepts short writes)
-                retval = perform_sglist (udev, param->iterations, dev->out_pipe,
+                retval = perform_sglist(dev, param->iterations, dev->out_pipe,
                                 &req, sg, param->sglen);
                 free_sglist (sg, param->sglen);
                 break;
         case 8:
                 if (dev->in_pipe == 0 || param->sglen == 0 || param->vary == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                         "TEST 8:  read/%d %d sglists %d entries 0..%d bytes\n",
                                 param->vary, param->iterations,
                                 param->sglen, param->length);
@@ -1738,7 +1737,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                         break;
                 }
                 // FIRMWARE:  bulk source (maybe generates short writes)
-                retval = perform_sglist (udev, param->iterations, dev->in_pipe,
+                retval = perform_sglist(dev, param->iterations, dev->in_pipe,
                                 &req, sg, param->sglen);
                 free_sglist (sg, param->sglen);
                 break;
@@ -1746,13 +1745,14 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
         /* non-queued sanity tests for control (chapter 9 subset) */
         case 9:
                 retval = 0;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                         "TEST 9:  ch9 (subset) control tests, %d times\n",
                                 param->iterations);
                 for (i = param->iterations; retval == 0 && i--; /* NOP */)
                         retval = ch9_postconfig (dev);
                 if (retval)
-                        dbg ("ch9 subset failed, iterations left %d", i);
+                        dev_err(&intf->dev, "ch9 subset failed, "
+                                        "iterations left %d\n", i);
                 break;
 
         /* queued control messaging */
@@ -1760,7 +1760,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                 if (param->sglen == 0)
                         break;
                 retval = 0;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                                 "TEST 10:  queue %d control calls, %d times\n",
                                 param->sglen,
                                 param->iterations);
@@ -1772,26 +1772,26 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                 if (dev->in_pipe == 0 || !param->length)
                         break;
                 retval = 0;
-                dev_dbg (&intf->dev, "TEST 11:  unlink %d reads of %d\n",
+                dev_info(&intf->dev, "TEST 11:  unlink %d reads of %d\n",
                                 param->iterations, param->length);
                 for (i = param->iterations; retval == 0 && i--; /* NOP */)
                         retval = unlink_simple (dev, dev->in_pipe,
                                                 param->length);
                 if (retval)
-                        dev_dbg (&intf->dev, "unlink reads failed %d, "
+                        dev_err(&intf->dev, "unlink reads failed %d, "
                                 "iterations left %d\n", retval, i);
                 break;
         case 12:
                 if (dev->out_pipe == 0 || !param->length)
                         break;
                 retval = 0;
-                dev_dbg (&intf->dev, "TEST 12:  unlink %d writes of %d\n",
+                dev_info(&intf->dev, "TEST 12:  unlink %d writes of %d\n",
                                 param->iterations, param->length);
                 for (i = param->iterations; retval == 0 && i--; /* NOP */)
                         retval = unlink_simple (dev, dev->out_pipe,
                                                 param->length);
                 if (retval)
-                        dev_dbg (&intf->dev, "unlink writes failed %d, "
+                        dev_err(&intf->dev, "unlink writes failed %d, "
                                 "iterations left %d\n", retval, i);
                 break;
 
@@ -1800,24 +1800,24 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
                 if (dev->out_pipe == 0 && dev->in_pipe == 0)
                         break;
                 retval = 0;
-                dev_dbg (&intf->dev, "TEST 13:  set/clear %d halts\n",
+                dev_info(&intf->dev, "TEST 13:  set/clear %d halts\n",
                                 param->iterations);
                 for (i = param->iterations; retval == 0 && i--; /* NOP */)
                         retval = halt_simple (dev);
-                
+
                 if (retval)
-                        DBG (dev, "halts failed, iterations left %d\n", i);
+                        ERROR(dev, "halts failed, iterations left %d\n", i);
                 break;
 
         /* control write tests */
         case 14:
                 if (!dev->info->ctrl_out)
                         break;
-                dev_dbg (&intf->dev, "TEST 14:  %d ep0out, %d..%d vary %d\n",
+                dev_info(&intf->dev, "TEST 14:  %d ep0out, %d..%d vary %d\n",
                                 param->iterations,
                                 realworld ? 1 : 0, param->length,
                                 param->vary);
-                retval = ctrl_out (dev, param->iterations, 
+                retval = ctrl_out(dev, param->iterations,
                                 param->length, param->vary);
                 break;
 
@@ -1825,7 +1825,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
         case 15:
                 if (dev->out_iso_pipe == 0 || param->sglen == 0)
                         break;
-                dev_dbg (&intf->dev, 
+                dev_info(&intf->dev,
                         "TEST 15:  write %d iso, %d entries of %d bytes\n",
                                 param->iterations,
                                 param->sglen, param->length);
@@ -1838,7 +1838,7 @@ usbtest_ioctl (struct usb_interface *intf, unsigned int code, void *buf)
         case 16:
                 if (dev->in_iso_pipe == 0 || param->sglen == 0)
                         break;
-                dev_dbg (&intf->dev,
+                dev_info(&intf->dev,
                         "TEST 16:  read %d iso, %d entries of %d bytes\n",
                                 param->iterations,
                                 param->sglen, param->length);
@@ -1898,7 +1898,8 @@ usbtest_probe (struct usb_interface *intf, const struct usb_device_id *id)
                         return -ENODEV;
                 if (product && le16_to_cpu(udev->descriptor.idProduct) != (u16)product)
                         return -ENODEV;
-                dbg ("matched module params, vend=0x%04x prod=0x%04x",
+                dev_info(&intf->dev, "matched module params, "
+                                        "vend=0x%04x prod=0x%04x\n",
                                 le16_to_cpu(udev->descriptor.idVendor),
                                 le16_to_cpu(udev->descriptor.idProduct));
         }
@@ -1940,7 +1941,8 @@ usbtest_probe (struct usb_interface *intf, const struct usb_device_id *id)
 
                         status = get_endpoints (dev, intf);
                         if (status < 0) {
-                                dbg ("couldn't get endpoints, %d\n", status);
+                                WARN(dev, "couldn't get endpoints, %d\n",
+                                                status);
                                 return status;
                         }
                         /* may find bulk or ISO pipes */
@@ -2082,21 +2084,9 @@ static struct usbtest_info generic_info = {
 };
 #endif
 
-// FIXME remove this 
-static struct usbtest_info hact_info = {
-        .name           = "FX2/hact",
-        //.ep_in                = 6,
-        .ep_out         = 2,
-        .alt            = -1,
-};
-
 
 static struct usb_device_id id_table [] = {
 
-        { USB_DEVICE (0x0547, 0x1002),
-                .driver_info = (unsigned long) &hact_info,
-                },
-
         /*-------------------------------------------------------------*/
 
         /* EZ-USB devices which download firmware to replace (or in our
@@ -2185,7 +2175,7 @@ static int __init usbtest_init (void)
 {
 #ifdef GENERIC
         if (vendor)
-                dbg ("params: vend=0x%04x prod=0x%04x", vendor, product);
+                pr_debug("params: vend=0x%04x prod=0x%04x\n", vendor, product);
 #endif
         return usb_register (&usbtest_driver);
 }