File served without vcl_fetch() being invoked.

[Vedad KAJTAZ, Kigo Inc.]

Le 01/03/2012 11:19, Andreas Plesner Jacobsen a écrit :
> On Thu, Mar 01, 2012 at 11:09:25AM +0100, Vedad KAJTAZ, Kigo Inc. wrote:
>>
>>>> Varnishlog:
>>>> http://pastebin.com/KkwHpyTD
>>>>
>>>> URL /img/cfbc7c98bf8f0a9081a5178b26582ab4090571844992f9fefa30a1fa20fa3668.png
>>>> is fetched from backend by varnish and received by client, but is
>>>> neither logged by syslog (hence, vcl_fetch was never invoked) nor by
>>>> varnishlog.
>>>
>>> I don't see this URL in the varnishlog. Are you sure the client is not fetching
>>> directly from the backend?
>>>
>>
>> Yes, I am sure, and that's the point. The backend log shows proxy
>> (varnish) IP as source:
>>
>> 87.98.213.163 - - [01/Mar/2012:09:25:53 +0100] "GET /img/cfbc7c98bf8f0a9081a5178b26582ab4090571844992f9fefa30a1fa20fa3668.png
>> HTTP/1.1" 200 196534 "http://marais-apartments.com/le_marais.html"
>> "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like
>> Gecko) Chrome/18.0.1025.39 Safari/535.19"
>>
>> The client's IP is 82.226.115.148. As stated in original message,
>> there is no proxy or whatsoever between client, varnish and backend.
>
> I would look at two things:
>
> * varnishlog -O - varnishlog may not think it's a complete request
> * X-Varnish received at the backend. Does this match the sequence in
>    varnishlog? If not, you're hitting a different varnishd than the one you're
>    logging.
>



I've done another test. This time, the "faulty" url that doesn't appear 
in varnishlog and is not logged by vcl_recv is:

/img/4aa49f0874eb11168795c4f9a904c62d2b33d4cc947b3207a9d43e7c4a6e963d.png


Excerpt from tcpdump session (could not paste everything, the file is 
over 2Mb):

http://pastebin.com/d1RWqVeK



One can see client requesting 
/img/cfbc7c98bf8f0a9081a5178b26582ab4090571844992f9fefa30a1fa20fa3668.png within 
a kept-alive request (lines 63-74).

Varnish forwards the request (lines 75-86) without invoking vcl_fetch, 
and altering only the "Accept-Language" header.

Client -> Varnish:

GET 
/img/4aa49f0874eb11168795c4f9a904c62d2b33d4cc947b3207a9d43e7c4a6e963d.png HTTP/1.1
Host: marais-apartments.com
Connection: keep-alive
Cache-Control: no-cache
Pragma: no-cache
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 
(KHTML, like Gecko) Chrome/18.0.1025.39 Safari/535.19
Accept: */*
Referer: http://marais-apartments.com/le_marais.html
Accept-Encoding: gzip,deflate,sdch
Accept-Language: en-US,en;q=0.8,fr-FR;q=0.6,fr;q=



Varnish -> Backend:

GET 
/img/4aa49f0874eb11168795c4f9a904c62d2b33d4cc947b3207a9d43e7c4a6e963d.png HTTP/1.1
Host: marais-apartments.com
Connection: keep-alive
Cache-Control: no-cache
Pragma: no-cache
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 
(KHTML, like Gecko) Chrome/18.0.1025.39 Safari/535.19
Accept: */*
Referer: http://marais-apartments.com/le_marais.html
Accept-Encoding: gzip,deflate,sdch
Accept-Language: en-US,en;q=0.8,fr-FR


Hope this helps,

-- 
Vedad KAJTAZ
Head of Software Development
T: +33 1 42 74 56 70 | E: vedad at kigo.net

kigo.net | Vacation Rental Software & Websites

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 4906 bytes
Desc: Signature cryptographique S/MIME
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20120301/de0c2c4f/attachment.bin>