h2 stream logging lost
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.
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).
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