☰

Grep 日志文件中的 SQL 查询及其执行时间

tag-icon • tag-icon linux awk sed grep cut
Grep 日志文件中的 SQL 查询及其执行时间

我有一个应用程序日志文件，它还捕获每个执行的 SQL 语句的执行时间，如下所示：-

示例日志：

I 2023-11-15 07:18:00.743Z 1760463 37 ZVRwqItu6aw-b8eejMLI_gAAAAU 1@45077318@A PHP Request Summary: 7 warnings/errors on 6 lines
I 2023-11-15 07:17:15.927Z 1773299 99 ZVRwenUWDwrXl_9NnC-2vwAAAAM 1@45077318@A There is no cache key assigned for the current PID
I 2023-11-15 07:17:55.778Z 1773397 24 ZVRwoydG6PTd3KWR_MnfVAAAABU - Initiating db proxy socket to dev01:8080
I 2023-11-15 07:17:55.865Z 1773397 33 ZVRwoydG6PTd3KWR_MnfVAAAABU 1@45077318@A execStmtEx: time: 0.002 / 0 rows: 1 sql: <some_plsql_statement>
I 2023-11-15 07:17:56.185Z 1773397 65 ZVRwoydG6PTd3KWR_MnfVAAAABU 1@45077318@A applicationConnection TRX Record Commit (execStmtEx) time: 0
I 2023-11-15 07:17:57.515Z 1755787 26 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.001 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.519Z 1755787 26 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.001 / 0 rows: 0 sql: <some_sql_here>
I 2023-11-15 07:17:57.529Z 1755787 27 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.531Z 1755787 27 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.001 / 0 rows: 0 <some_sql_here>
I 2023-11-15 07:17:57.535Z 1755787 28 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.542Z 1755787 28 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
...

我想 grep 查找所有这些 SQL 查询及其执行时间，按降序排序（根据它们的执行时间）。

期望的输出：

time: 0.002 | sql: <some_plsql_statement>
time: 0.002 | sql: <some_sql_here>

如何使用 Linux 命令实现此目的？有人可以帮助我实现这一目标吗？提前致谢。

答案1

提取相关字段，仅打印匹配的行，并按执行时间降序对结果进行排序：

sed -En 's/^.*(time: [0-9.]+) .* (sql: .*)/\1 | \2/p' logfile | sort -k2,3nr

输出

time: 0.002 | sql: <some_plsql_statement>
time: 0.002 | sql: <some_sql_here>
time: 0.002 | sql: <some_sql_here>
time: 0.002 | sql: <some_sql_here>
time: 0.001 | sql: <some_sql_here>
time: 0.001 | sql: <some_sql_here>

答案2

假设您的行始终具有相同数量的字段，并且sql:只会出现在您想要的行上，您可以执行此操作以对第 10 个字段进行排序，这似乎是运行命令所花费的时间：

$ grep sql: log | sort -rnk 10,10
I 2023-11-15 07:17:57.542Z 1755787 28 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.535Z 1755787 28 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.529Z 1755787 27 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:55.865Z 1773397 33 ZVRwoydG6PTd3KWR_MnfVAAAABU 1@45077318@A execStmtEx: time: 0.002 / 0 rows: 1 sql: <some_plsql_statement>
I 2023-11-15 07:17:57.519Z 1755787 26 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.001 / 0 rows: 0 sql: <some_sql_here>
I 2023-11-15 07:17:57.515Z 1755787 26 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.001 / 0 rows: 1 sql: <some_sql_here>

或者，如果您想对第三个字段（我猜是命令执行时间）进行排序，请使用：

$ grep sql: log | sort -rnk 3,3
I 2023-11-15 07:17:57.542Z 1755787 28 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.535Z 1755787 28 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.529Z 1755787 27 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.002 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:57.519Z 1755787 26 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.001 / 0 rows: 0 sql: <some_sql_here>
I 2023-11-15 07:17:57.515Z 1755787 26 ZVRwpA5grkn1knR4gk6FMwAAABA 1@45077318@A queryResults: time: 0.001 / 0 rows: 1 sql: <some_sql_here>
I 2023-11-15 07:17:55.865Z 1773397 33 ZVRwoydG6PTd3KWR_MnfVAAAABU 1@45077318@A execStmtEx: time: 0.002 / 0 rows: 1 sql: <some_plsql_statement>

time:如果你只想要从到 行尾 的文本，假设 GNU grep，请执行以下操作：

$ grep -o 'time:.* sql:.*' log | sort -rnk 2,2
time: 0.002 / 0 rows: 1 sql: <some_sql_here>
time: 0.002 / 0 rows: 1 sql: <some_sql_here>
time: 0.002 / 0 rows: 1 sql: <some_sql_here>
time: 0.002 / 0 rows: 1 sql: <some_plsql_statement>
time: 0.001 / 0 rows: 1 sql: <some_sql_here>
time: 0.001 / 0 rows: 0 sql: <some_sql_here>

相关内容