Java Util Log

從需求的角度出發(fā), 漸進(jìn)的理解 Java Util Log 源碼
基于 JDK 1.8 源碼
Java Util tutorial: http://tutorials.jenkov.com/java-logging/index.html

在 JUL 中有以下主要對象

• Logger 面向用戶獲取日志的接口
• LoggerManager 負(fù)責(zé)管理所有 logger
• Handler 負(fù)責(zé)最終日志的輸出, 例如 ConsoleHandler 輸出到終端, FileHandler 輸出到文件
• Formatter 用于格式化日志內(nèi)容, 例如添加時間戳, 輸出包名等
• Level 日志級別

最簡單的日志方式莫過于使用 System.out.println("debug log"); 的方式來輸出調(diào)試信息.

Logger logger = Logger.getLogger("TestLogger-" + random.nextInt());
logger.log(Level.INFO, "This is a test log.");

Logger

Logger 的創(chuàng)建

每個 Logger 對象在創(chuàng)建的時候都需要一個名稱, 這個名稱主要用在 logging.properties 中, 針對不同日志設(shè)置不同的輸出級別, 實現(xiàn)日志信息的過濾. 也可以指定 handler, 來輸出到不同的文件中去. 對于沒有上述需要的, 通常的做法是使用當(dāng)前類的名稱作為 logger name.

Logger logger = Logger.getLogger(JavaUtilLog.class.getName());

例如在 Web 服務(wù)中, HTTP 請求日志的級別設(shè)置為 Level.INFO, 應(yīng)用程序的日志級別設(shè)置為 Level.WARNING, 數(shù)據(jù)庫的日志級別設(shè)置為 Level.SEVERE. 將應(yīng)用程序的日志輸出到 app.log 文件中.

// In Java code
Logger rstLogger = Logger.getLogger("LOG_REQUEST");
Logger dbLogger = Logger.getLogger("LOG_DATABASE");
Logger appLogger = Logger.getLogger("LOG_APP");

############################################################
#   Custom Logging Configuration File
#   -Djava.util.logging.config.file=applogging.properties

LOG_REQUEST.level= INFO
LOG_DATABASE.level= SEVERE
LOG_APP.level= WARNING
LOG_APP.handlers = java.util.logging.FileHandler

java.util.logging.FileHandler.pattern = app.log
java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter

額外提一點, 如果需要將 HTTP 請求的日志輸出到 request.log 文件中, 如何實現(xiàn)呢? JUL 其實是不支持這種需求的, 不過可以通過繼承 FileHandler 實現(xiàn)一個 RequestFileHandler 然后添加到配置文件中.

日志的輸出

Logger 中會構(gòu)建一個 LogRecord 對象來包裝日志內(nèi)容, 之后遍歷所有可用的 handler, 調(diào)用 Handler.publish(LogRecord record) 由 handler 負(fù)責(zé)寫入操作.

日志內(nèi)容的原子性

Logger 日志輸出的相關(guān)函數(shù)中都沒有使用 synchronized 或其他鎖, 在多個線程都獲得同一個 logger 對象時, 同時在寫日志, 它時如何保證線程安全的, 換句話說如何保證多條日志信息不會互相影響, 每一條日志都能完整的輸出?

public void log(Level level, String msg) {
  // 日志過濾
  if (!isLoggable(level)) {
    return;
  }
  LogRecord lr = new LogRecord(level, msg);
  doLog(lr);
}

private void doLog(LogRecord lr) {
  // 填充 LogRecord
  lr.setLoggerName(name);
  // 此處 final 是為了線程安全考慮
  final Logger.LoggerBundle lb = getEffectiveLoggerBundle();
  final ResourceBundle bundle = lb.userBundle;
  final String ebname = lb.resourceBundleName;
  if (ebname != null && bundle != null) {
    lr.setResourceBundleName(ebname);
    lr.setResourceBundle(bundle);
  }
  log(lr);
}

public void log(LogRecord record) {
  // ...
  // 查找可用的 handler
  // 如果當(dāng)前 logger 上沒有掛載 handler, 則去父logger上查找
  Logger logger = this;
  while (logger != null) {
    final Handler[] loggerHandlers = isSystemLogger
        ? logger.accessCheckedHandlers()
        : logger.getHandlers();

    for (Handler handler : loggerHandlers) {
      handler.publish(record);
    }

    final boolean useParentHdls = isSystemLogger
        ? logger.config.useParentHandlers
        : logger.getUseParentHandlers();

    if (!useParentHdls) {
      break;
    }

    logger = isSystemLogger ? logger.parent : logger.getParent();
  }
}

通過代碼可以看出來, LogRecord 是作為一個原子集, 在 Logger 中填充好日志相關(guān)的信息, 然后將它對象傳遞給 handler, 由 handler 來保證一個 LogRecord 能夠完整的輸出.

handler 線程安全

Logger 上 handler 的添加和刪除操作都沒有加鎖, 如何保證在遍歷 handler 時, 當(dāng)前 handler 的數(shù)量保持不變? 例如線程A正在遍歷 handler 來輸出日志, 線程B此時刪除了中間某個 handler, 如何避免線程A拋出 java.util.ConcurrentModificationException 的異常

handler 存儲在 Logger.ConfigurationData 類中, 它是一個 CopyOnWriteArrayList 的 List 對象, 所以 Logger.addHandler() 和 Logger.removeHandler() 可以保持線程安全. 在遍歷 handler 輸出日志時, 會返回一個 Handler[], 這個數(shù)組不是 CopyOnWriteArrayList 中實際存儲的數(shù)組的包裝引用, 而是重新拷貝了一份. 所以線程B的刪除操作不會影響到線程A.

LogManager

LogManager 主要負(fù)責(zé)所有 Logger 的創(chuàng)建, 管理和銷毀. LogManager 的構(gòu)造函數(shù)是 private, LogManager 中定了一個全局的對象, 后續(xù)所有的操作其實都是在操作這一個對象.

Logger 的創(chuàng)建

Logger.getLogger() 實際調(diào)用的是 LogManager.demandLogger() 方法. 首先查找是否已經(jīng)存在名稱是 name 的 logger, 如果不存在則創(chuàng)建一個新的 logger 加入到 logger 列表.

Logger demandLogger(String name, String resourceBundleName, Class<?> caller) {
  Logger result = getLogger(name);
  if (result == null) {
    Logger newLogger = new Logger(name, resourceBundleName, caller, this, false);
    do {
      if (addLogger(newLogger)) {
        return newLogger;
      }

      // 因為方法中并沒有任何的加鎖操作, 所以在判斷完 result == null 之后, addLogger 之前
      // 可能有其他的線程已經(jīng)添加了同名的 logger, 我們這里的 addLogger 將會返回 false,
      // 所以在 addLogger 返回 false 之后我們需要調(diào)用 getLogger 嘗試獲取那個同名的 logger.
      //
      // 既然已經(jīng)有其他線程已經(jīng)創(chuàng)建并添加了同名的 logger, 為什么 getLogger 會有可能返回 null呢?
      // 因為 LogManager 在管理 logger 時使用的是弱引用(WeakReference), 如果那個已經(jīng)添加的 logger
      // 沒有被強(qiáng)引用, 在 addLogger 返回 false 之后 JVM 恰好執(zhí)行了一個 GC 操作, 那個沒有強(qiáng)引用的
      // logger 會被系統(tǒng)回收掉, 所以 getLogger 得到的是一個 null. 這就是這里 do-while 存在的意義.
      result = getLogger(name);
    } while (result == null);
  }
  return result;
}

Logger 的生命周期

LogManager 上有一個 userContext 的成員變量, 所有的 logger 實際都在保存在這個變量上. namedLoggers 的 value 實際是一個 logger 的弱引用.

// class LogManager {
private final LoggerContext userContext = new LoggerContext();
class LoggerContext {
    // Table of named Loggers that maps names to Loggers.
    private final ConcurrentHashMap<String,LoggerWeakRef> namedLoggers =
            new ConcurrentHashMap<>();
}

final class LoggerWeakRef extends WeakReference<Logger> {
  private String name;  // for namedLoggers cleanup
  private LogManager.LogNode node;       // for loggerRef cleanup
  private WeakReference<Logger> parentRef;  // for kids cleanup
  private boolean disposed = false;         // avoid calling dispose twice

  LoggerWeakRef(Logger logger) {
    super(logger, loggerRefQueue);
    name = logger.getName();
  }

  void dispose() {
    // ...
  }
}

對于弱引用通常會有這幾個疑問:

1. 如何知道一個 logger 已經(jīng)被回收了?
2. logger 被回收之后, 清理工作什么時候進(jìn)行?
3. logger 上綁定的 handler 什么時候關(guān)閉?

如果一個 logger 對象已經(jīng)被回收了, LogManager 并不能第一時間知道, 而是在每次調(diào)用 getLogger() 和 addLogger() 的時候才知道的, 而這兩個方法是在 demandLogger() 被調(diào)用.

LogManager.demandLogger() 實際調(diào)用的是 LoggerContext.findLogger(String) 方法. LogManager.addLogger() 實際調(diào)用的是 LoggerContext.addLocalLogger(Logger, boolean) 方法.

// class LoggerContext {
Logger findLogger(String name) {

  // ...

  synchronized (this) {
    // 確保這個 context 已經(jīng)初始化過了.
    ensureInitialized();
    LogManager.LoggerWeakRef ref = namedLoggers.get(name);
    if (ref == null) {
      // 在 LoggerWeakRef.dispose() 方法中清理 namedLoggers
      // 此處不需要清理
      return null;
    }
    logger = ref.get();
    if (logger == null) {
      // namedLoggers 中保存的弱引用 logger 已經(jīng)被 GC 回收了
      // 此時調(diào)用 LoggerWeakRef.dispose() 執(zhí)行清理操作.
      ref.dispose();
    }
    return logger;
  }
}

synchronized boolean addLocalLogger(Logger logger, boolean addDefaultLoggersIfNeeded) {

  // ...

  LogManager.LoggerWeakRef ref = namedLoggers.get(name);
  if (ref != null) {
    if (ref.get() == null) {
      // It's possible that the Logger was GC'ed after a
      // drainLoggerRefQueueBounded() call above so allow
      // a new one to be registered.
      ref.dispose();
    } else {
      // We already have a registered logger with the given name.
      return false;
    }
  }

  // ...

}

handler 只由 Logger 對象持有, 當(dāng) logger 對象銷毀后 handler 并未關(guān)閉. LogManager 的構(gòu)造函數(shù)中注冊了一個 JVM 退出的鉤子, 最終調(diào)用 LogManager.resetLogger(Logger) 來執(zhí)行 handler 的清理操作. 如果在代碼中給某個 logger 添加了自定義的 handler, 記得保持這個 handler 的強(qiáng)應(yīng)用, 并在合適的時候手動調(diào)用 Handler.close() 關(guān)閉它.

// class LogManager {
private LogManager(Void checked) {
  // Add a shutdown hook to close the global handlers.
  try {
    Runtime.getRuntime().addShutdownHook(new Cleaner());
  } catch (IllegalStateException e) {
    // If the VM is already shutting down,
    // We do not need to register shutdownHook.
  }
}

private void resetLogger(java.util.logging.Logger logger) {
  // Close all the Logger's handlers.
  Handler[] targets = logger.getHandlers();
  for (int i = 0; i < targets.length; i++) {
    Handler h = targets[i];
    logger.removeHandler(h);
    try {
      h.close();
    } catch (Exception ex) {
      // Problems closing a handler?  Keep going...
    }
  }
  
  // ...

}

handler

handler 負(fù)責(zé)將 logger 傳遞過來的 LogRecord 輸出到具體的介質(zhì)中. JDK 默認(rèn)提供了 ConsoleHandler , FileHandler 和 SocketHandler 等. handler 需要保證一條 LogRecord 在多線程的情況下能夠完整輸出, 不會被其他線程擾亂.

handler 是由 logger 調(diào)用過來的, 所以不能在 handler 中調(diào)用 logger, 這樣會造成調(diào)用死循環(huán), 導(dǎo)致棧溢出.

handler 會持有一個類型為 ErrorManager 的成員變量, handler 中任何有需要寫日志的地方, 通過它來輸出.