1 概述
logback.xml配置文件的详细配置,很多地方都说得比较细,本文主要从几个重点来看一下原理,了解原理能够帮助确定哪些应该配置,以及如何配置。
logback.xml是为打印日志服务的,打印的内容一般打印到控制台(Console)和文件(file)里,在生产环境中主要是打印到文件里,然后用扫描工具汇总到某个地方方便查询(如ELK)。打印的内容要符合一定的格式,提供足够的信息,方便进行日志查询和分析;如果所有日志都打印到一个文件里,就有可能文件过大而难以查看,还可能大到一个磁盘装不下,也很难把早期的日志删除掉仅保留一定期限内的日志,所以需要对日志文件进行拆分,每个文件确定在一定大小之内,并控制总体仅保留一定量的日志,避免日志总量过多把磁盘占满了宕机等。日志配置文件也不是一成不变的,当修改了配置文件,希望能够不需要重启Java进程而能够生效,比如修改日志级别。
2 原理
2.1 打印内容的格式
<appender name="console" class="ch.qos.logback.core.ConsoleAppender"><encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"><Pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %highlight(%-5level) [%thread] %logger{50} - %msg%n</Pattern><charset>UTF-8</charset></encoder>
</appender>
上面就是一个<appender>的配置,里面的<Pattern>就是日志内容的格式,还可以设置高亮颜色。如果要详细看logback支持的格式,那么可以参考官方文档:https://logback.qos.ch/manual/layouts.html
如果想了解原理也容易,上面就指明了对应的类ch.qos.logback.classic.encoder.PatternLayoutEncoder,这也代表着甚至可以通过它来自定义。
// 当加载logback.xml文件时,解析到<encoder>节点的时候,会调PatternLayoutEncoder.start()
// 源码位置:ch.qos.logback.classic.encoder.PatternLayoutEncoder
public class PatternLayoutEncoder extends PatternLayoutEncoderBase<ILoggingEvent> {public PatternLayoutEncoder() {}public void start() {// 1. 初始化PatternLayout,里面会初始化一些ConverterPatternLayout patternLayout = new PatternLayout();patternLayout.setContext(this.context);patternLayout.setPattern(this.getPattern());patternLayout.setOutputPatternAsHeader(this.outputPatternAsHeader);patternLayout.start();this.layout = patternLayout;super.start();}
}// 源码位置:ch.qos.logback.classic.PatternLayout
// 2. 静态代码块初始化converter,它们决定了<Pattern>节点里能够配置的变量,用%来指示变量,比如%d表示时间
public static final Map<String, String> DEFAULT_CONVERTER_MAP = new HashMap<String, String>();
static {DEFAULT_CONVERTER_MAP.putAll(Parser.DEFAULT_COMPOSITE_CONVERTER_MAP);DEFAULT_CONVERTER_MAP.put("d", DateConverter.class.getName());DEFAULT_CONVERTER_MAP.put("date", DateConverter.class.getName());DEFAULT_CONVERTER_MAP.put("r", RelativeTimeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("relative", RelativeTimeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("level", LevelConverter.class.getName());DEFAULT_CONVERTER_MAP.put("le", LevelConverter.class.getName());DEFAULT_CONVERTER_MAP.put("p", LevelConverter.class.getName());DEFAULT_CONVERTER_MAP.put("t", ThreadConverter.class.getName());DEFAULT_CONVERTER_MAP.put("thread", ThreadConverter.class.getName());DEFAULT_CONVERTER_MAP.put("lo", LoggerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("logger", LoggerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("c", LoggerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("m", MessageConverter.class.getName());DEFAULT_CONVERTER_MAP.put("msg", MessageConverter.class.getName());DEFAULT_CONVERTER_MAP.put("message", MessageConverter.class.getName());DEFAULT_CONVERTER_MAP.put("C", ClassOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("class", ClassOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("M", MethodOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("method", MethodOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("L", LineOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("line", LineOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("F", FileOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("file", FileOfCallerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("X", MDCConverter.class.getName());DEFAULT_CONVERTER_MAP.put("mdc", MDCConverter.class.getName());DEFAULT_CONVERTER_MAP.put("ex", ThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("exception", ThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("rEx", RootCauseFirstThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("rootException", RootCauseFirstThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("throwable", ThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("xEx", ExtendedThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("xException", ExtendedThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("xThrowable", ExtendedThrowableProxyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("nopex", NopThrowableInformationConverter.class.getName());DEFAULT_CONVERTER_MAP.put("nopexception", NopThrowableInformationConverter.class.getName());DEFAULT_CONVERTER_MAP.put("cn", ContextNameConverter.class.getName());DEFAULT_CONVERTER_MAP.put("contextName", ContextNameConverter.class.getName());DEFAULT_CONVERTER_MAP.put("caller", CallerDataConverter.class.getName());DEFAULT_CONVERTER_MAP.put("marker", MarkerConverter.class.getName());DEFAULT_CONVERTER_MAP.put("property", PropertyConverter.class.getName());DEFAULT_CONVERTER_MAP.put("n", LineSeparatorConverter.class.getName());DEFAULT_CONVERTER_MAP.put("black", BlackCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("red", RedCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("green", GreenCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("yellow", YellowCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("blue", BlueCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("magenta", MagentaCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("cyan", CyanCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("white", WhiteCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("gray", GrayCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("boldRed", BoldRedCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("boldGreen", BoldGreenCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("boldYellow", BoldYellowCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("boldBlue", BoldBlueCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("boldMagenta", BoldMagentaCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("boldCyan", BoldCyanCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("boldWhite", BoldWhiteCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("highlight", HighlightingCompositeConverter.class.getName());DEFAULT_CONVERTER_MAP.put("lsn", LocalSequenceNumberConverter.class.getName());DEFAULT_CONVERTER_MAP.put("prefix", PrefixCompositeConverter.class.getName());
}
public Map<String, String> getDefaultConverterMap() {return DEFAULT_CONVERTER_MAP;
}// 回到PatternLayoutEncoder,继续初始化
// 源码位置:ch.qos.logback.classic.encoder.PatternLayoutEncoder
public class PatternLayoutEncoder extends PatternLayoutEncoderBase<ILoggingEvent> {public PatternLayoutEncoder() {}public void start() {// 1. 初始化PatternLayout,里面会初始化一些Converter,细节看1.1PatternLayout patternLayout = new PatternLayout();patternLayout.setContext(this.context);patternLayout.setPattern(this.getPattern());patternLayout.setOutputPatternAsHeader(this.outputPatternAsHeader);// 3. 开始解析pattern,实际调用的是PatternLayout父类PatternLayoutBase的start()方法patternLayout.start();this.layout = patternLayout;super.start();}
}// 继承关系:PatternLayoutEncoder < PatternLayoutBase
// 源码位置:ch.qos.logback.core.pattern.PatternLayoutBase
public void start() {if (pattern == null || pattern.length() == 0) {addError("Empty or null pattern.");return;}try {Parser<E> p = new Parser<E>(pattern);if (getContext() != null) {p.setContext(getContext());}Node t = p.parse();// 4. 解析pattern,getEffectiveConverterMap()里面调了步骤2的getDefaultConverterMap()得到了初始化的converterthis.head = p.compile(t, getEffectiveConverterMap());if (postCompileProcessor != null) {postCompileProcessor.process(context, head);}ConverterUtil.setContextForConverters(getContext(), head);ConverterUtil.startConverters(this.head);super.start();} catch (ScanException sce) {StatusManager sm = getContext().getStatusManager();sm.add(new ErrorStatus("Failed to parse pattern \"" + getPattern() + "\".", this, sce));}
}// 源码位置:ch.qos.logback.core.pattern.parser.Parser
public Converter<E> compile(final Node top, Map converterMap) {Compiler<E> compiler = new Compiler<E>(top, converterMap);compiler.setContext(context);// compiler.setStatusManager(statusManager);// 5. 实际解析patternreturn compiler.compile();
}// 源码位置:ch.qos.logback.core.pattern.parser.Compiler
// 实际解析pattern,整个pattern已经被分成一个个Node,Node的格式如下:
// 以pattern=%d{yyyy-MM-dd HH:mm:ss.SSS}a b c%highlight(%-5level) [%thread] %logger{50} - %msg%n 为例:
// 1) 以%作为开始字符、以})和空格等作为结束字符作为一段进行分割成多段,开始字符和结束字符之间的字符作为一个Keyword Node,段之间如果还有非空字符则作为Literal Node;
// 上例中%d{yyyy-MM-dd HH:mm:ss.SSS}作为Keyword Node,a b c为Literal Node;
// 2) 如果只有一个关键字的则是Simple Keyword Node,如%d{yyyy-MM-dd HH:mm:ss.SSS}
// 如果有多个关键字嵌套的则是Composite Keyword Node,如%highlight(%-5levelx)
// 3) %后面的关键字要能够从converterMap取到,通过它能够从里面找到对应的Converter(参考步骤2),如果找不到就报错了;
// 4) 关键字前面的是format信息,后面的是option信息,
// 比如:%d{yyyy-MM-dd HH:mm:ss.SSS}中,yyyy-MM-dd HH:mm:ss.SSS是option信息,无format信息;
// 比如:%-5level中,5是format信息,表示最短5字符,无option信息;
// 5) 嵌套结构用childNode表示,如%highlight(%-5level)中,%-5level是一个childNode,格式和Node一样;
// 6) 每个Node都有个next,指向下一个节点,即链式结构,通过一层层的next可以遍历整条链;
// 下面最终都是把Converter放到Node里,实际上pattern里的信息都已经分解到Converter里了,打印日志的时候可以直接使用
Converter<E> compile() {head = tail = null;// 当n = n.next为null时,链条结束for (Node n = top; n != null; n = n.next) {switch (n.type) {case Node.LITERAL: // Literal NodeaddToList(new LiteralConverter<E>((String) n.getValue()));break;case Node.COMPOSITE_KEYWORD: // Composite Keyword NodeCompositeNode cn = (CompositeNode) n;// 根据keyword找到Converter,并进行实例化CompositeConverter<E> compositeConverter = createCompositeConverter(cn);if (compositeConverter == null) {addError("Failed to create converter for [%" + cn.getValue() + "] keyword");addToList(new LiteralConverter<E>("%PARSER_ERROR[" + cn.getValue() + "]"));break;}// 把信息设置到Converter里compositeConverter.setFormattingInfo(cn.getFormatInfo());compositeConverter.setOptionList(cn.getOptions());// 再处理childNode的ConverterCompiler<E> childCompiler = new Compiler<E>(cn.getChildNode(), converterMap);childCompiler.setContext(context);Converter<E> childConverter = childCompiler.compile();compositeConverter.setChildConverter(childConverter); // 记录childNode的ConverteraddToList(compositeConverter); // 记录当前node的Converterbreak;case Node.SIMPLE_KEYWORD: // Simple Keyword NodeSimpleKeywordNode kn = (SimpleKeywordNode) n;// 根据keyword找到Converter,并进行实例化,主要是Convert的具体类不一样,所以需要多写一个DynamicConverter<E> dynaConverter = createConverter(kn);if (dynaConverter != null) {// 把信息设置到Converter里dynaConverter.setFormattingInfo(kn.getFormatInfo());dynaConverter.setOptionList(kn.getOptions());addToList(dynaConverter); // 记录当前node的Converter} else {// 没有对应的Converter则报错Converter<E> errConveter = new LiteralConverter<E>("%PARSER_ERROR[" + kn.getValue() + "]");addStatus(new ErrorStatus("[" + kn.getValue() + "] is not a valid conversion word", this));addToList(errConveter); // 记录当前node的Converter}}}return head;
}
CompositeConverter<E> createCompositeConverter(CompositeNode cn) {String keyword = (String) cn.getValue();// 只是从Map里取到Converter的类名,然后实例化String converterClassStr = (String) converterMap.get(keyword);if (converterClassStr != null) {try {// 实例化converter对象return (CompositeConverter) OptionHelper.instantiateByClassName(converterClassStr, CompositeConverter.class, context);} catch (Exception e) {addError("Failed to instantiate converter class [" + converterClassStr + "] as a composite converter for keyword [" + keyword + "]", e);return null;}} else {addError("There is no conversion class registered for composite conversion word [" + keyword + "]");return null;}
}
DynamicConverter<E> createConverter(SimpleKeywordNode kn) {String keyword = (String) kn.getValue();// 只是从Map里取到Converter的类名,然后实例化String converterClassStr = (String) converterMap.get(keyword);if (converterClassStr != null) {try {return (DynamicConverter) OptionHelper.instantiateByClassName(converterClassStr, DynamicConverter.class, context);} catch (Exception e) {addError("Failed to instantiate converter class [" + converterClassStr + "] for keyword [" + keyword + "]", e);return null;}} else {addError("There is no conversion class registered for conversion word [" + keyword + "]");return null;}
}
3 架构一小步
3.1 pattern选择
- 日志的主要目的是为了定位问题,所以应该选择一些对定位问题比较有帮助的。从日志看出问题后,最好是能够定位到代码的位置,也就是哪个类的哪个方法,甚至是哪一行代码。
- 打印日志不能影响业务的正常运行,比如打印日志不能消耗掉很多性能。
关键字 | 说明 | 备注 |
%d{yyyy-MM-dd HH:mm:ss.SSS} | 打印日志的时间,要到毫秒 | |
%-5level | 日志级别,主要有TRACE、DEBUG、INFO、WARN、ERROR,最多5个字符,为了对齐则定为最少5个字符 | |
%thread | 线程标识,用于表示代码执行在哪个线程里 | |
%logger{50} | logger名称,等同于节点的name属性。一般获取logger的时候使用的是含包名的类名,所以logger的名称实际上指的是包名+类名,可能很长,需要限制长度,比如50字符。也可以使用%class{50}来代替。 | 带包名的类名一般比较长,所以它和%class一般只用一个。用logger的好处是能兼容类名和一些特殊的logger名。 |
%method | 方法名,打印代码所在的方法 | |
%line | 行号,打印代码的行号位置 | 这个配置对定位问题是比较有用的,但其比较耗费性能,一般不配置,除非性能不是问题。 |
%msg | 日志内容 | 最好在一个方法内能够唯一指示是哪个日志内容 |
%n | 换行符 |
Pattern=%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread] %logger{50}#%method - %msg%n202x-xx-xx xx:xx:xx.xxx DEBUG [http-nio-8080-exec-2] com.qqian.stepfmk.srvpro.hello.HelloController#say - Access saying hello, message=zhangsan
202x-xx-xx xx:xx:xx.xxx INFO [http-nio-8080-exec-2] com.qqian.stepfmk.srvpro.hello.HelloController#say - Access saying hello, message=zhangsan
202x-xx-xx xx:xx:xx.xxx WARN [http-nio-8080-exec-2] com.qqian.stepfmk.srvpro.hello.HelloController#say - Access saying hello, message=zhangsan
202x-xx-xx xx:xx:xx.xxx ERROR [http-nio-8080-exec-2] com.qqian.stepfmk.srvpro.hello.HelloController#say - Access saying hello, message=zhangsan
3.2 日志内容规范
- 日志内容必要用一句简短的话说明日志出现的结果,这句话最好唯一。
- 强调结果是为了帮忙定位问题,而不是说明代码做了啥。代码做了啥是可以通过看代码了解到的。
- 实际日志一般打印不了行号,这句话若能够唯一,就能够快速定位到具体的代码,相当于有了代码行号。
- 比如判断一个中间变量为不合法l时打印日志,这句话应该说明该变量哪里不合法。通过这个说明就大致能够判断问题的所在,即使不能直接判断问题,也应该尽可能提供最多的信息量。
- 日志内容要包含上下文,没有上下文的日志不要打印。
- 上下文一般是指出现日志所指示结果的一些相关变量。
- 这些变量可能是从前面传过来的,也可能是中间产生的。
- 打印哪些变量衡量的标准是:当出现日志内容指示的结果时,需要哪些变量才能确定问题。比如一个从数据库读取数据的结果为null时,需要知道组装查询SQL的重点变量。
- 对于异常信息必须打印堆栈。
- 使用logger.error("xxxx", e)打印异常时,注意不要给e提供占位符,有占位符只打印了e.getMessage(),没有打印堆栈。
- 有堆栈才能详细看到是哪段代码发生异常,也就是帮助定位到具体的代码。