Assert error in VSLb_bin(), cache/cache_shmlog.c line 414

[simonvik]

Panic at: Tue, 28 Mar 2017 09:02:57 GMT
Assert error in VSLb_bin(), cache/cache_shmlog.c line 414:
  Condition(vsl->wlp < vsl->wle) not true.
version = varnish-5.1.1 revision de38712, vrt api = 6.0
ident = Linux,4.4.30-20161130-1423-0a2a05d,x86_64,-junix,-smalloc,-smalloc,-hcritbit,epoll
now = 5507885.936845 (mono), 1490691775.571851 (real)
Backtrace:
  0x438975: /usr/sbin/varnishd() [0x438975]
  0x442e60: /usr/sbin/varnishd(VSLb_bin+0x250) [0x442e60]
  0x463364: /usr/sbin/varnishd(H2_Send_Frame+0x1c4) [0x463364]
  0x4635b4: /usr/sbin/varnishd(H2_Send+0x1a4) [0x4635b4]
  0x45e307: /usr/sbin/varnishd() [0x45e307]
  0x41fa79: /usr/sbin/varnishd(VDP_bytes+0x79) [0x41fa79]
  0x479c40: /usr/sbin/varnishd() [0x479c40]
  0x41fee6: /usr/sbin/varnishd(VDP_DeliverObj+0x36) [0x41fee6]
  0x45eeaf: /usr/sbin/varnishd(h2_deliver+0x41f) [0x45eeaf]
  0x43c141: /usr/sbin/varnishd(CNT_Request+0x1c1) [0x43c141]
thread = (cache-worker)
thr.req = 0x7f779a8ef020 {
  vxid = 54298212, transport = H2
  step = R_STP_TRANSMIT,
  req_body = R_BODY_NONE,
  restarts = 0, esi_level = 0,
  sp = 0x7f7d4d6b8e20 {
    fd = 142, vxid = 54298190,
    t_open = 1490691757.436334,
    t_idle = 1490691775.571774,
    transport = H2 {
      streams {
        0x00000000 idle  
        0x00000005 c-rem 
        0x00000007 c-rem 
        0x0000000f c-rem 
        0x00000011 c-rem 
        0x00000013 c-rem 
        0x00000015 c-rem 
        0x0000001b c-rem 
        0x0000001d c-rem 
        0x0000001f c-rem 
        0x00000021 c-rem 
        0x00000023 c-rem 
        0x00000025 c-rem 
        0x00000027 c-rem 
        0x00000029 c-rem 
        0x0000002b c-rem 
        0x0000002d c-rem 
        0x0000002f c-rem 
        0x00000031 c-rem 
        0x00000033 c-rem 
        0x00000035 c-rem 
        0x00000037 c-rem 
        0x00000039 c-rem 
        0x0000003b c-rem 
        0x0000003d c-rem 
        0x0000003f c-rem 
        0x00000041 c-rem 
        0x00000043 c-rem 
        0x00000045 c-rem 
        0x00000047 c-rem 
        0x00000049 c-rem 
        0x0000004b c-rem 
        0x0000004d c-rem 
        0x0000004f c-rem 
        0x00000051 c-rem 
        0x00000053 c-rem 
        0x00000055 c-rem 
        0x00000057 c-rem 
      }
    }
    client = ********** 51686,
    privs = 0x7f7d4d6b8e88 {
    },
  },
  worker = 0x7f7cbef6bc70 {
    stack = {0x7f7cbef6c000 -> 0x7f7cbef3c000},
    ws = 0x7f7cbef6be70 {
      id = \"wrk\",
      {s, f, r, e} = {0x7f7cbef6b410, +0, (nil), +2040},
    },
    VCL::method = DELIVER,
    VCL::return = deliver,
    VCL::methods = {RECV, PASS, HASH, DELIVER},
  },
  ws = 0x7f779a8ef208 {
    id = \"req\",
    {s, f, r, e} = {0x7f779a8f1008, +1232, (nil), +122864},
  },
  http_conn = 0x7f779a8ef130 {
    doclose = NULL,
    ws = (nil) {
    },
    {rxbuf_b, rxbuf_e} = {(nil), (nil)},
    {pipeline_b, pipeline_e} = {(nil), (nil)},
    content_length = 0,
    body_status = none,
    first_byte_timeout = 0.000000,
    between_bytes_timeout = 0.000000,
  },
  http[req] = 0x7f779a8ef2a0 {
    ws = 0x7f779a8ef208 {
      [Already dumped, see above]
    },
    hdrs {
      \"GET\",
      \"**********\",
      \"HTTP/2.0\",
      \"host: **********\",
      \"scheme: https\",
      \"user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87 Safari/537.36\",
      \"accept: image/webp,image/*,*/*;q=0.8\",
      \"referer: **********/\",
      \"accept-encoding: gzip, deflate, sdch, br\",
      \"accept-language: es-ES,es;q=0.8\",
      \"cookie: **********\",
      \"X-Forwarded-For: **********\",
      \"**********: **********\",
      \"**********: https\",
      \"X-Forwarded-Proto: https\",
      \"**********: **********\",
    },
  },
  http[resp] = 0x7f779a8efb90 {
    ws = 0x7f779a8ef208 {
      [Already dumped, see above]
    },
    hdrs {
      \"HTTP/1.1\",
      \"200\",
      \"OK\",
      \"Date: Tue, 28 Mar 2017 09:02:39 GMT\",
      \"Server: Apache\",
      \"Last-Modified: Sat, 11 Mar 2017 11:03:53 GMT\",
      \"ETag: \"c04331b8-5f21d5-54a726f0e8722\"\",
      \"Accept-Ranges: bytes\",
      \"Content-Length: 6234581\",
      \"Content-Type: image/jpeg\",
      \"X-Varnish: 54298212\",
      \"Age: 0\",
      \"Via: 1.1 varnish (Varnish/5.1)\",
    },
  },
  vcl = {
    name = \"boot\",
    busy = 1966,
    discard = 0,
    state = auto,
    temp = warm,
    conf = {
      srcname = {
          **********
      },
    },
  },
  vmods = {
    std = {Varnish 5.1.1 de38712, 6.0},
    one = {Varnish 5.1.1 de38712, 6.0},
    maxminddb = {Varnish 5.1.1 de38712, 6.0},
    directors = {Varnish 5.1.1 de38712, 6.0},
    xkey = {Varnish 5.1.1 de38712, 6.0},
    header = {Varnish 5.1.1 de38712, 6.0},
    cookie = {Varnish 5.1.1 de38712, 6.0},
    vsthrottle = {Varnish 5.1.1 de38712, 6.0},
    tcp = {Varnish 5.1.1 de38712, 6.0},
    bodyaccess = {Varnish 5.1.1 de38712, 6.0},
  },
  objcore[REQ] = 0x7f77a8d01700 {
    refcnt = 1,
    flags = {pass, private},
    exp_flags = {},
    boc = 0x7f7bc89f9380 {
      refcnt = 2,
      state = finished,
      vary = (nil),
      stevedore_priv = (nil),
    },
    exp = {1490691759.687844, 3600.000000, 0.000000, 0.000000},
    objhead = 0x7f7d5953b080,
    stevedore = 0x7f7d594d93c0 (malloc Transient) {
      Simple = 0x7f7cf076d5c0,
      Obj = 0x7f79561b9608 {priv=0x7f79561b9600, ptr=0x7f7cf076d5c0, len=408, space=408},
      LEN = 0x00000000005f21d5,
      VXID = 0x018e0725,
      FLAGS = 0x00,
      GZIPBITS = 0x0...0,
      LASTMODIFIED = 0x41d630f666400000,
      VARY = {len=0, ptr=(nil)},
      HEADERS = {len=0, ptr=0x7f7cf076d638},
      Body = 0x7f79561e90b8 {priv=0x7f79561e90b0, ptr=0x7f7641000000, len=6234581, space=6234581},
    },
  },
  flags = {
  },
},
thr.busyobj = (nil) {
},

Running on ubuntu 16.04 Varnish 5.1.1 patched to 15f5c12

[simonvik]

Still happens in 3f4a5a1bc3

[lucaliz]

Happened to me yesterday (21 Jun 2017).

Static assets for a high traffic site down for a couple of minutes, varnish 5.1.2 revision 6ece695 from Packagecloud on Ubuntu 16.04, ssl termination with hitch, http/2 enabled. Full error log + vcl config available privately if necessary.

Child (21472) died signal=6 (core dumped) Error: Child (21472) died signal=6 (core dumped) Error: Child (21472) Panic at: Wed, 21 Jun 2017 12:53:19 GMT Assert error in VSLb_bin(), cache/cache_shmlog.c line 414: Condition(vsl->wlp < vsl->wle) not true. version = varnish-5.1.2 revision 6ece695, vrt api = 6.0 ident = Linux,4.4.0-81-generic,x86_64,-junix,-smalloc,-smalloc,-hcritbit,epoll now = 83251.853007 (mono), 1498049410.980832 (real) Backtrace: 0x438f07: /usr/sbin/varnishd() [0x438f07] 0x4436a0: /usr/sbin/varnishd(VSLb_bin+0x230) [0x4436a0] 0x464051: /usr/sbin/varnishd(H2_Send_Frame+0x1d1) [0x464051] 0x464355: /usr/sbin/varnishd(H2_Send+0x255) [0x464355] 0x45f159: /usr/sbin/varnishd(h2_deliver+0x3c9) [0x45f159] 0x43d130: /usr/sbin/varnishd(CNT_Request+0x1f0) [0x43d130] 0x460734: /usr/sbin/varnishd(h2_do_req+0x84) [0x460734] 0x452109: /usr/sbin/varnishd() [0x452109] 0x45258b: /usr/sbin/varnishd() [0x45258b] 0x7fee3e8c26ba: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba) [0x7fee3e8c26ba] thread = (cache-worker)