Mailing List Archive

#1841: r01801.vtc panic on OSX: vwk_thread(), waiter/cache_waiter_kqueue.c line
109:
----------------------+-------------------
Reporter: lkarsten | Owner:
Type: defect | Status: new
Priority: normal | Milestone:
Component: varnishd | Version: trunk
Severity: normal | Keywords:
----------------------+-------------------
When building 4.1.1-beta1 on OSX, r01801.vtc ends with a panic.
{{{
Assert error in vwk_thread(), waiter/cache_waiter_kqueue.c line 109:\n
Condition(n >= 0) not true.\n
errno = 4 (Interrupted system call)\n
thread = (cache-kqueue)\n
version = varnish-4.1.1-beta1 revision 32af38d\n
ident = Darwin,14.3.0,x86_64,-jnone,-smalloc,-smalloc,-hcritbit,kqueue\n
Backtrace:\n
0x10316a38e: 0 varnishd 0x000000010316a38e
pan_backtrace + 46\n
0x10316a1a7: 0 varnishd 0x000000010316a1a7
pan_ic + 727\n
0x1031c34d0: 0 varnishd 0x00000001031c34d0
vwk_thread + 1296\n
0x7fff842bc268: 0 libsystem_pthread.dylib
0x00007fff842bc268 _pthread_body + 131\n
0x7fff842bc1e5: 0 libsystem_pthread.dylib
0x00007fff842bc1e5 _pthread_body + 0\n
0x7fff842ba41d: 0 libsystem_pthread.dylib
0x00007fff842ba41d thread_start + 13\n
}}}



{{{
FAIL: tests/r01801.vtc (exit: 2)
================================

**** 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/jenkins/slave-
root/workspace/varnish-4.1-build-osx-
x86_64/varnish-4.1.1-beta1/lib/libvmod_std/.libs/libvmod_std.so"
**** top 0.0 macro def vmod_debug=debug from "/Users/jenkins/slave-
root/workspace/varnish-4.1-build-osx-
x86_64/varnish-4.1.1-beta1/lib/libvmod_debug/.libs/libvmod_debug.so"
**** top 0.0 macro def vmod_directors=directors from "/Users/jenkins
/slave-root/workspace/varnish-4.1-build-osx-
x86_64/varnish-4.1.1-beta1/lib/libvmod_directors/.libs/libvmod_directors.so"
**** top 0.0 macro def pwd=/Users/jenkins/slave-
root/workspace/varnish-4.1-build-osx-
x86_64/varnish-4.1.1-beta1/bin/varnishtest
**** top 0.0 macro def topbuild=/Users/jenkins/slave-
root/workspace/varnish-4.1-build-osx-x86_64/varnish-4.1.1-beta1
**** top 0.0 macro def bad_ip=192.0.2.255
**** top 0.0 macro def
tmpdir=/var/folders/8h/vqvgz9dj23j0_b4w54jcnv5w0000gp/T//vtc.87884.22921d6f
* top 0.0 TEST ./tests/r01801.vtc starting
** top 0.0 === varnishtest "Test parsing IP constants"
* top 0.0 TEST Test parsing IP constants
** top 0.0 === server s1 {
** s1 0.0 Starting server
**** s1 0.0 macro def s1_addr=127.0.0.1
**** s1 0.0 macro def s1_port=57043
**** s1 0.0 macro def s1_sock=127.0.0.1 57043
* s1 0.0 Listen on 127.0.0.1 57043
** top 0.0 === varnish v1 -vcl+backend {
** s1 0.0 Started on 127.0.0.1 57043
** v1 0.0 Launch
*** v1 0.0 CMD: cd ${pwd} && exec ${varnishd} -d -n
/var/folders/8h/vqvgz9dj23j0_b4w54jcnv5w0000gp/T//vtc.87884.22921d6f/v1 -l
2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p
sigsegv_handler=on -p thread_pool_min=10 -p debug=+vtc_mode -a
'127.0.0.1:0' -M '127.0.0.1 57044' -P
/var/folders/8h/vqvgz9dj23j0_b4w54jcnv5w0000gp/T//vtc.87884.22921d6f/v1/varnishd.pid
*** v1 0.0 CMD: cd /Users/jenkins/slave-root/workspace/varnish-4.1
-build-osx-x86_64/varnish-4.1.1-beta1/bin/varnishtest && exec varnishd -d
-n /var/folders/8h/vqvgz9dj23j0_b4w54jcnv5w0000gp/T//vtc.87884.22921d6f/v1
-l 2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p
sigsegv_handler=on -p thread_pool_min=10 -p debug=+vtc_mode -a
'127.0.0.1:0' -M '127.0.0.1 57044' -P
/var/folders/8h/vqvgz9dj23j0_b4w54jcnv5w0000gp/T//vtc.87884.22921d6f/v1/varnishd.pid
*** v1 0.0 PID: 87902
**** v1 0.0 macro def v1_pid=87902
**** v1 0.0 macro def
v1_name=/var/folders/8h/vqvgz9dj23j0_b4w54jcnv5w0000gp/T//vtc.87884.22921d6f/v1
*** v1 0.1 debug| Debug: Platform:
Darwin,14.3.0,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
*** v1 0.1 debug| \n
*** v1 0.1 debug| 200 279 \n
*** v1 0.1 debug| -----------------------------\n
*** v1 0.1 debug| Varnish Cache CLI 1.0\n
*** v1 0.1 debug| -----------------------------\n
*** v1 0.1 debug|
Darwin,14.3.0,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
*** v1 0.1 debug| varnish-4.1.1-beta1 revision 32af38d\n
*** v1 0.1 debug| \n
*** v1 0.1 debug| Type 'help' for command list.\n
*** v1 0.1 debug| Type 'quit' to close CLI session.\n
*** v1 0.1 debug| Type 'start' to launch worker process.\n
*** v1 0.1 debug| \n
**** v1 0.2 CLIPOLL 1 0x1 0x0
*** v1 0.2 CLI connection fd = 9
*** v1 0.2 CLI RX 107
**** v1 0.2 CLI RX| cqmckqjwijreqwzngqsujyzridvgodmr\n
**** v1 0.2 CLI RX| \n
**** v1 0.2 CLI RX| Authentication required.\n
**** v1 0.2 CLI TX| auth
29e5d57cb9bcaf141ed17040096b7c24239dc9ad0e22734436bb1f2dce58b5e9\n
*** v1 0.2 CLI RX 200
**** v1 0.2 CLI RX| -----------------------------\n
**** v1 0.2 CLI RX| Varnish Cache CLI 1.0\n
**** v1 0.2 CLI RX| -----------------------------\n
**** v1 0.2 CLI RX|
Darwin,14.3.0,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
**** v1 0.2 CLI RX| varnish-4.1.1-beta1 revision 32af38d\n
**** v1 0.2 CLI RX| \n
**** v1 0.2 CLI RX| Type 'help' for command list.\n
**** v1 0.2 CLI RX| Type 'quit' to close CLI session.\n
**** v1 0.2 CLI RX| Type 'start' to launch worker process.\n
**** v1 0.2 CLI TX| vcl.inline vcl1 << %XJEIFLH|)Xspa8P\n
**** v1 0.2 CLI TX| vcl 4.0;\n
**** v1 0.2 CLI TX| backend s1 { .host = "127.0.0.1"; .port = "57043";
}\n
**** v1 0.2 CLI TX| \n
**** v1 0.2 CLI TX| \n
**** v1 0.2 CLI TX| \timport std from "/Users/jenkins/slave-
root/workspace/varnish-4.1-build-osx-
x86_64/varnish-4.1.1-beta1/lib/libvmod_std/.libs/libvmod_std.so";\n
**** v1 0.2 CLI TX| \n
**** v1 0.2 CLI TX| \tsub vcl_deliver {\n
**** v1 0.2 CLI TX| \t\tset resp.http.foo1 = std.ip("..", "1.2.3.4");\n
**** v1 0.2 CLI TX| \t\tset resp.http.foo2 = std.ip("..",
"1.2.3.4:8000");\n
**** v1 0.2 CLI TX| \t\tset resp.http.foo3 = std.ip("..", "1.2.3.4
8000");\n
**** v1 0.2 CLI TX| \t\tset resp.http.foo4 = std.ip("..", "::1");\n
**** v1 0.2 CLI TX| \t\tset resp.http.foo5 = std.ip("..", "[::1]");\n
**** v1 0.2 CLI TX| \t\tset resp.http.foo6 = std.ip("..",
"[::1]:8000");\n
**** v1 0.2 CLI TX| \t\tset resp.http.bar1 = std.port("1.2.3.4");\n
**** v1 0.2 CLI TX| \t\tset resp.http.bar2 =
std.port("1.2.3.4:8000");\n
**** v1 0.2 CLI TX| \t\tset resp.http.bar3 = std.port("1.2.3.4
8000");\n
**** v1 0.2 CLI TX| \t\tset resp.http.bar4 = std.port("::1");\n
**** v1 0.2 CLI TX| \t\tset resp.http.bar5 = std.port("[::1]");\n
**** v1 0.2 CLI TX| \t\tset resp.http.bar6 = std.port("[::1]:8000");\n
**** v1 0.2 CLI TX| \t}\n
**** v1 0.2 CLI TX| \n
**** v1 0.2 CLI TX| %XJEIFLH|)Xspa8P\n
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| VCL compiled.\n
**** v1 0.3 CLI TX| vcl.use vcl1
*** v1 0.3 CLI RX 200
** v1 0.3 Start
**** v1 0.3 CLI TX| start
*** v1 0.3 debug| Debug: Child (87924) Started\n
*** v1 0.3 debug| Info: Child (87924) said Child starts\n
*** v1 0.3 CLI RX 200
*** v1 0.3 wait-running
**** v1 0.3 CLI TX| status
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| Child in state running
**** v1 0.3 CLI TX| debug.xid 999
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| XID is 999
**** v1 0.3 CLI TX| debug.listen_address
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| 127.0.0.1 57045\n
** v1 0.3 Listen on 127.0.0.1 57045
**** v1 0.3 macro def v1_addr=127.0.0.1
**** v1 0.3 macro def v1_port=57045
**** v1 0.3 macro def v1_sock=127.0.0.1 57045
** top 0.3 === client c1 {
** c1 0.3 Starting client
** c1 0.3 Waiting for client
*** c1 0.3 Connect to 127.0.0.1 57045
*** c1 0.3 connected fd 10 from 127.0.0.1 57049 to 127.0.0.1 57045
** c1 0.3 === txreq
**** c1 0.3 txreq| GET / HTTP/1.1\r\n
**** c1 0.3 txreq| \r\n
** c1 0.3 === rxresp
**** v1 0.3 vsl| 0 CLI - Rd vcl.load "vcl1"
vcl_vcl1/vgc.so 1auto
**** v1 0.3 vsl| 0 CLI - Wr 200 34 Loaded
"vcl_vcl1/vgc.so" as "vcl1"
**** v1 0.3 vsl| 0 CLI - Rd vcl.use "vcl1"
**** v1 0.3 vsl| 0 CLI - Wr 200 0
**** v1 0.3 vsl| 0 CLI - Rd start
**** v1 0.3 vsl| 0 CLI - Wr 200 0
**** v1 0.3 vsl| 0 CLI - Rd debug.xid 999
**** v1 0.3 vsl| 0 CLI - Wr 200 10 XID is 999
**** v1 0.3 vsl| 0 CLI - Rd debug.listen_address
**** v1 0.3 vsl| 0 CLI - Wr 200 16 127.0.0.1 57045

*** s1 0.4 accepted fd 11
** s1 0.4 === rxreq
**** s1 0.4 rxhdr| GET / HTTP/1.1\r\n
**** s1 0.4 rxhdr| X-Forwarded-For: 127.0.0.1\r\n
**** s1 0.4 rxhdr| Accept-Encoding: gzip\r\n
**** s1 0.4 rxhdr| X-Varnish: 1002\r\n
**** s1 0.4 rxhdr| Host: 127.0.0.1\r\n
**** s1 0.4 rxhdr| \r\n
**** s1 0.4 rxhdrlen = 103
**** s1 0.4 http[ 0] | GET
**** s1 0.4 http[ 1] | /
**** s1 0.4 http[ 2] | HTTP/1.1
**** s1 0.4 http[ 3] | X-Forwarded-For: 127.0.0.1
**** s1 0.4 http[ 4] | Accept-Encoding: gzip
**** s1 0.4 http[ 5] | X-Varnish: 1002
**** s1 0.4 http[ 6] | Host: 127.0.0.1
**** s1 0.4 bodylen = 0
** s1 0.4 === txresp
**** s1 0.4 txresp| HTTP/1.1 200 OK\r\n
**** s1 0.4 txresp| Content-Length: 0\r\n
**** s1 0.4 txresp| \r\n
*** s1 0.4 shutting fd 11
** s1 0.4 Ending
**** v1 0.4 vsl| 1000 Begin c sess 0 HTTP/1
**** v1 0.4 vsl| 1000 SessOpen c 127.0.0.1 57049
127.0.0.1:57045 127.0.0.1 57045 1452859801.400176 10
**** v1 0.4 vsl| 1000 Link c req 1001 rxreq
**** v1 0.4 vsl| 0 ExpKill - EXP_Inbox
p=0x7fe0b85025e0 e=0.000000000 f=0x8
**** v1 0.4 vsl| 0 ExpKill - EXP_When p=0x7fe0b85025e0
e=1452859931.401523113 f=0x1c10
**** v1 0.4 vsl| 1002 Begin b bereq 1001 fetch
**** v1 0.4 vsl| 1002 Timestamp b Start: 1452859801.400502
0.000000 0.000000
**** v1 0.4 vsl| 1002 BereqMethod b GET
**** v1 0.4 vsl| 1002 BereqURL b /
**** v1 0.4 vsl| 1002 BereqProtocol b HTTP/1.1
**** v1 0.4 vsl| 1002 BereqHeader b X-Forwarded-For:
127.0.0.1
**** v1 0.4 vsl| 1002 BereqHeader b Accept-Encoding: gzip
**** v1 0.4 vsl| 1002 BereqHeader b X-Varnish: 1002
**** v1 0.4 vsl| 1002 VCL_call b BACKEND_FETCH
**** v1 0.4 vsl| 1002 VCL_return b fetch
**** v1 0.4 vsl| 1002 BereqHeader b Host: 127.0.0.1
**** v1 0.4 vsl| 1002 BackendOpen b 12 vcl1.s1 127.0.0.1
57043 127.0.0.1 57050
**** v1 0.4 vsl| 1002 Timestamp b Bereq: 1452859801.400846
0.000344 0.000344
**** v1 0.4 vsl| 1002 Timestamp b Beresp: 1452859801.401523
0.001021 0.000677
**** v1 0.4 vsl| 1002 BerespProtocol b HTTP/1.1
**** v1 0.4 vsl| 1002 BerespStatus b 200
**** v1 0.4 vsl| 1002 BerespReason b OK
**** v1 0.4 vsl| 1002 BerespHeader b Content-Length: 0
**** v1 0.4 vsl| 1002 BerespHeader b Date: Fri, 15 Jan 2016
12:10:01 GMT
**** v1 0.4 vsl| 1002 TTL b RFC 120 10 -1 1452859801
1452859801 1452859801 0 0
**** v1 0.4 vsl| 1002 VCL_call b BACKEND_RESPONSE
**** v1 0.4 vsl| 1002 VCL_return b deliver
**** v1 0.4 vsl| 1002 Storage b malloc s0
**** v1 0.4 vsl| 1002 ObjProtocol b HTTP/1.1
**** v1 0.4 vsl| 1002 ObjStatus b 200
**** v1 0.4 vsl| 1002 ObjReason b OK
**** v1 0.4 vsl| 1002 ObjHeader b Content-Length: 0
**** v1 0.4 vsl| 1002 ObjHeader b Date: Fri, 15 Jan 2016
12:10:01 GMT
**** v1 0.4 vsl| 1002 Fetch_Body b 0 none -
**** v1 0.4 vsl| 1002 BackendReuse b 12 vcl1.s1
**** v1 0.4 vsl| 1002 Timestamp b BerespBody:
1452859801.412254 0.011752 0.010731
**** v1 0.4 vsl| 1002 Length b 0
**** v1 0.4 vsl| 1002 BereqAcct b 103 0 103 38 0 38
**** v1 0.4 vsl| 1002 End b
---- c1 0.7 HTTP rx EOF (fd:10 read: Undefined error: 0)
* top 0.7 RESETTING after ./tests/r01801.vtc
** s1 0.7 Waiting for server (4/-1)
**** s1 0.7 macro undef s1_addr
**** s1 0.7 macro undef s1_port
**** s1 0.7 macro undef s1_sock
** v1 0.7 Wait
**** v1 0.7 CLI TX| backend.list
*** v1 0.7 debug| Error: Child (87924) died signal=6\n
*** v1 0.7 debug| Error: Child (87924) Last panic at: Fri, 15 Jan 2016
12:10:01 GMT\n
*** v1 0.7 debug| "Assert error in vwk_thread(),
waiter/cache_waiter_kqueue.c line 109:\n
*** v1 0.7 debug| Condition(n >= 0) not true.\n
*** v1 0.7 debug| errno = 4 (Interrupted system call)\n
*** v1 0.7 debug| thread = (cache-kqueue)\n
*** v1 0.7 debug| version = varnish-4.1.1-beta1 revision 32af38d\n
*** v1 0.7 debug| ident =
Darwin,14.3.0,x86_64,-jnone,-smalloc,-smalloc,-hcritbit,kqueue\n
*** v1 0.7 debug| Backtrace:\n
*** v1 0.7 debug| 0x10316a38e: 0 varnishd
0x000000010316a38e pan_backtrace + 46\n
*** v1 0.7 debug| 0x10316a1a7: 0 varnishd
0x000000010316a1a7 pan_ic + 727\n
*** v1 0.7 debug| 0x1031c34d0: 0 varnishd
0x00000001031c34d0 vwk_thread + 1296\n
*** v1 0.7 debug| 0x7fff842bc268: 0 libsystem_pthread.dylib
0x00007fff842bc268 _pthread_body + 131\n
*** v1 0.7 debug| 0x7fff842bc1e5: 0 libsystem_pthread.dylib
0x00007fff842bc1e5 _pthread_body + 0\n
*** v1 0.7 debug| 0x7fff842ba41d: 0 libsystem_pthread.dylib
0x00007fff842ba41d thread_start + 13\n
*** v1 0.7 debug| \n
*** v1 0.7 debug| "\n
*** v1 0.7 debug| Debug: Child cleanup complete\n
*** v1 0.7 CLI RX 101
**** v1 0.7 CLI RX| Unknown request in manager process (child not
running).\n
**** v1 0.7 CLI RX| Type 'help' for more info.
**** v1 1.5 STDOUT poll 0x11
** v1 1.5 R 87902 Status: 0000 (u 0.097042 s 0.057885)
* top 1.6 TEST ./tests/r01801.vtc FAILED

# top TEST ./tests/r01801.vtc FAILED (1.568) exit=1
}}}

--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1841>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator

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