日志框架--JDK Logging

Posted 2020-10-19 hxwang

前言

   从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，掌控日志的国际化信息等。