正文
日志框架--（二）JDK Logging
小程序：扫一扫查出行【扫一扫了解最新限行尾号】
复制小程序
前言
从jdk1.4起，JDK开始自带一套日志系统。JDK Logger最大的优点就是不需要任何类库的支持，只要有Java的运行环境就可以使用。相对于其他的日志框架，JDK自带的日志可谓是鸡肋，无论易用性，功能还是扩展性都要稍逊一筹，所以在商业系统中很少直接使用。
JDK Logging API提供了七个日志级别用来控制输出。这七个级别分别是：
级别 | SEVERE | WARNING | INFO | CONFIG | FINE | FINER | FINEST |
调用方法 | severe() | warning() | info() | config() | fine() | finer() | finest() |
含意 | 严重 | 警告 | 信息 | 配置 | 良好 | 较好 | 最好 |
如果将级别设为info，那么info值钱的低级别信息将不会输出，只有info级别只有的信息会输出，通过控制级别达到控制输出的目的。
1 Logger的使用package com.bes.logging; import java.util.logging.Level;
import java.util.logging.Logger; public class LoggerTest {
private static Loggerlogger = Logger.getLogger("com.bes.logging");
public static void main(String argv[]) {
// Log a FINEtracing message
logger.info("Main running.");
logger.fine("doingstuff");
try {
Thread.currentThread().sleep(1000);// do some work
} catch(Exception ex) {
logger.log(Level.WARNING,"trouble sneezing", ex);
}
logger.fine("done");
}
}
不做任何代码修改和JDK配置修改的话，运行上面的例子，你会发现，控制台只会出现【Main running.】这一句日志。如下问题应该呈现在你的大脑里…
1，【Main running.】以外的日志为什么没有输出？怎么让它们也能够出现？
2，日志中出现的时间、类名、方法名等是从哪里输出的？
3，为什么日志就会出现在控制台？
4，大型的系统可能有很多子模块(可简单理解为有很多包名)，如何对这些子模块进行单独的日志级别控制？
5，扩充：apache那个流行的log4j项目和JDK的logging有联系吗，怎么实现自己的LoggerManager？
带着这些问题，可能你更有兴趣了解一下JDK的logging机制，本章为你分析这个简单模块的机制。
2. Logging 配置
JDK默认的logging配置文件为：$JAVA_HOME/jre/lib/logging.properties，可以使用系统属性java.util.logging.config.file指定相应的配置文件对默认的配置文件进行覆盖，比如， java -Djava.util.logging.config.file=myfile
配置文件中通常包含以下几部分定义：
1， handlers：用逗号分隔每个Handler，这些handler将会被加到root logger中。也就是说即使我们不给其他logger配置handler属性，在输出日志的时候logger会一直找到root logger，从而找到handler进行日志的输入。
2， .level是root logger的日志级别
3， <handler>.xxx是配置具体某个handler的属性，比如java.util.logging.ConsoleHandler.formatter便是为ConsoleHandler配置相应的日志Formatter.
4， logger的配置，所有以[.level]结尾的属性皆被认为是对某个logger的级别的定义，如com.bes.server.level=FINE是给名为[com.bes.server]的logger定义级别为FINE。顺便说下，前边提到过logger的继承关系，如果还有com.bes.server.webcontainer这个logger，且在配置文件中没有定义该logger的任何属性，那么其将会从[com.bes.server]这个logger进行属性继承。除了级别之外，还可以为logger定义handler和useParentHandlers(默认是为true)属性，如com.bes.server.handler=com.bes.test.ServerFileHandler(需要是一个extends java.util.logging.Handler的类)，com.bes.server.useParentHandlers=false(意味着com.bes.server这个logger进行日志输出时，日志仅仅被处理一次，用自己的handler输出，不会传递到父logger的handler)。
以下是JDK配置文件示例
handlers= java.util.logging.FileHandler,java.util.logging.ConsoleHandler .level= INFO java.util.logging.FileHandler.pattern = %h/java%u.log
java.util.logging.FileHandler.limit = 50000
java.util.logging.FileHandler.count = 1
java.util.logging.FileHandler.formatter =java.util.logging.XMLFormatter java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter =java.util.logging.SimpleFormatter com.xyz.foo.level = SEVERE
3. Logging执行原理3.1.Logger的获取
1.首先是调用Logger的如下方法获得一个logger
public static synchronized Logger getLogger(String name) {
LogManager manager =LogManager.getLogManager();
returnmanager.demandLogger(name);
}
2.上面的调用会触发java.util.logging.LoggerManager的类初始化工作，LoggerManager有一个静态化初始化块(这是会先于LoggerManager的构造函数调用的）：
static {
manager = AccessController.doPrivileged(new PrivilegedAction<LogManager>() {
@Override
public LogManager run() {
LogManager mgr = null;
String cname = null;
try {
cname = System.getProperty("java.util.logging.manager");
if (cname != null) {
try {
Class<?> clz = ClassLoader.getSystemClassLoader()
.loadClass(cname);
mgr = (LogManager) clz.newInstance();
} catch (ClassNotFoundException ex) {
Class<?> clz = Thread.currentThread()
.getContextClassLoader().loadClass(cname);
mgr = (LogManager) clz.newInstance();
}
}
} catch (Exception ex) {
System.err.println("Could not load Logmanager \"" + cname + "\"");
ex.printStackTrace();
}
if (mgr == null) {
mgr = new LogManager();
}
return mgr; }
});
}
从静态初始化块中可以看出LoggerManager是可以使用系统属性java.util.logging.manager指定一个继承自java.util.logging.LoggerManager的类进行替换的，比如Tomcat启动脚本中就使用该机制以使用自己的LoggerManager。
不管是JDK默认的java.util.logging.LoggerManager还是自定义的LoggerManager，初始化工作中均会给LoggerManager添加两个logger，一个是名称为””的root logger，且logger级别设置为默认的INFO；另一个是名称为global的全局logger，级别仍然为INFO。
LogManager”类”初始化完成之后就会读取配置文件(默认为$JAVA_HOME/jre/lib/logging.properties)，把配置文件的属性名<->属性值这样的键值对保存在内存中，方便之后初始化logger的时候使用。
3.第1步骤中Logger类发起的getLogger操作将会调用java.util.logging.LoggerManager的如下方法：
Logger demandLogger(String name) {
Logger result =getLogger(name);
if (result == null) {
result = newLogger(name, null);
addLogger(result);
result =getLogger(name);
}
return result;
}
可以看出，LoggerManager首先从现有的logger列表中查找，如果找不到的话，会新建一个looger并加入到列表中。当然很重要的是新建looger之后需要对logger进行初始化，这个初始化详见java.util.logging.LoggerManager#addLogger()方法中，改方法会根据配置文件设置logger的级别以及给logger添加handler等操作。
到此为止logger已经获取到了，你同时也需要知道此时你的logger中已经有级别、handler等重要信息，下面将分析输出日志时的逻辑。
3.2.日志的输出
首先我们通常会调用Logger类下面的方法，传入日志级别以及日志内容。
public void log(Level level, String msg) {
if (!isLoggable(level)) {
return;
}
LogRecord lr = new LogRecord(level, msg);
doLog(lr);
}
该方法可以看出，Logger类首先是进行级别的校验，如果级别校验通过，则会新建一个LogRecord对象，LogRecord中除了日志级别，日志内容之外还会包含调用线程信息，日志时刻等；之后调用doLog(LogRecord lr)方法
private void doLog(LogRecord lr) {
lr.setLoggerName(name);
final 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);
}
doLog(LogRecord lr)方法中设置了ResourceBundle信息(这个与国际化有关)之后便直接调用log(LogRecord record) 方法
public void log(LogRecord record) {
if (!isLoggable(record.getLevel())) {
return;
}
Filter theFilter = filter;
if (theFilter != null && !theFilter.isLoggable(record)) {
return;
} // Post the LogRecord to all our Handlers, and then to
// our parents' handlers, all the way up the tree. 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.useParentHandlers
: logger.getUseParentHandlers(); if (!useParentHdls) {
break;
} logger = isSystemLogger ? logger.parent : logger.getParent();
}
}
很清晰，while循环是重中之重，首先从logger中获取handler，然后分别调用handler的publish(LogRecordrecord)方法。while循环证明了前面提到的会一直把日志委托给父logger处理的说法，当然也证明了可以使用logger的useParentHandlers属性控制日志不进行往上层logger传递的说法。到此为止logger对日志的控制差不多算是完成，接下来的工作就是看handler的了，这里我们以java.util.logging.ConsoleHandler为例说明日志的输出。
public ConsoleHandler() {
sealed = false;
configure();
setOutputStream(System.err);
sealed = true;
}
ConsoleHandler构造函数中除了需要调用自身的configure()方法进行级别、filter、formatter等的设置之外，最重要的我们最关心的是setOutputStream(System.err)这一句，把系统错误流作为其输出。而ConsoleHandler的publish(LogRecordrecord)是继承自java.util.logging.StreamHandler的，如下所示：
public synchronized void publish(LogRecord record) {
if (!isLoggable(record)) {
return;
}
String msg;
try {
msg = getFormatter().format(record);
} catch (Exception ex) {
// We don't want to throw an exception here, but we
// report the exception to any registered ErrorManager.
reportError(null, ex, ErrorManager.FORMAT_FAILURE);
return;
} try {
if (!doneHeader) {
writer.write(getFormatter().getHead(this));
doneHeader = true;
}
writer.write(msg);
} catch (Exception ex) {
// We don't want to throw an exception here, but we
// report the exception to any registered ErrorManager.
reportError(null, ex, ErrorManager.WRITE_FAILURE);
}
}
方法逻辑也很清晰，首先是调用Formatter对消息进行格式化，说明一下：格式化其实是进行国际化处理的重要契机。然后直接把消息输出到对应的输出流中。需要注意的是handler也会用自己的level和LogRecord中的level进行比较，看是否真正输出日志。
4.总结
至此，整个日志输出过程已经分析完成。我们来解答文章开头的四个问题了。
1，【Main running.】以外的日志为什么没有输出？怎么让它们也能够出现？
这就是JDK默认的logging.properties文件中配置的handler级别和跟级别均为info导致的，如果希望看到FINE级别日志，需要修改logging.properties文件,同时进行如下两个修改
java.util.logging.ConsoleHandler.level= FINE//修改
com.bes.logging.level=FINE//添加
2，日志中出现的时间、类名、方法名等是从哪里输出的？
请参照[java.util.logging.ConsoleHandler.formatter= java.util.logging.SimpleFormatter]配置中指定的java.util.logging.SimpleFormatter类，其publicsynchronized String format(LogRecord record) 方法说明了一切。
public synchronized String format(LogRecord record) {
dat.setTime(record.getMillis());
String source;
if (record.getSourceClassName() != null) {
source = record.getSourceClassName();
if (record.getSourceMethodName() != null) {
source += " " + record.getSourceMethodName();
}
} else {
source = record.getLoggerName();
}
String message = formatMessage(record);
String throwable = "";
if (record.getThrown() != null) {
StringWriter sw = new StringWriter();
PrintWriter pw = new PrintWriter(sw);
pw.println();
record.getThrown().printStackTrace(pw);
pw.close();
throwable = sw.toString();
}
return String.format(format,
dat,
source,
record.getLoggerName(),
record.getLevel().getLocalizedLevelName(),
message,
throwable);
}
3，为什么日志就会出现在控制台？
看到java.util.logging.ConsoleHandler 类构造方法中的[setOutputStream(System.err)]语句，相信你已经明白。
4，大型的系统可能有很多子模块(可简单理解为有很多包名)，如何对这些子模块进行单独的日志级别控制？
在logging.properties文件中分别对各个logger的级别进行定义，且最好使用java.util.logging.config.file属性指定自己的配置文件。
第5个问题暂时还解答不了，请继续期待，在后面的博文将讲述log4j和JDK logging的关系，以及怎么实现自己的LoggerManager以使得我们完全定制化logger、handler、formatter，掌控日志的国际化信息等。
package com.bes.logging; import java.util.logging.Level;
import java.util.logging.Logger; public class LoggerTest {
private static Loggerlogger = Logger.getLogger("com.bes.logging");
public static void main(String argv[]) {
// Log a FINEtracing message
logger.info("Main running.");
logger.fine("doingstuff");
try {
Thread.currentThread().sleep(1000);// do some work
} catch(Exception ex) {
logger.log(Level.WARNING,"trouble sneezing", ex);
}
logger.fine("done");
}
}
不做任何代码修改和JDK配置修改的话，运行上面的例子，你会发现，控制台只会出现【Main running.】这一句日志。如下问题应该呈现在你的大脑里…
1，【Main running.】以外的日志为什么没有输出？怎么让它们也能够出现？
2，日志中出现的时间、类名、方法名等是从哪里输出的？
3，为什么日志就会出现在控制台？
4，大型的系统可能有很多子模块(可简单理解为有很多包名)，如何对这些子模块进行单独的日志级别控制？
5，扩充：apache那个流行的log4j项目和JDK的logging有联系吗，怎么实现自己的LoggerManager？
带着这些问题，可能你更有兴趣了解一下JDK的logging机制，本章为你分析这个简单模块的机制。
2. Logging 配置
JDK默认的logging配置文件为：$JAVA_HOME/jre/lib/logging.properties，可以使用系统属性java.util.logging.config.file指定相应的配置文件对默认的配置文件进行覆盖，比如， java -Djava.util.logging.config.file=myfile
配置文件中通常包含以下几部分定义：
1， handlers：用逗号分隔每个Handler，这些handler将会被加到root logger中。也就是说即使我们不给其他logger配置handler属性，在输出日志的时候logger会一直找到root logger，从而找到handler进行日志的输入。
2， .level是root logger的日志级别
3， <handler>.xxx是配置具体某个handler的属性，比如java.util.logging.ConsoleHandler.formatter便是为ConsoleHandler配置相应的日志Formatter.
4， logger的配置，所有以[.level]结尾的属性皆被认为是对某个logger的级别的定义，如com.bes.server.level=FINE是给名为[com.bes.server]的logger定义级别为FINE。顺便说下，前边提到过logger的继承关系，如果还有com.bes.server.webcontainer这个logger，且在配置文件中没有定义该logger的任何属性，那么其将会从[com.bes.server]这个logger进行属性继承。除了级别之外，还可以为logger定义handler和useParentHandlers(默认是为true)属性，如com.bes.server.handler=com.bes.test.ServerFileHandler(需要是一个extends java.util.logging.Handler的类)，com.bes.server.useParentHandlers=false(意味着com.bes.server这个logger进行日志输出时，日志仅仅被处理一次，用自己的handler输出，不会传递到父logger的handler)。
以下是JDK配置文件示例
handlers= java.util.logging.FileHandler,java.util.logging.ConsoleHandler .level= INFO java.util.logging.FileHandler.pattern = %h/java%u.log
java.util.logging.FileHandler.limit = 50000
java.util.logging.FileHandler.count = 1
java.util.logging.FileHandler.formatter =java.util.logging.XMLFormatter java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter =java.util.logging.SimpleFormatter com.xyz.foo.level = SEVERE
3. Logging执行原理3.1.Logger的获取
1.首先是调用Logger的如下方法获得一个logger
public static synchronized Logger getLogger(String name) {
LogManager manager =LogManager.getLogManager();
returnmanager.demandLogger(name);
}
2.上面的调用会触发java.util.logging.LoggerManager的类初始化工作，LoggerManager有一个静态化初始化块(这是会先于LoggerManager的构造函数调用的）：
static {
manager = AccessController.doPrivileged(new PrivilegedAction<LogManager>() {
@Override
public LogManager run() {
LogManager mgr = null;
String cname = null;
try {
cname = System.getProperty("java.util.logging.manager");
if (cname != null) {
try {
Class<?> clz = ClassLoader.getSystemClassLoader()
.loadClass(cname);
mgr = (LogManager) clz.newInstance();
} catch (ClassNotFoundException ex) {
Class<?> clz = Thread.currentThread()
.getContextClassLoader().loadClass(cname);
mgr = (LogManager) clz.newInstance();
}
}
} catch (Exception ex) {
System.err.println("Could not load Logmanager \"" + cname + "\"");
ex.printStackTrace();
}
if (mgr == null) {
mgr = new LogManager();
}
return mgr; }
});
}
从静态初始化块中可以看出LoggerManager是可以使用系统属性java.util.logging.manager指定一个继承自java.util.logging.LoggerManager的类进行替换的，比如Tomcat启动脚本中就使用该机制以使用自己的LoggerManager。
不管是JDK默认的java.util.logging.LoggerManager还是自定义的LoggerManager，初始化工作中均会给LoggerManager添加两个logger，一个是名称为””的root logger，且logger级别设置为默认的INFO；另一个是名称为global的全局logger，级别仍然为INFO。
LogManager”类”初始化完成之后就会读取配置文件(默认为$JAVA_HOME/jre/lib/logging.properties)，把配置文件的属性名<->属性值这样的键值对保存在内存中，方便之后初始化logger的时候使用。
3.第1步骤中Logger类发起的getLogger操作将会调用java.util.logging.LoggerManager的如下方法：
Logger demandLogger(String name) {
Logger result =getLogger(name);
if (result == null) {
result = newLogger(name, null);
addLogger(result);
result =getLogger(name);
}
return result;
}
可以看出，LoggerManager首先从现有的logger列表中查找，如果找不到的话，会新建一个looger并加入到列表中。当然很重要的是新建looger之后需要对logger进行初始化，这个初始化详见java.util.logging.LoggerManager#addLogger()方法中，改方法会根据配置文件设置logger的级别以及给logger添加handler等操作。
到此为止logger已经获取到了，你同时也需要知道此时你的logger中已经有级别、handler等重要信息，下面将分析输出日志时的逻辑。
3.2.日志的输出
首先我们通常会调用Logger类下面的方法，传入日志级别以及日志内容。
public void log(Level level, String msg) {
if (!isLoggable(level)) {
return;
}
LogRecord lr = new LogRecord(level, msg);
doLog(lr);
}
该方法可以看出，Logger类首先是进行级别的校验，如果级别校验通过，则会新建一个LogRecord对象，LogRecord中除了日志级别，日志内容之外还会包含调用线程信息，日志时刻等；之后调用doLog(LogRecord lr)方法
private void doLog(LogRecord lr) {
lr.setLoggerName(name);
final 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);
}
doLog(LogRecord lr)方法中设置了ResourceBundle信息(这个与国际化有关)之后便直接调用log(LogRecord record) 方法
public void log(LogRecord record) {
if (!isLoggable(record.getLevel())) {
return;
}
Filter theFilter = filter;
if (theFilter != null && !theFilter.isLoggable(record)) {
return;
} // Post the LogRecord to all our Handlers, and then to
// our parents' handlers, all the way up the tree. 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.useParentHandlers
: logger.getUseParentHandlers(); if (!useParentHdls) {
break;
} logger = isSystemLogger ? logger.parent : logger.getParent();
}
}
很清晰，while循环是重中之重，首先从logger中获取handler，然后分别调用handler的publish(LogRecordrecord)方法。while循环证明了前面提到的会一直把日志委托给父logger处理的说法，当然也证明了可以使用logger的useParentHandlers属性控制日志不进行往上层logger传递的说法。到此为止logger对日志的控制差不多算是完成，接下来的工作就是看handler的了，这里我们以java.util.logging.ConsoleHandler为例说明日志的输出。
public ConsoleHandler() {
sealed = false;
configure();
setOutputStream(System.err);
sealed = true;
}
ConsoleHandler构造函数中除了需要调用自身的configure()方法进行级别、filter、formatter等的设置之外，最重要的我们最关心的是setOutputStream(System.err)这一句，把系统错误流作为其输出。而ConsoleHandler的publish(LogRecordrecord)是继承自java.util.logging.StreamHandler的，如下所示：
public synchronized void publish(LogRecord record) {
if (!isLoggable(record)) {
return;
}
String msg;
try {
msg = getFormatter().format(record);
} catch (Exception ex) {
// We don't want to throw an exception here, but we
// report the exception to any registered ErrorManager.
reportError(null, ex, ErrorManager.FORMAT_FAILURE);
return;
} try {
if (!doneHeader) {
writer.write(getFormatter().getHead(this));
doneHeader = true;
}
writer.write(msg);
} catch (Exception ex) {
// We don't want to throw an exception here, but we
// report the exception to any registered ErrorManager.
reportError(null, ex, ErrorManager.WRITE_FAILURE);
}
}
方法逻辑也很清晰，首先是调用Formatter对消息进行格式化，说明一下：格式化其实是进行国际化处理的重要契机。然后直接把消息输出到对应的输出流中。需要注意的是handler也会用自己的level和LogRecord中的level进行比较，看是否真正输出日志。
4.总结
至此，整个日志输出过程已经分析完成。我们来解答文章开头的四个问题了。
1，【Main running.】以外的日志为什么没有输出？怎么让它们也能够出现？
这就是JDK默认的logging.properties文件中配置的handler级别和跟级别均为info导致的，如果希望看到FINE级别日志，需要修改logging.properties文件,同时进行如下两个修改
java.util.logging.ConsoleHandler.level= FINE//修改
com.bes.logging.level=FINE//添加
2，日志中出现的时间、类名、方法名等是从哪里输出的？
请参照[java.util.logging.ConsoleHandler.formatter= java.util.logging.SimpleFormatter]配置中指定的java.util.logging.SimpleFormatter类，其publicsynchronized String format(LogRecord record) 方法说明了一切。
public synchronized String format(LogRecord record) {
dat.setTime(record.getMillis());
String source;
if (record.getSourceClassName() != null) {
source = record.getSourceClassName();
if (record.getSourceMethodName() != null) {
source += " " + record.getSourceMethodName();
}
} else {
source = record.getLoggerName();
}
String message = formatMessage(record);
String throwable = "";
if (record.getThrown() != null) {
StringWriter sw = new StringWriter();
PrintWriter pw = new PrintWriter(sw);
pw.println();
record.getThrown().printStackTrace(pw);
pw.close();
throwable = sw.toString();
}
return String.format(format,
dat,
source,
record.getLoggerName(),
record.getLevel().getLocalizedLevelName(),
message,
throwable);
}
3，为什么日志就会出现在控制台？
看到java.util.logging.ConsoleHandler 类构造方法中的[setOutputStream(System.err)]语句，相信你已经明白。
4，大型的系统可能有很多子模块(可简单理解为有很多包名)，如何对这些子模块进行单独的日志级别控制？
在logging.properties文件中分别对各个logger的级别进行定义，且最好使用java.util.logging.config.file属性指定自己的配置文件。
第5个问题暂时还解答不了，请继续期待，在后面的博文将讲述log4j和JDK logging的关系，以及怎么实现自己的LoggerManager以使得我们完全定制化logger、handler、formatter，掌控日志的国际化信息等。
