解决 Java 打印日志吞异常堆栈的问题

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
简介: 前几天有同学找我查一个空指针问题,Java 打印日志时,异常堆栈信息被吞了,导致定位不到出问题的地方。

前几天有同学找我查一个空指针问题,Java 打印日志时,异常堆栈信息被吞了,导致定位不到出问题的地方。

现象

捕获异常打印日志的代码类似这样:

try {
    // ...
} catch (Exception e) {
    log.error("系统异常 customerCode:{},data:{}", customerCode, data, e);
    // ...
}

查到的日志是这样的:

2023-06-26 11:11:11.111 ERROR 1 --- [pool-1-thread-1] c.mazhuang.service.impl.TestServiceImpl  : 系统异常 customerCode:123,data:{"name":"mazhuang","age":18}
java.lang.NullPointerException: null

异常堆栈丢了。

分析

在之前的一篇文章里已经验证过这种写法是可以正常打印异常和堆栈信息的:AI 自动补全的这句日志能正常打印吗?

再三确认代码写法没问题,纳闷之下只好搜索了一下关键词「Java异常堆栈丢失」,发现了这篇文章:Java异常堆栈丢失的现象及解决方法,这里面提到的问题与我们遇到的一样,而且给出了 Oracle 官方文档里的相关说明:

https://www.oracle.com/java/technologies/javase/release-notes-introduction.html

The compiler in the server VM now provides correct stack backtraces for all “cold” built-in exceptions. For performance purposes, when such an exception is thrown a few times, the method may be recompiled. After recompilation, the compiler may choose a faster tactic using preallocated exceptions that do not provide a stack trace. To disable completely the use of preallocated exceptions, use this new flag: -XX:-OmitStackTraceInFastThrow.

大致意思就是说,为了提高性能,JVM 会针对一些内建异常进行优化,在这些异常被某方法多次抛出时,JVM 可能会重编译该方法,这时候就可能会使用不提供堆栈信息的预分配异常。如果想要完全禁用预分配异常,可以使用 -XX:-OmitStackTraceInFastThrow 参数。

了解到这个信息后,翻了翻从服务上次发版以来的这条日志,果然最早的十几次打印是有异常堆栈的,后面就没有了。

解决方案

  • 回溯历史日志,找到正常打印的堆栈信息,定位和解决问题;

  • 也可以考虑在 JVM 参数里加上 -XX:-OmitStackTraceInFastThrow 参数,禁用优化;

本地复现

在本地写一个简单的程序复现一下:

public class StackTraceInFastThrowDemo {
    public static void main(String[] args) {
        int count = 0;
        boolean flag = true;
        while (flag) {
            try {
                count++;
                npeTest(null);
            } catch (Exception e) {
                int stackTraceLength = e.getStackTrace().length;
                System.out.printf("count: %d, stacktrace length: %d%n", count, stackTraceLength);
                if (stackTraceLength == 0) {
                    flag = false;
                }
            }
        }
    }

    public static void npeTest(Integer i) {
        System.out.println(i.toString());
    }
}

不添加 -XX:-OmitStackTraceInFastThrow 作为 JVM 参数时,运行结果如下:

...
count: 5783, stacktrace length: 2
count: 5784, stacktrace length: 2
count: 5785, stacktrace length: 0

Process finished with exit code 0

在我本机一般运行五六千次后,会出现异常堆栈丢失的情况。

添加 -XX:-OmitStackTraceInFastThrow 作为 JVM 参数时,运行结果如下:

...
count: 3146938, stacktrace length: 2
count: 3146939, stacktrace length: 2
count: 3146940, stacktrace length: 
Process finished with exit code 137 (interrupted by signal 9: SIGKILL)

运行了几百万次也不会出现异常堆栈丢失的情况,手动终止程序。

完整源码见:https://github.com/mzlogin/java-notes/blob/master/src/org/mazhuang/StackTraceInFastThrowDemo.java

参考

相关实践学习
通过日志服务实现云资源OSS的安全审计
本实验介绍如何通过日志服务实现云资源OSS的安全审计。
目录
相关文章
|
4月前
|
运维 监控 安全
Syslog 日志分析与异常检测技巧
系统日志蕴含设备运行关键信息,但分析提取颇具挑战。本文详解从命令行工具(如 Grep、Tail、Awk)到专业软件(如 EventLog Analyzer)的全流程日志分析技巧,助你高效挖掘 Syslog 价值,提升运维与安全响应能力。
270 4
|
4月前
|
Java 程序员 数据库连接
我们详细地讲解一下 Java 异常及要如何处理
我是小假 期待与你的下一次相遇 ~
|
7月前
|
SQL druid Oracle
【YashanDB知识库】yasdb jdbc驱动集成druid连接池,业务(java)日志中有token IDENTIFIER start异常
客户Java日志中出现异常,影响Druid的merge SQL功能(将SQL字面量替换为绑定变量以统计性能),但不影响正常业务流程。原因是Druid在merge SQL时传入null作为dbType,导致无法解析递归查询中的`start`关键字。
|
7月前
|
SQL Java 中间件
【YashanDB知识库】yasdb jdbc驱动集成BeetISQL中间件,业务(java)报autoAssignKey failure异常
在BeetISQL 2.13.8版本中,客户使用batch insert向yashandb表插入数据并尝试获取自动生成的sequence id时,出现类型转换异常。原因是beetlsql在prepareStatement时未指定返回列,导致yashan JDBC驱动返回rowid(字符串),与Java Bean中的数字类型tid不匹配。此问题影响业务流程,使无法正确获取sequence id。解决方法包括:1) 在batchInsert时不返回自动生成的sequence id;2) 升级至BeetISQL 3,其已修正该问题。
【YashanDB知识库】yasdb jdbc驱动集成BeetISQL中间件,业务(java)报autoAssignKey failure异常
|
8月前
|
Java 程序员 开发者
Java社招面试题:一个线程运行时发生异常会怎样?
大家好,我是小米。今天分享一个经典的 Java 面试题:线程运行时发生异常,程序会怎样处理?此问题考察 Java 线程和异常处理机制的理解。线程发生异常,默认会导致线程终止,但可以通过 try-catch 捕获并处理,避免影响其他线程。未捕获的异常可通过 Thread.UncaughtExceptionHandler 处理。线程池中的异常会被自动处理,不影响任务执行。希望这篇文章能帮助你深入理解 Java 线程异常处理机制,为面试做好准备。如果你觉得有帮助,欢迎收藏、转发!
517 14
|
8月前
|
缓存 Java 应用服务中间件
java语言后台管理若依框架-登录提示404-接口异常-系统接口404异常如何处理-登录验证码不显示prod-api/captchaImage 404 (Not Found) 如何处理-解决方案优雅草卓伊凡
java语言后台管理若依框架-登录提示404-接口异常-系统接口404异常如何处理-登录验证码不显示prod-api/captchaImage 404 (Not Found) 如何处理-解决方案优雅草卓伊凡
1379 5
|
8月前
|
XML JSON Java
Java中Log级别和解析
日志级别定义了日志信息的重要程度,从低到高依次为:TRACE(详细调试)、DEBUG(开发调试)、INFO(一般信息)、WARN(潜在问题)、ERROR(错误信息)和FATAL(严重错误)。开发人员可根据需要设置不同的日志级别,以控制日志输出量,避免影响性能或干扰问题排查。日志框架如Log4j 2由Logger、Appender和Layout组成,通过配置文件指定日志级别、输出目标和格式。
|
10月前
|
Java Maven
java项目中jar启动执行日志报错:no main manifest attribute, in /www/wwwroot/snow-server/z-server.jar-jar打包的大小明显小于正常大小如何解决
在Java项目中,启动jar包时遇到“no main manifest attribute”错误,且打包大小明显偏小。常见原因包括:1) Maven配置中跳过主程序打包;2) 缺少Manifest文件或Main-Class属性。解决方案如下:
2369 8
java项目中jar启动执行日志报错:no main manifest attribute, in /www/wwwroot/snow-server/z-server.jar-jar打包的大小明显小于正常大小如何解决
|
11月前
|
测试技术 开发工具 git
写了BUG还想跑——闲鱼异常日志问题自动追踪-定位-分发机制
为了高效地发现、定位和解决预发问题,闲鱼团队研发了一套异常日志问题自动追踪-定位-分发机制。这套机制通过自动化手段,实现了异常日志的定时扫描、精准定位和自动分发,显著降低了开发和测试的成本,提高了问题解决的效率。
480 15
写了BUG还想跑——闲鱼异常日志问题自动追踪-定位-分发机制
|
6天前
|
JSON 网络协议 安全
【Java】(10)进程与线程的关系、Tread类;讲解基本线程安全、网络编程内容;JSON序列化与反序列化
几乎所有的操作系统都支持进程的概念,进程是处于运行过程中的程序,并且具有一定的独立功能,进程是系统进行资源分配和调度的一个独立单位一般而言,进程包含如下三个特征。独立性动态性并发性。
42 1

热门文章

最新文章