Questions[varnishncsa](server)

How can I connect Varnish container with PHP-FPM + NGINX containers? Docker started correctly, site works but backendopen logs are empty.

Backend is healthy (returns HTTP 200 status).

varnishlog -g raw -i Backend_health

0 Backend_health - default Still healthy 4---X-RH 7 5 10 0.048069 0.065633 "HTTP/1.1 200 OK"

From http (nginx) container I see request in docker logs.

docker logs http

[10/Sep/2021:17:24:01 +0000] "GET /health_check.php HTTP/1.1" 200 5 "-" "-"

But backend connection doesn't open connection, logs are empty, verified via: varnishlog -i backendopen command. I've tried solution from this site, but not working: Php+Nginx+Varnish on docker-compose, ubuntu18.

docker-compose.yml

http:
    build:
    context: docker/http
    container_name: http
    ports:
       - 80:80
       - 443:443
    depends_on:
       - php
    volumes:
        - ./project:/var/www/project

php:
    build:
        context: docker/php
    container_name: php
    working_dir: /var/www/project
    volumes:
        - ./project:/var/www/project

    
varnish:
    build:
    context: docker/varnish
    container_name: varnish
    ports:
       - 6081:6081
       - 6082:6082

VCL config:

vcl 4.0;

import std;

backend default {
    .host = "http";
    .port = "80";
    .first_byte_timeout = 600s;
    .probe = {
        #.url = "/health_check.php";
        .request =
                    "GET /health_check.php HTTP/1.1"
                    "Host: http"
                    "Connection: close";
        .timeout = 2s;
        .interval = 5s;
        .window = 10;
        .threshold = 5;
   }
}

acl purge {
    "http";
}

sub vcl_recv {
    if (req.restarts > 0) {
        set req.hash_always_miss = true;
    }

    if (req.method == "PURGE") {
        if (client.ip !~ purge) {
            return (synth(405, "Method not allowed"));
        }
        # To use the X-Pool header for purging varnish during automated deployments, make sure the X-Pool header
        # has been added to the response in your backend server config. This is used, for example, by the
        # capistrano-magento2 gem for purging old content from varnish during it's deploy routine.
        if (!req.http.X-Magento-Tags-Pattern && !req.http.X-Pool) {
            return (synth(400, "X-Magento-Tags-Pattern or X-Pool header required"));
        }
        if (req.http.X-Magento-Tags-Pattern) {
          ban("obj.http.X-Magento-Tags ~ " + req.http.X-Magento-Tags-Pattern);
        }
        if (req.http.X-Pool) {
          ban("obj.http.X-Pool ~ " + req.http.X-Pool);
        }
        return (synth(200, "Purged"));
    }

    if (req.method != "GET" &&
        req.method != "HEAD" &&
        req.method != "PUT" &&
        req.method != "POST" &&
        req.method != "TRACE" &&
        req.method != "OPTIONS" &&
        req.method != "DELETE") {
          /* Non-RFC2616 or CONNECT which is weird. */
          return (pipe);
    }

    # We only deal with GET and HEAD by default
    if (req.method != "GET" && req.method != "HEAD") {
        return (pass);
    }

    # Bypass shopping cart and checkout
    if (req.url ~ "/checkout") {
        return (pass);
    }

    # Bypass health check requests
    if (req.url ~ "/pub/health_check.php") {
        return (pass);
    }

    # Set initial grace period usage status
    set req.http.grace = "none";

    # normalize url in case of leading HTTP scheme and domain
    set req.url = regsub(req.url, "^http[s]?://", "");

    # collect all cookies
    std.collect(req.http.Cookie);

    # Compression filter. See https://www.varnish-cache.org/trac/wiki/FAQ/Compression
    if (req.http.Accept-Encoding) {
        if (req.url ~ "\.(jpg|jpeg|png|gif|gz|tgz|bz2|tbz|mp3|ogg|swf|flv)$") {
            # No point in compressing these
            unset req.http.Accept-Encoding;
        } elsif (req.http.Accept-Encoding ~ "gzip") {
            set req.http.Accept-Encoding = "gzip";
        } elsif (req.http.Accept-Encoding ~ "deflate" && req.http.user-agent !~ "MSIE") {
            set req.http.Accept-Encoding = "deflate";
        } else {
            # unknown algorithm
            unset req.http.Accept-Encoding;
        }
    }

    # Remove all marketing get parameters to minimize the cache objects
    if (req.url ~ "(\?|&)(gclid|cx|ie|cof|siteurl|zanpid|origin|fbclid|mc_[a-z]+|utm_[a-z]+|_bta_[a-z]+)=") {
        set req.url = regsuball(req.url, "(gclid|cx|ie|cof|siteurl|zanpid|origin|fbclid|mc_[a-z]+|utm_[a-z]+|_bta_[a-z]+)=[-_A-z0-9+()%.]+&?", "");
        set req.url = regsub(req.url, "[?|&]+$", "");
    }

    # Static files caching
    if (req.url ~ "^/(pub/)?(media|static)/") {
        # Static files should not be cached by default
        return (pass);

        # But if you use a few locales and don't use CDN you can enable caching static files by commenting previous line (#return (pass);) and uncommenting next 3 lines
        #unset req.http.Https;
        #unset req.http.X-Forwarded-Proto;
        #unset req.http.Cookie;
    }

    # Authenticated GraphQL requests should not be cached by default
    if (req.url ~ "/graphql" && req.http.Authorization ~ "^Bearer") {
        return (pass);
    }

    return (hash);
}

sub vcl_hash {
    if (req.http.cookie ~ "X-Magento-Vary=") {
        hash_data(regsub(req.http.cookie, "^.*?X-Magento-Vary=([^;]+);*.*$", "\1"));
    }

    # To make sure http users don't see ssl warning
    if (req.http.X-Forwarded-Proto) {
        hash_data(req.http.X-Forwarded-Proto);
    }
    

    if (req.url ~ "/graphql") {
        call process_graphql_headers;
    }
}

sub process_graphql_headers {
    if (req.http.Store) {
        hash_data(req.http.Store);
    }
    if (req.http.Content-Currency) {
        hash_data(req.http.Content-Currency);
    }
}

sub vcl_backend_response {

    set beresp.grace = 3d;

    if (beresp.http.content-type ~ "text") {
        set beresp.do_esi = true;
    }

    if (bereq.url ~ "\.js$" || beresp.http.content-type ~ "text") {
        set beresp.do_gzip = true;
    }

    if (beresp.http.X-Magento-Debug) {
        set beresp.http.X-Magento-Cache-Control = beresp.http.Cache-Control;
    }

    # cache only successfully responses and 404s
    if (beresp.status != 200 && beresp.status != 404) {
        set beresp.ttl = 0s;
        set beresp.uncacheable = true;
        return (deliver);
    } elsif (beresp.http.Cache-Control ~ "private") {
        set beresp.uncacheable = true;
        set beresp.ttl = 86400s;
        return (deliver);
    }

    # validate if we need to cache it and prevent from setting cookie
    if (beresp.ttl > 0s && (bereq.method == "GET" || bereq.method == "HEAD")) {
        unset beresp.http.set-cookie;
    }

   # If page is not cacheable then bypass varnish for 2 minutes as Hit-For-Pass
   if (beresp.ttl <= 0s ||
       beresp.http.Surrogate-control ~ "no-store" ||
       (!beresp.http.Surrogate-Control &&
       beresp.http.Cache-Control ~ "no-cache|no-store") ||
       beresp.http.Vary == "*") {
        # Mark as Hit-For-Pass for the next 2 minutes
        set beresp.ttl = 120s;
        set beresp.uncacheable = true;
    }

    return (deliver);
}

sub vcl_deliver {
    if (resp.http.X-Magento-Debug) {
        if (resp.http.x-varnish ~ " ") {
            set resp.http.X-Magento-Cache-Debug = "HIT";
            set resp.http.Grace = req.http.grace;
        } else {
            set resp.http.X-Magento-Cache-Debug = "MISS";
        }
    } else {
        unset resp.http.Age;
    }

    # Not letting browser to cache non-static files.
    if (resp.http.Cache-Control !~ "private" && req.url !~ "^/(pub/)?(media|static)/") {
        set resp.http.Pragma = "no-cache";
        set resp.http.Expires = "-1";
        set resp.http.Cache-Control = "no-store, no-cache, must-revalidate, max-age=0";
    }

    unset resp.http.X-Magento-Debug;
    unset resp.http.X-Magento-Tags;
    unset resp.http.X-Powered-By;
    unset resp.http.Server;
    unset resp.http.X-Varnish;
    unset resp.http.Via;
    unset resp.http.Link;
}

sub vcl_hit {
    if (obj.ttl >= 0s) {
        # Hit within TTL period
        return (deliver);
    }
    if (std.healthy(req.backend_hint)) {
        if (obj.ttl + 300s > 0s) {
            # Hit after TTL expiration, but within grace period
            set req.http.grace = "normal (healthy server)";
            return (deliver);
        } else {
            # Hit after TTL and grace expiration
            return (restart);
        }
    } else {
        # server is not healthy, retrieve from cache
        set req.http.grace = "unlimited (unhealthy server)";
        return (deliver);
    }
}

I'm using varnishncsa to log requests that are taking to long to be answered on my backend servers using the following command:

varnishncsa -F '%t "%r" %s %T' | awk '$7 > 10 {print}'

I was trying to add information on the backend name but this is not being displayed on varnishncsa output:

sub vcl_backend_response {
    std.log("backend_name:" + beresp.backend.name);
}

what I'm doing wrong?

While trying to figure out why our Varnish 4.1 install (on CentOS7 via the varnish-cache.org repo) was not following vcl rules set out to log the client IP address in an X-Forwarded-For header (see: Varnish 4 logging proxy/load balancer instead of client IP addresses) I happened to notice something odd while looking through varnishlog files:

- Begin        req 9353447 rxreq
- Timestamp    Start: 1488771709.337974 0.000000 0.000000
- Timestamp    Req: 1488771709.337974 0.000000 0.000000
- ReqStart     172.25.20.65 19903
- ReqMethod    GET
- ReqURL       /about-us/
- ReqProtocol  HTTP/1.1
- ReqHeader    host: www.<notreallythishost>.com
- ReqHeader    Accept: */*
- ReqHeader    Accept-Encoding: gzip, deflate
- ReqHeader    Cache-Control: no-cache
- ReqHeader    From: bingbot(at)microsoft.com
- ReqHeader    Pragma: no-cache
- ReqHeader    User-Agent: Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)
- ReqHeader    X-Forwarded-For: 40.77.167.41
- ReqHeader    X-Forwarded-Port: 80
- ReqHeader    X-Forwarded-Proto: http
- ReqHeader    Connection: keep-alive
- ReqUnset     X-Forwarded-For: 40.77.167.41
- ReqHeader    X-Forwarded-For: 40.77.167.41, 172.25.20.65
- VCL_call     RECV
- ReqUnset     X-Forwarded-For: 40.77.167.41, 172.25.20.65
- ReqHeader    X-Forwarded-For: 172.25.20.65
- ReqUnset     Accept-Encoding: gzip, deflate
- ReqHeader    Accept-Encoding: gzip
- ReqUnset     User-Agent: Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)
- VCL_return   hash
- VCL_call     HASH
- VCL_return   lookup
- VCL_call     MISS
- VCL_return   fetch
- Link         bereq 9353449 fetch
- Timestamp    Fetch: 1488771709.338395 0.000421 0.000421
- RespProtocol HTTP/1.1

This fully explains why we were never able to get anything other than the load balancer IP address logged through varnishncsa at any point regardless of the logging technique we used.

It looks as though in the request processing it builds up the X-Forwarded-For header by adding the AWS Load Balancer IP address to the header, but as vc_call is called summarily decontructs it again and removes the original client IP address. So how do I go about keeping the X-Forwarded-For intact and why is Varnish shifting IPs off the left side rather than than just adding them onto the X-Forwarded-For header like it should? Bug?

In the varnish 3, varnishncsa can support -m option (-m tag:regex only list records where tag matches regex. Multiple -m options are AND-ed together. ). After upgraded to varnish 4, I cannot find the -m option in varnish 4. Is it any easy way to upgrade from 3 to 4. Please advice.

Thanks.

I've got a few load balancers that all perform health checks on a number of varnish instances. The health check on the varnish side consists of matching the request method and URL to return a 200 response.

if (req.method == "GET" && req.url == "/ping") {
       return(synth(200, "OK"));
}

Using HAProxy i've got health checks configured to poll /ping on the backend servers. This is generating a lot of messages in varnishncsa. Is it possible to somehow drop log entries going into varnishncsa if they match a certain req.url?