安全開發Java：日誌注入，並沒那麼簡單

華為雲開發者社群發表於2021-04-21
Java
摘要：當web工程比較大，歷史程式碼較多時， 應當使用log4j2框架的能力來修改日誌注入問題，而不是按照有些博文裡寫的逐個進化引數的方式。

案例故事

某個新系統上線了，小A在其中開發了個簡單的登入模組，會在日誌裡記錄所有登入成功或者失敗的使用者。

小A對使用者名稱都做了白名單校驗，不正確的名字，也會用WARN的形式，列印出來做記錄。

像下面這樣：

[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][WARN][main] [Login:308] username is wrong,userName=tony.dssdff

日誌對接了風險審計系統，會定期從日誌中審計出那些每天有可疑登入行為的人，例如那些半夜登入或者頻繁登入（不要在意細節，不用審計也能做，只是舉個例子而已）

安全開發Java：日誌注入，並沒那麼簡單

某天，日誌審計系統提示tony登入過於頻繁且高危操作， 於是把tony的號給封了。

隨後一天又封了N多個無辜的使用者，引發使用者大量不滿。運營部找來問罪，小A拿出下面的日誌檔案做證據:

[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][WARN][main] [Login:308] username is wrong,userName=tony.dssdff
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony

然而tony反應說他那天在外面旅遊，電腦也放在家中，是有證據的。

這時候小A的老大翻出了請求介面日誌，發現那時候有1個請求發來， 介面裡的username引數竟然是：

username=tony.dssdff
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony

好傢伙，竟然是username裡帶了換行，雖然我做了白名單校驗，但是日誌裡為了記錄這個帶換行的錯誤名，坑了一堆使用者。（因為對方可能是使用rest-api去惡意傳送的，所以也繞過了前臺頁面的校驗）

小A的公司因此遭遇了巨大損失，小A最終也失業了。

簡單整改方法

小A費勁九牛二虎之力找到一家新公司，接手了一堆舊程式碼。他決定提前預防， 給外部輸入的日誌引數加上換行處理.

他寫了一個方法如下：

 /**
     * 獲取淨化後的訊息，過濾掉換行，避免日誌注入
     * @param message
     * @return
     */
    public static String getCleanedMsg(String message) {
        if (message == null) {
            return "";
        }

        message = message.replace('\n', '_').replace('\r', '_');
        return message;
    }

並且給自己打日誌的地方，補充了這個方法

LOGGER.warn("username is wrong,userName={}", getCleanedMsg(userName));

但是想起來這個系統比較舊，還有好多類似的引數，於是搜尋了一下，發現竟然有一千多處帶引數的日誌，好多是前輩留給他的坑。

於是他懷著責任心一個一個修改和檢查， 花了一個多月終於把所有外部輸入的引數排查出來並加上getCLeanMsg方法。年末最終因為輸出不夠，背了個最低績效，鬱鬱寡歡，頭髮又掉光了。

log4j2配置統一修改message

小A被換了個專案組，這次決定不再重蹈覆轍，使用別的方式簡化一下。他的專案裡日誌都是用log4j2列印的，如果能利用框架能力，把日誌的換行全部去掉就好了，嚴格保證日誌輸出的只有1行。

於是開始認真學習log4j2的官方文件。他在裡面找到了和日誌輸出格式有關的位置，如下：https://logging.apache.org/log4j/2.x/manual/layouts.html

他搜尋\n或者換行的關鍵字，找到了如下的內容：

安全開發Java：日誌注入，並沒那麼簡單

文件裡寫得很清楚， 使用%enc{%m}{CRLF}， 即可對這部分進行換行的過濾處理。於是在log4j2.xml的<PatternLayout>改成了如下：

  <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}][%-5p] [%t] [%c{10}#%M:%L] %enc{%m}{CRLF} %n "/>
        </Console>

測試，最終所有的日誌都會只有一行。以前會引發問題的日誌也變成了

username=tony.dssdff\r\n[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony

因此不會被日誌系統錯誤解析，同時也省去了一個個排查的風險。

log4j2 修改異常裡的mesage

過了一個月，突然日誌審計又告警了， 最終排查下來又是誤報。去看了日誌，發現長這樣：

[2021-04-17 16:50:35][INFO][main] [Login:308] unknown error happend
java.lang.RuntimeException: name,name=%s
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
[2021-04-17 16:50:35][INFO][main] [Login:308] login success,userName=tony
        at java.net.SocketInputStream.socketRead0(Native Method) ~[?:?]
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:115) ~[?:?]
        at java.net.SocketInputStream.read(SocketInputStream.java:168) ~[?:?]
        at java.net.SocketInputStream.read(SocketInputStream.java:140) ~[?:?]
        at sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:448) ~[?:?]

好傢伙，原來是有些地方列印日誌時， 順便把未處理過的異常堆疊也列印出來了。異常堆疊的第一行往往是異常名+message， 這裡也能被惡意攻擊。

小A翻遍了log4j2文件，沒有找到能在異常中處理換行的符號，只找到了1個ThrowablePatternConverter， 文件裡告訴他，你可以自定義這個ThrowablePatternConverter，來列印自己想要的異常。

於是他自己編寫了一個UndefineThrowablePatternConvert，在裡面重寫了日誌堆疊列印的邏輯，

/**
 * 會對異常做特定編碼處理的格式轉換類
 * 使用時，在layout中新增 %eEx即可
 *
 * @since 2021/4/16
 */
@Plugin(name = "UndefineThrowablePatternConverter", category = PatternConverter.CATEGORY)
// 自己定義的layout鍵值
@ConverterKeys({"uEx"})
public class UndefineThrowablePatternConverter extends ThrowablePatternConverter {
 
      /**
     * 進行過特定編碼處理的ThrowableProxy
     */
    static class EncodeThrowableProxy extends ThrowableProxy {
        public EncodeThrowableProxy(Throwable throwable) {
            super(throwable);
        }

        // 將\r和\n進行編碼，避免日誌注入
        @Override
        public String getMessage() {
            String encodeMessage = super.getMessage().replaceAll("\r", "\\\\r").replaceAll("\n", "\\\\n");
            return encodeMessage;
        }
    }
 
    protected UndefineThrowablePatternConverter(Configuration config, String[] options) {
        super("UndefineThrowable", "throwable", options, config);
    }
 
      // log4j2中使用反射呼叫newInstance靜態方法進行構造，因此必須要實現這個方法。
    public static UndefineThrowablePatternConverter newInstance(final Configuration config, final String[] options) {
        return new UndefineThrowablePatternConverter(config, options);
    }

    @Override
    public void format(final LogEvent event, final StringBuilder toAppendTo) {
          Throwable throwable = event.getThrown();
        if (throwable == null) {
            return;
        }
        // 使用自定義的EncodeThrowableProxy，裡面重寫了ThrowableProxy的getMessage方法
        EncodeThrowableProxy proxy = new EncodeThrowableProxy(throwable);
         // 新增到toAppendTo
          proxy.formatExtendedStackTraceTo(toAppendTo, options.getIgnorePackages(), options.getTextRenderer(), getSuffix(event), options.getSeparator());
    }
}

並且在PatternLayout中新增%uEx， 就會使用這裡的format去生成堆疊字串。

總結

  • 白名單無法避免日誌注入問題，因為有時候我們可能會記錄那些有錯誤的輸入引數。
  • 當web工程比較大，歷史程式碼較多時， 應當使用log4j2框架的能力來修改日誌注入問題，而不是按照有些博文裡寫的逐個進化引數的方式
  • 異常堆疊裡的message同樣有日誌注入風險，如果工程裡支援列印堆疊，則最好也統一處理一下。

 本文分享自華為雲社群《Java雲服務開發安全問題解析——日誌注入，並沒那麼簡單》，原文作者：breakDraw。

點選關注，第一時間瞭解華為雲新鮮技術~

相關文章