diff --git a/CHANGELOG.md b/CHANGELOG.md index 7ecfe184715..6c49b2dec7d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm ### Added - 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 ### Changed diff --git a/attribute/set.go b/attribute/set.go index bd591894de5..a28f1435cb9 100644 --- a/attribute/set.go +++ b/attribute/set.go @@ -410,6 +410,15 @@ func (l *Set) MarshalJSON() ([]byte, error) { return json.Marshal(l.equivalent.iface) } +// MarshalLog is the marshaling function used by the logging system to represent this exporter. +func (l Set) MarshalLog() interface{} { + kvs := make(map[string]string) + for _, kv := range l.ToSlice() { + kvs[string(kv.Key)] = kv.Value.Emit() + } + return kvs +} + // Len implements `sort.Interface`. func (l *Sortable) Len() int { return len(*l) diff --git a/example/namedtracer/main.go b/example/namedtracer/main.go index a091e88f6c9..bde51637f8b 100644 --- a/example/namedtracer/main.go +++ b/example/namedtracer/main.go @@ -55,7 +55,7 @@ func initTracer() { func main() { // Set logging level to info to see SDK status messages - stdr.SetVerbosity(1) + stdr.SetVerbosity(5) // initialize trace provider. initTracer() diff --git a/exporters/stdout/stdouttrace/trace.go b/exporters/stdout/stdouttrace/trace.go index f1937a28ebe..c1da03c9365 100644 --- a/exporters/stdout/stdouttrace/trace.go +++ b/exporters/stdout/stdouttrace/trace.go @@ -106,3 +106,14 @@ func (e *Exporter) Shutdown(ctx context.Context) error { } return nil } + +// MarshalLog is the marshaling function used by the logging system to represent this exporter. +func (e *Exporter) MarshalLog() interface{} { + return struct { + Type string + WithTimestamps bool + }{ + Type: "stdout", + WithTimestamps: e.timestamps, + } +} diff --git a/sdk/go.mod b/sdk/go.mod index 41e782d9c72..2cd10292323 100644 --- a/sdk/go.mod +++ b/sdk/go.mod @@ -5,6 +5,7 @@ go 1.16 replace go.opentelemetry.io/otel => ../ require ( + github.com/go-logr/logr v1.2.2 github.com/google/go-cmp v0.5.6 github.com/stretchr/testify v1.7.0 go.opentelemetry.io/otel v1.3.0 diff --git a/sdk/resource/resource.go b/sdk/resource/resource.go index eb0ecd2cf91..4ef49b314fc 100644 --- a/sdk/resource/resource.go +++ b/sdk/resource/resource.go @@ -109,6 +109,17 @@ func (r *Resource) String() string { return r.attrs.Encoded(attribute.DefaultEncoder()) } +// MarshalLog is the marshaling function used by the logging system to represent this exporter. +func (r *Resource) MarshalLog() interface{} { + return struct { + Attributes attribute.Set + SchemaURL string + }{ + Attributes: r.attrs, + SchemaURL: r.schemaURL, + } +} + // Attributes returns a copy of attributes from the resource in a sorted order. // To avoid allocating a new slice, use an iterator. func (r *Resource) Attributes() []attribute.KeyValue { diff --git a/sdk/trace/batch_span_processor.go b/sdk/trace/batch_span_processor.go index 75f519a67b4..dda62c452c6 100644 --- a/sdk/trace/batch_span_processor.go +++ b/sdk/trace/batch_span_processor.go @@ -238,7 +238,7 @@ func (bsp *batchSpanProcessor) exportSpans(ctx context.Context) error { } if l := len(bsp.batch); l > 0 { - global.Debug("exporting spans", "count", len(bsp.batch)) + global.Debug("exporting spans", "count", len(bsp.batch), "dropped", bsp.dropped) err := bsp.e.ExportSpans(ctx, bsp.batch) // A new batch is always created after exporting, even if the batch failed to be exported. @@ -369,3 +369,16 @@ func (bsp *batchSpanProcessor) enqueueBlockOnQueueFull(ctx context.Context, sd R } return false } + +// MarshalLog is the marshaling function used by the logging system to represent this exporter. +func (bsp *batchSpanProcessor) MarshalLog() interface{} { + return struct { + Type string + SpanExporter SpanExporter + Config BatchSpanProcessorOptions + }{ + Type: "BatchSpanProcessor", + SpanExporter: bsp.e, + Config: bsp.o, + } +} diff --git a/sdk/trace/batch_span_processor_test.go b/sdk/trace/batch_span_processor_test.go index acc2d906426..f66c6bd1b43 100644 --- a/sdk/trace/batch_span_processor_test.go +++ b/sdk/trace/batch_span_processor_test.go @@ -23,9 +23,11 @@ import ( "testing" "time" + "github.com/go-logr/logr/funcr" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "go.opentelemetry.io/otel/internal/global" sdktrace "go.opentelemetry.io/otel/sdk/trace" "go.opentelemetry.io/otel/sdk/trace/tracetest" "go.opentelemetry.io/otel/trace" @@ -480,3 +482,44 @@ func TestBatchSpanProcessorForceFlushQueuedSpans(t *testing.T) { assert.Len(t, exp.GetSpans(), i+1) } } + +func BenchmarkSpanProcessor(b *testing.B) { + tp := sdktrace.NewTracerProvider( + sdktrace.WithBatcher( + tracetest.NewNoopExporter(), + sdktrace.WithMaxExportBatchSize(10), + )) + tracer := tp.Tracer("bench") + ctx := context.Background() + + b.ResetTimer() + b.ReportAllocs() + + for i := 0; i < b.N; i++ { + for j := 0; j < 10; j++ { + _, span := tracer.Start(ctx, "bench") + span.End() + } + } +} + +func BenchmarkSpanProcessorVerboseLogging(b *testing.B) { + global.SetLogger(funcr.New(func(prefix, args string) {}, funcr.Options{Verbosity: 5})) + tp := sdktrace.NewTracerProvider( + sdktrace.WithBatcher( + tracetest.NewNoopExporter(), + sdktrace.WithMaxExportBatchSize(10), + )) + tracer := tp.Tracer("bench") + ctx := context.Background() + + b.ResetTimer() + b.ReportAllocs() + + for i := 0; i < b.N; i++ { + for j := 0; j < 10; j++ { + _, span := tracer.Start(ctx, "bench") + span.End() + } + } +} diff --git a/sdk/trace/provider.go b/sdk/trace/provider.go index 47ff5fad1e2..68bdefe0c94 100644 --- a/sdk/trace/provider.go +++ b/sdk/trace/provider.go @@ -21,6 +21,7 @@ import ( "sync/atomic" "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/internal/global" "go.opentelemetry.io/otel/sdk/instrumentation" "go.opentelemetry.io/otel/sdk/resource" "go.opentelemetry.io/otel/trace" @@ -52,6 +53,23 @@ type tracerProviderConfig struct { resource *resource.Resource } +// MarshalLog is the marshaling function used by the logging system to represent this exporter. +func (cfg tracerProviderConfig) MarshalLog() interface{} { + return struct { + SpanProcessors []SpanProcessor + SamplerType string + IDGeneratorType string + SpanLimits SpanLimits + Resource *resource.Resource + }{ + SpanProcessors: cfg.processors, + SamplerType: fmt.Sprintf("%T", cfg.sampler), + IDGeneratorType: fmt.Sprintf("%T", cfg.idGenerator), + SpanLimits: cfg.spanLimits, + Resource: cfg.resource, + } +} + type TracerProvider struct { mu sync.Mutex namedTracer map[instrumentation.Library]*tracer @@ -91,6 +109,8 @@ func NewTracerProvider(opts ...TracerProviderOption) *TracerProvider { resource: o.resource, } + global.Info("TracerProvider created", "config", o) + for _, sp := range o.processors { tp.RegisterSpanProcessor(sp) } @@ -125,6 +145,7 @@ func (p *TracerProvider) Tracer(name string, opts ...trace.TracerOption) trace.T instrumentationLibrary: il, } p.namedTracer[il] = t + global.Info("Tracer created", "name", name, "version", c.InstrumentationVersion(), "schemaURL", c.SchemaURL()) } return t } diff --git a/sdk/trace/simple_span_processor.go b/sdk/trace/simple_span_processor.go index ecc45bc6c38..d31d3c1caff 100644 --- a/sdk/trace/simple_span_processor.go +++ b/sdk/trace/simple_span_processor.go @@ -115,3 +115,14 @@ func (ssp *simpleSpanProcessor) Shutdown(ctx context.Context) error { func (ssp *simpleSpanProcessor) ForceFlush(context.Context) error { return nil } + +// MarshalLog is the marshaling function used by the logging system to represent this exporter. +func (ssp *simpleSpanProcessor) MarshalLog() interface{} { + return struct { + Type string + Exporter SpanExporter + }{ + Type: "SimpleSpanProcessor", + Exporter: ssp.exporter, + } +}