Update conflicts (often called «deadlocks») occur in Firebird applications which perform intensive concurrent updates of data.

As you can see from the article «Transactions in Firebird», there are 3 types of errors which contain the keyword «deadlock»:

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

All 3 types of update conflicts have in common the fact, that update conflict usually is the result of 2 modification operations which try to modify the same record.

The possible options are the following: UPDATE, DELETE SELECT WITH LOCK, MERGE, UPDATE OR INSERT.

It is relatively easy to track the «victim» operation, which receives the error message – just put it into try… catch and log the parameters used in the query which breaks on the error.

However, with this approach, it is difficult to track the «winner» - i.e., the concurrent transaction where the update was done successfully, without error.

To help developers investigate the update conflicts, Firebird puts into error messages the reference to the concurrent transaction – i.e., the transaction where the concurrent update is not yet committed. Together with Trace API, it gives us the ability to track both conflicting operations.

Let's consider the practical steps on how to do it.

First, we need to configure tracing. For this, create the text file (in our case it is C:\Temp\mytrace.conf) with the following contents:

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 }

Database=mydatabase.fdb { enabled = true … }

Include filter parameter

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

The configuration file above enables tracing for all databases, so if you have more than 1 active database, better specify the name of the database in the configuration file, i.e.:Let's review the most important parameters in the configuration file:It means that we want to track only UPDATE and DELETE statements and ignore selects. It is necessary to filter out as many as possible statements, because in the production system under high load the amount of the records in the text log can be too high to analyze it.

Usually, we know what table is participating in update conflict, the good idea will be to put it into the filter, to reduce the number of updates to analyze:

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

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

Error logging parameters

log_errors = true include_gds_codes="deadlock"

Demonstration

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;

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

What if updates and deletes are done by stored procedures? Well, it makes the whole process more difficult: add to the filter all stored procedures which can be involved in concurrent updates, and also enable logging of procedures:Then, we need to specify the error logging and limit it to the deadlocks.Please note: parameter include_gds_codes appeared only in Firebird 3.0.2, so if you use 2.5 or 3.0.0 or 3.0.1, it is not possible to filter only deadlock errors, so all errors will be printed to the log.To demonstrate the overall process, let's prepare the test database – for simplicity, there will be 1 table with 1 primary column.After that, we need to start trace session:In this case, fbtracemgr prints log to the screen, but in the production, we need to redirect it to the file, of course.

After the successful start the fbtracemgr prints something like this:

Trace session ID 4 started

Time isql session 1 isql session 2 T1 isql -user SYSDBA -pass masterkey localhost:c:\temp\testdeadlock.fdb Database: localhost:c:\temp\testdeadlock.fdb, User: SYSDBA SQL> set transaction wait; Commit current transaction (y/n)?y Committing. SQL> select current_transaction from rdb$database; CURRENT_TRANSACTION ===================== 15 SQL> select * from t1; I1 ============ 2 SQL> T2 isql -user SYSDBA -pass masterkey localhost:c:\temp\testdeadlock.fdb Database: localhost:c:\temp\testdeadlock.fdb, User: SYSDBA SQL> set transaction wait; Commit current transaction (y/n)?y Committing. SQL> select current_transaction from rdb$database; CURRENT_TRANSACTION ===================== 20 SQL> select * from t1; I1 ============ 2 SQL> So, at the starting point, we can see that 2 transactions are started, #15 and #20. Then, let's try to perform the concurrent update of the same record: T3 SQL> UPDATE T1 SET i1=5 where i1=2; T4 SQL> UPDATE T1 SET i1=100 where i1=2; T5 SQL> commit; SQL> Statement failed, SQLSTATE = 40001 deadlock -update conflicts with concurrent update -concurrent transaction number is 15 SQL>

Then, let's start 2 isql sessions and try to simulate the update conflict. In the table below we have 2 columns for 2 isql sessions. Each row represents a moment in time when the commands were performed.

We started UPDATE in session 1 but did not commit it.

In session 2, UPDATE «hanged» - it waited for the end of the concurrent transaction, and when we have committed UPDATE in session 1, session 2 received the error:

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

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

So, we have a typical situation in case of update conflict with wait transaction.Let's review the trace log to find out the evidence of the update conflict.In this case, the trace log is very short, but in the case of the production system, it can be much longer, but the approach to find deadlocks is the same.As you can see, we have records in the log about both updates – successful and failed, and an error message about deadlock.

Let's consider how to analyze the log:

In the error message, let's locate the identifier of the transaction:

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

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)

Near the record about the error (usually right above it), you will see the failed statement:Notice that execution time is huge (~40 seconds)– it indicates the time when the operation awaited the result of the concurrent transaction.

And, finally, search for the transaction number with the successful UPDATE operation: for this, locate for TRA_NNN, where NNN is the transaction number. In our case, it will be TRA_15:

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)

How to avoid deadlocks?

So, this is it – we found both parties of the update conflict – the successful and the failed.Now you need to identify the best solution for your application to avoid deadlocks - it can be a change of the transaction parameters, or it is possible to add extra error processing and repeat the operation or perform additional checks on the business level of the application.

More details we will consider during the «All About Transactions» workshop at the Firebird Conference 2019 in Berlin, October 17-19.