Skip to content

Commit

Permalink
util/tracing: move some test utilities to test file
Browse files Browse the repository at this point in the history
Release note: None
  • Loading branch information
andreimatei committed Sep 28, 2021
1 parent 9b5af2c commit 411723d
Show file tree
Hide file tree
Showing 12 changed files with 211 additions and 208 deletions.
2 changes: 1 addition & 1 deletion pkg/util/log/ambient_context_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,7 @@ func TestAnnotateCtxSpan(t *testing.T) {
sp2.Finish()
sp1.Finish()

if err := tracing.TestingCheckRecordedSpans(sp1.GetRecording(), `
if err := tracing.CheckRecordedSpans(sp1.GetRecording(), `
span: root
tags: _verbose=1
event: a
Expand Down
4 changes: 2 additions & 2 deletions pkg/util/log/trace_client_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ func TestTrace(t *testing.T) {
return ctxWithSpan, sp
},
check: func(t *testing.T, _ context.Context, sp *tracing.Span) {
if err := tracing.TestingCheckRecordedSpans(sp.GetRecording(), `
if err := tracing.CheckRecordedSpans(sp.GetRecording(), `
span: s
tags: _verbose=1
event: test1
Expand Down Expand Up @@ -105,7 +105,7 @@ func TestTraceWithTags(t *testing.T) {
log.Info(ctxWithSpan, "log")

sp.Finish()
if err := tracing.TestingCheckRecordedSpans(sp.GetRecording(), `
if err := tracing.CheckRecordedSpans(sp.GetRecording(), `
span: s
tags: _verbose=1
event: [tag=1] test1
Expand Down
2 changes: 1 addition & 1 deletion pkg/util/log/trace_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -130,7 +130,7 @@ func TestEventLogAndTrace(t *testing.T) {
sp.Finish()
el.Finish()

if err := tracing.TestingCheckRecordedSpans(sp.GetRecording(), `
if err := tracing.CheckRecordedSpans(sp.GetRecording(), `
span: s
tags: _verbose=1
event: test3
Expand Down
2 changes: 1 addition & 1 deletion pkg/util/stop/stopper_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -713,7 +713,7 @@ func TestStopperRunAsyncTaskTracing(t *testing.T) {

s.Stop(ctx)
finish()
require.NoError(t, tracing.TestingCheckRecordedSpans(getRecording(), `
require.NoError(t, tracing.CheckRecordedSpans(getRecording(), `
span: parent
span: async child same trace
event: async 2`))
Expand Down
10 changes: 5 additions & 5 deletions pkg/util/tracing/collector/collector_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,7 @@ func TestTracingCollectorGetSpanRecordings(t *testing.T) {
nodeRecordings := getSpansFromAllNodes(localTraceID)
node1Recordings := nodeRecordings[roachpb.NodeID(1)]
require.Equal(t, 1, len(node1Recordings))
require.NoError(t, tracing.TestingCheckRecordedSpans(node1Recordings[0], `
require.NoError(t, tracing.CheckRecordedSpans(node1Recordings[0], `
span: root
tags: _unfinished=1 _verbose=1
event: structured=root
Expand All @@ -158,7 +158,7 @@ func TestTracingCollectorGetSpanRecordings(t *testing.T) {
`))
node2Recordings := nodeRecordings[roachpb.NodeID(2)]
require.Equal(t, 1, len(node2Recordings))
require.NoError(t, tracing.TestingCheckRecordedSpans(node2Recordings[0], `
require.NoError(t, tracing.CheckRecordedSpans(node2Recordings[0], `
span: root.child.remotechild
tags: _unfinished=1 _verbose=1
event: structured=root.child.remotechild
Expand All @@ -171,18 +171,18 @@ func TestTracingCollectorGetSpanRecordings(t *testing.T) {
nodeRecordings := getSpansFromAllNodes(remoteTraceID)
node1Recordings := nodeRecordings[roachpb.NodeID(1)]
require.Equal(t, 2, len(node1Recordings))
require.NoError(t, tracing.TestingCheckRecordedSpans(node1Recordings[0], `
require.NoError(t, tracing.CheckRecordedSpans(node1Recordings[0], `
span: root2.child.remotechild
tags: _unfinished=1 _verbose=1
`))
require.NoError(t, tracing.TestingCheckRecordedSpans(node1Recordings[1], `
require.NoError(t, tracing.CheckRecordedSpans(node1Recordings[1], `
span: root2.child.remotechild2
tags: _unfinished=1 _verbose=1
`))

node2Recordings := nodeRecordings[roachpb.NodeID(2)]
require.Equal(t, 1, len(node2Recordings))
require.NoError(t, tracing.TestingCheckRecordedSpans(node2Recordings[0], `
require.NoError(t, tracing.CheckRecordedSpans(node2Recordings[0], `
span: root2
tags: _unfinished=1 _verbose=1
event: structured=root2
Expand Down
2 changes: 1 addition & 1 deletion pkg/util/tracing/grpc_interceptor_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -240,7 +240,7 @@ func TestGRPCInterceptors(t *testing.T) {
span: /cockroach.testutils.grpcutils.GRPCTest/%[1]s
tags: span.kind=server test-baggage-key=test-baggage-value
event: structured=magic-value`, tc.name)
require.NoError(t, tracing.TestingCheckRecordedSpans(finalRecs, exp))
require.NoError(t, tracing.CheckRecordedSpans(finalRecs, exp))
})
}
testutils.SucceedsSoon(t, func() error {
Expand Down
165 changes: 0 additions & 165 deletions pkg/util/tracing/recording.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,11 +20,9 @@ import (
"time"

"github.com/cockroachdb/cockroach/pkg/util/tracing/tracingpb"
"github.com/cockroachdb/errors"
"github.com/cockroachdb/redact"
"github.com/gogo/protobuf/types"
jaegerjson "github.com/jaegertracing/jaeger/model/json"
"github.com/pmezard/go-difflib/difflib"
)

// RecordingType is the type of recording that a Span might be performing.
Expand Down Expand Up @@ -418,166 +416,3 @@ func isVerbose(s tracingpb.RecordedSpan) bool {
_, isVerbose := s.Baggage[verboseTracingBaggageKey]
return isVerbose
}

// TestingCheckRecordedSpans checks whether a recording looks like an expected
// one represented by a string with one line per expected span and one line per
// expected event (i.e. log message), with a tab-indentation for child spans.
//
// if err := TestingCheckRecordedSpans(Span.GetRecording(), `
// span: root
// event: a
// span: child
// event: [ambient] b
// event: c
// `); err != nil {
// t.Fatal(err)
// }
//
// The event lines can (and generally should) omit the file:line part that they
// might contain (depending on the level at which they were logged).
//
// Note: this test function is in this file because it needs to be used by
// both tests in the tracing package and tests outside of it, and the function
// itself depends on tracing.
func TestingCheckRecordedSpans(rec Recording, expected string) error {
normalize := func(rec string) string {
// normalize the string form of a recording for ease of comparison.
//
// 1. Strip out any leading new lines.
rec = strings.TrimLeft(rec, "\n")
// 2. Strip out trailing whitespace.
rec = strings.TrimRight(rec, "\n\t ")
// 3. Strip out file:line information from the recordings.
//
// Before | "event: util/log/trace_test.go:111 log"
// After | "event: log"
re := regexp.MustCompile(`event: .*:[0-9]*`)
rec = string(re.ReplaceAll([]byte(rec), []byte("event:")))
// 4. Change all tabs to four spaces.
rec = strings.ReplaceAll(rec, "\t", " ")
// 5. Compute the outermost indentation.
indent := strings.Repeat(" ", len(rec)-len(strings.TrimLeft(rec, " ")))
// 6. Outdent each line by that amount.
var lines []string
for _, line := range strings.Split(rec, "\n") {
lines = append(lines, strings.TrimPrefix(line, indent))
}
// 7. Stitch everything together.
return strings.Join(lines, "\n")
}

var rows []string
row := func(depth int, format string, args ...interface{}) {
rows = append(rows, strings.Repeat(" ", depth)+fmt.Sprintf(format, args...))
}

mapping := make(map[uint64]uint64) // spanID -> parentSpanID
for _, rs := range rec {
mapping[rs.SpanID] = rs.ParentSpanID
}
depth := func(spanID uint64) int {
// Traverse up the parent links until one is not found.
curSpanID := spanID
d := 0
for {
var ok bool
curSpanID, ok = mapping[curSpanID]
if !ok {
break
}
d++
}
return d
}

for _, rs := range rec {
d := depth(rs.SpanID)
row(d, "span: %s", rs.Operation)
if len(rs.Tags) > 0 {
var tags []string
for k, v := range rs.Tags {
tags = append(tags, fmt.Sprintf("%s=%v", k, v))
}
sort.Strings(tags)
row(d, " tags: %s", strings.Join(tags, " "))
}
for _, l := range rs.Logs {
var msg string
for _, f := range l.Fields {
msg = msg + fmt.Sprintf(" %s: %v", f.Key, f.Value.StripMarkers())
}
row(d, "%s", msg)
}
}

exp := normalize(expected)
got := normalize(strings.Join(rows, "\n"))
if got != exp {
diff := difflib.UnifiedDiff{
A: difflib.SplitLines(exp),
FromFile: "exp",
B: difflib.SplitLines(got),
ToFile: "got",
Context: 4,
}
diffText, _ := difflib.GetUnifiedDiffString(diff)
return errors.Newf("unexpected diff:\n%s\n\nrecording:\n%s", diffText, rec.String())
}
return nil
}

// TestingCheckRecording checks whether a recording looks like the expected
// one. The expected string is allowed to elide timing information, and the
// outer-most indentation level is adjusted for when comparing.
//
// if err := TestingCheckRecording(sp.GetRecording(), `
// === operation:root
// event:root 1
// === operation:remote child
// event:remote child 1
// `); err != nil {
// t.Fatal(err)
// }
//
func TestingCheckRecording(rec Recording, expected string) error {
normalize := func(rec string) string {
// normalize the string form of a recording for ease of comparison.
//
// 1. Strip out any leading new lines.
rec = strings.TrimLeft(rec, "\n")
// 2. Strip out trailing space.
rec = strings.TrimRight(rec, "\n\t ")
// 3. Strip out all timing information from the recordings.
//
// Before | "0.007ms 0.007ms event:root 1"
// After | "event:root 1"
re := regexp.MustCompile(`.*s.*s\s{4}`)
rec = string(re.ReplaceAll([]byte(rec), nil))
// 4. Change all tabs to four spaces.
rec = strings.ReplaceAll(rec, "\t", " ")
// 5. Compute the outermost indentation.
indent := strings.Repeat(" ", len(rec)-len(strings.TrimLeft(rec, " ")))
// 6. Outdent each line by that amount.
var lines []string
for _, line := range strings.Split(rec, "\n") {
lines = append(lines, strings.TrimPrefix(line, indent))
}
// 6. Stitch everything together.
return strings.Join(lines, "\n")
}

exp := normalize(expected)
got := normalize(rec.String())
if got != exp {
diff := difflib.UnifiedDiff{
A: difflib.SplitLines(exp),
FromFile: "exp",
B: difflib.SplitLines(got),
ToFile: "got",
Context: 4,
}
diffText, _ := difflib.GetUnifiedDiffString(diff)
return errors.Newf("unexpected diff:\n%s", diffText)
}
return nil
}
4 changes: 2 additions & 2 deletions pkg/util/tracing/service/service_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -67,13 +67,13 @@ func TestTracingServiceGetSpanRecordings(t *testing.T) {
sort.SliceStable(resp.Recordings, func(i, j int) bool {
return resp.Recordings[i].RecordedSpans[0].StartTime.Before(resp.Recordings[j].RecordedSpans[0].StartTime)
})
require.NoError(t, tracing.TestingCheckRecordedSpans(resp.Recordings[0].RecordedSpans, `
require.NoError(t, tracing.CheckRecordedSpans(resp.Recordings[0].RecordedSpans, `
span: root1
tags: _unfinished=1 _verbose=1
span: root1.child
tags: _unfinished=1 _verbose=1
`))
require.NoError(t, tracing.TestingCheckRecordedSpans(resp.Recordings[1].RecordedSpans, `
require.NoError(t, tracing.CheckRecordedSpans(resp.Recordings[1].RecordedSpans, `
span: fork1
tags: _unfinished=1 _verbose=1
`))
Expand Down
24 changes: 12 additions & 12 deletions pkg/util/tracing/span_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,7 @@ func TestRecordingString(t *testing.T) {
rec := root.GetRecording()
// Sanity check that the recording looks like we want. Note that this is not
// its String() representation; this just lists all the spans in order.
require.NoError(t, TestingCheckRecordedSpans(rec, `
require.NoError(t, CheckRecordedSpans(rec, `
span: root
tags: _verbose=1
event: root 1
Expand All @@ -91,7 +91,7 @@ func TestRecordingString(t *testing.T) {
event: local child 1
`))

require.NoError(t, TestingCheckRecording(rec, `
require.NoError(t, CheckRecording(rec, `
=== operation:root _verbose:1
event:root 1
=== operation:remote child _verbose:1
Expand Down Expand Up @@ -158,7 +158,7 @@ func TestRecordingInRecording(t *testing.T) {
root.Finish()

rootRec := root.GetRecording()
require.NoError(t, TestingCheckRecordedSpans(rootRec, `
require.NoError(t, CheckRecordedSpans(rootRec, `
span: root
tags: _verbose=1
span: child
Expand All @@ -168,14 +168,14 @@ func TestRecordingInRecording(t *testing.T) {
`))

childRec := child.GetRecording()
require.NoError(t, TestingCheckRecordedSpans(childRec, `
require.NoError(t, CheckRecordedSpans(childRec, `
span: child
tags: _verbose=1
span: grandchild
tags: _verbose=1
`))

require.NoError(t, TestingCheckRecording(childRec, `
require.NoError(t, CheckRecording(childRec, `
=== operation:child _verbose:1
=== operation:grandchild _verbose:1
`))
Expand All @@ -194,7 +194,7 @@ func TestSpan_ImportRemoteSpans(t *testing.T) {
sp.ImportRemoteSpans(ch.GetRecording())
sp.Finish()

require.NoError(t, TestingCheckRecordedSpans(sp.GetRecording(), `
require.NoError(t, CheckRecordedSpans(sp.GetRecording(), `
span: root
span: child
event: foo
Expand All @@ -221,10 +221,10 @@ func TestSpanRecordStructured(t *testing.T) {
require.NoError(t, types.UnmarshalAny(item.Payload, &d1))
require.IsType(t, (*types.Int32Value)(nil), d1.Message)

require.NoError(t, TestingCheckRecordedSpans(rec, `
require.NoError(t, CheckRecordedSpans(rec, `
span: root
`))
require.NoError(t, TestingCheckRecording(rec, `
require.NoError(t, CheckRecording(rec, `
=== operation:root
structured:{"@type":"type.googleapis.com/google.protobuf.Int32Value","value":4}
`))
Expand Down Expand Up @@ -350,7 +350,7 @@ func TestSpanReset(t *testing.T) {
}
}

require.NoError(t, TestingCheckRecordedSpans(sp.GetRecording(), `
require.NoError(t, CheckRecordedSpans(sp.GetRecording(), `
span: root
tags: _unfinished=1 _verbose=1
event: 1
Expand All @@ -364,7 +364,7 @@ func TestSpanReset(t *testing.T) {
event: 9
event: structured=10
`))
require.NoError(t, TestingCheckRecording(sp.GetRecording(), `
require.NoError(t, CheckRecording(sp.GetRecording(), `
=== operation:root _unfinished:1 _verbose:1
event:1
event:structured=2
Expand All @@ -380,11 +380,11 @@ func TestSpanReset(t *testing.T) {

sp.ResetRecording()

require.NoError(t, TestingCheckRecordedSpans(sp.GetRecording(), `
require.NoError(t, CheckRecordedSpans(sp.GetRecording(), `
span: root
tags: _unfinished=1 _verbose=1
`))
require.NoError(t, TestingCheckRecording(sp.GetRecording(), `
require.NoError(t, CheckRecording(sp.GetRecording(), `
=== operation:root _unfinished:1 _verbose:1
`))

Expand Down
Loading

0 comments on commit 411723d

Please sign in to comment.