I'm trying to get to the bottom of the 1205 exceptions I've been getting. I understand it's a lock, but I don't understand exactly why it's happening and how I can fix (either by recoding, table restructure, or mysql configuration). Also, I should note that I'm a Java developer using JPA, and not a MySQL admin, but I'll provide as much info as I can. Any help would be appreciated.
MySQL config: [client] port = 3306 socket = /tmp/mysql.sock [mysqld] port = 3306 socket = /tmp/mysql.sock skip-locking key_buffer_size = 384M max_allowed_packet = 1M table_open_cache = 512 sort_buffer_size = 2M read_buffer_size = 2M read_rnd_buffer_size = 8M myisam_sort_buffer_size = 64M thread_cache_size = 8 query_cache_size = 32M thread_concurrency = 16 innodb_additional_mem_pool_size = 16M innodb_buffer_pool_size = 512M innodb_file_io_threads = 4 innodb_thread_concurrency = 16 innodb_flush_log_at_trx_commit = 2 innodb_log_buffer_size = 8M innodb_log_file_size = 128M innodb_max_dirty_pages_pct = 90 innodb_lock_wait_timeout = 120 innodb_flush_method = O_DIRECT [mysqldump] quick max_allowed_packet = 16M [mysql] no-auto-rehash [myisamchk] key_buffer_size = 256M sort_buffer_size = 256M read_buffer = 2M write_buffer = 2M [mysqlhotcopy] interactive-timeout Most of the configuration above is based on articles provided at mysqlperformanceblog.com. Here is a count of records in my tables: mysql> select count(*) from EXTERNALIPADDRESSBINDING; +----------+ | count(*) | +----------+ | 135846 | +----------+ 1 row in set (0.08 sec) mysql> select count(*) from INTERNALIPADDRESSBINDING; +----------+ | count(*) | +----------+ | 3865629 | +----------+ 1 row in set (1.33 sec) mysql> select count(*) from NETWORKUSERBINDING; +----------+ | count(*) | +----------+ | 82601 | +----------+ 1 row in set (0.20 sec) Next, I took a look at the InnoDB status (not during the lock, unfortunately): mysql> SHOW INNODB STATUS; | InnoDB | | ===================================== 090922 15:03:50 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 35 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 574703, signal count 560578 Mutex spin waits 0, rounds 222148828, OS waits 40830 RW-shared spins 1023334, OS waits 398354; RW-excl spins 540552, OS waits 21948 ------------ TRANSACTIONS ------------ Trx id counter 0 2102243 Purge done for trx's n:o < 0 2102003 undo n:o < 0 0 History list length 3 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0 2100999, not started, OS thread id 34370254288 MySQL thread id 313, query id 660301 localhost root SHOW INNODB STATUS ---TRANSACTION 0 2102240, not started, OS thread id 34370247888 MySQL thread id 15, query id 659542 localhost 127.0.0.1 guser ---TRANSACTION 0 2102208, not started, OS thread id 34370247088 MySQL thread id 13, query id 659408 localhost 127.0.0.1 guser ---TRANSACTION 0 2102219, not started, OS thread id 34370246688 MySQL thread id 12, query id 659527 localhost 127.0.0.1 guser ---TRANSACTION 0 2102239, not started, OS thread id 34370245488 MySQL thread id 8, query id 659454 localhost 127.0.0.1 guser ---TRANSACTION 0 2102238, not started, OS thread id 34370245088 MySQL thread id 9, query id 659453 localhost 127.0.0.1 guser ---TRANSACTION 0 2102195, ACTIVE 48 sec, OS thread id 34370253488 starting index read, thread declared inside InnoDB 266 mysql tables in use 3, locked 0 31 lock struct(s), heap size 6752, 176 row lock(s), undo log entries 224 MySQL thread id 218, query id 660300 localhost 127.0.0.1 guser Sending data SELECT t0.ID, t0.BINDTIMESTAMP, t0.MACADDRESS_MACADDRESS, t0.internalIpAddress_ipAddress FROM INTERNALIPADDRESSBINDING t0, MACADDRESS t2, INTERNALIPADDRESS t1 WHERE ((((t1.IPADDRESS = '4.4.4.4') AND (t2.MACADDRESS = 'ZZ:ZZ:ZZ:ZZ:ZZ:ZZ')) AND (t0.BINDTIMESTAMP = '2009-09-22 15:01:53.0')) AND ((t1.IPADDRESS = t0.internalIpAddress_ipAddress) AND (t2.MACADDRESS = t0.MACADDRESS_MACADDRESS))) Trx read view will not see trx with id >= 0 2102196, sees < 0 2101972 ---TRANSACTION 0 2101972, ACTIVE 102 sec, OS thread id 34370246288 , thread declared inside InnoDB 294 mysql tables in use 3, locked 0 38 lock struct(s), heap size 6752, 144 row lock(s), holds adaptive hash latch, undo log entries 255 MySQL thread id 11, query id 660297 localhost 127.0.0.1 guser Sending data SELECT t0.ID, t0.BINDTIMESTAMP, t0.MACADDRESS_MACADDRESS, t0.internalIpAddress_ipAddress FROM INTERNALIPADDRESSBINDING t0, MACADDRESS t2, INTERNALIPADDRESS t1 WHERE ((((t1.IPADDRESS = '3.3.3.3') AND (t2.MACADDRESS = 'CC:CC:CC:CC:CC:CC')) AND (t0.BINDTIMESTAMP = '2009-09-22 14:57:33.0')) AND ((t1.IPADDRESS = t0.internalIpAddress_ipAddress) AND (t2.MACADDRESS = t0.MACADDRESS_MACADDRESS))) Trx read view will not see trx with id >= 0 2101973, sees < 0 2101973 -------- 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 (write thread) Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 206266 OS file reads, 88034 OS file writes, 16196 OS fsyncs 138.60 reads/s, 16961 avg bytes/read, 2.57 writes/s, 1.31 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 5, seg size 7, 74 inserts, 74 merged recs, 55 merges Hash table size 1106407, node heap has 5899 buffer(s) 207110.57 hash searches/s, 4830.43 non-hash searches/s --- LOG --- Log sequence number 0 3781613349 Log flushed up to 0 3781611114 Last checkpoint at 0 3781560806 0 pending log writes, 0 pending chkp writes 13373 log i/o's done, 1.23 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 608675752; in additional pool allocated 3250432 Dictionary memory allocated 92120 Buffer pool size 32768 Free buffers 1 Database pages 26868 Modified db pages 309 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 235947, created 870, written 86221 143.54 reads/s, 0.06 creates/s, 1.91 writes/s Buffer pool hit rate 1000 / 1000 -------------- ROW OPERATIONS -------------- 2 queries inside InnoDB, 0 queries in queue 3 read views open inside InnoDB Main thread id 34370244288, state: sleeping Number of rows inserted 102150, updated 506, deleted 0, read 9979592534 7.83 inserts/s, 0.06 updates/s, 0.00 deletes/s, 673708.69 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ I have to admit, I don't understand too much of what the above is stating. I'm currently doing some reading to get me up to speed in that regard, though. My table structures for the three problem tables are essentially similar to: id (primary key - auto_increment) foreignKey1 -> primaryTable1.id foreignKey2 -> primaryTable2.id timestamp My code is made up of two types of threads. The first thread (and note that there exists only one active thread of this type), does a delete based on timestamp once a hour for each of my 3 binding tables. The other type (and currently there are 5 threads), writes to one of these 3 tables exclusively. So, the deadlock must be happening when deletion starts, as indicated below. However, once it occurs, the deadlock seems to remain. Here are the jdbc exception I'm getting (note, everything appears to be good for a few days until all goes crazy): INFO | jvm 1 | 2009/09/19 19:20:32 | [TopLink Warning]: 2009.09.19 07:20:32.139--UnitOfWork(810972238)--Exception [TOPLINK-4002] (Oracle TopLink Essentials - 2.0.1 (Build b09d-fcs (12/06/2007))): oracle.toplink.essentials.exceptions.DatabaseException INFO | jvm 1 | 2009/09/19 19:20:32 | Internal Exception: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction INFO | jvm 1 | 2009/09/19 19:20:32 | Error Code: 1205 INFO | jvm 1 | 2009/09/19 19:20:32 | Call: DELETE FROM INTERNALIPADDRESSBINDING WHERE (BINDTIMESTAMP < ?) INFO | jvm 1 | 2009/09/19 19:20:32 | bind => [2009-03-23 19:18:29.207] INFO | jvm 1 | 2009/09/19 19:20:32 | Query: DeleteAllQuery() INFO | jvm 1 | 2009/09/19 19:21:02 | [TopLink Warning]: 2009.09.19 07:21:02.115--UnitOfWork(598977121)--Exception [TOPLINK-4002] (Oracle TopLink Essentials - 2.0.1 (Build b09d-fcs (12/06/2007))): oracle.toplink.essentials.exceptions.DatabaseException INFO | jvm 1 | 2009/09/19 19:21:02 | Internal Exception: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction INFO | jvm 1 | 2009/09/19 19:21:02 | Error Code: 1205 INFO | jvm 1 | 2009/09/19 19:21:02 | Call: INSERT INTO EXTERNALIPADDRESSBINDING (BINDTIMESTAMP, EXTERNALIPADDRESS_IPADDRESS, INTERNALIPADDRESS_IPADDRESS) VALUES (?, ?, ?, ?) INFO | jvm 1 | 2009/09/19 19:21:02 | bind => [2009-09-19 19:18:40.0, 1.1.1.1, 3.3.3.3] INFO | jvm 1 | 2009/09/19 19:21:02 | Query: InsertObjectQuery(edu.blah.entity.ExternalIPAddressBinding[id=null]) INFO | jvm 1 | 2009/09/19 19:21:02 | [TopLink Warning]: 2009.09.19 07:21:02.115--UnitOfWork(1752619158)--Exception [TOPLINK-4002] (Oracle TopLink Essentials - 2.0.1 (Build b09d-fcs (12/06/2007))): oracle.toplink.essentials.exceptions.DatabaseException INFO | jvm 1 | 2009/09/19 19:21:02 | Internal Exception: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction INFO | jvm 1 | 2009/09/19 19:21:02 | Error Code: 1205 INFO | jvm 1 | 2009/09/19 19:21:02 | Call: INSERT INTO EXTERNALIPADDRESSBINDING (BINDTIMESTAMP, EXTERNALIPADDRESS_IPADDRESS, INTERNALIPADDRESS_IPADDRESS) VALUES (?, ?, ?, ?) INFO | jvm 1 | 2009/09/19 19:21:02 | bind => [2009-09-19 19:18:40.0, 2.2.2.2, 4.4.4.4] INFO | jvm 1 | 2009/09/19 19:21:02 | Query: InsertObjectQuery(edu.blah.entity.ExternalIPAddressBinding[id=null])
