Nginx日志增长过快详细分析

443次阅读

共计 16725 个字符，预计需要花费 42 分钟才能阅读完成。

前言：

Nginx 日志里面 Mobileweb_access.log 增长特别大，一天上百兆，将近 100W 的访问记录，按照我们目前的规模，热点用户才 500 个左右，就算人人用手机 app 访问，怎么可能会有这么大的 url 访问量？以前只是安装使用 nginx，还没有抽出时间仔细研究，这回需要彻底的去分析 nginx 日志了。

1，日志分类
主要 2 种，一种是错误日志，一种是访问日志，这些配置都在 /usr/local/nginx/conf/nginx.conf 里面，默认都是打开的，自己也可以选择关闭。

1.1，访问日志
访问日志主要记录每一个访问 nginx 的请求，格式可以自己定义，在 nginx.conf 文件里面，通过访问日志，你可以看到每一个请求的详细信息，对于访问日志的格式，主要是配置文件中的 log_format 来限制的。

1.1.1 log_format 日志格式

$request_time：整个请求的总时间。

$time_iso8601：访问的时间与时区，比如 18/Jul/2012:17:00:01 +0800，时间信息最后的 ”+0800″ 表示服务器所处时区位于 UTC 之后的 8 小时。

$upstream_response_time：请求过程中，upstream 的响应时间。

$request_method：客户端请求的动作，通常为 GET 或 POST。

$request_uri：是浏览器发过来的值。该值是 rewrite 后的值。例如做了 internal redirects 后。

$args：这个变量等于请求行中 (GET 请求) 的参数，例如 foo=123&bar=blahblah;

$query_string：与 $args 相同。

$proxy_add_x_forwarded_for：变量包含客户端请求头中的 ”X-Forwarded-For”，与 $remote_addr 用逗号分开，如果没有 ”X-Forwarded-For” 请求头，则 $proxy_add_x_forwarded_for 等于 $remote_addr。

$upstream_addr：upstream 的地址，即真正提供服务的主机地址。

$status：记录请求返回的 http 状态码，比如成功是 200。

$http_user_agent：客户端浏览器信息

$http_range

$sent_http_content_length：发送内容的长度

$body_bytes_sent：发送给客户端的文件主体内容的大小，比如 899，可以将日志每条记录中的这个值累加起来以粗略估计服务器吞吐量。

$http_referer：记录从哪个页面链接访问过来的。

$host：请求主机头字段，否则为服务器名称。

$http_x_forwarded_for：客户端的真实 ip，通常 web 服务器放在反向代理的后面，这样就不能获取到客户的 IP 地址了，通过 $remote_add 拿到的 IP 地址是反向代理服务器的 iP 地址。反向代理服务器在转发请求的 http 头信息中，可以增加 x_forwarded_for 信息，用以记录原有客户端的 IP 地址和原来客户端的请求的服务器地址。

$http_user_agent：客户端浏览器信息

$body_bytes_sent：发送给客户端的文件主体内容的大小，比如 899，可以将日志每条记录中的这个值累加起来以粗略估计服务器吞吐量。

$ssl_protocol：SSL 协议版本，比如 TLSv1。

$ssl_cipher：交换数据中的算法，比如 RC4-SHA。

生产环境上的范例：

log_format main ‘$proxy_add_x_forwarded_for $remote_user [$time_local] “$request” ‘

‘$status $body_bytes_sent “$http_referer” ‘

‘”$http_user_agent” “$http_x_forwarded_for” ‘

‘upsteam: $upstream_addr’;

access_log logs/access.log main;

log_not_found off;

1.1.2，访问日志路径

access_log logs/access.log main;

Nginx 支持为每个 location 指定强大的日志记录。同样的连接可以在同一时间输出到不止一个的日志中。如果想关闭日志，可以如下：

access_log off;

能够使用 access_log 指令的字段包括：http、server、location。

PS：Nginx 进程设置的用户和组必须对日志路径有创建文件的权限，否则，会报错。

1.2，错误日志
错误日志主要记录客户端访问 Nginx 出错时的日志，格式不支持自定义。通过错误日志，你可以得到系统某个服务或 server 的性能瓶颈等。因此，将日志好好利用，你可以得到很多有价值的信息。错误日志由指令 error_log 来指定，具体格式如下：

error_log path(存放路径) level(日志等级)

path 含义同 access_log，level 表示日志等级，具体如下：

从左至右，日志详细程度逐级递减，即 debug 最详细，crit 最少，举例说明如下：

error_log logs/mobileweb_error.log error;

需要注意的是：error_log off 并不能关闭错误日志，而是会将错误日志记录到一个文件名为 off 的文件中。正确的关闭错误日志记录功能的方法如下：

error_log /dev/null;

上面表示将存储日志的路径设置为“垃圾桶”。

————————————– 分割线 ————————————–

CentOS 6.2 实战部署 Nginx+MySQL+PHP http://www.linuxidc.com/Linux/2013-09/90020.htm

使用 Nginx 搭建 WEB 服务器 http://www.linuxidc.com/Linux/2013-09/89768.htm

搭建基于 Linux6.3+Nginx1.2+PHP5+MySQL5.5 的 Web 服务器全过程 http://www.linuxidc.com/Linux/2013-09/89692.htm

CentOS 6.3 下 Nginx 性能调优 http://www.linuxidc.com/Linux/2013-09/89656.htm

CentOS 6.3 下配置 Nginx 加载 ngx_pagespeed 模块 http://www.linuxidc.com/Linux/2013-09/89657.htm

CentOS 6.4 安装配置 Nginx+Pcre+php-fpm http://www.linuxidc.com/Linux/2013-08/88984.htm

Nginx 安装配置使用详细笔记 http://www.linuxidc.com/Linux/2014-07/104499.htm

Nginx 日志过滤使用 ngx_log_if 不记录特定日志 http://www.linuxidc.com/Linux/2014-07/104686.htm

————————————– 分割线 ————————————–

2，为每一个工程定义特定的日志
location ~* ^/mobileWeb/.*$ {

client_max_body_size 5m;

include deny.conf;

proxy_pass http://mobilewebbackend;

include proxy.conf;

error_log logs/mobileweb_error.log error;

access_log logs/mobileweb_access.log main;

include gzip.conf;

}

这样，就会在日志路径 /usr/local/nginx/logs/ 下面生成 mobileWeb 工程的专门日志 mobileweb_error.log 以及 mobileweb_access.log 日志，如果想查询 mobileWeb 工程的访问记录，就可以单独去查看这 2 个日志。

更多详情见请继续阅读下一页的精彩内容：http://www.linuxidc.com/Linux/2014-11/108862p2.htm

3，开始分析
根据来源 ip 进行分组统计分析，看看哪个 ip 的访问量最多

[root@wgq_idc_web_1_21 tmp]# cat mobileweb_access.log |grep “14/Oct/2014” |awk ‘{print $1}’|sort -nr |uniq -c |sort -nr |more

705980 1xx.xx.xx.185,

190273 6x.1×4.1xx.35,

14900 1xx.xxx.xx.xx3,

14670 1xx.xxx.x3.8x,

结果发现，这几个 ip 都是我们公司广场公用的 wifi 出口 ip 地址，属于安全地址，不是私人的 IP 地址，很大程度上排除了从外部恶意攻击我们网站的可能性。接下来就需要重点分析，为什么会有这么多的 URL 记录。

仔细排查来源为 1xx.xx.xx.185 的日志记录，发现有很多 $http_user_agent 为空的记录，大概 90% 的记录都是如此，看记录如下：

1xx.xx.xx.185, 10.2xx.xx1.xx0 – [10/Oct/2014:10:52:11 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “1xx.xx.xx.185″upsteam: 110.xx7.1.22:7100

猜测是否不是手机 app 访问的记录？只有自己停掉 wifi，用手机的 4G 网络，去登录我们的移动 app 应用，操作完，点击了几下赞，访问了一些页面，操作时间 2 分钟，然后使用自己的移动 4Gip 地址“2xx.10x.5.129”去检索下 nginx 下的 mobileweb 的记录，4 台 nginx 记录，每一台 40 个左右 url 访问，4 台就是 160 个记录，下面是一台的记录

[root@wgq_idc_web_1_22 logs]# more mobileweb_access.log |grep “2xx.10x.5.129”

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:01 +0800] “POST /mobileWeb/userMobileCenter/queryUserNameAndIconByIds.htm? HTTP/1.1” 200 20 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:37 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:42 +0800] “POST /mobileWeb/square/query.htm? HTTP/1.1” 200 9485 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:49 +0800] “POST /mobileWeb/square/clickSupport.htm? HTTP/1.1” 200 46 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:51 +0800] “POST /mobileWeb/square/clickSupport.htm? HTTP/1.1” 200 46 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:54 +0800] “POST /mobileWeb/square/clickSupport.htm? HTTP/1.1” 200 46 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:55 +0800] “POST /mobileWeb/square/query.htm? HTTP/1.1” 200 4831 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:54:57 +0800] “POST /mobileWeb/userMobileCenter/queryUserNameAndIconByIds.htm? HTTP/1.1” 200 20 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:03 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:04 +0800] “POST /mobileWeb/version/queryVersion.htm? HTTP/1.1” 200 160 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:06 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:06 +0800] “POST /mobileWeb/mobile/loadCart.htm? HTTP/1.1” 200 940 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:07 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:07 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:07 +0800] “POST /mobileWeb/userMobileCenter/findAllinterfaceVersion.htm? HTTP/1.1” 200 411 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:13 +0800] “POST /mobileWeb/userMobileCenter/unReadNumsMobile.htm? HTTP/1.1” 200 239 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:56 +0800] “POST /mobileWeb/userMobileCenter/queryUserNameAndIconByIds.htm? HTTP/1.1” 200 20 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:57 +0800] “POST /mobileWeb/userMobileCenter/findAllinterfaceVersion.htm? HTTP/1.1” 200 411 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:58 +0800] “POST /mobileWeb/userMobileCenter/unReadNumsMobile.htm? HTTP/1.1” 200 239 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:58 +0800] “POST /mobileWeb/version/queryVersion.htm? HTTP/1.1” 200 160 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:55:59 +0800] “POST /mobileWeb/userMobileCenter/unReadNumsMobile.htm? HTTP/1.1” 200 239 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:00 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:06 +0800] “POST /mobileWeb/userMobileCenter/findAllinterfaceVersion.htm? HTTP/1.1” 200 411 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:07 +0800] “POST /mobileWeb/userMobileCenter/unReadNumsMobile.htm? HTTP/1.1” 200 239 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:07 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:08 +0800] “POST /mobileWeb/version/queryVersion.htm? HTTP/1.1” 200 160 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:08 +0800] “POST /mobileWeb/userMobileCenter/unReadNumsMobile.htm? HTTP/1.1” 200 239 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:08 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:16 +0800] “POST /mobileWeb/userMobileCenter/queryUserNameAndIconByIds.htm? HTTP/1.1” 200 20 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:19 +0800] “POST /mobileWeb/userMobileCenter/findAllinterfaceVersion.htm? HTTP/1.1” 200 411 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:21 +0800] “POST /mobileWeb/userMobileCenter/unReadNumsMobile.htm? HTTP/1.1” 200 239 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:21 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:23 +0800] “POST /mobileWeb/userMobileCenter/queryUserNameAndIconByIds.htm? HTTP/1.1” 200 20 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:23 +0800] “POST /mobileWeb/userMobileCenter/findAllinterfaceVersion.htm? HTTP/1.1” 200 411 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:24 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:24 +0800] “POST /mobileWeb/userMobileCenter/queryAdvertisement.htm? HTTP/1.1” 200 5175 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:24 +0800] “POST /mobileWeb/version/queryVersion.htm? HTTP/1.1” 200 160 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:25 +0800] “POST /mobileWeb/userMobileCenter/unReadNumsMobile.htm? HTTP/1.1” 200 239 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:56:25 +0800] “POST /mobileWeb/mobile/getCartItemNum.htm? HTTP/1.1” 200 114 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:14:57:37 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:00:37 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:02:07 +0800] “POST /mobileWeb/userMobileCenter/messageListMobile.htm? HTTP/1.1” 200 106 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:02:08 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:02:37 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:05:07 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:05:08 +0800] “POST /mobileWeb/push/query.htm? HTTP/1.1” 200 97 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:05:37 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.21:7100

2xx.10x.5.129, 10.2xx.xx1.xx0 – [16/Oct/2014:15:11:44 +0800] “POST /mobileWeb/square/queryCounts.htm? HTTP/1.1” 200 82 “-” “-” “2xx.10x.5.129″upsteam: 110.xx7.1.22:7100

[root@wgq_idc_web_1_22 logs]#

看到了我的访问 url 记录，其中 $http_user_agent 几乎都是为”-”空记录，奇怪，我也是用手机访问的，询问 andriod 开发人员，他说有些低版本的手机在记录 $http_user_agent 后退回去会报错返回空界面，所以后来就不记录 $http_user_agent 信息了。

原来如此，而且看到这么多 url 全是我访问过的，移动 mobileweb 后台开发人员说，移动 app 一个页面里面有许多 url 需要加载，所以你访问 1 个页面就会加载 N 个 link 连接去取各种数据值。分析道这里，已经差不多明了：就是一个登录用户访问页面，会加载 N（N>10）个 link 连接 url，这些 url 都被记录在 nginx 访问日志里面，短短 2 分钟内，我访问了一些页面，就有 160 个左右的记录，照这么算下来，一个小时就是 5000 个左右的记录，一天平均 25 分钟分钟，500 个用户个就是 SELECT 5000*25/60*500=1041667，差不多 100W 左右了，通常来说 nginx 日志的量比较大是正常的。

其中，半夜 1 点到 6 点左右，这个公司广场 wifi 的 ip 地址还会不停的访问 mobileweb，经过分析是由于登录了移动 app 应用，但是睡觉了没有退出应用，手机也没有关系，所以导致移动 app 依然不停的在访问 mobile 应用（因为 1 分钟左右会刷新一次去获取访问当前登录用户的站内互动消息）。

从此可以看出 nginx 的访问日志记录了用户的所有访问行为记录，而且详细到每一个页面里内嵌的 url 记录，如果用适当的工具仔细分析 nginx 日志，就会大概摸清楚用户的访问习惯，这些数据对于市场部门、产品部门来说，是非常有价值的。

Nginx 的详细介绍：请点这里
Nginx 的下载地址：请点这里