项目之接口响应慢排查
Posted
tags:
篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了项目之接口响应慢排查相关的知识,希望对你有一定的参考价值。
参考技术A 1、根据监控报警,找到对应接口2、找到接口对应日志,提取生产入参(仅限查询类的接口,如果有update操作,那么请使用测试环境入参)
3、根据每步执行时间,选择优化方式,比如手动在rpc调用、redis、db、复杂方法等增加日志、引入skywaliking或者arthas链路追踪工具,查看哪里执行耗时过多,有优化空间
4、优化后部署测试上线
记一次接口慢查排查
1. 前言
本篇文章记录了一次接口慢查问题排查过程,该问题产生的现象迷惑性较高。同时由于问题偶发性高,排查难度也比较大。排查过程从 druid 数据源“导致”的一个慢查现象作为切入点,逐步分析,排除诸多可能性后仍无解。之后重新审视故障现象,换个角度分析,找到了问题根因。最后对问题原因进行了验证确认,结果符合预期。到此,排查过程算是结束了,本文对问题进行记录归档。
2. 问题描述
前段时间收到业务同事反馈,说他们应用的某台机器连续两天多个接口出现了两次慢查情况(偶发性较高)。但持续时间比较短,但很快又恢复了。Pinpoint 调用链信息如下:
图1:长 RT 接口调用链信息
上图是业务同学反馈过来的信息,可以看出从 MyBatis 的 SqlSessionTemplate#selectList 方法到 MySQL 的 ConnectionImpl#prepareStatement 方法之间出现了 2111 毫秒的间隔,正是这个间隔导致了接口 RT 升高。接下来针对这个现象进行分析。
3. 排查过程
3.1 直奔主题
从全链路追踪系统给出的链路信息来看,问题的原因似乎很明显,就是 selectList 和 prepareStatement 之间存在着长耗时的操作。理论上只要查出哪里出现了长耗时操作,以及为什么发生,问题就解决了。于是先不管三七二十一,直接分析 MyBatis 的源码吧。
public class SimpleExecutor extends BaseExecutor {
public <E> List<E> doQuery(MappedStatement ms, Object parameter, RowBounds rowBounds, ResultHandler resultHandler, BoundSql boundSql) throws SQLException {
Statement stmt = null;
try {
Configuration configuration = ms.getConfiguration();
StatementHandler handler = configuration.newStatementHandler(wrapper, ms, parameter, rowBounds, resultHandler, boundSql);
stmt = prepareStatement(handler, ms.getStatementLog()); // 预编译
return handler.<E>query(stmt, resultHandler);
} finally {
closeStatement(stmt);
}
}
private Statement prepareStatement(StatementHandler handler, Log statementLog) throws SQLException {
Statement stmt;
Connection connection = getConnection(statementLog); // 获取数据库连接
stmt = handler.prepare(connection, transaction.getTimeout()); // 执行预编译
handler.parameterize(stmt);
return stmt;
}
}
MyBatis 的 SqlSessionTemplate#selectList 方法的调用链比较长,这里就不一一分析,感兴趣可以看一下我三年前的文章 MyBatis 源码分析 - SQL 的执行过程。SqlSessionTemplate#selectList 最终会执行到 SimpleExecutor#doQuery,该方法在执行后续逻辑前,会先调用 SimpleExecutor#prepareStatement 进行预编译。prepareStatement 方法涉及到两个外部操作,一个是获取数据库连接,另一个是执行调用 MySQL 驱动相关方法执行预编译。
从图1的监控上看,预编译速度很快,可以确定预编译没有问题。现在,把注意力移到 getConnection 方法上,这个方法最终会向底层的 druid 数据源申请数据库连接。druid 采用的是生产者消费者模型来维护连接池,更详细的介绍参考我的另一篇文章。如果连接池中没有可用连接,这个时候业务线程就会等待 druid 生产者创建连接。如果生产者创建连接速度比较慢,或者活跃连接数达到了最大值,此时业务线程就必须等待了。好在业务应用接了 druid 监控,我们可以通过监控了解连接池的情况。
图2:druid 监控图
上图是用 excel 绘制的,数据经过编辑,与当时情况存在一定的偏差,但不影响后续的分析。从监控上来看,连接池中的空闲连接全部被借出去了,但仍然不够,于是生产者不停的创建连接。这里引发了我们的思考,为什么活跃连接数会突然上升这么多?可能是出现了慢查。与此同时,业务线程的等待次数和等待时间大幅上涨,这说明 druid 连接生产者的“产能”似乎不足,以至于部分业务线程出现了等待。什么情况下生产者创建连接会出现问题呢?我们当时考虑到的情况如下:
- 网络出现了延迟或者丢包,造成重传
- 阿里云 RDS 实例负载很高,无法及时响应客户端的连接建立请求
先说第二种情况,RDS 负载的问题很好确认,阿里云上有 RDS 的监控。我们确认了两次问题发生时的监控曲线,发现实例负载并不高,没有明显波动,所以情况二可以排除。那情况一呢,网络会不会出现问题呢?这个猜想不好排除。原因如下:
活跃连接数正常情况下会很低,暴涨一般都不是正常现象。假如一个 Java 线程从发出 SQL 请求到收到数据耗时 5ms,那么一条连接可以达到 200 的 QPS。而这个单机 QPS 还不足 200,不应该用掉这么多连接,除非出现了慢查。但是我们用阿里云的 SQL 洞察服务里也没发现慢 SQL,因此可以排除掉慢查的可能性。不是慢查,似乎只能甩锅给网络了,一定是当时的网络(接锅好手)出了问题。
如果真是网络出问题了,那么 druid 生产者“产能”不足的问题似乎也能得到合理的解释。但是经过我们的分析,发现了一些矛盾点,如下:
图3:某个长 RT 请求的链路追踪数据
从链路数据上来看,SQL 的预编译和执行时间都是很快的,没有出现明显的等待时间。如果说上面的情况是偶然,但是我们翻看了很多链路数据,都发现 SQL 的预编译和执行速度都很快,不存在明显的延迟。因此,把锅甩给网络是不合适的。
排查到这里,思路断了。首先没有发现慢查,其次数据库资源也是充足的,最后网络似乎也没问题。都没有问题,那问题出在哪里呢?
3.2 扩大信息面
3.2.1 基本信息
首先查看了问题机器的 QPS,发现没有突发流量。虽有一定波动,但总体仍然平稳。
图4:QPS 折线图
接着看了应用的 CPU 使用率,发现了一点问题,使用率突然上升了很多。
图5:CPU 使用率折线图
询问了业务同学,这个点没有定时任务,QPS 与以往相似,没有什么异常。目前不知道 CPU 为什么会突然上升这么多,这个信息暂时无法提供有效的帮助,先放着。最后再看一下网络 I/O 监控。
图6:网络流量监控图
入站流量与出站流量在问题发生时间段内都出现了上升,其中出站流量上升幅度很大,说明当时应该有大量的数据发出去。但具体是哪些接口的行为,目前还不知道。
3.2.2 业务日志信息
接着分析了一下业务日志,我们发现了一些 WARN 级别信息:
# 业务线程打出的 WARN 日志,表示等待连接超时,重试一次
2021-07-20 09:56:42.422 [DubboServerHandler-thread-239] WARN com.alibaba.druid.pool.DruidDataSource [DruidDataSource.java:1400] - get connection timeout retry : 1
2021-07-20 09:56:42.427 [DubboServerHandler-thread-242] WARN com.alibaba.druid.pool.DruidDataSource [DruidDataSource.java:1400] - get connection timeout retry : 1
2021-07-20 09:56:42.431 [DubboServerHandler-thread-240] WARN com.alibaba.druid.pool.DruidDataSource [DruidDataSource.java:1400] - get connection timeout retry : 1
# Dubbo TimeoutFilter 答疑超时日志
2021-07-20 09:56:42.432 [DubboServerHandler-thread-254] WARN org.apache.dubbo.rpc.filter.TimeoutFilter [TimeoutFilter.java:60] - [DUBBO] invoke time out. method: xxx arguments: [yyy] , url is dubbo://172.***.***.***:20880/****
2021-07-20 09:56:42.489 [DubboServerHandler-thread-288] WARN org.apache.dubbo.rpc.filter.TimeoutFilter [TimeoutFilter.java:60] - [DUBBO] invoke time out. method: **** arguments: [***, ***] , url is dubbo://172.***.***.***:20880/****
这两种日志说实话没什么用,因为这些日志是结果,本就应该发生的。除了 WARN 信息,业务日志里找不到任何异常信息。需要说明的是,我们并没有设置业务线程获取连接重试次数,默认重试次数是0。但这里却进行了一次重试,而我们预期是业务线程在指定时间内获取连接失败后,应抛出一个 GetConnectionTimeoutException 异常。这个应该是 druid 的代码有问题,我给他们提了一个 issue (#4381),但是没人回复。这个问题修复也很简单,算是一个 good first issue,有兴趣的朋友可以提个 Pull Request 修复一下。
业务日志没有太多可用信息,我们继续寻找其他的线索,这次我们从 JVM 监控里发现了端倪。
3.2.3 GC 信息
问题发生的那一小段时间内,JVM 发生了多次的 YGC 和 FGC,而且部分 GC 的耗时很长。
图7:GC 次数与耗时监控
那么现在问题来了,GC 是原因还是结果?由于 GC 发生的时间与接口慢查出现的时间都在 9.56:30 之后,时间上大家是重叠的,谁影响了谁,还是互相影响,这都是不清楚的。GC 的引入似乎让排查变得更为复杂了。
到这里信息收集的差不多了,但是问题原因还是没有推断出来,十分郁闷。
3.3 重新审视
3.3.1 综合分析
如果我们仍然从 druid 这个方向排查,很难查出原因。时间宝贵,现在要综合收集的信息重新思考一下了。既然发生了 GC,那么应用的内存消耗一定是上升了。再综合网络 I/O 的情况,短时间内出现了比较大的波动,好像也能说明这个情况。但当时网络流量并不是特别大,似乎还不足以引发 GC。支撑力不足,先放一边。另外,应用的 QPS 没有多大变动,但是 CPU 负载却突然上升了很多。加之几次 GC 的耗时很长,搞不好它们俩之间有关联,即长时间的 GC 导致了 CPU 负载上升。目前,有两个排查方向,一个是从网络 I/O 方向排查,另一个是从 GC 方向排查。就现象而言,GC 的问题似乎更大,因此后续选择从 GC 方向排查。
3.3.2 换个思路
JVM 进行 GC,说明内存使用率一定是上去了。内存上升是一个累积过程,如果我们把排查时间从发生长耗时 GC 的时刻 9:57:00 向前推一分钟,没准会发现点什么。于是我到全链路追踪平台上按耗时倒序,拉取了问题应用在 9:56:00 这一分钟内的长 RT 接口列表,发现耗时靠前的十几个都是 queryAll 这个方法。如下:
图8:queryAll 方法耗时倒序列表
我们看一下耗时最长请求的调用链信息:
图9:耗时最长请求的链路信息
首先我们可以看到 MySQL 驱动的 execute 执行时间特别长,原因后面分析。其次 redis 缓存的读取耗时非常短,没有问题。但 redis 客户端写入数据耗时非常长,这就很不正常了。
于是立即向应用开发要了代码权限,分析了一下代码。伪代码如下:
public XxxService {
// 备注:该方法缓存实际上使用了 Spring @Cacheable 注解,而非显示操作缓存
public List queryAll(int xxxId) {
// 1、检查缓存,命中则立即返回
List xxxDTOs = customRedisClient.get(xxxId);
if (xxxDTOs != null) return list;
// 2、缓存未命中,查询数据库
List xxxDOs = XxxDao.queryAll(xxxId);
xxxDTOS = convert(xxxDOs)
// 3、写入缓存
customRedisClient.set(xxxId, xxxDTOs, 300s);
return list;
}
}
代码做的事情非常简单,那为什么会耗时这么多呢?原因是这样的,如果缓存失效了,queryAll 这个方法一次性会从数据库里取出上万条数据,且表结构包含了一些复杂的字段,比如业务规则,通讯地址等,所以单行记录相对较大。加之数据取出后,又进行了两次模型转换(DO → DTO → TO),转换的模型数量比原始模型数量要多一半,约 1.5 万个,TO 数量与 DTO 一致。模型转换完毕后,紧接着是写缓存,写缓存又涉及序列化。queryAll 方法调用一次会在新生代生成约五份比较大的数据,第一份是数据集 ResultSet,第二份是 DO 列表,第三份是 DTO 列表,第四份 TO 列表,最后一份是 DTO 列表的序列化内容。加之两秒内出现了二十多次调用,加剧了内存消耗,这应该能解释为什么 GC 次数会突然上升这么多。下面还有几个问题,我用 FAQ 的方式解答:
Q:那 GC 耗时长如何解释呢?
A:我猜测可能是垃圾回收器整理和复制大批量内存数据导致的。
-------------------------------------------------✂-------------------------------------------------
Q:还有 execute 方法和 set 方法之间为什么会间隔这么长时间内?
A:目前的猜测是模型类的转换以及序列化本身需要一定的时间,其次这期间应该有多个序列化过程同时在就行,不过这也解释不了时间为什么这么长。不过如果我们把 GC 考虑进来,就会得到相对合理的解释。从 9:56:33 ~ 5:56:52 之间出现了多次 GC,而且有些 GC 的时间很长(长时间的 stop the world),造成的现象就是两个方法之间的间隔很长。实际上我们可以看一下 9:56:31 第一个 queryAll 请求的调用链信息,会发现间隔并不是那么的长:
图10:queryAll 正常情况下的耗时情况
因此,我们可以认为后续调用链 execute 和 set 方法之间的超长间隔是因为 CPU 使用率,GC 等因素共同造成的。
-------------------------------------------------✂-------------------------------------------------
Q:第一个 set 和第二个 set 间隔为什么也会这么长?
A:第一个 set 是我们自定义的逻辑,到第二个 set 之间似乎没有什么特别的东西,当时没有查出问题。不过好在复现的时候,发现了端倪,后面章节给予解释。
-------------------------------------------------✂-------------------------------------------------
最后,我们把目光移到初始的问题上,即业务同事反馈部分接口 RT 上升的问题。下面仍用 FAQ 的方式解答。
Q:为什么多个接口的 RT 都出现了上升?调用链参考下图:
图11:某个长 RT 接口的链路信息
A:部分业务线程在等待 druid 创建数据库连接,由于 GC 的发生,造成了 STW。GC 对等待逻辑会造成影响。比如一个线程调用 awaitNanos 等待3秒钟,结果这期间发生了5秒的 GC(STW),那么当 GC 结束时,线程立即就超时了。在 druid 数据源中, maxWait 参数控制着业务线程的等待时间,代码如下:
public class DruidDataSource extends DruidAbstractDataSource {
private DruidPooledConnection getConnectionInternal(long maxWait) throws SQLException {
// ...
final long nanos = TimeUnit.MILLISECONDS.toNanos(maxWait);
if (maxWait > 0) {
// 尝试在设定时间内从连接池中获取连接
holder = pollLast(nanos);
} else {
holder = takeLast();
}
// ...
}
}
3.4 初步结论
经过前面的排查,很多现象都得到了合理的解释,是时候给个结论了:
本次 xxx 应用多个接口在两天连续出现了两次 RT 大幅上升情况,排查下来,初步认为是 queryAll 方法缓存失效,短时间内几十个请求大批量查询数据、模型转换以及序列化等操作,消耗量大量的内存,触发了多次长时间的 GC。造成部分业务线程等待超时,进而造成 Dubbo 线程池被打满。
接下来,我们要按照这个结论进行复现,以证明我们的结论是正确的。
4. 问题复现
问题复现还是要尽量模拟当时的情况,否则可能会造成比较大的误差。为了较为准确的模拟当时的接口调用情况,我写了一个可以控制 QPS 和请求总数的验证逻辑。
public class XxxController {
@Resource
private XxxApi xxxApi;
public Object invokeQueryAll(Integer qps, Integer total) {
RateLimiter rl = RateLimiter.create(qps.doubleValue());
ExecutorService es = Executors.newFixedThreadPool(50);
for (Integer i = 0; i < total; i++) {
es.submit(() -> {
rl.acquire();
xxxApi.queryAll(0);
});
}
return "OK";
}
}
复现的效果符合预期,CPU 使用率,网络 I/O 都上去了(由于监控属于公司内部系统,就不截图了)。同时 GC 也发生了,而且耗时也很长。GC 日志如下:
2021-07-29T19:09:07.655+0800: 631609.822: [GC (Allocation Failure) 2021-07-29T19:09:07.656+0800: 631609.823: [ParNew: 2797465K->314560K(2831168K), 2.0130187 secs] 3285781K->1362568K(4928320K), 2.0145223 secs] [Times: user=3.62 sys=0.07, real=2.02 secs]
2021-07-29T19:09:11.550+0800: 631613.717: [GC (Allocation Failure) 2021-07-29T19:09:11.551+0800: 631613.718: [ParNew: 2831168K->314560K(2831168K), 1.7428491 secs] 3879176K->1961168K(4928320K), 1.7443725 secs] [Times: user=3.21 sys=0.04, real=1.74 secs]
2021-07-29T19:09:13.300+0800: 631615.467: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1646608K(2097152K)] 1965708K(4928320K), 0.0647481 secs] [Times: user=0.19 sys=0.00, real=0.06 secs]
2021-07-29T19:09:13.366+0800: 631615.533: [CMS-concurrent-mark-start]
2021-07-29T19:09:15.934+0800: 631618.100: [GC (Allocation Failure) 2021-07-29T19:09:15.934+0800: 631618.101: [ParNew: 2831168K->2831168K(2831168K), 0.0000388 secs]2021-07-29T19:09:15.934+0800: 631618.101: [CMS2021-07-29T19:09:17.305+0800: 631619.471: [CMS-concurrent-mark: 3.668/3.938 secs] [Times: user=6.49 sys=0.01, real=3.94 secs]
(concurrent mode failure): 1646608K->1722401K(2097152K), 6.7005795 secs] 4477776K->1722401K(4928320K), [Metaspace: 224031K->224031K(1269760K)], 6.7028302 secs] [Times: user=6.71 sys=0.00, real=6.70 secs]
2021-07-29T19:09:24.732+0800: 631626.899: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1722401K(2097152K)] 3131004K(4928320K), 0.3961644 secs] [Times: user=0.69 sys=0.00, real=0.40 secs]
2021-07-29T19:09:25.129+0800: 631627.296: [CMS-concurrent-mark-start]
2021-07-29T19:09:29.012+0800: 631631.179: [GC (Allocation Failure) 2021-07-29T19:09:29.013+0800: 631631.180: [ParNew: 2516608K->2516608K(2831168K), 0.0000292 secs]2021-07-29T19:09:29.013+0800: 631631.180: [CMS2021-07-29T19:09:30.733+0800: 631632.900: [CMS-concurrent-mark: 5.487/5.603 secs] [Times: user=9.29 sys=0.00, real=5.60 secs]
(concurrent mode failure): 1722401K->1519344K(2097152K), 6.6845837 secs] 4239009K->1519344K(4928320K), [Metaspace: 223389K->223389K(1269760K)], 6.6863578 secs] [Times: user=6.70 sys=0.00, real=6.69 secs]
接着,我们再看一下那段时间内的接口耗时情况:
图12:问题复现时的 queryAll 耗时倒序列表
所有接口的消耗时间都很长,也是符合预期的。最后再看一个长 RT 接口的链路信息:
图13:某个长 RT 接口的链路信息
会发现和图片1,也就是业务同学反馈的问题是一致的,说明复现效果符合预期。
验证到这里,可以证明我们的结论是正确的了。找到了问题的根源,这个问题可以归档了。
5. 进一步探索
5.1 耗时测算
出于性能考虑,Pinpoint 给出的链路信息力度比较粗,以致于我们无法详细得知 queryAll 方法的耗时构成是怎样的。为了搞清楚这里面的细节,我对 queryAll 方法耗时情况进行比较详细的测算。在应用负载比较低的情况下触发一个请求,并使用 Arthas 的 trace 命令测算链路耗时。得到的监控如下:
图14:正常情况下 queryAll 方法链路信息
这里我对三个方法调用进行了编号,方法 ① 和 ② 之间存在 252 毫秒的间隔,方法 ② 和 ③ 之间存在 294 毫秒的间隔。Arthas 打印出的链路耗时情况如下:
图15:queryAll 方法耗时测量
这里的编号与上图一一对应,其中耗时比较多的调用我已经用颜色标注出来了。首先我们分析间隔1的构成,方法 ① 到 ② 之间有两个耗时的操作,一个是批量的模型转换,也就是把 DO 转成 DTO,消耗了约 79.6 毫秒。第二个耗时操作是 Object 的 toString 方法,约 171.6。两者加起来为 251.2,与全链路追踪系统给出的数据是一致的。这里大家肯定很好奇为什么 toString 方法会消耗掉这么多时间,答案如下:
public void put(Object key, Object value) {
// 省略判空逻辑
// 把 key 和 value 先转成字符串,再进行判空
if (StringUtils.isBlank(key.toString()) || StringUtils.isBlank(value.toString())) {
return;
}
CacheClient.set(key, value);
}
这是方法 ① 和 ② 路径中的一个方法,这段代码看起来人畜无害,问题发生在判空逻辑上(历史代码,不讨论其合理性)。当 value 是一个非常大集合或数组时,toString 会消耗掉很多时间。同时,toString 也会生成一个大字符串,无形中消耗了内存资源。这里看似不起眼的一句代码,实际上却是性能黑洞。这也提醒我们,在操作大批量数据时,要注意时空消耗。
最后,我们再来看一下方法 ② 和 ③ 之间的间隔问题,原因已经很明显了,就是 value 序列化过程消耗了大量的时间。另外,序列化好的字节数组也会暂时存在堆内存中,也是会消耗不少内存资源的。
到这里整个分析过程就结束了,通过上面的分析,我们可以看出,一次简单的查询竟然能引出了这么多问题。很多在以前看起来稀疏平常的逻辑,偶然间也会成为性能杀手。日常工作中,还是要经常关注一下应用的性能问题,为应用的稳定运行保驾护航。
5.2 内存消耗测算
由于问题发生时,JVM 只是进行了 FGC,内存并没有溢出,所以没有当时的内存 dump 数据。不过好在问题可以稳定复现,通过对 JVM 进行一些配置,我们可以让 JVM 发生 FGC 前自动对内存进行 dump。这里使用 jinfo 命令对正在运行的 JVM 进程设置参数:
jinfo -flag +HeapDumpBeforeFullGC $JVM_PID
拿到内存数据后,接下来用 mat 工具分析一下。首先看一下内存泄露吧:
图16:应用内存泄露分析
从内存消耗比例上来看,确实存在一些问题,主要是与 dubbo 的线程有关。随便选一个线程,在支配树(dominator tree)视图中查看线程支配的对象信息:
图17:dubbo 线程支配树情况
从上图可以看出,dubbo 线程 retained heap 约为 66 MB,主要由两个大的对象 ArrayList 和 StringBuilder 组成。ArrayList 里面存放的是 DTO,单个 DTO 的 retained heap 大小约为 5.1 KB。StringBuilder 主要是 toString 过程产生的,消耗了接近 26 MB 的内存。从 dump 的内存数据中没找到 DO 列表,应该是在 YGC 时被回收了。
好了,关于内存的分析就到这吧,大概知道内存消耗是怎样的就够了,更深入的分析就不搞了。
6. 总结
由于排查经验较少,这个问题断断续续也花了不少时间。这中间有找不到原因时的郁闷,也有发现一些猜想符合预期时的欣喜。不管怎么样,最后还是找到了问题的原因。在帮助别人的同时,自己也学到了不少东西。总的来说,付出是值得的。本文的最后,对问题排查过程进行简单的总结吧。
一开始,我直接从具体现象开始排查,期望找到引发现象的原因。进行了各种猜想,但是都没法得出合理的结论。接着扩大信息面,仍然无果。之后综合各种信息,思考之后,换个方向排查,找到了原因。最后进行验证,并对一些疑点进行解释,整个过程结束。
最后说说这次排查过程存在的问题吧。第一个问题是没有注意甄别别人反馈过来的信息,没有对信息进行快速确认,而是直接深入了。花了很多时间尝试了各种猜想,最终均无果。由于别人反馈过来的信息通常都是比较零碎片面的,甚至是不正确的。对于这些信息可以快速确认,幸运的话能直接找到原因。但如果发现此路不通,就不要钻牛角尖了,因为这个现象可能只是众多现象中的一个。在这个案例中,接口长 RT 看起来像是 druid 导致的,实际上却是因为 GC 造成 STW 导致的。继续沿着 druid 方向排查,最终一定是南辕北辙。其他的问题都是小问题,就不说了。另外,排查过程中要注意保存当时的一些日志数据,避免因数据过期而丢失,比如阿里云 RDS SQL 洞察是有时间限制的。
本篇文章到此结束,感谢阅读!
本文在知识共享许可协议 4.0 下发布,转载请注明出处
作者:田小波
原创文章优先发布到个人网站,欢迎访问:https://www.tianxiaobo.com
本作品采用知识共享署名-非商业性使用-禁止演绎 4.0 国际许可协议进行许可。
以上是关于项目之接口响应慢排查的主要内容,如果未能解决你的问题,请参考以下文章
Inet4AddressImpl.getHostByAddr 慢
网页响应慢,waiting(TTFB)时间过长,接口返回耗时,数据库占用CPU 90%以上