USB: usbtest displays diagnostics again
authorDavid Brownell <david-b@pacbell.net>
Sat, 26 Apr 2008 01:51:10 +0000 (18:51 -0700)
committerGreg Kroah-Hartman <gregkh@suse.de>
Fri, 2 May 2008 17:25:52 +0000 (10:25 -0700)
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>
drivers/usb/misc/usbtest.c

index a519838..742be3c 100644 (file)
@@ -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);
 }