502 when cache beresp.ttl is exhausted

[lloiacono]

I'm using dynamic directors with rancher and am getting a 502 error once the TTL of my cache object expires, if I try again then it works properly. I can request any URL and I would get a 200, then the page is cache for 5s (I set the TTL to 5s for testing), then after 5s I request the same URL again and I get the 502, then I request the same URL once again and it works. If I repeat the whole process I get the same results over and over.

Error:

HTTP/1.0 502 Bad Gateway Cache-Control: no-cache Content-Type: text/html X-Via: varnish-test

502 Bad Gateway

The server returned an invalid or incomplete response.

Configuration:

I have setup varnish with dynamic directors like this:

sub vcl_init {
  new www_dir = dynamic.director(
    port = 80,
    ttl = 5m
  );
  www_dir.debug(true);
}

And added the director as backend in vcl_recv like this:

set req.backend_hint = www_dir.backend(app);

app is the name of my backend service in rancher. If I dig to app I get something like:

app.                    1       IN      A       10.42.166.171
app.                    1       IN      A       10.42.215.78

Also in vcl_backend_response I've this:

set beresp.ttl = 5s;

I set the cache TTL to 5s to debug this easily.

On the varnish instance if I run this varnishlog -g raw -q '* ~ vmod-dynamic', after the 502 error I see this in the logs:

Log abandoned (vsl) Log reacquired

[nigoroll]

We'll definitely need varnishlog output. The Log abandoned issue should be fixed in current code. Please use a current master build or weekly packages and report back.

[lloiacono]

I tried using master but I'm not able to build it, I created an issue for that as I was not able to make it work: https://github.com/nigoroll/libvmod-dynamic/issues/39. Will try to get the full varnishlog in the mean time

[nigoroll]

Sorry, I was referring to varnish-cache master to be build (or installed from a weekly package) with the master branch of vmod_dynamic

[nigoroll]

please reopen if you can reproduce the issue still

[chuyenim]

Hello, I got the same issue. But it happens when director expired. It displays a 503 page after director(ttl = 5m) is over.

Error 503 Backend fetch failed
Backend fetch failed
Guru Meditation:
XID: 98383

Here is a part of vanishlog:

    -   BereqHeader    X-Forwarded-For: 116.111.62.50
    -   BereqHeader    host: go.app1pro.com
    -   BereqHeader    Accept-Encoding: gzip
    -   BereqHeader    X-Varnish: 98386
    -   VCL_call       BACKEND_FETCH
    -   VCL_return     fetch
    -   FetchError     Director www_dir returned no backend
    -   FetchError     No backend
    -   Timestamp      Beresp: 1539194406.719733 0.000058 0.000058
    -   Timestamp      Error: 1539194406.719737 0.000061 0.000004
    -   BerespProtocol HTTP/1.1
    -   BerespStatus   503
    -   BerespReason   Service Unavailable
    -   BerespReason   Backend fetch failed

My configs as below:

    probe www_probe {
    .window = 8;
    .initial = 7;
    .threshold = 6;
    .interval = 5s;
   }
   sub vcl_init {
    new www_dir = dynamic.director(
        port = "80",
        probe = www_probe,
        ##whitelist = www_acl,
        ttl = 5m);
   }

   sub vcl_recv {
            set req.http.host = "goapppro.com";
    set req.backend_hint = www_dir.backend("goapppro.com");
   }

It works well within 5m but after 5m it doesn't work and display an error 503 page.

-- Varnish 6.0.1 -- libvmod-dynamic (branch 6.0) -- Centos 7

[nigoroll]

This is actually a duplicate of #35, which I had fixed in varnish-cache itself, see https://github.com/varnishcache/varnish-cache/commit/d912ffe4f7a5e643275699c94b2722d486fd9e7f I do not think we can solve this issue with varnish-cache 6.0 in the vmod alone, but I can try to get that fix backported to 6.0 So for now the answer is: Use 6.1 oder master if you need probes