nginx+tomcat 响应请求时间和 AWK分析日志

1.Nginx统计请求和后台服务响应时间

nginx.conf 日志中使用

$upstram_response_time $request_time

$request_time和$upstream_response_time之间差别：
request_time：指的就是从接受用户请求的第一个字节到发送完响应数据的时间，即包括接收请求数据时间、程序响应时间、输出响应数据时间。

upstream_response_time：是指从Nginx向后端（php-cgi)建立连接开始到接受完数据然后关闭连接为止的时间。

$request_time肯定比$upstream_response_time值大，特别是使用POST方式传递参数时，因为Nginx会把request body缓存住，接受完毕后才会把数据一起发给后端。所以如果用户网络较差，或者传递数据较大时，$request_time会比$upstream_response_time大很多。

2.Tomcat通过%D或%T统计请求响应时间

server.xml使用配置：

<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs"
prefix="localhost_access_log." suffix=".txt"
pattern="%h %l %u [%{yyyy-MM-dd HH:mm:ss}t] %{X-Real_IP}i &quot;%r&quot; %s %b %D %F" />

%D - 官方解释：Time taken to process the request, in millis，处理请求的时间，以毫秒为单位
%T - 官方解释：Time taken to process the request, in seconds，处理请求的时间，以秒为单位
%F - 官方解释：Time taken to commit the response, in millis，提交响应的时间，以毫秒为单位

官方地址：http://tomcat.apache.org/tomcat-7.0-doc/config/valve.html#Access_Logging

%a - Remote IP address

%A - Local IP address

%b - Bytes sent, excluding HTTP headers, or '-' if zero

%B - Bytes sent, excluding HTTP headers

%h - Remote host name (or IP address if enableLookups for the connector is false)

%H - Request protocol

%l - Remote logical username from identd (always returns '-')

%m - Request method (GET, POST, etc.)

%p - Local port on which this request was received. See also %{xxx}p below.

%q - Query string (prepended with a '?' if it exists)

%r - First line of the request (method and request URI)

%s - HTTP status code of the response

%S - User session ID

%t - Date and time, in Common Log Format

%u - Remote user that was authenticated (if any), else '-'

%U - Requested URL path

%v - Local server name

%D - Time taken to process the request, in millis

%T - Time taken to process the request, in seconds

%F - Time taken to commit the response, in millis

%I - Current request thread name (can compare later with stacktraces)

3.通过awk命令辅助统计

AWK 简介

AWK 是一种“样式扫描和处理语言”。它允许您创建简短的程序，这些程序读取输入文件、为数据排序、处理数据、对输入执行计算以及生成报表。它的名称取自于它的创始人 Alfred Aho、 Peter Weinberger 和 Brian Kernighan 姓氏的首个字母。
本文论述的 awk 命令主要指 Linux 操作系统中广泛包含的内置程序 /bin/gawk，它是 Unix awk 程序的 GNU 版本。此命令主要负责读入并运行 AWK 语言编写的程序。在 Windows 平台上可以使用 Cygwin 在模拟环境下运行 awk 命令。
基本上来说，awk 可以从输入（标准输入，或一个或多个文件）中是否存在指定模式的记录（即文本行）。每次发现匹配时，就执行相关联的动作（例如写入到标准输出或外部文件）。

AWK 语言基础

为了能理解 AWK 程序，我们下面概述其基本知识。AWK 程序可以由一行或多行文本构成，其中核心部分是包含一个模式和动作的组合。

pattern { action }

模式( pattern ) 用于匹配输入中的每行文本。对于匹配上的每行文本，awk 都执行对应的动作( action )。模式和动作之间使用花括号隔开。awk 顺序扫描每一行文本，并使用记录分隔符（一般是换行符）将读到的每一行作为记录，使用域分隔符( 一般是空格符或制表符 ) 将一行文本分割为多个域，每个域分别可以使用 $1,$ 2, … $n 表示。$ 1 表示第一个域， $2 表示第二个域，$ n 表示第 n 个域。 $0 表示整个记录。模式或动作都可以不指定，缺省模式的情况下，将匹配所有行。缺省动作的情况下，将执行动作 {print}，即打印整个记录。

使用 awk 分解出日志中的信息

由于我们在日志配置文件中指定了访问日志的固定格式，因此，我们可以轻易地使用 awk 解析，抽取我们需要的数据。
以下面的示例日志为例：

202.189.63.115 - - [31/Aug/2012:15:42:31 +0800] "GET / HTTP/1.1" 200 1365 "-" 
"Mozilla/5.0 (Windows NT 6.1; WOW64; rv:15.0) Gecko/20100101 Firefox/15.0.1"

$0 就是整个记录行
$1 就是访问 IP ” 202.189.63.115”
$4 就是请求时间的前半部分 “[31/Aug/2012:15:42:31”
$5 就是请求时间的后半部分 “+0800]”

当我们使用默认的域分割符时，我们可以从日志中解析出下面不同类型的信息：

awk '{print $1}' access.log # IP 地址 (%h)
awk '{print $2}' access.log # RFC 1413 标识 (%l)
awk '{print $3}' access.log # 用户 ID (%u)
awk '{print $4,$ 5}' access.log # 日期和时间 (%t)
awk '{print $7}' access _log # URI (%>s)
awk '{print $9}' access _log # 状态码 (%>s)
awk '{print $10}' access _log # 响应大小 (%b)

仅使用默认的域分隔符，不方便解析出请求行、引用页和浏览器类型等其他信息，因为这些信息之中包含不确定个数的空格。因此，我们需要把域分隔符修改为 “ ，就能够轻松读出这些信息。

awk -F" '{print $2}' access.log # 请求行 (%r)
awk -F" '{print $4}' access.log # 引用页
awk -F" '{print $6}' access.log # 浏览器

注意：这里为了避免 Unix/Linux Shell 误解 “ 为字符串开始，我们使用了反斜杠，转义了 “ 。

使用 awk 场景举例

统计浏览器类型

统计有多少类型的浏览器访问过网站，并按出现的次数倒序排列，可以使用下面的命令：

awk -F\" '{print $6}' access.log | sort | uniq -c | sort -fr

此命令行首先解析出浏览器域，然后使用管道将输出作为第一个 sort 命令的输入。第一个 sort 命令主要是为了方便 uniq 命令统计出不同浏览器出现的次数。最后一个 sort 命令将把之前的统计结果倒序排列并输出。

发现系统存在的问题

使用下面的命令行，统计服务器返回的状态码，发现系统可能存在的问题：

awk '{print $9}' access.log | sort | uniq -c | sort

正常情况下，状态码 200 或 30x应该是出现次数最多的。40x一般表示客户端访问问题。50x 一般表示服务器端问题。

常见的状态码：

200 - 请求已成功，请求所希望的响应头或数据体将随此响应返回。
206 - 服务器已经成功处理了部分 GET 请求
301 - 被请求的资源已永久移动到新位置
302 - 请求的资源现在临时从不同的 URI 响应请求
400 - 错误的请求。当前请求无法被服务器理解
401 - 请求未授权，当前请求需要用户验证。
403 - 禁止访问。服务器已经理解请求，但是拒绝执行它。
404 - 文件不存在，资源在服务器上未被发现。
500 - 服务器遇到了一个未曾预料的状况，导致了它无法完成对请求的处理。
503 - 由于临时的服务器维护或者过载，服务器当前无法处理请求。
详细参阅Hypertext Transfer Protocol -- HTTP/1.1

有关状态码的 awk 命令示例：

查找并显示所有状态码为 404 的请求：

awk '($9 ~ /404/)' access.log

统计所有状态码为 404 的请求：

awk '($9 ~ /404/)' access.log | awk '{print $9,$7}' | sort

假设某个请求 ( 例如 : URI: /wap/lives/sZ17357009 ) 产生了大量的 404 错误，我们可以通过下面的命令找到这个请求是来自于哪一个引用页，和来自于什么浏览器。

awk -F\" '($2 ~ "^GET /wap/lives/sZ17357009 "){print $4,$6}' access.log

追查谁在盗链网站图片

有时候会发现其他网站出于某种原因，在他们的网站上使用保存在自己网站上的图片。如果您想知道究竟是谁未经授权使用自己网站上的图片，可以使用下面的命令：

awk -F\" '($2 ~ /\.(jpg|gif|png)/ && $4 !~ /^http:\/\/www\.example\.com/)\ 
{print $4}' access.log \ | sort | uniq -c | sort

以上命令将 www.example.com 修改为自己网站的域名

使用 ” 分解每一行；
请求行中必须包括 “.jpg” 、”.gif” 或 ”.png”；
引用页不是以您的网站域名字符串开始（在此例中，即 www.example.com ）；
显示出所有引用页，并统计出现的次数。

与访问 IP 地址相关的命令

统计共有多少个不同的 IP 访问：

awk '{print $1}' access.log |sort|uniq|wc – l

统计每一个 IP 访问了多少个页面：

awk '{++S[$1]} END {for (a in S) print a,S[a]}' log_file

将每个 IP 访问的页面数进行从小到大排序：

awk '{++S[$1]} END {for (a in S) print S[a],a}' log_file | sort -n

查看某一个 IP（例如 202.106.19.110 ）访问了哪些页面：

grep ^202.106.19.110 access.log | awk '{print $1,$7}'

统计 2017 年 10 月 19 日 14 时内有多少 IP 访问：

awk '{print $4,$1}' access.log | grep 19/Oct/2017:14 | awk '{print $2}'| sort | uniq | \
wc -l

统计访问最多的前十个 IP 地址:

awk '{print $1}' access.log |sort|uniq -c|sort -nr |head -10

与响应页面大小的命令

列出传输大小最大的几个文件:

cat access.log |awk '{print $10 " " $1 " " $4 " " $7}'|sort -nr|head -100

列出输出大于 204800 byte ( 200kb) 的页面以及对应页面发生次数:

cat access.log |awk '($10 > 200000){print $7}'|sort -n|uniq -c|sort -nr|head -100

与页面响应时间相关的命令

我们日志最后一列记录的是页面文件传输时间 (%T)，例如:

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %T" combined

可以使用下面的命令统计出所有响应时间超过 3 秒的日志记录：

awk '($NF > 3){print $0}' access.log

==NF 是当前记录中域的个数。$NF 即最后一个域==

列出相应时间超过 5 秒的请求:

awk '($NF > 5){print $0}' access.log | awk -F\" '{print $2}' |sort -n| 
uniq -c|sort -nr|head -20

简单统计nginx访问日志access log每分钟请求数

awk -F: '{count[$2":"$3]++} END {for (minute in count) print minute, count[minute]}' /var/log/nginx/access.log | sort > count.log

统计请求响应时间超过20s的记录

awk '($NF > 20){print $0}' /var/log/nginx/access.log >long20_1020.log

《AWK 编程语言》The AWK Programming Language, ISBN 0-201-07981-X.