摘要：當web工程比較大，歷史代碼較多時， 應當使用log4j2框架的能力來修改日誌注入問題，而不是按照有些博文裏寫的逐個進化參數的方式。
本文分享自華爲雲社區《Java雲服務開發安全問題解析——日誌注入，並沒那麼簡單》，原文做者：breakDraw。html
案例故事
某個新系統上線了，小A在其中開發了個簡單的登陸模塊，會在日誌裏記錄全部登陸成功或者失敗的用戶。java
小A對用戶名都作了白名單校驗，不正確的名字，也會用WARN的形式，打印出來作記錄。web
像下面這樣：apache
[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
日誌對接了風險審計系統，會按期從日誌中審計出那些天天有可疑登陸行爲的人，例如那些半夜登陸或者頻繁登陸（不要在乎細節，不用審計也能作，只是舉個例子而已）api
某天，日誌審計系統提示tony登陸過於頻繁且高危操做， 因而把tony的號給封了。安全
隨後一天又封了N多個無辜的用戶，引起用戶大量不滿。運營部找來問罪，小A拿出下面的日誌文件作證據:app
[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參數居然是：socket
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去惡意發送的，因此也繞過了前臺頁面的校驗）ide
小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或者換行的關鍵字，找到了以下的內容：
文檔裏寫得很清楚， 使用%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一樣有日誌注入風險，若是工程裏支持打印堆棧，則最好也統一處理一下。