java - 更改日志记录级别后，什么会捕获我的日志文件？

Question

我创建了简单的应用程序来测试 java.util.logging 行为:

 public static void main(String[] args) {
     Logger logger = Logger.getLogger("sample-name");

     logger.log(Level.SEVERE, "SEVERE");
     logger.log(Level.WARNING, "WARNING");
     logger.log(Level.INFO, "INFO");
     logger.log(Level.CONFIG, "CONFIG");
     logger.log(Level.FINE, "FINE");
     logger.log(Level.FINER, "FINE");
     logger.log(Level.FINEST, "FINEST");
 }

并启用日志记录到/usr/lib/jvm/java-11-openjdk/conf/logging.properties中的文件:

handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler

当我在此文件中保留日志记录级别 (.level) INFO 时，它可以工作。我的 user.home 中有一个 java0.log 输出文件，其中包含以下内容:

Aug 29, 2019 4:57:48 PM main.LoggingTester main
SEVERE: SEVERE
Aug 29, 2019 4:57:48 PM main.LoggingTester main
WARNING: WARNING
Aug 29, 2019 4:57:48 PM main.LoggingTester main
INFO: INFO

但是我想在将其更改为ALL后记录所有 - ant，发生了一些奇怪的事情 - 这是输出文件的内容:

Aug 29, 2019 5:00:32 PM com.sun.jna.Native extractFromResourcePath
FINE: Looking in classpath from java.net.URLClassLoader@5305068a for /com/sun/jna/linux-x86-64/libjnidispatch.so
Aug 29, 2019 5:00:32 PM com.sun.jna.Native extractFromResourcePath
FINE: Found library resource at jar:file:/opt/intellij/idea-IC-191.6707.61/lib/jna.jar!/com/sun/jna/linux-x86-64/libjnidispatch.so
Aug 29, 2019 5:00:32 PM com.sun.jna.Native extractFromResourcePath
FINE: Extracting library to /home/iid/.cache/JNA/temp/jna7163336009872108237.tmp
Aug 29, 2019 5:00:32 PM com.sun.jna.Native loadNativeDispatchLibraryFromClasspath
FINE: Trying /home/iid/.cache/JNA/temp/jna7163336009872108237.tmp
Aug 29, 2019 5:00:32 PM com.sun.jna.Native loadNativeDispatchLibraryFromClasspath
FINE: Found jnidispatch at /home/iid/.cache/JNA/temp/jna7163336009872108237.tmp

此外，还会创建java0.log.lock文件。

我猜还有其他东西占用了这个日志并写入它？因为这个设置是全局的。 但是即使我的应用程序结束了它的生命，锁定仍然存在，并且我期望一些其他日志文件，其中实际上也包含我的消息......

Answer 1

What captures my logging file after I change logging level?

第 3 方库 Java Native Access .

But I want to log ALL - ant after changing it to ALL, something weird happen

如果您将logging.properties中的.level更改为ALL，那么您已将ROOT记录器的级别更改为ALL，这意味着所有记录器都将继承该级别并设置为“ALL”，除非明确覆盖该级别。

I guess something else takes this log and writes to it?

任何使用 JUL 的第 3 方库也将开始写入您的日志文件。在这种情况下com.sun.jna.Native .

您最可能想要做的是将日志记录配置更改为:

handlers=java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level=ALL
.level=INFO
sample-name.level=ALL
sample-name.handlers=java.util.logging.FileHandler
java.util.logging.FileHandler.level=ALL

这会将 ROOT 记录器保留为默认设置，并将您的命名空间设置为记录所有级别。

Additionaly, java0.log.lock file is created.

当 FileHandler 打开且未关闭时，就会发生这种情况。最有可能的是，记录器在 LogManager 清理器运行之前被垃圾收集。将您的程序更改为:

private static final Logger logger = Logger.getLogger("sample-name");
public static void main(String[] args) {
    logger.log(Level.SEVERE, "SEVERE");
    logger.log(Level.WARNING, "WARNING");
    logger.log(Level.INFO, "INFO");
    logger.log(Level.CONFIG, "CONFIG");
    logger.log(Level.FINE, "FINE");
    logger.log(Level.FINER, "FINE");
    logger.log(Level.FINEST, "FINEST");
}

强制终止正在运行的 JVM 也会导致悬空的“lck”文件。

1. I think I understand your suggestion, but still - I would like to ask about why it behaves like that, and not how should I change my configuration. I would expect it to put there messages from all my loggers.

为什么在 design docs 中得到解答, API docs以及经常被忽视的java.util.logging bugs 。设置根级别意味着您也可以获得 JVM 记录器，因为它们是根记录器的子级。

handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler 行将 2 个处理程序附加到根记录器。根记录器是所有记录器的父记录器，由空字符串 ""

表示

在运行时，记录器树如下所示:

           "" ->java.util.logging.FileHandler, java.util.logging.ConsoleHandler
           |
         -----------------------
         ^                  ^
         |                  |
    sample-name      com.sun.jna.Native

根据日志记录概述部分1.1 Overview of Control Flow两个子记录器的记录将发送到 parent handlers 。在记录器树中，库记录器和应用程序记录器之间存在很大的区别。

Unless there is a lot of them, and the log file is somehow cut and replaced?

FileHandler defaults are specified in the API docs.默认创建一个日志文件，没有限制。

2. Lock file only appears when the log level is ALL (not the INFO). Does it seem like having something to do with garbage collector?

Lazily created loggers和 garbage collection of loggers当它们没有强有力的引用来阻止它们被GC时，它们会在运行时创建有趣的行为。始终将对记录器的引用保留为静态最终以避免意外。

“.lck”文件仅指示打开的文件处理程序。当处理程序关闭时，.lck' 就会消失。如果 file handler is created or closed 则更改日志级别不会改变。使用 handlers 与 .handlers 意味着 filehandler is created lazily when a log record is published .

...but the problem is my original logging messages disappeared. I would expect any other loggers to sum up into log file, and don't replace.

Follow the tracing and printing instructions in this thread.这将记录正在修改记录器设置的调用者并打印记录器树的状态。

And I still don't get why changing log level results in this lock. I don't explicitly close the handler - in any of those situations.

更改日志记录属性以使用 .handlers 而不是 handlers。无论点处理程序的级别如何，您都应该在运行时看到锁定文件。如果这是正确的，我上面的理论就是正确的。

您不需要显式关闭处理程序，只要它是attached即可。到记录器树。如果显式从记录器中删除处理程序，则该代码负责关闭处理程序。否则，LogManager$Cleaner 将在 JVM 正常关闭时为您关闭处理程序。