LogLevel debug2 handshake logging only on some logins, not on every login of a user

[Hildegard Meier]

> Use a command like
>
> 	strace -f -tt -s 200 -o /tmp/logfile.txt -p <pid of sshd>
>
> Then you'd have to verify what gets written in the logfile to the data
> in your syslog.....

Thanks very much!

I just had a sshd session with PID 32322 which lacked the debug log message.

The strace (exactly the command you stated above) looks for me like the debug log messages are written to /dev/log
But I am no strace reading expert. Does this strace look healthy like the logging to /dev/log works for the debug log messages?

32322 08:19:16.727870 poll([{fd=6, events=POLLIN}, {fd=7, events=POLLIN}], 2, -1 <unfinished ...>
32322 08:19:16.727919 <... poll resumed> ) = 2 ([{fd=6, revents=POLLIN}, {fd=7, revents=POLLIN}])
32322 08:19:16.727965 read(7,  <unfinished ...>
32322 08:19:16.728010 <... read resumed> "\0\0\1\245", 4) = 4
32322 08:19:16.728065 read(7,  <unfinished ...>
32322 08:19:16.728112 <... read resumed> "\0\0\0\6\0\0\1\235MACs ctos: hmac-md5-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64-etm at openssh.com,umac-
128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-ripemd160-etm at op"..., 421) = 421
32322 08:19:16.728206 getpid( <unfinished ...>
32322 08:19:16.728252 <... getpid resumed> ) = 32322
32322 08:19:16.728305 socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0 <unfinished ...>
32322 08:19:16.728363 <... socket resumed> ) = 4
32322 08:19:16.728457 connect(4, {sa_family=AF_UNIX, sun_path="/dev/log"}, 110 <unfinished ...>
32322 08:19:16.728514 <... connect resumed> ) = 0
32322 08:19:16.728548 sendto(4, "<151>May 11 08:19:16 sftpd[32322]: debug2: MACs ctos: hmac-md5-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64-etm at o
penssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-et"..., 466, MSG_NOSIGNAL, NULL, 0 <unfinished ...>
32322 08:19:16.728594 <... sendto resumed> ) = 466
32322 08:19:16.728656 close(4 <unfinished ...>
32322 08:19:16.728710 <... close resumed> ) = 0
32322 08:19:16.728747 poll([{fd=6, events=POLLIN}, {fd=7, events=POLLIN}], 2, -1) = 2 ([{fd=6, revents=POLLIN}, {fd=7, revents=POLLIN}])
32322 08:19:16.728838 read(7,  <unfinished ...>
32322 08:19:16.728918 <... read resumed> "\0\0\1\245", 4) = 4
32322 08:19:16.728995 read(7,  <unfinished ...>
32322 08:19:16.729032 <... read resumed> "\0\0\0\6\0\0\1\235MACs stoc: hmac-md5-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64-etm at openssh.com,umac-
128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-ripemd160-etm at op"..., 421) = 421
32322 08:19:16.729115 getpid( <unfinished ...>
32322 08:19:16.729204 <... getpid resumed> ) = 32322
32322 08:19:16.729243 socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0 <unfinished ...>
32322 08:19:16.729298 <... socket resumed> ) = 4
32322 08:19:16.729360 connect(4, {sa_family=AF_UNIX, sun_path="/dev/log"}, 110 <unfinished ...>
32322 08:19:16.729435 <... connect resumed> ) = 0
32322 08:19:16.729521 sendto(4, "<151>May 11 08:19:16 sftpd[32322]: debug2: MACs stoc: hmac-md5-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64-etm at o
penssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-et"..., 466, MSG_NOSIGNAL, NULL, 0 <unfinished ...>
32322 08:19:16.729614 <... sendto resumed> ) = 466
32322 08:19:16.729650 close(4)          = 0
32322 08:19:16.729734 poll([{fd=6, events=POLLIN}, {fd=7, events=POLLIN}], 2, -1) = 2 ([{fd=6, revents=POLLIN}, {fd=7, revents=POLLIN}])
32322 08:19:16.729802 read(7,  <unfinished ...>
32322 08:19:16.729834 <... read resumed> "\0\0\0004", 4) = 4
32322 08:19:16.729867 read(7,  <unfinished ...>
32322 08:19:16.729899 <... read resumed> "\0\0\0\6\0\0\0,compression ctos: none,zlib at openssh.com,zlib", 52) = 52
32322 08:19:16.729976 getpid( <unfinished ...>

> 1)  Do you have a per-client configuration in your sshd_config?
> 	Look for a "Match" block, also in included files.
no

> 2)  Is syslog-ng configured to relay the data? If yes, and using UDP,
> 	some log entries might simply be missing because of congestion.
Yes local syslog-ng filters the relevant debug messages (facility local2) and sends them via UDP to a remote syslog-ng server.