Ubuntu Tomcat日志中的慢查询识别

识别思路与前提

Tomcat 并不自带数据库“慢查询日志”，所谓“慢查询”通常是指：HTTP 请求处理耗时过长，或后端数据库执行的 SQL 过慢。识别路径主要有两条：
- 基于 Tomcat 的**访问日志（Access Log）**统计请求耗时，筛出高耗时的接口与来源。
- 基于应用的数据库慢查询日志（如 MySQL 的 slow query log）或 JDBC 日志，定位具体 SQL 语句与执行计划。
Tomcat 日志常见路径为：/var/log/tomcat/ 或 /opt/tomcat/logs/；访问日志通常以 localhost_access_log 开头，应用日志包含 catalina.out。若需长期分析，建议接入 ELK/Graylog 做聚合与可视化。

基于 Tomcat 访问日志的识别

确认访问日志已开启并包含耗时字段。在 server.xml 的 Valve（如 AccessLogValve）中，确保 pattern 含有 %D（毫秒）或 %T（秒），常见配置片段：
```
<Valve className="org.apache.catalina.valves.AccessLogValve"
       directory="logs" prefix="localhost_access_log" suffix=".txt"
       pattern="%h %l %u %t "%r" %s %b %D" />
```
其中 %D 便于以毫秒设定阈值（如 >800 ms）。

快速筛选高耗时请求（示例阈值 800 ms）：

# 单文件
grep 'QTime' /var/log/tomcat/localhost_access_log.*.txt | \
  awk -F'QTime:' '{if ($2+0 > 800) print $0}'

# 若使用 %D（毫秒）
awk '$NF > 800 {print}' /var/log/tomcat/localhost_access_log.*.txt

# 若使用 %T（秒，阈值换算为 0.8）
awk '$NF > 0.8 {print}' /var/log/tomcat/localhost_access_log.*.txt

按时间窗口与接口聚合统计 Top N 慢请求：

# 近 1 小时、按 URL 聚合，显示次数与最大耗时
grep "$(date -d '1 hour ago' '+%d/%b/%Y:%H')" /var/log/tomcat/localhost_access_log.*.txt | \
  awk -F'QTime:' '{t=$2+0; if(t>800) print $0}' | \
  awk '{url=$7; gsub(/^\?.*/, "", url); dur[url]+=t; cnt[url]++} END {for(u in dur) print dur[u], cnt[u], u}' | \
  sort -nr | head

实时观察新增慢请求：

tail -f /var/log/tomcat/localhost_access_log.*.txt | \
  awk -F'QTime:' '{if(($2+0) > 800) print strftime("%F %T"), $0}'

说明：若访问日志未输出 QTime/%D/%T，需先在 server.xml 中启用并包含耗时字段，再进行分析。

基于数据库与应用日志的识别

开启并收集数据库慢查询日志（以 MySQL 为例）：
- 在 my.cnf 中开启慢查询日志与阈值（单位秒），例如：
```
slow_query_log=1
slow_query_log_file=/var/log/mysql/mysql-slow.log
long_query_time=1
log_queries_not_using_indexes=1
```
- 使用 pt-query-digest 分析慢日志，输出最耗时的 SQL 与样本：
```
pt-query-digest /var/log/mysql/mysql-slow.log --limit 10
```
关联 Tomcat 与数据库侧证据：
- 在 Tomcat 侧用访问日志定位到具体接口与时间段，再在数据库慢日志中检索该时段对应 SQL 模板，结合 EXPLAIN 优化执行计划与索引。

连接池问题导致的“慢”识别与处置

连接池瓶颈常表现为获取连接超时、连接泄露等，可在 catalina.out 中检索关键词并快速定位：

# 实时观察
tail -f /var/log/tomcat/catalina.out | \
  egrep -i "connection pool|getconnectiontimeout|cannot get connection|connection leak"

# 最近 1 小时
egrep -i "connection pool" /var/log/tomcat/catalina.out | \
  grep "$(date -d '1 hour ago' '+%b %d %H:%M')"

典型现象与含义：
- GetConnectionTimeoutException: Wait millis 6000, active 100：活跃连接数触顶，获取连接超时。
- Cannot get a connection, pool error Timeout waiting for idle object：等待空闲连接超时，可能 maxWaitMillis 过短或连接未及时释放。
- Connection has been abandoned：疑似连接泄露，需检查未关闭的 Connection/Statement。

连接池参数优化示例（Tomcat JDBC 数据源，位于 context.xml 或 server.xml 的 Resource）：

<Resource name="jdbc/mydb" auth="Container" type="javax.sql.DataSource"
          maxTotal="200" maxIdle="50" maxWaitMillis="3000"
          removeAbandoned="true" removeAbandonedTimeout="300" logAbandoned="true"
          testOnBorrow="true" validationQuery="SELECT 1" validationQueryTimeout="5"
          minIdle="10" timeBetweenEvictionRunsMillis="60000"
          minEvictableIdleTimeMillis="300000" />

调整后重启 Tomcat，并通过 Tomcat Manager 或 JMX 观察 active/idle/waiting 等指标变化。

自动化与长期治理建议

日志轮转与保留：使用 cronolog 或 logrotate 按日切分，避免单文件过大，便于快速检索与归档。
集中化与可视化：将 catalina.out、localhost_access_log、应用日志、数据库慢日志 接入 ELK/Graylog，建立慢请求与慢 SQL 的看板与告警。
监控与持续优化：结合 Prometheus + Grafana 监控 Tomcat 与数据库关键指标（请求耗时、连接池使用、慢查询数），并定期复盘阈值与索引策略。

最新问答

相关标签