生产和测试环境中需要日志来记录、跟踪和分析系统的运行状态,但是有太多带有杂讯的日志又会影响跟踪,甚至可能对系统的运行带来影响。

我们需要怎样的日志

  1. 可以被记录、跟踪、分析和归档
  2. 了解系统运行的必要信息,方便排查和分析
  3. 最小化对系统性能的影响

Java日志实践

Log4j等日志框架默认info级别以上,不建议在生产环境打开debug级别的日志

等级

适用范围

Fatal

严重的,造成服务中断的错误

Error

其他错误运行期错误,非业务错误

Warn

警告信息,如程序调用了一个旧版本的接口,可选参数不合法,非业务预期的状态但仍可继续处理等

Info

有意义的内容,重要业务方法调用开始及结束

Debug

调试信息,变量在方法过程中的变化等信息

Trace

更详细的跟踪信息

内容
方法/事件的调用和结束,可附带重要输入/输出信息以及耗时等方法过程中某些较为重要的其他方法(诸如Client)的调用的输入/输出信息及耗时等重要变量的变化
什么不应该输出
敏感重要的信息,例如用户隐私信息,token以及sessionkey等信息冗余信息,例如对整个对象toString输出,或者json字符串格式化后输出不合适的Threshold级别,例如「权限鉴定」失败抛出error级别的信息由于现阶段没有合适的Profiler的应用,日志输出可能需要很大程度上承担性能分析的作用,以下为示例

字段

行为描述

行为级别

描述(TRACE情况下打印)

参数(建议入口打印)

耗时

示例

queryItemSearch

INVOKE/TRACE/END

callClientXXXX

{“KeyA”:”ValueA”}

20ms

以上参数均为可选,但是建议同一模块或子模块下使用同一规则,以方便统计分析归档等。

logger.info("[doSomething][INVOKE]Param:.....");
// ...
logger.info("[doSomething][TRACE ][queryDB1]cost:100ms");
// ..
logger.info("[doSomething][END   ]cost:200ms");

Log4j的配置

以下为Log4j的示例
log4j.properties
log4j.rootLogger=INFO,logFile
log4j.logger.com.danga.ttserver=ERROR
log4j.additivity.com.danga.ttserver=false

logFile appender
log4j.appender.logFile.Threshold=INFO
log4j.appender.logFile=org.apache.log4j.DailyRollingFileAppender
log4j.appender.logFile.File=/data/logs/(tomcat|jboss|timer)/${service}/${module-app(-subAction)}.log
log4j.appender.logFile.DatePattern='.'yyyyMMdd
log4j.appender.logFile.layout=org.apache.log4j.PatternLayout
log4j.appender.logFile.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss,SSS}[%-5p][%t](%c{3}:%L):%m%n
log4j.appender.logFile.encoding=UTF-8
在高并发情况下,当有大量请求至同一容器,我们很难通过日志简单的还原一次业务请求的明细过程。

我们可以藉由Log4j 提供的 MDC( mapped diagnostic context) 来解决这个问题。MDC (Apache Log4j 1.2.17 API)

// 下述代码嵌入请求入口(Filter、拦截器等)

MDC.put("TRACE_ID", "cx4jbc0jzovd");  // 随机生成追踪用的 ID修改 Log4j 的对应 pattern
log4j.appender.logFile.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss,SSS}[%-5p][%t](%c{3}:%L):%m%n
log4j.appender.logFile.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss,SSS}[%-5p][%t][%X{TRACE_ID}](%c{3}:%L):%m%n