测试场景MySQL 5.7.12主要测试 不同刷盘参数 对性能的影响, 使用以下三个场景:sync_binlog=1, innodb_flush_log_at_trx_commit=1, 简写为b1e1 (binlog-1-engine-1)sync_binlog=0, innodb_flush_log_at_trx_commit=1, 简写为b0e1sync_binlog=0, innodb_flush_log_at_trx_commit=0, 简写为b0e0
MySQL 环境搭建使用 MySQL sandbox, 对应三个场景的启动参数如下:1. ./start --sync-binlog=1 --log-bin=bin --server-id=5712 --gtid-mode=ON --enforce-gtid-consistency=1 --log-slave-updates=12. ./start --sync-binlog=0 --log-bin=bin --server-id=5712 --gtid-mode=ON --enforce-gtid-consistency=1 --log-slave-updates=13. ./start --sync-binlog=0 --log-bin=bin --server-id=5712 --gtid-mode=ON --enforce-gtid-consistency=1 --log-slave-updates=1 --innodb-flush-log-at-trx-commit=0
压力生成使用sysbench:
mysql -h127.0.0.1 -P5712 -uroot -pmsandbox -e"truncate table test.sbtest1"; /opt/sysbench-0.5/dist/bin/sysbench --test=/opt/sysbench-0.5/dist/db/insert.lua --mysql-table-engine=innodb --mysql-host=127.0.0.1 --mysql-user=root --mysql-password=msandbox --mysql-port=5712 --oltp-table-size=1000000 --mysql-db=test --oltp-table-name=stest --num-threads=1 --max-time=30 --max-requests=1000000000 --oltp-auto-inc=off --db-driver=mysql run
性能观测工具使用systemtap(简称stap), version 2.7/0.160
基准在没有观测压力的情况下, 对三种场景分别进行基准测试, 用以矫正之后测试的误差:
场景sysbench事务数b1e167546b0e1125699b0e0181612
火焰图与offcpu火焰图火焰图是Brendan Gregg首创的表示性能的图形方式, 其可以直观的看到压力的分布. Brendan提供了丰富的工具生成火焰图.
火焰图比较b0e1和b0e0使用stap脚本获取CPU profile, 并生成火焰图(火焰图生成的命令略, 参看Brendan的文档)
stap脚本
global tids probe process("/home/huangyan/sandboxes/5.7.12/bin/mysqld").function("mysql_execute_command") { if (pid() == target() && tids[tid()] == 0) { tids[tid()] = 1; } } global oncpu probe timer.profile { if (tids[tid()] == 1) { oncpu[ubacktrace()] <<< 1; } } probe timer.s(10) { exit(); } probe end { foreach (i in oncpu+) { print_stack(i); printf("\t%d\n", @count(oncpu[i])); } }
注意:1. 脚本只抓取MySQL的用户线程的CPU profile, 不抓取后台进程.2. 脚本只抓取10s, 相当于对整个sysbench的30s过程进行了短期抽样.
b0e1生成的火焰图
性能
在开启观测的情况下, 观察性能:
场景sysbench事务数b0e1119274b0e0166424
分析
在生成的火焰图中, 可以看到:
在b0e1场景中, _ZL27log_write_flush_to_disk_lowv的占比是12.93%, 其绝大部分时间是用于将innodb的log刷盘.在b0e0场景中, _ZL27log_write_flush_to_disk_lowv的开销被节省掉, 理论上的事务数比例应是1-12.93%=87.07%, 实际事务数的比例是119274/166424=71.67%, 误差较大误差较大的问题, 要引入offcpu来解决.
offcpu在之前的分析中我们看到理论和实际的事务数误差较大. 考虑_ZL27log_write_flush_to_disk_lowv的主要操作是IO操作, IO操作开始, 进程就会被OS进行上下文切换换下台, 以等待IO操作结束, 那么只分析CPU profile就忽略了IO等待的时间, 也就是说_ZL27log_write_flush_to_disk_lowv的开销被低估了.
offcpu也是Brendan Gregg提出的概念. 对于IO操作的观测, 除了CPU profile(称为oncpu时间), 还需要观测其上下文切换的代价, 即offcpu时间.
修改一下stap脚本可以观测offcpu时间. 不过为了将oncpu和offcpu的时间显示在一张火焰图上作对比, 我对于Brendan的工具做了微量修改, 本文将不介绍这些修改.
stap脚本
global tids probe process("/home/huangyan/sandboxes/5.7.12/bin/mysqld").function("mysql_execute_command") { if (pid() == target() && tids[tid()] == 0) { tids[tid()] = 1; } } global oncpu, offcpu, timer_count, first_cpu_id = -1; probe timer.profile { if (first_cpu_id == -1) { first_cpu_id = cpu(); } if (tids[tid()] == 1) { oncpu[ubacktrace()] <<< 1; } if (first_cpu_id == cpu()) { timer_count++; } } global switchout_ustack, switchout_timestamp probe scheduler.ctxswitch { if (tids[prev_tid] == 1) { switchout_ustack[prev_tid] = ubacktrace(); switchout_timestamp[prev_tid] = timer_count; } if (tids[next_tid] == 1 && switchout_ustack[next_tid] != "") { offcpu[switchout_ustack[next_tid]] <<< timer_count - switchout_timestamp[next_tid]; switchout_ustack[next_tid] = ""; } } probe timer.s(10) { exit(); } probe end { foreach (i in oncpu+) { print_stack(i); printf("\t%d\n", @sum(oncpu[i])); } foreach (i in offcpu+) { printf("---"); print_stack(i); printf("\t%d\n", @sum(offcpu[i])); } }
注意: timer.profile的说明中是这样写的:
Profiling timers are available to provide probes that execute on all CPUs at each system tick.
也就是说在一个时间片中, timer.profile会对每一个CPU调用一次. 因此代码中使用了如下代码, 保证时间片技术的正确性:
if (first_cpu_id == cpu()) { timer_count++; }
b0e1生成的带有offcpu的火焰图
性能
由于变更了观测脚本, 需要重新观测性能以减小误差:
场景sysbench事务数b0e1105980b0e0164739
分析
在火焰图中, 可以看到:1. _ZL27log_write_flush_to_disk_lowv的占比为31.23%2. 理论上的事务数比例应是1-31.23%=68.77%, 实际事务数的比例是105980/164739=64.33%, 误差较小.
观测误差的矫正在比较b0e1和b0e0两个场景时, 获得了比较好的结果. 但同样的方法在比较b1e1和b0e1两个场景时, 出现了一些误差.
误差现象b1e1的火焰图如图:
其中_ZN13MYSQL_BIN_LOG16sync_binlog_fileEb(sync_binlog的函数)占比为26.52%.
但性能差异为:
场景sysbench事务数b1e153752b0e1105980
理论的事务数比例为1-26.52%=73.48%, 实际事务数比例为53752/105980=50.71%, 误差较大.
分析压力分布首先怀疑压力转移, 即当sync_binlog的压力消除后, 服务器压力被转移到了其它的瓶颈上. 但如果压力产生了转移, 那么实际事务数比例应大于理论事务数比例, 即sync_binlog=0带来的性能提升更小.
不过我们还是可以衡量一下压力分布, 看看b1e1和b0e1的压力有什么不同, 步骤如下:
修改stap脚本, 在b1e1中不统计sync_binlog的代价. 生成的火焰图表示消除sync_binlog代价后, 理论上的服务器压力类型.与b0e1产生的火焰图做比较.stap脚本
只修改了probe end部分, 略过对my_sync堆栈的统计:
probe end { foreach (i in oncpu+) { if (isinstr(sprint_stack(i), "my_sync")) { continue; } print_stack(i); printf("\t%d\n", @sum(oncpu[i])); } foreach (i in offcpu+) { if (isinstr(sprint_stack(i), "my_sync")) { continue; } printf("---"); print_stack(i); printf("\t%d\n", @sum(offcpu[i])); } }
结果
b1e1, 理论的服务器压力图:
b0e1, 实际的服务器压力图:
可以看到, 压力分布是非常类似, 即没有发生压力分布.
BTW: 这两张图的类似, 具有一定随机性, 需要做多次试验才能产生这个结果.
分析
既然理论和实际的压力分布类似, 那么可能发生的就是压力的整体等比缩小. 推测是两个场景上的观测成本不同, 导致观测影响到了所有压力的观测.
观察stap脚本, 其中成本较大的是ctxswitch, 即上下文切换时的观测成本.
上下文切换的观测成本如果 “上下文切换的观测成本 影响 场景观测 的公平性” 这一结论成立, 那么我们需要解释两个现象:1. b1e1和b0e1的比较, 受到了 上下文切换的观测成本 的影响2. b0e1和b0e0的比较, 未受到 上下文切换的观测成本 的影响
假设 上下文切换的观测成本 正比于 上下文切换的次数, 那么我们只需要:1. 观测每个场景的上下文切换次数2. 对于b1e1和b0e1的比较, 由上下文切换次数计算得到理论的降速比, 与实际的降速比进行比较3. 对于b0e1和b0e0的比较, 由上下文切换次数计算得到是否会带来降速.
stap脚本
在probe scheduler.ctxswitch和probe end 增加了 ctxswitch_times 相关的内容:
global ctxswitch_times probe scheduler.ctxswitch { ctxswitch_times++; ... } probe end { ... printf("ctxswitch_times=%d\n", ctxswitch_times); }
结果
场景sysbench事务数上下文切换次数sync_binlog占比b1e15535282637036.80%b0e1105995693383–b0e0162709675092–
分析结果:1. b1e1与b0e1的比较1. 理论降速比: 693383/826370 = 83.90%2. 实际降速比: (实际的事务数比例/由sync_binlog占比推算的理论的事务数比例) = (55352/105995)/(1-36.80%) = 0.5222/0.6320 = 82.63%3. 误差很小. 即b1e1与b0e1的比较中, 理论值和实际值的误差来自于: IO操作的减少导致上下文切换的数量减小, 使得两个场景的观察成本不同.2. b0e1与b0e0的比较: 上下文切换次数相近, 即两个场景的观察成本相同.
实验结果符合之前的分析.
结论利用火焰图, 可以快速诊断出MySQL服务器级别的性能瓶颈, 做出合理的参数调整对于IO类型的操作的观测, 需要考虑oncpu和offcpu两种情况由于观测手段中使用了上下文切换作为观测点, 那IO操作数量的不同, 会引起上下文切换次数的不同, 从而引起观测误差.Copyright © 广州京杭网络科技有限公司 2005-2024 版权所有 粤ICP备16019765号
广州京杭网络科技有限公司 版权所有