Анализ технологических журналов с помощью инструментов bash

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

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

Для тех, кто не знаком, статья по сути приводит готовые примеры, которые можно начать использоваться «как есть».

У этой статьи нет цели дать полное описание всех свойств инструментов.

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

Существует много способов анализа технологических журналов, нет цели рассказать о них всех.

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

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

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

Как мне настроить технологические журналы и проделать то, что написано в статье

Технологические журналы настраиваются в файле logcfg.xml

Для отработки материала в данной статье вам понадобится

— клиент-серверный вариант технологической Платформы 1С:Предприятие (примеры готовились на примере 8.3.10)

— СУБД (примеры готовились для MS SQL Server)

— информационная база, как вариант, СНТ, входящий в Корпоративный Инструментальный Пакет

На рабочем сервере настраиваем технологический журнал в файле (logcfg.xml)

Это полный журнал, который будет собираться в директорию «C:\LOGS\FULL».

Если вы это делаете на рабочих серверах, то следите за местом. (Лучше, конечно, не настраивать полный журнал, а указывать только те события, которые нужны для анализа вам сейчас.)

Для целей этой статьи нам нужен полный журнал.

Подробнее об инструментах

Речь пойдет сначала об «утилитах» bash/sh.

Для пользователей linux не нужно практически ничего, они уже имеют «утилиты».

Для пользователей windows существуют варианты:

— c windows 10 есть встроенный bash (пока в beta-версии) (https://msdn.microsoft.com/en-us/commandline/wsl/about)

— есть инструмент cygwin (https://www.cygwin.com/)

— есть git bash (который в своей поставки содержит всё нужное) (https://git-scm.com/)

Авторы в os windows предпочитают использовать git bash, т.к. по сути его запуск и подготовка к использованию сводятся к клику правой кнопкой мыши в директории с журналами и выбором кнопки git bash here.

Все примеры в этой статье приводятся из расчета, что автор

— либо выполнил cd C:\LOGS\FULL (или аналогичный путь у вас)

— либо запустил в windows git bash here в директории «C:\LOGS\FULL»

Т.е., если выполните pwd, вы увидите директорию «C:\LOGS\FULL»

Для знакомства также рекомендуется книга Скотт Граннеман «Linux Необходимый код и команды Карманный справочник»

Также рекомендуем книгу Джеффри Фридл «Регулярные выражения»

Первые шаги

Хочется очень коротко озвучить приемы, которые применяются периодически для решения простейших микро-задач (посмотреть какие файлы в директории и т.п.).

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

(В целом, последнее замечание касается всей статьи).

Команды и утилиты

Копирование с удаленной машины server

Удалить всё, включая поддиректории, без подтверждения

Список файлов в порядке «последние использованные — снизу» с информацией о правах и времени их модификации

Только список в одну колонку

Только список в строку

Найти файлы по имени в текущей директории

Найти файлы по размеру больше 10 Мб от корня файловой системы

Найти файлы, старше 21:40 04.05.2017 (текущего года)

Просто вывести file

Вывести и пролистать file

Вывести первые 10 строк файла file

Вывести первые N

Вывести последние 10

Вывести последние N

Следить за изменениями в файлах и выводить каждую секунду обновления:

Вывод строк, включающих соответствия выражению, из входного потока

Поиск во всех подкаталогах

Вывод только совпадающего фрагмента

Вывод только совпадающего фрагмента с использованием perl конструкций

Вывести 5 строк до и после найденного выражения

Вывести совпадения, но не выводить имена файлов и пути

Вывести только определенное поле, например, ClientID= от строк, совпадающих с (не выводя всю строку).

Например, выражение — «,EXCP,»

Поиск по журналам rphost за определенный час (12 часов)

sed и perl

Вывести содержимое файла и заменить GUID-ы, адреса и номера портов на короткие имена:

Убрать всё с начала строки до выражения:

Убрать всё с выражения до конца строки:

Автор считает более удобным применять конструкцию

в качестве альтернативы sed. Это вопрос предпочтений и незначительного выигрыша в производительности и удобстве.

Применить более одного раза (для всех вхождений):

Например, получить сумму по 2-ой колонке, если разделитель ;

Разделителем может быть даже слово

Группировка по входным данным (группируемое поле — $1, суммируется — $2)

Простые реальные примеры

Вывести top 10 совпадений с именами файлов, содержащий текст «Lock request timeout»

Выводить все события «исключения», возникающие сейчас в работающих процессах rphost

Вывести последние 10 событий фиксации или отката транзакции в журналах всех процессов rphost, длительностью более 20 секунд

Для удобства чтения

В статье будет применяться прием, используемый для удобства чтения.

В bash перенос строки обозначается символом \

Т.е. по сути однострочная программа

может выглядеть и выполняться в таком виде

Для «сложных» одностроных программ такой подход в этой статье будет удобен, чтобы «программы менее походили на страшные заклинания» ,

однако вряд ли вы его будете применять на практике (автор не применяет).

Оптимизация

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

Для того, чтобы программы выполнялись быстро, следует пользоваться правилами:

— Постараться как можно ближе к началу отобрать необходимый объем строк;

— Не оперировать миллионами строк;

— Помнить, что сортировки на сотнях тысяч строк могут быть дорогими.

Вы можете воспользоваться утилитой time для получения реального времени выполнения программы.

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

Поэтому в этом случае можно сразу после первого pipe | добавить head, тем самым отобрав только 10 строк.

Если программа на 10 строках работает ожидаемо, то возможно, ожидаемое вами поведение сохранится и на большем числе строк (все зависит от вас).

Фильтрация событий технологического журнала Платформы

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

Например, события DBMSSQL содержат текст запроса и могут содержать контекст.

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

Попробуем получить все события DBMSSQL по определенному сеансу SessionID=2049

Таким образом, ключевыми стали:

— преобразование события к одной строке

— избавляемся от символов BOM, которые могут принести проблемы при работе с различными кодировками, т.к. не будут учитываться

— фильрация «утилитами» в привычном построчном режиме

— преобразование «обратно» к многострочному варианту после необходимых фильтраций

Обратное преобразование не всегда необходимо, поэтому можно, например, заменять
на пробелы.

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

Естественно, есть и другие способы.

Применение теории

Приведенные примеры позволяют решить поставленные задачи в течение буквально «пары минут», имея «в руках» только технологический журнал и «инструменты bash».

Найдем 5 наиболее длительных транзакций.

Шаг 1. Получим только фиксации и откаты транзакций

Шаг 2. Получим все свойства события полностью

Шаг 3. Оставляем события в одну строку (убираем «обратное» преобразование к многострочному варианту)

Шаг 4. Оставим только нужные поля.

— Например, длительность и первую строку контекста.

— Например, длительность и последнюю строку контекста.

В конструкции ‘s/^\d+:\d+.\d+-//g’ мы избавились от полей до длительности события, чтобы в дальшейшем можно было удобно группировать.

Шаг 5. Пробуем применить группировку с помощью awk

Найдем 5 наиболее длительных запросов к СУБД MS SQL Server.

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

Но проблема в том, что не все события DBMSSQL имеют контексты.

Поэтому группировка по первой или последней строке контекста не подойдет.

Нужно научиться группировать тексты запросов.

Однако в них могут быть числовые параметры, различные имена временных таблиц (#tt17, #tt56), когда структура таких таблиц по сути одинаковая.

Таким образом, нам нужно научиться сворачивать тексты запросов так, чтобы «уникальные» имена пропали.

Для тренировки явно добавим опцию

исключения Context в нашу программу, хотя, понятно, что самые длительные запросы будут только среди запросов без контекста из-за использования grep -v ‘Context’ .

Но так проще для тренировки.

Шаг 1. Получаем запросы без контекстов.

Шаг 2. Можно убрать GUID и имена временных таблиц, номера строк и цифры.

Найдем 5 наиболее длительных вызовов.

В целом задача не отличается от предыдущих.

Однако в предыдущих задачах мы можем заметить, что вывод awk нас не всегда устраивает, т.к. представлен в «удобном для чтения формате».

На самом деле он немного мешает. Решим задачу и изменим немного вывод awk:

Найдем 5 пространств, на которых больше других возникали ожидания на управляемых блокировках.

Используем тот же прием.

Однако, теперь нас интересует поле Regions.

Также обращаем внимание, что нас интересует не все события TLOCK, а только те, в которых было зафиксировано ожидание при установке управляемой блокировки.

Помним, что в этом случае поле WaitConnections= не пустое.

Аналогичным способом разобранную конструкцию можно самостоятельно применять и для других задачи поиска top 5 .

Поиск по другим журналам

Если посмотреть, например, на access логи nginx, то мы видим пригодные для разбора журналы.

Например, (в зависимости от того, как выглядят журналы у вас) получение оценки, на какой единицы масштабирования запросы

выполняются дольше других, может быть таким:

Когда серверов много

Допустим, вы знаете, что в вашей сети серверы имеют имена вида server1, server2, . server100 .

Тогда мы можем вывести имена всех серверов примерно так:

Но тогда, например, поиск EXCP по множеству серверов будет выглядеть примерно так:

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

По этой причине лучше искать более точечно. Например, среди последних 1000 строк.

Естественно через pipe | вы можете применять уже знакомые вам конструкции.

zip архивы

Технологические журналы рекомендуется складывать в zip архивы и не удалять какое-то время, т.к. они могут понадобиться для расследования проблем, которые были.

Естественно хранить такие архивы лучше не рабочих серверах, а в отведенных для этого хранилищах.

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

Можно воспользоваться конструкцией вида

Таким образом, поиск в определенной директории zip архива на удаленном сервере может выглядеть так

Источник

Примеры настройки технологического журнала

Технологический журнал и его настройка

Технологический журнал представляет собой совокупность каталогов и текстовых файлов, в которые различные приложения 1С:Предприятия могут записывать информацию о работе некоторых внутренних механизмов платформы. Состав выводимой информации определяется конфигурационным файлом технологического журнала, который имеет название logcfg.xml и должен быть помещен в подкаталог conf каталога загрузочных модулей 1С:Предприятия. В этом файле средствами XML определяются условия вывода в технологический журнал событий и их свойств. Если файл logcfg.xml отсутствует, не содержит ни одного элемента log, или содержит ошибки, то технологический журнал считается выключенным и не создается. При выключенном технологическом журнале производительность 1С:Предприятия несколько выше, чем при включенном.

В приведенных ниже примерах предполагается, что 1С:Предприятие установлено стандартным способом и его загрузочные модули расположены в каталоге C:\Program Files\1cv82\bin.

Важно иметь в виду, что в каталог технологического журнала при некоторых его настройках могут выводится данные очень большого объема. Поэтому на диске, где будут храниться данные журнала регистрации, должно быть достаточно места. Для работы технологического журнала необходимо, чтобы пользователи, от имени которых запускаются приложения 1С:Предприятия (как клиентские, так и серверные), имели полные права на каталог технологического журнала (D:\1cv82\logs), и право на чтение выше лежащего каталога (D:\1cv82).

ВНИМАНИЕ ! Необходимо иметь в виду, что каталог технологического журнала не предназначен для хранения в нем файлов, которые не относятся к технологическому журналу. Поэтому не следует размещать в нем дампы или использовать каталог, который может содержать файлы, не относящиеся к технологическому журналу «1С:Предприятия». Если в каталоге, который указан в качестве каталога
технологического журнала, имеются посторонние файлы, то указание каталога считается неверным, и технологический журнал не создается.

Система «1С:Предприятие» автоматически, с периодичностью 60 секунд, опрашивает каталоги конфигурационных файлов на предмет наличия файла logcfg.xml и анализирует его состав. Таким образом, изменение параметров технологического журнала может быть выполнено на ходу, без перезапуска работающих приложений системы «1С:Предприятие».

Далее приведены несколько примеров файлов logcfg.xml, содержащих наиболее часто используемые конфигурации технологического журнала.

Технологический журнал выключен

Если файл logcfg.xml отсутствует или имя файла не равно «logcfg.xml» (например logcfg_1.xml)в каталоге C:\Program Files\1cv82\bin\conf, то технологический журнал не создается. Если файл logcfg.xml необходим для правильной настойки дампов, то он не должен содержать ни одного элемента log.

Следующий пример определяет необходимость построения полного дампа приложения при его аварийном завершении. Дампы помещаются в каталог: D:\1cv82\dumps.

Полный технологический журнал

Приведенный ниже конфигурационный файл определяет вывод в технологический журнал всех событий вместе со всеми свойствами. Журнал будет сохраняться в течении 2 суток (48 часов). Объем выводимой информации при этом будет очень большим, однако, она может быть полезна при анализе сложных нештатных ситуаций. Данную конфигурацию рекомендуется использовать на этапе тестирования и при расследовании ошибок.

Обращения к СУБД

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

Источник