Varnish tip: see which cookies are being stripped in your VCL

Want to help support this blog? Try out Oh Dear, the best all-in-one monitoring tool for your entire website, co-founded by me (the guy that wrote this blogpost). Start with a 10-day trial, no strings attached.

We offer uptime monitoring, SSL checks, broken links checking, performance & cronjob monitoring, branded status pages & so much more. Try us out today!

Profile image of Mattias Geniar

Mattias Geniar, December 13, 2014

Follow me on Twitter as @mattiasgeniar

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.



Want to subscribe to the cron.weekly newsletter?

I write a weekly-ish newsletter on Linux, open source & webdevelopment called cron.weekly.

It features the latest news, guides & tutorials and new open source projects. You can sign up via email below.

No spam. Just some good, practical Linux & open source content.