Varnish woes

Varnish woes

Recently (*) at work, I was seeing some really odd behavior: browsers were requesting static files and getting truncated results.

The setup

Router

Basic router routing the traffic to the correct HA Proxy.

HA Proxy

HA Proxy is the edge and SSL terminator. It identifies the client, drops bad actors, and forwards the traffic to the next step.

Varnish

Varnish is used for routing the traffic to the right place and, of course, caching content that should be cached.

Nginx

Serving the files and deciding the cache policy.

What happened?

What I saw in the browser was that static files were sometimes cut short. JavaScript files, CSS files, and similar — all just static files on disk — were seemingly truncated at random.

There's a fair amount of things that can go wrong even with a basic setup like I described above:

  • Flaky internet connection on the client side (living in Germany, that's not a joke)
  • Flaky internet in the co-location — not very likely, but possible
  • Problems with the router — old hardware, so not impossible but also not very likely
  • Problems with HA Proxy
  • Problems with Varnish
  • Problems with the internal network
  • Problems with Nginx
  • Problems with the disk

Starting with the disk

As is often the case with "DevOps" problems, it's rarely easy. I figured that starting from the bottom made the most sense. The disks seemed healthy, so that was pretty quick to rule out.

Next up Nginx

Next suspect was Nginx. Looking at the access log, I saw that the size of the response was sometimes smaller than the file on disk. That made it seem like it could be something with Nginx. However, it's just plain files being served. Not much outside of disk problems can cause that. The lines look like this in the access log:

www.some-site.com 1.2.3.4 [07/Jun/2025:10:37:16 +0200] "GET /example-file HTTP/1.1" 200 2555581 3324466 "-" "client" 0.001 -

In this example, it looks like everything is fine — or at least "200 OK". There's nothing in the error log about this request either. So what's up here? Clients disconnecting isn't necessarily an error; it happens all the time, and we don't want logs cluttered by someone stepping into a Faraday cage with their mobile while visiting our site. So that makes sense, but it also makes the issue harder to spot.

If the client disconnects before the headers are sent, that is considered an error. But if you also want to see when clients prematurely disconnect after the headers have already been sent, you have to change the log level in Nginx.

In any case, we do see a problem from the access log: 200 2555581 3324466 "-". The file is 3,324,466 bytes, but the response is 2,555,581 bytes. At this point, I decided to keep Nginx as a suspect but expand the investigation to include Varnish.

Varnish, is it you?

We had problems with Varnish at the time — memory usage spiked, or rather slowly grew, until it consumed all RAM. That's a pretty good indication that something wasn't right. I'm very willing to admit that Varnish and I aren't the best of friends — we're more like acquaintances. We know of each other, but I don't know its inner secrets. However, I'm willing to learn and listen!

Looking at the VCL file, there's not that much to it. It can be made too complicated and slow things down, but it's not likely to prematurely close connections or leak memory. I started looking at the output of `varnishstat -1`. There's a fair bit of data there — 610 lines in my case. I saw that SMA.Transient.c_fail was pretty large, and "fail" never sounds good. SMA.Transient.c_bytes was also very large, which I felt was worth looking into.

So what's SMA.Transient.? It turns out that Varnish has multiple storage backends. There's `malloc`, which, like the name implies, stores data in RAM, and there's `Transient`, which has this description:

If you name any of your storage backend “Transient” it will be used for transient (short lived) objects. This includes the temporary objects created when returning a synthetic object. By default, Varnish would use an unlimited malloc backend for this.

Varnish will consider an object short lived if the TTL is below the parameter ‘shortlived’.

Okay, so Varnish is defaulting to store any synthetic or short-lived objects in RAM — with no upper limit! To see if any/many requests are going in there, you can run:

varnishlog -g request -q "Storage[2] eq 'Transient'"

In my case, with the server very low on RAM, I saw errors there. It's a lot of data flying by when looking in a production environment; I was lucky to have very frequent errors, but otherwise, it could be hard to spot unless those logs are forwarded to something more user-friendly.

In our case, the systemd Varnish file was default, with just the malloc storage engine tweaked to match the server memory. It looked like this:

[Unit]
Description=Varnish Cache, a high-performance HTTP accelerator
...
ExecStart=/usr/sbin/varnishd ... -s malloc,16384m

That means no upper limit for Transient storage — which explains the server running out of memory! So I made a small change:

[Unit]
Description=Varnish Cache, a high-performance HTTP accelerator
...
ExecStart=/usr/sbin/varnishd ... -s malloc,16384m -s Transient=malloc,512m

With that, the output of `varnishstat` started looking a lot better:

root@server:~# varnishstat -1|grep SMA.Transient
SMA.Transient.c_req                   120554844        12.93 Allocator requests
SMA.Transient.c_fail                          0         0.00 Allocator failures
SMA.Transient.c_bytes              1359073965022    145801.66 Bytes allocated
SMA.Transient.c_freed              1359073816886    145801.64 Bytes freed
SMA.Transient.g_alloc                       239          .   Allocations outstanding
SMA.Transient.g_bytes                    148136          .   Bytes outstanding
SMA.Transient.g_space                 536722776          .   Bytes available

Summary

So, what happened was this: requests came into HA Proxy. They were forwarded to Varnish, which in turn made requests to our Nginx servers. While reading the data, Varnish tried to allocate (and for some reason not free) Transient memory when getting the response body, which failed. As a result, the requests were cut short and only partial data was returned.

While I'm generally very happy with Varnish, I find this to be a bit odd behavior. I didn't spend time checking why the Transient storage wasn't freed when no limit was set, because it ought to hit the same problem with 512 MB — just faster and more often. But, as is often the case, I didn't have the time to fully investigate what was going on. I'm sure there's some good reason, as it's otherwise a really nice cache server.

Not really recently

(*) It was recently when I started writing this; now it's around a year ago. In case you're wondering about the date of the article and the date in the access log.