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

16.06.21

База данных - Технологический журнал

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

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

Наименование Файл Версия Размер
ps51_call_top25
.ps1 1,08Kb
12
.ps1 1,08Kb 12 Скачать

Понадобилось мне пропарсить технологический журнал, но во всех обучающих статьях используются утилиты и 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

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

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

См. также

Магия преобразований Vector, часть 2: технологический журнал

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

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

1 стартмани

15.11.2023    765    4    AlexSTAL    0    

8

Магия преобразований: ЖР, ТЖ, RAS/RAC, логи - универсальное решение Vector

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

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

1 стартмани

13.11.2023    2967    4    AlexSTAL    0    

42

«Монитор» – простой анализ производительности

Администрирование СУБД Технологический журнал Бесплатно (free)

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

21.09.2023    5722    Andreynikus    14    

79

Экспорт технологического журнала 1С в Elastic с помощью Logstash

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

Целью данного решения является организация хранения и анализа данных из технологического журнала 1С с использованием стека Elasticsearch + Logstash + Kibana.

5 стартмани

18.09.2023    3276    huxuxuya    3    

23

Мобильный помощник эксперта 1С (приложение android, позволяющее строить отчеты на СКД по логам технологического журнала и не только)

Технологический журнал Мониторинг Платформа 1С v8.3 Конфигурации 1cv8 Бесплатно (free)

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

16.05.2023    3317    capitan    0    

23

Разбор технологического журнала без боли и страданий

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

Технологический журнал - мощный инструмент логирования, используемый для анализа проблем производительности 1С. Но он обладает одним огромным недостатком, в "сыром виде" он почти не поддается адекватному анализу из-за своей структуры. Существует довольно много способов "разобрать" технологический журнал, но все опробованные способы обладают теми или иными недостатками. Предлагаю вам мой вариант "велосипеда" для разбора ТЖ и хранения разобранного в различных форматах.

1 стартмани

12.12.2022    8154    37    Segate    26    

86

Выполняем в СУБД запрос из ТЖ

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

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

1 стартмани

24.11.2022    2856    3    VKislitsin    1    

17
Комментарии
В избранное Подписаться на ответы Сортировка: Древо развёрнутое
Свернуть все
1. Famza 84 16.06.21 11:51 Сейчас в теме
Отлично! Только надо еще и код техжурнала добавить - у него тоже параметров не мало. Тогда видно будет, что выбираем ТЖ и PowerShell-ом разбираем. Я не знаком с PowerShell, например.
2. Dimashiro 64 16.06.21 13:44 Сейчас в теме
не совсем понял, что именно интересует? параметры настройки ТЖ, или сам пример строки, которая попадает под регулярное выражение?
3. Cmapnep 18 17.06.21 09:32 Сейчас в теме
Хотелось бы видеть сравнение "традиционного" подхода (через команды bash) и предлагаемого по производительности
При размерах ТЖ в сотни гектар производительность выходит на первый план
11. Dimashiro 64 18.06.21 11:27 Сейчас в теме
13. capitan 2466 21.06.21 16:27 Сейчас в теме
(7)Если есть желание померяться с гитбашем закиньте логи в любое облако
(3)
4. Shmell 533 17.06.21 10:12 Сейчас в теме
Нужно взять на заметку. Вариант, когда нет желания устанавливать git bash только ради просмотра ТЖ....
12. capitan 2466 21.06.21 16:22 Сейчас в теме
(4)Есть нюансы
git bash не обязательно устанавливать, достаточно распаковать
5. swenzik 17.06.21 13:07 Сейчас в теме
скрипт довольно быстро съедает всю память и вываливается с исключением out of memory. за Out-GridView спасибо!
6. Dimashiro 64 17.06.21 13:58 Сейчас в теме
(5) Powershell любит есть память, у меня правда не вываливался, попробую насобирать большой объем данных и потестировать еще. Да, Out-GridView - шикарен, всегда пожалуйста
7. Dimashiro 64 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 64 17.06.21 15:07 Сейчас в теме
(8) в вашем шаблоне поиска получается, что все символы, которые идут после Context= и до конца строки, будут помещены в группу context включая Interface и т.д. Не помню что точно выводится в TLOCK, но возможно в контекст попадает лишнее
14. capitan 2466 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 2466 21.06.21 16:48 Сейчас в теме
(15)Ага
Угу
В этом то и весь цимес.
10. пользователь 17.06.21 21:05
Сообщение было скрыто модератором.
...
17. user1746472 20.10.22 12:33 Сейчас в теме
скрипт после запуска думает 5 минут и возвращается в командную строку. больше ничего не происходит :(
18. iurum 01.12.22 10:49 Сейчас в теме
Попробовал на типовом техжурнале - никакого отчета не отобразилось. Может нужен ТЖ с определенными настройками?
Оставьте свое сообщение