Debian Tomcat日志中如何分析响应时间

Debian Tomcat日志分析响应时间的实用方法

一启用并验证访问日志中的响应时间字段

在 ${TOMCAT_HOME}/conf/server.xml 的内配置 AccessLogValve，使用包含响应时间的 pattern。常见字段：
- %D：请求处理时间，单位毫秒 ms。
- %F：提交响应的时间，单位毫秒 ms（从请求开始到响应提交给客户端的时间）。
- %{request_time}e：请求处理时间，单位秒 s（以请求属性 request_time 为准，需应用或过滤器设置该属性）。
示例配置（二选一或并存）：

<Host name="localhost" appBase="webapps" unpackWARs="true" autoDeploy="true">
  <!-- 记录毫秒级处理时间 -->
  <Valve className="org.apache.catalina.valves.AccessLogValve"
         directory="${catalina.base}/logs"
         prefix="localhost_access_log." suffix=".txt"
         pattern="%h %l %u %t "%r" %s %b %D %F"/>
  <!-- 记录秒级处理时间（需应用设置 request_time 属性） -->
  <Valve className="org.apache.catalina.valves.AccessLogValve"
         directory="${catalina.base}/logs"
         prefix="localhost_access_time_s." suffix=".txt"
         pattern="%h %l %u %t "%r" %s %b %{request_time}e"/>
</Host>

重启 Tomcat 生效：sudo systemctl restart tomcat。
日志默认位于 ${catalina.base}/logs/（常见为 /var/log/tomcatX/ 或 /opt/tomcat/logs/，以实际安装为准）。完成后可用 tail -f 实时查看新产生的访问日志。

二命令行快速分析响应时间

基本统计
- 平均/最大/最小响应时间（以 %D ms 为例）：
  - 平均：awk ‘{sum+=$NF} END {print “avg=” sum/NR " ms"}’ localhost_access_log.*.txt
  - 最大：awk ‘BEGIN{m=0} {if($NF>m) m=$NF} END {print “max=” m " ms"}’ localhost_access_log.*.txt
  - 最小：awk ‘BEGIN{m=1e9} {if($NF<m) m=$NF} END {print “min=” m " ms"}’ localhost_access_log.*.txt
- 按 URL 路径统计 P95/P99（需先提取路径，示例将 ? 后参数去掉）：
  - 提取并计算 P95：
    - awk -F’“’ '{url=$2; gsub(/?./,“”,url); times[url]=(times[url]==“”?“”:times[url]“,”)$NF} END {for(u in times){n=split(times[u],a,“,”); asort(a); p95=a[int(n0.95)]; print u, p95 " ms”}}’ localhost_access_log.*.txt
分布与分位数
- 以 100 ms 为桶统计分布：
  - awk '{bucket=int($NF/100)100; cnt[bucket]+=1} END {for(b in cnt) printf “%d-%d ms: %d\n”, b, b+99, cnt[b]}’ localhost_access_log..txt | sort -n
Top N 慢请求
- 最慢的 10 个请求（含方法、路径、耗时）：
  - awk -F’"’ ‘{print $2, $NF}’ localhost_access_log.*.txt | sort -k2 -nr | head -10
按分钟统计平均响应时间
- 假设时间格式为 [18/Jul/2018:17:00:01 +0800]，提取分钟并求均值：
  - awk -F’[][]’ ‘{split($2,t,“:”); m=t[2]; sum[m]+=$NF; cnt[m]++} END {for(m in sum) printf “%s: %.2f ms\n”, m, sum[m]/cnt[m]}’ localhost_access_log.*.txt | sort
说明
- 上述示例默认 %D 为最后一列（$NF）。如使用 %F 或 %{request_time}e，请将其放在 pattern 末尾或相应位置，并调整 $NF 为对应字段。
- 如需按 状态码、客户端 IP 分组，可在 awk 中增加条件判断（如 $9==200 或 $1 为 IP）。

三进阶结构化日志与可视化

JSON 化访问日志便于 ELK/Graylog 分析（示例仅列关键字段，可按需增减）：

<Valve className="org.apache.catalina.valves.AccessLogValve"
       directory="${catalina.base}/logs"
       prefix="localhost_access_json." suffix=".log"
       pattern="{"client":"%h","user":"%u","time":"%t","method":"%r","status":"%s","bytes":"%b","response_ms":"%D","commit_ms":"%F"}"/>

在 Logstash 中解析 JSON 后，可在 Kibana 构建 95/99 分位、Top N 慢 URL、按分钟趋势等可视化面板，实现持续观测与告警。

四若访问日志未记录时间的替代方案

应用层埋点
- 使用 Servlet Filter 在请求前后打点，计算 endTime - startTime，并用 SLF4J/Log4j 输出到应用日志或标准输出（被 Tomcat 访问日志采集）。
APM 方案
- 引入 New Relic / Datadog / AppDynamics 等 APM，获取更细粒度的数据库调用、外部依赖、调用栈与分位指标。
系统层面排查
- 结合 GC 日志、线程转储、系统资源监控（top/vmstat/iostat） 判断是否存在 JVM GC、线程阻塞 或 资源瓶颈 导致的响应变慢。

最新问答

相关标签