畅游数据库性能优化过程简析（上）

原创

musazhang

修改于 2017-08-22 14:56:48

3.3K0

修改于 2017-08-22 14:56:48

前言

经过周末两天的折腾，在大家的帮助下最终将用户 DB 的性能峰值由最初的不到 8W 的 QPS + TPS 提升至 17W，心情也由最初的忐忑过渡到现在的平静，现在想来，整个的优化过程感觉还是比较好玩的，趁着现在还有些印象，就把整个排查 & 优化过程详细的记录下来，以备不时之需，也希望能给人一些启发来解决其它问题，同时，也让俺感谢一下在整个解决过程中给予很多帮助的同事，没有你们在背后的帮助，DB 端解决问题的时间要更久！

问题背景

上周团队聚餐的时候，老大说有一个用户使用 DB 的时候遇到了问题，现有的 DB 性能无法满足用户的性能需求。用户在对现有的 DB 进行压力测试时发现 QPS + TPS 小于 7W/S，继续加大压力的时候 Load 上涨、Idle CPU 很低、Thread running 飙升、性能下降，最终导致网站处理并发能力的下降，无法达到预期的吞吐量。用户在对现有逻辑及吞吐量计算的基础上提出了性能指标，即 DB 的单机性能 QPS + TPS 大于 10W/S，只有这样才能满足业务要求，否则 DB 就是整个链路的瓶颈。由于用户的上线时间临近，上线压力比较大，老大说周末尽力搞定，如果搞不定，只能上最好的机器来解决性能问题，这样的话，成本就要上来了。（当时正在吃饭，瞬间感觉压力山大，不能好好的吃肉了……，有木有……！）

现场信息收集

第二天还没醒就收到老大的消息，然后怀着疑惑的心情火速上线，登录到机器上，开始了 DB 性能的调优之旅……

首先，使用 orzdba 监控工具查看了用户实例的性能状态，如下所示：

-----load-avg---- ---cpu-usage--- ---------QPS---------------TPS------Hit%-----------threads------ 
  1m    5m   15m |usr sys idl iow|  ins   upd   del    sel   iud|     lor    hit| run  con  cre  cac|
99.86 46.70 18.68| 65  25  10   0| 1045  3411     0  62800  4456|  304288 100.00| 251  963    0    0|
99.86 46.70 18.68| 64  25  11   0| 1005  2956     0  64017  2961|  311912 100.00| 299  963    0    0|
99.86 46.70 18.68| 66  25   9   0| 1223  3274     0  64511  4497|  309941 100.00| 325  963    0    0|
99.86 46.70 18.68| 66  24  10   0| 1188  2992     0  64425  4180|  413496 100.00| 331  963    0    0|
97.86 46.70 18.68| 66  24  10   0| 1148  3319     0  63536  4467|  307956 100.00| 262  963    0    0|
97.86 46.70 18.68| 63  25  11   0| 1162  3723     0  64628  4485|  300747 100.00| 306  963    0    0|
97.86 46.70 18.68| 66  25   9   0| 1117  4416     0  64077  5533|  305845 100.00| 273  963    0    0|
96.86 46.70 18.68| 64  24  12   0| 1101  4240     0  63520  5341|  307361 100.00| 234  963    0    0|
96.86 46.70 18.68| 65  25  10   0| 1128  4502     0  62604  5630|  312940 100.00|  52  963    0    0|
96.86 46.92 18.68| 65  25  10   0|  900  4846     0  60648  5746|  298142 100.00| 282  963    0    0|

从上面的性能信息可以发现命中率 100%，即用户基本是全内存操作，thread running 较高，CPU 有少量， thread running 彪升，到底线程在做什么呢？怀着这样的疑问，然后执行了一下 pstack {pid of mysqld} > pid.info 以获取实例的内部线程信息，然后使用 pt-pmp pid.info 将堆栈信息进行显示，发现了如下的信息：

192 __lll_lock_wait(libpthread.so.0),_L_lock_974(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),inline_mysql_mutex_lock(mysql_thread.h:690),lock(mysql_thread.h:690),open_table(mysql_thread.h:690),open_and_process_table(sql_base.cc:4726),open_tables(sql_base.cc:4726),open_normal_and_derived_tables(sql_base.cc:5856),execute_sqlcom_select(sql_parse.cc:5129),mysql_execute_command(sql_parse.cc:2656),mysql_parse(sql_parse.cc:6408),dispatch_command(sql_parse.cc:1340),do_command(sql_parse.cc:1037),do_handle_one_connection(sql_connect.cc:990),handle_one_connection(sql_connect.cc:906),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)
 31 __lll_lock_wait(libpthread.so.0),_L_lock_790(libpthread.so.0),pthread_mutex_lock(libpthread.so.0),rw_pr_wrlock(thr_rwlock.c:397),inline_mysql_prlock_wrlock(mysql_thread.h:984),MDL_map_partition::move_from_hash_to_lock_mutex(mysql_thread.h:984),find_or_insert(mdl.cc:898),MDL_map::find_or_insert(mdl.cc:898),try_acquire_lock_impl(mdl.cc:2033),MDL_context::acquire_lock(mdl.cc:2033),open_table_get_mdl_lock(sql_base.cc:2587),open_table(sql_base.cc:2587),open_and_process_table(sql_base.cc:4726),open_tables(sql_base.cc:4726),open_normal_and_derived_tables(sql_base.cc:5856),execute_sqlcom_select(sql_parse.cc:5129),mysql_execute_command(sql_parse.cc:2656),mysql_parse(sql_parse.cc:6408),dispatch_command(sql_parse.cc:1340),do_command(sql_parse.cc:1037),do_handle_one_connection(sql_connect.cc:990),handle_one_connection(sql_connect.cc:906),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)
    ...
    ...
    1 lfind(libc.so.6),lsearch(lf_hash.c:267),lf_hash_search(lf_hash.c:267),find_or_create_digest(pfs_digest.cc:223),end_statement_v1(pfs.cc:4815),inline_mysql_end_statement(mysql_statement.h:215),dispatch_command(mysql_statement.h:215),do_command(sql_parse.cc:1037),do_handle_one_connection(sql_connect.cc:990),handle_one_connection(sql_connect.cc:906),pfs_spawn_thread(pfs.cc:1860),start_thread(libpthread.so.0),clone(libc.so.6)

根据上述的 pt-pmp & pstack 文件相结合，可以看到如下堆栈：

#0  0x00007fc5f03eef7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007fc5f03ead77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007fc5f03ead20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000006a64e8 in inline_mysql_mutex_lock (src_line=115, src_file=0xc73308 "../sql/table_cache.h", that=0x138d9e0 <table_cache_manager>) at ../include/mysql/psi/mysql_thread.h:690
#4  lock (this=0x138d9e0 <table_cache_manager>) at ../sql/table_cache.h:115
#5  open_table (thd=thd@entry=0x397e5210, table_list=table_list@entry=0x7fbd44004e20, ot_ctx=ot_ctx@entry=0x7fbd740876e0) at ../sql/sql_base.cc:2944
#6  0x00000000006aed49 in open_and_process_table (ot_ctx=0x7fbd740876e0, has_prelocking_list=false, prelocking_strategy=0x7fbd74087920, flags=0, counter=0x397e7050, tables=0x7fbd44004e20, lex=0x397e6fa0, thd=0x397e5210) at ../sql/sql_base.cc:4726
#7  open_tables (thd=thd@entry=0x397e5210, start=start@entry=0x7fbd74087918, counter=0x397e7050, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x7fbd74087920) at ../sql/sql_base.cc:5159
#8  0x00000000006af7fa in open_normal_and_derived_tables (thd=thd@entry=0x397e5210, tables=0x7fbd44004e20, flags=flags@entry=0) at ../sql/sql_base.cc:5856
#9  0x0000000000572a48 in execute_sqlcom_select (thd=thd@entry=0x397e5210, all_tables=<optimized out>) at ../sql/sql_parse.cc:5129
#10 0x00000000006fa010 in mysql_execute_command (thd=thd@entry=0x397e5210) at ../sql/sql_parse.cc:2656

根据上面收集的信息我们可以清楚的得出以下结论：

应用在执行SQL语句的过程中，table_cache_manager 中的锁冲突比较严重；
MySQL Server 层中的 MDL_lock 冲突比较重；
实例开启了 Performance_schema 功能；

经过了上面的分析，我们需要着重查看上述问题的相关变量，变量设置的情况会对性能造成直接的影响，执行结果如下：

MySQL [(none)]> show variables like '%performance_schema'; 
+--------------------+-------+
| Variable_name      | Value |
+--------------------+-------+
| performance_schema | ON    |
+--------------------+-------+
1 row in set (0.00 sec)

MySQL [(none)]> show variables like '%instances';
+-----------------------------------------+--------+
| Variable_name                           | Value  |
+-----------------------------------------+--------+
| innodb_buffer_pool_instances            | 8      |
| metadata_locks_hash_instances           | 8      |
| ........................................|........|
| ........................................|........|
| table_open_cache_instances              | 1      |
+-----------------------------------------+--------+
10 rows in set (0.00 sec)

参数分析

这里我们先来介绍一下上述参数在 MySQL 中的作用 & 含义：

table_open_cache_instances 简介

table_open_cache_instances 指的是 MySQL 缓存 table 句柄的分区的个数，而每一个 cache_instance 可以包含不超过 table_open_cache/table_open_cache_instances 的table_cache_element，详细可以参考官方的说明文档：table_open_cache_instances，MySQL 打开表的过程可以简单的概括为：

1、根据线程的 thread_id 确定线程将要使用的 table_cache，即 thread_id % table_cache_instances; 2、从该 tabel_cache 元素中查找相关系连的 table_cache_element，如果存在转 3，如果不存在转 4； 3、从 2 中查找的table_cache_element 的 free_tables 中出取一个并返回，并调整 table_cache_element 中的 free_tables & used_tables 元素； 4、如果 2 中不存在，则重新创建一个 table, 并加入对应的 table_cache_element 的 used_tables的列表；

从以上过程可以看出，MySQL 在打开表的过程中会首先从 table_cache 中进行查找有没有可以直接使用的表句柄，有则直接使用，没有则会创建并加入到对应的 table_cache 中对应的 table_cache_element 中，从刚才提取的现场信息来看，有大量的线程在查找 table_cache 的过程中阻塞着了，而 table_open_cache_instances 的个数为 1，因此，此参数的设置需要调整，由于 table_open_cache_instances 的大小和线程 ID & 并发有关系，考虑当前的并发是1000左右，于是将该植设置为 32；

MySQL 中不同的线程虽然使用各自的 table 句柄，但是共享着同一个table_share，如果想从源码上了解 table & table_share 以及两者之间的相互，可以从变量 table_open_cache， table_open_cache_instances，table_definition_cache 入手，阅读 Table_cache_manager， Table_cache， Table_cache::get_table 等相关代码，由于篇幅限制，在此不在详述。

MDL Lock 的前世今生

在 5.1 中有一个 binlog log 乱序的问题，详情及复现方法可以参考这篇文章：alter table rename 操作导致复制中断，MDL_LOCK 就是为了解决上述问题而在 5.5 中引入的。简单的说 MDL Lock 是 MySQL Server 层中的表锁，主要是为了控制 Server 层 DDL & DML 的并发而设计的，但是 5.5 的设计中只有一把大锁，所以到5.6中添加了参数 metadata_locks_hash_instances 来控制分区的数量，进而实现大锁的拆分，虽然锁的拆分提高了并发的性能，但是仍然存在着不少的性能问题，所以在 5.7.4 中 MDL Lock 的实现方式采用了 lock free 算法，彻底的解决了 Server 层表锁的性能问题，而参数 metadata_locks_hash_instances 也将会在之后的某个版本中被删除掉；

参考文档：metadata_locks_hash_instances

由于实例中的表的数目比较多，而 metadata_locks_hash_instances 的参数设置仅为8，因此，为了将底锁的冲突的可能性，我们将此值设置为 32；

Performance Schema 作用 & 影响

通俗的说，performance schema 是 MySQL 的内部诊断器，用于记录 MySQL 在运行期间的各种信息，如表锁情况、mutex 竟争情况、执行语句的情况等，和 Information Schema 类似的是拥用的信息都是内存信息，而不是存在磁盘上的，但和 information_schema 有以下不同点：

information_schema 中的信息都是从 MySQL 的内存对象中读出来的，只有在需要的时候才会读取这些信息，如 processlist, profile, innodb_trx 等，不需要额外的存储或者函数调用，而 performance schema 则是通过一系列的回调函数来将这些信息额外的存储起来，使用的时候进行显示，因此 performance schema 消耗更多的 CPU & memory 资源；
Information_schema 中的表是没有表定义文件的，表结构是在内存中写死的，而 performation_schema 中的表是有表定义文件的；
实现方式不同，Information_schema 只是对内存的 traverse copy, 而 performance_schema 则使用固定的接口来进行实现；
作用不同，Information_schema 主要是轻量级的使用，即使在使用的时候也很少会有性能影响，performance_schema 则是 MySQL 的内部监控系统，可以很好的定位性能问题，但也很影响性能；

由以上的分析不难看出，在性能要求比较高的情况下，关闭 performance_schema 是一个不错的选择，因此将 performance_schema 关闭。另外关闭 performance_schema 的一个原因则是因为它本身的稳定性，因为之前在使用 performance_schema 的过程中遇到了不稳定的问题，当然，遇到一个问题我们就会修复一个，只是考虑到性能问题，我们暂时将其关闭。

Performance_schema 的详细使用说明可以参考：

performance_schema 中文文档 MySQL_Performance_Schema 官方文档

经过上面的分析和判断，我们对参数做了如下的调整：

table_open_cache_instances=32
metadata_locks_hash_instances=32
performance_schema=OFF
innodb_purge_threads=4

勉强解决问题

调整了以上参数后，我们重启实例，然后要求客户做新一轮的压力测试，测试部分数据如下：

-----load-avg---- ---cpu-usage--- ---------QPS---------------TPS------Hit%-----------threads------ 
  1m    5m   15m |usr sys idl iow|  ins   upd   del    sel   iud|     lor     hit| run  con  cre  cac|
 9.91  2.75  3.16| 24  14  62   0|    0  3698     0   87124  3698|  304288 100.00|  23  963    0    0|
 9.91  2.75  3.16| 41  24  35   0|    0  7191     0  124506  7191|  311912 100.00|  20  963    0    0|
12.48  3.41  3.37| 45  24  31   0|  352  8547     0  122248  8899|  309941 100.00|  35  963    0    0|
12.48  3.41  3.37| 55  27  18   0| 1514  7338     0  118130  8852|  413496 100.00| 217  963    0    0|
12.48  3.41  3.49| 60  27  13   0| 1815  6778     0  108114  8593|  307956 100.00|  20  963    0    0|
12.48  3.41  3.49| 58  25  17   0| 1909  7575     0  102566  9484|  300747 100.00|  17  963    0    0|
12.48  3.78  3.49| 57  23  20   0| 2022  7893     0  101197  9915|  305845 100.00|  21  963    0    0|
13.86  3.78  3.68| 58  26  16   0| 1732  7498     0  104869  9230|  307361 100.00|  27  963    0    0|
13.86  4.38  3.68| 57  24  19   0| 2067  6093     0  106261  8160|  312940 100.00|  33  963    0    0|
15.86  4.38  3.68| 57  24  19   0| 2008  5661     0  102623  7669|  298142 100.00|  12  963    0    0|

从以上的测试数据来看， QPS + TPS > 10W 已经满足要求，通过 perf top -p {pidof mysqld} 命令查看了一下系统负载，发现了一处比较吃 CPU 的地方 ut_delay，详情如下：

20.69%  mysqld               [.] ut_delay(unsigned long)
  4.86%  mysqld               [.] my_hash_sort_utf8
  3.94%  mysqld               [.] mutex_spin_wait(ib_mutex_t*, char const*, unsigned long)
  3.59%  mysqld               [.] read_view_open_now_low(unsigned long, mem_block_info_t*)
  3.13%  [kernel]             [k] _raw_spin_lock
  3.05%  mysqld               [.] my_ismbchar_utf8
  2.77%  mysqld               [.] my_charpos_mb
  2.29%  mysqld               [.] my_strnxfrm_unicode
  1.80%  mysqld               [.] MYSQLparse(THD*)
  1.61%  libc-2.17.so         [.] __memcpy_ssse3_back
  1.58%  libpthread-2.17.so   [.] pthread_mutex_lock
  0.73%  mysqld               [.] row_search_for_mysql(unsigned char*, unsigned long, row_prebuilt_t*, unsigned long, unsigned long)
  0.73%  mysqld               [.] my_convert
  0.71%  libc-2.17.so         [.] _int_malloc

使用 perf record & perf report 进行分析，发现调用比较多的地方是： mutex_spin_wait，于是断定 Innodb 底层资源冲突比较严重，根据以往的经验执行如下命令：

mysql> show variables like '%spin%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| innodb_spin_wait_delay | 10000 |
| innodb_sync_spin_loops | 30    |
+------------------------+-------+
2 rows in set (5.55 sec)

在 MySQL 内部，当 innodb 线程获取 mutex 资源而得不到满足时，会最多进行 innodb_sync_spin_loops 次尝试获取 mutex 资源，每次失败后会调用 ut_delay(ut_rnd_interval(0, srv_spin_wait_delay)，导致 ut_delay 占用了过多的 CPU，其中 ut_delay 的定义如下：

/*************************************************************//**
Runs an idle loop on CPU. The argument gives the desired delay
in microseconds on 100 MHz Pentium + Visual C++.
@return dummy value */
UNIV_INTERN
ulint
ut_delay(
/*=====*/
        ulint   delay)  /*!< in: delay in microseconds on 100 MHz Pentium */
{
        ulint   i, j;
        j = 0;
        for (i = 0; i < delay * 50; i++) {
                j += i;
                UT_RELAX_CPU();
        }
        if (ut_always_false) {
                ut_always_false = (ibool) j;
        }

        return(j);
}

由于这两个值的设定取决于实例的负载以及资源的竟争情况，所以不断的尝试设置这两个参数的值，经过多次的尝试最终将这两个参数分别设置为：innodb_spin_wait_delay = 6， innodb_sync_spin_loops = 20 (请注意这两个值不是推荐值！！！) 才将 ut_delay 的占用资源降下来，最终降低了不必要的 CPU 消耗的同时 idle cpu 也稳定在了 20+，具体资源占用详情如下：

6.52%  mysqld               [.] my_hash_sort_utf8
  3.93%  [kernel]             [k] _raw_spin_lock
  3.82%  mysqld               [.] my_ismbchar_utf8
  3.65%  mysqld               [.] my_charpos_mb
  3.31%  mysqld               [.] my_strnxfrm_unicode
  3.09%  mysqld               [.] ut_delay(unsigned long)
  2.58%  mysqld               [.] read_view_open_now_low(unsigned long, mem_block_info_t*)
  2.38%  mysqld               [.] MYSQLparse(THD*)
  1.91%  libc-2.17.so         [.] __memcpy_ssse3_back
  1.89%  mysqld               [.] mutex_spin_wait(ib_mutex_t*, char const*, unsigned long)
  1.79%  libpthread-2.17.so   [.] pthread_mutex_lock

优化到这个地步似乎达到了客户要求的性能，即 DB 单机性能为 QPS + TPS > 10W，可是如果并发量在加大，我们的 DB 能扛住更高的压力吗？

又起波澜

经过上面参数的调整，DB 已经不是性能的瓶颈，应用的吞吐量由之前的 1100 -> 1400+，但是离 2000 的吞吐量还比较远，瓶颈出现在了应用端，为了增加吞吐量，客户又增加了几台客户端机器，连接数也由之前的 900+ 上升到 1000+，此时发现 DB 虽然能够响应，但偶尔会出现 thread running 飙高的情况，具体运行状态如下，其中 mysql_com_tps = (mysql_com_insert + mysql_com_update + mysql_com_delete)：

+---------------------+--------+---------+------------------+------------------+------------------+------------------+---------------+-----------------+---------------------+
| dtime               | load_1 | idlecpu | mysql_com_insert | mysql_com_update | mysql_com_delete | mysql_com_select | mysql_com_tps | threads_running | threads_connections |
+---------------------+--------+---------+------------------+------------------+------------------+------------------+---------------+-----------------+---------------------+
| 2016-07-03 21:48:24 |   5.78 |   30.00 |             1706 |             6573 |                0 |            97359 |          8279 |              25 |                1011 |
| 2016-07-03 21:48:25 |   5.78 |   41.00 |             1606 |             7018 |                0 |            98273 |          8624 |              17 |                1011 |
| 2016-07-03 21:48:26 |   5.78 |   33.00 |             1616 |             5739 |                0 |            93752 |          7355 |             108 |                1011 |
| 2016-07-03 21:48:27 |   5.78 |   39.00 |             1505 |             6436 |                0 |            91381 |          7941 |              12 |                1011 |
| 2016-07-03 21:48:28 |   8.20 |   36.00 |             1849 |             4514 |                0 |            87881 |          6363 |             156 |                1011 |
| 2016-07-03 21:48:29 |   8.20 |   28.00 |             1702 |             6386 |                0 |            97621 |          8088 |              35 |                1011 |
| 2016-07-03 21:48:30 |   8.20 |   42.00 |             1442 |             6708 |                0 |            94920 |          8150 |              24 |                1011 |
| 2016-07-03 21:48:31 |   8.20 |   28.00 |             1399 |             8283 |                0 |            98801 |          9682 |             189 |                1011 |
| 2016-07-03 21:48:32 |   8.20 |   28.00 |             1254 |             7960 |                0 |            90461 |          9214 |             137 |                1011 |
| 2016-07-03 21:48:33 |   9.86 |   23.00 |             1039 |             7557 |                0 |            92145 |          8596 |             193 |                1011 |
| 2016-07-03 21:48:34 |   9.86 |   36.00 |             1358 |             7696 |                0 |            85274 |          9054 |             301 |                1011 |
| 2016-07-03 21:48:35 |   9.86 |   39.00 |             1069 |             8148 |                0 |            80185 |          9217 |             346 |                1011 |
| 2016-07-03 21:48:36 |   9.86 |   44.00 |             1019 |             8484 |                0 |            77787 |          9503 |             378 |                1011 |
| 2016-07-03 21:48:37 |   9.86 |   41.00 |             1023 |             7290 |                0 |            74965 |          8313 |             341 |                1011 |
| 2016-07-03 21:48:38 |  10.36 |   39.00 |              987 |             8031 |                0 |            83857 |          9018 |             279 |                1011 |
| 2016-07-03 21:48:39 |  10.36 |   39.00 |             1108 |             7165 |                0 |            84070 |          8273 |             255 |                1011 |
| 2016-07-03 21:48:40 |  10.36 |   42.00 |             1219 |             5804 |                0 |            80959 |          7023 |              22 |                1011 |
| 2016-07-03 21:48:41 |  10.36 |   40.00 |             1034 |             6546 |                0 |            82380 |          7580 |             296 |                1011 |
| 2016-07-03 21:48:42 |  10.36 |   41.00 |              809 |             5973 |                0 |            79554 |          6782 |             319 |                1011 |
| 2016-07-03 21:48:43 |  10.65 |   39.00 |              949 |             7252 |                0 |            79690 |          8201 |             312 |                1011 |

接下文：《畅游数据库性能优化过程简析（下）》

原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。

如有侵权，请联系 cloudcommunity@tencent.com 删除。

数据库

云数据库 SQL Server

原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。

如有侵权，请联系 cloudcommunity@tencent.com 删除。

数据库

云数据库 SQL Server

登录后参与评论

0 条评论

热度