Spring Batch - org.springframework.dao.DeadlockLoserDataAccessException in Azure SQL Server?

user_14419488 0
Viewed 405

I have a spring batch application that uses Azure SQL Server as a database.

The Source table has two entries for the combination of each Store [0001] Eff_Date [2021-10-29] and ItemID [0000000000000]

Something like

Store [0001] Eff_Date [2021-10-29] and ItemID [0000000000000]
Store [0001] Eff_Date [2021-10-29] and ItemID [0000000000000]

Store [0002] Eff_Date [2021-10-29] and ItemID [0000000000000]
Store [0002] Eff_Date [2021-10-29] and ItemID [0000000000000]

The target table has a cluster primary key constraint as Store + Eff_Date + ItemID.

The application is designed is such a way

  1. Insert the Record
  2. If Insert fails, update the Record

I was getting the following error while trying to process the above records

2021-12-15 03:42:51,134 DEBUG [SimpleAsyncTaskExecutor-1] ItemItemWriter - Writing record for [0001] Eff_Date [2021-10-29] Host Batch [0] UPC [0000000000000]
2021-12-15 03:42:51,134 DEBUG [SimpleAsyncTaskExecutor-1] ItemDaoImpl - Inserting New Item Data: ItemId [0000000000000] StoreNbr [0001] EffectiveDt [2021-10-29]

2021-12-15 03:42:51,136 DEBUG [SimpleAsyncTaskExecutor-1] ItemItemWriter - Writing record for [0001] Eff_Date [2021-10-29] Host Batch [0] UPC [0000000000000]
2021-12-15 03:42:51,136 DEBUG [SimpleAsyncTaskExecutor-1] ItemDaoImpl - Inserting New Item Data: ItemId [0000000000000] StoreNbr [0001] EffectiveDt [2021-10-29]
2021-12-15 03:42:51,139 DEBUG [SimpleAsyncTaskExecutor-1] ItemDaoImpl - Updating Existing Item Data: ItemId [0000000000000] StoreNbr [0001] EffectiveDt [2021-10-29]
2021-12-15 03:42:52,546 ERROR [SimpleAsyncTaskExecutor-1] ItemDaoImpl - An error occurred during item update for Item [0000000000000] ] Store [0001] ] Batch [0] ] Date [2021-10-29] :org.springframework.dao.DeadlockLoserDataAccessException:

Most of the update fails with DeadlockLoserDataAccessException.

So, I have updated the Insert & Update statement like (with and without Begin Tran & commit Tran, result is same)

  1. Begin Tran Insert into Table with (Tablock)... Commit tran
  2. Begin Tran Update Table with (Tablock) set commit Tran

also tried(with and without Begin Tran & commit Tran, result is same):

  1. Begin Tran Insert into Table with (SERIALIZABLE)... Commit tran
  2. Begin Tran Update Table with (SERIALIZABLE) set commit Tran

Now update statement no longer fails with DeadlockLoserDataAccessException however few of the insert statement throws the DeadlockLoserDataAccessException exception

 An error occurred during new item insert for Item [0000060923410] ] Store [0056]  
 An error occurred during new item insert for Item [0000060923410] ] Store [0052]  
 An error occurred during new item insert for Item [0000060923410] ] Store [3278]  
 An error occurred during new item insert for Item [0000060923410] ] Store [0052]  
 An error occurred during new item insert for Item [0000060923410] ] Store [3284]  
 An error occurred during new item insert for Item [0000060923410] ] Store [3278]  
 An error occurred during new item insert for Item [0000060923410] ] Store [3290]  
 An error occurred during new item insert for Item [0000060923410] ] Store [3284]  
 An error occurred during new item insert for Item [0001030010279] ] Store [3278]  
 An error occurred during new item insert for Item [0001030010279] ] Store [3284]  
 An error occurred during new item insert for Item [0000060923410] ] Store [3290]  
 An error occurred during new item insert for Item [0000954242689] ] Store [0052]  
 An error occurred during new item insert for Item [0001030010279] ] Store [3290]  
 An error occurred during tag request insert for Item [0001030010279] ] Store [3290]  
 An error occurred during new item insert for Item [0001030053664] ] Store [3284]  
 An error occurred during new item insert for Item [0001030080895] ] Store [3284]  
 An error occurred during tag request insert for Item [0001030080895] ] Store [3284]

What could be the reason and fix?

Note: I tried removing with (tablock) from the insert statement but update statement starts throwing the deadlock errors.

Deadlock details from SQL Server

<deadlock>
  <victim-list>
    <victimProcess id="process1d67b529c28" />
  </victim-list>
  <process-list>
    <process id="process1d67b529c28" taskpriority="0" logused="0" waitresource="OBJECT: 6:1442156233:0 " waittime="7673" ownerId="101271231" transactionname="implicit_transaction" lasttranstarted="2021-12-20T13:03:47.363" XDES="0x1d68c330428" lockMode="X" schedulerid="8" kpid="23916" status="suspended" spid="172" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2021-12-20T13:03:47.363" lastbatchcompleted="2021-12-20T13:03:47.273" lastattention="1900-01-01T00:00:00.273" clientapp="Microsoft JDBC Driver for SQL Server" hostname="myLaptop" hostpid="0" loginname="myDBUser" isolationlevel="read committed (2)" xactid="101271231" currentdb="6" currentdbname="myDBUser" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058">
      <executionStack>
        <frame procname="unknown" queryhash="0x7c82d557079e2a63" queryplanhash="0xe907b104918dcca3" line="1" stmtstart="6176" stmtend="12328" sqlhandle="0x020000003a328135b9a6da13379eb4d245948c00142904ee0000000000000000000000000000000000000000">
unknown    </frame>
        <frame procname="unknown" queryhash="0x0000000000000000" queryplanhash="0x0000000000000000" line="1" sqlhandle="0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000">
unknown    </frame>
      </executionStack>
      <inputbuf>
(@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 date,@P3 nvarchar(4000),@P4 nvarchar(4000),@P5 nvarchar(4000),@P6 nvarchar(4000),@P7 int,@P8 nvarchar(4000),@P9 nvarchar(4000),@P10 nvarchar(4000),@P11 nvarchar(4000),@P12 decimal(38,4),@P13 nvarchar(4000),@P14 smallint,@P15 decimal(38,4),@P16 decimal(38,2),@P17 smallint,@P18 decimal(38,0),@P19 decimal(38,0),@P20 smallint,@P21 nvarchar(4000),@P22 nvarchar(4000),@P23 nvarchar(4000),@P24 smallint,@P25 decimal(38,2),@P26 smallint,@P27 decimal(38,0),@P28 decimal(38,0),@P29 decimal(38,2),@P30 smallint,@P31 smallint,@P32 nvarchar(4000),@P33 nvarchar(4000),@P34 nvarchar(4000),@P35 decimal(38,2),@P36 decimal(38,4),@P37 nvarchar(4000),@P38 nvarchar(4000),@P39 nvarchar(4000),@P40 nvarchar(4000),@P41 nvarchar(4000),@P42 nvarchar(4000),@P43 nvarchar(4000),@P44 nvarchar(4000),@P45 nvarchar(4000),@P46 nvarchar(4000),@P47 nvarchar(4000),@P48 nvarchar(4000),@P49 nvarchar(4000),@P50 nvarchar(4000),@P51 nvarchar(4000),@P52 nvarchar(4000),@P53 nvarchar(4000),@P54 nvarchar(4000),@P55 n   </inputbuf>
    </process>
    <process id="process1d67b575468" taskpriority="0" logused="0" waitresource="OBJECT: 6:1442156233:7 " waittime="2498" ownerId="101271602" transactionname="implicit_transaction" lasttranstarted="2021-12-20T13:04:11.150" XDES="0x1d55a758428" lockMode="X" schedulerid="1" kpid="62644" status="suspended" spid="171" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2021-12-20T13:04:11.150" lastbatchcompleted="2021-12-20T13:03:46.487" lastattention="1900-01-01T00:00:00.487" clientapp="Microsoft JDBC Driver for SQL Server" hostname="myLaptop" hostpid="0" loginname="myDBUser" isolationlevel="read committed (2)" xactid="101271602" currentdb="6" currentdbname="myDBUser" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058">
      <executionStack>
        <frame procname="unknown" queryhash="0x7c82d557079e2a63" queryplanhash="0xe907b104918dcca3" line="1" stmtstart="6176" stmtend="12328" sqlhandle="0x02000000314353379a6b206b3eb6880ab89e1e4d79d124220000000000000000000000000000000000000000">
unknown    </frame>
      </executionStack>
      <inputbuf>
(@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 date,@P3 nvarchar(4000),@P4 nvarchar(4000),@P5 nvarchar(4000),@P6 nvarchar(4000),@P7 int,@P8 nvarchar(4000),@P9 nvarchar(4000),@P10 nvarchar(4000),@P11 nvarchar(4000),@P12 decimal(38,4),@P13 nvarchar(4000),@P14 smallint,@P15 decimal(38,4),@P16 decimal(38,0),@P17 smallint,@P18 decimal(38,0),@P19 decimal(38,0),@P20 smallint,@P21 nvarchar(4000),@P22 nvarchar(4000),@P23 nvarchar(4000),@P24 smallint,@P25 decimal(38,0),@P26 smallint,@P27 decimal(38,0),@P28 decimal(38,0),@P29 decimal(38,0),@P30 smallint,@P31 smallint,@P32 nvarchar(4000),@P33 nvarchar(4000),@P34 nvarchar(4000),@P35 decimal(38,0),@P36 decimal(38,4),@P37 nvarchar(4000),@P38 nvarchar(4000),@P39 nvarchar(4000),@P40 nvarchar(4000),@P41 nvarchar(4000),@P42 nvarchar(4000),@P43 nvarchar(4000),@P44 nvarchar(4000),@P45 nvarchar(4000),@P46 nvarchar(4000),@P47 nvarchar(4000),@P48 nvarchar(4000),@P49 nvarchar(4000),@P50 nvarchar(4000),@P51 nvarchar(4000),@P52 nvarchar(4000),@P53 nvarchar(4000),@P54 nvarchar(4000),@P55 n   </inputbuf>
    </process>
  </process-list>
  <resource-list>
    <objectlock lockPartition="0" objid="1442156233" subresource="FULL" dbid="6" objectname="3d6766e5-31cc-4898-8415-e27d1c16d503.myDBUser.STORE_ITEM" id="lock1d655388f80" mode="X" associatedObjectId="1442156233">
      <owner-list>
        <owner id="process1d67b575468" mode="X" />
      </owner-list>
      <waiter-list>
        <waiter id="process1d67b529c28" mode="X" requestType="wait" />
      </waiter-list>
    </objectlock>
    <objectlock lockPartition="7" objid="1442156233" subresource="FULL" dbid="6" objectname="3d6766e5-31cc-4898-8415-e27d1c16d503.myDBUser.STORE_ITEM" id="lock1d6350c9b80" mode="IX" associatedObjectId="1442156233">
      <owner-list>
        <owner id="process1d67b529c28" mode="IX" />
      </owner-list>
      <waiter-list>
        <waiter id="process1d67b575468" mode="X" requestType="wait" />
      </waiter-list>
    </objectlock>
  </resource-list>
</deadlock>

another one

<deadlock>
  <victim-list>
    <victimProcess id="process1d67b573088" />
  </victim-list>
  <process-list>
    <process id="process1d67b573088" taskpriority="0" logused="0" waitresource="OBJECT: 6:1442156233:4 " waittime="2510" ownerId="101411096" transactionname="implicit_transaction" lasttranstarted="2021-12-20T13:40:14.337" XDES="0x1d68c984428" lockMode="X" schedulerid="6" kpid="15084" status="suspended" spid="145" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2021-12-20T13:40:14.337" lastbatchcompleted="2021-12-20T13:40:14.260" lastattention="1900-01-01T00:00:00.260" clientapp="Microsoft JDBC Driver for SQL Server" hostname="myLaptop" hostpid="0" loginname="myDBUser" isolationlevel="read committed (2)" xactid="101411096" currentdb="6" currentdbname="myDBUser" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058">
      <executionStack>
        <frame procname="unknown" queryhash="0x7c82d557079e2a63" queryplanhash="0xe907b104918dcca3" line="1" stmtstart="6176" stmtend="12328" sqlhandle="0x020000003a328135b9a6da13379eb4d245948c00142904ee0000000000000000000000000000000000000000">
unknown    </frame>
        <frame procname="unknown" queryhash="0x0000000000000000" queryplanhash="0x0000000000000000" line="1" sqlhandle="0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000">
unknown    </frame>
      </executionStack>
      <inputbuf>
(@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 date,@P3 nvarchar(4000),@P4 nvarchar(4000),@P5 nvarchar(4000),@P6 nvarchar(4000),@P7 int,@P8 nvarchar(4000),@P9 nvarchar(4000),@P10 nvarchar(4000),@P11 nvarchar(4000),@P12 decimal(38,4),@P13 nvarchar(4000),@P14 smallint,@P15 decimal(38,4),@P16 decimal(38,2),@P17 smallint,@P18 decimal(38,0),@P19 decimal(38,0),@P20 smallint,@P21 nvarchar(4000),@P22 nvarchar(4000),@P23 nvarchar(4000),@P24 smallint,@P25 decimal(38,2),@P26 smallint,@P27 decimal(38,0),@P28 decimal(38,0),@P29 decimal(38,2),@P30 smallint,@P31 smallint,@P32 nvarchar(4000),@P33 nvarchar(4000),@P34 nvarchar(4000),@P35 decimal(38,2),@P36 decimal(38,4),@P37 nvarchar(4000),@P38 nvarchar(4000),@P39 nvarchar(4000),@P40 nvarchar(4000),@P41 nvarchar(4000),@P42 nvarchar(4000),@P43 nvarchar(4000),@P44 nvarchar(4000),@P45 nvarchar(4000),@P46 nvarchar(4000),@P47 nvarchar(4000),@P48 nvarchar(4000),@P49 nvarchar(4000),@P50 nvarchar(4000),@P51 nvarchar(4000),@P52 nvarchar(4000),@P53 nvarchar(4000),@P54 nvarchar(4000),@P55 n   </inputbuf>
    </process>
    <process id="process1d67ab88108" taskpriority="0" logused="0" waitresource="OBJECT: 6:1442156233:0 " waittime="2510" ownerId="101410953" transactionname="implicit_transaction" lasttranstarted="2021-12-20T13:40:12.427" XDES="0x1d595d04428" lockMode="X" schedulerid="5" kpid="13796" status="suspended" spid="146" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2021-12-20T13:40:12.427" lastbatchcompleted="2021-12-20T13:40:12.370" lastattention="1900-01-01T00:00:00.370" clientapp="Microsoft JDBC Driver for SQL Server" hostname="myLaptop" hostpid="0" loginname="myDBUser" isolationlevel="read committed (2)" xactid="101410953" currentdb="6" currentdbname="myDBUser" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128058">
      <executionStack>
        <frame procname="unknown" queryhash="0x7c82d557079e2a63" queryplanhash="0xe907b104918dcca3" line="1" stmtstart="6176" stmtend="12328" sqlhandle="0x020000003a328135b9a6da13379eb4d245948c00142904ee0000000000000000000000000000000000000000">
unknown    </frame>
        <frame procname="unknown" queryhash="0x0000000000000000" queryplanhash="0x0000000000000000" line="1" sqlhandle="0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000">
unknown    </frame>
      </executionStack>
      <inputbuf>
(@P0 nvarchar(4000),@P1 nvarchar(4000),@P2 date,@P3 nvarchar(4000),@P4 nvarchar(4000),@P5 nvarchar(4000),@P6 nvarchar(4000),@P7 int,@P8 nvarchar(4000),@P9 nvarchar(4000),@P10 nvarchar(4000),@P11 nvarchar(4000),@P12 decimal(38,4),@P13 nvarchar(4000),@P14 smallint,@P15 decimal(38,4),@P16 decimal(38,2),@P17 smallint,@P18 decimal(38,0),@P19 decimal(38,0),@P20 smallint,@P21 nvarchar(4000),@P22 nvarchar(4000),@P23 nvarchar(4000),@P24 smallint,@P25 decimal(38,2),@P26 smallint,@P27 decimal(38,0),@P28 decimal(38,0),@P29 decimal(38,2),@P30 smallint,@P31 smallint,@P32 nvarchar(4000),@P33 nvarchar(4000),@P34 nvarchar(4000),@P35 decimal(38,2),@P36 decimal(38,4),@P37 nvarchar(4000),@P38 nvarchar(4000),@P39 nvarchar(4000),@P40 nvarchar(4000),@P41 nvarchar(4000),@P42 nvarchar(4000),@P43 nvarchar(4000),@P44 nvarchar(4000),@P45 nvarchar(4000),@P46 nvarchar(4000),@P47 nvarchar(4000),@P48 nvarchar(4000),@P49 nvarchar(4000),@P50 nvarchar(4000),@P51 nvarchar(4000),@P52 nvarchar(4000),@P53 nvarchar(4000),@P54 nvarchar(4000),@P55 n   </inputbuf>
    </process>
  </process-list>
  <resource-list>
    <objectlock lockPartition="4" objid="1442156233" subresource="FULL" dbid="6" objectname="3d6766e5-31cc-4898-8415-e27d1c16d503.myDBUser.STORE_ITEM" id="lock1d6598a7280" mode="IX" associatedObjectId="1442156233">
      <owner-list>
        <owner id="process1d67ab88108" mode="IX" />
      </owner-list>
      <waiter-list>
        <waiter id="process1d67b573088" mode="X" requestType="wait" />
      </waiter-list>
    </objectlock>
    <objectlock lockPartition="0" objid="1442156233" subresource="FULL" dbid="6" objectname="3d6766e5-31cc-4898-8415-e27d1c16d503.myDBUser.STORE_ITEM" id="lock1d5b1706a00" mode="X" associatedObjectId="1442156233">
      <owner-list>
        <owner id="process1d67b573088" mode="X" />
      </owner-list>
      <waiter-list>
        <waiter id="process1d67ab88108" mode="X" requestType="wait" />
      </waiter-list>
    </objectlock>
  </resource-list>
</deadlock>

Note: I have appended my JDBC URL with sendStringParametersAsUnicode=false

I verified the table and found only char, varchar, int & Datetime2 columns.

Also jdbctemplate.update takes query, values and the datatype. Datatype is properly defined in the application. No reference of nvarchar found anywhere in the application.

database-deadlocks azure-sql-database spring sql-server java
1 Answers

Error: An error occurred during item update for Item [0000000000000] ] Store [0001] ] Batch [0] ] Date [2021-10-29] :org.springframework.dao.DeadlockLoserDataAccessException:

By deafult Transact-SQL statement is committed or rolled back when it completes (Autocommit Transactions).

The most commonly solution for issues related to modifications by other processes is to wrap the vulnerable statements in a transaction (execute all or nothing as one).

In theory, using a transaction provides isolation from the effects of other concurrent activities.

In reality, we only have a degree of isolation depending on the transaction isolation level.

Serializable is the most isolated of the standard transaction isolation levels. It's behaves like each SQL-transaction executes to completion before the next SQL-transaction begins.

Note that it is not the same as serialized executions, where each transaction actually runs exclusively to completion before the next one starts! Serializable isolation only required to have the same effects as if they were executed serially (in some unspecified order).

For example, if we execute UPDATE on two unrelated rows using two transactions, then Serializable isolation allows to execute these transaction in parallel since the result is the same as executing the transactions one after the other.

But what if we have a constraint (like primary key), which enforces a uniqueness relation between the rows - you cannot set (UPDATE/INSERT) a value which exists. This means that the server must confirm the value is not in used first (SQL Server is "smart" and not necessarily will have to scan the entire table but yet it will have to enforce uniqueness with all values).

cluster primary key constraint as Store + Eff_Date + ItemID

This enforces the relation between all rows and in your case all columns [Store],[Eff_Date],[ItemID]

Most of the update fails with DeadlockLoserDataAccessException.

This is not coming from SQL Server directly but from spring framework

To have more information about SQL Side you should monitor SQL Server errors. It is very difficult to monitor source of issue when you don't have the source of the error but only a "second hand" information.

In general from the SQL Server side, it makes sense to have waits/lock, as I explained above about the relations which you enfoeced by using this Promary key. These waits/locks can lead to deadlocks as well

Insert into Table with (Tablock)

This means that you lock the entire table from the start of the INSERT to the end! This sound like a very bad idea in most cases.

Insert into Table with (SERIALIZABLE)... Now update statement no longer fails with DeadlockLoserDataAccessException however few of the insert statement throws the DeadlockLoserDataAccessException exception

Again, I have no idea what is DeadlockLoserDataAccessException since it is not the source issue but the interpretation of the client side (the spring framework which connect the SQL Server), but it makes sense that you will have deadlock in the insert statement since you have UPDATE which require X lock (Exclusive lock)

Check my explanation above and remember that Serializable isolation is not the same as serialized executions!

What could be the reason and fix?

(1) First, start with monitor the source of the issue and not the interpretation of the issue by the spring framework.

Monitor the waits, locks, deadlock in the SQL Server side directly. There are multiple tools for this which Google can find youo best toturials for this common task.

If Insert fails, update the Record

(2) Instead of using INSERT and if this fails then trying to use UPDATE simply use MERGE query. This single query will not need to compate another query which lock the same resources and will probably provide much better performance on the way

(3) Try to remove all the query hints which you configure and let the server manage the queries, once you move to use MERGE.

user_44219440
Related