【mongoDB】mongoDB日志统计分析

mongoDB 某个分片日志示例：

2024-06-27T11:09:45.649+0800 I COMMAND [conn389929] command testDB.T_Test command: find { find: "T_Test", filter: { _id: "63759e9fd08e0f5f8e8270e7" }, limit: 1, shardVersion: [ Timestamp 22528000|1, ObjectId('5d6785e8e65179d5d4e78e46') ] } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 reslen:718 locks:{ Global: { acquireCount: { r: 4 }, acquireWaitCount: { r: 2 }, timeAcquiringMicros: { r: 57614434 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_command 57696ms

这个时间戳 "2024-06-27T11:09:45.649+0800" 可以分解为以下几个部分：

• 日期部分: 2024年6月27日 (年-月-日)
• 时间部分: 11时09分45.649秒 (时:分:秒.毫秒)
• 时区偏移: +0800，表示东八区，即中国标准时间（CST），比协调世界时（UTC）快8小时。

因此，这个时间戳表示在中国标准时间（CST）2024年6月27日上午11时09分45.649秒。

如何过滤出 protocol:op_query 或者 protocol:op_command大于 5000ms 的所有日志 ？

// mongoDB 复制集是 protocol:op_query
awk '/protocol:op_query/ && match($0, /protocol:op_query ([0-9]+)ms/, time) && time[1] > 5000 { print }' mongod.log

// mongoDB 分片是 protocol:op_command
awk '/protocol:op_command/ && match($0, /protocol:op_command ([0-9]+)ms/, time) && time[1] > 5000 { print }' mongod.log

• 使用awk命令处理日志文件mongod.log。
• /protocol:op_query/筛选包含"protocol:op_query"的行。
• match($0, /protocol:op_query ([0-9]+)ms/, time) 提取每行中的查询时间（单位为ms），并将其保存在time数组中。
• time[1] > 5000 检查提取出的时间是否大于5000ms。
• { print } 如果满足条件，打印整行日志。

这样，这行命令会输出所有查询时间超过5000ms的日志条目。

awk -F ' ' '{split($NF, a, "ms"); if (a[1] > 5000) print $0}'   mongod.log

这段代码是用 AWK 编写的命令，用于处理文件 mongod.log 中的数据。让我们逐步解读这段命令：

1. 命令结构：

   awk -F ' ' '{split($NF, a, "ms"); if (a[1] > 5000) print $0}' mongod.log
   

2. 解读命令部分：

   • awk -F ' ': 这里使用 -F ' ' 指定了字段分隔符为空格。这意味着每行文本会被按空格分割成多个字段，其中 $NF 表示最后一个字段。

   • '{split($NF, a, "ms"); if (a[1] > 5000) print $0}': 这是 AWK 的脚本部分，用单引号括起来，包含两个命令：

     • split($NF, a, "ms"): 使用 split 函数将最后一个字段 $NF 按照 "ms" 分割成多个部分，结果存储在数组 a 中。这个命令的目的是从末尾字段中提取出以 "ms" 结尾的数值。
     • if (a[1] > 5000) print $0: 如果 a 数组的第一个元素（即从最后一个字段中提取的数值部分）大于 5000，那么打印整行内容 $0。这样可以筛选出满足条件的行。

3. 作用：

   • 此命令的主要作用是读取文件 mongod.txt 的每一行，将最后一个字段按 "ms" 分割成数值部分，并检查这个数值是否大于 5000。如果满足条件，则输出整行内容。

4. 注意事项：

   • 命令中的 $NF 表示最后一个字段，如果每行字段数目不确定或者字段分隔符不仅仅是空格，可能需要根据实际情况调整 -F 参数和 $NF 的使用方式。

这样，整个命令就是一个用 AWK 实现的简单的文本处理流程，用于筛选出满足特定条件的行并进行输出。

如何用awk 一行式命令分别统计 每小时 日志有多少条？

你可以使用 awk 命令来统计每个小时日志条数，具体操作如下：

awk '{print substr($1, 12, 2)}' mongod.log | sort | uniq -c

image.png

这行命令的解释如下：

1. awk '{print substr($1, 12, 2)}' mongod.log: 这部分命令使用 awk 来处理日志文件 mongod.log，提取每行的时间戳的小时部分。substr($1, 12, 2) 表示从每行的第一个字段（时间戳部分）中提取从第12个字符开始的2个字符，即小时部分。这里假设日志文件中第一个字段确实是时间戳。

2. | sort: 使用 sort 对提取出的小时部分进行排序，以便后续的统计操作。

3. | uniq -c: 使用 uniq -c 统计每个小时部分的唯一值（即每个小时出现的次数），并且附带每个唯一值出现的次数。

这条命令的输出将会是每个小时日志条数的统计结果，例如：

3 11
5 12
2 13

这表示在日志中，11点有3条日志，12点有5条日志，13点有2条日志，依此类推。

如何用awk 一行式命令分别统计 每分钟 日志有多少条？

要用一行的 awk 命令来统计每分钟的日志条数，可以按照以下方式操作：

awk '{print substr($1, 12, 5)}' mongod.log | sort | uniq -c

image.png

这行命令的解释如下：

1. awk '{print substr($1, 12, 5)}' mongod.log: 这部分命令使用 awk 处理日志文件 mongod.log，提取每行的时间戳的分钟部分。substr($1, 12, 5) 表示从每行的第一个字段（时间戳部分）中提取从第12个字符开始的5个字符，即分钟部分。这里假设日志文件中第一个字段确实是时间戳。

2. | sort: 使用 sort 对提取出的分钟部分进行排序，以便后续的统计操作。

3. | uniq -c: 使用 uniq -c 统计每个分钟部分的唯一值（即每分钟出现的次数），并且附带每个唯一值出现的次数。

这条命令的输出将会是每分钟日志条数的统计结果，例如：

3 09:45
5 09:46
2 09:47

这表示在日志中，09:45有3条日志，09:46有5条日志，09:47有2条日志，依此类推。

如何用awk 一行式命令分别统计 每秒 日志有多少条？

如果你想用awk一行式命令输出每秒的日志条数，可以结合使用awk、sort和uniq命令。假设日志中的时间戳格式为 "HH:MM:SS.sss":

awk '{print substr($1, 12, 8)}' mongod.log | sort | uniq -c

这条命令的步骤是：

• awk '{print substr($1, 12, 8)}'：从每行的第一个字段中提取时间戳的时分秒部分（例如 "11:09:45"），并打印出来。
• sort：将提取出来的时分秒部分进行排序。
• uniq -c：对排序后的结果进行计数并输出，这样就能统计每秒的日志条数了。

这条命令假设日志文件中每行的时间戳格式是 "YYYY-MM-DDTHH:MM:SS.sss"，并且时间戳以秒为单位。

假设我们有以下日志文件 mongod.log：

2024-06-27T11:09:45.649+0800 I COMMAND [conn389929] command testDB.T_Test command: find { find: "T_Test", filter: { _id: "63759e9fd08e0f5f8e8270e7" }, limit: 1, shardVersion: [ Timestamp 22528000|1, ObjectId('5d6785e8e65179d5d4e78e46') ] } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 reslen:718 locks:{ Global: { acquireCount: { r: 4 }, acquireWaitCount: { r: 2 }, timeAcquiringMicros: { r: 57614434 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_command 57696ms
2024-06-27T11:09:45.650+0800 I COMMAND [conn389930] command testDB.T_Test command: find { find: "T_Test", filter: { _id: "63759e9fd08e0f5f8e8270e8" }, limit: 1, shardVersion: [ Timestamp 22528001|1, ObjectId('5d6785e8e65179d5d4e78e47') ] } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 reslen:718 locks:{ Global: { acquireCount: { r: 4 }, acquireWaitCount: { r: 2 }, timeAcquiringMicros: { r: 57614435 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_command 57696ms
2024-06-27T11:09:46.200+0800 I COMMAND [conn389931] command testDB.T_Test command: find { find: "T_Test", filter: { _id: "63759e9fd08e0f5f8e8270e9" }, limit: 1, shardVersion: [ Timestamp 22528002|1, ObjectId('5d6785e8e65179d5d4e78e48') ] } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 reslen:718 locks:{ Global: { acquireCount: { r: 4 }, acquireWaitCount: { r: 2 }, timeAcquiringMicros: { r: 57614436 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_command 57697ms
2024-06-27T11:09:46.201+0800 I COMMAND [conn389932] command testDB.T_Test command: find { find: "T_Test", filter: { _id: "63759e9fd08e0f5f8e8270ea" }, limit: 1, shardVersion: [ Timestamp 22528003|1, ObjectId('5d6785e8e65179d5d4e78e49') ] } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 reslen:718 locks:{ Global: { acquireCount: { r: 4 }, acquireWaitCount: { r: 2 }, timeAcquiringMicros: { r: 57614437 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_command 57697ms
2024-06-27T11:09:47.100+0800 I COMMAND [conn389933] command testDB.T_Test command: find { find: "T_Test", filter: { _id: "63759e9fd08e0f5f8e8270eb" }, limit: 1, shardVersion: [ Timestamp 22528004|1, ObjectId('5d6785e8e65179d5d4e78e4a') ] } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 reslen:718 locks:{ Global: { acquireCount: { r: 4 }, acquireWaitCount: { r: 2 }, timeAcquiringMicros: { r: 57614438 } }, Database: { acquireCount: { r: 2 } }, Collection: { acquireCount: { r: 2 } } } protocol:op_command 57698ms

使用命令：

awk '{print substr($1, 12, 8)}' mongod.log | sort | uniq -c

输出数据示例：

   2 11:09:45
   2 11:09:46
   1 11:09:47

解释：

• 11:09:45 出现了两次。
• 11:09:46 出现了两次。
• 11:09:47 出现了一次。

这些数据表示在每个时间戳秒钟内，日志文件中的条目数。