1

I'm struggling to make Varnish cache work with WordPress.
I have used Nginx as SSL termination proxy with Varnish as frontend and Nginx listening on port 8080 as backend. And Cloudflare is used as CDN.

My Varnish vcl file looks like: https://gist.github.com/MagePsycho/9be35ce90f1b886e19eedae852e29466

The strange thing is, caching works fine in Chrome's Incognito mode.

I have used following command to capture the log for Wordpress homepage

varnishlog -q 'ReqURL eq "/"'

1# varnishlog for Chrome - Normal

*   << Request  >> 131964
-   Begin          req 131963 rxreq
-   Timestamp      Start: 1550735920.247162 0.000000 0.000000
-   Timestamp      Req: 1550735920.247162 0.000000 0.000000
-   ReqStart       127.0.0.1 55348
-   ReqMethod      GET
-   ReqURL         /
-   ReqProtocol    HTTP/1.1
-   ReqHeader      X-Real-IP: 162.158.158.52
-   ReqHeader      X-Forwarded-For: 94.200.42.14, 162.158.158.52
-   ReqHeader      X-Forwarded-Proto: https
-   ReqHeader      X-Forwarded-Port: 443
-   ReqHeader      Host: blog.somedomain.com
-   ReqHeader      Connection: close
-   ReqHeader      Accept-Encoding: gzip
-   ReqHeader      CF-RAY: 4ac7ab4bcd05bc50-LHR
-   ReqHeader      CF-Visitor: {"scheme":"https"}
-   ReqHeader      pragma: no-cache
-   ReqHeader      cache-control: no-cache
-   ReqHeader      authorization: Basic bWFnZXBzeWNobzpwQHNzNDI5
-   ReqHeader      upgrade-insecure-requests: 1
-   ReqHeader      user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36
-   ReqHeader      accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
-   ReqHeader      accept-language: en-US,en;q=0.9
-   ReqHeader      cookie: __cfduid=d89eee15302ab3e849289d07c5e0211d81550672156; _ga=GA1.2.1671967921.1550672158; _gid=GA1.2.724641208.1550672158; __utmc=143790182; __utmz=143790182.1550672159.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); __zlcmid=qxi22o7iIoGPBJ; PHPS
-   ReqHeader      CF-Connecting-IP: 94.200.42.14
-   ReqHeader      CDN-Loop: cloudflare
-   ReqUnset       X-Forwarded-For: 94.200.42.14, 162.158.158.52
-   ReqHeader      X-Forwarded-For: 94.200.42.14, 162.158.158.52, 127.0.0.1
-   VCL_call       RECV
-   ReqUnset       Host: blog.somedomain.com
-   ReqHeader      Host: blog.somedomain.com
-   ReqUnset       X-Forwarded-For: 94.200.42.14, 162.158.158.52, 127.0.0.1
-   ReqHeader      X-Forwarded-For: 94.200.42.14, 162.158.158.52, 127.0.0.1, 127.0.0.1
-   VCL_return     pass
-   VCL_call       HASH
-   VCL_return     lookup
-   VCL_call       PASS
-   VCL_return     fetch
-   Link           bereq 131965 pass
-   Timestamp      Fetch: 1550735920.253008 0.005846 0.005846
-   RespProtocol   HTTP/1.1
-   RespStatus     200
-   RespReason     OK
-   RespHeader     Server: nginx/1.10.3 (Ubuntu)
-   RespHeader     Date: Thu, 21 Feb 2019 07:58:40 GMT
-   RespHeader     Content-Type: text/html; charset=UTF-8
-   RespHeader     Last-Modified: Wed, 20 Feb 2019 18:49:29 GMT
-   RespHeader     Content-Encoding: gzip
-   RespHeader     Vary: Accept-Encoding
-   RespHeader     Referrer-Policy: no-referrer-when-downgrade
-   RespHeader     Content-Security-Policy: default-src * data: 'unsafe-eval' 'unsafe-inline'
-   RespHeader     Strict-Transport-Security: max-age=31536000; includeSubDomains; preload
-   RespHeader     X-Varnish: 131964
-   RespHeader     Age: 0
-   RespHeader     Via: 1.1 varnish-v4
-   VCL_call       DELIVER
-   RespHeader     X-Cache: MISS
-   RespHeader     X-Cache-Hits: 0
-   RespUnset      Server: nginx/1.10.3 (Ubuntu)
-   RespUnset      X-Varnish: 131964
-   RespUnset      Age: 0
-   RespUnset      Via: 1.1 varnish-v4
-   VCL_return     deliver
-   Timestamp      Process: 1550735920.253035 0.005873 0.000027
-   RespHeader     Accept-Ranges: bytes
-   RespHeader     Transfer-Encoding: chunked
-   Debug          "RES_MODE 8"
-   RespHeader     Connection: close
-   Timestamp      Resp: 1550735920.255363 0.008201 0.002328
-   ReqAcct        1089 0 1089 484 28646 29130
-   End

2# varnishlog for Chrome - Incognito Mode

*   << Request  >> 131967
-   Begin          req 131966 rxreq
-   Timestamp      Start: 1550735974.938916 0.000000 0.000000
-   Timestamp      Req: 1550735974.938916 0.000000 0.000000
-   ReqStart       127.0.0.1 55402
-   ReqMethod      GET
-   ReqURL         /
-   ReqProtocol    HTTP/1.1
-   ReqHeader      X-Real-IP: 141.101.98.131
-   ReqHeader      X-Forwarded-For: 94.200.42.14, 141.101.98.131
-   ReqHeader      X-Forwarded-Proto: https
-   ReqHeader      X-Forwarded-Port: 443
-   ReqHeader      Host: blog.somedomain.com
-   ReqHeader      Connection: close
-   ReqHeader      Accept-Encoding: gzip
-   ReqHeader      CF-RAY: 4ac7aca19feebc0e-LHR
-   ReqHeader      CF-Visitor: {"scheme":"https"}
-   ReqHeader      pragma: no-cache
-   ReqHeader      cache-control: no-cache
-   ReqHeader      upgrade-insecure-requests: 1
-   ReqHeader      user-agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36
-   ReqHeader      accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
-   ReqHeader      accept-language: en-US,en;q=0.9
-   ReqHeader      CF-Connecting-IP: 94.200.42.14
-   ReqHeader      CDN-Loop: cloudflare
-   ReqUnset       X-Forwarded-For: 94.200.42.14, 141.101.98.131
-   ReqHeader      X-Forwarded-For: 94.200.42.14, 141.101.98.131, 127.0.0.1
-   VCL_call       RECV
-   ReqUnset       Host: blog.somedomain.com
-   ReqHeader      Host: blog.somedomain.com
-   ReqUnset       X-Forwarded-For: 94.200.42.14, 141.101.98.131, 127.0.0.1
-   ReqHeader      X-Forwarded-For: 94.200.42.14, 141.101.98.131, 127.0.0.1, 127.0.0.1
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqURL         /
-   VCL_return     hash
-   VCL_call       HASH
-   VCL_return     lookup
-   Hit            98349
-   VCL_call       HIT
-   VCL_return     deliver
-   RespProtocol   HTTP/1.1
-   RespStatus     200
-   RespReason     OK
-   RespHeader     Server: nginx/1.10.3 (Ubuntu)
-   RespHeader     Date: Wed, 20 Feb 2019 20:13:04 GMT
-   RespHeader     Content-Type: text/html; charset=UTF-8
-   RespHeader     Last-Modified: Wed, 20 Feb 2019 18:49:29 GMT
-   RespHeader     Content-Encoding: gzip
-   RespHeader     Vary: Accept-Encoding
-   RespHeader     Referrer-Policy: no-referrer-when-downgrade
-   RespHeader     Content-Security-Policy: default-src * data: 'unsafe-eval' 'unsafe-inline'
-   RespHeader     Strict-Transport-Security: max-age=31536000; includeSubDomains; preload
-   RespHeader     cache-control: max-age=900
-   RespHeader     magicmarker: 1
-   RespHeader     X-Varnish: 131967 98349
-   RespHeader     Age: 42390
-   RespHeader     Via: 1.1 varnish-v4
-   VCL_call       DELIVER
-   RespHeader     X-Cache: HIT
-   RespHeader     X-Cache-Hits: 2
-   RespUnset      Server: nginx/1.10.3 (Ubuntu)
-   RespUnset      X-Varnish: 131967 98349
-   RespUnset      Age: 42390
-   RespUnset      Via: 1.1 varnish-v4
-   RespUnset      magicmarker: 1
-   RespHeader     age: 0
-   VCL_return     deliver
-   Timestamp      Process: 1550735974.939009 0.000093 0.000093
-   RespHeader     Accept-Ranges: bytes
-   RespHeader     Content-Length: 28646
-   Debug          "RES_MODE 2"
-   RespHeader     Connection: close
-   Timestamp      Resp: 1550735974.939084 0.000168 0.000075
-   ReqAcct        646 0 646 514 28646 29160
-   End

Can anyone help me how to debug in such case?

MagePsycho
  • 1,944
  • 2
  • 29
  • 60

1 Answers1

2

There is nothing strange about this.

In regular Chrome session, you're sending some cookies, whereas incognito session starts with none.

The VCL provided uses less than ideal approach of stripping known cookies which are irrelevant for backend (Wordpress).

Why this is quite bad, is because once you add this or that plugin, or even Javascript tracking stuff that you're not really in control of, they might introduce more and more cookies that need to be stripped. In this particular case, I see __zlcmid is being sent by your Chrome, but there is no stripping code for the same in the VCL. There is potentially more, since varnishlog for cookie is trimmed at ; PHPS ...

A better approach is whitelisting cookies, that is to strip all cookies except for Wordpress known ones.

Danila Vershinin
  • 8,725
  • 2
  • 29
  • 35
  • Really appreciate your prompt answer @Daniel. Can you give me some reference template for a better approach of handling cookies? Thanks again. – MagePsycho Feb 21 '19 at 11:46
  • @MagePsycho you can take a look at [this sample VCL](https://github.com/GetPageSpeed/varnish-virtual-hosts/blob/master/sites-enabled/d.example.com.vcl) – Danila Vershinin Feb 21 '19 at 14:42