Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tracing: do not set tags when setting stats #61158

Merged
merged 2 commits into from
Feb 26, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 0 additions & 1 deletion pkg/sql/colflow/vectorized_flow.go
Original file line number Diff line number Diff line change
Expand Up @@ -960,7 +960,6 @@ func (s *vectorizedFlowCreator) setupOutput(
// At the last outbox, we can accurately retrieve stats for the
// whole flow from parent monitors. These stats are added to a
// flow-level span.
span.SetTag(execinfrapb.FlowIDTagKey, flowCtx.ID)
span.SetSpanStats(&execinfrapb.ComponentStats{
Component: execinfrapb.FlowComponentID(base.SQLInstanceID(outputStream.OriginNodeID), flowCtx.ID),
FlowStats: execinfrapb.FlowStats{
Expand Down
42 changes: 20 additions & 22 deletions pkg/sql/opt/exec/execbuilder/testdata/select
Original file line number Diff line number Diff line change
Expand Up @@ -15,31 +15,29 @@ SET vectorize=off; SET tracing = on; BEGIN; SELECT 1; COMMIT; SELECT 2; SET trac
# how many commands we ran in the session.
query ITT
SELECT
span, regexp_replace(regexp_replace(message, 'pos:[0-9]*', 'pos:?'), 'flowid: [0-9A-Fa-f-]*', 'flowid: ?'), operation
span, regexp_replace(message, 'pos:[0-9]*', 'pos:?'), operation
FROM [SHOW TRACE FOR SESSION]
WHERE message LIKE '%SPAN START%' OR message LIKE '%pos%executing%';
----
0 === SPAN START: session recording === session recording
1 === SPAN START: exec stmt === exec stmt
1 [NoTxn pos:?] executing ExecStmt: BEGIN TRANSACTION exec stmt
2 === SPAN START: sql txn === sql txn
3 === SPAN START: exec stmt === exec stmt
3 [Open pos:?] executing ExecStmt: SELECT 1 exec stmt
4 === SPAN START: consuming rows === consuming rows
5 === SPAN START: flow ===
cockroach.flowid: ? flow
6 === SPAN START: exec stmt === exec stmt
6 [Open pos:?] executing ExecStmt: COMMIT TRANSACTION exec stmt
7 === SPAN START: exec stmt === exec stmt
7 [NoTxn pos:?] executing ExecStmt: SELECT 2 exec stmt
8 === SPAN START: sql txn === sql txn
9 === SPAN START: exec stmt === exec stmt
9 [Open pos:?] executing ExecStmt: SELECT 2 exec stmt
10 === SPAN START: consuming rows === consuming rows
11 === SPAN START: flow ===
cockroach.flowid: ? flow
12 === SPAN START: exec stmt === exec stmt
12 [NoTxn pos:?] executing ExecStmt: SET TRACING = off exec stmt
0 === SPAN START: session recording === session recording
1 === SPAN START: exec stmt === exec stmt
1 [NoTxn pos:?] executing ExecStmt: BEGIN TRANSACTION exec stmt
2 === SPAN START: sql txn === sql txn
3 === SPAN START: exec stmt === exec stmt
3 [Open pos:?] executing ExecStmt: SELECT 1 exec stmt
4 === SPAN START: consuming rows === consuming rows
5 === SPAN START: flow === flow
6 === SPAN START: exec stmt === exec stmt
6 [Open pos:?] executing ExecStmt: COMMIT TRANSACTION exec stmt
7 === SPAN START: exec stmt === exec stmt
7 [NoTxn pos:?] executing ExecStmt: SELECT 2 exec stmt
8 === SPAN START: sql txn === sql txn
9 === SPAN START: exec stmt === exec stmt
9 [Open pos:?] executing ExecStmt: SELECT 2 exec stmt
10 === SPAN START: consuming rows === consuming rows
11 === SPAN START: flow === flow
12 === SPAN START: exec stmt === exec stmt
12 [NoTxn pos:?] executing ExecStmt: SET TRACING = off exec stmt

# ------------------------------------------------------------------------------
# Numeric References Tests.
Expand Down
2 changes: 2 additions & 0 deletions pkg/sql/rowflow/BUILD.bazel
Original file line number Diff line number Diff line change
Expand Up @@ -58,5 +58,7 @@ go_test(
"//pkg/util/randutil",
"//pkg/util/tracing",
"@com_github_cockroachdb_errors//:errors",
"@com_github_gogo_protobuf//types",
"@com_github_stretchr_testify//require",
],
)
44 changes: 27 additions & 17 deletions pkg/sql/rowflow/routers_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,6 @@ import (
"context"
"fmt"
"math"
"strings"
"sync"
"sync/atomic"
"testing"
Expand All @@ -39,6 +38,8 @@ import (
"github.com/cockroachdb/cockroach/pkg/util/randutil"
"github.com/cockroachdb/cockroach/pkg/util/tracing"
"github.com/cockroachdb/errors"
pbtypes "github.com/gogo/protobuf/types"
"github.com/stretchr/testify/require"
)

// setupRouter creates and starts a router. Returns the router and a WaitGroup
Expand Down Expand Up @@ -870,25 +871,34 @@ func TestRouterDiskSpill(t *testing.T) {
}
traceMetaSeen = true
span := meta.TraceData[0]
getTagValue := func(key string) string {
strValue, ok := span.Tags[key]
if !ok {
t.Errorf("missing tag: %s", key)
var stats execinfrapb.ComponentStats
var err error
var unmarshalled bool
span.Structured(func(any *pbtypes.Any) {
if !pbtypes.Is(any, &stats) {
return
}
return strValue
}
t.Logf("tags: %v\n", span.Tags)
rowsRouted := getTagValue("cockroach.stat.input.tuples")
memMax := getTagValue("cockroach.stat.max.memory.allocated")
diskMax := getTagValue("cockroach.stat.max.scratch.disk.allocated")
if rowsRouted != fmt.Sprintf("%d", numRows) {
t.Errorf("expected %d rows routed, got %s", numRows, rowsRouted)
if err = pbtypes.UnmarshalAny(any, &stats); err != nil {
return
}
unmarshalled = true
})
require.NoError(t, err)
require.True(t, unmarshalled)
require.True(t, stats.Inputs[0].NumTuples.HasValue())
require.True(t, stats.Exec.MaxAllocatedMem.HasValue())
require.True(t, stats.Exec.MaxAllocatedDisk.HasValue())
rowsRouted := stats.Inputs[0].NumTuples.Value()
memMax := stats.Exec.MaxAllocatedMem.Value()
diskMax := stats.Exec.MaxAllocatedDisk.Value()
if rowsRouted != numRows {
t.Errorf("expected %d rows routed, got %d", numRows, rowsRouted)
}
if strings.HasPrefix(memMax, `"0"`) {
t.Errorf("expected memMax > 0, got %s", memMax)
if memMax == 0 {
t.Errorf("expected memMax > 0, got %d", memMax)
}
if strings.HasPrefix(diskMax, `"0"`) {
t.Errorf("expected diskMax > 0, got %s", diskMax)
if diskMax == 0 {
t.Errorf("expected diskMax > 0, got %d", diskMax)
}
}
continue
Expand Down
4 changes: 2 additions & 2 deletions pkg/sql/trace_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -107,10 +107,10 @@ func TestTrace(t *testing.T) {

// Check that stat collection from the above SELECT statement is output
// to trace. We don't insert any rows in this test, thus the expected
// stat value is 0.
// num tuples value plus one is 1.
rows, err := sqlDB.Query(
"SELECT count(message) FROM crdb_internal.session_trace " +
"WHERE message LIKE '%cockroach.stat.kv.tuples.read: 0%'",
"WHERE message LIKE '%component%num_tuples%value_plus_one:1%'",
)
if err != nil {
t.Fatal(err)
Expand Down
3 changes: 0 additions & 3 deletions pkg/util/tracing/span.go
Original file line number Diff line number Diff line change
Expand Up @@ -314,9 +314,6 @@ func (s *spanInner) SetSpanStats(stats SpanStats) {
s.RecordStructured(stats)
s.crdb.mu.Lock()
s.crdb.mu.stats = stats
for name, value := range stats.StatsTags() {
s.setTagInner(name, value, true /* locked */)
}
s.crdb.mu.Unlock()
}

Expand Down