[Varnish] #1351: varnishlog segfault in vtx_scan_linktag

[Varnish]

#1351: varnishlog segfault in vtx_scan_linktag
------------------------+-------------------
 Reporter:  lkarsten    |      Owner:
     Type:  defect      |     Status:  new
 Priority:  normal      |  Milestone:
Component:  varnishlog  |    Version:  trunk
 Severity:  normal      |   Keywords:
------------------------+-------------------
 varnishlog segmentation faults in current master. (00090ea)

 Produce with: ``varnishlog > /dev/null &``, crashes after 3-5 seconds.

 varnishd is running with reduced shmlog size (-l 1M), and ~10kreq/s
 against a single small object.

 12:37:55 [ INFO] run[fryer1]: /opt/varnish/sbin/varnishd -T localhost:6082
 -a :6081 -f /opt/varnish/etc/testsuite.vcl -smalloc,50M -l1M -p
 default_ttl=86400 -p thread_pool_min=100
 12:37:57 [DEBUG] scp[fryer2]: ['scp', 'templates/siegerc.tmpl',
 'root at fryer2.varnish-software.com:.siegerc']
 12:37:57 [ INFO] run[fryer2]: ulimit -n 65548; siege -t 60m  -c 3
 http://fryer1.varnish-software.com:6081/cacheabledata/set_hot1/index.html

 {{{
 Program terminated with signal 11, Segmentation fault.
 #0  0x00007f40e9e8cc3a in vtx_scan_linktag (vslq=0x2305430, vtx=0x2305720,
     ptr=0x23273a0) at vsl_dispatch.c:596
 596             assert(VSL_TAG(ptr) == SLT_Link);
 (gdb) bt full
 #0  0x00007f40e9e8cc3a in vtx_scan_linktag (vslq=0x2305430, vtx=0x2305720,
     ptr=0x23273a0) at vsl_dispatch.c:596
         i = 0
         c_type = 32576
         c_vxid = 36860832
         c_vtx = 0x23057c0
         __func__ = "vtx_scan_linktag"
 #1  0x00007f40e9e8cf7e in vtx_scan (vslq=0x2305430, vtx=0x2305720)
     at vsl_dispatch.c:662
         ptr = 0x23273a0
         tag = SLT_Link
         ret = 0x0
         __func__ = "vtx_scan"
 #2  0x00007f40e9e8e3db in VSLQ_Dispatch (vslq=0x2305430,
     func=0x401790 <VSL_PrintTransactions at plt>, priv=0x0) at
 vsl_dispatch.c:954
         c = 0x2305328
         i = 1
         tag = SLT_Link
         len = 5
         vxid = 65537
         vtx = 0x2305720
         now = 4.9406564584124654e-317
         __func__ = "VSLQ_Dispatch"
 #3  0x00000000004028d8 in VUT_Main (func=0x401790
 <VSL_PrintTransactions at plt>,
     priv=0x0) at ../../lib/libvarnishtools/vut.c:297
         c = 0x0
         i = 0
         __func__ = "VUT_Main"
 #4  0x0000000000401ba0 in main (argc=1, argv=0x7fff55ca7918) at
 varnishlog.c:83
         opt = -1 '\377'
 (gdb)

 }}}

 vcl is standard but with streaming+conditionals disabled.
 {{{
 vcl 4.0;
 # Autogenerated by varnish-fry.

 backend default { .host = "127.0.0.1"; .port = "80"; }

 sub vcl_recv { unset req.http.if-modified-since; unset req.http.if-none-
 match; } sub vcl_backend_response { set beresp.do_stream = false; }
 }}}

 A rerun to confirm (this time to stdout, not /dev/null) made it crash with
 this (possibly unrelated) backtrace:

 {{{
 (gdb) bt full
 #0  0x00007fb44718b425 in raise () from /lib/x86_64-linux-gnu/libc.so.6
 No symbol table info available.
 #1  0x00007fb44718eb8b in abort () from /lib/x86_64-linux-gnu/libc.so.6
 No symbol table info available.
 #2  0x00007fb447c3c41d in VAS_Fail_default (
     func=0x7fb447c52704 "vslc_vtx_next", file=0x7fb447c51e7e
 "vsl_dispatch.c",
     line=212, cond=0x7fb447c51f48 "c->offset <= c->vtx->len", err=0,
     kind=VAS_ASSERT) at ../libvarnish/vas.c:67
 No locals.
 #3  0x00007fb447c47c71 in vslc_vtx_next (cursor=0xd3bca0) at
 vsl_dispatch.c:212
         c = 0xd3bc98
         chunk = 0xd3bce0
         __func__ = "vslc_vtx_next"
 #4  0x00007fb447c463dc in VSL_Next (cursor=0xd3bca0) at vsl_cursor.c:464
         tbl = 0x7fb447e578c0
         __func__ = "VSL_Next"
 #5  0x00007fb447c4d234 in VSL_PrintTransactions (vsl=0xd3b010,
     pt=0x7fff54bdb760, fo=0x7fb44750e260) at vsl.c:346
         t = 0x7fff54bdb780
         i = 0
         delim = 1
         verbose = 0
         __func__ = "VSL_PrintTransactions"
 #6  0x00007fb447c4a754 in vslq_callback (vslq=0xd3b430, vtx=0x0,
     func=0x401790 <VSL_PrintTransactions at plt>, priv=0x0) at
 vsl_dispatch.c:754
         n = 1
         vtxs = 0x7fff54bdb7b0
         trans = 0x7fff54bdb780
         ptrans = 0x7fff54bdb760
         i = 1
         j = 1
         __func__ = "vslq_callback"
 #7  0x00007fb447c4b448 in VSLQ_Dispatch (vslq=0xd3b430,
     func=0x401790 <VSL_PrintTransactions at plt>, priv=0x0) at
 vsl_dispatch.c:957
         c = 0xd3b328
         i = 1
         tag = SLT__Batch
         len = 288
         vxid = 4309726
 ---Type <return> to continue, or q <return> to quit---
         vtx = 0xd3bc00
         now = 4.9406564584124654e-317
         __func__ = "VSLQ_Dispatch"
 #8  0x00000000004028d8 in VUT_Main (func=0x401790
 <VSL_PrintTransactions at plt>,
     priv=0x0) at ../../lib/libvarnishtools/vut.c:297
         c = 0x0
         i = 0
         __func__ = "VUT_Main"
 #9  0x0000000000401ba0 in main (argc=1, argv=0x7fff54bdba18) at
 varnishlog.c:83
         opt = -1 '\377'

 }}}

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