记一次颇有意思的Log4j超大日志问题定位

来源:互联网 发布:wine mac 中文 编辑:程序博客网 时间:2024/05/22 10:24

问题背景

随着工作年限增加,学习的东西越来越多。逐渐发现以前常用的东西放下一段时间需要再次使用的时候就想不起来,需要到处查资料。现在也开始强迫自己写点东西,留下一点线索,来日闲暇再做细细品味。

现象:

  • 系统Tomcat记录前端操作的日志超过1GB导致编辑器不能打开分析。

任何的问题离不开所处的环境,所以问题产生的背景是必须的:

  • Tomcat负责的前端,负责显示业务逻辑界面,向外提供Rest业务接口,通过RMI与后台osgi实现接口调用;
  • Tomcat集成ActiveMQ消息队列,负责前端和后端复杂业务数据传递;
  • osgi负责后端具体的设备数据同步、业务逻辑处理、数据库存取等具体实现;
  • 前后端共用一套从Log4j扩展的RollingFileAppender的日志组件以完成单个日志文件超过设置的阈值就将日志分片并压缩,并且只保留一定数量的日志;

处理过程

拿到问题单第一反应就是查看前后台生成的日志是否有相同的现象。但是很遗憾,前端出现日志超大的情况,后端一切正常。

没问题,继续后面的排查。系统同时运行在Linux和windows系统,既然Windows系统下由问题,正常情况下载Linux系统下也应该有一致的现象。立即到Linux系统下查看前后台的日志状况,结果前后台日志一切正常。相同的java代码放到不同的系统会有不一样的效果,我有一种晴天霹雳的感觉。

不过难不倒本人,既然日志问题只在Windows下出现,那就打开Tomcat的调试端口单步跟踪应该很容易就搞定的吧。由于线上系统不能随便破坏,那就搭一套线上环境希望可以出现相同的问题。说干就干,立马搭建环境,注入业务,然后怀着忐忑的心情等待后台日志增加;当日志超过阈值还没有分片时我的内心是窃喜的,因为之后的定位可以单步调试,场景可以无限次数复现,仿佛问题已经被拿下。

既然问题可以复现,那么就单步调试一下日志分片的过程,问题岂不是迎刃而解。有了这样的理论支持,立即配置调试环境:Tomcat打开远程调试端口,eclipse配置好调试端口,调小日志的阈值,便于频繁触发日志分片场景。
OK,一切准备就绪,马上进入调试模式,开始一步步跟踪。怪异的问题再次发生,代码顺利执行,并没有任何异常。但是日志没有分片。NND,灵异事件再次发生!没有关系,把扩展的日志代码代码每一句详细看一遍,但是并没有问题。

到现在所有能观察到和可供分析的线索都已被证明不是问题的核心线索,工作又陷入了毫无头绪,连摸索都没有方向。时间已经过了一天多了,工作又回到了原点。焦虑的情绪开始在产生,而没有方向感则更加令人沮丧。

在进行下一步工作之前将之前的定位工作成果进行梳理并做出推:

  1. 代码逻辑没有问题,问题总是会发生;
  2. 问题只发生在Windows系统上,并且Windows后台日志没有任何异常,只有前端日志有问题;
  3. 说明是前端代码日志触发了Windows系统的某个机制导致日志分片不成功;
  4. 那么问题可以限定在前端日志类的范围;
  5. 日志文件跟系统的某个文件有冲突;

基于以上的推测,第一次尝试将日志文件名添加下划线,重新启动。日志文件大小超过阈值即被分片,奇迹发生了!修改前端日志文件名可以规避或者完成问题的修改。但是按照流程,没有找到根因的问题单测试是不会予以认可和提交。

没有关系,至少有了一定的进展,已经无限接近问题的解决!

真相已经在眼前,只是羞怯的露出一点衣角,现在我们难以窥探其庐山真容。接下来又是不断的尝试和修改,各种的弯路和折腾。
直到一次将日志目录下的所有日志清空,准备重新观察日志的变化。突然一个变化进入到视野里,前端日志明明已经由web.log修改为web_.log,按道理日志目录下只会生成一个web_.log,但是现在的现象很难解释。
本着”事出反常必有妖“的格言,问题已经很明白了。前端日志文件除了使用log4j.xml指定,还通过代码构造了日志对象。接下来将”web“字段复制到eclipse中搜索,果然不出所料,不下30处使用到了静态日志工厂构造了日志对象。结果已经很明显,接下来就是构造场景验证是否如此,制定修改方案,走流程单,附上问题修改报告。

写在最后

到圆满解决!问题定位前前后后用了三天时间,其中滋味也是一波三折,从开始自信满满到接下来的山穷水复,再到柳暗花明;中间伴随着自我怀疑,犹豫不定的情绪;再一次提醒我在计算机世界中,魔鬼藏在细节中。幸运的是,最终问题单在变成疑难问题之前完成了定位和修改。

总结下来,问题单和架构有本质的区别。解决问题单需要深入到细节,对于计算机体系广度的理解和系统业务的深入理解;而架构更偏重于业务的设计和实现,尽量满足系统的模块化和良好扩展。但两者之间有非常大的重合,需要很好理解计算机体系和业务体系是成为优秀架构师的必要条件。

在此,抛出一个问题:log4j多个RollingFileAppender打开同一个文件,在Windows系统日志分片不成功,Linux系统下日志分片正常。这是什么原因,希望有深入研究得同学能够赐教。