Часовые пояса в логах: как восстановить хронологию сбоя 1С

Ответ пришёл раньше запроса. Сессия успела закрыться до открытия, а почтовый шлюз доставил письмо до отправки. Так выглядела хронология из четырёх систем в статье «Реконструкция инцидента развалилась» на Хабре.

Каждый журнал записал правильное время — но по своим часам и в своём формате. Поэтому две записи 14:07:12 могут относиться к разным моментам.

Чтобы найти причину сбоя, сведите события 1С, Windows, веб-сервера и СУБД к одной шкале. Иначе причина поменяется местами со следствием, а вы потратите несколько часов на исправный узел.

Сначала выясните, что означает время в каждом журнале

Сортировка по столбцу времени не исправляет разные часовые пояса. Она только аккуратно выстраивает события в ошибочном порядке.

Начните с происхождения каждой метки. Где система взяла время? Записала ли смещение относительно UTC? От ответов зависит, можно ли сразу добавить событие в общую хронологию.

Вывод: сначала установите происхождение метки, потом сортируйте. Экспорт и экран пользователя могут показывать не время сервера.

Форматы RFC 3164 и RFC 5424, экспорт SaaS и время браузера описаны в статье на Хабре. Автор также показывает, почему метку на скриншоте нельзя автоматически приписывать серверу.

До сбора журналов запишите временную зону каждого участника цепочки:

• сервер 1С;
• сервер СУБД;
• IIS или Apache;
• балансировщик;
• почтовый шлюз;
• рабочее место администратора;
• учётная запись, из которой выгружали события.

Не угадывайте зону по адресу офиса или стойки. Сервер в Самаре может жить по UTC, а облачная панель — по зоне московской учётной записи. Местоположение оборудования этого не доказывает.

Сохраните исходную метку и рядом посчитайте UTC

Не заменяйте исходное время пересчитанным. Без оригинала вы не проверите арифметику и не повторите расследование, если исходная гипотеза окажется неверной.

Рабочая строка хронологии выглядит так:

исходная метка | подтверждённая зона | время UTC | система | событие | идентификатор

Допустим, журнал содержит 14:07:12+05:00. Смещение +05:00 говорит, что местное время опережает UTC на пять часов.

Оставьте расчёт прямо в рабочей таблице:

14:07:12 − 05:00 = 09:07:12Z

Положительное смещение вычитают. Для отрицательного прибавляют модуль: 14:07:12−03:00 соответствует 17:07:12Z.

Буква Z обозначает UTC без смещения. Рядом всё равно храните оригинал 14:07:12+05:00: он понадобится при проверке.

Если в журнале записано только 14:07:12, сначала подтвердите зону. Проверьте конфигурацию узла, настройки приложения и параметры экспорта. До этого метка остаётся условной.

Не восстанавливайте смещение по памяти. Ошибка в знаке удваивает промах: вместо вычитания пяти часов вы прибавите их и получите разницу в десять часов.

Повторяющийся локальный час нельзя упорядочить без смещения

При сезонном переводе часов один локальный час повторяется. В статье на Хабре такую метку называют принципиально неоднозначной.

Запись 02:30:00 без зоны не показывает, к первому или второму прохождению этого часа относится событие. Одной сортировки по времени здесь недостаточно.

Ищите другую опору: идентификатор запроса, номер сеанса, порядок строк или метку соседней системы со смещением. Если такой опоры нет, зафиксируйте ограничение прямо: порядок событий установить не удалось.

Отделите часовой пояс от рассинхронизации часов

Пересчёт в UTC исправляет форму записи времени. Но часы самого узла он не чинит. Эти проверки решают разные задачи.

Смена часового пояса Windows не переводит текущее время устройства. Она меняет его отображение относительно UTC. Этот принцип описан в руководстве Adminotes.

Вывод: постоянный сдвиг указывает на часовые пояса, растущий — на ход часов. Одной поправкой обе причины не закрыть.

В инциденте из статьи на Хабре несинхронизированные часы расходились на секунды за сутки. За месяц набегала минута или две. Это наблюдение из одного расследования, а не норма для вашего оборудования.

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

Тогда опирайтесь на идентификатор запроса. У веб-публикации это может быть идентификатор обращения, у СУБД — сеанс или транзакция, у 1С — связь с серверным процессом.

На Linux проверьте не только включение NTP

Строка NTP=yes в выводе timedatectl ещё не подтверждает синхронизацию. Она сообщает лишь, что служба включена.

NTPSynchronized=yes говорит, что система получила время. Но и эту строку нужно сопоставлять с клиентом синхронизации.

Автор статьи на Хабре указывает на две ловушки. При работе через chrony или ntpd поле NTP может показывать no, хотя время синхронизируется. После потери связи состояние ядра тоже меняется не сразу.

Проверьте цепочку командами:

timedatectl
systemctl status systemd-timesyncd
chronyc tracking
chronyc sources
ntpq -p

Запускайте команды для того клиента, который установлен на узле. Наличие работающего процесса ещё не подтверждает ответ вышестоящего сервера времени.

Сохраните результат рядом с журналом:

узел | часовой пояс | клиент времени | фактический сервер | состояние | время проверки

Такая запись отделит два сценария. В одном служба включена, но месяцами не получает ответ. В другом она работала во время сбоя, а связь пропала позднее.

Проверьте цепочку времени на Windows-серверах 1С

На каждом Windows-узле выполните три команды:

tzutil /g
Get-TimeZone
w32tm /query /status

tzutil /g и Get-TimeZone показывают текущую временную зону. Обе команды описаны в руководстве Adminotes по управлению часовыми поясами Windows.

Затем проверьте правила сезонного перевода:

w32tm /tz

По руководству Adminotes, команда выводит данные о зоне и сезонных правилах. Сохраните результат вместе с датой проверки: после инцидента конфигурация могла измениться.

Команда w32tm /query /status показывает состояние службы времени и текущий источник. Её приводит руководство GizVolt по диагностике времени в Windows Server.

Не ограничивайтесь часами в системном трее. Они не покажут источник синхронизации и не объяснят, почему соседний сервер отстал на несколько секунд.

В домене проверяйте цепочку до PDC

Служба времени Windows строит иерархию без циклов. Её устройство описывает официальная статья Microsoft KB816042 для всех поддерживаемых версий Windows Server.

Рядовые серверы и рабочие станции по умолчанию берут время у контроллера домена, который провёл их аутентификацию. Контроллеры домена сверяются с хозяином операций PDC.

Наверху цепочки стоит PDC корневого домена леса. Ошибка его часов расходится по домену. Поэтому проверка одного сервера 1С способна скрыть общую причину.

Запишите цепочку явно:

сервер 1С → контроллер домена → PDC корневого домена → внешний или внутренний источник

Затем запросите фактический источник на каждом звене. Схема из документации и результат команды могут различаться.

Microsoft KB816042 также описывает параметры Type, NtpServer, AnnounceFlags и пределы коррекции. Не меняйте их наугад посреди расследования.

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

Соберите шкалу вокруг одного опорного события

После пересчёта найдите событие с самодостаточной меткой. Для опоры годится запись RFC 5424 со смещением или другая метка, чья зона подтверждена конфигурацией.

Двигайтесь от неё в обе стороны. Добавляйте новую запись только после проверки зоны и состояния часов соответствующего узла.

Одного столбца UTC в рабочей таблице мало:

Вывод: вместе с UTC храните основание, по которому вы доверяете каждой метке.

Если цепочка начинается с сообщения 1С «Ошибка СУБД», сохраните время с рабочего места. После этого найдите первичную запись по порядку поиска причины в журнале СУБД.

При внезапном закрытии клиента сопоставьте число затронутых сеансов с событиями сервера. Для этого пригодится проверка масштаба вылета 1С по журналам.

Эти проверки не заменяют пересчёт в UTC. Они дают опорные признаки, которые связывают записи разных систем.

Не исправляйте журналы задним числом

Нормализованный файл храните отдельно от оригиналов. В рабочую копию добавляйте расчётные поля, комментарии и оценку доверия к метке.

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

Каждой неоднозначной метке назначьте статус:

• зона подтверждена конфигурацией;
• зона выведена по соседнему событию;
• часы узла расходились;
• точности не хватает;
• порядок установить нельзя.

Не заменяйте последний статус догадкой. Честный разрыв в хронологии полезнее уверенной последовательности, которая физически не могла произойти.

Порядок действий для следующего расследования

Добавляйте событие на общую шкалу после трёх проверок: оригинал сохранён, зона подтверждена, состояние часов узла известно.

1. Скопируйте исходные журналы. Метки внутри файлов не меняйте.
2. Зафиксируйте временную зону каждого узла, приложения, экспорта и браузера.
3. Переведите подтверждённые значения в UTC. Оригиналы держите рядом.
4. Проверьте фактический источник времени и синхронизацию каждого узла.
5. Только после этого сортируйте события. Записи с одинаковой секундой связывайте по идентификатору или порядку строк.

Постоянная разница в несколько часов ведёт к проверке временных зон. Растущее расхождение — к проверке синхронизации.

Повторяющийся локальный час без смещения не задаёт порядок событий. Оставьте этот участок неопределённым, пока не найдёте дополнительную опору.