Server locking up on a connection that is in 'Sleep' mode

MySQL & MariaDB
,
1

Hi all,

I just had an issue with with one of our Percona servers (5.7.33) where we had a connection that was in ‘Sleep’ mode but still had 10 lock structures.

Here’s what I know, the server in question is a replica of another server in a different physical location. And looking at the SHOW ENGINE INNODB STATUS output (see below) I found there was a connection “thread id 683542” that had 10 locks. SHOW PROCESSLIST indicated that the connection 683542 was in ‘Sleep’ mode with no queries.

Trying the least intrusive thing first I attempted “KILL QUERY 683542;”, but of course nothing happened. I followed that with “KILL CONNECTION 683542;” and the locks released.

Now I have the mystery of why a connection would hold locks without a query being run??

The last line in the Transaction section of the INNODB STATUS output showed this “Trx read view will not see trx with id >= 3340244945, sees < 3340244943” (again see below for more). I’m guessing that line is trying to tell me what’s wrong, but I’m lost as to what it means.

Can anyone fill me in?

SHOW ENGINE INNODB STATUS\G:
LOCK WAIT 5 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 683644, OS thread handle 140594649036544, query id 17701083614 System lock
INSERT INTO foo.who (table1_key, table2_key) VALUES (1150691, 1591)
------- TRX HAS BEEN WAITING 5 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 876085 page no 60 n bits 328 index PRIMARY of table goo.table1 trx id 3340357280 lock mode S locks rec but not gap waiting

—TRANSACTION 3340244944, ACTIVE 2159 sec
10 lock struct(s), heap size 1136, 4 row lock(s), undo log entries 3
MySQL thread id 683542, OS thread handle 140594882787072, query id 17697251551 111.777.888.999 Username
Trx read view will not see trx with id >= 3340244945, sees < 3340244943

SHOW PROCESSLIST:
| 683542 | Username | 111.777.888.999:54167 | NULL | Sleep | 2780 | | NULL | 0 | 1 |

2

Hi @jorr , welcome back to the Percona Forums.

The issue you faced is related on how transactions work, even though the transaction was doing nothing at the moment, it may have acquired some locks previously. To make it clearer I did a quick lab test.

In one connection, I started a transaction and inserted a record on some table (Notice the START TRANSACTION at the beggining)

...
Your MySQL connection id is 459
...

connection1> START TRANSACTION;
Query OK, 0 rows affected (0.00 sec)

connection1> SELECT * FROM test.tbl1;
Empty set (0.02 sec)

connection1> INSERT INTO test.tbl1 VALUES (1,'test');
Query OK, 1 row affected (0.03 sec)

connection1> SELECT * FROM test.tbl1;
+----+------+
| id | some |
+----+------+
|  1 | test |
+----+------+
1 row in set (0.03 sec)

I left that transaction open, and in another terminal I tried to update the table:

...
Your MySQL connection id is 516
...
connection2> UPDATE test.tbl1 SET some='other';

And the update didn’t finish. It stuck there; checking the processlist I had the following:

SHOW PROCESSLIST;
+-----+---------+----------------------+------+---------+------+----------+-----------------------------------+---------+-----------+---------------+
| Id  | User    | Host                 | db   | Command | Time | State    | Info                              | Time_ms | Rows_sent | Rows_examined |
+-----+---------+----------------------+------+---------+------+----------+-----------------------------------+---------+-----------+---------------+
| 459 | percona | 192.168.51.100:55602 | NULL | Sleep   |   88 |          | NULL                              |   88375 |         1 |             1 |
| 516 | percona | 192.168.51.100:55844 | NULL | Query   |   32 | updating | UPDATE test.tbl1 SET some='other' |   32029 |         0 |             0 |
| 526 | percona | 192.168.51.100:55884 | NULL | Query   |    0 | starting | SHOW PROCESSLIST                  |       0 |         0 |             0 |
+-----+---------+----------------------+------+---------+------+----------+-----------------------------------+---------+-----------+---------------+
6 rows in set (0.01 sec)

The first connection is 459 (The one with open transaction), you can see it’s in Sleep mode, since by that time I didn’t have anything running in the transaction, but the transaction itself was still open.

And from SHOW ENGINE INNODB STATUS\G

---TRANSACTION 8481, ACTIVE 48 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 516, OS thread handle 140711720212224, query id 8750 192.168.51.100 percona updating
UPDATE test.tbl1 SET some='other'
------- TRX HAS BEEN WAITING 48 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 124 page no 3 n bits 72 index PRIMARY of table `test`.`tbl1` trx id 8481 lock_mode X waiting
------------------
---TRANSACTION 8479, ACTIVE 117 sec
2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
MySQL thread id 459, OS thread handle 140711853520640, query id 8468 192.168.51.100 percona
Trx read view will not see trx with id >= 8480, sees < 8480

Eventually, my UPDATE failed:

connection2> UPDATE test.tbl1 SET some='other';
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

Once I commit my transaction, the update works:

connection1> COMMIT;
Query OK, 0 rows affected (0.17 sec)

connection2> UPDATE test.tbl1 SET some='other';
Query OK, 1 row affected (0.16 sec)
Rows matched: 1  Changed: 1  Warnings: 0

Bottom line; this happens whenever you’re using transactions, but left them open. I would suggest checking how you’re using the transactions and making sure you’re commiting (or rolling back) as soon as possible, to avoid this kind of issues.

This is a quick example on what happened, if you want to take a deeper look into the transactions, you can check the Documentation about this.

I hope this helps bring some clarification.

Best,
Mauricio.

3

Thank you for the explanation.