畅游数据库性能优化过程简析(下)

接上文《畅游数据库性能优化过程简析(上)》

查找问题原因

Thread running 的偶尔飙升引起了我的注意,说明内部必然有冲突,随着压力和并发量的不断增大,应用可能会受到类似之前的影响,因此很有必要查看其中的原因并尽最大的努力解决之。通过仔细的观察 thread running & mysql com 信息,当 thread running 较高 & com 信息较低的时候,执行了 pt-pmp -p {pid of mysqld},抓到了以下信息:

Wed Jul  6 14:21:22 CST 2016
    179 pthread_cond_wait,os_cond_wait(os0sync.cc:214),os_event_wait_low(os0sync.cc:214),sync_array_wait_event(sync0arr.cc:424),mutex_spin_wait(sync0sync.cc:580),mutex_enter_func(sync0sync.ic:218),pfs_mutex_enter_func(sync0sync.ic:218),read_view_remove(sync0sync.ic:218),read_view_close_for_mysql(sync0sync.ic:218),ha_innobase::external_lock(ha_innodb.cc:12326),handler::ha_external_lock(handler.cc:7190),unlock_external(lock.cc:646),mysql_unlock_tables(lock.cc:389),mysql_unlock_some_tables(lock.cc:389),JOIN::optimize(sql_optimizer.cc:406),mysql_execute_select(sql_select.cc:1087),mysql_select(sql_select.cc:1087),handle_select(sql_select.cc:110),execute_sqlcom_select(sql_parse.cc:5156),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)
    150 pthread_cond_wait,os_cond_wait(os0sync.cc:214),os_event_wait_low(os0sync.cc:214),sync_array_wait_event(sync0arr.cc:424),mutex_spin_wait(sync0sync.cc:580),mutex_enter_func(sync0sync.ic:218),pfs_mutex_enter_func(sync0sync.ic:218),read_view_open_now(sync0sync.ic:218),trx_assign_read_view(trx0trx.cc:1481),row_search_for_mysql(row0sel.cc:4090),ha_innobase::index_read(ha_innodb.cc:7516),handler::index_read_idx_map(handler.cc:6846),handler::ha_index_read_idx_map(handler.cc:2787),join_read_(handler.cc:2787),join_read__table(handler.cc:2787),make_join_statistics(sql_optimizer.cc:3592),JOIN::optimize(sql_optimizer.cc:363),mysql_execute_select(sql_select.cc:1087),mysql_select(sql_select.cc:1087),handle_select(sql_select.cc:110),execute_sqlcom_select(sql_parse.cc:5156),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)
      7 __lll_lock_wait(libpthread.so.0),_L_cond_lock_973(libpthread.so.0),__pthread_mutex_cond_lock(libpthread.so.0),pthread_cond_wait,os_cond_wait(os0sync.cc:214),os_event_wait_low(os0sync.cc:214),sync_array_wait_event(sync0arr.cc:424),mutex_spin_wait(sync0sync.cc:580),mutex_enter_func(sync0sync.ic:218),pfs_mutex_enter_func(sync0sync.ic:218),read_view_open_now(sync0sync.ic:218),trx_assign_read_view(trx0trx.cc:1481),row_search_for_mysql(row0sel.cc:4090),ha_innobase::index_read(ha_innodb.cc:7516),handler::index_read_idx_map(handler.cc:6846),handler::ha_index_read_idx_map(handler.cc:2787),join_read_(handler.cc:2787),join_read__table(handler.cc:2787),make_join_statistics(sql_optimizer.cc:3592),JOIN::optimize(sql_optimizer.cc:363),mysql_execute_select(sql_select.cc:1087),mysql_select(sql_select.cc:1087),handle_select(sql_select.cc:110),execute_sqlcom_select(sql_parse.cc:5156),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 operator(read0read.cc:296),ut_list_map<ut_list_base<trx_t>,(read0read.cc:296),read_view_open_now_low(read0read.cc:296),read_view_open_now(read0read.cc:388),trx_assign_read_view(trx0trx.cc:1481),row_search_for_mysql(row0sel.cc:4090),ha_innobase::index_read(ha_innodb.cc:7516),handler::index_read_idx_map(handler.cc:6846),handler::ha_index_read_idx_map(handler.cc:2787),join_read_(handler.cc:2787),join_read__table(handler.cc:2787),make_join_statistics(sql_optimizer.cc:3592),JOIN::optimize(sql_optimizer.cc:363),mysql_execute_select(sql_select.cc:1087),mysql_select(sql_select.cc:1087),handle_select(sql_select.cc:110),execute_sqlcom_select(sql_parse.cc:5156),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)
      ...
      ...

从上面的现场信息不难看出有很大一部分线程是在执行 read_view 的相关操作中被阻塞着了,那么什么是 read view,它的作用是什么,为什么会有大量的线程执行这个操作的时候被阻塞呢?

什么是 read view

read view 又称读视图,用于存储事务创建时的活跃事务集合。当事务创建时,线程会对 trx_sys 上全局锁,然后遍历当前活跃事务列表,将当前活跃事务的ID存储在数组中的同时,记录最大事务 low_limit_id & 最小事务 high_limit_id & 最小序列化事务 low_limit_no。

read view 的作用是什么

Innodb record 格式包含 {记录头,主建,Trx_id,roll_ptr, extra_column} 等信息。

当事务执行时,凡是大于low_limit_id 的数据对于事务是不可见的,凡是事务小于 high_limit_id 的数据都是可见的,事务 ID 是 read_view 数组中的某一个时也是不可见的,Purge thread 在执行 Purge 操作时,凡是小于 low_limit_no 的数据,都是可以被 Purge 的,因此, read view 是 MySQL MVCC 实现的基础;

为什么会有大量的线程阻塞

事务创建时的步骤如下:

  • 对 trx_sys->mutex 全局上锁;
  • 顺序扫描 trx_sys->rw_trx_list,对 read_view 中的元素分配内存并进行赋值,主要包括活跃事务ID的集合的创建,low_limit_id , high_limit_id, low_limit_no 等;
  • 将该 read_view 添加到有序列表 trx_sys->view_list中;
  • 释放 trx_sys->mutex 锁;

由于read_view 的创建和销毁都需要获取 trx_sys->mutex, 当并发量很大的时候,事务链表会比较长,又由于遍历本身也是一个费时的工作,所以此处便成为了瓶颈,既然我们遇到了这个问题,那么社区应该也有类似的问题。

read view 问题解决过程

首先,我们看一下bug#49169,read_view_open_now is inefficient with many concurrent sessions, 即当并发量很大时 read_view_open_now 效率低下的问题,问题的原因主要有以下几个:

  • 整个创建过程一直持有 trx_sys->mutex 锁;
  • read_view 的内存在每次创建中被分配,事务提交后被释放;
  • 需要遍历 trx_sys->trx_list (5.5) 或 trx_sys->rw_list (5.6);
  • 并发较大,活跃事务链表过长时,会在 trx_sys->mutex 上有较大的消耗;

该 bug 从 MySQL 5.1 的时候被 mrak 大神提出以来,一直到 MySQL 5.7 才被官方完整的解决,其中的解决过程也挺曲折的,另外 Percona 在 5.5 的时候就也推出了解决问题的办法,实现也相对简单好多,但没有 MySQL 5.7 方法的彻底,咱们分别看一下这两种解决方法以及 CDB 内核在这方面的改动。

Percona read view 问题改进

Percona 为了解决上述描述的问题,对trx_sys做了以下修改:

  • 在 trx_sys下维护一个全局的事务ID的有序集合,事务的 创建 & 销毁 的同时将事务的 ID 从这个集合中移除;
  • 在 trx_sys下维护一个有序的已分配序列号的事务列表,已记录拥有最小序列号的事务,供 purge 时使用;
  • 减少不必要的内存分配,为每一个 trx_t 缓存一个 read_view,read_view 数组的大小根据创建时的活跃全局事务 ID 集合做必要的调整;

做了上面的调整后,事务在创建过程中则不需要遍历 trx_sys->trx_list(version 5.5),直接使用 memcpy 即可获得活跃事务的ID,并且缓存的使用也大大减少了内存的不必要分配;

更详细的信息及源码可以参考 Alexey (sysbench owner, MySQL 另一大神)提交的代码,commit message 详情如下:

commit e1365c91d04347f1063f8e5a22c1ba2501c4f0d0
Author: Alexey Kopytov <akopytov@gmail.com>
Date:   Mon Mar 25 13:59:39 2013 +0400

    Bug #1131189: Remove trx_list scan from read_view_open_now()

    The patch introduces a concept if "trx descriptors" which is a global
    ordered array containing IDs of transactions in either TRX_ACTIVE or
    TRX_PREPARED state. It allows to replace the trx_list scan in
    read_view_open_now() and read_cursor_view_create_for_mysql() with a
    binary search on the descriptors array and two memcpy()s.

    Goals of using the ID array of transactions in certain states:

MySQL read view 问题改进

为了解决 read view 问题,5.6 做了以下几件事情:

  • 将 5.5 的 trx_list 拆分为 ro_trx_list & rw_trx_list, 由于只读事务不会对数据进行修改,所以在创建视图的同时就只需要扫描 rw_trx_list 即可;
  • auto-commit-non-locking-ro transactions 的特殊优化;
  • 添加语法 START TRANSACTION READ ONLY 用于声名事务是只读事务;

经过上面的修改,似乎解决了 read view 的问题,但实际却不然,因为他只是解决了事务链表的长度,创建时遍历&内存消耗的开销是没有解决的,并且使用上述特性需要修改应用程序,这一点是比较困难的,因此,5.7为了彻底的解决 read view 的性能问题,做了以下事情:

1. Refactor the MVCC code
  2. Reuse read views for AC-NL-RO selects
  3. Use a pool of read views
  4. Add MVCC class
  5. Use a trx_id to trx_t* map
  6. Keep the active trx_id_ts in a vector.
  7. Pre-allocate a small cache of record and table locks
  8. Avoid extra work when a transaction is tagged as read-only (during commit).
  9. General code cleanup
  10. Get rid of trx_sys_t::ro_trx_list. Adding and removing a transaction from the ro_trx_list is very costly.

经过了上面的代码重构,5.7 中很少看到 trx_sys->mutex 的性能瓶颈,有想更详细了解的同学可以看一下这些内容:

WL#6047: http://dev.mysql.com/worklog/task/?id=6047 
 http://bazaar.launchpad.net/~mysql/mysql-server/5.7/revision/5209

 WL#6578: http://dev.mysql.com/worklog/task/?id=6578 (部分类似于 Percona 5.6)
 http://bazaar.launchpad.net/~mysql/mysql-server/5.7/revision/6203
 http://bazaar.launchpad.net/~mysql/mysql-server/5.7/revision/6204
 http://bazaar.launchpad.net/~mysql/mysql-server/5.7/revision/6205
 http://bazaar.launchpad.net/~mysql/mysql-server/5.7/revision/6224
 http://bazaar.launchpad.net/~mysql/mysql-server/5.7/revision/6236
 http://bazaar.launchpad.net/~mysql/mysql-server/5.7/revision/6788

CDB read view 问题改进

为了解决 Read view 的性能问题,简单的说 CDB 内核团队对于Read view 主要做了以下事情:

  • backport percona 的 read view 相关修改到 CDB MySQL中;
  • 参照 5.7 的实现,在 5.6 中将 ro_trx_list 移除;

经过上面的修改彻底的解决了 read_view 的性能问题,在经历了大量 稳定性测试 & 性能测试 后,目前灰度发布中。

线上效果

鉴于当前存在的问题,为了解决客户的燃眉之急,决定上一个新版本,和客户联系后,可以重启实例,然后进行了替换操作,替换后的性能效果如下,可以看到 cpu 使用率、load、thread running 降低的同时 QPS + TPS 性能上升,至此问题真正觉得问题应该解决了,余下的就是等客户的反馈了。

+---------------------+--------+---------+------------------+------------------+------------------+------------------+---------------+-----------------+---------------------+
| 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 22:21:31 |   1.54 |   37.00 |             1995 |             8194 |                0 |           125782 |         10189 |              18 |                1012 |
| 2016-07-03 22:21:32 |   1.54 |   37.00 |             2205 |             8016 |                0 |           125974 |         10221 |              17 |                1012 |
| 2016-07-03 22:21:33 |   1.54 |   49.00 |             2061 |             5758 |                0 |           106469 |          7819 |              25 |                1012 |
| 2016-07-03 22:21:34 |   1.54 |   38.00 |             2450 |             7565 |                0 |           127511 |         10015 |              18 |                1012 |
| 2016-07-03 22:21:35 |   3.66 |   39.00 |             2121 |             6644 |                0 |           128277 |          8765 |              27 |                1012 |
| 2016-07-03 22:21:36 |   3.66 |   41.00 |             2617 |             5966 |                0 |           127987 |          8583 |              22 |                1012 |
| 2016-07-03 22:21:37 |   3.66 |   43.00 |             2009 |             6564 |                0 |           124135 |          8573 |              16 |                1012 |
| 2016-07-03 22:21:38 |   3.66 |   43.00 |             2294 |             5783 |                0 |           123519 |          8077 |              15 |                1012 |
| 2016-07-03 22:21:39 |   4.65 |   45.00 |             2050 |             6931 |                0 |           123719 |          8981 |              13 |                1012 |
| 2016-07-03 22:21:40 |   4.65 |   51.00 |             2039 |             5028 |                0 |           107993 |          7067 |              14 |                1012 |
| 2016-07-03 22:21:41 |   4.65 |   49.00 |             2041 |             5153 |                0 |           110077 |          7194 |              23 |                1012 |
| 2016-07-03 22:21:42 |   4.65 |   49.00 |             2215 |             5347 |                0 |           108539 |          7562 |              24 |                1012 |
| 2016-07-03 22:21:43 |   4.65 |   40.00 |             2000 |             7564 |                0 |           128957 |          9564 |              21 |                1012 |
| 2016-07-03 22:21:45 |   6.84 |   40.00 |             2218 |             6579 |                0 |           129526 |          8797 |              17 |                1012 |
| 2016-07-03 22:21:46 |   6.84 |   49.00 |             1859 |             5800 |                0 |           111708 |          7659 |              18 |                1012 |
| 2016-07-03 22:21:47 |   6.84 |   40.00 |             2098 |             6149 |                0 |           129089 |          8247 |              14 |                1012 |
| 2016-07-03 22:21:48 |   6.84 |   50.00 |             1761 |             4910 |                0 |           112003 |          6671 |              24 |                1012 |
| 2016-07-03 22:21:49 |   6.84 |   40.00 |             2283 |             7195 |                0 |           129313 |          9478 |              20 |                1012 |
| 2016-07-03 22:21:50 |   6.85 |   39.00 |             2394 |             6057 |                0 |           128982 |          8451 |              11 |                1012 |
| 2016-07-03 22:21:51 |   6.85 |   40.00 |             2160 |             5727 |                0 |           128516 |          7887 |              17 |                1012 |
| 2016-07-03 22:21:52 |   6.85 |   41.00 |             2405 |             5628 |                0 |           129897 |          8033 |              16 |                1012 |
| 2016-07-03 22:21:53 |   6.85 |   38.00 |             2072 |             7064 |                0 |           129313 |          9136 |              21 |                1012 |

将监控数据入库,查看峰值 & 当时的负载情况,详情如下:

MySQL [sysbench]> select dtime, (mysql_com_tps + mysql_com_select) as total_requests, mysql_com_select, mysql_com_tps, innodb_rows_update, idlecpu,threads_running from ip_10_108_107_97 order by total_requests desc;
+---------------------+----------------+------------------+---------------+--------------------+---------+-----------------+
| dtime               | total_requests | mysql_com_select | mysql_com_tps | innodb_rows_update | idlecpu | threads_running |
+---------------------+----------------+------------------+---------------+--------------------+---------+-----------------+
| 2016-07-03 22:15:17 |         170396 |           138029 |         32367 |              32357 |   44.00 |              19 |
| 2016-07-03 22:16:34 |         165842 |           136566 |         29276 |              28919 |   41.00 |              17 |
| 2016-07-03 22:15:14 |         164890 |           135873 |         29017 |              29007 |   43.00 |              16 |
| 2016-07-03 22:15:13 |         163007 |           131839 |         31168 |              31172 |   48.00 |              17 |
| 2016-07-03 22:15:16 |         162658 |           135986 |         26672 |              26687 |   44.00 |              13 |
| 2016-07-03 22:16:37 |         159783 |           134070 |         25713 |              25654 |   45.00 |              12 |
| 2016-07-03 22:16:35 |         156849 |           131101 |         25748 |              25609 |   44.00 |              23 |
| 2016-07-03 22:22:40 |         150488 |           129765 |         20723 |              19930 |   42.00 |              17 |
| 2016-07-03 22:22:38 |         148860 |           130581 |         18279 |              16767 |   39.00 |              25 |
| 2016-07-03 22:22:39 |         148797 |           131086 |         17711 |              16386 |   40.00 |              22 |
| 2016-07-03 22:16:36 |         148189 |           128710 |         19479 |              19418 |   44.00 |              21 |
| 2016-07-03 22:22:36 |         146731 |           129747 |         16984 |              14649 |   38.00 |              21 |
| 2016-07-03 22:22:37 |         145356 |           129450 |         15906 |              13810 |   39.00 |              24 |
| 2016-07-03 21:20:12 |         145331 |           128423 |         16908 |              15068 |   44.00 |              19 |
| 2016-07-03 21:20:10 |         145252 |           131791 |         13461 |              10909 |   43.00 |              10 |
| 2016-07-03 21:20:14 |         145200 |           127102 |         18098 |              17107 |   48.00 |              18 |
| 2016-07-03 21:19:09 |         144442 |           135123 |          9319 |               5555 |   42.00 |              19 |
| 2016-07-03 22:22:34 |         144181 |           129076 |         15105 |              12345 |   39.00 |              16 |
| 2016-07-03 22:22:33 |         143299 |           129232 |         14067 |              11302 |   39.00 |              15 |
| 2016-07-03 22:23:44 |         142831 |           130274 |         12557 |              10118 |   42.00 |              21 |
| 2016-07-03 21:19:10 |         142181 |           131958 |         10223 |               6051 |   43.00 |              18 |
| 2016-07-03 21:21:02 |         142168 |           120097 |         22071 |              21667 |   44.00 |              16 |

遗留问题 & 展望

真的完美了吗,其实不是这样的,我们还有很多的事情要做,因为在解决问题的过程中,我们通过 pstack & pt-pmp 抓到了很多有用的信息,有一些是暂时没有解决的,如:

  • innodb 内部表锁冲突严重;
  • MDL Lock 即使扩大也存在着不小的影响;
  • 内存分配也有一些需要优化的地方;
  • 执行计划的计算代价比较高;
  • thread running 彪高时没有可以控制的方法;
  • ….

由于时间问题我们暂时将遇到的问题一一记下,一个一个解决,我们相信 CDB 的内核会越来越强大,在提升性能的同时也不断的提升稳定性,我们一步一步踏在当下,努力让 CDB 变得更好!

原创声明,本文系作者授权云+社区发表,未经许可,不得转载。

如有侵权,请联系 yunjia_community@tencent.com 删除。

编辑于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏IT大咖说

饿了么资深Android工程师带你领略Kotlin协程的力量

内容来源:2018 年 6 月 28 日,饿了么资深Android工程师张涛在“droidcon上海2018安卓技术大会”进行《领略kotlin协程的力量》演讲...

1154
来自专栏Java帮帮-微信公众号-技术文章全总结

Oracle应用开发实战一

Oracle介绍 ORACLE数据库系统是美国ORACLE公司(甲骨文)提供的以分布式 数据库为核心的一组软件产品,是目前最流行的客户/服务器(CLIENT/S...

2776
来自专栏LET

Web Workers实践(2)

1379
来自专栏Linyb极客之路

Redis开发常用规范

虽然Redis支持持久化,但是Redis的数据存储全部都是在内存中的,成本昂贵。建议根据业务只将高频热数据存储到Redis中【QPS大于5000】,对于低频冷数...

842
来自专栏码洞

深入Python多进程编程基础

多进程编程知识是Python程序员进阶高级的必备知识点,我们平时习惯了使用multiprocessing库来操纵多进程,但是并不知道它的具体实现原理。下面我对多...

472
来自专栏XAI

SpringMVC+MongoDB+Maven整合(微信回调Oauth授权)

个人小程序。里面是基于百度大脑 腾讯优图做的人脸检测。是关于人工智能的哦。 2017年第一篇自己在工作中的总结文档。土豪可以打赏哦。 https://git.o...

5877
来自专栏Android 研究

Android跨进程通信IPC之1——Linux基础

由于Android系统是基于Linux系统的,所以有必要简单的介绍下Linux的跨进程通信,对大家后续了解Android的跨进程通信是有帮助的,本篇的主要内容如...

953
来自专栏Spark学习技巧

大数据基础系列之kafkaConsumer010+的多样demo及注意事项

一,KafkaConsumer使用要点解释 1,基本介绍 该客户端用户透明的处理kafka Broker的失败,透明的适应topic在集群中的迁移。这种客户端也...

2588
来自专栏CSDN技术头条

如何用 Redis 实现延时任务?

延时任务,顾名思义,就是延迟一段时间后才执行的任务。延时任务的使用还是很广泛的。关于延时任务的实现方式,我知道的就不少 3 种,今天就讲下如何用 redis 实...

1051
来自专栏数据和云

高频错误:ORA-01555深入剖析

黄玮(Fuyuncat) 资深Oracle DBA,个人网站www.HelloDBA.com,致力于数据库底层技术的研究,其作品获得广大同行的高度评价. ORA...

2878

扫码关注云+社区