Java日志框架
来源：互联网 发布：kbar软件下载 编辑：程序博客网 时间：2024/05/02 04:42
1、概述
目前java应用日志收集都是采用日志框架(slf4j、apache commons logging)+日志系统（log4j、log4j2、LogBack、JUL等）的方式。而针对在分布式环境需要实时分析统计的日志，一般采用apache flume、facebook scribe等分布式日志收集系统。
日志框架：提供日志调用的接口，实际的日志输出委托给日志系统实现。
- JCL(Jakarta Commons Logging)：比较流行的日志框架，很多框架都依赖JCL，例如Spring等。
- SLF4j：提供新的API，初衷是配合Logback使用，但同时兼容Log4j。
日志系统：负责输出日志
- Log4j：经典的一种日志解决方案。内部把日志系统抽象封装成Logger 、appender 、pattern 等实现。我们可以通过配置文件轻松的实现日志系统的管理和多样化配置。
- Log4j2：Log4j的2.0版本，对Log4j进行了优化，比如支持参数API、支持异步appender、插件式架构等
- Logback：Log4j的替代产品，需要配合日志框架SLF4j使用
- JUL(java.util.logging)：JDK提供的日志系统，较混乱，不常用
目前我们的应用大部分都是使用了SLF4j作为门面，然后搭配log4j或者log4j2日志系统。
下面将介绍slf4j + Log4j2 日志组件的引入、以及配置和使用
2、Maven依赖
</pre><pre name="code" class="html"><dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>1.7.13</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-slf4j-impl</artifactId> <version>2.4.1</version> </dependency> <!--兼容log4j--> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-1.2-api</artifactId> <version>2.0</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-api</artifactId> <version>2.4.1</version> </dependency> <dependency> <groupId>org.apache.logging.log4j</groupId> <artifactId>log4j-core</artifactId> <version>2.4.1</version> </dependency> <!--log4j2 异步appender需要--> <dependency> <groupId>com.lmax</groupId> <artifactId>disruptor</artifactId> <version>3.2.0</version> </dependency>
3、配置
- Appenders：也被称为Handlers，负责将日志事件记录到目标位置。在将日志事件输出之前，Appenders使用Layouts来对事件进行格式化处理。
- Layouts：也被称为Formatters，它负责对日志事件中的数据进行转换和格式化。Layouts决定了数据在一条日志记录中的最终形式。
- Loggers：Logger负责捕捉事件并将其发送给合适的Appender。
当Logger记录一个事件时，它将事件转发给适当的Appender。然后Appender使用Layout来对日志记录进行格式化，并将其发送给控制台、文件或者其它目标位置。另外，Filters可以让你进一步指定一个Appender是否可以应用在一条特定的日志记录上。在日志配置中，Filters并不是必需的，但可以让你更灵活地控制日志消息的流动。
3.1 Appender
3.1.1 ConsoleAppender
ConsoleAppender是最常用的Appenders之一，它只是将日志消息显示到控制台上。许多日志框架都将其作为默认的Appender，并且在基本的配置中进行预配置。例如，在Log4j中ConsoleAppender的配置参数如下所示。
<!--这个输出控制台的配置--> <Console name="Console" target="SYSTEM_OUT"> <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）--> <ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/> <!--这个都知道是输出日志的格式--> <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/> </Console>3.1.2 FileAppender
FileAppenders将日志记录写入到文件中，它负责打开、关闭文件，向文件中追加日志记录，并对文件进行加锁，以免数据被破坏或者覆盖。
在Log4j中，如果想创建一个FileAppender，需要指定目标文件的名字，写入方式是追加还是覆盖，以及是否需要在写入日志时对文件进行加锁：
<File name="File" fileName="fileAppender.log" append="true" locking="true"> <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/> </File>3.1.3 RollingFileAppender
RollingFileAppender跟FileAppender的基本用法一样。但RollingFileAppender可以设置log文件的size（单位：KB/MB/GB）上限、数量上限，当log文件超过设置的size上限，会自动被压缩。RollingFileAppender可以理解为滚动输出日志，如果log4j 2记录的日志达到上限，旧的日志将被删除，腾出的空间用于记录新的日志。
<!--这个会打印出所有的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档--> <RollingFile name="RollingFile1" fileName="logs/log1.log" filePattern="logs/$${date:yyyy-MM}/log-%d{MM-dd-yyyy}-%i.log"> <PatternLayout pattern="%d{yyyy-MM-dd 'at' HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/> <SizeBasedTriggeringPolicy size="100MB"/> </RollingFile>3.1.5 其他appender
我们已经介绍了一些经常用到的Appenders，还有很多其它Appender。它们添加了新功能或者在其它的一些Appender基础上实现了新功能。例如，Log4j中的RollingFileAppender扩展了FileAppender，它可以在满足特定条件时自动创建新的日志文件；SMTPAppender会将日志内容以邮件的形式发送出去；FailoverAppender会在处理日志的过程中，如果一个或者多个Appender失败，自动切换到其他Appender上。
如果想了解其他可以参考：https://logging.apache.org/log4j/2.0/manual/appenders.html
3.2 Layouts
Layouts将日志记录的内容从一种数据形式转换成另外一种。日志框架为纯文本、HTML、syslog、XML、JSON、序列化以及其它日志提供了Layouts。
这里贴一篇文章简单介绍下我们常用的PatternLayout ：http://wiki.jikexueyuan.com/project/log4j/log4j-patternlayout.html
其他的layouts配置可以参考：https://logging.apache.org/log4j/2.0/manual/layouts.html
<PatternLayout pattern="%d{yyyy-MM-dd 'at' HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>3.3 Loggers
Logger负责捕捉事件并将其发送给合适的Appender，Logger之间是有继承关系的。总是存在一个rootLogger，即使没有显示配置也是存在的，并且默认输出级别为DEBUG，其它的logger都继承自这个rootLogger。
Log4J中的继承关系是通过名称可以看出来，如"A"、"A.B"、"A.B.C"，A.B继承A，A.B.C继承A.B，比较类似于包名。
<loggers> <logger name="com.sankuai" level="info" includeLocation="true" additivity="true"> <appender-ref ref="RollingFile2"/> <appender-ref ref="RollingFile1"/> </logger><logger name="com.sankuai.meituan" level="error" includeLocation="true" additivity="true"> <appender-ref ref="RollingFile2"/> <appender-ref ref="RollingFile1"/> </logger> <!--建立一个默认的root的logger--> <root level="error"> <appender-ref ref="Console"/> <appender-ref ref="RollingFile1"/> </root> </loggers>
additivity是 子Logger 是否继承 父Logger 的 输出源（appender） 的标志位。具体说，默认情况下 子Logger 会继承 父Logger 的appender，也就是说 子Logger 会在 父Logger 的appender里输出。若是additivity设为false，则 子Logger 只会在自己的appender里输出，而不会在 父Logger 的appender里输出。
3.4 日志级别
DEBUG ， INFO ，WARN ，ERROR四种，分别对应Logger类的四种方法
debug(Object message ) ;
info(Object message ) ;
warn(Object message ) ;
error(Object message ) ;
如果设置级别为INFO，则优先级大于等于INFO级别（如：INFO、WARN、ERROR）的日志信息将可以被输出,
小于该级别的如：DEBUG将不会被输出
4、Log4j2 AsyncLogger与AsyncAppender
先上图
第一张图可以看出Log4j2的asyncLogger的性能较使用asyncAppender和sync模式有非常大的提升，特别是线程越多的时候。
第二张图是将log4j2的异步日志机制和其他日志系统进行对比，log4j2的asyncLogger 性能也是很有优势。
这里主要涉及了两个概念AsyncLogger和AysncAppender，是支持异步的Logger和Appender，下面分别简要介绍下这两个概念。
4.1 AsyncAppender
AsyncAppender持有其他的配置了aysnc的appender引用列表(appender需要通过配置注册成异步的)，当其他的logger需要打日志的时候（logEvent事件），asyncAppender会接收logEvent，缓存到queue中，然后用单独的线程完成从queue中取logEvent打印到目的appender，这个逻辑比较简单，看下源码就能明白这个流程。ps. AsyncAppender是Log4j 和Log4j2 都有的，不是新东西，但从上面的性能对比上还是有一点点差异的，主要的原因是：（引用官方说法）Asynchronous Appenders already existed in Log4j 1.x, but have been enhanced to flush to disk at the end of a batch (when the queue is empty).
关于AsyncAppender能提高性能的场景，可以看下这个篇文章。 http://littcai.iteye.com/blog/316605
如何配置一个AsyncAppender：
<?xml version="1.0" encoding="UTF-8"?><Configuration status="warn" name="MyApp" packages=""> <Appenders> <File name="MyFile" fileName="logs/app.log"> <PatternLayout> <Pattern>%d %p %c{1.} [%t] %m%n</Pattern> </PatternLayout> </File> <Async name="Async"> <AppenderRef ref="MyFile"/> </Async> </Appenders> <Loggers> <Root level="error"> <AppenderRef ref="Async"/> </Root> </Loggers></Configuration>@Plugin(name = "Async", category = "Core", elementType = "appender", printObject = true)public final class AsyncAppender extends AbstractAppender { private static final long serialVersionUID = 1L; private static final int DEFAULT_QUEUE_SIZE = 128; private static final String SHUTDOWN = "Shutdown"; private static final AtomicLong THREAD_SEQUENCE = new AtomicLong(1); private static ThreadLocal<Boolean> isAppenderThread = new ThreadLocal<>(); private final BlockingQueue<Serializable> queue; private final int queueSize; private final boolean blocking; private final long shutdownTimeout; private final Configuration config; private final AppenderRef[] appenderRefs; private final String errorRef; private final boolean includeLocation; private AppenderControl errorAppender; private AsyncThread thread; private AsyncAppender(final String name, final Filter filter, final AppenderRef[] appenderRefs, final String errorRef, final int queueSize, final boolean blocking, final boolean ignoreExceptions, final long shutdownTimeout, final Configuration config, final boolean includeLocation) { super(name, filter, null, ignoreExceptions); this.queue = new ArrayBlockingQueue<>(queueSize); this.queueSize = queueSize; this.blocking = blocking; this.shutdownTimeout = shutdownTimeout; this.config = config; this.appenderRefs = appenderRefs; this.errorRef = errorRef; this.includeLocation = includeLocation; } @Override public void start() { final Map<String, Appender> map = config.getAppenders(); final List<AppenderControl> appenders = new ArrayList<>(); for (final AppenderRef appenderRef : appenderRefs) { final Appender appender = map.get(appenderRef.getRef()); if (appender != null) { appenders.add(new AppenderControl(appender, appenderRef.getLevel(), appenderRef.getFilter())); } else { LOGGER.error("No appender named {} was configured", appenderRef); } } if (errorRef != null) { final Appender appender = map.get(errorRef); if (appender != null) { errorAppender = new AppenderControl(appender, null, null); } else { LOGGER.error("Unable to set up error Appender. No appender named {} was configured", errorRef); } } if (appenders.size() > 0) { thread = new AsyncThread(appenders, queue); thread.setName("AsyncAppender-" + getName()); } else if (errorRef == null) { throw new ConfigurationException("No appenders are available for AsyncAppender " + getName()); } thread.start(); super.start(); } @Override public void stop() { super.stop(); LOGGER.trace("AsyncAppender stopping. Queue still has {} events.", queue.size()); thread.shutdown(); try { thread.join(shutdownTimeout); } catch (final InterruptedException ex) { LOGGER.warn("Interrupted while stopping AsyncAppender {}", getName()); } LOGGER.trace("AsyncAppender stopped. Queue has {} events.", queue.size()); } /** * Actual writing occurs here. * * @param logEvent The LogEvent. */ @Override public void append(LogEvent logEvent) { if (!isStarted()) { throw new IllegalStateException("AsyncAppender " + getName() + " is not active"); } if (!(logEvent instanceof Log4jLogEvent)) { if (!(logEvent instanceof RingBufferLogEvent)) { return; // only know how to Serialize Log4jLogEvents and RingBufferLogEvents } logEvent = ((RingBufferLogEvent) logEvent).createMemento(); } logEvent.getMessage().getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters final Log4jLogEvent coreEvent = (Log4jLogEvent) logEvent; boolean appendSuccessful = false; if (blocking) { if (isAppenderThread.get() == Boolean.TRUE && queue.remainingCapacity() == 0) { // LOG4J2-485: avoid deadlock that would result from trying // to add to a full queue from appender thread coreEvent.setEndOfBatch(false); // queue is definitely not empty! appendSuccessful = thread.callAppenders(coreEvent); } else { final Serializable serialized = Log4jLogEvent.serialize(coreEvent, includeLocation); try { // wait for free slots in the queue queue.put(serialized); appendSuccessful = true; } catch (final InterruptedException e) { // LOG4J2-1049: Some applications use Thread.interrupt() to send // messages between application threads. This does not necessarily // mean that the queue is full. To prevent dropping a log message, // quickly try to offer the event to the queue again. // (Yes, this means there is a possibility the same event is logged twice.) // // Finally, catching the InterruptedException means the // interrupted flag has been cleared on the current thread. // This may interfere with the application's expectation of // being interrupted, so when we are done, we set the interrupted // flag again. appendSuccessful = queue.offer(serialized); if (!appendSuccessful) { LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}", getName()); } // set the interrupted flag again. Thread.currentThread().interrupt(); } } } else { appendSuccessful = queue.offer(Log4jLogEvent.serialize(coreEvent, includeLocation)); if (!appendSuccessful) { error("Appender " + getName() + " is unable to write primary appenders. queue is full"); } } if (!appendSuccessful && errorAppender != null) { errorAppender.callAppender(coreEvent); } } /** * Create an AsyncAppender. * * @param appenderRefs The Appenders to reference. * @param errorRef An optional Appender to write to if the queue is full or other errors occur. * @param blocking True if the Appender should wait when the queue is full. The default is true. * @param shutdownTimeout How many milliseconds the Appender should wait to flush outstanding log events * in the queue on shutdown. The default is zero which means to wait forever. * @param size The size of the event queue. The default is 128. * @param name The name of the Appender. * @param includeLocation whether to include location information. The default is false. * @param filter The Filter or null. * @param config The Configuration. * @param ignoreExceptions If {@code "true"} (default) exceptions encountered when appending events are logged; * otherwise they are propagated to the caller. * @return The AsyncAppender. */ @PluginFactory public static AsyncAppender createAppender(@PluginElement("AppenderRef") final AppenderRef[] appenderRefs, @PluginAttribute("errorRef") @PluginAliases("error-ref") final String errorRef, @PluginAttribute(value = "blocking", defaultBoolean = true) final boolean blocking, @PluginAttribute(value = "shutdownTimeout", defaultLong = 0L) final long shutdownTimeout, @PluginAttribute(value = "bufferSize", defaultInt = DEFAULT_QUEUE_SIZE) final int size, @PluginAttribute("name") final String name, @PluginAttribute(value = "includeLocation", defaultBoolean = false) final boolean includeLocation, @PluginElement("Filter") final Filter filter, @PluginConfiguration final Configuration config, @PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final boolean ignoreExceptions) { if (name == null) { LOGGER.error("No name provided for AsyncAppender"); return null; } if (appenderRefs == null) { LOGGER.error("No appender references provided to AsyncAppender {}", name); } return new AsyncAppender(name, filter, appenderRefs, errorRef, size, blocking, ignoreExceptions, shutdownTimeout, config, includeLocation); } /** * Thread that calls the Appenders. */ private class AsyncThread extends Thread { private volatile boolean shutdown = false; private final List<AppenderControl> appenders; private final BlockingQueue<Serializable> queue; public AsyncThread(final List<AppenderControl> appenders, final BlockingQueue<Serializable> queue) { this.appenders = appenders; this.queue = queue; setDaemon(true); setName("AsyncAppenderThread" + THREAD_SEQUENCE.getAndIncrement()); } @Override public void run() { isAppenderThread.set(Boolean.TRUE); // LOG4J2-485 while (!shutdown) { Serializable s; try { s = queue.take(); if (s != null && s instanceof String && SHUTDOWN.equals(s.toString())) { shutdown = true; continue; } } catch (final InterruptedException ex) { break; // LOG4J2-830 } final Log4jLogEvent event = Log4jLogEvent.deserialize(s); event.setEndOfBatch(queue.isEmpty()); final boolean success = callAppenders(event); if (!success && errorAppender != null) { try { errorAppender.callAppender(event); } catch (final Exception ex) { // Silently accept the error. } } } // Process any remaining items in the queue. LOGGER.trace("AsyncAppender.AsyncThread shutting down. Processing remaining {} queue events.", queue.size()); int count = 0; int ignored = 0; while (!queue.isEmpty()) { try { final Serializable s = queue.take(); if (Log4jLogEvent.canDeserialize(s)) { final Log4jLogEvent event = Log4jLogEvent.deserialize(s); event.setEndOfBatch(queue.isEmpty()); callAppenders(event); count++; } else { ignored++; LOGGER.trace("Ignoring event of class {}", s.getClass().getName()); } } catch (final InterruptedException ex) { // May have been interrupted to shut down. // Here we ignore interrupts and try to process all remaining events. } } LOGGER.trace("AsyncAppender.AsyncThread stopped. Queue has {} events remaining. " + "Processed {} and ignored {} events since shutdown started.", queue.size(), count, ignored); } /** * Calls {@link AppenderControl#callAppender(LogEvent) callAppender} on all registered {@code AppenderControl} * objects, and returns {@code true} if at least one appender call was successful, {@code false} otherwise. Any * exceptions are silently ignored. * * @param event the event to forward to the registered appenders * @return {@code true} if at least one appender call succeeded, {@code false} otherwise */ boolean callAppenders(final Log4jLogEvent event) { boolean success = false; for (final AppenderControl control : appenders) { try { control.callAppender(event); success = true; } catch (final Exception ex) { // If no appender is successful the error appender will get it. } } return success; } public void shutdown() { shutdown = true; if (queue.isEmpty()) { queue.offer(SHUTDOWN); } } } /** * Returns the names of the appenders that this asyncAppender delegates to as an array of Strings. * * @return the names of the sink appenders */ public String[] getAppenderRefStrings() { final String[] result = new String[appenderRefs.length]; for (int i = 0; i < result.length; i++) { result[i] = appenderRefs[i].getRef(); } return result; } /** * Returns {@code true} if this AsyncAppender will take a snapshot of the stack with every log event to determine * the class and method where the logging call was made. * * @return {@code true} if location is included with every event, {@code false} otherwise */ public boolean isIncludeLocation() { return includeLocation; } /** * Returns {@code true} if this AsyncAppender will block when the queue is full, or {@code false} if events are * dropped when the queue is full. * * @return whether this AsyncAppender will block or drop events when the queue is full. */ public boolean isBlocking() { return blocking; } /** * Returns the name of the appender that any errors are logged to or {@code null}. * * @return the name of the appender that any errors are logged to or {@code null} */ public String getErrorRef() { return errorRef; } public int getQueueCapacity() { return queueSize; } public int getQueueRemainingCapacity() { return queue.remainingCapacity(); }}AsyncLogger是Log4j2引入的新特性，业务代码调用Logger.log的时候直接返回，而不需要等到appender输出到日志目的地后才返回。Log4j2的Asynclogger是通过LMAX Disruptor代替queue实现的异步（无锁的并发框架，http://ifeve.com/disruptor/，Disruptor简介），达到更高的并发和lower latency。
4.2 AsyncLogger
1，Disruptor使用了一个RingBuffer替代队列，用生产者消费者指针替代锁。
2，生产者消费者指针使用CPU支持的整数自增，无需加锁并且速度很快。Java的实现在Unsafe package中。
尽管AsyncLogger 能够大幅度的提高性能，但是也会带来一些问题，下面是翻译官方的文档的Trade-offs：
Benefits
- Higher throughput，达到相对于sync logger的6-68倍的吞吐量
- Lower logging latency，latency是调用Logger.log直到return的时间，asyncLogger的latency比syncLogger以及基于queue的aysncAppender都要低，不仅平均latency低，而且99%、95%latency 也都低于后两者
- 降低极端大的日志量时候的延迟尖峰
Drawbacks
- Error handling, 如果在打印日志的时候出现错误，使用asyncLogger，业务是不知道异常的（可以通过配置ExceptionHandler处理异常），如果打印日志是业务逻辑的一部分，不建议使用asyncLogger
- 打印一些可变的内容的时候，使用asyncLogger 会出现问题。大部分时间，不需要担心这点，Log4j确保了类似于 logger.debug("My object is {}", myObject)，使用myObject在打印日志的时刻的版本打印（Log4j 所有打印都日志都是封装到Message的实现类里，存储在 final String里），不管之后是否改变。但是log4j也支持一些了可变的Message，如 MapMessage and StructuredDataMessage ，这些如果在打印日志时候改变，就有问题了
全局配置异步Logger
配置所有Logger都为AsyncLogger，只需要增加disruptor包，然后配置一个system property，-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector，Log4j的配置文件不需要修改。
混合使用同步和异步Logger
单独配置某个logger为async的，通过<asyncRoot>或者<asyncLogger>
<Configuration status="WARN"> <Appenders> <!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. --> <RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log" immediateFlush="false" append="false"> <PatternLayout> <Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern> </PatternLayout> </RandomAccessFile> </Appenders> <Loggers> <!-- pattern layout actually uses location, so we need to include it --> <AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true"> <AppenderRef ref="RandomAccessFile"/> </AsyncLogger> <Root level="info" includeLocation="true"> <AppenderRef ref="RandomAccessFile"/> </Root> </Loggers></Configuration>ps. location的问题
当layouts配置了输出%C or $class, %F or %file, %l or %location, %L or %line, %M or %method,或者HTML locationInfo, log4j会获取location的一个快照，而这对于sync 和async的logger都是一个耗时的操作(官方文档上说syncLogger会慢1.3~5倍，async会慢4-20倍)，所以默认都是不会输出location信息，除非Logger配置了includeLocation="true"(官方文档这么说的，但是我测试的是默认是输出的，不管了，反正当日志出现慢的时候，可以考虑通过配置includeLocation控制是否输出location信息)。
1 1
- Java日志框架
- java 常用日志框架
- Java日志框架介绍
- java 日志框架统一
- Java日志框架
- java log4jdbc日志框架
- JAVA日志框架
- JAVA日志框架
- Java日志框架
- Java日志框架
- Java日志框架1
- JAVA日志框架
- java框架学习日志
- JAVA日志框架
- java日志框架学习
- java 日志框架总结
- java-日志框架
- Java 日志框架总结
- 电话联系人相关业务层类
- 分享一单例模式的文件操作类
- 如何捕获DDL记录
- poj 3070 矩阵快速幂
- 算法基础1——插入排序
- Java日志框架
- 蓝桥杯大臣的旅费
- 生成appcompat_v7（兼容包）并报错的解决方法
- redis
- 多源最短路：floyd
- 三大算法--二分选择冒泡
- Spark-神奇的共享变量
- Java的字符表示格式
- 单源最短路
