panic in vbf_stp_mkbereq(): Condition((bo->stale_oc->flags & OC_F_PASS) == 0) not true.

[nigoroll]

Panic at: Wed, 05 Sep 2018 12:39:08 GMT
Assert error in vbf_stp_mkbereq(), cache/cache_fetch.c line 198:
  Condition((bo->stale_oc->flags & OC_F_PASS) == 0) not true.
version = varnish-trunk revision 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, vrt api = 7.0
ident = Linux,3.10.0-327.13.1.el7.x86_64,x86_64,-jnone,-smalloc,-sdefault,-hcritbit,epoll
now = 74308522.401266 (mono), 1536151106.734342 (real)
Backtrace:
  0x44298a: /opt/varnish/sbin/varnishd() [0x44298a]
  0x442e7b: /opt/varnish/sbin/varnishd() [0x442e7b]
  0x4c0a35: /opt/varnish/sbin/varnishd(VAS_Fail+0x4d) [0x4c0a35]
  0x42bc17: /opt/varnish/sbin/varnishd() [0x42bc17]
  0x42e987: /opt/varnish/sbin/varnishd() [0x42e987]
  0x467d92: /opt/varnish/sbin/varnishd() [0x467d92]
  0x466e3e: /opt/varnish/sbin/varnishd() [0x466e3e]
  0x467ec8: /opt/varnish/sbin/varnishd() [0x467ec8]
  0x7fcac773de25: /lib64/libpthread.so.0(+0x7e25) [0x7fcac773de25]
  0x7fcac7467bad: /lib64/libc.so.6(clone+0x6d) [0x7fcac7467bad]
thread = (cache-worker)
thr.req = (nil) {
},
thr.busyobj = 0x7fc9b7908020 {
  ws = 0x7fc9b7908060 {
    id = \"bo\",
    {s, f, r, e} = {0x7fc9b7909f60, +1920, (nil), +123032},
  },
  retries = 0, flags = {do_stream},
  vfc = 0x7fc9b7909f18 {
    failed = 0,
    req = (nil),
    resp = (nil),
    wrk = (nil),
    oc = (nil),
    obj_flags = 0x0,
  },
  director_req = 0x7fcac6812680 {
    cli_name = boot.a0unset,
    health = sick,
    admin_health = probe, changed = 1536150990.251284,
    type = backend {
      ipv4 = 127.0.0.1,
      port = 0,
      hosthdr = 127.0.0.1,
      n_conn = 0,
    },
  },
  objcore[fetch] = 0x7fc9c2236240 {
    refcnt = 2,
    flags = {busy},
    exp_flags = {},
    boc = 0x7fca671133e0 {
      refcnt = 2,
      state = invalid,
      vary = 0x7fca93a9c100,
      stevedore_priv = (nil),
    },
    exp = {0.000000, 0.000000, 0.000000, 0.000000},
    objhead = 0x7fca67347860,
    stevedore = (nil),
  },
  objcore[ims] = 0x7fca7061f7c0 {
    refcnt = 3,
    flags = {pass},
    exp_flags = {refd},
    exp = {1536151049.901384, 60.000000, 10.000000, 0.000000},
    objhead = 0x7fca67347860,
    stevedore = 0x7fcac68b0180 (malloc Transient) {
      Simple = 0x7fca43531600,
      Obj = 0x7fca2da1de78 {priv=0x7fca2da1de70, ptr=0x7fca43531600, len=1326, space=1328},
      LEN = 0x0000000000006b5e,
      VXID = 0x03820445,
      FLAGS = 0x0a,
      GZIPBITS = 0x00000000000000500000000000035a8d0000000000035ab00000000000018c0b,
      LASTMODIFIED = 0x41d6e3f382400000,
      VARY = {len=54, ptr=0x7fca43531678},
      HEADERS = {len=1152, ptr=0x7fca435316ae},
    },
  },
  vcl = {
    name = \"boot\",
    busy = 227,
    discard = 0,
    state = auto,
    temp = warm,
    conf = {
      srcname = {
        \"/opt/varnish/etc/varnish/active.vcl\",
        \"Builtin\",
        \"/opt/varnish/etc/varnish/init_cluster_deny.vcl\",
      },
    },
  },
  vmods = {
    std = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    header = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 7.0},
    cookie = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 7.0},
    directors = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    re = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 7.0},
    re2 = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    dispatch = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    blob = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    blobdigest = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    blobsynth = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    var = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 7.0},
    bipa = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    dns = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 7.0},
    cluster = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    vsthrottle = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 7.0},
    geoip2 = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
    hoailona = {Varnish trunk 99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a, 0.0},
  },
},

[nigoroll]

FYI the code is https://github.com/nigoroll/varnish-cache/commits/99cd38f0b9f12f1d78c1f8789dad5d5a4d8b4f5a based upon fe558421628f17340fae6a0b1cca477f04d033b1

[bsdphk]

As far as I can tell, that AZ() is proper and warranted.

Trying as I might, I can neither see or by experiment hit it.

The only place OF_IMSCAN is set, the first condition is that it cannot be OC_F_PASS and that flag is not adultered after that point in the code.

Possibly relevant: cache_req_fsm line 556 (vcl_hit + return(miss) + busy) is not exercised by any test-case

[nigoroll]

I'd like to propose two options to fix this:

2766 is the obvious one, fixing the actual bug (which is that all the flags are getting copied over from the stale_oc as OA_FLAGS, preserving an OF_IMSCAND even if the new object becomes a HFM)

But working on this I noticed that we might not want this: If we took all the effort of creating a fully fletched cache object for HFM, why not keep the body and re-use it for conditional requests? This is #2767

If we wanted to opt for B, we'd probably want to conditionally throw away the body if it's not IMS capable, but I wanted to get the suggestion out before leaving the train.

[nigoroll]

discussed with @bsdphk

• rewrite A: copy the flags and add ObjClrFlag() to clear the IMS flag
• polish A vtc
• keep B for october