Java日志框架浅析

头像
Ekko
     江苏
    阅读 9 分钟

    序

    前段时间Log4j爆出相关安全问题，各大公司都在紧急修复该问题，我所处的公司也不例外。但在排查相关问题时，发现对Java日志框架整体的认知还是比较乱的，于是乎，就搜罗各大文章对其进行了解并记录，以备后续复习或用之。

    Java日志历史

    title=

    1. 最开始Java应用都是使用System.out/err.println()的方式来跟踪自己的程序运行情况；
    2. 1996年，E.U.SEMPER（欧洲安全电子市场）项目编写己的跟踪API，该API演变为Log4j，主要作者就有：CekiGülcü，后该项目加入了Apache基金会项目；
    3. 2002年2月，Java1.4发布，Sun推出了自己的日志库：JUL（Java Util Logging）；
    4. 2002年8月，Apache推出了日志接口 JCL（ Jakarta Commons Logging）（日志抽象层）;
    5. 由于一些原因，CekiGülcü离开了Apache，在2005年的时候推出了一套新的日志接口Slf4j（Simple Logging Facade for Java）；
    6. 由于使用Slf4j，之前的日志产品都不是正统的Slf4j的实现，在2006年的时候，CekiGülcü又撸了一套日志产品LogBack，且是完美实现了Slf4j；

    7. Slf4j+LogBack的模式冲击了之前的JCL+Log4j的形式，Apache就在2012年推出了自己的新项目Log4j2，该项目是完全不兼容Lg4j1.x的。

      适配模式

      前面我们提到， Slf4j 的出现晚于 JUL、JCL、log4j 等日志框架，所以，这些日志框架也不可能牺牲掉版本兼容性，将接口改造成符合 Slf4j 接口规范。 Slf4j 也事先考虑到了这个问题，所以，它不仅仅提供了统一的接口定义，还提供了针对不同日志框架的适配器（slf4j-log4j12/slf4j-jdk14）；´但是其实之前很多Java应用应该依赖的JCL，所以光有日志产品适配包还不够，于是有了日志标准的适配包（slf4j-jcl）。

    image.png

    定义

    顾名思义，适配模式就是用做适配的，它将不兼容的接口转换为可兼容的接口，让原本由于接口不兼容而不能一起工作的类可以一起工作。

    实现方式

    ITarget 表示要转化成的接口定义。Adaptee 是一组不兼容 ITarget 接口定义的接口，Adaptor 将 Adaptee 转化成一组符合 ITarget 接口定义的接口。

    类适配器

    // 类适配器: 基于继承
public interface ITarget {
  void f1();
  void f2();
  void fc();
}

public class Adaptee {
  public void fa() { //... }
  public void fb() { //... }
  public void fc() { //... }
}

public class Adaptor extends Adaptee implements ITarget {
  public void f1() {
    super.fa();
  }
  
  public void f2() {
    //...重新实现f2()...
  }
  
  // 这里fc()不需要实现，直接继承自Adaptee，这是跟对象适配器最大的不同点
}

    对象适配器

    // 对象适配器：基于组合
public interface ITarget {
  void f1();
  void f2();
  void fc();
}

public class Adaptee {
  public void fa() { //... }
  public void fb() { //... }
  public void fc() { //... }
}

public class Adaptor implements ITarget {
  private Adaptee adaptee;
  
  public Adaptor(Adaptee adaptee) {
    this.adaptee = adaptee;
  }
  
  public void f1() {
    adaptee.fa(); //委托给Adaptee
  }
  
  public void f2() {
    //...重新实现f2()...
  }
  
  public void fc() {
    adaptee.fc();
  }
}

    具体使用哪种有两者判断标准

    • Adaptee 接口的个数
    • Adaptee 和 ITarget 的契合程度

    若接口个数不多则两种实现方式都可以；否则则判断适配的两者之间的接口定义是否大部分都相同，若相同，则可以使用类适配器（基于继承）这样可以复用代码，减少代码的冗余性；若少部分相同，则可以使用对象适配器（基于组合）这样可以让代码更灵活。

    Tips：代理模式在不改变原始类接口的条件下，为原始类定义一个代理类，主要目的是控制访问，而非加强功能，这是它跟装饰器模式最大的不同。

    Slf4j中的实现方案举例

    // slf4j统一的接口定义
package org.slf4j;
public interface Logger {
  public boolean isTraceEnabled();
  public void trace(String msg);
  public void trace(String format, Object arg);
  public void trace(String format, Object arg1, Object arg2);
  public void trace(String format, Object[] argArray);
  public void trace(String msg, Throwable t);
 
  public boolean isDebugEnabled();
  public void debug(String msg);
  public void debug(String format, Object arg);
  public void debug(String format, Object arg1, Object arg2)
  public void debug(String format, Object[] argArray)
  public void debug(String msg, Throwable t);

  //...省略info、warn、error等一堆接口
}

// log4j日志框架的适配器
// Log4jLoggerAdapter实现了LocationAwareLogger接口，
// 其中LocationAwareLogger继承自Logger接口，
// 也就相当于Log4jLoggerAdapter实现了Logger接口。
package org.slf4j.impl;
public final class Log4jLoggerAdapter extends MarkerIgnoringBase
  implements LocationAwareLogger, Serializable {
  final transient org.apache.log4j.Logger logger; // log4j
 
  public boolean isDebugEnabled() {
    return logger.isDebugEnabled();
  }
 
  public void debug(String msg) {
    logger.log(FQCN, Level.DEBUG, msg, null);
  }
 
  public void debug(String format, Object arg) {
    if (logger.isDebugEnabled()) {
      FormattingTuple ft = MessageFormatter.format(format, arg);
      logger.log(FQCN, Level.DEBUG, ft.getMessage(), ft.getThrowable());
    }
  }
 
  public void debug(String format, Object arg1, Object arg2) {
    if (logger.isDebugEnabled()) {
      FormattingTuple ft = MessageFormatter.format(format, arg1, arg2);
      logger.log(FQCN, Level.DEBUG, ft.getMessage(), ft.getThrowable());
    }
  }
 
  public void debug(String format, Object[] argArray) {
    if (logger.isDebugEnabled()) {
      FormattingTuple ft = MessageFormatter.arrayFormat(format, argArray);
      logger.log(FQCN, Level.DEBUG, ft.getMessage(), ft.getThrowable());
    }
  }
 
  public void debug(String msg, Throwable t) {
    logger.log(FQCN, Level.DEBUG, msg, t);
  }
  //...省略一堆接口的实现...
}

    桥接模式

    但是，还有一种情况，比如引用的是第三方框架用的是JCL，并且最终使用JUL打印日志，但是你的系统使用的是Slf4j，最终使用Log4j打印，那将会有两种输出，两种日志的输出环境不统一，但时候看日志的时候很麻烦，然后开发Slf4j的开发者为了让大家统一使用Slf4j，就又撸出了对应的桥接包（jul-to-slf4j/log4j-over-slf4j/jcl-over-slf4j）。

    image.png

    定义

    将抽象和实现解耦，让它们可以独立变化。定义中的“抽象”，指的并非“抽象类”或“接口”，而是被抽象出来的一套“类库”，它只包含骨架代码，真正的业务逻辑需要委派给定义中的“实现”来完成。而定义中的“实现”，也并非“接口的实现类”，而是一套独立的“类库”。“抽象”和“实现”独立开发，通过对象之间的组合关系，组装在一起。

    最佳实践

    日志级别

    • TRACE【跟踪函数调用，不存在变量参数】

      • 一般跟踪的是函数的调用，并且 TRACE 不应该含有变量参数，而仅能提示函数的调用关系。

    • DEBUG【调试应用程序，存在变量参数】

      • 一般用于细粒度级别上，对调试应用程序非常有帮助，主要用于开发过程中打印一些运行信息。

    • INFO【应用程序运行过程，避免过多】

      • INFO 消息在粗粒度级别上突出强调应用程序的运行过程。打印一些你感兴趣的或者重要的信息，这个可以用于生产环境中输出程序运行的一些重要信息，但是不能滥用，避免打印过多的日志。

    • WARN【符合预期潜在的错误或提示】

      • WARN 表示会出现潜在错误的情形，有些信息不是错误信息，但是也要给程序员一些提示。该级别表示程序会自动调整到正常的状态，类似参数未传入，使用了默认的参数，仍符合程序员预期之内的情况。

    • ERROR【出现错误，仍能运行】

      • ERROR 指出虽然发生错误事件，但仍然不影响系统的继续运行。打印错误和异常信息，如果不想输出太多的日志，可以使用这个级别。一般在 WARN 之后的级别在打印错误时，应该同时打印错误码。

    • FATEL【出现错误，不能运行】

      • FATAL 指出每个严重的错误事件将会导致应用程序的退出，这个级别比较高，重大错误，程序无法恢复，必须通过重启程序来解决。
      在 Log4j 中，日志级别的关系如下所示：
      ALL<TRACE<DEBUG<INFO<WARN<ERROR<FATAL<OFF
      设置了对应的级别之后，日志框架就只调用大于等于这个级别的方法。Log4j 建议只使用如下的四个界别：
      DEBUG<INFO<WARN<ERROR

    日志性能

    //  记录 DEBUG 日志，并设置只记录 >=INFO 级别的日志

private String slowString(String s) {
    System.out.println("slowString called via " + s);
    try {
        TimeUnit.SECONDS.sleep(1);
    } catch (InterruptedException e) {
    }
    return "OK";
}


StopWatch stopWatch = new StopWatch();
stopWatch.start("debug1");
log.debug("debug1:" + slowString("debug1"));
stopWatch.stop();

stopWatch.start("debug2");
log.debug("debug2:{}", slowString("debug2"));
stopWatch.stop();

stopWatch.start("debug3");
if (log.isDebugEnabled())
    log.debug("debug3:{}", slowString("debug3"));
stopWatch.stop();



@Log4j2
public class LoggingController {
...
log.debug("debug4:{}", ()->slowString("debug4"));
}

    测试如图所示：
    image.pngimage.png
    直接拼接字符串，占位符都会输出日志，事先判断日志级别或通过 lambda 表达式（Log4j2 日志 API）不会输出日志，减少性能影响。

    日志配置

    • 日志需要写入磁盘上的日志文件中，所以适当的使用滚动日志并且定时清除旧文件
    • 有的时候日志需要保留一点时间，方便排查问题时追溯。
    <configuration debug="false" scan="false">
  <springProperty scop="context" name="spring.application.name" source="spring.application.name" defaultValue=""/>
  <property name="log.path" value="logs/${spring.application.name}"/>
  <!-- 彩色日志格式 -->
  <property name="CONSOLE_LOG_PATTERN"
    value="${CONSOLE_LOG_PATTERN:-%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
  <!-- 彩色日志依赖的渲染类 -->
  <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter"/>
  <conversionRule conversionWord="wex"
    converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter"/>
  <conversionRule conversionWord="wEx"
    converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter"/>
  <!-- Console log output -->
  <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>${CONSOLE_LOG_PATTERN}</pattern>
    </encoder>
  </appender>

  <!-- Log file debug output -->
  <appender name="debug" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${log.path}/debug.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>${log.path}/%d{yyyy-MM, aux}/debug.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
      <maxFileSize>50MB</maxFileSize>
      <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
      <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
    </encoder>
  </appender>

  <!-- Log file error output -->
  <appender name="error" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${log.path}/error.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>${log.path}/%d{yyyy-MM}/error.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
      <maxFileSize>50MB</maxFileSize>
      <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
      <pattern>%date [%thread] %-5level [%logger{50}] %file:%line - %msg%n</pattern>
    </encoder>
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
      <level>ERROR</level>
    </filter>
  </appender>

  <!-- Level: FATAL 0  ERROR 3  WARN 4  INFO 6  DEBUG 7 -->
  <root level="INFO">
    <appender-ref ref="console"/>
    <appender-ref ref="debug"/>
    <appender-ref ref="error"/>
  </root>
</configuration>

    总结

    参考链接

    13 | 日志：日志记录真没你想象的那么简单
    51 | 适配器模式：代理、适配器、桥接、装饰，这四个模式有何区别？
    Java日志系统历史从入门到崩溃
    这份Java日志格式规范，拿走不谢！

    后端java
    Ekko
    2 声望0 粉丝
    « 上一篇
    接口幂等性设计
    下一篇 »
    Java并发编程-理解线程

    引用和评论

    推荐阅读
    头像
    数据分片-库内分表实践

    Ekko阅读 775

    头像
    在Java程序中监听mysql的binlog

    huan1993赞 11阅读 2k

    头像
    Jerry和您聊聊Chrome开发者工具

    注销赞 9阅读 4.5k评论 3

    头像
    Bitmap 和 布隆过滤器傻傻分不清？你这不应该啊

    程序员小富赞 8阅读 1.7k评论 1

    头像
    Just for fun——迅速写完快速排序

    ufdf赞 3阅读 2.6k

    头像
    Spring 实现 3 种异步流式接口，干掉接口超时烦恼

    程序员小富赞 5阅读 1.7k

    头像
    💢线上高延迟请求排查

    crossoverJie赞 6阅读 977评论 5

    0 条评论
    得票最新