Bug 3447

Summary:	immediate connection closed with nothing logged at DEBUG LogLevel - silent pipe() error?
Product:	Portable OpenSSH	Reporter:	Vincent Lefevre <vincent-openssh>
Component:	sshd	Assignee:	Assigned to nobody <unassigned-bugs>
Status:	CLOSED FIXED
Severity:	enhancement	CC:	dtucker, vincent-openssh
Priority:	P5
Version:	7.9p1
Hardware:	Other
OS:	Linux
Bug Depends on:
Bug Blocks:	3418

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