摘要：由于不是線程安全的，故在方法上增加了同步操作，造成競爭等待。至此，整個多線程調(diào)優(yōu)結(jié)束，通過充分優(yōu)化同步競爭的方式，最終使得分線程記錄日志的性能比最原始的多線程寫同一文件提高了倍去鎖提高到倍，替換提高倍

??在一次項目的性能調(diào)優(yōu)中，發(fā)現(xiàn)出現(xiàn)競爭瓶頸，導(dǎo)致在資源未使用滿的情況下，TPS已經(jīng)無法提升。祭起JMC（JAVA MISSON CONTROL）飛行記錄器大法后，發(fā)現(xiàn)線程集中等待在logback寫日志的地方，如下圖所示：

??由于項目組多線程寫如同一個文件日志，導(dǎo)致存在IO競爭，一般解決這種問題有三種選擇方式
：

異步日志，但是會存在斷電或者日志隊列溢出丟失的可能

遠(yuǎn)程日志，日志放入外部消息隊列，保證持久化，但需額外部署日志存儲隊列

多線程日志，按線程（或線程取模）記錄日志，減少競爭，日志也能保證持久化

??項目組權(quán)衡再三，決定采用第三種分線程日志的方式解決。

??項目組使用logback作為日志組件，loback是否有自動分線程寫日志的功能呢？網(wǎng)上搜索logack multiThread 的第一篇文章就是教你如何使用SiftingAppender來分線程記錄日志如下：
https://dzone.com/articles/si...
??SiftingAppender是logback根據(jù)mdc中的變量動態(tài)創(chuàng)建appender的代理，只要我們將一個線程號作為日志名分發(fā)器discriminator注入到SiftingAppender中，它就可以動態(tài)的為我們創(chuàng)建不同的appender，達(dá)到分線程的目的，配置方式舉例如下：

配置discriminator

public class ThreadDiscriminator extends ContextBasedDiscriminator {
    String KEY ="threadName";
    /**
     * Return the name of the current context name as found in the logging event.
     */
    public String getDiscriminatingValue(ILoggingEvent event) {
        return event.getThreadName();
    }
    
    public String getDefaultValue() {
        return KEY;
    }
    
    public String getKey() {
        return KEY;
    }
    
    public void setKey(String key) {
        this.KEY = key;
    }
}

配置logback appender

    
    
        
            threadName
        
        
            
                
                    UTF-8
                    %d{yyyy-MM-dd HH:mm:ss.SSS}[%c][%thread][%X{tradeNo}][%p]-%m%n
                
                        
                    D:/test/threadlogs/${threadName}-%d{yyyy-MM-dd}.%i.log
                    
                    100MB
                    60
                    20GB
                
            
        
     

??配置后查看輸出結(jié)果也完全正確，網(wǎng)上的方法非常靠譜，真是piece of cake！但是接下來的性能測試讓我再次懵逼：性能沒有任何提升！反而更加糟糕了！這是怎么一回事呢？繼續(xù)jmc查看線程狀態(tài)：

??這次寫文件outputStream的IO等待竟然提升到了AppenderBase.doAppender方法級別！查看AppenderBase.doAppender實現(xiàn)，這個方法是Synchronized！這個父類的方法是SiftingAppender的入口方法，這意味著在獲取/創(chuàng)建線程自己真正的Appender和寫入日志之前都必須排隊阻塞在這個方法上！阻塞的級別提升了，當(dāng)然性能更糟糕了！

??logback Appender有兩個最基礎(chǔ)的抽象類，一個是同步AppenderBase，一個是不同步的UnsynchronizedAppenderBase，這兩個類功能一樣，只是doAppender方法的同步策略不一樣（Synchronize VS ThreadLocal）。那么SiftingAppender為什么繼承了AppenderBase而不是UnsynchronizedAppenderBase呢？分析原因應(yīng)該是SiftingAppender作為Appender的代理集合，它即可能包含了繼承自UnsynchronizedAppenderBase的OutputStreamAppender（FileAppender的基類，自行實現(xiàn)底層同步，doAppend方法未同步），也可能包含了繼承AppenderBase的SocketAppender類（doAppend方法同步），為防止出現(xiàn)線程安全問題，它直接在自身的doAppend方法上進行了同步。
??在項目組實際使用時，項目組只需要分線程寫文件日志，這意味這它使用的最終FileAppender應(yīng)該是線程安全，完全獨立的。故我們嘗試在logback新增繼承于UnsynchronizedAppenderBase的ParrelSiftingAppender步驟如下：

logback core中增加繼承UnsynchronizedAppenderBase的UnsynchronizedSiftingAppenderBase

logback classic中增加繼承UnsynchronizedSiftingAppenderBase的ParrelSiftingAppender

logback classic中SiftAction注冊增加ParrelSiftingAppender的工廠注冊

??修改完成后測試發(fā)現(xiàn)果然性能提升了5倍左右，CPU資源利用率接近飽和，應(yīng)該基本達(dá)到效果了，JMC分析應(yīng)該是沒有競爭了把，但是發(fā)現(xiàn)新的競爭方法出現(xiàn)了：

Appender appender = appenderTracker.getOrCreate(discriminatingValue, timestamp);

??原來在SiftingAppender內(nèi)部使用了LinkedHashMap作為LRU Cache來管理Appender，會定期移除。由于LinkedHashMap不是線程安全的，故在getOrCreate方法上增加了Synchronized同步操作，造成競爭等待。
??結(jié)合業(yè)務(wù)場景，這里完全可以使用ConcurrentHashMap作為Appender的緩存，ConcurrentHashMap讀寫鎖分離，并且key值分區(qū)上鎖，在多讀少寫的情況下，有很高的并發(fā)性能。并且真正生成的日志Appender也并不多（100個左右），定時清理完全也不會出現(xiàn)內(nèi)存溢出問題。
??開始動手修改appenderTracker步驟如下：

logback core中增加AbstractConcurrentMapComponentTracker

logback core中增加ConcurrentMapAppenderTracker繼承

AbstractConcurrentMapComponentTracker

修改UnsynchronizedSiftingAppenderBase使用ConcurrentMapAppenderTracker進行Appender管理

??最終性能測試結(jié)果：在資源相同的情況下，優(yōu)化后比使用LinkedHashMap性能提高一倍。至此，整個logback多線程調(diào)優(yōu)結(jié)束，通過充分優(yōu)化同步競爭的方式，最終使得分線程記錄日志的性能比最原始的多線程寫同一文件提高了10倍（SiftAppender去鎖提高到5倍，Map替換提高2倍）！