Re: [PATCH] printk: inject caller information into the body of message

[Dmitry Vyukov]

On Wed, Jun 20, 2018 at 11:06 AM, Sergey Senozhatsky
<sergey.senozhatsky.work@xxxxxxxxx> wrote:
> Hi Dmitry,
>
> On (06/20/18 10:45), Dmitry Vyukov wrote:
>> Hi Sergey,
>>
>> What are the visible differences between this patch and Tetsuo's
>> patch?
>
> I guess none, and looking at your requirements below I tend to agree
> that Tetsuo's approach is probably what you need at the end of the day.
>
>> The only thing that will matter for syzkaller parsing in the
>> end is the resulting text format as it appears on console. But you say
>> "I'm not pushing for this particular message format", so what exactly
>> do you want me to provide feedback on?
>> I guess we need to handle pr_cont properly whatever approach we take.
>
> Mostly, was wondering about if:
> a) you need pr_cont() handling
> b) you need printk_safe() handling
>
> The reasons I left those things behind:
>
> a) pr_cont() is officially hated. It was never supposed to be used
>    on SMP systems. So I wasn't sure if we need all that effort and
>    add tricky code to handle pr_cont(). Given that syzkaller is
>    probably the only user of that functionality.

Well, if I put my syzkaller hat on, then I don't care what exactly
happens in the kernel, the only thing I care is well-formed output on
console that can be parsed unambiguously in all cases.
>From this point of view I guess pr_cont is actually syzkaller's worst
enemy. If pr_const is officially hated, and it causes corrupted crash
reports, then we can resolve it by just getting rid of more pr_cont's.
So potentially we do not need any support for pr_cont in this patch.
However, we also need to be practical and if there are tons of
pr_cont's then we need some intermediate support of them, just because
we won't be able to get rid of all of them overnight.

But even if we attach context to pr_cont, it still causes problems for
crash parsing, because today we see:

BUG: unable to handle
... 10 lines ...
kernel
... 10 lines ...
paging request
... 10 lines ...
at ADDR

Which is not too friendly for parsing regardless of contexts.
So I am leaning towards to getting rid of pr_cont's as the solution to
the problem.

Looking at current uses of pr_cont:
https://elixir.bootlin.com/linux/latest/ident/pr_cont
It does not look too bad. arch/ except for x86 and exotic drivers
won't cause problems for syzbot today, so we can live with these uses
for now.



> b) printk_safe output is quite uncommon. And we flush per-CPU buffer
>    from the same CPU which has caused printk_safe output [except for
>    panic() flush] therefore logging the info available to log_store()
>    seemed enough. IOW, once again, was a bit unsure if we want to add
>    some complex code to already complex code, with just one potential
>    user.


I can't fully answer this because I don't understand what are the
implications on actual output.
You can use this as litmus test: can you write a simple script that
will parse such output and make sense out of it?

Well, it's not for one user. It affects each and every single user of
Linux kernel out there. Just take a look at these, that's complete
nonsense, it's not that syzkaller can't make sense out of it, it's
nobody can make sense out of it:

https://gist.githubusercontent.com/dvyukov/1528e86e5139f2fd1bf9902398d48298/raw/3b42148554eefed210f1e626d5befd50405c5487/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/6e08ac521f3e19534970ed97aeee1603/raw/0f0bb361902de94e7ee331ac500a3ceebf812c22/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/6e9db2313e48773ad1cd861da8020008/raw/d5b7c023fc8a38c72b1cf8bb1da85fb1c31cea5f/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/3d1bda4c690414ac027de1da45759751/raw/2c68980eabf4f6be24060e807a75f2d3570b5a42/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/9b8831e9ac73ffafa111a33ad40c5667/raw/f4097fbea8f89b25a282a6ef7e648145e10ae4b7/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/d78a3187a1b4e004820e92efcb16f9e0/raw/5530bcbf009c3fba3c581b2d24c523c673c6ef12/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/da1e42436af9ad2afc7de49f2d503510/raw/7dd4cbcc651c5b87122f066a3c689999ae8c4121/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/4571b94bd8cbd78d759412c560fa395c/raw/964c73fc993fc8a9000571e0b7618000584f3638/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/b6deac5faa958ae3733413b34dd5feed/raw/c4da219e284f7fc55da8c3c3af623a87f31bf653/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/2f54c6a2e45347ea76d9c5ce3c0ff091/raw/45f4873898ec8e0d9aa16b9c5c63a85410fd05e0/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/96cb39e29124dbbe2a65a91ec7a5639e/raw/aa8f7b2b1dfa5b8bb8cf93d8a821ca9938e8fc54/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/424da8282d5b28f8be10eab595d37444/raw/acc2fb1ececc1ea9a8215213f7e37e08b524c096/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/b07f37720c632d6d56ae67d95e5599b3/raw/8624ba47d6eb4e7d4d58e3ae1242ebe6cc46d361/gistfile1.txt
https://gist.githubusercontent.com/dvyukov/bc24a7b92289ec04587fb29fc1085045/raw/3136e9262ee2233b5ab369a4a82e83953fc2d8a2/gistfile1.txt