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.
>


There is no other varnish running. This is the full list of process from 
the freebsd jail:

[root at kigoproxy squid]$ ps ax
   PID  TT  STAT      TIME COMMAND
  9799  ??  SsJ    0:01.13 /usr/sbin/syslogd -ss
10083  ??  IsJ    0:00.13 sendmail: Queue runner at 00:30:00 for 
/var/spool/clientmqueue (sendmail)
10090  ??  IsJ    0:01.08 /usr/sbin/cron -j 20 -J 20 -s
62308  ??  SsJ    0:09.64 varnishd: Varnish-Mgr kigoproxy.osilex.net 
(varnishd)
62309  ??  IJ     1:33.42 varnishd: Varnish-Chld kigoproxy.osilex.net 
(varnishd)
10129  10  IJ     0:00.01 /usr/local/bin/bash -l
16891  10  I+J    0:00.09 vim /etc/rc.conf
10192  11  IJ     0:00.02 /usr/local/bin/bash -l
16822  11  I+J    0:00.16 vim varnishd
16846  12  IJ     0:00.01 /usr/local/bin/bash -l
58918  12  I+J    0:00.03 vim default.vcl
17142  17  IJ     0:00.01 /usr/local/bin/bash -l
61229  17  I+J    0:00.77 vim kigo_simple.vcl
17174  18  I+J    0:00.07 /usr/local/bin/bash -l
17586  19  I+J    0:00.10 /usr/local/bin/bash -l
17730  20  I+J    0:00.02 /usr/local/bin/bash -l
58018  21  IJ     0:00.01 /usr/local/bin/bash -l
90489  21  I+J    0:00.01 tail -f /var/log/messages
59715  23  I+J    0:00.02 /usr/local/bin/bash -l
20976  24  SJ     0:00.01 /usr/local/bin/bash -l
96922  24  R+J    0:00.00 ps ax

Unfortunately, the back-end is a production server, and I won't be able 
to log X-varnish headers. I'll try snooping on the traffic instead.

I'll get back to the list quickly with new tests.


-- 
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/891a1ec9/attachment.bin>