1. 程式人生 > >Java日誌體系(logback)

Java日誌體系(logback)

logback

1.1 簡介

師出同門,與log4j一樣,logback也是由Ceki Gülcü開發的開源日誌元件,可以說是log4j的改進版;在現如今的專案中,logback的出現次數越來越多,是目前主流首選的日誌記錄工具。

1.2 logback結構

logback分成三個模組:logback-core,logback- classic,logback-access。

logback-core提供了logBack的核心功能,是另外兩個元件的基礎;

logback-classic模組實現了SLF4J API;

logback-access模組與Servlet容器整合提供Http來訪問日誌的功能。

1.3 使用

首先,需要在應用的pom.xml中新增依賴:

<!--slf4j -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.20</version>
</dependency>

<!-- logback -->
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.1.7</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-core</artifactId>
    <version>1.1.7</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-access</artifactId>
    <version>1.1.7</version>
</dependency>

其次,宣告測試程式碼:

import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class slf4j_logbackDemo {
    Logger logger=  LoggerFactory.getLogger(slf4j_logbackDemo.class);

    @Test
    public void test() {
        logger.debug("debug message");
        logger.info("info message");
        logger.warn("warning message");
        logger.error("error message");
        logger.warn("login message");
    }
}

最後,在classpath下宣告配置檔案:logback.xml;

<!--每天生成一個檔案,歸檔檔案儲存30天:-->
<configuration >

    <!--設定自定義pattern屬性-->
    <property name="pattern" value="%d{HH:mm:ss.SSS} [%-5level] [%thread] [%logger] %msg%n"/>

    <!--控制檯輸出日誌-->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <!--設定控制檯輸出日誌的格式-->
        <encoder>
            <pattern>${pattern}</pattern>
        </encoder>
    </appender>

    <!--滾動記錄日誌檔案:-->
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--當天生成的日誌檔名稱:-->
        <file>e:/log.out</file>
        <!--根據時間來記錄日誌檔案:-->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--歸檔日誌檔案的名稱:-->
            <fileNamePattern>testLog-%d{yyyy-MM-dd}.log</fileNamePattern>
            <!--歸檔檔案儲存30天-->
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <!--生成的日誌資訊格式-->
        <encoder>
            <pattern>${pattern}</pattern>
        </encoder>
    </appender>

    <!--根root logger-->
    <root level="DEBUG">
        <!--設定根logger的日誌輸出目的地-->
        <appender-ref ref="FILE" />
        <appender-ref ref="CONSOLE" />
    </root>

</configuration>

通過以上步驟,logback就可以正常的運行了。

1.4 配置檔案詳解

(1)configuration:配置根節點

<configuration scan="true" scanPeriod="60" debug="false"></configuration>  

scan:程式執行時配置檔案被修改,是否重新載入。true,重新載入;false,不重新載入;預設為true;

scanPeriod:監測配置檔案被修改的時間間隔,scan屬性必須設定為true才可生效;預設為1分鐘,預設單位是毫秒;

debug:是否列印logback程式執行的日誌資訊。true,列印;false,不列印;預設為false;

(2)property:屬性變數

<configuration scan="true" scanPeriod="60" debug="false">
    <property name="pattern" value="%d{HH:mm:ss.SSS} [%-5level] [%logger] %msg%n" ></property>
</configuration>  

name:變數的名稱,可以隨意起名,但建議名字要簡明直譯;

value:變數的值;

在配置檔案中,我們可以用 ${} 的方式來使用,將變數引入到其他節點中去。如果有多處使用相同的內容,便可使用屬性變數的方式進行統一,減少很多不必要的程式碼;

(3)logger<logger>:日誌物件

logger分為2種,一種是普通日誌物件,另一種是根日誌物件。對於大部分應用來說,只設置根日誌物件即可。
在java日誌系統中,無論是log4j還是logback,他們的日誌物件體系都是呈現“樹”的形式,根日誌物件為最頂層節點,其餘包或者類中的日誌物件都繼承於根日誌節點;

對於普通日誌物件來說,我們可以設定某一個包或者某一個類的日誌級別,還可以單獨設定日誌的輸出目的地;

<configuration scan="true" scanPeriod="60" debug="false">   
    <logger name="java.sql" level="debug" addtivity="true">
        <appender-ref ref="CONSOLE" />
    </logger>   
</configuration>  

name:用來指定此logger屬於哪個包或者哪個類;

level:用來指定此logger的日誌列印級別;

addtivity:是否向上傳遞日誌列印資訊。之前說了,logger物件呈現一個樹的結構,根logger是樹的頂端,下面的子logger的addtivity屬性如果設定為true則會向上傳遞列印資訊,出現日誌重複列印的現象;

appender-ref:日誌輸出目的地,將此logger所列印的日誌交給此appender;

值得注意的是,上面的例子中,如果此logger沒有指定appender,而且addtivity也設定為true,那麼此logger對應的日誌資訊只會列印一遍,是由root來完成的;但是如果addtivity設定成false,那麼此logger將不會輸出任何日誌資訊;

(3)logger<root>:根日誌物件

<root>也是日誌物件中的一種,但它位於logger體系中的最頂層。當一個類中的logger物件進行列印請求時,如果配置檔案中沒有為該類單獨指定日誌物件,那麼都會交給root根日誌物件來完成;

<root>節點中只有一個level屬性,還可以單獨指定日誌輸除目的地<apender-ref>;

<configuration scan="true" scanPeriod="60" debug="false">   
    <root level="DEBUG">
        <appender-ref ref="CONSOLE" />
    </root>
</configuration>  

(4)appender:日誌輸出目的地

與log4j中的appender一樣,logback中的<appender>節點也同樣負責日誌輸出的目的地。

appender中有2個必填屬性--name和class。name為<appender>節點的名稱,class為<appender>的全限定類名,也就是日誌輸出目的地的處理類。此外,我們還可以在<appender>中單獨指定日誌的格式,設定日誌過濾器等操作;

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">  
    <encoder>  
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg %n</pattern>  
    </encoder>  
</appender>  

在logback中,主要有以下三種日誌目的地處理類:

①ch.qos.logback.core.ConsoleAppender

將日誌輸出到控制檯,可以在其節點中設定<encoder>子節點,設定日誌輸出的格式;

例子:
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">  
    <encoder>  
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg %n</pattern>  
    </encoder>  
</appender>  

②ch.qos.logback.core.FileAppender

將日誌輸出到具體的磁碟檔案中,可以單獨指定具體的位置,也可以設定日誌的輸出格式;

例子:
<appender name="FILE" class="ch.qos.logback.core.FileAppender">  
    <file>e:/log.out</file>  
    <append>true</append>  
    <prudent>false</prudent>
    <encoder>  
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>  
    </encoder>  
</appender> 

子節點<append>:新增的日誌是否以追加到檔案結尾的方式寫入到log.out檔案中,true為追加,fasle為清空現存檔案寫入;
子節點<prudent>:日誌是否被安全的寫入磁碟檔案,預設為false。如果為true,則效率低下;

③ch.qos.logback.core.rolling.RollingFileAppender

滾動記錄日誌,當符合<rollingPolicy>節點中設定的條件時,會將現有日誌移到新的檔案中去。<rollingPolicy>節點中可設定的條件為:檔案的大小、時間等;

例子:
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>e:/log.out</file>
    <append>true</append>  
    <prudent>false</prudent>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>testLog-%d{yyyy-MM-dd}.log</fileNamePattern>
        <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
    </encoder>
</appender>

④ch.qos.logback.classic.AsyncAppender

非同步記錄日誌,內部通過使用快取的方式來實現非同步列印,將日誌列印事件event放入快取中。具體資料結構為BlockingQueue;

例子:
<appender name="FILE" class="ch.qos.logback.core.FileAppender">  
    <file>e:/log.out</file>  
    <append>true</append>  
    <prudent>false</prudent>
    <encoder>  
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>  
    </encoder>  
</appender> 
<appender name ="ASYNC" class= "ch.qos.logback.classic.AsyncAppender">  
    <discardingThreshold>0</discardingThreshold>  
    <queueSize>512</queueSize>  
    <appender-ref ref ="FILE"/>  
</appender>  

子節點<queueSize>:指的是BlockingQueue的佇列容量大小,預設為256個;
子節點<discardingThreshold>:如果BlockingQueue中還剩餘20%的容量,那麼程式會丟棄TRACE、DEBUG和INFO級別的日誌列印事件event,只保留WARN和ERROR級別的。為了保留所有的日誌列印事件,可以將該值設定為0。

(5)rollingPolicy

日誌檔案的滾動策略,與RollingFileAppender搭配使用,當日志文件發生變動時決定RollingFileAppender的行為;

在<rollingPolicy>節點中有一個class屬性,可選的值為TimeBasedRollingPolicy、FixedWindowRollingPolicy、TriggeringPolicy;

其中ch.qos.logback.core.rolling.TimeBasedRollingPolicy表示根據時間制定日誌檔案的滾動策略;

<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    <fileNamePattern>testLog-%d{yyyy-MM-dd}.log</fileNamePattern>
    <maxHistory>30</maxHistory>
</rollingPolicy>

ch.qos.logback.core.rolling.FixedWindowRollingPolicy表示如果日誌檔案大小超過指定範圍時,會根據檔名拆分成多個檔案;

<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">   
   <fileNamePattern>tests.%i.log.zip</fileNamePattern>   
   <minIndex>1</minIndex>   
   <maxIndex>3</maxIndex>   
 </rollingPolicy>   

(6)triggeringPolicy

與<rollingPolicy>節點一樣,<triggeringPolicy>節點也屬於日誌滾動策略中的一種。

ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy表示根據日誌檔案大小,超過制定大小會觸發日誌滾動;

 <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">   
   <maxFileSize>5MB</maxFileSize>   
 </triggeringPolicy> 

(7)encoder

日誌格式化節點,負責格式化日誌資訊。<encoder>只負責了兩件事情,第一負責將日誌資訊轉換成位元組陣列,第二將位元組陣列寫到輸出流當中去;

在<encoder>中使用<pattern>來設定對應的格式;

<encoder>   
    <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>   
</encoder  

%logger:表示輸出logger名稱,後面跟一個{0}表示:只輸出logger最右邊點符號之後的字串;例如:com.jiaboyan.test ---> test;

%d{HH:mm:ss.SSS}:表示格式化日期輸出,14:06:49.812;

%line:輸出執行日誌請求的行號。

%thread:表示產生日誌的執行緒名;

%level:輸出日誌級別;

%method:輸出執行日誌請求的方法名;

%class:輸出日誌列印類的全限定名,後面跟{0}表示,含義為全限定類名最右邊點符號之後的字串。例如:com.jiaboyan.test ---> test;

%-4relative含義:符號減號“-”是左對齊 標誌,接著是可選的最小寬度 修飾符,用十進位制數表示。relative是輸出從程式啟動到建立日誌記錄的時間,單位是毫秒;

%msg:表示應用程式提供需要列印的日誌資訊;

%n:表示換行符;

1.5 logback效能測試

接下來,我們對logback進行下效能測試,分為同步和非同步;

(1)測試程式碼:(單執行緒、同步)

public class slf4j_logbackDemo {

    Logger logger =  LoggerFactory.getLogger(slf4j_logbackDemo.class);

    @Test
    public void test() {
        long start = System.currentTimeMillis();
        for(int x=0;x<50;x++) {
            long startss = System.currentTimeMillis();
            for (int y = 0; y < 10000; y++) {
                logger.info("Info Message!");
            }
            System.out.print(System.currentTimeMillis()-startss+" ");
        }
        System.out.print(System.currentTimeMillis()-start+" ");
    }
}

配置檔案:(注意日誌輸出的格式,只有簡單的日誌資訊)

在筆者測試前,並沒有對日誌格式化做太多的關注。在測試完成後,發現日誌格式化對效能的影響很大,所以此次的測試為了節約時間,就只輸出日誌資訊,並沒有具體的時間、logger物件、日誌級別等資訊;

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>e:/log.out</file>
        <append>true</append>
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>
    <root level="info">
        <appender-ref ref="FILE" />
    </root>
</configuration>

結果:(單位毫秒)

182 86 34 31 44 38 30 31 45 57 33 29 35 42 46 43 48 40 40 45 50 40 44 53 65 38 59 32 26 29 32 30 34 32 34 23 26 20 20 21 20 22 20 22 21 20 23 22 20 23 

總耗時:1900

(2)測試程式碼:(多執行緒、同步)

public class slf4j_logbackDemo {

    Logger logger =  LoggerFactory.getLogger(slf4j_logbackDemo.class);

     @Test
    public void testThread() throws InterruptedException {
        long start = System.currentTimeMillis();
        final CountDownLatch countDownLatch = new CountDownLatch(50);
        for(int x= 0;x<50;x++){
            new Thread(new Runnable() {
                public void run() {
                    for (int y = 0; y < 10000; y++) {
                        logger.info("Info Message!");
                    }
                    countDownLatch.countDown();
                }
            }).start();
        }
        countDownLatch.await();
        long time = System.currentTimeMillis() - start;
        System.out.println(time);
    }
}

配置檔案:(同上)

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>e:/log.out</file>
        <append>true</append>
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>
    <root level="info">
        <appender-ref ref="FILE" />
    </root>
</configuration>

結果:(單位毫秒)

總耗時:2229

使用了CountDownLatch物件,可以計算出50個執行緒執行完畢後所花費的總時間。可以看出,由於執行緒建立的原因,在多執行緒的情況下並沒有體現出更優秀的效能。

當然,還有一方面因素就是日誌總量太小,不足以體現出多執行緒的優勢。

(3)測試程式碼:(單執行緒、非同步)

public class slf4j_logbackDemo {

    Logger logger =  LoggerFactory.getLogger(slf4j_logbackDemo.class);

     @Test
    public void test() throws InterruptedException {
        long start = System.currentTimeMillis();
        for(int x=0;x<50;x++) {
            long startss = System.currentTimeMillis();
            for (int y = 0; y < 10000; y++) {
                logger.info("Info Message!");
            }
            System.out.print(System.currentTimeMillis()-startss+" ");
        }
        System.out.print(System.currentTimeMillis()-start+" ");
    }
}

配置檔案:(同上)

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>e:/log.out</file>
        <append>true</append>
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>

    <appender name ="ASYNC" class= "ch.qos.logback.classic.AsyncAppender">  
        <discardingThreshold>0</discardingThreshold>  
        <queueSize>512</queueSize>  
        <appender-ref ref ="FILE"/>  
    </appender> 
    
    <root level="info">
        <appender-ref ref="ASYNC" />
    </root>
</configuration>

結果:(單位毫秒)

183 123 48 54 45 40 45 47 48 48 44 79 51 56 57 91 116 79 95 126 53 73 47 62 50 49 42 43 39 42 41 37 28 30 28 30 26 34 34 39 29 31 31 32 31 32 32 32 34 32 

總耗時:2619

奇怪的是,在非同步情況下,logback並沒有體現出應有的效能優勢。後來繼續通過測試發現,日誌資訊的輸出量、格式化影響很大。

在調整之前的日誌檔案大小為7.15M,在調整之後為19M。調整之前的格式為%msg%n,調整之後的為%d{HH:mm:ss.SSS} [%-5level] [%thread] [%logger] %msg%n;

在調整後進行測試,同步下24760ms,非同步下10921ms,效能提升一倍;

(4)測試程式碼:(多執行緒、非同步)

public class slf4j_logbackDemo {

    Logger logger =  LoggerFactory.getLogger(slf4j_logbackDemo.class);

     @Test
    public void test() throws InterruptedException {
        long start = System.currentTimeMillis();
        final CountDownLatch countDownLatch = new CountDownLatch(50);
        for(int x= 0;x<50;x++){
            new Thread(new Runnable() {
                public void run() {
                    for (int y = 0; y < 10000; y++) {
                        logger.info("Info Message!");
                    }
                    countDownLatch.countDown();
                }
            }).start();
        }
        countDownLatch.await();
        long time = System.currentTimeMillis() - start;
        System.out.println(time);
    }
}

配置檔案:(同上)

<configuration>
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>e:/log.out</file>
        <append>true</append>
        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>

    <appender name ="ASYNC" class= "ch.qos.logback.classic.AsyncAppender">  
        <discardingThreshold>0</discardingThreshold>  
        <queueSize>512</queueSize>  
        <appender-ref ref ="FILE"/>  
    </appender> 
    
    <root level="info">
        <appender-ref ref="ASYNC" />
    </root>
</configuration>

結果:(單位毫秒)

總耗時:2780