Frequent Deadlock
While testing one feature of our application, we've experienced surprisingly frequent deadlocks on concurrent inserts. In our application tests, deadlocks have been observed to occur 20% of the time. These deadlocks are replicated by the sample Java code posted below, where they can occur over 50% of the time.
Each transaction issues one SQL delete statement followed by several inserts into the same table. Each insert puts 64K of text into a MEDIUMTEXT column. When I run the sample code, deadlocks seem to happen more frequently when the delete statement matches no rows. In our application, however, it doesn't seem to matter whether rows are deleted or not. Executing the delete statement appears critical; if the table is emptied and the delete statements removed (leaving only the inserts), deadlocks are not observed.
Configuration:
Windows XP
MySQL 4.1.13 & 4.1.12
Connector/J 3.1.10 & 3.1.8
Java 1.4.2
Here are two instances of the deadlock as reported by InnoDB:
------------------------
LATEST DETECTED DEADLOCK
------------------------
050804 18:32:55
*** (1) TRANSACTION:
TRANSACTION 0 25619, ACTIVE 2 sec, OS thread id 5744 setting auto-inc lock
mysql tables in use 1, locked 1
LOCK WAIT 6 lock struct(s), heap size 1024, undo log entries 6
MySQL thread id 735, query id 55705 localhost 127.0.0.1 webapp update
INSERT INTO Glob (glob_id,associated_id,sequence,data) VALUES (null,9001,1,'aaaa...
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
TABLE LOCK table `xetus/glob` trx id 0 25619 lock mode AUTO-INC waiting
*** (2) TRANSACTION:
TRANSACTION 0 25608, ACTIVE 3 sec, OS thread id 1476 inserting, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
6 lock struct(s), heap size 1024, undo log entries 10
MySQL thread id 724, query id 55696 localhost 127.0.0.1 webapp update
INSERT INTO Glob (glob_id,associated_id,sequence,data) VALUES (null,8000,4,'aaaa...
*** (2) HOLDS THE LOCK(S):
TABLE LOCK table `xetus/glob` trx id 0 25608 lock mode AUTO-INC
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 20601 n bits 312 index `associated_id_index` of table `xetus/glob` trx id 0 25608 lock mode S waiting
Record lock, heap no 120 PHYSICAL RECORD: n_fields 3; 1-byte offs TRUE; info bits 32
0: len 8; hex 8000000000002329; asc #);; 1: len 4; hex 80000000; asc ;; 2: len 8; hex 80000000000028bf; asc (?;;
*** WE ROLL BACK TRANSACTION (1)
------------------------
LATEST DETECTED DEADLOCK
------------------------
050804 18:35:31
*** (1) TRANSACTION:
TRANSACTION 0 25685, ACTIVE 2 sec, OS thread id 2940 inserting
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 320, undo log entries 1
MySQL thread id 754, query id 56340 localhost 127.0.0.1 webapp update
INSERT INTO Glob (glob_id,associated_id,sequence,data) VALUES (null,2001,0,'aaaa...
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 20601 n bits 312 index `associated_id_index` of table `xetus/glob` trx id 0 25685 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 17
*** (2) TRANSACTION:
TRANSACTION 0 25686, ACTIVE 2 sec, OS thread id 4080 setting auto-inc lock, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
6 lock struct(s), heap size 1024, undo log entries 5
MySQL thread id 755, query id 56371 localhost 127.0.0.1 webapp update
INSERT INTO Glob (glob_id,associated_id,sequence,data) VALUES (null,3001,0,'aaaa...
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 20601 n bits 312 index `associated_id_index` of table `xetus/glob` trx id 0 25686 lock_mode X
Record lock, heap no 17
Record lock, heap no 65
Record lock, heap no 85
Record lock, heap no 128
Record lock, heap no 152
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
TABLE LOCK table `xetus/glob` trx id 0 25686 lock mode AUTO-INC waiting
*** WE ROLL BACK TRANSACTION (1)
Deadlocks also occur with about the same frequency in 4.0.22 between transactions executing the DELETE and INSERT.
The sample code assumes this table:
CREATE TABLE Glob(
glob_id bigint NOT NULL AUTO_INCREMENT,
associated_id bigint DEFAULT NULL,
sequence int DEFAULT NULL,
data MEDIUMTEXT,
PRIMARY KEY (glob_id),
UNIQUE KEY associated_id_index (associated_id,sequence)
) ENGINE=InnoDB;
Note the comment before the lines that delete globs; if the Glob table is empty before running the sample code,
the delete can be omitted and the deadlocks are not observed.
---------- start of Java code (obviously) ----------
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.sql.SQLException;
public class DeadlockTest extends Thread {
private static String data;
static {
int length = 65535;
char[] a = new char[length];
java.util.Arrays.fill(a, 'a');
data = new String(a);
}
private static int deleted_count = 0;
private static int committed_count = 0;
private static int rollback_count = 0;
private static synchronized void incDeletedCount() { ++deleted_count; }
private static synchronized void incCommittedCount() { ++committed_count; }
private static synchronized void incRollbackCount() { ++rollback_count; }
private static int notify_count = 0;
private static synchronized void countingNotify() { ++notify_count; DeadlockTest.class.notify(); }
private static final String insertStatement =
"INSERT INTO Glob (glob_id,associated_id,sequence,data) VALUES (null,?,?,?)";
private static final String deleteStatement =
"DELETE FROM Glob WHERE associated_id = ?";
private long k; // Used to generate a unique value for associated_id
DeadlockTest(long k) {
this.k = k;
}
public void run() {
try {
// Perform transactions in sqequence
long transaction_count = 2;
for (long j = 0; j < transaction_count; ++j) {
Connection con = DriverManager.getConnection(...);
con.setAutoCommit(false);
PreparedStatement pstmtDelete = null;
PreparedStatement pstmtInsert = null;
try {
// Delete any existing globs with the same associated_id value
// If the Glob table is empty before running this code,
// this delete can be removed and the deadlocks will occur
// rarely or not at all
pstmtDelete = con.prepareStatement(deleteStatement);
pstmtDelete.setLong(1, k*1000 + j);
pstmtDelete.executeUpdate();
incDeletedCount();
// Perform multiple inserts in this transaction
int insert_count = 5;
for (int i = 0; i < insert_count; ++i) {
pstmtInsert = con.prepareStatement(insertStatement);
pstmtInsert.setLong(1, k*1000 + j);
pstmtInsert.setInt(2, i);
pstmtInsert.setString(3, data);
pstmtInsert.executeUpdate();
}
con.commit();
incCommittedCount();
}
catch (SQLException ex) {
System.out.println("SQLException: " + ex.getMessage());
con.rollback();
incRollbackCount();
}
finally {
try { if (null != pstmtDelete) pstmtDelete.close(); }
catch (SQLException e) { System.out.println(e.toString()); }
try { if (null != pstmtInsert) pstmtInsert.close(); }
catch (SQLException e) { System.out.println(e.toString()); }
}
con.close();
}
}
catch (Exception e) {
System.out.println(e.toString());
}
catch (Throwable t) {
System.out.println(t.toString());
}
finally {
countingNotify();
}
}
private static final int THREAD_COUNT = 12;
public synchronized static void main(String[] args) throws Exception {
// The newInstance() call is a work around for some broken Java implementations
Class.forName("com.mysql.jdbc.Driver").newInstance();
// Launch concurrent threads
for (long i=0; i < THREAD_COUNT; ++i)
new DeadlockTest(i).start();
// Wait for all threads to finish
while ( notify_count < THREAD_COUNT ) {
DeadlockTest.class.wait();
}
System.out.println("Deleted " + deleted_count + " groups");
System.out.println("Committed " + committed_count + " transactions");
System.out.println("Aborted " + rollback_count + " transactions");
}
}