Предельные режимы. Часть 1. Анализ технологического журнала средствами Vector, ClickHouse и Grafana

Потоковый сбор технологического журнала: интеграция Vector, ClickHouse и Grafana

Часть 1. Потоковый сбор технологического журнала: интеграция Vector, ClickHouse и Grafana

Проектирование и развертывание высокопроизводительного конвейера агрегации и нормализации событий технологического журнала 1С в реальном времени. Интеграция агента Vector, колоночной аналитической СУБД ClickHouse и аналитических панелей Grafana с ограничением оверхеда на процессор до 1.5-2% CPU. Анализ транзакционных блокировок (TLOCKS, TTIMEOUT, TDEADLOCK), системных сбоев (EXCP) и сокращение MTTR с 3-8 часов до 15 минут.

Целевая аудитория и контекст

• Профиль читателя: Инженеры сопровождения, ведущие 1С-разработчики (Senior), технические архитекторы корпоративных систем, администраторы баз данных (DBA), отвечающие за стабильность и производительность высоконагруженных инсталляций «1С:Предприятие 8.3».
• Исходное состояние системы: Сквозной практический кейс - эксплуатационный контур «Торговый контур»:
  • База данных: Объем 1.8 ТБ под управлением СУБД PostgreSQL 16 (ОС Linux).
  • Прикладное решение: «1С:Комплексная автоматизация» / «1C:ERP 2.5» со значительным объемом доработок логики проведения документов, складского учета и контура интеграций.
  • Интенсивность операций: 350 одновременно активных пользователей в часы пиковой нагрузки складских отгрузок; более 40 000 транзакций обязательной поштучной маркировки («Честный Знак») в сутки; непрерывный входящий поток внешних вызовов через HTTP-сервисы (интеграции с 3PL-операторами и маркетплейсами по схемам FBO/FBS).
• Ограничения:
  • Недопустимость деградации времени отклика системы при проведении регламентных и контрольных замеров (жесткий SLA на проведение документов отгрузки).
  • Ограничение накладных расходов: агент мониторинга и сбор логов не должны утилизировать более 1.5-2% процессорных мощностей и исчерпывать лимиты дискового ввода-вывода (IOPS).
  • Требование к сохранению детальной телеметрии для ретроспективного расследования инцидентов и аудита блокировок.

Постановка проблемы

• Симптомы:
  • Возникновение очередей ожидания на управляемых транзакционных блокировках в часы пиковой активности: рост времени проведения документов реализации (показатель p95 деградирует до 14.2 секунд).
  • Периодические инциденты завершения пользовательских транзакций по ошибкам таймаута ожидания блокировки (TTIMEOUT) и взаимных блокировок (TDEADLOCK).
  • Высокий показатель среднего времени локализации причин инцидента (MTTR): от 3 до 8 часов на ручной сбор логов, их объединение и поиск контекста сбойной операции после жалоб пользователей.
• Почему стандартных инструментов недостаточно:
  • Штатный журнал регистрации 1С (ЖР): В современных версиях платформы ЖР функционирует на базе монолитного файла SQLite (1Cv8.lgd). При высокой интенсивности параллельных транзакций запись в ЖР сама становится источником конкуренции за ресурсы диска и вызывает блокировки файла базы данных (database is locked), усугубляя деградацию системы. Кроме того, ЖР фиксирует события прикладного уровня, но не содержит критически важных системных метрик: времени ожидания на блокировках, текста SQL-запросов и стека выполнения модулей платформы.
  • Классический анализ текстовых файлов технологического журнала (ТЖ): Пакетный сбор и парсинг логов внешними скриптами (на базе OneScript, Python или Bash) выполняется с задержкой, порождает регулярные скачки нагрузки на дисковую подсистему (I/O spikes) и требует хранения больших объемов несжатого текста. При отсутствии жесткого контроля глубины хранения файлы ТЖ способны переполнить доступное дисковое пространство за считанные часы, вызывая аварийную остановку рабочих процессов rphost.

Архитектура решения

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

Компоненты архитектуры

1. Сервер «1С:Предприятие 8.3»: Точечный сбор технологического журнала через logcfg.xml с минимальным окном ротации (2 часа). Логи записываются на локальный диск или в RAM-диск (tmpfs).
2. Агент Vector (Datadog): Легковесный конвейер обработки данных на Rust. Выполняет потоковое чтение (tailing) текстовых файлов логов, склейку многострочных контекстов, нормализацию полей с помощью Vector Remap Language (VRL) и пакетную отправку в хранилище.
3. СУБД ClickHouse: Колоночная база данных для долговременного хранения и мгновенной аналитики. Обеспечивает коэффициент сжатия до 7-10 раз благодаря специализированным кодекам и выполняет выборки по миллионам событий за доли секунды.
4. Grafana: Визуализация метрик стабильности, тепловых карт распределения длительности запросов и интерактивный поиск контекста блокировок.

Ключевые инженерные решения конвейера

1. Реконструкция точной временной метки события

В файлах технологического журнала 1С строки не содержат полной даты - строка начинается с минут, секунд и микросекунд:

114:23.456789-1005000,TLOCKS,1,...

Дата и час выполнения фиксируются платформой в имени каталога процесса и имени самого файла лога по маске ГГММДДЧЧ.log (например, 26090514.log соответствует 2026-09-05 14:00). В конвейере Vector с помощью VRL реализовано сопоставление метаданных пути к файлу (.file) и относительного времени строки:

1# Извлечение даты и часа из пути к файлу: .../26090514.log
2date_match, date_err = parse_regex(file_path, r'(?P<year>\d{2})(?P<month>\d{2})(?P<day>\d{2})(?P<hour>\d{2})\.log$')
3# Извлечение минут, секунд и микросекунд из заголовка события
4time_match, time_err = parse_regex(header.time, r'^(?P<min>\d{2}):(?P<sec>\d{2})\.(?P<msec>\d{6})$')
5
6if date_err == null && time_err == null {
7    iso_str = "20" + date_match.year + "-" + date_match.month + "-" + date_match.day + "T" + date_match.hour + ":" + time_match.min + ":" + time_match.sec + "." + time_match.msec + "Z"
8    .timestamp = parse_timestamp(iso_str, "%Y-%m-%dT%H:%M:%S.%fZ") ?? now()
9}

Это исключает искажение временных меток при задержках обработки и гарантирует строгую синхронизацию с событиями в СУБД и ОС.

2. Механизм Multiline для стеков вызовов и текстов запросов

Свойство Context (стек вызовов процедур и функций 1С) и свойство Sql содержат многочисленные переводы строк. Если собирать лог построчно, тело запроса и стек разрываются на несвязанные фрагменты. В конфигурации источника Vector применен режим halt_before:

1multiline:
2  start_pattern: '^\d{2}:\d{2}\.\d{6}-'
3  mode: "halt_before"
4  condition_pattern: '^\d{2}:\d{2}\.\d{6}-'
5  timeout_ms: 1000

Агент удерживает все строки, не начинающиеся с временной сигнатуры 1С (^\d{2}:\d{2}\.\d{6}-), и объединяет их в единый строковый буфер до появления следующего заголовка события.

Шаги реализации

Шаг 1: Конфигурирование точечного logcfg.xml

На сервере 1С создается файл настроек с фильтрами, отсекающими штатную короткую активность:

1<?xml version="1.0" encoding="UTF-8"?>
2<config xmlns="http://v8.1c.ru/v8/tech-log">
3  <log location="/var/log/1c/logs" history="2">
4    <!-- Исключения и аварийные дампы -->
5    <event><eq property="name" value="EXCP"/></event>
6    <event><eq property="name" value="EXCPCNTX"/></event>
7
8    <!-- Управляемые блокировки длительностью от 1 секунды -->
9    <event>
10      <eq property="name" value="TLOCKS"/>
11      <ge property="duration" value="1000000"/>
12    </event>
13    <event><eq property="name" value="TTIMEOUT"/></event>
14    <event><eq property="name" value="TDEADLOCK"/></event>
15
16    <!-- Запросы к СУБД / SDBL длительностью от 3 секунд -->
17    <event>
18      <eq property="name" value="SDBL"/>
19      <ge property="duration" value="3000000"/>
20    </event>
21
22    <!-- Контроль потребления памяти процессами -->
23    <event><eq property="name" value="MEM"/></event>
24
25    <property name="all"/>
26  </log>
27</config>

Инженерные параметры:

• history="2": платформа автоматически удаляет файлы старше 2 часов. Локальный диск не переполняется даже при всплесках ошибок.
• ge property="duration": исключает запись миллионов коротких микротранзакций, оставляя только аномальные события, превышающие пороговые значения (1 000 000 мкс = 1 с; 3 000 000 мкс = 3 с).

Шаг 2: Проектирование таблицы в ClickHouse

В файле init.sql создается таблица techlog.events:

1CREATE DATABASE IF NOT EXISTS techlog;
2
3CREATE TABLE IF NOT EXISTS techlog.events
4(
5    timestamp DateTime64(6, 'UTC') CODEC(DoubleDelta, ZSTD(1)),
6    event LowCardinality(String) CODEC(ZSTD(1)),
7    duration UInt64 CODEC(T64, ZSTD(1)),
8    process LowCardinality(String) CODEC(ZSTD(1)),
9    pid UInt32 CODEC(DoubleDelta, ZSTD(1)),
10    client_id UInt32 CODEC(T64, ZSTD(1)),
11    session_id UInt64 CODEC(T64, ZSTD(1)),
12    application_name LowCardinality(String) CODEC(ZSTD(1)),
13    computer_name LowCardinality(String) CODEC(ZSTD(1)),
14    user LowCardinality(String) CODEC(ZSTD(1)),
15    app_id LowCardinality(String) CODEC(ZSTD(1)),
16    ib_name LowCardinality(String) CODEC(ZSTD(1)),
17    context String CODEC(ZSTD(3)),
18    descr String CODEC(ZSTD(3)),
19    sql String CODEC(ZSTD(3)),
20    sdbl String CODEC(ZSTD(3)),
21    wait_connections String CODEC(ZSTD(1)),
22    locks String CODEC(ZSTD(1)),
23    regions String CODEC(ZSTD(1)),
24    memory Int64 CODEC(T64, ZSTD(1)),
25    memory_peak Int64 CODEC(T64, ZSTD(1)),
26    raw_text String CODEC(ZSTD(3)),
27    properties Map(LowCardinality(String), String) CODEC(ZSTD(1))
28)
29ENGINE = MergeTree()
30PARTITION BY toYYYYMM(timestamp)
31ORDER BY (event, toDate(timestamp), timestamp, process, client_id)
32SETTINGS index_granularity = 8192;

Особенности схемы:

• DoubleDelta, ZSTD(1): сжимает временные метки путем сохранения разницы между соседними значениями, что дает близкое к нулю потребление памяти на таймстампы.
• LowCardinality(String): словарное кодирование для повторяющихся строковых значений (event, process, user, application_name).
• ZSTD(3): алгоритм сжатия Zstandard третьего уровня для больших текстовых блоков (context, sql).

Шаг 3: Настройка агента Vector

Конфигурация vector.yaml задает конвейер обработки и параметры буферизации:

1sinks:
2  clickhouse:
3    type: clickhouse
4    inputs: ["parse_techlog"]
5    endpoint: "http://clickhouse:8123"
6    database: "techlog"
7    table: "events"
8    skip_unknown_fields: true
9    batch:
10      max_events: 5000
11      timeout_secs: 5
12    buffer:
13      type: disk
14      max_size: 1073741824 # 1 GiB дискового буфера
15      when_full: block

Использование дискового буфера (buffer.type: disk) гарантирует, что в случае сетевой недоступности ClickHouse или перезапуска контейнера логи не потеряются и не займут оперативную память хоста.

Шаг 4: Запуск инфраструктуры и дашборд Grafana

Развертывание стека выполняется одной командой:

1docker compose up -d

Сервис Grafana автоматически импортирует дашборд 1C:Enterprise TechLog Overview через механизм провижининга. На дашборде доступны:

• Индикаторы счетчиков EXCP, TLOCKS, TTIMEOUT, TDEADLOCK в реальном времени.
• Временной ряд возникновения блокировок и взаимных блокировок.
• Топ-10 блокировок с прямым указанием строк модулей 1С:
  Листинг: sql sql

  1SELECT timestamp, round(duration/1000000, 2) AS duration_sec, user, locks, context
  2FROM techlog.events
  3WHERE event = 'TLOCKS'
  4ORDER BY duration DESC LIMIT 10;

Верификация и метрики

Эффективность конвейера проверена в условиях сквозного кейса «Торговый контур» при моделировании конкурентного проведения 40 000 чеков маркировки и документов отгрузки:

• Исходный уровень (до внедрения):
  • Время обнаружения и локализации причин деградации (MTTR): от 3 до 8 часов. Инженер вручную включал ТЖ, ожидал повторения проблемы, собирал архивы логов, запускал локальные скрипты разбора.
  • Реакция на инциденты происходила постфактум - после накопления очереди блокировок и жалоб пользователей.
• Результат (после внедрения):
  • Время локализации инцидента (MTTR): до 15 минут. Инженер открывает дашборд Grafana, выбирает интервал всплеска TLOCKS и за 3 клика получает конкретный общий модуль, метод и номер строки кода, захватившей разделяемый ресурс (регистр накопления «ТоварыНаСкладах»).
  • Накладные расходы на сервере 1С:
    • Утилизация CPU агентом Vector: менее 1.2% одного процессорного ядра.
    • Дополнительный объем дискового пространства: не более 200-350 МБ благодаря фильтрации по длительности и 2-часовому кольцу ротации.

Риски и ограничения («Красная зона»)

При эксплуатации технологического журнала на высоконагруженных продуктивных базах необходимо учитывать критические риски:

1. Опасность директивы <property name="all"/> без фильтра по длительности: Включение сбора всех событий СУБД (SDBL, DBPOSTGRS, DBMSSQL) без указания условия <ge property="duration" .../> приводит к тому, что платформа начинает логировать каждый одиночный SELECT. Нагрузка на файловую систему возрастает лавинообразно: поток записи превышает 200-400 МБ/с, дисковая очередь (Disk Queue Length) подскакивает выше 50, что вызывает моментальную деградацию продуктивной базы. Правило: На продуктивных серверах директива <property name="all"/> допустима только в паре с жесткими порогами длительности (duration >= 1000000).

2. Права доступа к каталогу логов в Linux (usr1cv8): Процессы сервера 1С (rphost, rmngr) функционируют под системным пользователем usr1cv8:grp1cv8. Создаваемые каталоги имеют права 0750, а файлы логов - 0640. Если агент Vector запускается в контейнере под непривилегированным пользователем с другим UID, чтение логов блокируется ошибкой Permission Denied. Решение: Запуск контейнера Vector от пользователя с правами чтения (user: "0:0" в docker-compose.yml) либо настройка POSIX ACL на сервере:

   Листинг: bash bash

   1setfacl -R -d -m u:vector:rX /var/log/1c/logs
   2setfacl -R -m u:vector:rX /var/log/1c/logs

3. Смещение часового пояса (Local Time vs UTC): Платформа 1С формирует имена файлов и строки лога в локальном часовом поясе операционной системы хоста. Если сервер 1С работает по московскому времени (MSK, UTC+3), а парсер Vector безусловно дописывает маркер Z (UTC), метка времени в ClickHouse окажется сдвинута на 3 часа в прошлое. Это разрушает корреляцию с системными метриками СУБД и Prometheus. Решение: Приведение серверов контура к единой таймзоне UTC либо явное указание часового смещения в VRL-скрипте Vector.

Артефакты для читателя

К статье прилагается архив инженерных артефактов release_part_01_observability.zip. Ниже приведен состав архива:

• docker-compose.yml - манифест развертывания ClickHouse + Vector + Grafana.
• 1c/logcfg.xml - безопасный профиль сбора ключевых событий ТЖ 1С.
• clickhouse/init.sql - схема таблицы с алгоритмами сжатия и партиционированием.
• vector/vector.yaml - конфигурация склейки multiline и VRL-трансформации.
• grafana/provisioning/dashboards/techlog-overview.json - готовый дашборд аналитики инцидентов.
• README.md - руководство по эксплуатации и настройке прав доступа.

Заключение

Практические результаты

• Организован непрерывный конвейер сбора телеметрии ТЖ 1С без риска исчерпания дискового пространства и деградации производительности продуктивного сервера.
• Инженеры сопровождения и разработчики получили инструмент мгновенной локализации медленных запросов и управляемых блокировок с детализацией до конкретной строки кода модуля 1С.
• Исключена зависимость от монолитного SQLite-хранилища журнала регистрации при расследовании системных инцидентов.

Переход к следующей части

Развернутый конвейер позволяет оперативно фиксировать факты длительного выполнения операций на стороне СУБД. Однако понимание того, почему конкретный запрос к PostgreSQL выполнялся аномально долго - из-за неоптимального плана выполнения, нехватки shared_buffers, распухания таблиц (bloat) или конкуренции за блокировки на уровне строк - требует специализированных инструментов профилирования ядра СУБД.

В следующей публикации «Часть 2. Профилирование и настройка PostgreSQL: анализ ожиданий, pg_stat_statements, pg_profile» мы перейдем на уровень базы данных: настроим расширения статистики PostgreSQL, разберем методику выявления ресурсоемких планов запросов 1С и оптимизируем конфигурацию СУБД под смешанную OLTP-нагрузку.