cache-worker panic on FreeBSD

[michbsd]

Please see issue #2136 on varnish-cache: https://github.com/varnishcache/varnish-cache/issues/2136

When sending a POST request to an special URL - the cache-worker child panics - and it seems to be related the VSF - as when I remove the VSF include I am unable to reproduce the problem.

Please let me know what you require in order to debug this further.

Thanks!

[comotion]

It may also help if you can do a curl -xPOST -Dheader.log request directly to the backend and copy both the headers and the body here, as there may be clues regarding what is happening here.

Like in the varnish-cache ticket, did you get a more detailed backtrace? Ie varnish and VSF vmod built with debug information.. For that is what we need to get closer to the reason behind the problem.

[michbsd]

Right. I will reproduce the problem in my dev environment tomorrow and recompile varnish and vsf with debugging enabled - and send you the new backtraces.

Thanks!

[michbsd]

Here are the headers, when requesting the backend directly :

HTTP/1.1 301 Moved Permanently
Date: Wed, 16 Nov 2016 08:18:49 GMT
Server: Apache/2.4.23 (FreeBSD)
Location: http://www2.myhost.com/38891/agenda/this-is-a-test-d-couvert/
Content-Length: 297
Content-Type: text/html; charset=iso-8859-1

[michbsd]

Please find below a full backtrace:

(gdb) bt
#0  0x0000000801cb66ca in thr_kill () from /lib/libc.so.7
#1  0x0000000801d8b149 in abort () from /lib/libc.so.7
#2  0x000000000044f5cc in pan_ic (func=0x4d47e2 "child_sigsegv_handler", file=0x4d43f7 "mgt/mgt_child.c", line=285,
    cond=0x7ffffed17180 "Segmentation fault by instruction at 0x1", kind=VAS_ASSERT) at cache/cache_panic.c:653
#3  0x0000000000499a1d in child_sigsegv_handler (s=11, si=0x7ffffed17d70, c=0x7ffffed17a00) at mgt/mgt_child.c:283
#4  0x0000000801a32467 in swapcontext () from /lib/libthr.so.3
#5  0x0000000801a32062 in sigaction () from /lib/libthr.so.3
#6  <signal handler called>
#7  0x0000000800920955 in _assert_VSB_integrity (fun=0x80092c607 "VSB_bcat", s=0x1) at vsb.c:86
#8  0x0000000800920a57 in VSB_bcat (s=0x1, buf=0x80984a058, len=4) at vsb.c:283
#9  0x00000008114997e2 in vsf_iter_req_body (req=<value optimized out>, priv=0x80092c607, ptr=0x1, len=4) at vmod_vsf.c:88
#10 0x00000000004bad7f in sml_iterator (wrk=0x7ffffed18d58, oc=0x80984f020, priv=0x809848070, func=0x8114997d0 <vsf_iter_req_body>, final=0) at storage/storage_simple.c:268
#11 0x000000000044bdde in ObjIterate (wrk=0x7ffffed18d58, oc=0x80984f020, priv=0x809848070, func=0x8114997d0 <vsf_iter_req_body>, final=0) at cache/cache_obj.c:185
#12 0x0000000000453e2f in VRB_Iterate (req=0x80a8d8020, func=0x8114997d0 <vsf_iter_req_body>, priv=0x809848070) at cache/cache_req_body.c:168
#13 0x000000081149968b in vmod_body (ctx=0x7ffffed18200, priv=0x809849118, maxsize=<value optimized out>) at vmod_vsf.c:119
#14 0x000000080810a38e in VGC_function_vcl_recv () from vcl_jaf_1.1479286343.728222847/vgc.so
#15 0x0000000000466b5a in vcl_call_method (wrk=0x7ffffed18d58, req=0x80a8d8020, bo=0x0, specific=0x0, method=2, func=0x808108c30 <VGC_function_vcl_recv>)
    at cache/cache_vcl.c:1034
#16 0x0000000000468836 in VCL_recv_method (vcl=0x802c37b80, wrk=0x7ffffed18d58, req=0x80a8d8020, bo=0x0, specific=0x0) at vcl_returns.h:137
#17 0x000000000045619c in cnt_recv (wrk=0x7ffffed18d58, req=0x80a8d8020) at cache/cache_req_fsm.c:692
#18 0x000000000045541d in CNT_Request (wrk=0x7ffffed18d58, req=0x80a8d8020) at steps.h:35
#19 0x00000000004898f2 in HTTP1_Session (wrk=0x7ffffed18d58, req=0x80a8d8020) at http1/cache_http1_fsm.c:455
#20 0x000000000048a616 in http1_req (wrk=0x7ffffed18d58, arg=0x80a8d8020) at http1/cache_http1_fsm.c:87
#21 0x000000000047b7ac in Pool_Work_Thread (pp=0x80900f100, wrk=0x7ffffed18d58) at cache/cache_wrk.c:341
#22 0x000000000047b06c in WRK_Thread (qp=0x80900f100, stacksize=49152, thread_workspace=2048) at cache/cache_wrk.c:121
#23 0x000000000047ad31 in pool_thread (priv=0x80940fc40) at cache/cache_wrk.c:371
#24 0x0000000801a2d4f5 in pthread_create () from /lib/libthr.so.3
#25 0x0000000000000000 in ?? ()

Let me know if you require anything else.

[comotion]

the backtrace is a beauty, we will take a look at it. Looks like the response headers/body are irrelevant here, since the failure is in a vcl_recv codepath. perhaps @fgsch will take an interest?

[fgsch]

Sure thing. I'll take a look.