Реконструкция инцидента развалилась: в логах не было смещения часового пояса
При разборе инцидента часто приходится объединять данные из нескольких систем: веб-сервера, балансировщика, приложения, базы данных и почтового шлюза. На первый взгляд задача кажется простой: собрать записи, расположить их по времени и восстановить последовательность действий.
Проблемы начинаются, когда полученная картина противоречит здравому смыслу. Ответ сервера появляется раньше запроса, сессия завершается до установления соединения, а письмо доставляется за два часа до отправки. При этом ни один журнал не содержит явной ошибки. Каждый компонент честно записал событие - но ориентировался на собственные часы, формат и момент фиксации.
Чтобы понять причину расхождения, необходимо разделять несколько разных проблем.
Почему временные метки не совпадают
Дрейф системных часов
Часы компьютера могут постепенно отклоняться от эталонного времени. Даже небольшая погрешность в несколько секунд в сутки за месяц превращается в минуты. Для повседневной работы это почти незаметно, однако при расследовании инцидента такой разницы достаточно, чтобы поменять местами два последовательных события.
Например, запрос был отправлен в 12:00:04, а процесс на другом узле запустился в 12:00:02 по его локальным часам. При сортировке записей создастся впечатление, будто процесс стартовал раньше запроса.
Разные часовые пояса
Один сервер может писать время в UTC, другой - в локальном часовом поясе, а контейнер - в соответствии с настройками базового образа или окружения. При этом сами часы на всех узлах будут идти абсолютно правильно. Проблема заключается не в точности, а в том, что значения нельзя напрямую сравнивать.
Ситуацию усугубляет ручная настройка виртуальных машин, контейнеров и рабочих станций. Один администратор выбирает UTC, другой оставляет часовой пояс дата-центра, а третий использует параметры хост-системы.
Фиксация момента записи
Временная метка не всегда означает момент возникновения события. Иногда она отражает время, когда сообщение попало в очередь логирования, было обработано агентом или отправлено в центральное хранилище.
Если приложение записало событие локально, но передало его сборщику логов через несколько секунд, разница будет небольшой. Однако при буферизации, сетевых сбоях, повторной отправке или перегрузке разрыв может составить минуты и даже часы.
Эти причины требуют разных решений: синхронизация исправляет дрейф часов, единый формат устраняет неоднозначность часовых поясов, а корректное описание происхождения метки помогает понять задержку между событием и его регистрацией.
Почему старый формат syslog мешает расследованию
Классический BSD syslog, известный как RFC 3164, записывает дату примерно в следующем виде:
```text
Mar 18 14:32:10 host application: connection accepted
```
В такой строке отсутствуют год и часовой пояс. Год приходится восстанавливать по имени файла, периоду ротации или контексту соседних записей. Часовой пояс определить ещё сложнее: необходимо знать настройки узла, который сформировал сообщение. Если сервер уже выведен из эксплуатации, контейнер удалён, а архив сохранился отдельно, восстановление становится предположением.
Современный RFC 5424 предусматривает более подробную временную метку:
```text
2025-03-18T14:32:10.421+05:00
```
Здесь присутствуют год, доли секунды и смещение относительно UTC. Такая запись является самодостаточной: её можно правильно интерпретировать даже без доступа к исходному серверу.
Смещение `+05:00` - не декоративная деталь. Именно оно показывает, какой момент времени имелся в виду. Строка без часового пояса становится однозначной только вместе с настройками источника.
Почему правила "перевести всё в UTC" недостаточно
UTC действительно следует использовать как внутренний стандарт хранения и передачи логов. Однако это правило работает только для систем, которыми организация управляет напрямую.
В расследовании обычно участвуют внешние данные:
- заголовки электронных писем;
- журналы облачного провайдера;
- выгрузки из SaaS-панелей;
- отчёты подрядчиков;
- скриншоты интерфейсов;
- записи с пользовательских компьютеров.
В почтовом заголовке указывается часовой пояс отправителя, а не получателя. Внешний сервис может формировать журнал в собственной временной зоне. SaaS-платформа иногда экспортирует даты с учётом настроек аккаунта или браузера пользователя. Поэтому два сотрудника могут выгрузить один и тот же отчёт и получить разные значения времени.
Правильная стратегия - нормализовать данные в момент поступления. Система сбора должна сохранить исходную строку, определить источник, применить известный часовой пояс и записать нормализованное значение в UTC. Одновременно полезно хранить сведения о том, кто сформировал запись, когда она была принята и какой метод преобразования применялся.
Переход на летнее время создаёт отдельную проблему
В регионах, где используется летнее время, один час в году повторяется дважды. Например, значение `02:30` может соответствовать двум разным моментам. Если запись не содержит смещения или идентификатора временной зоны, установить правильный вариант невозможно.
Обратная ситуация возникает при переводе часов вперёд: некоторый диапазон времени просто не существует. Поэтому локальные метки без offset и без названия зоны нельзя считать надёжным источником для строгой хронологии.
Для критичных систем лучше использовать формат с числовым смещением или обозначением зоны IANA, например `Europe/Berlin`. Одного текста `2025-10-26 02:30:00` недостаточно.
Запущенная NTP-служба ещё не означает синхронизацию
На сервере обычно установлен клиент NTP, а соответствующая служба автоматически запускается вместе с системой. Но сам факт работы процесса не подтверждает, что часы получают корректное время.
Служба может:
- не иметь доступа к NTP-серверу;
- получать ответы с ошибками;
- использовать недоступный адрес;
- отклонять источник из-за большой погрешности;
- работать, но давно не выполнять успешную коррекцию.
В системах с systemd важно отличать два состояния:
```text
NTP=yes
NTPSynchronized=yes
```
Первое означает, что механизм синхронизации включён. Второе подтверждает, что синхронизация действительно состоялась. Для мониторинга необходимо проверять именно состояние `NTPSynchronized`.
При этом значения зависят от используемого компонента. Если время обслуживают chrony или ntpd, проверка systemd-timesyncd может показать `no`, даже когда часы исправны. Поэтому сначала нужно определить, какой демон реально управляет временем.
Что проверить до возникновения инцидента
Надёжная подготовка начинается с инвентаризации всех источников событий. Для каждого узла желательно зафиксировать:
- используемый часовой пояс;
- источник времени;
- состояние синхронизации;
- формат логов;
- наличие дробных секунд;
- способ доставки записей;
- возможную задержку буферизации;
- правила ротации и хранения.
На серверах следует контролировать не только доступность службы времени, но и величину текущей погрешности. Для chrony полезно отслеживать выбранный источник, задержку, уровень доверия и величину смещения. Нельзя ограничиваться проверкой, что процесс запущен.
В центральной системе логирования желательно хранить как минимум три значения:
1. время события по данным источника;
2. время приёма записи сборщиком;
3. время поступления записи в хранилище.
Разница между ними помогает отличить реальную задержку от неправильных часов.
CLOCK_REALTIME и CLOCK_MONOTONIC - не одно и то же
Для журналов обычно используется календарное время, связанное с `CLOCK_REALTIME`. Оно может измениться скачком: оператор вручную перевёл часы, NTP выполнил коррекцию, система получила неверное значение от аппаратных часов.
Для измерения длительности это опасно. Если зафиксировать начало операции, затем системные часы откорректируются назад, вычисленная продолжительность может оказаться отрицательной.
`CLOCK_MONOTONIC` предназначен именно для измерения интервалов. Он не привязан к календарной дате и не возвращается назад при изменении часового пояса или коррекции системного времени. Поэтому в приложениях следует использовать:
- `CLOCK_REALTIME` - для отметки события в журнале;
- `CLOCK_MONOTONIC` - для расчёта длительности, тайм-аутов и задержек.
На практике полезно записывать оба значения, если требуется одновременно знать абсолютный момент и точный интервал выполнения операции.
Как восстановить хронологию при уже случившемся сбое
Если логи уже собраны в разных форматах, не стоит сразу сортировать их по строковому значению даты. Сначала нужно составить карту источников и определить, что означает каждая метка.
Для каждой записи следует выяснить:
- где она была создана;
- какие часы использовались;
- в какой временной зоне;
- фиксирует ли она момент события или доставки;
- могла ли запись задержаться в очереди;
- имеется ли уникальный идентификатор запроса или корреляции.
Затем данные переводятся в единую шкалу, но исходные значения сохраняются. При сомнениях необходимо указывать диапазон возможного времени, а не выдавать предположение за точный факт.
Большую помощь оказывают идентификаторы трассировки, request ID и correlation ID. Даже если часы разошлись, одинаковый идентификатор позволяет связать записи между сервисами и восстановить причинно-следственную цепочку.
Итог
Корректная реконструкция инцидента требует больше, чем одинакового формата даты. Нужны синхронизированные часы, явное указание часового пояса, понимание момента фиксации события и контроль задержек доставки.
UTC следует использовать как стандарт внутри инфраструктуры, но внешние данные необходимо нормализовать на входе. Службу синхронизации нужно не просто запускать, а контролировать факт успешной работы. Для длительностей следует применять монотонные часы, а для календарных отметок - самодостаточный формат со смещением.
Если эти правила внедрены заранее, расследование превращается в анализ фактов, а не в попытку угадать, какие часы и настройки стояли за каждой строкой журнала.