Nota: Questo è iniziato come un “Come fare il debug”, tutorial, ma ha finito per essere la soluzione che mi ha aiutato su un server Ubuntu 16.04 LTS.
TLDR : Eseguite landscape-sysinfo e controllate se questo comando impiega molto tempo a finire; è la stampa delle informazioni di sistema su un nuovo login SSH. Notate che questo comando non è disponibile su tutti i sistemi, il pacchetto landscape-common lo installa. (“Ma aspetta, c'è di più…”)
Avvia un secondo server ssh su un'altra porta sulla macchina che ha il problema, fallo in modalità debug, che non lo farà biforcare e stamperà messaggi di debug:
sudo /usr/sbin/sshd -ddd -p 44321
connettersi a quel server da un'altra macchina in modalità verbose:
ssh -vvv -p 44321 username@server
Il mio client emette le seguenti linee proprio prima di iniziare a dormire:
debug1: Entering interactive session.
debug1: pledge: network
Googlando questo non è molto utile, ma i log del server sono migliori:
debug3: mm_send_keystate: Finished sending state [preauth]
debug1: monitor_read_log: child log fd closed
debug1: PAM: establishing credentials
debug3: PAM: opening session
---- Pauses here ----
debug3: PAM: sshpam_store_conv called with 1 messages
User child is on pid 28051
Ho notato che quando cambio UsePAM yes con UsePAM no allora questo problema si risolve.
Non è legato a UseDNS o a qualsiasi altra impostazione, solo UsePAM influisce su questo problema sul mio sistema.
Non ho idea del perché, e non lascio nemmeno UsePAM a no, perché non so quali siano gli effetti collaterali, ma questo mi permette di continuare a indagare.
Quindi per favore non consideratela una risposta, ma un primo passo per iniziare a scoprire cosa c'è di sbagliato.
Quindi ho continuato a indagare, e ho eseguito sshd con strace (sudo strace /usr/sbin/sshd -ddd -p 44321). Questo ha dato il seguente risultato:
sendto(4, "<87>Nov 20 20:35:21 sshd[2234]: "..., 110, MSG_NOSIGNAL, NULL, 0) = 110
close(5) = 0
stat("/etc/update-motd.d", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
umask(022) = 02
rt_sigaction(SIGINT, {SIG_IGN, [], SA_RESTORER, 0x7f15dce784b0}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_IGN, [], SA_RESTORER, 0x7f15dce784b0}, {SIG_DFL, [], 0}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
clone(child_stack=0, flags=CLONE_PARENT_SETTID|SIGCHLD, parent_tidptr=0x7ffde6152d2c) = 2385
wait4(2385, # BLOCKS RIGHT HERE, BEFORE THE REST IS PRINTED OUT # [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 2385
La linea /etc/update-motd.d mi ha insospettito, apparentemente il processo aspetta il risultato della roba che è in /etc/update-motd.d
Così ho fatto cd in /etc/update-motd.d e ho eseguito un sudo chmod -x * per inibire a PAM di eseguire tutti i file che generano questo Message Of The Day dinamico, che include il carico di sistema e se i pacchetti devono essere aggiornati, e questo ha risolto il problema.
Questo è un server basato su una CPU N3150 “ad alta efficienza energetica” che ha un sacco di lavoro da fare 24/7, quindi penso che raccogliere tutti questi motd-data fosse troppo per lui.
potrei iniziare ad abilitare gli script in quella cartella in modo selettivo, per vedere quali sono meno dannosi, ma in particolare chiamare landscape-sysinfo è molto lento, e 50-landscape-sysinfo chiama proprio quel comando. Penso che sia quello che causa il maggior ritardo.
Dopo aver riabilitato la maggior parte dei file sono giunto alla conclusione che50-landscape-sysinfo e 99-esm erano la causa dei miei problemi. 50-landscape-sysinfo ha impiegato circa 5 secondi per essere eseguito e 99-esm circa 3 secondi. Tutti i file rimanenti circa 2 secondi in tutto.
Né 50-landscape-sysinfo né 99-esm sono cruciali. 50-landscape-sysinfo stampa interessanti statistiche di sistema (e anche se hai poco spazio!), e 99-esm stampa messaggi relativi a Ubuntu Extended Security Maintenance
Infine puoi creare uno script con echo '/usr/bin/landscape-sysinfo' > info.sh && chmod +x info.sh e ottenere quella stampa su richiesta.