Why is Varnish not caching https requests in this configuration?

I'm trying to setup varnish with Drupal10 project, but it's always MISS on HTTPS request but HIT on HTTP requests.

I'm using lando, here is my varnish service simple config.

name: d10-api
recipe: drupal10
config:
  webroot: ./web
  config:
    php: '.lando/php.ini'

proxy:
  varnish:
    - varnish-d10.lndo.site

services:
  appserver:
  varnish:
    type: varnish:6.0
    ssl: true
    backends:
      - appserver
    configs:
      - vcl: /app/.lando/varnish/default.vcl

The vcl config used is the one by default come with varnish docker image. here is the configuration i use https://github.com/BERRAMOU/lando-base-varnish-config

Here is varnish log for an HTTPS request which is MISS

*   << Request  >> 360459
-   Begin          req 360452 rxreq
-   Timestamp      Start: 1722803049.990947 0.000000 0.000000
-   Timestamp      Req: 1722803049.990947 0.000000 0.000000
-   ReqStart       172.19.0.2 53104 a0
-   ReqMethod      GET
-   ReqURL         /node/1
-   ReqProtocol    HTTP/1.1
-   ReqHeader      Host: varnish-d10.lndo.site
-   ReqHeader      User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/127.0.0.0 Safari/537.36
-   ReqHeader      Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7
-   ReqHeader      Accept-Encoding: gzip, deflate, br, zstd
-   ReqHeader      Accept-Language: en-GB,en-US;q=0.9,en;q=0.8,fr;q=0.7
-   ReqHeader      Cache-Control: max-age=0
-   ReqHeader      Cookie: iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   ReqHeader      Priority: u=0, i
-   ReqHeader      Sec-Ch-Ua: "Not)A;Brand";v="99", "Google Chrome";v="127", "Chromium";v="127"
-   ReqHeader      Sec-Ch-Ua-Mobile: ?0
-   ReqHeader      Sec-Ch-Ua-Platform: "macOS"
-   ReqHeader      Sec-Fetch-Dest: document
-   ReqHeader      Sec-Fetch-Mode: navigate
-   ReqHeader      Sec-Fetch-Site: none
-   ReqHeader      Sec-Fetch-User: ?1
-   ReqHeader      Upgrade-Insecure-Requests: 1
-   ReqHeader      X-Forwarded-For: 172.19.0.1
-   ReqHeader      X-Forwarded-Host: varnish-d10.lndo.site
-   ReqHeader      X-Forwarded-Port: 443
-   ReqHeader      X-Forwarded-Proto: https
-   ReqHeader      X-Forwarded-Server: 58671badd9ab
-   ReqHeader      X-Lando: on
-   ReqHeader      X-Real-Ip: 172.19.0.1
-   ReqUnset       X-Forwarded-For: 172.19.0.1
-   ReqHeader      X-Forwarded-For: 172.19.0.1, 172.19.0.2
-   VCL_call       RECV
-   ReqHeader      X-VC-My-Purge-Key: bf79VN1ryQ9zhvomLOqoldCWv5w3xvyRJwIaRc2GKtmg4IpVDaA7IDF2X7W824JR
-   ReqUnset       X-VC-My-Purge-Key: bf79VN1ryQ9zhvomLOqoldCWv5w3xvyRJwIaRc2GKtmg4IpVDaA7IDF2X7W824JR
-   ReqHeader      vckey: ;iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   ReqUnset       vckey: ;iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   ReqHeader      vckey: ;iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D;datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjGp
-   ReqUnset       vckey: ;iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D;datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjGp
-   ReqHeader      vckey: ;iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D;datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjGp
-   ReqUnset       vckey: ;iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D;datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjGp
-   ReqHeader      vckey:
-   ReqUnset       vckey:
-   ReqHeader      vckey:
-   ReqUnset       Cookie: iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   ReqHeader      Cookie: iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   ReqUnset       Cookie: iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   ReqHeader      Cookie: iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   VCL_return     pass
-   VCL_call       HASH
-   ReqHeader      hash: /node/1
-   ReqUnset       hash: /node/1
-   ReqHeader      hash: /node/1#varnish-d10.lndo.site
-   ReqUnset       hash: /node/1#varnish-d10.lndo.site
-   ReqHeader      hash: /node/1#varnish-d10.lndo.sitehttps
-   ReqUnset       vckey:
-   VCL_return     lookup
-   VCL_call       PASS
-   VCL_return     fetch
-   Link           bereq 360460 pass
-   Timestamp      Fetch: 1722803050.015579 0.024632 0.024632
-   RespProtocol   HTTP/1.1
-   RespStatus     200
-   RespReason     OK
-   RespHeader     Date: Sun, 04 Aug 2024 20:24:09 GMT
-   RespHeader     Server: Apache/2.4.56 (Debian)
-   RespHeader     X-Powered-By: PHP/8.1.28
-   RespHeader     Cache-Control: max-age=31536000, public
-   RespHeader     X-Drupal-Dynamic-Cache: MISS
-   RespHeader     Content-language: en
-   RespHeader     X-Content-Type-Options: nosniff
-   RespHeader     X-Frame-Options: SAMEORIGIN
-   RespHeader     X-Drupal-Cache-Tags: CACHE_MISS_IF_UNCACHEABLE_HTTP_METHOD:form block_view config:block.block.olivero_account_menu config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_main_m
-   RespHeader     X-Drupal-Cache-Contexts: cookies:big_pipe_nojs languages:language_interface route session.exists theme timezone url.path.is_front url.path.parent url.query_args:_wrapper_format url.site user.permissions user.roles
-   RespHeader     X-Drupal-Cache-Max-Age: -1 (Permanent)
-   RespHeader     Expires: Sun, 19 Nov 1978 05:00:00 GMT
-   RespHeader     Last-Modified: Sun, 04 Aug 2024 20:23:43 GMT
-   RespHeader     ETag: "1722803023-gzip"
-   RespHeader     Vary: Cookie,Accept-Encoding
-   RespHeader     X-Generator: Drupal 10 (https://www.drupal.org)
-   RespHeader     Purge-Cache-Tags: config:block_list config:block.block.olivero_account_menu config:block.block.olivero_search_form_wide config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_p
-   RespHeader     Cache-Tags: config:block_list config:block.block.olivero_account_menu config:block.block.olivero_search_form_wide config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_page_ti
-   RespHeader     X-Drupal-Cache: HIT
-   RespHeader     Content-Encoding: gzip
-   RespHeader     Content-Type: text/html; charset=UTF-8
-   RespHeader     X-VC-Req-Host: varnish-d10.lndo.site
-   RespHeader     X-VC-Req-URL: /node/1
-   RespHeader     X-VC-Req-URL-Base: /node/1
-   RespHeader     X-VC-Cacheable: NO:Not cacheable, ttl: 0.000
-   RespHeader     X-Url: /node/1
-   RespHeader     X-Host: varnish-d10.lndo.site
-   RespHeader     X-Varnish: 360459
-   RespHeader     Age: 0
-   RespHeader     Via: 1.1 varnish (Varnish/6.0)
-   VCL_call       DELIVER
-   RespUnset      X-VC-Req-Host: varnish-d10.lndo.site
-   RespUnset      X-VC-Req-URL: /node/1
-   RespUnset      X-VC-Req-URL-Base: /node/1
-   RespUnset      Via: 1.1 varnish (Varnish/6.0)
-   RespUnset      X-Url: /node/1
-   RespUnset      X-Host: varnish-d10.lndo.site
-   RespUnset      Cache-Tags: config:block_list config:block.block.olivero_account_menu config:block.block.olivero_search_form_wide config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_page_ti
-   RespHeader     X-VC-Cache: MISS
-   RespUnset      X-VC-Cacheable: NO:Not cacheable, ttl: 0.000
-   VCL_return     deliver
-   Timestamp      Process: 1722803050.015603 0.024656 0.000024
-   RespHeader     Accept-Ranges: bytes
-   RespHeader     Transfer-Encoding: chunked
-   RespHeader     Connection: keep-alive
-   Timestamp      Resp: 1722803050.019641 0.028694 0.004038
-   ReqAcct        1210 0 1210 2733 4935 7668
-   End

And here is a log with http request which is HIT

   << Request  >> 393230
-   Begin          req 393228 rxreq
-   Timestamp      Start: 1722681295.423629 0.000000 0.000000
-   Timestamp      Req: 1722681295.423629 0.000000 0.000000
-   ReqStart       172.19.0.2 48756 a0
-   ReqMethod      GET
-   ReqURL         /node/1
-   ReqProtocol    HTTP/1.1
-   ReqHeader      Host: varnish-d10.lndo.site
-   ReqHeader      User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/127.0.0.0 Safari/537.36
-   ReqHeader      Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7
-   ReqHeader      Accept-Encoding: gzip, deflate
-   ReqHeader      Accept-Language: en-GB,en-US;q=0.9,en;q=0.8,fr;q=0.7
-   ReqHeader      Cache-Control: max-age=0
-   ReqHeader      If-Modified-Since: Fri, 02 Aug 2024 15:28:36 GMT
-   ReqHeader      If-None-Match: "1722612516-gzip"
-   ReqHeader      Upgrade-Insecure-Requests: 1
-   ReqHeader      X-Forwarded-For: 172.19.0.1
-   ReqHeader      X-Forwarded-Host: varnish-d10.lndo.site
-   ReqHeader      X-Forwarded-Port: 80
-   ReqHeader      X-Forwarded-Proto: http
-   ReqHeader      X-Forwarded-Server: 58671badd9ab
-   ReqHeader      X-Lando: on
-   ReqHeader      X-Real-Ip: 172.19.0.1
-   ReqUnset       X-Forwarded-For: 172.19.0.1
-   ReqHeader      X-Forwarded-For: 172.19.0.1, 172.19.0.2
-   VCL_call       RECV
-   ReqHeader      X-VC-My-Purge-Key: lb6kUhxJyT1teZgbUm5pbG6MPK174cCUkuS1PLBNJgvN3xq5nMu2tY4AVvqFC0v5
-   ReqUnset       X-VC-My-Purge-Key: lb6kUhxJyT1teZgbUm5pbG6MPK174cCUkuS1PLBNJgvN3xq5nMu2tY4AVvqFC0v5
-   ReqHeader      vckey: ;
-   ReqUnset       vckey: ;
-   ReqHeader      vckey: ;
-   ReqUnset       vckey: ;
-   ReqHeader      vckey: ;
-   ReqUnset       vckey: ;
-   ReqHeader      vckey: ;
-   ReqUnset       vckey: ;
-   ReqHeader      vckey:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   VCL_return     hash
-   ReqUnset       Accept-Encoding: gzip, deflate
-   ReqHeader      Accept-Encoding: gzip
-   VCL_call       HASH
-   ReqHeader      hash: /node/1
-   ReqUnset       hash: /node/1
-   ReqHeader      hash: /node/1#varnish-d10.lndo.site
-   ReqUnset       vckey:
-   VCL_return     lookup
-   Hit            425994 31535918.620684 120.000000 0.000000
-   VCL_call       HIT
-   VCL_return     deliver
-   RespProtocol   HTTP/1.1
-   RespStatus     200
-   RespReason     OK
-   RespHeader     Date: Sat, 03 Aug 2024 10:33:32 GMT
-   RespHeader     Server: Apache/2.4.56 (Debian)
-   RespHeader     X-Powered-By: PHP/8.1.28
-   RespHeader     Cache-Control: max-age=31536000, public
-   RespHeader     X-Drupal-Dynamic-Cache: MISS
-   RespHeader     Content-language: en
-   RespHeader     X-Content-Type-Options: nosniff
-   RespHeader     X-Frame-Options: SAMEORIGIN
-   RespHeader     X-Drupal-Cache-Tags: CACHE_MISS_IF_UNCACHEABLE_HTTP_METHOD:form block_view config:block.block.olivero_account_menu config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_main_m
-   RespHeader     X-Drupal-Cache-Contexts: cookies:big_pipe_nojs languages:language_interface route session.exists theme timezone url.path.is_front url.path.parent url.query_args:_wrapper_format url.site user.permissions user.roles
-   RespHeader     X-Drupal-Cache-Max-Age: -1 (Permanent)
-   RespHeader     Expires: Sun, 19 Nov 1978 05:00:00 GMT
-   RespHeader     Last-Modified: Fri, 02 Aug 2024 15:28:36 GMT
-   RespHeader     ETag: "1722612516-gzip"
-   RespHeader     Vary: Cookie,Accept-Encoding
-   RespHeader     X-Generator: Drupal 10 (https://www.drupal.org)
-   RespHeader     Purge-Cache-Tags: config:block_list config:block.block.olivero_account_menu config:block.block.olivero_search_form_wide config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_p
-   RespHeader     Cache-Tags: config:block_list config:block.block.olivero_account_menu config:block.block.olivero_search_form_wide config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_page_ti
-   RespHeader     X-Drupal-Cache: HIT
-   RespHeader     Content-Encoding: gzip
-   RespHeader     Content-Type: text/html; charset=UTF-8
-   RespHeader     X-VC-Req-Host: varnish-d10.lndo.site
-   RespHeader     X-VC-Req-URL: /node/1
-   RespHeader     X-VC-Req-URL-Base: /node/1
-   RespHeader     X-Url: /node/1
-   RespHeader     X-Host: varnish-d10.lndo.site
-   RespHeader     X-Varnish: 393230 425994
-   RespHeader     Age: 81
-   RespHeader     Via: 1.1 varnish (Varnish/6.0)
-   VCL_call       DELIVER
-   RespUnset      X-VC-Req-Host: varnish-d10.lndo.site
-   RespUnset      X-VC-Req-URL: /node/1
-   RespUnset      X-VC-Req-URL-Base: /node/1
-   RespUnset      Via: 1.1 varnish (Varnish/6.0)
-   RespUnset      X-Url: /node/1
-   RespUnset      X-Host: varnish-d10.lndo.site
-   RespUnset      Cache-Tags: config:block_list config:block.block.olivero_account_menu config:block.block.olivero_search_form_wide config:block.block.olivero_breadcrumbs config:block.block.olivero_content config:block.block.olivero_help config:block.block.olivero_page_ti
-   RespHeader     X-VC-Cache: HIT
-   VCL_return     deliver
-   Timestamp      Process: 1722681295.423819 0.000190 0.000190
-   RespProtocol   HTTP/1.1
-   RespStatus     304
-   RespReason     Not Modified
-   RespHeader     Connection: keep-alive
-   Timestamp      Resp: 1722681295.423894 0.000265 0.000075
-   ReqAcct        742 0 742 2700 0 2700
-   End

Did anyone have this issue with Drupal and varnish ? I have tried to set X-Forwarded-Proto in the vcl_deliver like this

    if (req.http.X-Forwarded-Proto == "https") {
        set resp.http.X-Forwarded-Proto = "https";
    }

I doubt it's a reverse_proxy issue, i have tried reverse_proxy_header to set reverse_proxy_header to X_FORWARDED_PROTO and also i tried to add hitch TLS proxy also but nothing seems to work, any help would be appreciated.

Solution

Based on what I'm seeing in the logs, the following Cookie is triggering a cache bypass:

-   ReqHeader      Cookie: iadvize-6912-vuid=%7B%22vuid%22%3A%22d4a2d9485db84d9f90dfa67bb2fa22350fd39c91bbd54%22%2C%22deviceId%22%3A%22b50aa778-6908-40e9-914f-f6415ae6e473%22%7D; datadome=WHOXlev3TenxhfPKnQ4F_L7hWMnVqjGZ7aYJvMA9qkwVZZ5eZwxoKCHtnTlLRt3xTME4Ep1nhSt~45GoUhsjG
-   VCL_return     pass

If I look at https://github.com/BERRAMOU/lando-base-varnish-config/blob/main/defaults/vcl_recv.vcl#L37, which has the following code:

set req.http.Cookie = regsuball(req.http.Cookie, "(^|;\s*)(__[a-z]+|wooTracker|VCKEY-[a-zA-Z0-9-_]+)=[^;]*", "");
set req.http.Cookie = regsub(req.http.Cookie, "^;\s*", "");
if (req.http.Cookie ~ "^\s*$") {
    unset req.http.Cookie;
}

I can conclude that the following cookies, that are part of your request, are not automatically removed using the VCL regsuball() function:

iadvize-6912-vuid
datadome

So if these cookies are part of the request, Varnish is going to fall back on its default behavior and a cache bypass will take place, as described in the built-in VCL.

What about the cache hit?

If you look at the cache hit transactions, you see the following log items:

-   ReqHeader      Cookie:
-   ReqUnset       Cookie:
-   ReqHeader      Cookie:
-   ReqUnset       Cookie:

This means your VCL code on line 37 & 38 of https://github.com/BERRAMOU/lando-base-varnish-config/blob/main/defaults/vcl_recv.vcl#L37-L38 has tried to remove some tracking cookies, but didn't find any.

In the end, the Cookie header is stripped off, which means the default behavior of bypassing the cache for cookies is not triggered. That's why this request is handled by the cache and the first one isn't.

Next steps?

You need to figure out if the iadvize-6912-vuid & datadome cookies are tracking cookies or not? If they're tracking cookies that are handled by some client-side Javascript logic, you can strip them off by adding their pattern to https://github.com/BERRAMOU/lando-base-varnish-config/blob/main/defaults/vcl_recv.vcl#L37.

If these are server-side cookies, you need to figure out why they are needed on that page and how they are set. Worst case: the page cannot be cached.