Приложение загружает логи Технологического журнала 1С в базу данных ClickHouse.
Загрузка логов Технологического журнала (ТЖ) выполняется из каталога, указанного в параметрах запуска. Допускается указывать несколько путей через пробел. Если путь к логам не указан, то поиск логов выполняется в текущем каталоге. Также можно указать не каталог, а конкретный файл с ТЖ. Поиск выполняется рекурсивно по маске *.log. Причем имя логов должно быть каноническим YYMMDDHH.log и родительский каталог должен содержать информацию о виде процесса и его PID (rphost_324).
Ключ -d запускает режим демона - процесс не завершается, а продолжает мониторить появление новых записей ТЖ в указанных каталогах. Ключ --config= позволяет указать расположение файла настроек (если расположение по умолчанию не подходит). Ключ -h выводит краткую справку.
Например, указанная команда запустит мониторинг каталогов E:\LOGS\EXCP и E:\LOGS\TLOCK, настройки, при этом, будут прочитаны из файла my-config.yaml:
ClickHouse1CTechJournal.bat -d --config=my-config.yaml E:\LOGS\EXCP E:\LOGS\TLOCK
В общем случае настройки задаются в файле config.yaml, который располагается в текущем каталоге. С помощью ключа --config можно указать произвольный путь к настройкам. Если файл не обнаружен, то будут использованы настройки по умолчанию. Описание настроек:
threadCount: 6 # Количество потоков используемых для параллельной загрузки
batchSize: 10000 # Размер порции записей из файла ТЖ в одной пакетной вставке (INSERT в таблицу)
thresholdSizeHashByAttr: 10485760 # [10Мб] Только для режима daemon. Порог размера файла в байтах, выше которого контрольная сумма будет считаться по атрибутам.
monitoringIntervalSec: 30 # Только для режима daemon. Интервал поиска изменений в файлах для очередной итерации загрузки в секундах
clickhouse: # Настройки ClickHouse
host: localhost # Хост: имя сервера или ip-адрес
port: 8123 # 8123 - http; 9000 - tcp
user: default # Имя пользователя
pass: '' # Пароль
database: TechJournal # База данных, куда будут загружаться логи
tablePostfix: Main # Постфикс к имени таблицы в БД - можно указывать имя кластера 1С
# Параметры ниже служат для тонкой настройки таблицы в ClickHouse, куда грузятся логи
engine: MergeTree # "Движок" таблицы
orderBy: datetime, event # Первичный ключ
partition: toHour(datetime), source # Секционирование таблиц логов: по часам и типу источника
Все описанные выше настройки переопределяются соответствующими переменными окружения, если они указаны. Это полезно при работе с приложением в Docker-контейнере. Полный и актуальный перечень доступных переменных окружения см. в перечислении com.clickhouse1ctj.config.ConfigKeys. Пример приведен в файле docker-compose.yml в разделе services.ch-1ctj.environment.
Собранное и упакованное приложение можно взять в дистрибутивах или откомпилировать самим.
java -classpath [путь_к_модулям] com.clickhouse1ctj.TechJournalToClickHouse [путь_к_логам_ТЖ]
Наиболее простой вариант взять архив с дистрибутивом, распаковать его и запустить cmd-файл в папке bin. Все необходимые библиотеки поставляются вместе с архивом.
ClickHouse1CTechJournal.bat [путь_к_логам_ТЖ]
Docker-образ опубликован в DockerHub: kron1sant/ch-1c-techjournal. Для запуска отдельного Docker контейнера можно воспользоваться командой:
docker run --name my-test -it --rm -v [путь_к_логам_ТЖ]:/var/lib/ClickHouse1CTechJournal/tj \
-e CH_DATABASE=TechJournalDocker -e CH_HOST=[хост_с_clickhouse] \
kron1sant/ch-1c-techjournal:latest
Для запуска сразу вместе с сервером ClickHouse можно воспользоваться файлом docker-compose.yml
docker-compose up -d
Приложение может работать как разовый загрузчик, либо как демон (служба). В случае работы в режиме демона, через равные промежутки времени (monitoringIntervalSec) запускается основной поток поиска файлов ТЖ в указанных при запуске каталогах. Все новые файлы автоматически попадают в пул для обработки. Если же файл присутствовал на предшествующей итерации, то выполняется проверка его изменений. Проверка выполняется через сверку предыдущей и текущей хеш-суммы файла. Здесь есть сложность, связанная с тем, что файлы ТЖ могут существенно разрастаться в объеме (для полного ТЖ, файла в 10 Гб не редкость). Чтобы не тратить время на получение полного хеша по большим файлам, на каждой итерации введен порог (thresholdSizeHashByAttr), который определяет размер файла в байтах. При превышении порога, хеш сумма рассчитывается не на весь файла, а только на первые thresholdSizeHashByAttr байт плюс в функцию хеша добавляется текущий размер и дата последнего изменения.
Независимо от режима запуска выявленные файлы ТЖ, помещаются в потокобезопасную очередь (пул файлов), откуда последовательно выбираются рабочими потоками, отвечающими за парсинг и загрузку в ClickHouse.
Число параллельных потоков, выполняющих загрузку, определяется настройкой threadCount, но не превышает количество файлов ТЖ, полученных для загрузки. Это связано с тем, что каждый рабочий поток берет из пула очередной файл ТЖ, целиком его парсит и загружает в базу. После чего переходит к следующему файлу в общем пуле. Если очередь пуста, то поток завершается. Основной рабочий процесс ждет завершения всех потоков, после чего выводит статистику (полное время обработки, количество файлов, количество записей) и, в зависимости от режима работы, либо полностью завершается, либо стартует следующую итерацию (режим демона).
Парсинг выполняется в рабочем потоке. Поток открывает файл ТЖ на чтение (не монопольно) и построчно
считывает его. Каждая строка сравнивается с регулярным выражением ^\d\d:\d\d\.\d{6}-\d+,[a-zA-Z]+,\d+,
,
которое определяет начало очередной записи лога. Так как в ТЖ могут присутствовать многострочные записи (контекст
прикладного кода, запросы SQL и пр.), то каждая последующая строка, которая не соответствует указанному шаблону
(т.е. не является началом лога), относится к данной записи. Иначе говоря, многострочные записи ТЖ
конкатенируются в одну строку. Полученная строка отправляется в отдельный парсер
com.clickhouse1ctj.parser.LogRecordParser, где из нее извлекается обязательная часть:
datetime, duration, event, level и прочие поля в формате [ключ]=[значение]
. Полный набор ключей ([key]
) из
необязательной части лога запоминается при парсинге, затем на его основе будет формировать таблица в
ClickHouse. Важно отметить, что набор этих полей (аттрибутов/свойств) записи лога нигде в полном объеме не описан
и может изменяться внутри платформы 1С от версии к версии.
Чтение выполняется до тех пор, пока количество полученных записей лога не достигнет значения batchSize. После чего полученный набор отправляется для загрузки в базу ClickHouse. После загрузки чтение файла возобновляется с последней прочитанной строки и будет продолжаться либо до конца файла, либо до следующей порции batchSize.
Перед началом обработки приложение уже проверило возможность подключения к ClickHouse по указанным параметрам. Если подключение не удается, то приложение завершает работу с соответствующим сообщением. Если указанная база данных clickhouse.database отсутствуют, то она будет создана автоматически при проверке подключения.
Данные из файлов ТЖ загружаются в таблицы, указанной базы. В текущей реализации для логов за один день формируется одна таблица. При создании таблицы учитываются заданные параметры (секционирование, индексирование, префикс и движок). Например, имя таблицы может иметь вид: 211030_MyCluster_TJ. Где MyCluster - это постфикс заданный параметром clickhouse.tablePostfix. В данном примере, все логи (rphost, ragent, rmngr, 1cv8 и т.д.) за 2021.10.30 будут загружены в одну таблицу. По умолчанию таблица секционируется (партицируется) по комбинации: астрономический_час_записи+источник, что в целом близко к организации ТЖ в файлах 1С (у 1С еще и PID участвует в иерархии). Каждая колонка в таблице соответствует полю записи ТЖ (duration, OSThread, Context и т.д.).
Для подключения к ClickHouse используется официальный драйвер JDBC для ClickHouse. Очередная порция записей ТЖ количеством в
batchSize (либо меньше, если это конец файла) вставляется в полученную таблицу (SQL INSERT
) в рамках
выполнения рабочего потока. Допускается параллельная вставка в одной и ту же таблицу из разных потоков.
ClickHouse прекрасно справляется с такой задача, до того момент пока не приходится изменить состав колонок таблицы.
Как было сказано ранее, набор полей в логах ТЖ не фиксированный, он может изменять от версии к версии. Да и вообще некоторые поля встречаются совсем у экзотических типов событий. Создавать каждый раз для всех полей колонки в таблице, было бы расточительно. Поэтому таблица увеличивается вширь динамически. При получении очередной порции записей из ТЖ, парсер также предоставляет список всех прочитанных полей, этот список сравнивается с существующими колонками таблицы и для вновь выявленных полей инициируется создание дополнительных колонок. Так как загрузка выполняется одновременно несколькими потоками, то нельзя предугадать момент, когда один из потоков решит вставить новые колонки. А учитывая, что ClickHouse нетранзакционный, то подобная параллельная вставка колонок и строк приводит к ошибкам:(
Для того, что избежать подобных коллизий, в приложении реализована блокировка таблицы (com.clickhouse1ctj.loader.TableLock), которая инициируется перед добавлением колонок. Ждет когда текущие потоки закончат INSERT'ы и запрещает стартовать новые. После завершения последнего, текущие (ожидающий) поток выполняет вставку колонок (ALTER TABLE ... ADD COLUMN ...) и снимает блокировку. Остальные потоки могли этого даже не заметить, так блокировка запрещала только вставку записи, но парсинг при этом мог выполняться. Физически операция по добавлению колонки в ClickHouse выполняется моментально.
Информация по комбинации свойств - поле(параметр) фиксируется при работе и сохраняется в отдельную таблицу properties_by_events_tj. Данная таблица общая на всю базу и имеет всего две соответствующие колонки: event и property. Она позволяет получить информацию о том, какие поля по указанному свойству использовались в ТЖ. Это очень ценно для анализа, так как количество уникальных полей переваливает за сотню, а для большинства событий для анализа достаточно 10-20.
Например, на полном ТЖ на моих данных встречается 132 уникальных поля. Это можно получить следующим запросом:
SELECT uniq(property) FROM properties_by_events_tj
Для вывода информационных сообщений в процессе работы приложения использовался SimpleLogger из org.slf4j. По умолчанию вывод осуществляется в StdErr и детализируется на уровне INFO. Если нужен более детальная информация о процессе работы приложения, то можно понизить уровень до DEBUG или TRACE.. Для этого нужно пересобрать приложение, указав соответствующее значение в файле: src/main/java/resources/simplelogger.properties, свойство org.slf4j.simpleLogger.defaultLogLevel=. Или задать соответствующее системное свойства Java (-Dorg.slf4j.simpleLogger.defaultLogLevel=DEBUG)
Использование ClickHouse позволяет структурировать логи ТЖ, что существенно упрощает их анализ. Эффективно решаются задачи по статистическому анализу: количество ошибок в разрезе процессов, длительность SQL запросов, потребление памяти при серверных вызовах. А также такие операции как: отбор всех последовательных событий происходивших в одном потоке (фильтр по OSThread), расследование таймаутов и блокировок и.д. ClickHouse использует знакомый всем SQL синтаксис, расширяя его дополнительным функциями (преобразования, статистики и т.д.).
Так как в ClickHouse используется разреженный индекс, то поиск записей по точному совпадению может выполняться не сильно эффективно, но в любом случае это существенно быстрее чем парсить гигабайты текста grep'ом. При необходимости можно изменить формат хранения логов в таблицах: изменить секционирование и первичный индекс, переписать процедуру формирования имени таблицы (например, чтобы одна таблица на каждый час или на каждый тип процесса).