Opmerking: Dit begon als een “Hoe te debuggen”, tutorial, maar eindigde als de oplossing die me hielp op een Ubuntu 16.04 LTS server.
TLDR : Voer landscape-sysinfo
uit en controleer of het lang duurt voordat dat commando klaar is; het is de systeeminformatie die wordt afgedrukt bij een nieuwe SSH login. Merk op dat dit commando niet op alle systemen beschikbaar is, het landscape-common
pakket installeert het. (“Maar wacht, er is meer…”)
Start een tweede ssh server op een andere poort op de machine die het probleem heeft, doe dit in debug mode, waardoor het niet fork en debug boodschappen zal uitdraaien:
sudo /usr/sbin/sshd -ddd -p 44321
maak verbinding met die server vanaf een andere machine in verbose mode:
ssh -vvv -p 44321 username@server
Mijn client geeft de volgende regels af vlak voordat hij begint te slapen:
debug1: Entering interactive session.
debug1: pledge: network
Googlen helpt niet echt, maar de serverlogs zijn beter:
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
Ik heb gemerkt dat als ik UsePAM yes
verander in UsePAM no
dan is dit probleem opgelost.
Niet gerelateerd aan UseDNS
of een andere instelling, alleen UsePAM
heeft invloed op dit probleem op mijn systeem.
Ik heb geen idee waarom, en ik laat UsePAM
ook niet op no
staan, omdat ik niet weet wat de neveneffecten zijn, maar dit laat me verder onderzoek doen.
Dus beschouw dit alstublieft niet als een antwoord, maar als een eerste stap om uit te zoeken wat er mis is.
Dus ging ik verder met het onderzoek, en liep sshd
met strace
(sudo strace /usr/sbin/sshd -ddd -p 44321
). Dit leverde het volgende op:
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
De regel /etc/update-motd.d
maakte me achterdochtig, blijkbaar wacht het proces op het resultaat van de dingen die in /etc/update-motd.d
staan, dus ik cd
‘d in /etc/update-motd.d
en liep een sudo chmod -x *
om PAM te remmen om alle bestanden uit te voeren die deze dynamische Message Of The Day
genereren, waaronder systeembelasting en of pakketten geüpgrade moeten worden, en dit loste het probleem op.
Dit is een server gebaseerd op een “energiezuinige” N3150 CPU die 24/7 veel werk te doen heeft, dus ik denk dat het verzamelen van al deze motd-data gewoon te veel was voor hem.
Ik ga misschien selectief scripts in die map aanzetten, om te zien welke minder schadelijk zijn, maar speciaal het aanroepen van landscape-sysinfo
is erg traag, en 50-landscape-sysinfo
roept dat commando wel aan. Ik denk dat dat degene is die de grootste vertraging veroorzaakt.
Na het opnieuw aanroepen van de meeste bestanden kwam ik tot de conclusie dat50-landscape-sysinfo
en 99-esm
de oorzaak van mijn problemen waren. 50-landscape-sysinfo
deed er ongeveer 5 seconden over om uit te voeren en 99-esm
ongeveer 3 seconden. Alle andere bestanden samen ongeveer 2 seconden.
Noch 50-landscape-sysinfo
en 99-esm
zijn cruciaal. 50-landscape-sysinfo
drukt interessante systeem statistieken af (en ook als je weinig ruimte hebt!), en 99-esm
drukt berichten af die gerelateerd zijn aan Ubuntu Extended Security Maintenance
Tenslotte kun je een script maken met echo '/usr/bin/landscape-sysinfo' > info.sh && chmod +x info.sh
en die afdruk op verzoek krijgen.