On Tue 2019-02-26 17:26:57, John Ogness wrote:
> On 2019-02-26, Petr Mladek <pmla...@suse.com> wrote:
> > The warning about dropped messages gets lost when the current
> > message is above console_loglevel and suppressed.
>
> Here you are reporting a bug. (More on this below.)
Yes.
> > The suppressed messages allow even slow consoles to caught up
> > with a flood of messages. The consoles must not get slowed
> > down by many warnings. Instead, the warning is delayed until
> > the next printable message.
>
> Here you are introducing a new behavior. (Also discussed below.)
> Although the two are similar, they are really 2 different things.
No, I am replacing random behavior with a predictable one to fix
the bug. The above paragraph explains why the fix looks like it looks.
Maybe I should have written somethink like:
A solution would be to print the warning regardless the log level.
But it might cause loosing more important messages because of
delay caused by the warnings.
A better solution is to count all dropped messages until there
is a non-suppressed one. Then we could print the summary
together with the message.
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index b4d26388bc62..c3f287422ef4 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -2398,20 +2400,24 @@ void console_unlock(void)
> > for (;;) {
> > struct printk_log *msg;
> > size_t ext_len = 0;
> > - size_t len;
> > + size_t len = 0;
> >
> > printk_safe_enter_irqsave(flags);
> > raw_spin_lock(&logbuf_lock);
> > +
> > + /* Reset dropped msg count when switching to all consoles. */
> > + if (unlikely(exclusive_console &&
> > + exclusive_console_stop_seq < log_first_seq)) {
> > + console_dropped_cnt = 0;
> > + console_seq = exclusive_console_stop_seq;
> > + }
> > +
>
> Wouldn't the fix to the bug be to move the "skip" target here?
No, the entire loop skiping suppressed messages is done under
the logbuf_lock. No old messages can be lost inside this loop.
> skip:
>
> > if (console_seq < log_first_seq) {
> > - len = sprintf(text,
> > - "** %llu printk messages dropped **\n",
> > - log_first_seq - console_seq);
> > + console_dropped_cnt += log_first_seq - console_seq;
> >
> > /* messages are gone, move to first one */
> > console_seq = log_first_seq;
> > console_idx = log_first_idx;
> > - } else {
> > - len = 0;
> > }
> > skip:
> > if (console_seq == log_next_seq)
> > @@ -2435,6 +2441,13 @@ void console_unlock(void)
> > exclusive_console = NULL;
> > }
> >
> > + if (unlikely(console_dropped_cnt)) {
> > + len = sprintf(text,
> > + "** %llu printk messages dropped **\n",
> > + console_dropped_cnt);
> > + console_dropped_cnt = 0;
> > + }
> > +
>
> My only objection to this is that the "messages dropped" only comes if a
> non-supressed message comes. So information about dropped information
> may never get printed unless some task prints something non-supressed.
>
> Imagine a situation where I am expecting a message to come, but don't
> see it because it was dropped. But if no more non-supressed messages
> come, I see neither the expected message nor the dropped message.
Good point! There is a simple fix for this. We could print the warning
also when all messages are proceed and we are about to leave
the for-cycle.
Best Regards,
Petr
