程序師世界是廣大編程愛好者互助、分享、學習的平台,程序師世界有你更精彩!
首頁
編程語言
C語言|JAVA編程
Python編程
網頁編程
ASP編程|PHP編程
JSP編程
數據庫知識
MYSQL數據庫|SqlServer數據庫
Oracle數據庫|DB2數據庫
 程式師世界 >> 編程語言 >> JAVA編程 >> JAVA綜合教程 >> Java日志框架

Java日志框架

編輯:JAVA綜合教程

Java日志框架


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依賴

      
      
      
                  org.slf4j
                  slf4j-api
                  1.7.13
              
              
                  org.apache.logging.log4j
                  log4j-slf4j-impl
                  2.4.1
              
              
              
                  org.apache.logging.log4j
                  log4j-1.2-api
                  2.0
              
              
                  org.apache.logging.log4j
                  log4j-api
                  2.4.1
              
              
                  org.apache.logging.log4j
                  log4j-core
                  2.4.1
              
              
              
                  com.lmax
                  disruptor
                  3.2.0
              

      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的配置參數如下所示。

        參數 描述 filter 用於決定是否需要使用該Appender來處理日志事件 layout 用於決定如何對日志記錄進行格式化,默認情況下使用“%m%n”,它會在每一行顯示一條日志記錄 follow 用於決定Appender是否需要了解輸出(system.out或者system.err)的變化,默認情況是不需要跟蹤這種變化 name 用於設置Appender的名字 ignoreExceptions 用於決定是否需要記錄在日志事件處理過程中出現的異常 target 用於指定輸出目標位置,默認情況下使用SYSTEM_OUT,但也可以修改成SYSTEM_ERR

         

        
                
                    
                    
                    
                    
                

        3.1.2FileAppender

         

        FileAppenders將日志記錄寫入到文件中,它負責打開、關閉文件,向文件中追加日志記錄,並對文件進行加鎖,以免數據被破壞或者覆蓋。

        在Log4j中,如果想創建一個FileAppender,需要指定目標文件的名字,寫入方式是追加還是覆蓋,以及是否需要在寫入日志時對文件進行加鎖:

         

         
                    
                

        3.1.3RollingFileAppender

         

        RollingFileAppender跟FileAppender的基本用法一樣。但RollingFileAppender可以設置log文件的size(單位:KB/MB/GB)上限、數量上限,當log文件超過設置的size上限,會自動被壓縮。RollingFileAppender可以理解為滾動輸出日志,如果log4j2記錄的日志達到上限,舊的日志將被刪除,騰出的空間用於記錄新的日志。

         

        
                
                    
                    
                

         

        3.1.5 其他appender

        我們已經介紹了一些經常用到的Appenders,還有很多其它Appender。它們添加了新功能或者在其它的一些Appender基礎上實現了新功能。例如,Log4j中的RollingFileAppender擴展了FileAppender,它可以在滿足特定條件時自動創建新的日志文件;SMTPAppender會將日志內容以郵件的形式發送出去;FailoverAppender會在處理日志的過程中,如果一個或者多個Appender失敗,自動切換到其他Appender上。

         

        3.2Layouts

        Layouts將日志記錄的內容從一種數據形式轉換成另外一種。日志框架為純文本、HTML、syslog、XML、JSON、序列化以及其它日志提供了Layouts。


        3.3Loggers

         

        Logger負責捕捉事件並將其發送給合適的Appender,Logger之間是有繼承關系的。總是存在一個rootLogger,即使沒有顯示配置也是存在的,並且默認輸出級別為DEBUG,其它的logger都繼承自這個rootLogger。
        Log4J中的繼承關系是通過名稱可以看出來,如"A"、"A.B"、"A.B.C",A.B繼承A,A.B.C繼承A.B,比較類似於包名。

         

        
                
                    
                    
                
        		
                    
                    
                
                
                
                    
                    
                
            


        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 Appendersalready 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:

         

        
        
          
            
              
                %d %p %c{1.} [%t] %m%n
              
            
            
              
            
          
          
            
              
            
          
        

        @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 isAppenderThread = new ThreadLocal<>();
            private final BlockingQueue 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 map = config.getAppenders();
                final List 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 appenders;
                private final BlockingQueue queue;
                public AsyncThread(final List appenders, final BlockingQueue 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是通過LMAXDisruptor代替queue實現的異步,達到更高的並發和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,如MapMessageandStructuredDataMessage,這些如果在打印日志時候改變,就有問題了

            全局配置異步Logger

            配置所有Logger都為AsyncLogger,只需要增加disruptor包,然後配置一個system property,-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector,Log4j的配置文件不需要修改。

            混合使用同步和異步Logger

            單獨配置某個logger為async的,通過或者

             

            
              
                
                
                  
                    %d %p %class{1.} [%t] %location %m %ex%n
                  
                
              
              
                
                
                  
                
                
                  
                
              
            

            ps. location的問題

             

            當layouts配置了輸出%C or $class, %F or %file, %l or %location, %L or %line, %M or %method,或者HTMLlocationInfo,log4j會獲取location的一個快照,而這對於sync 和async的logger都是一個耗時的操作(官方文檔上說syncLogger會慢1.3~5倍,async會慢4-20倍),所以默認都是不會輸出location信息,除非Logger配置了includeLocation="true"(官方文檔這麼說的,但是我測試的是默認是輸出的,不管了,反正當日志出現慢的時候,可以考慮通過配置includeLocation控制是否輸出location信息)。

             

             

             

  1. 上一頁:
  2. 下一頁:
Copyright © 程式師世界 All Rights Reserved