[Varnish] #1866: varnishncsa stops consuming logs after Assert error in vslc_vsm_next()

[Varnish]

#1866: varnishncsa stops consuming logs after Assert error in vslc_vsm_next()
--------------------+-------------------------
 Reporter:  johtru  |       Type:  defect
   Status:  new     |   Priority:  normal
Milestone:          |  Component:  varnishncsa
  Version:  4.1.1   |   Severity:  normal
 Keywords:          |
--------------------+-------------------------
 Last night, our logging pipe showed no web traffic data since our
 varnishncsa process had suddenly stopped to consume the varnishd shared
 memory log. The only output documenting the failure we got was captured on
 stderr and read:

 {{{
 Mar 07 11:03:59 web-front-01 varnishncsa-syslog-wrapper[889]: Assert error
 in vslc_vsm_next(), vsl_cursor.c line 130:
 Mar 07 11:03:59 web-front-01 varnishncsa-syslog-wrapper[889]:
 Condition((t) != 0) not true.
 }}}

 Cursiously, that did not cause the process to terminate - it just stopped
 relaying log data. We're using varnichncsa to relay access logs to other
 hosts via syslog for analysis. For that purpose, we have a systemd service
 that wraps the varnishncsa binary like so:

 {{{
 #!/bin/bash
 export LC_ALL=C

 FORMAT='%{VCL_Log:vxid}x %{X-BE}o %{Host}i %h %l %u %t \"%r\" %s %b
 \"%{Referer}i\" \"%{User-agent}i\" TIME=%D %{Varnish:time_firstbyte}x
 %{Varnish:handling}x XFP=%{X-Forwarded-Proto}i CT=%{Content-Type}o XFF=%{X
 -Forwarded-For}i'

 TAG="varnishncsa"
 PRIORITY="local0.info"

 /usr/bin/varnishncsa -g request -F "${FORMAT}" | /usr/local/bin/logger.pl
 -t "${TAG}" -p "${PRIORITY}"
 }}}

 (The pipe's consumer, `logger.pl`, is a tiny Perl script that works around
 a peculiarity of systemd, which would make all logs show up in the
 system's journal, as well as relaying elsewhere via syslog.)


 The box we have this running on receives ~1500reqs/s, and is equipped with
 ECC RDIMM. The hardware was tested for reliability extensively before
 having been put into service, so I think we can safely rule out memory
 problems. We're running Debian Jessie with the latest backports Kernel
 (4.3+70~bpo8+1, 4.3.0-0.bpo.1-amd64).

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