背景
上线新功能后，要多观察。如果出现不稳定性的情况，需要高优先级查清原因，避免出现更大的问题。
问题描述
部分应用出现重启
过程
-
11:58，接到报警，一个pod1三分钟内存在重启
-
12:02，pod1已经5分钟没有报警，数据已经正常恢复【有耗内存的功能，多人同时触发时，偶尔也会重启】
-
12:06，JVM监控 节点机IP: 10.10.48.116 JVM_FullGC次数，最近2分钟求平均 >= 5.0 次, 当前值5.0000 次
-
12:07，JVM监控 节点机IP: 10.10.48.116 JVM_FullGC，数据已经正常恢复
-
12:15，接到报警，pod2三分钟内存在重启告警
-
12:18，pod2和pod3三分钟内存在重启告警
-
12:20，pod2和pod3和pod4三分钟内存在重启告警
-
12:24，查看重启pod日志，发现一直在刷查询tableStore异常的日志： 2022-09-01 12:24:41[16-d ][I/O dispatcher 36] WARN c.a.o.tablestore.core.utils.LogUtil - TraceId:8-1 Failed RetriedCount:1 [ErrorCode]: OTSServerBusy , [Message]: Service is busy., [RequestId]:00-e1, [TraceId]:81db-cd, [HttpStatus:]503
-
12:25，JVM监控 节点机IP: 10.10.48.117 JVM_FullGC次数最近2分钟求平均 >= 5.0 次, 当前值5.5000 次
-
12:25，从 2022-09-01 12:22:00 开始，在 0 天, 3 分钟内发生 3 次 JVM监控 节点机IP: 10.10.48.117 JVM_FullGC次数最近2分钟求平均 >= 5.0 次, 当前值5.5000 次 JVM监控 节点机IP: 10.10.48.116 JVM_FullGC次数最近2分钟求平均 >= 5.0 次, 当前值5.0000 次
-
12:28，其它业务check过，没有明显异常。除个别业务在查询tableStore时也会出现503的报错
-
12:41，申请运维同学再加两个pod。增加可用pod数
-
12:50，添加pod后，重启没有停止。
-
13:07，查看是否有OOM。没有
-
13:22，收到阿里tableStore的同学反馈，503的原因是索引查询用的索引不是覆盖索引， 反查主表压力过大引起的5XX错误
-
13:23，把涉及的查询的定时任务都停掉
-
13:30, JVM_FullGC和pod重启告警 没有停止
-
13:40，看到是full GC告警，增加Pod和JVM堆内存各4G,并重新发版
-
13:42，重新发版完成。JVM_FullGC和pod重启告警都消失
-
14:00，把之前停止的定时任务启动
服务不稳定状态时堆内存及GC情况
故障原因
出现占用大内存的操作，导致FullGC频繁。
原因分析
- 是不是TableStore的异常导致服务异常
不是。看查询报错的请求低于12%
ots的报错情况
- pod为什么会重启
Full GC耗时过长，导致容器判定pod异常，并将其重启。
异常期间，pod存活探测的规则如下：
livenessProbe: # 存活探测的相关配置如下
httpGet:
path: /ready
port: http
initialDelaySeconds: 180
periodSeconds: 10 # 每隔10s探测一次
timeoutSeconds: 1 # 如果/ready接口1s内没有返回，则判断失败
successThreshold: 1
failureThreshold: 3 # 连续失败3次，则判断pod异常。容器重启pod
FullGC时会STW，此时所有请求都会阻塞。
FullGC耗时超过30s，pod就会重启。异常期间FullGC耗时都超过120s了。按配置的规则，容器会重启该pod
FullGC超过30s，则容器会将pod重启
-
为什么会触发FullGC
出现了耗内存的操作。
TableStore服务器返回的数据，占用大量内存
新加的查询TableStore的业务线程
-
上述业务占用内存是否合理
不合理。从业务上看，每次查询符合条件的记录最多不会超过100条。但现在返回了 131262 条
返回的数据量过多
核对过代码，发现查询条件错误。查询tableStore的三个条件应该是and的关系，但现在是or
-
这么严重的逻辑错误，为什么会出现
存在错误逻辑是2020年上线的老代码。写新功能的同学，直接copy过去。想着是两年前的线上代码，code reivew就没有作为重点，具体过程，相关的同学都不记得了。
-
这么严重的逻辑错误，为什么之前服务没有出现这种问题
之前的服务也是有问题的。
老代码由一个定时任务触发。只是串行查询TableStore，虽然会耗内存，但如果正在执行的pod没有其它在执行的耗内存操作，是不会触发FullGC的。
这也可能是当前应用偶发出现重启的原因。
新业务场景是接收到mq消息然后根据条件去触发这段老代码，当同时接收n个消息，则占用的内存*n ，则很容易触发FullGC
- 新功能上线快1周了，为什么今天才触发此异常
在查询TableStore，需要满足条件才会触发有异常的老代码。异常时，触发异常逻辑的的业务数据较多。
- 测试环节为什么没有发现
case没有全部覆盖业务场景。
当三个and的筛选条件被错写成or，查到的数据会变多。
目前的这个场景所涉及到的查询结果数据，被用于数据权限控制，返回的数据变多时造成的问题是，该看到该数据的人可以看到，不该看到该数据的也可以看到。
如果测试case只有一个：该查看数据的人是否可以查看。那么，测试是通过的。
小结
-
异常出现时，一象限的操作
如果pod重启时，是qps增高，则优先增加Pod
如果pod重启时，识别到FullGC耗时过长，则优先考虑增加内存来解决
出现异常时，要把jvm堆内的数据dump出来。在没有找到异常原因时，要把dump出来的堆数据都查看一下，因为dump时，有的pod中的jvm可能刚启动不久，异常操作还没有被触发。
-
异常出现后，二象限的操作
已经在线的代码，如果新功能涉及到，尽量不要copy
已经在线的代码，如果新功能涉及到，也要CodeReview
待上线的代码，要测试充分
待上线的功能，关键路径，测试Case要全面
增加jvm堆内存的告警，如果超过80%时就告警，然后dump出Heap内的数据进行分析
每个迭代确保用于技术优化的时间。目前这部分有一个bug需要解决：当前的规则中，需求的优先级是由产品决定，一个技术需求如果产品把优先级降低，如果引发故障，产品却不需要承担责任。需要推动这个事情解决，保持权责利一致，做多大的决定，就需要负多大的责任，也享受多大的利好。
网友评论