一次压测遇到的问题和排查过程记录

问题 & 排查

1、cpu使用率过高

问题描述

压测参数：并发数 5 持续执行 300s
开始压测后，CPU开始逐步飙高，且居高不下，使用率一直增加。

问题排查

首先，从压测参数来看，并发数并不高，持续时间也不高，排除并发过高导致服务承载不住的可能。
其次，推测是项目中的令牌桶造成了阻塞。
最后，原因是，在获取令牌桶失败后自旋时，未进行线程状态切换让出CPU。

解决方案

添加sleep，进行线程状态切换。

扩展内容

a.线程状态切换图

b.线程阻塞情况
调整前：

调整后：

c. http-nio-10070-exec-1
压测时，会发现有一个线程池，名称从http-nio-10070-exec-1~http-nio-10070-exec-10。后续随着并发数的增加，该线程池中的线程数也同步增加。

问题：

• 线程池是何时创建的
• 线程参数是如何约定的

在tomcat-embed-core-9.0.60.jar中，org.apache.coyote.AbstractProtocol#getNameInternal().

private String getNameInternal() {
    StringBuilder name = new StringBuilder(this.getNamePrefix());
    name.append('-');
    String id = this.getId();
    if (id != null) {
        name.append(id);
    } else {
        if (this.getAddress() != null) {
            name.append(this.getAddress().getHostAddress());
            name.append('-');
        }


        int port = this.getPortWithOffset();
        if (port == 0) {
            name.append("auto-");
            name.append(this.getNameIndex());
            port = this.getLocalPort();
            if (port != -1) {
                name.append('-');
                name.append(port);
            }
        } else {
            name.append(port);
        }
    }


    return name.toString();
}

protected String getNamePrefix() {
    return this.isSSLEnabled() ? "https-" + this.getSslImplementationShortName() + "-nio" : "http-nio";
}

此时会拼接出“http-nio-10070”。

创建连接时，创建线程池。

org.apache.tomcat.util.net.AbstractEndpoint#startInternal()

public void startInternal() throws Exception {
    if (!this.running) {
        this.running = true;
        this.paused = false;
        if (this.socketProperties.getProcessorCache() != 0) {
            this.processorCache = new SynchronizedStack(128, this.socketProperties.getProcessorCache());
        }


        if (this.socketProperties.getEventCache() != 0) {
            this.eventCache = new SynchronizedStack(128, this.socketProperties.getEventCache());
        }


        if (this.socketProperties.getBufferPool() != 0) {
            this.nioChannels = new SynchronizedStack(128, this.socketProperties.getBufferPool());
        }

        //没有线程池时，开始创建
        if (this.getExecutor() == null) {
            this.createExecutor();
        }


        this.initializeConnectionLatch();
        this.poller = new NioEndpoint.Poller();
        Thread pollerThread = new Thread(this.poller, this.getName() + "-Poller");
        pollerThread.setPriority(this.threadPriority);
        pollerThread.setDaemon(true);
        pollerThread.start();
        this.startAcceptorThread();
    }


}

//创建线程池
public void createExecutor() {
    this.internalExecutor = true;
//任务队列，无上限
    TaskQueue taskqueue = new TaskQueue();
//任务线程工厂，名称添加exec，在具体创建线程时，会再拼接上线程number。
    TaskThreadFactory tf = new TaskThreadFactory(this.getName() + "-exec-", this.daemon, this.getThreadPriority());
    this.executor = new ThreadPoolExecutor(this.getMinSpareThreads(), this.getMaxThreads(), 60L, TimeUnit.SECONDS, taskqueue, tf);
    taskqueue.setParent((ThreadPoolExecutor)this.executor);
}

//任务线程工厂
public class TaskThreadFactory implements ThreadFactory {
    //线程组，默认个数是10.
    private final ThreadGroup group;
    private final AtomicInteger threadNumber = new AtomicInteger(1);
    private final String namePrefix;
    private final boolean daemon;
    private final int threadPriority;


    public TaskThreadFactory(String namePrefix, boolean daemon, int priority) {
        SecurityManager s = System.getSecurityManager();
        this.group = s != null ? s.getThreadGroup() : Thread.currentThread().getThreadGroup();
        this.namePrefix = namePrefix;
        this.daemon = daemon;
        this.threadPriority = priority;
    }


    public Thread newThread(Runnable r) {
        //线程名称拼接上线程number
        TaskThread t = new TaskThread(this.group, r, this.namePrefix + this.threadNumber.getAndIncrement());
        t.setDaemon(this.daemon);
        t.setPriority(this.threadPriority);
        if (Constants.IS_SECURITY_ENABLED) {
            PrivilegedAction<Void> pa = new PrivilegedSetTccl(t, this.getClass().getClassLoader());
            AccessController.doPrivileged(pa);
            PrivilegedAction<Void> pa = new PrivilegedSetAccessControlContext(t);
            AccessController.doPrivileged(pa);
        } else {
            t.setContextClassLoader(this.getClass().getClassLoader());
        }


        return t;
    }
}

线程池参数：

maxThreads：最大线程数 200
minSpareThreads：初始化线程数大小 10
核心线程数：min(minSpareThreads,maxThreads)

当并发数20时，可以看到http-nio线程数增加到了20。

当并发数调到2000时，http-nio线程数最多到了200，不会再增加了。

2、504 Gateway Time-out

问题描述

在jmeter查看结果树异常请求时，发现偶尔有几个报错 Gateway Time-out。

问题排查

首先排除存储过程导致的超时，因为该压测接口的测试数据是统一mock的，网络稳定的情况下，不会出现超时的情况。
其次，推测是获取令牌失败导致的超时，但在此场景下，项目中会返回“当前并发数量过高，请稍后重试”的提示语。随机抽查了一个接口的入参，根据唯一请求标识（requestId）在es中查到确实打印出了“当前并发数量过高，请稍后重试”。因此，可以确定，符合该推测，但提示语未按预期展示。

解决方案

目前网关超时统一设置6s，当获取令牌超时后，项目构造的响应体提示语“当前并发数量过高，请稍后重试”只在日志中正常打印，但网关已经返回了Gateway Time-out。

对该项目超时做额外处理（超时设置为1mins）后，此问题解决。

3、限流对压测的影响

问题描述

在并发 20 持续执行 300s时，接口rt在2s，超出预期。

问题排查

项目设置了限流，导致首次获取不到令牌桶的请求的整体耗时拉长，平均rt变长。

解决方案

调大限流允许的并发数。同样压测参数下，rt降到2s以下。

jmeter相关

1、beanShell 动态生成签名

添加前置控制器

编写脚本

//获取指定Param
String app_key = vars.get("app_key");  

//获取接口请求体参数
Arguments args = sampler.getArguments();

//将签名结果放到变量中
vars.put("sign", sign);

扩展内容：
a.若脚本中引入第三方jar包，需在脚本顶部import，然后添加jar。

b.使用变量&函数
（1）脚本中将签名结果赋给sign变量，在接口中，需要获取sign变量的值。
如：url?sign=${sign}

（2）请求体中的唯一标识outBizCode需动态改变

这里使用函数处理
${__RandomString(32,1231asada,)}

2、响应断言

响应断言，即设置如何依据响应体判断此次请求成功与否。断言的设置会影响最终异常率。

通用逻辑是flag=success即为响应成功，mock数据，在执行到存储过程中后会报错，但此时已经走到核心逻辑，该报错可忽略。

3、导出结果树请求和响应文件

页面结果树不支持搜索，因此可自定义导出的请求和响应内容，再进行搜索。