Bug 3055 - Need some high-probability logging re MaxStartups
Summary: Need some high-probability logging re MaxStartups
Status: CLOSED FIXED
Alias: None
Product: Portable OpenSSH
Classification: Unclassified
Component: sshd (show other bugs)
Version: 8.0p1
Hardware: Other Linux
: P5 normal
Assignee: Damien Miller
URL:
Keywords:
Depends on:
Blocks: V_8_4
  Show dependency treegraph
 
Reported: 2019-08-11 20:50 AEST by Ian Jackson
Modified: 2023-01-13 13:42 AEDT (History)
3 users (show)

See Also:


Attachments
better logging for MaxStartups throttling (3.26 KB, patch)
2020-05-15 15:26 AEST, Damien Miller
no flags Details | Diff
Better MaxStartups logging v2 (5.04 KB, patch)
2020-05-15 15:48 AEST, Damien Miller
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Ian Jackson 2019-08-11 20:50:39 AEST
Hi.

Currently, when MaxStartups is reached, sshd logs a single message per dropped connection, at severity "verbose" (which doesn't appear anywhere by default).

It seems to me that things that stop ssh working should be logged a bit higher than verbose.  These connection drops can be quite mysterious nuisance otherwise.

Of course there's the problem that one message per such connection would be a DoS opportuity in itself.

For a troubleshooter to be able to tell what's going on, it would be good for there to be at least *some* high-priority message relatively near in time to each drop.  Also, a transition from "we are dropping connections sometimes" to "things are fine" should be somehow determinable by looking at the logs.

I propose the following broad approach:

 * The first time a connection is dropped because of MaxStartups, log a message with severity ERROR.
 * Periodically (every minute maybe?) report on number or proportion of dropped connections, again at severity ERROR.
 * If connections stop being dropped, make this clear in the log (with a message which implies that the next drop will be reported immediately), maybe ERROR or INFO.

In a bit more detail:

 * Maintain a counter of dropped connections, initially 0
 * Maintain a timer, initially inactive
 * When a connection is dropped:
    - If the timer is not running, report
           MaxStartups: first drop of a connection
      and set the timer.  (The counter remains at 0.)
    - If the timer is running, increment the counter (only)
 * When the timer fires:
    - If the counter is nonzero, report
           MaxStartups: %d drops since last report
      and reset the timer.
    - If the counter is zero, report
           MaxStartups: no longer dropping connections
      and do not reset the timer.

If a proper timer is awkward to implement in the sshd main loop, it would be good enough to remember when we last printed a message, and check that elapsed time after making the MaxStartups decision for each new connection.

A more sophisticated approach might distinguish random from always dropping, or sometimes report client or server addresses, or something.
Comment 1 Damien Miller 2020-05-15 15:26:35 AEST
Created attachment 3394 [details]
better logging for MaxStartups throttling

This implements better logging of MaxStartups.

When MaxStartups is first hit, sshd will log this and the four-tuple for the offending connection.

Add periodic logging (every 5 minutes) while in MaxStartups that includes how long the condition has been in effect, the number of connections dropped and the most recent offending connection.

Log when MaxStartups was exited too. This is defined by the number of active pre-auth connections falling to two below the threshold.

Hopefully this isn't too noisy, otherwise we might need to add time-based hysteresis for the exit case too.
Comment 2 Damien Miller 2020-05-15 15:48:35 AEST
Created attachment 3395 [details]
Better MaxStartups logging v2

Previous diff was missing a couple of files.
Comment 3 Damien Miller 2020-06-26 15:14:36 AEST
This has been committed and will be in openssh-8.4, due in a few months.
Comment 4 Darren Tucker 2020-10-02 14:55:06 AEST
Mass close of all bugs fixed in 8.4 release.