openssh bugs - Aug 2019 - [Bug 3055] New: Need some high-probability logging re MaxStartups

https://bugzilla.mindrot.org/show_bug.cgi?id=3055

            Bug ID: 3055
           Summary: Need some high-probability logging re MaxStartups
           Product: Portable OpenSSH
           Version: 8.0p1
          Hardware: Other
                OS: Linux
            Status: NEW
          Severity: normal
          Priority: P5
         Component: sshd
          Assignee: unassigned-bugs at mindrot.org
          Reporter: oxwghc at fyvzl.net

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.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3055

Colin Watson <cjwatson at debian.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |cjwatson at debian.org

-- 
You are receiving this mail because:
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3055

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |ASSIGNED
                 CC|                            |djm at mindrot.org,
                   |                            |dtucker at dtucker.net
           Assignee|unassigned-bugs at mindrot.org |djm at mindrot.org
   Attachment #3394|                            |ok?(dtucker at dtucker.net)
              Flags|                            |

--- Comment #1 from Damien Miller <djm at mindrot.org> ---
Created attachment 3394
  --> https://bugzilla.mindrot.org/attachment.cgi?id=3394&action=edit
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.

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3055

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
   Attachment #3394|0                           |1
        is obsolete|                            |
   Attachment #3394|ok?(dtucker at dtucker.net)    |
              Flags|                            |
   Attachment #3395|                            |ok?(dtucker at dtucker.net)
              Flags|                            |

--- Comment #2 from Damien Miller <djm at mindrot.org> ---
Created attachment 3395
  --> https://bugzilla.mindrot.org/attachment.cgi?id=3395&action=edit
Better MaxStartups logging v2

Previous diff was missing a couple of files.

-- 
You are receiving this mail because:
You are watching the assignee of the bug.
You are watching someone on the CC list of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3055

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Blocks|                            |3162
             Status|ASSIGNED                    |RESOLVED
         Resolution|---                         |FIXED

--- Comment #3 from Damien Miller <djm at mindrot.org> ---
This has been committed and will be in openssh-8.4, due in a few
months.


Referenced Bugs:

https://bugzilla.mindrot.org/show_bug.cgi?id=3162
[Bug 3162] Tracking bug for 8.4 release
-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3055

Darren Tucker <dtucker at dtucker.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |CLOSED

--- Comment #4 from Darren Tucker <dtucker at dtucker.net> ---
Mass close of all bugs fixed in 8.4 release.

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.

https://bugzilla.mindrot.org/show_bug.cgi?id=3055

Damien Miller <djm at mindrot.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
   Attachment #3395|ok?(dtucker at dtucker.net)    |
              Flags|                            |

-- 
You are receiving this mail because:
You are watching someone on the CC list of the bug.
You are watching the assignee of the bug.