之前在一个springboot项目中开启了access.log日志（参见spring boot打开tomcat的access日志），现在可以很方便的根据access日志统计时延。先看日志文件：
再看access.log里的8个字段：
%h %l %u %t "%r" %s %b %D
这几个字段都是啥意思？
- %h = 发起请求的客户端 IP 地址
- %l = 客户机的 RFC 1413 标识 ( 参考 ) ，只有实现了 RFC 1413 规范的客户端，才能提供此信息。
- %u = 访问用户的 ID
- %t = 收到请求的时间
- %r = 来自客户端的请求行
- %s = 服务器返回客户端的状态码
- %b = 返回给客户端的字节大小，但不包括响应头的大小
- %D = 接口请求时延
从以上参数可以看出，如果要统计时延超过500毫秒的请求，就看最后一个字段就行了。使用awk统计时延超过500毫秒命令如下：
wulf@wulf00 MINGW64 /e/workspace/subtitle/logs (master) $ awk '$NF >= 500 {print $0}' access_log*.log 127.0.0.1 - - [02/Dec/2020:06:51:19 +0800] "POST /liveSync HTTP/1.1" 200 43 668 127.0.0.1 - - [02/Dec/2020:06:51:19 +0800] "POST /liveSync HTTP/1.1" 200 43 768 127.0.0.1 - - [02/Dec/2020:06:51:52 +0800] "POST /liveStop HTTP/1.1" 200 43 819 127.0.0.1 - - [02/Dec/2020:06:51:53 +0800] "POST /liveStop HTTP/1.1" 200 43 1000 127.0.0.1 - - [02/Dec/2020:06:52:18 +0800] "POST /liveModify HTTP/1.1" 200 43 643 127.0.0.1 - - [02/Dec/2020:06:52:18 +0800] "POST /liveModify HTTP/1.1" 200 43 501 127.0.0.1 - - [02/Dec/2020:06:51:19 +0800] "POST /liveSync HTTP/1.1" 200 43 1668 127.0.0.1 - - [02/Dec/2020:06:51:47 +0800] "POST /liveSync HTTP/1.1" 200 43 888 127.0.0.1 - - [02/Dec/2020:06:51:53 +0800] "POST /liveStop HTTP/1.1" 200 43 710 127.0.0.1 - - [02/Dec/2020:06:52:18 +0800] "POST /liveModify HTTP/1.1" 200 43 666 127.0.0.1 - - [02/Dec/2020:06:51:19 +0800] "POST /liveSync HTTP/1.1" 200 43 608 127.0.0.1 - - [02/Dec/2020:06:51:47 +0800] "POST /liveSync HTTP/1.1" 200 43 558 127.0.0.1 - - [02/Dec/2020:06:52:18 +0800] "POST /liveModify HTTP/1.1" 200 43 556
有一点要注意，虽然我们在access日志文件里是8个字段，但实际上awk解析的时候是11个字段：
- awk '{print $1}' access_log.2020-12-02.log # IP 地址 (%h)
- awk '{print $2}' access_log.2020-12-02.log # RFC 1413 标识 (%l)
- awk '{print $3}' access_log.2020-12-02.log # 用户 ID (%u)
- awk '{print $4,$5}' access_log.2020-12-02.log # 日期和时间 (%t)
- awk '{print $7}' access_log.2020-12-02.log # URI (%>s)
- awk '{print $9}' access_log.2020-12-02.log # 状态码 (%>s)
- awk '{print $10}' access_log.2020-12-02.log # 响应大小 (%b)
- awk '{print $11}' access_log.2020-12-02.log # 时延大小 (%b)
我们注意到awk按字符串的空格来分割，比如我们要看接口名，那么http方法类型（其中的$6，即POST)就被干掉了：
$ awk '{print $7}' access_log*.log /liveSync
再结合这条命令awk '$NF >= 500 {print $0}' access_log*.log说两点：一个是$NF，它指定最后一列，即$11，所以用NF或者11都行；另一个是$0，它代表所有的列。