日志记录

Neo4j 提供日志用于监控目的。日志存储在 *logs* 目录中。如果要使用自定义目录,请使用参数 server.directories.logs 在 *neo4j.conf* 文件中设置该目录的路径。

日志文件

下表描述了 Neo4j 中可用的日志文件及其默认配置。在 *neo4j.conf* 文件中配置了启用或禁用哪些日志。

表 1. Neo4j 日志文件
文件名 描述 配置 默认值

neo4j.log

记录有关 Neo4j 的一般信息。对于 Debian 和 RPM 包,请运行 journalctl --unit=neo4j

true

debug.log

记录对调查 Neo4j 问题有用的信息。强烈建议将其保持启用状态。

true

http.log

记录有关 HTTP API 的信息。

false

gc.log

记录 JVM 提供的信息。

有关详细信息,请参阅 配置垃圾收集日志

false

query.log

企业版记录有关运行时间超过指定阈值的已执行查询的信息。必须是 INFOVERBOSEOFF 之一。

  • INFO 记录运行时间超过给定阈值的查询。

  • VERBOSE 记录所有查询的开始和结束时间。

  • OFF 禁用 *query.log*。

有关详细信息,请参阅 配置查询日志

VERBOSE

security.log

记录有关安全事件的信息。

true

service-out.log

Windows安装或运行 Windows 服务时的控制台输出日志。

service-error.log

Windows记录安装或运行 Windows 服务时遇到的错误信息。

默认日志配置

从 Neo4j 5.0 开始,Neo4j 使用 Log4j 2 进行日志记录。日志配置位于 *conf* 目录中,包含两个文件

  • *user-log.xml* — 提供 *neo4j.log* 的配置。

  • *server-logs.xml* — 提供 *debug.log*、*http.log*、*query.log* 和 *security.log* 的配置。

*gc.log* 由 Java 虚拟机 (JVM) 处理,并使用 JVM 参数配置。有关详细信息,请参阅 配置垃圾收集日志

如果要使用自定义目录存放 Log4j 配置文件,请使用参数 server.logs.user.configserver.logs.config 在 *neo4j.conf* 文件中设置 XML 文件的新路径。

每个配置文件包含两个主要元素:*Appenders* 和 *Loggers*

在 *Appenders* 元素中,可以定义
  • 输出位置,例如,文件、控制台、网络套接字等。

  • 输出格式,例如,纯文本、JSON、CSV 等。

  • 文件滚动时间以及在删除它们之前要保留多少个历史文件。

  • 是否以及哪些日志事件要发布以及如何发布。

在 *Loggers* 元素中,可以定义
  • 哪些日志事件要捕获以及发送到哪些 *Appenders*。

  • 要捕获的日志事件的日志级别。

  • 是否将日志事件转发到其他 *Loggers*。

有关详细信息,请参阅 Log4j 2 官方配置文档

以下示例显示了 *user-logs.xml* 文件的默认配置。

默认 *user-log.xml* 配置
<?xml version="1.0" encoding="UTF-8"?>
<!--

    Copyright (c) "Neo4j"
    Neo4j Sweden AB [https://neo4j.ac.cn]
    This file is a commercial add-on to Neo4j Enterprise Edition.

-->
<!--
    This is a log4j 2 configuration file that provides maximum flexibility.

    All configuration values can be queried with the lookup prefix "config:". You can, for example, resolve
    the path to your neo4j home directory with ${config:dbms.directories.neo4j_home}.

    Please consult https://logging.apache.ac.cn/log4j/2.x/manual/configuration.html for instructions and
    available configuration options.
-->
<Configuration status="ERROR" monitorInterval="30" packages="org.neo4j.logging.log4j"> \ (1)

    <Appenders> \ (2)
        <RollingRandomAccessFile name="Neo4jLog" fileName="${config:server.directories.logs}/neo4j.log" (3)
                                 filePattern="$${config:server.directories.logs}/neo4j.log.%02i"> (4)
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p %m%n"/> (5)
            <Policies> \ (6)
                <SizeBasedTriggeringPolicy size="20 MB"/> \ (7)
            </Policies>
            <DefaultRolloverStrategy fileIndex="min" max="7"/> \ (8)
        </RollingRandomAccessFile>

        <!-- Only used by "neo4j console", will be ignored otherwise -->
        <Console name="ConsoleAppender" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p %m%n"/>
        </Console>
    </Appenders>

    <Loggers> \ (9)
        <!-- Log level for the neo4j log. One of DEBUG, INFO, WARN, ERROR or OFF -->
        <Root level="INFO"> \ (10)
            <AppenderRef ref="Neo4jLog"/>
            <AppenderRef ref="ConsoleAppender"/>
        </Root>
    </Loggers>

</Configuration>

以下示例显示了 *server-logs.xml* 文件的默认配置。

默认 *server-logs.xml* 配置
<?xml version="1.0" encoding="UTF-8"?>
<!--

    Copyright (c) "Neo4j"
    Neo4j Sweden AB [https://neo4j.ac.cn]
    This file is a commercial add-on to Neo4j Enterprise Edition.

-->
<!--
    This is a log4j 2 configuration file.

    It is highly recommended to keep the original "debug.log" as is, to make sure enough data is captured in case
    of errors in a format that neo4j developers can work with.

    All configuration values can be queried with the lookup prefix "config:". You can, for example, resolve
    the path to your neo4j home directory with ${config:dbms.directories.neo4j_home}.

    Please consult https://logging.apache.ac.cn/log4j/2.x/manual/configuration.html for instructions and
    available configuration options.
-->
<Configuration status="ERROR" monitorInterval="30" packages="org.neo4j.logging.log4j"> \ (1)
    <Appenders> \ (2)
        <!-- Default debug.log, please keep -->
        <RollingRandomAccessFile name="DebugLog" fileName="${config:server.directories.logs}/debug.log" \ (3)
                                 filePattern="$${config:server.directories.logs}/debug.log.%02i"> \ (4)
            <Neo4jDebugLogLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p [%c{1.}] %m%n"/> \ (5)
            <Policies> \ (6)
                <SizeBasedTriggeringPolicy size="20 MB"/> \ (7)
            </Policies>
            <DefaultRolloverStrategy fileIndex="min" max="7"/> \ (8)
        </RollingRandomAccessFile>

        <RollingRandomAccessFile name="HttpLog" fileName="${config:server.directories.logs}/http.log"
                                 filePattern="$${config:server.directories.logs}/http.log.%02i">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p %m%n"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="20 MB"/>
            </Policies>
            <DefaultRolloverStrategy fileIndex="min" max="5"/>
        </RollingRandomAccessFile>

        <RollingRandomAccessFile name="QueryLog" fileName="${config:server.directories.logs}/query.log"
                                 filePattern="$${config:server.directories.logs}/query.log.%02i">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p %m%n"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="20 MB"/>
            </Policies>
            <DefaultRolloverStrategy fileIndex="min" max="7"/>
        </RollingRandomAccessFile>

        <RollingRandomAccessFile name="SecurityLog" fileName="${config:server.directories.logs}/security.log"
                                 filePattern="$${config:server.directories.logs}/security.log.%02i">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p %m%n"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="20 MB"/>
            </Policies>
            <DefaultRolloverStrategy fileIndex="min" max="7"/>
        </RollingRandomAccessFile>
    </Appenders>

    <Loggers> \ (9)
        <!-- Log levels. One of DEBUG, INFO, WARN, ERROR or OFF -->

        <!-- The debug log is used as the root logger to catch everything -->
        <Root level="INFO"> \ (10)
            <AppenderRef ref="DebugLog"/> <!-- Keep this -->
        </Root>

        <!-- The query log, must be named "QueryLogger" -->
        <Logger name="QueryLogger" level="INFO" additivity="false"> \ (11)
            <AppenderRef ref="QueryLog"/>
        </Logger>

        <!-- The http request log, must be named "HttpLogger" -->
        <Logger name="HttpLogger" level="INFO" additivity="false">
            <AppenderRef ref="HttpLog"/>
        </Logger>

        <!-- The security log, must be named "SecurityLogger" -->
        <Logger name="SecurityLogger" level="INFO" additivity="false">
            <AppenderRef ref="SecurityLog"/>
        </Logger>
    </Loggers>
</Configuration>
1 具有 monitorInterval 为 30 秒和包命名空间为 org.neo4j.logging.log4j 的配置标签。
监控间隔告诉 Log4j 定期检查 XML 文件是否有更改,并在检测到更改时重新加载该文件。
包命名空间使用 ${config:<setting>} 提供对 Neo4j 配置查找的访问权限。
2 Appenders 用于定义日志消息的写入位置。Appender 的 name 必须是唯一的,因为它在记录器引用 Appender 时使用。Neo4j 默认 Appenders 写入 *debug.log*、*http.log*、*query.log* 和 *security.log*。
3 默认情况下,Neo4j 使用 <RollingRandomAccessFile> Appender,因为它非常高效,因为它始终写入缓冲区。但是,如果服务器崩溃,最后一条日志消息可能会丢失。如果这对您来说不可接受,请改用 <RollingFile> Appender。有关详细信息,请参阅 Appenders
4 filePattern 指定文件滚动时要使用的文件模式。该模式在文件达到定义的触发器时将文件重命名为 *debug.log.01* 和 *http.log.01*。
5 PatternLayout 定义 Appender 的布局,在本例中使用 GMT+2 时区。有关详细信息,请参阅 日志布局
6 Policies 元素定义文件滚动时间以及在删除它们之前要保留多少个历史文件。
7 SizeBasedTriggeringPolicy 定义文件滚动时间。在本例中,当文件大小达到 20 MB 时,将根据 filePattern 重命名文件,并且日志文件将重新开始。在 Neo4j 4.0 中,这是使用参数 dbms.logs.user.rotation.size 配置的。
8 DefaultRolloverStrategy 定义要保留多少个历史文件。
fileIndex=min 意味着最小/最小的数字是最新的数字。
max 属性定义要保留多少个历史文件,然后将其删除,在本例中为 7 个文件。在 Neo4j 4.0 中,这是使用参数 dbms.logs.user.rotation.keep_number 配置的。
9 Loggers 用于定义日志级别以及日志消息要使用的 Appender。记录器由 name 属性引用。有关详细信息,请参阅 Loggers
10 根记录器是一个“万能”记录器,它捕获所有未被其他记录器捕获的事件,并将它们发送到 AppenderRef 元素中指定的 Appender。根记录器由 Root 元素引用。可以将其设置为 DEBUGINFOWARNERROROFF。默认日志级别为 INFO
11 还可以定义自定义记录器以捕获特定日志事件并将它们发送到 AppenderRef 元素中指定的 Appender。例如,QueryLogger 记录器(在 *server-logs.xml* 中配置)用于捕获日志级别为 INFO 或更高的日志事件,并将它们发送到 QueryLog Appender。
additivity="false" 设置为完全使用日志事件,而不将其发送到根记录器。
如果 additivity="true" 设置为 true(默认值),则日志事件也会发送到根记录器。

高级日志配置

默认日志配置是一个很好的起点,但您可能想要根据自己的需要对其进行自定义。以下部分描述了一些 Log4j 配置元素以及如何使用它们来自定义日志配置。有关更多信息和更高级的自定义(例如,过滤和扩展),请参阅 Log4j 官方配置文档

Appenders

所有 Log4j 标准 Appenders 都可以在 Neo4j 中使用。有关详细信息,请参阅 Log4j 官方 Appenders 文档

一些最常见的 Appenders 是 <RollingRandomAccessFile><RollingFile><Console>

<RollingRandomAccessFile> Appender

<RollingRandomAccessFile> 是 Neo4j 中的默认 Appender。它非常高效,对系统的影响很小,因为它始终写入缓冲区。但是,日志事件可能 不会 立即可见,如果服务器崩溃,最后一条日志消息可能会丢失。此 Appender 使用 filePattern 属性配置,该属性指定文件滚动时要使用的文件模式。该模式在文件达到定义的触发器时将文件重命名为 *debug.log.01* 和 *http.log.01*。

可能的触发器是 SizeBasedTriggeringPolicyTimeBasedTriggeringPolicySizeBasedTriggeringPolicy 定义文件滚动时间,在本例中,当文件大小达到 20 MB 时。TimeBasedTriggeringPolicy 根据时间定义文件滚动时间,在本例中,每天一次。

DefaultRolloverStrategy 定义要保留多少个历史文件以及使用哪个文件作为最新的文件。fileIndex=min 意味着最小/最小的数字是最新的数字。max 属性定义要保留多少个历史文件,然后将其删除,在本例中为 7 个文件。

有关详细信息,请参阅 Log4j 官方 RollingRandomAccessFile Appender 文档

<RollingFile> Appender

<RollingFile> Appender 与 <RollingRandomAccessFile> 非常类似,但它将日志事件写入文件。它在满足特定条件时滚动。一个标准方案是每天保留一个日志文件,或者在达到特定大小后滚动一个日志文件。

每天使用一个新日志文件的滚动文件 Appender 示例
<RollingFile name="myLog" fileName="${config:server.directories.logs}/my.log"
                       filePattern="${config:server.directories.logs}/my-%d{yyyy-MM-dd}.log">
  <!-- Layout -->
  <Policies>
      <TimeBasedTriggeringPolicy />
  </Policies>
</RollingFile>

滚动还支持压缩滚出的文件。在 filePattern 属性中添加 .gz.zip.bz2.deflate.pack200 之一作为后缀会导致文件使用适当的压缩方案进行压缩。

使用 zip 压缩的滚动文件 Appender 示例
<RollingFile name="myLog" fileName="${config:server.directories.logs}/my.log"
                       filePattern="${config:server.directories.logs}/my.%i.log.zip">
  <!-- Layout -->
  <Policies>
      <SizeBasedTriggeringPolicy size="20 MB"/>
  </Policies>
</RollingFile>

<Console> Appender

控制台 Appender 将日志事件输出到 *stdout* 或 *stderr*。它仅由“neo4j 控制台”使用。

控制台 Appender 示例
<Console name="console" target="SYSTEM_OUT"> <!-- or SYSTEM_ERR -->
  <PatternLayout pattern="%m%n"/>
</Console>

日志布局

日志文件可以用很多不同的方式写入,称为布局。Neo4j 附带了所有 Log4j 2 的默认布局,以及一些特定于 Neo4j 的布局。有关默认 Log4j 2 布局的详细信息,请参阅 Log4j 官方文档

<PatternLayout>

<PatternLayout> 是最常见的布局。它是一个灵活的布局,可以使用模式字符串进行配置,该模式字符串在 pattern 属性中指定。例如

<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p [%c{1.}] %m%n"/>

pattern 由以 % 为前缀的不同转换器组成。转换器将替换为日志事件中的对应值。

表 2. 模式布局转换器示例
转换器 描述

%d{date-pattern}{timezone}

日志事件的日期。时区是可选的。如果省略,将使用系统时间。

%p

事件的日志级别。可以是 DEBUGINFOWARNERROR。在 % 符号和 p 之间添加 -5 将使级别正好为 5 个字符长。

%c

日志事件起源的类。在类名后添加 {1.} 会压缩包名,例如 org.apache.commons.Foo 将变为 o.a.c.Foo

%m

日志事件的日志消息。

%n

特定于系统的换行符。

有关所有可用的转换器,请参阅 Log4j 2 模式布局文档

<Neo4jDebugLogLayout>

<Neo4jDebugLogLayout> 布局本质上与 PatternLayout 相同。主要区别在于在日志文件开头插入了一个包含诊断信息的标题,这些信息对 Neo4j 开发人员很有用。此布局通常仅用于 debug.log 文件。

Neo4j 调试日志布局的使用示例
<Neo4jDebugLogLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p [%c{1.}] %m%n"/>

<JsonTemplateLayout>

<JsonTemplateLayout> 等同于模式布局。有关更多信息,请参阅 Log4j 官方文档

有两种方法可以配置 JSON 模板布局。

  • 您可以指定一个 JSON 事件模板文件,布局将使用该文件。JSON 模板文件可以位于文件系统中。

    <JsonTemplateLayout eventTemplateUri="file://path/to/template.json"/>
  • JSON 事件模板文件可以嵌入到 XML 配置中

    <JsonTemplateLayout>
      <eventTemplate>
        <![CDATA[
          {
            "time": { "$resolver": "timestamp",
              "pattern": { "format": "yyyy-MM-dd HH:mm:ss.SSSZ", "timeZone": "UTC" }
            },
            "level": { "$resolver": "level", "field": "name" },
            "message": { "$resolver": "message" },
            "includeFullMap": { "$resolver": "map", "flatten": true },
            "stacktrace": { "$resolver": "exception", "field": "message" }
          }
        ]]>
      </eventTemplate>
    </JsonTemplateLayout>

还有一些内置模板可从类路径获取,例如

<JsonTemplateLayout eventTemplateUri="classpath:org/neo4j/logging/StructuredJsonLayout.json"/>
表 3. 可用的内置模板
eventTemplateUri 描述

classpath:org/neo4j/logging/StructuredJsonLayout.json

结构化日志消息的布局。仅适用于 query.logsecurity.log

classpath:org/neo4j/logging/StructuredLayoutWithMessage.json

用于记录 JSON 消息的通用布局。可用于任何日志文件。

classpath:org/neo4j/logging/QueryLogJsonLayout.json

与 Neo4j 4.x 查询日志向后兼容的 JSON 布局。

classpath:LogstashJsonEventLayoutV1.json

classpath:GelfLayout.json

Graylog 扩展日志格式 (GELF) 有效载荷规范,包含附加的 _thread_logger 字段。

classpath:GcpLayout.json

Google Cloud Platform 结构化日志记录,包含附加的 _thread_logger_exception 字段。

classpath:JsonLayout.json

与不太灵活的 <JsonLayout> 相同的布局。

过滤器

您还可以配置过滤器来确定是否发布日志事件以及如何发布。有关详细信息,请参阅 Log4j 官方文档

插件

您还可以通过将插件放到 plugin 目录中来将插件添加到 Log4j。有关详细信息,请参阅 Log4j 官方关于插件的文档

记录器

记录器将日志事件转发到追加器。可以有任意数量的 <Logger> 元素,但只有一个 <Root> 记录器元素。记录器可以是累加的。累加记录器将其日志事件转发到其追加器,然后将日志事件传递到下一个匹配的记录器。非累加记录器将其日志事件转发到其追加器,然后丢弃事件。根记录器是一个特殊的记录器,它匹配所有内容,因此,如果其他记录器没有接收到日志事件,则根记录器将接收到。因此,最佳实践始终包含一个根记录器,以确保不会错过任何日志事件。

记录器的配置
<Configuration>
    <!-- Appenders -->
    <Loggers>
        <Root level="WARN">
            <AppenderRef ref="DebugLog"/>
        </Root>

        <Logger name="HttpLogger" level="INFO" additivity="false">
            <AppenderRef ref="HttpLog"/>
        </Logger>
    </Loggers>
</Configuration>

记录器具有一个 level,用于过滤日志事件。级别还可以包含不同严重程度的级别。例如,level="INFO" 的记录器将转发 INFOWARNERROR 类型的日志事件。level="WARN" 的记录器只记录 WARNERROR 事件。

下表列出了 Neo4j 引发的所有日志级别及其严重程度级别

表 4. 日志级别
消息类型 严重程度级别 描述

DEBUG

低严重程度

报告有关已引发错误和可能解决方案的详细信息。

INFO

低严重程度

报告状态信息和非严重错误。

WARN

低严重程度

报告需要关注但不太严重的错误。

ERROR

高严重程度

报告阻止 Neo4j 服务器运行的错误,必须立即解决。

有关记录器的更多详细信息,请参阅 Log4j 官方文档 → 配置记录器

配置垃圾回收日志

垃圾回收日志(简称 GC 日志)是特殊的,无法使用 Log4j 2 配置。GC 日志由 Java 虚拟机 (JVM) 处理,必须直接传递到命令行。为了简化此过程,Neo4j 在 neo4j.conf 中公开了以下设置

表 5. 垃圾回收日志 配置
垃圾回收日志 配置 默认值 描述

server.logs.gc.enabled

false

启用垃圾回收日志记录。

server.logs.gc.options

-Xlog:gc*,safepoint,age*=trace

垃圾回收日志记录选项。有关可用选项,请参阅所用 JVM 发行版的文档。

server.logs.gc.rotation.keep_number

5

垃圾回收日志历史文件最大数量。

server.logs.gc.rotation.size

20MB

垃圾回收日志轮换的阈值大小。

配置安全日志

Neo4j 提供安全事件日志记录,用于记录所有安全事件。当配置 dbms.security.auth_enabled 设置为 true(默认值)时,安全日志会自动启用。它确保对 Neo4j 的所有请求都经过身份验证。有关安全日志的更多配置,请参阅 <NEO4J_HOME>/conf/server-logs.xml

对于本机用户管理,以下操作将被记录

  • 登录尝试——默认情况下,成功和失败的登录都会被记录。

  • 针对 system 数据库运行的所有 管理命令

  • 基于角色的访问控制的授权失败。

如果使用 LDAP 作为身份验证方法,一些 LDAP 配置错误也会被记录,以及 LDAP 服务器通信事件和失败。

如果预计会有许多程序化交互,建议通过在 neo4j.conf 文件中设置 dbms.security.log_successful_authentication 参数来禁用成功登录的日志记录

dbms.security.log_successful_authentication=false

安全日志可以使用 JSON 布局。要更改格式,必须将 SecurityLogger 的布局从使用 PatternLayout

<RollingRandomAccessFile name="SecurityLog" fileName="${config:server.directories.logs}/security.log"
                                 filePattern="$${config:server.directories.logs}/security.log.%02i">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p %m%n"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="20 MB"/>
            </Policies>
            <DefaultRolloverStrategy fileIndex="min" max="7"/>
</RollingRandomAccessFile>

更改为使用 JsonTemplateLayout

<RollingRandomAccessFile name="SecurityLog" fileName="${config:server.directories.logs}/security.log"
                                 filePattern="$${config:server.directories.logs}/security.log.%02i">
            <JsonTemplateLayout eventTemplateUri="classpath:org/neo4j/logging/StructuredJsonLayout.json"/>
            <Policies>
                <SizeBasedTriggeringPolicy size="20 MB"/>
            </Policies>
            <DefaultRolloverStrategy fileIndex="min" max="7"/>
 </RollingRandomAccessFile>

以下信息在 JSON 格式中可用

表 6. JSON 格式日志条目
名称 描述

time

日志消息的时间戳。

level

日志级别。

type

始终为 security

source

连接详细信息。

database

执行命令的数据库名称。此字段是可选的,因此并非所有安全事件都会填充此字段。

username

连接到安全事件的用户。此字段已被 executingUser 弃用。

executingUser

触发安全事件的用户姓名。与 authenticatedUser 相同,或冒充用户。

authenticatedUser

已验证并连接到安全事件的用户姓名。

message

日志消息。

stacktrace

如果日志消息包含堆栈跟踪,则包含在内。

安全日志的纯格式示例

2019-12-09 13:45:00.796+0000 INFO  [johnsmith]: logged in
2019-12-09 13:47:53.443+0000 ERROR [johndoe]: failed to log in: invalid principal or credentials
2019-12-09 13:48:28.566+0000 INFO  [johnsmith]: CREATE USER janedoe SET PASSWORD '********' CHANGE REQUIRED
2019-12-09 13:48:32.753+0000 INFO  [johnsmith]: CREATE ROLE custom
2019-12-09 13:49:11.880+0000 INFO  [johnsmith]: GRANT ROLE custom TO janedoe
2019-12-09 13:49:34.979+0000 INFO  [johnsmith]: GRANT TRAVERSE ON GRAPH * NODES A, B (*) TO custom
2019-12-09 13:49:37.053+0000 INFO  [johnsmith]: DROP USER janedoe
2019-12-09 13:52:24.685+0000 INFO  [johnsmith:alice]: impersonating user alice logged in

配置查询日志

查询日志记录默认启用,由设置 db.logs.query.enabled 控制。它有助于您分析长时间运行的查询,并且不会影响系统性能。默认情况下,会记录所有查询,但建议记录超过特定阈值的查询。

配置设置

以下值可用于参数 db.logs.query.enabled

表 7. db.logs.query.enabled
选项 描述

OFF

完全禁用日志记录。

INFO

在成功或失败的查询结束时记录。 db.logs.query.threshold 参数用于确定记录查询的阈值。如果查询的执行时间超过此阈值,则会记录该查询。将阈值设置为 0s 将导致记录所有查询。

VERBOSE

Default记录所有查询的开始和结束,无论 db.logs.query.threshold 是什么。

以下配置设置可用于查询日志记录

表 8. 查询日志 配置
查询日志 配置 默认值 描述

db.logs.query.early_raw_logging_enabled

false

记录查询文本和参数,不进行密码混淆。这允许在解析开始之前更早地记录查询。

db.logs.query.enabled

VERBOSE

记录已执行的查询。

db.logs.query.max_parameter_length

2147483647

此配置选项允许您设置要包含在日志中的最大参数长度。超过此长度的参数将被截断并在末尾添加 ...。这适用于查询中的每个参数。

db.logs.query.obfuscate_literals

false

如果为 true,则在写入日志之前混淆所有查询字面量。当 Cypher 查询公开敏感信息时,这很有用。

节点标签、关系类型和映射属性键仍然显示。更改此设置不会影响缓存的查询。因此,如果您希望此更改立即生效,您还需要清除查询缓存;CALL db.clearQueryCaches()

这不会混淆参数中的字面量。如果日志中不需要参数值,请将 db.logs.query.parameter_logging_enabled=false 设置为 false

db.logs.query.parameter_logging_enabled

true

记录执行的查询的日志参数。如果您不想显示敏感信息,可以禁用此配置设置。

db.logs.query.plan_description_enabled

false

此配置选项允许您记录每个查询的查询计划。查询计划显示为一个描述表,有助于调试。每次运行 Cypher 查询时,它都会生成并使用一个计划来执行代码。生成的计划可能会受到数据库更改的影响,例如添加新索引。因此,无法查看原始查询执行所使用的计划的历史记录。

启用此选项会对数据库性能产生影响,因为需要花费时间来准备计划并将其包含在查询日志中。不建议日常使用。

db.logs.query.threshold

0s

如果查询执行时间超过此阈值,则在查询完成后记录该查询(前提是查询日志设置为 INFO)。阈值为 0 秒表示记录所有查询。

db.logs.query.transaction.enabled

OFF

跟踪查询日志中事务的开始和结束。日志条目写入查询日志。它们包括特定查询的事务 ID 以及事务的开始和结束。您还可以选择日志级别(OFFINFOVERBOSE)。如果选择 INFO,则必须超过写入日志之前的时长(db.logs.query.transaction.threshold)。

db.logs.query.transaction.threshold

0s

如果事务打开时间超过此阈值(持续时间),则在事务完成后记录该事务,前提是事务日志设置为 INFO。默认值为 0 秒,表示记录所有事务。这在识别查询执行和事务提交后出现明显时间间隔时很有用,特别是在围绕锁定的性能分析中。

配置简单查询日志记录

在此示例中,查询日志记录设置为 INFO,所有其他查询日志参数都使用默认值。

db.logs.query.enabled=INFO

以下是使用此基本配置的查询日志示例

2017-11-22 14:31 ... INFO  9 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:31 ... INFO  0 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:32 ... INFO  3 ms: server-session	http	127.0.0.1	/db/data/cypher	neo4j - CALL dbms.procedures() - {}
2017-11-22 14:32 ... INFO  1 ms: server-session	http	127.0.0.1	/db/data/cypher	neo4j - CALL dbms.showCurrentUs...
2017-11-22 14:32 ... INFO  0 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:32 ... INFO  0 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59167	...
2017-11-22 14:32 ... INFO  2 ms: bolt-session	bolt	johndoe	neo4j-javascript/1.4.1		client/127.0.0.1:59261	...

配置更详细的查询日志记录

在此示例中,查询日志已启用,还启用了一些其他日志记录

db.logs.query.enabled=INFO
db.logs.query.parameter_logging_enabled=true
db.logs.query.threshold=<appropriate value>

以下示例查询在 Movies 数据库上运行

MATCH (n:Person {name:'Tom Hanks'})-[:ACTED_IN]->(n1:Movie)<-[:DIRECTED]-(n2:Person {name:"Tom Hanks"}) RETURN n1.title

<.file>query.log 中的对应查询日志为

2017-11-23 12:44:56.973+0000 INFO  1550 ms: (planning: 20, cpu: 920, waiting: 10) - 13792 B - 15 page hits, 0 page faults - bolt-session	bolt	neo4j	neo4j-javascript/1.4.1		client/127.0.0.1:58189	server/127.0.0.1:7687>	neo4j - match (n:Person {name:'Tom Hanks'})-[:ACTED_IN]->(n1:Movie)<-[:DIRECTED]-(n2:Person {name:"Tom Hanks"}) return n1.title; - {} - {}

检查特定查询参数时,一个明显但至关重要的注意事项是确保仅分析与该特定查询计划相关的条目,而不是例如每个日志条目按顺序的 CPU、时间、字节等。

以下是资源使用参数的细分,其中包含与上述查询相对应的描述

2017-11-23 12:44:56.973+0000

日志时间戳。

INFO

日志类别。

1550 ms

查询执行中花费的总累计墙上时间。它是规划时间 + CPU + 等待 + 任何其他处理时间的总和,例如获取执行线程所需的时间。此数字是每个 CPU 线程执行查询时累积的。

规划

是指 Cypher 引擎创建查询计划所花费的时间。对于重复查询,计划可能会被缓存,因此,此类查询的规划时间将短于以前未规划的查询的规划时间。在本例中,这为 1550 毫秒的总执行时间贡献了 20 毫秒。

CPU 时间

是指执行查询的各个线程所花费的时间,例如,查询在 08:00 提交。它使用 CPU 720 毫秒,但随后 CPU 切换到另一个查询,因此第一个查询不再使用 CPU。然后,在 100 毫秒后,它再次获取/使用 CPU 200 毫秒(需要加载更多结果,由驱动程序通过客户端请求),然后查询在 08:01:30 完成,因此总持续时间为 1550 毫秒(包括两次往返的某些往返时间),CPU 为 720+200=920 毫秒。

等待

查询在执行之前花费的等待时间(以毫秒为单位),例如,如果现有查询具有新查询必须等待释放的锁。在本例中,这为 1550 毫秒的总执行时间贡献了 10 毫秒。
重要的是要注意,客户端仅在记录缓冲区为空时从服务器请求数据(一次从服务器往返可能最终获得多个记录),并且如果客户端未及时读取数据,服务器将停止将数据推送到传出缓冲区。因此,这取决于结果集的大小。如果结果集相对较小并且适合一次往返,则客户端将立即接收所有结果,并且服务器将在没有客户端影响的情况下完成处理。同时,如果结果集很大,则客户端处理时间将影响总时间,因为它直接连接到何时从服务器请求新数据。

13792 B

记录的执行查询的分配字节数。这是查询生命周期中使用的堆内存量。记录的数字是在查询持续时间内累积的,即对于内存密集型或长时间运行的查询,该值可能大于当前内存分配。

15 页命中

页面命中表示结果是从页面缓存而不是磁盘返回的。在本例中,页面缓存命中了 15 次。

0 页错误

页面错误表示查询结果数据不在 dbms.memory.pagecache 中,因此必须从文件系统中获取。在本例中,查询结果完全从上面提到的 8 次页面缓存命中中返回,因此没有必要从磁盘进行 0 次命中。

bolt-session

会话类型。

bolt

查询使用的浏览器 ←→ 数据库通信协议。

neo4j

进程 ID。

neo4j-javascript/1.4.1

驱动程序版本。

client/127.0.0.1:52935

使用的查询客户端出站 IP:port

server/127.0.0.1:7687>

使用的服务器监听 IP:port

neo4j

查询执行者的用户名

match (n:Person {name:'Tom Hanks'})-[:ACTED_IN]→(n1:Movie)←[:DIRECTED]-(n2:Person {name:"Tom Hanks"}) return n1.title

执行的查询。

最后两个括号 {} {} 用于查询参数和 txMetaData

将元数据附加到事务

您可以将元数据附加到事务,并使用内置过程 tx.setMetaData 将其打印在查询日志中。

Neo4j 驱动程序还支持将元数据附加到事务。有关更多信息,请参阅相应的驱动程序手册。

每个图应用程序都应遵循一个约定,用于将元数据与发送到 Neo4j 的查询一起传递

{
  app: "neo4j-browser_v4.4.0", (1)
  type: "system" (2)
}
1 app 可以是用户代理样式名称加上版本。
2 type 可以是以下之一
  • system — 由应用程序自动运行的查询。

  • user-direct — 用户直接提交到/通过应用程序的查询。

  • user-action — 用户执行的操作产生的查询。

  • user-transpiled — 从用户输入派生的查询。

这通常以编程方式完成,但也可以与 Neo4j 开发工具一起使用。
通常,您会在用户数据库上启动事务,并通过调用 tx.setMetaData 将元数据列表附加到事务。您还可以使用过程 CALL tx.getMetaData() 来显示当前事务的元数据。这些示例使用 Neo4j 浏览器指南 中的 MovieGraph 数据集。

示例 1. 使用 cypher-shell 将元数据附加到事务
Cypher Shell 始终默认添加遵循约定的元数据。在此示例中,默认值被覆盖。
neo4j@neo4j> :begin
neo4j@neo4j# CALL tx.setMetaData({app: 'neo4j-cypher-shell_v.4.4.0', type: 'user-direct', user: 'jsmith'});
0 rows
ready to start consuming query after 2 ms, results consumed after another 0 ms
neo4j@neo4j# CALL tx.getMetaData();
+--------------------------------------------------------------------------+
| metadata                                                                 |
+--------------------------------------------------------------------------+
| {app: "neo4j-cypher-shell_v.4.4.0", type: "user-direct", user: "jsmith"} |
+--------------------------------------------------------------------------+

1 row
ready to start consuming query after 37 ms, results consumed after another 2 ms
neo4j@neo4j# MATCH (n:Person) RETURN n  LIMIT 5;
+----------------------------------------------------+
| n                                                  |
+----------------------------------------------------+
| (:Person {name: "Keanu Reeves", born: 1964})       |
| (:Person {name: "Carrie-Anne Moss", born: 1967})   |
| (:Person {name: "Laurence Fishburne", born: 1961}) |
| (:Person {name: "Hugo Weaving", born: 1960})       |
| (:Person {name: "Lilly Wachowski", born: 1967})    |
+----------------------------------------------------+

5 rows
ready to start consuming query after 2 ms, results consumed after another 1 ms
neo4j@neo4j# :commit
query.log 文件中的示例结果
2021-07-30 14:43:17.176+0000 INFO  id:225 - 2 ms: 136 B - bolt-session	bolt	neo4j-cypher-shell/v4.4.0		client/127.0.0.1:54026	server/127.0.0.1:7687>	neo4j - neo4j -
MATCH (n:Person) RETURN n  LIMIT 5; - {} - runtime=pipelined - {app: 'neo4j-cypher-shell_v.4.4.0', type: 'user-direct', user: 'jsmith'}
示例 2. 使用 Neo4j 浏览器将元数据附加到事务
CALL tx.setMetaData({app: 'neo4j-browser_v.4.4.0', type: 'user-direct', user: 'jsmith'})
MATCH (n:Person) RETURN n LIMIT 5
query.log 文件中的示例结果
2021-07-30 14:51:39.457+0000 INFO  Query started: id:328 - 0 ms: 0 B - bolt-session	bolt	neo4j-browser/v4.4.0		client/127.0.0.1:53666	server/127.0.0.1:7687>	neo4j - neo4j - MATCH (n:Person) RETURN n  LIMIT 5 - {} - runtime=null - {type: 'system', app: 'neo4j-browser_v4.4.0'}
示例 3. 使用 Neo4j Bloom 将元数据附加到事务
CALL tx.setMetaData({app: 'neo4j-browser_v.1.7.0', type: 'user-direct', user: 'jsmith'})
MATCH (n:Person) RETURN n LIMIT 5
query.log 文件中的示例结果
2021-07-30 15:09:54.048+0000 INFO  id:95 - 1 ms: 72 B - bolt-session	bolt	neo4j-bloom/v1.7.0		client/127.0.0.1:54693	server/127.0.0.1:11003>	neo4j - neo4j - RETURN TRUE - {} - runtime=pipelined - {app: 'neo4j-bloom_v1.7.0', type: 'system'}

在 Neo4j 浏览器和 Bloom 中,用户提供的元数据始终会被系统元数据替换。

对查询日志使用 JSON 格式

查询日志可以使用 JSON 布局。要更改格式,必须将 QueryLogger 的布局从使用 PatternLayout 更改

<RollingRandomAccessFile name="QueryLog" fileName="${config:server.directories.logs}/query.log"
                     filePattern="${config:server.directories.logs}/query.log.%02i"
             createOnDemand="true">
    <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSSZ}{GMT+0} %-5p %m%n"/>
    <Policies>
        <SizeBasedTriggeringPolicy size="20 MB"/>
    </Policies>
    <DefaultRolloverStrategy fileIndex="min" max="7"/>
</RollingRandomAccessFile>

更改为使用 JsonTemplateLayout

<RollingRandomAccessFile name="QueryLog" fileName="${config:server.directories.logs}/query.log"
                     filePattern="${config:server.directories.logs}/query.log.%02i"
             createOnDemand="true">
    <JsonTemplateLayout eventTemplateUri="classpath:org/neo4j/logging/QueryLogJsonLayout.json"/>
    <Policies>
        <SizeBasedTriggeringPolicy size="20 MB"/>
    </Policies>
    <DefaultRolloverStrategy fileIndex="min" max="7"/>
</RollingRandomAccessFile>

JSON 格式日志条目

QueryLogJsonLayout.json 模板模拟 4.x 布局,并包含以下信息

表 9. JSON 格式日志条目
名称 描述

time

日志消息的时间戳。

level

日志级别。

type

有效选项为 querytransaction

stacktrace

当日志消息关联有堆栈跟踪时包含。

如果日志条目的类型为 query,则可以使用以下附加字段

表 10. 类型为 query 的日志条目的 JSON 格式
名称 描述

event

有效选项为 startfailsuccess

id

查询 ID。当 db.logs.query.enabledVERBOSE 时包含。

elapsedTimeMs

以毫秒为单位的经过时间。

planning

花费在规划上的毫秒数。

cpu

在 CPU 上主动执行所花费的毫秒数。

waiting

在锁或其他查询上等待所花费的毫秒数,而不是主动运行此查询。

allocatedBytes

查询分配的字节数。

pageHits

页面命中的次数。

pageFaults

页面错误的次数。

source

连接详细信息。

database

运行查询的数据库名称。

executingUser

执行查询的用户的名称。与 authenticatedUser 相同或模拟用户。

authenticatedUser

执行身份验证并执行查询的用户的名称。

query

查询文本。

queryParameters

查询参数。当 db.logs.query.parameter_logging_enabledtrue 时包含。

runtime

用于运行查询的运行时。

annotationData

附加到事务的元数据。

failureReason

失败原因。在适用时包含。

errorInfo

在 5.25 中引入 GQL 错误信息作为 JSON 对象。有关 errorInfo JSON 对象内容的详细信息,请参阅GQL 错误信息

transactionId

正在运行的查询的事务 ID。

queryPlan

查询计划。当 db.logs.query.plan_description_enabledtrue 时包含。

如果日志条目的类型为 transaction,则可以使用以下附加字段

表 11. 类型为 transaction 的日志条目的 JSON 格式
名称 描述

event

有效选项为 startrollbackcommit

database

运行事务的数据库名称。

executingUser

连接到事务的用户的名称。与 authenticatedUser 相同或模拟用户。

authenticatedUser

执行身份验证并连接到事务的用户的名称。

transactionId

事务的 ID。

GQL 错误信息

查询日志在 JSON 对象 errorInfo 下包含 GQL 错误信息。 errorInfo 可以包含以下元素

  • GQLSTATUS — 一个 5 个字符的字母数字代码,用于识别错误。

  • statusDescription — 描述错误的消息。

  • classification — 错误类型,表示客户端、瞬态和数据库错误的分类。

  • position — 查询中发生此错误的位置(一个包含 columnoffsetline 字段的 JSON 对象)。

  • cause — 一个包含当前 errorInfo JSON 对象原因的 errorInfo JSON 对象的 JSON 对象。

当异常没有 GQL 对象时,会返回默认的 GQLSTATUS 代码 50N42。 从 Neo4j 5.25 开始,GQL 对象被添加到异常中;因此,您可以预期许多 50N42 代码。 但是,不要依赖此默认代码很重要,因为未来的 Neo4j 版本可能会通过将适当的 GQL 对象添加到异常中来更改它。 此外,外部过程的 GQL 代码尚未稳定。

以下是 errorInfo JSON 对象的示例

数据库错误的 errorInfo JSON 对象
...
"errorInfo": {
    "GQLSTATUS": "51N66",
    "statusDescription": "error: system configuration or operation exception - resource exhaustion. Insufficient resources to complete the request.",
    "cause": {
      "GQLSTATUS": "51N55",
      "statusDescription": "error: system configuration or operation exception - cannot create additional database. Failed to create the database `db10`. The limit of databases is reached. Either increase the limit using the config setting dbms.max_databases or drop a database.",
      "classification": "DATABASE_ERROR"
    },
    "classification": "DATABASE_ERROR"
  },
...
客户端错误的 errorInfo JSON 对象
...
"errorInfo": {
    "GQLSTATUS": "42N62",
    "statusDescription": "error: syntax error or access rule violation - variable not defined. Variable `m` not defined.",
    "position": {
      "column": 18,
      "offset": 17,
      "line": 1
    },
    "classification": "CLIENT_ERROR"
  },
"query": "MATCH (n) RETURN m",
...