Re: linux.git: printk() problem

[Linus Torvalds]

On Sun, Oct 23, 2016 at 12:06 PM, Joe Perches <joe@xxxxxxxxxxx> wrote:
> On Sun, 2016-10-23 at 11:11 -0700, Linus Torvalds wrote:
>>
>> And those two per se sound fairly easy to handle ("KERN_CONT means
>> append to the line buffer, otherwise flush the line buffer and move to
>> the record buffer").
>>
>> But what complicates things more is then the "console output", which
>> has two issues:
>>
>>  - it is done outside the locking regime for the line buffer and the
>> record buffer.
>>
>>  - it is done on _partial_ line buffers.
>
> EOL KERN_<LEVEL> and thread interleaving still exists.

Note that the thread interleaving is still trivial: it's easily done
at the point where we decide "can we append to the line buffer or
not". That's pretty simple. Just flush the record when the thread
changes.

So the interleaving will never go away, it's very fundamental - unless
we make the line buffer just be a per-thread thing. And yes, that
would be the cleanest solution, but it's also an extra buffer for each
thread, so realistically it's just not going to happen.

End result: I'm not worried about the interleaving. It will cause ugly
output, but we've always had that, and the solution to it is "if you
absolutely don't want interleaving, then don't try to print partial
lines!".

The classic "don't do that then" response, in other world.

No, the real complexity comes from that interaction with the console
output, which is done outside the core log locks, and which currently
has the added thing where we have a "has this line fragment been
flushed or not".

That "has this line fragment been flushed or not" is particularly
painful, because we may have flushed it *partially*. That "cont.cons"
thing is a counter of how many bytes have been flushed, and we can be
in the situation where we have had multiple continuations added to the
line buffer, and only *some* of them have been flushed to the console.

(Reasons for not flushing: we couldn't get the console lock because
another process held it due to logging or whatever).

And then the interface to the actual record logging only has a "all or
nothing was flushed" flag (LOG_NOCONS) to avoid flushing things twice.
So when we actually log the record, we lose the "this line was only
partially printed".

That whole "we've flushed part of the line to the console" thing is
why it would make things so much easier to just log full records to
the console. Getting rid of that gets rid of a lot of ugly and
hard-to-read crap. Yes, the line buffer would still remain, and yes,
you'd still see the interleaving with threads, but that's not
"complexity", that's just "visually ugly output".

                 Linus