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

Mattias Geniar, Saturday, December 13, 2014 - last modified: Monday, June 27, 2016

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.



Hi! My name is Mattias Geniar. I'm a Support Manager at Nucleus Hosting in Belgium, a general web geek, public speaker and podcaster. Currently working on DNS Spy. Follow me on Twitter as @mattiasgeniar.

I respect your privacy and you won't get spam. Ever.
Just a weekly newsletter about Linux and open source.

SysCast podcast

In the SysCast podcast I talk about Linux & open source projects, interview sysadmins or developers and discuss web-related technologies. A show by and for geeks!

cron.weekly newsletter

A weekly newsletter - delivered every Sunday - for Linux sysadmins and open source users. It helps keeps you informed about open source projects, Linux guides & tutorials and the latest news.

Share this post

Did you like this post? Will you help me share it on social media? Thanks!

Comments

John Doe Wednesday, October 21, 2015 at 10:56

You should probably attribute the source from where you have copied. Ethics and all considering you are soliciting ad revenue…

https://www.varnish-cache.org/trac/wiki/VCLExampleRemovingSomeCookies

Reply


    Mattias Geniar Wednesday, October 21, 2015 at 11:19

    The only ‘copied’ part in this article is the regex to remove a cookie, which isn’t even the main focus. All other content, like viewing which cookies got stripped, are by me.

    I appreciate your view on ethics, but I don’t feel I crossed a line here.

    Reply


Anthony Wednesday, February 17, 2016 at 01:23

Thanks for this article, very useful. One question: the -m flag doesn’t work for me on Varnish 4 and isn’t shown on this list: https://www.varnish-cache.org/docs/trunk/reference/varnishlog.html, is it for an earlier version?

Reply


Leave a Reply

Your email address will not be published. Required fields are marked *

Inbound links