Re: Event logging vs enhancing printk

[Andrea Arcangeli <andrea@suse.de>]

On Tue, Apr 09, 2002 at 10:28:57PM -0700, Martin J. Bligh wrote:
> >> Right - what I'm proposing would be a generic equivalent of the
> >> local staging buffer and sprintf - basically just a little wrapper
> >> that does this for you, keeping a per task buffer somewhere.
> > 
> > That still doesn't solve the race with the interrupt handlers, you'd
> > need a buffer for each irq handler and one the softirq too to make
> > printk buffered and coeherent coherent across newlines (doable but even
> > more tricky and in turn less robust and less self contained).
> 
> I was envisaging a larger buffer where the current location pointer 
> simply taken by the interrupt handler, and the remaining section of
> that buffer was used for the "inner printk". Which is really just 
> like a stack, so it makes more sense to just allocate this off the
> stack really .... I think this would work? We might need to flush
> on a certain size limit (128 chars, maybe?) to stop any risk of
> stack overflow.

that's equivalent with the big difference it will waste many nr_task
times more ram, you'd need to reserve some ram in each task-buffer for
the nr_irqs*(bufsize+1) nested printk. So for every task in the system
you wouldn't have only the overhead of bufsize but bufsize*(nr_irqs+2).
It doesn't sound a good idea to me. remember all irqs can be nested. The
kernel stack is just unsafe enough against nested irq (not anymore on
x86-64 luckily), printk should have a guaranteed bufsize instead. It
would be pointless to make printk robust against \n and overflowing
trivially with nested irq, then you'd be unreliable again.

> > Some other code may omit it by mistake, leading to the other cpus
> > blackholed and data lost after the buffer on the other cpus overflowed
> > so at least we should put a timer that spawns an huge warning if a cpu
> > doesn't flush the buffer in a rasonable amount of time so we can catch
> > those places.
> 
> It seems that 99.9% of these cases are just assembling a line of output 
> a few characters at a time. There might be a few odd miscreants around,
> but not enough to worry about - I think it's overkill to do the runtime
> timer check, but we could always run like this to test it, or try to
> work some sort of automated code inspection (though that sounds hard to
> do 100% reliably).

Doing the check at runtime would be better, it will catch binary-only
module bugs and drivers out of the kernel bugs too. It should be
possible to disable the debugging feature with an #ifdef though.

But again, the above is all assuming we will change it, but I'm not
suggesting to change printk, I think atomicity printk-against-printk is
enough because of the non-segfaulting-human-parsing and because of the
low rate and in turn near zero probability for races (so basically zero
wasted time while reading the logs).

An high bandwith logging channel were such race starts to matter could
be built with PF_NETLINK or something like that, without using printk,
you need to store the plenty of data into a file and read it later, all
the console stuff is overhead for such a load, printk isn't high
bandwith in production, also think all the serial consoles out there.

Andrea