Varnish 4.1 – How to serve cached copy on backend fetch failed instead of 503

503-errorvarnish

I have a site served by apache+tomcat and a cache served by Varnish 4.1

When apache is down, varnish always returns a 503 error.
I would like varnish to return the copy of the pages it has in its cache but my attempts with ttl and grace have been unsuccessful.
I think I've read all the documentation on varnish 4.1 that I could find, any help is really appreciated.

Thanks in advance

EDIT: varnishlog -g request -q "ReqUrl eq '/'"

curl

*   << Request  >> 1410492
-   Begin          req 1410491 rxreq
-   Timestamp      Start: 1646995409.603391 0.000000 0.000000
-   Timestamp      Req: 1646995409.603391 0.000000 0.000000
-   ReqStart       10.xxx.xxx.xxx 57472
-   ReqMethod      GET
-   ReqURL         /
-   ReqProtocol    HTTP/1.1
-   ReqHeader      host: akamai5.rsi.ch
-   ReqHeader      user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:98.0) Gecko/20100101 Firefox/98.0
-   ReqHeader      accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
-   ReqHeader      accept-language: it,en-US;q=0.7,en;q=0.3
-   ReqHeader      accept-encoding: gzip, deflate, br
-   ReqHeader      cookie: wt_rla=292330999892453%2C2%2C1646731482026; _pipe_c=do_not_track; _ga=GA1.2.836346559.1644414441; __gads=ID=453223b8518b57e5-22f191e137cd00c3:T=1644414444:RT=1644414444:S=ALNI_MbCUi8liJ5sbhjlTe68z1BhLhZJCQ; __utma=46365988.836346559.1644414441.16
-   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      cache-control: max-age=0
-   ReqHeader      x-forwarded-proto: https
-   ReqHeader      x-forwarded-ssl: on
-   ReqHeader      x-forwarded-port: 443
-   ReqHeader      x-forwarded-for: 1178.xxx.xxx.xxx
-   ReqHeader      connection: close
-   ReqUnset       x-forwarded-for: 1178.xxx.xxx.xxx
-   ReqHeader      X-Forwarded-For: 1178.xxx.xxx.xxx, 10.xxx.xxx.xxx
-   VCL_call       RECV
-   ReqUnset       cookie: wt_rla=292330999892453%2C2%2C1646731482026; _pipe_c=do_not_track; _ga=GA1.2.836346559.1644414441; __gads=ID=453223b8518b57e5-22f191e137cd00c3:T=1644414444:RT=1644414444:S=ALNI_MbCUi8liJ5sbhjlTe68z1BhLhZJCQ; __utma=46365988.836346559.1644414441.16
-   ReqHeader      Cookie: wt_rla=292330999892453%2C2%2C1646731482026; _pipe_c=do_not_track; _ga=GA1.2.836346559.1644414441; __gads=ID=453223b8518b57e5-22f191e137cd00c3:T=1644414444:RT=1644414444:S=ALNI_MbCUi8liJ5sbhjlTe68z1BhLhZJCQ; cs_fpid=1645804349272_22538249; wt_geid
-   ReqUnset       Cookie: wt_rla=292330999892453%2C2%2C1646731482026; _pipe_c=do_not_track; _ga=GA1.2.836346559.1644414441; __gads=ID=453223b8518b57e5-22f191e137cd00c3:T=1644414444:RT=1644414444:S=ALNI_MbCUi8liJ5sbhjlTe68z1BhLhZJCQ; cs_fpid=1645804349272_22538249; wt_geid
-   ReqHeader      Cookie: wt_rla=292330999892453%2C2%2C1646731482026; _pipe_c=do_not_track; _ga=GA1.2.836346559.1644414441; __gads=ID=453223b8518b57e5-22f191e137cd00c3:T=1644414444:RT=1644414444:S=ALNI_MbCUi8liJ5sbhjlTe68z1BhLhZJCQ; cs_fpid=1645804349272_22538249; wt_geid
-   ReqUnset       Cookie: wt_rla=292330999892453%2C2%2C1646731482026; _pipe_c=do_not_track; _ga=GA1.2.836346559.1644414441; __gads=ID=453223b8518b57e5-22f191e137cd00c3:T=1644414444:RT=1644414444:S=ALNI_MbCUi8liJ5sbhjlTe68z1BhLhZJCQ; cs_fpid=1645804349272_22538249; wt_geid
-   ReqHeader      Cookie: wt_rla=292330999892453%2C2%2C1646731482026; _pipe_c=do_not_track; _ga=GA1.2.836346559.1644414441; __gads=ID=453223b8518b57e5-22f191e137cd00c3:T=1644414444:RT=1644414444:S=ALNI_MbCUi8liJ5sbhjlTe68z1BhLhZJCQ; cs_fpid=1645804349272_22538249; wt_geid
-   VCL_return     hash
-   ReqUnset       accept-encoding: gzip, deflate, br
-   ReqHeader      Accept-Encoding: gzip
-   VCL_call       HASH
-   VCL_return     lookup
-   Hit            1410469
-   VCL_call       HIT
-   VCL_return     deliver
-   RespProtocol   HTTP/1.1
-   RespStatus     200
-   RespReason     OK
-   RespHeader     Date: Fri, 11 Mar 2022 10:42:05 GMT
-   RespHeader     Server: Apache-Coyote/1.1
-   RespHeader     Content-Type: text/html;charset=UTF-8
-   RespHeader     Set-Cookie: JSESSIONID=F8D07853DF7D90A3F381B316F64FA285; Path=/; HttpOnly
-   RespHeader     X-Varnish: 1410492 1410469
-   RespHeader     Age: 84
-   RespHeader     Via: 1.1 varnish-v4
-   VCL_call       DELIVER
-   RespHeader     X-Cache-Host: rsi-prod-varnish45
-   RespHeader     X-Frame-Options: SAMEORIGIN
-   RespHeader     X-XSS-Protection: 1; mode=block
-   RespHeader     X-Content-Type-Options: nosniff
-   RespHeader     Content-Security-Policy: script-src 'self' 'unsafe-inline' 'unsafe-eval' *
-   RespHeader     X-Cache: HIT
-   RespHeader     X-Cache-Hits: 3
-   RespHeader     X-Grace-Hit: yes
-   VCL_return     deliver
-   Timestamp      Process: 1646995409.603614 0.000222 0.000222
-   RespHeader     Accept-Ranges: bytes
-   RespHeader     Content-Length: 191244
-   Debug          "RES_MODE 2"
-   RespHeader     Connection: close
-   Timestamp      Resp: 1646995409.608024 0.004632 0.004410
-   ReqAcct        1130 0 1130 574 191244 191818
-   End

browser

*   << Request  >> 1410496
-   Begin          req 1410495 rxreq
-   Timestamp      Start: 1646995426.730217 0.000000 0.000000
-   Timestamp      Req: 1646995426.730217 0.000000 0.000000
-   ReqStart       10.xxx.xxx.xxx 60908
-   ReqMethod      GET
-   ReqURL         /
-   ReqProtocol    HTTP/1.1
-   ReqHeader      host: www.example.com
-   ReqHeader      user-agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0
-   ReqHeader      accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
-   ReqHeader      accept-language: it,it-IT;q=0.8,en-US;q=0.5,en;q=0.3
-   ReqHeader      accept-encoding: gzip, deflate, br
-   ReqHeader      cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; __utma=46365988.1217589648.1620392041.1638545296.1642173864.10; __utmz=46365988.16
-   ReqHeader      upgrade-insecure-requests: 1
-   ReqHeader      cache-control: max-age=0
-   ReqHeader      x-forwarded-proto: https
-   ReqHeader      x-forwarded-ssl: on
-   ReqHeader      x-forwarded-port: 443
-   ReqHeader      x-forwarded-for: 178.xxx.xxx.xxx
-   ReqHeader      connection: close
-   ReqUnset       x-forwarded-for: 178.xxx.xxx.xxx
-   ReqHeader      X-Forwarded-For: 178.xxx.xxx.xxx, 10.xxx.xxx.xxx
-   VCL_call       RECV
-   ReqUnset       cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; __utma=46365988.1217589648.1620392041.1638545296.1642173864.10; __utmz=46365988.16
-   ReqHeader      Cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; wt_rla=292330999892453%2C2%2C1646995242972; cs_fpid=1645855325408_55998969; JSESSI
-   ReqUnset       Cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; wt_rla=292330999892453%2C2%2C1646995242972; cs_fpid=1645855325408_55998969; JSESSI
-   ReqHeader      Cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; wt_rla=292330999892453%2C2%2C1646995242972; cs_fpid=1645855325408_55998969; JSESSI
-   ReqUnset       Cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; wt_rla=292330999892453%2C2%2C1646995242972; cs_fpid=1645855325408_55998969; JSESSI
-   ReqHeader      Cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; wt_rla=292330999892453%2C2%2C1646995242972; cs_fpid=1645855325408_55998969; JSESSI
-   VCL_return     hash
-   ReqUnset       accept-encoding: gzip, deflate, br
-   ReqHeader      Accept-Encoding: gzip
-   VCL_call       HASH
-   VCL_return     lookup
-   VCL_call       MISS
-   VCL_return     fetch
-   Link           bereq 1410497 fetch
-   Timestamp      Fetch: 1646995426.730455 0.000238 0.000238
-   RespProtocol   HTTP/1.1
-   RespStatus     503
-   RespReason     Backend fetch failed
-   RespHeader     Date: Fri, 11 Mar 2022 10:43:46 GMT
-   RespHeader     Server: Varnish
-   RespHeader     Content-Type: text/html; charset=utf-8
-   RespHeader     Retry-After: 5
-   RespHeader     X-Varnish: 1410496
-   RespHeader     Age: 0
-   RespHeader     Via: 1.1 varnish-v4
-   VCL_call       DELIVER
-   RespHeader     X-Cache-Host: rsi-prod-varnish45
-   RespHeader     X-Frame-Options: SAMEORIGIN
-   RespHeader     X-XSS-Protection: 1; mode=block
-   RespHeader     X-Content-Type-Options: nosniff
-   RespHeader     Content-Security-Policy: script-src 'self' 'unsafe-inline' 'unsafe-eval' *
-   RespHeader     X-Cache: HIT
-   RespHeader     X-Cache-Hits: 0
-   RespHeader     X-Grace-Hit: yes
-   VCL_return     deliver
-   Timestamp      Process: 1646995426.730495 0.000278 0.000040
-   RespHeader     Content-Length: 284
-   Debug          "RES_MODE 2"
-   RespHeader     Connection: close
-   Timestamp      Resp: 1646995426.730527 0.000310 0.000032
-   ReqAcct        929 0 929 490 284 774
-   End
**  << BeReq    >> 1410497
--  Begin          bereq 1410496 fetch
--  Timestamp      Start: 1646995426.730367 0.000000 0.000000
--  BereqMethod    GET
--  BereqURL       /
--  BereqProtocol  HTTP/1.1
--  BereqHeader    host: www.example.com
--  BereqHeader    user-agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0
--  BereqHeader    accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
--  BereqHeader    accept-language: it,it-IT;q=0.8,en-US;q=0.5,en;q=0.3
--  BereqHeader    upgrade-insecure-requests: 1
--  BereqHeader    x-forwarded-proto: https
--  BereqHeader    x-forwarded-ssl: on
--  BereqHeader    x-forwarded-port: 443
--  BereqHeader    X-Forwarded-For: 178.xxx.xxx.xxx, 10.xxx.xxx.xxx
--  BereqHeader    Cookie: _pipe_c=do_not_track; _ga=GA1.2.1217589648.1620392041; __gads=ID=1a22b33c44d55e6f-1a22b33c44d55e6f:T=1620392042:RT=1620392042:S=ALNI_MYR9nyXrxcQ8QV1Y2pNVDp67Gn9-w; wt_rla=292330999892453%2C2%2C1646995242972; cs_fpid=1645855325408_55998969; JSESSI
--  BereqHeader    Accept-Encoding: gzip
--  BereqHeader    X-Varnish: 1410497
--  VCL_call       BACKEND_FETCH
--  VCL_Log        Backend fetch: v_ssl_ece
--  VCL_return     fetch
--  FetchError     Director v_ssl_ece returned no backend
--  FetchError     No backend
--  Timestamp      Beresp: 1646995426.730387 0.000020 0.000020
--  Timestamp      Error: 1646995426.730390 0.000023 0.000003
--  BerespProtocol HTTP/1.1
--  BerespStatus   503
--  BerespReason   Service Unavailable
--  BerespReason   Backend fetch failed
--  BerespHeader   Date: Fri, 11 Mar 2022 10:43:46 GMT
--  BerespHeader   Server: Varnish
--  VCL_call       BACKEND_ERROR
--  BerespHeader   Content-Type: text/html; charset=utf-8
--  BerespHeader   Retry-After: 5
--  VCL_return     deliver
--  Storage        malloc Transient
--  ObjProtocol    HTTP/1.1
--  ObjStatus      503
--  ObjReason      Backend fetch failed
--  ObjHeader      Date: Fri, 11 Mar 2022 10:43:46 GMT
--  ObjHeader      Server: Varnish
--  ObjHeader      Content-Type: text/html; charset=utf-8
--  ObjHeader      Retry-After: 5
--  Length         284
--  BereqAcct      0 0 0 0 0 0
--  End

EDIT 2: hash and cookies

After much investigation we discovered that the problem lies in this configuration:

sub vcl_hash {
  hash_data( req.url );
  if( req.http.host ) {
    hash_data( req.http.host );
  } else {
    hash_data( server.ip );
  }
  # hash cookies for object with auth
  if( req.http.Cookie ) {
    hash_data( req.http.Cookie );
  }
  return( lookup );
}

If cookies are removed from the varnish hash it returns the cache correctly.
Is it useful for cookies to be included in the hash? At first glance I think so, if cookies are used to keep track of user authentication. How can we include only certain cookies in the hash (e.g. those from an authenticated session) and not those that are not useful for caching (e.g. those related to analytics)?

Best Answer

As long as the sum of the TTL and grace values are greater than zero, no backend fetches are made.

If your TTL expires, grace mode will ensure that stale content is served while a fetch attempt is made.

Grace, which is a stale-while-revalidate mechanism, can actually be abused and turned into a stale-if-error mechanism. By setting the grace high enough, users will never experience the downtime of the backend.

Here's some VCL:

vcl 4.1;

import std;

sub vcl_recv {
    if (std.healthy(req.backend_hint)) {
        set req.grace = 10s;
    }
}

sub vcl_backend_response {
    set beresp.grace = 24h;
}

This VCL code will enforce a 24-hour grace. This means your backend can be down for a day without anyone noticing. However, as long as the backend is healthy, Varnish will only use 10 seconds of grace.

It's important that your backend definition has a .probe property that refers to a health checking probe, otherwise std.healthy(req.backend_hint) will never be able to produce the right results.

I used set beresp.grace = 24h which might be excessive. By setting the grace to such a high duration, these objects remain in the cache while being expired. If you have a large catalog of content that needs to be cached, this may effect your hit rate and may cause forced cache eviction when the cache is full.

IMPORTANT: Varnish Cache 4.1 is end-of-life and should not be used. Please install Varnish 6.0 LTS or Varnish 7 instead.

My VCL example contains a vcl 4.1; version marker which will only work in Varnish 6 or Varnish 7. I do this on purpose to encourage users to use recent versions of Varnish. By switching this to vcl 4.0; the code will probably work on older versions of Varnish. Please consider upgrading.

503 error

Based on the VSL output that you added to your question, I can conclude that you have defined and used a director object in your VCL that doesn't have any backends.

This is the error I found in your VSL output:

Director v_ssl_ece returned no backend

Please have a look at the director named v_ssl_ece.

Check whether or not you need this director
Check if it is assigned correctly through req.backend_hint in vcl_recv or through bereq.backend in vcl_backend_fetch
Check why v_ssl_ece doesn't have any backends

If you cannot find the solution, please share your full VCL file so I can assist.

Best Answer

503 error

Related Solutions

Varnish throwing 503 errors when there is a healthy backend

Nginx – Configure php5-fpm for many concurrent users

Related Topic