[Solved] Not so randomly missing warnings, due to ratelimit

[Tout]

Since the start of this month, I have been migrating my dear desktop to Gentoo. I must say, I really like Gentoo so far! It is clean and I feel I am in control mostly So that is nice, since I like being in control in this regard.

So in my quest for perfection, Gentoo is pushing me to new levels. And that made me aware of a message in the log, I have not noticed before:

Code: Select all

[    4.114611] random: 7 urandom warning(s) missed due to ratelimiting

This is a message telling me (and please tell me if I misunderstand the situation), that there were 7 warnings suppressed due to ratelimiting.

Ratelimiting makes sure the system does not register too many warnings in a certain period. (?)

I would really like to know what 7 warnings I missed. So I searched around places a bit and tried some actions to find out. So far I have:

Emerged haveged, and put the daemon in the default runlevel, and later in the sysinit runlevel to get it up earlier
From what I understand, this helps expanding the entropy pool.

Emerged rng-tools and put the daemon in the sysinit level. This should change the way random numbers are put into the pool.

Boot the kernel with the printk.devkmsg=on

So you might already have guessed, these attempts did not bring me closer to solving this. The messages related to random, I find in dmesg, are:

Code: Select all

[    0.000000] random: get_random_bytes called from start_kernel+0x30e/0x4d9 with crng_init=0
[    0.809766] random: fast init done
[    3.934726] random: udevd: uninitialized urandom read (16 bytes read)
[    3.934835] random: udevd: uninitialized urandom read (16 bytes read)
[    3.934856] random: udevd: uninitialized urandom read (16 bytes read)
[    4.114610] random: crng init done
[    4.114611] random: 7 urandom warning(s) missed due to ratelimiting

These messages I think mean the following:

Start kernel calls it
Initial fast init had been done
Udev asks for random number, but urandom was not initialized to be read (3x)
crng init was finished <-- I guess this is where random is ready
And then after it's ready it notifies me that there were 7 warnings missed

Could you help me understanding this?

[Ionen]

As far as I'm aware skipped messages are typically only for repeated messages, so you've missed 7 lines of the same message you already seen 3 times.

Also, the messages probably happened before the init was finished, as this is a late summary made from buffered messages.

[Tout]

Aha, that sounds logical. So you think the message:

random: udevd: uninitialized urandom read (16 bytes read)

Has been thrown 7 more times?

Yes, I am also quite sure it is a summary after it happened.

edit: I tried to find examples of this behaviour of suppressing repeating warnings, and could not find any. So not proven yet. If I look at the code, which is actually quite fun to do, I notice the following:

Some snippets from the description of random.c:
https://elixir.bootlin.com/linux/v5.4.4 ... r/random.c

* Computers are very predictable devices. Hence it is extremely hard
* to produce truly random numbers on a computer

So instead, we must try to
* gather "environmental noise" from the computer's environment, which
* must be hard for outside attackers to observe, and use that to
* generate random numbers.

Randomness from these sources are
* added to an "entropy pool"

* When random bytes are desired, they are obtained by taking the SHA
* hash of the contents of the "entropy pool"

* The userspace interfaces are two character devices /dev/random and
* /dev/urandom.

/dev/random is suitable for use when very high
* quality randomness is desired ..., as it will only return a maximum of the number of
* bits of randomness

* The /dev/urandom device does not have this limit, and will return
* as many bytes as are requested.

Then in the code I see the following happening:

First it creates a ratelimit state, called urandom_warning:

ratelimit_state urandom_warning =

Code: Select all

RATELIMIT_STATE_INIT("warn_urandom_randomness", HZ, 3);

Then after some time is checks if there are missed warnings, and throws the message:

Code: Select all

		if (urandom_warning.missed) {
			pr_notice("random: %d urandom warning(s) missed "
				  "due to ratelimiting\n",
				  urandom_warning.missed);
			urandom_warning.missed = 0;
		}

While looking how a warning is thrown I noticed this code:

Code: Select all

	static int maxwarn = 10;
	int ret;

	if (!crng_ready() && maxwarn > 0) {
		maxwarn--;
		if (__ratelimit(&urandom_warning))
			printk(KERN_NOTICE "random: %s: uninitialized "
			       "urandom read (%zd bytes read)\n",
			       current->comm, nbytes);

So I guess this is where at __ratelimit(&urandom_warning), the magic is happening
https://elixir.bootlin.com/linux/v5.4.4 ... imit.c#L27

That function, I think (?), is called from ratelimit.c. That is stating the following:

Code: Select all

	/*
	 * If we contend on this state's lock then almost
	 * by definition we are too busy to print a message,
	 * in addition to the one that will be printed by
	 * the entity that is holding the lock already:
	 */

And setting missed:

Code: Select all

rs->missed++;

Question that remains: how can I see the missed warnings? Could you, the one reading this , help me answer this?


Copyright notice on random.c in kernel 5.4.48: (I think I have to include this here )


* Copyright (C) 2017 Jason A. Donenfeld <Jason@zx2c4.com>. All
* Rights Reserved.
*
* Copyright Matt Mackall <mpm@selenic.com>, 2003, 2004, 2005
*
* Copyright Theodore Ts'o, 1994, 1995, 1996, 1997, 1998, 1999. All
* rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
* are met:
* 1. Redistributions of source code must retain the above copyright
* notice, and the entire permission notice in its entirety,
* including the disclaimer of warranties.
* 2. Redistributions in binary form must reproduce the above copyright
* notice, this list of conditions and the following disclaimer in the
* documentation and/or other materials provided with the distribution.
* 3. The name of the author may not be used to endorse or promote
* products derived from this software without specific prior
* written permission.
*
* ALTERNATIVELY, this product may be distributed under the terms of
* the GNU General Public License, in which case the provisions of the GPL are
* required INSTEAD OF the above restrictions. (This clause is
* necessary due to a potential bad interaction between the GPL and
* the restrictions contained in a BSD-style copyright.)
*
* THIS SOFTWARE IS PROVIDED ``AS IS'' AND ANY EXPRESS OR IMPLIED
* WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
* OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE, ALL OF
* WHICH ARE HEREBY DISCLAIMED. IN NO EVENT SHALL THE AUTHOR BE
* LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
* CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT
* OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR
* BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
* LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE
* USE OF THIS SOFTWARE, EVEN IF NOT ADVISED OF THE POSSIBILITY OF SUCH
* DAMAGE.

[Tout]

Because I think it was save to do, after understanding the RATELIMIT_STATE_INIT macro, I decided to alter the random.c code, replacing:

Code: Select all

RATELIMIT_STATE_INIT("warn_urandom_randomness", HZ, 3);

with:

Code: Select all

RATELIMIT_STATE_INIT("warn_urandom_randomness", HZ, 10);

Compiled the kernel, booted, and indeed the missed warnings were gone And 10 instead of 3 warnings from udevd

Code: Select all

[    4.018346] random: udevd: uninitialized urandom read (16 bytes read)
[    4.018393] random: udevd: uninitialized urandom read (16 bytes read)
[    4.018401] random: udevd: uninitialized urandom read (16 bytes read)
[    4.018409] random: udevd: uninitialized urandom read (16 bytes read)
[    4.018422] random: udevd: uninitialized urandom read (16 bytes read)
[    4.018445] random: udevd: uninitialized urandom read (16 bytes read)
[    4.045218] random: udevd: uninitialized urandom read (16 bytes read)
[    4.045237] random: udevd: uninitialized urandom read (16 bytes read)
[    4.045262] random: udevd: uninitialized urandom read (16 bytes read)
[    4.045303] random: udevd: uninitialized urandom read (16 bytes read)

I'm still not sure if it skips unitialized reads from one process, or if it would skip them from all processes after reaching the rate limit. Ideas are welcome.

Next I will try to understand why udevd is having this uninitialized reads. edit: it is because it starts before crng is ready.

[halcon]

Next I will try to understand why udevd is having this uninitialized reads. edit: it is because it starts before crng is ready.

I digged into this a little a while ago, and I can say it's not that simple to fix it. The most helpful resources that I found about the matter, are:
That comment in Bugzilla
That topic in forum
Slackware initrd patches

If in short,

• if the boot process continues, it does not harm much, but, ideally, of course, it should be fixed anyway;
  OpenRC has no tools to wait until crng is initialized by kernel;
  userspace daemons (like haveged), which helped me with other services (like syslog-ng), didn't help me with udevd (and lvm either) because it is launching very early and I couldn't make udevd start after haveged with standard OpenRC's "after";
  CONFIG_RANDOM_TRUST_CPU is dangerous after all the CPU exploits from the last few years;
  CONFIG_CRYPTO_JITTERENTROPY=y, as is, did not help either, may be because I had to install the corresponding userspace program along with it but I haven't yet tried it;
  other options that I had not yet time to try are CONFIG_GCC_PLUGIN_LATENT_ENTROPY (may be it will help) and, as a last resort, Slackware initrd patches .

[Tout]

Wow, your search skills are good Thanks for posting these links. Did not encounter them myself I read through them, and will dive into it more when I have the time to do so. Will update here. From what I've understood now, I might try to do the patches, if I have and find the courage to do so

For LVM, that was the start of this quest. I use btrfs and and not LVM. Noticed the LVM warnings at boot and via a question I posted on LQ, found the answer in LVM being pulled in as a dependency. Not a very logical one as I remember. Was not able to loose it as a dependency, so ended up removing the initrd scripts regarding LVM

Post at LQ, which I enjoyed a lot :

https://www.linuxquestions.org/question ... 175679023/

edit: as for the LVM2 dependencies:

sys-fs/lvm2-2.02.187-r2 pulled in by:
sys-fs/cryptsetup-2.3.2 requires sys-fs/lvm2

sys-fs/cryptsetup-2.3.2 pulled in by:
sys-libs/libblockdev-2.24

Libblock dev has the LVM use flag, but that (-lvm) does not remove the dependency of cryptsetup... Maybe after this, I will look into that one

[halcon]

I might try to do the patches, if I have and find the courage to do so

If/when you do, please write back about the result, I'm interested.

[Tout]

Setting CONFIG_GCC_PLUGIN_LATENT_ENTROPY to */Y in the kernel didn't work for me, so now we know that

[halcon]

Setting CONFIG_GCC_PLUGIN_LATENT_ENTROPY to */Y in the kernel didn't work for me, so now we know that

Well, there is only one way left

[Tout]

The Slackware patch route is a bit too much for me. Diving into it, there are two things that are stopping me: the need to compile a non Gentoo package (twuewand). And also in a way the Slackware patch route persons found necessary to adjust for the patch route. Second block was that the patches are for older versions of mkinit and haveged. I guess it will take too much effort, which I better put into something else. So for now I will leave this path unfortunately... Maybe later

[halcon]

I guess it will take too much effort, which I better put into something else. So for now I will leave this path unfortunately... Maybe later

OK. There are things for each of us that would take too much effort, comparing the expected benefits and time spent...

As for me, I'm interested in the matter because, first, I have always built my initrd automatically with genkernel and never even looked into it, and, second, the mentioned idea of transferring Haveged's entropy to the kernel does not look difficult to me: as far as I understand it, all that rndaddentropy tool does, is taking entropy from stdin and seeding it to /dev/random (49, 55 and 58 lines):

Code: Select all

if((randfd = open("/dev/random", O_WRONLY)) < 0) {
...
while((count = fread(entropy.buf, 1, sizeof(entropy.buf), stdin)) > 0) {
...
if(ioctl(randfd, RNDADDENTROPY, &entropy) < 0) {

Yes, twuewand is not neither in Gentoo tree nor in overlays, but there is no need in the whole twuewand package, rndaddentropy tool does not look complicated - less than 100 lines, I also found another similar tool with a similar code: rngseed. May be, there is still something in Gentoo tree that can do this work.

The difficulty is that I (almost) haven't learned C and low-level operations, like this, and don't know which pitfalls / security risks could be there...

At least, after reading your last message, I unpacked my genkernel's initrd with xz (had to rename <filename>.img to <filename>.xz before it), then cpio and looked into it Looked at init shell script where the Slackware's command

Code: Select all

/sbin/haveged -F -n 512 -f - | /sbin/rndaddentropy

would have to be inserted...

If/when I am ready for the following steps, probably, makes sense to create a new topic for discussing the details? Not sure.

EDIT:
Looks like I found a tool that can do this work in Gentoo: rng-tools (it is mentioned in rngseed's README: "can do what this utility does and much more").

[Tout]

Hmmm, sounds like you have things a bit more clear indeed. A new topic might get more people into the specific topic of getting random numbers available early in the boot process. That also might attract some people with knowledge about C and security related matters. If you do decide to continue, would you please leave a link here, so people following this topic and people who reach this at a later point in time, can continue there?

[halcon]

If you do decide to continue, would you please leave a link here, so people following this topic and people who reach this at a later point in time, can continue there?

Sure that I will post the link if I decide to create a new topic! I think it will make sense only if nobody more experienced reply here... Still there are chances.

[halcon]

If you do decide to continue, would you please leave a link here, so people following this topic and people who reach this at a later point in time, can continue there?

Sure that I will post the link if I decide to create a new topic! I think it will make sense only if nobody more experienced reply here... Still there are chances.

Well... I don't see the reason to create a new topic because I, in general, resolved the problem.

Step-by-step, what I did:

1. Read this and this. The first source recommends to use the command cat /dev/hwrng | rngtest -c 1000, the second source recommends to use the same command but also rngd --rng-device=/dev/hwrng before it.

2. As I have always used genkernel for creating initramfs for my (custom! not genkernel-generated) kernel, so:

Code: Select all

cp /usr/src/linux/.config /usr/share/genkernel/arch/x86_64/kernel-config
genkernel ramdisk

, I read man genkernel and found options --initramfs-overlay and --linuxrc.

3. Installed sys-apps/rng-tools, added it to boot runlevel.

4. Found binaries which it installs:

Code: Select all

# equery f rng-tools | grep bin/
/usr/bin/randstat
/usr/bin/rngtest
/usr/sbin/rngd
#

5. Found major and minor numbers of /dev/hwrng:

Code: Select all

# file /dev/hwrng 
/dev/hwrng: character special (10/183)
#

6. Unpacked my current initramfs:

Code: Select all

# cd <some working folder>/genkernel
# cp /boot/initramfs-5.9.6-gentoo-v50.img ./

<from here: operations were done with a shell script for unpacking genkernel/dracut initramfs that I wrote, I'm typing commands looking at the script output generated with 'set -x', so I may miss something>

# mv initramfs-5.9.6-gentoo-v50.img initramfs-5.9.6-gentoo-v50.xz
# xz -dk initramfs-5.9.6-gentoo-v50.xz
# mv initramfs-5.9.6-gentoo-v50.xz initramfs-5.9.6-gentoo-v50.img
# mkdir unpacked
# cd unpacked
# cpio --extract --make-directories --format=newc --no-absolute-filenames --verbose <../initramfs-5.9.6-gentoo-v50
# cd ..
# rm initramfs-5.9.6-gentoo-v50

<to here: operations were done with a shell script for unpacking genkernel/dracut initramfs that I wrote, I'm typing commands looking at the script output generated with 'set -x', so I may miss something>

7. Renamed the folder "unpacked" to "unpacked-orig" and repeated the procedure of unpacking (to "unpacked").

8. Copied rngd binaries:

Code: Select all

# cp /usr/bin/randstat ./unpacked/usr/bin/
# cp /usr/bin/rngtest ./unpacked/usr/bin/
# cp /usr/sbin/rngd ./unpacked/usr/sbin/

9. Edited the file ./unpacked/init:

Code: Select all

# diff -u unpacked-orig/init unpacked/init
--- unpacked-orig/init	2020-12-04 02:15:56.936675589 +0300
+++ unpacked/init	2020-12-04 17:27:18.839399572 +0300
@@ -19,6 +19,7 @@
 [ ! -e /dev/ttyS1 ]    && mknod /dev/ttyS1 c 4 65
 [ ! -e /dev/urandom ]  && mknod /dev/urandom c 1 9
 [ ! -e /dev/zero ]     && mknod /dev/zero c 1 5
+[ ! -e /dev/hwrng ]    && mknod /dev/hwrng c 10 183
 
 # Take control
 exec >${CONSOLE} <${CONSOLE} 2>&1
@@ -569,6 +570,14 @@
 # Run debug shell if requested
 rundebugshell "before starting udevd"
 
+sleep 10
+run rngd --rng-device=/dev/hwrng \
+		|| bad_msg 'Failed to run rngd!'
+sleep 10
+run cat /dev/random | rngtest -c 1000 \
+		|| bad_msg 'Failed to run rngtest!'
+sleep 10
+
 # Initialize udev
 if [ ! -f "/etc/udev/hwdb.bin" ]
 then

10. Created the new initramfs using the added rng binaries and the changes to init (the file "linuxrc" is a symlink to the file "init"):

Code: Select all

# genkernel ramdisk --initramfs-overlay=./unpacked --initramfs-filename=custom-initramfs.img --linuxrc=./unpacked/linuxrc 
* Gentoo Linux Genkernel; Version 4.1.2
* Using genkernel configuration from '/etc/genkernel.conf' ...
* Running with options: ramdisk --initramfs-overlay=./unpacked --initramfs-filename=custom-initramfs.img --linuxrc=./unpacked/linuxrc

* Working with Linux kernel 5.9.6-gentoo-v50 for x86_64
* Using kernel config file '/usr/share/genkernel/arch/x86_64/generated-config' ...

* Current kernel's LOCALVERSION is set to '-v50'; Will ignore set --kernel-localversion value '-x86_64' because kernel was not build ...

* initramfs: >> Initializing ...
*         >> Appending devices cpio data ...
*         >> Appending base_layout cpio data ...
*         >> Appending util-linux cpio data ...
*         >> Appending eudev cpio data ...
*         >> Appending devicemanager cpio data ...
*         >> Appending auxilary cpio data ...
*         >> Appending busybox cpio data ...
*         >> Appending modprobed cpio data ...
*         >> Appending modules cpio data ...
*         >> Appending overlay cpio data ...
*         >> Appending linker cpio data ...
*         >> Deduping cpio ...
*         >> Pre-generating initramfs' /etc/ld.so.cache ...
*         >> Compressing cpio data (.xz) ...
* 
* You will find the initramfs in '/boot/custom-initramfs.img'.

* WARNING... WARNING... WARNING...
* Additional kernel parameters that *may* be required to boot properly:

* Do NOT report kernel bugs as genkernel bugs unless your bug
* is about the default genkernel configuration...
* 
* Make sure you have the latest ~arch genkernel before reporting bugs.
#

11. Checked that the new initramfs was created (with ls -al /boot).

12. Edited and saved GRUB2 configuration.

13. Rebooted, chose custom-initramfs.img in the GRUB2 menu.

14. Made photos of the initramfs output (as it is neither in dmesg, nor in rc.log). Typing from photos:

Code: Select all

rngd: error while loading shared libraries: libsysfs.so.2: cannot open shared object file: No such file or directory
!! Failed to run rngd!
rngtest 6.10
Copyright (c) 2004 by Henrique de Moraes Holschuh
This is free software<...>

rngtest: starting FIPS test...
rngtest: bits received from input: 20000032

<and then other messages of a successful rngtest run>

15. Looked at dmesg... The "problem" messages are gone!

before

Code: Select all

[    5.394752] uname (284) used greatest stack depth: 8 bytes left
[    5.743359] udevd[1755]: starting version 3.2.9
[    5.743622] random: udevd: uninitialized urandom read (16 bytes read)
[    5.743662] random: udevd: uninitialized urandom read (16 bytes read)
[    5.743674] random: udevd: uninitialized urandom read (16 bytes read)
[    5.744697] udevd[1756]: starting eudev-3.2.9

after

Code: Select all

[    5.396203] uname (284) used greatest stack depth: 8 bytes left
[   27.084081] random: crng init done
[   37.200581] udevd[1777]: starting version 3.2.9
[   37.201836] udevd[1778]: starting eudev-3.2.9

So, I can conclude that, even with rngd failed launch, calling cat /dev/random | rngtest -c 1000 was enough for creating the early entropy.

(edited for fixing a typo in the last line)

[halcon]

Some more notes:

to #8
Launching rngd requires (`lddtree` for checking)

Code: Select all

cp /lib64/libsysfs.so.2 ./unpacked/lib64
cp /usr/lib/libcrypto.so.1.1 ./unpacked/usr/lib
cp /usr/lib64/libcrypto.so* ./unpacked/usr/lib64/
cp /lib64/libpthread.so.0 ./unpacked/lib64/
cp /lib64/libdl.so.2 ./unpacked/lib64/
cp /lib64/libz.so.1 ./unpacked/lib64/

and also /etc/conf.d/rngd can be helpful.

And haveged dependencies are just

Code: Select all

cp /usr/lib64/libhavege.so.1 ./unpacked/usr/lib64/

to #9
init patch for haveged:

Code: Select all

--- unpacked-orig/init  2020-12-04 02:15:56.936675589 +0300
+++ unpacked/init     2020-12-05 12:09:24.714678629 +0300
@@ -569,6 +569,13 @@
 # Run debug shell if requested
 rundebugshell "before starting udevd"
 
+run haveged -r 0\
+               || bad_msg 'Failed to run haveged!'
+run rngtest -c 1000 < /dev/random \
+               || true
+good_msg '/dev/random tested; killing haveged (not to prevent it to start via OpenRC)...'
+killall haveged
+
 # Initialize udev
 if [ ! -f "/etc/udev/hwdb.bin" ]
 then

Testing `sleep`s should be removed for rngd as well, and killall, for starting a service, should be added as well.
Every `sleep` itself helps to accumulate the early entropy.
rngtest seems to exit always(?) with 1, so || true.

to #12
A hint how to make GRUB2 recognize non-standard initramfs filenames:
making /etc/grub.d/10_linux non-executable and using /etc/grub.d/40_custom