Gathering troubleshooting logs with varnishlog.sh

We provide an easy-to-use script named varnishlog.sh to gather troubleshooting information for targeted website traffic via the varnishlog program. varnishlog.sh allows quickly launching the varnishlog program in the background to record VSL log information.

Cachewall 0.40 and higher includes varnishlog.sh. If you need to download a copy for an earlier Cachewall version, use:

wget -q https://repo.cachewall.com/varnishlog.sh -O /usr/local/xvarnish/bin/varnishlog.sh

chmod +x /usr/local/xvarnish/bin/varnishlog.sh

Usage

varnishlog.sh allows managing daemonized varnishlog processes (instances) and provides convenient optional arguments for common varnishlog usage. Instances may be configured with a unique name, HTTP host filtering, VSL grouping, VSL query, and an output log path.

varnishlog.sh may be used as a standalone program:

varnishlog.sh

Usage: varnishlog.sh {start|stop|restart|status|list|stop-all} [-n NAME] [-h HOST] [-g GROUP] [-w LOGFILE] [-q QUERY]

It also may be used as a SysV-style init script (CentOS 6):

ln -s /usr/local/xvarnish/bin/varnishlog.sh /etc/init.d/varnishlog

chkconfig --add varnishlog

service varnishlog

Usage: varnishlog {start|stop|restart|status|list|stop-all} [-n NAME] [-h HOST] [-g GROUP] [-w LOGFILE] [-q QUERY]

Commands

A command argument is required.

start - Start an instance with the provided options.
stop - Stop an instance.
restart - Stop and start an instance with the provided options.
status - Show status of a started instance.
list - Show status for all started instances.
stop-all - Stop all started instances.

See -n NAME and -h HOST options to manage a specific named instance.

Optional Arguments

These arguments are optional and may be combined.

-n NAME specifies the instance name to manage.
-g GROUP specifies the grouping of the VSL log records. The default is to group by session.
-q QUERY specifies the VSL query to use. The default query is to match common error-related tags.
-h HOST specifies an HTTP host to log. Specifies query Host: (.*\.)?HOST'
-w LOGFILE specifies the output log file name. The default path is /var/log/varnishlog[-NAME].bin.

Optional arguments may interact with each other when combined.

Specifying both -h HOST with -q QUERY results in the query: ReqHeader ~ 'Host: (.*\.)?HOST' and QUERY
Specifying -h HOST without -q QUERY results in the query: ReqHeader ~ 'Host: (.*\.)?HOST'
Specifying -h HOST without -n NAME uses HOST as the instance name.

Reading Logs

Each instance logs to its named file in /var/log. These files are in a binary format. To view and query log information from these files, use the varnishlog program with the -r option.

The same VSL record grouping mode used to start an instance should be used while reading the log file.

Examples

Logging Requests to a Specific Website

Usually, it's best to start a varnishlog instance for a specific domain (aka -h domain.com) when troubleshooting problems for a given website. This way, all requests are logged and can be analyzed further without the worry that something was missed.

varnishlog.sh start -h domain.com

Starting varnishlog-domain-com:                            [  OK  ]

The binary log output is written to /var/log/varnishlog-domain-com.bin. You may read and query a log using the varnishlog program, for example:

varnishlog -r /var/log/varnishlog-domain-com.bin -g request -q "RespStatus == 503"

*   << Request  >> 885088
-   Begin          req 885087 rxreq
-   Timestamp      Start: 1521823144.786507 0.000000 0.000000
-   Timestamp      Req: 1521823144.786507 0.000000 0.000000
-   ReqStart       1.1.1.1 54250
-   ReqMethod      GET
-   ReqURL         /5a8b008bdc8a5.jpg
-   ReqProtocol    HTTP/1.1
-   ReqHeader      Accept: */*
-   ReqHeader      Referer: http://domain.com/
...

Managing Multiple Instances

varnishlog.sh start -n 503s -q "RespStatus == 503"

Starting varnishlog-503s:                                  [  OK  ]

varnishlog.sh start -h example.com

Starting varnishlog-example-com:                           [  OK  ]

varnishlog.sh list

varnishlog (pid  471982) is running...

varnishlog-503s (pid  472065) is running...

varnishlog-example-com (pid  473301) is running...

varnishlog.sh stop -n example.com

Stopping varnishlog-example-com:                           [  OK  ]

Example: Logging and Reviewing HTTPS Sessions (Hitch)

varnishlog.sh start -n https -q "ReqHeader ~ 'X-Forwarded-Proto: https'"

Starting varnishlog-https:                                 [  OK  ]

varnishlog -r /var/log/varnishlog-https.bin -g session

*   << Session  >> 1278565
-   Begin          sess 0 PROXY
-   SessOpen       127.0.0.1 48324 127.0.0.1:6086 127.0.0.1 6086 1521823295.621610 52
-   Proxy          2 1.1.1.1 45552 2.2.2.2 443
-   Link           req 1278566 rxreq
-   SessClose      RESP_CLOSE 0.429
-   End
**  << Request  >> 1278566
--  Begin          req 1278565 rxreq
--  Timestamp      Start: 1521823295.622449 0.000000 0.000000
...