2011-03-16 18:34:27

by Mauro Carvalho Chehab

[permalink] [raw]
Subject: [ANNOUNCE] 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.


2011-03-16 19:48:15

by Greg KH

[permalink] [raw]
Subject: Re: [ANNOUNCE] usbmon capture and parser script

On Wed, Mar 16, 2011 at 03:34:17PM -0300, Mauro Carvalho Chehab wrote:
> 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.

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

2011-03-16 20:20:53

by Paul Bolle

[permalink] [raw]
Subject: Re: [ANNOUNCE] usbmon capture and parser script

On Wed, 2011-03-16 at 12:47 -0700, Greg KH wrote:
> 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.

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

2011-03-16 20:31:34

by Greg KH

[permalink] [raw]
Subject: Re: [ANNOUNCE] usbmon capture and parser script

On Wed, Mar 16, 2011 at 09:20:24PM +0100, Paul Bolle wrote:
> On Wed, 2011-03-16 at 12:47 -0700, Greg KH wrote:
> > 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.
>
> 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.

Patches are always gladly welcome, especially for documentation :)

thanks,

greg k-h

2011-03-17 11:47:09

by Mauro Carvalho Chehab

[permalink] [raw]
Subject: Re: [ANNOUNCE] usbmon capture and parser script

Em 16-03-2011 17:20, Paul Bolle escreveu:
> On Wed, 2011-03-16 at 12:47 -0700, Greg KH wrote:
>> Very cool stuff. You are away of:
>> http://vusb-analyzer.sourceforge.net/
>> right?

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?

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

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.

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

Yeah, that seems a good idea to me too.

Cheers,
Mauro

2011-03-18 17:21:48

by Paul Bolle

[permalink] [raw]
Subject: Re: [ANNOUNCE] usbmon capture and parser script

On Thu, 2011-03-17 at 08:46 -0300, Mauro Carvalho Chehab wrote:
> 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.

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.

> Btw, it seems that most of your work is focused on getting VMware logs.

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

> 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?

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

2011-03-25 02:54:29

by Micah Elizabeth Scott

[permalink] [raw]
Subject: Re: [ANNOUNCE] usbmon capture and parser script

On Fri, Mar 18, 2011 at 10:21:33AM -0700, Paul Bolle wrote:
> On Thu, 2011-03-17 at 08:46 -0300, Mauro Carvalho Chehab wrote:
> > 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.
>
> 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.
>
> > Btw, it seems that most of your work is focused on getting VMware logs.
>
> Micah had a vmware.com address last time I contacted him. That should
> explain that focus.

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.

> > 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?
>
> 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.

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

2011-03-25 03:04:46

by Micah Elizabeth Scott

[permalink] [raw]
Subject: Re: [ANNOUNCE] usbmon capture and parser script

On Thu, Mar 24, 2011 at 07:54:01PM -0700, Micah Elizabeth Scott wrote:
> Paul Bolle contributed usbmon log support.

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