URL: https://www.opennet.me/cgi-bin/openforum/vsluhboard.cgi
Форум: vsluhforumID1
Нить номер: 97294
[ Назад ]

Исходное сообщение
"Странные даты в логах"

Отправлено uber , 09-Окт-18 08:10 
После внезапной перезагрузки, причем как обрубило, непонятно почему вообще сервер перегружался, в логах появилась врезка с датами Sep 19 22:25:01 и Sep 20 01:25:01, в промежутке между Oct  8 01:55:01 и Oct  8 02:15:01. Это лог cron, периодичность работы - 5 минут.


В логе messages, после обычной работы системы вплоть до Oct  8 01:59:12 и сразу после этого вижу это:
Oct  8 02:00:00 localhost rsyslogd: [origin software="rsyslogd" swVersion="8.8.0" x-pid="703" x-info="http://www.rsyslog.com"] start

потом, после обычной загрузки системы в логах, после Oct  8 02:00:01 вижу это:

Sep 19 22:23:46
то есть врезается кусок старого лога, вплоть до:

Sep 20 01:27:36

и после этого, как ни в чем не бывало:

Oct  8 02:00:10

То есть за девять секунд в лог messages попало двое суток старых записей.
Что это может быть?

если поможет разобраться, в логе cacti
2018/10/08 02:05:04 - POLLER: Poller[1] WARNING: Cron is out of sync with the Poller Interval!  The Poller Interval is '300' seconds, with a maximum of a '300' second Cron, but 603.7 seconds have passed since
the last poll!


Содержание

Сообщения в этом обсуждении
"Странные даты в логах"
Отправлено Andrey , 09-Окт-18 10:19 
> После внезапной перезагрузки, причем как обрубило, непонятно почему вообще сервер перегружался,
> в логах появилась врезка с датами Sep 19 22:25:01 и Sep
> 20 01:25:01, в промежутке между Oct  8 01:55:01 и Oct
>  8 02:15:01. Это лог cron, периодичность работы - 5 минут.

...
> Что это может быть?

Все что угодно. По имеющейся тут информации можно предположить что лог-файл был заблокирован на запись и процесс, который хотел писать в него, просто копил данные в кеше. Как только файл освободился - сбросил весь кеш на диск.

Такие-же симптомы возможны при перезагрузке, когда NTP не успел получить текущее время и дата-время берется из BIOS.
Посмотрите какому поцессу принадлежат врезанные логи.


"Странные даты в логах"
Отправлено uber , 09-Окт-18 14:35 
>[оверквотинг удален]
>>  8 02:15:01. Это лог cron, периодичность работы - 5 минут.
> ...
>> Что это может быть?
> Все что угодно. По имеющейся тут информации можно предположить что лог-файл был
> заблокирован на запись и процесс, который хотел писать в него, просто
> копил данные в кеше. Как только файл освободился - сбросил весь
> кеш на диск.
> Такие-же симптомы возможны при перезагрузке, когда NTP не успел получить текущее время
> и дата-время берется из BIOS.
> Посмотрите какому поцессу принадлежат врезанные логи.

Спасибо за ответ.
Куски скопированы из реальных логов, из более ранних дат, один в один, я проверял. Такие участки copy-past вижу в логе cacti, messages, dhcp-server.log везде родной процесс.

boot.log (Modify time) Oct  8 01:59 подтверждает перегрузку указанное время.
Перегрузка была аварийной, причин не нашел, похоже на потерю питания, но подтверждения найти не смог.

Проверил даты изменения файлов в системе, на всякий случай, - нет ничего подозрительного.
Получается последовательность такая:
1. аварийная перезагрузка
2. в логи попадает информация с более ранней датой, полностью соответствующая уже существующей в архивных логах.
3. далее работа нормализуется