Примечание: Это началось как “Как отлаживать”, учебник, но закончилось тем, что решение, которое помогло мне на сервере LTS Ubuntu 16.04.
TLDR : Запустите landscape-sysinfo и проверьте, не занимает ли эта команда много времени; это распечатка системной информации при новом входе в SSH. Обратите внимание, что эта команда доступна не на всех системах, пакет landscape-common устанавливает ее. (“But wait, there’s more…”)
Запустите второй сервер ssh на другом порту на машине, на которой есть проблема, сделайте это в отладочном режиме, который не сделает его вилкой и распечатает отладочные сообщения:
sudo /usr/sbin/sshd -ddd -p 44321
подключитесь к этому серверу с другой машины в подробном режиме:
ssh -vvv -p 44321 username@server
Мой клиент выводит следующие строки прямо перед началом сна:
debug1: Entering interactive session.
debug1: pledge: network
Googleling, что не очень полезно, но логи сервера лучше:
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
Я заметил, что когда я меняю UsePAM yes на UsePAM no, то эта проблема решается.
Не связанная с UseDNS или какими-либо другими параметрами, только UsePAM влияет на эту проблему в моей системе.
я понятия не имею, почему, и я также не оставляю UsePAM на no, потому что я не знаю, какие побочные эффекты, но это позволяет мне продолжить исследование.
Так что, пожалуйста, не считайте это ответом, а первым шагом к тому, чтобы начать выяснять, что не так.
Так что я продолжил расследование, и запустил sshd с strace (sudo strace /usr/sbin/sshd -ddd -p 44321). Это привело к следующему:
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
Строка /etc/update-motd.d вызывала у меня подозрения, очевидно, что процесс ждет результата, который есть в /etc/update-motd.d
Так что я cd вошёл в /etc/update-motd.d и запустил sudo chmod -x *, чтобы запретить PAM запускать все файлы, которые генерируют этот динамический Message Of The Day, который включает в себя загрузку системы, и если пакеты нужно обновить, то это решило проблему.
Это сервер, основанный на “энергоэффективном” процессоре N3150, которому предстоит много работы 24 часа в сутки 7 дней в неделю, поэтому я думаю, что сбор всех этих motd-данных был просто слишком большим для него.
Я могу начать выборочно включать скрипты в этой папке, чтобы посмотреть, какие из них менее вредны, но особенно вызов landscape-sysinfo очень медленный, и 50-landscape-sysinfo действительно вызывает эту команду. Я думаю, что именно это и вызывает наибольшую задержку.
После перезагрузки большинства файлов я пришел к выводу, что 50-landscape-sysinfo и 99-esm были причиной моих проблем. Выполнение 50-landscape-sysinfo заняло около 5 секунд, а 99-esm около 3 секунд. Все остальные файлы в сумме заняли около 2 секунд.
Ни 50-landscape-sysinfo, ни 99-esm не являются решающими. 50-landscape-sysinfo печатает интересную системную статистику (а также, если у вас мало места!), и 99-esm печатает сообщения, связанные с Ubuntu Extended Security Maintenance
Наконец, вы можете создать скрипт с echo '/usr/bin/landscape-sysinfo' > info.sh && chmod +x info.sh и получить эту распечатку по запросу.