Troubleshooting / Varnish

Varnish “Backend fetch failed”

by , , revisited on

We have by far the largest RPM repository with NGINX module packages and VMODs for Varnish. If you want to install NGINX, Varnish, and lots of useful performance/security software with smooth yum upgrades for production use, this is the repository for you.
Active subscription is required.

Here are some generic tips on finding the actual cause of the “Backend Fetch Failed” error shown by Varnish Cache.

Why backend fetch fails

Common reasons for getting “Backend fetch failed” error:

  • Varnish timeout was hit
  • A backend health probe failed – your backend is marked as sick
  • Your PHP has generated a fatal error (HTTP code > 500)
  • Varnish can’t communicate to the backend
  • Varnish cannot find an object to evict from the cache while serving large files (ExpKill LRU_Exhausted and FetchError Could not get storage in varnishlog), similar to this issue. The solution is often to return (pipe) for large files

Use varnishlog to see why backend fetch failed for particular request

It much better to hunt down the specific request that generated the error. When you get “Backend fetch failed” in the browser, take note of “XID: 12345” at the bottom of the page. Use that number to get relevant requests quickly.

varnishlog -d -q "vxid == 12345"

In versions prior to 5.1 you can use the X-Varnish header:

The “Backend fetch failed” may be triggered before communicating the backend, or after.

First, you will get client side request using the following command:

varnishlog -d -q 'RespHeader:X-Varnish[1] == 12345'

This will display the client-side request to Varnish. Investigate it for the ID of the backend request. Find a line that looks like this:

-   Link bereq 12346 pass

Now you can investigate actual errors. Review request details of Varnish connection to the backend:

varnishlog -d -q 'BereqHeader:X-Varnish == 12346'

If the previous commands do not return any request, it means that the 12345 represents the ID of backend request, or the memory log was already overwritten by new requests.
In the former case, run:

varnishlog -d -q 'BereqHeader:X-Varnish == 12345'

Use varnishlog to see all failed requests

varnishlog -d -q "BerespStatus == 503"

Will show the latest in-memory Varnish log entries for “Backend fetch failed”.

It may produce too many entries and quickly fill your screen. A better approach is to save in-memory Varnish log entries into a file.

varnishlog -A -d -w /var/log/varnish/varnish50x.log -q "RespStatus >= 500 or BerespStatus >= 500"

Now we can investigate the file and find out details about why we have failed requests.

Enable varnishlog service for collecting longer history of failed requests

One issue with the above approaches is that they allow us to lookup only recent requests. Varnish memory log obviously can’t hold for a long period of logged data.

Let’s enable varnishlog service which logs only failed requests. Run:

sudo systemctl edit varnishlog 

Then paste in:

ExecStart=/usr/bin/varnishlog -a -w /var/log/varnish/varnish.log -D -P /run/varnishlog/varnishlog.pid -q "(RespStatus >= 500 and RespStatus <= 599) or (BerespStatus >= 500 and BerespStatus <= 599)"

This overrides the default startup command of the service, to log only failed requests.

You can then enable the logging with:

sudo systemctl enable --now varnishlog

Now we can read all the failed requests from the binary log that is being recorded by the varnishlog daemon.

varnishlog -r /var/log/varnish/varnish.log

You can adjust how many days of varnish logs are being kept on server by looking into /etc/logrotate.d/varnish.

P.S. varnish-helper is an upcoming utility to make troubleshooting of “Backend Fetch Failed” easier.

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.

%d bloggers like this: