上QQ阅读APP看本书，新人免费读10天
设备和账号都新为新人
6.1 利用等待事件排查MySQL性能问题
通常，在生产服务器上线之前，我们都会对数据库服务器的硬件进行I/O基准测试，对数据库进行增、删、改、查的基准测试，建立基线参考数据，以便为日后的服务器扩容或架构升级提供数据支撑。在基准测试规划时，通常需要选择一款基准测试软件（I/O基准测试通常选择FIO和IOzone, MySQL数据库基准测试通常选择sysbench、TPCC-MySQL、Workbench等），在使用基准测试软件对服务器压测到一个极限值时，我们认为所得数据就是被测试服务器的最高性能。但这还不够，测试性能无法继续提升还可能是因为服务器在BIOS设置、硬件搭配、操作系统参数、文件系统策略、数据库配置参数等方面不够优化，所以还需要借助一些性能排查手段来找出瓶颈所在，以使得我们对数据库服务器上线之后可能存在的瓶颈点心中有数。下面以使用sysbench（0.5.x版本）基准测试工具压测MySQL数据库为例，介绍如何使用performance_schema的等待事件来排查数据库性能瓶颈。
首先，使用performance_schema配置表启用等待事件的采集与记录。
# 启用所有等待事件的instruments mysql> use performance_schema Database changed # 修改setup_instruments 表的enabled和timed字段为yes，表示启用对应的instruments mysql> 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启用之后才会开始采集） mysql> 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 mysql> 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 mysql> 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不再随着线程数的增加而增大为止。
[root@localhost～]# 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资源绝大部分都消耗在了%wa上，说明I/O设备性能出现严重不足 [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.00277.00160.008864.002774.00 26.63 47.84112.98 2.29100.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.00267.00244.008544.004643.00 25.81 28.20 40.29 1.96100.00
通过查看系统负载，一眼就可以看出来是由于磁盘性能严重不足所导致的，但是在数据库内部事件信息是如何体现的呢？（注意：如果你没有足够的performance_schema使用经验，此时是绝好的学习积累的机会，不要错过，也许哪一天看不出操作系统负载的端倪时，这些事件信息能帮上大忙。）
# 为了方便查询等待事件统计，我们可以先创建一个视图，用于实时统计当前等待事件（非历史数据） mysql>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个都是与I/O相关的等待事件，剩下1个是与binlog相关的互斥等待事件 mysql> 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 表（返回的数据行数可能比较多，且对查询结果没有做分组聚合，是逐行的事件记录数据） mysql> 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）
从上述等待事件的查询结果中可以非常清晰地看到，事务大多数的延迟时间花在了等待I/O上（主要是undo log、redo log、独立表空间文件、binlog的fetch和read系统调用），说明I/O设备可能出现了严重的性能瓶颈，这里与使用操作系统命令查看到的磁盘性能严重不足相对应。
结论：通过以上测试数据表明，MySQL性能低下是因为磁盘性能严重不足成为瓶颈（通常，在内存和磁盘不构成瓶颈的情况下，4核CPU的TPS达到800多才可能会构成瓶颈）。
针对I/O设备的性能不足，建议采用如下优化策略：
● 更换性能更好的I/O设备。
● 新增两个独立的相同设备，把MySQL中的redo log、binlog、其他数据文件分别放在三个独立的I/O设备上，以便数据库中的随机I/O和顺序I/O不会因为相互争抢资源而导致等待。
提示：在这个案例中我们故意使用了一台配置很差的服务器。我们可以思考一个问题：performance_schema对于使用MySQL到底能够提供多大的帮助呢？目前来讲，在互联网上并不能找到太多靠谱的performance_schema使用经验，需要我们不断地去挖掘。建议有条件的读者可以准备两台测试服务器（一台低配置、一台高配置），通过对比测试数据就能得出performance_schema的使用经验了，正所谓没有对比就没有伤害。