Kernel Logging
While I usually write about programming in the land of milk and honey (i.e., Cocoa), I spent most of the previous ten years writing kernel-level code. Recently, I’ve ventured back into the kernel and was reminded of the challenge of logging from an I/O Kit driver. When writing code in the kernel for an I/O Kit driver, you can’t invoke printf to log messages. Instead, you usually invoke IOLog.
IOLog is definitely better than its counterparts in some other kernel environments. At least it takes a printf style format string so you don’t have to write your own implementation of vsnprintf in the kernel, which is a pain. However, IOLog has a couple of limitations. The first is minor; you can’t invoke it in a primary interrupt handler. This isn’t a big deal since, especially in the I/O Kit model, you should have very little code running in the interrupt context. The second is major; its message buffer is small. If you frequently invoke IOLog, you will loose messages. If you are trying to debug a problem by logging a ton of messages, this limitation can result in you being mislead. For example, you’ll be banging your head against the desk trying to figure out how your driver does “A” and “C” but never does “B.” Well, in reality, your driver did do “B” but that message was lost since the IOLog buffer overflowed. Curses!
So, what can be done? Well, there is this inexplicably under-publicized tool called FireLog that addresses all of the shortcomings of IOLog. Perhaps it isn’t well known since it is hidden in the FireWire SDK. But, you say, “My driver doesn’t do anything with Firewire; how does this help me?” That’s part of the confusion, FireLog simply uses the FireWire bus to send messages to another machine. Furthermore, it does this while allowing FireWire to continue to work (some other tools make normal FireWire services unavailable). Your driver doesn’t need to do anything FireWire related; you want to download the FireWire SDK just for its incredible debugging tools. In fairness to IOLog, FireLog does require a second machine on which the FireLog application runs. However, you’ll need a second machine once you panic anyway; so, you may as well hook it up over FireWire for logging as well.
The FireWire SDK has other incredible tools that are also useful for I/O Kit developers in general. Since I just mentioned kernel panics, I’ll mention that the FWPanicView tool allows you to capture the screen of a panicked machine. This sure beats copying down all that information by hand. Once you panic, you’ll need to debug your driver. You can do this over Ethernet, but there are a couple of advantages to using FireWire and the FireWireKDP tool instead. FireWire-based debugging is available at times when Ethernet is not (early when the kernel is loading, right before sleep, and right after wake). In addition, you don’t have to worry about your network configuration. Just plug and debug. There are other debugging tools included in the FireWire SDK but the ones that I’ve mentioned and the ones that I use. Some of the others, while useful, have caveats that cause me to shy away from them.
So, if you are developing an I/O Kit driver and haven’t already, do yourself a favor, download the FireWire SDK, investigate the debugging tools, and dramatically improve your debugging efficiency. If you are a user-mode Cocoa developer who is now feeling left out after reading this, don’t. You too can use FireLog. Why would you? Well, the invocation overhead is much less than that of printf. Regardless, what else are you going to do with that old Pismo?
