Varnish request missing cache despite being in

0
votes

I have this request in the Varnish cache:

ReqMethod      GET
ReqURL         /organisation/xyz/proposal_0000000/comments/comment_0000001/

Some PURGE requests are then send to Varnish, resulting in this list of bans:

ban.list 200 2108
Present bans: 1458150360.937187 16 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/team0000000$ 1458150360.929092 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz$ 1458150360.926030 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/pitch0000000$ 1458150360.923491 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/practicalrelevance0000000$ 1458150360.921025 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/plan0000000$ 1458150360.918480 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/target0000000$ 1458150360.915931 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/duration0000000$ 1458150360.913486 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/difference0000000$ 1458150360.910710 0 - req.http.host == localhost:8088 && req.url ~ /$ 1458150360.908150 0 - req.http.host == localhost:8088 && req.url ~ /organisation$ 1458150360.906249 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/extrainfo0000000$ 1458150360.904289 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/connectioncohesion0000000$ 1458150360.901930 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/challenge0000000$ 1458150360.899287 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/goal0000000$ 1458150360.896989 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/partners0000000$ 1458150360.894324 0 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000$ 1458150360.891701 0 C
1458150348.035639 1 C

The same GET request is then executed again but with a MISS:

* << Request >> 32790
- Begin req 32789 rxreq - Timestamp Start: 1458150371.759282 0.000000 0.000000 - Timestamp Req: 1458150371.759282 0.000000 0.000000 - ReqStart 127.0.0.1 43526 - ReqMethod GET - ReqURL /organisation/xyz/proposal_0000000/comments/comment_0000001/ - ReqProtocol HTTP/1.1 - ReqHeader Host: localhost:8088 - ReqHeader Connection: keep-alive - ReqHeader Pragma: no-cache - ReqHeader Cache-Control: no-cache - ReqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8 - ReqHeader Upgrade-Insecure-Requests: 1 - ReqHeader Referer: http://localhost:8088/organisation/xyz/proposal_0000000/comments/?elements=paths - ReqHeader Accept-Encoding: gzip, deflate, sdch - ReqHeader Accept-Language: en-GB,en-US;q=0.8,en;q=0.6 - ReqHeader X-Forwarded-For: 127.0.0.1 - VCL_call RECV - VCL_return hash - ReqUnset Accept-Encoding: gzip, deflate, sdch - ReqHeader Accept-Encoding: gzip - VCL_call HASH - VCL_return lookup - ExpBan 3 banned lookup - VCL_call MISS - VCL_return fetch - Link bereq 32791 fetch - Timestamp Fetch: 1458150371.779571 0.020289 0.020289 - RespProtocol HTTP/1.1 - RespStatus 200 - RespReason OK - RespHeader Server: gunicorn/19.2.1 - RespHeader Date: Wed, 16 Mar 2016 17:46:11 GMT - RespHeader X-Caching-Mode: with_proxy_cache - RespHeader X-Caching-Strategy: HTTPCacheStrategyWeakAdapter - RespHeader Cache-Control: max-age=0, proxy-revalidate, s-maxage=31104000 - RespHeader Vary: Accept-Encoding, X-User-Path, X-User-Token - RespHeader Content-Type: application/json; charset=UTF-8 - RespHeader Access-Control-Allow-Origin: * - RespHeader Access-Control-Allow-Methods: POST,GET,DELETE,PUT,OPTIONS - RespHeader Access-Control-Allow-Headers: Origin, Content-Type, Accept, X-User-Path, X-User-Token - RespHeader ETag: W/"0|1|2016-03-16 13:44:05.887212+00:00|None|None" - RespHeader Content-Encoding: gzip - RespHeader X-Varnish: 32790 - RespHeader Age: 0 - RespHeader Via: 1.1 varnish-v4 - VCL_call DELIVER - VCL_return deliver - Timestamp Process: 1458150371.779598 0.020317 0.000028 - RespHeader Accept-Ranges: bytes - RespHeader Content-Length: 426 - Debug "RES_MODE 2" - RespHeader Connection: keep-alive - Timestamp Resp: 1458150371.779641 0.020359 0.000042 - ReqAcct 598 0 598 699 426 1125 - End

The ban list ist then:

ban.list 200 147
Present bans: 1458150360.937187 17 - req.http.host == localhost:8088 && req.url ~ /organisation/xyz/proposal_0000000/team0000000$

I know regular expressions. How can /organisation/xyz/proposal_0000000/comments/comment_0000001/ matches any of the pattern in the ban.list? It does not make sense.

I'm using Varnish 4.1.1

1
varnish

1 Answers

1
votes

The rule that matches your URL is: 

1458150360.910710     0 -  req.http.host == localhost:8088 && req.url ~ /$

regex req.url ~ /$ will match your URL and any other that ends with a slash; use req.url ~ ^/$.

A few observations:

About lurker-friendly ban expressions

read more here

Lurker-friendly ban expressions are those that use only obj., but not req. variables. Since lurker-friendly ban expressions lack of req., you might need to copy some of the req. contents into the obj structure. In fact, this copy operation is a mechanism to preserve the context of client request in the cached object. For example, you may want to copy useful parts of the client context such as the requested URL from req to obj.

The following snippet shows an example on how to preserve the context of a client request in the cached object:

sub vcl_backend_response {
   set beresp.http.x-url = bereq.url;
}

sub vcl_deliver {
   # The X-Url header is for internal use only
   unset resp.http.x-url;
}

Varnish test example for regex:

You can run it with: varnishtest test_regex.vtc

test_regex.vtc content:

# act like a backend server
server s1 {
    rxreq
    txresp
    expect req.url == "/organisation/xyz/proposal_0000000/comments/comment_0000001/"
    expect req.http.Test == "dosent_match" 
} -start

# define & start a varnish instance
varnish v1 -vcl {
    backend default {
    .host = "${s1_addr}";
    .port = "${s1_port}";
    }

    sub vcl_recv {
    if ( req.url ~ "/$" ) {
        set req.http.Test="match";
    } else {
        set req.http.Test="dosent_match";
    }
  }

} -start

# make a client request
client c1 { 

    txreq -url "/organisation/xyz/proposal_0000000/comments/comment_0000001/"
    rxresp

} -run

varnish v1 -expect client_req == 1