Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Date:   Wed, 20 Jun 2018 20:48:18 +0800
From:   Fengguang Wu <fengguang.wu@intel.com>
To:     Dmitry Vyukov <dvyukov@google.com>
Cc:     Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>,
        Petr Mladek <pmladek@suse.com>,
        Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>,
        Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
        syzkaller <syzkaller@googlegroups.com>,
        Steven Rostedt <rostedt@goodmis.org>,
        LKML <linux-kernel@vger.kernel.org>,
        Linus Torvalds <torvalds@linux-foundation.org>,
        Andrew Morton <akpm@linux-foundation.org>
Subject: Re: [PATCH] printk: inject caller information into the body of
 message
Message-ID: <20180620124818.4bnkp3i7q2wuwx4y@wfg-t540p.sh.intel.com>
References: <CACT4Y+brbqfBWntjVaj-Ri2WhBdXpkA_PYs59qgLZ0vtepZEtw@mail.gmail.com>
 <CACT4Y+ZGSefrYL9xtQs=yPMRNFsOUumuJXsShJPhCOBSLySxuw@mail.gmail.com>
 <20180620083126.GA477@jagdpanzerIV>
 <CACT4Y+YMubTm1xduj+XCbQnNwQxYFLjBT33cFKisN1HyeaBpZw@mail.gmail.com>
 <20180620090413.GA444@jagdpanzerIV>
 <CACT4Y+a6nUqdpSyYGGcXKAgVbcw+uQOz2kYx8tUS+8T5-bzqkg@mail.gmail.com>
 <20180620113731.y7apmqoh6ke6ar2v@wfg-t540p.sh.intel.com>
 <CACT4Y+bw5j9aTRVFKHNO-YH0vXtuOvB4ez4wg6C=1GpSbvfSAQ@mail.gmail.com>
 <20180620124157.gd5245o63dq6teul@wfg-t540p.sh.intel.com>
 <CACT4Y+b0XGxnJtvB2T3hZHm_UvT7Mk6zT35ODWBtdtQK7KZ=JA@mail.gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii; format=flowed
Content-Disposition: inline
In-Reply-To: <CACT4Y+b0XGxnJtvB2T3hZHm_UvT7Mk6zT35ODWBtdtQK7KZ=JA@mail.gmail.com>
User-Agent: NeoMutt/20170609 (1.8.3)
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Wed, Jun 20, 2018 at 02:45:25PM +0200, Dmitry Vyukov wrote:
>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.

Ah yes, sorry I overlooked the next KERN_CONT..

>
>> 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);
>>> }
>>>
>>
>