Snooping the USB Data Stream
to log the control request information. After the read has completed, I add the following lines to log the actual data read from the device:
printk("control read: data "); for (j = 0; j < ctrl.wLength; ++j) printk("%02x ", ctrl.data[j]); printk("\n");
After doing much the same modification to the write section of the if statement, I build, reload the usbcore modules and verify that I now can log all control messages to and from the device. The messages returned are:
CONTROL control read: bRequest=06 bRrequestType=80 wValue=0300 wIndex=0000 control read: data 00 00 61 63
Day 6: Looking at the modifications I have made to the kernel code, I think this work might be something other users might like to have. So, it is time to clean up the code to a state that the USB maintainer might accept for the main kernel source tree.
First, I recognized that the calls to printk() are incorrect. All printk() calls must be accompanied by a proper logging level. These logging levels are added to printk calls by pre-appending the proper KERN_ values to the message. The file include/linux/kernel.h contains the following valid values that must be used:
#define KERN_EMERG "<0>" /* system is unusable */ #define KERN_ALERT "<1>" /* action must be taken immediately */ #define KERN_CRIT "<2>" /* critical conditions */ #define KERN_ERR "<3>" /* error conditions */ #define KERN_WARNING "<4>" /* warning conditions */ #define KERN_NOTICE "<5>" /* normal but significant condition */ #define KERN_INFO "<6>" /* informational */ #define KERN_DEBUG "<7>" /* debug-level messages */
So, I change the printk calls in the usbfs_ioctl() function from:
Now the kernel janitors should not complain about improper printk() usage.
In looking further at the logging messages, however, it is hard to determine for what exact device the message is being logged. More information needs to be added to the printk() calls. Luckily, some macros already in the include/linux/device.h file can help us. They are the dev_printk() macro and its helper macros, dev_dbg(), dev_warn(), dev_info() and dev_err(). These macros all need an additional pointer to a struct device variable, which allows them to print out the unique device ID for the message. So I change the printk() calls again to look like this:
Then the control message printk() calls are changed to:
dev_info(&dev->dev, "control read: " "bRequest=%02x bRrequestType=%02x " "wValue=%04x wIndex=%04x\n", ctrl.bRequest, ctrl.bRequestType, ctrl.wValue, ctrl.wIndex); dev_info(&dev->dev, "control read: data "); for (j = 0; j < ctrl.wLength; ++j) printk("%02x ", ctrl.data[j]); printk("\n");
The printk calls that dump the data do not need to be changed, as they still are printing on the same line as the call to dev_info().
Now the log messages are much more informative, looking like the following:
usb 1-1: CONTROL usb 1-1: control read: bRequest=06 bRrequestType=80 wValue=0300 wIndex=0000 usb 1-1: control read: data 00 00 61 63
I can determine exactly what USB device is being talked to, which helps me weed out the messages for devices I do not care about.
Day 7: Oops, I now realize that if I expect this kernel change to be accepted by the community, I had better not always generate these messages. Otherwise, everyone would have their system logs overflowing with messages they do not care about. How to log messages only when asked?
I first look into making a new kernel build configuration option. A simple modification of the drivers/usb/core/Kconfig file adding a new option is simple, but in examining the required code changes, I soon realize that wrapping all of the new logging statements in a #ifdef CONFIG_USBFS_LOGGING statement would make the USB maintainer reject my kernel patch. #ifdef is not generally allowed within kernel code, as it cuts down on readability and makes maintaining the code over time almost impossible.
Instead, I look at making an option that can be changed at runtime. I add the following lines of code to the devio.c file:
static int usbfs_snoop = 0; module_param (usbfs_snoop, bool, S_IRUGO | S_IWUSR); MODULE_PARM_DESC (usbfs_snoop, "true to log all usbfs traffic");
This adds a new module parameter to the main usbcore module called usbfs_snoop. This can be seen after building the code by running the modinfo program:
$ modinfo usbcore license: GPL parm: blinkenlights:true to cycle leds on hubs parm: usbfs_snoop:true to log all usbfs traffic
By loading the module with the following line:
modprobe usbcore usbfs_snoop=1
- Stepping into Science
- Synacor, Inc.'s Zimbra Open Source Support and Zimbra Suite Plus
- Linux Journal December 2016
- CORSAIR's Carbide Air 740
- A Better Raspberry Pi Streaming Solution
- Tyson Foods Honored as SUSE Customer of the Year
- The Tiny Internet Project, Part II
- Radio Free Linux
- FutureVault Inc.'s FutureVault
- Tech Tip: Really Simple HTTP Server with Python
Pick up any e-commerce web or mobile app today, and you’ll be holding a mashup of interconnected applications and services from a variety of different providers. For instance, when you connect to Amazon’s e-commerce app, cookies, tags and pixels that are monitored by solutions like Exact Target, BazaarVoice, Bing, Shopzilla, Liveramp and Google Tag Manager track every action you take. You’re presented with special offers and coupons based on your viewing and buying patterns. If you find something you want for your birthday, a third party manages your wish list, which you can share through multiple social- media outlets or email to a friend. When you select something to buy, you find yourself presented with similar items as kind suggestions. And when you finally check out, you’re offered the ability to pay with promo codes, gifts cards, PayPal or a variety of credit cards.Get the Guide