[Varnish] #1520: m00011.vtc fails on x86_64

Varnish varnish-bugs at varnish-cache.org
Thu Dec 25 00:25:10 CET 2014


#1520: m00011.vtc fails on x86_64
-------------------------+-----------------------
 Reporter:  yoloseem     |       Owner:
     Type:  defect       |      Status:  reopened
 Priority:  normal       |   Milestone:
Component:  varnishtest  |     Version:  4.0.0
 Severity:  normal       |  Resolution:
 Keywords:               |
-------------------------+-----------------------

Comment (by lkarsten):

 Saw this when building 4.0.2 (from 4.0 branch in git) on OSX.

 Observed: any kind of invalid first argument to std.ip() makes the child
 process go away.

 Expected: child would not die, fallback value will be used/returned.

 The value of fallback does not seem to influence this, as the error
 appears with both 127.0.0.1 and client.ip as the second argument.

 {{{
 **** top   0.0 macro def varnishd=varnishd
 **** top   0.0 macro def varnishadm=varnishadm
 **** top   0.0 macro def varnishstat=varnishstat
 **** top   0.0 macro def varnishhist=varnishhist
 **** top   0.0 macro def varnishlog=varnishlog
 **** top   0.0 macro def varnishncsa=varnishncsa
 **** top   0.0 macro def vmod_std=std from "/Users/lkarsten/work/varnish-
 cache-git/lib/libvmod_std/.libs/libvmod_std.so"
 **** top   0.0 macro def vmod_debug=debug from "/Users/lkarsten/work
 /varnish-cache-git/lib/libvmod_debug/.libs/libvmod_debug.so"
 **** top   0.0 macro def vmod_directors=directors from
 "/Users/lkarsten/work/varnish-cache-
 git/lib/libvmod_directors/.libs/libvmod_directors.so"
 **** top   0.0 macro def pwd=/Users/lkarsten/work/varnish-cache-
 git/bin/varnishtest
 **** top   0.0 macro def topbuild=/Users/lkarsten/work/varnish-cache-git
 **** top   0.0 macro def bad_ip=192.0.2.255
 **** top   0.0 macro def
 tmpdir=/var/folders/tp/lfqnnc595hj9rxwxkzvgtn7h0000gn/T//vtc.43234.1ac78804
 *    top   0.0 TEST tests/m00011.vtc starting
 ***  top   0.0 varnishtest
 *    top   0.0 TEST Test std.ip
 ***  top   0.0 server
 **   s1    0.0 Starting server
 **** s1    0.0 macro def s1_addr=127.0.0.1
 **** s1    0.0 macro def s1_port=54884
 **** s1    0.0 macro def s1_sock=127.0.0.1 54884
 *    s1    0.0 Listen on 127.0.0.1 54884
 ***  top   0.0 varnish
 **   s1    0.0 Started on 127.0.0.1 54884
 **   v1    0.0 Launch
 ***  v1    0.0 CMD: cd ${pwd} && ${varnishd} -d -d -n
 /var/folders/tp/lfqnnc595hj9rxwxkzvgtn7h0000gn/T//vtc.43234.1ac78804/v1 -l
 2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p
 sigsegv_handler=on -p thread_pool_min=10 -a '127.0.0.1:0' -M '127.0.0.1
 54885' -P
 /var/folders/tp/lfqnnc595hj9rxwxkzvgtn7h0000gn/T//vtc.43234.1ac78804/v1/varnishd.pid
 ***  v1    0.0 CMD: cd /Users/lkarsten/work/varnish-cache-
 git/bin/varnishtest && varnishd -d -d -n
 /var/folders/tp/lfqnnc595hj9rxwxkzvgtn7h0000gn/T//vtc.43234.1ac78804/v1 -l
 2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p
 sigsegv_handler=on -p thread_pool_min=10 -a '127.0.0.1:0' -M '127.0.0.1
 54885' -P
 /var/folders/tp/lfqnnc595hj9rxwxkzvgtn7h0000gn/T//vtc.43234.1ac78804/v1/varnishd.pid
 ***  v1    0.0 PID: 43252
 ***  v1    0.0 debug| Platform:
 Darwin,13.4.0,x86_64,-smalloc,-smalloc,-hcritbit\n
 ***  v1    0.0 debug| 200 266     \n
 ***  v1    0.0 debug| -----------------------------\n
 ***  v1    0.0 debug| Varnish Cache CLI 1.0\n
 ***  v1    0.0 debug| -----------------------------\n
 ***  v1    0.0 debug| Darwin,13.4.0,x86_64,-smalloc,-smalloc,-hcritbit\n
 ***  v1    0.0 debug| varnish-4.0.2 revision 887c70e\n
 ***  v1    0.0 debug| \n
 ***  v1    0.0 debug| Type 'help' for command list.\n
 ***  v1    0.0 debug| Type 'quit' to close CLI session.\n
 ***  v1    0.0 debug| Type 'start' to launch worker process.\n
 ***  v1    0.0 debug| \n
 **** v1    0.1 CLIPOLL 1 0x1 0x0
 ***  v1    0.1 CLI connection fd = 8
 ***  v1    0.1 CLI RX  107
 **** v1    0.1 CLI RX| yhexxyfagdoinavcifjqeqfuvddicupd\n
 **** v1    0.1 CLI RX| \n
 **** v1    0.1 CLI RX| Authentication required.\n
 **** v1    0.1 CLI TX| auth
 97fe19ec05bc2b6b46342cd8c1596dfbdd7a72c52842e248ef202d595ff91534\n
 ***  v1    0.1 CLI RX  200
 **** v1    0.1 CLI RX| -----------------------------\n
 **** v1    0.1 CLI RX| Varnish Cache CLI 1.0\n
 **** v1    0.1 CLI RX| -----------------------------\n
 **** v1    0.1 CLI RX| Darwin,13.4.0,x86_64,-smalloc,-smalloc,-hcritbit\n
 **** v1    0.1 CLI RX| varnish-4.0.2 revision 887c70e\n
 **** v1    0.1 CLI RX| \n
 **** v1    0.1 CLI RX| Type 'help' for command list.\n
 **** v1    0.1 CLI RX| Type 'quit' to close CLI session.\n
 **** v1    0.1 CLI RX| Type 'start' to launch worker process.\n
 **** v1    0.1 CLI TX| vcl.inline vcl1 << %XJEIFLH|)Xspa8P\n
 **** v1    0.1 CLI TX| vcl 4.0;\n
 **** v1    0.1 CLI TX| backend s1 { .host = "127.0.0.1"; .port = "54884";
 }\n
 **** v1    0.1 CLI TX| \n
 **** v1    0.1 CLI TX| \n
 **** v1    0.1 CLI TX| \timport std from "/Users/lkarsten/work/varnish-
 cache-git/lib/libvmod_std/.libs/libvmod_std.so";\n
 **** v1    0.1 CLI TX| \tsub vcl_deliver {\n
 **** v1    0.1 CLI TX| \t\t# works\n
 **** v1    0.1 CLI TX| \t\tset resp.http.bar = std.ip("1.2.3.5",
 client.ip);\n
 **** v1    0.1 CLI TX| \t\t# child crashes.\n
 **** v1    0.1 CLI TX| \t\tset resp.http.foo = std.ip("1.2.3.*",
 client.ip);\n
 **** v1    0.1 CLI TX| \t}\n
 **** v1    0.1 CLI TX| \n
 **** v1    0.1 CLI TX| %XJEIFLH|)Xspa8P\n
 ***  v1    0.2 CLI RX  200
 **** v1    0.2 CLI RX| Message from VCC-compiler:\n
 **** v1    0.2 CLI RX| Not running as root, no priv-sep\n
 **** v1    0.2 CLI RX| Message from C-compiler:\n
 **** v1    0.2 CLI RX| Not running as root, no priv-sep\n
 **** v1    0.2 CLI RX| Message from dlopen:\n
 **** v1    0.2 CLI RX| Not running as root, no priv-sep\n
 **** v1    0.2 CLI RX| \n
 **** v1    0.2 CLI RX| VCL compiled.
 **** v1    0.2 CLI TX| vcl.use vcl1
 ***  v1    0.2 CLI RX  200
 **** v1    0.2 CLI RX| VCL 'vcl1' now active
 **   v1    0.2 Start
 **** v1    0.2 CLI TX| start
 ***  v1    0.2 debug| child (43275) Started\n
 ***  v1    0.2 CLI RX  200
 ***  v1    0.2 wait-running
 ***  v1    0.2 debug| Child (43275) said Not running as root, no priv-
 sep\n
 **** v1    0.2 CLI TX| status
 ***  v1    0.2 debug| Child (43275) said Child starts\n
 ***  v1    0.2 CLI RX  200
 **** v1    0.2 CLI RX| Child in state running
 **** v1    0.2 CLI TX| debug.xid 999
 ***  v1    0.2 CLI RX  200
 **** v1    0.2 CLI RX| XID is 999
 **** v1    0.2 CLI TX| debug.listen_address
 ***  v1    0.2 CLI RX  200
 **** v1    0.2 CLI RX| 127.0.0.1 54890\n
 **   v1    0.2 Listen on 127.0.0.1 54890
 **** v1    0.2 macro def v1_addr=127.0.0.1
 **** v1    0.2 macro def v1_port=54890
 **** v1    0.2 macro def v1_sock=127.0.0.1 54890
 ***  top   0.2 client
 **   c1    0.2 Starting client
 **   c1    0.2 Waiting for client
 ***  c1    0.2 Connect to 127.0.0.1 54890
 ***  c1    0.2 connected fd 9 from 127.0.0.1 54891 to 127.0.0.1 54890
 ***  c1    0.2 txreq
 **** c1    0.2 txreq| GET /foo1 HTTP/1.1\r\n
 **** c1    0.2 txreq| \r\n
 ***  c1    0.2 rxresp
 ***  s1    0.3 accepted fd 10
 ***  s1    0.3 rxreq
 **** s1    0.3 rxhdr| GET /foo1 HTTP/1.1\r\n
 **** s1    0.3 rxhdr| X-Forwarded-For: 127.0.0.1\r\n
 **** s1    0.3 rxhdr| Accept-Encoding: gzip\r\n
 **** s1    0.3 rxhdr| X-Varnish: 1002\r\n
 **** s1    0.3 rxhdr| Host: 127.0.0.1\r\n
 **** s1    0.3 rxhdr| \r\n
 **** s1    0.3 http[ 0] | GET
 **** s1    0.3 http[ 1] | /foo1
 **** s1    0.3 http[ 2] | HTTP/1.1
 **** s1    0.3 http[ 3] | X-Forwarded-For: 127.0.0.1
 **** s1    0.3 http[ 4] | Accept-Encoding: gzip
 **** s1    0.3 http[ 5] | X-Varnish: 1002
 **** s1    0.3 http[ 6] | Host: 127.0.0.1
 **** s1    0.3 bodylen = 0
 ***  s1    0.3 txresp
 **** s1    0.3 txresp| HTTP/1.1 200 OK\r\n
 **** s1    0.3 txresp| Content-Length: 1\r\n
 **** s1    0.3 txresp| \r\n
 **** s1    0.3 txresp| 1
 ***  s1    0.3 shutting fd 10
 **   s1    0.3 Ending
 ---- c1    0.3 HTTP rx EOF (fd:9 read: Undefined error: 0)
 *    top   0.3 RESETTING after tests/m00011.vtc
 **   s1    0.3 Waiting for server
 **** s1    0.3 macro undef s1_addr
 **** s1    0.3 macro undef s1_port
 **** s1    0.3 macro undef s1_sock
 **** v1    0.3 vsl|       1000 Begin           c sess 0 HTTP/1
 **** v1    0.3 vsl|       1000 SessOpen        c 127.0.0.1 54891
 127.0.0.1:0 127.0.0.1 54890 1419463280.974417 6
 **** v1    0.3 vsl|       1000 Link            c req 1001 rxreq
 **** v1    0.3 vsl|       1002 Begin           b bereq 1001 fetch
 **** v1    0.3 vsl|       1002 Timestamp       b Start: 1419463280.974853
 0.000000 0.000000
 **** v1    0.3 vsl|       1002 BereqMethod     b GET
 **** v1    0.3 vsl|       1002 BereqURL        b /foo1
 **** v1    0.3 vsl|       1002 BereqProtocol   b HTTP/1.1
 **** v1    0.3 vsl|       1002 BereqHeader     b X-Forwarded-For:
 127.0.0.1
 **** v1    0.3 vsl|       1002 BereqHeader     b Accept-Encoding: gzip
 **** v1    0.3 vsl|       1002 BereqHeader     b X-Varnish: 1002
 **** v1    0.3 vsl|       1002 VCL_call        b BACKEND_FETCH
 **** v1    0.3 vsl|       1002 VCL_return      b fetch
 **** v1    0.3 vsl|       1002 BackendOpen     b 7 s1(127.0.0.1,,54884)
 127.0.0.1 54892
 **** v1    0.3 vsl|       1002 Backend         b 7 s1 s1(127.0.0.1,,54884)
 **** v1    0.3 vsl|       1002 BereqHeader     b Host: 127.0.0.1
 **** v1    0.3 vsl|       1002 Timestamp       b Bereq: 1419463280.975133
 0.000280 0.000280
 **** v1    0.3 vsl|       1002 Timestamp       b Beresp: 1419463280.975551
 0.000698 0.000418
 **** v1    0.3 vsl|       1002 BerespProtocol  b HTTP/1.1
 **** v1    0.3 vsl|       1002 BerespStatus    b 200
 **** v1    0.3 vsl|       1002 BerespReason    b OK
 **** v1    0.3 vsl|       1002 BerespHeader    b Content-Length: 1
 **** v1    0.3 vsl|       1002 BerespHeader    b Date: Wed, 24 Dec 2014
 23:21:20 GMT
 **** v1    0.3 vsl|       1002 TTL             b RFC 120 -1 -1 1419463281
 1419463281 1419463280 0 0
 **** v1    0.3 vsl|       1002 VCL_call        b BACKEND_RESPONSE
 **** v1    0.3 vsl|       1002 VCL_return      b deliver
 **** v1    0.3 vsl|       1002 Storage         b malloc s0
 **** v1    0.3 vsl|       1002 ObjProtocol     b HTTP/1.1
 **** v1    0.3 vsl|       1002 ObjStatus       b 200
 **** v1    0.3 vsl|       1002 ObjReason       b OK
 **** v1    0.3 vsl|       1002 ObjHeader       b Content-Length: 1
 **** v1    0.3 vsl|       1002 ObjHeader       b Date: Wed, 24 Dec 2014
 23:21:20 GMT
 **** v1    0.3 vsl|       1002 Fetch_Body      b 3 length stream
 **** v1    0.3 vsl|       1002 BackendReuse    b 7 s1(127.0.0.1,,54884)
 **** v1    0.3 vsl|       1002 Timestamp       b BerespBody:
 1419463280.975811 0.000958 0.000260
 **** v1    0.3 vsl|       1002 Length          b 1
 **** v1    0.3 vsl|       1002 BereqAcct       b 107 0 107 38 1 39
 **** v1    0.3 vsl|       1002 End             b
 **** v1    0.3 vsl|          0 ExpKill         - EXP_Inbox
 p=0x7fa4f0405040 e=0.000000000 f=0x0
 **** v1    0.3 vsl|          0 ExpKill         - EXP_When p=0x7fa4f0405040
 e=1419463410.975550890 f=0x1c10
 **** v1    1.3 CLI TX| backend.list
 ***  v1    1.3 CLI RX  200
 **** v1    1.3 CLI RX| Backend name                   Refs   Admin
 Probe\n
 **** v1    1.3 CLI RX| s1(127.0.0.1,,54884)           1      probe
 Healthy (no probe)
 **   v1    1.3 Wait
 **** v1    1.3 vsl|          0 CLI             - Rd backend.list
 **** v1    1.3 vsl|          0 CLI             - Wr 200 122 Backend name
 Refs   Admin      Probe
 s1(127.0.0.1,,54884)           1      probe      Healthy (no probe)
 **** v1    1.3 vsl|          0 CLI             - EOF on CLI connection,
 worker stops
 **** v1    2.3 STDOUT poll 0x11
 **   v1    2.3 R 43252 Status: 0000 (u 0.071918 s 0.049559)
 *    top   2.3 TEST tests/m00011.vtc FAILED

 #     top  TEST tests/m00011.vtc FAILED (2.328) exit=1
 }}}

 with m00011.vtc reduced to:
 {{{
 varnishtest "Test std.ip"

 server s1 {
         rxreq
         txresp -body "1"
 } -start


 varnish v1 -vcl+backend {
         import ${vmod_std};
         sub vcl_deliver {
                 # works
                 set resp.http.bar = std.ip("1.2.3.5", client.ip);
                 # child crashes.
                 set resp.http.foo = std.ip("1.2.3.*", client.ip);
         }
 } -start

 client c1 {
         txreq -url "/foo1"
         rxresp
         expect resp.bodylen == 1
 } -run
 }}}

 gitref is 887c70e.

-- 
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1520#comment:8>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator



More information about the varnish-bugs mailing list