tracing: use byte-limits for logs/structured events per span

[irfansharif]

Touches #59188. Follow-on work from #60678. We can introduce byte-limits for
verbose logging and structured events, instead of limiting things based on
count.

This PR also:

• adds a _dropped tag to recordings with dropped logs/structured events.
• squashes a bug where reset spans (as used in SessionTracing) still
  held onto earlier structured events
• moves away from the internal usage of the opentracing.LogRecord type,
  it's unnecessary

Release justification: low risk, high benefit changes to existing
functionality

Release note: None

---

+cc @knz / @erikgrinaker / @angelapwen for pod-visibility.

[cockroach-teamcity]

This change is 

[tbg]

Reviewed 3 of 3 files at r1.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @irfansharif and @tbg)

---

pkg/util/tracing/crdbspan.go, line 259 at r2 (raw file):

	}

	s.mu.recording.structured.AddFirst(item)

Why is this going in the opposite direction? It looks like for messages, you add via AddLast and you remove via RemoveFirst which is also the order I expect. Here you reverse the order, adding to the front and removing from the back. Shouldn't they be the same to keep things simple? The intention in both cases is to drop the oldest things to make room for the new thing, right? I think there's also an optimization that applies chiefly to verbose logs but that we might as well apply to both (and perhaps factor out the code to be shared?): when an incoming msg alone blows the limit, we want to drop it. So we'd compare item.Size() against maxStructuredBytesPerSpan and and if it's bigger, discard it right there. The current code will lead to dropping all existing data and then holding on to a potentially very large blob, which is not what we want.

Can you mention on RecordStructured that payloads may be dropped subject to size constraints? Don't think it needs to be much more precise than that. Similar for Record{,f}.

Also, on GetRecording, this is also good to mention and you can reference the _dropped tag.

[irfansharif]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @tbg)

---

pkg/util/tracing/crdbspan.go, line 259 at r2 (raw file):

Also, on GetRecording, this is also good to mention and you can reference the _dropped tag.

Done.

Can you mention on RecordStructured that payloads may be dropped subject to size constraints? Don't think it needs to be much more precise than that. Similar for Record{,f}.

Done.

Why is this going in the opposite direction? [...] The intention in both cases is to drop the oldest things to make room for the new thing, right?

In both cases we drop the oldest thing and keep the newest. The reversal in order just stemmed from what the iteration over the ring buffer when materializing its contents (during GetRecording) looked like. For logs, I wanted the oldest log to appear first. For structured events, I wanted the opposite. I guess that's not really that important? We probably want to have timestamps associated with structured events if we care about ordering, so I've simplified for now.

we'd compare item.Size() against maxStructuredBytesPerSpan and and if it's bigger, discard it right there.

Done.

perhaps factor out the code to be shared?

Done (now using the same limit for both verbose + structured events).

[irfansharif]

The test flakes are due because different log messages have different sizes - seeing as how they embed a timestamp. Heading into a block of meetings but after I'll add a testing knob to pin the timestamp for logs which should get rid of the issue.

[tbg]

but I think we should keep the ringbufs separate due to the more complex semantics the sharing introduces.

Reviewed 5 of 5 files at r2.
Reviewable status: complete! 1 of 0 LGTMs obtained (waiting on @irfansharif and @tbg)

---

pkg/util/tracing/tracer.go, line 46 at r3 (raw file):

	// maxRecordedBytesPerSpan limits the size of logs and structured in a span;
	// use a comfortable limit.
	maxRecordedBytesPerSpan = 10 * (1 << 10) // 10 KiB

I wonder if this should be set significantly higher. For payloads only, and for their current usage, I would agree that 10 KiB is enough (though this would likely exclude contention events on some tables with large primary keys). But now we are sharing the combined buffer and so something like 256KiB is perhaps more appropriate. Concretely, I am worried about statement bundles which contain a verbose trace. Since we're not introducing a knob here (should we?) it could happen that the "interesting" part of the trace gets truncated away (though hopefully the eviction policy will keep the interesting part in most cases).

I wasn't actually thinking about merging the byte limits together. I thought it was a good idea to keep them separate. It could make sense to budget up to 256KiB for log messages and 10KiB for payloads. The current code has weird properties. For example, if you have 1KiB in payloads but 8.9999KiB in verbose messages, and another payload comes in, you'll throw out an existing payload rather than evict some old log messages, but then you will actually add the payload and still end up at >10KiB (though I guess at most at 19.999KiB). Things are easier when they are kept separate. If we had to prioritize, we'd likely prefer dropping verbose messages over payloads in all cases. But I don't want to get into that now (or probably ever), so using two buffers seems more appropriate.

[irfansharif]

but I think we should keep the ringbufs separate due to the more complex semantics the sharing introduces.

Done. Thanks for reviewing!

bors r+

Reviewable status: complete! 0 of 0 LGTMs obtained (and 1 stale) (waiting on @tbg)

---

pkg/util/tracing/tracer.go, line 46 at r3 (raw file):

It could make sense to budget up to 256KiB for log messages and 10KiB for payloads

Done.

[craig]

Build failed (retrying...):

• GitHub CI (Cockroach)

[craig]

Canceled.

[irfansharif]

bors r+

[craig]

Build succeeded:

• GitHub CI (Cockroach)