varnish-cache icon indicating copy to clipboard operation
varnish-cache copied to clipboard

h2 stream logging lost

Open nigoroll opened this issue 4 years ago • 2 comments

While tracking down the root cause for vtest failing on SunOS after the merge of #3661, I noticed that VSL from h2 frame handlers seems to get lost, for example I would not find this logging

https://github.com/varnishcache/varnish-cache/blob/6fca9764d193e963ec18152b570edf7dc3716141/bin/varnishd/http2/cache_http2_proto.c#L932-L935

while a VSL() would work.

nigoroll avatar Aug 30 '21 17:08 nigoroll

I tried to reproduce the missing logs but didn't manage. Normally the h2_sess logs buffered via the stream 0 req is flushed at ReqRelease() time before the session gets its final (unbuffered) SLT_End in SES_Delete(). Maybe you were looking at a test failing too fast to catch up with VSL? I was specifically looking at t02022 but this one has VSC checks that give varnishtest plenty of time to log logs (sic).

dridi avatar Aug 30 '21 21:08 dridi

notes from bugwash

  • The issue should be reproducible really with triggering a failure of the buffer allocation, expecting the debug meesage from the initial note. If that is not possible, the problem might be on my end
  • There was some discussion around buffered vs. unbuffered VSL in the h2 code paths. It might make sense to unify to just buffered
  • @mbgrydeland suspects that a VSL flush might be missing for the error path

nigoroll avatar Sep 27 '21 13:09 nigoroll