问题现象
会员部分 dubbo 接口偶现超时异常，而且时间不规律，几乎每天都有。
该API正常调用耗时4-5 毫秒
调用方配置1秒超时,failfast无重试
部署docker 8节点,jdk1.8
问题分析
- 查看接口逻辑
简单的SQL走索引查询,无慢查询 - 搜索 dubbo 拦截器ElapsedFilter的耗时日志
部分请求耗时长
ElapsedFilter是 dubbo SPI 机制的扩展点之一，超过 300 毫秒的接口耗时都会打印
猜想
- 数据库方面的可能性
推测1: 代码中调用数据库查询可以分为两步，获取数据库连接和 SQL 查询，慢SQL 平台监测的 SQL 执行时间，既然慢 SQL 平台没有发现，那可能是建立连接耗时较长
操作1: 查看Druid 配置的 initial-size（初始化链接数）是 5，max-active（最大连接池数量）是 50，但 min-idle（最小连接池数量）只有 1
推测2: 可能是连接长时间不被使用后都回收了，有新的请求进来后触发建立连接，耗时较长
操作2: 调整 min-idle 为 10，追加 Druid 连接池使用情况日志，每隔 3 秒打印连接池的活跃数等信息，重新观察
结果: 还有超时发生。超时发生时的连接数正常，连接池连接数无波动 - STW(Stop The World)
现象：调用端调用多个接口都同时超时，另外，调用端的几台机器都会同时报超时（可以在 elk 平台筛选 hostname 查看），且超时发生在同一台服务节点
推测1: 应该是某一时刻提供服务的某台机器出现比较全局性的问题导致几乎所有接口都超时
操作1: 查看链路日志
发现1: 服务端收到请求的时间比调用端发起调用的时间晚了一秒
推测2: STW(Stop The World)。垃圾回收会导致短暂的应用停顿，无法响应请求
操作2: 查看GC LOG
-XX:+PrintGCDetails -Xloggc:${APPLICATION_LOG_DIR}/gc.log -XX:+PrintGCDateStamps
-XX:+PrintGCApplicationStoppedTime(打印其他导致应用停顿的操作，如取消偏向锁)
发现2: ParNew 新生代 GC过长
2.1 GC 的停顿导致应用不可用，进而导致接口超时 的可能性
- 排查新生代垃圾回收耗时过长的问题, 此时JVM参数
-Xmx5g -Xms5g -Xmn1g -XX:MetaspaceSize=512m
-XX:MaxMetaspaceSize=512m -Xss256k -XX:SurvivorRatio=8
-XX:+UseParNewGC -XX:+UseConcMarkSweepGC
-XX:CMSInitiatingOccupancyFraction=70
现象1: 堆占用低，FGC无
推测1: ParNew可能耗时的操作有：①找到并标记存活对象，②回收对象，③S0S1复制存活对象。而①前提为所有线程都跑到安全点后暂停所有线程，可能是此处
操作1: 打印所有安全点操作的耗时
-XX:+PrintSafepointStatistics -XX: PrintSafepointStatisticsCount=1
-XX:+UnlockDiagnosticVMOptions -XX: -DisplayVMOutput
-XX:+LogVMOutput -XX:LogFile=/opt/apps/logs/safepoint.log
结果1: spin+block为跑到安全点并响应的时间，此处耗时短。
vmop[跑到安全点之后的操作]耗时长。排除线程等待进入安全点耗时过长的可能。
推测2: FinalReference[有finalize方法的Obj的引用形式]。框架会在对象 finalize 方法中做一些资源回收，关闭连接的操作，导致垃圾回收耗时增加。
操作2: 1.打印各类 Reference 回收的时间，2. 查复制存活对象的耗时
-XX:+PrintReferenceGC
结果2: FinalReference 的回收时间也极短。 YGC后存活对象少，复制不怎么耗时
2.2 垃圾回收线程 的可能性
推测1: 从 GC log 发现有两次 GC 回收的对象大小几乎一样，但是耗时却相差十倍，因此建议确认下系统的 CPU 情况，是否是虚拟环境，可能存在激烈的 CPU 资源竞争。
操作1: 通过 jstack 命令打印线程堆栈查看GC 线程数达到了 53个。
分析1: JVM 的 GC 线程数量是根据 CPU 的核数确定的，如果是八个核心以下，GC 线程数等于CPU 核心数，应用跑在 docker 容器，分配的核心是六核，实际GC线程数不合理
JVM 在 docker 环境中，获取到的 CPU 信息是宿主机的（容器中 /proc目录并未做隔离，各容器共享，CPU信息保存在该目录下），并不是指定的六核心，宿主机是八十核心，因此创建的垃圾回收线程数远大于 docker 环境的 CPU 资源，导致每次新生代回收线程间竞争激烈，耗时增加。
解决方案
-XX:ParallelGCThreads=6 -XX:ConcGCThreads=6
自此解决垃圾回收耗时较长问题
Docker——JVM 感知容器的 CPU 和 Memory 资源限制
摘自 https://www.cnblogs.com/caoweixiong/p/12427202.html
- 获取容器分配的CPU信息
java5/6/7/8u131以前：手动设置jvm相关的选项，如：
ParallelGCThreads
ConcGCThreads
G1ConcRefinementThreads
CICompilerCount / CICompilerCountPerCPU
java 8u131+ 和 java 8u191以前：--cpuset-cpus
java 8u191+： UseContainerSupport默认开启
java 10+: 使用最新版就好了，UseContainerSupport默认开启 - 获取容器分配的Memory信息
java5/6/7/8u131以前：务必设置内存选项
java8u131+ 和 java9+
java 8u131+ 和 java 8u191以前：-XX:+UnlockExperimentalVMOptions -XX:+UseCGroupMemoryLimitForHeap
java 8u191+： UseContainerSupport默认开启
java10+: 使用最新版就好了，UseContainerSupport默认开启
问题又现
现象: 同一时间多个接口同时超时, GC耗时正常。
推测: 受 GC 线程数思路的启发，由于应用运行基本不涉及刷盘的操作，都是 CPU 运算+内存读取，耗时仍旧应该是线程竞争或者锁引起的
操作: 用 jstack 对堆栈进行排查
结果: 发现总线程数仍有 900+，处于一个较高的水平，其中 forkjoin 线程和 netty 的 worker 的线程数仍较多
分析: 重新搜索代码中线程数是通过CPU核心数设置（Runtime.getRuntime().availableProcessors()）的地方，发现还是有不少框架使用这个参数，这部分无法通过设置JVM参数解决
对策: Java 8u221，并开启 cpu set，指定容器可使用的 CPU 数
新的超时问题
现象: 观察具体的超时机器和时间，发现并不是多台机器超时，而是一段时间有某台机器比较密集的超时，而且频率比之前密集了许多。
分析: 1 .对比之前的超时问题，以前的超时在各机器之间较为随机，而且频率低很多。2. 怀疑是宿主机或者是网络问题了
操作: 使用 tcpdump 命令抓取host 是调用方进来的包并保存抓包记录，通过 wireshark 分析（wireshark 是抓包分析神器）
结果: 抓到了一些异常包
注意抓包中出现的 「TCP Out_of_Order」,「TCP Dup ACK」,「TCP Retransmission」，三者的释义如下:
TCP Out_of_Order: 一般来说是网络拥塞，导致顺序包抵达时间不同，延时太长，或者包丢失，需要重新组合数据单元，因为他们可能是由不同的路径到达你的电脑上面。
TCP dup ack XXX#X: 重复应答，#前的表示报文到哪个序号丢失，#后面的是表示第几次丢失
TCP Retransmission：超时引发的数据重传
操作: 通过在 elk 中超时日志打印的 contextid，在 wireshark 过滤定位超时的 TCP 包，发现超时的时候有丢包和重传。抓了多个超时的日志都有丢包发生
结论: 确认是网络问题引起
对策: 转容器组继续排查网络偶发丢包问题
