一、消失的异常堆栈
在 618 保障大促稳定性过程中，消失的异常堆栈可能会给我们带来严重的麻烦，因为这些堆栈信息是我们解决线上问题的关键之一。如何快速定位问题？想必大家心中都有自己的答案，当然最简单直接的办法还是查找异常堆栈信息。
然而有时异常堆栈并不完整，只有一句描述，如下：
Caused by: java.lang.NullPointerException
复制代码
造成这种现象的原因其实很简单，原因如下：
JIT编译器对异常进行了优化，当代码中的某个位置抛出同一个异常很多次后,JIT服务端编译器(C2)会将其优化成抛出一个事先编译好的、类型匹配的异常,异常堆栈信息就看不到了。
复制代码
二、Fast Throw
Fast Throw，字段上理解就是快速抛异常，目前需要满足以下条件才有如此的优化：
只针对 HotSpot VM 才有, 例如 oracleJDK, libericaJDK 等
特定位置抛出很多次,其实就是 JIT 将它优化了
JIT 必须使用 C2 才会这样优化,不抛出原来的异常,改用 fast throw 抛出
这是一个事先分配好的异常,message 和堆栈都是空的
可以看出,如果某个异常在同一位置被抛出多次,会被 JIT C2 优化成空异常,例如本文的 NullPointerException,既没有 message,也没有堆栈.但他的速度非常快,不用分配内存和获取堆栈.
如果想关闭这个优化,设置-XX:-OmitStackTraceInFastThrow 即可。
存在即合理，既然存在 fast throw 的优化，必然有其价值。fast throw 优化的原因是为了提高性能。当同一种异常在相同的位置被抛出多次，编译器就会重新编译此方法。重编译后，编译器可能会使用不提供跟踪的预分配异常来选择更快的策略。
本地测试了一下抛出 NullPointerException,在开启与关闭 fast throw 的性能。
言而简之，不能因此出现了消失的异常堆栈就尝试关闭 fast throw 优化功能。
三、问题原因定位
对于线上环境中触发了 Fast Throw 机制，则可以通过向前追溯相同的日志来定位问题。
如在开门红中，有个接口的可用率调到 98.3%（不是 100%），如下图。
然后搜索日志发现大量的 Caused by: java.lang.NullPointerException，没有详细的异常堆栈，很显然是由于 fast throw 导致的，然后不断向前追溯相同的日志来定位问题如下图。
19:05:32.592 [JSF-BZ-22001-245-T-522] ERROR com.jd.m.soa.shop.service.jsf.shop.impl.ShopSoaOutSideJsfServiceImpl - ShopSoaOutSideJsfServiceImpl.getKACard errorcom.jd.sirector.SirectorException: java.lang.NullPointerException at com.jd.sirector.ScriptRuntime.waitIfNecessary(ScriptRuntime.java:129) ~[sirector-core-0.2.2-beta.jar:?] at com.jd.sirector.ScriptRuntime.run(ScriptRuntime.java:66) ~[sirector-core-0.2.2-beta.jar:?] at com.jd.sirector.Sirector.publish(Sirector.java:153) ~[sirector-core-0.2.2-beta.jar:?] **************** at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_60] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[?:1.8.0_60] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[?:1.8.0_60] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_60]Caused by: java.lang.NullPointerException at com.jd.******************wProxy.java:321) ~[shop-soa-service-1.1.jar:?] ************** ... 5 more19:05:44.063 [JSF-BZ-22001-245-T-503] ERROR com.jd.m.soa.shop.service.jsf.shop.impl.ShopSoaOutSideJsfServiceImpl - ShopSoaOutSideJsfServiceImpl.getKACard errorcom.jd.sirector.SirectorException: java.lang.NullPointerException at com.jd.sirector.ScriptRuntime.waitIfNecessary(ScriptRuntime.java:129) ~[sirector-core-0.2.2-beta.jar:?] at com.jd.sirector.ScriptRuntime.run(ScriptRuntime.java:66) ~[sirector-core-0.2.2-beta.jar:?] at com.jd.sirector.Sirector.publish(Sirector.java:153) ~[sirector-core-0.2.2-beta.jar:?] **************** at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_60] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[?:1.8.0_60] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[?:1.8.0_60] at java.lang.Thread.run(Thread.java:745) ~[?:1.8.0_60]Caused by: java.lang.NullPointerException19:05:47.831 [pool-84-thread-10] ERROR com.jd.m.soa.shop.service.base.shop.impl.ShopBaseServiceImpl - 上游返回的店铺星级值非法。value=0.0
复制代码
出现问题的原因找到了，接着就分析原因。原因很简单，由于某一台机器性能波动导致接口超时将兜底对象缓存，后续逻辑在处理的过种中对象中的 Boolean 属性值在转 boolean 时出现 NPE，问题根源还是代码兼容性不足够好。
这这台机器进行系统视图层分析，发现 TCP 重传数较高，如下左图。
四、问题原因分析
TCP 重传主要是为了保证数据传输的可靠性，TCP 是一种保证可靠传输的机制，如重传与确认机制、数据校验、数据分片、流量控制、拥塞控制等。TCP 重传的类型有超时重传和快速重传。超时重传是在请求包发送出去时开启计时器，当到达时间之后，没有收到 ACK，则进行重传直到达到上限次数或者收到 ACK。快速重传则依赖于数据包的期望序列号，并进行一致性检查。
很大原因是网络抖动
一般是由于链路的服务器或端口无法访问，对于虚拟机或者 docker，还需要考虑宿主机的问题。
通过系统级分析，最后确定是由于宿主机连接性问题导致 docker 实例 TCP 重传增高，当然最重要的是补充相关的指标监控。
总之，无论是在大促期间还在平时，遇到问题首先解决好问题，更为重要的是追本溯原，找出问题的根因，以便推动团队优化和提升。
作者：京东零售 张帅
来源：京东云开发者社区
评论