[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