====== Varnishのログ ======
===== Varnish Shared memory Log =====
Varnishのログは他の一般的なミドルウェアと異なり、ログをメモリ（Varnish Shared memory Log）上に出力します。
varnishlogやvarnishncsaなどのコマンドでVSLを読み込んでファイル出力や、varnishhistでヒストグラムの整形などを行います。
===== 生ログを確認 =====
varnishlogコマンドでリアルタイムの生ログを確認することが可能。
以下、バックエンドのnginxでphpinfoにアクセスしたときのログ
# varnishlog
* << BeReq >> 32783
- Begin bereq 32782 fetch
- Timestamp Start: 1415685949.873767 0.000000 0.000000
- BereqMethod GET
- BereqURL /
- BereqProtocol HTTP/1.1
- BereqHeader Host: 192.168.24.192:6081
- BereqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
- BereqHeader User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36
- BereqHeader Accept-Language: ja,en-US;q=0.8,en;q=0.6
- BereqHeader X-Forwarded-For: 192.168.26.56
- BereqHeader Accept-Encoding: gzip
- BereqHeader X-Varnish: 32783
- VCL_call BACKEND_FETCH
- VCL_return fetch
- BackendClose 21 default(127.0.0.1,,80) toolate
- BackendClose 17 default(127.0.0.1,,80) toolate
- BackendOpen 17 default(127.0.0.1,,80) 127.0.0.1 46330
- Backend 17 default default(127.0.0.1,,80)
- Timestamp Bereq: 1415685949.888515 0.014749 0.014749
- Timestamp Beresp: 1415685950.213864 0.340098 0.325349
- BerespProtocol HTTP/1.1
- BerespStatus 200
- BerespReason OK
- BerespHeader Server: nginx/1.6.2
- BerespHeader Date: Tue, 11 Nov 2014 06:05:50 GMT
- BerespHeader Content-Type: text/html
- BerespHeader Transfer-Encoding: chunked
- BerespHeader Connection: keep-alive
- BerespHeader X-Powered-By: PHP/5.4.34
- TTL RFC 120 -1 -1 1415685950 1415685950 1415685950 0 0
- VCL_call BACKEND_RESPONSE
- VCL_return deliver
- Storage malloc s0
- ObjProtocol HTTP/1.1
- ObjStatus 200
- ObjReason OK
- ObjHeader Server: nginx/1.6.2
- ObjHeader Date: Tue, 11 Nov 2014 06:05:50 GMT
- ObjHeader Content-Type: text/html
- ObjHeader X-Powered-By: PHP/5.4.34
- Fetch_Body 2 chunked stream
- BackendReuse 17 default(127.0.0.1,,80)
- Timestamp BerespBody: 1415685950.219570 0.345803 0.005706
- Length 48669
- BereqAcct 367 0 367 180 48728 48908
- End
===== 生ログをファイルに出力 =====
起動スクリプト（/etc/init.d/varnishlog）に出力するファイル名がハードコーディングされているので、ここを編集して設定可能。
# /etc/init.d/varnishlog start
# ps aux | grep varnishlog
root 6239 0.1 0.0 100384 492 ? Ss 15:09 0:00 /usr/bin/varnishlog -a -w /var/log/varnish/varnish.log -D -P /var/run/varnishlog.pid
# tail /var/log/varnish/varnish.log
- End
* << Session >> 10
- Begin sess 0 HTTP/1
- SessOpen 192.168.26.56 52864 :6081 192.168.24.192 6081 1415685456.258270 12
- Link req 11 rxreq
- Link req 13 rxreq
- SessClose RX_TIMEOUT 5.176
- End
===== NCSA形式のログを出力 =====
apacheなどで使われているNCSA形式のログを出力する。
起動スクリプト（/etc/init.d/varnishncsa ）に出力するファイル名がハードコーディングされているので、ここを編集して設定可能。
# /etc/init.d/varnishncsa start
# ps aux | grep varnishncsa
root 6275 0.1 0.0 100400 496 ? Ss 15:14 0:00 /usr/bin/varnishncsa -a -w /var/log/varnish/varnishncsa.log -D -P /var/run/varnishncsa.pid
# tail -f /var/log/varnish/varnishncsa.log
192.168.26.56 - - [11/Nov/2014:15:15:21 +0900] "GET http://192.168.24.192:6081/ HTTP/1.1" 200 48714 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
192.168.26.56 - - [11/Nov/2014:15:15:21 +0900] "GET http://192.168.24.192:6081/index.php?=PHPE9568F35-D428-11d2-A769-00AA001ACF42 HTTP/1.1" 200 2160 "http://192.168.24.192:6081/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
192.168.26.56 - - [11/Nov/2014:15:15:21 +0900] "GET http://192.168.24.192:6081/index.php?=PHPE9568F34-D428-11d2-A769-00AA001ACF42 HTTP/1.1" 200 2524 "http://192.168.24.192:6081/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.111 Safari/537.36"
===== varnishncsaを出力をsyslog-ngに渡す =====
varnishncsaの起動スクリプトを編集して、ログ出力をパイプでlogger（facility N）に渡す。
ただし、標準のDオプションでdaemon化するとsyslogに渡らないので、Dオプションをつけずに、＆でバックグラウンドで処理させる。
# vi /etc/init.d/varnishncsa
#DAEMON_OPTS="-a -w $logfile -D -P $pidfile"
FORMAT_OPTS="%h %l %u %t \"%r\" %s %b \"%{Referer}i\" \"%{User-agent}i\" %D"
SYSLOG_OPTS=" | /usr/bin/logger -t varnish -p local5.info"
DAEMON_OPTS="-P $pidfile -F '$FORMAT_OPTS'"$SYSLOG_OPTS
.
.
.
#daemon --pidfile $pidfile $exec "$DAEMON_OPTS"
daemon --pidfile $pidfile $exec "$DAEMON_OPTS" &