linux-kernel - Re: [PATCH] printk/console: Do not suppress information about dropped messages

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20190227025559.GA18340@jagdpanzerIV>
Date:   Wed, 27 Feb 2019 11:55:59 +0900
From:   Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
To:     John Ogness <john.ogness@...utronix.de>
Cc:     Petr Mladek <pmladek@...e.com>,
        Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        Steven Rostedt <rostedt@...dmis.org>,
        Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
        linux-kernel@...r.kernel.org
Subject: Re: [PATCH] printk/console: Do not suppress information about
 dropped messages

On (02/26/19 17:26), John Ogness wrote:
[..]
> >  		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.

I think this is exactly the problem (and thus the patch) we discussed some
3 years ago. I had a number of rather strangely looking serial logs, which
clearly had lost messages but no "%llu printk messages dropped" markers. So
I added `static bool lost_messages' to console_unlock(), set it when printing
loop would discover lost messages, then print "%llu printk messages dropped"
attached to whatever msg was next in the logbuf, regardless of msg->level.
IOW, if lost_messages was set then suppress_message_printing(msg->level)
was not even invoked. Yes, that would sometimes print several "debugging
noise" messages, but the main part was that I would have "%llu printk
messages dropped" markers in the logs; which was much more important to
me.

P.S. I'm very sorry, I'm overloaded with work at the moment; will start
     looking at pending patches in a day or two, or three, or four...

	-ss