Bug 30248

Summary: Не всегда запускаются сервисы
Product: Sisyphus Reporter: serpiph <serpiph>
Component: systemdAssignee: Alexey Shabalin <shaba>
Status: RESOLVED LATER QA Contact: qa-sisyphus
Severity: normal    
Priority: P3 CC: arseny, evg, shaba
Version: unstable   
Hardware: all   
OS: Linux   

Description serpiph 2014-08-25 21:47:25 MSK
Есть сервис vixie-cron, который должен запускаться при каждом запуске. Однако, просматривая логи, заметил, что старт сервиса происходит не всегда:
июн 29 21:21:12 server systemd[1]: Starting Vixie Cron Daemon...
июн 29 21:21:12 server systemd[1]: Started Vixie Cron Daemon.
июл 16 01:02:12 server systemd[1]: Stopping Vixie Cron Daemon...
июл 16 01:02:12 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
июл 16 03:24:37 server systemd[1]: Starting Vixie Cron Daemon...
июл 16 03:24:37 server systemd[1]: Started Vixie Cron Daemon.
июл 16 20:47:26 server systemd[1]: Stopping Vixie Cron Daemon...
июл 16 20:47:26 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
июл 17 01:13:14 server systemd[1]: Starting Vixie Cron Daemon...
июл 17 01:13:14 server systemd[1]: Started Vixie Cron Daemon.
июл 19 10:23:21 server systemd[1]: Stopping Vixie Cron Daemon...
июл 19 10:23:21 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
июл 28 23:27:19 server systemd[1]: Stopping Vixie Cron Daemon...
июл 28 23:27:19 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
июл 31 01:41:42 server systemd[1]: Stopping Vixie Cron Daemon...
июл 31 01:41:42 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
авг 02 14:32:06 server systemd[1]: Stopping Vixie Cron Daemon...
авг 02 14:32:06 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
авг 03 23:16:05 server systemd[1]: Stopping Vixie Cron Daemon...
авг 03 23:16:05 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
авг 06 19:32:49 server systemd[1]: Stopping Vixie Cron Daemon...
авг 06 19:32:49 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
авг 06 20:14:30 server systemd[1]: Starting Vixie Cron Daemon...
авг 06 20:14:30 server systemd[1]: Started Vixie Cron Daemon.
авг 21 09:03:36 server systemd[1]: Stopping Vixie Cron Daemon...
авг 21 09:03:36 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
авг 21 11:42:26 server systemd[1]: Starting Vixie Cron Daemon...
авг 21 11:42:26 server systemd[1]: Started Vixie Cron Daemon.
авг 23 09:26:36 server systemd[1]: Stopping Vixie Cron Daemon...
авг 23 09:26:36 server systemd[1]: Stopped Vixie Cron Daemon.
-- Reboot --
авг 23 18:34:09 server systemd[1]: Starting Vixie Cron Daemon...
авг 23 18:34:09 server systemd[1]: Started Vixie Cron Daemon.

Как видно, в некоторых случаях нет старта, а есть только останов. Демон никогда мною не выключался (всегда enabled). Я сначала грешил на логи и journald, но когда не отработали скрипты под crond в нужное время, подозрение упало на systemd, что именно сам демон лишь сымитировал запуск crond без реального запуска (иначе как бы он пытался остановить незапущенного демона?). Просьба внимательно это проверить.
Comment 1 Alexey Shabalin 2015-07-23 13:53:25 MSK
Вопрос с cron надо решать другим способом. В systemd есть функционал cron, надо переносить настройки на родные для systemd и совсем избавиться от cron.
Есть другие сервисы, которые не стартуют?
Comment 2 serpiph 2015-08-03 09:41:20 MSK
А как быть с функционалом anacron?
Comment 3 Evgenii Terechkov 2015-08-03 10:24:36 MSK
Ну да, с журналом что-то не то. Тоже нашел у себя за последний месяц одну запись об остановке без соответствующей записи о старте (обратное было бы вполне понятно: жесткие перезагрузки). Но не факт, что крон не стартует, я вот проблем с ним не заметил, хотя активно пользуюсь крон-задачами.

Насколько знаю, systemd не умеет "имитировать" запуск сервиса. Если сервис административно включен, но по факту оказывается не запущен, то надо смотреть systemctl status crond.service и логи/журнал на предмет проблем.

2shaba: это, воля ваша, слишком уж круто придумано - все планировщики заменять на systemd. Как минимум, это legacy за много десятков лет, который никто менять не будет, это должно работать. Не нужно дискриминировать юниты по признаку "а уж не планировщик ли ты часом?" :-)
Comment 4 serpiph 2015-08-03 10:38:53 MSK
(В ответ на комментарий №3)
> Ну да, с журналом что-то не то. Тоже нашел у себя за последний месяц одну
> запись об остановке без соответствующей записи о старте (обратное было бы
> вполне понятно: жесткие перезагрузки). Но не факт, что крон не стартует, я вот
> проблем с ним не заметил, хотя активно пользуюсь крон-задачами.

Мне, например, непонятно, как вызвать из журнала что происходило при старте юнита. Так, при вызове команды

$ systemctl status <unit>

Я вижу строки о том, что происходило при старте юнита (диагностика, ошибки запуска и т.д.). journalctl такой информации не предоставляет (или я просто не умею его готовить?). При старте системы невозможно (в отличии от старого доброго syslog) разобраться в порядке выполнения команд, так как постоянно визжу сообщения о пропущенных сообщениях, причём их так много, что половина логов - это эти странные сообщения. Почему у syslog ничего не терялось, а у journald постоянно что-то теряется?

> Насколько знаю, systemd не умеет "имитировать" запуск сервиса. Если сервис
> административно включен, но по факту оказывается не запущен, то надо смотреть
> systemctl status crond.service и логи/журнал на предмет проблем.

А как быть, если это обнаружилось не сразу и необходимо зарыться в предыдущие запуски? journalctl ничего не отдаёт.

> 2shaba: это, воля ваша, слишком уж круто придумано - все планировщики заменять
> на systemd. Как минимум, это legacy за много десятков лет, который никто менять
> не будет, это должно работать. Не нужно дискриминировать юниты по признаку "а
> уж не планировщик ли ты часом?" :-)

Согласен, не надо смешивать одно с другим. И так на systemd навешено слишком много работы. Скоро вся система будет один сплошной systemd. Всегда сознательное и разумное дробление операций было огромным плюсом Unix, сейчас всё смешали в одном месте.
Comment 5 Evgenii Terechkov 2015-08-03 11:10:48 MSK
Я так понимаю, никакого жесткого порядка запуска нет и не будет, race condition by design :-)

Например, вышеупомянутую запись о стопе без записи о старте я нашел выполнив команду "journalctl -u crond|egrep -i '(start|stop|reboot)' |less -i". "journalctl -u crond" выдаёт точно ту же информацию, что и хвост вывода "systemctl status crond.service". Плюс пишет в каком состоянии юнит (голова того же вывода).

Если в журнале ничего нет, возможно стоит поискать в логе самого крона (или куда его сообщения syslog шлёт).

Я везде использую journal+rsyslog, проблем не замечал.
Comment 6 serpiph 2015-08-03 11:26:32 MSK
(В ответ на комментарий №5)
> Я так понимаю, никакого жесткого порядка запуска нет и не будет, race condition
> by design :-)

Не в плане порядка, в плане того, что вместо строчек логов вижу часто лишь

$ journalctl -b
...
авг 03 08:55:05 comp systemd-journal[350]: Missed 13 kernel messages
...
$

Вот какие 13 сообщений он потерял? И это не единожды! Этих потерь порой доходит до сотни. Разбираться в таких логах невозможно. Кстати, методом проб и ошибок обнаружил, что одна из ошибок запуска юнита скрывалась в одном из таких "missed". Зла уже не хватает! 

> Например, вышеупомянутую запись о стопе без записи о старте я нашел выполнив
> команду "journalctl -u crond|egrep -i '(start|stop|reboot)' |less -i".
> "journalctl -u crond" выдаёт точно ту же информацию, что и хвост вывода
> "systemctl status crond.service". Плюс пишет в каком состоянии юнит (голова
> того же вывода).

Резюмируя сказанное, journalctl не показал никаких ошибок запуска crond, даже не написал, что то-то стартовал вообще (команда "journalctl -u crond").

> Если в журнале ничего нет, возможно стоит поискать в логе самого крона (или
> куда его сообщения syslog шлёт).

Пусто, ноль без палочки.

> Я везде использую journal+rsyslog, проблем не замечал.

В том и дело, что часто изменяющееся поведение journald приводит иногда к неработоспособности этой связки. Например, банально не дублирует сообщения в каналы syslog.
Comment 7 Alexey Shabalin 2015-08-10 18:30:36 MSK
(В ответ на комментарий №3)
> 2shaba: это, воля ваша, слишком уж круто придумано - все планировщики заменять
> на systemd. Как минимум, это legacy за много десятков лет, который никто менять
> не будет, это должно работать. Не нужно дискриминировать юниты по признаку "а
> уж не планировщик ли ты часом?" :-)

это не моя воля :) это планы апстрима systemd.
Тут ситуация примерно такая же, как и с syslog: в systemd есть journald, и можно обойтись без какого-либо отдельного syslog.
Так же и с cron, в systemd есть его функционал и можно обойтись без отдельного cron. При этом никто не мешает установить отдельно ни syslog, ни cron.
Для поддержки legacy cron, я знаю как минимум 3 генератора для systemd(автоматических конверторов crontab в юниты systemd):
1) crontab-generator (на си)
http://lists.freedesktop.org/archives/systemd-devel/2013-August/012591.html
2) systemd-cron (на python)
https://github.com/systemd-cron/systemd-cron
3) systemd-cron-next (на rust)
https://github.com/systemd-cron/systemd-cron-next

Тянуть в базовую систему rust или python мне не хочется, а реализацию на си в апстрим не приняли. Вот ответ:
http://lists.freedesktop.org/archives/systemd-devel/2013-September/013120.html
Предполагается что в дистрибутиве не так много пакетов, использующих cron и их легко перевести на таймеры systemd.
Например, вот статья, как самому заменить cron.
http://blog.higgsboson.tk/2013/06/09/use-systemd-as-a-cron-replacement/