五年Java经验，面试还是说不出日志该怎么写更好？——日志规范与最佳实践篇

本文是一个系列，欢迎关注

查看上一篇文章可以扫描文章下方的二维码，点击往期回顾-日志系列即可查看所有相关文章

概览

上一篇我们讨论了为什么要使用日志框架，这次我们深入问题的根源，为什么我们需要日志？

大多数开发人员会纠结日志该怎么输出，什么时候输出，输出了会不会有人看等问题，让我们跳出开发人员的局限来考虑这个问题：谁需要日志？日志有几种？日志都需要输出什么？如何输出日志？

谁需要日志？

• 开发者 开发人员在开发过程中需要输出一些变量方便调试，正确的做法是使用日志来输出（使用 System.out来输出，一不小心发布到线上，会被项目经理痛批）；其次线上问题很难重放，用户的表述一般都会失真，况且很多用户发现 bug 就删 app 关网页走人了
• 运维人员 整个系统大部分时间都是运维人员来维护，日志可以帮助运维人员来了解系统状态（很多运维系统接入的也是日志），运维人员发现日志有异常信息也可以及时通知开发来排查
• 运营人员 没错，就是运营人员，比如电商的转化率、视频网站的完播率、普通PV数据等都可以通过日志进行统计，随着大数据技术的普及，这部分日志占比也越来越高
• 安全人员 虽然大多数企业不重视安全，但是安全也可以通过日志来进行预警，比如某个用户突然大额转账、再比如数据库突然出现大量无条件分页查库（拖库）等等

日志有几种？

• 调试日志 用于开发人员开发或者线上回溯问题。
• 诊断日志 一般用于运维人员监控系统与安全人员分析预警。
• 埋点日志 一般用于运营决策分析，也有用作微服务调用链路追踪的（运维、调试）。
• 审计日志 与诊断日志类似，诊断日志偏向运维，审计日志偏向安全。

日志都需要输出什么？

注：日志级别会在下面讲解

• 调试日志

  • DEBUG 或者 TRACE 级别，比如方法调用参数，网络连接具体信息，一般是开发者调试程序使用，线上非特殊情况关闭这些日志
  • INFO 级别，一般是比较重要却没有风险的信息，如初始化环境、参数，清理环境，定时任务执行，远程调用第一次连接成功
  • WARN 级别，有可能有风险又不影响系统继续执行的错误，比如系统参数配置不正确，用户请求的参数不正确（要输出具体参数方便排查），或者某些耗性能的场景，比如一次请求执行太久、一条sql执行超过两秒，某些第三方调用失败，不太可能被运行的if分支等
  • ERROR 级别，用于程序出错打印堆栈信息，不应该用于输出程序问题之外的其他信息，需要注意打印了日志异常（Exception）就不应该抛（throw）了
• 诊断日志 一般输出 INFO 级别，请求响应时间，内存占用等等，线上接入监控系统时打开，建议输出到独立的文件，可以考虑 JSON 格式方便外部工具分析
• 埋点日志 业务按需定制，比如上文提到的转化率可以在用户付款时输出日志，完播率可以在用户播放完成后请求一次后台输出日志，一般可输出 INFO 级别，建议输出到独立的文件，可以考虑JSON格式方便外部工具分析
• 审计日志 大多 WARN 级别或者 INFO 级别，一般是敏感操作即可输出，登陆、转账付款、授权消权、删除等等，建议输出到独立的文件，可以考虑JSON格式方便外部工具分析

一般调试日志由开发者自定义输出，其他三种应该根据实际业务需求来定制。

日志的其他注意点

1. 线上日志应尽量谨慎，要思考：这个位置输出日志能帮助排除问题吗？输出的信息与排查问题相关吗？输出的信息足够排除问题吗？做到不少输出必要信息，不多输出无用信息（拖慢系统，淹没有用信息）
2. 超级 SessionId 与 RequestId，无论是单体应用还是微服务架构，应该为每个用户每次登陆生成一个超级 SessionId，方便跟踪区分一个用户；RequestId，每次请求生成一个 RequestId，用于跟踪一次请求，微服务也可以用于链路追踪
3. 日志要尽量单行输出，一条日志输出一行，否则不方便阅读以及其他第三方系统或者工具分析
4. 公司内部应该制定一套通用的日志规范，包括日志的格式，变量名（驼峰、下划线），分隔符（“=”或“:”等），何时输出（比如规定调用第三方前后输出INFO日志），公司的日志规范应该不断优化、调整，找到适合公司业务的最佳规范

OK，理论就聊到这里，接下来让我们回到技术层面。

使用概念

如果要想要学会使用日志框架，先要理解几个简单概念，Logger、Appenders、Layout、日志级别与级别继承（Level Inheritance）

Logger（日志实例）

用于输出日志，调用一次org.slf4j.LoggerFactory#getLogger(java.lang.Class<?>)或org.slf4j.LoggerFactory#getLogger(java.lang.String)就会产生一个日志实例，相同参数会共用同一个实例。

Appenders

日志输出器，logback 预定义了输出到控制台、文件、Socket 服务器、MySQL、PostgreSQL、Oracle 和其他数据库、JMS 和 UNIX Syslog 系统调用等实现，通过配置文件配置即可使用，当然我们常用的只有控制台和文件两种。

Layout

用于控制日志输出格式，前文所说的”自动输出日志相关信息，如：日期、线程、方法名称等等“就可以用 Layout 来控制，实际使用很简单，写一个 Layout 格式定义表达式（pattern）即可，使用方法类似于Java 的SimpleDateFomat。

日志级别

RFC 5424 （page 11）规定了 8 种日志级别，但是SLF4j 只定义了 5 种日志级别，分别是 ERROR、WARN、INFO、DEBUG、TRACE 这五个级别从高到低，配置级别越高日志输出就越少，如下图

我们看到滑动条上五个点正好对应五个级别，滑动指示器可以左右移动，指示器作为分界点，指示器左侧都可以输出，右侧都不能输出，左右调整指示器就可以调整日志的输出，滑倒右侧就可以全部输出，滑倒左侧就可以减少输出，那么是否能够彻底关闭输出呢？答案是可以的，配置文件中还可以配置为 ALL 与 OFF，分别对应所有（等价于TRACE）与关闭。

级别继承

理解了日志级别，让我们来考虑两个场景：

• 某些重要业务输出 INFO 级别，其他业务输出WARN级别的日志，同时关闭所有库、框架的日志

有需求就会有解决方案，其实很简单，logback 与 log4j 都支持按照日志实例来配置，现在问题解决了，但是新的问题又来了，如果线上所有日志都输出 INFO 级别，难道要一个一个配置吗？这时候就就要请出我们上面所提到的级别继承，如果 Java 一样，logback 与 log4j 中也都是单根继承模型，Java 中是 Object，日志中是 ROOT，如下图：

有了继承机制，我们只需要将 ROOT 调整到 INFO 级别，再按照需求细化调整我们业务对应的 logger 实例级别即可满足绝大多数场景。

Codding 实战

问：把大象装冰箱分几步？分三步：1、引入依赖，2、编码输出日志，3、调整配置文件。前文已经讲过步骤一，如果没有看过的读者请移步公众号查看往期回顾，这里直接进入步骤二。

步骤二

如果项目中使用了Lombok，那么可以直接在类上面加@Slf4j注解既可获得日志实例，否则可以使用static final org.slf4j.Logger logger = LoggerFactory.getLogger(TestLog.class);来获取日志实例

具体日志输出方法如下：

logger.trace("A TRACE Message");
logger.debug("A DEBUG Message");
logger.info("An INFO Message");
logger.warn("A WARN Message");
logger.error("An ERROR Message");

这里有个注意点，尽量使用参数占位而不要手动拼接字符串，如下

String level = "Trace";
// 反例
logger.trace("A " + level + " Message");
// 正确的做法
logger.trace("A {} Message", level);

这样做可以提高效率，如果不输出日志，第一种情况也会拼接字符串造成性能损耗，第二种就不会有此问题（阿里巴巴Java开发手册（华山版）这里表述有问题，占位符效率更高是因为尽量延迟进行字符串处理，如果不需要输出的日志就不处理了，下一篇原理分析会展开），另外我们也不需要if (logger.isTraceEnabled())来进行判断了（性能损耗不高，但是代码好看多了）。

步骤三

配置文件需要区分 logback 与 log4j2，两种框架在配置文件上有差别但很相似，来看具体配置文件。

logback 配置文件位置

lobback 支持 xml 与 groovy 脚本两种配置方式，logback 查找配置文件位置规则如下（后续文章会讲如何修改位置）

1. logback 尝试在类路径中找到一个名为 logback-test.xml 的文件。
2. 如果找不到此类文件，则 logback 会尝试在类路径中找到名为 logback.groovy 的文件。
3. 如果找不到这样的文件，它将在类路径中检查文件 logback.xml。
4. 如果找不到此类文件，则通过查找文件 META-INFservicesch.qos.logback.classic.spi.Configurator，如果有这个文件且内容是 com.qos.logback.classic.spi.Configurator 实现类的全类名，直接加载这个实现类。
5. 如果以上方法均不能成功执行，则 logback 会使用 BasicConfigurator 自动进行自我配置，会将日志输出到控制台。

这段长长的文字其实不用看，我们就把logback.xml放入Classpath根目录就可以了。。

logback 配置文件编写规则

logback 配置文件主要分为三类，一个或多个 Appender，用于定义输出位置（不同文件位置，或者网络又或者数据库）；一个或多个 Logger，用于细化配置不同 logger 的输出级别以及位置；一个 ROOT，是一个特殊的logger，用于配置根 Logger。

我们一起来看下面的配置文件实例

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

    <!-- 定义日志文件的存储地 -->
    <property name="LOG_PATH" value="/var/log"/>

    <property name="CONSOLE_LOG_PATTERN"
              value="%d{HH:mm:ss.SSS} %-5level [%10.10thread] %-30.30logger{29}\(%4L\\) - %msg%n"/>
    <!-- 控制台输出 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf-8</charset>
        </encoder>
    </appender>

    <!-- 文件日志格式(打印日志，不打印行号) -->
    <property name="FILE_LOG_PATTERN"
              value="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%10.10thread] %-30.30logger{29} - %msg%n"/>

    <appender name="FILE_ALL" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在记录的日志文件的路径及文件名 -->
        <file>${LOG_PATH}/log.log</file>
        <!-- 日志记录器的滚动策略，按日期，按大小记录 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!-- yyyy-MM-dd 按日滚动 -->
            <fileNamePattern>${LOG_PATH}/log-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!-- 单个文件最大50M -->
            <maxFileSize>50MB</maxFileSize>
            <!--  最多占用5G磁盘空间，500个文件（总共不能超过该5G） -->
            <maxHistory>500</maxHistory>
            <totalSizeCap>5GB</totalSizeCap>
        </rollingPolicy>
        <!-- 追加方式记录日志 -->
        <append>true</append>
        <!-- 日志文件的格式 -->
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>utf-8</charset>
        </encoder>
    </appender>

    <!-- 日志输出级别 STDOUT:控制台；FILE_ALL:文件 -->
    <root level="warn">
        <appender-ref ref="STDOUT"/>
    </root>
    <logger name="druid.sql" level="warn" additivity="true"/>
    <logger name="druid.sql.ResultSet" level="warn" additivity="true"/>
    <logger name="com.alibaba.druid.pool.DruidDataSource" level="debug" additivity="true">
        <appender-ref ref="FILE_ALL"/>
    </logger>
</configuration>

上面配置文件定义了两个 Appender，一个输出控制台，另一个输出到文件并且自动滚动。需注意的是property标签相当于定义一个变量，可以使用${xxx}进行引用，CONSOLE_LOG_PATTERN 与 FILE_LOG_PATTERN 定义了控制台与文件打印格式，具体编写方式类似于 Java 的SimpleDateFomat就不在此展开了，具体可以参考

• logback：http://logback.qos.ch/manual/...
• log4j：https://logging.apache.org/lo...

log4j2 配置文件位置

log4j2 支持 XML、JSON、YAML 或者 properties 格式的配置文件，具体查找方式如下：

1. 检查“ log4j.configurationFile”系统属性，如果有，尝试使用与文件扩展名匹配的ConfigurationFactory加载配置。
2. 如果未设置系统属性，则属性 ConfigurationFactory 将在类路径中查找 log4j2-test.properties。
3. 如果找不到此类文件，则 YAML ConfigurationFactory将在类路径中查找 log4j2-test.yaml或log4j2-test.yml。
4. 如果找不到此类文件，则 JSON ConfigurationFactory 将在类路径中查找 log4j2-test.json或log4j2-test.jsn。
5. 如果找不到这样的文件，XML ConfigurationFactory 将在类路径中查找 log4j2-test.xml。
6. 如果找不到测试文件，则属性 ConfigurationFactory 将在类路径上查找 log4j2.properties。
7. 如果找不到属性文件，则 YAML ConfigurationFactory 将在类路径上查找 log4j2.yaml或log4j2.yml。
8. 如果无法找到 YAML 文件，则 JSON ConfigurationFactory 将在类路径上查找 log4j2.json或log4j2.jsn。
9. 如果无法找到 JSON 文件，则 XML ConfigurationFactory 将尝试在类路径上找到 log4j2.xml。
10. 如果找不到配置文件，使用 DefaultConfiguration 自动配置，将日志输出到控制台。

这段更长的文字当然也不用看，我们就把 log4j2.xml 放入 Classpath 根目录就可以了

log4j2 配置文件编写

log4j 也是 Logger 与 Appender 配置项，也有一个ROOT的特殊 Logger，Appender 比logback支持更多输出位置，如kafka、Cassandra、Flume等。

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" strict="true">
    <!--  定义变量，可以被${xxx}引用  -->
    <Properties>
        <Property name="baseDir">logs</Property>
    </Properties>

    <!--  定义 Appenders 用来指定输出位置 -->
    <Appenders>
        <!-- 日志滚动 $${date:yyyy-MM}：按月滚动文件夹 按小时、文件序号滚动，每次滚动都使用gz压缩 -->
        <RollingFile name="RollingFile" fileName="${baseDir}/log.log"
                     filePattern="${baseDir}/$${date:yyyy-MM}/log-%d{yyyy-MM-dd-HH}-%i.log.gz">
            <!-- 日志格式 -->
            <PatternLayout pattern="%d %p %c{1.} [%t] %m%n"/>
            <Policies>
                <!-- 时间滚动（按月滚动目录，按小时滚动文件） -->
                <TimeBasedTriggeringPolicy/>
                <!-- 文件大小滚动（1小时内超过250M，强制滚动一次） -->
                <SizeBasedTriggeringPolicy size="250 MB"/>
            </Policies>
            <!-- 每天最多100个文件 -->
            <DefaultRolloverStrategy max="100">
                <!-- 删除策略，超过三十天删除，如果总文件小于100G，文件数量小于10个，则不会被删除 -->
                <Delete basePath="${baseDir}" maxDepth="2">
                    <IfFileName glob="*/app-*.log.gz">
                        <IfLastModified age="30d">
                            <IfAny>
                                <IfAccumulatedFileSize exceeds="100 GB"/>
                                <IfAccumulatedFileCount exceeds="10"/>
                            </IfAny>
                        </IfLastModified>
                    </IfFileName>
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>
    </Appenders>

    <Loggers>
        <!-- 多个logger -->
        <Logger name="org.apache.logging.log4j.test2" level="debug" additivity="false">
            <AppenderRef ref="RollingFile"/>
        </Logger>

        <!-- 一个ROOT -->
        <Root level="trace">
            <AppenderRef ref="STDOUT"/>
        </Root>
    </Loggers>
</Configuration>

可以看得出 log4j2 与 logback 配置文件书写大同小异，甚至同样需要注意additivity="true"时导致的日志重复输出问题，毕竟 log4j1 与 logback 都是 Ceki大神都作品。

总结

得益于 Ceki 大佬的努力，日志使用几乎没有有差异（Logback 与 Log4j2，Google 于 2018年4月开源了流式（fluent）日志框架 Flogger，Slf4j 也将在2.0版本支持，而 Log4j2 再次落后，不过笔者认为log4j2更强大，更多内容请关注下一篇文章）。关于日志如何输出本人也是经验之谈，免不了纰漏，欢迎补充指正，另外每个公司都有不同的应用场景，具体应该遵守公司统一规范。

本篇更多倾向基础使用，接下来的文章将展开对比、原理以及扩展日志框架，敬请各位期待。

本文相关代码

如果觉得写的不错，求关注、求点赞、求转发，如果有问题或者文中有错误，欢迎留言讨论。

扫码关注公众号，第一时间获得更新

参考

https://logging.apache.org/lo...

http://logback.qos.ch/manual/...