tracing: use manual collection in ForkCtxSpan

[irfansharif]

The spans created by ForkCtxSpan are expected to outlive the parent, so
automatic collection makes little sense here. It also causes the child
to be linked into the parent, which can delay memory reclamation; some
parent spans are effectively ephemeral.

As an example of this, consider the usage in replicaDecoder. The
parent context has a long-lived span, and forks off new tracing spans
for each decoded command. Similar problems occur prop up for the
raft-worker/raftScheduler goroutines.

---

For tests, we make two changes:

• Logic tests that asserted on async recordings are simply removed,
  we're making a backwards-incompatible change here
• Unit tests that want to assert on trace data from async spans can
  now configure the tracer to include them explicitly

While here, we introduce tracing.ContextWithRecordingSpanUsing to
capture the tracer used to construct spans, so most callers can provide
the one available.

Release note (general change): SHOW TRACE FOR SESSION previously
included cockroach internal traces for async threads kicked off as part
of user operations. This trace data is no longer captured.

[cockroach-teamcity]

This change is 

[irfansharif]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen, @knz, and @tbg)

---

pkg/util/tracing/tracer.go, line 629 at r1 (raw file):

// the tracer to include recordings from forked/async child spans, when
// retrieving the recording for a parent span.
func (t *Tracer) TestingIncludeAsyncSpansInRecordings() {

I tried introducing an interceptor instead (suggested in #59391 (review)), and asserting on span recordings on Finish, but it felt too clunky. For tests that want to "capture everything", think this is much easier to work with. It's also only just a handful of tests that want to do this today (the logic tests don't).

---

pkg/util/tracing/tracer.go, line 650 at r1 (raw file):

		return ctx, nil
	}
	collectionOpt := WithParentAndManualCollection(sp.Meta())

Didn't flip the ordering as suggested in #59391 (review), the Manual collection will be the one used in everything except for a select few tests, so optimizing for the memory usage seems unnecessary.

[tbg]

Looks like the rabbit hole is going a little deeper still, see the dist sender comments.

Reviewed 22 of 22 files at r1.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen, @irfansharif, and @knz)

---

pkg/sql/opt/exec/execbuilder/testdata/select, line 1763 at r1 (raw file):

----
querying next range at /Table/73/1/0
=== SPAN START: kv.DistSender: sending partial batch ===

Unfortunately, DistSender relies on async tasks in more than one place, these are the ones I found (might've missed some, you get the idea):

cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go

Lines 1370 to 1379 in cdd48a0

	if err := ds.rpcContext.Stopper.RunLimitedAsyncTask(
	ctx, "kv.DistSender: sending partial batch",
	ds.asyncSenderSem, false, /* wait */
	func(ctx context.Context) {
	ds.metrics.AsyncSentCount.Inc(1)
	responseCh <- ds.sendPartialBatch(
	ctx, ba, rs, routing, withCommit, batchIdx, true, /* needsTruncate */
	)
	},
	); err != nil {

cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go

Lines 993 to 1001 in cdd48a0

	// Both halves of the split batch succeeded. Piece them back together.
	resps := make([]roachpb.ResponseUnion, len(swappedReqs))
	copy(resps, br.Responses)
	resps[swapIdx], resps[lastIdx] = resps[lastIdx], resps[swapIdx]
	br.Responses = resps
	if err := br.Combine(qiReply.reply, qiReply.positions); err != nil {
	return nil, roachpb.NewError(err)
	}
	return br, nil

The batch responses are combined here:

cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go

Lines 1221 to 1226 in cdd48a0

	// Combine the new response with the existing one (including updating
	// the headers) if we haven't yet seen an error.
	if pErr == nil {
	if err := br.Combine(resp.reply, resp.positions); err != nil {
	pErr = roachpb.NewError(err)
	}

At the very least, we need to make sure that BatchResponse.Combine appends the spans; otherwise we're losing lots of spans from KV and the whole tracing thing is doomed. It looks like our testing of actual trace histories' accuracy is not very thorough (or rather, does not exist), which we need to fix and might as well now. I think we can set up a test cluster, ten scratch ranges, and a replica eval interceptor that looks at the key for all of the test's puts on each range and emits a metadata containing the key to the trace. The test can then verify that for every put we see the right meta in this range. I think it's actually straightforward to sue kvnemesis for this? We execute all regular KV ops in this method:

cockroach/pkg/kv/kvnemesis/applier.go

Lines 135 to 140 in c955e88

	func applyClientOp(ctx context.Context, db clientI, op *Operation) {
	switch o := op.GetValue().(type) {
	case *GetOperation:
	fn := db.Get
	if o.ForUpdate {
	fn = db.GetForUpdate

Each of these should verify that they keys it accesses are reflected in metas that we set up kvnemesis to inject via an eval interceptor. I'm still on the fence whether this is a good first step, randomized testing is great and everything, but it's also good to have a basic manual test of these things that is easier to debug, so maybe that's the better starting point, especially since we expect things to be broken as of this PR.

Not necessarily for now, but something we also need to do:

I think there is also an issue with tracking Errors that get retried away internally. These are detached from the batch response here:

cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go

Lines 1559 to 1561 in cdd48a0

	// Untangle the error from the received response.
	pErr = reply.Error
	reply.Error = nil // scrub the response error

We should make sure they implement Structured (do so trivially now) and added to the trace. There's also the question on how to track this error when it occurs:

cockroach/pkg/kv/kvclient/kvcoord/dist_sender.go

Lines 1547 to 1549 in cdd48a0

	log.VEventf(ctx, 1, "evicting range desc %s after %s", routingTok, err)
	routingTok.Evict(ctx)
	continue

---

pkg/util/tracing/tracer.go, line 753 at r1 (raw file):

// an existing Tracer is unavailable. Tests should typically expect to use
// ContextWithRecordingSpanUsing instead.
func ContextWithRecordingSpan(

Can you nuke this method? All callers in test can just ContextWithRecordingSpanUsing(ctx, NewTracer(), opName) and the ~3 callers in prod code should have a tracer they can grab.

[irfansharif]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @angelapwen, @knz, and @tbg)

---

pkg/sql/opt/exec/execbuilder/testdata/select, line 1763 at r1 (raw file):

At the very least, we need to make sure that BatchResponse.Combine appends the spans; otherwise we're losing lots of spans from KV and the whole tracing thing is doomed

We're already doing that here:

cockroach/pkg/roachpb/api.go

Line 535 in 9e31dd8

h.CollectedSpans = append(h.CollectedSpans, o.CollectedSpans...)

But I agree that our testing story here leaves much to be desired. I think that's well deserving of a PR of its own. I need to play around what what that looks like; I'd also prefer being able to isolate and test trace data in unit tests.

So if I'm reading the above right, given we're already combining spans from batch responses (including those captured using async tasks), does that unblock this PR? All this trace data is later imported into the span at the gateway, which is what we ultimately want (though, yes, would be nice to add tests for it).

---

pkg/util/tracing/tracer.go, line 753 at r1 (raw file):

Previously, tbg (Tobias Grieger) wrote…

Can you nuke this method? All callers in test can just ContextWithRecordingSpanUsing(ctx, NewTracer(), opName) and the ~3 callers in prod code should have a tracer they can grab.

Done.

[angelapwen]

per @tbg 😸

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

[irfansharif]

Thanks!

bors r+

[craig]

Build failed:

• GitHub CI (Cockroach)

[irfansharif]

Skewed with #59760.

bors r+