Bug 1493337

Summary: systemd is using uninitialized urandom
Product: Red Hat Enterprise Linux 7 Reporter: Erik Hamera <ehamera>
Component: systemdAssignee: systemd-maint
Status: NEW --- QA Contact: qe-baseos-daemons
Severity: medium Docs Contact:
Priority: unspecified    
Version: 7.4CC: bhsharma, ernunes, fweimer, jbastian, jsynacek, kdump-bugs, rvr, systemd-maint-list, wmealing, yselkowi, zsun
Target Milestone: rcFlags: bhsharma: needinfo? (jsynacek)
Target Release: ---   
Hardware: aarch64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Bug Depends On:    
Bug Blocks: 1534323, 1721114, 1633012    

Description Erik Hamera 2017-09-20 01:33:22 UTC
Description of problem:
There are 10 messages:
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
in /var/log/messages after installation. It looks suspicious to me.

Version-Release number of selected component (if applicable):
RHEL-7.4 Beta Pegas

How reproducible:
I don't know now.

Steps to Reproduce:
1. Install a new system via beaker.
2.
3.

Actual results:


Expected results:
No such message in /var/messages or explanation why it is o.k. here in Bugzilla, where anyone can find it.

Additional info:
/var/log/messages:
...
Sep 19 13:33:35 localhost kernel: ACPI: PCI Interrupt Link [LN5A] enabled at IRQ 108
Sep 19 13:33:35 localhost kernel: pcieport 0005:00:00.0: Signaling PME with IRQ 277
Sep 19 13:33:35 localhost kernel: rtc-efi rtc-efi: setting system clock to 2017-09-19 17:33:35 UTC (1505842415)
Sep 19 13:33:35 localhost kernel: Freeing unused kernel memory: 1280K
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost systemd[1]: systemd 219 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
Sep 19 13:33:35 localhost systemd[1]: Detected architecture arm64.
Sep 19 13:33:35 localhost systemd[1]: Running in initial RAM disk.
Sep 19 13:33:35 localhost systemd[1]: Set hostname to <localhost.localdomain>.
Sep 19 13:33:35 localhost kernel: usb 7-1: new high-speed USB device number 2 using xhci-hcd
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost kernel: random: systemd: uninitialized urandom read (16 bytes read)
Sep 19 13:33:35 localhost systemd[1]: Reached target Swap.
Sep 19 13:33:35 localhost systemd[1]: Starting Swap.
Sep 19 13:33:35 localhost systemd[1]: Created slice Root Slice.
Sep 19 13:33:35 localhost systemd[1]: Starting Root Slice.
Sep 19 13:33:35 localhost systemd[1]: Listening on udev Control Socket.
Sep 19 13:33:35 localhost systemd[1]: Starting udev Control Socket.
...

Comment 4 Lukáš Nykrýn 2017-09-20 07:24:28 UTC
https://github.com/systemd/systemd/issues/4167

Comment 5 Jan Synacek 2017-10-05 12:11:26 UTC
I've tried to backport the patch from https://github.com/systemd/systemd/issues/4167, but it doesn't seem to solve anything in our case. As mentioned in the upstream issue, that warning is harmless.

https://github.com/jsynacek/systemd-rhel/commit/af7410b9328a5a2bab5c9f7292240e2ea2f858c9

Comment 7 Bhupesh Sharma 2018-09-28 08:09:10 UTC
1. I am seeing an issue with RHEL8 on hpe-moonshot boards, were the kdumpctl service fails to start at boot/reboot:

service kdump status
Redirecting to /bin/systemctl status kdump.service
● kdump.service - Crash recovery kernel arming
   Loaded: loaded (/usr/lib/systemd/system/kdump.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Thu 2018-09-20 16:38:56 EDT; 88ms ago
  Process: 4496 ExecStart=/usr/bin/kdumpctl start (code=exited, status=1/FAILURE)
 Main PID: 4496 (code=exited, status=1/FAILURE)

Sep 20 16:38:55 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com systemd[1]: Starting Crash recovery kernel arming...
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com kdumpctl[4496]: kexec: setup_2nd_dtb failed.
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com kdumpctl[4496]: kexec: load failed.
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com kdumpctl[4496]: Cannot load /boot/vmlinuz-4.18.0-12.el8.aarch64
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com kdumpctl[4496]: kexec: failed to load kdump kernel
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com kdumpctl[4496]: Starting kdump: [FAILED]
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com systemd[1]: kdump.service: Main process exited, code=exited, status=1/FAILURE
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com systemd[1]: kdump.service: Failed with result 'exit-code'.
Sep 20 16:38:56 hpe-moonshot-02-c02.hpe1.lab.eng.bos.redhat.com systemd[1]: Failed to start Crash recovery kernel arming.

2. When the kdump service is restarted (after boot) manually, it succeeds

3. Here are the logs from 'dmesg', which show that 'systemd' does a read from an uninitiated pool:

[root@hpe-moonshot-02-c24 ~]# dmesg | grep -A 2 -B 2 random
[    0.000000]   Normal zone: 983039 pages, LIFO batch:1
[    0.000000] psci: is not implemented in ACPI.
[    0.000000] random: get_random_bytes called from start_kernel+0x9c/0x470 with crng_init=0
[    0.000000] percpu: Embedded 3 pages/cpu @(____ptrval____) s124312 r8192 d64104 u196608
[    0.000000] pcpu-alloc: s124312 r8192 d64104 u196608 alloc=3*65536
--
[   19.683469] systemd[1]: File /usr/lib/systemd/system/systemd-journald.service:36 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling.
[   19.892318] systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
[   20.063488] random: systemd: uninitialized urandom read (16 bytes read)
[   20.143126] systemd[1]: Listening on udev Control Socket.
[   20.280595] random: systemd: uninitialized urandom read (16 bytes read)
[   20.360015] systemd[1]: Reached target Local File Systems.
[   20.500585] random: systemd: uninitialized urandom read (16 bytes read)
[   20.580223] systemd[1]: Listening on Journal Socket.
[   20.713194] systemd[1]: Starting Create Volatile Files and Directories...
[   21.070650] urandom_read: 4 callbacks suppressed
[   21.070653] random: systemd: uninitialized urandom read (16 bytes read)
[   21.270820] random: systemd: uninitialized urandom read (16 bytes read)
[   21.410640] random: systemd: uninitialized urandom read (16 bytes read)
[   22.621489] device-mapper: uevent: version 1.0.3
[   22.705187] device-mapper: ioctl: 4.39.0-ioctl (2018-04-03) initialised: dm-devel@redhat.com
--
[   31.880763] mlx4_en: 0000:01:00.0: Port 2: Initializing port
[   32.033611] mlx4_core 0000:01:00.0 eno1d1: renamed from eth0
[   32.496158] random: fast init done
[   32.717270] SGI XFS with ACLs, security attributes, no debug enabled
[   32.851497] XFS (dm-0): Mounting V5 Filesystem
--
[  131.986661] Key type id_resolver registered
[  132.103453] Key type id_legacy registered
[  176.139560] random: crng init done

4. Since kexec-tools now use the random pool to generate the random seed need for creating the kaslr-seed for the 2nd kernel (kexec/kdump), so if the systemd fails to read the randoom entropy from the urandom pool, kexec/kdump services will also fail:

                /*
		 * Invoke the getrandom system call with
		 * GRND_NONBLOCK, to make sure we
		 * have a valid random seed to pass to the
		 * secondary kernel.
		 */
		result = syscall(SYS_getrandom, &fdt_val64,
				sizeof(fdt_val64),
				GRND_NONBLOCK);

		if(result == -1) {
			dbgprintf("%s: Reading random bytes failed.\n",
					__func__);
			result = -EINVAL;
			goto on_error;
		}

Please confirm if this is related to systemd.

Also please let me know in case U beed to raise a separate BZ for RHEL8 (since this one is for RHEL 7)