Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

/proc/sys/kernel/random/boot_id stays the same #4517

Closed
solsticedhiver opened this issue Aug 9, 2021 · 36 comments
Closed

/proc/sys/kernel/random/boot_id stays the same #4517

solsticedhiver opened this issue Aug 9, 2021 · 36 comments

Comments

@solsticedhiver
Copy link

solsticedhiver commented Aug 9, 2021

On 2 rpi0s (armv6h) running archlinuxarm (no RTC clock), since I upgraded to 5.10.52-6 kernel, the boot_id stays the same.

journalctl --list-boot list a different id for current boot though:

alarm@pi01:~$ cat /proc/sys/kernel/random/boot_id 
afddd092-21cf-4330-a670-037b9c7bbc65
alarm@pi01:~$ journalctl --list-boot
-13 afddd09221cf4330a670037b9c7bbc65 Wed 2021-07-28 03:09:13 CEST—Wed 2021-07-28 04:08:57 CEST
-12 6099256b298b4856bf7915578bd1475e Fri 2021-07-30 17:36:39 CEST—Fri 2021-07-30 18:58:40 CEST
-11 e5005cf743d449c0b237a30d87054fd6 Fri 2021-07-30 19:50:55 CEST—Fri 2021-07-30 20:32:10 CEST
-10 ea34a50300e84c0ab6a4ce9dd6466410 Sat 2021-07-31 18:54:48 CEST—Sat 2021-07-31 19:22:08 CEST
 -9 0bfc13814e074461acb3ef3855a6bcdc Sat 2021-07-31 19:29:34 CEST—Sat 2021-07-31 19:43:12 CEST
 -8 8ccea420067f43d09fbfbe788c2f7e93 Sat 2021-07-31 21:43:03 CEST—Sat 2021-07-31 22:52:38 CEST
 -7 22958d0a45f74b01bc93f625ed4562d0 Sun 2021-08-01 18:30:05 CEST—Sun 2021-08-01 18:43:55 CEST
 -6 345b1a6b5f0444728787003c3031bcd8 Sun 2021-08-01 21:01:49 CEST—Sun 2021-08-01 21:05:59 CEST
 -5 6324de467a0049bc878f55c55efa9d89 Mon 2021-08-02 18:08:28 CEST—Mon 2021-08-02 18:22:09 CEST
 -4 7b9e1a367bc24cbfb3be148d3f0b6ba0 Tue 2021-08-03 17:57:05 CEST—Tue 2021-08-03 18:10:42 CEST
 -3 d7115721186343ea8ec2b124203c24d8 Wed 2021-08-04 15:03:15 CEST—Wed 2021-08-04 15:54:30 CEST
 -2 0280323eeff4473780a87aca368f611f Wed 2021-08-04 15:56:54 CEST—Wed 2021-08-04 16:10:08 CEST
 -1 d299d18e65c1451c82fd6319d78faad4 Wed 2021-08-04 19:24:30 CEST—Wed 2021-08-04 20:44:56 CEST
  0 64671c173b5e4bb180f92e548340ba42 Thu 2021-08-05 16:28:19 CEST—Thu 2021-08-05 16:42:00 CEST
$ /opt/vc/bin/vcgencmd version
Aug  5 2021 13:49:33 
Copyright (c) 2012 Broadcom
version fc9eef11715b244b59c2da056d5aa540fc31255f (clean) (release) (start)

alarm@pi02:~$ cat /proc/sys/kernel/random/boot_id 
e333b40f-15b5-462e-8ec1-c772f4a02993
alarm@pi02:~$ journalctl --list-boot
 -1 e333b40f15b5462e8ec1c772f4a02993 Sun 2021-08-08 21:20:17 CEST—Mon 2021-08-09 13:55:20 CEST
  0 d6b33eec667a45c9a83ef5161f36a65f Mon 2021-08-09 13:55:21 CEST—Mon 2021-08-09 14:02:04 CEST
~$ /opt/vc/bin/vcgencmd version
Aug  5 2021 13:50:26 
Copyright (c) 2012 Broadcom
version fc9eef11715b244b59c2da056d5aa540fc31255f (clean) (release) (start_x)

@popcornmix
Copy link
Collaborator

Can you report output of vcgencmd version

@popcornmix
Copy link
Collaborator

It changes for me on a Pi3:

pi@pi3:~ $ cat /proc/sys/kernel/random/boot_id 
4aec9cbe-2d7e-4220-b92a-9cd41e917c28
[reboot]
pi@pi3:~ $ cat /proc/sys/kernel/random/boot_id 
e0e992bd-d9e1-4b18-aae5-2d0d2491441b
pi@pi3:~ $ uname -a
Linux pi3 5.10.52-v7+ #1441 SMP Tue Aug 3 18:10:09 BST 2021 armv7l GNU/Linux
pi@pi3:~ $ vcgencmd version
Aug  3 2021 18:17:07 
Copyright (c) 2012 Broadcom
version 40787ee5905644f639a2a0f6e00ae12e517a2211 (clean) (release) (start)

@solsticedhiver
Copy link
Author

solsticedhiver commented Aug 9, 2021

Yes. It's ok on rpi3. But it reports the same version as the rpi0s

I have edited my post above

@solsticedhiver
Copy link
Author

I confirm that downgrading the kernel to 5.10.52-4 makes it work back again.

Maybe that is an archlinux packaging issue because the version of the kernel is the same
I see one notable change that is the use of RANDOM_TRUST_BOOTLOADER=y. Couldn't this be a problem ?

@popcornmix
Copy link
Collaborator

I see one notable change that is the use of RANDOM_TRUST_BOOTLOADER=y. Couldn't this be a problem ?

I suspect reverting that would fix the issue. But the question is why is that isn't working on Pi0 but is on Pi3?
Perhaps a device tree issue. See raspberrypi/firmware#1595 for context on why that setting was added.

@solsticedhiver
Copy link
Author

I am not an archlinux packager.

@pelwell
Copy link
Contributor

pelwell commented Aug 18, 2021

It's working for me on a Zero W (which runs the same kernel as the Zero, B+, etc.):

pi@raspberrypi:~$ cat /proc/sys/kernel/random/boot_id
06b4b03d-8c02-4b45-a469-a3f821574195
pi@raspberrypi:~$ journalctl --list-boot
 0 06b4b03d8c024b45a469a3f821574195 Wed 2021-08-18 15:56:16 BST—Wed 2021-08-18 1
pi@raspberrypi:~$ sudo reboot
...
pi@raspberrypi:~$ cat /proc/sys/kernel/random/boot_id
228c99de-32c7-4f7d-a596-de0e93916fd4
pi@raspberrypi:~$ journalctl --list-boot
 0 228c99de32c74f7da596de0e93916fd4 Wed 2021-08-18 15:58:16 BST—Wed 2021-08-18 1

@solsticedhiver
Copy link
Author

I don't see any difference on a rpi0 W. Still the same problem.

@pelwell
Copy link
Contributor

pelwell commented Aug 18, 2021

It would help if you could show examples (boot_id and the journalctl output) from a system producing the identical values - those in your first post are different.

@solsticedhiver
Copy link
Author

solsticedhiver commented Aug 18, 2021

root@rpi0w:~# cat /proc/sys/kernel/random/boot_id 
f7979de0-6e38-4421-96d4-3295af874e14
root@rpi0w:~# journalctl --list-boot
 -9 5109888f0c2e4a9aa272db636b910123 Sat 2021-06-26 14:07:36 CEST—Tue 2021-07-13 15:42:28 CEST
 -8 aa77b5b9b9f640a2b46723bdf519fa7f Tue 2021-07-13 15:42:29 CEST—Mon 2021-07-19 14:53:02 CEST
 -7 026b8cda32f248058ca99ef99725b8d0 Mon 2021-07-19 14:53:03 CEST—Thu 2021-07-22 20:08:44 CEST
 -6 691f8a98ec084ad692fd5909352edf37 Thu 2021-07-22 20:08:44 CEST—Fri 2021-07-23 11:22:44 CEST
 -5 0c2613e1a2eb4c8c8455c81c3f34ce67 Fri 2021-07-23 11:22:44 CEST—Thu 2021-07-29 12:33:23 CEST
 -4 690aeb569a4e4847870df0bddfe8db08 Thu 2021-07-29 12:33:24 CEST—Tue 2021-08-03 14:34:53 CEST
 -3 49afef35f0724fbfa1853a48c4eba714 Tue 2021-08-03 14:34:54 CEST—Fri 2021-08-06 00:00:30 CEST
 -2 cbd4929e7b2b44eaa9b698d460e62ffe Fri 2021-08-06 00:04:07 CEST—Sat 2021-08-07 11:20:31 CEST
 -1 e333b40f15b5462e8ec1c772f4a02993 Sun 2021-08-08 21:20:17 CEST—Mon 2021-08-09 13:55:20 CEST
  0 d6b33eec667a45c9a83ef5161f36a65f Mon 2021-08-09 13:55:21 CEST—Mon 2021-08-09 14:02:04 CEST
root@rpi0w:~# date -Is
2021-08-18T23:31:56+02:00
root@rpi0w:~# reboot


root@rpi0w:~# cat /proc/sys/kernel/random/boot_id 
f7979de0-6e38-4421-96d4-3295af874e14
root@rpi0w:~# journalctl --list-boot|tail
 -9 5109888f0c2e4a9aa272db636b910123 Sat 2021-06-26 14:07:36 CEST—Tue 2021-07-13 15:42:28 CEST
 -8 aa77b5b9b9f640a2b46723bdf519fa7f Tue 2021-07-13 15:42:29 CEST—Mon 2021-07-19 14:53:02 CEST
 -7 026b8cda32f248058ca99ef99725b8d0 Mon 2021-07-19 14:53:03 CEST—Thu 2021-07-22 20:08:44 CEST
 -6 691f8a98ec084ad692fd5909352edf37 Thu 2021-07-22 20:08:44 CEST—Fri 2021-07-23 11:22:44 CEST
 -5 0c2613e1a2eb4c8c8455c81c3f34ce67 Fri 2021-07-23 11:22:44 CEST—Thu 2021-07-29 12:33:23 CEST
 -4 690aeb569a4e4847870df0bddfe8db08 Thu 2021-07-29 12:33:24 CEST—Tue 2021-08-03 14:34:53 CEST
 -3 49afef35f0724fbfa1853a48c4eba714 Tue 2021-08-03 14:34:54 CEST—Fri 2021-08-06 00:00:30 CEST
 -2 cbd4929e7b2b44eaa9b698d460e62ffe Fri 2021-08-06 00:04:07 CEST—Sat 2021-08-07 11:20:31 CEST
 -1 e333b40f15b5462e8ec1c772f4a02993 Sun 2021-08-08 21:20:17 CEST—Mon 2021-08-09 13:55:20 CEST
  0 d6b33eec667a45c9a83ef5161f36a65f Mon 2021-08-09 13:55:21 CEST—Mon 2021-08-09 14:02:04 CEST
root@rpi0w:~# date -Is
2021-08-18T23:42:15+02:00


root@rpi0w:~# cat /proc/sys/kernel/random/boot_id 
f7979de0-6e38-4421-96d4-3295af874e14
root@rpi0w:~# journalctl --list-boot|tail
 -9 5109888f0c2e4a9aa272db636b910123 Sat 2021-06-26 14:07:36 CEST—Tue 2021-07-13 15:42:28 CEST
 -8 aa77b5b9b9f640a2b46723bdf519fa7f Tue 2021-07-13 15:42:29 CEST—Mon 2021-07-19 14:53:02 CEST
 -7 026b8cda32f248058ca99ef99725b8d0 Mon 2021-07-19 14:53:03 CEST—Thu 2021-07-22 20:08:44 CEST
 -6 691f8a98ec084ad692fd5909352edf37 Thu 2021-07-22 20:08:44 CEST—Fri 2021-07-23 11:22:44 CEST
 -5 0c2613e1a2eb4c8c8455c81c3f34ce67 Fri 2021-07-23 11:22:44 CEST—Thu 2021-07-29 12:33:23 CEST
 -4 690aeb569a4e4847870df0bddfe8db08 Thu 2021-07-29 12:33:24 CEST—Tue 2021-08-03 14:34:53 CEST
 -3 49afef35f0724fbfa1853a48c4eba714 Tue 2021-08-03 14:34:54 CEST—Fri 2021-08-06 00:00:30 CEST
 -2 cbd4929e7b2b44eaa9b698d460e62ffe Fri 2021-08-06 00:04:07 CEST—Sat 2021-08-07 11:20:31 CEST
 -1 e333b40f15b5462e8ec1c772f4a02993 Sun 2021-08-08 21:20:17 CEST—Mon 2021-08-09 13:55:20 CEST
  0 d6b33eec667a45c9a83ef5161f36a65f Mon 2021-08-09 13:55:21 CEST—Mon 2021-08-09 14:02:04 CEST
root@rpi0w:~# date -Is
2021-08-18T23:44:15+02:00

on this rpi0 W, even journalctl does not list the current boot_id. It is even weirder. I don't know what is the boot_id there. I am confused. The boot does not seem to be registered. Or may be a wrong time

And for the rpi0 W, there are 2 boot_id..One for a cold boot, one for a reboot. but they stay the same.

@pelwell
Copy link
Contributor

pelwell commented Aug 19, 2021

Do you have a spare SD card you could install RPiOS onto? Even a Lite version would be enough. Once installed, see if boot_id changes on each boot, then run rpi-update to get the very latest kernel, reboot and check boot_id again.

@pelwell
Copy link
Contributor

pelwell commented Aug 19, 2021

Could you also confirm that, on your Arch Linux image, od -Ax -tx1 /proc/device-tree/chosen/kaslr-seed changes at each boot?

@pelwell
Copy link
Contributor

pelwell commented Aug 19, 2021

And one more - does /proc/sys/kernel/random/uuid change every time it is called? uuid and boot_id are generated by exactly the same function (proc_do_uuid) using the kernel random number generator, the only difference being that the boot_id value is cached the first time it is read. If you find that uuid is changing, try reading uuid before boot_id, and vice versa.

Looking at the implementation, one thing that would break the boot_id functionality is if the static 16-byte buffer intended to store the result was not being zeroed at boot time, Another cause might be some element of the OS reading boot_id before the random number generator has woken up, but I'm not sure that's even possible. Adding a small amount of debug logging to proc_do_uuid in drivers/char/random.c would provide answers to both questions.

@graysky2 Is this something you have come across?

@solsticedhiver
Copy link
Author

/proc/sys/kernel/random/uuid is changing every time it is called.
od -Ax -tx1 /proc/device-tree/chosen/kaslr-seed is changing too at each boot
I am compiling at the request of @graysky2 a kernel without RANDOM_TRUST_BOOTLOADER=y to check this the issue

@solsticedhiver
Copy link
Author

solsticedhiver commented Aug 19, 2021

It seems fine with RPiOs Lite and latest 5.10.59+ kernel. But I don't know how to check if the option is enabled or not.

Edit: so yes, that option is set in the kernel config.
So another mystery is why this is fine on RpiOs and not archlinuxarm

@popcornmix
Copy link
Collaborator

On rpios run:

sudo modprobe configs
zcat /proc/config.gz | grep  RANDOM_TRUST_BOOTLOADER

@pelwell
Copy link
Contributor

pelwell commented Aug 19, 2021

I'm just going through the effects of adding that flag, to see if it might be causing problems.

@solsticedhiver
Copy link
Author

So with a kernel compiled with RANDOM_TRUST_BOOTLOADER=n on archlinuxarm (5.10.59), this is working fine. Tested on rpi0 W.

But with the option set to yes (default archlinux arm package), this does not work; the boot_id stays the same (one for a cold boot, one for a reboot).

@pelwell
Copy link
Contributor

pelwell commented Aug 19, 2021

Can you try with this patch?:

diff --git a/drivers/char/random.c b/drivers/char/random.c
index 340ad21491e28..e7befd59bcc47 100644
--- a/drivers/char/random.c
+++ b/drivers/char/random.c
@@ -2070,8 +2070,15 @@ static int proc_do_uuid(struct ctl_table *table, int write,
                static DEFINE_SPINLOCK(bootid_spinlock);
 
                spin_lock(&bootid_spinlock);
-               if (!uuid[8])
+               pr_err("%s: uuid %02x%02x%02x%02x-%02x%02x-%02x%02x-%02x...",
+                      __func__, uuid[0], uuid[1], uuid[2], uuid[3],
+                      uuid[4], uuid[5], uuid[6], uuid[7], uuid[8]);
+               if (!uuid[8]) {
                        generate_random_uuid(uuid);
+                       pr_err("%s:   -> %02x%02x%02x%02x-%02x%02x-%02x%02x-%02x...",
+                              __func__, uuid[0], uuid[1], uuid[2], uuid[3],
+                              uuid[4], uuid[5], uuid[6], uuid[7], uuid[8]);
+               }
                spin_unlock(&bootid_spinlock);
        }

I'd like to confirm that the static storage is initially zero, and at what point in the boot sequence the boot_id is queried.

@graysky2
Copy link

@graysky2 Is this something you have come across?

If expectation is identical hash, yes. I do not have armv7h or armv6h devices. The "yes" is for arm64 RPi4.

@pelwell
Copy link
Contributor

pelwell commented Aug 19, 2021

Are you saying that on arm64 you get identical boot_ids between boots?

@graysky2
Copy link

Are you saying that on arm64 you get identical boot_ids between boots?

Yes, sorry. the output of the cat command matched the hash in the journal. Reboot, same.

@solsticedhiver
Copy link
Author

I have attached a chopped boot log (grepped on ' random:') Tell me if you want the complete log.

What I can see is that when the error happens the line proc_do_uuid: uuid 00000000-0000-0000-00... appears twice
But I let you debug that, and think about what it means

The normal boot log, is a kernel compiled with your patch, but with the option unset.
The strange boot log, is the one with the patch and the option set,where the error occurs.

normal-boot-log-random.log
strange-boot-log-random.log

@graysky2
Copy link

To be clear, is the expected behavior that /proc/sys/kernel/random/boot_id matches the hash for the boot (shown in journalctl --list-boot) and we expect that hash to change upon reboot (yet still be in sync between the two)?

If so, then I can confirm the expected behavior on RPi4 running armv7h as well as aarch64. Output for clarity:

% cat /proc/sys/kernel/random/boot_id
54bfccb8-01ba-4ee1-a65f-d07dec3b04a5

% journalctl --list-boot
...
 0 54bfccb801ba4ee1a65fd07dec3b04a5 Thu 2021-08-19 08:48:42 EDT—Fri 2021-08-20 05:12:51 EDT

# reboot

% cat /proc/sys/kernel/random/boot_id
5958801c-6d71-473c-9943-19308c2c437d

% journalctl --list-boot
...
 0 5958801c6d71473c994319308c2c437d Fri 2021-08-20 05:22:10 EDT—Fri 2021-08-20 05:22:52 EDT

@pelwell
Copy link
Contributor

pelwell commented Aug 20, 2021

Yes - exactly that. And that is the behaviour I observe.

@solsticedhiver Your strange log is peculiar. Are the uuids in the kernel log the same as that found in boot_id? And are they also unchanged after a reboot?

@solsticedhiver
Copy link
Author

Yes the uuids in the log do match the one in boot_id:

# cat /proc/sys/kernel/random/boot_id 
c52f762d-5977-4b1c-95de-6f0edd68910d
# journalctl -o verbose -b|egrep '^[ ]+_BOOT_ID' |tail -n 1|cut -d"=" -f 2
c52f762d59774b1c95de6f0edd68910d
# # journalctl -b `sed 's/-//g' /proc/sys/kernel/random/boot_id ` --no-hostname -o short-iso|grep ' random:'|uniq
2021-08-08T21:20:17+0200 kernel: random: fast init done
2021-08-08T21:20:17+0200 kernel: random: get_random_bytes called from start_kernel+0x33c/0x58c with crng_init=1
2021-08-08T21:20:17+0200 kernel: random: fast init done
2021-08-08T21:20:17+0200 kernel: random: get_random_bytes called from start_kernel+0x33c/0x58c with crng_init=1
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
[...]

# reboot

# cat /proc/sys/kernel/random/boot_id 
c52f762d-5977-4b1c-95de-6f0edd68910d
# journalctl -o verbose -b|egrep '^[ ]+_BOOT_ID' |tail -n 1|cut -d"=" -f 2
c52f762d59774b1c95de6f0edd68910d
# journalctl -b `sed 's/-//g' /proc/sys/kernel/random/boot_id ` --no-hostname -o short-iso|grep ' random:'|uniq
2021-08-08T21:20:17+0200 kernel: random: fast init done
2021-08-08T21:20:17+0200 kernel: random: get_random_bytes called from start_kernel+0x33c/0x58c with crng_init=1
2021-08-08T21:20:17+0200 kernel: random: fast init done
2021-08-08T21:20:17+0200 kernel: random: get_random_bytes called from start_kernel+0x33c/0x58c with crng_init=1
2021-08-08T21:20:17+0200 kernel: random: fast init done
2021-08-08T21:20:17+0200 kernel: random: get_random_bytes called from start_kernel+0x33c/0x58c with crng_init=1
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid 00000000-0000-0000-00...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid:   -> c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
2021-08-08T21:20:17+0200 kernel: random: lvmconfig: uninitialized urandom read (4 bytes read)
2021-08-08T21:20:17+0200 kernel: random: systemd: uninitialized urandom read (16 bytes read)
2021-08-08T21:20:17+0200 kernel: random: proc_do_uuid: uuid c52f762d-5977-4b1c-95...
[...]

Yes they do not change.
Though previusly, there was one uuid for a cold boot, and one for a reboot. but it was the same uuid for a cold boot and the other one for a reboot.

Now it is back at only one uuid for iehter a cold boot or a reboot. I don't know why.

@pelwell
Copy link
Contributor

pelwell commented Aug 20, 2021

And (last one for now) can you confirm that the uuid property also always returns the same value (c52f7...)?

@pelwell
Copy link
Contributor

pelwell commented Aug 20, 2021

No - I think uuid will vary. What would be useful is the complete kernel log up until the first appearance of that uuid.

@solsticedhiver
Copy link
Author

yes cat /proc/sys/kernel/random/uuid varies
Well the log is a mess because everyhting is logged to the same uuid. So every boot is mixed up. So I wiped out /var/log/journal to get something clean

That's why there was 2 times the line proc_do_uuid: uuid 00000000-0000-0000-00.. previuosly

strange-boot-log-random-2.log

@pelwell
Copy link
Contributor

pelwell commented Aug 24, 2021

The firmware in the ArchLinuxARM-rpi-latest.tar.gz I just downloaded dates from Jun 29. The patch adding the rng-seed property only went in on Jul 13. I suspect the kernel isn't handling the lack of that property very well - grab yourself some new firmware from here: https://github.com/raspberrypi/firmware/tree/master/boot

@graysky2
Copy link

graysky2 commented Aug 24, 2021

@pelwell - The images are generated on a bit of an irregular basis and are not meant to be current since Arch ARM is a rolling release. Unless a total newb, Arch [ARM] users generally keep their systems up-to-date. Our firmware packages are currently in parity with your's/upstream.

@solsticedhiver - Are you up-to-date?

@pelwell
Copy link
Contributor

pelwell commented Aug 24, 2021

Understood.

I've now installed Arch on a Zero W and updated it ("pacman -Syu"). The kernel is 5.10.60-1-ARCH, the firmware is Aug 19 2021, and /proc/sys/kernel/random/boot_id is working as expected.

I'm calling this user error until proven otherwise.

@pelwell
Copy link
Contributor

pelwell commented Aug 24, 2021

It's even working with the firmware from 29 Jun and the 5.10.60-1-ARCH kernel.

@solsticedhiver
Copy link
Author

Well, I never said it was a problem with the firmware. I just said it started with kernel 5.10.52-6. I did not track the firmware version

@graysky2 yes. I am up to date.

And yes, now that I have upgraded to 5.10.60-1-ARCH, it is working a little "better";
but that does not say what I have reported is false or wrong.

And by better, I mean it is not fixed yet. Look at that:

# cat /proc/sys/kernel/random/boot_id 
ce4a389d-dfa8-496f-8da3-c2a69010052e
# journalctl --list-boot
-1 c52f762d59774b1c95de6f0edd68910d Sun 2021-08-08 21:20:17 CEST—Fri 2021-08-20 16:51:44 CEST
 0 ce4a389ddfa8496f8da3c2a69010052e Tue 2021-08-24 22:40:28 CEST—Tue 2021-08-24 22:42:36 CEST
# reboot

# cat /proc/sys/kernel/random/boot_id 
ce4a389d-dfa8-496f-8da3-c2a69010052e
# journalctl --list-boot
-1 c52f762d59774b1c95de6f0edd68910d Sun 2021-08-08 21:20:17 CEST—Fri 2021-08-20 16:51:44 CEST
 0 ce4a389ddfa8496f8da3c2a69010052e Tue 2021-08-24 22:42:53 CEST—Tue 2021-08-24 22:42:56 CEST
# reboot

# cat /proc/sys/kernel/random/boot_id 
6fa901e6-00fc-4d0c-825c-878fa741d8b2
# journalctl --list-boot
-2 c52f762d59774b1c95de6f0edd68910d Sun 2021-08-08 21:20:17 CEST—Fri 2021-08-20 16:51:44 CEST
-1 ce4a389ddfa8496f8da3c2a69010052e Tue 2021-08-24 22:42:53 CEST—Tue 2021-08-24 22:42:56 CEST
 0 6fa901e600fc4d0c825c878fa741d8b2 Tue 2021-08-24 22:45:04 CEST—Tue 2021-08-24 22:45:23 CEST
# reboot

# cat /proc/sys/kernel/random/boot_id 
6fa901e6-00fc-4d0c-825c-878fa741d8b2
# journalctl -o verbose -b|egrep '^[ ]+_BOOT_ID' |tail -n 1
    _BOOT_ID=6fa901e600fc4d0c825c878fa741d8b2
# journalctl --list-boot
-2 c52f762d59774b1c95de6f0edd68910d Sun 2021-08-08 21:20:17 CEST—Fri 2021-08-20 16:51:44 CEST
-1 ce4a389ddfa8496f8da3c2a69010052e Tue 2021-08-24 22:42:53 CEST—Tue 2021-08-24 22:42:56 CEST
 0 6fa901e600fc4d0c825c878fa741d8b2 Tue 2021-08-24 22:47:00 CEST—Tue 2021-08-24 22:49:52 CEST
# reboot

# cat /proc/sys/kernel/random/boot_id 
ce4a389d-dfa8-496f-8da3-c2a69010052e
# journalctl --list-boot
-2 c52f762d59774b1c95de6f0edd68910d Sun 2021-08-08 21:20:17 CEST—Fri 2021-08-20 16:51:44 CEST
-1 ce4a389ddfa8496f8da3c2a69010052e Tue 2021-08-24 22:42:53 CEST—Tue 2021-08-24 22:42:56 CEST
 0 6fa901e600fc4d0c825c878fa741d8b2 Tue 2021-08-24 22:47:00 CEST—Tue 2021-08-24 22:50:12 CEST


Moreover the suppsedly randol boot_id is not random because I get the same uuid on diferrents rpi0s (all W). I mean the boot_id reported on differents rpi0s is matching the one on another rpi0s. Now it is 6fa901e600fc4d0c825c878fa741d8b2, but I suspect it depends on the time.

But never mind if it is "user error". I don't see how I can influence the boot_id ??

@graysky2 so I am gonna install a brand new arch on one rpi0 just to be sure. I will report back

@solsticedhiver
Copy link
Author

@pelwell well, so I have tried with a brand new archlinuxARM install, and I confirm the problem on 2 rpi0s W.

I even got the same boot_id on the 2, namely 6fa901e6-00fc-4d0c-825c-878fa741d8b2

@pelwell
Copy link
Contributor

pelwell commented Dec 9, 2021

In response to the deleted comment, I'm sympathetic to the problem but as long as I'm unable to reproduce it there's not a lot that can be done. Feel free to reopen the issue (or just comment) if some important new information comes to light.

@pelwell pelwell closed this as completed Dec 9, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants