一、前言
公司中的項目雖然已經用了很多的新技術了，但是日志的底層框架還是log4j，個人還是不喜歡用這個的。最近項目再生產環境上由於log4j引起了一場血案，於是決定升級到log4j2。
二、現象
雖然生產環境有多個結點分散高並發帶來的壓力，但是消息中心上一周好多接入方接入，導致並發量一下就增多了，導致服務卡死。在堆棧信息中看到大量的BLOCK異常，如下。
"http-nio-172.17.20.113-28080-exec-6452" #381905 daemon prio=5 os_prio=0 tid=0x00007f49e857e000 nid=0x8427f waiting for monitor entry [0x00007f49c1c75000] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:204) - waiting to lock <0x00000000e5915bd8> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.log(Category.java:856) at org.slf4j.impl.Log4jLoggerAdapter.log(Log4jLoggerAdapter.java:581) at com.cmos.core.logger.DefaultLogger.log(DefaultLogger.java:385) at com.cmos.core.logger.DefaultLogger.log(DefaultLogger.java:398) at com.cmos.core.logger.DefaultLogger.doLog(DefaultLogger.java:350) at com.cmos.core.logger.DefaultLogger.info(DefaultLogger.java:200) at com.cmos.core.logger.DefaultLogger.info(DefaultLogger.java:195) "http-nio-172.17.20.113-28080-exec-6452" #381905 daemon prio=5 os_prio=0 tid=0x00007f49e857e000 nid=0x8427f waiting for monitor entry [0x00007f49c1c75000] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:204) - waiting to lock <0x00000000e5915bd8> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.log(Category.java:856) at org.slf4j.impl.Log4jLoggerAdapter.log(Log4jLoggerAdapter.java:581) at com.cmos.core.logger.DefaultLogger.log(DefaultLogger.java:385) at com.cmos.core.logger.DefaultLogger.log(DefaultLogger.java:398) at com.cmos.core.logger.DefaultLogger.doLog(DefaultLogger.java:350) at com.cmos.core.logger.DefaultLogger.info(DefaultLogger.java:200) at com.cmos.core.logger.DefaultLogger.info(DefaultLogger.java:195)
三、log4j高並發線程block原因
log4j-1.2.16 Category forcedLog邏輯如下
log4j版本1.x中，使用的是synchronized(this)進行同步操作，所有線程共用一個Category，而它通過log4j.properties指定。 同一個Category下的線程打log時，需要進行全局同步，因此它的效率會很低，log4j 1.x版不適合高並發的場景。
為了杜絕這種現象的發生，最好升級到log4j2，或者更換為logback。
四、log4j2和logback選擇
到底是升級到log4j2呢，還是將底層日志框架更換為logback呢？
檢查了一下項目直接使用log4j Logger的情況，發現部分工具類中使用了（這倒沒有問題，可以統一改一下），沒有想到是系統部封裝的框架中居然也直接使用了log4j 的Logger，心里頓時說了一聲“草尼瑪啊...”。
既然是這樣的話，肯定不能使用logback了，也不能直接升級成log4j2了。
五、log4j1 如何平滑升級到log4j2
The Log4j 1.2 Bridge allows applications coded to use Log4j 1.2 API to use Log4j 2 instead.
1.依賴如下
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-1.2-api</artifactId>
<version>2.6.2</version>
</dependency>
我們看一下 log4j-1.2-api-2.6.2 Category forcedLog邏輯如下，並沒有調用callAppenders方法。
Log4j2 包含了基於 LMAX Disruptor（高性能線程間消息通信庫）的下一代 Asynchronous Loggers。在多線程環境下，Asynchronous Loggers 的吞吐量是 Log4j1 和 Logback 的 18 倍，而延遲時間也要低一個數量級。
相信大家已經明白了，log4j-1.2-api-2.6.2橋接的原理就是復寫了log4j-1.2.16相關的類，再輸出日志的時候調用的是log4j2中的方法。
2.刪除掉 log4j的依賴
3.將log4j.properties 替換成 log4j2.xml
log4j.properties內容如下
log4j.rootLogger=INFO,ConsoleAppender,FileAppender log4j.appender.ConsoleAppender=org.apache.log4j.ConsoleAppender log4j.appender.ConsoleAppender.layout=org.apache.log4j.PatternLayout log4j.appender.ConsoleAppender.layout.ConversionPattern=%d %p [%t] %C.%M(%L) | %m%n log4j.appender.FileAppender=org.apache.log4j.DailyRollingFileAppender log4j.appender.FileAppender.File=${user.dir}/logs/@logging.file-web@ log4j.appender.FileAppender.DatePattern = '.'yyyy-MM-dd log4j.appender.FileAppender.layout=org.apache.log4j.PatternLayout #log4j.appender.FileAppender.layout.ConversionPattern=%-5p %d [%t] %l - %m%n log4j.appender.FileAppender.layout.ConversionPattern=%d %p [%t] %C.%M(%L) | %m%n log4j.logger.com.ibatis=debug log4j.logger.com.ibatis.common.jdbc.SimpleDataSource=debug log4j.logger.com.ibatis.common.jdbc.ScriptRunner=debug log4j.logger.com.ibatis.sqlmap.engine.impl.SqlMapClientDelegate=debug log4j.logger.java.sql.Connection=debug log4j.logger.java.sql.Statement=debug log4j.logger.java.sql.PreparedStatement=debug,ConsoleAppender
對應的log4j2.xml內容如下
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<Properties>
<Property name="LOG_HOME">${sys:user.dir}/logs</Property>
<Property name="LOG_FILE">@logging.file-web@</Property>
</Properties>
<Appenders>
<Console name="console_appender" target="SYSTEM_OUT">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %p [%t] %C.%M(%L) | %m%n"/>
</Console>
<RollingFile name="file_appender" immediateFlush="true" fileName="${LOG_HOME}/${LOG_FILE}"
filePattern="${LOG_HOME}/${LOG_FILE}.%d{yyyy-MM-dd}">
<PatternLayout>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %p [%t] %C.%M(%L) | %m%n</pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy modulate="true" interval="1"/>
</Policies>
<DefaultRolloverStrategy max="30"/>
</RollingFile >
</Appenders>
<Loggers>
<logger name="com.ibatis.common.jdbc.SimpleDataSource" level="debug"/>
<logger name="java.sql.Connection" level="debug"/>
<logger name="com.ibatis" level="debug"/>
<logger name="com.ibatis.common.jdbc.ScriptRunner" level="debug"/>
<logger name="com.ibatis.sqlmap.engine.impl.SqlMapClientDelegate" level="debug"/>
<logger name="java.sql.Statement" level="debug"/>
<logger name="java.sql.PreparedStatement" level="debug">
<appender-ref ref="console_appender"/>
</logger>
<Root level="INFO">
<appender-ref ref="console_appender"/>
<appender-ref ref="file_appender"/>
</Root>
</Loggers>
</configuration>
如果在springboot項目中配置了 logging.config 屬性，請修改 logging.config=classpath:log4j.properties 為 logging.config=classpath:log4j2.xml
六、springboot 對log4j2的支持
springboot 日志系統結構如下。
LoggingSystem是個抽象類，功能如下。
- beforeInitialize方法：日志系統初始化之前需要處理的事情。抽象方法，不同的日志架構進行不同的處理
- initialize方法：初始化日志系統。默認不進行任何處理，需子類進行初始化工作
- cleanUp方法：日志系統的清除工作。默認不進行任何處理，需子類進行清除工作
- getShutdownHandler方法：返回一個Runnable用於當jvm退出的時候處理日志系統關閉后需要進行的操作，默認返回null，也就是什么都不做
- setLogLevel方法：抽象方法，用於設置對應logger的級別
可支持的日志系統配置如下。
@Override public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) { if (StringUtils.hasLength(configLocation)) { initializeWithSpecificConfig(initializationContext, configLocation, logFile); return; } initializeWithConventions(initializationContext, logFile); }
initializeWithSpecificConfig方法時在你指定日志配置文件時（也就是指定了 logging.config 屬性）調用。initializeWithConventions方法則是使用默認的配置。
我們簡單的看一下Log4J2LoggingSystem初始化過程。
1.默認查找的配置文件名稱
2.log4j2具體的初始化配置過程
可以發現，log4j2通過LogManager管理着多個LoggerContext，每個LoggerContext管理着不同的logger。
3.動態設置logger的level
4.沒找到日志配置文件的話使用loadDefaults方法加載
5.springboot具體是采用哪一個LoggingSystem是在LoggingApplicationListener中決定的，LoggingApplicationListener是一個ApplicationListener，springboot工程在啟動的時候會被加載。
以下摘自網絡
LoggingApplicationListener所做的事情...
1. 讀取配置文件中"logging."開頭的配置，比如logging.pattern.level, logging.pattern.console等設置到系統屬性中 2. 構造一個LogFile(LogFile是對日志對外輸出文件的封裝)，使用LogFile的靜態方法get構造，會使用配置文件中logging.file和logging.path配置構造 3. 判斷配置中是否配置了debug並為true，如果是，設置level的DEBUG，然后繼續查看是否配置了trace並為true，如果是，設置level的TRACE 4. 構造LoggingInitializationContext，查看是否配置了logging.config，如有配置，調用LoggingSystem的initialize方法並帶上該參數，否則調用initialize方法並且configLocation為null 5. 設置一些比如org.springframework.boot、org.springframework、org.apache.tomcat、org.apache.catalina、org.eclipse.jetty、org.hibernate.tool.hbm2ddl、org.hibernate.SQL這些包的log el，跟第3步的level一樣
6. 查看是否配置了logging.register-shutdown-hook，如配置並設置為true，使用addShutdownHook的addShutdownHook方法加入LoggingSystem的getShutdownHandler
七、spring默認日志系統
順便說一下，Spring的日志默認采用commons-logging。以下摘自網上！
log4j如何切換到logback？
1.將logback-classic和logback-core的jar包引入到工程，將有關log4j的jar包從工程的classpath中移除。 2.確認工程引入了slf4j的jar包，作為日志的適配。 3.在工程中新建logback.xml文件，將原來log4j配置文件（log4j.properties），轉換為logback的對應配置，然后將log4j.properties刪除。 4.將工程中，由於缺失了log4j.jar引起的錯誤進行修正，改為利用logback實現。 可能遇到的問題及解決方案： 1.Log4j轉換到logback后，運行后spring的日志都以紅字輸出到控制台，而不受logback控制。 因為Spring的日志默認采用commons-logging，解決方法是在工程中引入jcl-over-slf4j-1.6.1.jar，這樣就將commons-logging與slf4j對接，再通過logback進行了日志的統一輸出。 2.切換完成后，啟動工程時會出現java.lang.IllegalAccessError: tried to access field org.slf4j.impl.StaticLoggerBinder.SINGLETON from class org.slf4j.LoggerFactory這個錯誤。 原因是slf4j-api的jar包版本太低，改為slf4j-api-1.6.4.jar即可解決。