小日志大问题——Logger的错误使用导致的JAVA进程CPU占用过高问题

问题背景：

java工程和mysql混跑的一台服务器。最近的mysql的使用运算量比较大，然后就出现了查询运算卡死的情况。

最开始的排查方向放到了mysql上，结果始终找不到原因。

然后考虑是否是因为资源占用的问题，Top一看，java工程占用了160%以上的cpu，于是开始排查是什么原因导致的java这么大的cpu占用。

最后定位是日志过大导致的，日志级别从debug改成了info，减少日志量，优化前后cpu从最高160%多的占用降到了30%左右。

排查过程：

按照之前处理过的HttpClient buffer导致JAVA资源占用问题https://blog.csdn.net/wangyueshu/article/details/97391474的步骤排查，但是发现进程的子线程堆栈并没有阻塞或卡死的情况，不是代码逻辑或异常导致的。

然后想看看日志方面有没有什么异常。

工程日志分为ALL、INFO、FATAL、ERROR，发现两方面问题：

1. 日志记的比较混乱，有些常规的INFO信息打到了FATAL里，影响问题排查；

2. ALL日志特别大，满200M打包压缩，1分钟就能打一个，偶尔1分钟能打两个。进去一看DEBUG的日志全写里边了。

处理：

我们是使用的org.apache.logging.log4j，获取到logger后就可以通过log.debug/log.info/log.warn/log.error/log.fatal等记日志了，具体的日志设置是在工程resources中的配置文件log4j2.xml下。

1. 首先规范代码中的log.使用，要清楚每条日志的level层级（即对于工程的意义，致命的错误用FATAL、一般的错误用ERROR、警告用WARN、业务信息用INFO、代码调试的用DEBUG）然后选用合适的方法log.debug或log.warn等。

2. 线上运行的服务，要设置好日志记录的级别，尤其是访问量或数据量比较大的情况。

下面贴一下具体的配置文件。分别设置了控制台日志、Info日志、error日志、fatal日志，并设置了循环机制，即超出一定大小后日志就打包压缩等。

原来标红的All日志和root那设置的都是debug，处理后都改成info了。

 

<?xml version="1.0" encoding="UTF-8"?>

<!--
    status : 这个用于设置log4j2自身内部的信息输出,可以不设置,当设置成trace时,会看到log4j2内部各种详细输出
    monitorInterval : Log4j能够自动检测修改配置文件和重新配置本身, 设置间隔秒数。此处表示每隔600秒重读一次配置文件
-->
<Configuration status="OFF" monitorInterval="600">

    &