/dev/console and the MIBs of Heaven

Interesting problem with The Inside Thing at work today. The Inside Thing runs headless -- no video card, no serial port (yet...sigh), connections only over IP. SSH to The Inside Thing has been no problem, and I never thought it would be.

One of the developers today loaded a debugging version of the FreeBSD kernel module he's working on, and found that it really slowed things down: a test script that would complete in a second, using the non-debugging module, would take a minute or more to run; in addition, the whole system would slow down to the point of near-unusability. WTF?

The debugging version does a lot of kernel printfs (I'm not a developer, so forgive me for any imprecision in language here). Logging is done to two places: /var/log/whatever, and over UDP to The Outside Thing, which has its syslog daemon listening to port grep syslog /etc/services. /var, on The Inside Thing, is just this big (32 MB) memory filesystem, so that shouldn't be a problem. And the network connection is gigabit ethernet, so that shouldn't be an issue.

I ran fstat while the program was running; it showed nothing unexpected: files open in /usr (where the program lives), the developer's home directory (NFS), /dev/insidething and /var/log/whatever. But run systat -vm, and hey, what's this: tons of interrupts on sio0.

This didn't work:

rm /dev/cuaa
mknod /dev/cuaa0 c 2 2

So on to less drastic measures.

I tried upping the serial port speed (we'd turned it on, but still haven't got a socket we can hook to yet) from 9600 to 115200 in /etc/ttys, and HUPping init; no change. (Incidentally, to get the serial port working on another FreeBSD machine over a null modem cable, I had to set it to 9600.3wire; strange. Or perhaps not.)

My boss came by at that point, and told me that the kernel printfs were not affected by stuff like getty and init; instead, there was a kernel option or possibly a sysctl that set that. Sure enough, look around and there's machdep.conspeed: 9600. Set it to 115200 and whee, look at things go! The debugging program ran in 30 seconds, which by this point seemed like a definite improvement.

I experimented a bit and found the highest machdep.conspeed could be set to something like 118900. Like before, this was better but by no means great. Then my boss came in again and announced a new sysctl MIB, greater than all the rest. This one was The Light, and the other one only came to announce The Light to the world:

kern.consmute

Set to 1, and all those kernel printfs still get logged to syslog, but never slow down The Inside Thing. I'm assuming that all this was trying to go out over the serial port after FreeBSD detected no video card...but I'm the first to admit that's probably a crack-addled dream.

Original entry.