linux-kernel - Re: A Comparison of printk between upstream and linux-rt-devel

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 for Android: free password hash cracker in your pocket

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

Message-ID: <20240823070908.D0GYffCS@linutronix.de>
Date: Fri, 23 Aug 2024 09:09:08 +0200
From: Sebastian Andrzej Siewior <bigeasy@...utronix.de>
To: Derek Barbosa <debarbos@...hat.com>
Cc: pmaldek@...e.com, williams@...hat.com, john.ogness@...utronix.de,
	tglx@...utronix.de, linux-rt-users@...r.kernel.org,
	linux-kernel@...r.kernel.org
Subject: Re: A Comparison of printk between upstream and linux-rt-devel

On 2024-08-22 12:32:15 [-0400], Derek Barbosa wrote:
> Hi,
Hi,

> TLDR: plain, vanilla 6.11.0-0.rc3 is slower on flush and 
> does not print traces in panic/crash context consistently.

Thank you for testing.

> For the stock kernel, we observed an average of about 14,263 messages printed
> within 30 seconds. The standard deviation here hovers at around 1.52 messages,
> with a variance of 2.3 messages.
> 
> For the "new printk" kernel, we observed an average of about 12,693 messages
> printed within 30 seconds. The standard devation here hovers at about 131.2  
> messages, with a variance of 17211 messages. 
> 
> We observe a rough 12-13 percent overall delta between new printk and the
> stock kernel in this test case, with a larger disparity in standard
> deviation/variance.

I am a bit confused. You write here ~14k messages within 30secs for
"stock" aka 6.11.0-0.rc3 and then ~12k messages for "new printk" aka
from the latest RT tree. At the top you write "6.11.0-0.rc3 is slower on
flush". This means something else I guess.

Regarding your RCU stall: You stuff a _lot_ into the printk buffer. And
then printk is forced print everything out in a single sitting. The
whole printing job is done within a preempt_disable region so RCU has to
wait until it is done. If printing of the whole buffer takes >60sec then
you see your RCU stall.
The current RT tree will do the printing from a kthread which remains
preemptible because your printing threads don't print any errors/ panics
for 30seconds. So RCU gets its turn.

Sebastian