由Log4j2日志框架到Disruptor入门

        Disruptor是个啥相信听过的人不在少数，它是log4j2能提供高性能异步日志输出的底层支持，本质上他就是个并发框架，能够在无锁的情况下实现网络的Queue并发操作 ---- 来之官网的解释。

        作为一个开发者，并发中的线程、锁、Lock、synchronized、CAS是我常常听说的概念，并发的好处是提升性能，如何能提升性能，用通俗的话来说就是抢占利用CPU资源，让CPU不要闲着，那既然是多个线程抢占CPU那必然就引出各种竞争问题，有了竞争那就出现了锁。 

        如上图所示两个线程同时去修改value值，任何一个线程先进入并先执行完对结果不会有影响，结果value=blah\blahy, 结果都能接受，但是如果两个线程同时进入，最终结果可能是fluffy，显然这个结果不是我们想要的。然后针对这种多线程修改同步数据就有了各种解决方案，悲观锁、乐观锁、CAS，但是他们都会产生性能的损耗。

        我们把上面的场景类比到日志框架log4j，多线程打印日志的时候，最终输出的文件只有一个，拍大腿也能知道，肯定需要对输出日志那个对象或者方法啥的进行加锁以保证日志不会产生错误(每次追加日志总得知道上次写的位置吧)，log4j1.X还真这么干了，而且还粗暴，直接synchronized，这不就有可能直接阻塞业务代码吗，想想都阔怕，看下面的代码：

/** 
         Call the appenders in the hierrachy starting at 
         <code>this</code>.  If no appenders could be found, emit a 
         warning. 
      
         <p>This method calls all the appenders inherited from the 
         hierarchy circumventing any evaluation of whether to log or not 
         to log the particular log request. 
      
         @param event the event to log.  */  
    public void callAppenders(LoggingEvent event) {  
        int writes = 0;  
       
        for(Category c = this; c != null; c=c.parent) {  
          // Protected against simultaneous call to addAppender, removeAppender,...  
          synchronized(c) {  
            if(c.aai != null) {  
                writes += c.aai.appendLoopOnAppenders(event);  
            }  
            if(!c.additive) {  
                break;  
            }  
          }  
        }  
       
        if(writes == 0) {  
          repository.emitNoAppenderWarning(this);  
        }  
      }  

        那对这种就没有解决办法吗，当然有，联想到我们程序，如果并发性能不能满足，我们一般会怎样呢？MQ削峰，有请求先返回，消息丢MQ，另一个项目或者程序消费消息慢慢处理，不就阻塞业务线程的问题，咱们能想到的，开发log4j的那帮大佬当然也能想到，于是就有了下面这种代码（参看log4j1.X  的 AsyncAppender），将打印日志的动作和内容打包成一个LoggingEvent放到一个ArrayList中。

 /**
   * {@inheritDoc}
   */
  public void append(final LoggingEvent event) {
    //
    //   if dispatcher thread has died then
    //      append subsequent events synchronously
    //   See bug 23021
    if ((dispatcher == null) || !dispatcher.isAlive() || (bufferSize <= 0)) {
      synchronized (appenders) {
        appenders.appendLoopOnAppenders(event);
      }

      return;
    }

    // Set the NDC and thread name for the calling thread as these
    // LoggingEvent fields were not set at event creation time.
    event.getNDC();
    event.getThreadName();
    // Get a copy of this thread's MDC.
    event.getMDCCopy();
    if (locationInfo) {
      event.getLocationInformation();
    }
    event.getRenderedMessage();
    event.getThrowableStrRep();

    synchronized (buffer) {
      while (true) {
        int previousSize = buffer.size();

        if (previousSize < bufferSize) {
          buffer.add(event);

          //
          //   if buffer had been empty
          //       signal all threads waiting on buffer
          //       to check their conditions.
          //
          if (previousSize == 0) {
            buffer.notifyAll();
          }

          break;
        }

        //
        //   Following code is only reachable if buffer is full
        //
        //
        //   if blocking and thread is not already interrupted
        //      and not the dispatcher then
        //      wait for a buffer notification
        boolean discard = true;
        if (blocking
                && !Thread.interrupted()
                && Thread.currentThread() != dispatcher) {
          try {
            buffer.wait();
            discard = false;
          } catch (InterruptedException e) {
            //
            //  reset interrupt status so
            //    calling code can see interrupt on
            //    their next wait or sleep.
            Thread.currentThread().interrupt();
          }
        }

        //
        //   if blocking is false or thread has been interrupted
        //   add event to discard map.
        //
        if (discard) {
          String loggerName = event.getLoggerName();
          DiscardSummary summary = (DiscardSummary) discardMap.get(loggerName);

          if (summary == null) {
            summary = new DiscardSummary(event);
            discardMap.put(loggerName, summary);
          } else {
            summary.add(event);
          }

          break;
        }
      }
    }
  }

然后再搞个线程从ArrayList中消费这个event执行真正的打印日志，这完全是手写一个阻塞队列的既视感，各种synchronized、wait()、notify()，看着都累，这样性能能高吗，感觉只是减少了对业务线程的影响，甚至多线程去添加LoggingEvent的时候还来了个synchronized，所以log4j的同步日志和异步日志在日志输出性能上并无太大差别，甚至性能更差，这里放一个链接：log4j1.x版本中的AsyncAppender为什么效率还没有同步的高？ - 知乎

/**
   * Event dispatcher.
   */
  private static class Dispatcher implements Runnable {
    /**
     * Parent AsyncAppender.
     */
    private final AsyncAppender parent;

    /**
     * Event buffer.
     */
    private final List buffer;

    /**
     * Map of DiscardSummary keyed by logger name.
     */
    private final Map discardMap;

    /**
     * Wrapped appenders.
     */
    private final AppenderAttachableImpl appenders;

    /**
     * Create new instance of dispatcher.
     *
     * @param parent     parent AsyncAppender, may not be null.
     * @param buffer     event buffer, may not be null.
     * @param discardMap discard map, may not be null.
     * @param appenders  appenders, may not be null.
     */
    public Dispatcher(
      final AsyncAppender parent, final List buffer, final Map discardMap,
      final AppenderAttachableImpl appenders) {

      this.parent = parent;
      this.buffer = buffer;
      this.appenders = appenders;
      this.discardMap = discardMap;
    }

    /**
     * {@inheritDoc}
     */
    public void run() {
      boolean isActive = true;

      //
      //   if interrupted (unlikely), end thread
      //
      try {
        //
        //   loop until the AsyncAppender is closed.
        //
        while (isActive) {
          LoggingEvent[] events = null;

          //
          //   extract pending events while synchronized
          //       on buffer
          //
          synchronized (buffer) {
            int bufferSize = buffer.size();
            isActive = !parent.closed;

            while ((bufferSize == 0) && isActive) {
              buffer.wait();
              bufferSize = buffer.size();
              isActive = !parent.closed;
            }

            if (bufferSize > 0) {
              events = new LoggingEvent[bufferSize + discardMap.size()];
              buffer.toArray(events);

              //
              //   add events due to buffer overflow
              //
              int index = bufferSize;

              for (
                Iterator iter = discardMap.values().iterator();
                  iter.hasNext();) {
                events[index++] = ((DiscardSummary) iter.next()).createEvent();
              }

              //
              //    clear buffer and discard map
              //
              buffer.clear();
              discardMap.clear();

              //
              //    allow blocked appends to continue
              buffer.notifyAll();
            }
          }

          //
          //   process events after lock on buffer is released.
          //
          if (events != null) {
            for (int i = 0; i < events.length; i++) {
              synchronized (appenders) {
                appenders.appendLoopOnAppenders(events[i]);
              }
            }
          }
        }
      } catch (InterruptedException ex) {
        Thread.currentThread().interrupt();
      }
    }
  }

        讲了这么多前戏，该进入主题了，今天的主题是Disruptor，为什么前面却讲了这么多锁、线程、log4j啊等等，因为log4j2对log4j的升级正是应用了Disruptor这个并发框架，它不仅仅是把AsyncAppender中的手写阻塞队列换成了JUC中的ArrayBlockingQueue(参看log4j 2.X 的 AsyncAppender基于Appender的实现)，还将Logger的实现改成了AsyncLogger(logf4j1.X 是RootLogger)，而这个AsyncLogger的实现思路如下： 

@Override
    public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message,
            final Throwable thrown) {
        getTranslatorType().log(fqcn, level, marker, message, thrown);
    }

private final AsyncLogger.TranslatorType varargTranslatorType = new AsyncLogger.TranslatorType() {
        void log(String fqcn, StackTraceElement location, Level level, Marker marker, Message message, Throwable thrown) {
            AsyncLogger.this.logWithVarargTranslator(fqcn, location, level, marker, message, thrown);
        }

        void log(String fqcn, Level level, Marker marker, Message message, Throwable thrown) {
            AsyncLogger.this.logWithVarargTranslator(fqcn, level, marker, message, thrown);
        }
    };

private void logWithVarargTranslator(String fqcn, Level level, Marker marker, Message message, Throwable thrown) {
        // 获取一个Disruptor实例
        Disruptor<RingBufferLogEvent> disruptor = this.loggerDisruptor.getDisruptor();
        if (disruptor == null) {
            LOGGER.error("Ignoring log event after Log4j has been shut down.");
        } else {
            if (!this.isReused(message)) {
                InternalAsyncUtil.makeMessageImmutable(message);
            }

            StackTraceElement location = null;
            if (!disruptor.getRingBuffer().tryPublishEvent(this, new Object[]{this, location = this.calcLocationIfRequested(fqcn), fqcn, level, marker, message, thrown})) {
                // 处理队列满的情况
                this.handleRingBufferFull(location, fqcn, level, marker, message, thrown);
            }

        }
    }

        至此，Disruptor终于登场了，上来就是把要输出的日志打包成一个RingBufferLogEvent直接push到RingBuffer。看来这个RingBuffer是核心，类比到前面讲的阻塞队列，这玩意肯定也是队列，我们来看看它是如何消费的：     

// AsyncLogger先new出来,传入了一个AsyncLoggerDisruptor
public AsyncLogger(final LoggerContext context, final String name, final MessageFactory messageFactory,
            final AsyncLoggerDisruptor loggerDisruptor) {
        super(context, name, messageFactory);
        this.loggerDisruptor = loggerDisruptor;
        includeLocation = privateConfig.loggerConfig.isIncludeLocation();
        nanoClock = context.getConfiguration().getNanoClock();
    }

// AsyncLoggerDisruptor
@Override
    public synchronized void start() {
        if (disruptor != null) {
            LOGGER.trace(
                    "[{}] AsyncLoggerDisruptor not starting new disruptor for this context, using existing object.",
                    contextName);
            return;
        }
        LOGGER.trace("[{}] AsyncLoggerDisruptor creating new disruptor for this context.", contextName);
        ringBufferSize = DisruptorUtil.calculateRingBufferSize("AsyncLogger.RingBufferSize");
        final WaitStrategy waitStrategy = DisruptorUtil.createWaitStrategy("AsyncLogger.WaitStrategy");

        final ThreadFactory threadFactory = new Log4jThreadFactory("AsyncLogger[" + contextName + "]", true, Thread.NORM_PRIORITY) {
            @Override
            public Thread newThread(final Runnable r) {
                final Thread result = super.newThread(r);
                backgroundThreadId = result.getId();
                return result;
            }
        };
        asyncQueueFullPolicy = AsyncQueueFullPolicyFactory.create();

        disruptor = new Disruptor<>(RingBufferLogEvent.FACTORY, ringBufferSize, threadFactory, ProducerType.MULTI,
                waitStrategy);

        final ExceptionHandler<RingBufferLogEvent> errorHandler = DisruptorUtil.getAsyncLoggerExceptionHandler();
        disruptor.setDefaultExceptionHandler(errorHandler);

        final RingBufferLogEventHandler[] handlers = {new RingBufferLogEventHandler()};
        disruptor.handleEventsWith(handlers);

        LOGGER.debug("[{}] Starting AsyncLogger disruptor for this context with ringbufferSize={}, waitStrategy={}, "
                + "exceptionHandler={}...", contextName, disruptor.getRingBuffer().getBufferSize(), waitStrategy
                .getClass().getSimpleName(), errorHandler);
        disruptor.start();

        LOGGER.trace("[{}] AsyncLoggers use a {} translator", contextName, useThreadLocalTranslator ? "threadlocal"
                : "vararg");
        super.start();
    }

           终于可以休息了，第一篇浅尝辄止，预知后事如何，且听下回分解，下篇着重讲解环形队列的实现，先放个图吊吊胃口，还别说，程序的世界里环用的还挺多的，每每跟它沾边的都能带来性能的大幅提升，在这里小小的扫个盲，没听过的小伙伴可以自行百度：一致性hash环、mysql的redolog落盘方式、dubbo的zk重连时间轮.....