Log4j.xml配置日誌按級別過濾並將指定級別的日誌發送到ActiveMQ

在以前的一篇博客《Spring+Log4j+ActiveMQ實現遠程記錄日誌——實戰+分析》的評論中，有同窗提到這種方式應該要能根據日誌級別設置來決定是否發送到mq，否則會大量佔用網絡資源。因而通過了一番搜索後，實現了這個功能。如今記錄在這裏。

目標：將debug，info級別的日誌輸出到本地文件，將warn，error級別的日誌輸出到ActiveMQ。

說明：本文仍是使用以前的兩個項目：Product和Logging。

通過一番搜索後，發現log4j還能夠按照級別過濾日誌，但過濾只能使用log4j.xml配置：

Filters can be defined at appender level. For example, to filter only certain levels, the LevelRangeFilter can be used like this:

<appender name="TRACE" class="org.apache.log4j.ConsoleAppender">
    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="[%t] %-5p %c - %m%n" />
    </layout>
    <filter class="org.apache.log4j.varia.LevelRangeFilter">
        <!-- 注意這個min和max是相等的 -->
        <param name="levelMin" value="DEBUG" />
        <param name="levelMax" value="DEBUG" />
    </filter>
</appender>

在搜索資料的過程當中，也看到了有網友說log4j.properties方式也能夠實現按級別過濾日誌，具體步驟請參看《Log4j按級別輸出日誌到不一樣文件配置分析》。此種方式的缺點是，若是有多個Appender，則須要多個繼承的類（每一個Appender須要從新定義一個），所以感受不如log4j.xml方式經過爲appender配置filter來的直接。

而後我在這裏找到了一份log4j.xml樣本：https://code.google.com/p/log4j-jms-sample/source/browse/trunk/src/main/resources/log4j.xml，拿過來後，我只是在jms appender裏面增長了一個filter而已：

<appender name="jms" class="org.apache.log4j.net.JMSAppender">
    <param name="InitialContextFactoryName"
        value="org.apache.activemq.jndi.ActiveMQInitialContextFactory" />
    <param name="ProviderURL" value="tcp://localhost:61616" />
    <param name="TopicBindingName" value="logTopic" />
    <param name="TopicConnectionFactoryBindingName" value="ConnectionFactory" />
    <!-- Only log WARN & ERROR msg -->
    <filter class="org.apache.log4j.varia.LevelRangeFilter">
        <param name="LevelMin" value="WARN" />
        <param name="LevelMax" value="ERROR" />
    </filter>
</appender>

而Product項目的測試代碼至關簡單：

package com.demo.product;
import org.apache.log4j.Logger;
public class Main{
    public static void main(String[] args) throws Exception {
        Logger logger = Logger.getLogger(Main.class);
        logger.debug("Debug");
        logger.info("Info");
        logger.warn("Warn");
        logger.error("Error");
        logger.fatal("Fatal");
        System.exit(0);
    }
}

我覺得就這樣配置就能讓WARN和ERROR級別的日誌輸出到jms了，可是我運行的時候卻報錯了：

javax.jms.JMSException: Wire format negotiation timeout: peer did not send his wire format.
	at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
	at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1395)
	at org.apache.activemq.ActiveMQConnection.ensureConnectionInfoSent(ActiveMQConnection.java:1481)
	at org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:323)
	at org.apache.activemq.ActiveMQConnection.createTopicSession(ActiveMQConnection.java:1112)

搜索這個問題，有不少人遇到了，這裏列出了三種可能的緣由：

1. You're connecting to the port not used by ActiveMQ TCP transport

Make sure to check that you're connecting to the appropriate host:port

2. You're using log4j JMS appender and doesn't filter out ActiveMQ log messages

Be sure to read How do I use log4j JMS appender with ActiveMQ and more importantly to never send ActiveMQ log messages to JMS appender

3. Your broker is probably under heavy load (or network connection is unreliable), so connection setup cannot be completed in a reasonable time

If you experience sporadic exceptions like this, the best solution is to use failover transport, so that your clients can try connecting again if the first attempt fails. If you're getting these kind of exceptions more frequently you can also try extending wire format negotiation period (default 10 sec). You can do that by using wireFormat.maxInactivityDurationInitalDelay property on the connection URL in your client. For example:

tcp://localhost:61616?wireFormat.maxInactivityDurationInitalDelay=30000

第一種狀況顯然不是。

第三種狀況，因爲我就一個jms connection，也沒有往這個鏈接發送jms消息，因此不可能負載太重。

第二種狀況是不要把activemq的日誌發送到JMSAppender了，How do I use log4j JMS appender with ActiveMQ  一文中有如下配置：

## Be sure that ActiveMQ messages are not logged to 'jms' appender
log4j.logger.org.apache.activemq=INFO, stdout

 上面的意思是，對於org.apache.activemq包下的INFO級別以上的日誌，都輸出到stdout appender中。我對比了一下，從拷貝而來的log4j.xml中也包含了相似的配置：     

<!-- Be sure that ActiveMQ messages are not logged to 'jms' appender -->
<logger name="org.apache.activemq">
    <appender-ref ref="console" />
</logger>

可是爲什麼結果仍是這樣？幾經思考，我從新查看了一下報錯的日誌：

後面的內容是這樣的：

org.apache.activemq.transport.WireFormatNegotiator.negociate-118 | Received WireFormat ...

因而我去找到這個類，在這個negociate方法上打上斷點（Maven項目的好處還包括能夠自動下載jar包對應版本的源代碼），開始調試，而後發現是這一句報錯：

而後我想了想能不能不打印這個debug消息呢，因而我在開始的org.apache.activemq包中加上了level限制：

<logger name="org.apache.activemq">
    <level value="INFO" />
    <appender-ref ref="console" />
</logger>

這樣之後，問題解決。其實，只要我稍微細心一點，能夠發現

log4j.logger.org.apache.activemq=INFO, stdout

這個配置不只指明瞭org.apache.activemq包下的日誌信息輸出到stdout這個appender中，並且還指明瞭只有INFO以上的級別才能輸出。兩者同時指定才能達到目的，這在剛剛的xml文件中也獲得體現。

如今，WARN和ERROR級別的日誌就能夠輸出到ActiveMQ了：

在Logging項目中，和以前同樣，LogMessageListener也只是簡單打印了級別和內容：

public void onMessage(Message message) {
    LoggingEvent event;
    try {
        event = (LoggingEvent)((ActiveMQObjectMessage)message).getObject();
        System.out.println("[" + event.getLevel() + "] | " + event.getMessage());
    } catch (JMSException e) {
        e.printStackTrace();
    }
}

從結果中能看到輸出的日誌級別僅僅包括了WARN和ERROR：

至於剩下的DEBUG和INFO級別的日誌，則直接配置輸出到RollingFileAppender便可。日誌文件的內容也固然和預期同樣了：

最後貼出完整的log4j.xml配置內容：

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

    <!-- Console Appender, used to record activemq log. -->
    <appender name="console" class="org.apache.log4j.ConsoleAppender">
        <param name="Target" value="System.out" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern"
                value="[Log4j-JMS-Sample] %d{yyyy-MM-dd HH:mm:ss,SSS} %p [%t] %c.%M-%L | %m%n" />
        </layout>
    </appender>
    
    <!-- File Appender, used to record debug & info log. -->
    <appender name="file" class="org.apache.log4j.RollingFileAppender">
        <param name="File" value="C:\\logs\\log_debug_info.log" />
        <param name="Append" value="true" />
        <param name="MaxFileSize" value="500KB" />
        <param name="MaxBackupIndex" value="2" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" 
                value="%c %d{ISO8601} [%p] -- %m%n" />
        </layout>
        <!-- Only log DEBUG & INFO msg -->
        <filter class="org.apache.log4j.varia.LevelRangeFilter">
            <param name="LevelMin" value="DEBUG" />
            <param name="LevelMax" value="INFO" />
        </filter>
    </appender>
    
    <!-- JMS Appender, used to record warn & info log. -->
    <appender name="jms" class="org.apache.log4j.net.JMSAppender">
        <param name="InitialContextFactoryName"
            value="org.apache.activemq.jndi.ActiveMQInitialContextFactory" />
        <param name="ProviderURL" value="tcp://localhost:61616" />
        <param name="TopicBindingName" value="logTopic" />
        <param name="TopicConnectionFactoryBindingName" value="ConnectionFactory" />
        <!-- Only log WARN & ERROR msg -->
        <filter class="org.apache.log4j.varia.LevelRangeFilter">
            <param name="LevelMin" value="WARN" />
            <param name="LevelMax" value="ERROR" />
        </filter>
    </appender>

    <!-- Log in org.apache.activemq are logged to console. -->
    <logger name="org.apache.activemq">
        <level value="INFO" />
        <appender-ref ref="console" />
    </logger>

    <root>
        <priority value="DEBUG" />
        <appender-ref ref="console" />
        <appender-ref ref="jms" />
        <appender-ref ref="file" />
    </root>
</log4j:configuration>

固然，若是但願再把info和debug分開，能夠多配置一個fileappender，讓每一個過濾器的LevelMax和LevelMin的值相等併爲它們配置不一樣的文件便可。

參考：

http://wiki.apache.org/logging-log4j/Log4jXmlFormat

http://wiki.apache.org/logging-log4j/JMSAppender

http://activemq.apache.org/javaxjmsjmsexception-wire-format-negociation-timeout-peer-did-not-send-his-wire-format.html

http://activemq.apache.org/how-do-i-use-log4j-jms-appender-with-activemq.html