SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 1246555 --Thread 140363572082432 has waited at row0upd.cc line 2354 for 253.00 seconds the semaphore: X-lock (wait_ex) on RW-latch at 0x7fa949340740 created in file buf0buf.cc line 1069 a writer (thread id 140363572082432) has reserved it in mode wait exclusive number of readers 1, waiters flag 1, lock_word: ffffffffffffffff Last time read locked in file btr0sea.cc line 931 Last time write locked in file /export/home/pb2/build/sb_0-17068951-1447697721.44/mysql-5.6.28/storage/innobase/row/row0upd.cc line 2354
173 lock struct(s), heap size 30248, 7925 row lock(s), undo log entries 7924 MySQL thread id 5709783, OS thread handle 0x7fa8f0da7700, query id 92213034 10.23.163.54 citicqyh updating update TB_DEPARTMENT_INFO set TOTAL_USER=1 where ID='ac84f17e-82d3-4519-a1da-0d5a5a835d44' ---TRANSACTION 53065242, ACTIVE 313 sec fetching rows, thread declared inside InnoDB 2081 mysql tables in use 2, locked 0 MySQL thread id 5428690, OS thread handle 0x7fa8f0136700, query id 92213061 10.23.163.55 citicqyh Sending data SELECT COUNT(DISTINCT r.user_id) FROM TB_DEPARTMENT_INFO d left join tb_qy_user_department_ref r on r.department_id = d.id WHERE d.org_id = 'xxx' AND (d.dept_full_name LIKE 'xxx%' or d.dept_full_name = 'xxx Trx read view will not see trx with id >= xxx, sees < xxx
END OF INNODB MONITOR OUTPUT ============================
InnoDB: ###### Diagnostic info printed to the standard error stream InnoDB: Error: semaphore wait has lasted > 600 seconds InnoDB: We intentionally crash the server, because it appears to be hung. 7fa8f9580700 InnoDB: Assertion failure in thread 140363714529024 in file srv0srv.cc line 1754 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html InnoDB: about forcing recovery.
大家知道,数据库要访问的数据都必须先存在缓存中,而缓存一般比磁盘空间要小,数据缓存使用hash表来记录数据页是否在内存中。在Oracle中的并发控制比较精细:首先会对hash桶加latch,并根据hash桶查找对应的数据并加上pin,然后释放Latch。而MySQL相对没有控制得这么精细,对应的RW-Latch在errlog中说的很清楚,该RW-Latch是在buf0buf.cc的1069行创建的 RW-latch at 0x7fa949340740 created in file buf0buf.cc line 1069
mysql> show variables like 'i%instances'; +------------------------------+-------+ | Variable_name | Value | +------------------------------+-------+ | innodb_buffer_pool_instances | 1 | +------------------------------+-------+ 1 row in set (0.00 sec)
如何监控latch争用情况
mysql> show engine innodb statusG …… SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 23 OS WAIT ARRAY INFO: signal count 14 RW-shared spins 0, rounds 73, OS waits 5 RW-excl spins 0, rounds 1114, OS waits 5 RW-sx spins 0, rounds 0, OS waits 0 Spin rounds per wait: 73.00 RW-shared, 1114.00 RW-excl, 0.00 RW-sx
rounds:表示spin一次空转多少圈,也就是返回来询问的次数
OS waits:表示sleep,当突然增长比较快时,说明latch争用比较严重
1、如果OS waits值比较高,说明出现latch争用,异常SQL
2、获取latch的代价:73.00 RW-shared, 1114.00 RW-excl
查看锁类型show engine innodb mutex; +--------+-----------------------------+----------+ | Type | Name | Status | +--------+-----------------------------+----------+ | InnoDB | rwlock: dict0dict.cc:2687 | waits=1 | | InnoDB | rwlock: dict0dict.cc:1184 | waits=13 | | InnoDB | rwlock: log0log.cc:844 | waits=35 | | InnoDB | sum rwlock: buf0buf.cc:1457 | waits=4 | +--------+-----------------------------+----------+ 4 rows in set (0.16 sec)