diff --git a/CHANGELOG.md b/CHANGELOG.md index 6e1c838e32e..d7d9e477d72 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,12 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm - Support `OTEL_EXPORTER_ZIPKIN_ENDPOINT` env to specify zipkin collector endpoint (#2490) - Log the configuration of TracerProviders, and Tracers for debugging. To enable use a logger with Verbosity (V level) >=1 +- The `"go.opentelemetry.io/otel/sdk/trace".TraceProvider` can now be configured + with a newly added `Clock` interface. This interface is called when determining + the start and end times for a span. Additionally, a `WithClock` is also added + to the package enabling users to set custom implementations of the `Clock` interface. + The standard library `time` package is still used for this functionality by default + if no option is set. (#2052) ### Changed diff --git a/sdk/internal/internal.go b/sdk/internal/internal.go index 84a02306e64..6ae64817110 100644 --- a/sdk/internal/internal.go +++ b/sdk/internal/internal.go @@ -16,7 +16,6 @@ package internal // import "go.opentelemetry.io/otel/sdk/internal" import ( "fmt" - "time" "go.opentelemetry.io/otel" ) @@ -24,14 +23,3 @@ import ( // UserAgent is the user agent to be added to the outgoing // requests from the exporters. var UserAgent = fmt.Sprintf("opentelemetry-go/%s", otel.Version()) - -// MonotonicEndTime returns the end time at present -// but offset from start, monotonically. -// -// The monotonic clock is used in subtractions hence -// the duration since start added back to start gives -// end as a monotonic time. -// See https://golang.org/pkg/time/#hdr-Monotonic_Clocks -func MonotonicEndTime(start time.Time) time.Time { - return start.Add(time.Since(start)) -} diff --git a/sdk/trace/provider.go b/sdk/trace/provider.go index 68bdefe0c94..a0ee44e1d02 100644 --- a/sdk/trace/provider.go +++ b/sdk/trace/provider.go @@ -51,6 +51,9 @@ type tracerProviderConfig struct { // resource contains attributes representing an entity that produces telemetry. resource *resource.Resource + + // clock is used to provide start/end time for spans + clock Clock } // MarshalLog is the marshaling function used by the logging system to represent this exporter. @@ -78,6 +81,7 @@ type TracerProvider struct { idGenerator IDGenerator spanLimits SpanLimits resource *resource.Resource + clock Clock } var _ trace.TracerProvider = &TracerProvider{} @@ -107,6 +111,7 @@ func NewTracerProvider(opts ...TracerProviderOption) *TracerProvider { idGenerator: o.idGenerator, spanLimits: o.spanLimits, resource: o.resource, + clock: o.clock, } global.Info("TracerProvider created", "config", o) @@ -350,6 +355,18 @@ func WithSpanLimits(sl SpanLimits) TracerProviderOption { }) } +// WithClock returns a TracerProviderOption that will configure the +// TracerProvider's clock. The configured clock is used by Tracers +// to generate span start/end time. +// +// If this option is not used, the TracerProvider will provide the default +// clock which just calls the time package under the hood. +func WithClock(clk Clock) TracerProviderOption { + return traceProviderOptionFunc(func(cfg *tracerProviderConfig) { + cfg.clock = clk + }) +} + // ensureValidTracerProviderConfig ensures that given TracerProviderConfig is valid. func ensureValidTracerProviderConfig(cfg *tracerProviderConfig) { if cfg.sampler == nil { @@ -362,4 +379,7 @@ func ensureValidTracerProviderConfig(cfg *tracerProviderConfig) { if cfg.resource == nil { cfg.resource = resource.Default() } + if cfg.clock == nil { + cfg.clock = defaultClock() + } } diff --git a/sdk/trace/span.go b/sdk/trace/span.go index 41a68b58551..28f96ea6819 100644 --- a/sdk/trace/span.go +++ b/sdk/trace/span.go @@ -26,7 +26,6 @@ import ( "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/codes" "go.opentelemetry.io/otel/sdk/instrumentation" - "go.opentelemetry.io/otel/sdk/internal" "go.opentelemetry.io/otel/sdk/resource" semconv "go.opentelemetry.io/otel/semconv/v1.7.0" "go.opentelemetry.io/otel/trace" @@ -113,9 +112,6 @@ type recordingSpan struct { // name is the name of this span. name string - // startTime is the time at which this span was started. - startTime time.Time - // endTime is the time at which this span was ended. It contains the zero // value of time.Time until the span is ended. endTime time.Time @@ -155,6 +151,9 @@ type recordingSpan struct { // spanLimits holds the limits to this span. spanLimits SpanLimits + + // stopwatch holds the Stopwatch returned by Clock.Stopwatch method + stopwatch Stopwatch } var _ ReadWriteSpan = (*recordingSpan)(nil) @@ -229,7 +228,7 @@ func (s *recordingSpan) End(options ...trace.SpanEndOption) { // Store the end time as soon as possible to avoid artificially increasing // the span's duration in case some operation below takes a while. - et := internal.MonotonicEndTime(s.startTime) + et := s.stopwatch.Started().Add(s.stopwatch.Stop()) // Do relative expensive check now that we have an end time and see if we // need to do any more processing. @@ -387,7 +386,7 @@ func (s *recordingSpan) SpanKind() trace.SpanKind { func (s *recordingSpan) StartTime() time.Time { s.mu.Lock() defer s.mu.Unlock() - return s.startTime + return s.startTime() } // EndTime returns the time this span ended. For spans that have not yet @@ -520,7 +519,7 @@ func (s *recordingSpan) snapshot() ReadOnlySpan { sd.resource = s.resource sd.spanContext = s.spanContext sd.spanKind = s.spanKind - sd.startTime = s.startTime + sd.startTime = s.startTime() sd.status = s.status sd.childSpanCount = s.childSpanCount @@ -578,6 +577,10 @@ func (s *recordingSpan) addChild() { func (*recordingSpan) private() {} +func (s *recordingSpan) startTime() time.Time { + return s.stopwatch.Started() +} + // runtimeTrace starts a "runtime/trace".Task for the span and returns a // context containing the task. func (s *recordingSpan) runtimeTrace(ctx context.Context) context.Context { diff --git a/sdk/trace/time.go b/sdk/trace/time.go new file mode 100644 index 00000000000..60cff6a01ec --- /dev/null +++ b/sdk/trace/time.go @@ -0,0 +1,62 @@ +// Copyright The OpenTelemetry Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package trace // import "go.opentelemetry.io/otel/sdk/trace" + +import ( + "time" +) + +// Clock is the entrypoint for providing time to span's start/end timestamp. +// By default the standard "time" package will be used. User can replace +// it with customized clock implementation (e.g. with additional clock +// synchronization logic) by using the `WithClock` option. Also users may +// still be able to change the span start time even using a custom clock by +// providing a timestamp with the WithTimestamp option. +type Clock interface { + // Stopwatch returns a started Stopwatch measuring a time interval. + Stopwatch(t time.Time) Stopwatch +} + +// Stopwatch measures a time interval. +type Stopwatch interface { + // Started returns the time the Stopwatch was started. + Started() time.Time + // Stop stops the stopwatch and returns the duration from when this Stopwatch was started. + // This will only be called once when generating span's end time and should return a positive + // time.Duration in order to ensure the monotonicity of span's start/end time. + Stop() time.Duration +} + +type standardClock struct{} +type standardStopwatch time.Time + +func defaultClock() Clock { + return standardClock{} +} + +func (standardClock) Stopwatch(t time.Time) Stopwatch { + if t.IsZero() { + return standardStopwatch(time.Now()) + } + return standardStopwatch(t) +} + +func (w standardStopwatch) Started() time.Time { + return time.Time(w) +} + +func (w standardStopwatch) Stop() time.Duration { + return time.Since(time.Time(w)) +} diff --git a/sdk/trace/trace_test.go b/sdk/trace/trace_test.go index be27ed62041..76b6024e395 100644 --- a/sdk/trace/trace_test.go +++ b/sdk/trace/trace_test.go @@ -1659,6 +1659,66 @@ func TestAddLinksWithMoreAttributesThanLimit(t *testing.T) { } } +type frozenClock struct { + now time.Time +} +type frozenStopwatch struct { + started time.Time +} + +func (f frozenStopwatch) Started() time.Time { + return f.started +} +func (f frozenStopwatch) Stop() time.Duration { + return 0 +} + +// newFrozenClock returns a clock which stops at time t +func newFrozenClock(t time.Time) frozenClock { + return frozenClock{ + now: t, + } +} + +func (c frozenClock) Stopwatch(t time.Time) Stopwatch { + if t.IsZero() { + return frozenStopwatch{ + started: c.now, + } + } + return frozenStopwatch{ + started: t, + } +} + +func TestCustomClock(t *testing.T) { + te := NewTestExporter() + now := time.Now() + tp := NewTracerProvider(WithSyncer(te), WithClock(newFrozenClock(now))) + tracer := tp.Tracer("custom-clock") + + _, span := tracer.Start(context.Background(), "test-frozen-clock") + time.Sleep(time.Microsecond * 2) + span.End() + require.Equal(t, te.Len(), 1, "should only have one span") + + got := te.Spans()[0] + assert.Equal(t, now, got.StartTime(), "StartTime should return the frozen time") + assert.Equal(t, now, got.EndTime(), "EndTime should return the frozen time") + + // test user provided span start time + te.Reset() + now = time.Now() + _, span = tracer.Start(context.Background(), "test-frozen-clock-with-start-time", + trace.WithTimestamp(now)) + time.Sleep(time.Microsecond * 2) + span.End() + require.Equal(t, te.Len(), 1, "should only have one span") + got = te.Spans()[0] + assert.Equal(t, now, got.StartTime(), "StartTime should returns the user provided time") + assert.Equal(t, now, got.EndTime(), "StartTime should returns the user provided time") +} + type stateSampler struct { prefix string f func(trace.TraceState) trace.TraceState diff --git a/sdk/trace/tracer.go b/sdk/trace/tracer.go index 1177c729a8f..34b61ef23e0 100644 --- a/sdk/trace/tracer.go +++ b/sdk/trace/tracer.go @@ -16,7 +16,6 @@ package trace // import "go.opentelemetry.io/otel/sdk/trace" import ( "context" - "time" "go.opentelemetry.io/otel/sdk/instrumentation" "go.opentelemetry.io/otel/trace" @@ -117,16 +116,12 @@ func (tr *tracer) newSpan(ctx context.Context, name string, config *trace.SpanCo // newRecordingSpan returns a new configured recordingSpan. func (tr *tracer) newRecordingSpan(psc, sc trace.SpanContext, name string, sr SamplingResult, config *trace.SpanConfig) *recordingSpan { startTime := config.Timestamp() - if startTime.IsZero() { - startTime = time.Now() - } s := &recordingSpan{ parent: psc, spanContext: sc, spanKind: trace.ValidateSpanKind(config.SpanKind()), name: name, - startTime: startTime, attributes: newAttributesMap(tr.provider.spanLimits.AttributeCountLimit), events: newEvictedQueue(tr.provider.spanLimits.EventCountLimit), links: newEvictedQueue(tr.provider.spanLimits.LinkCountLimit), @@ -134,6 +129,7 @@ func (tr *tracer) newRecordingSpan(psc, sc trace.SpanContext, name string, sr Sa spanLimits: tr.provider.spanLimits, resource: tr.provider.resource, instrumentationLibrary: tr.instrumentationLibrary, + stopwatch: tr.provider.clock.Stopwatch(startTime), } for _, l := range config.Links() {