日志框架(logback原理分析)

Java开发中都是默认使用日志门面+日志实现的方式打印日志。日志门面主要是为了给Java日志访问提供一套标准、规范的API框架，其主要意义在于提供接口，具体的实现可以交由具体的日志实现框架。

1.那些年那些日志框架

日志门面	日志实现
JCL(Jakarta Commons Logging)	JUL(java.util.logging)
SLF4j(Simple Logging Facade for Java)	log4j、log4j2、logback

• log4j
  在很久以前，Java并没有日志框架，大家打印日志靠的还是print语句输出。后来Apache上出现了一个开源的项目，是由E.U.SEMPER(欧洲安全电子市场)编写的一个API，其主要作者是一位超级大神Ceki Gülcü，这个日志框架很快被广大Java程序员使用起来，成为一代最经典的日志框架。
• JUL
  很快，作为Java的发明者Sun公司坐不住了，在发布Java1.4版本的时候，推出了自带的系统JUL，很明显是与log4j进行对抗。但是这个时候log4j已经成熟了，而JUL存在很多的不足，比较混乱，一般并不推荐使用。
• JCL
  这个时候，Apache继续发力，推出了日志的接口，也就是我们现在说的日志门面，这样不论你用log4j还是JUL，都可以去实现JCL这个日志门面，然后随意切换。这样Apache统治了一段时间的日志框架，但是好景不常，人们发现JCL算法非常复杂，一旦出现问题难以排查。
• SLF4J
  大神Ceki Gülcü，也就是log4j的作者离开了Apache，他自己一个人写出了一个新的日志门面来替代JCL，也就是现在人们常用的SLF4J。它受类加载器的影响较小，不易产生内存溢出的问题，性能得到了改善，而且它比较简洁，很快成为新的宠儿。
• logback
  还是Ceki Gülcü大神，对log4j进行了升级改造，写出来一个可以直接实现SLF4J的框架logback，它相对log4j性能更好，功能更丰富。
• log4j2
  这次该Apache坐不住了，扶我起来，我还能战。Apache发布了一个新的项目log4j2，听起来像是log4j的升级版，但实际上我们知道他们不是同一个作者，很明显它是冲着logback来的。log4j2几乎包括了logback所有的功能和内容，而且比它更丰富。

2.为什么使用日志门面

日志框架这么多，明明可以拿来直接用，为何还要使用日志门面呢？我们都知道，编程届有一句话叫做高内聚低耦合。每一种日志框架都有自己的API，如果一个应用程序想要更换日志框架，那就得修改代码，使用其对应的API，这样就增加了应用程序对于日志框架的耦合性。
如果使用了日志门面，就可以在日志框架和应用程序之间架设一个沟通的桥梁，无论使用什么日志框架，使用的都是门面的API，只需要依赖不同的jar包，应用程序不需要修改任何代码。话不多说，直接上图。当然如果你需要自定义日志的输出格式，还是需要修改配置文件的。

现在大部分应用都使用slf4j作为日志门面，作者创建slf4j的目的是为了替代JCL。slf4j所提供的核心API是一些接口以及一个LoggerFactory的工厂类。在使用slf4j的时候，不需要在代码中或配置文件中指定你打算使用那个具体的日志系统，只需要依赖slf4j和日志实现框架以及中间桥接的jar包。下图是slf4j官方的项目组成图，本质上就是slf4j的jar加上不同日志实现框架的jar包或者中间桥接jar包，实际上就是上图的具体实践。

3.看看logback里面都有啥

结构

Logback分为三个模块，logback-core、logback-classic和logback-access。core模块为其他两个模块奠定了基础，classic模块扩展了core模块，相当于log4j的一个显著改进版本。logback-classic原生实现了slf4j API，可以和其他日志系统随意地来回切换，诸如log4j、JUL等。access模块与Servlet容器集成以提供HTTP访问日志的功能。

Logback建立于三个主要类之上：Logger（消息类型和级别来记录消息）、Appender（输出目的）和Layout（输出格式）。这三种组件协同工作，使开发者可以按照消息类型和级别来记录消息，还可以在程序运行期内控制消息的输出格式和输出目的地。

应用

• 添加依赖
  使用logback，首先需要添加相应的依赖。spring-boot-starter中包含了 spring-boot-starter-logging，该依赖内容就是默认的日志框架 logback+slf4j，而 spring-boot-starter-web 包含了spring-boot-starter，所以我们只需要引入web组件即可。

<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>

• 配置文件
  如果不需要定制化输出日志，可以不用设置配置文件，直接输出到控制台。如果想要按照自己的要求输出日志，则需要修改配置文件名为logback-spring.XML，因为logback.xml会被logback组件直接读取，如果要交给spring管理，需要springProfile标签，可以为不同的环境使用不同的配置。将logback-spring.XML放到resources目录下，在配置文件中可以进行定制化的配置以输出需要的日志。
• 打印日志
  无论是否修改配置文件，输出日志的方法都一样，通过slf4j的工厂类LoggerFactory获得Logger对象，再通过Logger输出相应级别的日志。下面代码通过logger.info()语句输出info级别的日志，我们也可以在自己的程序中需要的位置输出任意级别的日志内容。logback一共有五个级别，由低到高分别是trace、debug、info、warn以及error，很多人说我只在控制台看到过info、warn和error级别的日志，那是因为SpringBoot默认给我们使用的是info级别的，那它就只输出info及以上级别的日志内容，可以通过配置文件进行修改。

package com.boc.test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class TestApplication {
    Logger logger = LoggerFactory.getLogger(TestApplication.class);
    public static void main(String[] args) {
        logger.info("hello, logback ");
}
}

4.起飞的关键——异步输出

同步输出与异步输出

• 同步输出
  传统的日志打印采用的是同步输出的方式，所谓同步日志，即当输出日志时，必须等待日志输出语句执行完毕后，才能执行后面的业务逻辑语句。
  
  使用logback的同步日志进行日志输出，日志输出语句与程序的业务逻辑语句将在同一个线程运行。在高并发场景下，日志数量不但激增，作为磁盘IO来说，容易产生瓶颈，导致线程卡顿在生成日志过程中，会影响程序后续的主业务，降低程序的性能。
• 异步输出
  使用异步日志进行输出时，日志输出语句与业务逻辑语句并不是在同一个线程中运行，而是有专门的线程用于进行日志输出操作，处理业务逻辑的主线程不用等待即可执行后续业务逻辑。这样即使日志没有完成输出，也不会影响程序的主业务，从而提高了程序的性能。
  

生产者消费者

logback中常用的appender有ConsoleAppender和RollingFileAppender两种，前者作为控制台输出，在生产环境中可关闭。后者滚动文件输出，不断写入磁盘，在高并发场景下消耗CPU和时间都较大。Logback的异步输出采用生产者消费者的模式，将生成的日志放入消息队列中，并将创建一个线程用于输出日志事件，有效的解决了这个问题，提高了程序的性能。
logback中的异步输出日志使用了AsyncAppender这个appender，通过看AsyncAppender源码，跟到它的父类AsyncAppenderBase，可以看到它有几个重要的成员变量：

AppenderAttachableImpl<E> aai = new AppenderAttachableImpl<E>();
BlockingQueue<E> blockingQueue;
AsyncAppenderBase<E>.Worker worker = new AsyncAppenderBase.Worker();

BlockingQueue是一个队列，Worker是一个消费线程，基本可以判定是个生产者消费者模式。
再看消费者（work）的主要代码：

while (parent.isStarted()) {
try {
        E e = parent.blockingQueue.take();    //单条循环
        aai.appendLoopOnAppenders(e);
} catch (InterruptedException ie) {
break;
}
}

使用的是while单条循环 ，即logback异步输出是由一个消费者循环单条写入日志文件，工作流程如下图：

接下来看看具体是如何实现输出的：

public void start() {
        blockingQueue = new ArrayBlockingQueue<E>(queueSize);
    if (discardingThreshold == UNDEFINED)
        discardingThreshold = queueSize / 5;
    addInfo("Setting discardingThreshold to " + discardingThreshold);
    worker.setDaemon(true);
    worker.setName("AsyncAppender-Worker-" + getName());
    // make sure this instance is marked as "started" before staring the worker Thread
    super.start();
    worker.start();
}

start()方法初始化中，定义了一个ArrayBlockingQueue队列，以及启动了一个worker线程。
接着看append()方法：

@Override
protected void append(E eventObject) {
if (isQueueBelowDiscardingThreshold() && isDiscardable(eventObject)) {
return;
}
preprocess(eventObject);
put(eventObject);
}

在append()方法中，并没有马上处理日志事件，而是调用put()方法，接着把日志事件放进去消息队列中。然后由Worker线程去处理，Worker线程从队列中take()取出事件，然后由具体的Appender去处理。
当有多个线程向队列中写日志和取日志时，将会出现线程安全问题，logback中使用的是BlockingQueue即阻塞队列来存储日志，BlockingQueue有锁的机制，可以有效的保证原子性，跟数据库事务的原子性概念差不多，即一个操作（有可能包含有多个子操作）要么全部执行（生效），要么全部都不执行（都不生效），从而保证线程的安全。

BlockingQueue

BlockingQueue是一个接口，logback使用的是它的实现类ArrayBlockingQueue， ArrayBlockingQueue底层是使用一个数组实现队列的，并且在构造ArrayBlockingQueue时需要指定容量，也就意味着底层数组一旦创建了，容量就不能改变了，因此ArrayBlockingQueue是一个容量限制的阻塞队列。因此，在队列全满时执行入队将会阻塞，在队列为空时出队同样将会阻塞。
ArrayBlockingQueue的put()方法在队列不满的情况下，将会将元素添加到队列尾部，如果队列已满，将会阻塞，直到队列中有剩余空间可以插入。

public void put(E e) throws InterruptedException {
    //检查元素是否为null，如果是，抛出NullPointerException       
    checkNotNull(e);
    final ReentrantLock lock = this.lock;
    //加锁       
    lock.lockInterruptibly();
    try {
        //如果队列已满，阻塞，等待队列成为不满状态           
        while (count == items.length)
            notFull.await();
        //将元素入队           
        enqueue(e);
    } finally {
        lock.unlock();
    }
}

take()方法用于取走队头的元素，当队列为空时将会阻塞，直到队列中有元素可取走时将会被释放。其实现如下：

public E take() throws InterruptedException {
    final ReentrantLock lock = this.lock;
    //首先加锁       
    lock.lockInterruptibly();
    try {
        //如果队列为空，阻塞           
        while (count == 0)
            notEmpty.await();
        //队列不为空，调用dequeue()出队           
        return dequeue();
    } finally {
        //释放锁           
        lock.unlock();
    }
}

ArrayBlockingQueue的并发阻塞是通过ReentrantLock和Condition来实现的，ArrayBlockingQueue内部只有一把锁，意味着同一时刻只有一个线程能进行入队或者出队的操作，即logback同时只能有一个线程操作队列，操作前会加锁，操作完成后才会释放锁，保证了线程的安全。

异步输出常见属性

在只有入队高并发的情况下，因为操作数组，且不需要扩容，性能很高，但是如果ArrayBlockingQueue放满了，会出现队列满的情况，在这种情况下，AsyncAppender会做出一些处理，默认情况下，如果队列80%已满，AsyncAppender将丢弃trace、debug和info级别的日志，从这点就可以看出，该策略有一个惊人的对日志丢失的代价。另外其他的一些选项信息，会对性能产生影响，下面列出常用的几个属性配置信息：

属性名	类型	描述
queueSize	int	BlockingQueue的最大容量，默认情况下，大小为256。
discardingThreshold	int	默认情况下，当队列还有20%容量，他将丢弃trace、debug和info级别的日志，只保留warn和error级别的日志。
includeCallerData	boolean	提取调用者数据的代价是相当昂贵的。为了提升性能，默认情况下，当event被加入到queue时，event关联的调用者数据不会被提取。默认情况下，只有"cheap"的数据，如线程名。
neverBlock	boolean	默认是false，代表在队列放满的情况下是否卡住线程。也就是说，如果配置neverBlock=true，当队列满了之后，后面阻塞的线程想要输出的消息就直接被丢弃，从而线程不会阻塞。

默认情况下，event queue配置最大容量为256个events。如果队列被填满，应用程序线程被阻止记录新的events，直到工作线程有机会来转发一个或多个events。因此队列深度需要根据业务场景进行相应的测试，做出相应的更改，以达到较好的性能。neverBlock配置用于线程很重要，当不能卡顿，日志又不是很重要的场景，可能选择丢失日志保持线程不阻塞。

5.logback 还是 log4j2 ？

开头我们说到log4j2是Apache用于应对logback的，它几乎涵盖了所有logback的功能，并且比之更为强大一点。logback与slf4j是同一个作者，可以直接实现slf4j，不需要中间桥接包，几乎是没有开销的，而且springboot默认使用logback，所以大部分人包括我在内用的都是logback。但是个人感觉未来应该还是log4j2的天下，毕竟Apache太强大了，一个人还是难以干的过一个组织。