Re: printk feature for syzbot?

From: Dmitry Vyukov
Date: Fri May 11 2018 - 05:17:47 EST


On Fri, May 11, 2018 at 8:21 AM, Sergey Senozhatsky
<sergey.senozhatsky.work@xxxxxxxxx> wrote:
> On (05/11/18 11:38), Tetsuo Handa wrote:
>> >
>> > So you basically want to have one more con_msg_format_flags? Do
>> > you want to track a context which prints out a messages or the
>> > context which "generated" the message? A CPU/task that stores
>> > a logbuf entry - vprintk_emit() - is not always the same as the
>> > CPU/task that prints it to consoles - console_unlock().
>> >
>>
>> Well, below is the (partial) patch.
>
> Hi,
>
> Tetsuo, I will take a look a bit later, but at glance, there are several
> ways to achieve what you are trying to do. The first one is the way you
> did it - add additional buffer and make that context tracking info part of
> the message body. Another one would be to extend struct printk_log and add
> pid/cpu/flag there, which you then can convert into text in msg_print_text().
> So far we talked about extending printk_log. Yet another one could be - add
> vsprintf specifiers that would add pid/cpu/flag to the vsprintf-ed message.
> You then can re-define pr_fmt, for instance, in the code you want to track
> pr_fmt "%zZ" fmt, or somehow force printk to add that "%zZ" to every
> message.


For syzbot perspective, yes, we can set any necessary additional
configs, add cmdline arguments, etc.

Manually changing format strings won't work -- bugs are all over the place.

>From what I see, it seems that interrupts can be nested:

https://syzkaller.appspot.com/bug?id=72eddef9cedcf81486adb9dd3e789f0d77505ba5
https://syzkaller.appspot.com/bug?id=66fcf61c65f8aa50bbb862eb2fde27c08909a4ff

Will this in_nmi()/in_irq()/in_serving_softirq()/else be enough to
untangle output printed by such nested interrupts? For the first link
it seems that they both are the same type of interrupt --
apic_timer_interrupt.