お問い合わせ
IBSurgeon
このページは機械翻訳されています。英語の原文をお読みください。 English

Firebirdでデッドロックを追跡する方法

Alexey Kovyazin、2019年5月8日、(c) IBSurgeon

更新競合（しばしば「デッドロック」と呼ばれる）は、データの集中的な同時更新を行うFirebirdアプリケーションで発生します。

記事「 Firebirdのトランザクション」からわかるように、「deadlock」というキーワードを含むエラーには3つのタイプがあります：

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つのタイプの更新競合すべてに共通するのは、更新競合が通常、同じレコードを変更しようとする2つの変更操作の結果であるという事実です。

考えられる操作は次のとおりです：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つのisqlセッション用の2つの列があります。各行は、コマンドが実行された時点を表します。
時間 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>
つまり、開始時点では、トランザクション#15と#20の2つが開始されていることがわかります。次に、同じレコードの同時更新を実行してみましょう：
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>

セッション1でUPDATEを開始しましたが、コミットしませんでした。

セッション2では、UPDATEは「ハング」し、同時トランザクションの終了を待機しました。セッション1でUPDATEをコミットすると、セッション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)

これで、更新競合の両当事者（成功したものと失敗したもの）が見つかりました。

デッドロックを特定するためのツール

ご覧のとおり、ロック競合/デッドロックの根本原因を特定するのはかなり難しい場合があります。競合には常に2つの側面があり、一方の側面が「勝つ」（エラーメッセージなしで完了する）ため、勝者を特定するのが難しい場合があります。たとえば、競合はEXECUTE STATEMENT内、ネストされたストアドプロシージャ内、トリガー内で発生する可能性があり、またはこれらすべての組み合わせである可能性もあります。

デッドロックを特定するために、IBSurgeonは「Deadlock Analyzer」ツールを開発しました。これはトレースログを分析し、デッドロックにつながった呼び出しの詳細を示すわかりやすい図を作成します。 このツールはEnterprise Subscriptionの一部として利用可能です（試用版あり）- cc.ib-aid.comで登録してください。

また、HQbirdはfbtraceプラグインの拡張版を導入しています。これは変更と変更の試み（つまり、失敗した操作、ロック競合、デッドロック）のみを保存するように設定できます。

詳細については、IBSurgeonサポートにお問い合わせください：[email protected]。

デッドロックを回避するには？

次に、アプリケーションのデッドロックを回避するための最適なソリューションを特定する必要があります。それはトランザクションパラメータの変更、追加のエラー処理と操作の再試行、またはアプリケーションのビジネスレベルでの追加チェックの実行である可能性があります。