**** dT    0.001
*    top   TEST ../../../vmod/tests/purge_c00000.vtc starting
**** top   extmacro def pkg_version=trunk
**** top   extmacro def pkg_branch=trunk
**** top   extmacro def pwd=/root/VT/varnish-cache/varnish-trunk/_build/sub/vmod
**** top   extmacro def date(...)
**** top   extmacro def string(...)
**** top   extmacro def localhost=127.0.0.1
**** top   extmacro def bad_backend=127.0.0.1:48175
**** top   extmacro def listen_addr=127.0.0.1:0
**** top   extmacro def bad_ip=192.0.2.255
**** top   extmacro def topbuild=/root/VT/varnish-cache/varnish-trunk/_build/sub
**** top   extmacro def topsrc=/root/VT/varnish-cache/varnish-trunk/_build/sub/../..
**** top   macro def testdir=/root/VT/varnish-cache/varnish-trunk/_build/sub/vmod/../../../vmod/tests
**** dT    0.002
**** top   macro def tmpdir=/root/VT/_vtest_tmp/vtc.12122.7da0e82e
**** top   macro def vtcid=vtc.12122.7da0e82e
**** dT    0.004
**   top   === varnishtest "Test purge vmod"
*    top   VTEST Test purge vmod
**   top   === server s1 {
**   s1    Starting server
**** s1    macro def s1_addr=127.0.0.1
**** s1    macro def s1_port=12683
**** s1    macro def s1_sock=127.0.0.1:12683
**** dT    0.005
*    s1    Listen on 127.0.0.1:12683
**   top   === varnish v1 -cliok "param.set vsl_mask +ExpKill"
**** dT    0.006
**   s1    Started on 127.0.0.1:12683 (1 iterations)
**** dT    0.038
**   v1    Launch
***  v1    CMD: cd ${pwd} && exec varnishd  -d -n /root/VT/_vtest_tmp/vtc.12122.7da0e82e/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 50065' -P /root/VT/_vtest_tmp/vtc.12122.7da0e82e/v1/varnishd.pid -p vmod_path=/root/VT/varnish-cache/varnish-trunk/_build/sub/vmod/.libs 
**** dT    0.039
***  v1    CMD: cd /root/VT/varnish-cache/varnish-trunk/_build/sub/vmod && exec varnishd  -d -n /root/VT/_vtest_tmp/vtc.12122.7da0e82e/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 50065' -P /root/VT/_vtest_tmp/vtc.12122.7da0e82e/v1/varnishd.pid -p vmod_path=/root/VT/varnish-cache/varnish-trunk/_build/sub/vmod/.libs 
**** dT    0.042
***  v1    PID: 12138
**** v1    macro def v1_pid=12138
**** v1    macro def v1_name=/root/VT/_vtest_tmp/vtc.12122.7da0e82e/v1
**** dT    0.176
***  v1    debug|Debug: Version: varnish-trunk revision b825f55f348595cfc24f5eee92b86ecf2e880924
***  v1    debug|Debug: Platform: FreeBSD,13.4-RC3,arm,-jnone,-sdefault,-sdefault,-hcritbit
**** dT    0.177
***  v1    debug|200 308     
***  v1    debug|-----------------------------
***  v1    debug|Varnish Cache CLI 1.0
***  v1    debug|-----------------------------
***  v1    debug|FreeBSD,13.4-RC3,arm,-jnone,-sdefault,-sdefault,-hcritbit
***  v1    debug|varnish-trunk revision b825f55f348595cfc24f5eee92b86ecf2e880924
***  v1    debug|
***  v1    debug|Type 'help' for command list.
***  v1    debug|Type 'quit' to close CLI session.
***  v1    debug|Type 'start' to launch worker process.
***  v1    debug|
**** dT    0.258
**** v1    CLIPOLL 1 0x1 0x0 0x0
**** dT    0.259
***  v1    CLI connection fd = 6
**** dT    0.261
***  v1    CLI RX  107
**** v1    CLI RX|jfbbwtccjnieiogqjftfniihyobjrkgl
**** v1    CLI RX|
**** v1    CLI RX|Authentication required.
**** dT    0.263
**** v1    CLI TX|auth 2ce4599d0c380673751ee673e8d496f163abfdeeab783166545df828aef2bc81
**** dT    0.267
***  v1    CLI RX  200
**** v1    CLI RX|-----------------------------
**** v1    CLI RX|Varnish Cache CLI 1.0
**** v1    CLI RX|-----------------------------
**** v1    CLI RX|FreeBSD,13.4-RC3,arm,-jnone,-sdefault,-sdefault,-hcritbit
**** v1    CLI RX|varnish-trunk revision b825f55f348595cfc24f5eee92b86ecf2e880924
**** v1    CLI RX|
**** v1    CLI RX|Type 'help' for command list.
**** v1    CLI RX|Type 'quit' to close CLI session.
**** v1    CLI RX|Type 'start' to launch worker process.
**** dT    0.269
**** v1    CLI TX|param.set vsl_mask +ExpKill
**** dT    0.310
***  v1    CLI RX  200
**   v1    CLI 200 <param.set vsl_mask +ExpKill>
**   top   === varnish v1 -vcl+backend {
**** v1    CLI TX|vcl.inline vcl1 << %XJEIFLH|)Xspa8P
**** v1    CLI TX|vcl 4.1;
**** v1    CLI TX|backend s1 { .host = "127.0.0.1"; .port = "12683"; }
**** v1    CLI TX|
**** v1    CLI TX|
**** v1    CLI TX|\timport purge;
**** v1    CLI TX|
**** v1    CLI TX|\tsub vcl_recv {
**** v1    CLI TX|\t\tif (req.method ~ "PURGE") {
**** v1    CLI TX|\t\t\treturn (hash);
**** v1    CLI TX|\t\t}
**** v1    CLI TX|\t}
**** v1    CLI TX|
**** v1    CLI TX|\tsub my_purge {
**** v1    CLI TX|\t\tif (req.method == "PURGE") {
**** v1    CLI TX|\t\t\tset req.http.purged = purge.hard();
**** v1    CLI TX|\t\t}
**** v1    CLI TX|\t\telse {
**** v1    CLI TX|\t\t\tset req.http.purged = purge.soft();
**** v1    CLI TX|\t\t}
**** v1    CLI TX|\t\tif (req.http.purged == "0") {
**** v1    CLI TX|\t\t\treturn (synth(404));
**** v1    CLI TX|\t\t}
**** v1    CLI TX|\t\telse {
**** v1    CLI TX|\t\t\treturn (synth(200));
**** v1    CLI TX|\t\t}
**** v1    CLI TX|\t}
**** v1    CLI TX|
**** v1    CLI TX|\tsub vcl_hit {
**** v1    CLI TX|\t\tif (req.method ~ "PURGE") { call my_purge; }
**** v1    CLI TX|\t}
**** v1    CLI TX|
**** v1    CLI TX|\tsub vcl_miss {
**** v1    CLI TX|\t\tif (req.method ~ "PURGE") { call my_purge; }
**** v1    CLI TX|\t}
**** v1    CLI TX|
**** v1    CLI TX|\tsub vcl_synth {
**** v1    CLI TX|\t\tif (req.method ~ "PURGE") {
**** v1    CLI TX|\t\t\tset resp.http.purged = req.http.purged;
**** v1    CLI TX|\t\t\treturn (deliver);
**** v1    CLI TX|\t\t}
**** v1    CLI TX|\t}
**** v1    CLI TX|
**** v1    CLI TX|\tsub vcl_backend_response {
**** v1    CLI TX|\t\tset beresp.http.X-Varnish-Be = bereq.xid;
**** v1    CLI TX|\t}
**** v1    CLI TX|
**** v1    CLI TX|%XJEIFLH|)Xspa8P
**** dT    0.372
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.474
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.576
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.677
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.779
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.881
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.983
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.085
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.187
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.289
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.391
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.493
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.595
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.697
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.799
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    1.900
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.002
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.104
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.206
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.308
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.410
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.512
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.614
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.758
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.859
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    2.961
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.063
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.164
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.266
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.368
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.470
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.572
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.673
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.775
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.877
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    3.978
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.080
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.182
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.284
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.386
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.488
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.590
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.692
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.794
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.896
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    4.998
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.100
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.202
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.304
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.406
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.508
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.610
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.712
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.813
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.909
***  v1    CLI RX  200
**** v1    CLI RX|VCL compiled.
**** v1    CLI TX|vcl.use vcl1
**** dT    5.920
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    5.952
***  v1    CLI RX  200
**** v1    CLI RX|VCL 'vcl1' now active
**   v1    Start
**** v1    CLI TX|start
**** dT    6.022
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    6.036
***  v1    debug|Debug: Child (12147) Started
**** dT    6.128
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    6.432
***  v1    debug|Child launched OK
**** dT    6.433
**** v1    vsl|          0 CLI             - Rd vcl.load "vcl1" vcl_vcl1.1733924055.803864/vgc.so 1auto
**** dT    6.453
***  v1    CLI RX  200
***  v1    wait-running
**** v1    CLI TX|status
***  v1    debug|Info: Child (12147) said Child starts
**** dT    6.495
***  v1    CLI RX  200
**** v1    CLI RX|Child in state running
**** dT    6.496
**** v1    CLI TX|debug.listen_address
**** dT    6.537
**** v1    vsl|          0 CLI             - Wr 200 52 Loaded "vcl_vcl1.1733924055.803864/vgc.so" as "vcl1"
**** v1    vsl|          0 CLI             - Rd vcl.use "vcl1"
**** v1    vsl|          0 CLI             - Wr 200 0 
**** v1    vsl|          0 CLI             - Rd start
**** v1    vsl|          0 Debug           - sockopt: Setting SO_LINGER for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting SO_KEEPALIVE for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting SO_SNDTIMEO for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting SO_RCVTIMEO for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_NODELAY for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_KEEPIDLE for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_KEEPCNT for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_KEEPINTVL for a0=127.0.0.1:30367
**** v1    vsl|          0 Error           - Kernel filtering: sock=3, errno=2 No such file or directory
**** v1    vsl|          0 CLI             - Wr 200 0 
**** v1    vsl|          0 CLI             - Rd debug.listen_address 
**** v1    vsl|          0 CLI             - Wr 200 19 a0 127.0.0.1 30367

**** dT    6.538
***  v1    CLI RX  200
**** v1    CLI RX|a0 127.0.0.1 30367
**** v1    CLI TX|debug.xid 1000
**** dT    6.581
***  v1    CLI RX  200
**** v1    CLI RX|XID is 1000 chunk 1
**** v1    CLI TX|debug.listen_address
**** dT    6.624
***  v1    CLI RX  200
**** v1    CLI RX|a0 127.0.0.1 30367
**   v1    Listen on 127.0.0.1 30367
**** v1    macro def v1_addr=127.0.0.1
**** v1    macro def v1_port=30367
**** v1    macro def v1_sock=127.0.0.1:30367
**** v1    macro def v1_a0_addr=127.0.0.1
**** v1    macro def v1_a0_port=30367
**** v1    macro def v1_a0_sock=127.0.0.1:30367
**   top   === logexpect l1 -v v1 -q Hit -i Hit {
**** dT    6.626
**   l1    === expect * * Hit "^1002 -.+ 10.000000 0.000000$"
**** dT    6.628
**   top   === logexpect l2 -v v1 -q "Begin ~ bgfetch" {
**** dT    6.630
**   l2    === expect * * BerespHeader "X-Varnish-Be: 1005"
**** l1    begin|
**** dT    6.631
**** l1    qry  | Hit
***  l1    test | expect * * Hit ^1002 -.+ 10.000000 0.000000$
**** dT    6.632
**   top   === logexpect l3 -v v1 -g raw -q "vxid == 0" {
**** dT    6.634
**   l3    === expect * * ExpKill x=1008
**** dT    6.635
**   top   === client c1 {
**   c1    Starting client
**** dT    6.636
**   c1    Waiting for client
**** l2    begin|
**** l2    qry  | Begin ~ bgfetch
***  l2    test | expect * * BerespHeader X-Varnish-Be: 1005
**** l3    begin|
**** l3    qry  | vxid == 0
***  l3    test | expect * * ExpKill x=1008
**** dT    6.637
**   c1    Started on 127.0.0.1:30367 (1 iterations)
***  c1    Connect to 127.0.0.1:30367
**** dT    6.638
***  c1    connected fd 31 from 127.0.0.1 51318 to 127.0.0.1:30367
**   c1    === txreq -hdr "Accept-Language: fr"
**** dT    6.639
**** c1    txreq|GET / HTTP/1.1\r
**** c1    txreq|Accept-Language: fr\r
**** c1    txreq|Host: 127.0.0.1\r
**** c1    txreq|User-Agent: c1\r
**** c1    txreq|\r
**   c1    === rxresp
**** dT    6.641
**** v1    vsl|          0 CLI             - Rd debug.xid 1000 
**** v1    vsl|          0 CLI             - Wr 200 19 XID is 1000 chunk 1
**** v1    vsl|          0 CLI             - Rd debug.listen_address 
**** v1    vsl|          0 CLI             - Wr 200 19 a0 127.0.0.1 30367

**** dT    6.642
**** v1    vsl|       1000 Begin           c sess 0 HTTP/1
**** v1    vsl|       1000 SessOpen        c 127.0.0.1 51318 a0 127.0.0.1 30367 1733924062.132411 17
**** v1    vsl|       1000 Debug           c sockopt: Test confirmed SO_KEEPALIVE non heredity for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: Test confirmed SO_SNDTIMEO non heredity for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: Test confirmed SO_RCVTIMEO non heredity for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: Test confirmed TCP_NODELAY non heredity for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: SO_LINGER may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: Setting SO_KEEPALIVE for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: Setting SO_SNDTIMEO for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: Setting SO_RCVTIMEO for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: Setting TCP_NODELAY for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: TCP_KEEPIDLE may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: TCP_KEEPCNT may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1000 Debug           c sockopt: TCP_KEEPINTVL may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1000 Link            c req 1001 rxreq
**** dT    6.646
***  s1    accepted fd 4 127.0.0.1 51024
**   s1    === rxreq
**** dT    6.650
**** s1    rxhdr|GET / HTTP/1.1\r
**** s1    rxhdr|Accept-Language: fr\r
**** s1    rxhdr|Host: 127.0.0.1\r
**** s1    rxhdr|User-Agent: c1\r
**** s1    rxhdr|X-Forwarded-For: 127.0.0.1\r
**** s1    rxhdr|Via: 1.1 v1 (Varnish/trunk)\r
**** s1    rxhdr|Accept-Encoding: gzip\r
**** s1    rxhdr|X-Varnish: 1002\r
**** s1    rxhdr|\r
**** s1    rxhdrlen = 169
**** s1    http[ 0] |GET
**** s1    http[ 1] |/
**** s1    http[ 2] |HTTP/1.1
**** s1    http[ 3] |Accept-Language: fr
**** s1    http[ 4] |Host: 127.0.0.1
**** s1    http[ 5] |User-Agent: c1
**** s1    http[ 6] |X-Forwarded-For: 127.0.0.1
**** s1    http[ 7] |Via: 1.1 v1 (Varnish/trunk)
**** s1    http[ 8] |Accept-Encoding: gzip
**** s1    http[ 9] |X-Varnish: 1002
**** s1    bodylen = 0
**   s1    === expect req.http.Accept-Language == fr
**** s1    EXPECT req.http.Accept-Language (fr) == "fr" match
**   s1    === txresp -hdr "Vary: Accept-Language" -body fr
**** dT    6.651
**** s1    txresp|HTTP/1.1 200 OK\r
**** s1    txresp|Vary: Accept-Language\r
**** s1    txresp|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** s1    txresp|Server: s1\r
**** s1    txresp|Content-Length: 2\r
**** s1    txresp|\r
**** s1    txresp|fr
**** dT    6.652
**   s1    === rxreq
**** dT    6.657
**** c1    rxhdr|HTTP/1.1 200 OK\r
**** c1    rxhdr|Vary: Accept-Language\r
**** c1    rxhdr|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** c1    rxhdr|Server: s1\r
**** c1    rxhdr|Content-Length: 2\r
**** c1    rxhdr|X-Varnish-Be: 1002\r
**** c1    rxhdr|X-Varnish: 1001\r
**** c1    rxhdr|Age: 0\r
**** c1    rxhdr|Via: 1.1 v1 (Varnish/trunk)\r
**** c1    rxhdr|Accept-Ranges: bytes\r
**** c1    rxhdr|Connection: keep-alive\r
**** c1    rxhdr|\r
**** c1    rxhdrlen = 230
**** c1    http[ 0] |HTTP/1.1
**** c1    http[ 1] |200
**** c1    http[ 2] |OK
**** c1    http[ 3] |Vary: Accept-Language
**** c1    http[ 4] |Date: Wed, 11 Dec 2024 13:34:22 GMT
**** c1    http[ 5] |Server: s1
**** c1    http[ 6] |Content-Length: 2
**** c1    http[ 7] |X-Varnish-Be: 1002
**** c1    http[ 8] |X-Varnish: 1001
**** c1    http[ 9] |Age: 0
**** c1    http[10] |Via: 1.1 v1 (Varnish/trunk)
**** c1    http[11] |Accept-Ranges: bytes
**** c1    http[12] |Connection: keep-alive
**** dT    6.659
**** c1    c-l|fr
**** c1    bodylen = 2
**   c1    === expect resp.body == fr
**** c1    EXPECT resp.body (fr) == "fr" match
**   c1    === expect resp.http.X-Varnish-Be == 1002
**** c1    EXPECT resp.http.X-Varnish-Be (1002) == "1002" match
**   c1    === txreq -req SOFTPURGE
**** c1    txreq|SOFTPURGE / HTTP/1.1\r
**** c1    txreq|Host: 127.0.0.1\r
**** c1    txreq|User-Agent: c1\r
**** c1    txreq|\r
**   c1    === rxresp
**** dT    6.675
**** c1    rxhdr|HTTP/1.1 200 OK\r
**** c1    rxhdr|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** c1    rxhdr|Server: Varnish\r
**** c1    rxhdr|X-Varnish: 1003\r
**** c1    rxhdr|purged: 1\r
**** c1    rxhdr|Content-Length: 0\r
**** c1    rxhdr|Connection: keep-alive\r
**** c1    rxhdr|\r
**** c1    rxhdrlen = 144
**** c1    http[ 0] |HTTP/1.1
**** c1    http[ 1] |200
**** c1    http[ 2] |OK
**** c1    http[ 3] |Date: Wed, 11 Dec 2024 13:34:22 GMT
**** c1    http[ 4] |Server: Varnish
**** c1    http[ 5] |X-Varnish: 1003
**** c1    http[ 6] |purged: 1
**** c1    http[ 7] |Content-Length: 0
**** c1    http[ 8] |Connection: keep-alive
**** c1    bodylen = 0
**   c1    === expect resp.status == 200
**** c1    EXPECT resp.status (200) == "200" match
**   c1    === expect resp.http.purged == 1
**** c1    EXPECT resp.http.purged (1) == "1" match
**   c1    === txreq -hdr "Accept-Language: fr"
**** dT    6.676
**** c1    txreq|GET / HTTP/1.1\r
**** c1    txreq|Accept-Language: fr\r
**** c1    txreq|Host: 127.0.0.1\r
**** c1    txreq|User-Agent: c1\r
**** c1    txreq|\r
**   c1    === rxresp
**** dT    6.681
**** s1    rxhdr|GET / HTTP/1.1\r
**** s1    rxhdr|Accept-Language: fr\r
**** s1    rxhdr|Host: 127.0.0.1\r
**** s1    rxhdr|User-Agent: c1\r
**** s1    rxhdr|X-Forwarded-For: 127.0.0.1\r
**** s1    rxhdr|Via: 1.1 v1 (Varnish/trunk)\r
**** s1    rxhdr|Accept-Encoding: gzip\r
**** s1    rxhdr|X-Varnish: 1005\r
**** s1    rxhdr|\r
**** s1    rxhdrlen = 169
**** s1    http[ 0] |GET
**** s1    http[ 1] |/
**** s1    http[ 2] |HTTP/1.1
**** s1    http[ 3] |Accept-Language: fr
**** dT    6.682
**** s1    http[ 4] |Host: 127.0.0.1
**** s1    http[ 5] |User-Agent: c1
**** s1    http[ 6] |X-Forwarded-For: 127.0.0.1
**** s1    http[ 7] |Via: 1.1 v1 (Varnish/trunk)
**** s1    http[ 8] |Accept-Encoding: gzip
**** s1    http[ 9] |X-Varnish: 1005
**** s1    bodylen = 0
**   s1    === expect req.http.Accept-Language == fr
**** s1    EXPECT req.http.Accept-Language (fr) == "fr" match
**   s1    === txresp -hdr "Vary: Accept-Language" -body fr
**** s1    txresp|HTTP/1.1 200 OK\r
**** s1    txresp|Vary: Accept-Language\r
**** s1    txresp|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** s1    txresp|Server: s1\r
**** s1    txresp|Content-Length: 2\r
**** s1    txresp|\r
**** s1    txresp|fr
**   s1    === rxreq
**** dT    6.687
**** c1    rxhdr|HTTP/1.1 200 OK\r
**** c1    rxhdr|Vary: Accept-Language\r
**** c1    rxhdr|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** c1    rxhdr|Server: s1\r
**** c1    rxhdr|Content-Length: 2\r
**** c1    rxhdr|X-Varnish-Be: 1002\r
**** c1    rxhdr|X-Varnish: 1004 1002\r
**** c1    rxhdr|Age: 0\r
**** c1    rxhdr|Via: 1.1 v1 (Varnish/trunk)\r
**** c1    rxhdr|Accept-Ranges: bytes\r
**** c1    rxhdr|Connection: keep-alive\r
**** c1    rxhdr|\r
**** c1    rxhdrlen = 235
**** c1    http[ 0] |HTTP/1.1
**** c1    http[ 1] |200
**** c1    http[ 2] |OK
**** c1    http[ 3] |Vary: Accept-Language
**** c1    http[ 4] |Date: Wed, 11 Dec 2024 13:34:22 GMT
**** c1    http[ 5] |Server: s1
**** c1    http[ 6] |Content-Length: 2
**** c1    http[ 7] |X-Varnish-Be: 1002
**** c1    http[ 8] |X-Varnish: 1004 1002
**** c1    http[ 9] |Age: 0
**** c1    http[10] |Via: 1.1 v1 (Varnish/trunk)
**** c1    http[11] |Accept-Ranges: bytes
**** dT    6.688
**** c1    http[12] |Connection: keep-alive
**** c1    c-l|fr
**** c1    bodylen = 2
**   c1    === expect resp.body == fr
**** c1    EXPECT resp.body (fr) == "fr" match
**   c1    === expect resp.http.X-Varnish == "1004 1002"
**** c1    EXPECT resp.http.X-Varnish (1004 1002) == "1004 1002" match
**   c1    === expect resp.http.X-Varnish-Be == 1002
**** c1    EXPECT resp.http.X-Varnish-Be (1002) == "1002" match
***  c1    closing fd 31
**   c1    Ending
**** dT    6.689
**   top   === logexpect l2 -wait
**   l2    Waiting for logexp
**** dT    6.705
**** l2    match|       1005 BerespHeader    b X-Varnish-Be: 1005
**** l2    done |
**   top   === client c1 {
**** dT    6.706
**   c1    Starting client
**   c1    Waiting for client
**   c1    Started on 127.0.0.1:30367 (1 iterations)
***  c1    Connect to 127.0.0.1:30367
**** dT    6.707
***  c1    connected fd 31 from 127.0.0.1 43540 to 127.0.0.1:30367
**** dT    6.708
**   c1    === txreq -hdr "Accept-Language: en"
**** c1    txreq|GET / HTTP/1.1\r
**** c1    txreq|Accept-Language: en\r
**** c1    txreq|Host: 127.0.0.1\r
**** c1    txreq|User-Agent: c1\r
**** c1    txreq|\r
**** dT    6.710
**   c1    === rxresp
**** dT    6.713
**** s1    rxhdr|GET / HTTP/1.1\r
**** s1    rxhdr|Accept-Language: en\r
**** s1    rxhdr|Host: 127.0.0.1\r
**** s1    rxhdr|User-Agent: c1\r
**** s1    rxhdr|X-Forwarded-For: 127.0.0.1\r
**** s1    rxhdr|Via: 1.1 v1 (Varnish/trunk)\r
**** s1    rxhdr|Accept-Encoding: gzip\r
**** s1    rxhdr|X-Varnish: 1008\r
**** s1    rxhdr|\r
**** s1    rxhdrlen = 169
**** s1    http[ 0] |GET
**** s1    http[ 1] |/
**** s1    http[ 2] |HTTP/1.1
**** s1    http[ 3] |Accept-Language: en
**** s1    http[ 4] |Host: 127.0.0.1
**** s1    http[ 5] |User-Agent: c1
**** s1    http[ 6] |X-Forwarded-For: 127.0.0.1
**** s1    http[ 7] |Via: 1.1 v1 (Varnish/trunk)
**** s1    http[ 8] |Accept-Encoding: gzip
**** dT    6.714
**** s1    http[ 9] |X-Varnish: 1008
**** s1    bodylen = 0
**   s1    === expect req.http.Accept-Language == en
**** s1    EXPECT req.http.Accept-Language (en) == "en" match
**   s1    === txresp -hdr "Vary: Accept-Language" -body en
**** s1    txresp|HTTP/1.1 200 OK\r
**** s1    txresp|Vary: Accept-Language\r
**** s1    txresp|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** s1    txresp|Server: s1\r
**** s1    txresp|Content-Length: 2\r
**** s1    txresp|\r
**** s1    txresp|en
***  s1    shutting fd 4
**   s1    Ending
**** dT    6.720
**** c1    rxhdr|HTTP/1.1 200 OK\r
**** c1    rxhdr|Vary: Accept-Language\r
**** c1    rxhdr|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** c1    rxhdr|Server: s1\r
**** c1    rxhdr|Content-Length: 2\r
**** c1    rxhdr|X-Varnish-Be: 1008\r
**** c1    rxhdr|X-Varnish: 1007\r
**** c1    rxhdr|Age: 0\r
**** c1    rxhdr|Via: 1.1 v1 (Varnish/trunk)\r
**** c1    rxhdr|Accept-Ranges: bytes\r
**** c1    rxhdr|Connection: keep-alive\r
**** c1    rxhdr|\r
**** c1    rxhdrlen = 230
**** c1    http[ 0] |HTTP/1.1
**** c1    http[ 1] |200
**** c1    http[ 2] |OK
**** c1    http[ 3] |Vary: Accept-Language
**** c1    http[ 4] |Date: Wed, 11 Dec 2024 13:34:22 GMT
**** c1    http[ 5] |Server: s1
**** c1    http[ 6] |Content-Length: 2
**** c1    http[ 7] |X-Varnish-Be: 1008
**** c1    http[ 8] |X-Varnish: 1007
**** c1    http[ 9] |Age: 0
**** c1    http[10] |Via: 1.1 v1 (Varnish/trunk)
**** c1    http[11] |Accept-Ranges: bytes
**** c1    http[12] |Connection: keep-alive
**** dT    6.721
**** c1    c-l|en
**** c1    bodylen = 2
**   c1    === expect resp.body == en
**** dT    6.722
**** c1    EXPECT resp.body (en) == "en" match
**   c1    === expect resp.http.X-Varnish-Be == 1008
**** c1    EXPECT resp.http.X-Varnish-Be (1008) == "1008" match
**   c1    === txreq -req PURGE
**** c1    txreq|PURGE / HTTP/1.1\r
**** c1    txreq|Host: 127.0.0.1\r
**** c1    txreq|User-Agent: c1\r
**** c1    txreq|\r
**   c1    === rxresp
**** dT    6.737
**** l3    match|          0 ExpKill         - EXP_Removed x=1008 t=120 h=0
**** l3    done |
**** dT    6.739
**** c1    rxhdr|HTTP/1.1 200 OK\r
**** c1    rxhdr|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** c1    rxhdr|Server: Varnish\r
**** c1    rxhdr|X-Varnish: 1009\r
**** c1    rxhdr|purged: 2\r
**** c1    rxhdr|Content-Length: 0\r
**** c1    rxhdr|Connection: keep-alive\r
**** c1    rxhdr|\r
**** c1    rxhdrlen = 144
**** c1    http[ 0] |HTTP/1.1
**** c1    http[ 1] |200
**** c1    http[ 2] |OK
**** c1    http[ 3] |Date: Wed, 11 Dec 2024 13:34:22 GMT
**** c1    http[ 4] |Server: Varnish
**** c1    http[ 5] |X-Varnish: 1009
**** c1    http[ 6] |purged: 2
**** c1    http[ 7] |Content-Length: 0
**** c1    http[ 8] |Connection: keep-alive
**** c1    bodylen = 0
**   c1    === expect resp.status == 200
**** c1    EXPECT resp.status (200) == "200" match
**   c1    === expect resp.http.purged == 2
**** c1    EXPECT resp.http.purged (2) == "2" match
***  c1    closing fd 31
**   c1    Ending
**** dT    6.742
**   top   === logexpect l3 -wait
**   l3    Waiting for logexp
**   top   === client c1 {
**   c1    Starting client
**** dT    6.743
**** v1    vsl|          0 ExpKill         - EXP_Inbox flg=1e p=0x20ff6000 e=0.000000 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_When p=0x20ff6000 e=1733924192.144653 f=0x1e
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6000 e=129.998231 f=0x0
**** v1    vsl|       1001 Begin           c req 1000 rxreq
**** v1    vsl|       1001 Timestamp       c Start: 1733924062.133173 0.000000 0.000000
**** v1    vsl|       1001 Timestamp       c Req: 1733924062.133173 0.000000 0.000000
**** v1    vsl|       1001 VCL_use         c vcl1
**** v1    vsl|       1001 ReqStart        c 127.0.0.1 51318 a0
**** v1    vsl|       1001 ReqMethod       c GET
**** v1    vsl|       1001 ReqURL          c /
**** v1    vsl|       1001 ReqProtocol     c HTTP/1.1
**** v1    vsl|       1001 ReqHeader       c Accept-Language: fr
**** v1    vsl|       1001 ReqHeader       c Host: 127.0.0.1
**** v1    vsl|       1001 ReqHeader       c User-Agent: c1
**** v1    vsl|       1001 ReqHeader       c X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1001 ReqHeader       c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1001 VCL_call        c RECV
**** v1    vsl|       1001 VCL_return      c hash
**** v1    vsl|       1001 VCL_call        c HASH
**** v1    vsl|       1001 VCL_return      c lookup
**** v1    vsl|       1001 VCL_call        c MISS
**** v1    vsl|       1001 VCL_return      c fetch
**** v1    vsl|       1001 Link            c bereq 1002 fetch
**** v1    vsl|       1001 Timestamp       c Fetch: 1733924062.146605 0.013432 0.013432
**** v1    vsl|       1001 RespProtocol    c HTTP/1.1
**** v1    vsl|       1001 RespStatus      c 200
**** v1    vsl|       1001 RespReason      c OK
**** v1    vsl|       1001 RespHeader      c Vary: Accept-Language
**** v1    vsl|       1001 RespHeader      c Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1001 RespHeader      c Server: s1
**** v1    vsl|       1001 RespHeader      c Content-Length: 2
**** v1    vsl|       1001 RespHeader      c X-Varnish-Be: 1002
**** v1    vsl|       1001 RespHeader      c X-Varnish: 1001
**** v1    vsl|       1001 RespHeader      c Age: 0
**** dT    6.744
**** v1    vsl|       1001 RespHeader      c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1001 RespHeader      c Accept-Ranges: bytes
**** v1    vsl|       1001 VCL_call        c DELIVER
**** v1    vsl|       1001 VCL_return      c deliver
**** v1    vsl|       1001 Timestamp       c Process: 1733924062.146904 0.013730 0.000298
**** v1    vsl|       1001 Filters         c 
**** v1    vsl|       1001 RespHeader      c Connection: keep-alive
**** v1    vsl|       1001 Timestamp       c Resp: 1733924062.162638 0.029465 0.015734
**** v1    vsl|       1001 ReqAcct         c 72 0 72 230 2 232
**** v1    vsl|       1001 End             c 
**** v1    vsl|       1000 Link            c req 1003 rxreq
**** v1    vsl|          0 ExpKill         - EXP_Rearm p=0x20ff6000 E=1733924192.144653 e=1733924072.162910 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6000 e=129.980915 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_Inbox flg=e p=0x20ff6000 e=1733924192.144653 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_When p=0x20ff6000 e=1733924072.162910 f=0xe
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6000 e=9.999066 f=0x0
**** v1    vsl|       1003 Begin           c req 1000 rxreq
**** v1    vsl|       1003 Timestamp       c Start: 1733924062.162910 0.000000 0.000000
**** v1    vsl|       1003 Timestamp       c Req: 1733924062.162910 0.000000 0.000000
**** v1    vsl|       1003 VCL_use         c vcl1
**** v1    vsl|       1003 ReqStart        c 127.0.0.1 51318 a0
**** v1    vsl|       1003 ReqMethod       c SOFTPURGE
**** v1    vsl|       1003 ReqURL          c /
**** v1    vsl|       1003 ReqProtocol     c HTTP/1.1
**** v1    vsl|       1003 ReqHeader       c Host: 127.0.0.1
**** v1    vsl|       1003 ReqHeader       c User-Agent: c1
**** v1    vsl|       1003 ReqHeader       c X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1003 ReqHeader       c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1003 VCL_call        c RECV
**** v1    vsl|       1003 VCL_return      c hash
**** v1    vsl|       1003 VCL_call        c HASH
**** v1    vsl|       1003 VCL_return      c lookup
**** v1    vsl|       1003 VCL_call        c MISS
**** v1    vsl|       1003 ReqHeader       c purged: 1
**** v1    vsl|       1003 VCL_return      c synth
**** v1    vsl|       1003 RespProtocol    c HTTP/1.1
**** v1    vsl|       1003 RespStatus      c 200
**** v1    vsl|       1003 RespReason      c OK
**** v1    vsl|       1003 RespHeader      c Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1003 RespHeader      c Server: Varnish
**** v1    vsl|       1003 RespHeader      c X-Varnish: 1003
**** v1    vsl|       1003 VCL_call        c SYNTH
**** v1    vsl|       1003 RespHeader      c purged: 1
**** v1    vsl|       1003 VCL_return      c deliver
**** v1    vsl|       1003 Timestamp       c Process: 1733924062.165646 0.002736 0.002736
**** v1    vsl|       1003 RespHeader      c Content-Length: 0
**** v1    vsl|       1003 Storage         c malloc Transient
**** v1    vsl|       1003 Filters         c 
**** v1    vsl|       1003 RespHeader      c Connection: keep-alive
**** v1    vsl|       1003 Timestamp       c Resp: 1733924062.169008 0.006098 0.003361
**** v1    vsl|       1003 ReqAcct         c 57 0 57 144 0 144
**** v1    vsl|       1003 End             c 
**** v1    vsl|       1000 Link            c req 1004 rxreq
**** v1    vsl|       1002 Begin           b bereq 1001 fetch
**** v1    vsl|       1002 VCL_use         b vcl1
**** v1    vsl|       1002 Timestamp       b Start: 1733924062.136522 0.000000 0.000000
**** v1    vsl|       1002 BereqMethod     b GET
**** v1    vsl|       1002 BereqURL        b /
**** v1    vsl|       1002 BereqProtocol   b HTTP/1.1
**** v1    vsl|       1002 BereqHeader     b Accept-Language: fr
**** v1    vsl|       1002 BereqHeader     b Host: 127.0.0.1
**** v1    vsl|       1002 BereqHeader     b User-Agent: c1
**** v1    vsl|       1002 BereqHeader     b X-Forwarded-For: 127.0.0.1
**** dT    6.745
**** v1    vsl|       1002 BereqHeader     b Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1002 BereqHeader     b Accept-Encoding: gzip
**** v1    vsl|       1002 BereqHeader     b X-Varnish: 1002
**** v1    vsl|       1002 VCL_call        b BACKEND_FETCH
**** v1    vsl|       1002 VCL_return      b fetch
**** v1    vsl|       1002 Timestamp       b Fetch: 1733924062.136795 0.000273 0.000273
**** v1    vsl|       1002 Timestamp       b Connected: 1733924062.137766 0.001243 0.000970
**** v1    vsl|       1002 BackendOpen     b 23 s1 127.0.0.1 12683 127.0.0.1 51024 connect
**** v1    vsl|       1002 Timestamp       b Bereq: 1733924062.144359 0.007837 0.006593
**** v1    vsl|       1002 BerespProtocol  b HTTP/1.1
**** v1    vsl|       1002 BerespStatus    b 200
**** v1    vsl|       1002 BerespReason    b OK
**** v1    vsl|       1002 BerespHeader    b Vary: Accept-Language
**** v1    vsl|       1002 BerespHeader    b Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1002 BerespHeader    b Server: s1
**** v1    vsl|       1002 BerespHeader    b Content-Length: 2
**** v1    vsl|       1002 Timestamp       b Beresp: 1733924062.144652 0.008130 0.000293
**** v1    vsl|       1002 TTL             b RFC 120 10 0 1733924062 1733924062 1733924062 0 0 cacheable
**** v1    vsl|       1002 VCL_call        b BACKEND_RESPONSE
**** v1    vsl|       1002 BerespHeader    b X-Varnish-Be: 1002
**** v1    vsl|       1002 VCL_return      b deliver
**** v1    vsl|       1002 Timestamp       b Process: 1733924062.145230 0.008708 0.000577
**** v1    vsl|       1002 Filters         b 
**** v1    vsl|       1002 Storage         b malloc s0
**** v1    vsl|       1002 Fetch_Body      b 3 length stream
**** v1    vsl|       1002 BackendClose    b 23 s1 recycle
**** v1    vsl|       1002 Timestamp       b BerespBody: 1733924062.163946 0.027423 0.018715
**** v1    vsl|       1002 Length          b 2
**** v1    vsl|       1002 BereqAcct       b 169 0 169 110 2 112
**** v1    vsl|       1002 End             b 
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6000 e=9.985539 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_Inbox flg=1e p=0x20ff6080 e=0.000000 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_When p=0x20ff6080 e=1733924192.176331 f=0x1e
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6000 e=9.985419 f=0x0
**** v1    vsl|       1004 Begin           c req 1000 rxreq
**** v1    vsl|       1004 Timestamp       c Start: 1733924062.169314 0.000000 0.000000
**** v1    vsl|       1004 Timestamp       c Req: 1733924062.169314 0.000000 0.000000
**** v1    vsl|       1004 VCL_use         c vcl1
**** v1    vsl|       1004 ReqStart        c 127.0.0.1 51318 a0
**** v1    vsl|       1004 ReqMethod       c GET
**** v1    vsl|       1004 ReqURL          c /
**** v1    vsl|       1004 ReqProtocol     c HTTP/1.1
**** v1    vsl|       1004 ReqHeader       c Accept-Language: fr
**** v1    vsl|       1004 ReqHeader       c Host: 127.0.0.1
**** v1    vsl|       1004 ReqHeader       c User-Agent: c1
**** v1    vsl|       1004 ReqHeader       c X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1004 ReqHeader       c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1004 VCL_call        c RECV
**** v1    vsl|       1004 VCL_return      c hash
**** v1    vsl|       1004 VCL_call        c HASH
**** v1    vsl|       1004 VCL_return      c lookup
**** v1    vsl|       1004 Hit             c 1002 -0.006404 10.000000 0.000000 2 2
**** v1    vsl|       1004 VCL_call        c HIT
**** v1    vsl|       1004 VCL_return      c deliver
**** v1    vsl|       1004 Link            c bereq 1005 bgfetch
**** v1    vsl|       1004 Timestamp       c Fetch: 1733924062.171597 0.002283 0.002283
**** v1    vsl|       1004 RespProtocol    c HTTP/1.1
**** v1    vsl|       1004 RespStatus      c 200
**** v1    vsl|       1004 RespReason      c OK
**** v1    vsl|       1004 RespHeader      c Vary: Accept-Language
**** v1    vsl|       1004 RespHeader      c Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1004 RespHeader      c Server: s1
**** v1    vsl|       1004 RespHeader      c Content-Length: 2
**** dT    6.746
**** v1    vsl|       1004 RespHeader      c X-Varnish-Be: 1002
**** v1    vsl|       1004 RespHeader      c X-Varnish: 1004 1002
**** v1    vsl|       1004 RespHeader      c Age: 0
**** v1    vsl|       1004 RespHeader      c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1004 RespHeader      c Accept-Ranges: bytes
**** v1    vsl|       1004 VCL_call        c DELIVER
**** v1    vsl|       1004 VCL_return      c deliver
**** v1    vsl|       1004 Timestamp       c Process: 1733924062.171839 0.002525 0.000241
**** v1    vsl|       1004 Filters         c 
**** v1    vsl|       1004 RespHeader      c Connection: keep-alive
**** v1    vsl|       1004 Timestamp       c Resp: 1733924062.182046 0.012732 0.010206
**** v1    vsl|       1004 ReqAcct         c 72 0 72 235 2 237
**** v1    vsl|       1004 End             c 
**** v1    vsl|       1000 SessClose       c REM_CLOSE 0.050
**** v1    vsl|       1000 End             c 
**** v1    vsl|          0 ExpKill         - VBF_Superseded x=1002 n=1005
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6000 e=9.967980 f=0x80
**** v1    vsl|          0 ExpKill         - EXP_Inbox flg=26 p=0x20ff6000 e=1733924072.162910 f=0x80
**** v1    vsl|          0 ExpKill         - EXP_Removed x=1002 t=-0 h=1
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6080 e=129.981229 f=0x0
**** v1    vsl|       1005 Begin           b bereq 1004 bgfetch
**** v1    vsl|       1005 VCL_use         b vcl1
**** v1    vsl|       1005 Timestamp       b Start: 1733924062.170521 0.000000 0.000000
**** v1    vsl|       1005 BereqMethod     b GET
**** v1    vsl|       1005 BereqURL        b /
**** v1    vsl|       1005 BereqProtocol   b HTTP/1.1
**** v1    vsl|       1005 BereqHeader     b Accept-Language: fr
**** v1    vsl|       1005 BereqHeader     b Host: 127.0.0.1
**** v1    vsl|       1005 BereqHeader     b User-Agent: c1
**** v1    vsl|       1005 BereqHeader     b X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1005 BereqHeader     b Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1005 BereqHeader     b Accept-Encoding: gzip
**** v1    vsl|       1005 BereqHeader     b X-Varnish: 1005
**** v1    vsl|       1005 VCL_call        b BACKEND_FETCH
**** v1    vsl|       1005 VCL_return      b fetch
**** v1    vsl|       1005 Timestamp       b Fetch: 1733924062.170742 0.000220 0.000220
**** v1    vsl|       1005 Timestamp       b Connected: 1733924062.170823 0.000301 0.000081
**** v1    vsl|       1005 BackendOpen     b 23 s1 127.0.0.1 12683 127.0.0.1 51024 reuse
**** v1    vsl|       1005 Timestamp       b Bereq: 1733924062.175816 0.005294 0.004993
**** v1    vsl|       1005 BerespProtocol  b HTTP/1.1
**** v1    vsl|       1005 BerespStatus    b 200
**** v1    vsl|       1005 BerespReason    b OK
**** v1    vsl|       1005 BerespHeader    b Vary: Accept-Language
**** v1    vsl|       1005 BerespHeader    b Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1005 BerespHeader    b Server: s1
**** v1    vsl|       1005 BerespHeader    b Content-Length: 2
**** v1    vsl|       1005 Timestamp       b Beresp: 1733924062.176331 0.005809 0.000514
**** v1    vsl|       1005 TTL             b RFC 120 10 0 1733924062 1733924062 1733924062 0 0 cacheable
**** v1    vsl|       1005 VCL_call        b BACKEND_RESPONSE
**** v1    vsl|       1005 BerespHeader    b X-Varnish-Be: 1005
**** v1    vsl|       1005 VCL_return      b deliver
**** v1    vsl|       1005 Timestamp       b Process: 1733924062.176830 0.006308 0.000499
**** v1    vsl|       1005 Filters         b 
**** v1    vsl|       1005 Storage         b malloc s0
**** v1    vsl|       1005 Fetch_Body      b 3 length stream
**** v1    vsl|       1005 BackendClose    b 23 s1 recycle
**** v1    vsl|       1005 Timestamp       b BerespBody: 1733924062.194772 0.024250 0.017941
**** v1    vsl|       1005 Length          b 2
**** v1    vsl|       1005 BereqAcct       b 169 0 169 110 2 112
**** v1    vsl|       1005 End             b 
**** v1    vsl|       1006 Begin           c sess 0 HTTP/1
**** v1    vsl|       1006 SessOpen        c 127.0.0.1 43540 a0 127.0.0.1 30367 1733924062.200829 21
**** dT    6.747
**** v1    vsl|       1006 Debug           c sockopt: SO_LINGER may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1006 Debug           c sockopt: Setting SO_KEEPALIVE for a0=127.0.0.1:30367
**** v1    vsl|       1006 Debug           c sockopt: Setting SO_SNDTIMEO for a0=127.0.0.1:30367
**** v1    vsl|       1006 Debug           c sockopt: Setting SO_RCVTIMEO for a0=127.0.0.1:30367
**** v1    vsl|       1006 Debug           c sockopt: Setting TCP_NODELAY for a0=127.0.0.1:30367
**** v1    vsl|       1006 Debug           c sockopt: TCP_KEEPIDLE may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1006 Debug           c sockopt: TCP_KEEPCNT may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1006 Debug           c sockopt: TCP_KEEPINTVL may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1006 Link            c req 1007 rxreq
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6080 e=129.966478 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_Inbox flg=1e p=0x21027000 e=0.000000 f=0x0
**** v1    vsl|          0 ExpKill         - EXP_When p=0x21027000 e=1733924192.208496 f=0x1e
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6080 e=129.966323 f=0x0
**** v1    vsl|       1007 Begin           c req 1006 rxreq
**** v1    vsl|       1007 Timestamp       c Start: 1733924062.201516 0.000000 0.000000
**** v1    vsl|       1007 Timestamp       c Req: 1733924062.201516 0.000000 0.000000
**** v1    vsl|       1007 VCL_use         c vcl1
**** v1    vsl|       1007 ReqStart        c 127.0.0.1 43540 a0
**** v1    vsl|       1007 ReqMethod       c GET
**** v1    vsl|       1007 ReqURL          c /
**** v1    vsl|       1007 ReqProtocol     c HTTP/1.1
**** v1    vsl|       1007 ReqHeader       c Accept-Language: en
**** v1    vsl|       1007 ReqHeader       c Host: 127.0.0.1
**** v1    vsl|       1007 ReqHeader       c User-Agent: c1
**** v1    vsl|       1007 ReqHeader       c X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1007 ReqHeader       c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1007 VCL_call        c RECV
**** v1    vsl|       1007 VCL_return      c hash
**** v1    vsl|       1007 VCL_call        c HASH
**** v1    vsl|       1007 VCL_return      c lookup
**** v1    vsl|       1007 VCL_call        c MISS
**** v1    vsl|       1007 VCL_return      c fetch
**** v1    vsl|       1007 Link            c bereq 1008 fetch
**** v1    vsl|       1007 Timestamp       c Fetch: 1733924062.210146 0.008629 0.008629
**** v1    vsl|       1007 RespProtocol    c HTTP/1.1
**** v1    vsl|       1007 RespStatus      c 200
**** v1    vsl|       1007 RespReason      c OK
**** v1    vsl|       1007 RespHeader      c Vary: Accept-Language
**** v1    vsl|       1007 RespHeader      c Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1007 RespHeader      c Server: s1
**** v1    vsl|       1007 RespHeader      c Content-Length: 2
**** v1    vsl|       1007 RespHeader      c X-Varnish-Be: 1008
**** v1    vsl|       1007 RespHeader      c X-Varnish: 1007
**** v1    vsl|       1007 RespHeader      c Age: 0
**** v1    vsl|       1007 RespHeader      c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1007 RespHeader      c Accept-Ranges: bytes
**** v1    vsl|       1007 VCL_call        c DELIVER
**** v1    vsl|       1007 VCL_return      c deliver
**** v1    vsl|       1007 Timestamp       c Process: 1733924062.210395 0.008879 0.000249
**** v1    vsl|       1007 Filters         c 
**** v1    vsl|       1007 RespHeader      c Connection: keep-alive
**** v1    vsl|       1007 Timestamp       c Resp: 1733924062.226428 0.024911 0.016032
**** v1    vsl|       1007 ReqAcct         c 72 0 72 230 2 232
**** v1    vsl|       1007 End             c 
**** v1    vsl|       1006 Link            c req 1009 rxreq
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6080 e=129.948925 f=0x80
**** v1    vsl|          0 ExpKill         - EXP_Inbox flg=26 p=0x21027000 e=1733924192.208496 f=0x80
**** v1    vsl|          0 ExpKill         - EXP_Removed x=1008 t=120 h=0
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6080 e=129.948776 f=0x80
**** v1    vsl|       1008 Begin           b bereq 1007 fetch
**** v1    vsl|       1008 VCL_use         b vcl1
**** v1    vsl|       1008 Timestamp       b Start: 1733924062.203497 0.000000 0.000000
**** v1    vsl|       1008 BereqMethod     b GET
**** dT    6.748
**** v1    vsl|       1008 BereqURL        b /
**** v1    vsl|       1008 BereqProtocol   b HTTP/1.1
**** v1    vsl|       1008 BereqHeader     b Accept-Language: en
**** v1    vsl|       1008 BereqHeader     b Host: 127.0.0.1
**** v1    vsl|       1008 BereqHeader     b User-Agent: c1
**** v1    vsl|       1008 BereqHeader     b X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1008 BereqHeader     b Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1008 BereqHeader     b Accept-Encoding: gzip
**** v1    vsl|       1008 BereqHeader     b X-Varnish: 1008
**** v1    vsl|       1008 VCL_call        b BACKEND_FETCH
**** v1    vsl|       1008 VCL_return      b fetch
**** v1    vsl|       1008 Timestamp       b Fetch: 1733924062.203709 0.000212 0.000212
**** v1    vsl|       1008 Timestamp       b Connected: 1733924062.203791 0.000293 0.000081
**** v1    vsl|       1008 BackendOpen     b 23 s1 127.0.0.1 12683 127.0.0.1 51024 reuse
**** v1    vsl|       1008 Timestamp       b Bereq: 1733924062.207903 0.004406 0.004112
**** v1    vsl|       1008 BerespProtocol  b HTTP/1.1
**** v1    vsl|       1008 BerespStatus    b 200
**** v1    vsl|       1008 BerespReason    b OK
**** v1    vsl|       1008 BerespHeader    b Vary: Accept-Language
**** v1    vsl|       1008 BerespHeader    b Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1008 BerespHeader    b Server: s1
**** v1    vsl|       1008 BerespHeader    b Content-Length: 2
**** v1    vsl|       1008 Timestamp       b Beresp: 1733924062.208495 0.004998 0.000591
**** v1    vsl|       1008 TTL             b RFC 120 10 0 1733924062 1733924062 1733924062 0 0 cacheable
**** v1    vsl|       1008 VCL_call        b BACKEND_RESPONSE
**** v1    vsl|       1008 BerespHeader    b X-Varnish-Be: 1008
**** v1    vsl|       1008 VCL_return      b deliver
**** v1    vsl|       1008 Timestamp       b Process: 1733924062.209122 0.005625 0.000627
**** v1    vsl|       1008 Filters         b 
**** v1    vsl|       1008 Storage         b malloc s0
**** v1    vsl|       1008 Fetch_Body      b 3 length stream
**** v1    vsl|       1008 BackendClose    b 23 s1 recycle
**** v1    vsl|       1008 Timestamp       b BerespBody: 1733924062.227664 0.024166 0.018541
**** v1    vsl|       1008 Length          b 2
**** v1    vsl|       1008 BereqAcct       b 169 0 169 110 2 112
**** v1    vsl|       1008 End             b 
**** v1    vsl|          0 ExpKill         - EXP_Inspect p=0x20ff6080 e=129.948143 f=0x80
**** v1    vsl|          0 ExpKill         - EXP_Inbox flg=26 p=0x20ff6080 e=1733924192.176331 f=0x80
**** v1    vsl|          0 ExpKill         - EXP_Removed x=1005 t=120 h=0
**** v1    vsl|       1009 Begin           c req 1006 rxreq
**** v1    vsl|       1009 Timestamp       c Start: 1733924062.226700 0.000000 0.000000
**** v1    vsl|       1009 Timestamp       c Req: 1733924062.226700 0.000000 0.000000
**** v1    vsl|       1009 VCL_use         c vcl1
**** v1    vsl|       1009 ReqStart        c 127.0.0.1 43540 a0
**** v1    vsl|       1009 ReqMethod       c PURGE
**** v1    vsl|       1009 ReqURL          c /
**** v1    vsl|       1009 ReqProtocol     c HTTP/1.1
**** v1    vsl|       1009 ReqHeader       c Host: 127.0.0.1
**** v1    vsl|       1009 ReqHeader       c User-Agent: c1
**** v1    vsl|       1009 ReqHeader       c X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1009 ReqHeader       c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1009 VCL_call        c RECV
**** v1    vsl|       1009 VCL_return      c hash
**** v1    vsl|       1009 VCL_call        c HASH
**** v1    vsl|       1009 VCL_return      c lookup
**** v1    vsl|       1009 VCL_call        c MISS
**** v1    vsl|       1009 ReqHeader       c purged: 2
**** v1    vsl|       1009 VCL_return      c synth
**** v1    vsl|       1009 RespProtocol    c HTTP/1.1
**** v1    vsl|       1009 RespStatus      c 200
**** v1    vsl|       1009 RespReason      c OK
**** v1    vsl|       1009 RespHeader      c Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1009 RespHeader      c Server: Varnish
**** dT    6.749
**** v1    vsl|       1009 RespHeader      c X-Varnish: 1009
**** v1    vsl|       1009 VCL_call        c SYNTH
**** v1    vsl|       1009 RespHeader      c purged: 2
**** v1    vsl|       1009 VCL_return      c deliver
**** v1    vsl|       1009 Timestamp       c Process: 1733924062.228716 0.002015 0.002015
**** v1    vsl|       1009 RespHeader      c Content-Length: 0
**** v1    vsl|       1009 Storage         c malloc Transient
**** v1    vsl|       1009 Filters         c 
**** v1    vsl|       1009 RespHeader      c Connection: keep-alive
**** v1    vsl|       1009 Timestamp       c Resp: 1733924062.232581 0.005880 0.003864
**** v1    vsl|       1009 ReqAcct         c 53 0 53 144 0 144
**** v1    vsl|       1009 End             c 
**** v1    vsl|       1006 SessClose       c REM_CLOSE 0.033
**** v1    vsl|       1006 End             c 
**   c1    Waiting for client
**** dT    6.750
**   c1    Started on 127.0.0.1:30367 (1 iterations)
***  c1    Connect to 127.0.0.1:30367
**** dT    6.751
***  c1    connected fd 4 from 127.0.0.1 25083 to 127.0.0.1:30367
**   c1    === txreq -req PURGE
**** c1    txreq|PURGE / HTTP/1.1\r
**** c1    txreq|Host: 127.0.0.1\r
**** c1    txreq|User-Agent: c1\r
**** c1    txreq|\r
**** dT    6.754
**   c1    === rxresp
**** dT    6.756
**** c1    rxhdr|HTTP/1.1 404 Not Found\r
**** c1    rxhdr|Date: Wed, 11 Dec 2024 13:34:22 GMT\r
**** c1    rxhdr|Server: Varnish\r
**** c1    rxhdr|X-Varnish: 1011\r
**** c1    rxhdr|purged: 0\r
**** c1    rxhdr|Content-Length: 0\r
**** c1    rxhdr|Connection: keep-alive\r
**** c1    rxhdr|\r
**** c1    rxhdrlen = 151
**** c1    http[ 0] |HTTP/1.1
**** c1    http[ 1] |404
**** c1    http[ 2] |Not Found
**** c1    http[ 3] |Date: Wed, 11 Dec 2024 13:34:22 GMT
**** c1    http[ 4] |Server: Varnish
**** c1    http[ 5] |X-Varnish: 1011
**** c1    http[ 6] |purged: 0
**** c1    http[ 7] |Content-Length: 0
**** c1    http[ 8] |Connection: keep-alive
**** c1    bodylen = 0
**   c1    === expect resp.status == 404
**** c1    EXPECT resp.status (404) == "404" match
**   c1    === expect resp.http.purged == 0
**** c1    EXPECT resp.http.purged (0) == "0" match
***  c1    closing fd 4
**   c1    Ending
**** dT    6.758
**   top   === logexpect l1 -wait
**   l1    Waiting for logexp
**** dT    6.850
**** v1    vsl|       1010 Begin           c sess 0 HTTP/1
**** v1    vsl|       1010 SessOpen        c 127.0.0.1 25083 a0 127.0.0.1 30367 1733924062.244033 22
**** v1    vsl|       1010 Debug           c sockopt: SO_LINGER may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1010 Debug           c sockopt: Setting SO_KEEPALIVE for a0=127.0.0.1:30367
**** v1    vsl|       1010 Debug           c sockopt: Setting SO_SNDTIMEO for a0=127.0.0.1:30367
**** v1    vsl|       1010 Debug           c sockopt: Setting SO_RCVTIMEO for a0=127.0.0.1:30367
**** v1    vsl|       1010 Debug           c sockopt: Setting TCP_NODELAY for a0=127.0.0.1:30367
**** v1    vsl|       1010 Debug           c sockopt: TCP_KEEPIDLE may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1010 Debug           c sockopt: TCP_KEEPCNT may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1010 Debug           c sockopt: TCP_KEEPINTVL may be inherited for a0=127.0.0.1:30367
**** v1    vsl|       1010 Link            c req 1011 rxreq
**** v1    vsl|       1011 Begin           c req 1010 rxreq
**** v1    vsl|       1011 Timestamp       c Start: 1733924062.244684 0.000000 0.000000
**** v1    vsl|       1011 Timestamp       c Req: 1733924062.244684 0.000000 0.000000
**** v1    vsl|       1011 VCL_use         c vcl1
**** v1    vsl|       1011 ReqStart        c 127.0.0.1 25083 a0
**** v1    vsl|       1011 ReqMethod       c PURGE
**** v1    vsl|       1011 ReqURL          c /
**** v1    vsl|       1011 ReqProtocol     c HTTP/1.1
**** v1    vsl|       1011 ReqHeader       c Host: 127.0.0.1
**** v1    vsl|       1011 ReqHeader       c User-Agent: c1
**** v1    vsl|       1011 ReqHeader       c X-Forwarded-For: 127.0.0.1
**** v1    vsl|       1011 ReqHeader       c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1011 VCL_call        c RECV
**** dT    6.851
**** v1    vsl|       1011 VCL_return      c hash
**** v1    vsl|       1011 VCL_call        c HASH
**** v1    vsl|       1011 VCL_return      c lookup
**** v1    vsl|       1011 VCL_call        c MISS
**** v1    vsl|       1011 ReqHeader       c purged: 0
**** v1    vsl|       1011 VCL_return      c synth
**** v1    vsl|       1011 RespProtocol    c HTTP/1.1
**** v1    vsl|       1011 RespStatus      c 404
**** v1    vsl|       1011 RespReason      c Not Found
**** v1    vsl|       1011 RespHeader      c Date: Wed, 11 Dec 2024 13:34:22 GMT
**** v1    vsl|       1011 RespHeader      c Server: Varnish
**** v1    vsl|       1011 RespHeader      c X-Varnish: 1011
**** v1    vsl|       1011 VCL_call        c SYNTH
**** v1    vsl|       1011 RespHeader      c purged: 0
**** v1    vsl|       1011 VCL_return      c deliver
**** v1    vsl|       1011 Timestamp       c Process: 1733924062.245830 0.001146 0.001146
**** v1    vsl|       1011 RespHeader      c Content-Length: 0
**** v1    vsl|       1011 Storage         c malloc Transient
**** v1    vsl|       1011 Filters         c 
**** v1    vsl|       1011 RespHeader      c Connection: keep-alive
**** v1    vsl|       1011 Timestamp       c Resp: 1733924062.249817 0.005133 0.003987
**** v1    vsl|       1011 ReqAcct         c 53 0 53 151 0 151
**** v1    vsl|       1011 End             c 
**** v1    vsl|       1010 SessClose       c REM_CLOSE 0.006
**** v1    vsl|       1010 End             c 
**** dT    7.491
**** v1    vsl|          0 Debug           - sockopt: Not setting unmodified SO_LINGER for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Not setting unmodified SO_KEEPALIVE for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting SO_SNDTIMEO for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Setting SO_RCVTIMEO for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Not setting unmodified TCP_NODELAY for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Not setting unmodified TCP_KEEPIDLE for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Not setting unmodified TCP_KEEPCNT for a0=127.0.0.1:30367
**** v1    vsl|          0 Debug           - sockopt: Not setting unmodified TCP_KEEPINTVL for a0=127.0.0.1:30367
**** dT    9.510
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924064 1.0
**** dT    12.491
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924067 1.0
**** dT    15.471
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924070 1.0
**** dT    18.550
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924073 1.0
**** dT    21.544
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924076 1.0
**** dT    24.511
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924079 1.0
**** dT    27.521
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924082 1.0
**** dT    30.514
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924085 1.0
**** dT    33.497
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924088 1.0
**** dT    36.489
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924091 1.0
**** dT    39.587
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924094 1.0
**** dT    42.569
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924097 1.0
**** dT    45.564
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924100 1.0
**** dT    48.550
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924103 1.0
**** dT    51.536
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924106 1.0
**** dT    54.527
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924109 1.0
**** dT    57.507
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924112 1.0
**** dT    60.599
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924115 1.0
**** dT    63.590
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924118 1.0
**** dT    66.581
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924122 1.0
**** dT    69.569
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924125 1.0
**** dT    72.554
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924128 1.0
**** dT    75.547
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924131 1.0
**** dT    78.539
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924134 1.0
**** dT    81.639
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924137 1.0
**** dT    84.616
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924140 1.0
**** dT    87.610
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924143 1.0
**** dT    90.602
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924146 1.0
**** dT    93.589
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924149 1.0
**** dT    96.580
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924152 1.0
**** dT    99.664
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924155 1.0
**** dT    102.651
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924158 1.0
**** dT    105.640
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924161 1.0
**** dT    108.629
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924164 1.0
**** dT    111.605
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924167 1.0
**** dT    114.703
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924170 1.0
**** dT    117.680
**** v1    vsl|          0 CLI             - Rd ping
**** v1    vsl|          0 CLI             - Wr 200 19 PONG 1733924173 1.0
#    top  TEST ../../../vmod/tests/purge_c00000.vtc TIMED OUT (kill -9)
#    top  TEST ../../../vmod/tests/purge_c00000.vtc FAILED (120.020) signal=9
FAIL tests/purge_c00000.vtc (exit status: 2)