[systemd-devel] Switch root slowness

[Jan Synáček]

Hello,

commit 539618a0ddc2dc7f0fbe28de2ae0e07b34c81e60
Author: Lennart Poettering <lennart at poettering.net>
Date:   Wed Oct 29 17:06:32 2014 +0100

    util: make use of the new getrandom() syscall if it is available when needing entropy

    Doesn't require an fd, and could be a bit faster, so let's make use of
    it, if it is available.

Beginning from this commit, switch root takes about a minute on my machine.

Excerpts from the journal:
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: random: systemd urandom read with 10 bits of entropy available
Oct 30 13:08:37 fedora-rawhide-systemd-virt systemd-journal[109]: Journal started
Oct 30 13:08:37 fedora-rawhide-systemd-virt dracut-cmdline[105]: dracut-22 (Rawhide) dracut-038-36.git20140815.fc22
Oct 30 13:08:37 fedora-rawhide-systemd-virt dracut-cmdline[105]: Using kernel command line parameters:
Oct 30 13:08:37 fedora-rawhide-systemd-virt systemd-udevd[158]: starting version 216
^^^^
This line is pretty weird too, this commit is after v217 had been tagged.

Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] Initialized drm 1.1.0 20060810
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] Device Version 0.0
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] Compression level 0 log level 0
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] Currently using mode #0, list at 0x488
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] 12286 io pages at offset 0x1000000
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] 16777216 byte draw area at offset 0x0
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] RAM header offset: 0x3ffe000
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] rom modes offset 0x488 for 128 modes
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [TTM] Zone  kernel: Available graphics memory: 1024780 kiB
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [TTM] Initializing pool allocator
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [TTM] Initializing DMA pool allocator
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] qxl: 16M of VRAM memory size
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] qxl: 63M of IO pages memory ready (VRAM domain)
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] qxl: 64M of Surface memory size
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] main mem slot 1 [f4000000,3ffe000]
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] surface mem slot 2 [f8000000,4000000]
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] No driver support for vblank timestamp query.
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] fb mappable at 0xF4000000, size 3145728
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] fb: depth 24, pitch 4096, width 1024, height 768
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: fbcon: qxldrmfb (fb0) is primary device
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: Console: switching to colour frame buffer device 128x48
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: qxl 0000:00:02.0: fb0: qxldrmfb frame buffer device
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: qxl 0000:00:02.0: registered panic notifier
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: [drm] Initialized qxl 0.1.0 20120117 for 0000:00:02.0 on minor 0
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: PM: Starting manual resume from disk
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: PM: Hibernation image partition 8:2 present
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: PM: Looking for hibernation image.
Oct 30 13:08:37 fedora-rawhide-systemd-virt systemd-fsck[198]: /dev/sda3: clean, 83696/853440 files, 1149042/3410688 blocks
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: PM: Image not found (code -22)
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: PM: Hibernation image not present or could not be loaded.
Oct 30 13:08:37 fedora-rawhide-systemd-virt kernel: EXT4-fs (sda3): mounted filesystem with ordered data mode. Opts: (null)
Oct 30 13:08:38 fedora-rawhide-systemd-virt systemd[1]: Switching root.
Oct 30 13:08:38 fedora-rawhide-systemd-virt systemd-journal[109]: Journal stopped
^^^^
Hangs here for a while with no output.
vvvv
Oct 30 13:09:44 fedora-rawhide-systemd-virt systemd-journal[279]: Runtime journal is using 8.0M (max allowed 100.0M, trying to leave 150.1M free of 992.7M available → current limit 100.0M).
Oct 30 13:09:44 fedora-rawhide-systemd-virt systemd-journal[279]: Runtime journal is using 8.0M (max allowed 100.0M, trying to leave 150.1M free of 992.7M available → current limit 100.0M).
Oct 30 13:09:44 fedora-rawhide-systemd-virt systemd-journald[109]: Received SIGTERM from PID 1 (systemd).
<snip a lot of selinux related stuff>
Oct 30 13:09:44 fedora-rawhide-systemd-virt kernel: random: nonblocking pool is initialized

Is anyone else running into this?

Cheers,
-- 
Jan Synacek
Software Engineer, Red Hat
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 818 bytes
Desc: not available
URL: <http://lists.freedesktop.org/archives/systemd-devel/attachments/20141030/56629c32/attachment-0001.sig>