标签：
本部分包括如何查看Varnish正在做什么，从每个http请求流的详细记录到汇总统计计数器。
Logging in Varnish
Statistics
varnishtop
varnishhist
varnishstat
Varnish中一个很棒的特点是工作日志的记录方式。varnish不记录日志到日志文件，而是调用VSL记录到共享内存片段，VSL-varnish共享日志。当这个片段被写完后，varnish开始覆盖老数据。
这种方式比记录到文件快的多得多，并且不需要磁盘空间。除此之外VSL可以给到你需要的尽可能多的信息。
另一方面，如果你忘记有程序实际在写日志到磁盘，日志将会占用过多的磁盘。
varnishlog是可以用来查看varnish记录了什么的程序。varnish提供原生的日志，所有的都被写到日志里。其他一些客户端也能访问日志，一会儿向你展示。
在启动varnish的终端窗口键入varnishlog(varnish-4.0.3: varnishlog -v) 然后回车。
你将看到一些行，缓慢滚动（取决于你的日志量）像这样：
0 CLI - Rd ping 0 CLI - Wr 200 PONG 1273698726 1.0
varnish 主进程检查cache进程，为了查看是否一切ok。
刷新指向varnish的web页面，我们可以看到有些输出：
11 SessionOpen c 127.0.0.1 58912 0.0.0.0:8080 11 ReqStart c 127.0.0.1 58912 595005213 11 RxRequest c GET 11 RxURL c / 11 RxProtocol c HTTP/1.1 11 RxHeader c Host: localhost:8080 11 RxHeader c Connection: keep-alive
第一列是随机数，它是为了辨认访问会话。数字相同表示来自同一个会话，同时会被相同的进程处理。
第二列是日志信息的标签。所有的请求都被一种活动类型的标签标示着。Rx开始的标签表示是Varnish接收的数据，Tx表示发送的数据。
第三列表示数据是从客户端来或者发送到客户端(c)，或者是发送到后端或者从后端返回(b).
第四列表示被记录的数据。
基本的选项：
‘-b‘：只展示varnish和后端server交互的日志。当我们要优化缓存命中率时，非常有用。
[root@aliyun-web1 ~]# varnishlog -b|more * << BeReq >> 513184412 - Begin bereq 513184411 pass - Timestamp Start: 1435903539.233425 0.000000 0.000000 - BereqMethod GET - BereqURL / - BereqProtocol HTTP/1.1 - BereqHeader Host: www.example.com - BereqHeader Accept: */* - BereqHeader Accept-Charset: GB2312,utf-8;q=0.7,*;q=0.7 - BereqHeader Accept-Language: zh-cn, zh - BereqHeader User-Agent: Mozilla/5.0 (Linux; U; Android 4.4.2; zh-cn; GT-I9500 Build/KOT49H) AppleWebKit/537.36 (KHTML, like Gecko)Version/4.0 MQQBrowser/5.0 QQ-Manager Mobile Safari/537.36 - BereqHeader Referer: http://www.example.com/ - BereqHeader X-Forwarded-For: 180.153.206.22 - BereqHeader X-Forward-For: 180.153.206.22 - BereqHeader X-Varnish: 513184412 - VCL_call BACKEND_FETCH - VCL_return fetch - Backend 723 default default(10.171.199.83,,81) - Timestamp Bereq: 1435903539.233538 0.000113 0.000113 - Timestamp Beresp: 1435903539.372638 0.139213 0.139100 - BerespProtocol HTTP/1.1 - BerespStatus 200 - BerespReason OK - BerespHeader Server: openresty - BerespHeader Date: Fri, 03 Jul 2015 06:05:39 GMT - BerespHeader Content-Type: text/javascript; charset=utf-8 - BerespHeader Transfer-Encoding: chunked - BerespHeader Connection: keep-alive - BerespHeader Status: 200 OK - BerespHeader X-UA-Compatible: IE=Edge,chrome=1 - BerespHeader ETag: "a8bc468ef546910351aff1736593a25e" - BerespHeader Cache-Control: max-age=0, private, must-revalidate - BerespHeader X-Request-Id: 091be77be62554630e058bb89e6152e8 - BerespHeader X-Runtime: 0.099064 - BerespHeader X-Rack-Cache: miss
‘-c‘：和-b类似，不过是client和varnish的交互.
[root@aliyun-web1 ~]# varnishlog -c|more * << Request >> 617872310 - Begin req 511130871 rxreq - Timestamp Start: 1435903851.946365 0.000000 0.000000 - Timestamp Req: 1435903851.946365 0.000000 0.000000 - ReqStart 211.144.121.242 10509 - ReqMethod GET - ReqURL /images/example_v4/logo.png?1435895693 - ReqProtocol HTTP/1.1 - ReqHeader Accept: image/png, image/svg+xml, image/*;q=0.8, */*;q=0.5 - ReqHeader Referer: http://www.example.com.cn/articles/2015-04-16/909879.html - ReqHeader Accept-Language: zh-CN - ReqHeader User-Agent: Mozilla/5.0 (Windows NT 6.1; Trident/7.0; rv:11.0) like Gecko - ReqHeader Accept-Encoding: gzip, deflate - ReqHeader Host: static.example.com.cn - ReqHeader DNT: 1 - ReqHeader Connection: Keep-Alive - ReqHeader X-Forwarded-For: 211.144.121.242 - VCL_call RECV - ReqHeader X-Forward-For: 211.144.121.242 - VCL_return hash - ReqUnset Accept-Encoding: gzip, deflate - ReqHeader Accept-Encoding: gzip - VCL_call HASH - VCL_return lookup - Hit 3490076170 - VCL_call HIT - VCL_return deliver - RespProtocol HTTP/1.1 - RespStatus 200 - RespReason OK - RespHeader Server: openresty - RespHeader Date: Fri, 03 Jul 2015 06:09:53 GMT - RespHeader Last-Modified: Fri, 03 Jul 2015 03:54:53 GMT - RespHeader ETag: "5596078d-242a" - RespHeader Content-Type: image/png - RespHeader Vary: Accept-Encoding - RespHeader Content-Encoding: gzip - RespHeader X-Varnish: 617872310 268850698 - RespHeader Age: 58 - RespHeader Via: 1.1 varnish-v4 - VCL_call DELIVER - RespHeader X-Cache: HIT from example 317 - VCL_return deliver
译者注：由于各个版本参数的不同。译者使用的varnish-4.0.3和4.0的输出也不尽相同。 不过还是可以通过varnishlog -h查看确定的参数使用方法。 当然如果你安装了varnish对应版本的varnish-docs，你可通过man手册查看具体的用法,4.0.3官方varnishlog链接.
varnish拥有一组很好且非常实用的状态生成工具，实时的生成状态同时分析共享内存日志的日志数据。
varnishtop读取共享内存日志同时呈现连续最常发生的日志项的更新列表。
list length 6652 web1 4693.76 VCL_return deliver 2531.67 RespProtocol HTTP/1.1 2343.12 VCL_call HASH 2343.12 VCL_call RECV 2343.12 VCL_call DELIVER 2343.12 VCL_return lookup 2343.12 RespHeader Via: 1.1 varnish-v4 2343.12 RespHeader Server: openresty 2336.85 ReqMethod GET 2310.85 RespStatus 200 2310.85 RespReason OK 2310.12 ReqProtocol HTTP/1.1 2208.67 RespHeader Connection: keep-alive 2200.67 VCL_return hash 2142.21 RespHeader Accept-Ranges: bytes 2047.21 ReqHeader Accept-Encoding: gzip 2017.12 Debug XXX REF 2 1967.76 VCL_call HIT 1851.67 Debug RES_MODE 2 1726.94 ReqHeader Accept: */* 1711.48 RespHeader Last-Modified: Fri, 03 Jul 2015 09:04:41 GMT
使用适当的过滤参数-I, -i, -X and -x ，他可以按照请求的资源，客户端，user-agent，以及其他记录在日志里的信息来分层级显示。
varnishtop -i ReqURL显示客户端请求的URL。varnishtop -i BereqURL显示后端请求URL.varnishtop -I ReqHeader:Accept-Encoding显示客户端发送最频繁Accept-Encoding头。
更多用法参考varnishtop
varnishhist工具读取varnishd的共享内存日志，同时实时的呈现最近被处理的N个请求的柱状图。
1:20, n = 2000 web1 | | | | | ||| | ||| | ||| ||||| ||||| ||||| ||||| ||||| ||||| |||||| |||||| |||||| # ||||||| ## |||||||| ### +-------+-------+-------+-------+-------+-------+-------+-------+------- |1e-6 |1e-5 |1e-4 |1e-3 |1e-2 |1e-1 |1e0 |1e1 |1e2
N的值和垂直比例显示在左上角位置。水平比例是对数的，命中标记为|，未命中标记为#。
更多信息查看varnishhist
varnish有许多计数器。它统计miss，hit，存储信息，创建的线程，被删除的对象。varnishstat导出这些计数。当我在调优varnish这个工具显得十分有用。
Uptime mgt: 30+23:10:33 Hitrate n: 5 5 5 Uptime child: 30+23:10:32 avg(n): 0.7449 0.7449 0.7449 NAME CURRENT CHANGE AVERAGE AVG_10 MAIN.uptime 2675432 1.00 1.00 1.00 MAIN.sess_conn 305793621 223.68 114.00 161.26 MAIN.sess_fail 29 0.00 . 0.00 MAIN.client_req_400 24209 0.00 . 0.00 MAIN.client_req 698099671 352.50 260.00 340.48 MAIN.cache_hit 537081611 289.59 200.00 287.56 MAIN.cache_hitpass 17285224 5.99 6.00 6.24 MAIN.cache_miss 78237657 22.97 29.00 21.22 MAIN.backend_conn 4715330 0.00 1.00 0.00 MAIN.backend_fail 1557 0.00 . 0.00 MAIN.backend_reuse 158437412 58.92 59.00 52.42 MAIN.backend_toolate 400204 0.00 . 0.00 MAIN.backend_recycle 158838527 59.92 59.00 53.67 MAIN.backend_retry 37981 0.00 . 0.00 MAIN.fetch_head 661309 0.00 . 0.00 Child process uptime: How long the child process has been running.
一些工具可以规律的导出varnishstat同时利于查看的显示这些计数。其中一个便是Munin。
更多信息请查看varnishstat
varnish 4.0 官方文档翻译21-Reporting and statistics
标签：
原文地址：http://my.oschina.net/monkeyzhu/blog/475090
