It was suggested I post here as opposed to StackOverflow. I'm new to debugging mysql/innodb issues so here is the best I have:
I'm trying to run an integration test so these results are near identical each time, the test is consistently hanging at the same spot while trying to execute the same update. I'm getting a conflicting process that has locked the table the update is trying to use. If I just let it run I get a lock timeout exceeded exception, and when i kill the troubling process things do start moving again, though an exception is thrown in my test - "Caused by: org.mariadb.jdbc.internal.util.dao.QueryException: Could not send query: Last stream not finished".
Relevant information I can find from,
SHOW ENGINE INNODB STATUS;
------------
TRANSACTIONS
------------
---TRANSACTION 2609485, ACTIVE 36 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 9 lock struct(s), heap size 1136, 4 row lock(s), undo log entries 2
MySQL thread id 231, OS thread handle 162200, query id 10577 localhost 127.0.0.1 root updating
/* update com.ipl.inspire.imp.radio.entities.entity.circuit.Circuit */
update abstract_asset_network
set lastUpdated='2016-01-14 15:34:10.2', leg=0, networkStatus_id=4,
parent_id=NULL, xCoordinate=0, yCoordinate=0 where id=33
Trx read view will not see trx with id >= 2609485, sees < 2609468
------- TRX HAS BEEN WAITING 35 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 89945 page no 3 n bits 72 index PRIMARY
of table `imptest`.`abstract_asset_network` trx id 2609485
lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 4; hex 80000021; asc !;;
1: len 6; hex 00000027d0f8; asc ' ;;
2: len 7; hex 6e0000019b2827; asc n (';;
3: len 7; hex 99985cf88a07d0; asc \ ;;
4: len 1; hex 00; asc ;;
5: len 4; hex 80000000; asc ;;
6: len 4; hex 80000000; asc ;;
7: len 4; hex 80000003; asc ;;
8: SQL NULL;
------------------
---TRANSACTION 2609468, ACTIVE 38 sec
10 lock struct(s), heap size 1136, 4 row lock(s), undo log entries 3
MySQL thread id 228, OS thread handle 162260, query id 10138 localhost 127.0.0.1 root cleaning up
Trx read view will not see trx with id >= 2609468, sees < 2609468
Two transactions here, and it seems that trx 2609468 has caused a lock on the query update is trying to execute (trx 2609485) 2 seconds afterwards. The lock seems to last forever (or until innodb_lock_wait_timeout gets hit, which I have tried increasing).
SELECT * FROM INFORMATION_SCHEMA.INNODB_TRX
trx_id trx_state trx_started trx_requested_lock_id trx_wait_started trx_weight trx_mysql_thread_id trx_query trx_operation_state trx_tables_in_use trx_tables_locked trx_lock_structs trx_locks_memory_bytes trx_rows_locked trx_rows_modified trx_concurrency_tickets trx_isolation_level
2609485 LOCK WAIT 2016-01-14 15:34:17 2609485:89945:3:3 2016-01-14 15:34:18 11 231 update abstract_asset_network set lastUpdated='2016-01-14 15:34:10.2', leg=0, networkStatus_id=4, parent_id=NULL, xCoordinate=0, yCoordinate=0 where id=33 starting index read 1 5 9 1136 4 2 0 REPEATABLE READ
2609468 RUNNING 2016-01-14 15:34:15 13 228 0 6 10 1136 4 3 0 REPEATABLE READ
Which suggests pretty much what is explained from the innodb status query I believe, though maybe someone else can make more sense of it.
The last query that was executed on process id 228 was (from the general_log)
228 Query /* select generatedAlias0 from Imp as generatedAlias0 */
select imp0_.id as id1_67_, imp0_.black as black2_67_, imp0_.current as current3_67_,
imp0_.name as name4_67_, imp0_.redMessageHost as redMessa5_67_,
imp0_.redMessagePort as redMessa6_67_, imp0_.site_id as site_id7_67_
from imp imp0_
and then later:
231 Query update abstract_asset_network
set lastUpdated='2016-01-14 15:34:10.2', leg=0, networkStatus_id=4,
parent_id=NULL, xCoordinate=0, yCoordinate=0 where id=33
.
.
.
8 Query kill 228
231 Query COMMIT
231 Query set autocommit=1
231 Query SELECT 1
231 Query set autocommit=0
231 Query /* select ...
But I don't think it's relevant and it's more to do with the process being re-used for "cleaning up" something else. However this same scenario with the same processes/timing/lock/queries happens the same every single time with the only things changing being just the ids.
