Java和通常情况下的日志记录:最佳实践?

84

有时候当我看到我的日志代码时,我会想我是否做得正确。也许没有明确的答案,但我有以下疑虑:

库类

我有几个库类可能会记录一些INFO消息。致命错误则报告为异常。当前我在我的类中使用一个静态的logger实例,并将类名作为日志名称。(Log4j's: Logger.getLogger(MyClass.class))

这是正确的方式吗?也许这个库类的用户不想要从我的实现中收到任何消息,或者希望将其重定向到特定应用程序的日志。我应该允许用户从“外部世界”设置一个logger吗?如何处理这种情况?

通用日志

在某些应用程序中,我的类可能希望将日志消息写入特定的日志,而不是由类名标识。(例如:HTTP请求日志) 如何最好地实现这样的操作?一个查找服务脑海中浮现...

9个回答

46

你的规范相当标准,看起来还不错(在我看来)。

需要注意的一点是,过多的不必要的调试调用会导致内存碎片化,因此,在使用 Log4J(以及大多数其他 Java 日志记录框架)时,最终可能会得到类似以下的代码:

if (log.isDebugEnabled()) {
  log.debug("...");
}

因为构造那个日志信息(你可能并没有使用它)可能会很昂贵,特别是如果要重复执行成千上万次。

你的INFO级别日志不应该太“啰嗦”(从你的说法来看,似乎并不是)。INFO消息应该是有意义和重要的,比如应用程序的启动和停止。这些是在遇到问题时可能需要知道的事情。Debug/fine级别的日志更多地用于诊断实际问题。Debug/fine级别的日志通常只在需要时打开。Info通常一直开启。

如果有人不想从您的类中获取特定的INFO消息,则当然可以更改您的log4j配置以不获取它们。在这方面,Log4j非常简单明了(相对于Java 1.4日志而言)。

至于你提到的HTTP问题,在我的经验中,通常情况下Java日志记录并不会出现这样的问题,因为通常只需要一个类负责你感兴趣的内容,所以你只需要在一个地方进行日志记录。在(我所经历的罕见情况下),如果您想要在看似不相关的类之间共享常见的日志消息,只需插入一些易于搜索的标记即可。


4
提供信息,Scala语言中可以编写一个debug方法,使用按名称传递参数来避免冗长的代码。编译器会自动将debug()参数中的代码转换为仅在debug()决定调用它时才评估的函数。因此,只有在isDebugEnabled()为真时才会连接字符串。下面是实现此功能的示例代码:override def debug(msg: => AnyRef) = if (isDebugEnabled) logger.debug(msg)http://github.com/dpp/liftweb/blob/338119b8d7a76adcb9f45e9aa8a2b946d9c81118/lift-util/src/main/scala/net/liftweb/util/Log.scala - Blair Zajac
8
使用 slf4j 提供的 {}-构造是另一个很好的理由。 - Thorbjørn Ravn Andersen

23
以下是我在所有项目中遵循的指南,以确保良好的性能。我根据互联网上的各种来源形成了这组指南。
截至今天,我认为Log4j 2是Java中记录日志的最佳选择。
基准测试结果可在此处找到。我采用的最佳性能实践如下:
  1. 目前我避免使用SLF4J,原因如下:
  2. 为了提高性能,使用异步日志记录所有常规日志
  3. 使用同步日志记录错误消息,因为我们希望尽快看到错误消息
  4. 不要在常规日志中使用位置信息,例如文件名、类名、方法名、行号,因为为了推导这些信息,框架需要对堆栈进行快照并遍历它。这会影响性能。因此只在错误日志中使用位置信息,而不在常规日志中使用
  5. 为了跟踪由单独线程处理的单个请求,请考虑使用线程上下文和随机UUID,如此处所述
  6. 由于我们在单独的文件中记录错误,因此非常重要的是在错误日志中也记录上下文信息。例如,如果应用程序在处理文件时遇到错误,请在错误日志文件中打印文件名和正在处理的文件记录以及堆栈跟踪
  7. 日志文件应易于理解且可用grep搜索。例如,如果应用程序在多个文件中处理客户记录,则每个日志消息应如下所示:
12:01:00,127 INFO FILE_NAME=file1.txt - Processing starts
12:01:00,127 DEBUG FILE_NAME=file1.txt, CUSTOMER_ID=756
12:01:00,129 INFO FILE_NAME=file1.txt - Processing ends
  1. 使用下面所示的SQL标记记录所有的SQL语句,并使用过滤器启用或禁用它:
private static final Marker sqlMarker = 
  MarkerManager.getMarker("SQL");

private void method1() {
    logger.debug(sqlMarker, "SELECT * FROM EMPLOYEE");
}
  1. 使用Java 8 Lambdas记录所有参数。当给定的日志级别被禁用时,这将节省应用程序格式化消息的时间:
int i=5, j=10;
logger.info("Sample output {}, {}", ()->i, ()->j);
  1. 不要使用字符串拼接。使用参数化消息,如上所示。

  2. 使用动态重新加载日志配置,这样应用程序可以自动重新加载日志配置中的更改,而无需重新启动应用程序。

  3. 不要使用 printStackTrace()System.out.println()

  4. 应用程序在退出之前应关闭记录器:

LogManager.shutdown();
  1. 最后,供大家参考,我使用以下配置:
<?xml version="1.0" encoding="UTF-8"?>
<Configuration monitorinterval="300" status="info" strict="true">
    <Properties>
        <Property name="filePath">${env:LOG_ROOT}/SAMPLE</Property>
        <Property name="filename">${env:LOG_ROOT}/SAMPLE/sample
        </Property>
        <property name="logSize">10 MB</property>
    </Properties>
    <Appenders>
        <RollingFile name="RollingFileRegular" fileName="${filename}.log"
            filePattern="${filePath}/sample-%d{yyyy-dd-MM}-%i.log">
            <Filters>
                <MarkerFilter marker="SQL" onMatch="DENY"
                    onMismatch="NEUTRAL" />
            </Filters>
            <PatternLayout>
                <Pattern>%d{HH:mm:ss,SSS} %m%n
                </Pattern>
            </PatternLayout>
            <Policies>
                <TimeBasedTriggeringPolicy
                    interval="1" modulate="true" />
                <SizeBasedTriggeringPolicy
                    size="${logSize}" />

            </Policies>
        </RollingFile>
        <RollingFile name="RollingFileError" 
            fileName="${filename}_error.log"
            filePattern="${filePath}/sample_error-%d{yyyy-dd-MM}-%i.log"
            immediateFlush="true">
            <PatternLayout>
                <Pattern>%d{HH:mm:ss,SSS} %p %c{1.}[%L] [%t] %m%n
                </Pattern>
            </PatternLayout>
            <Policies>
                <TimeBasedTriggeringPolicy
                    interval="1" modulate="true" />
                <SizeBasedTriggeringPolicy
                    size="${logSize}" />
            </Policies>
        </RollingFile>
    </Appenders>
    <Loggers>
        <AsyncLogger name="com"
            level="trace">
            <AppenderRef ref="RollingFileRegular"/>
        </AsyncLogger>
        <Root includeLocation="true" level="trace">
            <AppenderRef ref="RollingFileError" level="error" />
        </Root>
    </Loggers>
</Configuration>
需要的Maven依赖项在这里:
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-api</artifactId>
    <version>2.8.1</version>
</dependency>
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-core</artifactId>
    <version>2.8.1</version>
</dependency>
<dependency>
    <groupId>com.lmax</groupId>
    <artifactId>disruptor</artifactId>
    <version>3.3.6</version>
</dependency>
<!-- (Optional)To be used when working 
with the applications using Log4j 1.x -->
<dependency>
    <groupId>org.apache.logging.log4j</groupId>
    <artifactId>log4j-1.2-api</artifactId>
    <version>2.8.1</version>
</dependency>

1
我同意你的大部分观点。特别是应该使用8中的那些提供者,而且if (LOGGER.isDebugEnabled()) ...应该被视为已经过时了。 - Aitch
对于 CPU 敏感的应用程序,需要注意第二点,异步日志记录可能会导致高 CPU 使用率。 - WestFarmer

14

@cletus的答案中,他谈到了这个问题

if (log.isDebugEnabled()) {
  log.debug("val is " + value);
}

这个问题可以通过使用SLF4J来解决。它提供了格式化帮助。

log.debug("val is {}", value);

仅当级别为debug时,才会构造消息。

因此,目前建议使用SL4J及其伴侣日志记录器Logback,以获得更好的性能和稳定性,建议使用。


3
“评估”这个术语可能有些误导,因为Java不支持“按名称调用”的方法。但是,“参数化消息”不会在禁用日志记录语句的情况下“产生参数构造的成本”。正如您已经指出的那样,这更加简洁,并且能够提高性能。 - beatngu13
@beatngu13:谢谢,现在可以了吗? - serv-inc
当然,你的投票我已经得到了。;) 但是感谢你的澄清。 - beatngu13
2
我有一个问题。如果我们将变量 value 更改为方法:getValue()。并且该方法可能需要很长时间才能完成。那么 if (log.isDebugEnabled()) {log.debug("val is " + getValues());}log.debug("val is {}", getValue()); 花费的成本是否相同? - user2256235
如果您这样使用,getValue()应该在传递给log.debug()之前被评估,因此几乎没有机会。滥用API,您可以创建一个自定义的Throwable并使用log.debug(String, Trowable),但是log.isDebugEnabled后来看起来更清晰。有关澄清,请参见https://dev59.com/0lwY5IYBdhLWcg3w0Kgs。 - serv-inc
1
如@user所述,两个语句都将立即评估。或者,如果您使用Java 8和适当的日志记录框架,则可以传递Supplier。请参阅此博客文章以查看一些使用Log4j的示例。 - beatngu13

7

关于实例化日志记录器,我使用Eclipse Java模板设置我的日志记录器取得了一些成功:

private static Logger log = Logger.getLogger(${enclosing_type}.class);

这样做可以避免JVM弄乱堆栈跟踪,并减少(或许微不足道的)创建堆栈跟踪所带来的开销。

使用这样的模板的好处在于,如果你想对日志记录器设置统一标准,你可以与团队共享它。

看起来IntelliJ支持相同的概念,用于表示封闭类型名称的模板变量。我没有看到在NetBeans中轻松实现它的方法。


5

我正在审查一个应用程序的日志级别,目前我发现了一种模式:

private static final Logger logger = Logger.getLogger(Things.class)

public void bla() {
  logger.debug("Starting " + ...)
  // Do stuff
  ...
  logger.debug("Situational")

  // Algorithms
  for(Thing t : things) {
    logger.trace(...)
  }

  // Breaking happy things
  if(things.isEmpty){
    logger.warn("Things shouldn't be empty!")
  }

  // Catching things
  try {
    ...
  } catch(Exception e) {
    logger.error("Something bad happened")
  }

  logger.info("Completed "+...)
}

一个log4j2文件定义了一个socket-appender,带有故障转移的file-appender和一个console-appender。有时候情况需要时我会使用log4j2标记。
思考另一个角度可能会有帮助。

5

我可能从某个地方借鉴了这个方法,但它非常实用。

它可以减少在复制、粘贴和重构时混淆日志记录器的风险,而且还能节省输入时间。

在你的代码中:

private final static Logger logger = LoggerFactory.make();

...并在LoggerFactory中:

public static Logger make() {
    Throwable t = new Throwable();
    StackTraceElement directCaller = t.getStackTrace()[1];
    return Logger.getLogger(directCaller.getClassName());
}

(请注意,堆栈转储是在初始化期间完成的。堆栈跟踪可能不会被JVM优化掉,但实际上并没有任何保证)

最有可能是从Heinz M. Kabutz博士那里盗取的。但我不确定。 - KarlP
11
请记住,虚拟机是可以省略堆栈帧或执行其他优化,因此您可能会得到一个空的 StackTraceElements 数组。有关更多信息,请参见 http://java.sun.com/j2se/1.5.0/docs/api/java/lang/Throwable.html#getStackTrace() 。 - Bombe
1
你在类变量定义中漏掉了类型。 - Sebastian

4

对于您所描述的log4j配置,首选选项是使用 log4j配置文件。这使得您的实现用户可以按照自己的实现需求稍后覆盖您的配置。请参见此处获取非常详细的入门指南。


还有一种非 XML 格式,稍微更易读些。 - KarlP

3
作为补充,我认为重要的是意思是为Java提供简单日志门面(SLF4J)(http://www.slf4j.org/)。由于在一个大项目的不同部分中使用不同的日志框架存在问题,因此SLF4J是解决成功管理这些部分问题的事实标准,不是吗?
第二个概念:似乎一些老派任务可以用 面向切面编程 替代,Spring框架有它自己的 实现, AOP-方法对于记录在StackOverflow上 这里 和Spring博客 这里 被考虑。

0

对于任何日志API,我们至少有以下这些日志级别: ERROR > WARN > INFO > DEBUG > TRACE

我们可以使用每个日志级别来编写不同类型的日志,以更好地理解我们收集的跟踪信息:

Trace - 最好在每个方法的入口点处编写跟踪,包括方法名称和方法参数,以及在退出点处编写返回值/对象。

注意 - 最好遵循我们的编码准则并编写模块化的方法,这样我们就不需要在方法之间编写多个日志行以打印数据。

Debug - 我们将在方法中间添加调试日志,以显示哪个if / else / switch条件得到满足,以及我们从DB获取的数据并在方法中使用等等。 注意 - 不要添加作为参数发送或作为值返回的数据,因为这些数据已经通过Trace级别打印(尽量不要多次打印相同的日志)。

信息 - 假设客户端有日志级别为信息,那么如果他们看到日志,您想向他们显示什么消息和所有内容?在信息中添加这些内容。例如 - Blabla连接成功/已删除/已修改或Blabla链接已锁定/已解锁或blabla触发了blabla节点/节点的同步。

警告 - 这是一种罕见的情况,但编写代码时我们会遇到一些非正常情况,它只是由于任何陈旧条目或任何破坏而发生,通常我们忽略此情况,但如果我们添加这样的条件并在那里添加警告日志,将会更好。例如 - 我正在从一个带有列条件的表中查询,该列不是主键或唯一的,但被告知它将始终只返回一行,因此在这种情况下,我们应该编写一个条件,如if resultSet.size > 1,并添加一些更好的消息的警告日志。

错误 - 在每个未预期的 catch 块中都应该存在错误日志,并且它应该正确地打印完整的堆栈跟踪(而不仅仅是错误消息)。此外,在 catch 块中,人们会抛出一个新的 Exception,而没有记录现有的 Exception 跟踪,这种情况下,我们无法得到实际的异常点。因此,在每个 catch 块中编写带有完整堆栈跟踪的错误日志非常重要。

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接