许多人说,log4j性能有问题,日志格式使用的时候不够灵活,推荐使用log4j2,那本文分析一下log4j的运行过程,查看下性能瓶颈所在,选用一个常用的DailyRollingFileAppender作为范本解释
- log4j类图
为方便理解和观察,大致的一个类结构图,核心类包含了一些主要方法,并没有罗列出所有:
- 运行步骤
1、容器初始化,解析配置文件,使用反射初始化appender,这里就是DailyRollingFileAppender,当然这里它需要设置文件的日期格式、文件路径和名称、bufferedio是否开启、buffersize大小,创建写日志的FilterWriter,完成上面的动作都需要调用DailyRollingFileAppender的activateOptions和父类的activateOptions方法
2、业务中的日志打印,首先获取logger,把消息封装成一个loggingEvent事件,把该日志提供给该logger所绑定的appender
3、日志记录,就是调用appender的doAppend方法,由于是继承关系,其实是调用AppenderSkeleton的doAppend方法,注意这里的方法是被synchronized的,当多个logger需要记录日志时,在该位置会被阻塞
3.1类之间的调用关系如下:
AppenderSkeleton.doAppend()——》WriterAppender.append——》WriterAppender.subAppend
记录文件就是使用java.io的Writer,如果没有开启bufferedIO,则每次写日志都强制flush,否则依赖于缓冲区空间满以后在刷新
- 异步appender的处理
AsyncAppender:调用关系如下,因为为调用doAppend所以,多线程同样为阻塞,尽管这个是异步的appender,异步只能体现在最后记录日志事件的动作上了
AppenderSkeleton.doAppend()——》AsyncAppender.append
生产则: -
public void append(final LoggingEvent event) { // // if dispatcher thread has died then // append subsequent events synchronously // See bug 23021 //如果消费线程为空,或者不是存活的,或者队列长度小于等于0,这里直接变为同步执行了 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. // //如果是队列内容为空,有可能消费完,有可能是首次进队列,那么此时的nofityAll是为了唤醒同时监听buffer对象的消费者 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; //如果队列满了以后,看它的阻塞策略是否为true,如果是,检查当前线程是否已经被中断,保证当前的线程不是消费线程,此时只能进入线程等待了,因为策略不允许丢弃 //等的过程wait是释放对buffer的持有,锁释放的两种清空如下,所以这是否消费者可以努力的去消费把,队列给腾出空间来,消费者消费过程中也会notifyAll,唤醒等待中的生产者线程 //1.该线程的同步方法、同步代码块执行完、该线程同步方法、同步代码块中遇到return,break、该线程同步方法、同步代码块中发生了未处理的Exception、Error //2.其他线程执行了同步监听器对象的wait()、其他线程执行了当前线程的stop 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; } } } }
消费者:
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(); //空队列,就等待吧,节省CPU资源,因为这里等待了,所以生产者哪里对空队列加入消息后会notify它,是需要唤醒消费线程 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(); //队列内容已经被移动到了events里,队列有了足够的空间,可以把因为队列满而进行等待的线程唤醒了,因为消息不能丢啊 //正好消费者的线程也把锁释放了,生产者线程被唤醒后,下一个while true循环就可以继续往队列里放东西了 } } // // 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(); } }