Многострочный контекст событий

26.03.21

База данных - HighLoad оптимизация

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

Постановка задачи.

Иногда для событий (например) DBMSQL контекст вызова содержит несколько строк. Пример  можно найти в ИТС, по ключевым словам awk –vORS=. Рассмотрим этот случай подробнее.

Bash-cкрипты тестировал на технологическом журнале, платформа 8.3.12, управляемые формы. Пропустим установку bash и сбор технологического журнала, желающие - смотрите //infostart.ru/public/825405/

Основная версия скрипта анализа дополнительного контекста событий.

#!/bin/bash
printf "%20s%20s%20s%20s", "Duration/Count", "Duration", "Count", "Context" \
; echo \
; time cat $@ \
| awk -vORS= '{ \
if ($0~"^[0-9][0-9].{10,30}DBMSSQL") { print "\n"$0;} \
else if ($0~"^[0-9][0-9]:[0-9][0-9]") { print "\n"; } \
else { gsub("\t","",$0); print "-"$0; } \
}' \
| egrep '^[0-9][0-9].{10,30}DBMSSQL.*,Context=' \
| awk -F'-|(,DBMSSQL.*?,Context=)' '{ \
LastContext=substr($NF,1,90); \
FirstContext=substr($2,1,90); \
if (length(FirstContext)<9) {FirstContext=substr($3,1,90);} \
Duration[LastContext]+=$2; Count[LastContext]+=1; \
} \
END { for (i in Count) \
{printf "%20d%20d%20d%5s%-90s\n", \
Duration[i]/(Count[i]*1000000),Duration[i]/1000000,Count[i],"\t",i \
}}' \
| sort -rnb \
| head -n20

Файл *.sh запускать в каталоге с подкаталогами rphost, параметры командной строки например ./script.sh "rphost*/200330*.log". Вызов команды начинается точка-слэш, иначе будет "command not found".


Построчный комментарий:
1.    Печать заголовка: частное "Duration/Count", колонки "Duration", "Count", "Context"
2.    Отделить заголовок от таблицы
3.    Начинаем замер времени, считываем файлы по маске - параметр командной строки
4.    Начинаем awk, обрабатываем каждую полученную строку. Опция –vORS= означает, что внутренней переменной ORS присвоено пустое значение. При выводе записей awk символ начала строки «\n», не будет добавляться автоматически, необходимо добавлять явно.
5.    Если событие DBMSSQL, то выводим исходную строку «с новой строки»
6.    Если строка начинается с минуты-секунды, то это какое-то событие, но не контекст и не DBMSSQL. Выводим символ перехода строки.
7.    Иначе выводим строку, из которой функция gsub убирает символы табуляции.  Выводим тире как разделитель.
8.    Закончена обработка awk (4).
9.    Фильтруем строки, содержащие DBMSSQL и контекст.
10.    Разделители подобраны так, что $2 = длительность, $2 = первая строка контекста, $3 = вторая строка контекста, $NF = последняя строка контекста.
11.    Вырезаем первые 90 символов для последней строки контекста. Это лучше для сортировки и вывода на экран.
12.    Вырезаем первые 90 символов для первой строки контекста. Это лучше для сортировки и вывода на экран.
13.    Если первая строка неинформативная, то используем вторую строку контекста.
14.    Суммируем длительность и количество событий для последней строки. Если нужна первая строка – здесь заменяем LastContext на FirstContext.
15.    после окончания обработки строк awk(10) начинаем цикл
16.    формат колонок "%20d%20d%20d%5s%-60s\n"
17.    печатаем накопленные переменные  в виде таблицы.
18.    Заканчиваем обработку итогов awk (10).
19.    Сортируем таблицу по убыванию
20.    Выводим первые 20 строк

Дополнительные бонусы.

Похожим скриптом можно искать объектное чтение. Для этого нужно добавить фильтр со словом "Version" в текст запроса. При объектном чтении платформа считывает версию объекта

| awk -vORS= '{ \
if ($0~"^[0-9][0-9].{10,30}DBMSSQL.{180,220}SELECT.{4,6}Version") { print "\n"$0;} \
else if ($0~"^[0-9][0-9]:[0-9][0-9]") { print "\n"; } \
else { gsub("\t","",$0); print "-"$0; } \
}' \

Группы строк, которые начинаются ^.{12,25},Context, появляются в технологическом журнале при запуске из толстого клиента внешних обработок. Поэтому в этой статье их не рассматриваем.

Модификация первого скрипта с группировкой по событиям. Можно найти события SDBL, длительность которых существенно отличается от соответствующих событий DBMSSQL. Это отличие (highly likely) говорит об большом объеме передаваемых данных от СУБД серверу приложений.

#!/bin/bash
printf "%10s%10s%10s%20s", "Duration", "Count", "Event", "Context" \
; echo \
; time cat */*.log \
| awk -vORS= '{ \
if ($0~"^[0-9][0-9].{10,30},(DBMSSQL|SDBL|EDS)") { print "\n"$0;} \
else if ($0~"^[0-9][0-9]:[0-9][0-9]") { print "\n"; } \
else { gsub("\t","",$0); print "-"$0; } \
}' \
| egrep '^[0-9][0-9].{10,30},(DBMSSQL|SDBL|EDS).*,Context=' \
| awk -F'-|(,(DBMSSQL|SDBL|EDS).*?,Context=)' '{ \
Event=$0; \
sub("^.{12}-[0-9]{0,9},","",Event); \
sub(",.*$","",Event); \
LastContext=substr($NF,1,120); \
FirstContext=substr($2,1,120); \
if (length(FirstContext)<9) {FirstContext=substr($3,1,120);} \
Duration[LastContext,Event]+=$2; Count[LastContext,Event]+=1; \
Context[LastContext,Event]=LastContext; Events[LastContext,Event]=Event; \
} \
END { for (i in Count) \
{printf "%10d%10d%10s%5s%-120s\n", \
Duration[i]/1000000,Count[i],Events[i],"\t",Context[i] \
}}' \
| sort -rnb \
| head -n90

 

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

 

 
 Обновление от 09/2020. Немного модифицировал скрипт для SDBL.

 

технологический bash context регулярные Богачев grep egrep awk gawk cat sed print printf echo sort logcfg

См. также

Анализируем SQL сервер глазами 1С-ника

HighLoad оптимизация Инструменты администратора БД Платформа 1С v8.3 Конфигурации 1cv8 Абонемент ($m)

Обработка для простого и удобного анализа настроек, нагрузки и проблем с SQL сервером с упором на использование оного для 1С. Анализ текущих зааросов на sql, ожиданий, конвертация запроса в 1с и рекомендации где может тормозить

1 стартмани

15.02.2024    7357    149    ZAOSTG    66    

95

Удаление строк из таблицы значений различными способами с замером производительности

HighLoad оптимизация Платформа 1С v8.3 Конфигурации 1cv8 Абонемент ($m)

Встал вопрос: как быстро удалить строки из ТЗ? Рассмотрел пять вариантов реализации этой задачи. Сравнил их друг с другом на разных объёмах данных с разным процентом удаляемых строк. Также сравнил с выгрузкой с отбором по структуре.

09.01.2024    5766    doom2good    48    

63

Опыт оптимизации 1С на PostgreSQL

HighLoad оптимизация Бесплатно (free)

При переводе типовой конфигурации 1C ERP/УТ/КА на PostgreSQL придется вложить ресурсы в доработку и оптимизацию запросов. Расскажем, на что обратить внимание при потерях производительности и какие инструменты/подходы помогут расследовать проблемы после перехода.

20.11.2023    8590    ivanov660    6    

75

ТОП проблем/задач у владельцев КОРП лицензий 1С на основе опыта РКЛ

HighLoad оптимизация Бесплатно (free)

Казалось бы, КОРП-системы должны быть устойчивы, быстры и надёжны. Но, работая в рамках РКЛ, мы видим немного другую картину. Об основных болевых точках КОРП-систем и подходах к их решению пойдет речь в статье.

15.11.2023    4999    a.doroshkevich    20    

72

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

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

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

1 стартмани

13.11.2023    2883    4    AlexSTAL    0    

42

Начните уже использовать хранилище запросов

HighLoad оптимизация Запросы

Очень немногие из тех, кто занимается поддержкой MS SQL, работают с хранилищем запросов. А ведь хранилище запросов – это очень удобный, мощный и, главное, бесплатный инструмент, позволяющий быстро найти и локализовать проблему производительности и потребления ресурсов запросами. В статье расскажем о том, как использовать хранилище запросов в MS SQL и какие плюсы и минусы у него есть.

11.10.2023    15962    skovpin_sa    14    

98

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

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

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

21.09.2023    5667    Andreynikus    14    

79
Комментарии
В избранное Подписаться на ответы Сортировка: Древо развёрнутое
Свернуть все
1. VKislitsin 958 31.03.20 13:31 Сейчас в теме
Николай, и снова плюс.
Особенно интересным мне показался последний бонус, со сравнением длительности SDBL и входящих в него DBMSSQL.
2. vasilev2015 2677 31.03.20 13:40 Сейчас в теме
(1) Здравствуйте !

Спасибо на добром слове.
Думаю, могут быть интересны и другие события.
3. RustIG 1301 01.04.20 08:49 Сейчас в теме
Добрый день!
Вопрос: 1С (СУБД) - ТЖ - Анализатор ТЖ. В этой цепи ТЖ является промежуточным звеном.

Уже задавали вопрос, повторю его :
почему вместо изучения регулярок и сдачи их на экзамене просто не поменять формат журнала технологического
?

Поясните, пож-та.
4. vasilev2015 2677 01.04.20 10:00 Сейчас в теме
(3) Здравствуйте, Рустем !

Возможно, разработчики когда-то озаботятся этим вопросом.
Какой формат ТЖ мы хотели бы видеть ?
Пока просто выкладываю код - по образцу stackoverflow.
Для всех и для себя. Чтобы запомнить.
5. RustIG 1301 01.04.20 11:32 Сейчас в теме
(4) да, спасибо.
мой вопрос 50/50: сам вроде понимаю, что нет серебряной пули - событий много и разных.
в секунду несколько событий на разном уровне транзакций СУБД.
своих идей нет.
6. starik-2005 3031 03.04.20 00:22 Сейчас в теме
(4)
Какой формат ТЖ мы хотели бы видеть ?
Json, например. И было бы просто супер, если можно было бы несколько файлов конфигурационных для сбора техжурнала прописать, и получить отдельные события в разных файлах (а может это уже есть?)
asved.ru; +1 Ответить
7. vasilev2015 2677 03.04.20 10:20 Сейчас в теме
(6) Здравствуйте, Сергей !

Мне кажется, написать транслятор (переводчик) существующего журнала в формат JSON - несложная задача, за несколько дней можно сделать. Думаете, это будет иметь спрос среди нашего общества ? Вы сами готовы инвестировать в это дело 2-3 SM ?

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

но я стараюсь, чтобы скрипты работали в универсальном случае, поскольку журнал существенно меняется вместе с платформой 1С.
8. starik-2005 3031 03.04.20 10:35 Сейчас в теме
(7)
Мне кажется, написать транслятор (переводчик) существующего журнала в формат JSON - несложная задача,
Так в принципе и делать-то ничего не надо - все уже сделали тут и тут как минимум (фактически преобразование CSV в JSON). Я бы это предложил товарищам из 1С сделать.

Чем это хорошо? json хорошо парсится всеми скриптовыми языками, в постгресе даже есть поля типа jsonb, к которым можно делать запросы, ну и эластик, который работает с JSON'ом (пример с хабра):
curl -XPUT "$ES_URL/blog/post/1?pretty" -d'
{
  "title": "Веселые котята",
  "content": "<p>Смешная история про котят<p>",
  "tags": [
    "котята",
    "смешная история"
  ],
  "published_at": "2014-09-12T20:44:42+00:00"
}'
Показать
ИМХО, в части девопса json может быть проще обработан скриптами "без программирования" ETL, которое приходится "программировать" всяческими вот такими скриптами с awk.

А по поводу создания нескольких настроек ТЖ, то тут ведь разные события и разное время реакции на них должно быть. Если rphost помер - это одно, а если это запрос длительный - другое. Запускать регламенты анализа для одного и другого можно с разным "временным квантом".

С другой стороны, 1С сама за АПДЕКС, который совершенно без лицеприятия четко и конкретно указывает, укладываются ли все операции в целевое время, а если не все, то как много тех, которые не укладываются. Вот и предмет анализа. Было бы круто при определенном падении апдекса в течение заданного времени автоматом переводить систему в режим анализа (чтобы еще сильнее ее просадить, но собрать нужные для разбирательства с проблемами данные). И вообще апдекс надо уже засунуть в саму платформу, а не в обертку сверху.
9. vasilev2015 2677 03.04.20 11:02 Сейчас в теме
(8) спасибо, интересные предложения.
11. Andreynikus 1360 12.05.21 22:38 Сейчас в теме
(8)
Оставлю на всякий случай предостережение, что бы кто-нибудь ненароком не подумал что ТЖ это CSV ))
1. У событий ТЖ свойства могут дублироваться с разными значениям в пределах одного события
2. У значений свойств могут быть запятые, и значения кавычками не выделены (привет всем вашим парсерам)
3. Тексты запросов, контексты и пр. могут быть многострочными
4. ... и еще тыщамильенов нюансов, так что ТЖ это совсем не CSV, а вот устранить описанные косяки и писать ТЖ сразу в формет Json вот это был бы реально прогресс для 1С. Но чувствую что жить в эту пору прекрасную ...
10. AlekseyBelyy 9 21.02.21 12:52 Сейчас в теме
прикольно, спасибо за статью.
почему никто при формировании таблицы результата анализа логов скриптами не использует команду column?
ведь красивая же табличка получается, отформатированная.
... | column -t -s"@" -N"Total Mem Peak(Mb),Max Mem Peak(Mb),Avg Mem Peak(Mb),Number of execs,Context" -O"5,1,2,3,4" -R"1,2,3,4"
Прикрепленные файлы:
12. kuza_87 28 05.06.22 21:55 Сейчас в теме
(10)
| column -t -s"@" -N"Total Mem Peak(Mb),Max Mem Peak(Mb),Avg Mem Peak(Mb),Number of execs,Context" -O"5,1,2,3,4" -R"1,2,3,4
А есть пример скрипта с использованием column? А то у меня какая-то размазня получается
Оставьте свое сообщение