(38) Что-то тут в тексте малость каша. То, что в сложных ситуациях причину таймаута сложновато найти - это Виктор верно сказал. Но вот предположения о причинах тут требуют уточнения:
Цитата |
---|
Но запись конкретно в этот блокируемый регистр занимает миллисекунды, и записано очень мало строк |
- сама запись вероятно и быстро, но вот у наборов записей бывают подписки и там всё бывает не быстро. Но на самом деле это не важно, так как блокировка удерживается до конца транзакции;
Цитата |
---|
Похоже это всё обернуто дополнительной транзакцией длительных фоновых операций и задержку дает другой регистр |
- тут 2 момента. 1 - каждое фоновое задание, это отдельный сеанс, он не может быть обёрнут в одну транзакцию ни с каким другим сеансом (как другим фоновым, так и в частности пользовательским из которого запустилось фоновое). 2
Цитата |
---|
и задержку дает другой регистр |
в основном, задержку даёт не регистр, а исполняемый код, запросы и ожидания на блокировках;
Цитата |
---|
Получается надо шерстить по событиям всех регистров движений |
- не знаю о каких событиях тут идёт речь, но если о TLOCK, то ни чего там по другим регистрам шерстить не надо.
В общем случае методика следующая:
1. Смотрим TTIMEOUT из него понимаем на какой таблице было ожидание, и какой connectID был виновником НАЧАЛА ожидания;
2. Смотрим по connectID виновника события SDBL фиксации или отмены транзакции, которая началось ранее или одновременно по отношению к нашему событию таймаута и закончилось
позже начала нашего таймаута/тлока. И вот тут самое интересно что позже начала, а не позже окончания.
Тут-то и кроется основное расстройство для таких "анализаторов" как я. Я то ждал по молодости, что виновник удерживал блокировку все 20 секунд, но на практике часто тут получается цепочка ожиданий из которых в ТЖ виден только первый виновник. (Например, пытаемся заблокировать остатки по 2-м товарам и попадаем на ожидание от сеанса 1, который держит блокировку по первому товару 15 секунд. На 10-й секунде ещё сеанс 2 устанавливает блокировку по товару 2 тоже на 15 секунд.
В итоге мы видим таймаут в ТЖ, где виновник сеанс 1 и по sdbl понимаем, что он отпустил конфликтный ресурс ранее, чем мы словили таймаут). И чтобы найти других виновников необходимо вычислить по tlock'ам сеансы, которые блокировали конфликтный ресурс по пересекающемуся пространству не позже, чем завершилась транзакция сеанса 1. И в цепочке в общем случае может быть несколько таких виновников.
Чтобы это провернуть необходимо собирать в ТЖ как минимум все таймауты без ограничения по времени установки (так как виновник мог установить её мгновенно), а так же необходимо собирать поля блокировки для tlock'ов (эти 2 настройки могут приводить к очень большим файлам логов на нагруженных системах). Ну и ещё найти пересечение пространств у двух tlock'ов технически не так уж и просто (хотя если по этому пространству немного потенциальных виновников, то можно скинуть в один файл и найти глазами).