9点快下班的时候,突然被拉进来一个群,说一台机器发生了异常。
从表象来说,这台机器的CPU占用高峰期是在夜里4点,但是过了很久才发生了oom。然后因为kill掉了某个消费者的线程,才被基础架构组的同事发现。
组里的老哥接着这次机会,向我介绍了他对OOM的一些理解。OOM其实很正常,但是只要JVM在OOM之后能自动恢复,或者对线上的主流程业务没有太大影响,就还是可以接受的。只需要在合适的时候去把它改掉。
那么事情的经过是怎样的呢?
首先前提夜里四点,一个定时任务,调用了我们的一个系统的接口。
这个接口负责将所有的历史订单数据缓存在redis中,以供订单数据的统计分析。但是
这个接口24下半年才上线,起初数据量不多,所以当时选择直接推送全量的数据。但是最近这个记录的数据越来越多。
存入redis本身这个操作并没有问题,但是呢,问题出现在日志打印的环节。
这个接口缓存数据后,会将所有的数据作为一份日志打印。
首先,这个日志数据是一个 Map 对象,数据量很大;然后将其转接为一个json字符串打印。
其次,打印日志的时候使用了一个日志工具,传参的时候,将这个大Json字符串进行了拼接。
这个这个大字符串就在内存中占用了很大的空间。
然后呢,这个过程中,就发生了OOM,JVM就选举了几个占用内存比较大的线程进行了销毁,释放资源。
这里应该是选中了日志打印的线程,和一个MQ消费者的线程。这两个线程都不会自动回复。
其中,日志打印是异步的,但是所有日志事件提交到日志队列中的,所以日志队列中慢慢的就会排满,因为日志打印的线程已经被kill了。
这里不确认,日志事件的队列满了之后,是如何影响那么提交日志事件的线程的。
同时,OOM的过程中,kill 了一个日志消费的线程,所以这个消息队列的消费时长就涨了上去。所以最终才能观察到。
这次OOM问题中,有两个点值得下次再说一下。
第一,就是前文提到的,对于字符串对象的理解要深入,要把八股和代码结合起来。这里的大Json字符串直接用+号拼接就是我犯的错误。
第二,日志打印任务的线程,是一个守护线程,那么它出现OOM的时候,和普通线程OOM有什么区别呢?那么我们讨论觉得是没有什么区别的。