Re: linux.git: printk() problem

[Linus Torvalds]

On Sun, Oct 23, 2016 at 2:22 AM, Geert Uytterhoeven
<geert@xxxxxxxxxxxxxx> wrote:
>
> These changes have an interesting side-effect on sequences of printk()s that
> lack proper continuation: they introduced a discrepancy between dmesg output
> and the actual kernel output.

Yes.

So the "print vs log" handling is really really horrible. I cleaned up
some of it, but left the really fundamental problems. I wanted to just
rewrite it all, but didn't quite have the heart for it.

The best solution by far would be to just not support KERN_CONT at
all, but there's too many "silly details" things that keep it from
being possible.

The basic issue is that we have the line buffer that is used for
continuations, and then the record buffer that is used for logging.

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.

Again, this would be absolutely trivial if we just said "we only print
the record buffer". Easy, and solves all the problems. Except for
_one_ problem:

 - if a hang occurs in the middle of a continuation, we historically
*really* want that continuation to have been printed out.

For example, one of the really historical uses for partial lines is this:

       pr_info("Checking 'hlt' instruction... ");

       if (!boot_cpu_data.hlt_works_ok) {
               pr_cont("disabled\n");
               return;
       }
       halt();
       halt();
       halt();
       halt();
       pr_cont("OK\n");

and the point was that there used to be some really old i386 machines
that hung on the "hlt" instruction (probably not because of a CPU bug,
but because of either power supply issues or some DMA issues).

To support that, we really *had* to print out the continuation lines
even when they were partial. And that complicates the printk logic a
lot.

Now, that "hlt" case is long long gone, and maybe we should just say
"screw that". It would be really quite easy to say "we don't print out
continuation lines immediately, we just buffer them for 0.1s instead,
and KERN_CONT only works for things that really happen more or less
immediately".

Maybe that really is the right answer. Because the original cause of
us having to bend over backwards in this case is really no longer
there. And it would simplify printk a *lot*.

Let me whip up a minimal patch for you to try.

                Linus