mysql案例分析
工作中，需要设计一个数据库存储，项目的需求大致如下：
(1）对于每个用户，需要存储一个或多个库， 每个库， 由一个用户标识来标识，这里成为clientFlag.
SRE实战 互联网时代守护先锋，助力企业售后服务体系运筹帷幄！一键直达领取阿里云限量特价优惠。(2) 对于每一个库，结构如下：
1) 一个clientFlag对应多个组，组包括组名和组的描述一类的信息
2)一个组中有多个成员，每个成员包括成员名和成员描述一类的信息
3)一个成员包括若干张自己喜欢的图片，图片有图片的文件ID和图片的描述信息
4)每张图片对应于多个版本，每个版本下存储使用深度学习引擎生成的特征
这个需求的目的是，给出一张图片，找出最有可能喜欢这张图片的人。
这是一个逻辑很简单的数据库，应该不难设计。首先，我们需要考虑的是不同用户的信息是存储在一张表上，还是以clientFlag做分割。从减少数据竞争考虑，使用clientFlag作为表名的一部分来实现数据分割，为什么是一部分，因为这样可以使clientFlag不会与其他表意外重名，这点需要注意。我们没有考虑继续进行分割，例如使用clientFlag-groupName作为表名的一部分，这里考虑了mysql的特性，mysql在文件特别多的情况下，表示并不是太好，如果以clientFlag-groupName作为表名的一部分，在mysql的服务器配置参数innodb_file_per_table为ON时，很容易出现几千几万个文件，这种情况下mysql运行效果并不好. 如果真的使用了很多的文件，可以考虑增大table_open_cache的值。具体可以参考网页： https://dev.mysql.com/doc/refman/5.6/en/table-cache.html。修改其中的5.6可以查看其他版本。
分割的缺点：
（1）在写数据库操作的代码时，写数据库语句变得更加困难，需要更多的拼接，出错的可能性和代码维护，都变得比固定表名的数据库苦难，增加了字符串拼接的时间。
（2）因为在表格层次进行分割，所以没有办法使用预处理语句 (prepared statement)，这里可能会导致一定程度的性能下降。
表格设计：
表格设计，考虑到组有组描述，成员有成员描述，图片有图片描述，为了减少冗余，满足第二范式，可以如下设计：
（1） 组表包括：
1）组名 2) 组描述 （第一列唯一索引）
(2) 成员包括：
1) 组名，成员名，用户描述 （前两列唯一索引）
(3) 图像表包括：
1）组名，成员名，图像ID，图像描述 （前三列唯一索引）
（4) 每一个特征表（一个clientFlag，一个特征对应一张表）包括：
1）组名，成员名，图像ID，图像特征 （前三列唯一索引）
上面设计的好处如下：
(1）不需要存储冗余的组信息，成员信息，图像描述信息
（2）在查找数据的时候，如果是按照先获取所有组，获取一个组的所有成员，获取成员的所有图片，获取图片的特征的方式查找，不需要进行表的关联，代码运行速度比较快，而且逻辑简单
（3）相关的数据会出现在一起，对于某些语句很友好
上面设计的缺点如下：
（1）组名，成员名，图片ID重复出现，对组名，用户名，图像ID的修改代价比较大
（2）组名，成员名，图片ID一般都是使用字符串表示，在表中占用比较大，而且为了保证唯一性，需要在上述字段上面添加唯一索引，导致索引占用也比较大
我的设计采取了下面的设计：
（1）组表包括：
1) 自增ID 2) 组名 3）组描述 （第一列主键，第二列唯一索引）
(2）成员表包括：
1）自增ID 2）外建关联 组ID 3) 成员名 4）成员描述 （第一列主键，第二三列唯一索引）
（3）图像表包括：
1）自增ID 2) 外健关联 成员ID 3）文件ID 4) 文件描述 （第一列主键，第二三列唯一索引）
(4) 每一个特征表（一个clientFlag，一个特征对应一张表）包括：
1）外键关联 图像ID 2) 特征 （第一列主键）
优点：
（1）不需要存储冗余的组信息，成员信息，图像描述信息
（2）组名，成员名，图片ID 不重复出现，修改组名，成员名等只需要修改一处
（3）表格大小更小，索引大小也更小
缺点：
（1）在查找数据的时候，经常需要使用join或者子查询，因为唯一索引的存在，子查询可以转化为常量表达式，性能上没有问题，代码会变得比较难写
（2）如果数据为随机并发插入，那么数据存储不存在聚集现象，对有些数据的查找不利，尤其是硬盘查找
表格设计的一个注意事项：
（1）合理选择每一列的类型和大小。
（2）避免NULL类型，例如对于描述而言，空字符串应该是合理的默认值。
测试数据：
关于测试数据， 这里使用英文数据进行测试，对于组名，可以考虑使用随机不重复的英文字符串，对于描述信息，可以使用更长的随机不重复的英文字符串，对于特征，使用字节数据，这里使用2000byte的字节数组。
（1）想要获取不重复字符串，可以考虑使用uuid，关于长度， 如果需要的长度较短，可以将生成的uuid字符串截断，得到需要的长度。如果需要的长度更长，有两种方式，第一种，重复获取多个uuid字符串，然后拼接得到需要的长度，第二种是在后面随便添加一些字符数组，重复的应该也没有什么问题，因为uuid已经可以保证唯一性了。在我的最初测试数据中，需要有1000个组，每个组有1000个成员，每个成员有10张图片。对于这么大量级的数据，按照我的测试来看，没有出现过uuid冲突的情况。我的名字基本为20个字符，描述大约为50或者60个字符。
（2）对于特征数据，这里有两种方式，第一个使用split截断一个比较大的二进制文件，然后每一个文件当做一个特征。第二种是在读取一个大文件的时候，在代码中进行分割，从我的实际操作来看，第二种方式比较好。实际上并不需要有一千万个不一样的特征，因为mysql并不精确比较不同的行的数据是否一致，所以，有数十万个应该就足够了。
压测的用处：
（1) 可以测试硬件的效果，这不是这次测试的目的
（2）可以测试不同服务器参数的影响
(3) 可以测试在测试量级下，服务器的性能
（4）可以使用测试数据，检测所写语句的性能，在这里，我对我的几乎所有的语句使用了explain查看了语句的性能，防止在写的时候，犯一些低级的错误，例如将可以索引查找的变成表扫描一类的
（5）分析在运行中出现的各种问题，例如在使用事务并发对一个成员的实现所有图片和特征替换的时候，会发现死锁的出现，在使用percona toolkit的pt-deadlock-logger分析，可以看出这种死锁来源于插入和删除的冲突， 查看innodb status的输出，可以看到间隙锁，应该是导致出现出现这种问题的原因。
（6）纠正一些自己的错误。
测试过程中，考虑使用的助手：
（1）高性能mysql中的状态记录：
#!/bin/sh INTERVAL=5 PREFIX=$INTERVAL-sec-status RUNFILE=/home/sun/benchmarks/running mysql -e 'SHOW GLOBAL VARIABLES' >> mysql-variables while test -e $RUNFILE; do file=$(date +%F_%I) sleep=$(date +%s.%N | awk "{print $INTERVAL - (\$1 % $INTERVAL)}") sleep $sleep ts="$(date +"TS %s.%N %F %T")" loadavg="$(uptime)" echo "$ts $loadavg" >> $PREFIX-${file}-status mysql -e 'SHOW GLOBAL STATUS' >> $PREFIX-${file}-status & echo "$ts $loadavg" >> $PREFIX-${file}-innodbstatus mysql -e 'SHOW ENGINE INNODB STATUS\G' >> $PREFIX-${file}-innodbstatus & echo "$ts $loadavg" >> $PREFIX-${file}-processlist mysql -e 'SHOW FULL PROCESSLIST\G' >> $PREFIX-${file}-processlist & echo $ts done echo Exiting because $RUNFILE does not exist
这段文本非常有用，可以省去你很多必须的代码，而且，对于分析mysql状态来说，非常有益。另外，下面分析用的脚本，同样很重要：
#!/bin/bash # This script converts SHOW GLOBAL STATUS into a tabulated format, one line # per sample in the input, with the metrics divided by the time elapsed # between samples. awk ' BEGIN { printf "#ts date time load QPS"; fmt = " %.2f"; } /^TS/ { # The timestamp lines begin with TS. ts = substr($2, 1, index($2, ".") - 1); load = NF - 2; diff = ts - prev_ts; prev_ts = ts; printf "\n%s %s %s %s", ts, $3, $4, substr($load, 1, length($load)-1); } /Queries/ { printf fmt, ($2-Queries)/diff; Queries=$2 } ' "$@"
对于上面的bash脚本，有一点要特别主要， /Queries/ 可能需要替换成$1~/^Com_insert$/, $1~/^Com_select$/或者$1~/^Questions$/等， Queries在之后的出现，最好也相应的替换，这样才是你需要的QPS，具体是使用Com_insert, Com_select，还是Questions，查看一下mysql官方文档。对于我的测试操作测试来看，我使用的go语言的客户端prepare语句，Queries得出的数值大约是Com_insert的四倍，而Com_insert得到的数值才是我需要的QPS。
（2）慢日志查询
这里可以考虑启用表格版的慢日志查询，文件版本更加精确，但是查看需要先使用脚本一类的分析比较好。启用表格版本的慢日志查询如下：
(1) 将log_output设置为TABLE, 设置如下 set global log_output="TABLE"; (2) 将slow_query_log设置为ON, 设置如下 set global slow_query_log=ON; (3) 设置合适的long_query_time set global long_query_time=0.5; show global variables like 'long_query_time';
如果用于测试，注意其中的global标志，因为基本是在另外一个连接中启用的慢日志查询，所以global标志是必要的，而且show global variables like 'long_query_time' 和show variables like 'long_query_time'得到的结果可能是不同的。
慢日志查询的作用是告诉你，哪条语句执行比较慢，从而给你一定的指导，免得在优化的路上走错了方向。
（3）explain语句或者explain extended，这里我简单介绍一下这个语法。
先给出查询语句，这里忽略掉clientFlag标识符：
explain insert into portrait(person_id, file_id, description) values ((select person.id from person inner join group where person.name = 'xxxx' and group.name = 'xxxxx'), 'xxxx', 'xxxx');
输出结果为：
*************************** 1. row *************************** id: 1 select_type: SIMPLE table: group_123 type: const possible_keys: name key: name key_len: 22 ref: const rows: 1 Extra: Using index *************************** 2. row *************************** id: 1 select_type: SIMPLE table: person_123 type: index possible_keys: NULL key: group_id key_len: 26 ref: NULL rows: 921849 Extra: Using where; Using index 2 rows in set (0.00 sec)
这里，我们首先需要关注rows，也就是需要扫描的估计行数，如果这个值和预计的一致，基本可以确定这个语句是合理的。对于这个案例来说，我们可以使用组名（groupName)的唯一索引从组表中获取组的ID，然后使用（组ID，用户名）的唯一索引获取用户的ID，也就是说明，上述两个row中，每一个，我们都应该是可以只扫描一行就得到结果的。而第二个结果中，可以看出，基本扫描了整个表格，才得到结果。下面，简单描述一下各个字段，其实，我觉得，主要关注扫描的行数，基本可以判断语句是否合理。
id: select语句的标识符，用来标识是第几个select语句。如果这一行是其他行的union结果，这个值为NULL. 在这种情况下，table列显示为类似于<unionM, N>来表示id值为M和N的行的union.
select_type: select的类型，有如下值：
（1）simple 简单select查询（不使用union或者子查询）
（2）primary 最外层的select查询
（3）union union中第二个及以后的查询语句
（4）dependent union 依赖于外层查询的union中的第二个及以后的查询语句
（5）union result union的结果
（6）subquery 子查询中的第一个select
（7）dependent subquery 依赖于外层查询的子查询中的第一个查询
（8）derived 派生表
（9）materialized 物化子查询
（10）uncacheable subquery 对于外层查询的每一行，都需要重新计算的子查询
（11）uncacheable union uncacheable subquery包含的union语句中的第二个及以后的查询
table: 扫描行（结果行）对应的表格。如果为union查询，派生表查询或者子查询，可能会显示为 <unionM, N>, <derivedN>或者<subqueryN>。
type: 官方描述是 "join type"， 更合理的说法应该是“access type"，我觉得你可以理解为扫描类型，也就是说，mysql如何查找对应的行。从好到坏依次是：
1）system 当访问的表只有一行时（系统表），特殊类型的const。
2）const 最多只有一行匹配。当mysql查找过程可以使用主键索引或者其他唯一索引匹配一个常量时，就会出现const。
3）eq_ref 当一个主键或者非空唯一键和从其他表中获取的常量或表达式做相等比较时。
4）ref 使用=或者<=>做相等比较，这里的键不为唯一键，或者只是唯一键的前缀，含义与(3)相同。
5）ref_or_null 与ref基本相同，只是可以匹配NULL值。
6) index_merge 使用index merge优化进行查询。
7）unique_subquery 这种类型使用eq_ref来处理in子查询。
8）index_subquery 这种类型可以理解为使用ref来处理in子查询。
9）range 某个键在指定范围内的值。
10) index 使用索引进行扫描。
11）ALL 全表扫描
注：从好到坏的顺序基本是大致的，并不是从上到下严格变坏。例如：对于小表来说，全表扫描的性能很多时候优于index方式，甚至range等方式。对于index和ALL两种方式，如果index方式可以使用覆盖扫描，那么index方式大多时候更优（当Extra列有using index显示），其他时候，很有可能全表扫描更快，因为全表扫描不需要回表查询。这些显示的类型，最好参照扫描行数一起查看。
possible_keys: mysql可能选择的用来查找表格中对应行的索引。这一行显示的结果与explain输出中显示的表格顺序无关，也就是说，在实际中，对于显示的表格顺序，possible_keys中的某些索引可能不能够使用。如果这个值为空，可以考虑检查语句，然后创建一个合适的索引。
key: mysql实际决定使用的索引。对于key中显示的名字，可以参考show index得到的结果，show index的结果中，有比较详细的索引说明信息。当possible_keys中没有合适的索引时，mysql也会使用某些索引来实现覆盖索引的效果。
key_len: 索引大小。对于innodb来说，如果使用二级索引，计算时，不会考虑主键的长度。 key_len的用处在于，对于一个复合索引，可以根据key_len来确定使用的索引的全部，还是某个特定前缀。关于key_len的计算，对于基本类型，如int，为4个字节。但是，对于字符型，尤其是varchar(n)的计算方式如下：对于utf8（或者说utf8mb3），计算索引长度的时候为3×n+2，对于utf8mb4，计算索引长度为4×n+2，对于其他的字符型，可以简单构建一个表格进行测试，或者查询相关文档。
ref: 显示与key列中的索引进行对比的是哪一列，或者说是一个常数。如果值是一个const，那么对比对象应该是一个常量（或者type 为const的select结果）， 如果值是一个func，那么对比对象应该是某个函数的结果。
rows: mysql认为在执行这个语句过程中必须要检查的行数。我觉得这个数值非常重要，是最终要的衡量语句好坏的指示器。对于innodb来说，这个数值可能不是精确值，如果与精确值偏差很大，可以考虑执行analyze table，来更新innodb关于表的统计信息，不过，就算是这样，也不能保证获取的值足够精确。这个值在很多时候，已经足够我们确定所写语句是否足够优秀。
Extra: 这一列显示mysql如何处理查询的额外信息。重要的一些如下：
1）Using filesort, Using temporary
这个标识获取结果的时候需要使用临时表排序，可以考虑对索引进行优化（调整索引顺序，添加必要的索引），或者对order by条件进行修改（例如，对于一些不展示的获取来说，不一定需要按照名字排序），如果实在需要使用临时表排序，考虑一下tmp_table_size和max_heap_table_size是否合理，如果你想知道内存临时表和硬盘临时表的信息，可以查看Created_tmp_disk_tables和Created_tmp_tables的数目（使用show status和show global status)。
2）Using index
这个标识是覆盖索引扫描的标识。说明查询过程中只需要检测索引内容就可以，而不用回表查询。
（4）set profiling=1; show profiles; show profile for query N; set profiling=0;
或者：使用performance shema来进行查询剖析。
我们先介绍set profiling相关的语句，这个语句是Session级别的，也就是说，单个连接有效，如果想要在一个Session中记录profiling信息，必须要在这个连接中启用profiling， 这种方式，有自己的便捷性，尤其适合使用mysql提供的客户端进行一些简单的profiling，而对于代码实现的一些调用来说，往往不那么友好。具体使用方法如下：
set profiling = 1;
select count(*) from group;
show profiles\G
*************************** 1. row *************************** Query_ID: 1 Duration: 0.00122225 Query: select count(*) from group 1 row in set, 1 warning (0.00 sec)
show profile for query 1;
+--------------------------------+----------+ | Status | Duration | +--------------------------------+----------+ | starting | 0.000133 | | Executing hook on transaction | 0.000017 | | starting | 0.000020 | | checking permissions | 0.000017 | | Opening tables | 0.000073 | | init | 0.000022 | | System lock | 0.000027 | | optimizing | 0.000017 | | statistics | 0.000041 | | preparing | 0.000039 | | executing | 0.000013 | | Sending data | 0.000699 | | end | 0.000016 | | query end | 0.000009 | | waiting for handler commit | 0.000019 | | closing tables | 0.000017 | | freeing items | 0.000028 | | cleaning up | 0.000019 | +--------------------------------+----------+ 18 rows in set, 1 warning (0.00 sec)
set profiling=0;
通过上述表格输出，可以看到调用这条语句需要总的时间，已经在每个步骤中需要的时间，可以针对性的进行优化。如果希望可以直接看到耗时最多一些步骤，也可以考虑使用如下语句，按照耗时从多到少显示：
set @query_id = 1; SELECT STATE, SUM(DURATION) as Total_R, ROUND( 100 * SUM(DURATION)/ (select SUM(DURATION) from INFORMATION_SCHEMA.PROFILING where QUERY_ID = @query_id), 2) AS Pct_R, COUNT(*) AS Calls, SUM(DURATION) / COUNT(*) AS "R/Call" FROM INFORMATION_SCHEMA.PROFILING where QUERY_ID = @query_id group by STATE ORDER BY Total_R DESC;
输出结果如下：
+--------------------------------+----------+-------+-------+--------------+ | STATE | Total_R | Pct_R | Calls | R/Call | +--------------------------------+----------+-------+-------+--------------+ | Sending data | 0.000699 | 57.01 | 1 | 0.0006990000 | | starting | 0.000153 | 12.48 | 2 | 0.0000765000 | | Opening tables | 0.000073 | 5.95 | 1 | 0.0000730000 | | statistics | 0.000041 | 3.34 | 1 | 0.0000410000 | | preparing | 0.000039 | 3.18 | 1 | 0.0000390000 | | freeing items | 0.000028 | 2.28 | 1 | 0.0000280000 | | System lock | 0.000027 | 2.20 | 1 | 0.0000270000 | | init | 0.000022 | 1.79 | 1 | 0.0000220000 | | waiting for handler commit | 0.000019 | 1.55 | 1 | 0.0000190000 | | cleaning up | 0.000019 | 1.55 | 1 | 0.0000190000 | | optimizing | 0.000017 | 1.39 | 1 | 0.0000170000 | | closing tables | 0.000017 | 1.39 | 1 | 0.0000170000 | | Executing hook on transaction | 0.000017 | 1.39 | 1 | 0.0000170000 | | checking permissions | 0.000017 | 1.39 | 1 | 0.0000170000 | | end | 0.000016 | 1.31 | 1 | 0.0000160000 | | executing | 0.000013 | 1.06 | 1 | 0.0000130000 | | query end | 0.000009 | 0.73 | 1 | 0.0000090000 | +--------------------------------+----------+-------+-------+--------------+ 17 rows in set, 18 warnings (0.01 sec)
下面介绍使用performance schema来进行查询剖析：
peformance_schema中，存储相关信息的表格是events_statements_history_long和events_stages_history_long。开启方式如下：
1）确定相关语句和阶段测量已经开启，开启方式是通过setup_instruments表格。一些测试会被默认开启。
update performance_schema.setup_instruments set ENABLED = 'YES', TIMED = 'YES' where name like '%statement/%'; update performance_schema.setup_instruments set ENABLED = 'YES', TIMED = 'YES' where name like '%stage/%';
2) 确保events_statements_*和events_stages_*消费者已经被启用。一些消费者会默认开启。
update performance_schema.setup_consumers set ENABLED = 'YES' where name like '%events_statements_%'; update performance_schema.setup_consumers set ENABLED = 'YES' where name like '%events_stages_%';
(3) 运行你打算profile的语句，这里开始的profiling是全局模式的，所以，你可以在其他连接中调用语句。例如调用如下语句：
select count(*) from group;
(4）使用performance_schema中的表格进行查询，注意其中的EVENT_ID，这个字段和Query_ID类似，这里的时间单位是皮秒，转化成秒，需要除以10的12次方。
select event_id, truncate(timer_wait/1000000000000,6) as Duration, SQL_TEXT From performance_schema.events_statements_history_long;
+----------+----------+------------------------------------------------------------+ | event_id | Duration | SQL_TEXT | +----------+----------+------------------------------------------------------------+ | 312 | 0.003801 | truncate performance_schema.events_statements_history_long | | 325 | 0.000861 | select count(*) from group_111 | +----------+----------+------------------------------------------------------------+
2 rows in set (0.00 sec)
SELECT event_name AS Stage, TRUNCATE(TIMER_WAIT/1000000000000,6) AS Duration FROM performance_schema.events_stages_history_long WHERE NESTING_EVENT_ID=325;
+------------------------------------------------+----------+ | Stage | Duration | +------------------------------------------------+----------+ | stage/sql/starting | 0.000122 | | stage/sql/Executing hook on transaction begin. | 0.000001 | | stage/sql/starting | 0.000009 | | stage/sql/checking permissions | 0.000006 | | stage/sql/Opening tables | 0.000061 | | stage/sql/init | 0.000007 | | stage/sql/System lock | 0.000016 | | stage/sql/optimizing | 0.000006 | | stage/sql/statistics | 0.000030 | | stage/sql/preparing | 0.000025 | | stage/sql/executing | 0.000001 | | stage/sql/Sending data | 0.000503 | | stage/sql/end | 0.000002 | | stage/sql/query end | 0.000002 | | stage/sql/waiting for handler commit | 0.000014 | | stage/sql/closing tables | 0.000012 | | stage/sql/freeing items | 0.000029 | | stage/sql/cleaning up | 0.000001 | +------------------------------------------------+----------+ 18 rows in set (0.00 sec)
对于上述语句，可以参考profiling的处理，进行一定的顺序排列和汇总。
关于上述的profiling在使用触发器的情况下，会有一定的问题，我在这里简单介绍一下。场景如下：
1）有group表存储组的信息，person表存储用户信息，group_member存储组的成员关系，也就是成员关系。group表的设计如下：
CREATE TABLE `group` ( `id` mediumint(8) unsigned NOT NULL AUTO_INCREMENT, `name` varchar(20) NOT NULL, `description` varchar(60) NOT NULL DEFAULT '', `count` int(11) NOT NULL DEFAULT '0', PRIMARY KEY (`id`), UNIQUE KEY `name` (`name`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8;
CREATE TABLE `person` (
`id` int(10) unsigned NOT NULL AUTO_INCREMENT,
`name` varchar(20) NOT NULL,
`description` varchar(60) NOT NULL DEFAULT '',
PRIMARY KEY (`id`),
UNIQUE KEY `name` (`name`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;
CREATE TABLE `group_member` (
`group_id` mediumint(8) unsigned NOT NULL,
`person_id` int(10) unsigned NOT NULL,
PRIMARY KEY (`group_id`,`person_id`),
KEY `person_id` (`person_id`),
CONSTRAINT `grp_member_111_ibfk_1` FOREIGN KEY (`group_id`) REFERENCES `group_111` (`id`) ON DELETE CASCADE,
CONSTRAINT `grp_member_111_ibfk_2` FOREIGN KEY (`person_id`) REFERENCES `person_111` (`id`) ON DELETE CASCADE
) ENGINE=InnoDB DEFAULT CHARSET=utf8;
2) 触发器如下，
CREATE TRIGGER `instri_member` AFTER INSERT ON `group_member` FOR EACH ROW insert into group_count values (NEW.group_id, 1) on duplicate key update count = count+1 CREATE TRIGGER `deltri_member` AFTER DELETE ON `group_member` FOR EACH ROW update group_count set count = count-1 where group_id = OLD.group_id
3) 进行如下的插入语句操作：
insert into group_member values((select id from group where name = 'xxx'), (select id from person where name = 'yyy'));
调用show profiles，显示结果如下：
+----------+------------+--------------------------------------------------------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+--------------------------------------------------------------------------------------------+ | 1 | 0.01630200 | insert into grp_count_111 values (NEW.group_id, 1) on duplicate key update count = count+1 | +----------+------------+--------------------------------------------------------------------------------------------+ 1 row in set, 1 warning (0.00 sec)
这里需要注意两点：
（1）我们调用的语句没有出现，而触发器的语句被记录。
（2）触发器触发的这条语句时间很短。
然后我们调用show profile for query 1, 结果如下：
+--------------------------------+----------+ | Status | Duration | +--------------------------------+----------+ | continuing inside routine | 0.000034 | | Executing hook on transaction | 0.000010 | | Sending data | 0.000013 | | checking permissions | 0.000012 | | Opening tables | 0.000049 | | init | 0.000021 | | update | 0.016120 | | end | 0.000018 | | query end | 0.000005 | | closing tables | 0.000022 | +--------------------------------+----------+ 10 rows in set, 1 warning (0.00 sec)
与show profiles的结果基本一致。
下面，我们再看一下，使用performance_schema的统计信息：
SELECT EVENT_ID, TRUNCATE(TIMER_WAIT/1000000000000,6) as Duration, SQL_TEXT FROM performance_schema.events_statements_history_long; +----------+----------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | EVENT_ID | Duration | SQL_TEXT | +----------+----------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | 252 | 0.004271 | truncate table performance_schema.events_statements_history_long | | 198 | 0.016278 | insert into grp_count_111 values (NEW.group_id, 1) on duplicate key update count = count+1 | | 176 | 0.050943 | insert into grp_member_111 values((select id from group_111 where name = '69be790a-332a-400e-8'), (select id from person_111 where name = 'dca83c7d-b1f6-4193-b')) | +----------+----------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 3 rows in set (0.00 sec)
SELECT event_name AS Stage, TRUNCATE(TIMER_WAIT/1000000000000,6) AS Duration -> FROM performance_schema.events_stages_history_long WHERE NESTING_EVENT_ID=176; +------------------------------------------------+----------+ | Stage | Duration | +------------------------------------------------+----------+ | stage/sql/starting | 0.000249 | | stage/sql/Executing hook on transaction begin. | 0.000009 | | stage/sql/starting | 0.000020 | | stage/sql/checking permissions | 0.000013 | | stage/sql/checking permissions | 0.000011 | | stage/sql/checking permissions | 0.000011 | | stage/sql/Opening tables | 0.000177 | | stage/sql/init | 0.000017 | | stage/sql/System lock | 0.000028 | | stage/sql/update | 0.000014 | | stage/sql/optimizing | 0.000018 | | stage/sql/statistics | 0.000116 | | stage/sql/preparing | 0.000022 | | stage/sql/executing | 0.000007 | | stage/sql/Sending data | 0.000015 | | stage/sql/optimizing | 0.000011 | | stage/sql/statistics | 0.000055 | | stage/sql/preparing | 0.000014 | | stage/sql/executing | 0.000006 | +------------------------------------------------+----------+ 19 rows in set (0.00 sec)
SELECT event_name AS Stage, TRUNCATE(TIMER_WAIT/1000000000000,6) AS Duration FROM performance_schema.events_stages_history_long WHERE NESTING_EVENT_ID=198; +------------------------------------------------+----------+ | Stage | Duration | +------------------------------------------------+----------+ | stage/sql/Sending data | 0.000330 | | stage/sql/Executing hook on transaction begin. | 0.000007 | | stage/sql/Sending data | 0.000013 | | stage/sql/checking permissions | 0.000011 | | stage/sql/Opening tables | 0.000051 | | stage/sql/init | 0.000019 | | stage/sql/update | 0.016126 | | stage/sql/end | 0.000007 | | stage/sql/query end | 0.000004 | | stage/sql/closing tables | 0.000010 | | stage/sql/end | 0.000005 | | stage/sql/query end | 0.000005 | | stage/sql/waiting for handler commit | 0.033397 | | stage/sql/closing tables | 0.000043 | | stage/sql/freeing items | 0.000047 | | stage/sql/cleaning up | 0.000002 | +------------------------------------------------+----------+ 16 rows in set (0.00 sec)
4) 总结：
由上面输出结果可以看出来，在有触发器存在的情况下， 使用performance_schema查看运行时间是更加明智的选择，因为set profiling的方式只会显示触发器操作需要的时间，而这个时间很多时候是耗时比较少的操作。
