Nota: Esto comenzó como un tutorial de “Cómo depurar”, pero terminó siendo la solución que me ayudó en un servidor Ubuntu 16.04 LTS.
TLDR : Ejecute landscape-sysinfo y compruebe si ese comando tarda mucho en terminar; es la impresión de la información del sistema en un nuevo inicio de sesión SSH. Tenga en cuenta que este comando no está disponible en todos los sistemas, el paquete landscape-common lo instala. (“Pero espere, hay más…”)
Inicie un segundo servidor ssh en otro puerto en la máquina que tiene el problema, hágalo en modo debug, que no lo hará fork e imprimirá mensajes de depuración:
sudo /usr/sbin/sshd -ddd -p 44321
conéctate a ese servidor desde otra máquina en modo verbose:
ssh -vvv -p 44321 username@server
Mi cliente emite las siguientes líneas justo antes de empezar a dormir:
debug1: Entering interactive session.
debug1: pledge: network
Buscar en Google no es realmente útil, pero los registros del servidor son mejores:
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
Me he dado cuenta de que cuando cambio UsePAM yes por UsePAM no se resuelve el problema.
No está relacionado con UseDNS ni con ningún otro ajuste, sólo UsePAM afecta a este problema en mi sistema.
No tengo ni idea de por qué, y tampoco voy a dejar UsePAM en no, porque no sé cuáles son los efectos secundarios, pero esto me permite seguir investigando.
Así que, por favor, no consideres esto como una respuesta, sino como un primer paso para empezar a averiguar lo que está mal.
Así que seguí investigando, y ejecuté sshd con strace (sudo strace /usr/sbin/sshd -ddd -p 44321). Esto dio como resultado lo siguiente:
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 línea /etc/update-motd.d me hizo sospechar, aparentemente el proceso espera el resultado de las cosas que están en /etc/update-motd.d
Así que ejecuté el cd con el /etc/update-motd.d para inhibir a PAM de ejecutar todos los archivos que generan este sudo chmod -x * dinámico, que incluye la carga del sistema y si los paquetes necesitan ser actualizados, y esto resolvió el problema.
Este es un servidor basado en una CPU N3150 “energéticamente eficiente” que tiene mucho trabajo que hacer 24/7, así que creo que recoger todos estos datos motd era demasiado para él.
Puede que empiece a habilitar scripts en esa carpeta de forma selectiva, para ver cuáles son menos dañinos, pero especialmente llamar a Message Of The Day es muy lento, y landscape-sysinfo sí llama a ese comando. Creo que es el que provoca el mayor retraso.
Después de volver a activar la mayoría de los archivos llegué a la conclusión de que50-landscape-sysinfo y 50-landscape-sysinfo eran la causa de mis problemas. 99-esm tardaba unos 5 segundos en ejecutarse y 50-landscape-sysinfo unos 3 segundos. Todos los demás archivos tardaron unos 2 segundos en total.
Ni 99-esm ni 50-landscape-sysinfo son cruciales. 99-esm imprime estadísticas interesantes del sistema (¡y también si tienes poco espacio!), y 50-landscape-sysinfo imprime mensajes relacionados con 99-esm
Finalmente puedes crear un script con Ubuntu Extended Security Maintenance y obtener esa impresión a petición.