MySQL Deadlock MySQLTransactionRollbackException in Java Concurrent Application

Question

 //Table Structure//

Create Table: CREATE TABLE `smsLog` (
`aUnique` varchar(30) NOT NULL,
`aMsgId` varchar(50) NOT NULL,
`uid` varchar(30) DEFAULT NULL,
`aClubUnique` varchar(30) DEFAULT NULL,
`aParsedMobile` varchar(30) DEFAULT NULL,
`aSmsAccount` varchar(30) DEFAULT NULL,
`aNetworkCode` varchar(30) DEFAULT NULL,
`sms` int(11) DEFAULT NULL,
`aTariffClass` int(11) DEFAULT NULL,
`aServiceDesc` int(11) DEFAULT NULL,
`aPushCount` int(11) DEFAULT NULL,
`aSmsResponse` varchar(255) DEFAULT NULL,
`aPushCode` varchar(20) DEFAULT NULL,
`billpush` datetime DEFAULT NULL,
  `aCreated` datetime DEFAULT NULL,
`aBillingType` varchar(10) NOT NULL,
`aCampaign` varchar(30) NOT NULL,
PRIMARY KEY (`aUnique`),
KEY `pushcode` (`aPushCode`),
KEY `uid` (`uid`),
KEY `parsedmobile` (`aParsedMobile`),
KEY `created` (`aCreated`),
KEY `smsaccount` (`aSmsAccount`),
KEY `pushcount` (`aPushCount`),
KEY `resp` (`aSmsResponse`),
KEY `campaign` (`aCampaign`),
KEY `sms` (`sms`),
KEY `billpush` (`billpush`),
KEY `club` (`aClubUnique`),
KEY `statCampaign` (`sms`,`aCampaign`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1 ROW_FORMAT=COMPACT

1 row in set (0.00 sec)

 ==============================================



  String rowLockQuery="SELECT 1 FROM smsLog WHERE uid=? AND sms='2' 
  GROUP BY 1 FOR UPDATE";
   String updatequery = "UPDATE smsLog SET abillpush=? WHERE uid=? AND sms='2'"; 

     PreparedStatement preStatement=null;
     PreparedStatement preLockStatement=null;
       try{
         con.setAutoCommit(false);
         preLockStatement=con.prepareStatement(rowLockQuery);
         preLockStatement.setString(1, uid);
         rs=preLockStatement.executeQuery();

         if(rs.next() && rs.getInt(1)>0)
         {
        preStatement=con.prepareStatement(updatequery);
        preStatement.setString(1,newbillpush);
        preStatement.setString(2,uid);
        preStatement.executeUpdate();
         }
        con.commit();
         }

       //catch... finally code...

I get following exception for Update Query. I can't find the reason why.

SQLException occurred com.mysql.jdbc.exceptions.jdbc4.
MySQLTransactionRollbackException: 
Deadlock found when trying to get lock; try restarting transaction

while executing

   show engine innodb status\g

I got the following.. I can't see why update query is having problem and how can it be resolved? DB is MySQL InnoDB.

          Type: InnoDB
          Name: 
        Status: 
        =====================================
        130515 18:45:04 INNODB MONITOR OUTPUT
        =====================================
        Per second averages calculated from the last 55 seconds
        -----------------
        BACKGROUND THREAD
        -----------------
        srv_master_thread loops: 295368 1_second, 44484 sleeps, 29526 10_second, 178 background, 174 flush
        srv_master_thread log flush and writes: 50910
        ----------
        SEMAPHORES
        ----------
        OS WAIT ARRAY INFO: reservation count 3105429, signal count 96714621
        Mutex spin waits 432817470, rounds 438340125, OS waits 702536
        RW-shared spins 16170554, OS waits 1668078; RW-excl spins 2935530, OS waits 553845
        Spin rounds per wait: 1.01 mutex, 5.54 RW-shared, 54.13 RW-excl
        ------------------------
        LATEST DETECTED DEADLOCK
        ------------------------
        130515 18:43:07
        *** (1) TRANSACTION:
        TRANSACTION CA072A19, ACTIVE 2 sec, process no 24674, OS thread id 1298565440 fetching rows
        mysql tables in use 1, locked 1
        LOCK WAIT 11 lock struct(s), heap size 3112, 15 row lock(s), undo log entries 8
        MySQL thread id 61290, query id 38534459  Updating
        UPDATE smsLog SET abillpush='2013-05-15 16:15:42' WHERE uid='ran123321' AND sms='2'
        *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
        RECORD LOCKS space id 260 page no 1165542 n bits 168 index `PRIMARY` of table `anyxume`.`mobileClubBillingLog` trx id CA072A19 lock_mode X locks rec but not gap waiting
        Record lock, heap no 100 PHYSICAL RECORD: n_fields 19; compact format; info bits 0
         0: len 16; hex 313937363139373735383633314b4453; asc 1976197758631KDS;;
         1: len 6; hex 0000ca0729fe; asc     ) ;;
         2: len 7; hex 000007a7a10cb6; asc        ;;
         3: len 0; hex ; asc ;;
         4: len 16; hex 34323231373237303335363331434453; asc 4221727035631CDS;;
         5: len 16; hex 393938353737333930383233314b4453; asc 9985773908231KDS;;
         6: len 11; hex 3237373434383432393439; asc 27744842949;;
         7: len 0; hex ; asc ;;
         8: len 5; hex 63656c6c63; asc cellc;;
         9: len 4; hex 80000001; asc     ;;
         10: len 4; hex 80000005; asc     ;;
         11: len 4; hex 80000001; asc     ;;
         12: len 4; hex 80000000; asc     ;;
         13: len 0; hex ; asc ;;
         14: len 0; hex ; asc ;;
         15: len 8; hex 8000124f003511bf; asc    O 5  ;;
         16: len 8; hex 8000124f0032c6c6; asc    O 2  ;;
         17: len 4; hex 636c7562; asc club;;
         18: len 16; hex 373139363836313836343533314b4453; asc 7196861864531KDS;;

        *** (2) TRANSACTION:
        TRANSACTION CA0729FE, ACTIVE 4 sec, process no 24674, OS thread id 1310812480 starting index read
        mysql tables in use 1, locked 1
        14 lock struct(s), heap size 3112, 368 row lock(s), undo log entries 6
        MySQL thread id 61496, query id 38535072  Updating
        UPDATE smsLog SET abillpush='2013-05-15 16:15:42' WHERE uid='ran212345' AND sms='2'
        *** (2) HOLDS THE LOCK(S):
        RECORD LOCKS space id 260 page no 1165542 n bits 168 index `PRIMARY` of table `anyxume`.`mobileClubBillingLog` trx id CA0729FE lock_mode X locks rec but not gap
        Record lock, heap no 100 PHYSICAL RECORD: n_fields 19; compact format; info bits 0
         0: len 16; hex 313937363139373735383633314b4453; asc 1976197758631KDS;;
         1: len 6; hex 0000ca0729fe; asc     ) ;;
         2: len 7; hex 000007a7a10cb6; asc        ;;
         3: len 0; hex ; asc ;;
         4: len 16; hex 34323231373237303335363331434453; asc 4221727035631CDS;;
         5: len 16; hex 393938353737333930383233314b4453; asc 9985773908231KDS;;
         6: len 11; hex 3237373434383432393439; asc 27744842949;;
         7: len 0; hex ; asc ;;
         8: len 5; hex 63656c6c63; asc cellc;;
         9: len 4; hex 80000001; asc     ;;
         10: len 4; hex 80000005; asc     ;;
         11: len 4; hex 80000001; asc     ;;
         12: len 4; hex 80000000; asc     ;;
         13: len 0; hex ; asc ;;
         14: len 0; hex ; asc ;;
         15: len 8; hex 8000124f003511bf; asc    O 5  ;;
         16: len 8; hex 8000124f0032c6c6; asc    O 2  ;;
         17: len 4; hex 636c7562; asc club;;
         18: len 16; hex 373139363836313836343533314b4453; asc 7196861864531KDS;;

        *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
        RECORD LOCKS space id 260 page no 1369260 n bits 400 index `userunique` of table `anyxume`.`mobileClubBillingLog` trx id CA0729FE lock_mode X waiting
        Record lock, heap no 240 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
         0: len 16; hex 34323231373237303335363331434453; asc 4221727035631CDS;;
         1: len 16; hex 303134393736353137353633314b4453; asc 0149765175631KDS;;

        *** WE ROLL BACK TRANSACTION (1)
        ------------
        TRANSACTIONS
        ------------
        Trx id counter CA073739
        Purge done for trx's n:o < CA072B60 undo n:o < 0
        History list length 597
        LIST OF TRANSACTIONS FOR EACH SESSION:
        ---TRANSACTION CA07371A, not started, process no 24674, OS thread id 1311078720
        MySQL thread id 61961, query id 38718252 
        ---TRANSACTION CA0735E2, not started, process no 24674, OS thread id 1292974400
        MySQL thread id 61960, query id 38701114 
        ---TRANSACTION CA073610, not started, process no 24674, OS thread id 1317202240
        MySQL thread id 61959, query id 38703312 
        ---TRANSACTION CA0736F7, not started, process no 24674, OS thread id 1261025600
        MySQL thread id 61958, query id 38715121 
        ---TRANSACTION CA073594, not started, process no 24674, OS thread id 1285519680
        MySQL thread id 61957, query id 38697158 
        ---TRANSACTION CA073545, not started, process no 24674, OS thread id 1318267200
        MySQL thread id 61956, query id 38692493 
        ---TRANSACTION CA07353B, not started, process no 24674, OS thread id 1316936000
        MySQL thread id 61955, query id 38692221 
        ---TRANSACTION CA073684, not started, process no 24674, OS thread id 1258363200
        ---TRANSACTION CA072B5D, ACTIVE 112 sec, process no 24674, OS thread id 1284454720 updating or deleting
        mysql tables in use 1, locked 1
        266 lock struct(s), heap size 31160, 526 row lock(s), undo log entries 261
        MySQL thread id 52162, query id 38546447  Updating
        UPDATE smsLog SET abillpush='2013-05-15 16:15:42' WHERE uid='ran5543212' AND sms='2'
        Trx read view will not see trx with id >= CA072B5E, sees < CA0729B6
        --------
        FILE I/O
        --------
        I/O thread 0 state: waiting for i/o request (insert buffer thread)
        I/O thread 1 state: waiting for i/o request (log thread)
        I/O thread 2 state: waiting for i/o request (read thread)
        I/O thread 3 state: waiting for i/o request (read thread)
        I/O thread 4 state: waiting for i/o request (read thread)
        I/O thread 5 state: waiting for i/o request (read thread)
        I/O thread 6 state: doing file i/o (write thread) ev set
        I/O thread 7 state: waiting for i/o request (write thread)
        I/O thread 8 state: doing file i/o (write thread) ev set
        I/O thread 9 state: waiting for i/o request (write thread)
        Pending normal aio reads: 0, aio writes: 22,
         ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
        Pending flushes (fsync) log: 0; buffer pool: 0
        3599293 OS file reads, 25445832 OS file writes, 1963825 OS fsyncs
        0 pending preads, 2 pending pwrites
        4.27 reads/s, 26632 avg bytes/read, 242.83 writes/s, 12.55 fsyncs/s
        -------------------------------------
        INSERT BUFFER AND ADAPTIVE HASH INDEX
        -------------------------------------
        Ibuf: size 1944, free list len 52611, seg size 54556,
        1832720 inserts, 1510416 merged recs, 644369 merges
        Hash table size 108635393, node heap has 166234 buffer(s)
        566434.48 hash searches/s, 14182.00 non-hash searches/s
        ---
        LOG
        ---
        Log sequence number 3905250202816
        Log flushed up to   3905249778085
        Last checkpoint at  3905052469518
        0 pending log writes, 0 pending chkp writes
        4306448 log i/o's done, 17.45 log i/o's/second
        ----------------------
        BUFFER POOL AND MEMORY
        ----------------------
        Total memory allocated 56125915136; in additional pool allocated 0
        Dictionary memory allocated 1810268
        Buffer pool size   3350400
        Free buffers       3578
        Database pages     3180587
        Old database pages 1174063
        Modified db pages  232551
        Pending reads 0
        Pending writes: LRU 0, flush list 23, single page 0
        Pages made young 1393521, not young 0
        9.15 youngs/s, 0.00 non-youngs/s
        Pages read 3882679, created 79303, written 43799864
        6.95 reads/s, 0.15 creates/s, 517.30 writes/s
        Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
        Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
        LRU len: 3180587, unzip_LRU len: 0
        I/O sum[26224]:cur[128], unzip sum[0]:cur[0]
        --------------
        ROW OPERATIONS
        --------------
        0 queries inside InnoDB, 0 queries in queue
        10 read views open inside InnoDB
        Main thread process no. 24674, id 1218373952, state: sleeping
        Number of rows inserted 1153277, updated 68599757, deleted 1, read 58688766311
        5.69 inserts/s, 576.39 updates/s, 0.00 deletes/s, 692223.92 reads/s
        ----------------------------
        END OF INNODB MONITOR OUTPUT
        ============================

There should be more output from `SHOW ENGINE INNODB STATUS` about the locks. — Andreas Wederbrand, May 15 '13 at 15:42
i see. are there indices on uid and sms? how many rows are affected usually by such an update? — luksch, May 15 '13 at 15:46
@AndreasWederbrand I have edited my question and have added the missing logs!! — Madan Madan, May 15 '13 at 15:58
@luksch Yess on uid and sms there are indices. The log files shows me TransactionRoll Back Exception after 2-3 minutes of program running.. and it continues.. and later I get exception as Connection is closed! — Madan Madan, May 15 '13 at 16:07
There must be at least another active transaction for a deadlock to occur. Please check your log again, the relevant section begins at `LIST OF TRANSACTIONS FOR EACH SESSION:`. — RandomSeed, May 15 '13 at 16:25
how many records are affected by a typical update statement? if several, then chances are that locking is not a granular as you expect it to be. In that case you can first do a select on all rows to update, ORDER them be the primary key and to the update in this order in every concurrent update — luksch, May 15 '13 at 16:32

luksch · Answer 1 · 2013-05-17T08:27:37.207

2

You have

UPDATE smsLog 
SET abillpush='2013-05-15 16:15:42' 
WHERE uid='ran123321' AND sms='2';

If this affects more than one row it is possible that mysql uses table locking for the update. In that case you can try to first select the rows to be updated:

SELECT aUnique 
FROM smsLog 
WHERE uid='ran123321' AND sms='2' 
ORDER BY aUnique;

Then take the ordered result set and update in this order

UPDATE smsLog 
  SET abillpush='2013-05-15 16:15:42' 
WHERE aUnique IN (the list);

Of course you can combine the latter into one statement.

UPDATE smsLog 
  SET abillpush='2013-05-15 16:15:42' 
WHERE aUnique IN (
   SELECT aUnique 
   FROM smsLog 
   WHERE uid='ran123321' AND sms='2' ORDER BY aUnique);

Taking your code example you get:

String updatequery = "UPDATE smsLog "+ 
      "SET abillpush=? "+
      "WHERE aUnique IN ("+
      "SELECT aUnique " +
      "FROM smsLog " +
      "WHERE uid=? AND sms=? ORDER BY aUnique)";

This is just an idea and is not tested. nevertheless it should work.

edited May 17 '13 at 08:27

answered May 15 '13 at 16:38

luksch

11,497
6
38
53

@Luksh PRIM-KEY is uid in query. – Madan Madan May 15 '13 at 16:44
@Luksh it's a concurrent application.. update can happen parallelly! – Madan Madan May 15 '13 at 18:38
@Luksh I have edited my question with full status logs.. hope it helps to find the problem and then solution – Madan Madan May 15 '13 at 18:54
@Luksh I need to update all the records that have sms='2' for a uid. Like some uid can have 5-10 tickets that need to be updated.. so how can I do this in Java code? – Madan Madan May 15 '13 at 22:46
1

Dear Madan Madan. ```"Like some uid can have 5-10 tickets that need to be updated"``` indicates that uid is NOT our primary key. Can you please post the results of ```SHOW CREATE TABLE smsLog\G```? – luksch May 16 '13 at 07:49
still, it would maybe help to find out what your real pk is, if you have one defined... please do the ```SHOW CREATE TABLE smsLog\G``` and add the results to the question – luksch May 16 '13 at 21:39
well, I updated my suggestion as well. Try it with the last update statement. It is important that all your concurrent updates only update the rows in order of the primary key, which is ```aUnique```. That way there is no possible dead lock. – luksch May 17 '13 at 08:23
@Luksh.. thanks. So, will it update multiple rows of that single userunique having different primary keys (aUnique) for different tickets?? – Madan Madan May 17 '13 at 09:56

score 1 · Answer 2 · answered May 15 '13 at 20:31

1

Without seing all queries running it's hard to know exactly what's going on but from the error I can see that your query has first acquired a write lock and then later it needs to have a write lock that also requires gap locking. I've had this problem my self and never got a good answer why the locks are taken in this order but it seems to be related to an update not using the entire primary key.

However, it's often possible to get this lock before the update with a FOR UPDATE statement. In your case it would be

SELECT 1 FROM smsLog WHERE uid='ran212345' AND sms='2' FOR UPDATE

Giv it a try and hope for the best :)

answered May 15 '13 at 20:31

Andreas Wederbrand

38,065
11
68
78

I need to update all the records that have sms='2' for a uid. Like some uid can have 5-10 tickets that need to be updated.. so how can I do this in Java code? – Madan Madan May 15 '13 at 22:46
+1 If this problem is indeed related to gap locking, you may want to disable this feature by switching to a [`READ COMMITTED`](http://dev.mysql.com/doc/refman/5.6/en/innodb-record-level-locks.html) (or lower) isolation level. If you can live with the risk of the "Phantom Problem" occurring, that is (which, I believe, cannot happen in this specific case). – RandomSeed May 15 '13 at 23:28
@MadanMadan Make sure you execute the suggested `SELECT` and your `UPDATE` within the same the same transaction. – RandomSeed May 15 '13 at 23:37
As @YaK says you need to do the `FOR UPDATE` part within the same transaction, either through a stored procedure or with a java transaction manager. It might also be possible to do it as a jdbc batch execution but I haven't tested that. – Andreas Wederbrand May 16 '13 at 04:33
@YaK Can Select..For Update Query be used to update multiple rows of same userid?? I am also looking at tutorial how to use it.. but if confirmation from professional guys like you appears, confidence within me rises high!! Coz the system which I am handling is really risky one! – Madan Madan May 16 '13 at 07:08
2

SELECT ... FOR UPDATE will not update any rows, it will take a write lock on all rows it examines in the engine. When you do the UPDATE later the lock is already in place and no more locking is needed. – Andreas Wederbrand May 16 '13 at 08:43
@AndreasWederbrand.. I am using PreparedStatement.. That means I should write two statement one for Select.. For Update and as soon as it executes, I write Update Statement.. please correct me if I am getting somewhere wrong... – Madan Madan May 16 '13 at 09:59
@AndreasWederbrand Nopes it didn't help.. it showed me the same exceptions after 5 mins of concurrent application running!!! I am using now Select for update and then update statement – Madan Madan May 16 '13 at 11:22
I don't think you're executing those two statements in the same transaction. – Andreas Wederbrand May 16 '13 at 15:11
@AndreasWederbrand It's under the same transaction. I have edited my question with PreparedStatement. . – Madan Madan May 16 '13 at 20:41
Is this the only update running? Can you post the DDL and indexes? There is two indexes at play here. Both the PRIMARY and one called userunique. – Andreas Wederbrand May 17 '13 at 06:13
@AndreasWederbrand PRIMARY KEY for each ticket is different. UserUnique is not a primary key in this table. There are different tickets for the same user. how to do DDL and Indexes?? Please advise. – Madan Madan May 17 '13 at 07:04
@AndreasWederbrand Okey i have updated my question with Table structure – Madan Madan May 17 '13 at 07:35

MySQL Deadlock MySQLTransactionRollbackException in Java Concurrent Application

2 Answers2

Linked