Bug 14456 - usbmon: binary interface reports URB data wrongly
Summary: usbmon: binary interface reports URB data wrongly
Status: RESOLVED INVALID
Alias: None
Product: Drivers
Classification: Unclassified
Component: USB (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Pete Zaitcev
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-10-23 07:33 UTC by Márton Németh
Modified: 2009-10-26 01:20 UTC (History)
1 user (show)

See Also:
Kernel Version: 2.6.32-rc5
Subsystem:
Regression: No
Bisected commit-id:


Attachments
URBs captured through the text interface (2.66 KB, text/plain)
2009-10-23 07:33 UTC, Márton Németh
Details
URBs captured through binary interface (13.98 KB, text/plain)
2009-10-23 07:35 UTC, Márton Németh
Details
caputre data saved from Wireshark (3.14 KB, application/octet-stream)
2009-10-23 07:36 UTC, Márton Németh
Details
Patch for Wireshark to dump URBs on stdout (1.83 KB, patch)
2009-10-23 07:38 UTC, Márton Németh
Details | Diff
Linux kernel configuration 2.6.32-rc5 (66.83 KB, text/plain)
2009-10-23 07:40 UTC, Márton Németh
Details
Some debug messages for usbmon binary interface (2.42 KB, patch)
2009-10-23 10:38 UTC, Márton Németh
Details | Diff
Repeated with wireshark (15.63 KB, text/plain)
2009-10-23 10:39 UTC, Márton Németh
Details
the debug messages from dmesg (18.38 KB, text/plain)
2009-10-23 10:40 UTC, Márton Németh
Details
Some more debug messages (4.11 KB, patch)
2009-10-24 06:16 UTC, Márton Németh
Details | Diff
Patch for Wireshark to dump URBs on stdout (typo corrected) (1.83 KB, patch)
2009-10-24 07:29 UTC, Márton Németh
Details | Diff
strace verbose output while running Wireshark (313.66 KB, application/x-gzip)
2009-10-25 08:02 UTC, Márton Németh
Details
stdout of the previous Wireshark capture (28.48 KB, text/plain)
2009-10-25 08:05 UTC, Márton Németh
Details
the bad capture file saved from Wireshark (3.39 KB, application/octet-stream)
2009-10-25 08:06 UTC, Márton Németh
Details

Description Márton Németh 2009-10-23 07:33:42 UTC
Created attachment 23496 [details]
URBs captured through the text interface

There is a difference in binary data what is reported through the text interface /sys/kernel/debug/usb/usbmon/1u and through /dev/usbmon1. The URB data is wrong on binary interface.

How to reproduce:
1. modprobe -k usbmon
2. mount debugfs /sys/kernel/debug/ -t debugfs
3. Open two xterm windows: "A" and "B"
4. On "A" execute:
   cat /sys/kernel/debug/usb/usbmon/1u >usbmon_1u.txt
5. On "B" execute a patched version of Wireshark. Redirect stdout to usbmon_binary_wireshark.txt . The patch just prints out what Wireshark reads from /dev/usbmon1 in human readable form. The lines starting with 
pcap_read_linux_usb_pseudoheader() show the pseudoheader. Lines starting with libpcap_read_rec_data() show the URB packet data.
6. Start capturing in Wireshark on USB bus 1.
7. Plug in Genius NetScroll 110 USB mouse to USB bus 1.

Current result:
The URBs captured through text interface seems to be OK, the URBs captured on binary interface are bad.

Expected result:
The same URB data is read through the text interface and the binary interface.
Comment 1 Márton Németh 2009-10-23 07:35:22 UTC
Created attachment 23497 [details]
URBs captured through binary interface
Comment 2 Márton Németh 2009-10-23 07:36:05 UTC
Created attachment 23498 [details]
caputre data saved from Wireshark
Comment 3 Márton Németh 2009-10-23 07:38:45 UTC
Created attachment 23499 [details]
Patch for Wireshark to dump URBs on stdout
Comment 4 Márton Németh 2009-10-23 07:40:15 UTC
Created attachment 23500 [details]
Linux kernel configuration 2.6.32-rc5
Comment 5 Márton Németh 2009-10-23 10:38:30 UTC
Created attachment 23501 [details]
Some debug messages for usbmon binary interface
Comment 6 Márton Németh 2009-10-23 10:39:14 UTC
Created attachment 23502 [details]
Repeated with wireshark
Comment 7 Márton Németh 2009-10-23 10:40:49 UTC
Created attachment 23503 [details]
the debug messages from dmesg

The attachment 23502 [details] and this one was created at the same time.
Comment 8 Greg Kroah-Hartman 2009-10-23 23:05:18 UTC
On Fri, Oct 23, 2009 at 07:33:48AM +0000, bugzilla-daemon@bugzilla.kernel.org wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=14456
> 
>            Summary: usbmon: binary interface reports URB data wrongly

Can you please post this information on the linux-usb@vger.kernel.org
mailing list so that the linux usb developers can comment on it?
Comment 9 Márton Németh 2009-10-24 06:16:55 UTC
Created attachment 23511 [details]
Some more debug messages
Comment 10 Márton Németh 2009-10-24 07:26:59 UTC
Note that there is one additional layer between kernel and Wireshark: this is libpcap from http://www.tcpdump.org/ .
Comment 11 Márton Németh 2009-10-24 07:29:07 UTC
Created attachment 23512 [details]
Patch for Wireshark to dump URBs on stdout (typo corrected)
Comment 12 Márton Németh 2009-10-25 08:02:23 UTC
Created attachment 23519 [details]
strace verbose output while running Wireshark

I checked usbmon from  http://people.redhat.com/zaitcev/linux/usbmon-5.4.tar.gz
which works correctly without debugfs and usbfs mounted. The packages are shown correctly.

Wireshark can only start capturing if usbfs is mounted, debugfs is not necessary.

I run Wireshark with strace, the output is attached. The packages are captured wrongly. You might also want to see attachment 23511 [details] which is created from dmesg with a patched usbmon kernel module. On that log the function calls are also shown.
Comment 13 Márton Németh 2009-10-25 08:04:11 UTC
(In reply to comment #12)
> You might also want to see attachment 23511 [details] which is created from
> dmesg with a patched usbmon kernel module. On that log the function calls are
> also shown.

I mean attachment 23503 [details]...
Comment 14 Márton Németh 2009-10-25 08:05:07 UTC
Created attachment 23520 [details]
stdout of the previous Wireshark capture
Comment 15 Márton Németh 2009-10-25 08:06:34 UTC
Created attachment 23521 [details]
the bad capture file saved from Wireshark
Comment 16 Pete Zaitcev 2009-10-25 18:34:09 UTC
Thanks, that helps a lot.

So, Wireshark (libpcap) does this:

4849  open("/dev/usbmon1", O_RDONLY|O_LARGEFILE) = 3
.........
4849  select(4, [3], NULL, NULL, {0, 250000} <unfinished ...>
4849  <... select resumed> )            = 1 (in [3], left {0, 241497})
4849  ioctl(3, 0xc00c9207, 0xbfc161a0)  = 0   <---- 32 bit MON_IOCX_MFETCH
4849  ioctl(3, 0x9208, 0x1)             = 1   <---- MON_IOCH_MFLUSH
4849  time(NULL)                        = 1256456277
4849  select(4, [3], NULL, NULL, {0, 250000}) = 1 (in [3], left {0, 247121})
4849  ioctl(3, 0xc00c9207, 0xbfc161a0)  = 0
4849  ioctl(3, 0x9208, 0x1)             = 1

And usbmon(8) does this:

open("/dev/usbmon0", O_RDWR)            = 3
ioctl(3, 0x4018920a, 0x7fff258c5c70)    = 0   <---- MON_IOCX_GETX
write(1, "26092318 0.800486 S Ci:1:001:0 s "..., 58) = 58
ioctl(3, 0x4018920a, 0x7fff258c5c70)    = 0
write(1, "26092318 0.800791 C Ci:1:001:0 0 "..., 46) = 46

It's one of:
 - I never tested MFETCH implementation and it's buggy, or
 - Paolo never tested his code for binary API and it's buggy, or
 - Something bitrotted and Paolo's code stopped working

I see from the text output that it's a 32-bit kernel, so there are
no issues with the compat implementation.
Comment 17 Márton Németh 2009-10-25 22:26:47 UTC
Upgrading to libpcap git 339d28cefc11bbadaa92005b4f7b365f4732432c ("git clone git://bpf.tcpdump.org/libpcap") fixes the problem.
Comment 18 Pete Zaitcev 2009-10-26 01:20:15 UTC
Thanks a lot. I already started writing tests but you pre-empted that.
Let's close the bug.

Note You need to log in before you can comment on or make changes to this bug.