Як відстежувати взаємні блокування (deadlocks) у Firebird

Олексій Ковязін, 08-травня-2019, (c) IBSurgeon

Конфлікти оновлення (часто звані «взаємними блокуваннями») виникають у застосунках Firebird, які виконують інтенсивні конкурентні оновлення даних.

Як видно зі статті « Транзакції у Firebird», існує 3 типи помилок, які містять ключове слово «deadlock»:

Code

deadlock
-update conflicts with concurrent update
-concurrent transaction number is NNN

lock time-out on wait transaction
-deadlock
-update conflicts with concurrent update
-concurrent transaction number is NNN

lock conflict on no wait transaction
-deadlock
-update conflicts with concurrent update
-concurrent transaction number is NNN

Усі 3 типи конфліктів оновлення мають спільну рису: конфлікт оновлення зазвичай є результатом двох операцій модифікації, які намагаються змінити один і той самий запис.

Можливі варіанти: UPDATE, DELETE SELECT WITH LOCK, MERGE, UPDATE OR INSERT.

Відносно легко відстежити операцію-«жертву», яка отримує повідомлення про помилку - просто помістіть її в try… catch та занотуйте параметри, використані в запиті, який завершується помилкою.

Однак за такого підходу складно відстежити «переможця» - тобто конкурентну транзакцію, де оновлення було виконано успішно, без помилки.

Щоб допомогти розробникам досліджувати конфлікти оновлення, Firebird вставляє в повідомлення про помилки посилання на конкурентну транзакцію - тобто транзакцію, де конкурентне оновлення ще не зафіксовано. Разом із Trace API це дає нам змогу відстежувати обидві конфліктуючі операції.

Розгляньмо практичні кроки, як це зробити.

Спочатку потрібно налаштувати трасування. Для цього створіть текстовий файл (у нашому випадку це C:\Temp\mytrace.conf) із таким вмістом:

Code

database
{
	enabled = true
	include_filter="(UPDATE%)|(DELETE%)|(MERGE%)|(SELECT%FROM%WITH LOCK)|(UPDATE OR INSERT%)"
	log_statement_finish = true
	log_errors = true
	include_gds_codes="deadlock"
	log_initfini = false
	time_threshold = 0
	max_sql_length = 65000

}

Наведений вище файл конфігурації вмикає трасування для всіх баз даних, тому якщо у вас активна більш ніж одна база даних, краще вказати назву бази даних у файлі конфігурації, наприклад:

Code

Database=mydatabase.fdb
{
  enabled = true
…
}

Розгляньмо найважливіші параметри у файлі конфігурації:

Параметр include filter

Code

include_filter="(UPDATE%)|(DELETE%)|(MERGE%)|(SELECT%FROM%WITH LOCK)|(UPDATE OR INSERT%)"

Це означає, що ми хочемо відстежувати лише оператори UPDATE та DELETE та ігнорувати SELECT. Необхідно відфільтрувати якомога більше операторів, оскільки у виробничій системі за високого навантаження кількість записів у текстовому журналі може бути надто великою для аналізу.

Зазвичай ми знаємо, яка таблиця бере участь у конфлікті оновлення, тому гарною ідеєю буде додати її у фільтр, щоб зменшити кількість оновлень для аналізу:

Code

include_filter="(UPDATE T1%)|(DELETE FROM T1%)|(MERGE INTO T1%)|(SELECT% FROM T1%WITH lock%)|(UPDATE OR INSERT INTO T1%)"

Що як оновлення та видалення виконуються збереженими процедурами? Що ж, це ускладнює весь процес: додайте у фільтр усі збережені процедури, які можуть брати участь у конкурентних оновленнях, а також увімкніть журналювання процедур:

Code

include_filter="(UPDATE T1%)|(DELETE FROM T1%)|(MERGE INTO T1%)|(SELECT% FROM T1%with lock%)|(UPDATE OR INSERT INTO T1%)|(%SP_UPDATE_T1%)|(%SP_DEL_T1%)"
log_procedures=true

Параметри журналювання помилок

Потім потрібно вказати журналювання помилок та обмежити його лише взаємними блокуваннями.

Code

log_errors = true
include_gds_codes="deadlock"

Зверніть увагу: параметр include_gds_codes з’явився лише у Firebird 3.0.2, тому якщо ви використовуєте 2.5, 3.0.0 або 3.0.1, неможливо відфільтрувати лише помилки взаємного блокування, тому всі помилки будуть записані в журнал.

Демонстрація

Щоб продемонструвати весь процес, підготуймо тестову базу даних - для простоти буде 1 таблиця з 1 первинним стовпцем.

Code

C:\HQbird\Firebird30>isql
Use CONNECT or CREATE DATABASE to specify a database
SQL> create database "c:\temp\testdeadlock.fdb" user "SYSDBA" password "masterkey";
SQL> create table t1(i1 integer not null primary key);
SQL> insert into t1(i1) values(1);
SQL> commit; exit;

Після цього потрібно запустити сеанс трасування:

Code

fbtracemgr.exe -se localhost:service_mgr -start -conf "C:\temp\mytrace.conf" -user SYSDBA -pass masterkey

У цьому випадку fbtracemgr виводить журнал на екран, але у виробничому середовищі його, звісно, потрібно перенаправити у файл.

Після успішного запуску fbtracemgr виводить приблизно таке:

Code

Trace session ID 4 started

Потім запустімо 2 сеанси isql і спробуймо змоделювати конфлікт оновлення. У таблиці нижче маємо 2 стовпці для 2 сеансів isql. Кожен рядок представляє момент часу, коли було виконано команди.


Час	сеанс isql 1	сеанс isql 2
T1	`<br>isql -user SYSDBA -pass masterkey localhost:c:\temp\testdeadlock.fdb<br>Database: localhost:c:\temp\testdeadlock.fdb, User: SYSDBA<br>SQL> set transaction wait;<br>Commit current transaction (y/n)?y<br>Committing.<br>SQL> select current_transaction from rdb$database;<br> CURRENT_TRANSACTION<br>=====================<br> 15<br>SQL> select * from t1;<br> I1<br>============<br> 2<br>SQL><br>`
T2		`<br>isql -user SYSDBA -pass masterkey localhost:c:\temp\testdeadlock.fdb<br>Database: localhost:c:\temp\testdeadlock.fdb, User: SYSDBA<br>SQL> set transaction wait;<br>Commit current transaction (y/n)?y<br>Committing.<br>SQL> select current_transaction from rdb$database;<br> CURRENT_TRANSACTION<br>=====================<br> 20<br>SQL> select * from t1;<br> I1<br>============<br> 2<br>SQL><br>`
Отже, на стартовій точці ми бачимо, що запущено 2 транзакції, #15 та #20. Потім спробуймо виконати конкурентне оновлення того самого запису:

T3	`<br>SQL> UPDATE T1 SET i1=5 where i1=2;<br>`
T4		`<br>SQL> UPDATE T1 SET i1=100 where i1=2;<br>`
T5	`<br>SQL> commit;<br>SQL><br>`	`<br>Statement failed, SQLSTATE = 40001<br>deadlock<br>-update conflicts with concurrent update<br>-concurrent transaction number is 15<br>SQL><br>`

Ми запустили UPDATE у сеансі 1, але не зафіксували його.

У сеансі 2 UPDATE «завис» - він чекав завершення конкурентної транзакції, і коли ми зафіксували UPDATE у сеансі 1, сеанс 2 отримав помилку:

Code

Statement failed, SQLSTATE = 40001
deadlock
-update conflicts with concurrent update
-concurrent transaction number is 15
SQL>

Отже, ми маємо типову ситуацію конфлікту оновлення з транзакцією очікування.

Розгляньмо журнал трасування, щоб знайти докази конфлікту оновлення.

У цьому випадку журнал трасування дуже короткий, але у виробничій системі він може бути значно довшим, однак підхід до пошуку взаємних блокувань той самий.

Code

fbtracemgr.exe -se localhost:service_mgr -start -conf "C:\temp\fbtrace.conf" -user SYSDBA -pass masterkey
Trace session ID 4 started

2019-05-07T11:28:43.9850 (2692:00000000018C1940) EXECUTE_STATEMENT_FINISH
        C:\TEMP\TESTDEADLOCK.FDB (ATT_12, SYSDBA:NONE, NONE, TCPv6:::1/52938)
        C:\HQbird\Firebird30\isql.exe:8828
                (TRA_15, CONCURRENCY | WAIT | READ_WRITE)

Statement 52:
-------------------------------------------------------------------------------
UPDATE T1 SET i1=5 where i1=2
0 records fetched
      0 ms, 2 read(s), 21 fetch(es), 3 mark(s)

2019-05-07T11:29:45.0190 (2692:00000000018C0040) FAILED EXECUTE_STATEMENT_FINISH
        C:\TEMP\TESTDEADLOCK.FDB (ATT_13, SYSDBA:NONE, NONE, TCPv6:::1/52968)
        C:\HQbird\Firebird30\isql.exe:7032
                (TRA_20, CONCURRENCY | WAIT | READ_WRITE)

Statement 55:
-------------------------------------------------------------------------------

UPDATE T1 SET i1=100 where i1=2
0 records fetched
  40242 ms, 19 fetch(es), 2 mark(s)

2019-05-07T11:29:45.0190 (2692:00000000018C0040) ERROR AT JStatement::execute
        C:\TEMP\TESTDEADLOCK.FDB (ATT_13, SYSDBA:NONE, NONE, TCPv6:::1/52968)
        C:\HQbird\Firebird30\isql.exe:7032
335544336 : deadlock
335544451 : update conflicts with concurrent update
335544878 : concurrent transaction number is 15

Як ви бачите, у нас є записи в журналі про обидва оновлення - успішне та невдале, а також повідомлення про помилку щодо взаємного блокування.

Розглянемо, як аналізувати журнал:

У повідомленні про помилку знайдемо ідентифікатор транзакції:

Code

 2019-05-07T11:29:45.0190 (2692:00000000018C0040) ERROR AT JStatement::execute
        C:\TEMP\TESTDEADLOCK.FDB (ATT_13, SYSDBA:NONE, NONE, TCPv6:::1/52968)
        C:\HQbird\Firebird30\isql.exe:7032
335544336 : deadlock
335544451 : update conflicts with concurrent update
335544878 : concurrent transaction number is 15

Поруч із записом про помилку (зазвичай безпосередньо над ним) ви побачите невдалий оператор:

Code

2019-05-07T11:29:45.0190 (2692:00000000018C0040) FAILED EXECUTE_STATEMENT_FINISH
        C:\TEMP\TESTDEADLOCK.FDB (ATT_13, SYSDBA:NONE, NONE, TCPv6:::1/52968)
        C:\HQbird\Firebird30\isql.exe:7032
                (TRA_20, CONCURRENCY | WAIT | READ_WRITE)

Statement 55:
-------------------------------------------------------------------------------
UPDATE T1 SET i1=100 where i1=2
0 records fetched
  40242 ms, 19 fetch(es), 2 mark(s)

Зверніть увагу, що час виконання величезний (~40 секунд) - це вказує на час, протягом якого операція очікувала на результат конкурентної транзакції.

І, нарешті, знайдіть номер транзакції з успішною операцією UPDATE: для цього знайдіть TRA_NNN, де NNN - номер транзакції. У нашому випадку це буде TRA_15:

Code

2019-05-07T11:28:43.9850 (2692:00000000018C1940) EXECUTE_STATEMENT_FINISH
        C:\TEMP\TESTDEADLOCK.FDB (ATT_12, SYSDBA:NONE, NONE, TCPv6:::1/52938)
        C:\HQbird\Firebird30\isql.exe:8828
                (TRA_15, CONCURRENCY | WAIT | READ_WRITE)

Statement 52:
-------------------------------------------------------------------------------
UPDATE T1 SET i1=5 where i1=2
0 records fetched
      0 ms, 2 read(s), 21 fetch(es), 3 mark(s)

Отже, ось і все - ми знайшли обидві сторони конфлікту оновлення - успішну та невдалу.

Інструменти для виявлення взаємних блокувань

Як ви бачите, може бути досить складно визначити першоджерело конфлікту блокувань/взаємного блокування: оскільки конфлікт завжди має дві сторони, і одна сторона “перемагає” (завершується без повідомлень про помилки), може бути складно визначити переможця. Наприклад, конфлікт може статися всередині EXECUTE STATEMENT, або у вкладеній збереженій процедурі, або всередині тригера, або це може бути комбінація всіх цих елементів.

Щоб виявити взаємні блокування, IBSurgeon розробив інструмент “Deadlock Analyzer”, який аналізує журнал трасування та створює зрозумілі діаграми з деталями викликів, які призвели до взаємних блокувань. Цей інструмент доступний як частина Enterprise Subscription (має пробну версію) - зареєструйтеся на cc.ib-aid.com.

Крім того, HQbird представляє розширену версію плагіна fbtrace, який можна налаштувати для збереження лише змін та спроб змін (тобто невдалих операцій, конфліктів блокувань та взаємних блокувань).

Зверніться до служби підтримки IBSurgeon, щоб отримати більше інформації про це: [email protected].

Як уникнути взаємних блокувань?

Тепер вам потрібно визначити найкраще рішення для вашого застосунку, щоб уникнути взаємних блокувань - це може бути зміна параметрів транзакції, або можна додати додаткову обробку помилок і повторити операцію, або виконати додаткові перевірки на бізнес-рівні застосунку.