Mailing List Archive

On Wed, Apr 26, 2017 at 3:31 PM, Jesper Larsen <jla@fcoo.dk> wrote:
> Hi Varnish people
>
> I use something like this snippet:
>
> sub vcl_recv {
> if (req.url ~ "^\/foo\/") {
> set req.url = regsub(req.url, "^\/foo\/", "/");
> set req.backend_hint = special_backend;
> }
> }
>
> for rewriting req.url before sending the request to the backend. As you can see I simply remove the first portion of the path before sending the request to the backend. For urls not matching the regex I do not change req.url. I have also enabled restarts. I am using the original url in vcl_hash.
>
> But I have noticed that when the "special_backend" is down my default backend gets the request. I suppose the reason is that I have modified req.url. And when the request is restarted it uses this modified url which does not start with "/foo/".
>
> My question is: What would you recommend that I do to avoid this? Should I modify the url in another subroutine?

Hello Jesper,

Could you please describe in more details how to reproduce? Ideally
with just enough VCL. Possibly with the offending transaction's logs.

Please also mention Varnish's version.

Thanks,
Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

Hi Dridi

On Wed, Apr 26, 2017 at 3:46 PM, Dridi Boukelmoune [dridi@varni.sh] wrote:
>Hello Jesper,
>
>Could you please describe in more details how to reproduce? Ideally
>with just enough VCL. Possibly with the offending transaction's logs.

vcl 4.0;

import std;
import directors;

backend default {
.host = "yourbackendip";
.port = "8000";
}

backend special_backend {
.host = "yourbackendip";
.port = "8080";
}

sub vcl_recv {
if (req.url ~ "^\/foo\/") {
set req.url = regsub(req.url, "^\/foo\/", "/");
set req.backend_hint = special_backend;
} else {
set req.backend_hint = default;
}
}

For this test I ran:

$ python -m SimpleHTTPServer 8000

on the backend as a default backend and no server on port 8080.

When I do a request for:

http://varnish_server/foo

I get a 404 from the default backend even though I pressume that the request should time out instead.

Output from Python server:
Serving HTTP on 0.0.0.0 port 8000 ...
172.17.0.2 - - [27/Apr/2017 12:58:44] code 404, message File not found
172.17.0.2 - - [27/Apr/2017 12:58:44] "GET /foo HTTP/1.1" 404 -

Varnish output:
* << BeReq >> 3
- Begin bereq 2 fetch
- Timestamp Start: 1493290724.892610 0.000000 0.000000
- BereqMethod GET
- BereqURL /foo
- BereqProtocol HTTP/1.1
- BereqHeader Host: localhost:9090
- BereqHeader User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:53.0) Gecko/20100101 Firefox/53.0
- BereqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- BereqHeader Accept-Language: en-US,en;q=0.5
- BereqHeader Upgrade-Insecure-Requests: 1
- BereqHeader X-Forwarded-For: 172.17.0.1
- BereqHeader Accept-Encoding: gzip
- BereqHeader X-Varnish: 3
- VCL_call BACKEND_FETCH
- VCL_return fetch
- BackendOpen 24 boot.default 192.168.1.45 8000 172.17.0.2 40436
- BackendStart 192.168.1.45 8000
- Timestamp Bereq: 1493290724.892916 0.000306 0.000306
- Timestamp Beresp: 1493290724.893714 0.001105 0.000799
- BerespProtocol HTTP/1.0
- BerespStatus 404
- BerespReason File not found
- BerespHeader Server: SimpleHTTP/0.6 Python/2.7.12
- BerespHeader Date: Thu, 27 Apr 2017 10:58:44 GMT
- BerespHeader Connection: close
- BerespHeader Content-Type: text/html
- TTL RFC 120 10 -1 1493290725 1493290725 1493290724 0 0
- VCL_call BACKEND_RESPONSE
- VCL_return deliver
- Storage malloc s0
- ObjProtocol HTTP/1.0
- ObjStatus 404
- ObjReason File not found
- ObjHeader Server: SimpleHTTP/0.6 Python/2.7.12
- ObjHeader Date: Thu, 27 Apr 2017 10:58:44 GMT
- ObjHeader Content-Type: text/html
- Fetch_Body 4 eof stream
- BackendClose 24 boot.default
- Timestamp BerespBody: 1493290724.893893 0.001284 0.000179
- Length 195
- BereqAcct 335 0 335 150 195 345
- End

* << Request >> 2
- Begin req 1 rxreq
- Timestamp Start: 1493290724.892466 0.000000 0.000000
- Timestamp Req: 1493290724.892466 0.000000 0.000000
- ReqStart 172.17.0.1 46312
- ReqMethod GET
- ReqURL /foo
- ReqProtocol HTTP/1.1
- ReqHeader Host: localhost:9090
- ReqHeader User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:53.0) Gecko/20100101 Firefox/53.0
- ReqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- ReqHeader Accept-Language: en-US,en;q=0.5
- ReqHeader Accept-Encoding: gzip, deflate
- ReqHeader Connection: keep-alive
- ReqHeader Upgrade-Insecure-Requests: 1
- ReqHeader Cache-Control: max-age=0
- ReqHeader X-Forwarded-For: 172.17.0.1
- VCL_call RECV
- VCL_return hash
- ReqUnset Accept-Encoding: gzip, deflate
- ReqHeader Accept-Encoding: gzip
- VCL_call HASH
- VCL_return lookup
- VCL_call MISS
- VCL_return fetch
- Link bereq 3 fetch
- Timestamp Fetch: 1493290724.893937 0.001471 0.001471
- RespProtocol HTTP/1.0
- RespStatus 404
- RespReason File not found
- RespHeader Server: SimpleHTTP/0.6 Python/2.7.12
- RespHeader Date: Thu, 27 Apr 2017 10:58:44 GMT
- RespHeader Content-Type: text/html
- RespProtocol HTTP/1.1
- RespHeader X-Varnish: 2
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish-v4
- VCL_call DELIVER
- VCL_return deliver
- Timestamp Process: 1493290724.894007 0.001541 0.000070
- RespHeader Content-Length: 195
- Debug "RES_MODE 2"
- RespHeader Connection: keep-alive
- Timestamp Resp: 1493290724.894064 0.001598 0.000057
- ReqAcct 351 0 351 219 195 414
- End

* << Session >> 1
- Begin sess 0 HTTP/1
- SessOpen 172.17.0.1 46312 :80 172.17.0.2 80 1493290724.892237 16
- Link req 2 rxreq
- SessClose RX_TIMEOUT 5.007
- End

>Please also mention Varnish's version.

varnishd (varnish-4.1.3 revision 5e3b6d2)

>Thanks,
>Dridi

Best regards,
Jesper
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

> sub vcl_recv {
> if (req.url ~ "^\/foo\/") {

Here you are looking for /foo/ at the beginning of the URL.

> set req.url = regsub(req.url, "^\/foo\/", "/");
> set req.backend_hint = special_backend;
> } else {
> set req.backend_hint = default;
> }
> }
>
> For this test I ran:
>
> $ python -m SimpleHTTPServer 8000
>
> on the backend as a default backend and no server on port 8080.
>
> When I do a request for:
>
> http://varnish_server/foo

And here you are send /foo, which won't match.

> varnishd (varnish-4.1.3 revision 5e3b6d2)

You should also upgrade to 4.1.6 released today.

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

Hi again Dridi

>> sub vcl_recv {
>> if (req.url ~ "^\/foo\/") {
>
>Here you are looking for /foo/ at the beginning of the URL.
<snip>
>And here you are send /foo, which won't match.

Yes, sorry about that. When I request /foo/ it works with the config file you got. But it does not work with this one:

vcl 4.0;

import std;
import directors;

backend default {
.host = "whatever";
.port = "8000";
}

backend special_backend {
.host = "whatever";
.port = "8080";
}

sub vcl_recv {
if (req.url ~ "^\/foo\/") {
set req.url = regsub(req.url, "^\/foo\/", "/");
set req.backend_hint = special_backend;
} else {
set req.backend_hint = default;
}
}

sub vcl_deliver {
# Restart if backend has returned an error message
if (resp.status >= 500 && req.restarts < 4) {
return(restart);
}
}

The difference it the vcl_deliver subroutine where I restart the request on 5xx errors. And these restarted requests seem to use the modified req.url for the restarted request.

* << BeReq >> 3
- Begin bereq 2 fetch
- Timestamp Start: 1493294118.610413 0.000000 0.000000
- BereqMethod GET
- BereqURL /
- BereqProtocol HTTP/1.1
- BereqHeader Host: localhost:9090
- BereqHeader User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:53.0) Gecko/20100101 Firefox/53.0
- BereqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- BereqHeader Accept-Language: en-US,en;q=0.5
- BereqHeader Upgrade-Insecure-Requests: 1
- BereqHeader X-Forwarded-For: 172.17.0.1
- BereqHeader Accept-Encoding: gzip
- BereqHeader X-Varnish: 3
- VCL_call BACKEND_FETCH
- VCL_return fetch
- FetchError no backend connection
- Timestamp Beresp: 1493294118.610523 0.000109 0.000109
- Timestamp Error: 1493294118.610528 0.000114 0.000005
- BerespProtocol HTTP/1.1
- BerespStatus 503
- BerespReason Service Unavailable
- BerespReason Backend fetch failed
- BerespHeader Date: Thu, 27 Apr 2017 11:55:18 GMT
- BerespHeader Server: Varnish
- VCL_call BACKEND_ERROR
- BerespHeader Content-Type: text/html; charset=utf-8
- BerespHeader Retry-After: 5
- VCL_return deliver
- Storage malloc Transient
- ObjProtocol HTTP/1.1
- ObjStatus 503
- ObjReason Backend fetch failed
- ObjHeader Date: Thu, 27 Apr 2017 11:55:18 GMT
- ObjHeader Server: Varnish
- ObjHeader Content-Type: text/html; charset=utf-8
- ObjHeader Retry-After: 5
- Length 278
- BereqAcct 0 0 0 0 0 0
- End

* << Request >> 2
- Begin req 1 rxreq
- Timestamp Start: 1493294118.610336 0.000000 0.000000
- Timestamp Req: 1493294118.610336 0.000000 0.000000
- ReqStart 172.17.0.1 46896
- ReqMethod GET
- ReqURL /foo/
- ReqProtocol HTTP/1.1
- ReqHeader Host: localhost:9090
- ReqHeader User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:53.0) Gecko/20100101 Firefox/53.0
- ReqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- ReqHeader Accept-Language: en-US,en;q=0.5
- ReqHeader Accept-Encoding: gzip, deflate
- ReqHeader Connection: keep-alive
- ReqHeader Upgrade-Insecure-Requests: 1
- ReqHeader Cache-Control: max-age=0
- ReqHeader X-Forwarded-For: 172.17.0.1
- VCL_call RECV
- ReqURL /
- VCL_return hash
- ReqUnset Accept-Encoding: gzip, deflate
- ReqHeader Accept-Encoding: gzip
- VCL_call HASH
- VCL_return lookup
- VCL_call MISS
- VCL_return fetch
- Link bereq 3 fetch
- Timestamp Fetch: 1493294118.610608 0.000273 0.000273
- RespProtocol HTTP/1.1
- RespStatus 503
- RespReason Backend fetch failed
- RespHeader Date: Thu, 27 Apr 2017 11:55:18 GMT
- RespHeader Server: Varnish
- RespHeader Content-Type: text/html; charset=utf-8
- RespHeader Retry-After: 5
- RespHeader X-Varnish: 2
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish-v4
- VCL_call DELIVER
- VCL_return restart
- Timestamp Process: 1493294118.610649 0.000313 0.000041
- Timestamp Restart: 1493294118.610655 0.000319 0.000006
- Link req 4 restart
- End

* << BeReq >> 5
- Begin bereq 4 fetch
- Timestamp Start: 1493294118.610691 0.000000 0.000000
- BereqMethod GET
- BereqURL /
- BereqProtocol HTTP/1.1
- BereqHeader Host: localhost:9090
- BereqHeader User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:53.0) Gecko/20100101 Firefox/53.0
- BereqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- BereqHeader Accept-Language: en-US,en;q=0.5
- BereqHeader Upgrade-Insecure-Requests: 1
- BereqHeader X-Forwarded-For: 172.17.0.1
- BereqHeader Accept-Encoding: gzip
- BereqHeader X-Varnish: 5
- VCL_call BACKEND_FETCH
- VCL_return fetch
- BackendOpen 24 boot.default 192.168.1.45 8000 172.17.0.2 41022
- BackendStart 192.168.1.45 8000
- Timestamp Bereq: 1493294118.610834 0.000143 0.000143
- Timestamp Beresp: 1493294118.611334 0.000644 0.000501
- BerespProtocol HTTP/1.0
- BerespStatus 200
- BerespReason OK
- BerespHeader Server: SimpleHTTP/0.6 Python/2.7.12
- BerespHeader Date: Thu, 27 Apr 2017 11:55:18 GMT
- BerespHeader Content-type: text/html; charset=UTF-8
- BerespHeader Content-Length: 348
- TTL RFC 120 10 -1 1493294119 1493294119 1493294118 0 0
- VCL_call BACKEND_RESPONSE
- VCL_return deliver
- Storage malloc s0
- ObjProtocol HTTP/1.0
- ObjStatus 200
- ObjReason OK
- ObjHeader Server: SimpleHTTP/0.6 Python/2.7.12
- ObjHeader Date: Thu, 27 Apr 2017 11:55:18 GMT
- ObjHeader Content-type: text/html; charset=UTF-8
- ObjHeader Content-Length: 348
- Fetch_Body 3 length stream
- BackendClose 24 boot.default
- Timestamp BerespBody: 1493294118.611433 0.000742 0.000099
- Length 348
- BereqAcct 332 0 332 155 348 503
- End

* << Request >> 4
- Begin req 2 restart
- Timestamp Start: 1493294118.610655 0.000319 0.000000
- ReqStart 172.17.0.1 46896
- ReqMethod GET
- ReqURL /
- ReqProtocol HTTP/1.1
- ReqHeader Host: localhost:9090
- ReqHeader User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:53.0) Gecko/20100101 Firefox/53.0
- ReqHeader Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- ReqHeader Accept-Language: en-US,en;q=0.5
- ReqHeader Connection: keep-alive
- ReqHeader Upgrade-Insecure-Requests: 1
- ReqHeader Cache-Control: max-age=0
- ReqHeader X-Forwarded-For: 172.17.0.1
- ReqHeader Accept-Encoding: gzip
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- VCL_call MISS
- VCL_return fetch
- Link bereq 5 fetch
- Timestamp Fetch: 1493294118.611446 0.001110 0.000791
- RespProtocol HTTP/1.0
- RespStatus 200
- RespReason OK
- RespHeader Server: SimpleHTTP/0.6 Python/2.7.12
- RespHeader Date: Thu, 27 Apr 2017 11:55:18 GMT
- RespHeader Content-type: text/html; charset=UTF-8
- RespHeader Content-Length: 348
- RespProtocol HTTP/1.1
- RespHeader X-Varnish: 4
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish-v4
- VCL_call DELIVER
- VCL_return deliver
- Timestamp Process: 1493294118.611479 0.001143 0.000033
- RespHeader Accept-Ranges: bytes
- Debug "RES_MODE 2"
- RespHeader Connection: keep-alive
- Timestamp Resp: 1493294118.611523 0.001187 0.000044
- ReqAcct 352 0 352 244 348 592
- End

I guess a solution for this issue is to store the original req.url and set it to the original value again in vcl_deliver in case of a restart?

>Dridi

Jesper
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

> Yes, sorry about that. When I request /foo/ it works with the config file you got. But it does not work with this one:

OK, time to take a step back, I misread your first email:

> And when the request is restarted it uses this modified url [...]

Yes, the request remains as-is after a restart, that is intentional. I
thought I had read that in some cases you didn't get the modifications
after a restart, still not getting the hang of this "reading" thing.

If you want to reset req, use the std.rollback function before
returning restart.

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

<snip>
>Yes, the request remains as-is after a restart, that is intentional. I
>thought I had read that in some cases you didn't get the modifications
>after a restart, still not getting the hang of this "reading" thing.
>
>If you want to reset req, use the std.rollback function before
>returning restart.

Great the std.rollback solves the issue. Thanks for quick and competent help to a varnish rookie:-)

>Dridi

Jesper


_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc