Java Util Log
Java Util Log
从需求的角度出发, 渐进的理解 Java Util Log 源码
基于 JDK 1.8 源码
Java Util tutorial: http://tutorials.jenkov.com/java-logging/index.html
在 JUL 中有以下主要对象
- Logger 面向用户获取日志的接口
- LoggerManager 负责管理所有 logger
- Handler 负责最终日志的输出, 例如 ConsoleHandler 输出到终端, FileHandler 输出到文件
- Formatter 用于格式化日志内容, 例如添加时间戳, 输出包名等
- Level 日志级别
最简单的日志方式莫过于使用 System.out.println("debug log");
的方式来输出调试信息.
Logger logger = Logger.getLogger("TestLogger-" + random.nextInt());
logger.log(Level.INFO, "This is a test log.");
Logger
Logger 的创建
每个 Logger 对象在创建的时候都需要一个名称, 这个名称主要用在 logging.properties 中, 针对不同日志设置不同的输出级别, 实现日志信息的过滤. 也可以指定 handler, 来输出到不同的文件中去. 对于没有上述需要的, 通常的做法是使用当前类的名称作为 logger name.
Logger logger = Logger.getLogger(JavaUtilLog.class.getName());
例如在 Web 服务中, HTTP 请求日志的级别设置为 Level.INFO, 应用程序的日志级别设置为 Level.WARNING, 数据库的日志级别设置为 Level.SEVERE. 将应用程序的日志输出到 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 文件中, 如何实现呢? JUL 其实是不支持这种需求的, 不过可以通过继承 FileHandler 实现一个 RequestFileHandler 然后添加到配置文件中.
日志的输出
Logger 中会构建一个 LogRecord 对象来包装日志内容, 之后遍历所有可用的 handler, 调用 Handler.publish(LogRecord record)
由 handler 负责写入操作.
日志内容的原子性
Logger 日志输出的相关函数中都没有使用 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
// 如果当前 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 中填充好日志相关的信息, 然后将它对象传递给 handler, 由 handler 来保证一个 LogRecord 能够完整的输出.
handler 线程安全
Logger 上 handler 的添加和删除操作都没有加锁, 如何保证在遍历 handler 时, 当前 handler 的数量保持不变? 例如线程A正在遍历 handler 来输出日志, 线程B此时删除了中间某个 handler, 如何避免线程A抛出 java.util.ConcurrentModificationException 的异常
handler 存储在 Logger.ConfigurationData 类中, 它是一个 CopyOnWriteArrayList
的 List 对象, 所以 Logger.addHandler() 和 Logger.removeHandler() 可以保持线程安全. 在遍历 handler 输出日志时, 会返回一个 Handler[], 这个数组不是 CopyOnWriteArrayList
中实际存储的数组的包装引用, 而是重新拷贝了一份. 所以线程B的删除操作不会影响到线程A.
LogManager
LogManager 主要负责所有 Logger 的创建, 管理和销毁. LogManager 的构造函数是 private, LogManager 中定了一个全局的对象, 后续所有的操作其实都是在操作这一个对象.
Logger 的创建
Logger.getLogger()
实际调用的是 LogManager.demandLogger()
方法. 首先查找是否已经存在名称是 name 的 logger, 如果不存在则创建一个新的 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 之前
// 可能有其他的线程已经添加了同名的 logger, 我们这里的 addLogger 将会返回 false,
// 所以在 addLogger 返回 false 之后我们需要调用 getLogger 尝试获取那个同名的 logger.
//
// 既然已经有其他线程已经创建并添加了同名的 logger, 为什么 getLogger 会有可能返回 null呢?
// 因为 LogManager 在管理 logger 时使用的是弱引用(WeakReference), 如果那个已经添加的 logger
// 没有被强引用, 在 addLogger 返回 false 之后 JVM 恰好执行了一个 GC 操作, 那个没有强引用的
// logger 会被系统回收掉, 所以 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() {
// ...
}
}
对于弱引用通常会有这几个疑问:
- 如何知道一个 logger 已经被回收了?
- logger 被回收之后, 清理工作什么时候进行?
- logger 上绑定的 handler 什么时候关闭?
如果一个 logger 对象已经被回收了, LogManager 并不能第一时间知道, 而是在每次调用 getLogger()
和 addLogger()
的时候才知道的, 而这两个方法是在 demandLogger()
被调用.
LogManager.demandLogger()
实际调用的是 LoggerContext.findLogger(String)
方法. LogManager.addLogger()
实际调用的是 LoggerContext.addLocalLogger(Logger, boolean)
方法.
// class LoggerContext {
Logger findLogger(String name) {
// ...
synchronized (this) {
// 确保这个 context 已经初始化过了.
ensureInitialized();
LogManager.LoggerWeakRef ref = namedLoggers.get(name);
if (ref == null) {
// 在 LoggerWeakRef.dispose() 方法中清理 namedLoggers
// 此处不需要清理
return null;
}
logger = ref.get();
if (logger == null) {
// namedLoggers 中保存的弱引用 logger 已经被 GC 回收了
// 此时调用 LoggerWeakRef.dispose() 执行清理操作.
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 对象持有, 当 logger 对象销毁后 handler 并未关闭. LogManager 的构造函数中注册了一个 JVM 退出的钩子, 最终调用 LogManager.resetLogger(Logger)
来执行 handler 的清理操作. 如果在代码中给某个 logger 添加了自定义的 handler, 记得保持这个 handler 的强应用, 并在合适的时候手动调用 Handler.close()
关闭它.
// 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 负责将 logger 传递过来的 LogRecord 输出到具体的介质中. JDK 默认提供了 ConsoleHandler
, FileHandler
和 SocketHandler
等. handler 需要保证一条 LogRecord 在多线程的情况下能够完整输出, 不会被其他线程扰乱.
handler 是由 logger 调用过来的, 所以不能在 handler 中调用 logger, 这样会造成调用死循环, 导致栈溢出.
handler 会持有一个类型为 ErrorManager
的成员变量, handler 中任何有需要写日志的地方, 通过它来输出.