lkml.org 
[lkml]   [2020]   [Feb]   [13]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [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@gmail.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

    \
     
     \ /
      Last update: 2020-02-13 13:01    [W:7.396 / U:0.028 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site