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

[Dmitry Vyukov <dvyukov@google.com>]

On Wed, Jun 20, 2018 at 2:41 PM, Fengguang Wu <fengguang.wu@intel.com> wrote:
> On Wed, Jun 20, 2018 at 02:31:51PM +0200, Dmitry Vyukov wrote:
>>
>> On Wed, Jun 20, 2018 at 1:37 PM, Fengguang Wu <fengguang.wu@intel.com>
>> wrote:
>>>
>>> On Wed, Jun 20, 2018 at 11:30:05AM +0200, Dmitry Vyukov wrote:
>>>>
>>>>
>>>> On Wed, Jun 20, 2018 at 11:06 AM, Sergey Senozhatsky
>>>> <sergey.senozhatsky.work@gmail.com> 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.
>>>
>>>
>>>
>>> +1 for 0day kernel testing.
>>>
>>> I admit that goal may never be 100% achievable -- at least some serial
>>> console logs can sometimes become messy. So we'll have to write dmesg
>>> parsing code in defensive ways.
>>>
>>> But some unnecessary pr_cont() broken-up messages can obviously be
>>> avoided. For example,
>>>
>>> arch/x86/mm/fault.c:
>>>
>>>         printk(KERN_ALERT "BUG: unable to handle kernel ");
>>>         if (address < PAGE_SIZE)
>>>                 printk(KERN_CONT "NULL pointer dereference");
>>>         else
>>>                 printk(KERN_CONT "paging request");
>>>
>>> I've actually proposed to remove the above KERN_CONT, unfortunately the
>>> patch was silently ignored.
>>
>>
>>
>> I've just cooked this change too, but do you mind reviving your patch?
>
>
> Yes, sure. My version is more dumb. Since I'm not sure if it's OK to
> do string formatting at this critical point. Let's see how others
> think about the 2 approaches. I'm fine as long as our problem is fixed. :)

It already does string formatting for address. And I think we also
need to get rid of KERN_CONT for address while we are here.


> diff --git a/arch/x86/mm/fault.c b/arch/x86/mm/fault.c
> index 9a84a0d08727..c7b068c6b010 100644
> --- a/arch/x86/mm/fault.c
> +++ b/arch/x86/mm/fault.c
> @@ -671,11 +671,10 @@ show_fault_oops(struct pt_regs *regs, unsigned long
> error_code,
>                        printk(smep_warning, from_kuid(&init_user_ns,
> current_uid()));
>        }
>
> -       printk(KERN_ALERT "BUG: unable to handle kernel ");
>        if (address < PAGE_SIZE)
> -               printk(KERN_CONT "NULL pointer dereference");
> +               printk(KERN_ALERT "BUG: unable to handle kernel NULL pointer
> dereference");
>        else
> -               printk(KERN_CONT "paging request");
> +               printk(KERN_ALERT "BUG: unable to handle kernel paging
> request");
>
>
>        printk(KERN_CONT " at %px\n", (void *) address);
>
>> It actually makes the code even shorter, which is nice:
>>
>> --- a/arch/x86/mm/fault.c
>> +++ b/arch/x86/mm/fault.c
>> @@ -671,13 +671,9 @@ show_fault_oops(struct pt_regs *regs, unsigned
>> long error_code,
>>                        printk(smep_warning, from_kuid(&init_user_ns,
>> current_uid()));
>>        }
>>
>> -       printk(KERN_ALERT "BUG: unable to handle kernel ");
>> -       if (address < PAGE_SIZE)
>> -               printk(KERN_CONT "NULL pointer dereference");
>> -       else
>> -               printk(KERN_CONT "paging request");
>> -
>> -       printk(KERN_CONT " at %px\n", (void *) address);
>> +       printk(KERN_ALERT "BUG: unable to handle kernel %s at %px\n",
>> +               (address < PAGE_SIZE ? "NULL pointer dereference" :
>> +               "paging request"), (void *) address);
>>
>>        dump_pagetable(address);
>> }
>>
>