相信大家都知道,作为一个开发,除了要会写bug之外,还要能够通过日志来解决bug。这样,线上出了问题,有人来找我们解决,有人需要我们,我们才能保住自己的饭碗……可见,要知道怎么检测和解决自己搞出来的bug是多么的重要。
嘿嘿,开个玩笑,引入正题。相信很多人在项目中都有用到日志管理工具:log4j、logback等。但是不知道有多少人是这样给项目添加日志配置的:项目要用到log4j,好的,导入相应的maven包,网上找个配置文件,看着比较靠谱,管他三七二十一,放项目里面试试,日志文件正常输出,ok,关闭配置文件,继续写bug去了,但是对于配置文件里面的配置却一知半解,反正能用就行。
这样其实是很不好的习惯,毕竟,只会CV的程序员是没有钱途的。强哥今天就根据自己之前做过的项目的实际案例简单的和大家聊聊在项目上线后,日志配置的一些问题,及处理办法。
首先,给个项目在最开始项目上线时,配置的log4j2.xml日志文件内容:
<?xml version="1.0" encoding="UTF-8"?><configuration status="WARN" monitorInterval="30"> <Properties> <Property name="fileName">./logs/xxx</Property> </Properties> <!--先定义所有的appender--> <appenders> <!--这个输出控制台的配置--> <console name="Console" target="SYSTEM_OUT"> <!--输出日志的格式--> <PatternLayout pattern="[xxx] [%d{yyyy-MM-dd HH:mm:ss,SSS}] [%t] [%p] %c{1}:%L - %m%n"/> </console> <!-- 这个会打印出所有的info及以下级别的信息,每次大小超过size,则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩,作为存档--> <RollingFile name="RollingFileDebug" fileName="${fileName}/debug.log" filePattern="${fileName}/$${date:yyyy-MM}/debug-%d{yyyy-MM-dd}-%i.log"> <!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)--> <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY"/> <PatternLayout pattern="[xxx] [%d{yyyy-MM-dd HH:mm:ss,SSS}] [%t] [%p] %c{1}:%L - %m%n"/> <Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="10 MB"/> </Policies> <DefaultRolloverStrategy/> </RollingFile> <RollingFile name="RollingFileInfo" fileName="${fileName}/info.log" filePattern="${fileName}/$${date:yyyy-MM}/info-%d{yyyy-MM-dd}-%i.log"> ……//内容类似上面的RollingFileDebug </RollingFile> <RollingFile …… </RollingFile> </appenders> <!--然后定义logger,只有定义了logger并引入的appender,appender才会生效--> <loggers> <!--过滤掉spring和mybatis的一些无用的DEBUG信息--> <logger name="org.springframework" level="INFO"></logger> <logger name="org.mybatis" level="DEBUG"></logger> <root level="debug"> <appender-ref ref="Console"/> <appender-ref ref="RollingFileDebug"/> …… </root> </loggers></configuration>
这个项目有个功能是通过定时器每分钟捞取第三方的接口的大量内容,获取数据后,再对数据进行处理入库。
日志配置中的:
<loggers> <!--过滤掉spring和mybatis的一些无用的DEBUG信息--> <logger name="org.springframework" level="INFO"></logger> <logger name="org.mybatis" level="DEBUG"></logger> <root level="debug"> <appender-ref ref="Console"/> <appender-ref ref="RollingFileDebug"/> …… </root></loggers>
可以看出,对日志进行了控制台输出之外,还进行了不同级别的日志输出及压缩打包。最终出来的日志文件目录类似这样:
结合项目的特点,不知道大家有没有觉得哪里需要改进的地方?
在项目刚上线的一段时间,并没有发现什么不妥的地方,日志文件正常输出,线上出了问题直接敲命令:tail -f console.log 就可以实时的看到日志输出,发现问题所在。而且每天也会自动进行日志文件归档,保留日志历史,看起来一切都是那么的合理且舒适。
可是,当项目运行一段时间之后,问题渐渐凸显。某天,强哥发现在部署其他项目到同一台机子的时候,磁盘不够用了???奇了怪,这个机子没放几个项目,怎么就没空间啦,直接敲命令看看有哪些大文件占用了磁盘空间:
find . -type f -size +800M -print0 | xargs -0 du -h | sort -nr
发现,上线一段时间后的项目,console.log日志文件居然达到了30多个G,这也太夸张了。不知不觉,项目的控制台输出日志自己膨胀到如此地步,简直无法无天。看看内容除了获取第三方接口数据输出之外,主要的日志输出都是sql语句的打印。于是很简单的处理办法就是,既然项目已经稳定上线,sql语句的输出看不看其实影响不大。于是,就先把日志输出级别改为INFO级别,减少sql语句的打印:
<loggers> <!--过滤掉spring和mybatis的一些无用的DEBUG信息--> <logger name="org.springframework" level="INFO"></logger> <logger name="org.mybatis" level="INFO"></logger> <root level="INFO"> <appender-ref ref="Console"/> <appender-ref ref="RollingFileDebug"/> <appender-ref ref="RollingFileInfo"/> <appender-ref ref="RollingFileWarn"/> <appender-ref ref="RollingFileError"/> </root></loggers>
可是没过多久发现,虽然改了日志输出级别,但是由于项目中定时器调用第三方接口的日志输出还是非常多,而且console.log文件并不会自动归档,该文件依然还会以极快的速度一天天膨胀,将磁盘耗尽。
没有办法,贪心不足蛇吞象,不用说了,今天就要把你这蛇给宰了:
<loggers> <!--过滤掉spring和mybatis的一些无用的DEBUG信息--> <logger name="org.springframework" level="INFO"></logger> <logger name="org.mybatis" level="INFO"></logger> <root level="INFO"> <appender-ref ref="RollingFileDebug"/> <appender-ref ref="RollingFileInfo"/> <appender-ref ref="RollingFileWarn"/> <appender-ref ref="RollingFileError"/> </root></loggers>
直接把控制台日志删了。有些人可能会问:输出日志不看了?出问题了怎么办?其实,日志还是能看得到的。我们看到,在配置中已经有了debug.log,info.log,error.log等文件,而这些文件根据不同的输出级别也是实时更新的。那么控制台日志在这种情况下其实就完全没有必要了,这玩意儿更适合开发适合用。
解决了这个问题之后,我们继续看看日志的归档配置,不知道大家知不知道下面的配置,日志是如何归档的。各种级别的日志在到达多大后会归档为一个文件?最多一个级别归档一天归档出几个文件?文件个数满了,后面的输出日志怎么办?
<RollingFile name="RollingFileDebug" fileName="${fileName}/debug.log"filePattern="${fileName}/$${date:yyyy-MM}/debug-%d{yyyy-MM-dd}-%i.log"><!--控制台只输出level及以上级别的信息(onMatch),其他的直接拒绝(onMismatch)--><ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY"/><PatternLayout pattern="[xxx] [%d{yyyy-MM-dd HH:mm:ss,SSS}] [%t] [%p] %c{1}:%L - %m%n"/><Policies> <TimeBasedTriggeringPolicy/> <SizeBasedTriggeringPolicy size="10 MB"/></Policies><DefaultRolloverStrategy /></RollingFile>
其实,也很简单,上面配置内容,注意这三行:
<TimeBasedTriggeringPolicy/><SizeBasedTriggeringPolicy size="10 MB"/><DefaultRolloverStrategy/>
第一行的意思是:通过时间触发归档,即到了某一时间时,不管当前主文件(如:debug.log)有多大,都对其进行归档(如输出:debug-2019-10-01-1.log);
第二行的意思是:当主文件大小达到10M时对文件进行归档。
第三行的意思是:根据某个滚动存储算法,保存同一天该级别的主日志文件的归档个数。上面使用的是默认算法,默认每天最多将主文件归档7份。
通过上面的配置后,在./2019-10/目录下的日志文件列表如下:
那么,一个级别的文档一天默认就保存7份够吗?像文章上面提到的,日志输出量很大,只保留7份不是依然不够吗?对的,我们其实可以通过设置上面第三行的配置,添加参数min,max等属性对归档文件个数进行限制,设置max=20甚至更大便可以保存更多份日志文件。
当然日志文件越多,占用磁盘空间就越大,而且假如设了20个还是不够呢?剩下新的日志是不是就丢了?
其实,默认的DefaultRolloverStrategy归档策略是:将当天最旧的日志删除,然后前面的日志文件末尾数字-1后重命名,最后新的日志写入新生成的数字最大的那个文件中。也就是说,丢掉旧的日志,保存较新的日志,没错,赤裸裸的渣男特性-->喜新厌旧。不过这个也比较符合我们的查看日志的情况:一般遇到线上问题之后,我们都喜欢先看看最近的日志是否有报错信息,找到错误后再解决问题。
当然,如果我们的项目日志是比较重要的,丝毫不能丢失的,比如支付相关的系统。那么,上面的处理方式就不是很适合了,日志文件必须时刻保留,可以考虑通过搭建ELK日志管理系统对日志就行处理。不过,因为这个不是本篇文章的重点,就不多提了,以后有机会可以聊聊。
希望大家以后在使用一个东西的时候,能够多想一想,多看一看,一个配置是否适用于不同环境,至少做到心中有数,这样对自己敲出来的代码也会更有信心。好啦,今天就到这,下期真的要开始设计模式了,哈哈!