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 19:37:31 +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: <20180620113731.y7apmqoh6ke6ar2v@wfg-t540p.sh.intel.com>
References: <201805112058.AAB05258.HJQFFOMFOVtOSL@I-love.SAKURA.ne.jp>
 <20180517112135.GB20796@jagdpanzerIV>
 <20180518121506.wilixxkznbtskw34@pathway.suse.cz>
 <20180524021451.GA23443@jagdpanzerIV>
 <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>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii; format=flowed
Content-Disposition: inline
In-Reply-To: <CACT4Y+a6nUqdpSyYGGcXKAgVbcw+uQOz2kYx8tUS+8T5-bzqkg@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 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.

>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.

We met exactly the same issue and ended up with special handling in
https://github.com/intel/lkp-tests/blob/master/lib/dmesg.rb:

       /(BUG: unable to handle kernel)/,
       /(BUG: unable to handle kernel) NULL pointer dereference/,
       /(BUG: unable to handle kernel) paging request/,

>So I am leaning towards to getting rid of pr_cont's as the solution to
>the problem.

+1 for reducing unnecessary pr_cont() uses.

Thanks,
Fengguang