Most Varnish configs
contain a lot of logic to strip cookies from the client, to avoid them being sent to the server. This is needed, because cookies are often part of the hash-calculation of a request (if they are included in the vcl_hash routine), and a random cookie would make for a unique hash each time and that can destroy your caching strategy. Here’s a tip on how you can see what cookies your client is sending, and what cookies your Varnish VCL is removing and sending on to the backend.
View the client’s request#
First of, see what cookies your client is sending to a particular request. You can easily filter on the source IP of the connection or on the URL that’s being called.
$ varnishlog -c -q "ReqURL ~ '/my-unique-page'"
$ varnishlog -c -q "ReqStart[1] eq '10.0.1.1'"
The first varnishlog example will show you all the headers for the request to the URL “/my-unique-page”, regardless of the source IP. The second example will show you all requests coming from IP 10.0.1.1.
In the output that follows, pay special attention to the Cookie: header in the request.
- ReqStart 10.0.1.1 65175
- ReqMethod GET
- ReqURL /my-unique-page
- ReqProtocol HTTP/1.1
- ReqHeader Host: xxx
- ReqHeader Connection: keep-alive
...
- ReqHeader Cookie: my-cookie=2; has_js=1; __utma=123456789; __utmb=123456789;
...
- VCL_return hash
- VCL_call MISS
...
The example above shows that 4 cookies are sent along, semi-colon separated:
- my-cookie=2
- has_js=1
- __utma=123456789
- __utmb=123456789
You can strip cookies that are sent from the client in vcl_recv, the routine that processes/prepares the client’s request. To remove cookies, you can use snippets like these.
set req.http.Cookie = regsuball(req.http.Cookie, "has_js=[^;]+(; )?", "");
set req.http.Cookie = regsuball(req.http.Cookie, "__utm.=[^;]+(; )?", "");
The VCL code above strips out the has_js and the __utm. cookies, where the dot “.” indicates a wildcard – this catches the __utma, __utmb, … cookie names in a regular expression.
Notice that the VCL example above does not strip the “my-cookie” cookie. But how can you test this? Well, the varnishlog example above shows the cookies received from the client, we can use a similar varnishlog command to show what cookies Varnish is sending to the backend.
View what Varnish is sending to the backend#
The previous example contained the -c parameter of varnishlog, which include the log entries which result from communication with a client. Similarly, there is a -b parameter for including log entries which result from communication with a backend server. So if you take the same examples from above, you can see the backend communication made by Varnish.
$ varnishlog -b -q "BereqURL ~ '/my-unique-page'"
Notice the 2 subtle differences in the command: -c is swapped for -b, to show backend communication, and ReqURL is swapped for BereqURL. The Req* tags are the request as received from the client; the Bereq* tags (“backend request”) are what Varnish transmits to the backend after the VCL has manipulated it. In other words, ReqURL is the URL received from the client, BereqURL is the URL Varnish sends on to the backend.
The output is similar to the Varnishlog example from the client, but with a clear difference in the Cookie: headers.
- BereqMethod GET
- BereqURL /my-unique-page
- BereqProtocol HTTP/1.1
- BereqHeader Host: xxx
- BereqHeader Cookie: my-cookie=2;
...
The varnishlog with BereqURL filter shows which cookies remain, in this case only the my-cookie one, that we did not remove in the VCL.
Conclusion#
You can use varnishlog to filter on the requests that come from the client, as well as the requests that are sent to the backend server, after the VCL manipulation by Varnish. Pay close attention to the Cookie: header in the Req* (client) and Bereq* (backend) tags, they show you which cookies are not being stripped to the backend.
Varnishlog is a powerful tool for debugging Varnish requests, but you need correct filters to show you the relevant output, not all output. If you want to, you can read up more useful varnishtop and varnishlog commands .