Неправильная дата в сообщении при запуске

Содержание

Вопрос или проблема
Ответ или решение
Ошибка времени в сообщении при запуске
Описание проблемы
Анализ проблемы
Решение проблемы
Заключение

Вопрос или проблема

У меня есть сервер A, который отправляет сообщение syslog на демон rsyslog другого сервера B всякий раз, когда он (A) запускается. Для этого я добавил в crontab корневого пользователя директиву, подобную следующей:

@reboot logger -T -n [SERVERB_IPADDR] -P [SERVERB_PORT] "Сервер A $(date) запустился"

Это работает, сообщение появляется в rsyslog сервера B. (На сервере B была проведена значительная конфигурация, чтобы он слушал этот конкретный TCP порт, но это не имеет значения здесь.) Однако я заметил, что дата совершенно неверная. Сегодня сообщение было

Сервер A Thu 8 Aug 2024 16:51:50 CEST запустился

Чтобы устранить эту проблему, я еще раз перезагрузил Сервер A, и теперь дата была

Сервер A Thu 8 Aug 2024 16:51:54 CEST запустился

Выпало всего 4 секунды. Конечно, ручной запуск команды logger выдает правильную дату. Что здесь не так? Как мне это исправить? Сервер A работает на Raspberry Pi, может ли быть так, что часы не полностью инициализированы в момент, когда cron запускается?

Оба сервера работают на Ubuntu Server, A на Ubuntu 24.04.1 LTS, B на Ubuntu 22.04.5 LTS.

Редактирование: оказывается, что часы на этой системе неверны в момент отправки стартового сообщения. Добавление sleep 60 && перед командой logger отправляет сообщение на 60 секунд позже, но с правильной временной меткой, на сервер rsyslog. Спасибо @terdon за предложение.

Я считаю это ошибкой: во время перезагрузки любые команды, введенные в crontab, по-видимому, не могут полагаться на внутренние часы.

Оказывается, что часы неверны в момент отправки сообщения журнала. Есть соответствующая строка в локальном /var/log/syslog:

2024-08-08T16:52:01.461191+02:00 serverA systemd[1]: Запущен cron.service - демон обработки фоновых программ.
(...)
2024-08-08T16:52:02.276312+02:00 serverA CRON[1005]: (root) CMD (logger -T.. и т.д.)

Обратите внимание на неверную дату. Это может быть характерно для этого оборудования (Raspberry Pi). Так что урок из этого должен быть: не полагайтесь на системное время в ваших командах @reboot в crontab.

На самом деле, у меня работает NTP на этом сервере. Он запускается немного раньше, чем cron. При этом часы все еще показывают 8 августа. Затем NTP отправляет различные запросы на серверы времени. Полсекунды спустя часы были установлены на правильную дату, но к тому времени cron уже отправил свое сообщение журнала с неправильным временем.

Ответ или решение

Ошибка времени в сообщении при запуске

Описание проблемы

В данной ситуации сервер A (который использует Raspberry Pi и работает под управлением Ubuntu 24.04.1 LTS) отправляет сообщение в системный лог сервера B при каждом своем запуске. Для этого в crontab пользователя root на сервере A установлен следующий параметр:

@reboot logger -T -n [SERVERB_IPADDR] -P [SERVERB_PORT] "Сервер A $(date) запущен"

Хотя эта команда работает корректно и сообщение появляется в rsyslog сервера B (Ubuntu 22.04.5 LTS), дата и время в сообщении оказались неправильными. При этом, если вручную выполнить команду logger, выводится корректная текущая дата.

Анализ проблемы

Проблема заключается в том, что к моменту вызова команды logger time (с помощью $(date)) системные часы ещё не синхронизированы и показывают неправильное время. Из логов /var/log/syslog видно, что служба cron стартует до того, как NTP (Network Time Protocol) успевает настроить системное время. Следовательно, cron выполняет запланированную команду, которая использует неправильное время.

Решение проблемы

Для решения данной проблемы можно использовать следующие подходы:

Добавление задержки: Как показано в вашем редактировании, добавление команды sleep перед вызовом logger позволяет подождать, пока NTP синхронизирует время.
```
@reboot sleep 60 && logger -T -n [SERVERB_IPADDR] -P [SERVERB_PORT] "Сервер A $(date) запущен"
```
Это позволяет ждать 60 секунд, что дает достаточно времени для корректной инициализации системного времени.
Использование другого механизма инициализации: Вместо использования cron для запуска команд при перезагрузке, можно рассмотреть возможность добавления пользовательского скрипта в систему инициализации через systemd. Это позволит вам более точно контролировать порядок запуска служб и обеспечить выполнение ваших команд только после того, как NTP полностью синхронизировал системное время.

Пример создания юнита systemd может выглядеть так:
```
[Unit]
Description=Send startup log message
After=ntp.service

[Service]
Type=oneshot
ExecStart=/usr/bin/logger -T -n [SERVERB_IPADDR] -P [SERVERB_PORT] "Сервер A $(date) запущен"

[Install]
WantedBy=multi-user.target
```
Этот файл можно сохранить как /etc/systemd/system/startup-log.service, а затем активировать с помощью команд:
```
sudo systemctl daemon-reload
sudo systemctl enable startup-log.service
```
Проверка настройки NTP: Убедитесь, что служба NTP настроена правильно и запускается как можно раньше в процессе загрузки системы. Например, можно рассмотреть применение systemd-timesyncd, который наладит синхронизацию времени с серверами времени.

Заключение

Ситуация с неправильной датой в сообщении при запуске системы – не редкость, особенно на системах с низким уровнем аппаратных ресурсов, таких как Raspberry Pi. Использование механизма sleep является быстрым решением, однако для более стабильной работы рекомендуется интегрировать ваши команды в систему инициализации systemd. Таким образом, вы сможете избежать подобных проблем в будущем и повысить надежность работы ваших серверов.