Everything in our production environment was working well. Yesterday, suddenly out of no where we were getting "lock wait" on any transaction related to a specific row. Same transaction on another row worked when the lock was removed, but editing that one row caused the entire table to lock up. Now, another problem is that the DB doesn't return all rows at times, ex. it returns 1 instead of 10. We are using java + hibernate. Like I said, there were no problems whatsoever, this is odd. I followed this https://mysql.wisborg.dk/2017/05/30/innodb-locks-analysis-why-is-blocking-query-null-and-how-to-find-more-information-about-the-blocking-transaction/
But still, the blocking transaction show trx_query as NULL. When running
select * from information_schema.innodb_trx;
Many transactions are null in the query column.
SHOW ENGINE INNODB STATUS;
---------------------------------------
=====================================
2019-08-02 21:24:39 2add8607e700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 57 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 3498 srv_active, 0 srv_shutdown, 61234 srv_idle
srv_master_thread log flush and writes: 64732
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 22165
OS WAIT ARRAY INFO: signal count 118693
Mutex spin waits 269941, rounds 833090, OS waits 9670
RW-shared spins 25736, rounds 372709, OS waits 6243
RW-excl spins 29187, rounds 404172, OS waits 5955
Spin rounds per wait: 3.09 mutex, 14.48 RW-shared, 13.85 RW-excl
------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-08-02 16:29:28 2adf53544700
*** (1) TRANSACTION:
TRANSACTION 22187462, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 6 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 2
MySQL thread id 26615, OS thread handle 0x2adecc1de700, query id 1141023 172.31.8.177 dbuser updating
/* update com.catchapp.server.persistence.user.User */ update user set cloudkit_id=null, created='2019-08-02 16:20:55', entity_status='active', unique_id='48df7cf7bffe474d85787bddf8425189', updated='2019-08-02 16:29:28', address_street_1=null, address_street_2=null, api_version='3.1', bio=null, city=null, country=null, distance_unit='mile', dob='1994-09-03', email='souzasire@gmail.com', email_sent=0, external_code='WHSPGI', facebook_id=null, facebook_token=null, first_name='Renata', gender='female', google_access_token=null, google_id=null, google_refresh_token=null, hometown=null, image_url='
', last_name='Souza', membership='basic', needs_password_change=0, new_user=1, num_completed_events=0, password='{SSHA}4wKS9ZG7hhhpbxQRtsi6zVyERS0/bRHMCXpuLA==', phone=null, phone_normalized=null, role_flag=1, smoker=null, state=null, time
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1380 page no 790 n bits 104 index
', last_name='Souza', membership='basic', needs_password_change=0, new_user=1, num_completed_events=0, password='{SSHA}4wKS9ZG7hhhpbxQRtsi6zVyERS0/bRHMCXpuLA==', phone=null, phone_normalized=null, role_flag=1, smoker=null, state=null, time
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1380 page no 790 n bits 104 index

PRIMARY
of table catchappprod
.user
trx id 22187462 lock_mode X locks rec but not gap waiting
Record lock, heap no 36 PHYSICAL RECORD: n_fields 46; compact format; info bits 0
0: len 30; hex 326339663838333136633531353832393031366335333232356133303032; asc 2c9f88316c515829016c53225a3002; (total 32 bytes);
1: len 6; hex 000001528dbd; asc R ;;
2: len 7; hex 420000015204cb; asc B R ;;
3: SQL NULL;
4: len 5; hex 99a3c50537; asc 7;;
5: len 6; hex 616374697665; asc active;;
6: len 30; hex 343864663763663762666665343734643835373837626464663834323531; asc 48df7cf7bffe474d85787bddf84251; (total 32 bytes);
7: len 5; hex 99a3c50537; asc 7;;
8: SQL NULL;
9: SQL NULL;
10: SQL NULL;
11: SQL NULL;
12: SQL NULL;
13: len 4; hex 6d696c65; asc mile;;
14: len 3; hex 8f9523; asc #;;
15: len 19; hex 736f757a617369726540676d61696c2e636f6d; asc souzasire@gmail.com;;
16: len 6; hex 574853504749; asc WHSPGI;;
17: SQL NULL;
18: SQL NULL;
19: len 6; hex 52656e617461; asc Renata;;
20: len 6; hex 66656d616c65; asc female;;
21: SQL NULL;
22: SQL NULL;
23: SQL NULL;
24: SQL NULL;
25: len 30; hex 687474703a2f2f63617463686170702d70726f642e73332e616d617a6f6e; asc http://catchapp-prod.s3.amazon ; (total 82 bytes);
26: len 5; hex 536f757a61; asc Souza;;
27: len 4; hex 80000000; asc ;;
28: len 4; hex 80000000; asc ;;
29: len 30; hex 7b535348417d34774b53395a47376868687062785152747369367a567945; asc {SSHA}4wKS9ZG7hhhpbxQRtsi6zVyE; (total 46 bytes);
30: SQL NULL;
31: SQL NULL;
32: len 4; hex 80000001; asc ;;
33: SQL NULL;
34: SQL NULL;
35: len 15; hex 416d65726963612f4368696361676f; asc America/Chicago;;
36: len 9; hex 536f757a6173697265; asc Souzasire;;
37: len 5; hex 3437353833; asc 47583;;
38: len 4; hex 80000001; asc ;;
39: SQL NULL;
40: SQL NULL;
41: len 1; hex 31; asc 1;;
42: len 4; hex 80000000; asc ;;
43: len 1; hex 81; asc ;;
44: len 5; hex 6261736963; asc basic;;
45: len 6; hex 5055424c4943; asc PUBLIC;;
*** (2) TRANSACTION:
TRANSACTION 22187459, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
6 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 2
MySQL thread id 26616, OS thread handle 0x2adf53544700, query id 1141027 172.31.8.177 dbuser updating
/* update com.catchapp.server.persistence.user.User */ update user set cloudkit_id=null, created='2019-08-02 16:20:55', entity_status='active', unique_id='48df7cf7bffe474d85787bddf8425189', updated='2019-08-02 16:29:28', address_street_1=null, address_street_2=null, api_version='3.1', bio=null, city=null, country=null, distance_unit='mile', dob='1994-09-03', email='souzasire@gmail.com', email_sent=0, external_code='WHSPGI', facebook_id=null, facebook_token=null, first_name='Renata', gender='female', google_access_token=null, google_id=null, google_refresh_token=null, hometown=null, image_url='
PRIMARY
of table catchappprod
.user
trx id 22187459 lock mode S locks rec but not gap
Record lock, heap no 36 PHYSICAL RECORD: n_fields 46; compact format; info bits 0
0: len 30; hex 326339663838333136633531353832393031366335333232356133303032; asc 2c9f88316c515829016c53225a3002; (total 32 bytes);
1: len 6; hex 000001528dbd; asc R ;;
2: len 7; hex 420000015204cb; asc B R ;;
3: SQL NULL;
4: len 5; hex 99a3c50537; asc 7;;
5: len 6; hex 616374697665; asc active;;
6: len 30; hex 343864663763663762666665343734643835373837626464663834323531; asc 48df7cf7bffe474d85787bddf84251; (total 32 bytes);
7: len 5; hex 99a3c50537; asc 7;;
8: SQL NULL;
9: SQL NULL;
10: SQL NULL;
11: SQL NULL;
12: SQL NULL;
13: len 4; hex 6d696c65; asc mile;;
14: len 3; hex 8f9523; asc #;;
15: len 19; hex 736f757a617369726540676d61696c2e636f6d; asc souzasire@gmail.com;;
16: len 6; hex 574853504749; asc WHSPGI;;
17: SQL NULL;
18: SQL NULL;
19: len 6; hex 52656e617461; asc Renata;;
20: len 6; hex 66656d616c65; asc female;;
21: SQL NULL;
22: SQL NULL;
23: SQL NULL;
24: SQL NULL;
25: len 30; hex 687474703a2f2f63617463686170702d70726f642e73332e616d617a6f6e; asc http://catchapp-prod.s3.amazon ; (total 82 bytes);
26: len 5; hex 536f757a61; asc Souza;;
27: len 4; hex 80000000; asc ;;
28: len 4; hex 80000000; asc ;;
29: len 30; hex 7b535348417d34774b53395a47376868687062785152747369367a567945; asc {SSHA}4wKS9ZG7hhhpbxQRtsi6zVyE; (total 46 bytes);
30: SQL NULL;
31: SQL NULL;
32: len 4; hex 80000001; asc ;;
33: SQL NULL;
34: SQL NULL;
35: len 15; hex 416d65726963612f4368696361676f; asc America/Chicago;;
36: len 9; hex 536f757a6173697265; asc Souzasire;;
37: len 5; hex 3437353833; asc 47583;;
38: len 4; hex 80000001; asc ;;
39: SQL NULL;
40: SQL NULL;
41: len 1; hex 31; asc 1;;
42: len 4; hex 80000000; asc ;;
43: len 1; hex 81; asc ;;
44: len 5; hex 6261736963; asc basic;;
45: len 6; hex 5055424c4943; asc PUBLIC;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1380 page no 790 n bits 104 index PRIMARY
of table catchappprod
.user
trx id 22187459 lock_mode X locks rec but not gap waiting
Record lock, heap no 36 PHYSICAL RECORD: n_fields 46; compact format; info bits 0
0: len 30; hex 326339663838333136633531353832393031366335333232356133303032; asc 2c9f88316c515829016c53225a3002; (total 32 bytes);
1: len 6; hex 000001528dbd; asc R ;;
2: len 7; hex 420000015204cb; asc B R ;;
3: SQL NULL;
4: len 5; hex 99a3c50537; asc 7;;
5: len 6; hex 616374697665; asc active;;
6: len 30; hex 343864663763663762666665343734643835373837626464663834323531; asc 48df7cf7bffe474d85787bddf84251; (total 32 bytes);
7: len 5; hex 99a3c50537; asc 7;;
8: SQL NULL;
9: SQL NULL;
10: SQL NULL;
11: SQL NULL;
12: SQL NULL;
13: len 4; hex 6d696c65; asc mile;;
14: len 3; hex 8f9523; asc #;;
15: len 19; hex 736f757a617369726540676d61696c2e636f6d; asc souzasire@gmail.com;;
16: len 6; hex 574853504749; asc WHSPGI;;
17: SQL NULL;
18: SQL NULL;
19: len 6; hex 52656e617461; asc Renata;;
20: len 6; hex 66656d616c65; asc female;;
21: SQL NULL;
22: SQL NULL;
23: SQL NULL;
24: SQL NULL;
25: len 30; hex 687474703a2f2f63617463686170702d70726f642e73332e616d617a6f6e; asc http://catchapp-prod.s3.amazon ; (total 82 bytes);
26: len 5; hex 536f757a61; asc Souza;;
27: len 4; hex 80000000; asc ;;
28: len 4; hex 80000000; asc ;;
29: len 30; hex 7b535348417d34774b53395a47376868687062785152747369367a567945; asc {SSHA}4wKS9ZG7hhhpbxQRtsi6zVyE; (total 46 bytes);
30: SQL NULL;
31: SQL NULL;
32: len 4; hex 80000001; asc ;;
33: SQL NULL;
34: SQL NULL;
35: len 15; hex 416d65726963612f4368696361676f; asc America/Chicago;;
36: len 9; hex 536f757a6173697265; asc Souzasire;;
37: len 5; hex 3437353833; asc 47583;;
38: len 4; hex 80000001; asc ;;
39: SQL NULL;
40: SQL NULL;
41: len 1; hex 31; asc 1;;
42: len 4; hex 80000000; asc ;;
43: len 1; hex 81; asc ;;
44: len 5; hex 6261736963; asc basic;;
45: len 6; hex 5055424c4943; asc PUBLIC;;
*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 22211040
Purge done for trx's n:o = 22211040, sees = 22211039, sees = 22211038, sees = 22210954, sees = 22210909, sees = 22210502, sees = 22210002, sees = 22209497, sees = 22209481, sees = 22209430, sees = 22209378, sees = 22208805, sees = 22208534, sees = 22208451, sees = 22208366, sees = 22208236, sees = 22208141, sees = 22207536, sees = 22206743, sees = 22206623, sees = 22205264, sees = 22205261, sees = 22204497, sees = 22204482, sees = 22203903, sees < 22198567
--------
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: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
I/O thread 10 state: waiting for i/o request (write thread)
I/O thread 11 state: waiting for i/o request (write thread)
I/O thread 12 state: waiting for i/o request (write thread)
I/O thread 13 state: waiting for i/o request (write thread)
I/O thread 14 state: waiting for i/o request (write thread)
I/O thread 15 state: waiting for i/o request (write thread)
I/O thread 16 state: waiting for i/o request (write thread)
I/O thread 17 state: waiting for i/o request (write thread)
I/O thread 18 state: waiting for i/o request (write thread)
I/O thread 19 state: waiting for i/o request (write thread)
I/O thread 20 state: waiting for i/o request (write thread)
I/O thread 21 state: waiting for i/o request (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
29552 OS file reads, 175874 OS file writes, 98491 OS fsyncs
0.02 reads/s, 16384 avg bytes/read, 2.47 writes/s, 1.67 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 48746, seg size 48748, 20592 merges
merged operations:
insert 841, delete mark 3317352, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 12119119, node heap has 442 buffer(s)
909.30 hash searches/s, 351.57 non-hash searches/s
---
LOG
---
Log sequence number 4441306931
Log flushed up to 4441306098
Pages flushed up to 4441306098
Last checkpoint at 4441306098
0 pending log writes, 0 pending chkp writes
18712 log i/o's done, 0.28 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 6267207680; in additional pool allocated 0
Dictionary memory allocated 822706
Buffer pool size 373760
Free buffers 252854
Database pages 120464
Old database pages 44620
Modified db pages 4
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 4184, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 54318, created 66146, written 348418
0.02 reads/s, 0.00 creates/s, 1.84 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: 120464, unzip_LRU len: 0
I/O sum:cur, unzip sum:cur
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 46720
Free buffers 31671
Database pages 14992
Old database pages 5552
Modified db pages 2
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 568, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 6678, created 8314, written 49253
0.00 reads/s, 0.00 creates/s, 0.47 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: 14992, unzip_LRU len: 0
I/O sum:cur, unzip sum:cur
---BUFFER POOL 1
Buffer pool size 46720
Free buffers 31761
Database pages 14901
Old database pages 5519
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 486, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 6755, created 8146, written 42935
0.00 reads/s, 0.00 creates/s, 0.18 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
...
----------------------------
END OF INNODB MONITOR OUTPUT
============================
I added more ram to the instance to no avail. I'm using a custom parameter group, and set IO threads to 16. default was 4. This did not help.
public ChatMessage addMessage(
Chat chat,
User user,
String message,
MessageType type) throws CatchappRdbException {
ChatMessage chatMessage = new ChatMessage();
chatMessage.setChat(chat);
chatMessage.setMessage(message);
chatMessage.setUser(user);
chatMessage.setType(type);
chat.getMessages().add(chatMessage);
chat.setLast_message(new Date());
Session session = getSession();
try {
// session.saveOrUpdate(chat);
session.saveOrUpdate(chatMessage);
} catch (HibernateException he) {
throw new CatchappRdbException(he);
} finally {
flushSession(session);
}
return chatMessage;
}
this works for anything other row. If running this for the one particular row, the seems like a few tables get locked. I found the transaction causing the block but the trx_query is null.
I wonder if it's a max open files issue or within hibernate trying to access some file that is taking forever but I couldn't find anything.
I'm wondering if paid AWS support can help with this.
Asked by franklinexpress
(111 rep)
Aug 3, 2019, 12:01 AM
Last activity: Aug 7, 2025, 12:05 PM
Last activity: Aug 7, 2025, 12:05 PM