踩坑記(1)——使用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包版本:


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM