安全開發Java:日誌注入,並沒那麼簡單

華為雲開發者社群 發表於 2021-04-21
摘要:當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。

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