知识库

在查询日志中显示查询 CPU 利用率和已分配字节

在 Neo4j 3.3 和更早版本中,当使用以下配置参数启用查询日志记录时

# Log executed queries that takes longer than the configured threshold. Enable by uncommenting this line.
dbms.logs.query.enabled=true

# If the execution of query takes more time than this threshold, the query is logged. If set to zero then all queries
# are logged.
dbms.logs.query.threshold=0

# The file size in bytes at which the query log will auto-rotate. If set to zero then no rotation will occur. Accepts a
# binary suffix "k", "m" or "g".
dbms.logs.query.rotation.size=20m

# Maximum number of history files for the query log.
dbms.logs.query.rotation.keep_number=7

# Include parameters for the executed queries being logged (this is enabled by default).
dbms.logs.query.parameter_logging_enabled=true

# Uncomment this line to include detailed time information for the executed queries being logged:
dbms.logs.query.time_logging_enabled=true

# Uncomment this line to include bytes allocated by the executed queries being logged:
dbms.logs.query.allocation_logging_enabled=true

# Uncomment this line to include page hits and page faults information for the executed queries being logged:
dbms.logs.query.page_logging_enabled=true

日志将以如下所示的输出写入

2018-10-29 21:07:37.219+0000 INFO  31 ms: (planning: 0, cpu: 29, waiting: 0) - 1969624 B - 0 page hits, 6 page faults - bolt-session	bolt	neo4j	neo4j-javascript/1.5.3		client/127.0.0.1:65274	server/127.0.0.1:7687>	neo4j - match (n:Person {name:"Keanu Reeves"})-[:ACTED_IN]->(m) return m - {} - {}

请注意,它显示 CPU - cpu: 29 和已分配字节 - 1969624 B

但是,从 Neo4j 3.4 开始,使用上述设置将无法捕获 CPU 和已分配字节,因为默认情况下已禁用跟踪。由于捕获 CPU 和已分配字节时会产生明显的开销,因此 Neo4j 3.4 更改了默认行为,以避免资源争用。因此,即使使用 dbms.logs.query.time_logging_enabled=truedbms.logs.query.allocation_logging_enabled=true 启用查询日志记录,查询日志中的输出也将缺少 CPU已分配字节,如下所示

2018-10-29 21:17:29.222+0000 INFO  30 ms: (planning: 0, waiting: 0) - 9 page hits, 0 page faults - bolt-session	bolt	neo4j	neo4j-javascript/1.5.3		client/127.0.0.1:65383	server/127.0.0.1:7687>	neo4j - match (n:Person {name:"Keanu Reeves"})-[:ACTED_IN]->(m) return m - {} - {}

为了捕获查询 CPU 利用率和已分配字节,必须将以下配置参数设置为 true 以覆盖默认值 (false)。

dbms.track_query_allocation=true
dbms.track_query_cpu_time=true

使用这些设置,query.log 将显示如下

2018-10-29 21:21:04.446+0000 INFO  141 ms: (planning: 124, cpu: 139, waiting: 0) - 19388616 B - 10 page hits, 0 page faults - bolt-session	bolt	neo4j	neo4j-javascript/1.6.1		client/127.0.0.1:65482	server/127.0.0.1:7687>	neo4j - EXPLAIN match (n:Person {name:"Keanu Reeves"})-[:ACTED_IN]->(m) return m - {} - {}