zhouinfo

log日志 JDK Logging

发布 : 2020-08-19 分类 : java 浏览 :

log日志 JDK Logging

JDK logging机制。

JDK Logging的使用很简单，先使用Logger类的静态方法getLogger就可以获取到一个logger，然后在任何地方都可以通过获取到的logger进行日志输入。

示例

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
package site.zhouinfo;
import java.util.logging.Logger;

public class JdkLogging {
	private final static Logger log = Logger.getLogger(JdkLogging.class.getName());
	public static void main(String[] args) {
		log.severe("jdk logger severe");
		log.warning("jdk logger warning");
		log.info("jdk logger info");
		log.config("jdk logger config");
		log.fine("jdk logger fine");
		log.finer("jdk logger finer");
		log.finest("jdk logger finest");
	}
}

执行结果

1
2
3
4
5
6
八月 19, 2020 5:02:46 下午 site.zhouinfo.JdkLogging main
严重: jdk logger severe
八月 19, 2020 5:02:46 下午 site.zhouinfo.JdkLogging main
警告: jdk logger warning
八月 19, 2020 5:02:46 下午 site.zhouinfo.JdkLogging main
信息: jdk logger info

JDK 日志类

Logger

  1. 代码需要输入日志的地方都会用到Logger，这几乎是一个JDK logging模块的代言人，我们常常用Logger.getLogger(类名.class.getName())获得一个logger，然后使用logger做日志的输出。
  2. logger其实只是一个逻辑管理单元，其多数操作都只是作为一个中继者传递别的<角色>，比如说：Logger.getLogger(“xxx”)的调用将会依赖于LogManager类，使用logger输入日志信息的时候会调用logger中的所有handler进行日志的输入。
  3. logger是有层次关系的，我们可一般性的理解为包名之间的父子继承关系。每个logger通常以java包名为其名称。子logger通常会从父logger继承logger级别、handler、ResourceBundle名(与国际化信息有关)等。
  4. 整个JVM会存在一个名称为空的root logger，所有匿名的logger都会把root logger作为其父

LogManager

整个JVM内部所有logger的管理，logger的生成、获取等操作都依赖于它，也包括配置文件的读取。LogManager中会有一个HashTable private HashTable<String,WeakReference<Logger>> loggers 用于存储目前所有的logger，如果需要获取logger的时候，HashTable已经有存在logger的话就直接返回HashTable中的，如果HashTable中没有logger，则新建一个同时放入HashTable进行保存。

Handler

用来控制日志输出的，比如JDK自带的ConsoleHandler把输出流重定向到System.err输出，每次调用Logger的方法进行输出时都会调用Handler的publish方法，每个logger有多个handler。我们可以利用handler来把日志输入到不同的地方(比如文件系统或者是远程Socket连接).

Formatter

日志在真正输出前需要进行一定的格式话：比如是否输出时间？时间格式？是否输入线程名？是否使用国际化信息等都依赖于Formatter。

Log Level

不必说，这是做容易理解的一个，也是logging为什么能帮助我们适应从开发调试到部署上线等不同阶段对日志输出粒度的不同需求。JDK Log级别从高到低为OFF(231-1)—>SEVERE(1000)—>WARNING(900)—>INFO(800)—>CONFIG(700)—>FINE(500)—>FINER(400)—>FINEST(300)—>ALL(-231)，每个级别分别对应一个数字，输出日志时级别的比较就依赖于数字大小的比较。但是需要注意的是：不仅是logger具有级别，handler也是有级别，也就是说如果某个logger级别是FINE，客户希望输入FINE级别的日志，如果此时logger对应的handler级别为INFO，那么FINE级别日志仍然是不能输出的。

总结对应关系：

  • LogManager与logger是1对多关系，整个JVM运行时只有一个LogManager，且所有的logger均在LogManager中
  • logger与handler是多对多关系，logger在进行日志输出的时候会调用所有的hanlder进行日志的处理
  • handler与formatter是一对一关系，一个handler有一个formatter进行日志的格式化处理
  • logger与level是一对一关系
  • hanlder与level也是一对一关系

Logging配置：

JDK默认的logging配置文件为：$JAVA_HOME/jre/lib/logging.properties，可以使用系统属性java.util.logging.config.file指定相应的配置文件对默认的配置文件进行覆盖，配置文件中通常包含以下几部分定义：

  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的级别的定义，如site.zhouinfo.level=FINE是给名为site.zhouinfo的logger定义级别为FINE。顺便说下，前边提到过logger的继承关系，如果还有site.zhouinfo.log这个logger，且在配置文件中没有定义该logger的任何属性，那么其将会从site.zhouinfo这个logger进行属性继承。除了级别之外，还可以为logger定义handler和useParentHandlers(默认是为true)属性，如site.zhouinfo.handler=site.zhouinfo.log.ServerFileHandler(需要是一个extends java.util.logging.Handler的类)，site.zhouinfo.useParentHandlers=false(意味着site.zhouinfo这个logger进行日志输出时，日志仅仅被处理一次，用自己的handler输出，不会传递到父logger的handler)。以下是JDK配置文件示例
1
2
3
4
5
6
7
8
9
10
11
12
13
14
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
 
site.zhouinfo.level = SEVERE
sun.rmi.transport.tcp.logLevel = FINE

Logging执行原理

Logger的获取

  1. 首先是调用Logger的如下方法获得一个logger
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    @CallerSensitive
    public static Logger getLogger(String name) {
        return demandLogger(name, null, Reflection.getCallerClass());
    }

    private static Logger demandLogger(String name, String resourceBundleName, Class<?> caller) {
        LogManager manager = LogManager.getLogManager();
        SecurityManager sm = System.getSecurityManager();
        if (sm != null && !LoggerHelper.disableCallerCheck) {
            if (caller.getClassLoader() == null) {
                return manager.demandSystemLogger(name, resourceBundleName);
            }
        }
        return manager.demandLogger(name, resourceBundleName, caller);
    }
  2. 上面的调用会触发java.util.logging.LoggerManager的类初始化工作，LoggerManager有一个静态化初始化块(这是会先于LoggerManager的构造函数调用)：
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    22
    23
    24
    25
    26
    27
    28
    29
    30
    31
    32
    33
    34
    35
    36
    37
    38
    39
    40
    41
    42
    43
    44
    45
    46
    47
    48
    49
    static {
        AccessController.doPrivileged(new PrivilegedAction<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 (Exception ex) {
                        System.err.println("Could not load Logmanager \"" + cname + "\"");
                        ex.printStackTrace();
                    }
                    if (manager == null) {
                        manager = new LogManager();
                    }

                    // Create and retain Logger for the root of the namespace.
                    manager.rootLogger = manager.new RootLogger();
                    // since by design the global manager's userContext and
                    // systemContext don't have their requiresDefaultLoggers
                    // flag set - we make sure to add the root logger to
                    // the global manager's default contexts here.
                    manager.addLogger(manager.rootLogger);
                    manager.systemContext.addLocalLogger(manager.rootLogger, false);
                    manager.userContext.addLocalLogger(manager.rootLogger, false);

                    // Adding the global Logger. Doing so in the Logger.<clinit>
                    // would deadlock with the LogManager.<clinit>.
                    Logger.global.setLogManager(manager);
                    // Make sure the global logger will be registered in the
                    // global manager's default contexts.
                    manager.addLogger(Logger.global);
                    manager.systemContext.addLocalLogger(Logger.global, false);
                    manager.userContext.addLocalLogger(Logger.global, false);

                    // We don't call readConfiguration() here, as we may be running
                    // very early in the JVM startup sequence.  Instead readConfiguration
                    // will be called lazily in getLogManager().
                    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)，把配置文件的属性名<->属性值这样的键值对保存在内存中，方便之后初始化logger的时候使用。
  1. 1步骤中Logger类发起的getLogger操作将会调用java.util.logging.LoggerManager的如下方法：
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    Logger demandLogger(String name, String resourceBundleName, Class<?> caller) {
        Logger result = getLogger(name);
        if (result == null) {
            Logger newLogger = new Logger(name, resourceBundleName, caller, false);
            do {
                if (addLogger(newLogger)) {
                   return newLogger;
                }
                result = getLogger(name);
            } while (result == null);
        }
        return result;
    }
  • 可以看出，LoggerManager首先从现有的logger列表中查找，如果找不到的话，会新建一个logger并加入到列表中。当然很重要的是新建looger之后需要对logger进行初始化，这个初始化详见java.util.logging.LoggerManager#addLogger()方法中，改方法会根据配置文件设置logger的级别以及给logger添加handler等操作。

到此为止logger已经获取到了，你同时也需要知道此时你的logger中已经有级别、handler等重要信息，下面将分析输出日志时的逻辑。

日志的输出

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

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
public void info(String msg) {
    if (Level.INFO.intValue() < levelValue) {
        return;
    }
    log(Level.INFO, msg);
}

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


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

之后调用doLog(LogRecord lr)方法

1
2
3
4
5
6
7
8
9
10
private void doLog(LogRecord lr) {
    lr.setLoggerName(name);
    String ebname = getEffectiveResourceBundleName();
    if (ebname != null && !ebname.equals(SYSTEM_LOGGER_RB_NAME)) {
        lr.setResourceBundleName(ebname);
        lr.setResourceBundle(findResourceBundle(ebname, true));
    }
    log(lr);
}

  • doLog(LogRecord lr)方法中设置了ResourceBundle信息(这个与国际化有关)

之后便直接调用log(LogRecord record) 方法 

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
public void log(LogRecord record) {
    if (record.getLevel().intValue() < levelValue || levelValue == offValue) {
        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(LogRecord record)方法。while循环证明了前面提到的会一直把日志委托给父logger处理的说法，当然也证明了可以使用logger的useParentHandlers属性控制日志不进行往上层logger传递的说法。

到此为止logger对日志的控制差不多算是完成，接下来的工作就是看handler的了，这里我们以java.util.logging.ConsoleHandler为例说明日志的输出。

1
2
3
4
5
6
public ConsoleHandler() {
    sealed = false;
    configure();
    setOutputStream(System.err);
    sealed = true;
}
  • ConsoleHandler构造函数中除了需要调用自身的configure()方法进行级别、filter、formatter等的设置之外，最重要的我们最关心的是setOutputStream(System.err)这一句，把系统错误流作为其输出。

ConsoleHandler的publish(LogRecord record)是继承自java.util.logging.StreamHandler的，如下所示：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
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进行比较，看是否真正输出日志。

总结

1. 日志为什么有些没有输出？怎么让它们也能够出现？

这就是JDK默认的logging.properties文件中配置的handler级别和跟级别均为info导致的，如果希望看到FINE级别日志，需要修改logging.properties文件,同时进行如下两个修改

1
2
java.util.logging.ConsoleHandler.level= FINE//修改
site.zhouinfo.level=FINE//添加

2. 日志中出现的时间、类名、方法名等是从哪里输出的？

请参照java.util.logging.ConsoleHandler.formatter= java.util.logging.SimpleFormatter配置中指定的java.util.logging.SimpleFormatter类，其public synchronized String format(LogRecord record)方法说明了一切。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
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);
    }

    public synchronized String formatMessage(LogRecord record) {
        String format = record.getMessage();
        java.util.ResourceBundle catalog = record.getResourceBundle();
        if (catalog != null) {
            try {
                format = catalog.getString(record.getMessage());
            } catch (java.util.MissingResourceException ex) {
                format = record.getMessage();
            }
        }
        try {
            Object parameters[] = record.getParameters();
            if (parameters == null || parameters.length == 0) {
                return format;
            }
            // Is it a java.text style format?
            // Ideally we could match with
            // Pattern.compile("\\{\\d").matcher(format).find())
            // However the cost is 14% higher, so we cheaply check for
            // 1 of the first 4 parameters
            if (format.indexOf("{0") >= 0 || format.indexOf("{1") >=0 ||
                        format.indexOf("{2") >=0|| format.indexOf("{3") >=0) {
                return java.text.MessageFormat.format(format, parameters);
            }
            return format;

        } catch (Exception ex) {
            // Formatting failed: use localized format string.
            return format;
        }
    }

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

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

1
2
3
4
5
6
public ConsoleHandler() {
    sealed = false;
    configure();
    setOutputStream(System.err);
    sealed = true;
}

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

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

qingkangxu

本文作者 : zhouinfo
原文链接 : http://blog.zhouinfo.site/2020/08/19/log%E6%97%A5%E5%BF%97-JDK-Logging/
版权声明 : 本博客所有文章除特别声明外，均采用 CC Apache License 2.0 许可协议。转载请注明出处！
标签: #java #log
留下足迹