Advanced
Mailing List Archive

Mailing List Archive

  1. Home >
  2. Varnish>
  3. Misc
Varnish cache MISS
martynas at atomgraph
Mar 10, 2021, 12:30 PM
Post #1 of 5 (766 views)
Permalink
Hi,

one again I'm mystified as to why responses from the backend are not
cached -- or rather, why only some of them are.

At the bottom you can find a log with 2 requests, one after another --
1st one miss, 2nd one hit.
The only difference I can see is that the 1st one contains an
Authorization header. I know that by default Varnish doesn't cache
authenticated interactions, but I changed my VCL to specifically allow
that (I think):

sub vcl_recv {
...

if (req.http.Cookie) { // allow req.http.Authorization
/* Not cacheable by default */
return (pass);
}
return (hash);
}

And this configuration works on a different host -- I can see requests
even with Authorization being hit and delivered.

But not on this one... What am I missing? I'm at a loss.


=== varnishadmi log ===

* << Request >> 470
- Begin req 385 rxreq
- Timestamp Start: 1615407572.284968 0.000000 0.000000
- Timestamp Req: 1615407572.284968 0.000000 0.000000
- ReqStart 172.26.0.6 33016
- ReqMethod GET
- ReqURL
/smth/root-admin-prod/sparql?%24Ontology=%3Chttps%3A%2F%2Fsmth.com%2Fadmin%2Fns%23%3E&%24Mode=%3Chttp%3A%2F%2Fwww.w3.org%2Fns%2Fauth%2Facl%23Read%3E&%24AuthenticatedAgentClass=%3Chttp%3A%2F%2Fwww.w3.org%2F2000%2F01%2Frdf-schema%23Resour
- ReqProtocol HTTP/1.1
- ReqHeader Authorization: Basic ****************************************
- ReqHeader Accept:
application/rdf+xml;q=0.8,application/n-triples;q=0.9,application/trix;q=0.8,application/ld+json;q=0.8,application/rdf+thrift,text/turtle;q=0.8,text/rdf+n3;q=0.8,application/rdf+json;q=0.8
- ReqHeader User-Agent: Jersey/2.30.1 (Apache HttpClient 4.5.10)
- ReqHeader Host: atomgraph.smth.varnish
- ReqHeader Connection: Keep-Alive
- ReqHeader Accept-Encoding: gzip,deflate
- ReqHeader X-Forwarded-For: 172.26.0.6
- 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 471 fetch
- Timestamp Fetch: 1615407572.305271 0.020303 0.020303
- RespProtocol HTTP/1.1
- RespStatus 200
- RespReason OK
- RespHeader Server: nginx/1.10.3 (Ubuntu)
- RespHeader Date: Wed, 10 Mar 2021 20:19:32 GMT
- RespHeader Content-Type: application/n-triples; charset=UTF-8
- RespHeader Last-Modified: Wed, 10 Mar 2021 20:19:32 GMT
- RespHeader Etag: 7f4f7c54-96d7-114d-bbe6-6a7cac14f19a
- RespHeader Vary: Accept, Accept-Datetime, Accept-Encoding,
Origin, Revision
- RespHeader Cache-Control: private
- RespHeader Request-Id: ECA4A374-81DD-11EB-87DD-901B0E95D742
- RespHeader Strict-Transport-Security: max-age=31536000
- RespHeader Client-Request-Id: 69f411cc-3616-4dea-a42a-423dae6d79f9
- RespHeader Access-Control-Max-Age: 86400
- RespHeader Access-Control-Allow-Credentials: true
- RespHeader Access-Control-Allow-Origin: atomgraph.smth.com
- RespHeader Access-Control-Allow-Headers: Accept,
Accept-Asynchronous, Accept-Datetime, Asynchronous-Content-Type,
Asynchronous-Location, Asynchronous-Method, Authorization,
Content-Encoding, Content-Type, Graph, Introspection-Content-Type,
Link, Location, Revision,
- RespHeader Access-Control-Expose-Headers: *
- RespHeader X-Varnish: 470
- RespHeader Age: 0
- RespHeader Via: 1.1 varnish (Varnish/5.2)
- VCL_call DELIVER
- VCL_return deliver
- Timestamp Process: 1615407572.305315 0.020348 0.000044
- RespHeader Accept-Ranges: bytes
- RespHeader Content-Length: 0
- RespHeader Connection: keep-alive
- Timestamp Resp: 1615407572.305420 0.020452 0.000104
- ReqAcct 4868 0 4868 1020 0 1020
- End

* << Request >> 33273
- Begin req 33229 rxreq
- Timestamp Start: 1615407574.651147 0.000000 0.000000
- Timestamp Req: 1615407574.651147 0.000000 0.000000
- ReqStart 172.26.0.6 33014
- ReqMethod GET
- ReqURL
/smth/contexts-prod/sparql?auth_token=*************************&%24this=%3Chttps%3A%2F%2Fsmth.com%2Fadmin%2Facl%2Fagents%2F678e3f45-c9b0-4673-9cc7-217d7804e7e4%2F%3E&query=BASE%20%20%20%20%3Chttps%3A%2F%2Fsmth.com%2F%3E%0APREFIX%20%
- ReqProtocol HTTP/1.1
- ReqHeader Accept:
application/rdf+xml;q=0.8,application/n-triples;q=0.9,application/trix;q=0.8,application/ld+json;q=0.8,application/rdf+thrift,text/turtle;q=0.8,text/rdf+n3;q=0.8,application/rdf+json;q=0.8
- ReqHeader User-Agent: Jersey/2.30.1 (Apache HttpClient 4.5.10)
- ReqHeader Host: atomgraph.smth.varnish
- ReqHeader Connection: Keep-Alive
- ReqHeader Accept-Encoding: gzip,deflate
- ReqHeader X-Forwarded-For: 172.26.0.6
- VCL_call RECV
- VCL_return hash
- ReqUnset Accept-Encoding: gzip,deflate
- ReqHeader Accept-Encoding: gzip
- VCL_call HASH
- VCL_return lookup
- Hit 98307 85213.183949 10.000000 0.000000
- VCL_call HIT
- VCL_return deliver
- RespProtocol HTTP/1.1
- RespStatus 200
- RespReason OK
- RespHeader Server: nginx/1.10.3 (Ubuntu)
- RespHeader Date: Wed, 10 Mar 2021 19:59:47 GMT
- RespHeader Content-Type: application/n-triples; charset=UTF-8
- RespHeader Last-Modified: Wed, 10 Mar 2021 19:59:47 GMT
- RespHeader Etag: a69bec4d-2a04-804c-8b79-16a8e598e9b8
- RespHeader Vary: Accept, Accept-Datetime, Accept-Encoding,
Origin, Revision
- RespHeader Cache-Control: private
- RespHeader Request-Id: 2A365E1A-81DB-11EB-87DD-901B0E95D742
- RespHeader Strict-Transport-Security: max-age=31536000
- RespHeader Access-Control-Max-Age: 86400
- RespHeader Access-Control-Allow-Credentials: true
- RespHeader Access-Control-Allow-Origin: *
- RespHeader Access-Control-Allow-Headers: Accept,
Accept-Asynchronous, Accept-Datetime, Asynchronous-Content-Type,
Asynchronous-Location, Asynchronous-Method, Authorization,
Content-Encoding, Content-Type, Graph, Introspection-Content-Type,
Link, Location, Revision,
- RespHeader Access-Control-Expose-Headers: *
- RespHeader X-Varnish: 33273 98307
- RespHeader Age: 1186
- RespHeader Via: 1.1 varnish (Varnish/5.2)
- VCL_call DELIVER
- VCL_return deliver
- Timestamp Process: 1615407574.651280 0.000133 0.000133
- RespHeader Accept-Ranges: bytes
- RespHeader Content-Length: 4454
- RespHeader Connection: keep-alive
- Timestamp Resp: 1615407574.651352 0.000205 0.000072
- ReqAcct 1961 0 1961 959 4454 5413
- End
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Varnish cache MISS [ In reply to ]
martynas at atomgraph
Mar 10, 2021, 1:07 PM
Post #2 of 5 (766 views)
Permalink
Nevermind :) I realized the URLs in this log are truncated and the
first one contains a unique ID in it...

On Wed, Mar 10, 2021 at 9:30 PM Martynas Jusevi?ius
<martynas@atomgraph.com> wrote:
>
> Hi,
>
> one again I'm mystified as to why responses from the backend are not
> cached -- or rather, why only some of them are.
>
> At the bottom you can find a log with 2 requests, one after another --
> 1st one miss, 2nd one hit.
> The only difference I can see is that the 1st one contains an
> Authorization header. I know that by default Varnish doesn't cache
> authenticated interactions, but I changed my VCL to specifically allow
> that (I think):
>
> sub vcl_recv {
> ...
>
> if (req.http.Cookie) { // allow req.http.Authorization
> /* Not cacheable by default */
> return (pass);
> }
> return (hash);
> }
>
> And this configuration works on a different host -- I can see requests
> even with Authorization being hit and delivered.
>
> But not on this one... What am I missing? I'm at a loss.
>
>
> === varnishadmi log ===
>
> * << Request >> 470
> - Begin req 385 rxreq
> - Timestamp Start: 1615407572.284968 0.000000 0.000000
> - Timestamp Req: 1615407572.284968 0.000000 0.000000
> - ReqStart 172.26.0.6 33016
> - ReqMethod GET
> - ReqURL
> /smth/root-admin-prod/sparql?%24Ontology=%3Chttps%3A%2F%2Fsmth.com%2Fadmin%2Fns%23%3E&%24Mode=%3Chttp%3A%2F%2Fwww.w3.org%2Fns%2Fauth%2Facl%23Read%3E&%24AuthenticatedAgentClass=%3Chttp%3A%2F%2Fwww.w3.org%2F2000%2F01%2Frdf-schema%23Resour
> - ReqProtocol HTTP/1.1
> - ReqHeader Authorization: Basic ****************************************
> - ReqHeader Accept:
> application/rdf+xml;q=0.8,application/n-triples;q=0.9,application/trix;q=0.8,application/ld+json;q=0.8,application/rdf+thrift,text/turtle;q=0.8,text/rdf+n3;q=0.8,application/rdf+json;q=0.8
> - ReqHeader User-Agent: Jersey/2.30.1 (Apache HttpClient 4.5.10)
> - ReqHeader Host: atomgraph.smth.varnish
> - ReqHeader Connection: Keep-Alive
> - ReqHeader Accept-Encoding: gzip,deflate
> - ReqHeader X-Forwarded-For: 172.26.0.6
> - 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 471 fetch
> - Timestamp Fetch: 1615407572.305271 0.020303 0.020303
> - RespProtocol HTTP/1.1
> - RespStatus 200
> - RespReason OK
> - RespHeader Server: nginx/1.10.3 (Ubuntu)
> - RespHeader Date: Wed, 10 Mar 2021 20:19:32 GMT
> - RespHeader Content-Type: application/n-triples; charset=UTF-8
> - RespHeader Last-Modified: Wed, 10 Mar 2021 20:19:32 GMT
> - RespHeader Etag: 7f4f7c54-96d7-114d-bbe6-6a7cac14f19a
> - RespHeader Vary: Accept, Accept-Datetime, Accept-Encoding,
> Origin, Revision
> - RespHeader Cache-Control: private
> - RespHeader Request-Id: ECA4A374-81DD-11EB-87DD-901B0E95D742
> - RespHeader Strict-Transport-Security: max-age=31536000
> - RespHeader Client-Request-Id: 69f411cc-3616-4dea-a42a-423dae6d79f9
> - RespHeader Access-Control-Max-Age: 86400
> - RespHeader Access-Control-Allow-Credentials: true
> - RespHeader Access-Control-Allow-Origin: atomgraph.smth.com
> - RespHeader Access-Control-Allow-Headers: Accept,
> Accept-Asynchronous, Accept-Datetime, Asynchronous-Content-Type,
> Asynchronous-Location, Asynchronous-Method, Authorization,
> Content-Encoding, Content-Type, Graph, Introspection-Content-Type,
> Link, Location, Revision,
> - RespHeader Access-Control-Expose-Headers: *
> - RespHeader X-Varnish: 470
> - RespHeader Age: 0
> - RespHeader Via: 1.1 varnish (Varnish/5.2)
> - VCL_call DELIVER
> - VCL_return deliver
> - Timestamp Process: 1615407572.305315 0.020348 0.000044
> - RespHeader Accept-Ranges: bytes
> - RespHeader Content-Length: 0
> - RespHeader Connection: keep-alive
> - Timestamp Resp: 1615407572.305420 0.020452 0.000104
> - ReqAcct 4868 0 4868 1020 0 1020
> - End
>
> * << Request >> 33273
> - Begin req 33229 rxreq
> - Timestamp Start: 1615407574.651147 0.000000 0.000000
> - Timestamp Req: 1615407574.651147 0.000000 0.000000
> - ReqStart 172.26.0.6 33014
> - ReqMethod GET
> - ReqURL
> /smth/contexts-prod/sparql?auth_token=*************************&%24this=%3Chttps%3A%2F%2Fsmth.com%2Fadmin%2Facl%2Fagents%2F678e3f45-c9b0-4673-9cc7-217d7804e7e4%2F%3E&query=BASE%20%20%20%20%3Chttps%3A%2F%2Fsmth.com%2F%3E%0APREFIX%20%
> - ReqProtocol HTTP/1.1
> - ReqHeader Accept:
> application/rdf+xml;q=0.8,application/n-triples;q=0.9,application/trix;q=0.8,application/ld+json;q=0.8,application/rdf+thrift,text/turtle;q=0.8,text/rdf+n3;q=0.8,application/rdf+json;q=0.8
> - ReqHeader User-Agent: Jersey/2.30.1 (Apache HttpClient 4.5.10)
> - ReqHeader Host: atomgraph.smth.varnish
> - ReqHeader Connection: Keep-Alive
> - ReqHeader Accept-Encoding: gzip,deflate
> - ReqHeader X-Forwarded-For: 172.26.0.6
> - VCL_call RECV
> - VCL_return hash
> - ReqUnset Accept-Encoding: gzip,deflate
> - ReqHeader Accept-Encoding: gzip
> - VCL_call HASH
> - VCL_return lookup
> - Hit 98307 85213.183949 10.000000 0.000000
> - VCL_call HIT
> - VCL_return deliver
> - RespProtocol HTTP/1.1
> - RespStatus 200
> - RespReason OK
> - RespHeader Server: nginx/1.10.3 (Ubuntu)
> - RespHeader Date: Wed, 10 Mar 2021 19:59:47 GMT
> - RespHeader Content-Type: application/n-triples; charset=UTF-8
> - RespHeader Last-Modified: Wed, 10 Mar 2021 19:59:47 GMT
> - RespHeader Etag: a69bec4d-2a04-804c-8b79-16a8e598e9b8
> - RespHeader Vary: Accept, Accept-Datetime, Accept-Encoding,
> Origin, Revision
> - RespHeader Cache-Control: private
> - RespHeader Request-Id: 2A365E1A-81DB-11EB-87DD-901B0E95D742
> - RespHeader Strict-Transport-Security: max-age=31536000
> - RespHeader Access-Control-Max-Age: 86400
> - RespHeader Access-Control-Allow-Credentials: true
> - RespHeader Access-Control-Allow-Origin: *
> - RespHeader Access-Control-Allow-Headers: Accept,
> Accept-Asynchronous, Accept-Datetime, Asynchronous-Content-Type,
> Asynchronous-Location, Asynchronous-Method, Authorization,
> Content-Encoding, Content-Type, Graph, Introspection-Content-Type,
> Link, Location, Revision,
> - RespHeader Access-Control-Expose-Headers: *
> - RespHeader X-Varnish: 33273 98307
> - RespHeader Age: 1186
> - RespHeader Via: 1.1 varnish (Varnish/5.2)
> - VCL_call DELIVER
> - VCL_return deliver
> - Timestamp Process: 1615407574.651280 0.000133 0.000133
> - RespHeader Accept-Ranges: bytes
> - RespHeader Content-Length: 4454
> - RespHeader Connection: keep-alive
> - Timestamp Resp: 1615407574.651352 0.000205 0.000072
> - ReqAcct 1961 0 1961 959 4454 5413
> - End
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Varnish cache MISS [ In reply to ]
dridi at varni
Mar 10, 2021, 1:17 PM
Post #3 of 5 (766 views)
Permalink
On Wed, Mar 10, 2021 at 9:09 PM Martynas Jusevi?ius
<martynas@atomgraph.com> wrote:
>
> Nevermind :) I realized the URLs in this log are truncated and the
> first one contains a unique ID in it...

You might also want to pay attention to backend response headers:

- RespHeader Cache-Control: private

If this cache-control came from the backend then there's a fair chance
that it made the response uncacheable.

Dridi
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Varnish cache MISS [ In reply to ]
martynas at atomgraph
Mar 10, 2021, 1:20 PM
Post #4 of 5 (766 views)
Permalink
Yes, that could be a problem, but I think I sorted this by using

On Wed, Mar 10, 2021 at 10:18 PM Dridi Boukelmoune <dridi@varni.sh> wrote:
>
> On Wed, Mar 10, 2021 at 9:09 PM Martynas Jusevi?ius
> <martynas@atomgraph.com> wrote:
> >
> > Nevermind :) I realized the URLs in this log are truncated and the
> > first one contains a unique ID in it...
>
> You might also want to pay attention to backend response headers:
>
> - RespHeader Cache-Control: private
>
> If this cache-control came from the backend then there's a fair chance
> that it made the response uncacheable.
>
> Dridi
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: Varnish cache MISS [ In reply to ]
martynas at atomgraph
Mar 10, 2021, 1:20 PM
Post #5 of 5 (766 views)
Permalink
...by using

sub vcl_backend_response {
return (deliver);
}

On Wed, Mar 10, 2021 at 10:20 PM Martynas Jusevi?ius
<martynas@atomgraph.com> wrote:
>
> Yes, that could be a problem, but I think I sorted this by using
>
> On Wed, Mar 10, 2021 at 10:18 PM Dridi Boukelmoune <dridi@varni.sh> wrote:
> >
> > On Wed, Mar 10, 2021 at 9:09 PM Martynas Jusevi?ius
> > <martynas@atomgraph.com> wrote:
> > >
> > > Nevermind :) I realized the URLs in this log are truncated and the
> > > first one contains a unique ID in it...
> >
> > You might also want to pay attention to backend response headers:
> >
> > - RespHeader Cache-Control: private
> >
> > If this cache-control came from the backend then there's a fair chance
> > that it made the response uncacheable.
> >
> > Dridi
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc

©2024 GT.net. A Gossamer Threads company.
5th Floor, 455 Granville St., Vancouver, BC V6C 1T1, Canada | Legal