解析 JSON 查询日志
有时我们需要检查查询日志,以找出运行时间最长的查询和/或其他问题查询,例如缺少索引的查询或未正确使用参数的查询。
这可以通过解析并排序查询日志的属性来实现;在使用 CSV 格式的查询日志时通常比较直接,但在像 Aura 这样的 JSON 格式日志中,我们可以使用下面的 jq 命令按需获取运行时间最长的查询。
Aura
cat query.log.json |
jq '. | sort_by(.jsonPayload.elapsedTimeMs) | reverse ' |
jq '.[] | select(.jsonPayload.event == "success") |
{ timestamp: .timestamp,
severity: .severity,
event: .jsonPayload.event,
id: .jsonPayload.id,
elapsedTimeMs: .jsonPayload.elapsedTimeMs,
allocatedBytes: .jsonPayload.allocatedBytes,
pageFaults: .jsonPayload.pageFaults,
pageHits: .jsonPayload.pageHits,
waiting: .jsonPayload.waiting,
planning: .jsonPayload.planning,
runtime: .jsonPayload.runtime,
username: .jsonPayload.username,
query: .jsonPayload.query } | join(" | ") '
这将产生以下按行格式化的输出
"2022-10-20T04:51:22.485Z | INFO | success | 13452855 | 1792 | 248 | 0 | 905357 | 0 | 0 | slotted | neo4j | MATCH (n) return n"
本地部署
另一方面,在非 Aura 环境中,我们需要使用下面版本的 jq 脚本,以适配下方所示的略有不同的格式。
{
"time": "2022-10-23 00:09:37.772+0000",
"level": "INFO",
"event": "success",
"type": "query",
"elapsedTimeMs": 2,
"planning": 0,
"cpu": 2,
"waiting": 0,
"allocatedBytes": 176,
"pageHits": 4,
"pageFaults": 0,
"source": "bolt-session\tbolt\tneo4j-browser/v5.0.0\t\tclient/127.0.0.1:49863\tserver/127.0.0.1:11004>",
"database": "neo4j",
"username": "neo4j",
"executingUser": "neo4j",
"authenticatedUser": "neo4j",
"query": "MATCH (tom {name: \"Tom Hanks\"}) RETURN tom",
"queryParameters": "{}",
"runtime": "pipelined",
"annotationData": "{type: 'user-direct', app: 'neo4j-browser_v5.0.0'}"
}
因此我们的 jq 命令将如下所示
cat query.log.json |
jq -s -c 'sort_by(.elapsedTimeMs) | reverse | .[]' |
jq '. | select( .event == "success") |
{ time: .time,
level: .level,
event: .event,
type: .type,
id: .id,
elapsedTimeMs: .elapsedTimeMs,
planning: .planning,
cpu: .cpu,
waiting: .waiting,
allocatedBytes: .allocatedBytes,
pageHits: .pageHits,
pageFaults: .pageFaults,
source: .source,
username: .username,
executingUser: .executingUser,
authenticatedUser: .authenticatedUser,
authenticatedUser: .authenticatedUser,
runtime: .runtime,
query: .query,
queryParameters: .queryParameters } | join(" | ") '
输出如下所示
"2022-10-23 00:09:16.352+0000 | INFO | success | query | | 95 | 62 | 91 | 0 | 0 | 9 | 0 | bolt-session\tbolt\tneo4j-browser/v5.0.0\t\tclient/127.0.0.1:49863\tserver/127.0.0.1:11004> | neo4j | neo4j | neo4j | pipelined | EXPLAIN MATCH (nineties:Movie) WHERE nineties.released >= 1990 AND nineties.released < 2000 RETURN nineties.title | {}"
"2022-10-23 00:09:31.071+0000 | INFO | success | query | | 27 | 26 | 26 | 0 | 0 | 1 | 0 | bolt-session\tbolt\tneo4j-browser/v5.0.0\t\tclient/127.0.0.1:49863\tserver/127.0.0.1:11004> | neo4j | neo4j | neo4j | pipelined | EXPLAIN MATCH (tom {name: \"Tom Hanks\"}) RETURN tom | {}"
最后需要说明的是,上述命令在运行时会占用大量内存。例如,对一个 7GB(未压缩)且包含约 400 万条记录的文件,内存使用约 60GB,耗时约 10 分钟即可完成。
此页面有帮助吗?