Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
From:   John Ogness <john.ogness@linutronix.de>
To:     "J. Avila" <elavila@google.com>
Cc:     Peter Zijlstra <peterz@infradead.org>,
        Petr Mladek <pmladek@suse.com>,
        Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>,
        Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
        Steven Rostedt <rostedt@goodmis.org>,
        Linus Torvalds <torvalds@linux-foundation.org>,
        Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
        Andrea Parri <parri.andrea@gmail.com>,
        Thomas Gleixner <tglx@linutronix.de>,
        Paul McKenney <paulmck@kernel.org>,
        Saravana Kannan <saravanak@google.com>,
        kexec@lists.infradead.org, linux-kernel@vger.kernel.org
Subject: Re: Issue in dmesg time with lockless ring buffer
In-Reply-To: <20210122235238.655049-1-elavila@google.com>
References: <20210122235238.655049-1-elavila@google.com>
Date:   Mon, 25 Jan 2021 14:38:20 +0106
Message-ID: <87im7l2lcr.fsf@jogness.linutronix.de>
MIME-Version: 1.0
Content-Type: text/plain
Precedence: bulk

On 2021-01-22, "J. Avila" <elavila@google.com> wrote:
> When doing some internal testing on a 5.10.4 kernel, we found that the
> time taken for dmesg seemed to increase from the order of milliseconds
> to the order of seconds when the dmesg size approached the ~1.2MB
> limit. After doing some digging, we found that by reverting all of the
> patches in printk/ up to and including
> 896fbe20b4e2333fb55cc9b9b783ebcc49eee7c7 ("use the lockless
> ringbuffer"), we were able to once more see normal dmesg times.
>
> This kernel had no meaningful diffs in the printk/ dir when compared
> to Linus' tree. This behavior was consistently reproducible using the
> following steps:
>
> 1) In one shell, run "time dmesg > /dev/null"
> 2) In another, constantly write to /dev/kmsg
>
> Within ~5 minutes, we saw that dmesg times increased to 1 second, only
> increasing further from there. Is this a known issue?

The last couple days I have tried to reproduce this issue with no
success.

Is your dmesg using /dev/kmsg or syslog() to read the buffer?

Are there any syslog daemons or systemd running? Perhaps you can run
your test within an initrd to see if this effect is still visible?

John Ogness