varnish提供了varnishlog和varnishncsa两个工具用于日志处理。varnishlog 用于记录varnish 自身定义的日志格式，varnishncsa 用于记录作类似apache/ncsa定义的日志格式 。两个工具可以说是互相补充，前者便于详细的查看varnish 缓存、接收、发送、是否命中等详细的处理过程，便于对varnish进行性能分析和故障查询；后者便于日常的日志分析和数据挖掘。

一、varnishlog工具详解

varnishlog自带的参数如下：

  • -a 当把日志写到文件里时，使用附加，而不是覆盖。
  • -b 只显示 varnishd 和后端服务器的日志。
  • -C 匹配正则表达式的时候，忽略大小写差异。
  • -c 只显示 varnishd 和客户端的日志。
  • -D 以进程方式运行
  • -d 在启动过程中处理旧的日志，一般情况下，varnishhist 只会在进程写入日志后启动。
  • -I regex 匹配正则表达式的日志，如果没有使用-i 或者-I，那么所有的日志都会匹配。
  • -i tag 匹配指定的 tag，如果没有使用-i 或者-I，那么所有的日志都会被匹配。
  • -k num 只显示开始的 num 个日志记录。
  • -n 指定 varnish 实例的名字，用来获取日志，如果没有指定，默认使用主机名。
  • -o 以请求 ID 给日志分组，这个功能没多大用。如果要写到一个文件里使用 -w 选项。
  • -P file 记录 PID 号的文件
  • -r file 从一个文件读取日志，而不是从共享内存读取。
  • -s sum 跳过开始的 num 条日志。
  • -u 无缓冲的输出。
  • -V 显示版本，然后退出。
  • -w file 把日志写到一个文件里代替显示他们，如果不是用-a 参数就会发生覆盖，如果 varnishlog 在写日志时，接收到一个 SIGHUP 信号，他会创建一个新的文件,老的文件可以移走。
  • -X regex 排除匹配正则表达式的日志。
  • -x tag 排除匹配 tag 的日志。
    如果-o 选项被指定，需要使用正则表达式和tag 来制定需要的日志。

平时我们用到的最多的几个参数是-a 、-w、-r、-o、-P 。其能用到的tag标签如下：

Backend
BackendClose
BackendOpen
BackendReuse
BackendXID
CLI
ClientAddr
Debug
Error
ExpBan
ExpKill
ExpPick
Hit
HitPass
HttpError
HttpGarbage
Length
ObjHeader
ObjLostHeader
ObjProtocol
ObjRequest
ObjResponse
ObjStatus
ObjURL
ReqEnd
ReqStart
RxHeader
RxLostHeader
RxProtocol
RxRequest
RxResponse
RxStatus
RxURL
SessionClose
SessionOpen
StatAddr
StatSess
TTL
TxHeader
TxLostHeader
TxProtocol
TxRequest
TxResponse
TxStatus
TxURL
VCL_acl
VCL_call
VCL_return
VCL_trace
WorkThread

下面列举两个常用示例：

1下面的命令简单的打印日志到一个文件：
2varnishlog -w /var/log/varnish.log
3
4下面这条命令读取一个日志文件，然后显示请求的首页：
5varnishlog -r /var/log/varnish.log -c -o RxURL '^/$'

varnishlog记录的日志格式如下：

 113 SessionOpen  c 192.168.10.168 6605 0.0.0.0:80
 213 ReqStart  c 192.168.10.168 6605 356267494
 313 RxRequest c GET
 413 RxURL  c /web/index/css/index_beta30.css
 513 RxProtocolc HTTP/1.1
 613 RxHeader  c Host: img.361way.com
 713 RxHeader  c Connection: keep-alive
 813 RxHeader  c Cache-Control: max-age=0
 913 RxHeader  c If-Modified-Since: Sat, 16 Feb 2013 05:18:03 GMT
1013 RxHeader  c User-Agent: Mozilla/5.0 (Windows NT 5.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.89 Safari/537.1
1113 RxHeader  c Accept: text/css,*/*;q=0.1
1213 RxHeader  c Referer: https://blog.361way.com/
1313 RxHeader  c Accept-Encoding: gzip,deflate,sdch
1413 RxHeader  c Accept-Language: zh-CN,zh;q=0.8
1513 RxHeader  c Accept-Charset: GBK,utf-8;q=0.7,*;q=0.3
1613 VCL_call  c recv lookup
1713 VCL_call  c hash
1813 Hashc /web/index/css/index_beta30.css
1913 Hashc img.361way.com
2013 VCL_returnc hash
2113 Hit c 356267177
2213 VCL_call  c hit deliver
2313 VCL_call  c deliver deliver
2413 TxProtocolc HTTP/1.1
2513 TxStatus  c 304
2613 TxResponsec Not Modified
2713 TxHeader  c Server: nginx
2813 TxHeader  c Content-Type: text/css
2913 TxHeader  c Last-Modified: Sat, 16 Feb 2013 05:18:03 GMT
3013 TxHeader  c Expires: Sat, 16 Mar 2013 03:39:18 GMT
3113 TxHeader  c Cache-Control: max-age=86400
3213 TxHeader  c Content-Encoding: gzip
3313 TxHeader  c Accept-Ranges: bytes
3413 TxHeader  c Date: Fri, 15 Mar 2013 06:00:53 GMT
3513 TxHeader  c Age: 8686
3613 TxHeader  c Connection: keep-alive
3713 TxHeader  c X-Cache: HIT from TEST.com
3813 TxHeader  c Via: 361way-CACHE
3913 Length c 0
4013 ReqEnd c 356267494 1363327253.501475096 1363327253.501555920 0.000028133 0.000038862 0.000041962
4113 Debug  c herding

从上面不难看出，其显示的过程是比较详细的。另外需要注意的是varnishlog记录的日志文件只能通过varnishlog工具去读取，不支持cat、more、less、vim等工具查看。

二、varnishncsa 工具详解

varnishncsa 工具读取共享内存的日志，然后以 apache/NCSA 的格式显示出来。其自带参数如下：

  • -a 当把日志写到文件里时，使用附加，而不是覆盖。
  • -b 只显示varnishd和后端服务器的日志。
  • -C 匹配正则表达式的时候，忽略大小写差异。
  • -c 只显示varnishd和客户端的日志。
  • -D 以进程方式运行
  • -d 在启动过程中处理旧的日志，一般情况下，varnishhist只会在进程写入日志后启动。
  • -f 在日志输出中使用X-Forwarded-ForHTTP头代替client.ip。
  • -I regex 匹配正则表达式的日志，如果没有使用-i或者-I，那么所有的日志都会匹配。
  • -i tag 匹配指定的tag，如果没有使用-i或者-I，那么所有的日志都会被匹配。
  • -n 指定varnish实例的名字，用来获取日志，如果没有指定，默认使用主机名。
  • -P file记录PID号的文件
  • -r file从一个文件读取日志，而不是从共享内存读取。
  • -w file把日志写到一个文件里代替显示他们，如果不是用-a参数就会发生覆盖，如果varnishlog在写日志时，接收到一个SIGHUP信号，他会创建一个新的文件，老的文件可以移走。
  • -X regex 排除匹配正则表达式的日志。
  • -x tag 排除匹配tag的日志。

常用到的varnishncsa语句如下：

1/App/varnish/bin/varnishncsa -a -w /logs/varnish.log &

varnishncsa产生的日志文件可以通过cat、more、less、vim都工具读取或打开，打开后的文件格式和apache日志并没有太大区别，如下：

192.168.10.168 - - [15/Mar/2013:14:14:39 +0800] "GET http://img.361way.com/web/index/img/beta30_head_line.jpg HTTP/1.1" 304 0 "https://blog.361way.com/" "Mozilla/5.0 (Windows NT 5.1) AppleWebKit/537.1 (KHTML, like Gecko) Chrome/21.0.1180.89 Safari/537.1"

注：varnishncsa输出的日志格式也有可能并不是我们想要的格式，这时可以通过-F参数更改其输出格式。一个现网中经常会碰到的例子是，varnish被置于nginx之后，此时varnish记录的client.IP就会是前端nginx的IP。该问题的解决方法也很简单，在前端nginx上设置X-Forwarder-For头 ，而varnish通过-F对日志整形，获取客户的真实IP 。如下：

1varnishncsa -F "%{X-Forwarded-For}i %h %l %u %t "%r" %s %b "%{Referer}i" "%{User-agent}i""

varnishncsa默认的日志格式是：

1"%h %l %u %t "%r" %s %b "%{Referer}i" "%{User-agent}i""

三、varnish日志轮询

日志文件过大，会影响到主机IO的读写，对机器的性能也有很大挑战。因此，我们需要按时间对日志进行cut切割。rpm安装的varnish自带了varnishlog、varnishncsa两个脚本（位于/etc/init.d下）用于启动和关闭日志。而对于日志的轮询上，其会在/etc/logrotate.d目录下生成一个varnish文件，用于通过logrotate工具进行日志轮询。

当然源码包安装的也会带有上面三个文件，其在源码包的redhat 目录下。不过不能真接拿来用，需要根据我们的安装目录进行相应的修改，感觉麻烦的也可以通过自定义脚本来实现日志的切割。如下：

 1#!/bin/bash
 2stop() {
 3    pid=`ps -ef | grep "/App/varnish/sbin/varnishd" | grep -v grep | awk '{print $2}'`
 4    num=`ps -ef | grep "/App/varnish/sbin/varnishd" | grep -v grep | wc -l`
 5    if [ $num -gt 0 ] ; then
 6        kill -9 $pid
 7        echo -e "kill varnish"
 8    fi
 9}
10start() {
11    echo "start..."
12    /App/varnish/sbin/varnishd -u www -g www -f /App/varnish/etc/varnish/default.vcl -s malloc,25G -a 0.0.0.0:80 -T 127.0.0.1:2000
13    num=`ps -ef | grep "/App/varnish/sbin/varnishd" | grep -v grep | wc -l`
14    if [ $num -gt 0 ] ; then
15        echo -e "start varnish"
16        ps -ef | grep "/App/varnish/sbin/varnishd" | grep -v grep | awk '{print "pid="$2}'
17    else
18        echo -e "start varnish"
19        stop
20    fi
21}
22stoplog() {
23        pid=`ps -ef | grep "/App/varnish/bin/varnishncsa" | grep -v grep | awk '{print $2}'`
24        num=`ps -ef | grep "/App/varnish/bin/varnishncsa" | grep -v grep | wc -l`
25        if [ $num -gt 0 ] ; then
26                kill -9 $pid
27                echo -e "kill varnishlog"
28        fi
29}
30startlog() {
31        echo "startlog..."
32    /App/varnish/bin/varnishncsa -a -w /logs/varnish.log &
33    sleep 1
34        num=`ps -ef | grep "/App/varnish/bin/varnishncsa" | grep -v grep | wc -l`
35        if [ $num -gt 0 ] ; then
36                echo -e "start varnishlog"
37                ps -ef | grep "/App/varnish/bin/varnishncsa" | grep -v grep | awk '{print "pid="$2}'
38        else
39                echo -e "start varnishlog"
40        stoplog
41        fi
42}
43cutlog() {
44    _yesdate=$(date -d "yesterday" +"%Y-%m-%d")
45    stoplog
46    mv /logs/varnish.log /logs/${_yesdate}.log
47    startlog
48}
49case $1 in
50    "start")
51        stop
52        start
53    ;;
54    "stop")
55        stop
56    ;;
57    "startlog")
58        stoplog
59        startlog
60    ;;
61    "stoplog")
62        stoplog
63    ;;
64    "cutlog")
65        cutlog
66    ;;
67    "startall")
68        stop
69        stoplog
70        start
71        startlog
72    ;;
73    "stopall")
74        stop
75        stoplog
76    ;;
77    *)
78        echo "$0 start stop startlog stoplog startall stopall cutlog"
79    ;;
80esac
81exit 0

该脚本包含了varnish的启动、关闭、varnishnsca的启动、关闭与切割。当然部分内容可能和自己的现网应用有出入的，可以再自行修改。日志cut，可以配合crontab工具定时进行。