0、performance_schema的介绍
MySQL的performance schema 由来已久,用于监控MySQL server在一个较低级别的运行过程中的资源消耗、资源等待等情况。但由于内存消耗,性能影响等原因,导致其始终无法进入主流的MySQL默认配置,对MySQL的问题诊断以及处理造成很多不利的影响。
一般而言,Performance Schema会对性能造成影响,比如row mutex的位置。实际上,MySQL经常出现问题的地方,很多时候是在Server层,在这一层,很多Performance Schema的设置并不会导致性能的下降(或者明显下降),以下分享希望能对大家有一定帮助。
Performance Schema特点如下:
1、提供了一种在数据库运行时实时检查server的内部执行情况的方法。performance_schema 数据库中的表使用performance_schema存储引擎。该数据库主要关注数据库运行过程中的性能相关的数据,与information_schema不同,information_schema主要关注server运行过程中的元数据信息
2、performance_schema通过监视server的事件来实现监视server内部运行情况, “事件”就是server内部活动中所做的任何事情以及对应的时间消耗,利用这些信息来判断server中的相关资源消耗在了哪里?一般来说,事件可以是函数调用、操作系统的等待、SQL语句执行的阶段(如sql语句执行过程中的parsing 或 sorting阶段)或者整个SQL语句与SQL语句集合。事件的采集可以方便的提供server中的相关存储引擎对磁盘文件、表I/O、表锁等资源的同步调用信息。 3、performance_schema中的事件与写入二进制日志中的事件(描述数据修改的events)、事件计划调度程序(这是一种存储程序)的事件不同。performance_schema中的事件记录的是server执行某些活动对某些资源的消耗、耗时、这些活动执行的次数等情况。 4、performance_schema中的事件只记录在本地server的performance_schema中,其下的这些表中数据发生变化时不会被写入binlog中,也不会通过复制机制被复制到其他server中。 5、 当前活跃事件、历史事件和事件摘要相关的表中记录的信息。能提供某个事件的执行次数、使用时长。进而可用于分析某个特定线程、特定对象(如mutex或file)相关联的活动。 6、PERFORMANCE_SCHEMA存储引擎使用server源代码中的“检测点”来实现事件数据的收集。对于performance_schema实现机制本身的代码没有相关的单独线程来检测,这与其他功能(如复制或事件计划程序)不同 7、收集的事件数据存储在performance_schema数据库的表中。这些表可以使用SELECT语句查询,也可以使用SQL语句更新performance_schema数据库中的表记录(如动态修改performance_schema的setup_*开头的几个配置表,但要注意:配置表的更改会立即生效,这会影响数据收集) 8、performance_schema的表中的数据不会持久化存储在磁盘中,而是保存在内存中,一旦服务器重启,这些数据会丢失(包括配置表在内的整个performance_schema下的所有数据) 9、MySQL支持的所有平台中事件监控功能都可用,但不同平台中用于统计事件时间开销的计时器类型可能会有所差异。
1、performance schema入门
在mysql的5.7版本中,性能模式是默认开启的,如果想要显式的关闭的话需要修改配置文件,不能直接进行修改,会报错Variable 'performance_schema' is a read only variable。
--查看performance_schema的属性
mysql> SHOW VARIABLES LIKE 'performance_schema';
+--------------------+-------+
| Variable_name | Value |
+--------------------+-------+
| performance_schema | ON |
+--------------------+-------+
1 row in set (0.01 sec)
on表示开启,off表示关闭,可以在配置文件中修改performance_schema的属性值,按照如下修改配置。
[mysqld]
performance_schema=ON
--切换数据库
use performance_schema;
--查看当前数据库下的所有表,会看到有很多表存储着相关的信息,如下图所示。
show tables;
--可以通过show create table tablename来查看创建表的时候的表结构
mysql> show create table setup_consumers;
为了方便理解后续内容的学习,需要首先理解下面两个基本概念:
instruments: 生产者,用于采集mysql中各种各样的操作产生的事件信息,对应配置表中的配置项我们可以称为监控采集配置项。
consumers:消费者,对应的消费者表用于存储来自instruments采集的数据,对应配置表中的配置项我们可以称为消费存储配置项。
2、performance_schema表的分类
performance_schema库下的表可以按照监视不同的纬度进行分组。
序号 | 类别 | 查询sql | 表名 |
1 | 记录语句事件信息(当前语句事件表events_statements_current 历史语句事件表events_statements_history 长语句历史事件表events_statements_history_long 聚合后的摘要表summary,其中,summary表还可以根据帐号(account),主机(host),程序(program),线程(thread),用户(user)和全局(global)再进行细分) | show tables like '%statement%'; | |
2 | 等待事件记录表,与语句事件类型的相关记录表类似 | show tables like '%wait%'; | |
3 | 阶段事件记录表,记录语句执行的阶段事件的表 | show tables like '%stage%'; | |
4 | 事务事件记录表,记录事务相关的事件的表 | show tables like '%transaction%'; | |
5 | 监控文件系统层调用的表 | show tables like '%file%'; | |
6 | 监视内存使用的表 | show tables like '%memory%'; | |
7 | 动态对performance_schema进行配置的配置表 | show tables like '%setup%'; |
3、performance_schema的简单配置与使用
数据库刚刚初始化并启动时,前面提到的instruments和consumers并不是全部都启用了的(而是每一一个配置表的每一项都有一个开关字段,或为YES,或为NO,为YES就表示对应的表保存性能数据,为NO就表示对应的表不保存性能数据))。因此默认不会收集所有的事件,可能你需要检测的事件并没有打开,需要进行设置。
具体打开方式可以使用如下两个语句打开对应的instruments和consumers(行计数可能会因MySQL版本而异)。
(1)打开等待事件的采集器配置项开关,需要修改setup_instruments配置表中对应的采集器配置项
UPDATE setup_instruments SET ENABLED = 'YES', TIMED = 'YES'where name like 'wait%';
(2)打开等待事件的保存表配置开关,修改setup_consumers配置表中对应的配置项
UPDATE setup_consumers SET ENABLED = 'YES'where name like '%wait%';
--当配置完成之后可以查看当前server正在做什么,可以通过查询events_waits_current表来得知,该表中每个线程只包含一行数据,用于显示每个线程的最新监视事件。
ysql> select * from events_waits_current\G;
/*该信息表示线程id为14的线程正在等待buf_dblwr_mutex锁,等待事件为307377
属性说明:
id:事件来自哪个线程,事件编号是多少。
event_name:表示检测到的具体的内容。
source:表示这个检测代码在哪个源文件中以及行号。
timer_start:表示该事件的开始时间。
timer_end:表示该事件的结束时间。
timer_wait:表示该事件总的花费时间。
注意:_current表中每个线程只保留一条记录,一旦线程完成工作,该表中不会再记录该线程的事件信息
_history表中记录每个线程应该执行完成的事件信息,但每个线程的事件信息只会记录10条,再多就会被覆盖,*_history_long表中记录所有线程的事件信息,但总记录数量是10000,超过就会被覆盖掉
*/
select thread_id,event_id,event_name,timer_wait from events_waits_history order by thread_id limit 21;
/*
summary表提供所有事件的汇总信息,该组中的表以不同的方式汇总事件数据(如:按用户,按主机,按线程等等)。例如:要查看哪些instruments占用最多的时间,可以通过对events_waits_summary_global_by_event_name表的COUNT_STAR或SUM_TIMER_WAIT列进行查询(这两列是对事件的记录数执行COUNT(*)、事件记录的TIMER_WAIT列执行SUM(TIMER_WAIT)统计而来)
*/
SELECT EVENT_NAME,COUNT_STAR FROM events_waits_summary_global_by_event_name ORDER BY COUNT_STAR DESC LIMIT 10;
/*
instance表记录了哪些类型的对象会被检测。这些对象在被server使用时,在该表中将会产生一条事件记录,例如,file_instances表列出了文件I/O操作及其关联文件名
*/
select * from file_instances limit 20;
4、常用配置项的参数说明(此处还要多结合实践慢慢领会,单看这个感觉作用不大。)
1、启动选项
performance_schema_consumer_events_statements_current=TRUE
是否在mysql server启动时就开启events_statements_current表的记录功能(该表记录当前的语句事件信息),启动之后也可以在setup_consumers表中使用UPDATE语句进行动态更新setup_consumers配置表中的events_statements_current配置项,默认值为TRUE
performance_schema_consumer_events_statements_history=TRUE
与performance_schema_consumer_events_statements_current选项类似,但该选项是用于配置是否记录语句事件短历史信息,默认为TRUE
performance_schema_consumer_events_stages_history_long=FALSE
与performance_schema_consumer_events_statements_current选项类似,但该选项是用于配置是否记录语句事件长历史信息,默认为FALSE
除了statement(语句)事件之外,还支持:wait(等待)事件、state(阶段)事件、transaction(事务)事件,他们与statement事件一样都有三个启动项分别进行配置,但这些等待事件默认未启用,如果需要在MySQL Server启动时一同启动,则通常需要写进my.cnf配置文件中
performance_schema_consumer_global_instrumentation=TRUE
是否在MySQL Server启动时就开启全局表(如:mutex_instances、rwlock_instances、cond_instances、file_instances、users、hostsaccounts、socket_summary_by_event_name、file_summary_by_instance等大部分的全局对象计数统计和事件汇总统计信息表 )的记录功能,启动之后也可以在setup_consumers表中使用UPDATE语句进行动态更新全局配置项
默认值为TRUE
performance_schema_consumer_statements_digest=TRUE
是否在MySQL Server启动时就开启events_statements_summary_by_digest 表的记录功能,启动之后也可以在setup_consumers表中使用UPDATE语句进行动态更新digest配置项
默认值为TRUE
performance_schema_consumer_thread_instrumentation=TRUE
是否在MySQL Server启动时就开启
events_xxx_summary_by_yyy_by_event_name表的记录功能,启动之后也可以在setup_consumers表中使用UPDATE语句进行动态更新线程配置项
默认值为TRUE
performance_schema_instrument[=name]
是否在MySQL Server启动时就启用某些采集器,由于instruments配置项多达数千个,所以该配置项支持key-value模式,还支持%号进行通配等,如下:
# [=name]可以指定为具体的Instruments名称(但是这样如果有多个需要指定的时候,就需要使用该选项多次),也可以使用通配符,可以指定instruments相同的前缀+通配符,也可以使用%代表所有的instruments
## 指定开启单个instruments
--performance-schema-instrument= 'instrument_name=value'
## 使用通配符指定开启多个instruments
--performance-schema-instrument= 'wait/synch/cond/%=COUNTED'
## 开关所有的instruments
--performance-schema-instrument= '%=ON'
--performance-schema-instrument= '%=OFF'
注意,这些启动选项要生效的前提是,需要设置performance_schema=ON。另外,这些启动选项虽然无法使用show variables语句查看,但我们可以通过setup_instruments和setup_consumers表查询这些选项指定的值。
2、系统变量
show variables like '%performance_schema%';
--重要的属性解释
performance_schema=ON
/*
控制performance_schema功能的开关,要使用MySQL的performance_schema,需要在mysqld启动时启用,以启用事件收集功能
该参数在5.7.x之前支持performance_schema的版本中默认关闭,5.7.x版本开始默认开启
注意:如果mysqld在初始化performance_schema时发现无法分配任何相关的内部缓冲区,则performance_schema将自动禁用,并将performance_schema设置为OFF
*/
performance_schema_digests_size=10000
/*
控制events_statements_summary_by_digest表中的最大行数。如果产生的语句摘要信息超过此最大值,便无法继续存入该表,此时performance_schema会增加状态变量
*/
performance_schema_events_statements_history_long_size=10000
/*
控制events_statements_history_long表中的最大行数,该参数控制所有会话在events_statements_history_long表中能够存放的总事件记录数,超过这个限制之后,最早的记录将被覆盖
全局变量,只读变量,整型值,5.6.3版本引入 * 5.6.x版本中,5.6.5及其之前的版本默认为10000,5.6.6及其之后的版本默认值为-1,通常情况下,自动计算的值都是10000 * 5.7.x版本中,默认值为-1,通常情况下,自动计算的值都是10000
*/
performance_schema_events_statements_history_size=10
/*
控制events_statements_history表中单个线程(会话)的最大行数,该参数控制单个会话在events_statements_history表中能够存放的事件记录数,超过这个限制之后,单个会话最早的记录将被覆盖
全局变量,只读变量,整型值,5.6.3版本引入 * 5.6.x版本中,5.6.5及其之前的版本默认为10,5.6.6及其之后的版本默认值为-1,通常情况下,自动计算的值都是10 * 5.7.x版本中,默认值为-1,通常情况下,自动计算的值都是10
除了statement(语句)事件之外,wait(等待)事件、state(阶段)事件、transaction(事务)事件,他们与statement事件一样都有三个参数分别进行存储限制配置,有兴趣的同学自行研究,这里不再赘述
*/
performance_schema_max_digest_length=1024
/*
用于控制标准化形式的SQL语句文本在存入performance_schema时的限制长度,该变量与max_digest_length变量相关(max_digest_length变量含义请自行查阅相关资料)
全局变量,只读变量,默认值1024字节,整型值,取值范围0~1048576
*/
performance_schema_max_sql_text_length=1024
/*
控制存入events_statements_current,events_statements_history和events_statements_history_long语句事件表中的SQL_TEXT列的最大SQL长度字节数。 超出系统变量performance_schema_max_sql_text_length的部分将被丢弃,不会记录,一般情况下不需要调整该参数,除非被截断的部分与其他SQL比起来有很大差异
全局变量,只读变量,整型值,默认值为1024字节,取值范围为0~1048576,5.7.6版本引入
降低系统变量performance_schema_max_sql_text_length值可以减少内存使用,但如果汇总的SQL中,被截断部分有较大差异,会导致没有办法再对这些有较大差异的SQL进行区分。 增加该系统变量值会增加内存使用,但对于汇总SQL来讲可以更精准地区分不同的部分。
*/
5、重要配置表的相关说明
配置表之间存在相互关联关系,按照配置影响的先后顺序,可添加为
/*
performance_timers表中记录了server中有哪些可用的事件计时器
字段解释:
timer_name:表示可用计时器名称,CYCLE是基于CPU周期计数器的定时器
timer_frequency:表示每秒钟对应的计时器单位的数量,CYCLE计时器的换算值与CPU的频率相关、
timer_resolution:计时器精度值,表示在每个计时器被调用时额外增加的值
timer_overhead:表示在使用定时器获取事件时开销的最小周期值
*/
select * from performance_timers;
/*
setup_timers表中记录当前使用的事件计时器信息
字段解释:
name:计时器类型,对应某个事件类别
timer_name:计时器类型名称
*/
select * from setup_timers;
/*
setup_consumers表中列出了consumers可配置列表项
字段解释:
NAME:consumers配置名称
ENABLED:consumers是否启用,有效值为YES或NO,此列可以使用UPDATE语句修改。
*/
select * from setup_consumers;
/*
setup_instruments 表列出了instruments 列表配置项,即代表了哪些事件支持被收集:
字段解释:
NAME:instruments名称,instruments名称可能具有多个部分并形成层次结构
ENABLED:instrumetns是否启用,有效值为YES或NO,此列可以使用UPDATE语句修改。如果设置为NO,则这个instruments不会被执行,不会产生任何的事件信息
TIMED:instruments是否收集时间信息,有效值为YES或NO,此列可以使用UPDATE语句修改,如果设置为NO,则这个instruments不会收集时间信息
*/
SELECT * FROM setup_instruments;
/*
setup_actors表的初始内容是匹配任何用户和主机,因此对于所有前台线程,默认情况下启用监视和历史事件收集功能
字段解释:
HOST:与grant语句类似的主机名,一个具体的字符串名字,或使用“%”表示“任何主机”
USER:一个具体的字符串名称,或使用“%”表示“任何用户”
ROLE:当前未使用,MySQL 8.0中才启用角色功能
ENABLED:是否启用与HOST,USER,ROLE匹配的前台线程的监控功能,有效值为:YES或NO
HISTORY:是否启用与HOST, USER,ROLE匹配的前台线程的历史事件记录功能,有效值为:YES或NO
*/
SELECT * FROM setup_actors;
/*
setup_objects表控制performance_schema是否监视特定对象。默认情况下,此表的最大行数为100行。
字段解释:
OBJECT_TYPE:instruments类型,有效值为:“EVENT”(事件调度器事件)、“FUNCTION”(存储函数)、“PROCEDURE”(存储过程)、“TABLE”(基表)、“TRIGGER”(触发器),TABLE对象类型的配置会影响表I/O事件(wait/io/table/sql/handler instrument)和表锁事件(wait/lock/table/sql/handler instrument)的收集
OBJECT_SCHEMA:某个监视类型对象涵盖的数据库名称,一个字符串名称,或“%”(表示“任何数据库”)
OBJECT_NAME:某个监视类型对象涵盖的表名,一个字符串名称,或“%”(表示“任何数据库内的对象”)
ENABLED:是否开启对某个类型对象的监视功能,有效值为:YES或NO。此列可以修改
TIMED:是否开启对某个类型对象的时间收集功能,有效值为:YES或NO,此列可以修改
*/
SELECT * FROM setup_objects;
/*
threads表对于每个server线程生成一行包含线程相关的信息,
字段解释:
THREAD_ID:线程的唯一标识符(ID)
NAME:与server中的线程检测代码相关联的名称(注意,这里不是instruments名称)
TYPE:线程类型,有效值为:FOREGROUND、BACKGROUND。分别表示前台线程和后台线程
PROCESSLIST_ID:对应INFORMATION_SCHEMA.PROCESSLIST表中的ID列。
PROCESSLIST_USER:与前台线程相关联的用户名,对于后台线程为NULL。
PROCESSLIST_HOST:与前台线程关联的客户端的主机名,对于后台线程为NULL。
PROCESSLIST_DB:线程的默认数据库,如果没有,则为NULL。
PROCESSLIST_COMMAND:对于前台线程,该值代表着当前客户端正在执行的command类型,如果是sleep则表示当前会话处于空闲状态
PROCESSLIST_TIME:当前线程已处于当前线程状态的持续时间(秒)
PROCESSLIST_STATE:表示线程正在做什么事情。
PROCESSLIST_INFO:线程正在执行的语句,如果没有执行任何语句,则为NULL。
PARENT_THREAD_ID:如果这个线程是一个子线程(由另一个线程生成),那么该字段显示其父线程ID
ROLE:暂未使用
INSTRUMENTED:线程执行的事件是否被检测。有效值:YES、NO
HISTORY:是否记录线程的历史事件。有效值:YES、NO *
THREAD_OS_ID:由操作系统层定义的线程或任务标识符(ID):
*/
select * from threads
注意:在performance_schema库中还包含了很多其他的库和表,能对数据库的性能做完整的监控,大家需要参考官网详细了解。
6、performance_schema实践操作
基本了解了表的相关信息之后,可以通过这些表进行实际的查询操作来进行实际的分析。
- 哪类的SQL执行最多?
SELECT DIGEST_TEXT,COUNT_STAR,FIRST_SEEN,LAST_SEEN FROM events_statements_summary_by_digest ORDER BY COUNT_STAR DESC
- 哪类SQL的平均响应时间最多?
SELECT DIGEST_TEXT,AVG_TIMER_WAIT FROM events_statements_summary_by_digest ORDER BY COUNT_STAR DESC
- 哪类SQL排序记录数最多?
SELECT DIGEST_TEXT,SUM_SORT_ROWS FROM events_statements_summary_by_digest ORDER BY COUNT_STAR DESC
- 哪类SQL扫描记录数最多?
SELECT DIGEST_TEXT,SUM_ROWS_EXAMINED FROM events_statements_summary_by_digest ORDER BY COUNT_STAR DESC
- 哪类SQL使用临时表最多?
SELECT DIGEST_TEXT,SUM_CREATED_TMP_TABLES,SUM_CREATED_TMP_DISK_TABLES FROM events_statements_summary_by_digest ORDER BY COUNT_STAR DESC
- 哪类SQL返回结果集最多?
SELECT DIGEST_TEXT,SUM_ROWS_SENT FROM events_statements_summary_by_digest ORDER BY COUNT_STAR DESC
- 哪个表物理IO最多?
SELECT file_name,event_name,SUM_NUMBER_OF_BYTES_READ,SUM_NUMBER_OF_BYTES_WRITE FROM file_summary_by_instance ORDER BY SUM_NUMBER_OF_BYTES_READ + SUM_NUMBER_OF_BYTES_WRITE DESC
- 哪个表逻辑IO最多?
SELECT object_name,COUNT_READ,COUNT_WRITE,COUNT_FETCH,SUM_TIMER_WAIT FROM table_io_waits_summary_by_table ORDER BY sum_timer_wait DESC
- 哪个索引访问最多?
SELECT OBJECT_NAME,INDEX_NAME,COUNT_FETCH,COUNT_INSERT,COUNT_UPDATE,COUNT_DELETE FROM table_io_waits_summary_by_index_usage ORDER BY SUM_TIMER_WAIT DESC
- 哪个索引从来没有用过?
SELECT OBJECT_SCHEMA,OBJECT_NAME,INDEX_NAME FROM table_io_waits_summary_by_index_usage WHERE INDEX_NAME IS NOT NULL AND COUNT_STAR = 0 AND OBJECT_SCHEMA <> 'mysql' ORDER BY OBJECT_SCHEMA,OBJECT_NAME;
- 哪个等待事件消耗时间最多?
SELECT EVENT_NAME,COUNT_STAR,SUM_TIMER_WAIT,AVG_TIMER_WAIT FROM events_waits_summary_global_by_event_name WHERE event_name != 'idle' ORDER BY SUM_TIMER_WAIT DESC
- 剖析某条SQL的执行情况,包括statement信息,stege信息,wait信息
SELECT EVENT_ID,sql_text FROM events_statements_history WHERE sql_text LIKE '%count(*)%';
- 查看每个阶段的时间消耗
SELECT event_id,EVENT_NAME,SOURCE,TIMER_END - TIMER_START FROM events_stages_history_long WHERE NESTING_EVENT_ID = 1553;
- 查看每个阶段的锁等待情况
SELECT event_id,event_name,source,timer_wait,object_name,index_name,operation,nesting_event_id FROM events_waits_history_longWHERE nesting_event_id = 1553
7、典型应用
7.1利用等待事件排查MySQL性能问题
前面讲的都是一些理论知识,下面分享一下网上(https://zhuanlan.zhihu.com/p/42860952)一条关于性能调优的实践,感觉比较落地。
通常,在生产服务器上线之前, 我们会对数据库服务器的硬件进行IO基准测试,对数据库进行增删改查的基准测试,建立基线参考数据,以便日后的服务器扩容或架构升级提供数据支撑。在基准测试规划时,我们通常需要选择一款基准测试软件(IO基准测试通常选择fio和iozone,MySQL数据库基准测试通常选择sysbench、tpcc-mysql、workbench等),在使用这些基准测试软件对服务器压测到一个极限值时,我们认为所得数据就是被测试服务器的最高性能。但这还不够,测试性能无法继续提升的原因还可能是因为你的服务器在BIOS设置、硬件搭配、操作系统参数、文件系统策略、数据库配置参数等方面不够优化。所以我们还需要借助一些性能排查手段来找出性能瓶颈所在,以使得我们对数据库服务器一旦上线之后可能的瓶颈点心中有数。以下我们以sysbench基准测试工具压测MySQL数据库为例,介绍如何使用performance_schema的等待事件来排查数据库性能瓶颈所在。
首先,使用performance_schema配置表启用等待事件的采集与记录
# 启用所有的等待事件的instruments
admin@localhost : performance_schema 11:47:46> use performance_schema
Database changed
# 修改setup_instruments 表的enabled和timed字段为yes,表示启用对应的instruments
admin@localhost : performance_schema 11:48:05> update setup_instruments set enabled='yes',timed='yes' where name like 'wait/%';
Query OK, 269 rows affected (0.00 sec)
Rows matched: 323 Changed: 269 Warnings: 0
# 查看修改结果,enabled和timed字段为YES即表示当前instruments已经启用(但此时采集器并不会立即采集事件数据,需要保存这些等待事件的表--consumers,启用之后才会开始采集)
admin@localhost : performance_schema 11:49:40> select * from setup_instruments where name like 'wait/%';
+--------------------------------------------------------------------+---------+-------+
| NAME | ENABLED | TIMED |
+--------------------------------------------------------------------+---------+-------+
| wait/synch/mutex/sql/TC_LOG_MMAP::LOCK_tc | YES | YES |
| wait/synch/mutex/sql/LOCK_des_key_file | YES | YES |
............
| wait/io/socket/sql/server_tcpip_socket | YES | YES |
| wait/io/socket/sql/server_unix_socket | YES | YES |
| wait/io/socket/sql/client_connection | YES | YES |
| wait/lock/metadata/sql/mdl | YES | YES |
+--------------------------------------------------------------------+---------+-------+
323 rows in set (0.01 sec)
# 启用等待事件的consumers
admin@localhost : performance_schema 11:48:21> update setup_consumers set enabled='yes' where name like '%wait%';
Query OK, 3 rows affected (0.00 sec)
Rows matched: 3 Changed: 3 Warnings: 0
admin@localhost : performance_schema 11:49:20> select * from setup_consumers where name like '%wait%';
+---------------------------+---------+
| NAME | ENABLED |
+---------------------------+---------+
| events_waits_current | YES |
| events_waits_history | YES |
| events_waits_history_long | YES |
+---------------------------+---------+
3 rows in set (0.00 sec)
然后,使用sysbench对数据库执行加压,并逐渐增加并发线程数,直到tps、qps不再随着线程数的增加而增加为止。
sysbench --test=oltp --db-driver=mysql --mysql-table-engine=innodb --mysql-host=10.10.10.10 --mysql-port=3306 --mysql-db=sbtest --mysql-user='qbench' --mysql-password='qbench' --test=/usr/share/doc/sysbench/tests/db/oltp.lua --oltp-table-size=5000000 --oltp-tables-count=8 --num-threads=16 --max-time=1800 --max-requests=0 --report-interval=1 run
............
[ 111s] threads: 16, tps: 52.99, reads/s: 668.93, writes/s: 171.98, response time: 629.52ms (95%)
[ 112s] threads: 16, tps: 42.00, reads/s: 650.93, writes/s: 202.98, response time: 688.46ms (95%)
............
从sysbench的输出结果中,我们可以看到在16个并发线程oltp压力下,tps只能跑到100不到,且延迟在600ms+,说明存在严重的性能瓶颈(或者在MySQL内部发生了严重的互斥等待,或者硬件设备严重的性能不足),现在,我们先使用操作系统命令查看硬件负载情况。
# top命令查看到CPU资源绝大部分都消耗,说明IO设备性能出现严重不足
[root@localhost ~]# top
top - 18:59:03 up 7:02, 3 users, load average: 4.28, 5.82, 4.22
Tasks: 186 total, 1 running, 185 sleeping, 0 stopped, 0 zombie
Cpu0 : 4.1%us, 8.5%sy, 0.0%ni, 11.9%id, 75.4%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 4.0%us, 13.1%sy, 0.0%ni, 17.5%id, 65.0%wa, 0.0%hi, 0.3%si, 0.0%st
Cpu2 : 9.4%us, 32.1%sy, 0.0%ni, 2.3%id, 55.5%wa, 0.0%hi, 0.7%si, 0.0%st
Cpu3 : 3.0%us, 5.3%sy, 0.0%ni, 31.0%id, 60.0%wa, 0.0%hi, 0.7%si, 0.0%st
Mem: 8053664k total, 1684236k used, 6369428k free, 87868k buffers
Swap: 2031612k total, 0k used, 2031612k free, 150680k cached
# iostat命令查看磁盘负载,通过%util列可以看到,磁盘处于100%满负载状态
avg-cpu: %user %nice %system %iowait %steal %idle
1.77 0.00 2.28 95.70 0.00 0.25
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util
dm-2 0.00 0.00 277.00 160.00 8864.00 2774.00 26.63 47.84 112.98 2.29 100.10
avg-cpu: %user %nice %system %iowait %steal %idle
5.05 0.00 11.62 64.14 0.00 19.19
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util
dm-2 0.00 0.00 267.00 244.00 8544.00 4643.00 25.81 28.20 40.29 1.96 100.00
通过查询系统负载,一眼就可以看出来是由于磁盘性能严重不足导致的,但是,在数据库内部的事件信息是如何体现的呢(注意:如果你没有足够的performance_schema使用经验,此时是绝好的学习积累的机会,不要错过,也许哪一天操作系统负载并不能看出来端倪的时候,这些事件信息能帮上大忙)
# 为了方便查询等待事件统计,我们可以先创建一个视图,用于实时统计当前等待事件(非历史数据)
admin@localhost : performance_schema 12:14:14> create view sys.test_waits as select sum(TIMER_WAIT) as TIMER_WAIT,sum(NUMBER_OF_BYTES) as NUMBER_OF_BYTES, EVENT_NAME,OPERATION from events_waits_current where EVENT_NAME!='idle' group by EVENT_NAME,OPERATION;
Query OK, 0 rows affected (0.04 sec)
# 使用前面创建的视图进行查询,对这个视图查询结果进行降序排序查询。从下面的查询结果中,我们可以看到时间开销排名前5的有4个都是与IO相关的等待,剩下1个是binlog相关的互斥等待
admin@localhost : performance_schema 12:30:38> select sys.format_time(TIMER_WAIT),sys.format_bytes(NUMBER_OF_BYTES),EVENT_NAME,OPERATION from sys.test_waits where sys.format_time(TIMER_WAIT) not regexp 'ns|us' order by TIMER_WAIT desc;
+-----------------------------+-----------------------------------+------------------------------------------------+------------+
| sys.format_time(TIMER_WAIT) | sys.format_bytes(NUMBER_OF_BYTES) | EVENT_NAME | OPERATION |
+-----------------------------+-----------------------------------+------------------------------------------------+------------+
| 16.60 s | 224.00 KiB | wait/io/file/innodb/innodb_data_file | read |
| 16.05 s | 553 bytes | wait/io/table/sql/handler | fetch |
| 1.96 s | NULL | wait/io/file/sql/binlog | sync |
| 1.96 s | NULL | wait/synch/cond/sql/MYSQL_BIN_LOG::update_cond | timed_wait |
| 1.85 s | 1.34 KiB | wait/io/file/sql/binlog | write |
| 56.66 ms | NULL | wait/io/file/innodb/innodb_log_file | sync |
+-----------------------------+-----------------------------------+------------------------------------------------+------------+
6 rows in set (0.01 sec)
# 当然,你也可以直接查询events_waits_current表(返回数据行数可能比较多,且查询结果并没有做分组聚合,是逐行的事件记录数据)
admin@localhost : performance_schema 11:59:25> select THREAD_ID,EVENT_NAME,sys.format_time(TIMER_WAIT),INDEX_NAME,NESTING_EVENT_TYPE,OPERATION,NUMBER_OF_BYTES from events_waits_current where EVENT_NAME!='idle' order by TIMER_WAIT desc;
+-----------+------------------------------------------------+-----------------------------+------------+--------------------+------------+-----------------+
| THREAD_ID | EVENT_NAME | sys.format_time(TIMER_WAIT) | INDEX_NAME | NESTING_EVENT_TYPE | OPERATION | NUMBER_OF_BYTES |
+-----------+------------------------------------------------+-----------------------------+------------+--------------------+------------+-----------------+
| 115 | wait/io/table/sql/handler | 169.48 ms | PRIMARY | STATEMENT | fetch | 39 |
| 115 | wait/io/file/innodb/innodb_data_file | 169.48 ms | NULL | WAIT | read | 16384 |
| 101 | wait/io/table/sql/handler | 93.76 ms | PRIMARY | STATEMENT | fetch | 39 |
| 101 | wait/io/file/innodb/innodb_data_file | 93.76 ms | NULL | WAIT | read | 16384 |
| 111 | wait/io/file/innodb/innodb_data_file | 73.08 ms | NULL | STATEMENT | read | 16384 |
| 103 | wait/io/file/innodb/innodb_data_file | 63.13 ms | NULL | STATEMENT | read | 16384 |
| 106 | wait/io/file/innodb/innodb_data_file | 53.24 ms | NULL | STATEMENT | read | 16384 |
| 113 | wait/io/table/sql/handler | 51.90 ms | PRIMARY | STATEMENT | fetch | 39 |
| 113 | wait/io/file/innodb/innodb_data_file | 51.90 ms | NULL | WAIT | read | 16384 |
| 49 | wait/synch/cond/sql/MYSQL_BIN_LOG::update_cond | 27.48 ms | NULL | STATEMENT | timed_wait | NULL |
............
57 rows in set (0.00 sec)
从上述等待事件的查询结果中,我们可以非常清晰地看到,事务大多数的延迟时间花在了等待IO上(主要是undo log、redo log,独立表空间文件,binlog的fetch和read系统调用),说明IO设备可能出现了严重的性能瓶颈,这里与操作系统命令查看到的磁盘性能严重不足相对应。
结论:通过以上测试数据表明,MySQL的性能严重低下的原因是因为磁盘性能严重不足成为了瓶颈(一般情况下,4个core的cpu在内存和磁盘不构成瓶颈的情况下可以达到800+ tps才可能会构成瓶颈)
针对IO性能不足,建议优化策略:
更换IO性能更好的设备
新增2个独立的相同设备,把MySQL 中的redo log、binlog、其他data file分别放在3个独立的IO设备上,以便数据库中的随机IO和顺序IO不会因为相互争抢资源而导致IO等待
PS:
当然,你也许会说,我们在这个案例里故意使用一台配置很差的服务器。是的没错。但我们可以去思考一个问题:performance_schema到底能够对我们使用MySQL提供多大帮助呢?对于目前来讲,互联网上并不能找到太多靠谱的performance_schema使用经验,需要我们不断地去挖掘。我们建议有条件的同行可以准备两台测试服务器(一台低配置,一台高配置服务器),通过对比测试数据你就能得出performance_schema的使用经验了,正所谓没有对比就没有伤害
7.2锁问题排查
7.2.1 找出谁持有全局读锁
全局读锁通常是由flush table with read lock;这类语句添加,这类语句通常是在各种备份工具为了拿到一致性备份时使用,另外,在具有主从复制架构的环境中做主备切换时也常常使用,除了这两种情况之外,还有一种情况也是最难排查的一种情况,那就是线上系统权限约束不规范的时候,各种人员使用的数据库帐号都具有RELOAD权限时,都可以对数据库加全局读锁。
在MySQL 5.7之前的版本,要排查谁持有全局读锁通常在数据库层面是很难直接查询到有用数据(innodb_locks表也只能记录innodb层的锁信息,而全局读锁是server层的锁,所以也无法查询到),从MySQL 5.7开始提供表performance_schema.metadata_locks表记录一些Server层的锁信息(包括全局读锁和MDL锁等),下面我们通过一个示例来演示然后使用performance_schema来找出谁持有全局读锁。
首先,开启第一个会话,执行全局读锁。
# 执行加锁语句
root@localhost : sbtest 12:28:30> flush table with read lock;
Query OK, 0 rows affected (0.00 sec)
# 查询以下加锁线程的process id,以便后续排查过程好对应
root@localhost : sbtest 12:31:48> select connection_id();
+-----------------+
| connection_id() |
+-----------------+
| 4 |
+-----------------+
1 row in set (0.00 sec)
现在,我们开启第二个会话执行任意可能对数据造成修改的语句,我们就以update操作为例吧。
root@localhost : sbtest 12:42:36> use sbtest
Database changed
root@localhost : sbtest 12:42:38> select * from sbtest1 limit 1\G;
*************************** 1. row ***************************
id: 21
k: 2483476
c: 09279210219-37745839908-56185699327-79477158641-86711242956-61449540392-42622804506-61031512845-36718422840-11028803849
pad: 96813293060-05308009118-09223341195-19224109585-45598161848
1 row in set (0.00 sec)
ERROR:
No query specified
root@localhost : sbtest 12:42:39> select connection_id();
+-----------------+
| connection_id() |
+-----------------+
| 5 |
+-----------------+
1 row in set (0.00 sec)
root@localhost : sbtest 12:42:44> update sbtest1 set pad='xxx' where id=21;
操作被阻塞,现在,我们开启第三个会话,开始使用一些手段进行排查。
root@localhost : (none) 12:42:25> select connection_id();
+-----------------+
| connection_id() |
+-----------------+
| 16 |
+-----------------+
1 row in set (0.00 sec)
# 查询processlist信息,这里只能看到processid为5的线程State为Waiting for global read lock,表示正在等待全局读锁
root@localhost : (none) 12:43:11> show processlist;
+----+-------+---------------------+--------+-------------+-------+---------------------------------------------------------------+------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+-------+---------------------+--------+-------------+-------+---------------------------------------------------------------+------------------------------------------+
| 3 | qfsys | 192.168.2.168:41042 | NULL | Binlog Dump | 11457 | Master has sent all binlog to slave; waiting for more updates | NULL |
| 4 | root | localhost | sbtest | Sleep | 234 | | NULL |
| 5 | root | localhost | sbtest | Query | 26 | Waiting for global read lock | update sbtest1 set pad='xxx' where id=21 |
| 16 | root | localhost | NULL | Query | 0 | starting | show processlist |
+----+-------+---------------------+--------+-------------+-------+---------------------------------------------------------------+------------------------------------------+
4 rows in set (0.00 sec)
# 继续查询information_schema.innodb_locks、innodb_lock_waits、innodb_trx表,发现三个表均为空。
root@localhost : (none) 12:59:30> select * from information_schema.innodb_locks;
Empty set, 1 warning (0.00 sec)
root@localhost : (none) 12:59:40> select * from information_schema.innodb_lock_waits;
Empty set, 1 warning (0.00 sec)
root@localhost : (none) 12:59:43> select * from information_schema.innodb_trx\G
Empty set (0.00 sec)
# 再使用show engine innodb status;查看一把(这里只需要看TRANSACTION段落即可),仍然无任何有用的锁信息。
root@localhost : (none) 12:59:48> show engine innodb status;
......
=====================================
2018-06-25 13:01:43 0x7fe55ded8700 INNODB MONITOR OUTPUT
=====================================
......
------------
TRANSACTIONS
------------
Trx id counter 2527502
Purge done for trx's n:o < 2527500 undo n:o < 0 state: running but idle
History list length 3
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 422099353083504, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 422099353082592, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 422099353081680, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
......
通过上面的常规手段查询下来,无任何有用信息,这个时候,有gdb调试经验的老鸟估计就要开始使用gdb,strace,pstack什么的命令查看MySQL 调用栈、线程信息什么的了,但这对于没有C语言基础的人来说,基本上是看天书,好在从MySQL 5.7版本开始,提供performance_schema.metadata_locks表,该表记录了各种Server层的锁信息(包括全局读锁和MDL锁信息),下面我们开启第三个会话查询该表试试看。
# 我们还可以通过performance_schema.metadata_locks表来排查谁持有全局读锁,全局读锁通常在该表记录着同一个会话的OBJECT_TYPE为global和commit、LOCK_TYPE都为SHARED的两把显式锁,如下
root@localhost : (none) 01:01:43> select * from performance_schema.metadata_locks where OWNER_THREAD_ID!=sys.ps_thread_id(connection_id())\G;
*************************** 1. row ***************************
OBJECT_TYPE: GLOBAL
OBJECT_SCHEMA: NULL
OBJECT_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140621322913984
LOCK_TYPE: SHARED # 共享锁
LOCK_DURATION: EXPLICIT # 显式
LOCK_STATUS: GRANTED # 已授予
SOURCE: lock.cc:1110
OWNER_THREAD_ID: 94 # 持有锁的内部线程ID为94
OWNER_EVENT_ID: 16
*************************** 2. row ***************************
OBJECT_TYPE: COMMIT
OBJECT_SCHEMA: NULL
OBJECT_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140621322926064
LOCK_TYPE: SHARED # 共享锁
LOCK_DURATION: EXPLICIT # 显式
LOCK_STATUS: GRANTED # 已授予
SOURCE: lock.cc:1194
OWNER_THREAD_ID: 94 # 持有锁的内部线程ID为94
OWNER_EVENT_ID: 16
*************************** 3. row ***************************
OBJECT_TYPE: GLOBAL
OBJECT_SCHEMA: NULL
OBJECT_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140621391527216
LOCK_TYPE: INTENTION_EXCLUSIVE # 意向排它锁
LOCK_DURATION: STATEMENT # 语句
LOCK_STATUS: PENDING # 状态为pending,表示正在等待被授予
SOURCE: sql_base.cc:3190
OWNER_THREAD_ID: 95 # 被阻塞的内部线程ID为95
OWNER_EVENT_ID: 38
3 rows in set (0.00 sec)
# 查看process id为4,5 各自对应的内部线程ID是多少
root@localhost : (none) 01:33:36> select sys.ps_thread_id(4);
+---------------------+
| sys.ps_thread_id(4) |
+---------------------+
| 94 | # process id=4的线程对应的内部线程ID正好为94,说明就是process id=4的线程持有了全局读锁
+---------------------+
1 row in set (0.00 sec)
root@localhost : (none) 01:34:10> select sys.ps_thread_id(5);
+---------------------+
| sys.ps_thread_id(5) |
+---------------------+
| 95 | # proces id=5的线程对应的内部线程正好是95,说明在等待全局读锁的就是process id=5的线程
+---------------------+
1 row in set (0.00 sec)
如果是生产环境,综合上述信息,通过show processlist信息中对应的process id=4的行记录中找到user、host、db信息,大致判断一下是属于什么业务用途,找相关人员询问清楚,该杀掉就杀掉,顺便讨论下今后如何避免这个问题。
7.2.2 找出谁持有MDL锁
我们可能经常会发现执行语句时被阻塞等待MDL锁,例如:使用show processlist;语句查看线程信息时可能会发现State列为"Waiting for table metadata lock",碰到这种情况我们应该如何去排查是谁持有了MDL锁没有释放呢,下面我们尝试着进行MDL锁等待场景模拟(mdl锁记录对应的instruments为wait/lock/metadata/sql/mdl,默认未启用,对应的consumers为performance_schema.metadata_locks,在setup_consumers只受全局配置项global_instrumentation控制,默认启用)。
首先,打开两个会话,分别执行如下语句。
# 会话1,显式开启一个事务,并执行一个update语句更新sbtest1表不提交
root@localhost : sbtest 12:26:25> use sbtest
Database changed
root@localhost : sbtest 12:26:30> begin;
Query OK, 0 rows affected (0.00 sec)
root@localhost : sbtest 12:26:32> update sbtest1 set pad='yyy' where id=1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
# 会话2,对sbtest1表执行DDL语句添加一个普通索引
root@localhost : sbtest 12:42:50> use sbtest
Database changed
root@localhost : sbtest 12:42:56> alter table sbtest1 add index i_c(c); # 被阻塞
此时,我们另外开启一个会话3,使用show processlist语句查询线程信息,可以发现update语句正在等待MDL锁(Waiting for table metadata lock)。
root@localhost : (none) 12:37:49> show processlist;
+----+------+-----------+--------+---------+------+---------------------------------+--------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+--------+---------+------+---------------------------------+--------------------------------------+
| 92 | root | localhost | sbtest | Query | 121 | Waiting for table metadata lock | alter table sbtest1 add index i_c(c) |
| 93 | root | localhost | NULL | Query | 0 | starting | show processlist |
| 94 | root | localhost | sbtest | Sleep | 1078 | | NULL |
+----+------+-----------+--------+---------+------+---------------------------------+--------------------------------------+
3 rows in set (0.00 sec)