问题描述:
研发突然找我,遇到了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结束释放写锁才能执行成功,否则则会等待一段时间,产生报错:
下面开始模拟锁表的场景:
一、打开一个终端,连接上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