code 206 - visible as '206' in varnishncsa and as '200' from VCL code

[Johnny Halfmoon]

----- Message from l at lrowe.co.uk ---------
     Date: Fri, 29 Jul 2011 14:23:50 +0100
     From: Laurence Rowe <l at lrowe.co.uk>
Reply-To: Laurence Rowe <l at lrowe.co.uk>
  Subject: Re: code 206 - visible as '206' in varnishncsa and as '200'  
from VCL code
       To: Johnny Halfmoon <jhalfmoon at milksnot.com>
       Cc: "varnish-misc at varnish-cache.org" <varnish-misc at varnish-cache.org>


> On 28 July 2011 16:37, Johnny Halfmoon <jhalfmoon at milksnot.com> wrote:
>> Hi there,
>>
>> as a long time user of Varnish I still have an annoying little issue on my
>> todo list: It seems that when returning partial content, Varnishnsca
>> properly logs the transfer with a code 206 'partial content', but logging
>> the exact same transfer from VCL code, it returns code '200', which is
>> incorrect. I have tried using VRT_r_obj_status, VRT_r_rest_status and
>> VRT_r_beresp status to no avail. This is the case with both Varnish 2.1.5
>> and 3.0.0. Is this done on purpose by the code or can it be registered as a
>> bug?
>>
>> This is how I test it (examples using Varnish 3.0.0):
>>
>> #=== The command to do the RANGE request (note the returncode 206 'partial
>> content) ===
>>
>> testproxy02 ~ # http_proxy=http://127.0.0.1:80 curl -v -r 500-1000
>> http://vi.nl
>> .
>> .
>>>
>>> Proxy-Connection: Keep-Alive
>>>
>> < HTTP/1.1 206 Partial Content
>> < Server: Apache
>> .
>> ...<output truncated>...
>>
>> #=== This is the output of varnishncsa (note the code '206')===
>>
>> testproxy02 ~ # varnishncsa
>> 127.0.0.1 - - [28/Jul/2011:17:17:23 +0200] "GET http://bla.nlhttp://bla.nl
>> HTTP/1.1" 206 501 "-" "curl/7.15.5 (x86_64-redhat-linux-gnu) libcurl/7.15.5
>> OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5"
>>
>> #=== This is the output I get in syslog (note the code '200') ===
>>
>> testproxy02 ~ # tail -f /var/log/varnish/current
>>  code:200
>>  127.0.0.1 - - "Thu, 28 Jul 2011 15:16:56 GMT" "GET http://bla.nl" 200 58944
>> "-" "curl/7.15.5 (x86_64-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b
>> zlib/1.2.3 libidn/0.6.5" X:616508938 B:bla_nl V:bla.nl h:1
>>
>> #=== This is the bit of inline C code used to do the loggin from VCL ===
>>
>> int mycode = VRT_r_resp_status(sp);
>> if (mycode == NULL) { mycode = 0; }
>> syslog(LOG_DEBUG, "code:%u ", mycode );
>> .
>> ...<output truncated>...
>>
>> #=== EOF ===
>
> I believe Varnish makes the request to the backend without the Range
> header, so the result may still be cached. I'm not familiar enough
> with the VRT commands to know exactly what you are logging, but if it
> is the backend response code then you would expect that to be 200 (as
> it would not have seen the Range header.)
>
> Laurence
>

Hi Laurence,

thank you for your reply. I agree that the backend response would be  
200. But what I need to see is the actual response code Varnish sends  
to the frontend, which should be 206. In the example code I therefor  
explicitly read out VRT_r_resp_status , but still see code 200.

Cheers,

Johnny