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: <20200213115957.GC36551@google.com>
Date:   Thu, 13 Feb 2020 20:59:57 +0900
From:   Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>
To:     John Ogness <john.ogness@...utronix.de>
Cc:     Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
        Petr Mladek <pmladek@...e.com>,
        Peter Zijlstra <peterz@...radead.org>,
        Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        Steven Rostedt <rostedt@...dmis.org>,
        Linus Torvalds <torvalds@...ux-foundation.org>,
        Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
        Andrea Parri <parri.andrea@...il.com>,
        Thomas Gleixner <tglx@...utronix.de>,
        kexec@...ts.infradead.org, linux-kernel@...r.kernel.org
Subject: Re: [PATCH 2/2] printk: use the lockless ringbuffer

On (20/02/13 10:42), John Ogness wrote:
> On 2020-02-13, Sergey Senozhatsky <sergey.senozhatsky.work@...il.com> wrote:
> >> -	while (user->seq == log_next_seq) {
> >> +	if (!prb_read_valid(prb, user->seq, r)) {
> >>  		if (file->f_flags & O_NONBLOCK) {
> >>  			ret = -EAGAIN;
> >>  			logbuf_unlock_irq();
> >> @@ -890,30 +758,26 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
> >>  
> >>  		logbuf_unlock_irq();
> >>  		ret = wait_event_interruptible(log_wait,
> >> -					       user->seq != log_next_seq);
> >> +					prb_read_valid(prb, user->seq, r));
> >>  		if (ret)
> >>  			goto out;
> >>  		logbuf_lock_irq();
> >>  	}
> >>  
> >> -	if (user->seq < log_first_seq) {
> >> -		/* our last seen message is gone, return error and reset */
> >> -		user->idx = log_first_idx;
> >> -		user->seq = log_first_seq;
> >> +	if (user->seq < r->info->seq) {
> >> +		/* the expected message is gone, return error and reset */
> >> +		user->seq = r->info->seq;
> >>  		ret = -EPIPE;
> >>  		logbuf_unlock_irq();
> >>  		goto out;
> >>  	}
> >
> > Sorry, why doesn't this do something like
> >
> > 	if (user->seq < prb_first_seq(prb)) {
> > 		/* the expected message is gone, return error and reset */
> > 		user->seq = prb_first_seq(prb);
> > 		ret = -EPIPE;
> > 		...
> > 	}
> 
> Here prb_read_valid() was successful, so a record _was_ read. The
> kerneldoc for the prb_read_valid() says:

Hmm, yeah. That's true.

OK, something weird...

I ran some random printk-pressure test (mostly printks from IRQs;
+ some NMI printk-s, but they are routed through nmi printk-safe
buffers; + some limited number of printk-safe printk-s, routed
via printk-safe buffer (so, once again, IRQ); + user-space
journalctl -f syslog reader), and after the test 'cat /dev/kmsg'
is terminally broken

[..]
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
cat /dev/kmsg
cat: /dev/kmsg: Broken pipe
[..]

dmesg works. Reading from /dev/kmsg - doesn't; it did work, however,
before the test.

So I printed seq numbers from devksmg read to a seq buffer and dumped
it via procfs, just seq numbers before we adjust user->seq (set to
r->seq) and after

+                       offt += snprintf(BUF + offt,
+                                       sizeof(BUF) - offt,
+                                       "%s: devkmsg_read() error %llu %llu %llu\n",
+                                       current->comm,
+                                       user->seq,
+                                       r->info->seq,
+                                       prb_first_seq(prb));


...
systemd-journal: devkmsg_read() error 1979235 1979236 1979236
systemd-journal: corrected seq 1979236 1979236
systemd-journal: devkmsg_read() error 1979237 1979243 1979243
systemd-journal: corrected seq 1979243 1979243
systemd-journal: devkmsg_read() error 1979244 1979250 1979250
systemd-journal: corrected seq 1979250 1979250
systemd-journal: devkmsg_read() error 1979251 1979257 1979257
systemd-journal: corrected seq 1979257 1979257
systemd-journal: devkmsg_read() error 1979258 1979265 1979265
systemd-journal: corrected seq 1979265 1979265
systemd-journal: devkmsg_read() error 1979266 1979272 1979272
systemd-journal: corrected seq 1979272 1979272
systemd-journal: devkmsg_read() error 1979272 1979273 1979273
systemd-journal: corrected seq 1979273 1979273
systemd-journal: devkmsg_read() error 1979274 1979280 1979280
systemd-journal: corrected seq 1979280 1979280
systemd-journal: devkmsg_read() error 1979281 1982465 1980933
systemd-journal: corrected seq 1982465 1982465
cat: devkmsg_read() error 1980987 1982531 1980987
cat: corrected seq 1982531 1982531
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981015 1982563 1981015
cat: corrected seq 1982563 1982563
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981080 1982633 1981080
cat: corrected seq 1982633 1982633
cat: devkmsg_read() error 1981095 1982652 1981095
cat: corrected seq 1982652 1982652
cat: devkmsg_read() error 1981095 1982652 1981095
cat: corrected seq 1982652 1982652
cat: devkmsg_read() error 1981095 1982652 1981095
cat: corrected seq 1982652 1982652
cat: devkmsg_read() error 1981095 1982652 1981095
cat: corrected seq 1982652 1982652
cat: devkmsg_read() error 1981095 1982652 1981095
cat: corrected seq 1982652 1982652
cat: devkmsg_read() error 1981095 1982652 1981095
cat: corrected seq 1982652 1982652
cat: devkmsg_read() error 1981095 1982652 1981095
cat: corrected seq 1982652 1982652
...


What's up with that user->seq counter?

	-ss

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ