WS_Assert_Allocated() failing in backref() #3

Closed
opened 2017-05-16 09:06:28 +00:00 by slink · 9 comments
slink commented 2017-05-16 09:06:28 +00:00 (Migrated from code.uplex.de)

most likely introduced somewhen since 26f3394ebf

Panic at: Tue, 16 May 2017 08:10:37 GMT
Assert error in WS_Assert_Allocated(), cache/cache_ws.c line 84:
  Condition(p >= ws->s && (p + len) < ws->f) not true.
version = varnish-trunk revision c2ecb4d, vrt api = 6.1
ident = Linux,3.10.0-327.13.1.el7.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit,epoll
now = 32136798.615207 (mono), 1494922235.224495 (real)
Backtrace:
  0x441e2e: /opt/varnish/sbin/varnishd() [0x441e2e]
  0x442323: /opt/varnish/sbin/varnishd() [0x442323]
  0x463836: /opt/varnish/sbin/varnishd(WS_Assert_Allocated+0x8c) [0x463836]
  0x7f99c1df99da: ./vmod_cache/_vmod_re.ULPFRKSQUETAUXS@AK@LSMKDVYIUYJHP(+0x19da) [0x7f99c1df99da]
  0x7f99c1df9d7d: ./vmod_cache/_vmod_re.ULPFRKSQUETAUXS@AK@LSMKDVYIUYJHP(vmod_regex_backref+0xb3) [0x7f99c1df9d7d]
  0x7f99ca46d261: vcl_boot.1494901856.060504436/vgc.so(VGC_function_vcl_deliver+0x571) [0x7f99ca46d261]
  0x454a42: /opt/varnish/sbin/varnishd() [0x454a42]
  0x455161: /opt/varnish/sbin/varnishd(VCL_deliver_method+0x164) [0x455161]
  0x445e74: /opt/varnish/sbin/varnishd() [0x445e74]
  0x449547: /opt/varnish/sbin/varnishd(CNT_Request+0x51b) [0x449547]
thread = (cache-worker)
thr.req = 0x7f99bb486020 {
  vxid = 13565958, transport = HTTP/1 {
    state = HTTP1::Proc
  }
  step = R_STP_DELIVER,
  req_body = R_BODY_NONE,
  restarts = 0, esi_level = 0,
  sp = 0x7f99bb00f620 {
    fd = 31, vxid = 13565957,
    t_open = 1494922235.218907,
    t_idle = 1494922235.218907,
    transport = HTTP/1 {
      state = HTTP1::Proc
    }
    client = *redacted* 5229,
    privs = 0x7f99bb00f688 {
      priv {p 0x7f99bb488708 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f800
      priv {p 0x7f99bb488770 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80fa10
      priv {p 0x7f99bb4887d8 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f9b0
      priv {p 0x7f99bb488840 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f9a0
      priv {p 0x7f99bb4888a8 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f7e0
      priv {p 0x7f99bb488910 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f910
      priv {p 0x7f99bb488978 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f8c0
      priv {p 0x7f99bb4889e0 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f7f0
      priv {p 0x7f99bb488a90 l 104 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f950
    },
  },
  worker = 0x7f998f780c30 {
    stack = {0x7f998f781000 -> 0x7f998f761000},
    ws = 0x7f998f780e30 {
      id = \"wrk\",
      {s, f, r, e} = {0x7f998f7803f0, +0, (nil), +2040},
    },
    VCL::method = inside DELIVER,
    VCL::return = 0x0,
    VCL::methods = {RECV, HASH, MISS, DELIVER},
  },
  ws = 0x7f99bb486208 {
    id = \"req\",
    {s, f, r, e} = {0x7f99bb488008, +2888, (nil), +122864},
  },
  http_conn = 0x7f99bb486130 {
    fd = 31 (@0x7f99bb00f638),
    doclose = NULL,
    ws = 0x7f99bb486208 {
      [Already dumped, see above]
    },
    {rxbuf_b, rxbuf_e} = {0x7f99bb488320, 0x7f99bb488617},
    {pipeline_b, pipeline_e} = {(nil), (nil)},
   content_length = -1,
    body_status = none,
    first_byte_timeout = 0.000000,
    between_bytes_timeout = 0.000000,
  },
  http[req] = 0x7f99bb4862a0 {
    ws = 0x7f99bb486208 {
      [Already dumped, see above]
    },
    hdrs {
      \"GET\",
      *REDACTED*,
    },
  },
  http[resp] = 0x7f99bb486b90 {
    ws = 0x7f99bb486208 {
      [Already dumped, see above]
    },
    hdrs {
      \"HTTP/1.1\",
      \"301\",
      \"Moved Permanently\",
      *REDACTED*,
    },
  },
  vcl = {
    name = \"boot\",
    busy = 124,
    discard = 0,
    state = auto,
    temp = warm,
    conf = {
      srcname = {
        \"/opt/varnish/etc/varnish/active.vcl\",
        \"Builtin\",
      },
    },
  },
  vmods = {
    std = {Varnish trunk c2ecb4d, 6.1},
    header = {Varnish trunk c2ecb4d, 6.1},
    cookie = {Varnish trunk c2ecb4d, 6.1},
    directors = {Varnish trunk c2ecb4d, 6.1},
    re = {Varnish trunk c2ecb4d, 6.1},
    blobcode = {Varnish trunk c2ecb4d, 6.1},
    blobdigest = {Varnish trunk c2ecb4d, 6.1},
    var = {Varnish trunk c2ecb4d, 6.1},
    bipa = {Varnish trunk c2ecb4d, 6.1},
  },
  objcore[REQ] = 0x7f9995882020 {
    refcnt = 2,
    flags = {},
    exp_flags = {refd},
    exp = {1494922235.224136, 3.000000, 0.000000, 0.000000},
    objhead = 0x7f9995896080,
    stevedore = 0x7f99dc8a9180 (malloc Transient) {
      Simple = 0x7f9994c50300,
      Obj = 0x7f9994c4c248 {priv=0x7f9994c4c240, ptr=0x7f9994c50300, len=680, space=680},
      LEN = 0x0...0,
      VXID = 0x00cf0007,
      FLAGS = 0x00,
      GZIPBITS = 0x0...0,
      LASTMODIFIED = 0x41d646acfec00000,
      VARY = {len=0, ptr=(nil)},
      HEADERS = {len=560, ptr=0x7f9994c50378},
    },
  },
  flags = {
    hash_ignore_busy,
  },
},
thr.busyobj = (nil) {
},
most likely introduced somewhen since 26f3394ebfee66b996a4fbe18d61601824d6874d ``` Panic at: Tue, 16 May 2017 08:10:37 GMT Assert error in WS_Assert_Allocated(), cache/cache_ws.c line 84: Condition(p >= ws->s && (p + len) < ws->f) not true. version = varnish-trunk revision c2ecb4d, vrt api = 6.1 ident = Linux,3.10.0-327.13.1.el7.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit,epoll now = 32136798.615207 (mono), 1494922235.224495 (real) Backtrace: 0x441e2e: /opt/varnish/sbin/varnishd() [0x441e2e] 0x442323: /opt/varnish/sbin/varnishd() [0x442323] 0x463836: /opt/varnish/sbin/varnishd(WS_Assert_Allocated+0x8c) [0x463836] 0x7f99c1df99da: ./vmod_cache/_vmod_re.ULPFRKSQUETAUXS@AK@LSMKDVYIUYJHP(+0x19da) [0x7f99c1df99da] 0x7f99c1df9d7d: ./vmod_cache/_vmod_re.ULPFRKSQUETAUXS@AK@LSMKDVYIUYJHP(vmod_regex_backref+0xb3) [0x7f99c1df9d7d] 0x7f99ca46d261: vcl_boot.1494901856.060504436/vgc.so(VGC_function_vcl_deliver+0x571) [0x7f99ca46d261] 0x454a42: /opt/varnish/sbin/varnishd() [0x454a42] 0x455161: /opt/varnish/sbin/varnishd(VCL_deliver_method+0x164) [0x455161] 0x445e74: /opt/varnish/sbin/varnishd() [0x445e74] 0x449547: /opt/varnish/sbin/varnishd(CNT_Request+0x51b) [0x449547] thread = (cache-worker) thr.req = 0x7f99bb486020 { vxid = 13565958, transport = HTTP/1 { state = HTTP1::Proc } step = R_STP_DELIVER, req_body = R_BODY_NONE, restarts = 0, esi_level = 0, sp = 0x7f99bb00f620 { fd = 31, vxid = 13565957, t_open = 1494922235.218907, t_idle = 1494922235.218907, transport = HTTP/1 { state = HTTP1::Proc } client = *redacted* 5229, privs = 0x7f99bb00f688 { priv {p 0x7f99bb488708 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f800 priv {p 0x7f99bb488770 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80fa10 priv {p 0x7f99bb4887d8 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f9b0 priv {p 0x7f99bb488840 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f9a0 priv {p 0x7f99bb4888a8 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f7e0 priv {p 0x7f99bb488910 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f910 priv {p 0x7f99bb488978 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f8c0 priv {p 0x7f99bb4889e0 l -1 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f7f0 priv {p 0x7f99bb488a90 l 104 f (nil)} vcl 0x7f99dc8a93c0 id 7f99bb486020 vmod 7f99dc80f950 }, }, worker = 0x7f998f780c30 { stack = {0x7f998f781000 -> 0x7f998f761000}, ws = 0x7f998f780e30 { id = \"wrk\", {s, f, r, e} = {0x7f998f7803f0, +0, (nil), +2040}, }, VCL::method = inside DELIVER, VCL::return = 0x0, VCL::methods = {RECV, HASH, MISS, DELIVER}, }, ws = 0x7f99bb486208 { id = \"req\", {s, f, r, e} = {0x7f99bb488008, +2888, (nil), +122864}, }, http_conn = 0x7f99bb486130 { fd = 31 (@0x7f99bb00f638), doclose = NULL, ws = 0x7f99bb486208 { [Already dumped, see above] }, {rxbuf_b, rxbuf_e} = {0x7f99bb488320, 0x7f99bb488617}, {pipeline_b, pipeline_e} = {(nil), (nil)}, content_length = -1, body_status = none, first_byte_timeout = 0.000000, between_bytes_timeout = 0.000000, }, http[req] = 0x7f99bb4862a0 { ws = 0x7f99bb486208 { [Already dumped, see above] }, hdrs { \"GET\", *REDACTED*, }, }, http[resp] = 0x7f99bb486b90 { ws = 0x7f99bb486208 { [Already dumped, see above] }, hdrs { \"HTTP/1.1\", \"301\", \"Moved Permanently\", *REDACTED*, }, }, vcl = { name = \"boot\", busy = 124, discard = 0, state = auto, temp = warm, conf = { srcname = { \"/opt/varnish/etc/varnish/active.vcl\", \"Builtin\", }, }, }, vmods = { std = {Varnish trunk c2ecb4d, 6.1}, header = {Varnish trunk c2ecb4d, 6.1}, cookie = {Varnish trunk c2ecb4d, 6.1}, directors = {Varnish trunk c2ecb4d, 6.1}, re = {Varnish trunk c2ecb4d, 6.1}, blobcode = {Varnish trunk c2ecb4d, 6.1}, blobdigest = {Varnish trunk c2ecb4d, 6.1}, var = {Varnish trunk c2ecb4d, 6.1}, bipa = {Varnish trunk c2ecb4d, 6.1}, }, objcore[REQ] = 0x7f9995882020 { refcnt = 2, flags = {}, exp_flags = {refd}, exp = {1494922235.224136, 3.000000, 0.000000, 0.000000}, objhead = 0x7f9995896080, stevedore = 0x7f99dc8a9180 (malloc Transient) { Simple = 0x7f9994c50300, Obj = 0x7f9994c4c248 {priv=0x7f9994c4c240, ptr=0x7f9994c50300, len=680, space=680}, LEN = 0x0...0, VXID = 0x00cf0007, FLAGS = 0x00, GZIPBITS = 0x0...0, LASTMODIFIED = 0x41d646acfec00000, VARY = {len=0, ptr=(nil)}, HEADERS = {len=560, ptr=0x7f9994c50378}, }, }, flags = { hash_ignore_busy, }, }, thr.busyobj = (nil) { }, ```
slink commented 2017-05-16 09:18:36 +00:00 (Migrated from code.uplex.de)

more symbols, not necessarily the same crash

#0  0x00007f5fc98721d7 in raise () from /lib64/libc.so.6
#1  0x00007f5fc98738c8 in abort () from /lib64/libc.so.6
#2  0x00000000004424c2 in pan_ic (func=0x4e2650 <__func__.7406> "WS_Assert_Allocated", file=0x4e23a2 "cache/cache_ws.c", line=84, 
    cond=0x4e2490 "p >= ws->s && (p + len) < ws->f", kind=VAS_ASSERT) at cache/cache_panic.c:665
#3  0x0000000000463836 in WS_Assert_Allocated (ws=0x7f5fa7146208, ptr=0x7f5fa7148a88, len=42) at cache/cache_ws.c:84
#4  0x00007f5fae3e89da in backref (ctx=0x7f5fa46b41b0, refnum=1, fallback=0x7f5fb6c6fbb2 <Address 0x7f5fb6c6fbb2 out of bounds>, 
    task=0x7f5fa000e4d8) at vmod_re.c:220
#5  0x00007f5fae3e8d7d in vmod_regex_backref (ctx=0x7f5fa46b41b0, re=0x7f5fc900fce0, refnum=1, 
    fallback=0x7f5fb6c6fbb2 <Address 0x7f5fb6c6fbb2 out of bounds>) at vmod_re.c:263
more symbols, not necessarily the same crash ``` #0 0x00007f5fc98721d7 in raise () from /lib64/libc.so.6 #1 0x00007f5fc98738c8 in abort () from /lib64/libc.so.6 #2 0x00000000004424c2 in pan_ic (func=0x4e2650 <__func__.7406> "WS_Assert_Allocated", file=0x4e23a2 "cache/cache_ws.c", line=84, cond=0x4e2490 "p >= ws->s && (p + len) < ws->f", kind=VAS_ASSERT) at cache/cache_panic.c:665 #3 0x0000000000463836 in WS_Assert_Allocated (ws=0x7f5fa7146208, ptr=0x7f5fa7148a88, len=42) at cache/cache_ws.c:84 #4 0x00007f5fae3e89da in backref (ctx=0x7f5fa46b41b0, refnum=1, fallback=0x7f5fb6c6fbb2 <Address 0x7f5fb6c6fbb2 out of bounds>, task=0x7f5fa000e4d8) at vmod_re.c:220 #5 0x00007f5fae3e8d7d in vmod_regex_backref (ctx=0x7f5fa46b41b0, re=0x7f5fc900fce0, refnum=1, fallback=0x7f5fb6c6fbb2 <Address 0x7f5fb6c6fbb2 out of bounds>) at vmod_re.c:263 ```
slink commented 2017-05-16 09:29:37 +00:00 (Migrated from code.uplex.de)
(gdb) print *ov
$2 = {magic = 2219571769, subject = 0x7f5fa7148a88 "X-Forwarded-Proto,Accept-EncodingEncoding", ovector = {0, 33, -1, -1, -1, -1, 17, 
    18, 18, 33, -1 <repeats 12 times>}}
(gdb) print ctx->ws
$3 = (struct ws *) 0x7f5fa7146208
(gdb) print *ctx->ws
$4 = {magic = 905626964, id = "req", s = 0x7f5fa7148008 "GET", f = 0x7f5fa7148ab0 "g", r = 0x0, e = 0x7f5fa7165ff8 "\025"}
``` (gdb) print *ov $2 = {magic = 2219571769, subject = 0x7f5fa7148a88 "X-Forwarded-Proto,Accept-EncodingEncoding", ovector = {0, 33, -1, -1, -1, -1, 17, 18, 18, 33, -1 <repeats 12 times>}} (gdb) print ctx->ws $3 = (struct ws *) 0x7f5fa7146208 (gdb) print *ctx->ws $4 = {magic = 905626964, id = "req", s = 0x7f5fa7148008 "GET", f = 0x7f5fa7148ab0 "g", r = 0x0, e = 0x7f5fa7165ff8 "\025"} ```
slink commented 2017-05-16 09:44:26 +00:00 (Migrated from code.uplex.de)

Status changed to closed by commit bf2b7a7830

Status changed to closed by commit bf2b7a7830968dafe66e495bbb80ec867dfc476c
slink commented 2017-05-16 10:07:21 +00:00 (Migrated from code.uplex.de)

reviewed by @geoff : We don't need the terminating null for the subject, the actual off-by-one is in WS_Assert_Allocated

reviewed by @geoff : We don't need the terminating null for the subject, the actual off-by-one is in WS_Assert_Allocated
slink commented 2017-05-16 10:07:28 +00:00 (Migrated from code.uplex.de)

Status changed to reopened

Status changed to reopened
slink commented 2017-05-16 10:07:49 +00:00 (Migrated from code.uplex.de)

Reassigned to @geoff

Reassigned to @geoff
geoff commented 2017-05-16 12:09:27 +00:00 (Migrated from code.uplex.de)

mentioned in commit b4497cfdbe

mentioned in commit b4497cfdbe7bb2811018a86055d1c6648171fa28
geoff commented 2017-05-16 12:40:22 +00:00 (Migrated from code.uplex.de)

Status changed to closed by commit 2177905cec

Status changed to closed by commit 2177905cec9aad3e74592d1d88f43d47f011f41e
slink commented 2017-05-17 09:23:32 +00:00 (Migrated from code.uplex.de)

mentioned in issue #4

mentioned in issue #4
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
uplex-varnish/libvmod-re#3
No description provided.