Powershell: Анализ технологического журнала. Топ-25 вызовов.

Публикация № 1458982 16.06.21

Администрирование - Производительность и оптимизация (HighLoad) - Технологический журнал

Powershell ТехнологическийЖурнал ТЖ Анализ

Использование Powershell для анализа технологического журнала 1с. Пример получения топ-25 вызовов

Понадобилось мне пропарсить технологический журнал, но во всех обучающих статьях используются утилиты и linux. В то же время большинство 1с серверов стоят на windows машинах, где есть powershell, возможностей у которого не меньше. В этой статье мой вариант скрипта top 25 call-вызовов используя инструмент от microsoft.

Тестирование скрипта проходило на платформе 8.3.17.

Сразу привожу полный код, подробное объяснение ниже. Внимание! Скрипт написал на Powershell 5.1:

$inputFile = "E:\exchange\logs_analyze\call\*\*.log"
$searchPattern = "^(?<time>\d\d:\d\d.\d+)-(?<dur>\d+),(?<eventName>CALL),.+Context=(?<context>.+),Interface.+Memory=(?<memory>-*\d+),.+CpuTime=(?<cputime>\d+)"

Select-String -Path $inputFile -Pattern $searchPattern |
ForEach-Object{
    $dur,$eventName,$context,$memory,$cputime = $_.Matches[0].Groups[2..6].Value
    [PSCustomObject] @{
        Duration = [math]::Round($dur/1000000,2)
        EventName = $eventName
        Memory = $memory
        Context = $context
        CpuTime = $cputime
    }
} | Group-Object Context | 
ForEach-Object{
    $measureDur, $measureCPU=$_.Group | Measure-Object Duration,CpuTime -Sum -Average -Maximum
    [PSCustomObject] @{
        DurSum = $measureDur.Sum
        DurAvr = [math]::Round($measureDur.Average,2)
        cpuSum = $measureCPU.Sum
        cpuAvr = [math]::Round($measureCPU.Average,2)
        cpuMax = $measureCPU.Maximum
        Count = $measureDur.Count
        Context = $_.Name
    }
} |
Sort-Object -Property "cpuMax" -Descending | Select-Object -First 10 | Out-GridView

Подробное объяснение

Начинаем с объявления переменных и задаем регулярное выражение для разбора данных.

$inputFile = "E:\exchange\logs_analyze\call\*\*.log"
$searchPattern = "^(?<time>\d\d:\d\d.\d+)-(?<dur>\d+),(?<eventName>CALL),.+Context=(?<context>.+),Interface.+Memory=(?<memory>-*\d+),.+CpuTime=(?<cputime>\d+)"

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

"^(?<time>\d\d:\d\d.\d+)-(?<dur>\d+),

/d - означает любую цифру, а /d+ - любое количество цифр. Поэтому когда мы пропарсим строку вида "00:09.509005-150", мы получим группу time содержащую "00:09.509005" и группу dur содержащую "150"

Context=(?<context>.+),

В группу context помещаем все, что между Context= и запятой. Аналогично с группой memory и cputime.

Читаем данные:

Select-String -Path $inputFile -Pattern $searchPattern

Вызываем команду Select-String, аналог grep, куда передаем наши переменные

Первый цикл и создание объектов:

ForEach-Object{
    $dur,$eventName,$context,$memory,$cputime = $_.Matches[0].Groups[2..6].Value
    [PSCustomObject] @{
        Duration = [math]::Round($dur/1000000,2)
        EventName = $eventName
        Memory = $memory
        Context = $context
        CpuTime = $cputime
    }
}

Pipeline в Powershell работает с объектами, поэтому нам надо вытащить полученные группы и превратить их в объекты, которые передадим дальше. Select-String возвращает объект MatchInfo из которого надо получить группы.

$dur,$eventName,$context,$memory,$cputime = $_.Matches[0].Groups[2..6].Value

В данной строке мы берем значения групп с 3 по 7 и присваиваем их переменным. Вторая группа(time) нам сейчас не интересна, а в первой группе(с индексом 0) содержится вся строка целиком, ее добавляет сам Powershell. 

[PSCustomObject] @{
        Duration = [math]::Round($dur/1000000,2)
        EventName = $eventName
        Memory = $memory
        Context = $context
        CpuTime = $cputime
    }

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

Группировка:

Group-Object Context

объединяем наши созданные объекты по контексту

Второй цикл и новые объекты:

ForEach-Object{
    $measureObj, $measureCPU=$_.Group | Measure-Object Duration,CpuTime -Sum -Average -Maximum
    [PSCustomObject] @{
        DurSum = $measureObj.Sum
        DurAvr = [math]::Round($measureObj.Average,2)
        cpuSum = $measureCPU.Sum
        cpuAvr = [math]::Round($measureCPU.Average,2)
        cpuMax = $measureCPU.Maximum
        Count = $measureObj.Count
        Context = $_.Name
    }
}

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

Measure-Object Duration,CpuTime -Sum -Average -Maximum

На вход получает сгруппированные данные и считает сумму, среднее и максимум по реквизитам Duration и CpuTime, если нужно еще Memory, то именно сюда его нужно добавить.

Сортировка и выбор:

Sort-Object -Property "cpuMax" -Descending | Select-Object -First 25

Сортируем наши объекты по полю cpuMax и выбираем первые 25

Получаем результат:

Out-GridView

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

Скачать файлы

Наименование Файл Версия Размер
ps51_call_top25

.ps1 1,08Kb
1
.ps1 1,08Kb 1 Скачать

Специальные предложения

Комментарии
В избранное Подписаться на ответы Сортировка: Древо развёрнутое
Свернуть все
1. Famza 84 16.06.21 11:51 Сейчас в теме
Отлично! Только надо еще и код техжурнала добавить - у него тоже параметров не мало. Тогда видно будет, что выбираем ТЖ и PowerShell-ом разбираем. Я не знаком с PowerShell, например.
2. Dimashiro 57 16.06.21 13:44 Сейчас в теме
не совсем понял, что именно интересует? параметры настройки ТЖ, или сам пример строки, которая попадает под регулярное выражение?
3. Cmapnep 14 17.06.21 09:32 Сейчас в теме
Хотелось бы видеть сравнение "традиционного" подхода (через команды bash) и предлагаемого по производительности
При размерах ТЖ в сотни гектар производительность выходит на первый план
11. Dimashiro 57 18.06.21 11:27 Сейчас в теме
13. capitan 2094 21.06.21 16:27 Сейчас в теме
(7)Если есть желание померяться с гитбашем закиньте логи в любое облако
(3)
4. Shmell 391 17.06.21 10:12 Сейчас в теме
Нужно взять на заметку. Вариант, когда нет желания устанавливать git bash только ради просмотра ТЖ....
12. capitan 2094 21.06.21 16:22 Сейчас в теме
(4)Есть нюансы
git bash не обязательно устанавливать, достаточно распаковать
5. swenzik 17.06.21 13:07 Сейчас в теме
скрипт довольно быстро съедает всю память и вываливается с исключением out of memory. за Out-GridView спасибо!
6. Dimashiro 57 17.06.21 13:58 Сейчас в теме
(5) Powershell любит есть память, у меня правда не вываливался, попробую насобирать большой объем данных и потестировать еще. Да, Out-GridView - шикарен, всегда пожалуйста
7. Dimashiro 57 17.06.21 14:15 Сейчас в теме
(5) Подскажите какой объем логов вы пытались проанализировать? У меня был небольшой кусок полных логов, около 14Гб, максимальный объем памяти, который понадобился скрипту, чтобы их прожевать 270Мб
8. swenzik 17.06.21 14:18 Сейчас в теме
(7) 1Гб но я переделал скрипт под
$searchPattern = "^(?<time>\d\d:\d\d.\d+)-(?<dur>\d+),(?<eventName>TLOCK),.+Context=(?<context>.+)"
со всеми сопутствующими правками в обоих циклах
9. Dimashiro 57 17.06.21 15:07 Сейчас в теме
(8) в вашем шаблоне поиска получается, что все символы, которые идут после Context= и до конца строки, будут помещены в группу context включая Interface и т.д. Не помню что точно выводится в TLOCK, но возможно в контекст попадает лишнее
14. capitan 2094 21.06.21 16:28 Сейчас в теме
(8)
(9)
А вот интересно - многострочный контекст он отработает ?
15. swenzik 21.06.21 16:31 Сейчас в теме
(14) в таком варианте нет, надо изобретать что-то типа (если требуется зацепить только последнюю строку контекста)
$searchPattern = "^(?<time>\d\d:\d\d.\d+)-(?<dur>\d+),(?<eventName>TLOCK),.+Context='[\s\S]+?\t+(?<context>.+)'$"
но это лучше спросить у настоящих сварщиков, регекспом это можно отработать точно
16. capitan 2094 21.06.21 16:48 Сейчас в теме
(15)Ага
Угу
В этом то и весь цимес.
10. пользователь 17.06.21 21:05
Сообщение было скрыто модератором.
Прикрепленные файлы:
...
Оставьте свое сообщение

См. также

Автоматизация анализа файлов технологического журнала Промо

Технологический журнал v8 Россия Абонемент ($m)

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

1 стартмани

14.02.2012    33921    77    Aleksey.Bochkov    18    

Просмотр файлов технологических журналов 1С (WinAPI)

Производительность и оптимизация (HighLoad) Технологический журнал v8 Россия Абонемент ($m)

Программа просмотра файлов технологических журналов 1С (WinAPI). Работает с большими файлами. Минимальное потребление памяти при индексировании данных, просмотре. Анализ управляемых взаимоблокировок, таймаутов, ожиданий. Фильтры по событиям, периоду, пользователям, соединениям, сеансам.

1 стартмани

24.08.2021    1111    6    sdf1979    2    

Оперативный мониторинг управляемых блокировок и серверных вызовов кластера 1С (windows сервис BETA расширения функционала конфигурации "Центр Контроля Качества")

Технологический журнал ЦКК v8 v8::blocking Абонемент ($m)

Windows сервис расширения функционала счетчиков производительности конфигурации "Центр Контроля Качества". Собирает и агрегирует информацию из технологического журнала об управляемых блокировках (TLOCK, TDEADLOCK, TTIMEOUT), а так же серверных вызовов (CALL в разрезе p:processName для процессов rphost и в разрезе IName для процессов ragent и rmngr). Агрегированная информация каждую минуту отправляется по http в конфигурацию ЦКК и там представлена в виде счетчиков производительности.

1 стартмани

29.03.2021    1851    1    sdf1979    0    

Парсер технологического журнала (golang + redis + elasticsearch)

Технологический журнал v8 1cv8.cf Абонемент ($m)

На просторах интернета, в том числе на данном ресурсе содержится разнообразное количество инструментов, позволяющих читать, трансформировать логи технологического журнала. Инструмент, который я описываю в данной статье, - является альтернативным вариантом, реализованным на стеке технологий Goroutines (golang) + Redis + Elasticsearch.

1 стартмани

07.01.2021    6289    3    Shmell    14    

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

Технологический журнал v8 Россия Абонемент ($m)

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

1 стартмани

24.04.2009    42282    2137    Широкий    127    

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

Тестирование и исправление Технологический журнал v8 1cv8.cf Россия Абонемент ($m)

При разработке конфигурации в клиент-серверном варианте могут возникнуть проблемы при загрузке конфигурации в файловый вариант. В статье описан один из вариантов решения проблемы.

1 стартмани

28.01.2020    6043    3    newtraveller    0    

V8 Log Scanner - утилита для быстрого парсинга логов ТЖ

Сервисные утилиты Технологический журнал v8 Россия Абонемент ($m)

Как можно быстро настраивать logcfg.xml и парсить логи технологического журнала с помощью самописной open-source утилиты V8LogScanner. Без необходимости погружаться в регулярные выражения.

1 стартмани

07.11.2017    24017    5    ripreal1    27    

Techlogqueryviewer - Вьювер запросов к СУБД из технологического журнала 1С: Предприятие

Технологический журнал v8 1cv8.cf Абонемент ($m)

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

1 стартмани

14.08.2016    8514    9    KAV2    8    

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

Технологический журнал v8 1cv8.cf Россия Абонемент ($m)

Простой, шустрый и легкий в использовании off-line парсер технологического журнала 1С.

5 стартмани

06.12.2015    23866    94    sarycheff    29    

Анализ технологического журнала утечек памяти

Технологический журнал v8 1cv8.cf Абонемент ($m)

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

1 стартмани

14.11.2015    20393    70    logarifm    13    

Анализ технологического журнала

Технологический журнал v8 1cv8.cf Абонемент ($m)

Конфигурация, облегчающая анализ технологического журнала 1С: Предприятие 8 посредством загрузки данных технологического журнала в базу с последующей возможностью анализа при помощи специализированного отчета.

1 стартмани

19.08.2015    15442    187    liurn    8    

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

Технологический журнал v8 1cv8.cf Абонемент ($m)

Как получить правильный logcfg.xml

1 стартмани

11.01.2013    39468    253    romansun    14    

Анализ исключений в технологическом журнале 8.2

Технологический журнал v8 1cv8.cf Россия Абонемент ($m)

Конфигурация позволяет загружать данные технологического журнала извлекая из него исключения (EXCP) и сохраняет их в базу данных, при сохранении производится парсинг, класиффицирующий ошибки по уже известным. Позволяет постфактум проанализировать статистику работы системы, выявить проблемы, оценить мероприятия по отказоустойчивасти Функционал: 1. Анализируется технологический по событиям EXCP и CALL. Загрузка производится из сетевого каталога на стороне сервера 2. По вхождению подстроки в событие определяется «тип ошибки» (справочник заполняется пользователем) 3. В случае добавления в спр новой типовой ошибки – можно повторно пропарсить уже загруженные события 4. Есть свертка базы (удаление записей с датой менее ДатаЧ) 5. Объединено с БСП, использованы подсистемы: отчетов и обновлений

1 стартмани

13.06.2012    10485    100    xoxland    5    

Парсинг технологического журнала 1С средствами SQL CLR

Технологический журнал v8 1cv8.cf Россия Абонемент ($m)

В статье рассказывается о том как реализовать парсинг (разбор) файлов технологического журнала c помощью SQL CLR, а также настроить хранение информации из него в базе данных. В статье приведен полный листинг функции, а также примеры использования.

1 стартмани

29.11.2011    20387    261    squad    25