性能测试误差对比研究（二）

2021-05-07 16:27:55 浏览数 (1)

今天填一下之前的坑，前文性能测试误差对比研究（一）中，我对几种比较常见的性能测试误差来源，进行了对比测试。效果还是不错的，基本的结论都是非常清晰的。

今天我继续分享剩下几种性能测试误差来源对性能测试误差影响，以及定量测试其中的影响程度。

测试脚本

由于「FunTester」已经优化了性能测试框架软启动的问题，总体测试的时间会比较长，所以我这里简单实现了一个简化统计，在测试过程中表现还是很不错的。分享一下Groovy脚本：

  • 这个脚本会在后面测试中略微修改。
代码语言：javascript复制
package com.funtester.groovy

import com.funtester.frame.SourceCode
import com.funtester.utils.Time

import java.util.concurrent.CountDownLatch
import java.util.concurrent.atomic.AtomicInteger

/**
 * 结束控制
 */
class FunTester extends SourceCode {

    static Vector<Long> costs = new Vector<>()

    static CountDownLatch countDownLatch;

    private static final int thread = 20//线程数

    private static final int times = 50//单线程次数

    private static final AtomicInteger excutetimes= new AtomicInteger()

    static void main(String[] args) {
        countDownLatch = new CountDownLatch(thread)


        def s = Time.getTimeStamp()
        thread.times {
            new FunTest().start()
        }
        countDownLatch.await()
        def e = Time.getTimeStamp()
        def rts = []
        costs.each {rts << it}
        def rt = rts.sum() / rts.size()
        double qps = thread * 1000.0 / rt
        double qps2 = excutetimes.get() * 1000.0 / (e - s)
        def deviation = com.funtester.frame.SourceCode.getPercent(Math.abs(qps - qps2) * 100 / Math.max(qps, qps2))
        output("通过平均时间计算QPS:$qps")
        output("通过总时间计算QPS:$qps2")
        output("误差是:$deviation")


    }


    private static class FunTest extends Thread {


        @Override
        void run() {
            times.times {
                def start = Time.getTimeStamp()
                sleep(0.1)
                def end = Time.getTimeStamp()
                excutetimes.getAndIncrement()
                costs.add(end - start)
            }
            countDownLatch.countDown()
        }
    }
}

有些小伙伴表示Groovy脚本比较晦涩难懂，下面是Java版本：

代码语言：javascript复制
package com.funtester.java;

import com.funtester.frame.SourceCode;
import com.funtester.utils.Time;

import java.util.ArrayList;
import java.util.List;
import java.util.Vector;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.atomic.AtomicInteger;

/**
 * 结束控制
 */
public class FunTester extends SourceCode {

    static Vector<Long> costs = new Vector<>();

    static CountDownLatch countDownLatch;

    private static final int thread = 20;//线程数

    private static final int times = 50;//单线程次数

    private static final AtomicInteger excutetimes = new AtomicInteger();

    static void main(String[] args) throws InterruptedException {

        countDownLatch = new CountDownLatch(thread);


        long s = Time.getTimeStamp();
        for (int i = 0; i < thread; i  ) {
            new FunTest().start();
        }
        countDownLatch.await();
        long e = Time.getTimeStamp();
        List rts = new ArrayList();
        costs.forEach(f -> rts.add(f));
        long count = rts.stream().count();
        long rt = count / rts.size();
        double qps = thread * 1000.0 / rt;
        double qps2 = excutetimes.get() * 1000.0 / (e - s);
        String deviation = getPercent(Math.abs(qps - qps2) * 100 / Math.max(qps, qps2));
        output("通过平均时间计算QPS:"   qps);
        output("通过总时间计算QPS:"   qps2);
        output("误差是:"   deviation);


    }


    private static class FunTest extends Thread {


        @Override
        public void run() {
            for (int i = 0; i < times; i  ) {
                long start = Time.getTimeStamp();
                SourceCode.sleep(0.1);
                long end = Time.getTimeStamp();
                excutetimes.getAndIncrement();
                costs.add(end - start);
            }
            countDownLatch.countDown();
        }

    }

}

首先跑一个20线程，50次数的基准测试，结果如下：

代码语言：javascript复制
INFO-> 当前用户：fv，工作目录：/Users/fv/Documents/workspace/funtester/,系统编码格式:UTF-8,系统Mac OS X版本:10.16
INFO-> 通过平均时间计算QPS:193.4142449591
INFO-> 通过总时间计算QPS:189.5375284306
INFO-> 误差是:2%

Process finished with exit code 0

异步结束

上面的例子是一个sleep固定时间的，然后执行完所有的循环次数以后再通知结束，等所有线程执行结束之后再进行数据统计工作。

概率上讲所有的线程应该是会在某一个很短的时间间隔内结束执行，但是实际情况中大多都不是这个理想模型。很多因素，包括接口执行时间分布不均匀、各个线程执行任务并不一致、异常处理消等等原因会导致各个线程在结束时间点上差别比较大，导致误差偏大，当然在「固定时间」请求模式中不存在这个问题。

下面是我修改run()方法内容。

代码语言：javascript复制
@Override
        void run() {
            times.times {
                def start = Time.getTimeStamp()
                sleep(0.1   getRandomDouble() / 3)
                def end = Time.getTimeStamp()
                excutetimes.getAndIncrement()
                costs.add(end - start)
            }
            countDownLatch.countDown()
        }

在20线程，50次数的情况下测试数据如下：

代码语言：javascript复制
INFO-> 当前用户：fv，工作目录：/Users/fv/Documents/workspace/funtester/,系统编码格式:UTF-8,系统Mac OS X版本:10.16
INFO-> 通过平均时间计算QPS:75.8204722857
INFO-> 通过总时间计算QPS:70.2641933671
INFO-> 误差是:7.33%

Process finished with exit code 0

明显误差开始增加了。下面测试增加线程到40，测试结果如下：

代码语言：javascript复制
INFO-> 当前用户：fv，工作目录：/Users/fv/Documents/workspace/funtester/,系统编码格式:UTF-8,系统Mac OS X版本:10.16
INFO-> 通过平均时间计算QPS:148.2708834906
INFO-> 通过总时间计算QPS:130.3101381287
INFO-> 误差是:12.11%

Process finished with exit code 0

误差持续增加，下面我保持20线程，增加次数到100，结果如下：

代码语言：javascript复制
INFO-> 当前用户：fv，工作目录：/Users/fv/Documents/workspace/funtester/,系统编码格式:UTF-8,系统Mac OS X版本:10.16
INFO-> 通过平均时间计算QPS:73.8407918687
INFO-> 通过总时间计算QPS:68.8373373718
INFO-> 误差是:6.78%

Process finished with exit code 0

误差反而降下来了，这也是符合概率学中，实验次数越多，实验结果越是趋近于理论值。

结论比较明显了，在随机不确定请求耗时的情况下，增加线程会增加误差，增加请求次数会降低误差。总体讲在多线程，低请求次数中，QPS的误差还是比较大的，在性能测试中，应当增加请求次数来平衡这个误差。

下面我引入private static boolean KEY = false//控制线程结束来控制所有的线程一起结束。

重写run()方法如下：

代码语言：javascript复制
 @Override
        for ( int i in 0..<times ) {
                def start = Time.getTimeStamp()
                sleep(0.1   getRandomDouble() / 3)
                def end = Time.getTimeStamp()
                excutetimes.getAndIncrement()
                costs.add(end - start)
                if (KEY) break
            }
            KEY = true
            countDownLatch.countDown()

这里Groovy没有跳出循环的机制，所以只能换成for循环形式了，这是我始料未及的，差点翻车了。

同样在40线程，50次数的情况下，测试结果如下：

代码语言：javascript复制
INFO-> 当前用户：fv，工作目录：/Users/fv/Documents/workspace/funtester/,系统编码格式:UTF-8,系统Mac OS X版本:10.16
INFO-> 通过平均时间计算QPS:149.5957705046
INFO-> 通过总时间计算QPS:145.44
INFO-> 误差是:2.78%

Process finished with exit code 0

可以看到，误差明显下降了不少，QPS反而增加了一些，哈哈。这里不多讲了。

日志打印

下面分享一下性能测试中对日志记录对性能测试的影响，这里我用的log4j2日志组件，没有使用异步日志打印，所以影响应该会相比异步打印稍大一些。

首先分享一个数据，在我使用自己封装的moco服务的测试中，关闭日志情况下QPS可以达到将近3万，在开启日志记录的情况下QPS只能到5千。有兴趣的童鞋可以翻看以前的文章：

  • 解决moco框架API在post请求json参数情况下query失效的问题
  • 给moco API添加limit功能
  • 给moco API添加random功能
  • 解决moco框架API在cycle方法缺失的问题
  • 五行代码构建静态博客
  • moco API模拟框架视频讲解（上）
  • moco API模拟框架视频讲解（中）
  • moco API模拟框架视频讲解（下）
  • 如何mock固定QPS的接口
  • mock延迟响应的接口
  • moco固定QPS接口升级补偿机制

回到正题，我继续采用固定sleep的模型进行测试，run方法如下：

代码语言：javascript复制
        @Override
        void run() {
            times.times {
                def start = Time.getTimeStamp()
                sleep(0.1)
                10.times {
                    logger.info(text)
                }
                def end = Time.getTimeStamp()
                excutetimes.getAndIncrement()
                costs.add(end - start)
            }
            countDownLatch.countDown()
        }

添加属性private static Logger logger = LogManager.getLogger(FunTester.class);和private static String text = getManyString("FunTester",100)。

在20线程，50次记录的模式下，测试结果如下：

代码语言：javascript复制
INFO-> 通过平均时间计算QPS:186.3620268734
INFO-> 通过总时间计算QPS:182.5150574922
INFO-> 误差是:2.06%

误差虽然不大，但是对比基准测试的结果：

代码语言：javascript复制
INFO-> 通过平均时间计算QPS:193.4142449591
INFO-> 通过总时间计算QPS:189.5375284306
INFO-> 误差是:2%

明显QPS有了较大的影响，所以这个题目的研究内容并不仅仅是误差，还有对QPS的影响。下面增加线程到40线程，结果如下：

代码语言：javascript复制
INFO-> 通过平均时间计算QPS:347.3654501639
INFO-> 通过总时间计算QPS:339.328130302
INFO-> 误差是:2.31%

对比基准测试的40线程测试结果：

代码语言：javascript复制
INFO-> 通过平均时间计算QPS:384.8059375556
INFO-> 通过总时间计算QPS:380.8073115004
INFO-> 误差是:1.04%

此时QPS下降尤为明显，已经达到10%以上了。下面继续增加循环次数到100，看看结果如何：

代码语言：javascript复制
INFO-> 通过平均时间计算QPS:364.3792003243
INFO-> 通过总时间计算QPS:352.8581510233
INFO-> 误差是:3.16%

对比基准测试结果：

代码语言：javascript复制
INFO-> 当前用户：fv，工作目录：/Users/fv/Documents/workspace/funtester/,系统编码格式:UTF-8,系统Mac OS X版本:10.16
INFO-> 通过平均时间计算QPS:388.6098454304
INFO-> 通过总时间计算QPS:384.6893633391
INFO-> 误差是:1.01%

Process finished with exit code 0

QPS有所升高，但是误差稍微有些增加。大致结论如下：少量（远未达到硬件IO瓶颈前）日志记录，在QPS方面影响较大，甚至能达到10%以上，随着线程增加，QPS降低越来越大，随着请求次数增加，QPS下降趋势减缓。在误差方面，增加日志记录，自然会导致QPS误差变大。主要是因为打印日志消耗时间，算在总时间内和算在请求耗时的区别。案例中我是算在了请求时间内，所以算出来的误差很低，但是如果将日志打印计算在请求时间之外，误差将会很大。

所以在以后的性能测试过程中，尽量避免记录日志。

「FunTester」，腾讯云年度作者、Boss直聘签约作者，GDevOps官方合作媒体，非著名测试开发。
FunTester测试框架架构图初探
腾讯云测试服务 api 性能测试 groovy

0 人点赞