Mailing List Archive

varnishncsa show ESI request
Hi,

I'm using varnishncsa, but it's difficult to investigate because does
not show ESI sub-request in association.
I added show ESI option (-e) and Varnish:vxid_parent x format.

wip patch
https://gist.github.com/xcir/78c02d50681a4a78bc8c79ffd8421c8c

- Output sample

# varnishncsa -c -e -g request -F '%{Varnish:side}x %D
v:%{Varnish:vxid}x vp:%{Varnish:vxid_parent}x %{Varnish:hitmiss}x "%r"
%s %b'
c 1547310 v:193913332 vp:0 miss "GET http://**** HTTP/1.1" 200 7985
<-- slow base page
c 577 v:193913334 vp:193913332 hit "GET http://**** HTTP/1.1" 200 163
c 48233 v:193913336 vp:193913332 miss "GET http://**** HTTP/1.1" 200
1561 <-- fast sub-request
c 527 v:193913338 vp:193913332 hit "GET http://**** HTTP/1.1" 200 164

# varnishncsa -b -c -e -g request -F '%{Varnish:side}x %D
v:%{Varnish:vxid}x vp:%{Varnish:vxid_parent}x %{Varnish:hitmiss}x "%r"
%s %b'
c 2262459 v:221188118 vp:0 miss "GET http://**** HTTP/1.1" 200 18168
b 817749 v:221188119 vp:221188118 - "GET http://**** HTTP/1.1" 200 0
c 550 v:221188120 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
c 295 v:221188122 vp:221188118 hit "GET http://**** HTTP/1.1" 200 1565
c 494 v:221188123 vp:221188118 hit "GET http://**** HTTP/1.1" 200 162
c 262 v:221188125 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
c 1242 v:221188127 vp:221188118 hit "GET http://**** HTTP/1.1" 200 1488
c 211 v:221188129 vp:221188118 hit "GET http://**** HTTP/1.1" 200 44
c 1316055 v:221188130 vp:221188118 miss "GET http://**** HTTP/1.1" 200
4353 <-- slow sub-request
c 34039 v:221188132 vp:221188118 hit "GET http://**** HTTP/1.1" 200 788
c 18784 v:221188134 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
c 32942 v:221188135 vp:221188118 hit "GET http://**** HTTP/1.1" 200 774
c 22181 v:221188136 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
c 5766 v:221188138 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
c 8005 v:221188140 vp:221188118 miss "GET http://**** HTTP/1.1" 200
163 <-- fast sub-request
c 1626 v:221188142 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
c 230 v:221188144 vp:221188118 hit "GET http://**** HTTP/1.1" 200 739
b 1315672 v:221188131 vp:221188130 - "GET http://**** HTTP/1.1" 200 0
b 1187 v:221188141 vp:221188140 - "GET http://**** HTTP/1.1" 200 0

I’m thinking about whether to put PR.
Can I get your opinion?

Regards,
--
Shohei Tanaka(@xcir)
http://blog.xcir.net/ (JP)
_______________________________________________
varnish-misc mailing list
varnish-misc@varnish-cache.org
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
Re: varnishncsa show ESI request [ In reply to ]
Hi,

Unless I'm mistaken, what you are asking for is the first item in the
EXAMPLE section of "man varnishncsa":

Log the second field of the Begin record, corresponding to the VXID
of the parent transaction:

varnishncsa -F "%{VSL:Begin[2]}x"

Am I missing something?

--
Guillaume Quintard


On Tue, Jul 2, 2019 at 11:21 PM kokoniimasu <kokoniimasu@gmail.com> wrote:

> Hi,
>
> I'm using varnishncsa, but it's difficult to investigate because does
> not show ESI sub-request in association.
> I added show ESI option (-e) and Varnish:vxid_parent x format.
>
> wip patch
> https://gist.github.com/xcir/78c02d50681a4a78bc8c79ffd8421c8c
>
> - Output sample
>
> # varnishncsa -c -e -g request -F '%{Varnish:side}x %D
> v:%{Varnish:vxid}x vp:%{Varnish:vxid_parent}x %{Varnish:hitmiss}x "%r"
> %s %b'
> c 1547310 v:193913332 vp:0 miss "GET http://**** HTTP/1.1" 200 7985
> <-- slow base page
> c 577 v:193913334 vp:193913332 hit "GET http://**** HTTP/1.1" 200 163
> c 48233 v:193913336 vp:193913332 miss "GET http://**** HTTP/1.1" 200
> 1561 <-- fast sub-request
> c 527 v:193913338 vp:193913332 hit "GET http://**** HTTP/1.1" 200 164
>
> # varnishncsa -b -c -e -g request -F '%{Varnish:side}x %D
> v:%{Varnish:vxid}x vp:%{Varnish:vxid_parent}x %{Varnish:hitmiss}x "%r"
> %s %b'
> c 2262459 v:221188118 vp:0 miss "GET http://**** HTTP/1.1" 200 18168
> b 817749 v:221188119 vp:221188118 - "GET http://**** HTTP/1.1" 200 0
> c 550 v:221188120 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
> c 295 v:221188122 vp:221188118 hit "GET http://**** HTTP/1.1" 200 1565
> c 494 v:221188123 vp:221188118 hit "GET http://**** HTTP/1.1" 200 162
> c 262 v:221188125 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
> c 1242 v:221188127 vp:221188118 hit "GET http://**** HTTP/1.1" 200 1488
> c 211 v:221188129 vp:221188118 hit "GET http://**** HTTP/1.1" 200 44
> c 1316055 v:221188130 vp:221188118 miss "GET http://**** HTTP/1.1" 200
> 4353 <-- slow sub-request
> c 34039 v:221188132 vp:221188118 hit "GET http://**** HTTP/1.1" 200 788
> c 18784 v:221188134 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
> c 32942 v:221188135 vp:221188118 hit "GET http://**** HTTP/1.1" 200 774
> c 22181 v:221188136 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
> c 5766 v:221188138 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
> c 8005 v:221188140 vp:221188118 miss "GET http://**** HTTP/1.1" 200
> 163 <-- fast sub-request
> c 1626 v:221188142 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
> c 230 v:221188144 vp:221188118 hit "GET http://**** HTTP/1.1" 200 739
> b 1315672 v:221188131 vp:221188130 - "GET http://**** HTTP/1.1" 200 0
> b 1187 v:221188141 vp:221188140 - "GET http://**** HTTP/1.1" 200 0
>
> I’m thinking about whether to put PR.
> Can I get your opinion?
>
> Regards,
> --
> Shohei Tanaka(@xcir)
> http://blog.xcir.net/ (JP)
> _______________________________________________
> varnish-misc mailing list
> varnish-misc@varnish-cache.org
> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>
Re: varnishncsa show ESI request [ In reply to ]
Hi, Guillaume.

Thank You for your advice.

> varnishncsa -F "%{VSL:Begin[2]}x"

As you pointed out, I was mistaken about that.

I'm remove vxid_parent format.

2019?7?3?(?) 23:29 Guillaume Quintard <guillaume@varnish-software.com>:
>
> Hi,
>
> Unless I'm mistaken, what you are asking for is the first item in the EXAMPLE section of "man varnishncsa":
>
> Log the second field of the Begin record, corresponding to the VXID of the parent transaction:
>
> varnishncsa -F "%{VSL:Begin[2]}x"
>
> Am I missing something?
>
> --
> Guillaume Quintard
>
>
> On Tue, Jul 2, 2019 at 11:21 PM kokoniimasu <kokoniimasu@gmail.com> wrote:
>>
>> Hi,
>>
>> I'm using varnishncsa, but it's difficult to investigate because does
>> not show ESI sub-request in association.
>> I added show ESI option (-e) and Varnish:vxid_parent x format.
>>
>> wip patch
>> https://gist.github.com/xcir/78c02d50681a4a78bc8c79ffd8421c8c
>>
>> - Output sample
>>
>> # varnishncsa -c -e -g request -F '%{Varnish:side}x %D
>> v:%{Varnish:vxid}x vp:%{Varnish:vxid_parent}x %{Varnish:hitmiss}x "%r"
>> %s %b'
>> c 1547310 v:193913332 vp:0 miss "GET http://**** HTTP/1.1" 200 7985
>> <-- slow base page
>> c 577 v:193913334 vp:193913332 hit "GET http://**** HTTP/1.1" 200 163
>> c 48233 v:193913336 vp:193913332 miss "GET http://**** HTTP/1.1" 200
>> 1561 <-- fast sub-request
>> c 527 v:193913338 vp:193913332 hit "GET http://**** HTTP/1.1" 200 164
>>
>> # varnishncsa -b -c -e -g request -F '%{Varnish:side}x %D
>> v:%{Varnish:vxid}x vp:%{Varnish:vxid_parent}x %{Varnish:hitmiss}x "%r"
>> %s %b'
>> c 2262459 v:221188118 vp:0 miss "GET http://**** HTTP/1.1" 200 18168
>> b 817749 v:221188119 vp:221188118 - "GET http://**** HTTP/1.1" 200 0
>> c 550 v:221188120 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
>> c 295 v:221188122 vp:221188118 hit "GET http://**** HTTP/1.1" 200 1565
>> c 494 v:221188123 vp:221188118 hit "GET http://**** HTTP/1.1" 200 162
>> c 262 v:221188125 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
>> c 1242 v:221188127 vp:221188118 hit "GET http://**** HTTP/1.1" 200 1488
>> c 211 v:221188129 vp:221188118 hit "GET http://**** HTTP/1.1" 200 44
>> c 1316055 v:221188130 vp:221188118 miss "GET http://**** HTTP/1.1" 200
>> 4353 <-- slow sub-request
>> c 34039 v:221188132 vp:221188118 hit "GET http://**** HTTP/1.1" 200 788
>> c 18784 v:221188134 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
>> c 32942 v:221188135 vp:221188118 hit "GET http://**** HTTP/1.1" 200 774
>> c 22181 v:221188136 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
>> c 5766 v:221188138 vp:221188118 hit "GET http://**** HTTP/1.1" 200 0
>> c 8005 v:221188140 vp:221188118 miss "GET http://**** HTTP/1.1" 200
>> 163 <-- fast sub-request
>> c 1626 v:221188142 vp:221188118 hit "GET http://**** HTTP/1.1" 200 163
>> c 230 v:221188144 vp:221188118 hit "GET http://**** HTTP/1.1" 200 739
>> b 1315672 v:221188131 vp:221188130 - "GET http://**** HTTP/1.1" 200 0
>> b 1187 v:221188141 vp:221188140 - "GET http://**** HTTP/1.1" 200 0
>>
>> I’m thinking about whether to put PR.
>> Can I get your opinion?
>>
>> Regards,
>> --
>> Shohei Tanaka(@xcir)
>> http://blog.xcir.net/ (JP)
>> _______________________________________________
>> 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