ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

Posted 2020-10-01 运维的自我修养

 问题描述：

研发突然找我，遇到了mysql的 ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction，具体报错如下：

org.apache.hadoop.mapred.YarnChild.main(YarnChild.java:158) Caused by: java.io 

.IOException: java.sql.SQLException: Lock wait timeout exceeded;
  try restarting transaction at org.apache.sqoop.mapreduce.AsyncSqlRecordWriter.write(AsyncSqlRecordWriter.java:220) 
at org.apache.sqoop.mapreduce.AsyncSqlRecordWriter.write(AsyncSqlRecordWriter.java:46) at 
org.apache.hadoop.mapred.MapTask$NewDirectOutputCollector.write(MapTask.java:655) at 

　产生这个问题的原因是因为在mysql中产生了事务A，执行了修改的语句，比如： update t1 set aget=18 where id=1;此时事务并未进行提交，事务B开始运行，也同样需要修改id为1的用户的年龄： update t1 set aget=20 where id=1; 那么此时事务B会等待事务A结束释放写锁才能执行成功，否则则会等待一段时间，产生报错：

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

 

下面开始模拟锁表的场景：

一、打开一个终端，连接上mysql，关闭事务自动提交，执行一个update语句

 

查看连接的id：

 

二、打开另外一个终端，用mysql连接上去，更新一步骤中的update的那条数据，

然后等待一会，会报ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

 

三、再打开一个终端连接上去，查看锁的状态

   在mysql5.5之后，information_schema数据库加了三个关于锁的表

     innodb_trx ## 当前运行的所有事务

     innodb_locks ## 当前出现的锁

     innodb_lock_waits ## 锁等待的对应关系

 

这个表对于排查因为事务未提交引起的锁问题可以说是举足轻重。当我们有事务长时间未提交导致锁住数据库，其他程序拿不到锁的时候，因为对这张表进行排查。

通过这个表我们可以查出连接的线程ID，可根据时间判断怀疑一下

SELECT * FROM information_schema.INNODB_TRX\\G

比如我们获取一条记录的线程id， 即可拿着该线程id去information_schma.processlist中获取他的具体情况

我们可以通过如下的方法找出连接的服务器，进而判断进程：

 

此处host可以出现端口，然后再用lsof –p $port 来查看是哪个程序，基本上就可以确认了，是哪个程序搞的鬼，接下来看下记录锁信息的表 innodb_locks

如果 我们要排查的问题正锁死我们的某张表，那么该表的数据表就会有所体现。同时和这个表使用的 还有information_schema.innodb_lock_waits

 

此时如果我们要想恢复，可以手动杀掉id9的连接，如果是死锁的情况下。

 

在第一个终端查看：

 

注意：如果我们如果有权限，可以使用能看到相对来说更为复杂和详细的信息

 四、其他排查手段

#通过innodb status 提供的详细的系统情况来分析问题。

SHOW ENGINE INNODB STATUS\\G 

如果我没没有使用show engine innodb status的权限，退而求其次我们可以使用另外一种思路来找到是哪个表持续被锁，导致拿不到锁的问题。

show open tables where in_use>0;

查看现在系统正在使用的表，然后使用： 

show full processlist;

查找正在query该表的任务，查看代码是否有一直没有提交事物，却没有commit的代码，用这个思路来找问题出现在哪儿。

mysql> show engine innodb status\\G 
*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
2017-08-08 22:39:01 0x7fde3ce46700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 37 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 13 srv_active, 0 srv_shutdown, 1407 srv_idle
srv_master_thread log flush and writes: 1420
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 44
OS WAIT ARRAY INFO: signal count 44
RW-shared spins 0, rounds 56, OS waits 28
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 56.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 1305
Purge done for trx\'s n:o < 1303 undo n:o < 0 state: running but idle
History list length 6
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 422074379878000, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 422074379876176, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 1303, ACTIVE 238 sec
2 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 9, OS thread handle 140592481601280, query id 101 localhost root
Trx read view will not see trx with id >= 1303, sees < 1303
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:, log i/o\'s:, sync i/o\'s:
Pending flushes (fsync) log: 0; buffer pool: 0
274 OS file reads, 245 OS file writes, 165 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 1593743, node heap has 0 buffer(s)
Hash table size 1593743, node heap has 0 buffer(s)
Hash table size 1593743, node heap has 0 buffer(s)
Hash table size 1593743, node heap has 0 buffer(s)
Hash table size 1593743, node heap has 0 buffer(s)
Hash table size 1593743, node heap has 0 buffer(s)
Hash table size 1593743, node heap has 0 buffer(s)
Hash table size 1593743, node heap has 0 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 2549841
Log flushed up to   2549841
Pages flushed up to 2549841
Last checkpoint at  2549832
0 pending log flushes, 0 pending chkp writes
78 log i/o\'s done, 0.00 log i/o\'s/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 6596591616
Dictionary memory allocated 342962
Buffer pool size   393192
Free buffers       392904
Database pages     288
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 242, created 46, written 111
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 288, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size   49146
Free buffers       49106
Database pages     40
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 40, created 0, written 27
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 40, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size   49152
Free buffers       49144
Database pages     8
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 8, created 0, written 0
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 8, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size   49146
Free buffers       49137
Database pages     9
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 9, created 0, written 0
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 9, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size   49152
Free buffers       49076
Database pages     76
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 76, created 0, written 6
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 76, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size   49146
Free buffers       49055
Database pages     91
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 85, created 6, written 17
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 91, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size   49152
Free buffers       49140
Database pages     12
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 11, created 1, written 3
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 12, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size   49146
Free buffers       49106
Database pages     40
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 5, created 35, written 43
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 40, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size   49152
Free buffers       49140
Database pages     12
Old database pages 0
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 8, created 4, written 15
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 12, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Process ID=17616, Main thread ID=140591056803584, state: sleeping
Number of rows inserted 6, updated 5, deleted 0, read 48
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

　　

参考文档：http://www.cnblogs.com/piperck/p/6212524.html