How to deal with the java underlying JDK Logging module

Start with examples

The use of JDK Logging is very simple. As shown in the following code, you can first use the static method getLogger of the Logger class to get a logger, and then you can use the obtained logger anywhere. Make log entry. For example, calls like logger.info("Main running.").

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");
      }
}

If you run the above example without making any code modifications or JDK configuration modifications, you will find that only the log [Main running.] will appear on the console. The following questions should appear in your brain...

1. Why are there no output logs other than [Main running.]? How to make them appear?

2. Where are the time, class name, method name, etc. that appear in the log output?

3. Why does the log appear on the console?

4. A large system may have many sub-modules (which can be simply understood as having many package names). How to control the log levels of these sub-modules individually?

5, Expansion: Is the popular log4j project of apache related to JDK logging? How to implement your own LoggerManager?

With these questions, you may be more interested in learning about the logging mechanism of JDK. This chapter will analyze the mechanism of this simple module for you.

Terminology Answer

Before in-depth analysis, you need to master the following terms

logger: For logger, you need to know the following aspects

1, Logger will be used wherever the code needs to input logs. This is almost a spokesperson for the JDK logging module. We often use Logger.getLogger("com.aaa.bbb"); to obtain a logger, and then use logger to do Log output.

2, logger is actually just a logical management unit, and most of its operations just serve as a relay to pass other "roles". For example: the call to Logger.getLogger("xxx") will Relying on the LogManager class, when using the logger to input log information, all handlers in the logger will be called to input the log.

3. Logger has a hierarchical relationship. We can generally understand it as the parent-child inheritance relationship between package names. Each logger is usually named after the java package name. Child loggers usually inherit the logger level, handler, ResourceBundle name (related to internationalization information), etc. from the parent logger.

4, there will be a root logger with an empty name in the entire JVM, and all anonymous loggers will regard the root logger as their parent

LogManager: All loggers within the entire JVM Management, logger generation, acquisition and other operations all depend on it, including the reading of configuration files. There will be a Hashtable [private Hashtable35bf2dffdda6a7e3e41e02bf88c5368c> loggers] in the LogManager to store all current loggers. If you need to obtain the logger, if there is already a logger in the Hashtable, it will be returned directly to the Hashtable. If the hashtable If there is no logger, create a new one and put it into the Hashtable for saving.

Handler: Used to control log output. For example, the ConsoleHanlder that comes with the JDK redirects the output stream to System.err output. The Handler will be called every time the Logger method is called for output. publish method, each logger has multiple handlers. We can use handlers to input logs to different places (such as file systems or remote Socket connections).

Formatter: The logs need to be formatted before they are actually output: for example Do you want to output the time? Time format? Do you want to enter a thread name? Whether to use internationalization information etc. depends on Formatter.

Log Level: Needless to say, this is the one that is easy to understand, and it is also why logging can help us adapt to the different needs for log output granularity in different stages from development and debugging to deployment and online. The JDK Log levels from high to low are OFF(231-1)—>SEVERE(1000)—>WARNING(900)—>INFO(800)—>CONFIG(700)—> FINE(500)—>FINER(400)—>FINEST(300)—>ALL(-231). Each level corresponds to a number. The comparison of levels when outputting logs depends on the size of the number. Compare. But it should be noted that not only loggers have levels, handlers also have levels. That is to say, if a logger level is FINE and the customer wants to input FINE level logs, if the handler level corresponding to the logger is INFO, then the FINE level Logs still cannot be output.

Summary of the corresponding relationship

LogManager and logger have a 1-to-many relationship. There is only one LogManager when the entire JVM is running, and all loggers are in LogManager.

Logger and handler are Many-to-many relationship, the logger will call all handlers for log processing when outputting logs

The handler and the formatter are in a one-to-one relationship, and a handler has a formatter to format the log

Obviously: there is a one-to-one relationship between logger and level, and there is also a one-to-one relationship between hanlder and level

Logging configuration:

The default logging configuration file of JDK is: $JAVA_HOME/jre /lib/logging.properties, you can use the system property java.util.logging.config.file to specify the corresponding configuration file to overwrite the default configuration file. The configuration file usually contains the following definitions:

1，  handlers：用逗号分隔每个Handler，这些handler将会被加到root logger中。也就是说即使我们不给其他logger配置handler属性，在输出日志的时候logger会一直找到root logger，从而找到handler进行日志的输入。

2，  .level是root logger的日志级别

3，  0827ab9817f5e2ad2bd92ebb7f6baa6b.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
sun.rmi.transport.tcp.logLevel = FINE

Logging执行原理

Logger的获取

A，首先是调用Logger的如下方法获得一个logger

    public static synchronized Logger getLogger(String name) {
           LogManager manager =LogManager.getLogManager();
        returnmanager.demandLogger(name);
    }

B,上面的调用会触发java.util.logging.LoggerManager的类初始化工作，LoggerManager有一个静态化初始化块(这是会先于LoggerManager的构造函数调用的~_~)：

static {
   AccessController.doPrivileged(newPrivilegedAction<Object>() {
       public Object run() {
           String cname =null;
           try {
               cname =System.getProperty("java.util.logging.manager");
               if (cname !=null) {
                  try {
                       Class clz =ClassLoader.getSystemClassLoader().loadClass(cname);
                       manager= (LogManager) clz.newInstance();
                   } catch(ClassNotFoundException ex) {
               Class clz =Thread.currentThread().getContextClassLoader().loadClass(cname);
                      manager= (LogManager) clz.newInstance();
                   }
               }
           } catch (Exceptionex) {
              System.err.println("Could not load Logmanager \"" + cname+ "\"");
              ex.printStackTrace();
           }
           if (manager ==null) {
               manager = newLogManager();
           }
      
           manager.rootLogger= manager.new RootLogger();
          manager.addLogger(manager.rootLogger);
 
           Logger.global.setLogManager(manager);
          manager.addLogger(Logger.global);
 
           return null;
       }
   });
}

从静态初始化块中可以看出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)，把配置文件的属性名e09be6022d700e04aeaa85a5f42fdcb2属性值这样的键值对保存在内存中，方便之后初始化logger的时候使用。

C,A步骤中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等重要信息，下面将分析输出日志时的逻辑。 

日志的输出

首先我们通常会调用Logger类下面的方法，传入日志级别以及日志内容。

    public void log(Levellevel, String msg) {
          if (level.intValue() < levelValue ||levelValue == offValue) {
              return;
          }
          LogRecord lr = new LogRecord(level, msg);
          doLog(lr);
    }

该方法可以看出，Logger类首先是进行级别的校验，如果级别校验通过，则会新建一个LogRecord对象，LogRecord中除了日志级别，日志内容之外还会包含调用线程信息，日志时刻等；之后调用doLog(LogRecord lr)方法

    private void doLog(LogRecord lr) {
          lr.setLoggerName(name);
          String ebname =getEffectiveResourceBundleName();
          if (ebname != null) {
              lr.setResourceBundleName(ebname);
              lr.setResourceBundle(findResourceBundle(ebname));
          }
          log(lr);
    }

doLog(LogRecord lr)方法中设置了ResourceBundle信息(这个与国际化有关)之后便直接调用log(LogRecord record) 方法 

   public void log(LogRecord record) {
          if (record.getLevel().intValue() <levelValue || levelValue == offValue) {
              return;
          }
          synchronized (this) {
              if (filter != null &&!filter.isLoggable(record)) {
                  return;
              }
          }
          Logger logger = this;
          while (logger != null) {
              Handler targets[] = logger.getHandlers();
              if(targets != null) {
                  for (int i = 0; i < targets.length; i++){
                           targets[i].publish(record);
                       }
              }
              if(!logger.getUseParentHandlers()) {
                       break;
              }
              logger= logger.getParent();
          }
    }

很清晰，while循环是重中之重，首先从logger中获取handler，然后分别调用handler的publish(LogRecordrecord)方法。while循环证明了前面提到的会一直把日志委托给父logger处理的说法，当然也证明了可以使用logger的useParentHandlers属性控制日志不进行往上层logger传递的说法。到此为止logger对日志的控制差不多算是完成，接下来的工作就是看handler的了，这里我们以java.util.logging.ConsoleHandler为例说明日志的输出。

public class ConsoleHandler extends StreamHandler {
    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 tothrow an exception here, but we
           // report theexception 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 tothrow an exception here, but we
           // report theexception to any registered ErrorManager.
           reportError(null,ex, ErrorManager.WRITE_FAILURE);
       }
    }

方法逻辑也很清晰，首先是调用Formatter对消息进行格式化，说明一下：格式化其实是进行国际化处理的重要契机。然后直接把消息输出到对应的输出流中。需要注意的是handler也会用自己的level和LogRecord中的level进行比较，看是否真正输出日志。

 总结

至此，整个日志输出过程已经分析完成。细心的读者应该可以解答如下四个问题了。

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) { StringBuffer sb = new StringBuffer(); // Minimize memory allocations here. dat.setTime(record.getMillis()); args[0] = dat; StringBuffer text = new StringBuffer(); if (formatter == null) { formatter = new MessageFormat(format); } formatter.format(args, text, null); sb.append(text); sb.append(" "); if (record.getSourceClassName() != null) { sb.append(record.getSourceClassName()); } else { sb.append(record.getLoggerName()); } if (record.getSourceMethodName() != null) { sb.append(" "); sb.append(record.getSourceMethodName()); } sb.append(lineSeparator); String message = formatMessage(record); sb.append(record.getLevel().getLocalizedName()); sb.append(": "); sb.append(message); sb.append(lineSeparator); if (record.getThrown() != null) { try { StringWriter sw = newStringWriter(); PrintWriter pw = newPrintWriter(sw); record.getThrown().printStackTrace(pw); pw.close(); sb.append(sw.toString()); } catch (Exception ex) { } } return sb.toString();}public synchronized String format(LogRecord record) {
    StringBuffer sb = new StringBuffer();
    // Minimize memory allocations here.
    dat.setTime(record.getMillis());
    args[0] = dat;
    StringBuffer text = new StringBuffer();
    if (formatter == null) {
        formatter = new MessageFormat(format);
    }
    formatter.format(args, text, null);
    sb.append(text);
    sb.append(" ");
    if (record.getSourceClassName() != null) {     
        sb.append(record.getSourceClassName());
    } else {
        sb.append(record.getLoggerName());
    }
    if (record.getSourceMethodName() != null) {
        sb.append(" ");
       sb.append(record.getSourceMethodName());
    }
    sb.append(lineSeparator);
    String message = formatMessage(record);
   sb.append(record.getLevel().getLocalizedName());
    sb.append(": ");
    sb.append(message);
    sb.append(lineSeparator);
    if (record.getThrown() != null) {
        try {
            StringWriter sw = newStringWriter();
            PrintWriter pw = newPrintWriter(sw);
           record.getThrown().printStackTrace(pw);
            pw.close();
             sb.append(sw.toString());
        } catch (Exception ex) {
        }
    }
    return sb.toString();
}

3，为什么日志就会出现在控制台？

    看到java.util.logging.ConsoleHandler 类构造方法中的[setOutputStream(System.err)]语句，相信你已经明白。

4，大型的系统可能有很多子模块(可简单理解为有很多包名)，如何对这些子模块进行单独的日志级别控制？

    在logging.properties文件中分别对各个logger的级别进行定义，且最好使用java.util.logging.config.file属性指定自己的配置文件。

The above is the detailed content of How to deal with the java underlying JDK Logging module. For more information, please follow other related articles on the PHP Chinese website!