Bug 1658800 - upgrading nss packages restarts sshd repeatedly causing systemd to refuse to start it due to start-limit-hit
Summary: upgrading nss packages restarts sshd repeatedly causing systemd to refuse to ...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: nss
Version: 8.0
Hardware: All
OS: Unspecified
unspecified
high
Target Milestone: rc
: 8.0
Assignee: nss-nspr-maint
QA Contact: BaseOS QE Security Team
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-12-12 20:59 UTC by Mike Gahagan
Modified: 2019-05-22 04:51 UTC (History)
1 user (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-03-18 11:33:23 UTC
Type: Bug
Target Upstream Version:


Attachments (Terms of Use)

Description Mike Gahagan 2018-12-12 20:59:21 UTC
Description of problem:
Upgrading nss packages can cause sshd to restart frequently enough that we hit the start limit and systemd will refuse to start the service. This causes the system to be unavailable for ssh connections:

Dec 12 15:42:41 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:42:41 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:42:41 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:42:41 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:42:41 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2040]: Server listening on 0.0.0.0 port 22.
Dec 12 15:42:41 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2040]: Server listening on :: port 22.
Dec 12 15:42:41 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2040]: Received signal 15; terminating.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2280]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2280]: Server listening on :: port 22.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2280]: Received signal 15; terminating.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2407]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2407]: Server listening on :: port 22.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started /usr/bin/systemctl start man-db-cache-update.
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting man-db-cache-update.service...
Dec 12 15:43:32 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started /usr/bin/systemctl start man-db-cache-update.
Dec 12 15:43:36 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started man-db-cache-update.service.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[2407]: Received signal 15; terminating.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3175]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3175]: Server listening on :: port 22.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3175]: Received signal 15; terminating.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3302]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3302]: Server listening on :: port 22.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started /usr/bin/systemctl start man-db-cache-update.
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting man-db-cache-update.service...
Dec 12 15:43:50 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started /usr/bin/systemctl start man-db-cache-update.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3302]: Received signal 15; terminating.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3691]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3691]: Server listening on :: port 22.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3691]: Received signal 15; terminating.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3955]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3955]: Server listening on :: port 22.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started /usr/bin/systemctl start man-db-cache-update.
Dec 12 15:43:52 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started /usr/bin/systemctl start man-db-cache-update.
Dec 12 15:43:54 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started man-db-cache-update.service.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[3955]: Received signal 15; terminating.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[4223]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[4223]: Server listening on :: port 22.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[4223]: Received signal 15; terminating.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting OpenSSH server daemon...
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[4223]: Server listening on 0.0.0.0 port 22.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[4223]: Server listening on :: port 22.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Started OpenSSH server daemon.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com sshd[4223]: Received signal 15; terminating.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping OpenSSH server daemon...
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped OpenSSH server daemon.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped target sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopping sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Reached target sshd-keygen.target.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: sshd.service: Start request repeated too quickly.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: sshd.service: Failed with result 'start-limit-hit'.
Dec 12 15:43:59 host-8-250-47.host.centralci.eng.rdu2.redhat.com systemd[1]: Failed to start OpenSSH server daemon.

Version-Release number of selected component (if applicable):

[root@host-8-250-47 yum.repos.d]# rpm -qa | grep nss-
nss-tools-debuginfo-3.41.0-1.el8.x86_64
nss-sysinit-3.39.0-1.5.el8.x86_64
nss-softokn-devel-3.39.0-1.2.el8.x86_64
nss-util-3.41.0-1.el8.x86_64
nss-softokn-debuginfo-3.39.0-1.2.el8.x86_64
nss-softokn-freebl-debuginfo-3.39.0-1.2.el8.x86_64
nss-sysinit-debuginfo-3.41.0-1.el8.x86_64
nss-softokn-3.39.0-1.2.el8.x86_64
nss-3.39.0-1.5.el8.x86_64
nss-softokn-freebl-devel-3.39.0-1.2.el8.x86_64
nss-devel-3.39.0-1.5.el8.x86_64
nss-util-debuginfo-3.41.0-1.el8.x86_64
nss-util-devel-3.41.0-1.el8.x86_64
nss-util-debugsource-3.39.0-1.1.el8.x86_64
nss-debugsource-3.41.0-1.el8.x86_64
nss-softokn-debugsource-3.39.0-1.2.el8.x86_64
nss-debuginfo-3.41.0-1.el8.x86_64
nss-softokn-freebl-3.39.0-1.2.el8.x86_64
nss-tools-3.39.0-1.5.el8.x86_64

How reproducible:
always when running installibility testing.

Steps to Reproduce:
1.Provision a system with RHEL 8, run the upgrade test from mini-tps or trigger the CI job
2.
3.

Actual results:
sshd is left in a non-working state due hitting the start limit. Waiting a few minutes then restarting sshd manually gets sshd back to a working state.


Expected results:
sshd stays running

Additional info:

Comment 2 Nikos Mavrogiannopoulos 2019-01-21 16:01:07 UTC
Hi Mike,
 What is the request here? Have you verified whether the issue is in mini-tps or you believe it is in NSS (which looks unrelated to sshd)?

Comment 3 Mike Gahagan 2019-01-22 19:14:50 UTC
Hi,

We reviewed what mini-tps was doing and in this case I do not believe mini-tps really had anything to do with it. The issue was caused by sshd getting restarted in %post of the nss packages. I don't recall the exact fix but I think it was determined some of the sshd restarts were unnecessary and were removed which preventing future nss packages from hitting the sshd restart limit defined in the systemd unit file. If current nss packages are passing in mini-tps then we can go ahead and close this bug as there is nothing else needed to do.


Note You need to log in before you can comment on or make changes to this bug.