Mailing List Archive

HIT after PURGE & Restart
I have a strange problem, where it seems that purged objects are not
being purged immediately, so the restarted request hits the object that
was supposed to be purged, and then the next request for that object
misses. Here are the relevant fields from a set of requests for the same
object showing the sequence. That second restarted request should not be
getting a hit, since it is a restart from a purge of that same object.

This is CentOS 7/Varnish 4.0.4. No varying except on Accept-Encoding.
Very little VCL. All cookies are removed in VCL_recv. TTL is set to 7
days in vcl_backend_response on anything that comes back with a 200 or 304.

Any input greatly appreciated. It only seems to happen on images.

--

My VCL_purge is:

sub vcl_purge {
set req.method = "GET";
return (restart);
}

In VCL_recv I have:

if (req.method == "PURGE") {
if (!client.ip ~ purgers) {
return (synth(405, "Purging not allowed for " + client.ip));
}
return (purge);
}

--

* << Request >> 100892
- Begin req 100891 rxreq
- ReqMethod PURGE
- VCL_call RECV
- VCL_return purge
- VCL_call HASH
- VCL_return lookup
- VCL_call PURGE
- ReqMethod GET
- VCL_return restart
- Timestamp Restart: 1492038073.166852 0.000092 0.000092
- Link req 100893 restart
- End

* << Request >> 100893
- Begin req 100892 restart
- ReqMethod GET
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- Hit 100603
- VCL_call HIT
- VCL_return deliver
- VCL_call DELIVER
- VCL_return deliver
- Timestamp Process: 1492038073.166894 0.000133 0.000041
- Debug "RES_MODE 2"
- Timestamp Resp: 1492038073.166977 0.000216 0.000083
- Debug "XXX REF 2"
- ReqAcct 275 0 275 347 4481 4828
- End

* << Request >> 364403
- Begin req 364402 rxreq
- ReqMethod GET
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- Debug "XXXX MISS"
- VCL_call MISS
- VCL_return fetch
- VCL_call DELIVER
- RespHeader X-Cache: MISS
- VCL_return deliver
- Timestamp Process: 1492046821.365675 0.003335 0.000031
- Debug "RES_MODE 2"
- Timestamp Resp: 1492046821.365740 0.003400 0.000065
- Debug "XXX REF 2"
- ReqAcct 545 0 545 323 4481 4804
- End

* << Request >> 364767
- Begin req 364766 rxreq
- ReqMethod GET
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- Hit 364404
- VCL_call HIT
- VCL_return deliver
- VCL_call DELIVER
- RespHeader X-Cache: HIT
- VCL_return deliver
- Timestamp Process: 1492056635.579030 0.000051 0.000051
- Debug "RES_MODE 2"
- Timestamp Resp: 1492056635.579060 0.000081 0.000031
- Debug "XXX REF 2"
- ReqAcct 487 0 487 349 4481 4830
- End

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: HIT after PURGE & Restart [ In reply to ]
Is there any chance that:
- someone requested the object between the purge and the subsequent hit?
- you re-processed the request again, changing the cache (non-idempotent
URL rewrite, maybe?)

--
Guillaume Quintard

On Thu, Apr 13, 2017 at 8:21 AM, Nigel Peck <np.lists@sharphosting.uk>
wrote:

>
> I have a strange problem, where it seems that purged objects are not being
> purged immediately, so the restarted request hits the object that was
> supposed to be purged, and then the next request for that object misses.
> Here are the relevant fields from a set of requests for the same object
> showing the sequence. That second restarted request should not be getting a
> hit, since it is a restart from a purge of that same object.
>
> This is CentOS 7/Varnish 4.0.4. No varying except on Accept-Encoding. Very
> little VCL. All cookies are removed in VCL_recv. TTL is set to 7 days in
> vcl_backend_response on anything that comes back with a 200 or 304.
>
> Any input greatly appreciated. It only seems to happen on images.
>
> --
>
> My VCL_purge is:
>
> sub vcl_purge {
> set req.method = "GET";
> return (restart);
> }
>
> In VCL_recv I have:
>
> if (req.method == "PURGE") {
> if (!client.ip ~ purgers) {
> return (synth(405, "Purging not allowed for " + client.ip));
> }
> return (purge);
> }
>
> --
>
> * << Request >> 100892
> - Begin req 100891 rxreq
> - ReqMethod PURGE
> - VCL_call RECV
> - VCL_return purge
> - VCL_call HASH
> - VCL_return lookup
> - VCL_call PURGE
> - ReqMethod GET
> - VCL_return restart
> - Timestamp Restart: 1492038073.166852 0.000092 0.000092
> - Link req 100893 restart
> - End
>
> * << Request >> 100893
> - Begin req 100892 restart
> - ReqMethod GET
> - VCL_call RECV
> - VCL_return hash
> - VCL_call HASH
> - VCL_return lookup
> - Hit 100603
> - VCL_call HIT
> - VCL_return deliver
> - VCL_call DELIVER
> - VCL_return deliver
> - Timestamp Process: 1492038073.166894 0.000133 0.000041
> - Debug "RES_MODE 2"
> - Timestamp Resp: 1492038073.166977 0.000216 0.000083
> - Debug "XXX REF 2"
> - ReqAcct 275 0 275 347 4481 4828
> - End
>
> * << Request >> 364403
> - Begin req 364402 rxreq
> - ReqMethod GET
> - VCL_call RECV
> - VCL_return hash
> - VCL_call HASH
> - VCL_return lookup
> - Debug "XXXX MISS"
> - VCL_call MISS
> - VCL_return fetch
> - VCL_call DELIVER
> - RespHeader X-Cache: MISS
> - VCL_return deliver
> - Timestamp Process: 1492046821.365675 0.003335 0.000031
> - Debug "RES_MODE 2"
> - Timestamp Resp: 1492046821.365740 0.003400 0.000065
> - Debug "XXX REF 2"
> - ReqAcct 545 0 545 323 4481 4804
> - End
>
> * << Request >> 364767
> - Begin req 364766 rxreq
> - ReqMethod GET
> - VCL_call RECV
> - VCL_return hash
> - VCL_call HASH
> - VCL_return lookup
> - Hit 364404
> - VCL_call HIT
> - VCL_return deliver
> - VCL_call DELIVER
> - RespHeader X-Cache: HIT
> - VCL_return deliver
> - Timestamp Process: 1492056635.579030 0.000051 0.000051
> - Debug "RES_MODE 2"
> - Timestamp Resp: 1492056635.579060 0.000081 0.000031
> - Debug "XXX REF 2"
> - ReqAcct 487 0 487 349 4481 4830
> - End
>
> _______________________________________________
> varnish-misc mailing list
> varnish-misc@varnish-cache.org
> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>
Re: HIT after PURGE & Restart [ In reply to ]
On Thu, Apr 13, 2017 at 8:48 AM, Guillaume Quintard
<guillaume@varnish-software.com> wrote:
> Is there any chance that:
> - someone requested the object between the purge and the subsequent hit?
> - you re-processed the request again, changing the cache (non-idempotent URL
> rewrite, maybe?)

At first glance things look OK on 4.0, 4.1, 5.0 and 5.1:

varnishtest "purge+restart should miss"

server s1 {
rxreq
txresp -body first

rxreq
txresp -body second
} -start

varnish v1 -vcl+backend {
sub vcl_recv {
if (req.method == "PURGE") {
return (purge);
}
}

sub vcl_purge {
set req.method = "GET";
return (restart);
}
} -start

client c1 {
txreq
rxresp
expect resp.body == first

txreq -req PURGE
rxresp
expect resp.body == second
} -run

I will try a more involved test later on.

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: HIT after PURGE & Restart [ In reply to ]
Thanks for this, really helpful to have the assistance. There's no
chance that the object was requested between the purge and hit, because
those log entries are from a simple varnishlog query for the specific URI.

varnishlog -d -q "ReqURL eq '/media/images/logo-glyph-2x.png'"

So it would be shown in the log.

I don't think there's anything in my VCL that is causing this. But I'm
including it all below in case and to help in diagnosing this.

Regarding the test, Dridi, I wouldn't expect that to fail. This is not
happening in the majority of cases. But what is happening is that I'm
monitoring the log for any misses, and noticed that there are
unexplainable misses sometimes. I have a script that issues a PURGE
request for every URI on the site, with TTL being set to 7 days, so
nothing should be getting missed, yet sometimes things are. After a few
days looking at these misses from various angles, to try and work out
what's going on, the description in my original message *seems* to be
what is happening. There is no Vary issue since nothing is varied on,
and all cookies are removed in VCL_recv. They are definitely being
cached with the 7d TTL. So there should be no need for a miss.

The real issue for me is the miss on something that has been purged and
re-cached a short time before, but the purge and subsequent HIT seems to
be related to the problem.

I just checked the log again and there are no fresh misses since
yesterday, which confirms the theory that this is related to the PURGE
and otherwise all ok.

I also included below a second example of the same thing from yesterday.
It's not a high traffic site, so I may need to spend some more time
gathering info, but I think I have enough to present to you, hence the
query. Thanks again.

=======
VCL
(very simple as mentioned)
=======

vcl 4.0;
import std;

# Default backend definition. Set this to point to your content server.
backend default {
.host = "x.x.x.x";
.port = "80";
}

# Access list for purging, local only
acl purgers {
"127.0.0.1";
"x.x.x.x";
}

# Process any "PURGE" requests converting
# them to GET and restarting
sub vcl_purge {
set req.method = "GET";
return (restart);
}

sub vcl_synth {
# Handle 301 redirects, taking reason as the URL
# and then replacing it with the standard reason
# Recommended at:
# https://varnish-cache.org/tips/vcl/redirect.html
if (resp.status == 301) {
set resp.http.location = resp.reason;
set resp.reason = "Moved Permanently";
return (deliver);
}
}

sub vcl_recv {
# Server_Name was here
if (req.restarts == 0) {
set req.http.X-Processed-By = "Server_Name";
}
# allow PURGE from localhost and x.x.x.x
if (req.method == "PURGE") {
if (!client.ip ~ purgers) {
return (synth(405, "Purging not allowed for " + client.ip));
}
return (purge);
}
# Forward client's IP to the backend
if (req.restarts == 0) {
if (req.http.X-Real-IP) {
# Do nothing, we already have all we need recorded
} elsif (req.http.X-Forwarded-For) {
set req.http.X-Forwarded-For = req.http.X-Forwarded-For +
", " + client.ip;
} else {
set req.http.X-Forwarded-For = client.ip;
}
}
# Redirect non-HTTPS to HTTPS
# Identified by the fact it does not have the X-Forwarded-Port header
if (req.http.X-Forwarded-Port != "443") {
return (synth(301, "https://www.example.com" + req.url));
}

# Unset all cookies
unset req.http.Cookie;

}

sub vcl_backend_response {

# Server_Name was here
set beresp.http.X-Processed-By = "Server_Name";

# Don't cache 404 responses
if ( beresp.status == 404 ) {
set beresp.ttl = 120s;
set beresp.uncacheable = true;
return (deliver);
}

# Compress appropriate responses
if (beresp.http.content-type ~
"\b((text/(html|plain|css|javascript|xml|xsl))|(application/(javascript|xml|xhtml\+xml)))\b")
{
set beresp.do_gzip = true;
}

# Set long TTL and grace time for 200 and 304 responses
if ( beresp.status == 200 || beresp.status == 304 ) {

# Allow stale content, in case the backend goes down
set beresp.grace = 6h;

# This is how long Varnish will keep cached content
set beresp.ttl = 7d;
}

}

sub vcl_deliver {
# Send special headers that indicate the cache status of each response
if (obj.hits > 0) {
set resp.http.X-Cache = "HIT";
set resp.http.X-Cache-Hits = obj.hits;
} else {
set resp.http.X-Cache = "MISS";
}

return (deliver);
}

=======
Second Example
=======

* << Request >> 230660
- Begin req 230659 rxreq
- Timestamp Start: 1492038071.998363 0.000000 0.000000
- Timestamp Req: 1492038071.998363 0.000000 0.000000
- ReqMethod PURGE
- VCL_call RECV
- VCL_return purge
- VCL_call HASH
- VCL_return lookup
- VCL_call PURGE
- ReqMethod GET
- VCL_return restart
- Timestamp Restart: 1492038071.998436 0.000074 0.000074
- Link req 230661 restart
- End

* << Request >> 230661
- Begin req 230660 restart
- Timestamp Start: 1492038071.998436 0.000074 0.000000
- ReqMethod GET
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- Hit 167648
- VCL_call HIT
- VCL_return deliver
- VCL_call DELIVER
- RespHeader X-Cache: HIT
- RespHeader X-Cache-Hits: 1
- VCL_return deliver
- Timestamp Process: 1492038071.998474 0.000112 0.000038
- Debug "RES_MODE 2"
- Timestamp Resp: 1492038071.998528 0.000166 0.000054
- Debug "XXX REF 2"
- ReqAcct 269 0 269 346 1538 1884
- End

* << Request >> 364940
- Begin req 364939 rxreq
- Timestamp Start: 1492060849.803654 0.000000 0.000000
- Timestamp Req: 1492060849.803654 0.000000 0.000000
- ReqMethod GET
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- Debug "XXXX MISS"
- VCL_call MISS
- VCL_return fetch
- Link bereq 364941 fetch
- Timestamp Fetch: 1492060849.805443 0.001789 0.001789
- VCL_call DELIVER
- RespHeader X-Cache: MISS
- VCL_return deliver
- Timestamp Process: 1492060849.805531 0.001876 0.000087
- Debug "RES_MODE 2"
- RespHeader Connection: close
- RespHeader Accept-Ranges: bytes
- Timestamp Resp: 1492060849.805594 0.001939 0.000063
- Debug "XXX REF 2"
- ReqAcct 347 0 347 322 1538 1860
- End

* << Request >> 364994
- Begin req 364993 rxreq
- Timestamp Start: 1492061706.708306 0.000000 0.000000
- Timestamp Req: 1492061706.708306 0.000000 0.000000
- ReqMethod GET
- VCL_call RECV
- VCL_return hash
- VCL_call HASH
- VCL_return lookup
- Hit 364941
- VCL_call HIT
- VCL_return deliver
- VCL_call DELIVER
- RespHeader X-Cache: HIT
- RespHeader X-Cache-Hits: 1
- VCL_return deliver
- Timestamp Process: 1492061706.708382 0.000076 0.000076
- Debug "RES_MODE 2"
- RespHeader Connection: close
- RespHeader Accept-Ranges: bytes
- Timestamp Resp: 1492061706.708417 0.000111 0.000035
- Debug "XXX REF 2"
- ReqAcct 447 0 447 347 1538 1885
- End

On 13/04/2017 07:45, Dridi Boukelmoune wrote:
> On Thu, Apr 13, 2017 at 8:48 AM, Guillaume Quintard
> <guillaume@varnish-software.com> wrote:
>> Is there any chance that:
>> - someone requested the object between the purge and the subsequent hit?
>> - you re-processed the request again, changing the cache (non-idempotent URL
>> rewrite, maybe?)
>
> At first glance things look OK on 4.0, 4.1, 5.0 and 5.1:
>
> varnishtest "purge+restart should miss"
>
> server s1 {
> rxreq
> txresp -body first
>
> rxreq
> txresp -body second
> } -start
>
> varnish v1 -vcl+backend {
> sub vcl_recv {
> if (req.method == "PURGE") {
> return (purge);
> }
> }
>
> sub vcl_purge {
> set req.method = "GET";
> return (restart);
> }
> } -start
>
> client c1 {
> txreq
> rxresp
> expect resp.body == first
>
> txreq -req PURGE
> rxresp
> expect resp.body == second
> } -run
>
> I will try a more involved test later on.
>
> Dridi
>

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: HIT after PURGE & Restart [ In reply to ]
On Thu, Apr 13, 2017 at 11:26 PM, Nigel Peck <np.lists@sharphosting.uk> wrote:
>
> Thanks for this, really helpful to have the assistance. There's no chance
> that the object was requested between the purge and hit, because those log
> entries are from a simple varnishlog query for the specific URI.
>
> varnishlog -d -q "ReqURL eq '/media/images/logo-glyph-2x.png'"
>
> So it would be shown in the log.

Focus on the URL might be a hint of something going on with the host
header. Since your VCL relies solely on the built-in for hashing,
please bear in mind that the host is part of the cache key. You can
enable Hash records in the log (man varnishd) or simply look at the
Host+URL combo.

> I don't think there's anything in my VCL that is causing this. But I'm
> including it all below in case and to help in diagnosing this.
>
> Regarding the test, Dridi, I wouldn't expect that to fail.

I went ahead and tried to tickle the purge further by purging a
resource while it's referenced by another transaction and couldn't
get a spurious hit. I needed some synchronization and since 4.0 is
EOL and it doesn't have barriers in varnishtest, I didn't feel like
adapting the test to the good old semas.

> This is not
> happening in the majority of cases. But what is happening is that I'm
> monitoring the log for any misses, and noticed that there are unexplainable
> misses sometimes. I have a script that issues a PURGE request for every URI
> on the site, with TTL being set to 7 days, so nothing should be getting
> missed, yet sometimes things are. After a few days looking at these misses
> from various angles, to try and work out what's going on, the description in
> my original message *seems* to be what is happening. There is no Vary issue
> since nothing is varied on, and all cookies are removed in VCL_recv. They
> are definitely being cached with the 7d TTL. So there should be no need for
> a miss.

Regarding unexpected misses, objects could be evicted forcefully to
make space during insertions. See n_lru_nuked (man varnish-counters).

> The real issue for me is the miss on something that has been purged and
> re-cached a short time before, but the purge and subsequent HIT seems to be
> related to the problem.

Yes, but with truncated logs, it's hard to tell further.

> I just checked the log again and there are no fresh misses since yesterday,
> which confirms the theory that this is related to the PURGE and otherwise
> all ok.
>
> I also included below a second example of the same thing from yesterday.
> It's not a high traffic site, so I may need to spend some more time
> gathering info, but I think I have enough to present to you, hence the
> query. Thanks again.

Please don't send more, we're no longer supporting 4.0 and I would
recommend an upgrade to 4.1, especially with VCL looking simple
enough.

> =======
> VCL
> (very simple as mentioned)
> =======
>
> vcl 4.0;
> import std;
>
> # Default backend definition. Set this to point to your content server.
> backend default {
> .host = "x.x.x.x";
> .port = "80";
> }
>
> # Access list for purging, local only
> acl purgers {
> "127.0.0.1";
> "x.x.x.x";
> }
>
> # Process any "PURGE" requests converting
> # them to GET and restarting
> sub vcl_purge {
> set req.method = "GET";
> return (restart);
> }
>
> sub vcl_synth {
> # Handle 301 redirects, taking reason as the URL
> # and then replacing it with the standard reason
> # Recommended at:
> # https://varnish-cache.org/tips/vcl/redirect.html
> if (resp.status == 301) {
> set resp.http.location = resp.reason;
> set resp.reason = "Moved Permanently";
> return (deliver);
> }
> }
>
> sub vcl_recv {
> # Server_Name was here
> if (req.restarts == 0) {
> set req.http.X-Processed-By = "Server_Name";
> }

You can use the server.identity variable instead of hard-coding it in
VCL (see man vcl).

> # allow PURGE from localhost and x.x.x.x
> if (req.method == "PURGE") {
> if (!client.ip ~ purgers) {
> return (synth(405, "Purging not allowed for " + client.ip));
> }
> return (purge);
> }
> # Forward client's IP to the backend
> if (req.restarts == 0) {
> if (req.http.X-Real-IP) {
> # Do nothing, we already have all we need recorded
> } elsif (req.http.X-Forwarded-For) {
> set req.http.X-Forwarded-For = req.http.X-Forwarded-For + ", " +
> client.ip;
> } else {
> set req.http.X-Forwarded-For = client.ip;
> }
> }

This is Varnish 4.0, you don't need to update the XFF header in VCL.

> # Redirect non-HTTPS to HTTPS
> # Identified by the fact it does not have the X-Forwarded-Port header
> if (req.http.X-Forwarded-Port != "443") {
> return (synth(301, "https://www.example.com" + req.url));
> }
>
> # Unset all cookies
> unset req.http.Cookie;
>
> }
>
> sub vcl_backend_response {
>
> # Server_Name was here
> set beresp.http.X-Processed-By = "Server_Name";

See comment above about the server.identity variable.

>
> # Don't cache 404 responses
> if ( beresp.status == 404 ) {
> set beresp.ttl = 120s;
> set beresp.uncacheable = true;
> return (deliver);
> }
>
> # Compress appropriate responses
> if (beresp.http.content-type ~
> "\b((text/(html|plain|css|javascript|xml|xsl))|(application/(javascript|xml|xhtml\+xml)))\b")
> {
> set beresp.do_gzip = true;
> }
>
> # Set long TTL and grace time for 200 and 304 responses
> if ( beresp.status == 200 || beresp.status == 304 ) {
>
> # Allow stale content, in case the backend goes down
> set beresp.grace = 6h;
>
> # This is how long Varnish will keep cached content
> set beresp.ttl = 7d;
> }
>
> }
>
> sub vcl_deliver {
> # Send special headers that indicate the cache status of each response
> if (obj.hits > 0) {
> set resp.http.X-Cache = "HIT";
> set resp.http.X-Cache-Hits = obj.hits;
> } else {
> set resp.http.X-Cache = "MISS";
> }

You don't need a shiny HIT or MISS in the response. The X-Varnish
header will tell you that already: one id is a miss, two of them a
hit.

Dridi

_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: HIT after PURGE & Restart [ In reply to ]
This is great, thanks Dridi for all the awesome tips!

Nigel

> On 14 Apr 2017, at 08:11, Dridi Boukelmoune <dridi@varni.sh> wrote:
>
>> On Thu, Apr 13, 2017 at 11:26 PM, Nigel Peck <np.lists@sharphosting.uk> wrote:
>>
>> Thanks for this, really helpful to have the assistance. There's no chance
>> that the object was requested between the purge and hit, because those log
>> entries are from a simple varnishlog query for the specific URI.
>>
>> varnishlog -d -q "ReqURL eq '/media/images/logo-glyph-2x.png'"
>>
>> So it would be shown in the log.
>
> Focus on the URL might be a hint of something going on with the host
> header. Since your VCL relies solely on the built-in for hashing,
> please bear in mind that the host is part of the cache key. You can
> enable Hash records in the log (man varnishd) or simply look at the
> Host+URL combo.
>
>> I don't think there's anything in my VCL that is causing this. But I'm
>> including it all below in case and to help in diagnosing this.
>>
>> Regarding the test, Dridi, I wouldn't expect that to fail.
>
> I went ahead and tried to tickle the purge further by purging a
> resource while it's referenced by another transaction and couldn't
> get a spurious hit. I needed some synchronization and since 4.0 is
> EOL and it doesn't have barriers in varnishtest, I didn't feel like
> adapting the test to the good old semas.
>
>> This is not
>> happening in the majority of cases. But what is happening is that I'm
>> monitoring the log for any misses, and noticed that there are unexplainable
>> misses sometimes. I have a script that issues a PURGE request for every URI
>> on the site, with TTL being set to 7 days, so nothing should be getting
>> missed, yet sometimes things are. After a few days looking at these misses
>> from various angles, to try and work out what's going on, the description in
>> my original message *seems* to be what is happening. There is no Vary issue
>> since nothing is varied on, and all cookies are removed in VCL_recv. They
>> are definitely being cached with the 7d TTL. So there should be no need for
>> a miss.
>
> Regarding unexpected misses, objects could be evicted forcefully to
> make space during insertions. See n_lru_nuked (man varnish-counters).
>
>> The real issue for me is the miss on something that has been purged and
>> re-cached a short time before, but the purge and subsequent HIT seems to be
>> related to the problem.
>
> Yes, but with truncated logs, it's hard to tell further.
>
>> I just checked the log again and there are no fresh misses since yesterday,
>> which confirms the theory that this is related to the PURGE and otherwise
>> all ok.
>>
>> I also included below a second example of the same thing from yesterday.
>> It's not a high traffic site, so I may need to spend some more time
>> gathering info, but I think I have enough to present to you, hence the
>> query. Thanks again.
>
> Please don't send more, we're no longer supporting 4.0 and I would
> recommend an upgrade to 4.1, especially with VCL looking simple
> enough.
>
>> =======
>> VCL
>> (very simple as mentioned)
>> =======
>>
>> vcl 4.0;
>> import std;
>>
>> # Default backend definition. Set this to point to your content server.
>> backend default {
>> .host = "x.x.x.x";
>> .port = "80";
>> }
>>
>> # Access list for purging, local only
>> acl purgers {
>> "127.0.0.1";
>> "x.x.x.x";
>> }
>>
>> # Process any "PURGE" requests converting
>> # them to GET and restarting
>> sub vcl_purge {
>> set req.method = "GET";
>> return (restart);
>> }
>>
>> sub vcl_synth {
>> # Handle 301 redirects, taking reason as the URL
>> # and then replacing it with the standard reason
>> # Recommended at:
>> # https://varnish-cache.org/tips/vcl/redirect.html
>> if (resp.status == 301) {
>> set resp.http.location = resp.reason;
>> set resp.reason = "Moved Permanently";
>> return (deliver);
>> }
>> }
>>
>> sub vcl_recv {
>> # Server_Name was here
>> if (req.restarts == 0) {
>> set req.http.X-Processed-By = "Server_Name";
>> }
>
> You can use the server.identity variable instead of hard-coding it in
> VCL (see man vcl).
>
>> # allow PURGE from localhost and x.x.x.x
>> if (req.method == "PURGE") {
>> if (!client.ip ~ purgers) {
>> return (synth(405, "Purging not allowed for " + client.ip));
>> }
>> return (purge);
>> }
>> # Forward client's IP to the backend
>> if (req.restarts == 0) {
>> if (req.http.X-Real-IP) {
>> # Do nothing, we already have all we need recorded
>> } elsif (req.http.X-Forwarded-For) {
>> set req.http.X-Forwarded-For = req.http.X-Forwarded-For + ", " +
>> client.ip;
>> } else {
>> set req.http.X-Forwarded-For = client.ip;
>> }
>> }
>
> This is Varnish 4.0, you don't need to update the XFF header in VCL.
>
>> # Redirect non-HTTPS to HTTPS
>> # Identified by the fact it does not have the X-Forwarded-Port header
>> if (req.http.X-Forwarded-Port != "443") {
>> return (synth(301, "https://www.example.com" + req.url));
>> }
>>
>> # Unset all cookies
>> unset req.http.Cookie;
>>
>> }
>>
>> sub vcl_backend_response {
>>
>> # Server_Name was here
>> set beresp.http.X-Processed-By = "Server_Name";
>
> See comment above about the server.identity variable.
>
>>
>> # Don't cache 404 responses
>> if ( beresp.status == 404 ) {
>> set beresp.ttl = 120s;
>> set beresp.uncacheable = true;
>> return (deliver);
>> }
>>
>> # Compress appropriate responses
>> if (beresp.http.content-type ~
>> "\b((text/(html|plain|css|javascript|xml|xsl))|(application/(javascript|xml|xhtml\+xml)))\b")
>> {
>> set beresp.do_gzip = true;
>> }
>>
>> # Set long TTL and grace time for 200 and 304 responses
>> if ( beresp.status == 200 || beresp.status == 304 ) {
>>
>> # Allow stale content, in case the backend goes down
>> set beresp.grace = 6h;
>>
>> # This is how long Varnish will keep cached content
>> set beresp.ttl = 7d;
>> }
>>
>> }
>>
>> sub vcl_deliver {
>> # Send special headers that indicate the cache status of each response
>> if (obj.hits > 0) {
>> set resp.http.X-Cache = "HIT";
>> set resp.http.X-Cache-Hits = obj.hits;
>> } else {
>> set resp.http.X-Cache = "MISS";
>> }
>
> You don't need a shiny HIT or MISS in the response. The X-Varnish
> header will tell you that already: one id is a miss, two of them a
> hit.
>
> Dridi


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