一则性能测试问题分析案例_性能测试实战案例分析题-CSDN博客

本文链接：https://blog.csdn.net/dj355/article/details/132274297

前言：

性能测试是软件开发过程中非常重要的一环，可以帮助我们发现和解决性能瓶颈问题。

1 线程堆栈

线程堆栈也称作线程调用堆栈。Java 线程堆栈是虚拟机中线程（包括锁）状态的一个瞬间快照，即系统在某个时刻所有线程的运行状态,包括每一个线程的调用堆栈，锁的持有情况等信息，从线程堆栈中可以得到以下信息：

线程的名字，ID，线程的数量等；

线程的运行状态，锁的状态（锁被那个线程持有，哪个线程在等待锁等）；

函数间的调用关系，包括完整类名，所执行的方法，源代码的行数等；

2 问题现象

在测试一个场景时，发现响应时间很长，日志也无报错现象，根据调用链逐级定位，发现 80% 的时间都是消耗在 DAO 层的方法上，这时首先考虑的是 sql 会不会有问题？于是找 DBA 同学帮忙抓 sql 看下，但 DBA 同学反映 sql 执行很快，执行计划也没有问题，那问题出现在哪里呢，找不到原因就看下线程堆栈，系统在 dao 层方法后做了什么？

此时就 jstack 就派上用场了。

jstack 使用，一般来说执行 jstack -l pid > test.txt，然后查看 test.txt 文件即可观察对比线程堆栈。

jstack 线程堆栈如下：

"DubboServerHandler-10.165.184.51:20881-thread-200" daemon prio=10 tid=0x00007f2fd6208800 nid=0x504b waiting on condition [0x00007f2fc0280000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000078172f2c0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at com.alibaba.druid.pool.DruidDataSource.pollLast(DruidDataSource.java:1487) at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1086) at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:953) at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4544) at com.alibaba.druid.filter.logging.LogFilter.dataSource_getConnection(LogFilter.java:827) at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4540) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:931) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:923) at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:100) at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111) at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77) at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:81) at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:67) at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:279) at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:72) at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:59) ...

3 问题分析

先关注线程状态，发现堆栈信息里大量的 dubbo 线程处于 TIMED_WAITING 状态，从 “waiting on condition” 可以看出系统在等待一个条件发生，这时的线程处于 sleep 状态，一般会有超时时间唤醒，一般出现 TIMED_WAITING 很正常，一些等待 IO 都会出现这种状态，但是大量的 TIMED_WAITING 就要找原因了，观察线程堆栈发现处于 TIMED_WAITING 状态的线程都在等待 druid 获取连接池的连接，这种现象很像连接池不够用了，于是增加数据库连接池的连接数，TPS 直接提升了 3 倍。