如何从消失的异常堆栈定位线上问题

如何,消失,异常,堆栈,定位,问题 · 浏览次数 : 266

小编点评

**一、快速定位问题** 1. 查找异常堆栈信息,如果异常堆栈完整,可以分析异常原因。 2. 如果异常堆栈不完整,可以尝试关闭fast throw优化功能,重新编译方法以排除fast throw带来的优化。 3. 使用日志向前追溯相同的日志,定位问题。 **二、Fast Throw机制** Fast Throw 是 JVM 中用于优化异常处理的技术。当异常在相同位置被抛出多次时,JIT 会重新编译方法以使用预分配的异常进行处理,以提高性能。 **三、问题原因定位** 1. 分析接口可用率降低问题的原因。 2. 分析TCP重传数高问题的原因。 **四、问题原因分析** **1. TCP重传** 多台机器或同一机房同时进行TCP重传的原因可能是网络抖动单机或某个应用出现TCP重传一般是由于链路的服务器或端口无法访问,对于虚拟机或docker,还需要考虑宿主机的问题。 **2. Docker 连接性问题** 由于宿主机连接性问题导致docker实例TCP重传增高,问题也可能根源于宿主机连接性问题。

正文

一、消失的异常堆栈

在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
10w 996ms 3525ms
100w 5983ms 28345ms
500w 35678ms ——

言而简之,不能因此出现了消失的异常堆栈就尝试关闭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 error
com.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 more
19:05:44.063 [JSF-BZ-22001-245-T-503] ERROR com.jd.m.soa.shop.service.jsf.shop.impl.ShopSoaOutSideJsfServiceImpl - ShopSoaOutSideJsfServiceImpl.getKACard error
com.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
19: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。快速重传则依赖于数据包的期望序列号,并进行一致性检查。

  • 多台机器或者同一机房同时TCP重传

很大原因是网络抖动

  • 单机或者某个应用出现TCP重传

一般是由于链路的服务器或端口无法访问,对于虚拟机或者docker,还需要考虑宿主机的问题。

通过系统级分析,最后确定是由于宿主机连接性问题导致docker实例TCP重传增高,当然最重要的是补充相关的指标监控。

总之,无论是在大促期间还在平时,遇到问题首先解决好问题,更为重要的是追本溯原,找出问题的根因,以便推动团队优化和提升。

作者:京东零售 张帅

来源:京东云开发者社区

与如何从消失的异常堆栈定位线上问题相似的内容:

如何从消失的异常堆栈定位线上问题

在618保障大促稳定性过程中,消失的异常堆栈可能会给我们带来严重的麻烦,因为这些堆栈信息是我们解决线上问题的关键之一。如何快速定位问题?想必大家心中都有自己的答案,当然最简单直接的办法还是查找异常堆栈信息。

【RocketMQ】消息的拉取总结

在上一讲中,介绍了消息的存储,生产者向Broker发送消息之后,数据会写入到CommitLog中,这一讲,就来看一下消费者是如何从Broker拉取消息的。 RocketMQ消息的消费以组为单位,有两种消费模式: 广播模式:同一个消息队列可以分配给组内的每个消费者,每条消息可以被组内的消费者进行消费。

toastr.js 便捷弹框怎么用?怎么本地化?

toastr.js 是一个非常简洁的弹窗消息插件,本文将从如何引用开始,逐步将其本地化使用。

过年回去,终于给老人讲清楚两台电脑是如何通信的

摘要:本文将从小白的角度,讲解两台计算机之间是如何精确的找到对方的位置并发送和接收消息的,以从宏观角度把握计算机网络的体系结构。 本文分享自华为云社区《两台计算机之间究竟是如何通信的?》,作者:龙哥手记。 计算机网络的知识点非常杂乱且琐碎,非常容易让人产生畏惧心理。其实计网通篇研究的核心就是不同计算

【Azure 应用服务】Azure Function Python函数中,如何获取Event Hub Trigger的消息Event所属于的PartitionID呢?

问题描述 在通过Azure Function消费Event Hub中的消息时,我们从Function 的 Trigger Details 日志中,可以获得当前Funciton中处理的消息是哪一个分区(PartitionID), 偏移量Offset,序列号SequenceNumber 等信息。 但是在

Kafka为什么这么快?

Kafka 是一个基于发布-订阅模式的消息系统,它可以在多个生产者和消费者之间传递大量的数据。Kafka 的一个显著特点是它的高吞吐率,即每秒可以处理百万级别的消息。那么 Kafka 是如何实现这样高得性能呢?本文将从七个方面来分析 Kafka 的速度优势。 - 零拷贝技术 - 仅可追加日志结构 -

从Kafka中学习高性能系统如何设计

相信各位小伙伴之前或多或少接触过消息队列,比较知名的包含Rocket MQ和Kafka,在京东内部使用的是自研的消息中间件JMQ,从JMQ2升级到JMQ4的也是带来了性能上的明显提升,并且JMQ4的底层也是参考Kafka去做的设计。在这里我会给大家展示Kafka它的高性能是如何设计的,大家也可以学习相关方法论将其利用在实际项目中,也许下一个顶级项目就在各位的代码中产生了。

VOP 消息仓库演进之路|如何设计一个亿级企业消息平台

VOP作为京东企业业务对外的API对接采购供应链解决方案平台,一直致力于从企业采购数字化领域出发,发挥京东数智化供应链能力,通过产业链上下游耦合与链接,有效助力企业客户的成本优化与资产效能提升。本文将介绍VOP如何通过亿级消息仓库系统来保障上千家企业KA客户与京东的数据交互。

【RocketMQ】消息的消费总结

消费者从Broker拉取到消息之后,会将消息提交到线程池中进行消费,RocketMQ消息消费是批量进行的,如果一批消息的个数小于预先设置的批量消费大小,直接构建消费请求ConsumeRequest将消费请求提交到线程池处理,否则需要分批构建进行提交。 消息消费 在消息被提交到线程池后进行处理时,会调

【Azure 存储服务】Azure Storage Account Queue中因数据格式无法处理而在一个小时内不在可见的问题

问题描述 在从Storage Account 队列中获取数据(Queue),在门户中,明显看见有数据,但是通过消费端代码去获取的时候,就是无法获取到有效数据的情况。获取消息的代码如下: 问题解答 经过对 receiveMessages 方法定义的查询,第二个参数,第三个参数的两个时间表示的意思为 消