CUBA 应用程序日志

要深入了解运行中的CUBA应用程序，记录日志是一种重要的手段。 Java生态系统具有非常成熟的应用程序日志记录机制。本指南介绍了如何在CUBA应用程序中利用这个生态系统。

将要构建的内容

本指南对 CUBA 宠物医院示例进行了增强，以演示如何在 CUBA 应用程序中集成、配置日志功能，也演示了如何在CUBA 应用程序中查看日志或使用外部工具查看日志。

开发环境要求

您的开发环境需要满足以下条件：

下载 并解压本指南的源码，或者使用 git 克隆下来：

git clone https://github.com/cuba-guides/cuba-petclinic-application-logging.git

示例: CUBA 宠物诊所

这个示例是以 CUBA 宠物诊所项目为基础，而这个项目的基础是众所周知的 Spring 宠物诊所项目。CUBA 宠物诊所应用程序涉及到了宠物诊所的领域模型及与管理一家宠物诊所相关的业务流程。

这个应用程序的领域模型如下：

领域模型

主要的实体是 Pet 和 Visit。 Pet 到诊所就诊，就诊时(Vist) 会有一名兽医（Vet）负责照顾它。每个宠物都有主人，一个主人可以有多个宠物。一次就诊(Vist)即是一个宠物在主人的帮助下到诊所诊治的活动。

为什么应用程序日志是必须的

日志记录对于了解应用程序行为是必须的，通过日志可以看出应用程序出现了哪些异常行为、分析出用户如何与系统进行交互。

日志是应用程序开发及运营的基本工具。 开发人员在代码中加入语句以标记出特定动作的发生。

在下面的宠物诊所示例中，两个可能的日志消息会被写入。在成功地保存了 Pet 实例后，会记录一条包含宠物详情的常规消息。在保存失败时，会记录一条包含失败信息的错误级消息。

PetServiceBean.java
private Pet savePet(Pet pet) {
    try {
        Pet savedPet = dataManager.commit(pet);
        log.info("Pet " + pet + " was saved correctly");
        return savedPet;
    } catch (Exception e) {
        log.error("Pet " + pet + " could not be saved", e);
        return null;
    }
}

日志消息会被保存到配置好的位置，管理员或开发人员会从这些位置访问日志消息。 通常，日志消息被保存到一个文本文件，但也有可能会保存到数据库或一个中心化的日志服务。

在应用程序开发阶段，开发人员可以随时挂起应用程序的执行来查看应用程序的内部状态。

对于已经上线运行的应用程序，通常不能这样做。这可能是因为安全问题或应用程序运行在不受开发人员控制的服务器上。

因此记录日志成为开发人员诊断应用程序问题的一个必备工具。

Java 日志生态系统

在 Java 生态系统（也包括其它生态系统）中日志扮演着一个重要的角色。在 Java 生态系统中有各种各样的关于与应用程序所运行的平台的日志机制进行交互的机制和概念。

这些主要是 JVM 的API和各种日志库，这些库封装了“写日志消息”这个抽象中包含的记录到文件或数据库的技术细节。

在最近几年，一个常用的组合被 Java 生态采纳，成为一个事实标准。

  • Slf4J

  • Logback

Slf4J 是一个抽象的 API，封装了日志库的创建细节。它为不同严重级别（DEBUG 、 INFO 、 WARN 等）的消息提供了不同的方法，这些方法将消息存储到日志系统。

Logback ,可以说是实现了这套 API 的日志库，最终，日志的实际输出是由它执行的。 在 Logback 中使用 Appender 的概念表示一个输出通道，一个 Appender 是一个日志库中的组件，它获取由应用程序开发人员创建的日志事件并将日志事件写入特定的输出目标。Logback 包提供了一些选项，通过这些选项可以配置日志系统的某些行为，比如哪些信息应该写到哪些输出通道（appender）。

在 CUBA 应用程序中如何记录日志

CUBA 应用程序中日志库的用法与其它Java 应用程序没有区别。 CUBA 默认适当地配置了 Sl4fJ 和 Logback 。 框架本身使用它们来记录框架内部的日志消息。

要在一个类里面记录信息，需要在这个类上创建一个 Logger 类的实例。

DiseaseWarningMailingServiceBean.java
@Service(DiseaseWarningMailingService.NAME)
public class DiseaseWarningMailingServiceBean implements DiseaseWarningMailingService {

    private static final Logger log = LoggerFactory.getLogger(DiseaseWarningMailingServiceBean.class); (1)

    // ...

    @Override
    public int warnAboutDisease(PetType petType, String disease, String city) {

        log.debug("Disease warnings should be send out for Pet type: {}, Disease: {} in the area of {}", petType, disease, city); (2)

        List<Pet> petsInDiseaseCity = findPetsInDiseaseCity(petType, city);
        List<Pet> petsWithEmail = filterPetsWithValidOwnersEmail(petsInDiseaseCity);

        log.debug("possible pets in danger: {}", petsWithEmail);

        petsWithEmail.forEach(pet -> sendEmailToPetsOwner(pet, disease, city));
        int amountOfInformedPets = petsWithEmail.size();

        log.info("Summary: Disease warning send out to {} Pet(s) in {}", amountOfInformedPets, city); (3)

        return amountOfInformedPets;
    }

    // ...
}
1 给这个类配置的 Logger 是由Slf4J 定义的
2 warnAboutDisease 初始化后记录调试日志消息
3 记录方法执行结果的摘要信息。消息中的可变部分可以传递给方法参数并且在日志消息中使用 {} 点位符标记出来

通过 CUBA UI 查看日志消息

有几种方法可以访问正在运行的应用程序的日志输出。 最常见的方法是直接访问服务器上的日志文件。不幸的是，这通常需要特殊的权限和知识才能访问该文件。

CUBA 提供了一个用户界面，可以用来查看应用程序的运行时日志信息。 可以通过 Administration > Server Log > View 菜单打开这个界面：

在这个界面上可以显示不同的日志文件，也可以将日志文件下载下来。这个功能给了非管理员角色访问日志的权限，同时仍然可以限制哪些角色允许访问日志。

日志级别

要记录的信息在多个维护有不同类型。为了帮助消息的使用者能快速地区分出有用信息和无用信息， 所有的日志库都提供了一个非常重要的对消息进行分类的维度：日志级别。

日志级别可以表示出消息的重要/紧急程度。请注意，日志级别是按顺序排列的。 Slf4J 定义了下列可用在应用程序中的 日志级别

  • TRACE

  • DEBUG

  • INFO

  • WARN

  • ERROR

  • FATAL

DEBUG 日志消息一般用于帮助开发员标识应用程序的内部状态。

ERROR 和 FATAL 通常用于应用程序发生了非预期异常，并且不能再继续运行的情况。

调整日志配置

Logback (也包括其它日志库)允许定义处理日志信息的方式、日志信息的输出位置，这主要是通过上面提到的 appender 的概念来实现。

通常有两种方式来调整 logback 的配置。一种方式是使用一个名为 logback.xml 的配置文件，配置信息写在这个文件中，这种调整在部署时进行。作为一种可选方式，logback 也在一定程度上支持运行时配置。CUBA 提供一个用于运行时调整日志配置的 UI: (Administration > Server Log > Options)。

在部署时: logback.xml 配置文件

logback.xml 文件是调整 logback 配置的主要地方。在 CUBA 应用程序中这个文件位于 deploy/tomcat/conf/logback.xml （使用了https://doc.cuba-platform.cn/manual-7.0-chs/fast_deployment.html[快速部署] 方式）。它看起来是这样：

logback.xml
<configuration debug="false" packagingData="true">

    <property name="logDir" value="${catalina.base}/logs"/> (1)

    <appender name="File" class="ch.qos.logback.core.rolling.RollingFileAppender"> (2)
        <file>${logDir}/app.log</file>

        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>DEBUG</level>
        </filter>

        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread%X{cubaApp}%X{cubaUser}] %logger - %msg%n</pattern> (3)
        </encoder>
    </appender>

    <appender name="Console" class="ch.qos.logback.core.ConsoleAppender"> (4)
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} %-5level %-40logger{36}- %msg%n</pattern>
        </encoder>
    </appender>

    <root>
        <appender-ref ref="Console"/>
        <appender-ref ref="File"/>
    </root>

    <logger name="com.haulmont.sample.petclinic" level="DEBUG"/> (5)
    <logger name="com.haulmont.cuba" level="DEBUG"/>
    <logger name="com.haulmont.cuba.core.sys" level="INFO"/>

    <!-- ... -->

</configuration>
1 logDir 是为配置文件定义的变量，它定义了日志文件应该保存的位置。 它使用了来自 tomcat 的变量 catalina.base 来引用安装位置。
2 一个文件通道(appender)，可将日志消息写入日志文件 app.log
3 pattern 用于配置日志文件中一行日志消息的显示格式
4 另外一个通道，将日志消息写到 STDOUT (使用了不同的选项)
5 可以给每个类或者包配置日志级别

CUBA 默认配置多个日志输出通道(appender)。 一个输出通道描述了日志信息应该写到哪。已经有多个可开箱即用输出通道(appender) 。每个通道都有一些选项来配置自身的行为（比如日志消息如何格式化、哪些信息应该记录等）。常用的日志输出通道是 FileAppender 和 ConsoleAppender 。

日志配置允许根据类名或包名配置阈值，这意味着对于应用程序的特定部分，可以输出 DEBUG 级别的日志消息，而对其它部分只可以看到 WARN 和 ERROR 级别的消息。

在上面的示例中，com.haulmont.sample.petclinic 包的日志级别设置为了 DEBUG 。这意味着它将输出所有 DEBUG 级别以上的日志。根据日志级别的定义 ， 这个包将记录 INFO 、 WARN 、 ERROR 和 FATAL 级别的日志。TRACE 级别的日志将不会显示。

根据应用程序的部署方式，有几个有关 logback.xml 文件放置位置的选项。 除了上面提到的 快速部署之外， logback.xml 可以放在应用程序 内部，或者将其配置为应用程序外部的指定路径。 详细信息请参阅更多信息。

在运行时: CUBA 日志 UI

通过配置文件调整配置需要重启应用程序。在临时的调试期间，不需要重启应用、可以只调整日志级别或一部分程序的日志级别将非常有用。

对于这种场景， CUBA 应用程序允许在运行时通过用户界面重新配置已有的logger或添加新的logger。

使用 MDC 设置日志上下文

一旦应用程序有了一定量的日志信息，就会出现大量重复出现的信息。在宠物诊所示例中，许多日志消息会包含宠物 ID ，以便快速获取上下文信息。 对于这些类型的信息，Logback 中有一个上下文(context)，称为 MDC。

MDC 允许将某些值设置到上下文中， 这些值每次都会和实际的日志消息一起输出。 使用上下文的方式，这些值只需要设置一次，编写输出日志语句的开发人员将不再需要将其包含在日志消息中。

CUBA 本身也使用了 MDC 将不同的上下文值附加到日志消息中。这些值主要是当前用户及当前应用程序，这意味着最终的日志消息可以根据用户来过滤。

在宠物诊所示例中，PetContactFetcherBean 以如下方式使用 MDC 上下文： 在方法 Optional<Contact> findContact(Pet pet) 体最前面将宠物的身份号码设置到 MDC上下文中，如下所示：

PetContactFetcherBean.java
@Component(PetContactFetcher.NAME)
public class PetContactFetcherBean implements PetContactFetcher {

    private static final Logger log = LoggerFactory.getLogger(PetContactFetcherBean.class);

    @Override
    public Optional<Contact> findContact(Pet pet) {

        MDC.put("petId", pet.getIdentificationNumber()); (1)

        log.debug("Searching Contact for Pet"); (2)

        try {
            Optional<Owner> petOwner = loadOwnerFor(pet);

            if (petOwner.isPresent()) {
                log.debug("Found Owner: {}", petOwner);

                // ...

                if (isAvailable(telephone)) {
                    return createContact(telephone, ContactType.TELEPHONE);
                }

                // ...

            } else {
                return Optional.empty();
            }
        } finally {
            MDC.remove("petId"); (4)
        }
    }

    private Optional<Contact> createContact(String contactValue, ContactType contactType) {

        Contact contact = new Contact();
        contact.setValue(contactValue);
        contact.setType(contactType);

        log.info("Contact created: {}", contact); (3)

        return Optional.of(contact);
    }

    // ...
}
1 宠物的身份号码被注册到上下文中，使用 petId 作为键名
2 后续的日志消息将不需要包含宠物ID
3 MDC 中值的生命周期独立于方法边界
4 MDC 中 petId 键在方法结束时被清除

现在 MDC 中有了值，下一步是重新配置 logback 以便在日志输出中看到这些值。

logback.xml
<configuration debug="false" packagingData="true">

    <!-- ... -->

    <appender name="File" class="ch.qos.logback.core.rolling.RollingFileAppender">

        <!-- ... -->

        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread%X{cubaApp}%X{cubaUser}] [Pet: %X{petId}] %logger - %msg%n</pattern> (1)
        </encoder>

    </appender>

    <!-- ... -->

</configuration>
1 %X{petId} 从 MDC中取到键名为 petId 的值并且写到日志文件

最终的日志输出包含宠物身份号：

2018-12-13 08:54:41.345 DEBUG [http-nio-8080-exec-7/petclinic/admin] [Pet: 205] c.h.s.p.c.PetContactFetcherBean - Searching Contact for Pet
2018-12-13 08:54:41.354 DEBUG [http-nio-8080-exec-7/petclinic-core/admin] [Pet: 205] c.h.c.c.a.RdbmsStore - load: metaClass=petclinic_Owner, id=79fa17b9-a130-207d-5091-f79cceb9cf99, view=com.haulmont.sample.petclinic.entity.owner.Owner/_local
2018-12-13 08:54:41.371 DEBUG [http-nio-8080-exec-7/petclinic/admin] [Pet: 205] c.h.s.p.c.PetContactFetcherBean - Found Owner: Optional[com.haulmont.sample.petclinic.entity.owner.Owner-79fa17b9-a130-207d-5091-f79cceb9cf99 [detached]]
2018-12-13 08:54:41.374 INFO  [http-nio-8080-exec-7/petclinic/admin] [Pet: 205] c.h.s.p.c.PetContactFetcherBean - Contact created: TELEPHONE: 0049817312

日志条目现在包含以下消息片断：[Pet: 205]。上下文条目也被用于 CUBA 内部日志消息，比如 RdbmsStore 的日志消息。

与直接将上下文值写入日志相比，MDC 具有以下优势：

  • 日志输出格式会比较统一

  • 日志消息是结构化的，允许精确搜索

  • 上下文的定义可以被提取为源码中的一个独立实现

日志集中化方案

有关运行中的应用程序的执行细节信息非常重要。 但是，要处理大量日志数据也是极富挑战性的。 将这些信息存储在服务器的文件系统中不容易访问到，也不能高效地利用这些信息。这就是为什么通常使用集中式日志记录解决方案来存储和访问日志信息。

有一个基于 Elasticsearch 的非常通用的开源中心化日志系统。Elasticsearch 是一个全文搜索数据库，也非常适用于日志场景。

基于输出通道(appender)的概念，Logback 可以很容易地与中心化日志方案集成起来。在配置文件中，已经配置为应用程序配置了两个输出通道：ConsoleAppender 和 FileAppender。

对于 Elasticsearch，有一个Logback 输出通道(Appender)，它将直接将日志记录信息发送到 elasticsearch 集群，而不是将日志消息放入文件中。 有一些关于如何配置日志记录到 Elasticsearch（也称为 ELK-Stack）的选项。 由于本指南主要涉及在应用程序中与Logback的集成，因此关于如何配置 Elasticsearch 服务器不在本指南讨论的范围。

要使用 Elasticsearch 作为以日志存储后端，需要给 CUBA 应用程序添加一个依赖。在 build.gradle 中给 所有 模块添加以下依赖： runtime "com.internetitem:logback-elasticsearch-appender:1.6" 。

logback.xml 配置文件应该添加以下输出通道（appender）：

logback.xml
<configuration debug="false" packagingData="true">

    <!-- ... -->

    <appender name="elasticsearch" class="com.internetitem.logback.elasticsearch.ElasticsearchAppender"> (1)
        <url>${ELASTICSEARCH_CLUSTER_URL}</url> (2)
        <index>cuba-petclinic-logs-%date{yyyy-MM-dd}</index> (3)
        <type>cuba-petclinic</type>
        <errorLoggerName>es-error-logger</errorLoggerName>
        <includeMdc>true</includeMdc>
        <properties>
            <property>
                <name>host</name>
                <value>${HOSTNAME}</value>
                <allowEmpty>false</allowEmpty>
            </property>
            <property>
                <name>severity</name>
                <value>%level</value>
            </property>
            <property>
                <name>thread</name>
                <value>%thread</value>
            </property>
            <property>
                <name>logger</name>
                <value>%logger</value>
            </property>
            <property>
                <name>stacktrace</name>
                <value>%ex</value>
            </property>
        </properties>
    </appender>

    <!-- ... -->

</configuration>
1 为应用程序注册了一个类型为 ElasticsearchAppender 的输出通道： elasticsearch 。
2 elasticsearch 集群的 URL 从环境变量中提取。
3 应用程序日志的 elasticsearch 索引是 cuba-petclinic-logs-%date{yyyy-MM-dd} ，按天生成

进行了这些配置，应用程序将获取日志消息并将其发送给 elasticsearch，Kibana 是一个可以访问 elasticsearch 中的数据的用户界面，它可以以适当的方式展示日志信息。通过结构化和全文索引功能，日志信息可以非常容易地被访问，这种方式给直接访问日志文件要方便和高效许多。

Elasticsearch Kibana UI logging

总结

日志记录是开发人员和管理员为运行中的应用程序查找问题原因的重要部分。 它使开发人员能够打开“黑盒子”并获得有价值的信息。它的用途涵盖从性能分析到用户行为分析。

Java 和 CUBA 生态系统中的日志记录工具非常成熟，可以毫无障碍地使用。 但由于日志 API 非常通用且可以多种方式使用，能否在应用程序中获得高质量的日志信息，很大程度上取决于对于日志 API 的使用约定。 有多种机制可以避免在巨量的日志信息中迷失自我，比如对日志进行恰当的配置、使用诊断上下文(MDC) 和日志级别。

CUBA 提供了一种处理日志记录配置和日志访问的固定方式。 但因为它是基于标准的 Java 日志记录机制，因此可以很好地与集中式日志系统等其他解决方案配合使用。

更多信息