Mailing List Archive

Log slow backend requests. VSL-query?
Hello,

Trying to log only the slow backend requests:

varnishncsa -b -q 'Timestamp:Process[2] > 0.1’

does not produce any output.

In fact, even varnishncsa -b -q 'Timestamp:Process[2] > 0’ does not work.

What am I doing wrong? :)
Re: Log slow backend requests. VSL-query? [ In reply to ]
On 03/21/2017 07:11 PM, Danila Vershinin wrote:
>
> Trying to log only the slow backend requests:
>
> varnishncsa -b -q 'Timestamp:Process[2] > 0.1?

Timestamp:Process only appears in the client-side logs, but with -b
you're filtering for the backend logs.

The "Backend fetch timestamps" section at the bottom of vsl(7) tells
you the names of the timestamps for backends:

http://www.varnish-cache.org/docs/5.1/reference/vsl.html#backend-fetch-timestamps

The one you're probably looking for is Timestamp:Beresp[3]. Beresp is
the timestamp set after receiving backend response headers (the first
timestamp recorded after the backend starts sending a response). Field
3 is the time elapsed since the most recent timestamp, which would be
Bereq (backend request sent), so this is the best measurement of how
fast or slow a backend responds after receiving a request.

One thing to watch out for: if there is a fetch error such as a
timeout that results in no backend response being received at all,
then Timestamp:Beresp isn't recorded in the log. Instead of that you
get Timestamp:Error, so you might want to query for Timestamp:Error[3]
as well.


HTH,
Geoff
--
** * * UPLEX - Nils Goroll Systemoptimierung

Scheffelstra?e 32
22301 Hamburg

Tel +49 40 2880 5731
Mob +49 176 636 90917
Fax +49 40 42949753

http://uplex.de
Re: Log slow backend requests. VSL-query? [ In reply to ]
Thank you very much, Geoff.

> On 21 Mar 2017, at 21:28, Geoff Simmons <geoff@uplex.de> wrote:
>
> On 03/21/2017 07:11 PM, Danila Vershinin wrote:
>>
>> Trying to log only the slow backend requests:
>>
>> varnishncsa -b -q 'Timestamp:Process[2] > 0.1’
>
> Timestamp:Process only appears in the client-side logs, but with -b
> you're filtering for the backend logs.
>
> The "Backend fetch timestamps" section at the bottom of vsl(7) tells
> you the names of the timestamps for backends:
>
> http://www.varnish-cache.org/docs/5.1/reference/vsl.html#backend-fetch-timestamps
>
> The one you're probably looking for is Timestamp:Beresp[3]. Beresp is
> the timestamp set after receiving backend response headers (the first
> timestamp recorded after the backend starts sending a response). Field
> 3 is the time elapsed since the most recent timestamp, which would be
> Bereq (backend request sent), so this is the best measurement of how
> fast or slow a backend responds after receiving a request.
>
> One thing to watch out for: if there is a fetch error such as a
> timeout that results in no backend response being received at all,
> then Timestamp:Beresp isn't recorded in the log. Instead of that you
> get Timestamp:Error, so you might want to query for Timestamp:Error[3]
> as well.
>
>
> HTH,
> Geoff
> --
> ** * * UPLEX - Nils Goroll Systemoptimierung
>
> Scheffelstraße 32
> 22301 Hamburg
>
> Tel +49 40 2880 5731
> Mob +49 176 636 90917
> Fax +49 40 42949753
>
> http://uplex.de
>
> _______________________________________________
> varnish-misc mailing list
> varnish-misc@varnish-cache.org
> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc


_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc