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 又称读视图,用于存储事务创建时的活跃事务集合。当事务创建时,线程会对 trx_sys 上全局锁,然后遍历当前活跃事务列表,将当前活跃事务的ID存储在数组中的同时,记录最大事务 low_limit_id & 最小事务 high_limit_id & 最小序列化事务 low_limit_no。
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 实现的基础;
事务创建时的步骤如下:
由于read_view 的创建和销毁都需要获取 trx_sys->mutex, 当并发量很大的时候,事务链表会比较长,又由于遍历本身也是一个费时的工作,所以此处便成为了瓶颈,既然我们遇到了这个问题,那么社区应该也有类似的问题。
首先,我们看一下bug#49169,read_view_open_now is inefficient with many concurrent sessions, 即当并发量很大时 read_view_open_now 效率低下的问题,问题的原因主要有以下几个:
该 bug 从 MySQL 5.1 的时候被 mrak 大神提出以来,一直到 MySQL 5.7 才被官方完整的解决,其中的解决过程也挺曲折的,另外 Percona 在 5.5 的时候就也推出了解决问题的办法,实现也相对简单好多,但没有 MySQL 5.7 方法的彻底,咱们分别看一下这两种解决方法以及 CDB 内核在这方面的改动。
Percona 为了解决上述描述的问题,对trx_sys做了以下修改:
做了上面的调整后,事务在创建过程中则不需要遍历 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:
为了解决 read view 问题,5.6 做了以下几件事情:
经过上面的修改,似乎解决了 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
为了解决 Read view 的性能问题,简单的说 CDB 内核团队对于Read view 主要做了以下事情:
经过上面的修改彻底的解决了 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 抓到了很多有用的信息,有一些是暂时没有解决的,如:
由于时间问题我们暂时将遇到的问题一一记下,一个一个解决,我们相信 CDB 的内核会越来越强大,在提升性能的同时也不断的提升稳定性,我们一步一步踏在当下,努力让 CDB 变得更好!
原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。
如有侵权,请联系 cloudcommunity@tencent.com 删除。
原创声明:本文系作者授权腾讯云开发者社区发表,未经许可,不得转载。
如有侵权,请联系 cloudcommunity@tencent.com 删除。