openssh unix dev - May 2024 - OpenSSH server doesn't log client disconnect without SSH_MSG_DISCONNECT

On Tue, 21 May 2024, Opty wrote:
> Hello,
> 
> can anyone confirm that OpenSSH server doesn't log client disconnect
> without SSH_MSG_DISCONNECT?
OpenSSH logs the disconnection regardless of whether the client sends
SSH_MSG_DISCONNECT or just drops the connection.

A little more information may be logged from the disconnect packet
if it was sent, but there should always be a "Connection closed by
..."
message regardless.

-d

On Wed, May 22, 2024 at 6:29?AM Damien Miller <djm at mindrot.org>
wrote:
> OpenSSH logs the disconnection regardless of whether the client sends
> SSH_MSG_DISCONNECT or just drops the connection.
>
> A little more information may be logged from the disconnect packet
> if it was sent, but there should always be a "Connection closed by
..."
> message regardless.
I should have shown examples from the system log.

SSH-2.0-OpenSSH_9.3:

2024-05-19T15:48:06.591206+02:00 qeporkak sshd 15053 - - Accepted
keyboard-interactive/pam for opty from 127.0.0.1 port 41006 ssh2
2024-05-19T15:48:06.601660+02:00 qeporkak elogind-daemon 1111 - - New
session 2 of user opty.
2024-05-19T15:48:07.797821+02:00 qeporkak sshd 15058 - - Received
disconnect from 127.0.0.1 port 41006:11: disconnected by user
2024-05-19T15:48:07.797967+02:00 qeporkak sshd 15058 - - Disconnected
from user opty 127.0.0.1 port 41006
2024-05-19T15:48:07.802031+02:00 qeporkak elogind-daemon 1111 - -
Removed session 2.

SSH-2.0-PuTTY_Release_0.81:

2024-05-19T15:58:43.680548+02:00 qeporkak sshd 15171 - - Accepted
keyboard-interactive/pam for opty from 127.0.0.1 port 39223 ssh2
2024-05-19T15:58:43.688472+02:00 qeporkak elogind-daemon 1111 - - New
session 3 of user opty.
2024-05-19T15:58:45.000831+02:00 qeporkak elogind-daemon 1111 - -
Removed session 3.

Neither 'Received disconnect' nor 'Disconnected' with PuTTY.

Regards,
Opty

On Wed, May 22, 2024 at 6:29?AM Damien Miller <djm at mindrot.org>
wrote:
> On Tue, 21 May 2024, Opty wrote:
> > Hello,
> >
> > can anyone confirm that OpenSSH server doesn't log client
disconnect
> > without SSH_MSG_DISCONNECT?
>
> OpenSSH logs the disconnection regardless of whether the client sends
> SSH_MSG_DISCONNECT or just drops the connection.
>
> A little more information may be logged from the disconnect packet
> if it was sent, but there should always be a "Connection closed by
..."
> message regardless.
Unpatched:
2024-05-26T13:40:18.419241+02:00 qeporkak sshd 16107 - - Accepted
keyboard-interactive/pam for opty from 127.0.0.1 port 48133 ssh2
2024-05-26T13:40:18.428291+02:00 qeporkak elogind-daemon 1114 - - New
session 2 of user opty.
2024-05-26T13:40:19.309320+02:00 qeporkak elogind-daemon 1114 - -
Removed session 2.

Q&D patch:
diff -Naur a/putty-0.81/ssh/connection2.c b/putty-0.81/ssh/connection2.c
--- a/putty-0.81/ssh/connection2.c      2024-04-06 11:43:47.000000000 +0200
+++ b/putty-0.81/ssh/connection2.c      2024-05-26 14:00:38.382879095 +0200
@@ -1269,6 +1269,10 @@
          * and indeed OpenSSH feels this is more polite than sending a
          * DISCONNECT. So now we don't.
          */
+
+        /* We do again. */
+        ssh2_bpp_queue_disconnect(s->ppl.bpp, "disconnected by
user",
SSH2_DISCONNECT_BY_APPLICATION);
+
         ssh_user_close(s->ppl.ssh, "All channels closed");
         return;
     }

Patched:
2024-05-26T14:07:33.091682+02:00 qeporkak sshd 19168 - - Accepted
keyboard-interactive/pam for opty from 127.0.0.1 port 45639 ssh2
2024-05-26T14:07:33.107564+02:00 qeporkak elogind-daemon 1114 - - New
session 3 of user opty.
2024-05-26T14:07:34.335668+02:00 qeporkak sshd 19179 - - Received
disconnect from 127.0.0.1 port 45639:11: disconnected by user
2024-05-26T14:07:34.335790+02:00 qeporkak sshd 19179 - - Disconnected
from user opty 127.0.0.1 port 45639
2024-05-26T14:07:34.340569+02:00 qeporkak elogind-daemon 1114 - -
Removed session 3.

QED?

Regards,
Opty