usbmon capture and parser script

While trying to debug some issues on a driver on Linux, and using a Beagleboard card as a hardware USB sniffer[1], I noticed the need of having a parser to work with the sniffer data. While wireshark provides a good way of looking into the info, most of the times, I just want to convert the data into something more concise that allows me to work on a char terminal, and that allows to use a device-specific parser that translates an obscure log into device-specific register reads and writes.

[1] using the code available at: http://beagleboard-usbsniffer.blogspot.com/

So, I wrote a parser, in perl, called parse_tcpdump_log.pl. The current version is, in fact, more than a parser, as it allows both parsing a previously captured log, or to start a capture and parse data in real time. The script is available at the v4l-utils tree, on:

	http://git.linuxtv.org/v4l-utils.git?a=blob;f=contrib/parse_tcpdump_log.pl;h=f90e981125462a58cadefa607cbff0ecb4b5ed45;hb=HEAD

At the output, each line is a URB data control transfer. The script groups the request and the complete URB's into one line, so, each line of the dump will correspond to a call to usb_control_msg().

The output is:

        000000000 ms 000000 ms (000127 us EP=80) 80 06 00 01 00 00 28 00 >>> 12 01 00 02 00 00 00 40 40 20 13 65 10 01 00 01 02 01
        000000000 ms 000000 ms (000002 us EP=80) 80 06 00 01 00 00 28 00 >>> 12 01 00 02 09 00 00 40 6b 1d 02 00 06 02 03 02 01 01
        000000006 ms 000005 ms (000239 us EP=80) c0 00 00 00 45 00 03 00 <<< 00 00 10
        000001006 ms 001000 ms (000112 us EP=80) c0 00 00 00 45 00 03 00 <<< 00 00 10
        000001106 ms 000100 ms (000150 us EP=80) c0 00 00 00 45 00 03 00 <<< 00 00 10

The provided info on each of the above lines are:

- Time from the script start;
- Time from the last transaction;
- Time between URB send request and URB response;
- Endpoint for the transfer;
- 8 bytes with the following URB fields:
- Type (1 byte);
- Request (1 byte);
- wValue (2 bytes);
- wIndex (2 bytes);
- wLength (2 bytes);
- URB direction:
>>> - To URB device
<<< - To host
- Optional data (length is given by wLength).

It is also possible to produce a detailed log, when used with "--debug 2", like:

PARSED data:
RAW: ID => 0xffff880105a53f00
RAW: Payload => 00000000000000000000000000000000000200000000000012010002090000406b1d0200060203020101
RAW: Time => 1300309970.745112
RAW: Status => 0
RAW: ArrivalTime => 5584788795812741120.745112
RAW: URBLength => 18
RAW: TransferType => 2
RAW: Device => 1
RAW: Type => C
RAW: DataLength => 18
RAW: BusID => 1
RAW: HasData => present
RAW: Endpoint => 128
RAW: PayloadSize => 42
RAW: SetupRequest => not present

There are a few other parsers at the v4l-utils git tree that can work with the default output format and produce a device-specific output. For example, the parser_em28xx.pl will produce a code that will look close to the C clauses inside the em28xx driver. So, for a real-time debug of the em28xx driver, for example, it will do:

# ./parse_tcpdump_log.pl --pcap |./parse_em28xx.pl 

em28xx_read_reg(dev, EM28XX_R26_COMPR); /* read 0x0c */
em28xx_write_reg(dev, EM28XX_R26_COMPR, 0x0c); i2c_master_send(0xb8>>1, { 02 00 }, 0x02); i2c_master_send(0xb8>>1, { 00 00 }, 0x02); i2c_master_send(0xb8>>1, { 03 }, 0x01); i2c_master_recv(0xb8>>1, &buf, 0x01); /* 6f */
em28xx_read_reg(dev, 0x05); /* read 0x00 */
i2c_master_send(0xb8>>1, { 03 6f }, 0x02); em28xx_write_ac97(dev, AC97_MASTER_VOL, 0x8000); em28xx_write_ac97(dev, AC97_LINE_LEVEL_VOL, 0x8000); em28xx_write_ac97(dev, AC97_MASTER_MONO_VOL, 0x8000); em28xx_write_ac97(dev, AC97_LFE_MASTER_VOL, 0x8000);

I wrote a short summary on how to use it at:
http://linuxtv.org/wiki/index.php/Bus_snooping/sniffing#Snooping_Procedures:

The script also accepts the "--man" and "--help" parameters to produce a manpage or a help.

In summary, I hope that this script will ease USB device driver debug and development.

Feedback, fixes, etc are welcome.

Have fun,
Mauro.

Very cool stuff. You are away of:
http://vusb-analyzer.sourceforge.net/
right?

I know you are doing this in console mode, but it looks close to the same idea.

thanks,

greg k-h

Perhaps there should be some references to vusb-analyzer and similar tools in Documentation/usb/usbmon.txt (it now only mentions "usbdump" and "USBMon"). I remember looking for a tool like that (ie, a parser) for quite some time before stumbling onto vusb-analyzer.

Paul Bolle

Patches are always gladly welcome, especially for documentation :)

thanks,

greg k-h

Em 16-03-2011 17:20, Paul Bolle escreveu:

Thanks for pointing it. It seems very interesting.

Paul,

On a quick test, it seems that it doesn't recognize the tcpdump file format (at least, it was not able to capture the dump files I got with the beagleboard). Adding support for it could be an interesting addition to your code.

Btw, it seems that most of your work is focused on getting VMware logs. Most USB adapters I handle are USB 2.0 only, and have very high bandwidth requirements (something like 40%-60% of the total bandwidth available at the USB bus). It would be nice to be capable of using a VM on some cases, but the last time I tested VMWare, kvm, etc, none of them were capable of properly support USB 2.0 with isoc data transfers.

Do you know if any of them are now capable of properly emulate USB 2.0 isoc transfers and give enough performance for the devices to actually work with such high-bandwidth requirements?

Yes, there are some similarities, although I think that the tools complement each other.

Doing it via console is nice, as I can just use the serial interface of the beagleboard to capture and parse data in real time.

An offline graphic analyser is interesting, especially when you need to filter data and check event timings.

Yeah, that seems a good idea to me too.

Cheers,
Mauro

Please note that Micah Dowty is the maintainer of vusb-analyzer. I mostly cleaned, etc. its usbmon support (which was originally added by Christoph Zimmermann). Anyway, you're always free to try to add support for another file format. I must say that Micah was rather easy to work with.

Micah had a vmware.com address last time I contacted him. That should explain that focus.

This is not something I know much about. I tried to use some digital camera over USB with qemu without much success. Apparently qemu's USB pass through has little chance of supporting high bandwidth USB devices. See
http://lists.nongnu.org/archive/html/qemu-devel/2010-09/msg00017.html
for the - not very interesting - answer I got when I wanted to know more about the problems of USB pass through in qemu.

Paul Bolle

Right, vusb-analyzer doesn't currently understand tcpdump files.

I originally wrote it as just an internal debugging tool for VMware, but we open sourced it and I've been quite interested in including support for other log formats. It originally just had support for VMware's logs and for XML files dumped by the Ellisys hardware analyzers we use. Paul Bolle contributed usbmon log support.

I unfortunately haven't had much time to work on vusb-analyzer myself in the past few years.. I'm hoping that will change soon, but in any case I'd be happy to accept patches.

As another point of interest... I have some friends working on a hardware USB analyzer project (openvizsla.org) and they've been planning on using vusb-analyzer or something based on it. I've been thinking about rewriting it in something a bit faster than Python, improving the support for traversing large log files efficiently, and making it fully understand lower-level USB packet logs like you'd see from a hardware analyzer.

I think vusb-analyzer's strength has always been the graphical timing analysis and quickly navigating complex logs. Wireshark is probably better suited for deep protocol analysis.

I can't really speak for qemu, but I wrote the EHCI USB 2.0 Isochronous emulation that VMware uses.

At the risk of sounding like an advertisment, there are of course plenty of caveats to emulating Isochronous transfers in userspace.. but VMware's emulation usually manages to work correctly. You'll certainly run into problem devices sometimes, but the raw CPU power hasn't been an issue. I routinely tested it with high-bandwidth uncompressed TV tuner devices back in 2005 or 2006.

Cheers,
--beth

I guess I must be too tired to write email without making mistakes tonight...

As Paul said, the usbmon support was by Christoph Zimmermann. Paul had a number of other contributions, including a handful of cleanups to the usbmon code.

Sorry guys.

--beth