Matt Zagrabelny
2018-11-01 21:40:00 UTC
Package: openssh-server
Version: 1:7.9p1-1
Severity: normal
Greetings,
Thanks for contributing to Debian!
I recently installed Buster to a VM and upgraded its kernel and noticed ssh(d)
took a while to start. I pinged the host and then attempted to ssh to it and
it consistently took about 3 minutes.
According to systemd-analyze it is slow, too. Though not the same slowness
that was observed via ping and ssh tests:
# systemd-analyze blame
21.484s ssh.service
However, ssh would start much quicker when I started to login at tty1.
Looking at the journal I see:
# journalctl -b
Nov 01 10:30:47 systemd[1]: ssh.service: Start-pre operation timed out. Terminating.
Nov 01 10:30:47 systemd[1]: ssh.service: Failed with result 'timeout'.
Nov 01 10:30:47 systemd[1]: ssh.service: Service RestartSec=100ms expired, scheduling restart.
Nov 01 10:30:47 systemd[1]: ssh.service: Scheduled restart job, restart counter is at 1.
Nov 01 10:30:47 systemd[1]: Stopped OpenBSD Secure Shell server.
Nov 01 10:30:47 systemd[1]: Starting OpenBSD Secure Shell server...
Nov 01 10:32:18 systemd[1]: ssh.service: Start-pre operation timed out. Terminating.
Nov 01 10:32:18 systemd[1]: ssh.service: Failed with result 'timeout'.
Nov 01 10:32:18 systemd[1]: Failed to start OpenBSD Secure Shell server.
Nov 01 10:32:18 systemd[1]: ssh.service: Service RestartSec=100ms expired, scheduling restart.
Nov 01 10:32:18 systemd[1]: ssh.service: Scheduled restart job, restart counter is at 2.
Nov 01 10:32:18 systemd[1]: Stopped OpenBSD Secure Shell server.
Nov 01 10:32:18 systemd[1]: Starting OpenBSD Secure Shell server...
Nov 01 16:08:53 kernel: random: crng init done
Nov 01 16:08:53 kernel: random: 7 urandom warning(s) missed due to ratelimiting
Nov 01 10:32:39 sshd[522]: Server listening on 0.0.0.0 port 22.
Nov 01 10:32:39 sshd[522]: Server listening on :: port 22.
Nov 01 10:32:39 systemd[1]: Started OpenBSD Secure Shell server.
Searching the internet for things like "crng init done" yields some hits:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=43838a23a05fbd13e47d750d3dfd77001536dd33
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=897572
https://github.com/systemd/systemd/issues/4167
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1685794
While it appears that the initial cause for the blocking behavior of sshd was
due to a kernel change, I'm not sure if the "fixes" are userspace related.
I didn't see any chatter in my searches about ssh blocking due to the aforementioned kernel
change so I decided to open up this bug report for discussion.
Thanks you for your time!
-m
-- System Information:
Debian Release: buster/sid
APT prefers unstable
APT policy: (500, 'unstable'), (500, 'testing'), (500, 'stable'), (500, 'oldstable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Kernel: Linux 4.17.0-3-amd64 (SMP w/8 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages openssh-server depends on:
ii adduser 3.117
ii debconf [debconf-2.0] 1.5.69
ii dpkg 1.19.0.5+b1
ii libaudit1 1:2.8.3-1+b1
ii libc6 2.27-5
ii libcom-err2 1.44.4-1
ii libgssapi-krb5-2 1.16-2
ii libkrb5-3 1.16-2
ii libpam-modules 1.1.8-3.8
ii libpam-runtime 1.1.8-3.8
ii libpam0g 1.1.8-3.8
ii libselinux1 2.8-1+b1
ii libssl1.1 1.1.1-2
ii libsystemd0 239-7
ii libwrap0 7.6.q-27
ii lsb-base 9.20170808
ii openssh-client 1:7.9p1-1
ii openssh-sftp-server 1:7.9p1-1
ii procps 2:3.3.15-2
ii ucf 3.0038
ii zlib1g 1:1.2.11.dfsg-1
Versions of packages openssh-server recommends:
ii libpam-systemd 239-7
ii ncurses-term 6.1+20180714-1
ii xauth 1:1.0.10-1
Versions of packages openssh-server suggests:
ii molly-guard 0.7.1
ii monkeysphere 0.41-1
ii rssh 2.3.4-8
ii ssh-askpass 1:1.2.4.1-10
pn ufw <none>
-- Configuration Files:
/etc/pam.d/sshd changed [not included]
-- debconf information excluded
Version: 1:7.9p1-1
Severity: normal
Greetings,
Thanks for contributing to Debian!
I recently installed Buster to a VM and upgraded its kernel and noticed ssh(d)
took a while to start. I pinged the host and then attempted to ssh to it and
it consistently took about 3 minutes.
According to systemd-analyze it is slow, too. Though not the same slowness
that was observed via ping and ssh tests:
# systemd-analyze blame
21.484s ssh.service
However, ssh would start much quicker when I started to login at tty1.
Looking at the journal I see:
# journalctl -b
Nov 01 10:30:47 systemd[1]: ssh.service: Start-pre operation timed out. Terminating.
Nov 01 10:30:47 systemd[1]: ssh.service: Failed with result 'timeout'.
Nov 01 10:30:47 systemd[1]: ssh.service: Service RestartSec=100ms expired, scheduling restart.
Nov 01 10:30:47 systemd[1]: ssh.service: Scheduled restart job, restart counter is at 1.
Nov 01 10:30:47 systemd[1]: Stopped OpenBSD Secure Shell server.
Nov 01 10:30:47 systemd[1]: Starting OpenBSD Secure Shell server...
Nov 01 10:32:18 systemd[1]: ssh.service: Start-pre operation timed out. Terminating.
Nov 01 10:32:18 systemd[1]: ssh.service: Failed with result 'timeout'.
Nov 01 10:32:18 systemd[1]: Failed to start OpenBSD Secure Shell server.
Nov 01 10:32:18 systemd[1]: ssh.service: Service RestartSec=100ms expired, scheduling restart.
Nov 01 10:32:18 systemd[1]: ssh.service: Scheduled restart job, restart counter is at 2.
Nov 01 10:32:18 systemd[1]: Stopped OpenBSD Secure Shell server.
Nov 01 10:32:18 systemd[1]: Starting OpenBSD Secure Shell server...
Nov 01 16:08:53 kernel: random: crng init done
Nov 01 16:08:53 kernel: random: 7 urandom warning(s) missed due to ratelimiting
Nov 01 10:32:39 sshd[522]: Server listening on 0.0.0.0 port 22.
Nov 01 10:32:39 sshd[522]: Server listening on :: port 22.
Nov 01 10:32:39 systemd[1]: Started OpenBSD Secure Shell server.
Searching the internet for things like "crng init done" yields some hits:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=43838a23a05fbd13e47d750d3dfd77001536dd33
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=897572
https://github.com/systemd/systemd/issues/4167
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1685794
While it appears that the initial cause for the blocking behavior of sshd was
due to a kernel change, I'm not sure if the "fixes" are userspace related.
I didn't see any chatter in my searches about ssh blocking due to the aforementioned kernel
change so I decided to open up this bug report for discussion.
Thanks you for your time!
-m
-- System Information:
Debian Release: buster/sid
APT prefers unstable
APT policy: (500, 'unstable'), (500, 'testing'), (500, 'stable'), (500, 'oldstable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Kernel: Linux 4.17.0-3-amd64 (SMP w/8 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages openssh-server depends on:
ii adduser 3.117
ii debconf [debconf-2.0] 1.5.69
ii dpkg 1.19.0.5+b1
ii libaudit1 1:2.8.3-1+b1
ii libc6 2.27-5
ii libcom-err2 1.44.4-1
ii libgssapi-krb5-2 1.16-2
ii libkrb5-3 1.16-2
ii libpam-modules 1.1.8-3.8
ii libpam-runtime 1.1.8-3.8
ii libpam0g 1.1.8-3.8
ii libselinux1 2.8-1+b1
ii libssl1.1 1.1.1-2
ii libsystemd0 239-7
ii libwrap0 7.6.q-27
ii lsb-base 9.20170808
ii openssh-client 1:7.9p1-1
ii openssh-sftp-server 1:7.9p1-1
ii procps 2:3.3.15-2
ii ucf 3.0038
ii zlib1g 1:1.2.11.dfsg-1
Versions of packages openssh-server recommends:
ii libpam-systemd 239-7
ii ncurses-term 6.1+20180714-1
ii xauth 1:1.0.10-1
Versions of packages openssh-server suggests:
ii molly-guard 0.7.1
ii monkeysphere 0.41-1
ii rssh 2.3.4-8
ii ssh-askpass 1:1.2.4.1-10
pn ufw <none>
-- Configuration Files:
/etc/pam.d/sshd changed [not included]
-- debconf information excluded