在 Java 应用程序中记录运行时信息对于了解任何应用程序的行为都非常有用，尤其是在你遇到意外情况、错误或只需要跟踪某些应用程序事件的情况下。

在现实世界的生产环境中，我们通常没有调试的余地。因此，在尝试诊断不容易复现的问题时，日志文件可能是唯一的证据。

如果处理得当，日志文件还可以通过提供有关问题原因的线索以及问题发生时的系统状态，为我们节省大量时间。

当然，日志记录它还可用于审计目的、收集统计数据、提取商业智能和各种其他任务。

总的来说，日志记录无疑是一种基础实践，它在应用程序的生命周期内提供了显着的好处——这也让“加个日志”变成了一种冲动。

于是问题就来了，过多的不恰当地使用日志记录也会出现很多问题。

在以下部分中，我们将介绍一些在应用程序中使用日志时可能遇到的最常见的有害做法。

PS:所有示例和配置都使用流行的log4j 2库。Logback和Stackify 也提供了很好的支持。

9 个 Java 日志记录陷阱，以及如何避免

1. 记录敏感信息

首先，“尽可能多地记录以防万一”方法带来的最具破坏性的问题，可能就是在日志中显示敏感信息。

大多数应用程序处理应该保持私有的数据，例如用户凭据或财务信息。将此类信息记录到纯文本文件中的危险是显而易见的——日志文件很可能会被多个不安全的系统处理。

此外，记录某些类别的数据（例如财务信息）也受到严格监管，并可能产生严重的法律影响。

避免这种情况的最佳方法就是确保您从不记录此类敏感信息。

有一些替代方法，例如加密日志文件，但这通常会使这些文件的整体可用性大大降低，这并不理想。

在我们继续之前，这里有一个更全面的信息类型列表，你需要非常小心地记录这些信息。

记录普通用户输入

Java 应用程序中另一个常见的安全问题是JVM Log Forging。

简而言之，当来自外部来源（如用户输入或其他不受信任的来源）的数据直接写入日志时，可能会发生日志伪造。恶意攻击者可以输入模拟日志条目的输入，例如“ \n\nweb – 2017-04-12 17:47:08,957 [main] INFO Amount reversed successful”，这可能导致日志数据损坏。

有多种方法可以处理此类漏洞：

• 不要记录任何用户输入 - 因为用户数据对于找到某些问题的根本原因至关重要
• 在记录之前使用验证——这个解决方案会影响性能，以及放弃记录重要信息
• 登录到数据库——更安全但性能成本更高，并且可能引入另一个漏洞 ——SQL注入
• 使用像 OWASP 的 Enterprise Security API 这样的工具

PS：使用ESAPI绝对是一个好方法；这个来自OWASP的开源安全库 可以在将数据写入日志之前对其进行编码：

message = message.replace( '\n' ,  '_' ).replace( '\r' , '_' )
  .replace( '\t' , '_' );
message = ESAPI.encoder().encodeForHTML( message );

2. 过多的日志记录

另一种要避免的做法是记录太多信息。这可能会发生在试图捕获所有潜在相关数据的过程中。

这种方法带来的一个非常现实的问题就是性能下降。

然而，随着日志库的发展，现在已经有了一些工具来减少这方面的担忧。

作为提高性能的一个例子，log4j的 2.x 版本使用异步日志记录，这意味着在单独的线程中执行 I/O 操作。

太多的日志消息也会导致在确实发生问题时难以读取日志文件和识别相关信息。

减少代码日志行数的一种方法是记录系统中跨领域关注点的重要信息。

例如，如果你想记录特定方法的开始和结束，那可以添加一个Aspect，它将为每个具有指定自定义注释的方法执行此操作：

@Aspect
public class MyLogger {

    private static final Logger logger = LogManager.getLogger(MyLogger.class);

    @Around("execution(* *(..)) && @annotation(LogMethod)")
    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {
        logger.info("Starting method execution: " + joinPoint.getSignature().getName() + 
          " in class:"+joinPoint.getSignature().getDeclaringTypeName());
        Object result = joinPoint.proceed();
        logger.info("Exiting method execution: " + joinPoint.getSignature().getName() + 
          " in class:"+joinPoint.getSignature().getDeclaringTypeName());
        return result;
    }
}

在自定义方面的帮助下，我们现在可以非常有选择性地在日志中选择我们实际需要该信息的应用程序的确切区域。因此，我们可以显着减少系统的整体日志记录足迹。

3. 神秘的日志信息

在解析日志文件时，遇到没有提供足够信息的行可能会令人沮丧。一个常见的缺陷是日志消息中缺乏特异性或上下文。

为了说明问题，让我们看一下缺少特异性的日志消息：

Operation failed.

相反，我们可以添加更具体和可识别的信息：

File upload picture.jpg failed.

请始终牢记，我们的日志肯定会被其他开发人员或系统管理员阅读，他们需要了解应用程序中发生了什么。

在日志消息中添加上下文的一个好方法是包含事件的时间戳、日志级别、线程名称和完全限定的类名称。 这样，我们就可以更轻松地识别特定事件在运行时发生的时间和地点。

要在使用log4j 2时添加此信息，就可以配置模式布局，其中%d为日期，%p为日志级别，%t为线程名称，%c为类名：

<PatternLayout>
    <Pattern>%d [%t] %p %c - %m%n</Pattern>
</PatternLayout>

使用上述布局的日志消息将如下所示：

2017-05-11 22:51:43,223 [main] INFO com.stackify.service.MyService - User info updated

4. 使用单个日志文件

只为应用程序使用一个日志文件的缺点是，随着时间的推移，它会变得非常大并且难以使用。

快速查找相关信息的一个好习惯是每天创建一个新的日志文件，并将日期作为文件名的一部分。

让我们看一个例子，如果使用log4j2库，如何创建一个名称等于当前日期的日志文件：

SimpleLayout layout = new SimpleLayout();
FileAppender appender = new FileAppender(layout, LocalDate.now().toString(), false);
logger.addAppender(appender);

同一个库还提供了配置滚动文件附加程序的选项，该附加程序将在特定时间间隔创建新的日志文件：

<RollingFile name="RollingFile" fileName="logs/app.log"
  filePattern="logs/$${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz">
    <PatternLayout>
        <Pattern>%d [%t] %p %c - %m%n</Pattern>
    </PatternLayout>
    <Policies>
        <TimeBasedTriggeringPolicy />
        <SizeBasedTriggeringPolicy size="250 MB"/>
    </Policies>
    <DefaultRolloverStrategy max="20"/>
</RollingFile>

上面的配置将导致每天创建一个或多个文件，每个文件最多 250 MB，以当前日期作为文件名，放置在名称格式为 year-month 的文件夹中。

5. 选择不正确的日志级别

选择不适当的日志级别将导致丢失重要事件或被大量不太重要的数据淹没。

简而言之，为系统中的不同日志选择正确的日志级别是正确理解日志所需的核心内容之一。

大多数日志框架都有一组类似于FATAL、ERROR、WARN、INFO、DEBUG、TRACE的级别，从高到低排列。

可用的日志级别

让我们看一下其中的每一个以及它们应该根据严重性包含的日志消息的类型：

• FATAL 应该保留给导致应用程序崩溃或无法启动的错误（例如：JVM 内存不足）
• ERROR应包含系统正常运行需要解决的技术问题（例如：无法连接到数据库）
• WARN最适用于不会严重影响应用程序功能的临时问题或意外行为（例如：用户登录失败）
• INFO应包含描述应用程序中发生的事情的消息（例如：用户注册、下订单）
• DEBUG 适用于可能对调试问题有用的消息（例如：方法执行已启动）
• TRACE与DEBUG类似，但包含更详细的事件（例如：数据模型更新）

控制日志级别

消息的日志级别在写入时设置：

logger.info("Order ID:" + order.getId() + " placed.");

日志记录 API 通常允许你设置要查看消息的级别。这意味着，如果你将应用程序或某些类的日志级别设置为INFO，例如，你将只能看到级别为FATAL、ERROR、WARN和INFO 的消息，而不会包含DEBUG和TRACE消息。

这很有帮助，因为我们通常会在开发中显示DEBUG或更低的消息，而不是在生产中。

以下是如何使用log4j2.properties文件在log4j 2中设置类、包或整个应用程序的日志级别：

loggers=classLogger,packageLogger

logger.classLogger.name=com.stackify.service.MyService
logger.classLogger.level=info

logger.packageLogger.name=com.stackify.config
logger.packageLogger.level=debug

rootLogger.level=debug

要在消息中显示日志级别，可以在log4j2PatternLayout中添加%p选项。

在我们继续之前，请记住，如果现有级别都不适合您的应用程序需求，你也可以定义自定义日志级别。

6. 跨多个系统和日志跟踪单个操作

在具有多个独立部署的服务的分布式系统中，这些服务协同工作以处理传入请求，在所有这些系统中跟踪单个请求可能很困难。

一个请求很可能会影响多个这些服务，如果确实发生问题，我们将需要证实这些系统的所有单独日志，以全面了解发生的情况。

为了解决这种架构，我们现在在生态系统中有新一代的日志辅助工具，例如Zipkin和Spring Cloud Sleuth。

Zipkin跨微服务架构跟踪请求，以帮助我们确定是哪个应用程序导致了问题。它还带有一个有用的 UI，您可以在其中根据应用程序、跟踪长度或时间戳过滤跟踪。

Spring Cloud Sleuth项目通过为每个跟踪添加唯一的 64 位 ID 来工作；例如，一个 Web 请求可以构成一个跟踪。这样，可以跨多个服务识别请求。

这些工具解决了核心库的局限性，你可以驾驭更加分布式的架构风格的新现实。

7. 不使用 JSON 记录

虽然以纯文本格式登录非常普遍，但日志存储和数据分析系统的出现已将其转变为 JSON。

JSON 作为主要的应用程序日志格式具有与纯文本一样可读的优点，同时也更容易被自动化处理工具解析。

例如，Log4j 2为此目的 提供了JSONLayout：

<JSONLayout complete="true" compact="false"/>

这将生成一个格式良好的 JSON 文档：

[
    {
        "logger":"com.stackify.service.MyService",
        "timestamp":"1376681196470",
        "level":"INFO",
        "threadId":1,
        "thread":"main",
        "threadPriority":1,
        "message":"Order ID:1234 placed."
    },
    ...
]

作为 JSON，当日志管理系统（如 Retrace ）处理日志数据时，其语义将更加丰富——这将立即启用其强大的结构化/语义日志记录功能。

8. 记录对性能的影响

最后，让我们考虑一个在应用程序中添加日志时不可避免的问题：对性能的影响。

预计性能会出现小幅下降。但是，跟踪这一点很重要，这样你就可以将其最小化而不会使系统变慢。

选择日志 API 时要考虑的一些与性能相关的方面是：

• 使用缓冲区的文件 I/O 操作——这很关键，因为文件 I/O 是一项昂贵的操作
• 异步日志记录——应该考虑这一点，以便日志记录不会阻塞其他应用程序进程
• 记录响应时间 – 写入日志条目并返回所需的时间
• 用于记录的线程数
• 日志级别过滤——这是为了验证是否启用了与消息对应的日志级别，可以通过遍历层次结构或让Logger直接指向Logger配置来完成；就性能而言，后一种方法更可取

当然，如果你需要保持选择的开放性和系统的灵活性，就始终可以使用更高级别的抽象，例如 slf4j。

在我们移动之前，你可以采取以下几个步骤来提高系统的日志记录性能：

• 为详细包调整应用程序的日志级别
• 避免在运行时记录源位置信息，因为查找当前线程、文件、方法是一项代价高昂的操作
• 避免使用长堆栈跟踪记录错误
• 在写入具有该级别的消息之前检查是否启用了特定的日志级别 - 这样，如果不需要，则不会构造该消息
• 在投入生产之前检查日志以检查是否可以删除任何日志记录

9. 最后一点

在结束之前，让我们看一下你应该避免的最后一种做法——那就是使用标准输出而不是日志记录。

虽然System.out() 可以是在开发周期的早期开始的快速方法，但在此之后绝对不是一个好习惯。

除了失去专用日志 API 的所有强大功能这一事实之外，这里的主要缺点只是日志数据不会在任何地方持久化。

最后，另一个值得一提的是一种可以使阅读和分析日志数据变得更加容易的做法——标准化的日志消息。简单地说，类似的事件在日志中应该有类似的消息。

如果你需要搜索该特定事件的所有实例或从日志数据中提取有意义的见解，标准日志消息非常重要。

例如，如果上传操作失败 - 在日志中包含这些不同的消息会令人困惑：

Could not upload file picture.jpg

File upload picture.jpg failed.

相反，每当文件上传失败时，您应该始终使用这些消息之一来记录失败。

结论

日志的使用在应用程序开发中变得无处不在，因为它为系统运行时带来了非常有用和可操作的洞察力。

但是，为了充分利用你的日志数据，重要的是要超越基础知识，培养一种日志文化，并了解在大规模和生产中使用这些数据的更多精细点。

作者：Eugen Paraschiv