知识库

解析 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 分钟内完成。