(SOLVED) Slow OpenSSH Daemon startup (3+ minutes!)

tomz17 · 2018-11-15 16:08:43

Anyone else observing the OpenSSH daemon starting really slowly after being called by systemd? This only started happening within the past month or two, so it may be tied to a recent update.

i.e. On last boot it took 3 minutes from the time systemd launched the daemon before it started accepting incoming connections

> journalctl -b -u sshd
    -- Logs begin at Fri 2016-10-21 23:16:04 EDT, end at Thu 2018-11-15 10:50:49 EST. --
    Nov 15 10:28:46 mgt systemd[1]: Started OpenSSH Daemon.
    Nov 15 10:31:51 mgt sshd[341]: Server listening on 0.0.0.0 port 22.
    Nov 15 10:31:51 mgt sshd[341]: Server listening on :: port 22.

Completely stock /etc/ssh config, and changing the OpenSSH Daemon to verbose e.g.

/etc/ssh/sshd_config 

LogLevel VERBOSE

does not yield any additional log info during daemon startup.

Any suggestions or additional thoughts on how to figure this out?

Everything else seems in order

> systemd-analyze time
    Startup finished in 2.051s (kernel) + 675ms (userspace) = 2.727s
    graphical.target reached after 675ms in userspace

> systemd-analyze  blame
           497ms dev-sda2.device
           283ms systemd-hwdb-update.service
           200ms ldconfig.service
           138ms systemd-resolved.service
           137ms systemd-journald.service
           124ms systemd-journal-flush.service
           113ms systemd-udev-trigger.service
            69ms systemd-sysusers.service
            62ms lvm2-monitor.service
            42ms systemd-journal-catalog-update.service
            41ms systemd-networkd.service
            38ms systemd-tmpfiles-setup.service
            35ms user@1000.service
            31ms systemd-remount-fs.service
            19ms systemd-udevd.service
            19ms systemd-logind.service
            17ms sys-kernel-debug.mount
            16ms dev-hugepages.mount
            14ms dev-mqueue.mount
            14ms tmp.mount
            13ms systemd-sysctl.service
            12ms systemd-tmpfiles-setup-dev.service
            12ms systemd-tmpfiles-clean.service
            11ms kmod-static-nodes.service
             8ms sys-kernel-config.mount
             8ms systemd-update-utmp.service
             8ms user-runtime-dir@1000.service
             6ms systemd-random-seed.service
             6ms systemd-update-done.service
             6ms systemd-user-sessions.service

Last edited by tomz17 (2018-11-15 17:55:38)

V1del · 2018-11-15 16:16:38

Likely the issue with the delayed random seed, try installing and enabling haveged or rng-tools

tomz17 · 2018-11-15 17:54:45

V1del wrote:

Likely the issue with the delayed random seed, try installing and enabling haveged or rng-tools

Fixed! Thank you. It was indeed the lack of entropy in the VM.

Installing haveged dropped daemon startup time to < 1 second

journalctl -b -u sshd
    -- Logs begin at Fri 2016-10-21 23:16:04 EDT, end at Thu 2018-11-15 12:50:34 EST. --
    Nov 15 12:50:20 mgt systemd[1]: Started OpenSSH Daemon.
    Nov 15 12:50:20 mgt sshd[321]: Server listening on 0.0.0.0 port 22.

Last edited by tomz17 (2018-11-15 17:55:06)

Nathael · 2019-08-08 22:20:35

Hi all !

I also ran into this problem which prevents login on console or ssh on an embedded system and tracked it to (very) late crng_init

I tried to reply on the debian bug tracker, but they closed the bug report (obviously, they don't care much about solving problems ...) : https://bugs.debian.org/cgi-bin/bugrepo … bug=912087
I did not try to reply on systemd mailing lists as they rather think a security problem is not a problem until someone manages to exploit it (https://github.com/systemd/systemd/issues/4167).

Anyway, for those interested in solving the problem, I made a small program (160 lines,
including comments !) which solves the problem :
http://www.nathael.org/Data/Devel/entropy_pool_init.c

I don't know how it integrates with systemd, but for those using a decent init system, you can integrate it to sysvinit or any init that's not a monolithic crap.
It's loosely based on what's done by haveged (without the HAVEGE algorithm) and what is in
/etc/init.d/urandom and in the "fast init" in the drivers/char/random.c driver.

I feel like it's a quite good compromise between speed, complexity and security.

It may be improved with the real HAVEGE algorithm, but I did not have time to use it, and did
not want to have the haveged daemon running forever either (and the packages installed).

Compile with :
$(CROSS_COMPILE)gcc entropy_pool_init.c -o entropy_pool_init -Wall -Wextra
and place result in /sbin

Then modify /etc/init.d/urandom to call entropy_pool_init with saved entropy file as
argument :
/sbin/entropy_pool_init /var/lib/urandom/random-seed

This should replace the (date and cat "$SAVEDFILE" )>/dev/urandom under "start" case.

You can even improve by calling this as soon as /proc and /dev are available and date got
set (from hwclock), so possibly before eudev/udev on a well configured system with a
recent well configured kernel, which will also remove all these kind of messages :
[ 3.255107] random: udevd: uninitialized urandom read (16 bytes read)

Have fun !
+++

fukawi2 · 2019-08-09 00:16:56

Nathael wrote:

I don't know how it integrates with systemd, but for those using a decent init system,

Presumably you're not using Arch based on this being your first post to the forums, but regardless of that this thread is 9 months old, please don't necro-bump: https://wiki.archlinux.org/index.php/Co … bumping.22

Closing.

Arch Linux

#1 2018-11-15 16:08:43

(SOLVED) Slow OpenSSH Daemon startup (3+ minutes!)

#2 2018-11-15 16:16:38

Re: (SOLVED) Slow OpenSSH Daemon startup (3+ minutes!)

#3 2018-11-15 17:54:45

Re: (SOLVED) Slow OpenSSH Daemon startup (3+ minutes!)

#4 2019-08-08 22:20:35

Re: (SOLVED) Slow OpenSSH Daemon startup (3+ minutes!)

#5 2019-08-09 00:16:56

Re: (SOLVED) Slow OpenSSH Daemon startup (3+ minutes!)

Board footer