Dotaz: sshd neloguje ip adresu

[hajoucha]

Ahojda,

nedaří se mi donutit sshd, aby logoval ip adresy pokoušející se o připojení. Jde o archlinux s OpenSSH_8.2p1, OpenSSL 1.1.1g 21 Apr 2020.

V logu (journalctl -b -u sshd) je pouze:

May 12 08:41:57 stroj sshd[5093]: error: kex_exchange_identification: Connection closed by remote host
May 12 08:42:00 stroj sshd[5094]: error: Could not get shadow information for NOUSER
May 12 09:20:55 stroj sshd[30969]: error: kex_exchange_identification: Connection closed by remote host
May 12 09:21:00 stroj sshd[30977]: error: Could not get shadow information for NOUSER
May 12 09:38:47 stroj sshd[34423]: error: kex_exchange_identification: Connection closed by remote host
May 12 09:38:50 stroj sshd[34431]: error: Could not get shadow information for NOUSER
May 12 09:50:03 stroj sshd[36653]: error: kex_exchange_identification: Connection closed by remote host
May 12 09:50:06 stroj sshd[36663]: error: Could not get shadow information for NOUSER
May 12 10:13:57 stroj sshd[60015]: error: kex_exchange_identification: Connection closed by remote host
May 12 10:14:01 stroj sshd[60023]: error: Could not get shadow information for NOUSER

A to i přesto, že mám v /etc/ssh/sshd_config mj. toto:

LogLevel DEBUG2
UsePAM no
AllowUsers pavel

Ostatní direktivy mi připadají pro tento problém irelevantní.

Proč nejsou v logu ip adresy strojů, ze kterých přichází příslušné spojení? Nemohou být na vině iptables ? Ale i pak by sshd měl vědět více ne?

Odpovědi

[Aleš Kapica]

Pod jakým uživatelem čumíš do toho logu?

[hajoucha]

jako root.

[hajoucha]

pro zajímavost jsem to vyzkoušel jako běžný uživatel (journalctl -b -u sshd) a ukazuje mi to přesně to samé…

[Aleš Kapica]

A neměl bys spíš než sshd hledat jenom ssh?

[hajoucha]

nene, v tom to nebude. Není to o vyhledávání. Ono se to do journalu ani nezapíše. Prostě tam ta informace vůbec není.

Když změním v sshd_config direktivu UsePAM na

UsePAM yes

Tak jsou pak výpisy např. takto:

May 11 00:14:34 stroj sshd[1215385]: error: kex_exchange_identification: Connection closed by remote host
May 11 00:14:37 stroj sshd[1215431]: pam_tally2(sshd:auth): pam_get_uid; no such user
May 11 00:14:37 stroj sshd[1215431]: pam_unix(sshd:auth): check pass; user unknown
May 11 00:14:37 stroj sshd[1215431]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=189.133.146.57
May 11 02:58:05 stroj sshd[1461080]: error: kex_exchange_identification: Connection closed by remote host
May 11 02:58:10 stroj sshd[1461149]: pam_tally2(sshd:auth): pam_get_uid; no such user
May 11 02:58:10 stroj sshd[1461149]: pam_unix(sshd:auth): check pass; user unknown
May 11 02:58:10 stroj sshd[1461149]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=115.79.212.170

[Josef Kufner]

Ten log se buď zobrazí, nebo nezobrazí. Ukazovat bude pro všechny uživatele to samé.

[hajoucha]

dodávám, že iptables na vině nejsou, protože stejné (tj. bez ip adresy) výpisy dostanu po iptables -F INPUT. Problém musí být jinde.

[Josef Kufner]

Moje logy od sshd vypadají takto:

$ journalctl | grep 'sshd\[6407\]'
kvě 12 15:13:39 server sshd[6407]: Connection from YY.YY.YY.YY port 10746 on XX.XX.XX.XX port 22
kvě 12 15:13:43 server sshd[6407]: Postponed keyboard-interactive for root from YY.YY.YY.YY port 10746 ssh2 [preauth]
kvě 12 15:13:46 server sshd[6407]: error: PAM: Authentication failure for root from YY.YY.YY.YY
kvě 12 15:13:46 server sshd[6407]: Failed keyboard-interactive/pam for root from YY.YY.YY.YY port 10746 ssh2

Ten první řádek tam opravdu nemáš?

Můj config vypadá takto:

# grep -i log /etc/ssh/sshd_config
SyslogFacility AUTH
LogLevel VERBOSE
...

[hajoucha]

Opravdu nemám. Ten výpis výše je kompletní přesně jak to dostanu tím uvedeným příkazem. Nic navíc tam není. V konfiguráku mám:

# SyslogFacility AUTH

Ale AUTH je podle man sshd_config defaultní hodnota.

Zkusil jsem to změnit na DAEMON. V manu není co to znamená,ale je tam, že to je povolená hodnota.

[Josef Kufner]

Pak mne ještě napadá jedna věc, která by mohla mít vliv. Jak sshd spouštíš? Může běžet jako samostatný démon, nebo přes inetd a nebo přes socket activation. Pokud se spouští přes inetd, tak tam může chybět to navázání spojení, protože to zajišťuje inetd a sshd pak dostane už navázané spojení na stdin/out.

[hajoucha]

tady docela tápu, jestli se nepletu, tak jsem to udělal tak, že jsem stáhnul openssh balíček a následně zadal systemctl enable sshd. Počítám, že to znamená, že sshd běží jako samostatný démon, ne? Jak to zjistím?

 # systemctl status sshd
● sshd.service - OpenSSH Daemon
     Loaded: loaded (/usr/lib/systemd/system/sshd.service; enabled; vendor preset: disabled)
     Active: active (running) since Tue 2020-05-12 08:31:33 CEST; 8h ago
   Main PID: 514 (sshd)
      Tasks: 20 (limit: 19152)
     Memory: 1.0G
     CGroup: /system.slice/sshd.service
             ├─   514 sshd: /usr/bin/sshd -D [listener] 0 of 10-100 startups

…

[Josef Kufner]

Takto ti běží jako samostatný démon, který poslouchá na portu 22, takže by to mělo fungovat tak, jak očekáváš.

[hajoucha]

Tak změna na SyslogFacility DAEMON nepomohla. Log vypadá stejně.

[j]

iptables s tim nic mit nemuzou ani teoreticky ... zato ta lennartovo jebka kterou pouzivas.

Normalni logy sshcka jsou mimo jinyho popsany trebas https://en.wikibooks.org/wiki/OpenSSH/Logging_and_Troubleshooting ... a ipcka jsou tam vzdy, pokud to dava smysl. Pri pokusu o login heslem tam uvidis IP + usera.

Jinak to zkus pustit rovnou z radky = ne jako servisu.

Nejak tak: sshd -p 22 -D -d -e

=> debug, zapis na standardni vystup, bez odpojeni konzole.

[hajoucha]

ok, díky, vyzkouším, ale nejdříve zítra, až budu u té mašiny fyzicky, abych si „pod sebou neuříznul větev“.

[hajoucha]

Tak jsem to zkusil - pustil jsem sshd a následně se pokusil přihlásit z jiného stroje jako neexistující uživatel „prase“:

stroj ~ :( # /usr/bin/sshd -p 22 -D -d -e                                                                                                                               
/etc/ssh/sshd_config line 115: Deprecated option UsePrivilegeSeparation                                                                                                
debug1: sshd version OpenSSH_8.2, OpenSSL 1.1.1g  21 Apr 2020                                                                                                          
debug1: private host key #0: ssh-rsa SHA256:XXXXXXXXXXXX
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:XXXXXXXXXXXXX
debug1: private host key #2: ssh-ed25519 SHA256:XXXXXXXXXXXX
debug1: rexec_argv[0]='/usr/bin/sshd' 
debug1: rexec_argv[1]='-p' 
debug1: rexec_argv[2]='22'
debug1: rexec_argv[3]='-D'
debug1: rexec_argv[4]='-d'
debug1: rexec_argv[5]='-e'
debug1: Set /proc/self/oom_score_adj from 0 to -1000
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 4 out 4 newsock 4 pipe -1 sock 7                                           
rexec line 115: Deprecated option UsePrivilegeSeparation
debug1: sshd version OpenSSH_8.2, OpenSSL 1.1.1g  21 Apr 2020
debug1: private host key #0: ssh-rsa SHA256:XXXXXXXXXXXX
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:XXXXXXXXXXX
debug1: private host key #2: ssh-ed25519 SHA256:XXXXXXXXXXX
debug1: inetd sockets after dupping: 3, 3
Connection from xxx.xxx.xxx.xxx port 46812 on yyy.yyy.yyy.yyy port 22 rdomain ""
debug1: Local version string SSH-2.0-OpenSSH_8.2
debug1: Remote protocol version 2.0, remote software version OpenSSH_8.1
debug1: match: OpenSSH_8.1 pat OpenSSH* compat 0x04000000
debug1: permanently_set_uid: 99/99 [preauth]
debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth] 
debug1: kex: algorithm: curve25519-sha256 [preauth]
debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: \implicit\ compression:mo none [preauth]
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: \implicit\ compression: none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug1: rekey out after 134217728 blocks [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: Sending SSH2_MSG_EXT_INFO [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug1: rekey in after 134217728 blocks [preauth] 
debug1: KEX done [preauth]
debug1: userauth-request for user prase service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
Invalid user prase from xxx.xxx.xxx.xxx port 46812
debug1: userauth-request for user prase service ssh-connection method password [preauth]
debug1: attempt 1 failures 0 [preauth]
Could not get shadow information for NOUSER
Failed password for invalid user prase from xxx.xxx.xxx.xxx port 46812 ssh2
debug1: userauth-request for user prase service ssh-connection method password [preauth]
debug1: attempt 2 failures 1 [preauth]
Failed password for invalid user prase from xxx.xxx.xxx.xxx port 46812 ssh2
debug1: userauth-request for user prase service ssh-connection method password [preauth]  
debug1: attempt 3 failures 2 [preauth]
Failed password for invalid user prase from xxx.xxx.xxx.xxx port 46812 ssh2
maximum authentication attempts exceeded for invalid user prase from xxx.xxx.xxx.xxx port 46812mo ssh2 [preauth]
Disconnecting invalid user prase xxx.xxx.xxx.xxx port 46812: Too many authentication failures [preauth]
debug1: do_cleanup [preauth]
debug1: monitor_read_log: child log fd closed
debug1: do_cleanup
debug1: Killing privsep child 891654
stroj ~ :( # 

Akorát jsem ip změnil na xxx.xxx… a yyy.yyy… a ještě <> u implicit za \implicit\ kvůli html editoru. Dle mého názoru to vypadá normálně…

[Josef Kufner]

...
Server listening on 0.0.0.0 port 22.
...
Connection from xxx.xxx.xxx.xxx port 46812 on yyy.yyy.yyy.yyy port 22 rdomain ""
...
Disconnecting invalid user prase xxx.xxx.xxx.xxx port 46812: Too many authentication failures [preauth]
...

To vypadá dobře.

[hajoucha]

hm, takže chyba bude v nastavení logování systemd/journal ?