usbmon: Extended text API

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);

}

	cnt += snprintf(pbuf + cnt, limit - cnt, " %d", ep->length);

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);

	}

}

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_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,

	/* .write =	mon_text_write, */

	/* .poll =		mon_text_poll, */

	/* .ioctl =	mon_text_ioctl, */

	.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);

}

	int text_inited;

	struct dentry *dent_s;		/* Debugging file */

	struct dentry *dent_t;		/* Text interface file */

	struct dentry *dent_u;		/* Second text interface file */

	int uses_dma;

	/* Ref */