linux-kernel - 2 s boot time regression between 5.17 and 5.18-rc4?

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: Windows password security audit tool. GUI, reports in PDF.

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

Message-ID: <a6688497-e234-ddaa-f371-b9e7539df74d@molgen.mpg.de>
Date:   Mon, 16 May 2022 00:09:20 +0200
From:   Paul Menzel <pmenzel@...gen.mpg.de>
To:     Theodore Ts'o <tytso@....edu>,
        "Jason A. Donenfeld" <Jason@...c4.com>
Cc:     LKML <linux-kernel@...r.kernel.org>
Subject: 2 s boot time regression between 5.17 and 5.18-rc4?

Dear Linux folks,


Looking at the timestamps I only just noticed a two second regression. 
The line below

     systemd[1]: Created slice Slice /system/getty.

is logged two seconds later. I haven’t debugged yet, and wanted to 
report it early. (No idea if it’s even related to the random subsystem.)

### 5.17-rc8

```
[    0.000000] Linux version 5.17.0-rc8-00254-g24544474c7a3 
(root@...877da5b3e) (gcc (Debian 11.2.0-12) 11.2.0, GNU ld (GNU Binutils 
for Debian) 2.37) #292 SMP PREEMPT Sat Mar 19 17:58:03 UTC 2022
[    0.000000] Command line: 
BOOT_IMAGE=/boot/vmlinuz-5.17.0-rc8-00254-g24544474c7a3 root=/dev/sda3 
rw quiet noisapnp cryptomgr.notests ipv6.disable_ipv6=1 selinux=0 
apic=verbose
[…]
[    0.495882] Run /sbin/init as init process
[    0.495883]   with arguments:
[    0.495884]     /sbin/init
[    0.495885]     noisapnp
[    0.495886]   with environment:
[    0.495887]     HOME=/
[    0.495887]     TERM=linux
[    0.495888]     BOOT_IMAGE=/boot/vmlinuz-5.17.0-rc8-00254-g24544474c7a3
[    0.508902] random: random: 1
[    0.508906] random: random: 2
[    0.508906] random: random: 3
[    0.508907] random: random: 4
[    0.535152] random: random: 1
[    0.535155] random: random: 2
[    0.535156] random: random: 3
[    0.535157] random: random: 4
[    0.535158] random: fast init done
[    0.656129] systemd[1]: Inserted module 'autofs4'
[    0.670092] NET: Registered PF_INET6 protocol family
[    0.670798] Segment Routing with IPv6
[    0.670817] In-situ OAM (IOAM) with IPv6
[    0.688171] systemd[1]: systemd 250.4-1 running in system mode (+PAM 
+AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS -OPENSSL 
+ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP 
+LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB 
+ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[    0.688462] systemd[1]: Detected architecture x86-64.
[    0.689648] systemd[1]: Hostname set to <kodi>.
[    0.882098] systemd[1]: Queued start job for default target Graphical 
Interface.
[    0.882399] random: systemd: uninitialized urandom read (16 bytes read)
[    0.884599] systemd[1]: Created slice Slice /system/getty.
[…]
```

### 5.18-rc4+ (based on commit 38d741cb70b3 (Merge tag 
'drm-fixes-2022-04-29' of git://anongit.freedesktop.org/drm/drm)

```
[    0.000000] Linux version 5.18.0-rc4-00303-g7c523829a82e 
(root@...b429beb4a) (gcc (Debian 11.2.0-12) 11.2.0, GNU ld (GNU Binutils 
for Debian) 2.37) #349 SMP PREEMPT_DYNAMIC Fri Apr 29 06:33:06 UTC 2022
[    0.000000] Command line: 
BOOT_IMAGE=/boot/vmlinuz-5.18.0-rc4-00303-g7c523829a82e root=/dev/sda3 
rw quiet noisapnp cryptomgr.notests ipv6.disable_ipv6=1 selinux=0
[…]
[    0.536857] Run /sbin/init as init process
[    0.536859]   with arguments:
[    0.536860]     /sbin/init
[    0.536861]     noisapnp
[    0.536862]   with environment:
[    0.536862]     HOME=/
[    0.536863]     TERM=linux
[    0.536864]     BOOT_IMAGE=/boot/vmlinuz-5.18.0-rc4-00303-g7c523829a82e
[    0.592103] random: fast init done
[    0.708529] systemd[1]: Inserted module 'autofs4'
[    0.720889] NET: Registered PF_INET6 protocol family
[    0.721601] Segment Routing with IPv6
[    0.721619] In-situ OAM (IOAM) with IPv6
[    0.737764] systemd[1]: systemd 250.4-1 running in system mode (+PAM 
+AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS -OPENSSL 
+ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP 
+LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB 
+ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[    0.738077] systemd[1]: Detected architecture x86-64.
[    0.739470] systemd[1]: Hostname set to <kodi>.
[    0.931002] systemd[1]: Queued start job for default target Graphical 
Interface.
[    1.434543] tsc: Refined TSC clocksource calibration: 3900.224 MHz
[    1.434549] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 
0x70705a6472c, max_idle_ns: 881590586812 ns
[    1.434562] clocksource: Switched to clocksource tsc
[    2.826543] random: crng init done
[    2.828295] systemd[1]: Created slice Slice /system/getty.
[…]
```

I am going to be away from the system for a week, but maybe I find time 
to try to reproduce it in QEMU.


Kind regards,

Paul
View attachment "linux-5.18-rc6+.txt" of type "text/plain" (58887 bytes)

View attachment "kodi-coreboot-linux-5.17-rc8-apic-verbose.txt" of type "text/plain" (69201 bytes)