背景

建立MySQL的性能模型, 对 MySQL的服务器参数调优 和 容量规划 有很大意义. 性能模型指的是如何通过观测得到量化的性能数值, 并能对 环境调整造成的影响 进行准确的量化预测. 其中最简单的性能模型是使用单线程进行insert.

测试场景

1. MySQL 5.7.12

2. 主要测试 不同刷盘参数 对性能的影响, 使用以下三个场景:

1. sync_binlog=1, innodb_flush_log_at_trx_commit=1, 简写为b1e1 (binlog-1-engine-1)

2. sync_binlog=0, innodb_flush_log_at_trx_commit=1, 简写为b0e1

3. sync_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

分析

在生成的火焰图中, 可以看到:

1. 在b0e1场景中, _ZL27log_write_flush_to_disk_lowv的占比是12.93%, 其绝大部分时间是用于将innodb的log刷盘.

2. 在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的压力有什么不同, 步骤如下:

1. 修改stap脚本, 在b1e1中不统计sync_binlog的代价. 生成的火焰图表示消除sync_binlog代价后, 理论上的服务器压力类型.

2. 与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的比较: 上下文切换次数相近, 即两个场景的观察成本相同.

实验结果符合之前的分析.

结论

1. 利用火焰图, 可以快速诊断出MySQL服务器级别的性能瓶颈, 做出合理的参数调整

2. 对于IO类型的操作的观测, 需要考虑oncpu和offcpu两种情况

3. 由于观测手段中使用了上下文切换作为观测点, 那IO操作数量的不同, 会引起上下文切换次数的不同, 从而引起观测误差