Varnish cache always MISS on dynamic pages

Question

Varnish doesn't seem to be working properly for dynamic pages, it always returns a MISS in the response headers whether the request is coming from the browser or the CLI (curl/wget).

curl -IL -X GET 'http://website.com/'

HTTP/1.1 200 OK
Date: 2020年10月04日 10:45:45 GMT
Content-Type: text/html; charset=UTF-8
Vary: Accept-Encoding
Set-Cookie: PHPSESSID=aqhdrf2kemsc2n6uvv0a4m1j51; expires=Sun, 04-Oct-2020 11:45:45 GMT; Max-Age=3600; path=/; domain=website.com; HttpOnly
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Frame-Options: SAMEORIGIN
X-Cache: MISS
Pragma: no-cache
Expires: -1
Cache-Control: no-store, no-cache, must-revalidate, max-age=0
Accept-Ranges: bytes
Content-Length: 23297
Connection: keep-alive

However requests on static assets do hit varnish as expected:

curl -IL -X GET 'http://website.com/static/frontend/Magento/blank/en_US/images/logo.svg'

HTTP/1.1 200 OK
Date: 2020年10月04日 10:36:06 GMT
Content-Type: image/svg+xml
Last-Modified: 2020年10月03日 20:48:21 GMT
Vary: Accept-Encoding
ETag: W/"5f78e395-f43"
Expires: 2021年10月04日 10:36:06 GMT
Cache-Control: max-age=31536000, public
X-Frame-Options: SAMEORIGIN
X-Cache: HIT
X-Cache-Hits: 14
Accept-Ranges: bytes
Content-Length: 3907
Connection: keep-alive

I added the X-Cache and X-Cache-Hits headers to debug in production mode. This is a pretty stock version of Magento with no custom modules and using the blank theme. My default.vcl file is pretty much stock "Varnish 6" settings exported from the backend except for enabling caching static files and the debug response headers I included.

/etc/varnish/default.vcl

# VCL version 5.0 is not supported so it should be 4.0 even though actually used Varnish version is 6
vcl 4.0;
import std;
# The minimal Varnish version is 6.0
# For SSL offloading, pass the following header in your proxy server or load balancer: 'X-Forwarded-Proto: https'
backend default {
 .host = "localhost";
 .port = "8080";
 .first_byte_timeout = 600s;
 .probe = {
 .url = "/health_check.php";
 .timeout = 2s;
 .interval = 5s;
 .window = 10;
 .threshold = 5;
 }
}
acl purge {
 "localhost";
}
sub vcl_recv {
 if (req.method == "PURGE") {
 if (client.ip !~ purge) {
 return (synth(405, "Method not allowed"));
 }
 # To use the X-Pool header for purging varnish during automated deployments, make sure the X-Pool header
 # has been added to the response in your backend server config. This is used, for example, by the
 # capistrano-magento2 gem for purging old content from varnish during it's deploy routine.
 if (!req.http.X-Magento-Tags-Pattern && !req.http.X-Pool) {
 return (synth(400, "X-Magento-Tags-Pattern or X-Pool header required"));
 }
 if (req.http.X-Magento-Tags-Pattern) {
 ban("obj.http.X-Magento-Tags ~ " + req.http.X-Magento-Tags-Pattern);
 }
 if (req.http.X-Pool) {
 ban("obj.http.X-Pool ~ " + req.http.X-Pool);
 }
 return (synth(200, "Purged"));
 }
 if (req.method != "GET" &&
 req.method != "HEAD" &&
 req.method != "PUT" &&
 req.method != "POST" &&
 req.method != "TRACE" &&
 req.method != "OPTIONS" &&
 req.method != "DELETE") {
 /* Non-RFC2616 or CONNECT which is weird. */
 return (pipe);
 }
 # We only deal with GET and HEAD by default
 if (req.method != "GET" && req.method != "HEAD") {
 return (pass);
 }
 # Bypass shopping cart, checkout and search requests
 if (req.url ~ "/checkout" || req.url ~ "/catalogsearch") {
 return (pass);
 }
 # Bypass health check requests
 if (req.url ~ "/pub/health_check.php") {
 return (pass);
 }
 # Set initial grace period usage status
 set req.http.grace = "none";
 # normalize url in case of leading HTTP scheme and domain
 set req.url = regsub(req.url, "^http[s]?://", "");
 # collect all cookies
 std.collect(req.http.Cookie);
 # Compression filter. See https://www.varnish-cache.org/trac/wiki/FAQ/Compression
 if (req.http.Accept-Encoding) {
 if (req.url ~ "\.(jpg|jpeg|png|gif|gz|tgz|bz2|tbz|mp3|ogg|swf|flv)$") {
 # No point in compressing these
 unset req.http.Accept-Encoding;
 } elsif (req.http.Accept-Encoding ~ "gzip") {
 set req.http.Accept-Encoding = "gzip";
 } elsif (req.http.Accept-Encoding ~ "deflate" && req.http.user-agent !~ "MSIE") {
 set req.http.Accept-Encoding = "deflate";
 } else {
 # unknown algorithm
 unset req.http.Accept-Encoding;
 }
 }
 # Remove all marketing get parameters to minimize the cache objects
 if (req.url ~ "(\?|&)(gclid|cx|ie|cof|siteurl|zanpid|origin|fbclid|mc_[a-z]+|utm_[a-z]+|_bta_[a-z]+)=") {
 set req.url = regsuball(req.url, "(gclid|cx|ie|cof|siteurl|zanpid|origin|fbclid|mc_[a-z]+|utm_[a-z]+|_bta_[a-z]+)=[-_A-z0-9+()%.]+&?", "");
 set req.url = regsub(req.url, "[?|&]+$", "");
 }
 # Static files caching
 if (req.url ~ "^/(pub/)?(media|static)/") {
 # Static files should not be cached by default
 #return (pass);
 # But if you use a few locales and don't use CDN you can enable caching static files by commenting previous line (#return (pass);) and uncommenting next 3 lines
 unset req.http.Https;
 unset req.http.X-Forwarded-Proto;
 unset req.http.Cookie;
 }
 return (hash);
}
sub vcl_hash {
 if (req.http.cookie ~ "X-Magento-Vary=") {
 hash_data(regsub(req.http.cookie, "^.*?X-Magento-Vary=([^;]+);*.*$", "1円"));
 }
 # For multi site configurations to not cache each other's content
 if (req.http.host) {
 hash_data(req.http.host);
 } else {
 hash_data(server.ip);
 }
 # To make sure http users don't see ssl warning
 if (req.http.X-Forwarded-Proto) {
 hash_data(req.http.X-Forwarded-Proto);
 }
 if (req.url ~ "/graphql") {
 call process_graphql_headers;
 }
}
sub process_graphql_headers {
 if (req.http.Store) {
 hash_data(req.http.Store);
 }
 if (req.http.Content-Currency) {
 hash_data(req.http.Content-Currency);
 }
}
sub vcl_backend_response {
 set beresp.grace = 3d;
 if (beresp.http.content-type ~ "text") {
 set beresp.do_esi = true;
 }
 if (bereq.url ~ "\.js$" || beresp.http.content-type ~ "text") {
 set beresp.do_gzip = true;
 }
 if (beresp.http.X-Magento-Debug) {
 set beresp.http.X-Magento-Cache-Control = beresp.http.Cache-Control;
 }
 # cache only successfully responses and 404s
 if (beresp.status != 200 && beresp.status != 404) {
 set beresp.ttl = 0s;
 set beresp.uncacheable = true;
 return (deliver);
 } elsif (beresp.http.Cache-Control ~ "private") {
 set beresp.uncacheable = true;
 set beresp.ttl = 86400s;
 return (deliver);
 }
 # validate if we need to cache it and prevent from setting cookie
 if (beresp.ttl > 0s && (bereq.method == "GET" || bereq.method == "HEAD")) {
 unset beresp.http.set-cookie;
 }
 # If page is not cacheable then bypass varnish for 2 minutes as Hit-For-Pass
 if (beresp.ttl <= 0s ||
 beresp.http.Surrogate-control ~ "no-store" ||
 (!beresp.http.Surrogate-Control &&
 beresp.http.Cache-Control ~ "no-cache|no-store") ||
 beresp.http.Vary == "*") {
 # Mark as Hit-For-Pass for the next 2 minutes
 set beresp.ttl = 120s;
 set beresp.uncacheable = true;
 }
 return (deliver);
}
sub vcl_deliver {
 if (resp.http.X-Magento-Debug) {
 if (resp.http.x-varnish ~ " ") {
 set resp.http.X-Magento-Cache-Debug = "HIT";
 set resp.http.Grace = req.http.grace;
 } else {
 set resp.http.X-Magento-Cache-Debug = "MISS";
 }
 } else {
 unset resp.http.Age;
 }
 if (obj.hits > 0) {
 set resp.http.X-Cache = "HIT";
 set resp.http.X-Cache-Hits = obj.hits;
 }
 else {
 set resp.http.X-Cache = "MISS";
 }
 # Not letting browser to cache non-static files.
 if (resp.http.Cache-Control !~ "private" && req.url !~ "^/(pub/)?(media|static)/") {
 set resp.http.Pragma = "no-cache";
 set resp.http.Expires = "-1";
 set resp.http.Cache-Control = "no-store, no-cache, must-revalidate, max-age=0";
 }
 unset resp.http.X-Magento-Debug;
 unset resp.http.X-Magento-Tags;
 unset resp.http.X-Powered-By;
 unset resp.http.Server;
 unset resp.http.X-Varnish;
 unset resp.http.Via;
 unset resp.http.Link;
}
sub vcl_hit {
 if (obj.ttl >= 0s) {
 # Hit within TTL period
 return (deliver);
 }
 if (std.healthy(req.backend_hint)) {
 if (obj.ttl + 300s > 0s) {
 # Hit after TTL expiration, but within grace period
 set req.http.grace = "normal (healthy server)";
 return (deliver);
 } else {
 # Hit after TTL and grace expiration
 return (restart);
 }
 } else {
 # server is not healthy, retrieve from cache
 set req.http.grace = "unlimited (unhealthy server)";
 return (deliver);
 }
}

Also my config settings in the backend:

Full Page Cache

Caching Application: Varnish Cache (Recommended)
TTL for public content: 86400
Access list: localhost
Backend host: localhost
Backend port: 8080
Grace period: 300

I checked the whole response XML and there's no cacheable="false" being set, I found odd that the Cache-Control header is set to no-cache but that seems to be the behaviour the VCL file sets for non-static files by default.

Any advice on what to do?

EDIT

Here's the response headers without Varnish:

HTTP/1.1 200 OK
Server: nginx
Date: 2020年10月04日 14:45:45 GMT
Content-Type: text/html; charset=UTF-8
Transfer-Encoding: chunked
Connection: keep-alive
Vary: Accept-Encoding
Set-Cookie: PHPSESSID=6km5ae28tvc6d2sh4j0bm6pkhm; expires=Sun, 04-Oct-2020 15:45:45 GMT; Max-Age=3600; path=/; domain=website.com; HttpOnly
Pragma: cache
Cache-Control: max-age=0
Expires: 2020年10月04日 14:45:45 GMT
X-Magento-Tags: store,cms_b,BLOCK_HTML,cms_p_2
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Frame-Options: SAMEORIGIN

• Danila Vershinin: And what are the actual app headers? Obtain with curl -IL -X GET 'http://localhost.com:8080/ -H "Host: example.com" -H "X-Forwarded-Proto: https"
• Media Lounge: Thanks, I just updated the question with the response headers.
• Danila Vershinin: The problematic response data is Expires: 2020年10月04日 14:45:45 GMT; this actually sets beresp.ttl = 0 in Varnish (cache lifetime is none). What are the settings you have in Magento admin for cache TTL? set it to e.g. 2 weeks, and re-check. Also you could by mistake set improper expires in NGINX config.
• Media Lounge: Thanks your comment pointed me in the right direction, turns out I had some Open FD Cache settings in my nginx.conf file that were not playing nice with Varnish, removing them fixed the issue.

Answer 1

My initial advice when it comes to check if varnish is in the way is to verify whether the same issue appears with FPC.

in other words, switch off Varnish. Add log in

\Magento\PageCache\Model\App\FrontController\BuiltinPlugin::aroundDispatch

below the line: $result = $this->kernel->load();

or in:

\Magento\Framework\App\PageCache\Kernel::load

below the line: $responseData = $this->fullPageCache->load($this->identifier->getValue());

and then, you may have 2 different outcomes:

1. the issue is also happening with FPC. Then, just troubleshoot this on dev environment: common issues are a php, js console error prevents the cache to be created.
2. it does not happen with FPC, then revert to basic vcl.

• Media Lounge: Hey Herve! Long time no see, I can confirm FPC works as expected without Varnish on but reverting to the basic VCL didn't help 😢
• Herve Tribouilloy: thanks for the update. Interesting question either way. Good to check the basis first. Now, of course we have to dig deeper in the beast. I have not worked with varnish in a while but will do some research.. we might need bounty power to boost this though :-)
• Media Lounge: Thanks, question will be available for bounty in 2 days but definitely will add by then if I haven't figured it out.