踩坑记——使用slf4j+logback记录日志

Posted 小菜变大鸟

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了踩坑记——使用slf4j+logback记录日志相关的知识,希望对你有一定的参考价值。

 刚开始的jar包版本如下,因为选择jar包版本不同导致的一些坑,踩过了就记录下来:

<spring.version>3.1.0.RELEASE</spring.version>
<slf4j.version>1.7.25</slf4j.version>
<logback.version>1.2.3</logback.version>
<logback.ext.version>0.1.1</logback.ext.version>

commons-logging:scope为provided,这样是为了打包时不会被带上,也就是不使用commons-logging而是准备使用slf4j
jcl-over-slf4j:这个是桥接包,将已经使用commons-logging记录日志又没法改变(spring默认使用的就是commons-logging)的jar包的日志桥接到slf4
slf4j-api:这就是我们要用的slf4j的日志接口,其实和commons-logging一样都是接口,不是具体实现
logback-classic:具体的日志实现,真正记录日志的jar
logback-ext-spring:为了将logback和spring集成而使用的包,如果不用这个包也可以记录日志,但会有个问题(下文会说)

<!-- log -->
<dependency>
<groupId>commons-logging</groupId>
<artifactId>commons-logging</artifactId>
<version>${commons-logging.version}</version>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jcl-over-slf4j</artifactId>
<version>${slf4j.version}</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>${slf4j.version}</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>${logback.version}</version>
</dependency>
<dependency>
<groupId>org.logback-extensions</groupId>
<artifactId>logback-ext-spring</artifactId>
<version>${logback.ext.version}</version>
</dependency>

准备好依赖后,开始配置logback的使用环境
在web.xml中配置logback的监听器,ch.qos.logback.ext.spring.web.LogbackConfigListener类就是logback-ext-spring.jar中的
logback默认也会查找几个地方的配置文件,不过我喜欢自定义路径,毕竟并不是所有公司都会讲配置全部放到resources目录下而是统一在硬盘上进行的管理

<!-- logback -->
<context-param>
<param-name>logbackExposeWebAppRoot</param-name>
<param-value>false</param-value>
</context-param>
<context-param>
<param-name>logbackConfigLocation</param-name>
<param-value>file:/opt/config/testservice/logback.xml</param-value>
</context-param>
<listener>
<listener-class>ch.qos.logback.ext.spring.web.LogbackConfigListener</listener-class>
</listener>

问题一:
程序正常启动,本来很开心的一件事,却遇到了转折,当改了java文件的代码并保存后,tomcat热部署reload会导致在项目重新加载过程中爆出异常——说可能导致内存泄露??纳里,表示完全是懵逼的

静下心看了看,发现居然是logback-1这个线程在重载的过程中没有被释放掉,那么每重载一次就会多出一个logback线程,当然也就会造成内存泄露了;在eclipse的debug视图的dubug窗口中查看线程,确实也是这种情况,重载前只有一个logback-1线程,重载后却有两个同名的logback-1了:

重载后如下图,报出内存泄露异常也是对的

那么什么原因造成的呢?我跟着监听器ch.qos.logback.ext.spring.web.LogbackConfigListener跟了下代码,发现是contextDestroyed执行时报错,所以也懒得深究原因了(其实就是代码写的有问题,在logback-ext-spring的0.1.2版本修复了)。

 

将logback-ext-spring从0.1.1替换到0.1.2(高于0.1.1就行)问题就解决了,看来这个jar包的作者也发现这个问题并修复了。我最后使用的版本就是<logback.ext.version>0.1.3</logback.ext.version>;完全看自己了最高版本目前是0.1.4而我的spring是3.1的最高只能和0.1.3的一起使用。

 

问题二:

     当解决了问题一后,以为终于可以好好玩耍了(其实完全可以正常玩耍了,只是强迫症。。。);同样看了下debug视图的debug窗口,发现刚启动的时候只有一个logback-1线程

之后,每一分钟会多出一个logback-n线程,一共会多出到logback-8,记一个日志有必要这么多线程么?

 

刚开始以为是哪里代码又问题,后来一想不可能,启动后什么也没做就慢慢增加,所以猜测是logback内部有什么猫腻,然后找到了logback-core内部创建线程池的地方,果然发现指定了常驻线程池的线程数

 

JDK文档,明确写了“保留在池中的线程数”,这个我是觉得有点多了,所以我就开始找低版本的

发现CoreConstants类中SCHEDULED_EXECUTOR_POOL_SIZE这个常量随着版本在变化,如下:

1.1.9以上     8
1.1.8       2
1.1.7       2
1.1.6及以下   无

最终分析,个人觉得没必要开启常驻内存8个线程来记录日志,所以我选择了1.1.7(参考maven仓库使用记录,选择使用人数较多的)

最终确定jar包版本:

<spring.version>3.1.0.RELEASE</spring.version>
<slf4j.version>1.7.25</slf4j.version>
<logback.version>1.1.7</logback.version>
<logback.ext.version>0.1.3</logback.ext.version>

总结:jar包并不是越新越好,而是要看你用了哪些功能,以上来就使用最新的包往往会出现一些与预期不一致的效果,解决起来又比较头疼~~

 

 

 

最终确定jar包版本:

以上是关于踩坑记——使用slf4j+logback记录日志的主要内容,如果未能解决你的问题,请参考以下文章

Logback日志输出踩坑记

SLF4J + logback 实现日志输出和记录

SLF4J - 借助SLF4J, 统一适配所有日志实现为logback日志实现的实践

Java# 在项目中使用SLF4J+Logback来记录日志

Java# 在项目中使用SLF4J+Logback来记录日志

IDEA项目搭建九——使用slf4j和logback进行日志记录