自定义Logback输出格式：掌握JSON日志的奥秘

自定义Logback输出格式：掌握JSON日志的奥秘

  1. 我的工具箱 🪜
  2. 2015.07.26
  3. 8 min read

说到 log4j, 基本人人都知道, 但是 logback, 估计用的人不多, 其实这两个都是 sl4j 的实现, 而且是一个作者写的.

logback 比 log4j 更加好用, 而且效率更高.

如何配置 logback.

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.1.3</version>
</dependency>

配置文件: logback.xml

<?xml version="1.0" encoding="UTF-8" ?>
<configuration scan="true" scanPeriod="10 minutes">
 <property name="LOG_HOME" value="d:/logs"/>

 <appender name="stdot" class="ch.qos.logback.core.ConsoleAppender">
  <layout class="ch.qos.logback.classic.PatternLayout">
   <pattern>%d{yyyy-MM-dd HH:mm:ss} [%p][%c][%M][%L]-> %m%n</pattern>
  </layout>
 </appender>
 <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
  <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
   <FileNamePattern>${LOG_HOME}/log.%d{yyyy-MM-dd}(%i).log</FileNamePattern>
   <cleanHistoryOnStart>true</cleanHistoryOnStart>
   <TimeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
    <MaxFileSize>10MB</MaxFileSize>
   </TimeBasedFileNamingAndTriggeringPolicy>
  </rollingPolicy>
  <encoder>
    <charset>utf-8</charset>
    <pattern>%d{yyyy-MM-dd HH:mm:ss} [%p][%c][%M][%L]-> %m%n</pattern>
  </encoder>
  <append>false</append>
  <prudent>false</prudent>
 </appender>

 <logger name="org.mortbay.log" additivity="false"  level="ERROR">
       <appender-ref ref="stdot" />
 </logger>

 <logger name="org.mybatis.spring" additivity="false"  level="ERROR">
       <appender-ref ref="stdot" />
 </logger>

 <root level="debug">
  <appender-ref ref="stdot" />
  <appender-ref ref="file" />
 </root>

</configuration>

将这个文件放到资源目录根目录下, 服务器启动时, logback 会根据 logback 这个名称自己去匹配加载

这里如果要输出项目中的 SQL 很简单, 只需要将日志级别改成 debug 就可以了（mybatis 是这样的, 其他的没试过）

今天主要说的是日志格式

%d{yyyy-MM-dd HH:mm:ss} [%p][%c][%M][%L]-> %m%n

这里就是配置格式的, 以下是各个参数的说明

参数说明
%m输出代码中指定的消息
%p输出优先级, 即 DEBUG, INFO, WARN, ERROR, FATAL
%r输出自应用启动到输出该 log 信息耗费的毫秒数
%c输出所属的类目, 通常就是所在类的全名
%t输出产生该日志事件的线程名
%n输出一个回车换行符, Windows 平台为 \r\n, Unix 平台为 \n
%d输出日志时间点的日期或时间, 默认格式为 ISO8601, 也可以在其后指定格式, 比如: %d{yyy MMM dd HH:mm:ss,SSS}, 输出类似: 2002 年 10 月 18 日 22: 10: 28, 921
%l输出日志事件的发生位置, 包括类目名、发生的线程, 以及在代码中的行数. 举例: Testlog4.main(TestLog4.java:10)

这个时候, 日志就会输出 时间, 日志优先级, 类名, 方法名, 行数, 日志内容

基本就是这样的了

2016-09-02 14:45:53 [DEBUG][com.ulewo.mapper.SignInMapper.selectCount][debug][132]-> ==>  Preparing: select count(1) from ulewo_sign_in WHERE sign_date = DATE_FORMAT(?,'%Y-%m-%d')
2016-09-02 14:45:53 [DEBUG][com.ulewo.mapper.SignInMapper.selectCount][debug][132]-> ==> Parameters: 2016-09-02 14:45:53.098(Timestamp)
2016-09-02 14:45:53 [DEBUG][com.ulewo.mapper.SignInMapper.selectCount][debug][132]-> <==      Total: 1

这里输出了 SQL.

为什么要讲输出格式, 本来这样输出挺好的呀, 是的, 现在在我们的生产环境中, 总共有 16 台服务器, 有时候查问题, 要一台台的查, 因为不知道请求到底是大到那个服务器上, 这样查问题非常的痛苦, 于是项目引入了 graylog 一个日志收集工具, 可以将各个服务器的日志收集到一起, 这样查问题就方便多了. 但是 graylog 要求日志必须是 json 格式的, 那么按照我上面格式就无法使用了, 所以要修改日志输出格式.

查了一番资料发现, 只要重写 ClassicConverter 和 PatternLayout 这两个类就可以了

重新 Converter 类

public class NetbarLogerConvert extends ClassicConverter {

 long lastTimestamp = -1;
 String timestampStrCache = null;
 SimpleDateFormat simpleFormat = null;

 String businessName = null;

 static String hostName;
 static String localIp;

 static {
  InetAddress ia = null;
  try {
   ia = ia.getLocalHost();
   hostName = ia.getHostName();
   localIp = ia.getHostAddress();
  } catch (Exception e) {
   // TODO Auto-generated catch block
   e.printStackTrace();
  }
 }

 @Override
 public String convert(ILoggingEvent le) {
  LogObject log = new LogObject();
  log.setBusiness(businessName);
  log.setIp(localIp);
  log.setHostName(hostName);
  log.setTime(getTime(le));
  log.setLeave(le.getLevel().toString());
  log.setClassName(getFullyQualifiedName(le));
  log.setMethodName(getMethodName(le));
  log.setLine(getLineNumber(le));
  log.setMessage(le.getFormattedMessage());
  return JacksonUtil.writJson(log);
 }

 public void start() {
  businessName = getFirstOption();
  businessName = businessName == null ? "未设置产品线" : businessName;
  String datePattern = DateStyle.YYYY_MM_DD_HH_MM_SS.getValue();
  try {
   simpleFormat = new SimpleDateFormat(datePattern);
   // maximumCacheValidity =
   // CachedDateFormat.getMaximumCacheValidity(pattern);
  } catch (IllegalArgumentException e) {
   addWarn("Could not instantiate SimpleDateFormat with pattern " + datePattern, e);
   // default to the ISO8601 format
   simpleFormat = new SimpleDateFormat(CoreConstants.ISO8601_PATTERN);
  }
  List optionList = getOptionList();
  // if the option list contains a TZ option, then set it.
  if (optionList != null && optionList.size() > 1) {
   TimeZone tz = TimeZone.getTimeZone((String) optionList.get(1));
   simpleFormat.setTimeZone(tz);
  }
 }

 private String getTime(ILoggingEvent le) {
  long timestamp = le.getTimeStamp();
  synchronized (this) {
   // if called multiple times within the same millisecond
   // return cache value
   if (timestamp == lastTimestamp) {
    return timestampStrCache;
   } else {
    lastTimestamp = timestamp;
    // SimpleDateFormat is not thread safe.
    // See also http://jira.qos.ch/browse/LBCLASSIC-36
    timestampStrCache = simpleFormat.format(new Date(timestamp));
    return timestampStrCache;
   }
  }
 }

 private String getFullyQualifiedName(ILoggingEvent le) {

  StackTraceElement[] cda = le.getCallerData();
  if (cda != null && cda.length > 0) {
   return cda[0].getClassName();
  } else {
   return CallerData.NA;
  }
 }

 private String getLineNumber(ILoggingEvent le) {
  StackTraceElement[] cda = le.getCallerData();
  if (cda != null && cda.length > 0) {
   return Integer.toString(cda[0].getLineNumber());
  } else {
   return CallerData.NA;
  }
 }

 private String getMethodName(ILoggingEvent le) {
  StackTraceElement[] cda = le.getCallerData();
  if (cda != null && cda.length > 0) {
   return cda[0].getMethodName();
  } else {
   return CallerData.NA;
  }
 }

 public class LogObject {
  /**
   * 产品线
   */
  private String business;
  /**
   * 主机名
   */
  private String hostName;
  /**
   * IP
   */
  private String ip;
  /**
   * 时间
   */
  private String time;
  /**
   * 日志级别
   */
  private String leave;
  /**
   * 类名
   */
  private String className;
  /**
   * 方法名
   */
  private String methodName;
  /**
   * 行数
   */
  private String line;
  /**
   * 日志内容
   */
  private String message;

  public String getTime() {
   return time;
  }

  public void setTime(String time) {
   this.time = time;
  }

  public String getLeave() {
   return leave;
  }

  public void setLeave(String leave) {
   this.leave = leave;
  }

  public String getClassName() {
   return className;
  }

  public void setClassName(String className) {
   this.className = className;
  }

  public String getMethodName() {
   return methodName;
  }

  public void setMethodName(String methodName) {
   this.methodName = methodName;
  }

  public String getLine() {
   return line;
  }

  public void setLine(String line) {
   this.line = line;
  }

  public String getMessage() {
   return message;
  }

  public void setMessage(String message) {
   this.message = message;
  }

  public String getBusiness() {
   return business;
  }

  public void setBusiness(String business) {
   this.business = business;
  }

  public String getIp() {
   return ip;
  }

  public void setIp(String ip) {
   this.ip = ip;
  }

  public String getHostName() {
   return hostName;
  }

  public void setHostName(String hostName) {
   this.hostName = hostName;
  }

 }
}

重写 layout 类

public class NetbarLoggerPatternLayout extends PatternLayout {
 static {
  defaultConverterMap.put("netbarLoggerPattern", NetbarLogerConvert.class.getName());
 }
}

这里如何获取 方法名, 行数, 甚至还有其他的一些信息可以参考 logback

这个类:

public class PatternLayout extends PatternLayoutBase<ILoggingEvent> {

  public static final Map<String, String> defaultConverterMap = new HashMap<String, String>();

  static {

    defaultConverterMap.put("d", DateConverter.class.getName());
    defaultConverterMap.put("date", DateConverter.class.getName());

    defaultConverterMap.put("r", RelativeTimeConverter.class.getName());
    defaultConverterMap.put("relative", RelativeTimeConverter.class.getName());

    defaultConverterMap.put("level", LevelConverter.class.getName());
    defaultConverterMap.put("le", LevelConverter.class.getName());
    defaultConverterMap.put("p", LevelConverter.class.getName());

    defaultConverterMap.put("t", ThreadConverter.class.getName());
    defaultConverterMap.put("thread", ThreadConverter.class.getName());

    defaultConverterMap.put("lo", LoggerConverter.class.getName());
    defaultConverterMap.put("logger", LoggerConverter.class.getName());
    defaultConverterMap.put("c", LoggerConverter.class.getName());

    defaultConverterMap.put("m", MessageConverter.class.getName());
    defaultConverterMap.put("msg", MessageConverter.class.getName());
    defaultConverterMap.put("message", MessageConverter.class.getName());

    defaultConverterMap.put("C", ClassOfCallerConverter.class.getName());
    defaultConverterMap.put("class", ClassOfCallerConverter.class.getName());

    defaultConverterMap.put("M", MethodOfCallerConverter.class.getName());
    defaultConverterMap.put("method", MethodOfCallerConverter.class.getName());

    defaultConverterMap.put("L", LineOfCallerConverter.class.getName());
    defaultConverterMap.put("line", LineOfCallerConverter.class.getName());

    defaultConverterMap.put("F", FileOfCallerConverter.class.getName());
    defaultConverterMap.put("file", FileOfCallerConverter.class.getName());

    defaultConverterMap.put("X", MDCConverter.class.getName());
    defaultConverterMap.put("mdc", MDCConverter.class.getName());

    defaultConverterMap.put("ex", ThrowableProxyConverter.class.getName());
    defaultConverterMap.put("exception", ThrowableProxyConverter.class
        .getName());
    defaultConverterMap.put("throwable", ThrowableProxyConverter.class
        .getName());

    defaultConverterMap.put("xEx", ExtendedThrowableProxyConverter.class.getName());
    defaultConverterMap.put("xException", ExtendedThrowableProxyConverter.class
        .getName());
    defaultConverterMap.put("xThrowable", ExtendedThrowableProxyConverter.class
        .getName());

    defaultConverterMap.put("nopex", NopThrowableInformationConverter.class
        .getName());
    defaultConverterMap.put("nopexception",
        NopThrowableInformationConverter.class.getName());

    defaultConverterMap.put("cn", ContextNameAction.class.getName());
    defaultConverterMap.put("contextName", ContextNameConverter.class.getName());

    defaultConverterMap.put("caller", CallerDataConverter.class.getName());

    defaultConverterMap.put("marker", MarkerConverter.class.getName());

    defaultConverterMap.put("property", PropertyConverter.class.getName());


    defaultConverterMap.put("n", LineSeparatorConverter.class.getName());
  }

  public PatternLayout() {
    this.postCompileProcessor = new EnsureExceptionHandling();
  }

  public Map<String, String> getDefaultConverterMap() {
    return defaultConverterMap;
  }

  public String doLayout(ILoggingEvent event) {
    if (!isStarted()) {
      return CoreConstants.EMPTY_STRING;
    }
    return writeLoopOnConverters(event);
  }

}

这里有各个参数 convert 的实现, 直接拷贝过来就可以了.

然后 logback 这里的配置修改下

<appender name="stdot" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="com.stnts.netbar.logger.NetbarLoggerPatternLayout">
    <pattern>%netbarLoggerPattern{XXX 系统}</pattern>
    </layout>
</appender>

上面 layout 的 class 指定为你重写的 class,pattern 中用你自己定义的 pattern 名后面大括号是定义产品线的

这个时候日志就是这样输出的:

{"message":"[微信公众帐号][定时刷新 AccessToken 的定时器] redis 中获取的 accessToken 的过期时间: 7200 秒","methodName":"refresh","className":"xxx.xxx.xxx.class","hostName":"pcname","time":"2016-09-02 14:40:00","leave":"INFO","line":"50","business":"xxxx 系统","ip":"192.168.32.115"}

就是一个完整的 json 了.

当然你觉得这样的日志格式, 你看起来还不舒服, 可以自己去定义了.

Java 学习笔记