VSL Timeout and Varnishkafka

[Luca Toscano]

2016-06-22 11:59 GMT+02:00 Luca Toscano <toscano.luca at gmail.com>:

>
>
> 2016-06-21 20:27 GMT+02:00 Geoff Simmons <geoff at uplex.de>:
>
> First of all thanks a lot for the answer!
>
> On 06/21/2016 07:27 PM, Luca Toscano wrote:
>> >
>> > -   VSL            timeout -   End            synth
>>
>> The timeout (-T arg of the VSL tools) starts when the Begin tag for a
>> transaction is read from shared memory, and ticks until the End tag is
>> read for that transaction. If End is not encountered before the
>> timeout expires, you get the synthesized VSL record.
>>
>> So in your example, VSL isn't seeing End in the log before the timeout
>> elapses, probably 120 seconds if you haven't changed the default. This
>> could happen, for example, if you have a response that takes that long
>> to complete.
>>
>
> My understanding is that a Varnish worker will flush all the tags related
> to a specific request only when it is done with it (this is what I got from
> https://info.varnish-software.com/blog/understanding-timeouts-varnish-cache).
> As written in my past email I tried to set up a basic backend timeout
> scenario but I wasn't able to reproduce the VSL error. More details:
>
> - Varnish -> Apache -> PHP-FPM <-> php script that sleeps for 200 seconds
> before emitting HTML
> - Varnish is configured with default parameters plus "-p
> first_byte_timeout=150" (note: bigger than the 120 seconds set by default
> for VSL timeout, the default one is 60)
> - a simple curl request for the URL that runs the PHP script correctly
> triggers a backend fetch timeout, but Begin|End SLT Timestamps are there.
> - I also tried with varnishlog -g request -T 5 to force a VSL Timeout, but
> didn't succeed.
>
> Is it possible that the VSL timeout is something related only to the data
> flow between SHM and varnishkafka (so not related to the time taken by a
> Varnish worker to serve a request) ?
>
> If this is completely false and incorrect, would you mind to give me a
> more specific example about how to trigger a VSL timeout?
>
>
>>
>> To set the timeout in a VSL client, you can use:
>>
>> VSL_Arg(vsl, 'T', timeout)
>>
>> ... where timeout is a string containing decimal digits.
>>
>> varnishevent is very similar to varnishkafka and supports -T, you can
>> see some working code here:
>>
>>
>> https://code.uplex.de/uplex-varnish/varnishevent/blob/master/src/varnishevent.c#L641
>
>
> Thanks for the link, I implemented the -T exactly in the same way
> yesterday for Varnishkafka, really good to have a working example to
> confirm my code. Also, Varnishevent looks really awesome, nice work!
> Looking forward to test it :)
>
>
Nice test that I found in the Varnish codebase (meant to trigger a VSL
timeout):

https://github.com/varnishcache/varnish-cache/blob/4.1/bin/varnishtest/tests/r01762.vtc#L29

Luca
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20160622/7ac8ad6c/attachment.html>