[Varnish] #1841: r01801.vtc panic on OSX: vwk_thread(), waiter/cache_waiter_kqueue.c line 109:

Varnish varnish-bugs at varnish-cache.org
Fri Jan 15 13:29:54 CET 2016


#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



More information about the varnish-bugs mailing list