文档章节

一次日志打印错乱引出对jvm加载jar包顺序的研究

ericquan8
 ericquan8
发布于 2017/08/25 14:35
字数 886
阅读 415
收藏 0

问题现象

某天测试同学说最新版代码出的包日志打印有问题:1,日志输出目录变更了;2,日志格式也变更了;

跟我们定义的logback.xml完全不一样。

解决过程

日志出问题,先检查最终打到包里的logback.xml是否正确。直接解压看,正常的。用相同的代码在本地IDE跑,日志都是按照logback.xml中设置打印。没办法,再回去出问题的机器上看日志,发现日志格式是公司内部定义的;此时另外一个同学说有可能我们的logback.xml被覆盖了,在classpath中有另外一个logback.xml。有道理,去lib下搜一把。

找到了,确实是某个下游依赖库也引入另外一个logback.xml,立马找负责该库的兄弟解决问题,重新出包,done,日志恢复正常。但这样也不是方法,如果后面哪位兄弟再搞出一个logback文件,坑还得再才踩。翻下logback文档,发现可以指定具体logback.xml,不走默认配置,加以下启动参数:

-Dlogback.configurationFile=xxx/logback.xml

彻底解决问题~

相关思考

还有一个疑问,当前有两个logback.xml,为什么是我们的被覆盖?因为日志文件是打在jar包里的,那其实属于classloader加载jar包顺序的问题。google一下答案,找到一个说法:java加载jar的先后顺序是由操作系统决定(可参考深入探讨Java类加载器),而Linux系统决定的依据是该jar在系统中的INode值。

这样看,应该是我们jar包的inode值比下游依赖包的inode值大;下游依赖包被先加载,我们的包后加载。classloader遇到相同的logback.xml文件,就不在加载了。

由于没有保留案发现场,只能自己在本地再做一个测试,先搞两个测试库jar-a, jar-b,classpath中均有logback.xml,再搞另外一个java项目依赖这两库。以下是两个jar中定义的logback.xml中部分内容

<!-- jar-a的logback -->  
<appender name="Console" class="ch.qos.logback.core.ConsoleAppender">   
    <encoder charset="UTF-8">
        <pattern>[A-main] - %d{HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
    </encoder>  
</appender>

<!-- jar-b的logback -->  
<appender name="Console" class="ch.qos.logback.core.ConsoleAppender">   
    <encoder charset="UTF-8"> 
        <pattern>[B-main] - %d{HH:mm:ss.SSS} [%thread] %-5level %logger - %msg%n</pattern>
    </encoder>  
</appender>

将最终应用的项目打包:
打印代码:

log.info("i am robot");

看结果,先看inode:

jar-a的inode值比jar-b的大,再看实际日志输出:

classloader最终读取了jar-b中的logback.xml。好,同一台机换个inode:

这回jar-a的inode值比jar-b的小,再看实际日志输出:

看起来是inode值小的会被先加载,说得通了。然后第二天,问题出现了;我在另外两台机子上试,结果却是无论怎么改inode值,结果始终不变。此时心里是崩溃的~~~没办法,再找google大师问一把,最后在官方文档上翻到这样一句话:

The order in which the JAR files in a directory are enumerated in the expanded class path is not specified and may vary from platform to platform and even from moment to moment on the same machine. A well-constructed application should not depend upon any particular order. If a specific order is required, then the JAR files can be enumerated explicitly in the class path.

大意为:同一个目录下,jvm加载jar包顺序是无法保证的,每个系统的都不一样,甚至同一个系统不同的时刻加载都不一样。

这下终于豁然开朗了~

© 著作权归作者所有

ericquan8
粉丝 6
博文 17
码字总数 21510
作品 0
广州
程序员
私信 提问
Java学习笔记(九)——记录一次关于slf4j的线上问题排查

之前看我文章的小伙伴可能知道,由于我们公司由.net转java,所以我也一直在边做项目边学习java,这里记录一次排查slf4j记录日志相关的问题 遇到的问题 遇到的问题其实很简单,日志文件已经按...

Bug生活2048
2018/08/22
0
0
Android Java虚拟机拦截技术分析

最近反编译金山毒霸,分析其广告拦截功能是如何实现的。根据金山毒霸的介绍,采用了java虚拟机拦截技术,带着好奇去研究了一下。在查看代码过程中,会看到许多被hook的Java类,例如ActivityT...

JayPark不作死
2014/02/21
529
1
java项目中依赖的jar包中含有相同类时的加载顺序

新建一个javaProject,并打包,如下图: 新建第二个javaProject,并打包,其中的包名和类名及方法都和第一个project一致,只是输出不同: 新建测试project,引入上面两个包的依赖,main方法中...

一缕清风
2016/08/04
6.6K
1
java日志,需要知道的几件事

java日志,需要知道的几件事 如果对于commons-loging 、log4j 、slf4j 、LogBack 等都已经非常清楚了,可以忽略本文。几次解决日志冲突问题时对这几个概念的简单总结,希望对这块基础没有理解...

maoxiajun
2012/02/10
558
2
关于jdk1.6的instrumentation代理使用问题

Java SE 6 的新特性:虚拟机启动后的动态 instrument 在 Java SE 5 当中,开发者只能在 premain 当中施展想象力,所作的 Instrumentation 也仅限与 main 函数执行前,这样的方式存在一定的局...

关键词
2014/03/12
246
0

没有更多内容

加载失败,请刷新页面

加载更多

前端技术之:Prisma Demo服务部署过程记录

安装前提条件: 1、已经安装了docker运行环境 2、以下命令执行记录发生在MackBook环境 3、已经安装了PostgreSQL(我使用的是11版本) 4、Node开发运行环境可以正常工作 首先需要通过Node包管...

popgis
今天
5
0
数组和链表

数组 链表 技巧一:掌握链表,想轻松写出正确的链表代码,需要理解指针获引用的含义: 对指针的理解,记住下面的这句话就可以了: 将某个变量赋值给指针,实际上就是将这个变量的地址赋值给指...

code-ortaerc
今天
4
0
栈-链式(c/c++实现)

上次说“栈是在线性表演变而来的,线性表很自由,想往哪里插数据就往哪里插数据,想删哪数据就删哪数据...。但给线性表一些限制呢,就没那么自由了,把线性表的三边封起来就变成了栈,栈只能...

白客C
今天
43
0
Mybatis Plus service

/** * @author beth * @data 2019-10-20 23:34 */@RunWith(SpringRunner.class)@SpringBootTestpublic class ServiceTest { @Autowired private IUserInfoService iUserInfoS......

一个yuanbeth
今天
5
0
php7-internal 7 zval的操作

## 7.7 zval的操作 扩展中经常会用到各种类型的zval,PHP提供了很多宏用于不同类型zval的操作,尽管我们也可以自己操作zval,但这并不是一个好习惯,因为zval有很多其它用途的标识,如果自己...

冻结not
昨天
6
0

没有更多内容

加载失败,请刷新页面

加载更多

返回顶部
顶部