如何編寫Log4j2脫敏外掛

咖啡拿鐵發表於2018-07-07

1.背景

我所在的公司最近要求需要在所有地方都要脫敏敏感資料，應該是受faceBook資料洩密影響吧。

說到脫敏一般來說在資料輸出的地方需要脫敏而我們資料落地輸出的地方一般是有三個地方:

介面返回值脫敏
日誌脫敏
資料庫脫敏

這裡主要說一下如何進行日誌脫敏，對於程式碼中來說日誌列印敏感資料有兩種:

敏感資料在方法引數中

LOGGER.info("person mobile:{}", mobile);複製程式碼

對於這種建議寫個Util直接進行脫敏，因為mobile這個引數名在程式碼中是無法獲取的，當時有想過對傳的引數使用正則匹配，這樣的話效率太低，會讓每個日誌方法都進行正則匹配，效率極低，並且如果剛好有個符合手機號的字串但是不是敏感資訊，這樣也被脫敏了。

 LOGGER.info("person mobile:{}", DesensitizationUtil.mobileDesensitiza(mobile));複製程式碼

2.敏感資料在引數物件中

Person person = new Person(); 
person.setMobile(mobile); 
LOGGER.info("person :{}", person);複製程式碼

對於我們業務中最多的其實就是上面的日誌了，為了把整個引數打全，第一種方法需要把引數取出來，第二種只需要傳一個引數即可，然後通過toString列印出這個日誌，對於這種脫敏有兩個方案

修改toString這個方法，對於修改toString方法又有三個辦法:

直接在toString中修改程式碼，這種方法很麻煩，效率低，需要修改每一個要脫敏的類，或者寫個idea外掛自動修改toString()，這樣不好的地方在於所有編譯器都需要開個外掛，不夠通用。
在編譯時期修改抽象語法樹修改toString()方法，就像類似Lombok一樣，這個之前調研過，開發難度較大，可能後會更新如何去寫。
在載入的時候通過實現Instrumentation介面 + asm庫，修改class檔案的位元組碼，但是有個比較麻煩的地方在於需要給jvm加上啟動引數 -javaagent:agent
jar
path，這個已經實現了，但是實現後發現的確不夠通用。

可以看到上面修改上面toString()方法三個都比較麻煩，我們可以換個思路，不利用toString()生成日誌資訊，下面的部分具體解釋如何去做。

2.方案

首先我們要知道當我們使用LOGGER.info的時候到底是發生了什麼？如下圖所示，我這裡列舉的是非同步的情況(我們專案中都是使用非同步，同步效率太低了)。

log4j提供給我們擴充套件的地方實在是太多了，只要你有需求都可以在裡面自定義，比如美團點評自己的xmdt統一日誌和線下報警日誌都是自己實現的Appender，統一日誌也對LogEvent進行了封裝。

我們同樣也可以利用Log4j2提供給我們的擴充套件性，在裡面定製化自己的需求。

2.1自定義PatterLayout的Convert

也就是修改上面圖中第8步。通過重寫Convert，並且加入過濾邏輯。

優點：

這種方法是最理想的，他基本不會影響我們的日誌的效能，因為過濾的邏輯都在PatterLayout裡面。

缺點：

但是我在這個地方很尷尬我只能拿到已經生成的String,我只能用笨辦法一個詞一個詞的匹配去搞，然後在修改這個詞後面所接的資料進行脫敏，這樣太複雜。有想過利用什麼演算法去優化(比如那些評論系統是如果過濾幾萬字文章的敏感詞的)，但是這樣成本太高，故而放棄。

2.2自定義全域性filter

在想到第一個方法的時候，這個時候其實是遇到瓶頸了，當時沒有完全分析Log4j2的鏈路，後面我覺得可能從Log4j2全景鏈路上看，能找到更多的思路，所有便有了上面的圖。

上面2.1的方案，為什麼不大可行呢？主要是我只能拿到已經生成的String了。這個時候我就想我要是能修改String的生成方法就好了，日誌其實就是一個字串而已，具體這個字串怎麼來的不重要。

這個時候我就想到了json，json也是字串，是我們資料交換的一種格式。利用生成Json的時候，進行過濾，對我們需要轉換的值進行脫敏從而達到我們的目的。

當然轉換Json和toString()方法，可能兩個會有很大效率的差別，這個時候就只能祭出fastjson了，fastjson利用asm位元組碼技術，擺脫了反射的降低效率，下面的效能基準測試中也已經說明，效率影響基本可以忽略不計。

所以其實我們就需要兩種filter:一個是log4j2的用於脫敏日誌的filter,一個是fastjson的filter用於轉換Json的時候進行對某些欄位做處理。

優點：

改動最小，只需要在Log4j.xml配置檔案中新增這個過濾器全域性生效，即可使用。

缺點:

1.既然是全域性生效，必然會讓每個日誌都會從以前的toString轉變為json，在追求極端效能的某些服務(比如哪怕多1ms都不可接受)上可能不適用。

2.可以看見我們這個是在第一步，而第一步的後面是自帶的等級過濾器，因為我們有時候會動態調整日誌級別，會導致我們這個哪怕不是當前可輸出等級，他也會進行轉換，有點得不償失。

這個第二點經過優化我把等級過濾器的工作也提前做了，等級不夠的直接拒絕。

示例程式碼如下:

@Plugin(name = "CrmSensitiveFilter", category = Node.CATEGORY, elementType = Filter.ELEMENT_TYPE, printObject = true) 
public class CrmSensitiveFilter extends AbstractFilter { 
    private static final long                       serialVersionUID = 1L; 
 
    private final boolean                           enabled; 
 
 
 
    private CrmSensitiveFilter(final boolean enabled, final Result onMatch, final Result onMismatch) { 
        super(onMatch, onMismatch); 
        //線上線下開關 
        this.enabled = enabled; 
    } 
 
    @Override 
    public Result filter(final Logger logger, final Level level, final Marker marker, final Object msg, 
                         final Throwable t) { 
        return filter(logger, level, marker, null, msg); 
    } 
 
    @Override 
    public Result filter(Logger logger, Level level, Marker marker, String msg, Object... params) { 
        if (this.enabled == false) { 
            return onMatch; 
        } 
        if (level == null || logger.getLevel().intLevel() < level.intLevel()) { 
            return onMismatch; 
        } 
        if (params == null || params.length <= 0) { 
            return super.filter(logger, level, marker, msg, params); 
        } 
        for (int i = 0; i < params.length; i++) { 
            params[i] = deepToString(params[i]); 
        } 
        return onMatch; 
    } 
 
 
 
    @PluginFactory 
    public static CrmSensitiveFilter createFilter(@PluginAttribute("enabled") final Boolean enabled, 
                                                  @PluginAttribute("onMatch") final Result match, 
                                                  @PluginAttribute("onMismatch") final Result mismatch) throws IllegalArgumentException, 
                                                                                                     IllegalAccessException { 
        return new CrmSensitiveFilter(enabled, match, mismatch); 
    } 
}
複製程式碼

2.3重寫MessageFactory

上面全域性過濾器的缺點是無法定製化，這個時候我把目光鎖定在第三步，生成日誌內容輸出Message。

通過重寫MessageFactory我們可以生成我們自己的Message，並且我們能在程式碼層面指定我們的LoggerMannger到底是使用我們自己的MesssageFactory，還是使用預設的，能由我們自己控制。

當然我們這裡生成的Message基本思路不變依然是fastjson的value過濾器。

優點:

能定製化LOGGER，非全域性。

缺點：

侷限於Log4j2,其他LogBack等日誌框架不適用

下面給出部分程式碼:

public class DesensitizedMessageFactory extends AbstractMessageFactory { 
    private static final long                      serialVersionUID = 1L; 
 
    /** 
     * Instance of DesensitizedMessageFactory. 
     */ 
    public static final DesensitizedMessageFactory INSTANCE         = new DesensitizedMessageFactory(); 
 
    /** 
     * @param message The message pattern. 
     * @param params The message parameters. 
     * @return The Message. 
     * 
     * @see MessageFactory#newMessage(String, Object...) 
     */ 
    @Override 
    public Message newMessage(String message, Object... params) { 
        return new DesensitizedMessage(message, params); 
    } 
 
    /** 
     * 
     * @param message 
     * @return 
     */ 
    @Override 
    public Message newMessage(Object message) { 
        return new ObjectMessage(DesensitizedMessage.deepToString(message)); 
    } 
}
複製程式碼

3.使用

我們團隊業務專案之前log4j是使用的2.6版本的，之前是一直是使用的filter，突然有次升級直接升到2.7，突然一下脫敏不管用了，當時研究原始碼發現，filter發生了一些改變當傳日誌引數小於等於2的時候是有問題的。

需要根據自己業務場景選擇一個最適合業務場景的:

log4j版本小於2.6使用filter，大於2.6(當然不大於2.6也能使用)使用MessageFactory

3.1 filter配置(二選一)

找到Log4j.xml（每個環境都有自己對應的哈）

在最外層節點下面，也就是裡面寫如下配置，enabled用於線上線下切換，true為生效，false為不生效。

3.2 MessageFactory配置(二選一)

建立檔案:log4j2.component.properties

輸入:log4j2.messageFactory=log.message.DesensitizedMessageFactory

4.效能基準測試:

基準測試聚焦列印日誌效率如何。

硬體：

4核,8G複製程式碼

作業系統：

linux複製程式碼

JRE：

v1.8.0_101，初始堆大小4G複製程式碼

預熱策略：

測試開始前，全域性預熱，執行全部測試若干次，判斷執行時間穩定後停止，確保所需class全部載入完成每個測試開始前，獨立預熱，重複執行該測試64次，確保JIT編譯器充分優化完程式碼。複製程式碼

執行策略：

迴圈執行，初始次數200，以200的步長遞增，遞增至1000為止。每次執行10次，去掉一個最高，去掉一個最低，取平均值。複製程式碼

測試結果：

由上面結果可見增長速率基本穩定

上述結果脫敏的時間大概是未脫敏的時間1.5倍，

平均下來未脫敏的是0.1255ms 產生一條，而脫敏的是0.18825ms產生一條日誌，兩者相差0.06ms左右。

我們整個請求預估最多有10-20條日誌列印，整條請求平均會影響時間0.6ms-1.2ms左右，我覺得這個時間可以忽略不計在整個請求當中。

所以這種模式的效能還是比較好，可以應用於生產環境。