Skip to content

Commit c5b5627

Browse files
committed
kv: include tracing for split QueryIntent requests
When performing a parallel commit, we split out QueryIntent requests for previously pipelined writes that need to be verified as part of the parallel commit into their own batches. These are then run in parallel with the EndTxn batch. Previously, we were missing tracing for these, as we weren't using the correct SpanOpt. This is now fixed. Epic: none Release note: None
1 parent 51e4bca commit c5b5627

File tree

4 files changed

+55
-0
lines changed

4 files changed

+55
-0
lines changed

pkg/kv/kvclient/kvcoord/dist_sender.go

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1538,6 +1538,7 @@ func (ds *DistSender) divideAndSendParallelCommit(
15381538
} else {
15391539
ctx, hdl, err := ds.stopper.GetHandle(ctx, stop.TaskOpts{
15401540
TaskName: taskName,
1541+
SpanOpt: stop.ChildSpan,
15411542
})
15421543
if err != nil {
15431544
return nil, kvpb.NewError(err)

pkg/kv/kvclient/kvcoord/txn_test.go

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ import (
99
"bytes"
1010
"context"
1111
"fmt"
12+
"regexp"
1213
"sort"
1314
"sync/atomic"
1415
"testing"
@@ -26,19 +27,23 @@ import (
2627
"github.com/cockroachdb/cockroach/pkg/kv/kvserver/kvserverbase"
2728
"github.com/cockroachdb/cockroach/pkg/kv/kvserver/tscache"
2829
"github.com/cockroachdb/cockroach/pkg/roachpb"
30+
"github.com/cockroachdb/cockroach/pkg/settings/cluster"
2931
"github.com/cockroachdb/cockroach/pkg/storage"
3032
"github.com/cockroachdb/cockroach/pkg/storage/enginepb"
3133
"github.com/cockroachdb/cockroach/pkg/storage/mvccencoding"
3234
"github.com/cockroachdb/cockroach/pkg/testutils"
3335
"github.com/cockroachdb/cockroach/pkg/testutils/kvclientutils"
3436
"github.com/cockroachdb/cockroach/pkg/testutils/localtestcluster"
3537
"github.com/cockroachdb/cockroach/pkg/testutils/serverutils"
38+
"github.com/cockroachdb/cockroach/pkg/testutils/testcluster"
3639
"github.com/cockroachdb/cockroach/pkg/util/admission/admissionpb"
3740
"github.com/cockroachdb/cockroach/pkg/util/hlc"
3841
"github.com/cockroachdb/cockroach/pkg/util/leaktest"
3942
"github.com/cockroachdb/cockroach/pkg/util/log"
4043
"github.com/cockroachdb/cockroach/pkg/util/randutil"
4144
"github.com/cockroachdb/cockroach/pkg/util/syncutil"
45+
"github.com/cockroachdb/cockroach/pkg/util/tracing"
46+
"github.com/cockroachdb/cockroach/pkg/util/tracing/tracingpb"
4247
"github.com/cockroachdb/cockroach/pkg/util/uuid"
4348
"github.com/cockroachdb/errors"
4449
"github.com/stretchr/testify/require"
@@ -2460,3 +2465,50 @@ func TestTxnBufferedWritesOmitAbortSpanChecks(t *testing.T) {
24602465
require.Error(t, err)
24612466
require.Regexp(t, "TransactionRetryWithProtoRefreshError: .*WriteTooOldError", err)
24622467
}
2468+
2469+
// TestTxnTracesSplitQueryIntents verifies that the split out QueryIntent
2470+
// requests are captured in the verbose tracing of a transaction.
2471+
func TestTxnTracesSplitQueryIntents(t *testing.T) {
2472+
defer leaktest.AfterTest(t)()
2473+
defer log.Scope(t).Close(t)
2474+
2475+
st := cluster.MakeTestingClusterSettings()
2476+
tc := testcluster.StartTestCluster(t, 1, base.TestClusterArgs{
2477+
ServerArgs: base.TestServerArgs{
2478+
Settings: st,
2479+
},
2480+
})
2481+
ctx := context.Background()
2482+
defer tc.Stopper().Stop(ctx)
2483+
// NB: Disable buffered writes to ensure writes are pipelined, and therefore
2484+
// there are QueryIntent requests to split.
2485+
kvcoord.BufferedWritesEnabled.Override(ctx, &st.SV, false)
2486+
2487+
db := tc.Server(0).DB()
2488+
2489+
tracer := tracing.NewTracer()
2490+
traceCtx, sp := tracer.StartSpanCtx(context.Background(), "test-txn", tracing.WithRecording(tracingpb.RecordingVerbose))
2491+
2492+
if err := db.Txn(traceCtx, func(ctx context.Context, txn *kv.Txn) error {
2493+
if err := txn.CPut(ctx, "a", "val", nil); err != nil {
2494+
return err
2495+
}
2496+
if err := txn.Put(ctx, "c", "d"); err != nil {
2497+
return err
2498+
}
2499+
return nil
2500+
}); err != nil {
2501+
t.Fatal(err)
2502+
}
2503+
collectedSpans := sp.FinishAndGetRecording(tracingpb.RecordingVerbose)
2504+
dump := collectedSpans.String()
2505+
// dump:
2506+
// 0.275ms 0.171ms sending split out pre-commit QueryIntent batch
2507+
found, err := regexp.MatchString(
2508+
// The (?s) makes "." match \n. This makes the test resilient to other log
2509+
// lines being interspersed.
2510+
`.*sending split out pre-commit QueryIntent batch`,
2511+
dump)
2512+
require.NoError(t, err)
2513+
require.True(t, found, "didn't match: %s", dump)
2514+
}

pkg/sql/opt/exec/execbuilder/testdata/show_trace

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,7 @@ SELECT $$
4646
FROM [SHOW KV TRACE FOR SESSION]
4747
WHERE message NOT LIKE '%Z/%'
4848
AND operation NOT LIKE 'kv.DistSender: sending partial batch%'
49+
AND operation NOT LIKE 'kv.DistSender: sending pre-commit query intents%'
4950
AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
5051
AND tag NOT LIKE '%intExec=%'
5152
AND tag NOT LIKE '%scExec%'

pkg/sql/opt/exec/execbuilder/testdata/upsert

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1076,6 +1076,7 @@ SET tracing = on,kv,results; UPSERT INTO t.kv(k, v) VALUES (2,3); SET tracing =
10761076
query TT
10771077
SELECT operation, message FROM [SHOW KV TRACE FOR SESSION]
10781078
WHERE operation != 'dist sender send' AND operation != 'kv.DistSender: sending partial batch'
1079+
AND operation NOT LIKE 'kv.DistSender: sending pre-commit query intents%'
10791080
----
10801081
colbatchscan Scan /Table/120/1/2/0 lock Exclusive (Block, Unreplicated)
10811082
count CPut /Table/120/1/2/0 -> /TUPLE/2:2:Int/3

0 commit comments

Comments
 (0)