LINUX.ORG.RU
решено ФорумAdmin

sshd не запускается с первого раза после перезагрузки

 ,


0

1

При загрузке системы сервис sshd не запускается. Через минуту срабатывает таймаут systemd-юнита, он перезапускает sshd и всё грузится дальше. Отключил всё лишнее, в логах всё равно ничего не вижу. Где можно покопать ещё? Конфиг sshd не менял кроме выставления LogLevel VERBOSE. Из нестандартного - на сервере мало памяти (256 MB), хотя после загрузки потребление 44MB, не думаю, что в этом может быть проблема.

journalctl -u ssh.service
Jul 30 13:13:18 nether systemd[1]: Starting OpenBSD Secure Shell server...
Jul 30 13:14:46 nether systemd[1]: ssh.service: Start-pre operation timed out. Terminating.
Jul 30 13:14:46 nether systemd[1]: ssh.service: Control process exited, code=killed, status=15/TERM
Jul 30 13:14:46 nether systemd[1]: ssh.service: Failed with result 'timeout'.
Jul 30 13:14:46 nether systemd[1]: Failed to start OpenBSD Secure Shell server.
Jul 30 13:14:46 nether systemd[1]: ssh.service: Service RestartSec=100ms expired, scheduling restart.
Jul 30 13:14:46 nether systemd[1]: ssh.service: Scheduled restart job, restart counter is at 1.
Jul 30 13:14:46 nether systemd[1]: Stopped OpenBSD Secure Shell server.
Jul 30 13:14:46 nether systemd[1]: Starting OpenBSD Secure Shell server...
Jul 30 13:15:10 nether sshd[365]: Server listening on 0.0.0.0 port 22.
Jul 30 13:15:10 nether sshd[365]: Server listening on :: port 22.
Jul 30 13:15:10 nether systemd[1]: Started OpenBSD Secure Shell server.
...

Сеть настроена статически:

cat /etc/network/interfaces
root@nether:~# cat /etc/network/interfaces
source /etc/network/interfaces.d/*

auto lo
iface lo inet loopback

iface ens3 inet static
        address 5.8.72.4/24
        gateway 5.8.72.1
        dns-nameservers 185.31.172.240 89.188.29.4

Фаервол отключен.

Также не запускаются с первого раза другие серверы вроде apache2 и тд.

★★★★★

Последнее исправление: Legioner (всего исправлений: 1)

ssh.service: Start-pre operation timed out. Terminating.

Что там в ExecStartPre?

В дефолтном у меня

ExecStartPre=/usr/sbin/sshd -t
-t      Test mode.  Only check the validity of the configuration file and sanity of the keys.  This is useful for updating sshd reliably as configuration options may change.

Может на ключах зависает?

Попробуй таймут покрутить. https://www.freedesktop.org/software/systemd/man/systemd.service.html#Timeout...

Radjah ★★★★★
()
Последнее исправление: Radjah (всего исправлений: 1)
Ответ на: комментарий от Radjah
[Unit]
Description=OpenBSD Secure Shell server
Documentation=man:sshd(8) man:sshd_config(5)
After=network.target auditd.service
ConditionPathExists=!/etc/ssh/sshd_not_to_be_run

[Service]
EnvironmentFile=-/etc/default/ssh
ExecStartPre=/usr/sbin/sshd -t
ExecStart=/usr/sbin/sshd -D $SSHD_OPTS
ExecReload=/usr/sbin/sshd -t
ExecReload=/bin/kill -HUP $MAINPID
KillMode=process
Restart=on-failure
RestartPreventExitStatus=255
Type=notify
RuntimeDirectory=sshd
RuntimeDirectoryMode=0755

[Install]
WantedBy=multi-user.target
Alias=sshd.service

Хотелось бы причину понять, т.к. это со всеми сетевыми демонами происходит, sshd это просто пример. Так-то через минуту-полторы всё грузится, подождать не сложно, просто что-то не так же в системе, раз это происходит.

Legioner ★★★★★
() автор топика
Последнее исправление: Legioner (всего исправлений: 1)
Ответ на: комментарий от Legioner
# systemctl edit ssh.service

И пропиши что-то типа

[Service]
TimeoutStartSec=30s
Может будет успевать раздупляться за это время.

Хотелось бы причину понять

Я так понял, что железка весьма слабенькая, а стартует при загрузке довольно много всего. Демон из-за этого не успевает вовремя отрапортовать, что готов к работе, и init его считает зависшим.

Если ничего не путаю, то «Type=notify» требует, чтобы демон отрапортовал о своей готовности.

Radjah ★★★★★
()
Последнее исправление: Radjah (всего исправлений: 1)

У меня такое было если выставить в конфиге sshd ипку с которой нужно было слушать. Решается на основе зависимостей запуска systemd

Cactus64k
()
Ответ на: комментарий от Radjah

Вряд ли, после таймаута всё моментально рестартует. Железка не слабая, обычный VPS на xeon-е каком-то.

Legioner ★★★★★
() автор топика
Ответ на: комментарий от Legioner
Jul 30 13:13:18 nether systemd[1]: Starting OpenBSD Secure Shell server...
Jul 30 13:14:46 nether systemd[1]: ssh.service: Start-pre operation timed out. Terminating.

88 секунд.

Jul 30 13:14:46 nether systemd[1]: Starting OpenBSD Secure Shell server...
Jul 30 13:15:10 nether sshd[365]: Server listening on 0.0.0.0 port 22.

24 секунды.

Посмотри еще systemd-analize plot > boot.svg. Где-то что-то параллельно хорошо грузит систему.

И тег systemd добавь, а то главный спец не увидит. :)

Cast intelfx

Radjah ★★★★★
()
Ответ на: комментарий от Radjah

Ну вот вывод текущей загрузки с кучкой дополнительных сервисов, которые я отключал для проверки:

-- тут начало загрузки
Jul 30 13:56:42 nether kernel: Linux version 4.19.0-5-amd64 (debian-kernel@lists.debian.org) (gcc version 8.3.0 (Debian 8.3.0-6)) #1 SM
-- всякая фигня ядреная грузится за 2 секунды
Jul 30 13:56:44 nether systemd[1]: Started Login Service.
-- это первая задержка
Jul 30 13:57:13 nether systemd-timesyncd[286]: Synchronized to time server for the first time 45.32.4.67:123 (2.debian.pool.ntp.org).
-- ровно минута после последней записи, пошли рестарты
Jul 30 13:58:13 nether systemd[1]: strongswan-swanctl.service: Start operation timed out. Terminating.
Jul 30 13:58:13 nether systemd[1]: unbound.service: Start-pre operation timed out. Terminating.
Jul 30 13:58:13 nether systemd[1]: ssh.service: Start-pre operation timed out. Terminating.
Jul 30 13:58:13 nether systemd[1]: strongswan-swanctl.service: Main process exited, code=killed, status=15/TERM
Jul 30 13:58:13 nether systemd[1]: strongswan-swanctl.service: Failed with result 'timeout'.
Jul 30 13:58:13 nether systemd[1]: Failed to start strongSwan IPsec IKEv1/IKEv2 daemon using swanctl.
Jul 30 13:58:13 nether systemd[1]: ssh.service: Control process exited, code=killed, status=15/TERM
Jul 30 13:58:13 nether systemd[1]: ssh.service: Failed with result 'timeout'.
Jul 30 13:58:13 nether systemd[1]: Failed to start OpenBSD Secure Shell server.
Jul 30 13:58:13 nether systemd[1]: unbound.service: Control process exited, code=killed, status=15/TERM
Jul 30 13:58:13 nether systemd[1]: unbound.service: Failed with result 'timeout'.
Jul 30 13:58:13 nether systemd[1]: Failed to start Unbound DNS server.
Jul 30 13:58:13 nether systemd[1]: Condition check resulted in Unbound DNS server via resolvconf being skipped.
Jul 30 13:58:13 nether systemd[1]: Reached target Host and Network Name Lookups.
Jul 30 13:58:13 nether systemd[1]: Starting The Apache HTTP Server...
Jul 30 13:58:13 nether systemd[1]: strongswan-swanctl.service: Service RestartSec=100ms expired, scheduling restart.
Jul 30 13:58:13 nether systemd[1]: strongswan-swanctl.service: Scheduled restart job, restart counter is at 1.
Jul 30 13:58:13 nether systemd[1]: ssh.service: Service RestartSec=100ms expired, scheduling restart.
Jul 30 13:58:13 nether systemd[1]: ssh.service: Scheduled restart job, restart counter is at 1.
Jul 30 13:58:13 nether systemd[1]: unbound.service: Service RestartSec=100ms expired, scheduling restart.
Jul 30 13:58:13 nether systemd[1]: unbound.service: Scheduled restart job, restart counter is at 1.
Jul 30 13:58:13 nether systemd[1]: Stopped Unbound DNS server.
Jul 30 13:58:13 nether systemd[1]: Starting Unbound DNS server...
Jul 30 13:58:13 nether systemd[1]: Stopped OpenBSD Secure Shell server.
Jul 30 13:58:13 nether systemd[1]: Starting OpenBSD Secure Shell server...
Jul 30 13:58:13 nether systemd[1]: Stopped strongSwan IPsec IKEv1/IKEv2 daemon using swanctl.
Jul 30 13:58:13 nether systemd[1]: Starting strongSwan IPsec IKEv1/IKEv2 daemon using swanctl...
-- какой-то рандом, может из-за него?
Jul 30 13:58:43 nether kernel: random: crng init done
Jul 30 13:58:43 nether kernel: random: 7 urandom warning(s) missed due to ratelimiting
-- полетело всё шустро
Jul 30 13:58:43 nether systemd[1]: Started The Apache HTTP Server.
Jul 30 13:58:43 nether sshd[387]: Server listening on 0.0.0.0 port 22.
Jul 30 13:58:43 nether sshd[387]: Server listening on :: port 22.
Jul 30 13:58:43 nether systemd[1]: Started OpenBSD Secure Shell server.
Jul 30 13:58:43 nether charon-systemd[379]: loaded 0 RADIUS server configurations
Jul 30 13:58:43 nether kernel: Initializing XFRM netlink socket
Jul 30 13:58:43 nether charon-systemd[379]: HA config misses local/remote address
Jul 30 13:58:43 nether charon-systemd[379]: loaded plugins: charon-systemd aes rc2 sha2 sha1 md5 mgf1 random nonce x509 revocation cons
Jul 30 13:58:43 nether charon-systemd[379]: dropped capabilities, running as uid 0, gid 0
Jul 30 13:58:43 nether charon-systemd[379]: spawning 16 worker threads
Jul 30 13:58:43 nether charon-systemd[379]: loaded certificate 'CN=vbezhenar.com'
Jul 30 13:58:43 nether charon-systemd[379]: loaded certificate 'C=US, O=Let's Encrypt, CN=Let's Encrypt Authority X3'
Jul 30 13:58:43 nether swanctl[463]: no authorities found, 0 unloaded
Jul 30 13:58:43 nether charon-systemd[379]: added vici pool ipv4: 172.23.199.2, 253 entries
Jul 30 13:58:43 nether swanctl[463]: loaded pool 'ipv4'
Jul 30 13:58:43 nether swanctl[463]: successfully loaded 1 pools, 0 unloaded
Jul 30 13:58:43 nether swanctl[463]: loaded connection 'vpn'
Jul 30 13:58:43 nether swanctl[463]: successfully loaded 1 connections, 0 unloaded
Jul 30 13:58:43 nether charon-systemd[379]: added vici connection: vpn
Jul 30 13:58:46 nether package-helper[382]: /var/lib/unbound/root.key has content
Jul 30 13:58:46 nether package-helper[382]: success: the anchor is ok
Jul 30 13:58:46 nether unbound[468]: [468:0] notice: init module 0: iterator
Jul 30 13:58:46 nether systemd[1]: Started Unbound DNS server.
Jul 30 13:58:46 nether systemd[1]: Reached target Multi-User System.
Jul 30 13:58:46 nether systemd[1]: Reached target Graphical Interface.
Jul 30 13:58:46 nether systemd[1]: Starting Update UTMP about System Runlevel Changes...
Jul 30 13:58:46 nether systemd[1]: Condition check resulted in Unbound DNS server via resolvconf being skipped.
Jul 30 13:58:46 nether unbound[468]: [468:0] info: start of service (unbound 1.9.0).
Jul 30 13:58:46 nether systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Jul 30 13:58:46 nether systemd[1]: Started Update UTMP about System Runlevel Changes.
Jul 30 13:58:46 nether systemd[1]: Startup finished in 1.881s (kernel) + 2min 4.982s (userspace) = 2min 6.863s.
-- пошли боты пароль подбирать, в общем всё загружено
Jul 30 13:58:54 nether sshd[471]: Connection from 93.39.116.254 port 44433 on 5.2.72.4 port 22

Есть подозрение, что тут с рандомом что-то не так. Типа нет рандома после загрузки, поэтому висят сервисы. Буду пока в этом направлении курить.

Legioner ★★★★★
() автор топика
Последнее исправление: Legioner (всего исправлений: 1)
Ответ на: комментарий от Legioner

Похоже это оно: https://unix.stackexchange.com/questions/442698/when-i-log-in-it-hangs-until-...

Помогло apt install haveged. Всё теперь грузится за 2 секунды.

Legioner ★★★★★
() автор топика
Последнее исправление: Legioner (всего исправлений: 1)
Ответ на: комментарий от Legioner

Эти две строчки у себя тоже вижу, но зависания в основном были из-за долгого получения настроек сети. До таймаута по запуску ни разу не доходило.

Может энтропии таки хватало на всех.

Radjah ★★★★★
()

SSH и апач пытаются запуститься до того, как поднялась сеть.

network.target не гарантирует поднятие сети: Running Services After the Network is up

Я для себя проблему решил с помощью:

systemctl enable systemd-networkd-wait-online.service

bigbit ★★★★★
()
Ответ на: комментарий от Avial

Нет, дело не в этом. Демоны биндятся на 0.0.0.0, им без разницы, онлайн сеть или нет. Да и странно было бы править дистрибутивные юниты.

Legioner ★★★★★
() автор топика
Последнее исправление: Legioner (всего исправлений: 1)
Ответ на: комментарий от Legioner

systemctl edit имя_юнита делает отдельный файл с переназначениями для юнита.

https://www.freedesktop.org/software/systemd/man/systemd.unit.html Пример 2

Я так всякий самосбор из /opt подкидываю вместо дистрибутивных программ. И юнит не правится, и обновление ничего не ломает, и всякую дичь от мейнтейнеров можно исправлять.

Radjah ★★★★★
()
Ответ на: комментарий от Legioner
-- какой-то рандом, может из-за него?
Jul 30 13:58:43 nether kernel: random: crng init done

Да, 90% из-за него.

https://unix.stackexchange.com/questions/442698/when-i-log-in-it-hangs-until-crng-init-done/442744#442744

Попробуй поставить haveged или rng-tools. А, ты уже починил. Ну да.

intelfx ★★★★★
()
Последнее исправление: intelfx (всего исправлений: 3)
Ответ на: комментарий от Legioner

В настройках виртуалки не стоит получение энтропии от хоста гипервизора, бывает)

FireFighter ★★★
()
Вы не можете добавлять комментарии в эту тему. Тема перемещена в архив.