Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:18 as permitted sender) client-ip=2620:137:e000::1:18;
Message-ID: <7fc5853e-dbe6-c2d2-2130-003e3b9777bc@gmx.de>
Date:   Thu, 7 Apr 2022 21:36:04 +0200
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101
 Thunderbird/91.7.0
Subject: Re: [PATCH printk v2 09/12] printk: add functions to prefer direct
 printing
Content-Language: en-US
To:     John Ogness <john.ogness@linutronix.de>,
        Petr Mladek <pmladek@suse.com>
Cc:     Sergey Senozhatsky <senozhatsky@chromium.org>,
        Steven Rostedt <rostedt@goodmis.org>,
        Thomas Gleixner <tglx@linutronix.de>,
        linux-kernel@vger.kernel.org,
        Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
        Jiri Slaby <jirislaby@kernel.org>,
        "Paul E. McKenney" <paulmck@kernel.org>,
        Frederic Weisbecker <frederic@kernel.org>,
        Neeraj Upadhyay <quic_neeraju@quicinc.com>,
        Josh Triplett <josh@joshtriplett.org>,
        Mathieu Desnoyers <mathieu.desnoyers@efficios.com>,
        Lai Jiangshan <jiangshanlai@gmail.com>,
        Joel Fernandes <joel@joelfernandes.org>,
        Kees Cook <keescook@chromium.org>,
        Andrew Morton <akpm@linux-foundation.org>,
        Luis Chamberlain <mcgrof@kernel.org>,
        Wei Liu <wei.liu@kernel.org>,
        Xiaoming Ni <nixiaoming@huawei.com>,
        Peter Zijlstra <peterz@infradead.org>,
        Andy Shevchenko <andriy.shevchenko@linux.intel.com>,
        Marco Elver <elver@google.com>,
        Sebastian Andrzej Siewior <bigeasy@linutronix.de>,
        Daniel Lezcano <daniel.lezcano@linaro.org>,
        Shawn Guo <shawn.guo@linaro.org>,
        Dmitry Torokhov <dmitry.torokhov@gmail.com>,
        Matti Vaittinen <matti.vaittinen@fi.rohmeurope.com>,
        "Eric W. Biederman" <ebiederm@xmission.com>,
        Phil Auld <pauld@redhat.com>,
        Juri Lelli <juri.lelli@redhat.com>,
        Wang Qing <wangqing@vivo.com>, rcu@vger.kernel.org
References: <20220405132535.649171-1-john.ogness@linutronix.de>
 <20220405132535.649171-10-john.ogness@linutronix.de> <Yk61Q+w7tWTjh8xl@alley>
 <b746d99e-729f-ca0d-5d30-6d803d1cd833@gmx.de>
 <87zgkxnepg.fsf@jogness.linutronix.de>
From:   Helge Deller <deller@gmx.de>
In-Reply-To: <87zgkxnepg.fsf@jogness.linutronix.de>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: quoted-printable
Precedence: bulk

Hi John,

On 4/7/22 16:35, John Ogness wrote:
> On 2022-04-07, Helge Deller <deller@gmx.de> wrote:
>>>>  - emergency reboot/shutdown
>>>>  - cpu and rcu stalls
>>>>  - hard and soft lockups
>>>>  - hung tasks
>>>>  - warn
>>>>  - sysrq
>>
>> I agree that those needs direct printing.
>> Did you maybe checked how much (e.g. in percentage) of a normal log is
>> then still left to be printed threadened?  Just in case it's not much,
>> is there still a benefit to introduce threadened printing?
>
> A "normal" log can still contain many many messages. There have been
> reports [0] where the system died because _printk_ killed it. This was
> not any of the scenarios that we want direct printing for. It was just a
> lot of messages that some driver wanted to output.
>
> Until now the response was always to reduce printk usage or avoid it
> altogether. printk has a bad reputation because it is so unpredictable
> and expensive. So we are fixing printk. With threaded printers, we make
> a dramatic change. printk becomes 100% lockless and consistently quite
> fast. You can use it to debug or log messages within any code in the
> kernel and not need to worry about horrible latencies being introduced.
>
> For drivers that start dumping tons of messages, there is no concern
> that the system will die because of the messages.

Thank you for this good explanation!

In my case - while I debug low-level kernel code - I then just need to use
pr_warn() or pr_emerg() and get it printed non-threadened. That's sufficie=
nt for me.

>> Or another example, e.g. when running on a slow console (the best
>> testcase I know of is a 9600 baud serial port), where some printks are
>> threadened. Then a warn printk() has to be shown, doesn't it mean all
>> threadened printks have to be flushed (waited for) until the warning
>> can be shown. Will there then still be a measureable time benefit?
>
> Now you are talking about something else, unrelated to the threaded
> printing. A warn is considered a serious non-normal event. In this case,
> printk temporarily falls back to the direct, slow, unpredictable,
> printk-caller-context behavior we know today.

Good.

> If we see that direct printing is being used during normal operation
> (i.e. developers are performing warns just for fun), then we should not
> mark warns for direct printing. We will need to get some real-world
> experience here, but the goal is that systems do not use direct printing
> unless a real serious emergency is going on. Otherwise, the system risks
> dying because of the messages rather than the problem being reported.

I agree, it's good if this gets fixed at some point.

Thanks!
Helge

> John
>
> [0] https://lore.kernel.org/all/20190306171943.12345598@oasis.local.home