[logs] Logging oddity from FreeBSD

[Tina Bird]

> > Jun 13 00:57:57 <hostname> kernel: 
> > 
> > Jun 13 00:57:57 <hostname> named[45636]: transfer of 
> 'example.com/IN' from
> > xyz.xyz.xyz.xyz#53: failed to connect: timed out

> I have seen this something similar elsewhere with a different vendor's
> *nix + modified kernel (hi, Marcus) + syslogd.  It tended to happen
> when the system was busy and logging a *lot* of messages at the kernel
> level.  On some *nix systems, logging from kernel space to user space
> happens by way of a circular buffer.  I think what happens is that the
> kernel is producing logs faster than userspace can actually read them,
> so syslogd/klogd gets partial messages at the wraparound point.

Yeah, that's exactly the scenario I was imagining...I'm sure there was a
list discussion about it at some point around here.

> You should be able to sim/stim this by setting up a system with a
> firewall that does a lot of logging from kernel space, no rate
> limiting for the logging, loading up the system with some CPU-hogging
> and IO-hogging processes, and throwing a wide variety of bad traffic
> at it really fast, for a while.  The kernel log buffer will fill up,
> and then syslogd will start reading partial lines.
> 
> Oh, and you've made certain that there aren't vt100 or ANSI escapes
> that are playing cursor games, right?

It's archival data. I am not sufficiently bothered right this very moment to
explore it any more deeply, but at least I've had someone validate my
speculation that it was due to poorly behaved buffering.

thanks!