Unlike the packet socket, usbmon has an interface which provides traces
in a text format. This is used for two purposes. First, it serves as a
-common trace exchange format for tools while most sophisticated formats
+common trace exchange format for tools while more sophisticated formats
are finalized. Second, humans can read it in case tools are not available.
To collect a raw text trace, execute following steps.
Verify that bus sockets are present.
# ls /sys/kernel/debug/usbmon
-1s 1t 2s 2t 3s 3t 4s 4t
+1s 1t 1u 2s 2t 2u 3s 3t 3u 4s 4t 4u
#
2. Find which bus connects to the desired device
3. Start 'cat'
-# cat /sys/kernel/debug/usbmon/3t > /tmp/1.mon.out
+# cat /sys/kernel/debug/usbmon/3u > /tmp/1.mon.out
This process will be reading until killed. Naturally, the output can be
redirected to a desirable location. This is preferred, because it is going
* Raw text data format
-The '1t' type data consists of a stream of events, such as URB submission,
+Two formats are supported currently: the original, or '1t' format, and
+the '1u' format. The '1t' format is deprecated in kernel 2.6.21. The '1u'
+format adds a few fields, such as ISO frame descriptors, interval, etc.
+It produces slightly longer lines, but otherwise is a perfect superset
+of '1t' format.
+
+If it is desired to recognize one from the other in a program, look at the
+"address" word (see below), where '1u' format adds a bus number. If 2 colons
+are present, it's the '1t' format, otherwise '1u'.
+
+Any text format data consists of a stream of events, such as URB submission,
URB callback, submission error. Every event is a text line, which consists
of whitespace separated words. The number or position of words may depend
on the event type, but there is a set of words, common for all types.
Here is the list of words, from left to right:
+
- URB Tag. This is used to identify URBs is normally a kernel mode address
of the URB structure in hexadecimal.
+
- Timestamp in microseconds, a decimal number. The timestamp's resolution
depends on available clock, and so it can be much worse than a microsecond
(if the implementation uses jiffies, for example).
+
- Event Type. This type refers to the format of the event, not URB type.
Available types are: S - submission, C - callback, E - submission error.
-- "Pipe". The pipe concept is deprecated. This is a composite word, used to
- be derived from information in pipes. It consists of three fields, separated
- by colons: URB type and direction, Device address, Endpoint number.
+
+- "Address" word (formerly a "pipe"). It consists of four fields, separated by
+ colons: URB type and direction, Bus number, Device address, Endpoint number.
Type and direction are encoded with two bytes in the following manner:
Ci Co Control input and output
Zi Zo Isochronous input and output
Ii Io Interrupt input and output
Bi Bo Bulk input and output
- Device address and Endpoint number are 3-digit and 2-digit (respectively)
- decimal numbers, with leading zeroes.
-- URB Status. In most cases, this field contains a number, sometimes negative,
- which represents a "status" field of the URB. This field makes no sense for
- submissions, but is present anyway to help scripts with parsing. When an
- error occurs, the field contains the error code. In case of a submission of
- a Control packet, this field contains a Setup Tag instead of an error code.
- It is easy to tell whether the Setup Tag is present because it is never a
- number. Thus if scripts find a number in this field, they proceed to read
- Data Length. If they find something else, like a letter, they read the setup
- packet before reading the Data Length.
+ Bus number, Device address, and Endpoint are decimal numbers, but they may
+ have leading zeros, for the sake of human readers.
+
+- URB Status word. This is either a letter, or several numbers separated
+ by colons: URB status, interval, start frame, and error count. Unlike the
+ "address" word, all fields save the status are optional. Interval is printed
+ only for interrupt and isochronous URBs. Start frame is printed only for
+ isochronous URBs. Error count is printed only for isochronous callback
+ events.
+
+ The status field is a decimal number, sometimes negative, which represents
+ a "status" field of the URB. This field makes no sense for submissions, but
+ is present anyway to help scripts with parsing. When an error occurs, the
+ field contains the error code.
+
+ In case of a submission of a Control packet, this field contains a Setup Tag
+ instead of an group of numbers. It is easy to tell whether the Setup Tag is
+ present because it is never a number. Thus if scripts find a set of numbers
+ in this word, they proceed to read Data Length (except for isochronous URBs).
+ If they find something else, like a letter, they read the setup packet before
+ reading the Data Length or isochronous descriptors.
+
- Setup packet, if present, consists of 5 words: one of each for bmRequestType,
bRequest, wValue, wIndex, wLength, as specified by the USB Specification 2.0.
These words are safe to decode if Setup Tag was 's'. Otherwise, the setup
packet was present, but not captured, and the fields contain filler.
+
+- Number of isochronous frame descriptors and descriptors themselves.
+ If an Isochronous transfer event has a set of descriptors, a total number
+ of them in an URB is printed first, then a word per descriptor, up to a
+ total of 5. The word consists of 3 colon-separated decimal numbers for
+ status, offset, and length respectively. For submissions, initial length
+ is reported. For callbacks, actual length is reported.
+
- Data Length. For submissions, this is the requested length. For callbacks,
this is the actual length.
+
- Data tag. The usbmon may not always capture data, even if length is nonzero.
The data words are present only if this tag is '='.
+
- Data words follow, in big endian hexadecimal format. Notice that they are
not machine words, but really just a byte stream split into words to make
it easier to read. Thus, the last word may contain from one to four bytes.
}
}
-This format may be changed in the future.
-
Examples:
An input control transfer to get a port status.
-d5ea89a0 3575914555 S Ci:001:00 s a3 00 0000 0003 0004 4 <
-d5ea89a0 3575914560 C Ci:001:00 0 4 = 01050000
+d5ea89a0 3575914555 S Ci:1:001:0 s a3 00 0000 0003 0004 4 <
+d5ea89a0 3575914560 C Ci:1:001:0 0 4 = 01050000
An output bulk transfer to send a SCSI command 0x5E in a 31-byte Bulk wrapper
to a storage device at address 5:
-dd65f0e8 4128379752 S Bo:005:02 -115 31 = 55534243 5e000000 00000000 00000600 00000000 00000000 00000000 000000
-dd65f0e8 4128379808 C Bo:005:02 0 31 >
+dd65f0e8 4128379752 S Bo:1:005:2 -115 31 = 55534243 5e000000 00000000 00000600 00000000 00000000 00000000 000000
+dd65f0e8 4128379808 C Bo:1:005:2 0 31 >
* Raw binary format and API
* to a local DoS. But we have to keep to root in order to prevent
* password sniffing from HID devices.
*/
-#define EVENT_MAX (2*PAGE_SIZE / sizeof(struct mon_event_text))
+#define EVENT_MAX (4*PAGE_SIZE / sizeof(struct mon_event_text))
-#define PRINTF_DFL 160
+/*
+ * Potentially unlimited number; we limit it for similar allocations.
+ * The usbfs limits this to 128, but we're not quite as generous.
+ */
+#define ISODESC_MAX 5
+
+#define PRINTF_DFL 250 /* with 5 ISOs segs */
+
+struct mon_iso_desc {
+ int status;
+ unsigned int offset;
+ unsigned int length; /* Unsigned here, signed in URB. Historic. */
+};
struct mon_event_text {
struct list_head e_link;
unsigned int pipe; /* Pipe */
unsigned long id; /* From pointer, most of the time */
unsigned int tstamp;
+ int busnum;
int length; /* Depends on type: xfer length or act length */
int status;
+ int interval;
+ int start_frame;
+ int error_count;
char setup_flag;
char data_flag;
+ int numdesc; /* Full number */
+ struct mon_iso_desc isodesc[ISODESC_MAX];
unsigned char setup[SETUP_MAX];
unsigned char data[DATA_MAX];
};
static void mon_text_ctor(void *, struct kmem_cache *, unsigned long);
+struct mon_text_ptr {
+ int cnt, limit;
+ char *pbuf;
+};
+
+static struct mon_event_text *
+ mon_text_read_wait(struct mon_reader_text *rp, struct file *file);
+static void mon_text_read_head_t(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep);
+static void mon_text_read_head_u(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep);
+static void mon_text_read_statset(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep);
+static void mon_text_read_intstat(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep);
+static void mon_text_read_isostat(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep);
+static void mon_text_read_isodesc(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep);
+static void mon_text_read_data(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep);
+
/*
* mon_text_submit
* mon_text_complete
len = DATA_MAX;
if (usb_pipein(pipe)) {
- if (ev_type == 'S')
+ if (ev_type != 'C')
return '<';
} else {
- if (ev_type == 'C')
+ if (ev_type != 'S')
return '>';
}
{
struct mon_event_text *ep;
unsigned int stamp;
+ struct usb_iso_packet_descriptor *fp;
+ struct mon_iso_desc *dp;
+ int i, ndesc;
stamp = mon_get_timestamp();
ep->type = ev_type;
ep->pipe = urb->pipe;
ep->id = (unsigned long) urb;
+ ep->busnum = rp->r.m_bus->u_bus->busnum;
ep->tstamp = stamp;
ep->length = (ev_type == 'S') ?
urb->transfer_buffer_length : urb->actual_length;
/* Collecting status makes debugging sense for submits, too */
ep->status = urb->status;
+ if (usb_pipeint(urb->pipe)) {
+ ep->interval = urb->interval;
+ } else if (usb_pipeisoc(urb->pipe)) {
+ ep->interval = urb->interval;
+ ep->start_frame = urb->start_frame;
+ ep->error_count = urb->error_count;
+ }
+ ep->numdesc = urb->number_of_packets;
+ if (usb_pipeisoc(urb->pipe) && urb->number_of_packets > 0) {
+ if ((ndesc = urb->number_of_packets) > ISODESC_MAX)
+ ndesc = ISODESC_MAX;
+ fp = urb->iso_frame_desc;
+ dp = ep->isodesc;
+ for (i = 0; i < ndesc; i++) {
+ dp->status = fp->status;
+ dp->offset = fp->offset;
+ dp->length = (ev_type == 'S') ?
+ fp->length : fp->actual_length;
+ fp++;
+ dp++;
+ }
+ }
+
ep->setup_flag = mon_text_get_setup(ep, urb, ev_type, rp->r.m_bus);
ep->data_flag = mon_text_get_data(ep, urb, ep->length, ev_type,
rp->r.m_bus);
ep->type = 'E';
ep->pipe = urb->pipe;
ep->id = (unsigned long) urb;
+ ep->busnum = 0;
ep->tstamp = 0;
ep->length = 0;
ep->status = error;
* dd if=/dbg/usbmon/0t bs=10
* Also, we do not allow seeks and do not bother advancing the offset.
*/
-static ssize_t mon_text_read(struct file *file, char __user *buf,
+static ssize_t mon_text_read_t(struct file *file, char __user *buf,
+ size_t nbytes, loff_t *ppos)
+{
+ struct mon_reader_text *rp = file->private_data;
+ struct mon_event_text *ep;
+ struct mon_text_ptr ptr;
+
+ if (IS_ERR(ep = mon_text_read_wait(rp, file)))
+ return PTR_ERR(ep);
+ mutex_lock(&rp->printf_lock);
+ ptr.cnt = 0;
+ ptr.pbuf = rp->printf_buf;
+ ptr.limit = rp->printf_size;
+
+ mon_text_read_head_t(rp, &ptr, ep);
+ mon_text_read_statset(rp, &ptr, ep);
+ ptr.cnt += snprintf(ptr.pbuf + ptr.cnt, ptr.limit - ptr.cnt,
+ " %d", ep->length);
+ mon_text_read_data(rp, &ptr, ep);
+
+ if (copy_to_user(buf, rp->printf_buf, ptr.cnt))
+ ptr.cnt = -EFAULT;
+ mutex_unlock(&rp->printf_lock);
+ kmem_cache_free(rp->e_slab, ep);
+ return ptr.cnt;
+}
+
+static ssize_t mon_text_read_u(struct file *file, char __user *buf,
size_t nbytes, loff_t *ppos)
{
struct mon_reader_text *rp = file->private_data;
+ struct mon_event_text *ep;
+ struct mon_text_ptr ptr;
+
+ if (IS_ERR(ep = mon_text_read_wait(rp, file)))
+ return PTR_ERR(ep);
+ mutex_lock(&rp->printf_lock);
+ ptr.cnt = 0;
+ ptr.pbuf = rp->printf_buf;
+ ptr.limit = rp->printf_size;
+
+ mon_text_read_head_u(rp, &ptr, ep);
+ if (ep->type == 'E') {
+ mon_text_read_statset(rp, &ptr, ep);
+ } else if (usb_pipeisoc(ep->pipe)) {
+ mon_text_read_isostat(rp, &ptr, ep);
+ mon_text_read_isodesc(rp, &ptr, ep);
+ } else if (usb_pipeint(ep->pipe)) {
+ mon_text_read_intstat(rp, &ptr, ep);
+ } else {
+ mon_text_read_statset(rp, &ptr, ep);
+ }
+ ptr.cnt += snprintf(ptr.pbuf + ptr.cnt, ptr.limit - ptr.cnt,
+ " %d", ep->length);
+ mon_text_read_data(rp, &ptr, ep);
+
+ if (copy_to_user(buf, rp->printf_buf, ptr.cnt))
+ ptr.cnt = -EFAULT;
+ mutex_unlock(&rp->printf_lock);
+ kmem_cache_free(rp->e_slab, ep);
+ return ptr.cnt;
+}
+
+static struct mon_event_text *mon_text_read_wait(struct mon_reader_text *rp,
+ struct file *file)
+{
struct mon_bus *mbus = rp->r.m_bus;
DECLARE_WAITQUEUE(waita, current);
struct mon_event_text *ep;
- int cnt, limit;
- char *pbuf;
- char udir, utype;
- int data_len, i;
add_wait_queue(&rp->wait, &waita);
set_current_state(TASK_INTERRUPTIBLE);
if (file->f_flags & O_NONBLOCK) {
set_current_state(TASK_RUNNING);
remove_wait_queue(&rp->wait, &waita);
- return -EWOULDBLOCK; /* Same as EAGAIN in Linux */
+ return ERR_PTR(-EWOULDBLOCK);
}
/*
* We do not count nwaiters, because ->release is supposed
schedule();
if (signal_pending(current)) {
remove_wait_queue(&rp->wait, &waita);
- return -EINTR;
+ return ERR_PTR(-EINTR);
}
set_current_state(TASK_INTERRUPTIBLE);
}
set_current_state(TASK_RUNNING);
remove_wait_queue(&rp->wait, &waita);
+ return ep;
+}
- mutex_lock(&rp->printf_lock);
- cnt = 0;
- pbuf = rp->printf_buf;
- limit = rp->printf_size;
+static void mon_text_read_head_t(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep)
+{
+ char udir, utype;
udir = usb_pipein(ep->pipe) ? 'i' : 'o';
switch (usb_pipetype(ep->pipe)) {
case PIPE_CONTROL: utype = 'C'; break;
default: /* PIPE_BULK */ utype = 'B';
}
- cnt += snprintf(pbuf + cnt, limit - cnt,
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
"%lx %u %c %c%c:%03u:%02u",
ep->id, ep->tstamp, ep->type,
- utype, udir, usb_pipedevice(ep->pipe), usb_pipeendpoint(ep->pipe));
+ utype, udir,
+ usb_pipedevice(ep->pipe), usb_pipeendpoint(ep->pipe));
+}
+
+static void mon_text_read_head_u(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep)
+{
+ char udir, utype;
+
+ udir = usb_pipein(ep->pipe) ? 'i' : 'o';
+ switch (usb_pipetype(ep->pipe)) {
+ case PIPE_ISOCHRONOUS: utype = 'Z'; break;
+ case PIPE_INTERRUPT: utype = 'I'; break;
+ case PIPE_CONTROL: utype = 'C'; break;
+ default: /* PIPE_BULK */ utype = 'B';
+ }
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ "%lx %u %c %c%c:%d:%03u:%u",
+ ep->id, ep->tstamp, ep->type,
+ utype, udir,
+ ep->busnum, usb_pipedevice(ep->pipe), usb_pipeendpoint(ep->pipe));
+}
+
+static void mon_text_read_statset(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep)
+{
if (ep->setup_flag == 0) { /* Setup packet is present and captured */
- cnt += snprintf(pbuf + cnt, limit - cnt,
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
" s %02x %02x %04x %04x %04x",
ep->setup[0],
ep->setup[1],
(ep->setup[5] << 8) | ep->setup[4],
(ep->setup[7] << 8) | ep->setup[6]);
} else if (ep->setup_flag != '-') { /* Unable to capture setup packet */
- cnt += snprintf(pbuf + cnt, limit - cnt,
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
" %c __ __ ____ ____ ____", ep->setup_flag);
} else { /* No setup for this kind of URB */
- cnt += snprintf(pbuf + cnt, limit - cnt, " %d", ep->status);
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ " %d", ep->status);
+ }
+}
+
+static void mon_text_read_intstat(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep)
+{
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ " %d:%d", ep->status, ep->interval);
+}
+
+static void mon_text_read_isostat(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep)
+{
+ if (ep->type == 'S') {
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ " %d:%d:%d", ep->status, ep->interval, ep->start_frame);
+ } else {
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ " %d:%d:%d:%d",
+ ep->status, ep->interval, ep->start_frame, ep->error_count);
}
- cnt += snprintf(pbuf + cnt, limit - cnt, " %d", ep->length);
+}
+
+static void mon_text_read_isodesc(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep)
+{
+ int ndesc; /* Display this many */
+ int i;
+ const struct mon_iso_desc *dp;
+
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ " %d", ep->numdesc);
+ ndesc = ep->numdesc;
+ if (ndesc > ISODESC_MAX)
+ ndesc = ISODESC_MAX;
+ if (ndesc < 0)
+ ndesc = 0;
+ dp = ep->isodesc;
+ for (i = 0; i < ndesc; i++) {
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ " %d:%u:%u", dp->status, dp->offset, dp->length);
+ dp++;
+ }
+}
+
+static void mon_text_read_data(struct mon_reader_text *rp,
+ struct mon_text_ptr *p, const struct mon_event_text *ep)
+{
+ int data_len, i;
if ((data_len = ep->length) > 0) {
if (ep->data_flag == 0) {
- cnt += snprintf(pbuf + cnt, limit - cnt, " =");
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ " =");
if (data_len >= DATA_MAX)
data_len = DATA_MAX;
for (i = 0; i < data_len; i++) {
if (i % 4 == 0) {
- cnt += snprintf(pbuf + cnt, limit - cnt,
+ p->cnt += snprintf(p->pbuf + p->cnt,
+ p->limit - p->cnt,
" ");
}
- cnt += snprintf(pbuf + cnt, limit - cnt,
+ p->cnt += snprintf(p->pbuf + p->cnt,
+ p->limit - p->cnt,
"%02x", ep->data[i]);
}
- cnt += snprintf(pbuf + cnt, limit - cnt, "\n");
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
+ "\n");
} else {
- cnt += snprintf(pbuf + cnt, limit - cnt,
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt,
" %c\n", ep->data_flag);
}
} else {
- cnt += snprintf(pbuf + cnt, limit - cnt, "\n");
+ p->cnt += snprintf(p->pbuf + p->cnt, p->limit - p->cnt, "\n");
}
-
- if (copy_to_user(buf, rp->printf_buf, cnt))
- cnt = -EFAULT;
- mutex_unlock(&rp->printf_lock);
- kmem_cache_free(rp->e_slab, ep);
- return cnt;
}
static int mon_text_release(struct inode *inode, struct file *file)
return 0;
}
-static const struct file_operations mon_fops_text = {
+static const struct file_operations mon_fops_text_t = {
.owner = THIS_MODULE,
.open = mon_text_open,
.llseek = no_llseek,
- .read = mon_text_read,
- /* .write = mon_text_write, */
- /* .poll = mon_text_poll, */
- /* .ioctl = mon_text_ioctl, */
+ .read = mon_text_read_t,
+ .release = mon_text_release,
+};
+
+static const struct file_operations mon_fops_text_u = {
+ .owner = THIS_MODULE,
+ .open = mon_text_open,
+ .llseek = no_llseek,
+ .read = mon_text_read_u,
.release = mon_text_release,
};
rc = snprintf(name, NAMESZ, "%dt", ubus->busnum);
if (rc <= 0 || rc >= NAMESZ)
goto err_print_t;
- d = debugfs_create_file(name, 0600, mon_dir, mbus, &mon_fops_text);
+ d = debugfs_create_file(name, 0600, mon_dir, mbus, &mon_fops_text_t);
if (d == NULL)
goto err_create_t;
mbus->dent_t = d;
- /* XXX The stats do not belong to here (text API), but oh well... */
+ rc = snprintf(name, NAMESZ, "%du", ubus->busnum);
+ if (rc <= 0 || rc >= NAMESZ)
+ goto err_print_u;
+ d = debugfs_create_file(name, 0600, mon_dir, mbus, &mon_fops_text_u);
+ if (d == NULL)
+ goto err_create_u;
+ mbus->dent_u = d;
+
rc = snprintf(name, NAMESZ, "%ds", ubus->busnum);
if (rc <= 0 || rc >= NAMESZ)
goto err_print_s;
err_create_s:
err_print_s:
+ debugfs_remove(mbus->dent_u);
+ mbus->dent_u = NULL;
+err_create_u:
+err_print_u:
debugfs_remove(mbus->dent_t);
mbus->dent_t = NULL;
err_create_t:
void mon_text_del(struct mon_bus *mbus)
{
+ debugfs_remove(mbus->dent_u);
debugfs_remove(mbus->dent_t);
debugfs_remove(mbus->dent_s);
}