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 -m RxURL:/my-unique-page $ varnishlog -c -m ReqStart: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.
29 ReqStart c 10.0.1.1 65175 295468531 29 RxRequest c GET 29 RxURL c /my-unique-page 29 RxProtocol c HTTP/1.1 29 RxHeader c Host: xxx 29 RxHeader c Connection: keep-alive ... 29 RxHeader c Cookie: my-cookie=2; has_js=1; __utma=123456789; __utmb=123456789; ... 29 VCL_return c hash 29 VCL_call c miss fetch ...
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 -m TxUrl:/my-unique-page
Notice the 2 subtle differences in the command: -c is swapped for -b, to show backend communication, and RxURL is swapped for TxURL. The “Rx” and “Tx” naming comes from the telecom/networking world, where “Rx” stands for “Receiving” and “Tx” stands for “Transmitting”. In other words, an RxURL is an URL received from the client, a TxURL is a URL sent by Varnish (transmitted) to the backend.
The output is similar to the Varnishlog example from the client, but with a clear difference in the Cookie: headers.
314 BackendXID b 295505930 314 TxRequest b GET 314 TxURL b /my-unique-page 314 TxProtocol b HTTP/1.1 314 TxHeader b Host: xxx 314 TxHeader b Cookie: my-cookie=2; ...
The varnishlog with TxURL 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 RxURL and TxURL, 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.