Получение top 25 вызовов в клиент-серверном режиме работы с наибольшей суммарной длительностью
Надеюсь, читатель встречал такую статью на ИТС. Постарался написать о том же, но по-новому, без заимствований. Благодарю Виктора Богачева за предоставленные методические материалы и поддержку.
Bash-cкрипты тестировал на технологическом журнале, платформа 8.3.12. Это важно, ведь формат событий CALL значительно изменялся от версии к версии:
- 8.3.1 добавлены свойства Report, Method, SessionID, Memory, MemoryPeak, InBytes, OutBytes, Context.
- 8.3.6 добавлены свойства IName, MName
- 8.3.8 добавлено свойство Usr
Получение полей Usr, Context в версии 8.2 было более трудным.
Пропустим установку bash и сбор технологического журнала. Возьмем быка за рога !
Упрощенная (первая) версия скрипта анализа длительности вызовов.
printf "%15s%15s%15s%15s%-30s%-90s", "Memory(Mb)", "Duration(sec)", "Quantity", "SessionID", "Usr", "Context" \
; printf "%s\n" \
; egrep '^[0-9][0-9].{9,25},CALL,.*,Usr=[^,]+,SessionID=[^,]+,Context=[^,]+,Interface=.*,Memory=.*,MemoryPeak=' -h -R --include "*.log" \
| awk -F'(^.{13})|(,CALL,.*Usr=)|(,SessionID=)|(,Context=)|(,Interface=.*,Memory=)|(,MemoryPeak=)' \
'{ Memory[$4,$3,$5]+=$6; Duration[$4,$3,$5]+=$2; Usr[$4,$3,$5] = $3; SessionID[$4,$3,$5] = $4; Context[$4,$3,$5] = $5; Quantity[$4,$3,$5]+=1} \
END {for (i in Memory) {printf "\n%15d%15d%15d%15s\t%-30s%-90s", Memory[i]/1000000, Duration[i]/1000000, Quantity[i], SessionID[i], Usr[i], Context[i]}}' \
| sort -rnb \
| head -n20
Комментарии к коду:
Знак «\» - в конце строки означает, что скрипт продолжается. Для каждой строки подробный комментарий внизу по номеру. Если строка начинается «|» - значит, она получает данные из предыдущей строки. Если строка начинается «;» - значит, команда выполняется самостоятельно. Команда awk разбита на строки с 4 по 6 для удобства чтения.
- Печать заголовка таблицы. Колонки с помощью команды printf по форматной строке "%15s%15s%15s%15s%-30s%-90s". Цифры означают ширину колонок, s – строковый формат, d – числовой. Полученная таблица прекрасно переносится из Bash-консоли в Excel.
- Разделительная строка между заголовком и данными табличной части
- Считываем данные из файлов текущего каталога и ниже, рекурсивно. Используем маску файла *.log Команда cat получает все данные, а egrep – только строки заданного формата.
- В параметре F разделители подобраны таким образом, чтобы переменные awk соответствовали параметрам Memory=$6; Duration=$2; Usr=$3; SessionID=$4; Context=$5;. Разделители записаны в скобках через ИЛИ. Недостаток такого метода в том, что требуется строка CALL строго определенной структуры, а эти строки имеют очень много вариантов формата. Поэтому скрипт выберет только часть строк. Параметры являются структурой (функцией, группировкой) от Usr, SessionID, Context. На мой взгляд - это самый правильный способ группировки, обоснование ниже.
- Этот участок команды awk выполняется для каждой строки файла. Все переменные группированы по одинаковым аргументам. Это для удобства печати. Память, длительность и количество вызовов – накапливаются.
- Участок «END» команды awk выполняется, когда обработаны все строки. В цикле командой printf по форматной строке "\n%15d%15d%15d%15s\t%-30s%-90s" выводятся строки таблицы. В данном случае переменная Memory печатается раньше, чем Duration, поэтому сортировка будет по объему памяти. Поменяйте их местами (в строке и заголовке), чтобы сделать сортировку по Duration. Можно сортировать по количеству вызовов Quantity, можно считать отношение Duration/ Quantity и сортировать по нему.
- Сортировка по убыванию
- Первые 25 строк выборки.
Проверочная работа.
Подсчитаем общее количество строк и количество строк, подходящих под шаблон. Выведем неподходящие строки.
egrep '^[0-9][0-9].{9,25},CALL,' -h -R --include "*.log" \
| awk '{if ($0~"Usr=[^,]+,SessionID=[^,]+,Context=[^,]+,Interface=.*,Memory=.*,MemoryPeak=") {my[2]+=1;} \
if ($0~"((Context|Module|Method).*,Usr=.*SessionID)|((Context|Module|Method).*SessionID.*,Usr=)") {my[3]+=1;} \
else if ($0~"(,Usr=.*(Context|Module|Method).*SessionID)|(,Usr=.*SessionID.*(Context|Module|Method))") {my[3]+=1;} \
else if ($0~"(SessionID.*(Context|Module|Method).*,Usr=)|(SessionID.*,Usr=.*(Context|Module|Method))") {my[3]+=1;} \
else print $0; \
{my[1]+=1;}} \
END {print my[1],my[2],my[3]}'
Для конкретного файла у меня получились цифры 3084 2235 3027. То есть из всех событий CALL только 60% удовлетворяют формату первого скрипта и 98% содержат Context|Module|Method, Usr, SessionID в какой-то последовательности. Сделаем вторую версию ТОТАЛЬНОЙ. Если переменная отсутствует – будем считать ее значение пустым. Сочетание Module-Method приравняем к контексту, если Context отсутствует.
Основная версия скрипта анализа длительности вызовов.
printf "%15s%15s%15s%15s%-30s%-90s", "Memory(Mb)", "Duration(sec)", "Quantity", "SessionID", "Usr", "Context" \
; printf "%s\n" \
; time egrep '^[0-9][0-9].{9,25},CALL,' -h -R --include "*.log" \
| awk -F'(,|=)' '{ \
ColumnName=3; ColumnVal=4; my[1]=""; my[2]=""; my[3]=""; my[4]=""; my[5]=""; my[6]=0; \
while(ColumnName<NF){ColumnName++; ColumnVal++; \
if ($ColumnName=="Usr") {my[1]=$ColumnVal;} \
else if ($ColumnName=="SessionID") {my[2]=$ColumnVal;} \
else if ($ColumnName=="Context") {my[3]=$ColumnVal;} \
else if ($ColumnName=="Module") {my[4]=$ColumnVal;} \
else if ($ColumnName=="Method") {my[5]=$ColumnVal;} \
else if ($ColumnName=="Memory") {my[6]=$ColumnVal;}}; \
if (my[3]=="") {print $1","$2","$3",Usr="my[1]",SessionID="my[2]",Context="my[4]"_"my[5]",Interface=,Memory="my[6]",MemoryPeak=";} \
else {print $1","$2","$3",Usr="my[1]",SessionID="my[2]",Context="my[3]",Interface=,Memory="my[6]",MemoryPeak=";} \
}' \
| awk -F'(^.{13})|(,CALL,.*Usr=)|(,SessionID=)|(,Context=)|(,Interface=.*,Memory=)|(,MemoryPeak=)' \
'{ Memory[$4,$3,$5]+=$6; Duration[$4,$3,$5]+=$2; Usr[$4,$3,$5] = $3; SessionID[$4,$3,$5] = $4; Context[$4,$3,$5] = $5; Quantity[$4,$3,$5]+=1} \
END {for (i in Memory) {printf "\n%15d%15d%15d%15s\t%-30s%-90s", Memory[i]/1000000, Duration[i]/1000000, Quantity[i], SessionID[i], Usr[i], Context[i]}}' \
| sort -rnb \
| head -n20
Комментарии к коду:
- Печать заголовка таблицы. Колонки с помощью команды printf по форматной строке "%15s%15s%15s%15s%-30s%-90s". Цифры означают ширину колонок, s – строковый формат, d – числовой. Полученная таблица прекрасно переносится из Bash-консоли в Excel.
- Разделительная строка между заголовком и данными табличной части
- Начинаем замер времени, выбираем строки событий CALL.
- С помощью команды awk для каждой строки в цикле перебираем элементы строки, разделители – запятые и равно. Переменная ColumnName возрастает от 3 до NF – предопределенная переменная команды awk.
- Если в строке где-то есть запись например ,Usr=Васильев Николай, то выполнится условие ($ColumnName=="Usr") и значение Васильев Николай попадет в переменную my[1]
- Номер сессии
- Контекст
- Модуль
- Метод
- Память
- Для каждой строки выводим переменные в нужном порядке, с соседними словами чтобы формат подходил под первый скрипт. Если контекст – пустой, то вместо него пишем Module_Method
- В параметре F разделители подобраны таким образом, чтобы переменные awk соответствовали параметрам Memory=$6; Duration=$2; Usr=$3; SessionID=$4; Context=$5;. Разделители записаны в скобках через ИЛИ. Параметры являются структурой (функцией, группировкой) от Usr, SessionID, Context. На мой взгляд - это самый правильный способ группировки, обоснование ниже.
- Этот участок команды awk выполняется для каждой строки файла. Все переменные группированы по одинаковым аргументам. Это для удобства печати. Память, длительность и количество вызовов – накапливаются.
- Участок «END» команды awk выполняется, когда обработаны все строки. В цикле командой printf по форматной строке "\n%15d%15d%15d%15s\t%-30s%-90s" выводятся строки таблицы. В данном случае переменная Memory печатается раньше, чем Duration, поэтому сортировка будет по объему памяти. Поменяйте их местами (в строке и заголовке), чтобы сделать сортировку по Duration. Можно сортировать по количеству вызовов Quantity, можно считать отношение Duration/Quantity и сортировать по нему.
- Сортировка по убыванию
- Первые 25 строк выборки.
Скрипт претендует на универсальность. Поэтому если у Вас он не заработает - пишите, разберемся.
Версия от 20/10/2021. Убрал PRINT, удалось обойтись одним оператором AWK. Так лучше.
printf "%15s%15s%15s%-30s%-90s", "Duration(sec)", "Memory(Mb)", "Quantity", "processName", "Context" \
; printf "%s\n" \
; time egrep '^[0-9][0-9].{9,25},CALL,' -h -R --include "*.log" \
| awk -F'(^.{13})|(,|=)' '{ \
ColumnName=3; ColumnVal=4; my[1]=""; my[2]=""; my[3]=""; my[4]=0; my[5]=""; my[6]=""; \
while(ColumnName<NF){ColumnName++; ColumnVal++; \
if ($ColumnName=="Usr") {my[1]=$ColumnVal;} \
if ($ColumnName=="SessionID") {my[2]=$ColumnVal;} \
if ($ColumnName=="p:processName") {my[6]=$ColumnVal;} \
if ($ColumnName=="Context") {my[5]=$ColumnVal;} \
if ($ColumnName=="Module") {my[3]=my[3]"_"$ColumnVal;} \
if ($ColumnName=="Method") {my[3]=my[3]"_"$ColumnVal;} \
if ($ColumnName=="Func") {my[3]=my[3]"_"$ColumnVal;} \
if ($ColumnName=="Memory") {my[4]=$ColumnVal;}}; \
if (length(my[5])<9) {my[5]=my[3];} \
Memory[my[5],my[6]]+=my[4]; Duration[my[5],my[6]]+=$2; Context[my[5],my[6]]=my[5]; \
processName[my[5],my[6]]=my[6]; Quantity[my[5],my[6]]+=1} \
END {for (i in Memory) {printf "\n%15d%15d%15d\t%-30s\t%-90s", Duration[i]/1000000, \
Memory[i]/1000000, Quantity[i], processName[i], Context[i]}}' \
| sort -rnb \
| head -n20
Дополнительные бонусы. Несколько похожих скриптов.
Сколько пользователей работает через терминальный сервер, а сколько – через веб сервер.
printf "%-30s%-30s%-30s", "applicationName", "Usr", "computerName" \
; printf "%s\n" \
; egrep '^[0-9][0-9].{9,25},CALL,.*applicationName=[^,]+,t:computerName=[^,]+,t:connectID=[^,]+,Usr=[^,]+,SessionID=' -h -R --include "*.log" \
| awk -F'(^.*applicationName=)|(,t:computerName=)|(,t:connectID=)|(,Usr=)|(,SessionID=)' \
'{applicationName[$5,$3]=$2; computerName[$5,$3]=$3; Usr[$5,$3]=$5} \
END {for (i in Usr) {printf "\n%-30s%-30s%-30s", applicationName[i], Usr[i], computerName[i]}}' \
| sort -nb
Комментарии к коду:
- Выводим заголовок таблицы
- Разделительная строка между заголовком и данными табличной части
- Читаем файлы рекурсивно по маске, строки определенного формата. [^,]+ означает несколько символов кроме запятой.
- Выбираем через или разделители так, чтобы определить переменные
- Выполняем группировку в переменные applicationName, Usr, computerName
- Выводим переменные в таблице
- Сортируем
Собрать все значения переменной.
time cat *.log \
| egrep '^[0-9][0-9].{9,25},CALL,.*Module=' \
| awk -F'^.*Module=' '{print $2}' \
| awk -F',' '{Module[$1]=$1} \
END {for (i in Module) {print Module[i] "\n"}}'
Поиск максимального значение Duration без сортировки, за один проход
time egrep '^[0-9][0-9].{9,25},CALL,' -H -r \
| awk -F'(,|-)' '{if($2>Max2){Max1=$0; Max2=$2;};} \
| END {print Max1}'
Результат работы:
Наименование файла, строка события с максимальным Duration.
Комментарии к коду:
- Читаем файлы рекурсивно с указанием имени файла, строки определенного формата.
- Для разделителей «,» или «-» значение Duration будет второй колонкой. Запоминаем значение и всю строку.
- Выводим строку события.
Куда инвестировать в кризис ?
Согласитесь, этот вопрос сейчас особенно острый. Акции Газпрома, биткоины, рубли, доллары, недвижимость, Форекс ? Мой сосед еще надеется на йены (привет, Максим !). Дочка почти верит в Деда Мороза.
Даже в семейном кругу мы обсуждаем, что этот кризис – пятый на нашей памяти и при кризисе нам жить намного привычнее, чем без него. Доверять можно только себе самому, инвестировать в себя. Поэтому я заказал на Инфостарте счет за курсы и бережно отнес его руководителю. Вы можете сделать также.
Обновление апрель 2024.
События CALL используем для анализа загрузки сервера приложений, которая не связана с запросами СУБД. Например, отчет "Ведомость" рассчитывает сальдо по дням, сильно загружает сервер приложений. Смотрите подробнее //infostart.ru/public/2060362/ Быстродействие типовой 1С.
