Вступление
Анализ взаимоблокировок описан на ИТС, там же пошаговая инструкция. Предлагают анализировать файл технологического журнала в блокноте. Ниже Bash-скрипт для получения информации из технологического журнала по событиям TTIMEOUT, TDEADLOCK, TLOCK.
Пропустим установку Bash и сбор технологического журнала.
Упрощенная (первая) версия.
egrep '^[0-9][0-9].{10,24},TLOCK.*WaitConnections=[0-9]' -h -R \
| awk -F'(:.{8,21},TLOCK.*t:connectID=)|(,SessionID=.*,Regions=)|(,Locks=.*WaitConnections=)|(,connectionID=)' \
'BEGIN {print "#!/bin/bash" > "2step.sh"} \
{cow[$3,$2,$1]="egrep '\''^"$1"\.{10,25},TLOCK.*t:connectID="$2".*,Regions="$3".*WaitConnections="$4"'\'' -h -R"; \
tiger[$3,$2,$1]="egrep '\''^"$1"\.{10,25},TLOCK.*t:connectID="$4".*,Regions="$3".*WaitConnections=,'\'' -h -R"; \
timeout[$3,$2,$1]="egrep '\''^"$1"\.{10,25},TTIMEOUT.*t:connectID="$2".*WaitConnections="$4"'\'' -h -R";} \
END {for (item in cow) {print cow[item]"\n"timeout[item]"\n"tiger[item]"\n"tiger1[item] >> "2step.sh"; }}' \
; ./2step.sh
Комментарии к коду:
1. выбираем возможные жертвы с непустым временем ожидания. Предполагаем, что порядок тегов событий TLOCK не изменяется.
2. разделители подобраны таким образом, что $1 минута события, $2 ID соединения жертвы, $3 область блокировки, $4 ID соединения виновника
3. очищаем файл шаблона запроса 2step. Первая строка командного скрипта bash должна быть стандартной #!/bin/bash.
4. заполняем текстовые переменные cow (жертва), tiger (виновник), timeout для шаблона запроса egrep.
5. эти шаблоны предполагают, что минута времени виновника и жертвы совпадают. Конечно, можно проверять предыдущую минуту, например "egrep '\''^"$1-1"\.{10,25},TLOCK.*t:connectID="$4".*, Regions="$3".*WaitConnections=,'\'' -h -R"; и более ранние события. Но мы не будем распространятся в эту сторону: такие ситуации могут возникать только при очень длительных блокировках, которые являются совершенным злом, их необходимо анализировать отдельно. Очень трудно было напечатать одинарную кавычку в шаблон из кода awk. Наконец нашел конструкцию: внутри двойных кавычек открывается одинарная кавычка, слэш одинарная кавычка, одинарная кавычка. На выходе имеем одинарную кавычку.
6. после обработки событий TLOCK всех возможных жертв, выводим в файл 2step запрос по шаблону
7. выполняем файл 2step.sh. Выходят события жертвы блокировки, виновника блокировки, запись TTIMEOUT.
Первая версия прекрасно работает, но есть возможности ее улучшить: дополнительно группировать события по области блокировки (Regions), добавить события DEADLOCK.
Основная версия скрипта:
#!/bin/bash
egrep '^[0-9][0-9].{10,24},TLOCK,.*WaitConnections=[0-9]' -H -R --include "200311*.log" \
| awk -F'(^.{1,20}\/)|(.log:)|(:.{8,21},TLOCK,.*t:connectID=)|(,SessionID=.*,Regions=)|(,Locks=.*,WaitConnections=)|((,connectionID=)|(,Context=))' \
'BEGIN {print "#!/bin/bash" > "2step.sh"} \
{gsub("'\''",".",$5) \
; ord[$3,$5,$4]="Time"$3"Regions"$5"Tiger"$6"EndOrder" \
; cow[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TLOCK.*t:connectID="$4".*,Regions="$5".*WaitConnections="$6"'\'' -h -R --include "$2".log" \
; tiger[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TLOCK.*t:connectID="$6".*,Regions="$5".*WaitConnections=,'\'' -h -R --include "$2".log" \
; deadlock[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TDEADLOCK.*t:connectID="$4".*DeadlockConnectionIntersections=."$4"."$6"'\'' -h -R --include "$2".log" \
; timeout[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TTIMEOUT.*t:connectID="$4".*WaitConnections="$6"'\'' -h -R --include "$2".log";} \
END {for (K in ord) \
{print ord[K]cow[K]"\n"ord[K]timeout[K]"\n"ord[K]deadlock[K]"\n"ord[K]tiger[K]"\n"ord[K]"echo "; }}' \
| sort -rnb \
| awk -F'^.*EndOrder' '{print $2;}' >> "2step.sh" \
; ./2step.sh >> "result.txt"
Комментарии к коду: скрипт запускать из среды Bash в каталоге, где собраны подкаталоги rphost за день. В моем случае объем за день 3 Гб, 4 каталога rphost, 66 файлов. Время работы скрипта на моем компьютере – 10 Минут. Скрипт находит события не только по которым зафиксировано TTIMEOUT или TDEADLOCK, но и ожидания на блокировках.
1. Выбираем файлы по маске, например 200311*.log с событиями TLOCK, которые имели ожидание. Выборка включает имя файла.
2. Разделители awk подобраны так, что: $2 краткое имя файла, $3 Минута события, $4 ConnectID жертвы, $5 Область блокировки, $6 ConnectID виновника. Оказывается, после ConnectID виновника может быть тег connectionID ИЛИ Context. Порядок тегов очень важен.
3. Очищаем файл шаблона запроса 2step. Первая строка командного скрипта bash должна быть стандартной #!/bin/bash.
4. Область блокировки может содержать одинарные кавычки, от этого страдает построение шаблона запроса. Заменяем одинарные кавычки на точку.
5. Заполняем выражение упорядочивания: область, виновник, жертва.
6. Заполняем текстовые переменные cow (жертва), tiger (виновник), timeout, deadlock для шаблона запроса egrep. Используем допущение, что час и минута всех файлов всех событий одной взаимоблокировки совпадают.
7. Формируем шаблон запроса, между группами строк выводим echo
8. Сортируем по области блокировки
9. Убираем область сортировки, помещаем шаблон запроса в файл.
10. Выполняем шаблон запроса.
Дополнительные бонусы:
Скрипт для поиска длительных транзакций
#!/bin/bash
printf "%15s\t\t%s", "Duration(sec.)", "Event string" \
; echo \
; egrep '^.{12,25},SDBL,.*Func=(Commit|Rollback)Transaction' -h -R --include "$@" \
| awk -F'(-|,)' '{printf "\n%4d\t%s", $2/1000000, $0}' \
| sort -rnb \
| head
Комментарии к коду:
- Обязательная первая строка bash-скрипта
- Заголовок таблицы
- Отделяем заголовок от таблицы
- Выбираем события SDBL, маску файла берем из параметра командной строки.
- Печатаем длительность в секундах, строку события.
- Сортируем
- Выводим первые 10 строк.
Вариант скрипта анализа взаимоблокировок без сортировки
#!/bin/bash
egrep '^[0-9][0-9].{10,24},TLOCK,.*WaitConnections=[0-9]' -H -R --include "$@" \
| awk -F'(^.{1,20}\/)|(.log:)|(:.{8,21},TLOCK,.*t:connectID=)|(,SessionID=.*,Regions=)|(,Locks=.*,WaitConnections=)|((,connectionID=)|(,Context=))' \
'BEGIN {print "#!/bin/bash" > "2step.sh"} \
{gsub("'\''",".",$5) \
;ord[$5]=$5 \
;cow[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TLOCK.*t:connectID="$4".*,Regions="$5".*WaitConnections="$6"'\'' -h -R --include "$2".log" \
;region[cow[$3,$5,$4]]=$5 \
;tiger[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TLOCK.*t:connectID="$6".*,Regions="$5".*WaitConnections=,'\'' -h -R --include "$2".log" \
;deadlock[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TDEADLOCK.*t:connectID="$4".*DeadlockConnectionIntersections=."$4"."$6"'\'' -h -R --include "$2".log" \
;timeout[$3,$5,$4]="egrep '\''^"$3"\.{10,25},TTIMEOUT.*t:connectID="$4".*WaitConnections="$6"'\'' -h -R --include "$2".log";} \
END {for (L in ord) { print "echo " >> "2step.sh"; \
for (K in cow) { if (region[cow[K]]==ord[L]) \
{print cow[K]"\n"timeout[K]"\n"deadlock[K]"\n"tiger[K] >> "2step.sh";} \
}}}' \
; ./2step.sh >> "result.txt"
Обновление от 26/07/2022
Всем привет ! Решил упростить обработку, переделал колонки в AWK. Обратите внимание на один нюанс: обработка ищет проблемы не по ключевым словам TDEADLOCK, TTIMEOUT а анализирует все ненулевые ожидания.
#!/bin/bash
egrep '^.{20,30},TLOCK,.*WaitConnections=[0-9]' -H -R --include "*.log" \
| awk -F'(:)|(.connectID=)|(,SessionID.*,Regions=)|(,Locks=.*,WaitConnections=)|(,Context=)|(,connectionID=)' \
'BEGIN {print "#!/bin/bash" > "2step.sh"} \
{gsub("'\''",".",$9) \
;ord[$9]=$9 \
;cow[$2,$9,$8]="egrep '\''^"$2"\.{10,25},TLOCK.*t:connectID="$8".*,Regions="$9".*WaitConnections="$10"'\'' -h -R --include "$1 \
;region[cow[$2,$9,$8]]=$9 \
;tiger[$2,$9,$8]="egrep '\''^"$2"\.{10,25},TLOCK.*t:connectID="$10".*,Regions="$9".*WaitConnections=,'\'' -h -R --include "$1 \
;deadlock[$2,$9,$8]="egrep '\''^"$2"\.{10,25},TDEADLOCK.*t:connectID="$8".*DeadlockConnectionIntersections=."$8"."$10"'\'' -h -R --include "$1 \
;timeout[$2,$9,$8]="egrep '\''^"$2"\.{10,25},TTIMEOUT.*t:connectID="$8".*WaitConnections="$10"'\'' -h -R --include "$1;} \
END {for (L in ord) { print "echo " >> "2step.sh"; \
for (K in cow) { if (region[cow[K]]==ord[L]) \
{print cow[K]"\n"timeout[K]"\n"deadlock[K]"\n"tiger[K] >> "2step.sh";} \
}}}' \
; ./2step.sh >> "result.txt"
Если у Вас что-то не получается - обращайтесь, будем думать вместе.
Благодарю Виктора Богачева за предоставленные методические материалы и поддержку.
