Bug 3447 - immediate connection closed with nothing logged at DEBUG LogLevel - silent pipe() error?
Summary: immediate connection closed with nothing logged at DEBUG LogLevel - silent pi...
Status: CLOSED FIXED
Alias: None
Product: Portable OpenSSH
Classification: Unclassified
Component: sshd (show other bugs)
Version: 7.9p1
Hardware: Other Linux
: P5 enhancement
Assignee: Assigned to nobody
URL:
Keywords:
Depends on:
Blocks: V_9_1
  Show dependency treegraph
 
Reported: 2022-06-15 23:39 AEST by Vincent Lefevre
Modified: 2022-10-04 21:58 AEDT (History)
2 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Vincent Lefevre 2022-06-15 23:39:46 AEST
With some sshd server (on a Debian 10 machine, but the code appears to be similar in the current version, as shown below), I get random immediate connections closed (a packet dump shows that the server sends a FIN as its second packet, probably because it has closed the socket), and nothing is logged at DEBUG LogLevel. So the only explanation I have is that the pipe() fails, since this seems to be the only way one doesn't get anything logged at this LogLevel.

In case of early connection closed, sshd should ensure that something is logged at least at the DEBUG LogLevel. In particular, one should get something when pipe() fails, and this should probably be an error().

The current sshd.c source from https://github.com/openssh/openssh-portable has the following code in server_accept_loop().

                        if (unset_nonblock(*newsock) == -1 ||
                            pipe(startup_p) == -1) {
                                close(*newsock);
                                continue;
                        }

Concerning unset_nonblock(), defined in misc.c, there is an error() or a debug() in case of error. But nothing in case of pipe() failure. I would expect something like

  error("pipe(startup_p): %s", strerror(errno));

One major improvement is that one would know the reason of the pipe() failure.
Comment 1 Darren Tucker 2022-06-17 11:05:12 AEST
Added proposed error logging upstream.  Thanks for the report, it will be in the next major release.

The other possibility is that it's hitting the MaxStartups limit (or possibly PerSourceMaxStartups, but that's not enabled by default) and the missing log entries are due to the log rate limiting in drop_connection().
Comment 2 Vincent Lefevre 2022-06-17 19:34:54 AEST
(In reply to Darren Tucker from comment #1)
> Added proposed error logging upstream.  Thanks for the report, it
> will be in the next major release.

Thanks.

> The other possibility is that it's hitting the MaxStartups limit (or
> possibly PerSourceMaxStartups, but that's not enabled by default)
> and the missing log entries are due to the log rate limiting in
> drop_connection().

OpenSSH 7.9p1 (used on the Debian 10 server) doesn't seem to have log rate limiting:

        if (drop_connection(startups) == 1) {
[...]
                verbose("drop connection #%d from [%s]:%d "
                    "on [%s]:%d past MaxStartups", startups,
                    raddr, get_peer_port(*newsock),
                    laddr, get_local_port(*newsock));

and OpenSSH 9.0p1 doesn't seem to have log rate limiting for VERBOSE log level and below since in drop_connection(), drop_level >= SYSLOG_LEVEL_VERBOSE. Compared to 7.9p1, it has additional log messages at higher levels, e.g. with error().
Comment 3 Damien Miller 2022-10-04 21:58:57 AEDT
Closing bugs from openssh-9.1 release cycle