Bug 1305608

Description of problem:

1. Please reference- 

https://github.com/systemd/systemd/issues/1961 

for a background, as it appears to affect RHEL 7.2's systemd 219-19.

2. A test application is continuously making ssh connections at a rate on the order of 10/sec to execute command to the hosts that experience this problem. Each of these remotely executed commands is typically very short in execution time. 

3. We do not believe that rate limiting parameters in the SSH configuration file /etc/ssh/sshd_config defined, such as "MaxSessions" or "MaxStartups" are the root cause or are related in this scenario. 

4. The problem seems to be introduced somewhere in systemd 208 - 219. The exact same application test does not cause the below problems with systemd 208 or older.

5. When the host receiving the the ssh commands is operating well, the systemd-logind will typically look as follows, here you can see that new sessions are being created and removed soon there after.

[root@hostname ~]# journalctl -u systemd-logind -f
-- Logs begin at Mon 2016-02-01 20:36:09 EST. --
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: New session 759045 of user root.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: New session 759046 of user root.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: New session 759048 of user root.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: New session 759047 of user root.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: New session 759049 of user root.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: Removed session 759045.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: Removed session 759047.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: Removed session 759046.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: Removed session 759048.
Feb 04 15:35:12 hostname.example.com systemd-logind[571]: Removed session 759049.
Feb 04 15:35:13 hostname.example.com systemd-logind[571]: New session 759050 of user root.
Feb 04 15:35:13 hostname.example.com systemd-logind[571]: Removed session 759050.
Feb 04 15:35:13 hostname.example.com systemd-logind[571]: New session 759051 of user root.
Feb 04 15:35:13 hostname.example.com systemd-logind[571]: Removed session 759051.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: New session 759054 of user root.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: New session 759056 of user root.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: New session 759053 of user root.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: New session 759052 of user root.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: New session 759055 of user root.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: New session 759057 of user root.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: New session 759058 of user root.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: Removed session 759054.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: Removed session 759053.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: Removed session 759057.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: Removed session 759055.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: Removed session 759052.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: Removed session 759056.
Feb 04 15:35:14 hostname.example.com systemd-logind[571]: Removed session 759058.

When a host running systemd 219 experience the problem (usually some time after 10's of minutes to a couple of hours of the above loading,) the "Remove session" logs will cease and only "New session" logs will be seen.

At this time, or some time soon there after, the systemd-logind process will begin utilizing near 100% CPU and can hang the system. 

6. One indication of the problem is a large number (10s-100s) of logs indicating abandon sessions as seen with the following command: systemctl |grep "of user root" |grep "abandoned"

7. Another indication of this problem is a large and increasing number files (100s-1000s) indicated via "ls /run/systemd/sessions/ | wc -l". 


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

This issue has been narrowed down to having been introduced some time between systemd version 208 (where the problem is not seen and version 219 where the problem is seen.)

Further the version of openssh-server is the same in both in good and bad hosts.

openssh-6.6.1p1-23.el7_2.x86_64
openssh-clients-6.6.1p1-23.el7_2.x86_64
openssh-server-6.6.1p1-23.el7_2.x86_64


How reproducible:
Always after 10 minutes - a few hours.


Steps to Reproduce:
1. Create a script that opens and closes SSH connections at a rate of about 10 per second. Keep in mind the "MaxSessions" or "MaxStartups" parameters mentioned above as they could play a role if the rate or amount of connections tested exceeds what is allowed by SSHD. If the sshd_config limits are exceeded in your configuration file, then the test could be invalidated/masked.

2. Wait for a period of time and monitor with "journalctl -u systemd-logind -f"


Actual results:
100% CPU utilization and possible system hangs.


Expected results:
Graceful handling of the connections.