1 应用场景
在DBA的工作中经常遇到应用卡顿,延迟过大,一个操作点了好长时间还没有响应。或者是应用服务器接连报连接超时,而数据库状态及各项性能指标都无明显异常的情况,检查数据库里执行的SQL语句,也没有执行时间明显异常SQL语句。这时分析的主要方向就需要转到事务上来,应用发给数据库的SQL语句是以事务为单位来执行的,只有一个事务的所有语句都执行完了,数据库才会给应用发送响应信息,有时单个语句执行的时间是正常的,或者说是在可以容忍的范围之内,整个事务执行的时间却超过了应用可以容忍的范围。
MySQL数据库的存储引擎是分离的,对事务的支持是通过INNODB存储引擎实现的,这对搜集和分析事务的信息造成了不小的麻烦。在Performance Schema出现之前,要分析MySQL数据库的事务,只能通过INNODB的状态引擎和Information Schema的innodb_trx视图来进行,对历史事务只能通过状态值来镜像简单的分析,有了Performance Schema之后,对MySQL的事务分析来说,可以说是打开了一个新的世界,视野一下子开阔了不少,可用的信息,可分析的时间段一下子拓展开了,可以说打破了之前的时空限制,有一种豁然开朗的感觉。这篇文章简单介绍一下通过Performance Schema怎样分析MySQL数据库当前和历史的事务信息。
Performance Schema最早在MYSQL 5.5中出现,在5.6,5.7版本中performance_schema又添加了更多的监控项,统计信息也更丰富,到了MySQL 8.0以上的版本,监控项及统计信息更是得到了进一步的加强,对系统性能的影响也得到了有效的控制。
从MySQL 5.7之后,Performance Schema默认就是启用的,不过对有些云上的数据库来说比如阿里云的MySQL RDS ,Performance Schema却是禁用的,禁用的原因是会对数据库的性能有影响,但是,阿里云也提供了类似的功能,好像叫SQL 洞察,是基于Performance Schema来实现的。
2 检查Performance Schema中事务相关的instruments和consumers是否打开
Performance Schema虽然启用了,但是并不是所有的instruments和consumers都打开了,这应当是基于性能方面的考虑,毕竟有些instrument对性能的影响不能忽略,而有些consumers占用的空间也不小。这里,我们要对事务进行分析,就要检查,事务相关的选项是否打开了,首先检查的是instruments,这个是决定对那些指标进行采样的,使用下面的语句
--检查instruments
SELECT NAME, ENABLED, TIMED FROM performance_schema.setup_instruments WHERE NAME = 'transaction';
-----------+-------+-----+
NAME |ENABLED|TIMED|
-----------+-------+-----+
transaction|YES |YES |
-----------+-------+-----+
--可以看到,事务的instruments是激活的。
--检查setup_consumers,这个决定了采样信息是怎么存储保留的。
SELECT * FROM performance_schema.setup_consumers WHERE NAME LIKE 'events_transactions%';
--------------------------------+-------+
NAME |ENABLED|
--------------------------------+-------+
events_transactions_current |YES |
events_transactions_history |YES |
events_transactions_history_long|NO |
--------------------------------+-------+
复制
可以看到,current和history是激活的,history_long(长期历史信息)却没有激活。如果要用,需要激活一下。激活的方式可以分为临时激活(重启后失效)和永久激活
UPDATE performance_schema.setup_consumers
SET ENABLED = 'YES'
WHERE NAME LIKE 'events_transactions_history_long';
--永久激活
--编辑mysql Server 配置文件加入下面条目
[mysqld]
performance-schema-consumer-events-transactions-history-long=ON
复制
3 当前线程的事务分析
3.1 Performance Schema中的事务事件
事务的一次执行在Performance Schema记作一个事件。在设置为事务手动提交时,事务事件不完全包括和START TRANSACTION, COMMIT, or ROLLBACK statements相关的事件。事务事件的时间和这些语句的时间会有些微的重叠,在启用了gtid时,对于已提交的事务,可以用gtid来定位一个事务,如果gtid未启用,要想定位一个事务,可以使用线程id和事件id的组合。
3.2 events_transactions_current–线程当前事务表
events_transactions_current表名里并不包含线程的字样,在标题里写成线程事务表的原因是这个表监测的当前的线程的事务信息,包含当前事务事件。当前的每一个线程存储一行,显示监测到的每个线程当前事务的状态。这个表的大小和当前的线程数量有关系,没有固定的大小,随着当前线程数量的变化而变化。所谓的当前事务,是指线程正在执行的没有提交的事务或者是最后一个已提交的事务(线程的状态为sleeps时)。这个表里大部分列的含义可以从列明直接推断出来,有几个列需要解释一下。
- TRX_ID列:官方的参考指南里说未使用列,里面的值不知道是什么意思,可能不是当前线程监测到的事务的事务id。
- GTID列:当事务提交之后,如果事务用的是gtid模式而且事务的访问模式是读写,这个列显示的是事务的gtid值,否则这个列显示AUTOMATIC,未提交事务该列的值是AUTOMATIC。
- NESTING_EVENT_TYPE:上一级事件(嵌入事件)的类型,可以是 TRANSACTION, STATEMENT, STAGE, or WAIT,不可能是事务(事务不能嵌入到另一个事务中)。
- NESTING_EVENT_ID:上一级事件的事件ID。
查询这个表时,一般和线程表关联,可以同时获得执行事务线程的信息,下面的SQL查询服务器在本地执行的当前事务信息(只打开一个会话)。
select t.THREAD_ID,t.EVENT_ID,t.EVENT_NAME ,t.STATE ,t.GTID ,
t.TIMER_START ,
t.TIMER_END ,
format_pico_time(t.TIMER_WAIT) TIMER_WAIT
from events_transactions_current t left join threads h on h.THREAD_ID=t.THREAD_ID
where PROCESSLIST_HOST in ('localhost');
---------+--------+-----------+---------+---------+---------------+---------------+----------+
THREAD_ID|EVENT_ID|EVENT_NAME |STATE |GTID |TIMER_START |TIMER_END |TIMER_WAIT|
---------+--------+-----------+---------+---------+---------------+---------------+----------+
47| 47|transaction|COMMITTED|AUTOMATIC|370775321720000|370780559123000|5.24 ms |
---------+--------+-----------+---------+---------+---------------+---------------+----------+
复制
如果一个刚连接的线程,没有执行过任何事务,这个表里没有和这个线程相关的条目。
3.3 The events_transactions_history Table --线程历史事务表
把这个表称作线程历史事务表是因为这个表里面包含数据库当前每个线程最近提交的N个事务,N的具体值由系统变量 performance_schema_events_transactions_history_size的值来确定,这个值的缺省值如下
show variables like 'performance_schema_events_transactions_history_size';
---------------------------------------------------+-----+
Variable_name |Value|
---------------------------------------------------+-----+
performance_schema_events_transactions_history_size|10 |
---------------------------------------------------+-----+
```这个参数的缺省值是10,这里历史表里包括每个线程的10近期提交的10个事务。线程终结了,这个线程所有的事务信息也就被释放了。所以这个表虽然是历史表,表里包含的实际上是当前线程的历史信息。 在这个表里查不到已经关闭的线程的历史事务,这一点在使用这个表作事务分析时不能忽略。如下表查询的是数据库本地执行的事务历史信息。
```sql
select t.THREAD_ID,t.EVENT_ID,t.EVENT_NAME ,t.STATE ,t.GTID ,
t.TIMER_START ,
t.TIMER_END ,
format_pico_time(t.TIMER_WAIT) TIMER_WAIT
from events_transactions_history t left join threads h on h.THREAD_ID=t.THREAD_ID
where PROCESSLIST_HOST in ('localhost');
---------+--------+-----------+---------+---------+-----------------+-----------------+---------------+---------------------------------------------------------+
THREAD_ID|EVENT_ID|EVENT_NAME |STATE |GTID |TIMER_START |TIMER_END |TIMER_WAIT|
---------+--------+-----------+---------+---------+---------------+---------------+----------+
47| 3|transaction|COMMITTED|AUTOMATIC|229269308674000|229270700522000|1.39 ms |
47| 7|transaction|COMMITTED|AUTOMATIC|239457835728000|239458114888000|279.16 us |
47| 9|transaction|COMMITTED|AUTOMATIC|239461012694000|239461896439000|883.75 us |
47| 38|transaction|COMMITTED|AUTOMATIC|278962713954000|278963027160000|313.21 us |
47| 43|transaction|COMMITTED|AUTOMATIC|357860833003000|357861296480000|463.48 us |
47| 45|transaction|COMMITTED|AUTOMATIC|365182270483000|365209612386000|27.34 ms |
47| 47|transaction|COMMITTED|AUTOMATIC|370775321720000|370780559123000|5.24 ms |
---------+--------+-----------+---------+---------+-----------------+-----------------+---------------+---------------------------------------------------------+ |
复制
看到这个表里没有未提交的事务,表里最后一条事务信息(TIMER_START最大)正是events_transactions_current 的事务。从上面的两个表里,可以获得MySQL数据库正在执行的事务和已经提交的事务(默认为10个,如果数据库里有长事务,可以通过参数来调整),如果线程已经终结了,就要通过events_transactions_history_long表来分析了,请看下一章。
4 历史线程的事务events_transactions_history_long
这个表里包含最近N个所有线程的已经得事务。它的列定义同前面两个表相同,事务在提交之后才会被记录到这个表中,N的大小由performance_schema_events_transactions_history_long_size变量决定,这个变量的缺省值是
show variables like 'performance_schema_events_transactions_history_long_size';
--------------------------------------------------------+-----+
Variable_name |Value|
--------------------------------------------------------+-----+
performance_schema_events_transactions_history_long_size|10000|
--------------------------------------------------------+-----+
这个表的consumer默认是关闭的,可以在线打开
```sql
UPDATE performance_schema.setup_consumers
SET ENABLED = 'YES'
WHERE NAME LIKE 'events_transactions_history_long';
复制
select * from events_transactions_history_long;
THREAD_ID|EVENT_ID|END_EVENT_ID|EVENT_NAME |STATE |TRX_ID |GTID |XID_FORMAT_ID|XID_GTRID|XID_BQUAL|XA_STATE|SOURCE |TIMER_START |TIMER_END |TIMER_WAIT |ACCESS_MODE|ISOLATION_LEVEL|AUTOCOMMIT|NUMBER_OF_SAVEPOINTS|NUMBER_OF_ROLLBACK_TO_SAVEPOINT|NUMBER_OF_RELEASE_SAVEPOINT|OBJECT_INSTANCE_BEGIN|NESTING_EVENT_ID|NESTING_EVENT_TYPE|
---------+--------+------------+-----------+---------+---------------+---------+-------------+---------+---------+--------+---------------+-----------------+-----------------+------------+-----------+---------------+----------+--------------------+-------------------------------+---------------------------+---------------------+----------------+------------------+
63| 10016| 10016|transaction|COMMITTED|421642321774968|AUTOMATIC| | | | |handler.cc:1330|15889601643357000|15889601688558000| 45201000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 10015|STATEMENT |
66| 9982| 9982|transaction|COMMITTED|421642321774160|AUTOMATIC| | | | |handler.cc:1330|15889602505265000|15889602543512000| 38247000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 9981|STATEMENT |
63| 10018| 10018|transaction|COMMITTED|421642321774968|AUTOMATIC| | | | |handler.cc:1330|15889602767808000|15889602800347000| 32539000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 10017|STATEMENT |
66| 9984| 9984|transaction|COMMITTED|421642321774160|AUTOMATIC| | | | |handler.cc:1330|15889604893128000|15889604933580000| 40452000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 9983|STATEMENT |
63| 10020| 10020|transaction|COMMITTED|421642321774968|AUTOMATIC| | | | |handler.cc:1330|15889605083170000|15889605117028000| 33858000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 10019|STATEMENT |
66| 9986| 9986|transaction|COMMITTED|421642321774160|AUTOMATIC| | | | |handler.cc:1330|15889606699159000|15889606736652000| 37493000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 9985|STATEMENT |
63| 10022| 10022|transaction|COMMITTED|421642321774968|AUTOMATIC| | | | |handler.cc:1330|15889606807451000|15889606839423000| 31972000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 10021|STATEMENT |
66| 9988| 9988|transaction|COMMITTED|421642321774160|AUTOMATIC| | | | |handler.cc:1330|15889607033638000|15889607066702000| 33064000|READ WRITE |REPEATABLE READ|YES | 0| 0| 0| | 9987|STATEMENT |
复制
5 事务执行的sql语句
5.1 事务事件和语句事件的关系
如果连接数据库的程序设置为自动提交,此时每条语句为一个单独的事务,事务的上一级事件就是这条语句。如果是手动提交的事务,所有的事务方位模式都是READ WRITE,事务的上一级事件是事务执行的第一个sql语句,事务是后面执行的SQL语句的上级事件。
5.2 查询事务的SQL语句
根据事务执行的SQL语句和事务的上下级关系不同,查询的关联条件也需要改变一下。下面sql语句用于查询事务的上级事件是SQL语句的情况,适用于自动提交和手动提交下执行的第一条SQL语句,关联条件里还需要加上线程ID。
select t.THREAD_ID,t.EVENT_ID,t.EVENT_NAME ,t.STATE ,t.GTID ,
db_start.db_start + INTERVAL t.TIMER_START / 1000000000000 second TIMER_START ,
db_start.db_start + INTERVAL t.TIMER_END / 1000000000000 second TIMER_END ,
format_pico_time(t.TIMER_WAIT) TIMER_WAIT ,s.SQL_TEXT
from events_transactions_history_long t inner join events_statements_history_long s
on t.NESTING_EVENT_ID=s.EVENT_ID and t.THREAD_ID=s.THREAD_ID
left join (
select
now()-INTERVAL VARIABLE_VALUE second + INTERVAL 8 hour db_start
from
global_status
where
variable_name = 'Uptime') db_start on 1 = 1
where t.NESTING_EVENT_TYPE='STATEMENT' order by 6;
---------+--------+-----------+---------+---------+--------------------------+--------------------------+----------+-
THREAD_ID|EVENT_ID|EVENT_NAME |STATE |GTID |TIMER_START |TIMER_END |TIMER_WAIT|SQL_TEXT
---------+--------+-----------+---------+---------+--------------------------+--------------------------+----------+--------------------------------------------------------------------------
64| 34524|transaction|COMMITTED|ANONYMOUS|2025-03-24 15:44:31.621361|2025-03-24 15:44:31.698892|77.53 ms |INSERT INTO sbtest1 (id, k, c, pad) VALUES (50088, 46983, '64366685620-205
66| 34596|transaction|COMMITTED|ANONYMOUS|2025-03-24 15:44:31.621744|2025-03-24 15:44:31.758276|136.53 ms |INSERT INTO sbtest2 (id, k, c, pad) VALUES (49827, 50494, '02301799100-740
65| 34376|transaction|COMMITTED|ANONYMOUS|2025-03-24 15:44:31.641548|2025-03-24 15:44:31.759389|117.84 ms |UPDATE sbtest2 SET c='44387265975-88104821761-84835339892-71535337991-2465
67| 34188|transaction|COMMITTED|AUTOMATIC|2025-03-24 15:44:31.654543|2025-03-24 15:44:31.654861|317.86 us |SELECT SUM(k) FROM sbtest1 WHERE id BETWEEN 50226 AND 50325
67| 34190|transaction|COMMITTED|AUTOMATIC|2025-03-24 15:44:31.655711|2025-03-24 15:44:31.655880|169.86 us |SELECT c FROM sbtest3 WHERE id BETWEEN 49872 AND 49971 ORDER BY c
67| 34192|transaction|COMMITTED|AUTOMATIC|2025-03-24 15:44:31.656848|2025-03-24 15:44:31.657354|506.32 us |SELECT DISTINCT c FROM sbtest3 WHERE id BETWEEN 49836 AND 49935 ORDER BY c
67| 34194|transaction|COMMITTED|ANONYMOUS|2025-03-24 15:44:31.657945|2025-03-24 15:44:31.758546|100.60 ms |UPDATE sbtest3 SET k=k+1 WHERE id=50131
64| 34526|transaction|COMMITTED|AUTOMATIC|2025-03-24 15:44:31.700299|2025-03-24 15:44:31.700369|69.72 us |SELECT c FROM sbtest1 WHERE id=49816
64| 34528|transaction|COMMITTED|AUTOMATIC|2025-03-24 15:44:31.701768|2025-03-24 15:44:31.701836|67.66 us |SELECT c FROM sbtest1 WHERE id=50352
64| 34530|transaction|COMMITTED|AUTOMATIC|2025-03-24 15:44:31.703409|2025-03-24 15:44:31.703472|62.94 us |SELECT c FROM sbtest1 WHERE id=50168
---------+--------+-----------+---------+---------+--------------------------+--------------------------+----------+-
复制
上面的语句对时间进行了处理,里面的db_start子查询用来获得数据库的启动时间,根据服务器的时区设置确定是否加上8小时的偏移量,关于Performance Schema的时间格式及转换可以参考我的另一篇文章
从一次应用性能的优化说起–谈谈Performance Schema的应用
在非自动提交模式下,如果要查询事务执行的所有查询语句,需要根据事件父子关系的不同分别获取后再union一下,如下面
---------+----------+---------+-------------------------------------+----------------+----------------+
select * from
(select t.THREAD_ID,t.EVENT_ID tran_event,h.EVENT_ID sql_event,h.SQL_TEXT,t.TIMER_START tran_start ,h.TIMER_START sql_start from events_transactions_history t
left join events_statements_history h on h.EVENT_ID = t.NESTING_EVENT_ID and h.THREAD_ID = t.THREAD_ID where h.THREAD_ID = 47
union
select t.THREAD_ID,t.EVENT_ID tran_event,h.EVENT_ID sql_event,h.SQL_TEXT,t.TIMER_START tran_start ,h.TIMER_START sql_start from events_transactions_history t
left join events_statements_history h on h.NESTING_EVENT_ID =t.EVENT_ID and h.THREAD_ID = t.THREAD_ID where h.THREAD_ID = 47) th
order by 1,2,5,6;
THREAD_ID|tran_event|sql_event|SQL_TEXT |tran_start |sql_start |
---------+----------+---------+-------------------------------------+----------------+----------------+
47| 25| 27|select * from country limit 10 |1013828597026000|1045132775764000|
47| 25| 28|commit |1013828597026000|1077856622893000|
47| 30| 29|begin |1320102553092000|1320102487728000|
47| 30| 31|select * from country limit 10 |1320102553092000|1323722655309000|
47| 30| 32|select count(*) from city |1320102553092000|1331415237845000|
47| 30| 33|update t_f set id=3 where num4=12.32|1320102553092000|1345604889880000|
47| 30| 34|select count(*) from city |1320102553092000|1352559679559000|
47| 30| 35|select * from country limit 10 |1320102553092000|1357393210951000|
47| 30| 36|select * from country limit 2 |1320102553092000|1361727003373000|
47| 30| 37|commit |1320102553092000|1379716197706000|
---------+----------+---------+-------------------------------------+----------------+----------------+
##### 5 事务汇总信息
Performance Schema不单提供了当前和历史事务的详细信息,也提供了不同维度的事务汇总信息,有5个事务汇总表可以查询
```sql
show tables like 'events_transactions_summary%';
Tables_in_performance_schema (events_transactions_summary%)|
-----------------------------------------------------------+
events_transactions_summary_by_account_by_event_name |
events_transactions_summary_by_host_by_event_name |
events_transactions_summary_by_thread_by_event_name |
events_transactions_summary_by_user_by_event_name |
events_transactions_summary_global_by_event_name |
复制
在MySQL数据中,account(账号)是主机(host)和用户(user)的组合,看一个以用户维度的事务总结信息
---------------+-----------+----------+----------------+--------------+--------------+---------------+----------------+--------------------+--------------------+--------------------+--------------------+---------------+-------------------+-------------------+-------------------+-------------------+
select * from events_transactions_summary_by_user_by_event_name ;
USER |EVENT_NAME |COUNT_STAR|SUM_TIMER_WAIT |MIN_TIMER_WAIT|AVG_TIMER_WAIT|MAX_TIMER_WAIT |COUNT_READ_WRITE|SUM_TIMER_READ_WRITE|MIN_TIMER_READ_WRITE|AVG_TIMER_READ_WRITE|MAX_TIMER_READ_WRITE|COUNT_READ_ONLY|SUM_TIMER_READ_ONLY|MIN_TIMER_READ_ONLY|AVG_TIMER_READ_ONLY|MAX_TIMER_READ_ONLY|
---------------+-----------+----------+----------------+--------------+--------------+---------------+----------------+--------------------+--------------------+--------------------+--------------------+---------------+-------------------+-------------------+-------------------+-------------------+
|transaction| 24| 72771207000| 6675000| 3032133000| 34953294000| 24| 72771207000| 6675000| 3032133000| 34953294000| 0| 0| 0| 0| 0|
event_scheduler|transaction| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0| 0|
root |transaction| 94| 652502859740000| 152998000| 6941519784000|652335184727000| 94| 652502859740000| 152998000| 6941519784000| 652335184727000| 0| 0| 0| 0| 0|
sysbenchdb |transaction| 309402|4280250284568000| 0| 13833945000| 1047390143000| 309402| 4280250284568000| 0| 13833945000| 1047390143000| 0| 0| 0| 0| 0|
---------------+-----------+----------+----------------+--------------+--------------+---------------+----------------+--------------------+--------------------+--------------------+--------------------+---------------+-------------------+-------------------+-------------------+-------------------+
复制
可以看到每个用户的执行的事务次数,对于每个指标,都提供了最大值,最小值和平均值,对于我们分析十分管用。
6 一点感想
MySQL的Performance Schema 功能确实很强大,对MySQL数据库的可观测性的改善可以说是立杆见影,对性能分析来说,历史的性能数据的重要性是难以估量的,这篇文章只是简单介绍了在事务分析方面的一部分内容,后面还有很多需要学习的地方。