【问题标题】:Logging in Java and in general: Best Practices?使用 Java 和一般情况下的日志记录:最佳实践?
【发布时间】:2010-10-28 17:16:36
【问题描述】:

有时当我看到我的日志记录代码时,我想知道我是否做得对。对此可能没有明确的答案,但我有以下担忧:

库类

我有几个库类可能会记录一些INFO 消息。致命错误报告为异常。目前,我的类中有一个静态记录器实例,其类名作为日志记录名称。 (Log4j 的:Logger.getLogger(MyClass.class)

这是正确的方法吗?也许这个库类的用户不想要我的实现中的任何消息,或者想要将它们重定向到特定于应用程序的日志。我应该允许用户从“外部世界”设置记录器吗?您如何处理此类情况?

一般日志

在某些应用程序中,我的类可能希望将日志消息写入未由类名标识的特定日志。 (即:HTTP Request log)做这种事情的最好方法是什么?想到一个查找服务...

【问题讨论】:

    标签: java logging log4j


    【解决方案1】:

    您的约定非常标准且非常好(恕我直言)。

    需要注意的一件事是过多的 unnedded 调试调用导致的内存碎片,因此,使用 Log4J(和大多数其他 Java 日志框架),您最终会得到如下结果:

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

    因为构建该日志消息(您可能没有使用)可能会很昂贵,尤其是在完成数千或数百万次的情况下。

    您的 INFO 级别日志记录不应过于“健谈”(从您所说的情况来看,听起来并非如此)。 INFO 消息通常应该是有意义和重要的,例如正在启动和停止的应用程序。如果遇到问题,您可能想知道的事情。当您真正遇到要诊断的问题时,更多地使用调试/精细级别日志记录。调试/精细日志记录通常仅在需要时打开。信息通常随时可用。

    如果有人不希望您的课程提供特定的 INFO 消息,他们当然可以随意更改您的 log4j 配置以不获取它们。 Log4j 在这个部门非常简单明了(与 Java 1.4 日志记录相反)。

    至于您的 HTTP 问题,我通常认为 Java 日志记录不会有问题,因为通常一个类负责您感兴趣的内容,因此您只需将其放在一个位置即可。在(在我的经验中很少见)当您想要跨看似不相关的类的通用日志消息时,只需放入一些可以轻松获取的标记。

    【讨论】:

    • 作为参考,在 Scala 中,可以编写一个调试方法来执行该代码,而无需使用名称参数的冗长。编译器自动将 debug() 参数中的代码转换为仅在 debug() 决定调用它时才评估的函数。因此,除非 isDebugEnabled() 为真,否则不会连接字符串。实现此功能的示例代码: override def debug(msg: => AnyRef) = if (isDebugEnabled) logger.debug(msg) github.com/dpp/liftweb/blob/…
    • 这是使用 slf4j 提供的 {} 结构的另一个很好的理由。
    【解决方案2】:

    以下是我在所有项目中遵循的一套准则,以确保良好的性能。我已经根据互联网上各种来源的输入形成了这套指南。

    到今天为止,我相信 Log4j 2 是迄今为止登录 Java 的最佳选择。

    基准测试可用here。我为获得最佳性能而遵循的做法如下:

    1. 我目前避免使用 SLF4J,原因如下:
    2. 使用异步记录器执行所有常规记录以获得更好的性能
    3. 使用同步记录器将错误消息记录在单独的文件中,因为我们希望在错误消息发生时立即看到它
    4. 不要在常规日志记录中使用位置信息,例如文件名、类名、方法名、行号,因为为了派生这些信息,框架会拍摄堆栈快照并遍历它。这会影响性能。因此,仅在错误日志中使用位置信息,而不是在常规日志中
    5. 为了跟踪由单独线程处理的单个请求,请考虑使用线程上下文和随机 UUID,如 here 所述
    6. 由于我们将错误记录在单独的文件中,因此将上下文信息也记录在错误日志中非常重要。例如如果应用程序在处理文件时遇到错误,则在错误日志文件中打印文件名和正在处理的文件记录以及堆栈跟踪
    7. 日志文件应该是 grep-able 且易于理解的。例如如果应用程序处理多个文件中的客户记录,则每个日志消息应如下所示:
    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 Lambda 记录所有参数。当给定的日志级别被禁用时,这将使应用程序免于格式化消息:
    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>
    
    1. 所需的 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>
    

    【讨论】:

    • 我同意你的大部分观点。尤其是 8. 中的那些提供者应该被使用,if (LOGGER.isDebugEnabled()) ... 应该被认为完全弃用。
    • 对于 CPU 敏感的应用程序,请注意第 2 点,异步日志记录会消耗大量 CPU。
    【解决方案3】:

    @cletus' answer,他写的问题

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

    这可以通过使用SLF4J 来克服。它提供了格式化帮助

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

    仅当级别为调试时才构造消息。

    因此,现在,出于性能和稳定性的原因,使用 SL4J 及其配套记录器 Logback 是 advised

    【讨论】:

    • “已评估”一词可能有点误导,因为 Java 不支持 call by name。但是,parameterized messages 不会“在日志语句被禁用的情况下产生参数构造成本”。正如您已经指出的那样,这更加简洁,并且性能更好。
    • @beatngu13:谢谢,现在可以了吗?
    • 当然,你还是得到了我的支持。 ;) 但感谢您的澄清。
    • 我有一个问题。如果我们将变量:value 更改为方法:getValue()。而且该方法可能会花费大量时间。 if (log.isDebugEnabled()) {log.debug("val is " + getValues());} 的成本是否与 log.debug("val is {}", getValue()); 相同
    • @user2256235:正如@user 所提到的,这两个语句都将被立即评估。或者,如果您使用 Java 8 和适当的日志记录框架,则可以传递 Supplier。查看this blog post 以查看 Log4j 的一些示例。
    【解决方案4】:

    关于实例化记录器,我使用 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 文件定义了一个套接字附加器,带有一个故障转移文件附加器。还有一个控制台附加程序。有时我会在需要时使用 log4j2 标记。

      认为额外的视角可能会有所帮助。

      【讨论】:

        【解决方案6】:

        您所描述的那种 log4j 配置的首选选项是使用 log4j 配置文件。这允许您实现的用户完全按照您的要求进行操作,因为他们稍后可以使用更适合他们自己实现的内容覆盖您的配置。请参阅here 以获得非常全面的入门知识。

        【讨论】:

        • ...还有一种非xml格式,可读性略高。
        【解决方案7】:

        我可能从某个地方偷了这个,但它很好。

        它减少了在复制和粘贴时混淆记录器的风险^h^h^h重构,并且输入更少。

        在您的代码中:

        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 博士那里偷来的。但我不确定
        • 请记住,VM 可以随意省略堆栈帧或执行其他优化,这样您最终可能会得到一个空的 StackTraceElements 数组。请参阅java.sun.com/j2se/1.5.0/docs/api/java/lang/… 了解更多信息。
        • 您错过了类变量定义中的类型。
        【解决方案8】:

        作为补充,我认为 Java 的简单日志门面 (SLF4J) (http://www.slf4j.org/) 很重要。由于在大型项目的不同部分使用不同的日志框架存在一些问题,SLF4J 是解决问题以成功管理这些部分的事实标准,不是吗?

        第二个概念:似乎一些老派任务可以用Aspect-Oriented-Programming 代替,Spring frmwrk 有它自己的implementation,AOP 日志记录方法在 StackOverflow 上考虑 here,在 Spring 上考虑 here博客。

        【讨论】:

          猜你喜欢
          • 1970-01-01
          • 1970-01-01
          • 2012-11-02
          • 1970-01-01
          • 2018-03-27
          • 2010-09-18
          • 2021-08-05
          • 2010-10-08
          • 1970-01-01
          相关资源
          最近更新 更多