Существует несколько хороших статей про регулярные выражения.
https://its.1c.ru/db/metod8dev#content:5927:hdoc (Статья на ИТС недавно обновилась)
Постараюсь написать проще и подробнее - как для себя. Для начинающих, которые уже прочитали Джеффри Фридл "Регулярные выражения" или Бен Форта "Регулярные выражения 10 минут на урок" и установили Cygwin64 GitBash с ресурса https://git-scm.com/download/win.
Предупреждение 1. При копировании примеров из статьи в bash могут возникнуть проблемы. Из-за этого выходит сообщение «Binary file (standard input) matches». Поэтому текстовые файлы примеров команд и фрагмент журнала приложу в архиве. Кто захочет – скачает.
Предупреждение 2. Относитесь к шпаргалке критически, опирайтесь на свои собственные знания.
Скрипт обработки ТЖ сильно зависит от настроек. Универсальных скриптов не бывает. Поэтому пара слов про ТЖ.
Длительность более 10 миллисекунд позволяет отсечь служебные запросы. Пользовательские запросы дольше. Данные журнала накапливаются за од ин час. Это лучшая настройка поскольку собирать журнал можно только на диске сервера (если использовать сетевой диск – возможны дикие тормоза), а место на диске сервера очень дорогое. Чтобы собирать журнал с нескольких серверов на свой рабочий компьютер, ежечасно запускайте помощью Планировщик заданий Windows командный файл *.bat, пример содержимого:
xcopy \\SERVERName1\F\*.* D:\$log$\*.* /S /E /Y
xcopy \\SERVERName2\F\*.* D:\$log$\*.* /S /E /Y
Задача 1. Подсчитать количество дедлоков (управляемые блокировки) за ночь с 00 по 06 часов
Выбираем содержимое файлов из подкаталогов текущего каталога cat rphost*/ *0[0-6].log |
|
Символы |
Значение |
|
rphost |
Используем, что дедлок содержится только в логах rphost. Выбрать все файлы проще: cat */*.log |
|
* |
любое количество символов в имени файла. Вообще, любое количество символов в регулярных выражениях означается «.*», но создателей команды cat это не смущает. |
|
/ |
Спуск к подкаталогам. Я бы удивился, если бы увидел привычный «\». |
|
0[0-6] |
Числа 00, 01,02,03,04,05,06. На каждый час создается свой файл |
|
.log |
Точка здесь означает точку. Расширение файла – log. |
|
| |
Нам всем привычны временные таблицы. Чтобы поместить результат запроса в аналог временной таблицы, ставим знак «|» (pipe, труба). Следующая команда использует этот результат. |
Почти каждый запрос начинается с команды cat.
Чтобы выбрать строки, содержащие дедлок, нужно составить шаблон. Смотрим строка 1 файла ТЖ, записываем ^[0-9][0-9]:.{10,20}DEADLOCK.
|
Символы |
Значение |
|
^ |
Начало строки |
|
[0-9] |
один цифровой символ |
|
: |
двоеточие |
|
. |
означает любой символ |
|
{10,20} |
от 15 до 20 повторений предыдущего символа |
|
DEADLOCK |
должно быть написано большими буквами. Если у вас не дедлоков – считайте другое слово, например SDBL |
Профессионалы применяют более сложные шаблоны начала строки – выбирайте сами. На мой взгляд, в шаблоне должно быть начало строки и расстояние от начала строки до DEADLOCK было ограничено. Иначе объем чтения сильно возрастает.
Чтобы выбрать все строки, содержащие шаблон – используем команду egrep. Следующая команда выведет все строки, подобные шаблону, на экран
cat */rphost*0[0-6].log | egrep ‘^[0-9][0-9]:.{10,20}DEADLOCK’
команда выведет количество.
cat */rphost*0[0-6].log | egrep ‘^[0-9][0-9]:.{10,20}DEADLOCK’ -c
|
Символы |
Значение |
|
-с |
(обязательно прописная), показывает количество строк. Без этой опции результат выйдет на экран. Обычно дедлоков немного, строки можно подсчитать визуально. |
|
> имяфайла |
Перенаправить вывод в файл |
|
- -help |
(два тире help). получить подсказку |
Иногда можно не использовать cat:
egrep ‘^[0-9][0-9]:.{15,20}DEADLOCK’ –d recurse
|
Символы |
Значение |
|
–d recurse |
Рекурсивный обход поддиректорий. При этом в результат может добавляться имя файла, которое содержит час и дату. профессионалы используют –r. Можно задавать имя файла. |
|
–H |
Добавляет имя файла в результат. |
|
-h |
Подавляет вывод имени файла в результат |
|
- - color |
(два тире color) выделяет цветом шаблон поиска |
Задача 2. Подсчитать количество взаимоблокировок СУБД
Количество взаимоблокировок СУБД считается примерно также. Нужно учитывать, что в ТЖ это событие EXCP с пояснением «Конфликт блокировок при выполнении транзакции». (К сожалению, в примерном ТЖ управляемые блокировки.) Для вывода на экран используйте скрипт
egrep ‘^[0-9][0-9]:.{10,20}EXCP.*блокировок при выполнении транзакции’ -d recurse
|
Символы |
Значение |
|
.* |
Несколько (или нисколько) любых символов. Сравните .+ или .{1,2} |
Задача 3. Найти TLOCK жертвы (виновника) взаимоблокировки.
egrep –A2 ‘^[0-9][0-9]:.{15,20}DEADLOCK’ –d recurse
|
Символы |
Значение |
|
-A2 |
Две строки после строки, подобной шаблону. Есть похожие опции –B2, -C2 |
Если журнал настроен только по событиям TLOCK, TTIMEOUT, TDEADLOCK, то TLOCK жертвы должен быть следующим после TDEADLOCK.
В случае, если первый способ не подойдет, можно решить в два приема:
1. Найти строки, содержащие TDEADLOCK, запомнить время, connectID жертвы, пространство блокировок (Regions), измерения пространства блокировок (Здесь я не отображаю измерения, но их нужно сравнивать. Они обычно начинаются Fld). Выполняем
cat */*.log | egrep '^[0-9][0-9].{10,25}TDEADLOCK’, получаем
29:46.696046-0,TDEADLOCK,5,process=rphost,p:processName= processName,t:clientID=5008,t:applicationName=BackgroundJob,t:computerName= computerName,t:connectID=6520,SessionID=52328,Usr=.Регламентные задания,DeadlockConnectionIntersections='6520 6171 AccumRg10307.DIMS Exclusive Fld10308=44:8cbcf07d2b194ea349f50188353e0a15 Fld10309=32:80bb000c293fb1b711e5cef51b92cf25 Context='
2. По запомненным параметрам с учетом времени искать TLOCK жертвы.
Выполняем
cat */*.log | egrep –A1 '^29.{10,25}TLOCK.*connectID=6520.*Regions= AccumRg10307.DIMS', получаем две строки
29:47.259006-187992,TLOCK,4,process=rphost,p:processName= processName,t:clientID=5008,t:applicationName=BackgroundJob,t:computerName= computerName,t:connectID=6520,SessionID=52328,Usr=.Регламентные задания,Regions=AccumRg10307.DIMS,Locks='AccumRg10307.DIMS Exclusive ,Context='
ОбщийМодуль.МодульРегламентныхЗаданий.Модуль : 1350 : РегистрыСведений. ДокументыДляПерепроведения.ПерепровестиДокументы();
TLOCK виновника нужно искать раньше TDEADLOCK, по запомненным параметрам с учетом времени. В нашем случае connectID=6171
Задача 4. Найти топ-5 запросов с максимальной длительностью.
Нужно учитывать, что длительность запроса хранится в событии SDBL или DBMSSQL, а контекст хранится в строках, следующих за следующей строкой.
Команда egrep ищет внутри одной строки. Поэтому строки нужно «склеить» (убрать переход строки), фильтровать нужный контекст, длительность переместить на первое место, сортировать по длительности, выбрать первые 5 по длительности.
Для «склеивания» строк применим скрипт
cat *.log |\
awk -vORS= '{
if ($0~"^[0-9][0-9].{8,30}SDBL|DBMSSQL") { print "\n"$0;} \
else if ($0~"^[0-9][0-9].{8,30}Context") { print $0; } \
else if ($0~"^[0-9][0-9]") { print "\n"; } \
else { print "-"$0; }
}' |\
|
Символы |
Значение |
|
\ |
Здесь означает, что команда продолжается на следующей строке. Используем для наглядности. |
|
awk ‘{}’ |
Это сложная и мощная команда, но здесь для каждой строки она просто выводит данные в зависимости от условий |
|
-vORS= |
Парамeтры команды awk. Убирает непечатаемые символы. |
|
If(){} |
Если истинно условие() выполнить программу {} |
|
$0 |
Текст обрабатываемой строки, без конца строки |
|
$0~”шаблон1” |
Текст обрабатываемой строки, без конца строки подобен шаблон1 |
|
SDBL|DBMSSQL |
Символ | означает ИЛИ. Этот шаблон равен SDBL или DBMSSQL. Для наглядности можно заключать в скобки (). |
|
«\n» |
Начало строки в кавычках. Символ конца строки \$ |
|
print "\n"$0 |
Вывести начало строки, текст обрабатываемой строки, без конца строки |
|
else if ($0~"^[0-9][0-9].{8,30}Context") { print $0; } |
Если не выполняется первое условие, но в строке есть слово Context, строка приклеивается к предыдущей. |
|
else if ($0~"^[0-9][0-9]") { print "\n"; } \
|
Если не выполняются предыдущие условия, но строка начинается с цифр, то вывести перевод строки. Эта команда заменяет на перевод строки все события кроме Context, SDBL и DBMSSQL |
|
else { print "-"$0; }\ |
Если не выполняются предыдущие условия, «приклеить» строку к предыдущей, но перед ней вставить тире. Эта команда обрабатывает контекст который начинается с пробелов. |
|
}' |\ |
Закрываются командные скобки команды awk, данные передаются через pipe следующей команде, которая будет на следующей строке. |
Фильтруем нужный контекст командой egrep ',(DBMSSQL|SDBL),.*,Context=' |\
Применим команду awk -F',(DBMSSQL|SDBL),.*?(,Context=)' '{print $1 "-" $2}' |\
|
Символы |
Значение |
|
awk –F’’ ‘{}’ |
Команда обрабатывает строки, используя разделитель заданный –F’’. Например, для файла csv удобно использовать разделитель «;». Но в данном случае разделителем объявлен огромный шаблон, это приводит к тому, что он исчезает из строки. |
|
.*? |
Ленивый квантор. Выбирает минимальное число символов, чтобы строка подходила под шаблон. |
|
$1 |
Первая колонка с учетом разделителя. |
|
NF |
Количество колонок |
|
$NF |
Последняя колонка |
|
NS |
Количество обработанных строк |
Применим команду awk -F'-' '{print $2, $NF}' | sort –rnb | head 5
|
Символы |
Значение |
|
-F'-' |
Используем разделитель “-” |
|
{print $2, $NF} |
Вывести вторую и последнюю колонку контекста |
|
sort –rnb |
Сортировать |
|
head 5 |
Вывести первые пять записей. Последние пять записей tail 5 |
Посмотрим результат. Первая колонка – длительность.
|
186991 РегистрСведений.МойРегистр.МодульМенеджера : 285 : ДокументОбъект.Записать(РежимЗаписиДокумента.Проведение);' 15947 РегистрСведений. МойРегистр.МодульМенеджера : 285 : ДокументОбъект.Записать(РежимЗаписиДокумента.Проведение);' 14975 РегистрСведений. МойРегистр.МодульМенеджера : 285 : ДокументОбъект.Записать(РежимЗаписиДокумента.Проведение);' |
Итоговый скрипт:
time cat *.log \
| awk -vORS= '{if ($0~"^[0-9][0-9].{8,30}SDBL|DBMSSQL") \
{ print "\n"$0;} \
else if ($0~"^[0-9][0-9].{8,30}Context") { print $0; } \
else if ($0~"^[0-9][0-9]") { print "\n"; } \
else { print "-"$0; } \
}' \
| egrep ',(DBMSSQL|SDBL),.*,Context=' \
| awk -F',(DBMSSQL|SDBL),.*?(,Context=)' '{print $1 "-" $2}' \
| awk -F'-' '{print $2, $NF}' \
| sort –rnb \
| head 5
Вариант скрипта, если выводить без контекста, только имя файла и время:
time egrep '^[0-9][0-9].{8,30}(SDBL|DBMSSQL)' -d recurse \
| awk -F',' '{print $1}' \
| awk -F'-' '{print $2/1000000 " -длительность секунд. Имя файла:Минут:Секунд " $1}' \
| sort -rnb \
| head -n10
Вариант скрипта: ищем объектные чтения
time cat *.log \
|awk -vORS= '{ \
if ($0~"^[0-9][0-9].{8,30}(SDBL|DBMSSQL).{180,220}SELECT ID, Version, Marked, PredefinedID") \
{ print "\n"$0; } \
else if ($0~"^[0-9][0-9].{8,30}Context") { print $0; } \
else if ($0~"^[0-9][0-9]") { print "\n"; } \
else { print "-"$0; } \
}' \
| egrep '(SDBL|DBMSSQL).*?Context=' \
| awk -F'(SDBL|DBMSSQL).*?,Context=' '{print $1 "-" $2}' \
| awk -F'-' '{duration[$NF]+=$2; count[$NF]+=1;} \
END {for (i in count) {print "\n" duration[i] / 1000000 " секунд " count[i] " выполнений " duration[i] / (count[i]*1000000) " среднее время " i}}' \
| sort -rnb \
| head -n20
Используем, что объектное чтение элемента справочника имеет вид: SELECT ID, Version, Marked, PredefinedID
Кстати, запросы получения данных в форме списка при включенном "Динамическом считывании" содержат "TOP 45". Чаще всего опцию "Динамическое считывание следует отключить.
Вариант скрипта: ищем наиболее частые ошибки
time cat *.log
| awk -vORS= '{ \
if ($0~"^[0-9][0-9].{6,30},EXCP.*?Descr=") { print "\n"$0;} \
else if ($0~"^[0-9][0-9].{6,30},[A-D,F-Z]") { print "\n"; } \
else { print $0; } \
}' \
| egrep '^[0-9][0-9].{6,30}EXCP.*?Descr=' \
| awk -F'^.*Descr[^А-Я]*?' '{print $2;}' \
| awk -F'[A-Z]*?' '{count[$1]+=1;} \
END {for (i in count) {print "\n" count[i] " ошибок " i}}' \
| sort -rnb \
| head
Здесь первый awk убирает события кроме ошибок и следующих строк, второй awk убирает все символы до первой большой русской буквы в описании ошибки, третий awk убирает из описания ошибки все что идет после большой латинской буквы.
Задача 5. Найти такие события, которые в сумме имеют максимальную длительность.
Например, система оповещения пользователей, подключается при старте программы командой «ПодключитьОбработчикОжидания(,60)» и потребляет серьезные ресурсы при большом количестве пользователей.
Мы видели, что в предыдущем варианте получился практически готовый ответ, только его нужно сгруппировать. Вместо последней команды выполним
awk -F'-' '{count[$NF]+=$2;} END {for (i in count) {print "\n" "длительность " count[i] " контекст вызова " i}}' | sort -rnb | head -n5
|
Символы |
Значение |
|
count[$NF] +=$2 |
Определяем структуру, ключ – содержимое последнего столбца, значение – содержимое второго столбца, если в структуре ничего не было. Если такой ключ в структуре уже существовал - то сумма существующего и нового значений. |
|
END {} |
После обработки всех строк выполнить |
|
for (i in count) {print "\n" count[i] " контекст вызова " i} |
Вывести каждое значение структуры и ключ структуры |
длительность 217913 контекст вызова РегистрСведений.МойРегистр.МодульМенеджера : 285 : ДокументОбъект.Записать(РежимЗаписиДокумента.Проведение);'
Итоговый скрипт
time cat *.log \
| awk -vORS= '{if ($0~"^[0-9][0-9].{8,30}SDBL|DBMSSQL") \
{ print "\n"$0;} \
else if ($0~"^[0-9][0-9].{8,30}Context") { print $0; } \
else if ($0~"^[0-9][0-9]") { print "\n"; } \
else { print "-"$0; } \
}' \
| egrep ',(DBMSSQL|SDBL),.*,Context=' \
| awk -F',(DBMSSQL|SDBL),.*?(,Context=)' '{print $1 "-" $2}' \
| awk -F'-' '{count[$NF]+=$2;} END {for (i in count) \
{print "\n" count[i] "<--Длительность; Контекст-->" i}}' \
| sort -rnb \
| head -n20 \
| sed 's/[ \t]//g'
Задача 6. Найти TLOCK, которые ожидали
cat *.log | egrep 'TLOCK.*WaitConnections=[0-9]'
Задача 7. Найти все управляемые разделяемые блокировки
cat *.log | egrep 'TLOCK.*\bShared\b'
|
|
Значение |
| \b | граница слова |
Задача 8. Найти топ самых долгих транзакций
cat *.log | egrep 'SDBL.*Func=Commit' | gawk -F'-' '{print $2}' | sort -rnb | head
Задача 9. Посчитать количество событий в каждом файле
egrep '^[0-9][0-9].{8,30},' -H -d recurse |\
awk -F',' '{print $1 "log" $2}' |\
awk -F'log' '{ count[$1, $3]++ } END {for (i in count) {print count[i] "." i}}'
|
|
Значение |
| count[$1, $3]++ |
Добавляет счетчик в структуру вида Имя файла. Имя события |
Результат работы - на экране в формате количество событий, имя файла, имя события. Пример:
2495.19032013.EXCP
2632.19031908.SDBL
Копируем в Excel (Calc), меню Данные - Текст по столбцам, сортируем, рисуем диаграмму )
Задача 10. Подсчитать определенный фрагмент по часам
cat *.* | egrep ',EXCP' -d recurse -c
Задача 11. Вывести в файл строки, которые не начинаются "(".
cat 19050709.log | egrep '^[^\(]' >> file1.log
Такое преобразование нужно, если в файл журнала попал текст Insert-запроса, который "раздувает" файл лога в разы.
|
|
Значение |
| '^[]' | Начало строки ^ диапазон [] |
| ^\( |
Не ^ знак скобки \( |
