@logback實(shí)驗(yàn)2.0

驗(yàn)證：不同的logger打印的日志中的類(lèi)的全限定名稱不一樣、不同的日志級(jí)別打印的結(jié)果不一樣、日志有效級(jí)的繼承關(guān)系

在java程序中，常用的獲取Logger的方式為 LoggerFactory.getLogger();通過(guò) LoggerFactory.getLogger() 可以獲取到具體的 logger 實(shí)例，名字相同則返回的 logger 實(shí)例也相同。logback的官方文檔中提出以下三點(diǎn)特性:

1. 不同的logger打印的日志中的類(lèi)的全限定名稱不一樣
2. 不同的日志級(jí)別打印的結(jié)果不一樣
3. 日志有效級(jí)的繼承關(guān)系

下面的代碼就可以測(cè)試出以上的三種特性

import ch.qos.logback.classic.Level;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.ResponseBody;
import org.springframework.web.bind.annotation.RestController;

/**
 * Created by shuai on 2019/1/9.
 */
@RestController
public class DemoController {

    private final static Logger log = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
    private final static Logger LOGGER = LoggerFactory.getLogger(TestController.class);

    @RequestMapping(value = "/api/v1/testlog")
    @ResponseBody
    public void testLog(@RequestParam(value = "id") Long id) {
        log.warn("打印一個(gè)warn");
        log.debug("打印一個(gè)debug");
        System.out.println(log.getName());

        LOGGER.warn("警告信息");
        LOGGER.debug("調(diào)試信息");
        System.out.println(LOGGER.getName());
        System.out.println();

        // ch.qos.logback.classic.Logger 可以設(shè)置日志的級(jí)別
        // 獲取一個(gè)名為 "com.springboot.utils" 的 logger 實(shí)例
        ch.qos.logback.classic.Logger logger =
                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger("com.springboot.utils");
        // 設(shè)置 logger 的級(jí)別為 INFO
        logger.setLevel(Level.INFO);
        // 這條日志可以打印，因?yàn)?WARN >= INFO
        logger.warn("警告信息");
        // 這條日志不會(huì)打印，因?yàn)?DEBUG < INFO
        logger.debug("調(diào)試信息");
        System.out.println(logger.getName());
        System.out.println();

        // "com.springboot.utils.test.TestSome" 會(huì)繼承 "com.springboot.utils" 的有效級(jí)別
        Logger barLogger = LoggerFactory.getLogger("com.springboot.utils.test");
        // 這條日志會(huì)打印，因?yàn)?INFO >= INFO
        barLogger.info("子級(jí)信息");
        // 這條日志不會(huì)打印，因?yàn)?DEBUG < INFO
        barLogger.debug("子級(jí)調(diào)試信息");
        System.out.println(barLogger.getName());
    }
}

結(jié)果如下：

點(diǎn)擊放大

得出文檔中的結(jié)論是正確的。

@logback實(shí)驗(yàn)2.1-驗(yàn)證logger.isDebugEnabled()對(duì)性能的影響

假設(shè)我們的日志級(jí)別設(shè)置為info，debug()方法調(diào)用后會(huì)判斷日志級(jí)別是否能夠打印輸出，然后return。但是在調(diào)用debug()方法時(shí)，必須提供入?yún)⒌膮?shù)。如果代碼里有需要拼裝的代碼，這顯然很得不償失。
考慮到 logback-classic 實(shí)現(xiàn)了 SLF4J 的 Logger 接口，一些打印方法可以接收多個(gè)傳參。這些打印方法的變體主要是為了提高性能以及減少對(duì)代碼可讀性的影響。

如下代碼筆者將獲取的Logger日志級(jí)別設(shè)置為INFO，所以debug級(jí)別的日志不會(huì)打印。再使用3個(gè)while循環(huán)1w次，分別執(zhí)行代碼測(cè)試使用的時(shí)間：

LOGGER.debug("這是實(shí)驗(yàn)1的日志，打印一句《天行九歌》 歌詞： 任俠平生愿，" + str + "。第 " + count + " 次。");

LOGGER.debug("這是實(shí)驗(yàn)2的日志，打印一句《天行九歌》 歌詞： 任俠平生愿，{}。第 {} 次。", str, count);

if (LOGGER.isDebugEnabled()) {
    LOGGER.debug("這是實(shí)驗(yàn)3的日志，打印一句《天行九歌》 歌詞： 任俠平生愿，" + str + "。第 " + count + " 次。");
}

驗(yàn)證代碼如下：

import ch.qos.logback.classic.Level;
import org.slf4j.LoggerFactory;

/**
 * Created by shuai on 2019/1/10.
 */
public class DemoController {

    public static void main(String[] args) {
        DemoController.testIsDebugEnabled();
    }


    /**
     * 關(guān)于LOGGER.isDebugEnabled()的性能測(cè)試
     */
    public static void testIsDebugEnabled() {
        ch.qos.logback.classic.Logger LOGGER =
                (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(DemoController.class);
        LOGGER.setLevel(Level.INFO);
        int count = 0;
        String str = "一葉邊舟蓮波漣";
        long t1 = System.currentTimeMillis();
        System.out.println("實(shí)驗(yàn)1，開(kāi)始時(shí)間為: " + t1 + " ms");
        while (count < 100000) {
            count++;
            LOGGER.debug("這是實(shí)驗(yàn)1的日志，打印一句《天行九歌》 歌詞： 任俠平生愿，" + str + "。第 " + count + " 次。");
        }
        long t2 = System.currentTimeMillis();
        System.out.println("實(shí)驗(yàn)1，結(jié)束時(shí)間為: " + t2 + " ms");
        System.out.println("實(shí)驗(yàn)1，花費(fèi)時(shí)間為: " + (t2 - t1) + " ms");
        System.out.println();

        count = 0;
        long t5 = System.currentTimeMillis();
        System.out.println("實(shí)驗(yàn)2，開(kāi)始時(shí)間為: " + t5 + " ms");
        while (count < 100000) {
            count++;
            LOGGER.debug("這是實(shí)驗(yàn)2的日志，打印一句《天行九歌》 歌詞： 任俠平生愿，{}。第 {} 次。", str, count);
        }
        long t6 = System.currentTimeMillis();
        System.out.println("實(shí)驗(yàn)2，結(jié)束時(shí)間為: " + t6 + " ms");
        System.out.println("實(shí)驗(yàn)2，花費(fèi)時(shí)間為: " + (t6 - t5) + " ms");
        System.out.println();

        count = 0;
        long t3 = System.currentTimeMillis();
        System.out.println("實(shí)驗(yàn)3，開(kāi)始時(shí)間為: " + t3 + " ms");
        while (count < 100000) {
            count++;
            if (LOGGER.isDebugEnabled()) {
                LOGGER.debug("這是實(shí)驗(yàn)3的日志，打印一句《天行九歌》 歌詞： 任俠平生愿，" + str + "。第 " + count + " 次。");
            }
        }
        long t4 = System.currentTimeMillis();
        System.out.println("實(shí)驗(yàn)3，結(jié)束時(shí)間為: " + t4 + " ms");
        System.out.println("實(shí)驗(yàn)3，花費(fèi)時(shí)間為: " + (t4 - t3) + " ms");

    }

}

實(shí)驗(yàn)結(jié)果為:

點(diǎn)擊查看大圖

得出官方文檔中的結(jié)論是正確的。官方文檔的結(jié)論，原文翻譯如下：
對(duì)于一些 Logger 如下輸出日志：

logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));

會(huì)產(chǎn)生構(gòu)建消息參數(shù)的成本，是因?yàn)樾枰獙⒄麛?shù)轉(zhuǎn)為字符串，然后再將字符串拼接起來(lái)。但是我們是不需要關(guān)心 debug 信息是否被記錄（強(qiáng)行曲解作者的意思）。

為了避免構(gòu)建參數(shù)帶來(lái)的損耗，可以在日志記錄之前做一個(gè)判斷，如下：

if(logger.isDebugEnabled()) { 
  logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
}

在這種情況下，如果 logger沒(méi)有開(kāi)啟 debug 模式，不會(huì)有構(gòu)建參數(shù)帶來(lái)的性能損耗。換句話說(shuō)，如果 logger 在 debug 級(jí)別，將會(huì)有兩次性能的損耗，一次是判斷是否啟用了 debug 模式，一次是打印 debug 日志。在實(shí)際應(yīng)用當(dāng)中，這種性能上的損耗是可以忽略不計(jì)的，因?yàn)樗ㄙM(fèi)的時(shí)間小于打印一條日志的時(shí)間的 1%。

更好的選擇

有一種更好的方式去格式化日志信息。假設(shè) entry 是一個(gè) Object 對(duì)象：

Object entry = new SomeObject();
logger.debug("The entry is {}", entry);

只有在需要打印 debug 信息的時(shí)候，才會(huì)去格式化日志信息，將 '{}' 替換成 entry 的字符串形式。也就是說(shuō)在這種情況下，如果禁止了日志的打印，也不會(huì)有構(gòu)建參數(shù)上的性能消耗。

下面兩行輸出的結(jié)果是一樣的，但是一旦禁止日志打印，第二個(gè)變量的性能至少比第一個(gè)變量好上 30 倍。

logger.debug("The new entry is " + entry + ".");
logger.debug("The new entry is {}", entry);

使用兩個(gè)參數(shù)的例子如下：

logger.debug("The new entry is {}, It replaces {}.", entry, oldEntry);

如果需要使用三個(gè)或三個(gè)以上的參數(shù)，可以采用如下的形式：

Object[] paramArray = {newVal, below, above};
logger.debug("Value {} was inserted between {} and {}.", paramArray);

@logback實(shí)驗(yàn)3.0-驗(yàn)證修改logback配置文件后，自動(dòng)加載并生效

以下代碼有兩個(gè)入口，分別是：

• POST：/log/test/change 修改logback的配置文件
• GET：/log/test/out 查看logback的配置文件內(nèi)容

先設(shè)置一個(gè)每2秒執(zhí)行一次的定時(shí)器，打印INFO級(jí)別和WARN級(jí)別的日志，日志級(jí)別設(shè)置為INFO。再通過(guò)POST接口/log/test/change將日志級(jí)別改為WARN，看看修改后打印日志的變化。修改日志級(jí)別只需要將logback配置文件中的<root level="INFO">這一行改為<root level="WARN">即可。下面的對(duì)應(yīng)的代碼和配置文件：

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.core.joran.spi.ConfigurationWatchList;
import ch.qos.logback.core.joran.util.ConfigurationWatchListUtil;
import ch.qos.logback.core.status.Status;
import com.alibaba.fastjson.JSONArray;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.scheduling.annotation.Scheduled;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.bind.annotation.RestController;

import java.io.BufferedInputStream;
import java.io.ByteArrayOutputStream;
import java.io.FileOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.net.URL;
import java.net.URLConnection;
import java.util.ArrayList;
import java.util.List;

/**
 * Created by shuai on 2019/1/10.
 */
@RestController
public class TestController {
    private final static Logger LOGGER = LoggerFactory.getLogger(TestController.class);
    private final static String XML_FILE_TYPE = ".xml";

    @RequestMapping(value = "/log/test/status", method = RequestMethod.GET)
    public String d() throws IOException {
        LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
        List<Status> list = context.getStatusManager().getCopyOfStatusList();
        List<String> r = new ArrayList<String>();
        for (Status s : list) {
            r.add(s.getMessage());
        }
        return JSONArray.toJSONString(r);
    }

    private static int count = 0;

    /**
     * 每2秒打印一次 WARN 和 INFO 級(jí)別的日志
     */
    @Scheduled(cron = "0/2 * * * * *")
    public void execute() {
        LOGGER.warn("WARN級(jí)別,第{}次，當(dāng)前時(shí)間為 {}", count++, System.currentTimeMillis());
        LOGGER.info("INFO級(jí)別,第{}次，當(dāng)前時(shí)間為 {}", count++, System.currentTimeMillis());
    }

    /**
     * 修改當(dāng)前l(fā)ogback的配置文件內(nèi)容
     * @param body 配置文件
     * @return
     * @throws IOException
     */
    @RequestMapping(value = "/log/test/change", method = RequestMethod.POST)
    public String change(@RequestBody String body) throws IOException {
        LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
        if (context == null) {
            LOGGER.info("Empty LoggerContext context");
            return "Empty LoggerContext context";
        }
        ConfigurationWatchList configurationWatchList = ConfigurationWatchListUtil.getConfigurationWatchList(context);
        if (configurationWatchList == null) {
            LOGGER.info("Empty ConfigurationWatchList in context");
            return "Empty ConfigurationWatchList in context";
        }
        URL mainConfigurationURL = configurationWatchList.getMainURL();
        if (mainConfigurationURL == null) {
            LOGGER.info("Empty URL mainConfigurationURL");
            return "Empty URL mainConfigurationURL";
        }
        if (!mainConfigurationURL.toString().endsWith(XML_FILE_TYPE)) {
            LOGGER.info("mainConfigurationURL.toString() Method Result Is Not EndWith .XML");
            return "mainConfigurationURL.toString() Method Result Is Not EndWith .XML";
        }
        //寫(xiě)入logback配置文件
        FileOutputStream outputStream = new FileOutputStream(mainConfigurationURL.getFile());
        outputStream.write(body.getBytes());
        outputStream.close();
        //讀取logback配置文件
        URLConnection urlConnection = mainConfigurationURL.openConnection();
        InputStream inputStream = urlConnection.getInputStream();
        BufferedInputStream bis = new BufferedInputStream(inputStream);
        ByteArrayOutputStream buf = new ByteArrayOutputStream();
        int result = bis.read();
        while (result != -1) {
            buf.write((byte) result);
            result = bis.read();
        }
        inputStream.close();
        bis.close();
        buf.close();
        return buf.toString();
    }


    /**
     * 查看當(dāng)前的logback的配置文件內(nèi)容
     * @return
     * @throws IOException
     */
    @RequestMapping(value = "/log/test/out", method = RequestMethod.GET)
    public String out() throws IOException {
        LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
        if (context == null) {
            LOGGER.info("Empty LoggerContext context");
            return "Empty LoggerContext context";
        }
        ConfigurationWatchList configurationWatchList = ConfigurationWatchListUtil.getConfigurationWatchList(context);
        if (configurationWatchList == null) {
            LOGGER.info("Empty ConfigurationWatchList in context");
            return "Empty ConfigurationWatchList in context";
        }
        URL mainConfigurationURL = configurationWatchList.getMainURL();
        if (mainConfigurationURL == null) {
            LOGGER.info("Empty URL mainConfigurationURL");
            return "Empty URL mainConfigurationURL";
        }
        if (!mainConfigurationURL.toString().endsWith(XML_FILE_TYPE)) {
            LOGGER.info("mainConfigurationURL.toString() Method Result Is Not EndWith .XML");
            return "mainConfigurationURL.toString() Method Result Is Not EndWith .XML";
        }
        //讀取logback配置文件
        URLConnection urlConnection = mainConfigurationURL.openConnection();
        InputStream inputStream = urlConnection.getInputStream();
        BufferedInputStream bis = new BufferedInputStream(inputStream);
        ByteArrayOutputStream buf = new ByteArrayOutputStream();
        int result = bis.read();
        while (result != -1) {
            buf.write((byte) result);
            result = bis.read();
        }
        String str = buf.toString();
        inputStream.close();
        bis.close();
        buf.close();
        return str;
    }

}

當(dāng)前的logback.xml文件內(nèi)容為:

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true" scan="true" scanPeriod="4 seconds">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | %X{tracker_id} | %X{localIp} |[%t]:[%p]|[%c:%L] - %m %n</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

日志結(jié)果為：

點(diǎn)擊查看大圖

@logback實(shí)驗(yàn)3.1-對(duì)部分日志通過(guò)配置輸出到指定的位置

在業(yè)務(wù)上我們有時(shí)候需要對(duì)某些日志進(jìn)行特定的分析，比如說(shuō)某個(gè)類(lèi)里面的日志我需要指定輸入到foo.log文件中，后期會(huì)用來(lái)做分析。logback的官方文檔中就提供了這樣的功能，官方文檔翻譯如下：

root logger 通過(guò) <root> 元素來(lái)進(jìn)行配置。它只支持一個(gè)屬性——level。它不允許設(shè)置其它任何的屬性，因?yàn)?additivity 并不適用 root logger。而且，root logger 的名字已經(jīng)被命名為 "ROOT"，也就是說(shuō)也不支持 name 屬性。level 屬性的值可以為：TRACE、DEBUG、INFO、WARN、ERROR、ALL、OFF，但是不能設(shè)置為 INHERITED 或 NULL。
跟 <logger> 元素類(lèi)似，<root> 元素可以包含 0 或多個(gè) <appender-ref> 元素。

還是以上面的每2秒執(zhí)行一次的定時(shí)任務(wù)打印的日志作為例子，我們?cè)谂渲梦募信渲茫簩?code>com.springboot.controller.TestController的日志打印到foo.log文件中，其余配置不變。修改后的配置文件如下：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true" scan="true" scanPeriod="4 seconds">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | %X{tracker_id} | %X{localIp} |[%t]:[%p]|[%c:%L] - %m %n</pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>foo.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | %X{tracker_id} | %X{localIp} |[%t]:[%p]|[%c:%L] - %m %n</pattern>
            <outputPatternAsHeader>true</outputPatternAsHeader>
        </encoder>
    </appender>

    <logger name="com.springboot.controller.TestController" level="INFO" >
        <appender-ref ref="FILE"/>
    </logger>

    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

啟動(dòng)程序后，定時(shí)任務(wù)會(huì)自動(dòng)在控制臺(tái)打印日志，并且根據(jù)配置，會(huì)往文件foo.log中打印日志。
結(jié)果如下：

點(diǎn)擊查看大圖

@logback實(shí)驗(yàn)4.0-驗(yàn)證重寫(xiě)Appender，監(jiān)控ERROR級(jí)別的錯(cuò)誤日志

驗(yàn)證：通過(guò)繼承 AppenderBase 可以編寫(xiě)你自己的 appender。它支持處理過(guò)濾器，狀態(tài)信息，以及其它大多數(shù) appender 共享的功能。子類(lèi)僅僅只需要實(shí)現(xiàn) append(Object eventObject) 方法。

第四章中講到了很多種 logback 提供的 appender，比較實(shí)用的有 DBAppender 和 SMTPAppender。分別將 logger 日志插入數(shù)據(jù)庫(kù)和發(fā)送郵件，但是DBappender需要自己建立數(shù)據(jù)源連接池，而 SMTPAppender 僅僅只在它的循環(huán)緩存區(qū)中保留最后 256 個(gè)日志事件，當(dāng)緩存區(qū)快要滿的時(shí)候丟掉舊的日志事件，都存在一定的局限性。
一個(gè)業(yè)務(wù)處理比較頻繁的系統(tǒng)中，每天會(huì)產(chǎn)生成千上萬(wàn)的日志數(shù)據(jù)，其中需要開(kāi)發(fā)人員特別注意是一般是ERROR級(jí)別的日志，當(dāng)出現(xiàn)ERROR級(jí)別的日志，大多數(shù)情況下需要開(kāi)發(fā)人員去介入查看系統(tǒng)當(dāng)時(shí)的業(yè)務(wù)異常情況。開(kāi)發(fā)者即不希望漏掉錯(cuò)誤日志，也不希望錯(cuò)誤日志時(shí)效性太差。比較常用的做法是將所有的服務(wù)日志打印全部收集起來(lái)，并解析日志的內(nèi)容，將ERROR級(jí)別的日志解析出來(lái)，并發(fā)送郵件通知開(kāi)發(fā)者。但是收集、解析、存儲(chǔ)、郵件報(bào)警等一系列的操作在日志量很大的情況下，處理起來(lái)比較麻煩（當(dāng)然也是有解決方案的）。有沒(méi)有一種即能夠穩(wěn)定、實(shí)時(shí)的接收到系統(tǒng)的ERROR日志又不影響性能的方案呢？此處就可以用到重寫(xiě)Appender這個(gè)方案。
重寫(xiě)的Appender可以實(shí)現(xiàn)只收集ERROR級(jí)別的日志，并且發(fā)送郵件提醒開(kāi)發(fā)者。
方案：當(dāng)日志級(jí)別為ERROR時(shí)，重寫(xiě)的Appender 發(fā)送http請(qǐng)求將error日志發(fā)送到日志收集服務(wù)，并存儲(chǔ)到數(shù)據(jù)庫(kù)中，日志收集服務(wù)再通過(guò)定時(shí)任務(wù)每隔一段時(shí)間(根據(jù)業(yè)務(wù)實(shí)際情況配置時(shí)間)發(fā)送收集到的error日志給對(duì)應(yīng)服務(wù)的開(kāi)發(fā)者，這樣既能減輕client端的壓力，日志的穩(wěn)定性和時(shí)效性也會(huì)大大增加。

配置和代碼如下：

    <appender name="ERRORLOG" class="com.springboot.log.ErrorLogMonitorHttpAppender">
        <url>http://localhost:8080/api/v1/addlog</url>
        <env>test</env>
        <localSystemName>someOneProjectName</localSystemName>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>ERROR</level>
        </filter>
        <encoder charset="UTF-8">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | %X{tracker_id} | %X{localIp} |[%t]:[%p]|[%c:%L] - %m %n</pattern>
        </encoder>
    </appender>

import ch.qos.logback.core.AppenderBase;
import ch.qos.logback.core.encoder.Encoder;
import com.springboot.http.HttpClientUtil;
import com.springboot.utils.IpUtils;
import com.springboot.vo.LogVO;

import java.io.ByteArrayOutputStream;
import java.util.concurrent.LinkedBlockingQueue;

/**
 * Created by shuai on 2019/1/3.
 */
public class ErrorLogMonitorHttpAppender<E> extends AppenderBase<E> {

    private String url;
    private String localSystemName;
    private String env;
    private LinkedBlockingQueue<E> queue = new LinkedBlockingQueue<E>(512);
    protected Encoder<E> encoder;
    private ByteArrayOutputStream byteArrayOutputStream;
    private HttpClientUtil httpClientUtil;

    public LinkedBlockingQueue<E> getQueue() {
        return queue;
    }

    public void setQueue(LinkedBlockingQueue<E> queue) {
        this.queue = queue;
    }

    public Encoder<E> getEncoder() {
        return encoder;
    }

    public void setEncoder(Encoder<E> encoder) {
        this.encoder = encoder;
    }

    public String getUrl() {
        return url;
    }

    public void setUrl(String url) {
        this.url = url;
    }

    public String getLocalSystemName() {
        return localSystemName;
    }

    public void setLocalSystemName(String localSystemName) {
        this.localSystemName = localSystemName;
    }

    public String getEnv() {
        return env;
    }

    public void setEnv(String env) {
        this.env = env;
    }

    public void start() {
        if (isStarted()) {
            addError(" Has been launched。 Don't create again！");
            return;
        }
        started = true;
        httpClientUtil = HttpClientUtil.getHttpClientUtil();
        new Thread(
                new Runnable() {
                    @Override
                    public void run() {
                        send();
                    }
                }
        ).start();
    }

    protected void send() {
        while (true) {
            try {
                E event = queue.take();
                byteArrayOutputStream = new ByteArrayOutputStream();
                this.encoder.init(byteArrayOutputStream);
                this.encoder.doEncode(event);
                byte[] byteArray = byteArrayOutputStream.toByteArray();
                LogVO logVO = new LogVO();
                logVO.setEnv(env);
                logVO.setBody(new String(byteArray, "utf-8"));
                logVO.setLocalIp(IpUtils.getRealIp());
                logVO.setLocalSystemName(localSystemName);
                //發(fā)送日志給日志收集服務(wù)
                httpClientUtil.doPostVO(url, null, logVO, "utf-8", 5000, 5000);
            } catch (Throwable t) {
                addError("send errorLog Exception:", t);
            }
        }
    }


    @Override
    protected void append(E eventObject) {
        if (eventObject != null) {
            try {
                queue.offer(eventObject);
            } catch (Throwable t) {
                addError("offer LinkedBlockingQueue error:", t);
            }
        }
    }
}

@logback實(shí)驗(yàn)4.1-驗(yàn)證logback中異步打印AsyncAppender的includeCallerData配置對(duì)性能的影響

如下是 AsyncAppender 的一些屬性：

上述為logback的官方文檔的翻譯，文中對(duì)includeCallerData屬性官方建議不要開(kāi)啟，會(huì)對(duì)性能有影響。下面我們就來(lái)做個(gè)試驗(yàn)，驗(yàn)證此配置對(duì)應(yīng)性能效率的影
響。

試驗(yàn)內(nèi)容：

1. 設(shè)定兩個(gè)同樣配置的異步打印的AsyncAppender，其中一個(gè)將includeCallerData屬性設(shè)置為true
2. 對(duì)兩個(gè)AsyncAppender分別打印相同的一行日志，分別記錄打印10w條日志和100w條日志花費(fèi)的時(shí)間

試驗(yàn)環(huán)境

JDK : 1.8
電腦配置：

電腦配置

logback.xml文件配置如下：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true" scan="true" scanPeriod="4 seconds">

    <!--包含調(diào)用者信息的日志-->
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>/Users/shuai/Desktop/myIncludeCallerData.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | %X{tracker_id} | %X{localIp} |[%t]:[%p]|[%c:%L] - %m %n</pattern>
        </encoder>
    </appender>
    <appender name="CONSOLE_ASYNC_FILE_TRUE" class="ch.qos.logback.classic.AsyncAppender">
        <discardingThreshold>3000</discardingThreshold>
        <queueSize>10000</queueSize>
        <!--獲取調(diào)用者的信息配置-->
        <includeCallerData>true</includeCallerData>
        <appender-ref ref="FILE"/>
    </appender>
    <!--引用CONSOLE_ASYNC_FILE_TRUE，并命名為includeCallerData，在程序中獲取-->
    <logger name="includeCallerData" level="info">
        <appender-ref ref="CONSOLE_ASYNC_FILE_TRUE"/>
    </logger>

    <!--不包含調(diào)用者信息的日志-->
    <appender name="FILE_NO" class="ch.qos.logback.core.FileAppender">
        <file>/Users/shuai/Desktop/my.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} | %X{tracker_id} | %X{localIp} |[%t]:[%p]|[%c:%L] - %m %n</pattern>
        </encoder>
    </appender>
    <appender name="CONSOLE_ASYNC_FILE_FALSE" class="ch.qos.logback.classic.AsyncAppender">
        <discardingThreshold>3000</discardingThreshold>
        <queueSize>10000</queueSize>
        <appender-ref ref="FILE_NO"/>
    </appender>
    <!--引用CONSOLE_ASYNC_FILE_FALSE，并命名為notIncludeCallerData，在程序中獲取-->
    <logger name="notIncludeCallerData" level="info">
        <appender-ref ref="CONSOLE_ASYNC_FILE_FALSE"/>
    </logger>


    <root level="INFO">
    </root>
</configuration>

實(shí)驗(yàn)類(lèi)如下：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;

/**
 * Created by shuai on 2019/1/22.
 */
@RestController
public class TestPerformanceController {

    @RequestMapping(value = "/api/test/per/data")
    public void tr(@RequestParam(value = "t") int t) {
        t = t == 0 ? 10000 : t;
        notIncludeCallerData(t);
        includeCallerData(t);
    }

    public void notIncludeCallerData(int t) {
        Logger LOGGER = LoggerFactory.getLogger("notIncludeCallerData");
        long t1 = System.currentTimeMillis();
        int count = 0;
        while (count < t) {
            LOGGER.info("沒(méi)有調(diào)用者信息的日志，打印當(dāng)前的count[{}],打印一行日志,時(shí)間[{}]", count, System.currentTimeMillis());
            ++count;
        }
        LOGGER.info("沒(méi)有調(diào)用者信息的日志，當(dāng)前打印完成,花費(fèi)時(shí)間為[{}]", System.currentTimeMillis() - t1);
        System.out.println("沒(méi)有調(diào)用者信息的日志，當(dāng)前打印完成,花費(fèi)時(shí)間為[ "+ (System.currentTimeMillis() - t1) +" ms]");
    }

    public void includeCallerData(int t) {
        Logger LOGGER = LoggerFactory.getLogger("includeCallerData");
        long t1 = System.currentTimeMillis();
        int count = 0;
        while (count < t) {
            LOGGER.info("有調(diào)用者信息的日志，打印當(dāng)前的count[{}],打印一行日志,時(shí)間[{}]", count, System.currentTimeMillis());
            ++count;
        }
        LOGGER.info("有調(diào)用者信息的日志，當(dāng)前打印完成,花費(fèi)時(shí)間為[{}]", System.currentTimeMillis() - t1);
        System.out.println("有調(diào)用者信息的日志，當(dāng)前打印完成,花費(fèi)時(shí)間為[ "+ (System.currentTimeMillis() - t1) +" ms]");
    }
}

看看10w條日志的結(jié)果：

點(diǎn)擊查看答題

有調(diào)用方信息的logger打印10w條日志，花費(fèi)的時(shí)間為： 9109 ms
無(wú)調(diào)用方信息的logger打印10w條日志，花費(fèi)的時(shí)間為： 50 ms

再看看100w條日志的結(jié)果：

點(diǎn)擊查看大圖

有調(diào)用方信息的logger打印100w條日志，花費(fèi)的時(shí)間為： 89509 ms
無(wú)調(diào)用方信息的logger打印100w條日志，花費(fèi)的時(shí)間為： 316 ms

再看看1000w條日志的結(jié)果：

千萬(wàn)日志數(shù)據(jù)

以上得出，異步打印的Appender:ch.qos.logback.classic.AsyncAppender中的配置了<includeCallerData>true</includeCallerData>會(huì)花費(fèi)更多的時(shí)間，日志打印的效率差360多倍。一個(gè)千萬(wàn)用戶級(jí)別互聯(lián)網(wǎng)產(chǎn)品，每五分鐘請(qǐng)求量最高如果在15w最低在1w，平均每次請(qǐng)求會(huì)產(chǎn)生10條日志，那server端日志一天約有4億條日志數(shù)據(jù)，即便分成10個(gè)實(shí)例，每個(gè)實(shí)例也會(huì)有4千萬(wàn)條日志。所以線上日志輸出，最好不要開(kāi)啟此配置，官方文檔中的建議可以采納。