OOM本质是程序程序申请内存过大,虚拟机无法满足我们,然后自杀了。OOM经常伴随Full GC,高JDBC, Pending User Request等一系列的问题内存溢出的案例数不胜数, 所以日常运维中我们需要尽量避免OOM的发生。
DEBUG日志在日常的开发和运维可以用来排查和定位问题。为排查问题,很多时候,应用需要启用DEBUG日志。
而这次的故事主角就是DEBUG日志。
某客户的一个应用不可用告警,经查看应用进程丢失,日志中有明显的OOM报错,由于我们已经优化了生产环境参数,所以,在OOM的同时,应用也生成了对应的内存快照文件。
我们首选是打开内存快照文件进行问题定位,从分析工具自动生成的报告文件中得知,存在一个疑似内存泄漏点a
可见406个WebLogic Execute Thread占用了89.95%的内存。
看到这里,我们的第一个反应是,我们的线程在异常发生时间点是否正常?
有没有STUCK线程?
为什么会积攒406个执行线程?
是不是本身触发了WebLogic本身的Bug呢?
为了解答这些困惑,OLM工程师查看执行线程的信息来确认问题发生时间点执行线程在做什么(截取线程关键信息如下):
这部分代码
org.apache.http.impl.conn.Wire.wire
属于Apache Http Client
参考链接
http://hc.apache.org/httpcomponents-client-ga/httpclient/apidocs/org/apache/http/impl/conn/Wire.html
从官方的说明看这部分代码是控制报文日志记录。这一点,在dominator_tree结构图中得到了证实。
从展开的日志内容看,我们可以确认应用的log4j的日志级别为DEBUG(为确保客户信息,进行了脱敏处理)。
从Dump文件中,我们确认了出问题报文对应的URL请求
http://XXXXXXX:XXXXXX/XXXXGeneralHttpTask/GeneralService/CallxxxxxxResultDealReplace
确认了出现问题的应用包位置,并最终确认应用日志级别确实设置为Debug。
也说明填满内存的主要对象确实是DEBUG日志。
温馨提示:
Debug日志可以协调我们定位问题,但是在生产环境中还是需要谨慎开启,对于业务大的环境,我们每一个细微的参数,都有可能导致生产环境的崩溃。
| 北京 | 上海 | 广州 | 成都 |
4008-906-960