经过周末两天的折腾,在大家的帮助下最终将用户 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
根据上面收集的信息我们可以清楚的得出以下结论:
经过了上面的分析,我们需要着重查看上述问题的相关变量,变量设置的情况会对性能造成直接的影响,执行结果如下:
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 指的是 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 等相关代码,由于篇幅限制,在此不在详述。
在 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 是 MySQL 的内部诊断器,用于记录 MySQL 在运行期间的各种信息,如表锁情况、mutex 竟争情况、执行语句的情况等,和 Information Schema 类似的是拥用的信息都是内存信息,而不是存在磁盘上的,但和 information_schema 有以下不同点:
由以上的分析不难看出,在性能要求比较高的情况下,关闭 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 删除。
原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。
如有侵权,请联系 cloudcommunity@tencent.com 删除。