I recently came into possession of a LucidSound LS30 wireless headset. The headset came well reviewed by the Wirecutter, and given the descriptions and the moderate documentation on the LucidSound web site, I was optimistic that the headset would have reasonable Linux compatibility.

Everything I’ve found out about the headset specifically will likely wait for another day, but this whole process of trying to debug the behavior of a misbehaving USB device has given me more insight into debugging and interfacing with the Linux kernel and hardware drivers.

Starting Point

The vast majority of Linux users should be familiar with the dmesg command. This command spits out the various debug messages sent from the linux kernel, and these days is full of color and is relatively readable. Staring at this will usually yield some basic information, but detailed debug messages are often not sent here as the user really doesn’t care on a day to day basis. As an extreme example, dmesg will usually spit out some basic information every time you insert a USB device, but you wouldn’t want this log spewing messages every time you triggered an event with your mouse or keyboard. If you want to view that kind of information, you’re probably not looking for kernel debugging information but rather should look into usbmon.

That aside, I haven’t dug into the specifics of how buffering is handled in the kernel interface, but my understanding suggests that any call that sends a message to dmesg is actually flushed right away. This is in contrast to most messages sent to stdout waiting to flush until the system is opportunistically ready to handle the buffer, or some specific line control character (typically \n) is placed into the buffer. One consequence of flushing regularly is you will incur a serious performance hit if a large volume of messages is being sent with high regularity.

Getting Debugging Messages

In my case I knew that the problem revolved around specifics of the snd-usb-audio.ko kernel driver, and digging into the source of that driver even shows a number of built in debug messages that I wasn’t seeing.

Getting access to these messages is actually pretty straightforward. A few years back a control mechanism for these messages was introduced into debugfs to control exactly what messages are displayed when you need to probe and debug your hardware. An LWN article describing the interface, along with the core kernel documentation are readily available, but given the difficulty I had finding anyone who knew that this thing existed, I gather it is not widely known to anyone who doesn’t dive into the kernel space from time to time.

With that in mind, here is a basic overview of the quick/dirty way to get the debug interface to spill it’s secrets:

The core configuration is handled by inspecting the debugfs dynamic debugging control file. Assuming sysfs is mounted at /sys, this file is at /sys/kernel/debug/dynamic_debug/control. If you want to enable messages that are at higher debug levels (e.g. dev_dbg() kernel calls and such), we simply send a message to this interface (via echo) specifying the file we want to enable message printing for. This takes the form of:

echo file <somefile.c> +p > /sys/kernel/debug/dynamic_debug/control

The obvious question being when starting out: how the hell do I figure out what file I actually need to look at? As in my case, there is a chance you already have a vague idea of where the problem exists, and simply want to pinpoint a certain behavior. Either that or you have a specific module in mind, but not much else. Conveniently, you can actually inspect the control file directly to pull out what lines of code are generating existing messages.

grep \.c: /sys/kernel/debug/dynamic_debug/control | cut -d: -f1 | sort | uniq

Most of the files for a bundled kernel module will have some relative path, but note that if you end up building and inserting a module (see insmod) as you tinker and hack at the kernel, that module may end up using an absolute path rather than the standard one.

To wrap it up, bellow is an example listing showing how to remove a stock kernel module in my system, followed by the insertion and enabling a custom module built in my home directory.

set -e; set -u; echo "$_______" # don't copy this directly into your terminal!
echo file sound/usb/stream.c +p > /sys/kernel/debug/dynamic_debug/control
dmesg -w # watch the output
# do some stuff, test your hardware, etc. ^C
# unplug hardware
rmmod snd-usb-audio
cd ${KERNEL_SOURCE_PATH}
sudo insmod ./debian/linux-image-4.13.0-25-generic-dbgsym/usr/lib/debug/lib/modules/4.13.0-25-generic/kernel/sound/usb/snd-usb-audio.ko
echo file ${KERNEL_SOURCE_PATH}/sound/usb/stream.c +p > /sys/kernel/debug/dynamic_debug/control
dmesg -w
# do more hardware stuff ^C

A note about your terminal suddenly closing

One final note, I’ve put that first line up there to discourage copy/paste from random web sites into your terminal. It should fail and stop your terminal session if you copy and paste it directly in. Ignore it, it’s to make you read this paragraph. Be honest, you found me through a random google search trying to quickly solve a problem. If you’re a bash user, use ^x ^e (Ctrl-X, Ctrl-E) to open your default editor in a terminal, to paste and inspect the commands. When you save the output and close the editor, the resulting file is run automatically.