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

16.06.21

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

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

Скачать исходный код

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

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

См. также

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

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

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

вчера в 08:30    1247    kuzyara    1    

47

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

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

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

1 стартмани

15.11.2023    873    4    AlexSTAL    0    

8

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

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

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

1 стартмани

13.11.2023    3277    5    AlexSTAL    0    

44

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

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

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

21.09.2023    5995    Andreynikus    14    

80

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

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

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

5 стартмани

18.09.2023    3588    huxuxuya    3    

23

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

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

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

16.05.2023    3527    capitan    0    

24

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

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

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

1 стартмани

12.12.2022    8481    39    Segate    26    

89
Комментарии
Подписаться на ответы Инфостарт бот Сортировка: Древо развёрнутое
Свернуть все
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 2475 21.06.21 16:27 Сейчас в теме
(7)Если есть желание померяться с гитбашем закиньте логи в любое облако
(3)
4. Shmell 535 17.06.21 10:12 Сейчас в теме
Нужно взять на заметку. Вариант, когда нет желания устанавливать git bash только ради просмотра ТЖ....
12. capitan 2475 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 2475 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 2475 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 Сейчас в теме
Попробовал на типовом техжурнале - никакого отчета не отобразилось. Может нужен ТЖ с определенными настройками?
Оставьте свое сообщение