amazon web services - Long running mysql "cleaning up" transaction -

i have been trying debug 'lock wait timeout exceeded' error in mysql (aws rds) v5.6.19a, sporadically thrown when attempt select row, using primary id, update, i.e:

select primary_id tbl_widgets primary_id = 5 update 

after many hours debugging have ruled out part of application 'directly' locking same row (which obvious culprit). such have started dig deeper rabbit hole mysql locking , noticed following correlation between 'lock wait timeout exceeded' error being thrown , information provided by:

show engine innodb status; 

there appears long running transaction in cleaning up state locking increasing number of rows upto ~10 minutes, here relevant lines transaction 10 manual innodb status queries:

2015-08-19 13:29:04 ---transaction 25861246681, active 158 sec 10 lock struct(s), heap size 1184, 21 row lock(s), undo log entries 20 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7146839061 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:29:42 ---transaction 25861246681, active 196 sec 13 lock struct(s), heap size 2936, 28 row lock(s), undo log entries 27 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7147149416 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:30:10 ---transaction 25861246681, active 224 sec 13 lock struct(s), heap size 2936, 31 row lock(s), undo log entries 30 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7147321023 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:30:41 ---transaction 25861246681, active 255 sec 13 lock struct(s), heap size 2936, 35 row lock(s), undo log entries 34 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7147511090 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:31:12 ---transaction 25861246681, active 286 sec 15 lock struct(s), heap size 2936, 38 row lock(s), undo log entries 37 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7147604774 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:31:30 ---transaction 25861246681, active 304 sec 21 lock struct(s), heap size 2936, 42 row lock(s), undo log entries 39 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7147789789 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:31:57 ---transaction 25861246681, active 331 sec 21 lock struct(s), heap size 2936, 46 row lock(s), undo log entries 43 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7147837536 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:32:28 ---transaction 25861246681, active 362 sec 22 lock struct(s), heap size 2936, 51 row lock(s), undo log entries 48 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7147905807 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:33:16 ---transaction 25861246681, active 410 sec 23 lock struct(s), heap size 2936, 58 row lock(s), undo log entries 55 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7148317478 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682  2015-08-19 13:33:49 ---transaction 25861246681, active 443 sec 24 lock struct(s), heap size 2936, 64 row lock(s), undo log entries 61 mysql thread id 5110120, os thread handle 0x2ba082506700, query id 7148471519 10.0.1.154 mfuser cleaning trx read view not see trx id >= 25861246682, sees < 25861246682 

i came across following blog post (http://databaseblog.myname.nl/2014/10/when-your-query-is-blocked-but-there-is_26.html) provides potential solution helps determine going on in long running transaction, in particular set:

set global innodb_status_output_locks=on; 

unfortunately not possible perform operation on rds due restricted permissions.

i kindly request debugging on how might work out going on in cleaning up transaction, , possibly how avoid together.

edit add: average cpu usage of mysql instance 20%

in case "cleaning up" locks went away after killed jvm running debugger in. apparently remnant of earlier debug run interrupted before transaction cleaned up.

that doesn't you, here couple suggestions debugging in situation.

1. you have 1 piece of information, number of locks. using breakpoints can pause application in various places try , pinpoint when count goes up. (or maybe goes after errors seen in log; or after user actions.)

2. if can't use breakpoints, have 1 other tool, select update statement blocks after lock has occurred. might able sprinkle around code, possibly additional logging, pinpoint blocking starts.

3. consider temporarily debugging application against locally installed mysql database. either installed on local server, or on development machine. might hassle set up, can have many other benefits (e.g. test bed db scripts; ability work on laptop while offline.)

all assumes lock being caused own code, , not other job. (in log cleaning-up user "mfuser".) makes possible reproduce problem on demand.