Skip to content

Commit 2d68329

Browse files
committed
sql: include write buffering info to EXPLAIN ANALYZE top level
In order to make it easier to notice that write buffering is enabled, we now will include top-level `write buffering enabled` message to the output of EXPLAIN ANALYZE when write buffering is enabled for all mutations as well as read-only stmts that are part of explicit txns. Release note: None
1 parent d3b81e1 commit 2d68329

File tree

2 files changed

+107
-0
lines changed

2 files changed

+107
-0
lines changed

pkg/sql/explain_test.go

Lines changed: 91 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,7 @@ import (
2929
"github.com/cockroachdb/cockroach/pkg/util/timeutil"
3030
"github.com/cockroachdb/errors"
3131
"github.com/stretchr/testify/assert"
32+
"github.com/stretchr/testify/require"
3233
)
3334

3435
func TestStatementReuses(t *testing.T) {
@@ -645,3 +646,93 @@ func TestExplainAnalyzeSQLNodes(t *testing.T) {
645646
})
646647
}
647648
}
649+
650+
// TestExplainAnalyzeBufferedWrites verifies that write buffering info is
651+
// printed only when applicable.
652+
func TestExplainAnalyzeBufferedWrites(t *testing.T) {
653+
defer leaktest.AfterTest(t)()
654+
defer log.Scope(t).Close(t)
655+
656+
ctx := context.Background()
657+
srv, godb, _ := serverutils.StartServer(t, base.TestServerArgs{})
658+
defer srv.Stopper().Stop(ctx)
659+
660+
conn, err := godb.Conn(ctx)
661+
require.NoError(t, err)
662+
_, err = conn.ExecContext(ctx, `CREATE TABLE t (v INT);`)
663+
require.NoError(t, err)
664+
665+
for _, tc := range []struct {
666+
setup []string
667+
cleanup string
668+
query string
669+
infoPrinted bool
670+
}{
671+
{ // disabled
672+
setup: []string{`SET kv_transaction_buffered_writes_enabled = false;`},
673+
query: `INSERT INTO t VALUES (1)`,
674+
infoPrinted: false,
675+
},
676+
{ // enabled
677+
setup: []string{`SET kv_transaction_buffered_writes_enabled = true;`},
678+
query: `INSERT INTO t VALUES (1), (2)`,
679+
infoPrinted: true,
680+
},
681+
// In this case we won't actually buffer any writes, so the write
682+
// buffering effectively gets disabled during the stmt execution, but we
683+
// still include the info.
684+
// TODO(yuzefovich): consider differentiating this case if it becomes
685+
// frequent. For now it seems ok since we'll have a message in the trace
686+
// about this switch.
687+
{
688+
setup: []string{
689+
`SET kv_transaction_buffered_writes_enabled = true;`,
690+
`SET CLUSTER SETTING kv.transaction.write_buffering.max_buffer_size = '1B';`,
691+
},
692+
cleanup: `RESET CLUSTER SETTING kv.transaction.write_buffering.max_buffer_size;`,
693+
query: `INSERT INTO t VALUES (1), (2), (3)`,
694+
infoPrinted: true,
695+
},
696+
{ // read-only implicit
697+
setup: []string{`SET kv_transaction_buffered_writes_enabled = true;`},
698+
query: `SELECT * FROM t`,
699+
infoPrinted: false,
700+
},
701+
{ // read-only explicit
702+
setup: []string{
703+
`SET kv_transaction_buffered_writes_enabled = true;`,
704+
`BEGIN;`,
705+
},
706+
cleanup: `COMMIT;`,
707+
query: `SELECT * FROM t`,
708+
infoPrinted: true,
709+
},
710+
} {
711+
for _, stmt := range tc.setup {
712+
_, err = conn.ExecContext(ctx, stmt)
713+
require.NoError(t, err)
714+
}
715+
result, err := conn.QueryContext(ctx, "EXPLAIN ANALYZE "+tc.query)
716+
require.NoError(t, err)
717+
rows, err := sqlutils.RowsToStrMatrix(result)
718+
require.NoError(t, err)
719+
var printed bool
720+
for _, row := range rows {
721+
if len(row) > 1 {
722+
t.Fatalf("unexpectedly more than a single string is returned in %v", row)
723+
}
724+
if strings.Contains(row[0], "buffered writes enabled") {
725+
printed = true
726+
}
727+
}
728+
if printed != tc.infoPrinted {
729+
var negate string
730+
if !tc.infoPrinted {
731+
negate = "not "
732+
}
733+
t.Fatalf("expected 'buffered writes enabled' to %sbe printed", negate)
734+
}
735+
_, err = conn.ExecContext(ctx, tc.cleanup)
736+
require.NoError(t, err)
737+
}
738+
}

pkg/sql/instrumentation.go

Lines changed: 16 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -80,6 +80,9 @@ type instrumentationHelper struct {
8080
// Transaction information.
8181
implicitTxn bool
8282
txnPriority roachpb.UserPriority
83+
// txnBufferedWritesEnabled tracks whether the write buffering was
84+
// enabled on the transaction before executing the stmt.
85+
txnBufferedWritesEnabled bool
8386

8487
codec keys.SQLCodec
8588

@@ -420,6 +423,7 @@ func (ih *instrumentationHelper) Setup(
420423
ih.fingerprint = stmt.StmtNoConstants
421424
ih.implicitTxn = implicitTxn
422425
ih.txnPriority = txnPriority
426+
ih.txnBufferedWritesEnabled = p.txn.BufferedWritesEnabled()
423427
ih.retryCount = uint64(retryCount)
424428
ih.codec = cfg.Codec
425429
ih.origCtx = ctx
@@ -883,6 +887,18 @@ func (ih *instrumentationHelper) emitExplainAnalyzePlanToOutputBuilder(
883887
asOfSystemTime = ih.evalCtx.AsOfSystemTime
884888
}
885889
ob.AddTxnInfo(iso, ih.txnPriority, qos, asOfSystemTime)
890+
// Highlight that write buffering was enabled on the current txn, unless
891+
// we're in "deterministic explain" mode.
892+
if ih.txnBufferedWritesEnabled && !flags.Deflake.HasAny(explain.DeflakeAll) {
893+
// In order to not pollute the output, we don't include the write
894+
// buffering info for read-only implicit txns. However, if we're in an
895+
// explicit txn, even if the stmt is read-only, it might still be
896+
// helpful to highlight the write buffering being enabled.
897+
readOnlyImplicit := !ih.containsMutation && ih.implicitTxn
898+
if !readOnlyImplicit {
899+
ob.AddTopLevelField("buffered writes enabled", "")
900+
}
901+
}
886902

887903
// When building EXPLAIN ANALYZE output we do **not** want to create
888904
// post-query plans if they are missing. The fact that they are missing

0 commit comments

Comments
 (0)