Varnishlog filter the records for debugging
Written by Guillermo Garron
Date: 2011-07-25 10:36:30 00:00
Varnish Logs
Varnish is a powerful reverse proxy that can balance the load of multiple web servers, and cache the required pages at the same time. You can read more about it at its home page
Now we all know that debugging is an important part of installing, configuring and fine tuning any piece of software, and that goes to varnish too, and varnishlog is a great utility to help you while debugging varnish.
varnishlog
As the name says, it display Varnish logs, but if you have a very busy site, and your run it with no parameters you will hardly follow the logs in the screen, so your first option to solve this, is to write the logs to a file and analyze them later.
varnishlog -w /home/user/varnishlogs.log
You can then use less to view the document. But you’ll have too much information to digest and it would be better to filter it by IP or some other field. We normally use grep to do that, but in the case of varnishlog the info is placed one field by line so grep is not useful.
Here an example, of the varnishlog output.
17 SessionOpen c 66.249.72.22 47013 :80
17 ReqStart c 66.249.72.22 47013 487860892
17 RxRequest c GET
17 RxURL c /find-Linux-command-to-find-files-on-your-disk
17 RxProtocol c HTTP/1.1
17 RxHeader c Host: www.go2linux.org
17 RxHeader c Connection: Keep-alive
17 RxHeader c Accept: */*
17 RxHeader c From: googlebot(at)googlebot.com
17 RxHeader c User-Agent: Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)
17 RxHeader c Accept-Encoding: gzip,deflate
17 RxHeader c If-Modified-Since: Sun, 24 Jul 2011 16:10:35 GMT
17 VCL_call c recv lookup
17 VCL_call c hash hash
17 Hit c 487859722
17 VCL_call c hit deliver
17 VCL_call c deliver deliver
17 TxProtocol c HTTP/1.1
17 TxStatus c 304
17 TxResponse c Not Modified
17 TxHeader c Date: Mon, 25 Jul 2011 16:28:26 GMT
17 TxHeader c Via: 1.1 varnish
17 TxHeader c X-Varnish: 487860892
17 TxHeader c Last-Modified: Sun, 24 Jul 2011 16:10:35 GMT
17 TxHeader c Cache-Control: public, max-age=300
17 TxHeader c Vary: Accept-Encoding, Accept-Encoding
17 TxHeader c Connection: keep-alive
17 TxHeader c X-Cache: HIT
17 TxHeader c X-Cache-Hits: 1
17 Length c 0
17 ReqEnd c 487860892 1311611306.344539404 1311611306.344666958 0.000112295 0.000054836 0.000072718
We can now filter for any of those fields, and only show the records that contain certain value for a specific field. Let’s see an example.
varnishlog -c -o RxRequest GET
Will show all records (like the one above) that have the field RxRequest with GET value. You can also list all records for an specific IP
varnishlog -c -o SessionOpen 11.22.33.44
You can also write everything to a file with
varnishlog -w /home/user/varnish.log
and then read from there filtering with:
varnishlog -r /home/user/varnish.log -c -o SessionOpen 11.22.33.44
As you can see varnishlog can be very useful, if you can filter the info you really need