We are using Symfony (Sulu) with Varnish as reverse proxy, with tag based invalidation (xkey) which works as expected. Now we want to use ESI for dynamic blocks on our website, separate from the "main" cache lifetime.
But each time the webpage is cached in full, even after hard refresh/clear browser cache or using new browser, the page is always displaying the first cache entry.
Using a Docker setup with PHP(port: 9000), NGINX (port: 8000) and Varnish (port: 8081)
We have enabled ESI in Symfony:
framework:
...
esi: true
fragments: { path: /_fragment }
And provide render_esi in our Twig templates:
navbar.html.twig
...
{{ render_esi(controller('App\\Controller\\Website\\LoginButtonController::renderEsiLoginButton')) }}
<div class="navbar-main__toggler"></div>
</div>
LoginButtonController
class LoginButtonController extends AbstractController
{
public function renderEsiLoginButton(): Response
{
$response = $this->render('esi/_login_button.html.twig', ['random_nr' => rand()]);
$response->setMaxAge(10);
$response->setSharedMaxAge(10);
$response->setPublic();
return $response;
}
}
_login_button.html.twig
<div class="navbar-main__action-account">
<div class="account__dropdown">
<a href="#" class="account__user">{{ random_nr }}</a>
...
</div>
</div>
And our Varnish default.vcl:
# /etc/varnish/default.vcl
vcl 4.0;
include "/etc/varnish/sulu.vcl";
include "/etc/varnish/fos_user_context.vcl";
include "/etc/varnish/fos_user_context_url.vcl";
include "/etc/varnish/fos_tags_xkey.vcl";
acl invalidators {
"localhost";
"$VARNISH_INVALIDATOR_HOST";
}
backend default {
.host = "$VARNISH_BACKEND_HOST";
.port = "$VARNISH_BACKEND_PORT";
}
sub vcl_recv {
call fos_tags_xkey_recv;
call fos_user_context_recv;
call sulu_recv;
// # Add a Surrogate-Capability header to announce ESI
set req.http.Surrogate-Capability = "abc=ESI/1.0";
# Remove all cookies except the session ID (SULUSESSID)
# Check configured session ID name in your config/packages/framework.yaml
if (req.http.Cookie) {
set req.http.Cookie = ";" + req.http.Cookie;
set req.http.Cookie = regsuball(req.http.Cookie, "; +", ";");
set req.http.Cookie = regsuball(req.http.Cookie, ";(SULUSESSID)=", "; \1=");
set req.http.Cookie = regsuball(req.http.Cookie, ";[^ ][^;]*", "");
set req.http.Cookie = regsuball(req.http.Cookie, "^[; ]+|[; ]+$", "");
if (req.http.Cookie == "") {
# If there are no more cookies, remove the header to get page cached.
unset req.http.Cookie;
}
}
# No cache besides GET and HEAD
if (req.method != "GET" && req.method != "HEAD") {
return (pass);
}
# if Authorization or no-cache header we skip the cache
if (req.http.Authorization || req.http.Cache-Control ~ "no-cache") {
return (pass);
}
# Force the lookup, the backend must tell not to cache or vary on all
# headers that are used to build the hash.
return (hash);
}
sub vcl_hash {
call fos_user_context_hash;
}
sub vcl_backend_response {
set beresp.grace = 2m;
call fos_user_context_backend_response;
call sulu_backend_response;
// Check for ESI acknowledgement and remove Surrogate-Control header
if (beresp.http.Surrogate-Control ~ "ESI/1.0") {
unset beresp.http.Surrogate-Control;
set beresp.do_esi = true;
}
}
sub vcl_deliver {
call fos_tags_xkey_deliver;
call fos_user_context_deliver;
call sulu_deliver;
# Include debugging info
set resp.http.Obj-Hits = obj.hits;
set resp.http.Seen-Cookie = req.http.Cookie;
# set resp.http.Vary = "X-User-Context-Hash";
}
Our fos_http_cache config:
fos_http_cache:
tags:
enabled: true
response_header: xkey
max_header_value_length: 1024
proxy_client:
symfony:
use_kernel_dispatcher: true
user_context:
enabled: true
role_provider: true
# user_hash_header: 'X-User-Context-Hash'
hash_cache_ttl: 900
and sulu http cache:
when@prod: &prod
sulu_http_cache:
debug:
enabled: false
tags:
enabled: true
cache:
max_age: 240
shared_max_age: 480
proxy_client:
symfony:
enabled: false
varnish:
enabled: true
servers: [ '%env(VARNISH_SERVER)%' ]
tag_mode: purgekeys
When using curl, we also see the esi:include tags correctly
curl -i -X GET 'http://localhost:8000/en' -H 'Surrogate-Capability: ESI/1.0:
<span class="navbar-main__action-search-button"></span>
<esi:include src="/_fragment?_hash=HAz3Ym5wXab4GXTRKnq8oUR3WwnGqUpprL0niBc%2BEwg%3D&_path=_format%3Dhtml%26_locale%3Den%26_controller%3DApp%255CController%255CWebsite%255CLoginButtonController%253A%253ArenderEsiLoginButton" onerror="continue" />
<div class="navbar-main__toggler"></div>
But the webpage is still cached in full, even after hard refresh/clear browser cache or using new browser, the page is always displaying the first random number. Until we clear the Varnish cache in full.
What are we missing?
Update 1: as requested the output of varnishlog:
$ varnishlog -g request -q "ReqUrl eq '/en'"
* << Request >> 65566
- Begin req 65565 rxreq
- Timestamp Start: 1700910701.474503 0.000000 0.000000
- Timestamp Req: 1700910701.474503 0.000000 0.000000
- VCL_use boot
- ReqStart 192.168.207.1 60914 a0
- ReqMethod GET
- ReqURL /en
- ReqProtocol HTTP/1.1
- ReqHeader Host: localhost:8081
- ReqHeader Connection: keep-alive
- ReqHeader sec-ch-ua: "Not A(Brand";v="99", "Google Chrome";v="121", "Chromium";v="121"
- ReqHeader sec-ch-ua-mobile: ?0
- ReqHeader sec-ch-ua-platform: "macOS"
- ReqHeader Upgrade-Insecure-Requests: 1
- ReqHeader User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.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 Sec-Fetch-Site: none
- ReqHeader Sec-Fetch-Mode: navigate
- ReqHeader Sec-Fetch-User: ?1
- ReqHeader Sec-Fetch-Dest: document
- ReqHeader Accept-Encoding: gzip, deflate, br, zstd
- ReqHeader Accept-Language: en-GB,en-US;q=0.9,en;q=0.8
- ReqHeader X-Forwarded-For: 192.168.207.1
- VCL_call RECV
- ReqHeader X-Fos-Original-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
- ReqUnset 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: application/vnd.fos.user-context-hash
- ReqHeader X-Fos-Original-Url: /en
- ReqURL /_fos_user_context_hash
- VCL_return hash
- ReqUnset Accept-Encoding: gzip, deflate, br, zstd
- ReqHeader Accept-Encoding: gzip
- VCL_call HASH
- VCL_return lookup
- ExpBan 393224 banned lookup
- VCL_call MISS
- VCL_return fetch
- Link bereq 65567 fetch
- Timestamp Fetch: 1700910703.172124 1.697620 1.697620
- RespProtocol HTTP/1.1
- RespStatus 200
- RespReason OK
- RespHeader Server: nginx
- RespHeader Content-Type: application/vnd.fos.user-context-hash
- RespHeader X-Powered-By: PHP/8.2.5
- RespHeader X-User-Context-Hash: 5224d8f5b85429624e2160e538a3376a479ec87b89251b295c44ecbf7498ea3c
- RespHeader Cache-Control: max-age=900, public
- RespHeader Date: Sat, 25 Nov 2023 11:11:43 GMT
- RespHeader Vary: cookie, authorization
- RespHeader xkey: fos_http_cache_hashlookup- webspace-amfori
- RespHeader X-Generator: Sulu/2.5.10
- RespHeader x-url: /_fos_user_context_hash
- RespHeader x-host: localhost:8081
- RespHeader X-Varnish: 65566
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish (Varnish/6.5)
- VCL_call DELIVER
- RespUnset xkey: fos_http_cache_hashlookup- webspace-amfori
- ReqHeader X-User-Context-Hash: 5224d8f5b85429624e2160e538a3376a479ec87b89251b295c44ecbf7498ea3c
- VCL_return restart
- Timestamp Process: 1700910703.172133 1.697630 0.000009
- Timestamp Restart: 1700910703.172134 1.697631 0.000000
- Link req 65568 restart
- End
...
Update 2: modified VCL moving Surrogate-Capability to the top:
sub vcl_recv {
// # Add a Surrogate-Capability header to announce ESI
set req.http.Surrogate-Capability = "abc=ESI/1.0";
call fos_tags_xkey_recv;
call fos_user_context_recv;
call sulu_recv;
...
Results in working ESI _fragment calls in Varnish varnishlog:
$ varnishlog -g request -q "ReqUrl eq '/en'"
* << Request >> 295260
- Begin req 295259 rxreq
- Timestamp Start: 1701104453.954200 0.000000 0.000000
- Timestamp Req: 1701104453.954200 0.000000 0.000000
- VCL_use boot
- ReqStart 192.168.207.1 45193 a0
- ReqMethod GET
- ReqURL /en
- ReqProtocol HTTP/1.1
- ReqHeader Host: localhost:8081
- ReqHeader User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0
- ReqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
- ReqHeader Accept-Language: en-US,en;q=0.5
- ReqHeader Accept-Encoding: gzip, deflate, br
- ReqHeader Connection: keep-alive
- ReqHeader Cookie: trusted_device=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3MDA4MzEwNzYuMjIxNzQ1LCJleHAiOjE3MDYwMTUwNzYuMjE5NDQ2LCJ1c3IiOiJzYW5kZXIuaG9mbWFuQGljYXBwcy5jb20iLCJmd2wiOiJhZG1pbiIsInZzbiI6MH0.haaj4WNSp4inor3rWD1FlUm52qXwmWEJ3mkmgTEtX4Q; userTimez
- ReqHeader Upgrade-Insecure-Requests: 1
- ReqHeader Sec-Fetch-Dest: document
- ReqHeader Sec-Fetch-Mode: navigate
- ReqHeader Sec-Fetch-Site: none
- ReqHeader Sec-Fetch-User: ?1
- ReqHeader Pragma: no-cache
- ReqHeader Cache-Control: no-cache
- ReqHeader X-Forwarded-For: 192.168.207.1
- VCL_call RECV
- ReqHeader Surrogate-Capability: abc=ESI/1.0
- ReqHeader X-Fos-Original-Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
- ReqUnset Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
- ReqHeader accept: application/vnd.fos.user-context-hash
- ReqHeader X-Fos-Original-Url: /en
- ReqURL /_fos_user_context_hash
- VCL_return hash
- ReqUnset Accept-Encoding: gzip, deflate, br
- ReqHeader Accept-Encoding: gzip
- VCL_call HASH
- VCL_return lookup
- ExpBan 32789 banned lookup
- VCL_call MISS
- VCL_return fetch
- Link bereq 295261 fetch
- Timestamp Fetch: 1701104455.867260 1.913060 1.913060
- RespProtocol HTTP/1.1
- RespStatus 200
- RespReason OK
- RespHeader Server: nginx
- RespHeader Content-Type: application/vnd.fos.user-context-hash
- RespHeader X-Powered-By: PHP/8.2.5
- RespHeader X-User-Context-Hash: 5224d8f5b85429624e2160e538a3376a479ec87b89251b295c44ecbf7498ea3c
- RespHeader Cache-Control: max-age=900, public
- RespHeader Date: Mon, 27 Nov 2023 17:00:55 GMT
- RespHeader Vary: cookie, authorization
- RespHeader xkey: fos_http_cache_hashlookup- webspace-amfori
- RespHeader X-Generator: Sulu/2.5.10
- RespHeader x-url: /_fos_user_context_hash
- RespHeader x-host: localhost:8081
- RespHeader X-Varnish: 295260
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish (Varnish/6.5)
- VCL_call DELIVER
- RespUnset xkey: fos_http_cache_hashlookup- webspace-amfori
- ReqHeader X-User-Context-Hash: 5224d8f5b85429624e2160e538a3376a479ec87b89251b295c44ecbf7498ea3c
- VCL_return restart
- Timestamp Process: 1701104455.867277 1.913076 0.000016
- Timestamp Restart: 1701104455.867278 1.913077 0.000000
- Link req 295262 restart
- End
** << BeReq >> 295261
-- Begin bereq 295260 fetch
-- VCL_use boot
-- Timestamp Start: 1701104453.954671 0.000000 0.000000
-- BereqMethod GET
-- BereqURL /_fos_user_context_hash
-- BereqProtocol HTTP/1.1
-- BereqHeader Host: localhost:8081
-- BereqHeader User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0
-- BereqHeader Accept-Language: en-US,en;q=0.5
-- BereqHeader Cookie: trusted_device=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3MDA4MzEwNzYuMjIxNzQ1LCJleHAiOjE3MDYwMTUwNzYuMjE5NDQ2LCJ1c3IiOiJzYW5kZXIuaG9mbWFuQGljYXBwcy5jb20iLCJmd2wiOiJhZG1pbiIsInZzbiI6MH0.haaj4WNSp4inor3rWD1FlUm52qXwmWEJ3mkmgTEtX4Q; userTimez
-- BereqHeader Upgrade-Insecure-Requests: 1
-- BereqHeader Sec-Fetch-Dest: document
-- BereqHeader Sec-Fetch-Mode: navigate
-- BereqHeader Sec-Fetch-Site: none
-- BereqHeader Sec-Fetch-User: ?1
-- BereqHeader Pragma: no-cache
-- BereqHeader X-Forwarded-For: 192.168.207.1
-- BereqHeader Surrogate-Capability: abc=ESI/1.0
-- BereqHeader X-Fos-Original-Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
-- BereqHeader accept: application/vnd.fos.user-context-hash
-- BereqHeader X-Fos-Original-Url: /en
-- BereqHeader Accept-Encoding: gzip
-- BereqHeader X-Varnish: 295261
-- VCL_call BACKEND_FETCH
-- VCL_return fetch
-- BackendOpen 25 default 192.168.207.8 8000 192.168.207.10 37256 connect
-- Timestamp Bereq: 1701104453.955471 0.000800 0.000800
-- Timestamp Beresp: 1701104455.866936 1.912265 1.911465
-- BerespProtocol HTTP/1.1
-- BerespStatus 200
-- BerespReason OK
-- BerespHeader Server: nginx
-- BerespHeader Content-Type: application/vnd.fos.user-context-hash
-- BerespHeader Transfer-Encoding: chunked
-- BerespHeader Connection: keep-alive
-- BerespHeader X-Powered-By: PHP/8.2.5
-- BerespHeader X-User-Context-Hash: 5224d8f5b85429624e2160e538a3376a479ec87b89251b295c44ecbf7498ea3c
-- BerespHeader Cache-Control: max-age=900, public
-- BerespHeader Date: Mon, 27 Nov 2023 17:00:55 GMT
-- BerespHeader Vary: cookie
-- BerespHeader Vary: authorization
-- BerespHeader xkey: fos_http_cache_hashlookup- webspace-amfori
-- BerespHeader X-Generator: Sulu/2.5.10
-- TTL RFC 900 10 0 1701104456 1701104456 1701104455 0 900 cacheable
-- VCL_call BACKEND_RESPONSE
-- TTL VCL 900 120 0 1701104456 cacheable
-- BerespHeader x-url: /_fos_user_context_hash
-- BerespHeader x-host: localhost:8081
-- VCL_return deliver
-- Filters esi
-- Storage malloc s0
-- Fetch_Body 2 chunked -
-- BackendClose 25 default recycle
-- Timestamp BerespBody: 1701104455.867224 1.912553 0.000287
-- Length 0
-- BereqAcct 901 0 901 435 0 435
-- End
* << Request >> 295262
- Begin req 295260 restart
- Timestamp Start: 1701104455.867278 1.913077 0.000000
- ReqStart 192.168.207.1 45193 a0
- ReqMethod GET
- ReqURL /_fos_user_context_hash
- ReqProtocol HTTP/1.1
- ReqHeader Host: localhost:8081
- ReqHeader User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0
- ReqHeader Accept-Language: en-US,en;q=0.5
- ReqHeader Connection: keep-alive
- ReqHeader Cookie: trusted_device=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3MDA4MzEwNzYuMjIxNzQ1LCJleHAiOjE3MDYwMTUwNzYuMjE5NDQ2LCJ1c3IiOiJzYW5kZXIuaG9mbWFuQGljYXBwcy5jb20iLCJmd2wiOiJhZG1pbiIsInZzbiI6MH0.haaj4WNSp4inor3rWD1FlUm52qXwmWEJ3mkmgTEtX4Q; userTimez
- ReqHeader Upgrade-Insecure-Requests: 1
- ReqHeader Sec-Fetch-Dest: document
- ReqHeader Sec-Fetch-Mode: navigate
- ReqHeader Sec-Fetch-Site: none
- ReqHeader Sec-Fetch-User: ?1
- ReqHeader Pragma: no-cache
- ReqHeader Cache-Control: no-cache
- ReqHeader X-Forwarded-For: 192.168.207.1
- ReqHeader Surrogate-Capability: abc=ESI/1.0
- ReqHeader X-Fos-Original-Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
- ReqHeader accept: application/vnd.fos.user-context-hash
- ReqHeader X-Fos-Original-Url: /en
- ReqHeader Accept-Encoding: gzip
- ReqHeader X-User-Context-Hash: 5224d8f5b85429624e2160e538a3376a479ec87b89251b295c44ecbf7498ea3c
- VCL_call RECV
- ReqUnset Surrogate-Capability: abc=ESI/1.0
- ReqHeader Surrogate-Capability: abc=ESI/1.0
- ReqURL /en
- ReqUnset X-Fos-Original-Url: /en
- ReqUnset accept: application/vnd.fos.user-context-hash
- ReqHeader accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
- ReqUnset X-Fos-Original-Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- ExpBan 32783 banned lookup
- VCL_call MISS
- VCL_return fetch
- Link bereq 295263 fetch
- Timestamp Fetch: 1701104456.583858 2.629658 0.716580
- RespProtocol HTTP/1.1
- RespStatus 200
- RespReason OK
- RespHeader Server: nginx
- RespHeader Content-Type: text/html; charset=UTF-8
- RespHeader X-Powered-By: PHP/8.2.5
- RespHeader Cache-Control: max-age=240, public, s-maxage=480
- RespHeader Date: Mon, 27 Nov 2023 17:00:56 GMT
- RespHeader Link: </build/website/runtime.67e3af91.js>; rel="preload"; as="script",</build/website/main.c77e8851.js>; rel="preload"; as="script",</build/website/app.56c210d4.css>; rel="preload"; as="style"
- RespHeader xkey: account-1 media-9750 media-9268 media-9269 media-9270 media-9586 media-9585 media-9276 media-9582 media-9583 media-9274 media-9610 media-9658 category-2 category-4 category-5 category-6 category-7 a280a8cf-ef54-41af-a576-e2ee364cde7c f76cf5c1-0dd5-
- RespHeader X-Generator: Sulu/2.5.10
- RespHeader x-url: /en
- RespHeader x-host: localhost:8081
- RespHeader Content-Encoding: gzip
- RespHeader Vary: X-User-Context-Hash, Accept-Encoding
- RespHeader X-Varnish: 295262
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish (Varnish/6.5)
- VCL_call DELIVER
- RespUnset xkey: account-1 media-9750 media-9268 media-9269 media-9270 media-9586 media-9585 media-9276 media-9582 media-9583 media-9274 media-9610 media-9658 category-2 category-4 category-5 category-6 category-7 a280a8cf-ef54-41af-a576-e2ee364cde7c f76cf5c1-0dd5-
- RespUnset Vary: X-User-Context-Hash, Accept-Encoding
- RespHeader Vary: , Accept-Encoding
- RespUnset Vary: , Accept-Encoding
- RespHeader Vary: Accept-Encoding
- RespUnset x-url: /en
- RespUnset x-host: localhost:8081
- RespHeader Obj-Hits: 0
- RespHeader Seen-Cookie: trusted_device=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3MDA4MzEwNzYuMjIxNzQ1LCJleHAiOjE3MDYwMTUwNzYuMjE5NDQ2LCJ1c3IiOiJzYW5kZXIuaG9mbWFuQGljYXBwcy5jb20iLCJmd2wiOiJhZG1pbiIsInZzbiI6MH0.haaj4WNSp4inor3rWD1FlUm52qXwmWEJ3mkmgTEtX4Q; user
- VCL_return deliver
- Timestamp Process: 1701104456.583879 2.629679 0.000020
- Filters esi
- RespHeader Accept-Ranges: bytes
- RespHeader Connection: keep-alive
- RespHeader Transfer-Encoding: chunked
- Link req 295264 esi
- Timestamp Resp: 1701104456.805554 2.851354 0.221675
- ReqAcct 770 0 770 880 3654 4534
- End
** << BeReq >> 295263
-- Begin bereq 295262 fetch
-- VCL_use boot
-- Timestamp Start: 1701104455.867403 0.000000 0.000000
-- BereqMethod GET
-- BereqURL /en
-- BereqProtocol HTTP/1.1
-- BereqHeader Host: localhost:8081
-- BereqHeader User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0
-- BereqHeader Accept-Language: en-US,en;q=0.5
-- BereqHeader Cookie: trusted_device=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3MDA4MzEwNzYuMjIxNzQ1LCJleHAiOjE3MDYwMTUwNzYuMjE5NDQ2LCJ1c3IiOiJzYW5kZXIuaG9mbWFuQGljYXBwcy5jb20iLCJmd2wiOiJhZG1pbiIsInZzbiI6MH0.haaj4WNSp4inor3rWD1FlUm52qXwmWEJ3mkmgTEtX4Q; userTimez
-- BereqHeader Upgrade-Insecure-Requests: 1
-- BereqHeader Sec-Fetch-Dest: document
-- BereqHeader Sec-Fetch-Mode: navigate
-- BereqHeader Sec-Fetch-Site: none
-- BereqHeader Sec-Fetch-User: ?1
-- BereqHeader Pragma: no-cache
-- BereqHeader X-Forwarded-For: 192.168.207.1
-- BereqHeader Accept-Encoding: gzip
-- BereqHeader X-User-Context-Hash: 5224d8f5b85429624e2160e538a3376a479ec87b89251b295c44ecbf7498ea3c
-- BereqHeader Surrogate-Capability: abc=ESI/1.0
-- BereqHeader accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
-- BereqHeader X-Varnish: 295263
-- VCL_call BACKEND_FETCH
-- VCL_return fetch
-- BackendOpen 25 default 192.168.207.8 8000 192.168.207.10 37256 reuse
-- Timestamp Bereq: 1701104455.867506 0.000103 0.000103
-- Timestamp Beresp: 1701104456.582952 0.715549 0.715446
-- BerespProtocol HTTP/1.1
-- BerespStatus 200
-- BerespReason OK
-- BerespHeader Server: nginx
-- BerespHeader Content-Type: text/html; charset=UTF-8
-- BerespHeader Transfer-Encoding: chunked
-- BerespHeader Connection: keep-alive
-- BerespHeader X-Powered-By: PHP/8.2.5
-- BerespHeader Cache-Control: max-age=240, public, s-maxage=480
-- BerespHeader Date: Mon, 27 Nov 2023 17:00:56 GMT
-- BerespHeader X-Reverse-Proxy-TTL: 86400
-- BerespHeader Surrogate-Control: content="ESI/1.0"
-- BerespHeader Link: </build/website/runtime.67e3af91.js>; rel="preload"; as="script",</build/website/main.c77e8851.js>; rel="preload"; as="script",</build/website/app.56c210d4.css>; rel="preload"; as="style"
-- BerespHeader xkey: account-1 media-9750 media-9268 media-9269 media-9270 media-9586 media-9585 media-9276 media-9582 media-9583 media-9274 media-9610 media-9658 category-2 category-4 category-5 category-6 category-7 a280a8cf-ef54-41af-a576-e2ee364cde7c f76cf5c1-0dd5-
-- BerespHeader Vary: X-User-Context-Hash
-- BerespHeader X-Generator: Sulu/2.5.10
-- BerespHeader Content-Encoding: gzip
-- TTL RFC 480 10 0 1701104457 1701104457 1701104456 0 480 cacheable
-- VCL_call BACKEND_RESPONSE
-- TTL VCL 480 120 0 1701104457 cacheable
-- BerespHeader x-url: /en
-- BerespHeader x-host: localhost:8081
-- TTL VCL 86400 120 0 1701104457 cacheable
-- BerespUnset X-Reverse-Proxy-TTL: 86400
-- BerespUnset Surrogate-Control: content="ESI/1.0"
-- VCL_return deliver
-- Filters gunzip esi_gzip
-- BerespUnset Content-Encoding: gzip
-- BerespHeader Content-Encoding: gzip
-- BerespUnset Vary: X-User-Context-Hash
-- BerespHeader Vary: X-User-Context-Hash, Accept-Encoding
-- Storage malloc s0
-- Fetch_Body 2 chunked -
-- Gzip G F E 19864 3649 80 29112 29122
-- Gzip U F - 3997 19864 80 80 31905
-- BackendClose 25 default recycle
-- Timestamp BerespBody: 1701104456.583813 0.716410 0.000860
-- Length 3649
-- BereqAcct 881 0 881 1087 0 1087
-- End
** << Request >> 295264
-- Begin req 295262 esi
-- Timestamp Start: 1701104456.583969 0.000000 0.000000
-- ReqURL /_fragment?_hash=8bu9984nZ8dzK0ti7IeJWjYw%2BVIgXHNOzgK9K%2FxsZak%3D&_path=absolute_uri%3D0%26_format%3Dhtml%26_locale%3Den%26_controller%3DApp%255CController%255CWebsite%255CLoginButtonController%253A%253ArenderEsiLoginButton
-- ReqUnset Accept-Encoding: gzip, deflate, br
-- ReqHeader Accept-Encoding: gzip
-- ReqStart 192.168.207.1 45193 a0
-- ReqMethod GET
-- ReqURL /_fragment?_hash=8bu9984nZ8dzK0ti7IeJWjYw%2BVIgXHNOzgK9K%2FxsZak%3D&_path=absolute_uri%3D0%26_format%3Dhtml%26_locale%3Den%26_controller%3DApp%255CController%255CWebsite%255CLoginButtonController%253A%253ArenderEsiLoginButton
-- ReqProtocol HTTP/1.1
-- ReqHeader Host: localhost:8081
-- ReqHeader User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:121.0) Gecko/20100101 Firefox/121.0
-- ReqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
-- ReqHeader Accept-Language: en-US,en;q=0.5
-- ReqHeader Connection: keep-alive
-- ReqHeader Cookie: trusted_device=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJpYXQiOjE3MDA4MzEwNzYuMjIxNzQ1LCJleHAiOjE3MDYwMTUwNzYuMjE5NDQ2LCJ1c3IiOiJzYW5kZXIuaG9mbWFuQGljYXBwcy5jb20iLCJmd2wiOiJhZG1pbiIsInZzbiI6MH0.haaj4WNSp4inor3rWD1FlUm52qXwmWEJ3mkmgTEtX4Q; userTimez
-- ReqHeader Upgrade-Insecure-Requests: 1
-- ReqHeader Sec-Fetch-Dest: document
-- ReqHeader Sec-Fetch-Mode: navigate
-- ReqHeader Sec-Fetch-Site: none
-- ReqHeader Sec-Fetch-User: ?1
-- ReqHeader Pragma: no-cache
-- ReqHeader Cache-Control: no-cache
-- ReqHeader Accept-Encoding: gzip
-- ReqHeader X-Forwarded-For: 192.168.207.1
-- VCL_call RECV
-- ReqHeader Surrogate-Capability: abc=ESI/1.0
-- ReqHeader X-Fos-Original-Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
-- ReqUnset Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
-- ReqHeader accept: application/vnd.fos.user-context-hash
-- ReqHeader X-Fos-Original-Url: /_fragment?_hash=8bu9984nZ8dzK0ti7IeJWjYw%2BVIgXHNOzgK9K%2FxsZak%3D&_path=absolute_uri%3D0%26_format%3Dhtml%26_locale%3Den%26_controller%3DApp%255CController%255CWebsite%255CLoginButtonController%253A%253ArenderEsiLoginButton
-- ReqURL /_fos_user_context_hash
...
By the looks of it, you're doing everything right. But some targeted
varnishlogcommands will give us a better understanding of how Varnish is caching the various fragments.I'm going to need you to send me the output of the following command:
My assumption is that the issue is occurring on the homepage. If that's not the case, alter the filter in the
varnishlogcommand.When Varnish performs the various fetches, we can have a look at the
TTLtags in the logs. This will tell us how Varnish decided on the TTL of each fragment (either through a TTL set in the VCL code, or through theCache-Controlheader.The logs will also return the various ESI subrequests as separate log transactions, making it easier to understand what happened when.
Please put the log output in your original question and I'll help you figure out what's going on.
Update
I'm not seeing the
Surrogate-Capabilityheader in your (backend) request. Without this header, Symfony will not trigger theSurrogate-Controlheader which enables ESI processing in Varnish. Despite seeingSurrogate-Capabilityin your VCL code.However I'm seeing
call fos_user_context_backend_response;,call sulu_backend_response;&call sulu_recv;in the VCL code right before you set the header. Chances are that a return statement is made there, which bypasses your header.My suggestion would be to move
set req.http.Surrogate-Capability = "abc=ESI/1.0";to the beginning of thevcl_recvsubroutine.Just ensure the header gets set and the logic doesn't get bypassed by other calls.
An easy way to fix this is to move this logic to the
vcl_backend_fetchsubroutine because setting the header is related to a fetch and not to receiving a request. Here's the VCL code: