Commit 4c6e8971 authored by Alan Stern's avatar Alan Stern Committed by Greg Kroah-Hartman

USB: make the "usbfs_snoop" log more pertinent

This patch (as1261) reduces the amount of detailed URB information
logged by usbfs when the usbfs_snoop parameter is enabled.

Currently we don't display the final status value for a completed URB.
But we do display the entire data buffer twice: both before submission
and after completion.  The after-completion display doesn't limit
itself to the actual_length value.  But since usbmon is readily
available in virtually all distributions, there's no reason for usbfs
to print out any buffer contents at all!

So this patch restricts the information to: userspace buffer pointer,
endpoint number, type, and direction, length or actual_length, and
timeout value or status.  Now everything fits neatly into a single
line.

Along with those changes, the patch also fixes the snoop output for
the REAPURBNDELAY and REAPURBNDELAY32 ioctls.  The current version
omits the 'N' from the names.
Signed-off-by: default avatarAlan Stern <stern@rowland.harvard.edu>
Signed-off-by: default avatarGreg Kroah-Hartman <gregkh@suse.de>
parent ccf5b801
...@@ -100,11 +100,15 @@ MODULE_PARM_DESC(usbfs_snoop, "true to log all usbfs traffic"); ...@@ -100,11 +100,15 @@ MODULE_PARM_DESC(usbfs_snoop, "true to log all usbfs traffic");
dev_info(dev , format , ## arg); \ dev_info(dev , format , ## arg); \
} while (0) } while (0)
#define USB_DEVICE_DEV MKDEV(USB_DEVICE_MAJOR, 0) enum snoop_when {
SUBMIT, COMPLETE
};
#define USB_DEVICE_DEV MKDEV(USB_DEVICE_MAJOR, 0)
#define MAX_USBFS_BUFFER_SIZE 16384 #define MAX_USBFS_BUFFER_SIZE 16384
static int connected(struct dev_state *ps) static int connected(struct dev_state *ps)
{ {
return (!list_empty(&ps->list) && return (!list_empty(&ps->list) &&
...@@ -301,24 +305,42 @@ static struct async *async_getpending(struct dev_state *ps, ...@@ -301,24 +305,42 @@ static struct async *async_getpending(struct dev_state *ps,
return NULL; return NULL;
} }
static void snoop_urb(struct urb *urb, void __user *userurb) static void snoop_urb(struct usb_device *udev,
void __user *userurb, int pipe, unsigned length,
int timeout_or_status, enum snoop_when when)
{ {
unsigned j; static const char *types[] = {"isoc", "int", "ctrl", "bulk"};
unsigned char *data = urb->transfer_buffer; static const char *dirs[] = {"out", "in"};
int ep;
const char *t, *d;
if (!usbfs_snoop) if (!usbfs_snoop)
return; return;
dev_info(&urb->dev->dev, "direction=%s\n", ep = usb_pipeendpoint(pipe);
usb_urb_dir_in(urb) ? "IN" : "OUT"); t = types[usb_pipetype(pipe)];
dev_info(&urb->dev->dev, "userurb=%p\n", userurb); d = dirs[!!usb_pipein(pipe)];
dev_info(&urb->dev->dev, "transfer_buffer_length=%u\n",
urb->transfer_buffer_length); if (userurb) { /* Async */
dev_info(&urb->dev->dev, "actual_length=%u\n", urb->actual_length); if (when == SUBMIT)
dev_info(&urb->dev->dev, "data: "); dev_info(&udev->dev, "userurb %p, ep%d %s-%s, "
for (j = 0; j < urb->transfer_buffer_length; ++j) "length %u\n",
printk("%02x ", data[j]); userurb, ep, t, d, length);
printk("\n"); else
dev_info(&udev->dev, "userurb %p, ep%d %s-%s, "
"actual_length %u status %d\n",
userurb, ep, t, d, length,
timeout_or_status);
} else {
if (when == SUBMIT)
dev_info(&udev->dev, "ep%d %s-%s, length %u, "
"timeout %d\n",
ep, t, d, length, timeout_or_status);
else
dev_info(&udev->dev, "ep%d %s-%s, actual_length %u, "
"status %d\n",
ep, t, d, length, timeout_or_status);
}
} }
static void async_completed(struct urb *urb) static void async_completed(struct urb *urb)
...@@ -347,7 +369,8 @@ static void async_completed(struct urb *urb) ...@@ -347,7 +369,8 @@ static void async_completed(struct urb *urb)
secid = as->secid; secid = as->secid;
} }
snoop(&urb->dev->dev, "urb complete\n"); snoop(&urb->dev->dev, "urb complete\n");
snoop_urb(urb, as->userurb); snoop_urb(urb->dev, as->userurb, urb->pipe, urb->actual_length,
as->status, COMPLETE);
spin_unlock(&ps->lock); spin_unlock(&ps->lock);
if (signr) if (signr)
...@@ -690,7 +713,7 @@ static int proc_control(struct dev_state *ps, void __user *arg) ...@@ -690,7 +713,7 @@ static int proc_control(struct dev_state *ps, void __user *arg)
unsigned int tmo; unsigned int tmo;
unsigned char *tbuf; unsigned char *tbuf;
unsigned wLength; unsigned wLength;
int i, j, ret; int i, pipe, ret;
if (copy_from_user(&ctrl, arg, sizeof(ctrl))) if (copy_from_user(&ctrl, arg, sizeof(ctrl)))
return -EFAULT; return -EFAULT;
...@@ -710,24 +733,17 @@ static int proc_control(struct dev_state *ps, void __user *arg) ...@@ -710,24 +733,17 @@ static int proc_control(struct dev_state *ps, void __user *arg)
free_page((unsigned long)tbuf); free_page((unsigned long)tbuf);
return -EINVAL; return -EINVAL;
} }
snoop(&dev->dev, "control read: bRequest=%02x " pipe = usb_rcvctrlpipe(dev, 0);
"bRrequestType=%02x wValue=%04x " snoop_urb(dev, NULL, pipe, ctrl.wLength, tmo, SUBMIT);
"wIndex=%04x wLength=%04x\n",
ctrl.bRequest, ctrl.bRequestType, ctrl.wValue,
ctrl.wIndex, ctrl.wLength);
usb_unlock_device(dev); usb_unlock_device(dev);
i = usb_control_msg(dev, usb_rcvctrlpipe(dev, 0), ctrl.bRequest, i = usb_control_msg(dev, pipe, ctrl.bRequest,
ctrl.bRequestType, ctrl.wValue, ctrl.wIndex, ctrl.bRequestType, ctrl.wValue, ctrl.wIndex,
tbuf, ctrl.wLength, tmo); tbuf, ctrl.wLength, tmo);
usb_lock_device(dev); usb_lock_device(dev);
snoop_urb(dev, NULL, pipe, max(i, 0), min(i, 0), COMPLETE);
if ((i > 0) && ctrl.wLength) { if ((i > 0) && ctrl.wLength) {
if (usbfs_snoop) {
dev_info(&dev->dev, "control read: data ");
for (j = 0; j < i; ++j)
printk("%02x ", (u8)(tbuf)[j]);
printk("\n");
}
if (copy_to_user(ctrl.data, tbuf, i)) { if (copy_to_user(ctrl.data, tbuf, i)) {
free_page((unsigned long)tbuf); free_page((unsigned long)tbuf);
return -EFAULT; return -EFAULT;
...@@ -740,22 +756,15 @@ static int proc_control(struct dev_state *ps, void __user *arg) ...@@ -740,22 +756,15 @@ static int proc_control(struct dev_state *ps, void __user *arg)
return -EFAULT; return -EFAULT;
} }
} }
snoop(&dev->dev, "control write: bRequest=%02x " pipe = usb_sndctrlpipe(dev, 0);
"bRrequestType=%02x wValue=%04x " snoop_urb(dev, NULL, pipe, ctrl.wLength, tmo, SUBMIT);
"wIndex=%04x wLength=%04x\n",
ctrl.bRequest, ctrl.bRequestType, ctrl.wValue,
ctrl.wIndex, ctrl.wLength);
if (usbfs_snoop) {
dev_info(&dev->dev, "control write: data: ");
for (j = 0; j < ctrl.wLength; ++j)
printk("%02x ", (unsigned char)(tbuf)[j]);
printk("\n");
}
usb_unlock_device(dev); usb_unlock_device(dev);
i = usb_control_msg(dev, usb_sndctrlpipe(dev, 0), ctrl.bRequest, i = usb_control_msg(dev, usb_sndctrlpipe(dev, 0), ctrl.bRequest,
ctrl.bRequestType, ctrl.wValue, ctrl.wIndex, ctrl.bRequestType, ctrl.wValue, ctrl.wIndex,
tbuf, ctrl.wLength, tmo); tbuf, ctrl.wLength, tmo);
usb_lock_device(dev); usb_lock_device(dev);
snoop_urb(dev, NULL, pipe, max(i, 0), min(i, 0), COMPLETE);
} }
free_page((unsigned long)tbuf); free_page((unsigned long)tbuf);
if (i < 0 && i != -EPIPE) { if (i < 0 && i != -EPIPE) {
...@@ -774,7 +783,7 @@ static int proc_bulk(struct dev_state *ps, void __user *arg) ...@@ -774,7 +783,7 @@ static int proc_bulk(struct dev_state *ps, void __user *arg)
unsigned int tmo, len1, pipe; unsigned int tmo, len1, pipe;
int len2; int len2;
unsigned char *tbuf; unsigned char *tbuf;
int i, j, ret; int i, ret;
if (copy_from_user(&bulk, arg, sizeof(bulk))) if (copy_from_user(&bulk, arg, sizeof(bulk)))
return -EFAULT; return -EFAULT;
...@@ -801,18 +810,14 @@ static int proc_bulk(struct dev_state *ps, void __user *arg) ...@@ -801,18 +810,14 @@ static int proc_bulk(struct dev_state *ps, void __user *arg)
kfree(tbuf); kfree(tbuf);
return -EINVAL; return -EINVAL;
} }
snoop(&dev->dev, "bulk read: len=0x%02x timeout=%04d\n", snoop_urb(dev, NULL, pipe, len1, tmo, SUBMIT);
bulk.len, bulk.timeout);
usb_unlock_device(dev); usb_unlock_device(dev);
i = usb_bulk_msg(dev, pipe, tbuf, len1, &len2, tmo); i = usb_bulk_msg(dev, pipe, tbuf, len1, &len2, tmo);
usb_lock_device(dev); usb_lock_device(dev);
snoop_urb(dev, NULL, pipe, len2, i, COMPLETE);
if (!i && len2) { if (!i && len2) {
if (usbfs_snoop) {
dev_info(&dev->dev, "bulk read: data ");
for (j = 0; j < len2; ++j)
printk("%02x ", (u8)(tbuf)[j]);
printk("\n");
}
if (copy_to_user(bulk.data, tbuf, len2)) { if (copy_to_user(bulk.data, tbuf, len2)) {
kfree(tbuf); kfree(tbuf);
return -EFAULT; return -EFAULT;
...@@ -825,17 +830,12 @@ static int proc_bulk(struct dev_state *ps, void __user *arg) ...@@ -825,17 +830,12 @@ static int proc_bulk(struct dev_state *ps, void __user *arg)
return -EFAULT; return -EFAULT;
} }
} }
snoop(&dev->dev, "bulk write: len=0x%02x timeout=%04d\n", snoop_urb(dev, NULL, pipe, len1, tmo, SUBMIT);
bulk.len, bulk.timeout);
if (usbfs_snoop) {
dev_info(&dev->dev, "bulk write: data: ");
for (j = 0; j < len1; ++j)
printk("%02x ", (unsigned char)(tbuf)[j]);
printk("\n");
}
usb_unlock_device(dev); usb_unlock_device(dev);
i = usb_bulk_msg(dev, pipe, tbuf, len1, &len2, tmo); i = usb_bulk_msg(dev, pipe, tbuf, len1, &len2, tmo);
usb_lock_device(dev); usb_lock_device(dev);
snoop_urb(dev, NULL, pipe, len2, i, COMPLETE);
} }
kfree(tbuf); kfree(tbuf);
if (i < 0) if (i < 0)
...@@ -1053,13 +1053,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb, ...@@ -1053,13 +1053,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb,
is_in = 0; is_in = 0;
uurb->endpoint &= ~USB_DIR_IN; uurb->endpoint &= ~USB_DIR_IN;
} }
snoop(&ps->dev->dev, "control urb: bRequest=%02x "
"bRrequestType=%02x wValue=%04x "
"wIndex=%04x wLength=%04x\n",
dr->bRequest, dr->bRequestType,
__le16_to_cpup(&dr->wValue),
__le16_to_cpup(&dr->wIndex),
__le16_to_cpup(&dr->wLength));
break; break;
case USBDEVFS_URB_TYPE_BULK: case USBDEVFS_URB_TYPE_BULK:
...@@ -1072,7 +1065,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb, ...@@ -1072,7 +1065,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb,
uurb->number_of_packets = 0; uurb->number_of_packets = 0;
if (uurb->buffer_length > MAX_USBFS_BUFFER_SIZE) if (uurb->buffer_length > MAX_USBFS_BUFFER_SIZE)
return -EINVAL; return -EINVAL;
snoop(&ps->dev->dev, "bulk urb\n");
break; break;
case USBDEVFS_URB_TYPE_ISO: case USBDEVFS_URB_TYPE_ISO:
...@@ -1104,7 +1096,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb, ...@@ -1104,7 +1096,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb,
return -EINVAL; return -EINVAL;
} }
uurb->buffer_length = totlen; uurb->buffer_length = totlen;
snoop(&ps->dev->dev, "iso urb\n");
break; break;
case USBDEVFS_URB_TYPE_INTERRUPT: case USBDEVFS_URB_TYPE_INTERRUPT:
...@@ -1113,7 +1104,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb, ...@@ -1113,7 +1104,6 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb,
return -EINVAL; return -EINVAL;
if (uurb->buffer_length > MAX_USBFS_BUFFER_SIZE) if (uurb->buffer_length > MAX_USBFS_BUFFER_SIZE)
return -EINVAL; return -EINVAL;
snoop(&ps->dev->dev, "interrupt urb\n");
break; break;
default: default:
...@@ -1200,11 +1190,14 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb, ...@@ -1200,11 +1190,14 @@ static int proc_do_submiturb(struct dev_state *ps, struct usbdevfs_urb *uurb,
return -EFAULT; return -EFAULT;
} }
} }
snoop_urb(as->urb, as->userurb); snoop_urb(ps->dev, as->userurb, as->urb->pipe,
as->urb->transfer_buffer_length, 0, SUBMIT);
async_newpending(as); async_newpending(as);
if ((ret = usb_submit_urb(as->urb, GFP_KERNEL))) { if ((ret = usb_submit_urb(as->urb, GFP_KERNEL))) {
dev_printk(KERN_DEBUG, &ps->dev->dev, dev_printk(KERN_DEBUG, &ps->dev->dev,
"usbfs: usb_submit_urb returned %d\n", ret); "usbfs: usb_submit_urb returned %d\n", ret);
snoop_urb(ps->dev, as->userurb, as->urb->pipe,
0, ret, COMPLETE);
async_removepending(as); async_removepending(as);
free_async(as); free_async(as);
return ret; return ret;
...@@ -1670,7 +1663,7 @@ static int usbdev_ioctl(struct inode *inode, struct file *file, ...@@ -1670,7 +1663,7 @@ static int usbdev_ioctl(struct inode *inode, struct file *file,
break; break;
case USBDEVFS_REAPURBNDELAY32: case USBDEVFS_REAPURBNDELAY32:
snoop(&dev->dev, "%s: REAPURBDELAY32\n", __func__); snoop(&dev->dev, "%s: REAPURBNDELAY32\n", __func__);
ret = proc_reapurbnonblock_compat(ps, p); ret = proc_reapurbnonblock_compat(ps, p);
break; break;
...@@ -1691,7 +1684,7 @@ static int usbdev_ioctl(struct inode *inode, struct file *file, ...@@ -1691,7 +1684,7 @@ static int usbdev_ioctl(struct inode *inode, struct file *file,
break; break;
case USBDEVFS_REAPURBNDELAY: case USBDEVFS_REAPURBNDELAY:
snoop(&dev->dev, "%s: REAPURBDELAY\n", __func__); snoop(&dev->dev, "%s: REAPURBNDELAY\n", __func__);
ret = proc_reapurbnonblock(ps, p); ret = proc_reapurbnonblock(ps, p);
break; break;
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment