写点什么

哭了!“日志注入”为什么跟想象中的不一样

发布于: 2021 年 04 月 21 日

​​​​摘要:当 web 工程比较大,历史代码较多时, 应当使用 log4j2 框架的能力来修改日志注入问题,而不是按照有些博文里写的逐个进化参数的方式。


本文分享自华为云社区《Java云服务开发安全问题解析——日志注入,并没那么简单》,原文作者:breakDraw。

案例故事


某个新系统上线了,小 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
复制代码


日志对接了风险审计系统,会定期从日志中审计出那些每天有可疑登录行为的人,例如那些半夜登录或者频繁登录(不要在意细节,不用审计也能做,只是举个例子而已)



​某天,日志审计系统提示 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 或者换行的关键字,找到了如下的内容:



文档里写得很清楚, 使用 %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 修改异常里的 message


过了一个月,突然日志审计又告警了, 最终排查下来又是误报。去看了日志,发现长这样:


[2021-04-17 16:50:35][INFO][main] [Login:308] unknown error happendjava.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 同样有日志注入风险,如果工程里支持打印堆栈,则最好也统一处理一下。


点击关注,第一时间了解华为云新鲜技术~

发布于: 2021 年 04 月 21 日阅读数: 21
用户头像

提供全面深入的云计算技术干货 2020.07.14 加入

华为云开发者社区,提供全面深入的云计算前景分析、丰富的技术干货、程序样例,分享华为云前沿资讯动态,方便开发者快速成长与发展,欢迎提问、互动,多方位了解云计算! 传送门:https://bbs.huaweicloud.com/

评论

发布
暂无评论
哭了!“日志注入”为什么跟想象中的不一样