Skip to content

Commit

Permalink
tracing: use timeutil for Now() and Since()
Browse files Browse the repository at this point in the history
Previously, for performance reasons (as well as a few others) we used
`time.Now()` and `time.Since` in the tracing library. But the work in
f782e45 alleviated those concerns, so
we can now switch to using `timeutil` library in two places.
```
Tracer_StartSpanCtx/opts=none-24                                    508ns ± 0%     512ns ± 0%  +0.80%  (p=0.000 n=10+10)
Tracer_StartSpanCtx/opts=real-24                                    510ns ± 1%     515ns ± 1%  +0.96%  (p=0.000 n=10+10)
Tracer_StartSpanCtx/opts=real,logtag-24                             539ns ± 1%     544ns ± 1%  +0.90%  (p=0.000 n=10+10)
Tracer_StartSpanCtx/opts=real,autoparent-24                         480ns ± 0%     486ns ± 1%  +1.26%  (p=0.000 n=10+10)
Tracer_StartSpanCtx/opts=real,manualparent-24                       523ns ± 1%     527ns ± 1%  +0.91%  (p=0.004 n=10+10)
Tracer_StartSpanCtx/opts=real,autoparent,withEventListener-24       755ns ± 0%     765ns ± 0%  +1.40%  (p=0.000 n=10+10)
Tracer_StartSpanCtx/opts=real,manualparent,withEventListener-24     547ns ± 1%     552ns ± 1%  +0.89%  (p=0.000 n=10+10)
Span_GetRecording/root-only-24                                     7.36ns ± 0%    6.75ns ± 0%  -8.26%  (p=0.000 n=10+10)
Span_GetRecording/child-only-24                                    7.36ns ± 0%    6.75ns ± 0%  -8.30%  (p=0.000 n=10+10)
Span_GetRecording/root-child-24                                    7.36ns ± 0%    6.74ns ± 0%  -8.32%  (p=0.000 n=10+10)
RecordingWithStructuredEvent/with-event-listener-24                3.47µs ± 1%    3.47µs ± 1%    ~     (p=0.541 n=10+10)
RecordingWithStructuredEvent/without-event-listener-24             3.31µs ± 0%    3.32µs ± 1%    ~     (p=0.271 n=10+10)
SpanCreation/detached-child=false-24                               1.07µs ± 1%    1.07µs ± 1%    ~     (p=0.955 n=10+10)
SpanCreation/detached-child=true-24                                1.84µs ± 1%    1.82µs ± 1%  -1.30%  (p=0.000 n=10+10)
```
And no changes in allocations.

Epic: None

Release note: None
  • Loading branch information
yuzefovich committed Nov 4, 2022
1 parent d860e15 commit 53ef606
Show file tree
Hide file tree
Showing 3 changed files with 2 additions and 5 deletions.
3 changes: 0 additions & 3 deletions pkg/testutils/lint/lint_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -731,9 +731,6 @@ func TestLint(t *testing.T) {
":!**/embedded.go",
":!util/timeutil/time.go",
":!util/timeutil/zoneinfo.go",
":!util/tracing/span.go",
":!util/tracing/crdbspan.go",
":!util/tracing/tracer.go",
":!cmd/roachtest/tests/gorm_helpers.go",
)
if err != nil {
Expand Down
2 changes: 1 addition & 1 deletion pkg/util/tracing/crdbspan.go
Original file line number Diff line number Diff line change
Expand Up @@ -854,7 +854,7 @@ func (s *crdbSpan) getRecordingNoChildrenLocked(
// -1 indicates an unfinished Span. For a recording it's better to put some
// duration in it, otherwise tools get confused. For example, we export
// recordings to Jaeger, and spans with a zero duration don't look nice.
rs.Duration = time.Since(rs.StartTime)
rs.Duration = timeutil.Since(rs.StartTime)
rs.Finished = false
} else {
rs.Finished = true
Expand Down
2 changes: 1 addition & 1 deletion pkg/util/tracing/tracer.go
Original file line number Diff line number Diff line change
Expand Up @@ -1130,7 +1130,7 @@ child operation: %s, tracer created at:
opts.LogTags = opts.Parent.i.crdb.logTags
}

startTime := time.Now()
startTime := timeutil.Now()

// First, create any external spans that we may need (OpenTelemetry, net/trace).
// We do this early so that they are available when we construct the main Span,
Expand Down

0 comments on commit 53ef606

Please sign in to comment.