nginx日志

nginx 日志主要有两条指令:

  1. log_format:用来设置日志格式;
  2. access_log:用来指定日志文件的存放路径、格式(把定义的log_format 跟在后面)和缓存大小;如果不想启用日志则access_log off ;

log_format 日志格式

语法格式:

该指令用来设置日志记录的格式。

1
2
log_format name format [format ...]
name : 给定义的格式起的名称,应该是全局唯一的

默认日志格式

默认情况下,nginx的默认日志格式如下(不同版本可能略有不同):

1
2
3
log_format combined '$remote_addr - $remote_user [$time_local]  '
'"$request" $status $body_bytes_sent '
'"$http_referer" "$http_user_agent"';

日志格式举例:

1
192.168.161.1 - - [25/Oct/2016:05:39:45 +0800] "GET /favicon.ico HTTP/1.1" 404 571 "http://192.168.161.126/" "Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.2785.143 Safari/537.36"

常见内置变量

nginx中log日志变量

日志分类

access_log

该指令用来指定访问日志的路径及格式等信息。

语法格式

1
access_log path [log_format_name [buffer=buffer_size | off]]

示例:

1
2
3
4
log_format reverseRealIpFormat1 '$remote_addr - $remote_user [$time_local]  '
'"$request" $status $body_bytes_sent '
'"$http_referer" "$http_user_agent"';
access_log /var/log/nginx/my-access.log reverseRealIpFormat1 buffer=8k;

在access_log中可以使用变量,但是不能与buffer同时启用,否则buffer不能启用

1
2
1. access_log /var/log/nginx/$server_name.log reverseRealIpFormat1;
2. access_log /var/log/nginx/$server_name.log reverseRealIpFormat1 buffer=8k;

error_log

error_log是设置记录错误日志的指令。

该指令在 http, stream, server 和 location 段都可以被指定,可以覆盖更外面的段的设置。

1
error_log /var/log/nginx/error.log warn;

open_log_file_cache

每次记录日志都是将日志文件打开->写入->关闭,太消耗IO.

open_log_file_cache 可以设置路径中含有变量的日志配置中日志文件的文件描述符缓存。

1
2
3
4
5
6
7
8
open_log_file_cache max=N [inactive=time] [min_uses=N] [valid=time] | off;

参数注释如下:

max:设置缓存中的最大文件描述符数量,如果缓存被占满,采用LRU算法将描述符关闭。
inactive:设置存活时间,默认是10s
min_uses:设置在inactive时间段内,日志文件最少使用多少次后,该日志文件描述符记入缓存中,默认是1次
valid:设置检查频率,默认60s

例如:

1
open_log_file_cache max=655350 inactive=20s;

设置刷盘策略

buffer 满 32k 才刷盘;假如 buffer 不满 5s 钟强制刷盘

1
access_log /data/logs/nginx-access.log buffer=32k flush=5s;

使用举例

一般log_format在全局设置,可以设置多个。access_log 可以在全局设置,但往往是定义在虚拟主机(server)中的location中

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
http {
log_format main '$remote_addr - $remote_user [$time_local] "$request" '
'"$status" $body_bytes_sent "$http_referer" '
'"$http_user_agent" "$http_x_forwarded_for" '
'"$gzip_ratio" $request_time $bytes_sent $request_length';

log_format srcache_log '$remote_addr - $remote_user [$time_local] "$request" '
'"$status" $body_bytes_sent $request_time $bytes_sent $request_length '
'[$upstream_response_time] [$srcache_fetch_status] [$srcache_store_status] [$srcache_expire]';

open_log_file_cache max=1000 inactive=60s;

server {
server_name ~^(www\.)?(.+)$;
access_log logs/$2-access.log main;
error_log logs/$2-error.log;
location /srcache {
access_log logs/access-srcache.log srcache_log;
}
}
}

日志分析:

通过对日志格式的定义,就可以使用常见的 Linux 命令行工具进行分析了:

查找访问频率最高的 URL 和次数:

1
cat access.log | awk -F ‘^A’ ‘{print $10}’ | sort | uniq -c

查找当前日志文件 500 错误的访问:

1
cat access.log | awk -F ‘^A’ ‘{if($5 == 500) print $0}’

查找当前日志文件 500 错误的数量:

1
cat access.log | awk -F ‘^A’ ‘{if($5 == 500) print $0}’ | wc -l

查找某一分钟内 500 错误访问的数量:

1
cat access.log | awk -F ‘^A’ ‘{if($5 == 500) print $0}’ | grep ’09:00’ | wc-l

查找耗时超过 1s 的慢请求:

1
tail -f access.log | awk -F ‘^A’ ‘{if($6>1) print $0}’

假如只想查看某些位:

1
tail -f access.log | awk -F ‘^A’ ‘{if($6>1) print $3″|”$4}’

查找 502 错误最多的 URL:

1
cat access.log | awk -F ‘^A’ ‘{if($5==502) print $11}’ | sort | uniq -c

查找 200 空白页

1
cat access.log | awk -F ‘^A’ ‘{if($5==200 && $8 < 100) print $3″|”$4″|”$11″|”$6}’

切割日志

Nginx 的日志都是写在一个文件当中的,不会自动地进行切割,如果访问量很大的话,将导致日志文件容量非常大,不便于管理和造成Nginx 日志写入效率低下等问题。所以,往往需要要对access_log、error_log日志进行切割。

切割日志一般利用USR1信号让nginx产生新的日志。实例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
#!/bin/bash

logdir="/data/logs/nginx"
pid=`cat $logdir/nginx.pid`
DATE=`date -d "1 hours ago" +%Y%m%d%H`
DATE_OLD=`date -d "7 days ago" +%Y%m%d`
for i in `ls $logdir/*access.log`; do
mv $i $i.$DATE
done
for i in `ls $logdir/*error.log`; do
mv $i $i.$DATE
done
kill -s USR1 $pid
rm -v $logdir"/access.log."$DATE_OLD*

rm -v $logdir"/error.log."$DATE_OLD*

1、分析:

将上面的脚本放到crontab中,每小时执行一次(0 ),这样每小时会把当前日志重命名成一个新文件;然后发送USR1这个信号让Nginx 重新生成一个新的日志。(相当于备份日志)
将前7天的日志删除;
2、说明:
在没有执行kill -USR1 $pid之前,即便已经对文件执行了mv命令而改变了文件名称,nginx还是会向新命名的文件”*access.log.2016032623”照常写入日志数据的。原因在于:linux系统中,内核是根据文件描述符来找文件的。

3、logrotates:
使用系统自带的logrotates,也可以实现nginx的日志分割,查看其bash源码,发现也是发送USR1这个信号。

使用日志排查问题举例

磁盘满

问题描述

某周日晚8点多,收到报警短信,我们一个pv统计服务的打点统计结果突然大幅减少。赶紧登VPN上内网,发现pv统计曲线,在故障发生后,对比上周日下降到1/3左右。

解决步骤

  1. 检查了统计计算程序,未发现异常。
  2. 检查了一下机器列表
    发现有一台电信的机器(ds1)挂了,lvs上已经自动下线;另一台电信机器(ds2)CPU空闲率从81%下降到42%

  3. 先将这些程序 kill掉,并在 联通机房的 ls2 机器上启动起来
    操作完毕后,ds2的CPU空闲率回升到70%多,但pv统计结果依然维持在1/3左右

  4. 查看ds2上的打点日志(nginx的access log),发现竟然没有新日志写入。再查看nginx的错误日志,有如下字样:
1
[alert] 19963#0: *17264042335 write() to "/usr/local/nginx/logs/xxx.log" failed (28: No space left on device) while logging request

再用df -lh命令查看,发现磁盘已满

1
2
3
Filesystem            Size  Used Avail Use% Mounted on
/dev/xvde1 493G 493G 0G 100% /
tmpfs 2.0G 0 2.0G 0% /dev/shm

清理一部分无用日志,重启nginx,再观察,统计结果终于回升了。

问题原因

原来电信机房的ds1机器挂了之后,所有电信的流量都到ds2这一台机器上了,导致打点日志增长过快,加上之前有部分无用日志未及时清理,导致硬盘满了,所有电信网络打点请求的日志都没有记录下来。我们电信的请求量大约是联通的两倍,因此反映到统计结果上是下降到1/3。

结论

这次问题的出现到解决,实际上经历了较长的时间。回过头来思考,其实问题是可以很快定位解决的。观察到日志下降到1/3的现象,就可以怀疑是整个电信的日志没有收集到,查一下电信机器上的打点日志 和 error log,很快可以看到问题。另外,出现程序执行不对劲,日志写入不了等等奇怪问题,都可以看看是否磁盘满了。


参考博客:

  1. http://www.jianshu.com/p/4fcaac8f2996
  2. https://lanjingling.github.io/2016/03/14/nginx-access-log/
  3. http://tabalt.net/blog/a-nginx-log-problem-investigation-record/