Re: [PATCH 1/4] printk: Introduce per-console loglevel setting

2019-03-20 Thread Petr Mladek
On Thu 2019-03-14 23:12:49, Tetsuo Handa wrote:
> Petr Mladek wrote:
> > It might be even more straightforward when the per-console value
> > defines the effective console level. I mean the following semantic:
> > 
> >+ "console_loglevel" would define the default loglevel used
> >  by consoles at runtime.
> > 
> >+ the per-console loglevel could override the default
> >  console_loglevel.
> > 
> >+ We would need a custom handler for the sysctl "console_loglevel".
> >  It would write the given value to the global console_loglevel
> >  variable and for all already registered consoles (con->loglevel).
> 
> But some functions change console_loglevel without sysctl (e.g.
> console_verbose() when reporting hung tasks and panic()). Should
> con->loglevel be changed (which might result in too much messages to
> slow consoles) when console_loglevel changes?

It is about the semantic. We either want to set a hard limit
for each console or we want to set per-console loglevel that
will get used in normal situations.

I prefer the 2nd semantic. IMHO, console_verbose() should be
used only in situations when people really want to see all
lines, for example, panic, sysrq output when the machine
looks deadlocked, ignore_loglevel is set. I believe that they
want to see them even on the slow consoles that are
there exactly for debugging these critical situations.

Best Regards,
Petr


Re: [PATCH 1/4] printk: Introduce per-console loglevel setting

2019-03-14 Thread Tetsuo Handa
Petr Mladek wrote:
> It might be even more straightforward when the per-console value
> defines the effective console level. I mean the following semantic:
> 
>+ "console_loglevel" would define the default loglevel used
>  by consoles at runtime.
> 
>+ the per-console loglevel could override the default
>  console_loglevel.
> 
>+ We would need a custom handler for the sysctl "console_loglevel".
>  It would write the given value to the global console_loglevel
>  variable and for all already registered consoles (con->loglevel).

But some functions change console_loglevel without sysctl (e.g.
console_verbose() when reporting hung tasks and panic()). Should
con->loglevel be changed (which might result in too much messages to
slow consoles) when console_loglevel changes?

> 
>  The value will be used also for all newly registered consoles
>  when they do not have any custom one.
> 
> 
>+ The handler for "loglevel" early param should behave the same
>  as the sysctl handler.
> 
> 
> IMHO, there is no perfect solution. The advantage of the above
> proposal is that you "see" and "use" exactly what you "set".


Re: [PATCH 1/4] printk: Introduce per-console loglevel setting

2019-03-12 Thread Calvin Owens
On Friday 03/08 at 12:10 +0900, Sergey Senozhatsky wrote:
> On (03/01/19 16:48), Calvin Owens wrote:
> [..]
> > msg = log_from_idx(console_idx);
> > -   if (suppress_message_printing(msg->level)) {
> > -   /*
> > -* Skip record we have buffered and already printed
> > -* directly to the console when we received it, and
> > -* record that has level above the console loglevel.
> > -*/
> > -   console_idx = log_next(console_idx);
> > -   console_seq++;
> > -   goto skip;
> > -   }
> >  
> > /* Output to all consoles once old messages replayed. */
> > if (unlikely(exclusive_console &&
> > @@ -2405,7 +2402,7 @@ void console_unlock(void)
> > console_lock_spinning_enable();
> >  
> > stop_critical_timings();/* don't trace print latency */
> > -   call_console_drivers(ext_text, ext_len, text, len);
> > +   call_console_drivers(ext_text, ext_len, text, len, msg->level);
> > start_critical_timings();
> 
> So it seems that now we always format the text and ext message (if
> needed) and only then check if there is at least one console we can
> print that message on.
> 
> Can we iterate the consoles first and check if msg is worth
> the effort (per console suppress_message_printing()) and only
> if it is do all the formatting and call console drivers?

Makes sense, will do.

Thanks,
Calvin
 
>   -ss


Re: [PATCH 1/4] printk: Introduce per-console loglevel setting

2019-03-08 Thread Petr Mladek
On Fri 2019-03-01 16:48:17, Calvin Owens wrote:
> Not all consoles are created equal: depending on the actual hardware,
> the latency of a printk() call can vary dramatically. The worst examples
> are serial consoles, where it can spin for tens of milliseconds banging
> the UART to emit a message, which can cause application-level problems
> when the kernel spews onto the console.
> 
> At Facebook we use netconsole to monitor our fleet, but we still have
> serial consoles attached on each host for live debugging, and the latter
> has caused problems. An obvious solution is to disable the kernel
> console output to ttyS0, but this makes live debugging frustrating,
> since crashes become silent and opaque to the ttyS0 user. Enabling it on
> the fly when needed isn't feasible, since boxes you need to debug via
> serial are likely to be borked in ways that make this impossible.

I guess that many other people have similar problem.


> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index d3d170374ceb..6ead14f8c2bc 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1164,9 +1164,14 @@ module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
>  MODULE_PARM_DESC(ignore_loglevel,
>"ignore loglevel setting (prints all kernel messages to the 
> console)");
>  
> -static bool suppress_message_printing(int level)
> +static int effective_loglevel(struct console *con)
>  {
> - return (level >= console_loglevel && !ignore_loglevel);
> + return max(console_loglevel, con ? con->level : LOGLEVEL_EMERG);
> +}
> +
> +static bool suppress_message_printing(int level, struct console *con)
> +{
> + return (level >= effective_loglevel(con) && !ignore_loglevel);

Hmm, the semantic is cleaner when the per-console level defines
the minimal loglevel. But it is still complicated. Also it is
very confusing that the per-console value is called "level"
or "loglevel" but it is actually minimal loglevel.

It might be even more straightforward when the per-console value
defines the effective console level. I mean the following semantic:

   + "console_loglevel" would define the default loglevel used
 by consoles at runtime.

   + the per-console loglevel could override the default
 console_loglevel.

   + We would need a custom handler for the sysctl "console_loglevel".
 It would write the given value to the global console_loglevel
 variable and for all already registered consoles (con->loglevel).

 The value will be used also for all newly registered consoles
 when they do not have any custom one.


   + The handler for "loglevel" early param should behave the same
 as the sysctl handler.


IMHO, there is no perfect solution. The advantage of the above
proposal is that you "see" and "use" exactly what you "set".


>  }
>  
>  #ifdef CONFIG_BOOT_PRINTK_DELAY
> @@ -1198,7 +1203,7 @@ static void boot_delay_msec(int level)
>   unsigned long timeout;
>  
>   if ((boot_delay == 0 || system_state >= SYSTEM_RUNNING)
> - || suppress_message_printing(level)) {
> + || suppress_message_printing(level, NULL)) {

We should delay the message only when it will really reach the
console. The same check might be used also for formatting
the text as pointed out by Sergey in the other mail.

If the above proposal was accepted, we would have custom
handlers for sysctl. Then we could easily maintain a global
variable with maximal effective console loglevel.

Best Regards,
Petr


Re: [PATCH 1/4] printk: Introduce per-console loglevel setting

2019-03-07 Thread Sergey Senozhatsky
On (03/01/19 16:48), Calvin Owens wrote:
[..]
>   msg = log_from_idx(console_idx);
> - if (suppress_message_printing(msg->level)) {
> - /*
> -  * Skip record we have buffered and already printed
> -  * directly to the console when we received it, and
> -  * record that has level above the console loglevel.
> -  */
> - console_idx = log_next(console_idx);
> - console_seq++;
> - goto skip;
> - }
>  
>   /* Output to all consoles once old messages replayed. */
>   if (unlikely(exclusive_console &&
> @@ -2405,7 +2402,7 @@ void console_unlock(void)
>   console_lock_spinning_enable();
>  
>   stop_critical_timings();/* don't trace print latency */
> - call_console_drivers(ext_text, ext_len, text, len);
> + call_console_drivers(ext_text, ext_len, text, len, msg->level);
>   start_critical_timings();

So it seems that now we always format the text and ext message (if
needed) and only then check if there is at least one console we can
print that message on.

Can we iterate the consoles first and check if msg is worth
the effort (per console suppress_message_printing()) and only
if it is do all the formatting and call console drivers?

-ss