From 7467923a5117778f0155a8b452ba8e759dfcd7d0 Mon Sep 17 00:00:00 2001 From: Tyler Yahn Date: Mon, 17 Jul 2023 07:57:01 -0700 Subject: [PATCH] Add info/debug logging to the metric SDK (#4315) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * Add debug logging to the metric SDK Resolves #3722 * Log MeterProvider and Meter setup at info level * Add changelog entry --------- Co-authored-by: Chester Cheung Co-authored-by: Robert Pająk --- CHANGELOG.md | 1 + .../otlpmetric/otlpmetricgrpc/exporter.go | 10 ++++++- .../otlpmetric/otlpmetrichttp/exporter.go | 10 ++++++- exporters/prometheus/exporter.go | 21 +++++++++++++++ exporters/stdout/stdoutmetric/exporter.go | 7 +++++ sdk/metric/manual_reader.go | 19 +++++++++++++ sdk/metric/periodic_reader.go | 27 +++++++++++++++++++ sdk/metric/provider.go | 17 +++++++++++- 8 files changed, 109 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index c653ff02a7e..770c6250764 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,7 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm - Add `Exporter` struct in `go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetricgrpc`. (#4272) - Add `Exporter` struct in `go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetrichttp`. (#4272) - Add `WithoutCounterSuffixes` option in `go.opentelemetry.io/otel/exporters/prometheus` to disable addition of `_total` suffixes. (#4306) +- Add info and debug logging to the metric SDK. (#4315) ### Changed diff --git a/exporters/otlp/otlpmetric/otlpmetricgrpc/exporter.go b/exporters/otlp/otlpmetric/otlpmetricgrpc/exporter.go index 3b29613a7b4..1f28bfd6a59 100644 --- a/exporters/otlp/otlpmetric/otlpmetricgrpc/exporter.go +++ b/exporters/otlp/otlpmetric/otlpmetricgrpc/exporter.go @@ -18,6 +18,7 @@ import ( "context" ominternal "go.opentelemetry.io/otel/exporters/otlp/otlpmetric/internal" + "go.opentelemetry.io/otel/internal/global" "go.opentelemetry.io/otel/sdk/metric" "go.opentelemetry.io/otel/sdk/metric/aggregation" "go.opentelemetry.io/otel/sdk/metric/metricdata" @@ -43,7 +44,9 @@ func (e *Exporter) Aggregation(k metric.InstrumentKind) aggregation.Aggregation // This method returns an error if called after Shutdown. // This method returns an error if the method is canceled by the passed context. func (e *Exporter) Export(ctx context.Context, rm *metricdata.ResourceMetrics) error { - return e.wrapped.Export(ctx, rm) + err := e.wrapped.Export(ctx, rm) + global.Debug("OTLP/gRPC exporter export", "Data", rm) + return err } // ForceFlush flushes any metric data held by an exporter. @@ -67,6 +70,11 @@ func (e *Exporter) Shutdown(ctx context.Context) error { return e.wrapped.Shutdown(ctx) } +// MarshalLog returns logging data about the Exporter. +func (e *Exporter) MarshalLog() interface{} { + return struct{ Type string }{Type: "OTLP/gRPC"} +} + // New returns an OpenTelemetry metric Exporter. The Exporter can be used with // a PeriodicReader to export OpenTelemetry metric data to an OTLP receiving // endpoint using gRPC. diff --git a/exporters/otlp/otlpmetric/otlpmetrichttp/exporter.go b/exporters/otlp/otlpmetric/otlpmetrichttp/exporter.go index b84ffc34f18..47d3c469825 100644 --- a/exporters/otlp/otlpmetric/otlpmetrichttp/exporter.go +++ b/exporters/otlp/otlpmetric/otlpmetrichttp/exporter.go @@ -18,6 +18,7 @@ import ( "context" ominternal "go.opentelemetry.io/otel/exporters/otlp/otlpmetric/internal" + "go.opentelemetry.io/otel/internal/global" "go.opentelemetry.io/otel/sdk/metric" "go.opentelemetry.io/otel/sdk/metric/aggregation" "go.opentelemetry.io/otel/sdk/metric/metricdata" @@ -43,7 +44,9 @@ func (e *Exporter) Aggregation(k metric.InstrumentKind) aggregation.Aggregation // This method returns an error if called after Shutdown. // This method returns an error if the method is canceled by the passed context. func (e *Exporter) Export(ctx context.Context, rm *metricdata.ResourceMetrics) error { - return e.wrapped.Export(ctx, rm) + err := e.wrapped.Export(ctx, rm) + global.Debug("OTLP/HTTP exporter export", "Data", rm) + return err } // ForceFlush flushes any metric data held by an exporter. @@ -67,6 +70,11 @@ func (e *Exporter) Shutdown(ctx context.Context) error { return e.wrapped.Shutdown(ctx) } +// MarshalLog returns logging data about the Exporter. +func (e *Exporter) MarshalLog() interface{} { + return struct{ Type string }{Type: "OTLP/HTTP"} +} + // New returns an OpenTelemetry metric Exporter. The Exporter can be used with // a PeriodicReader to export OpenTelemetry metric data to an OTLP receiving // endpoint using protobufs over HTTP. diff --git a/exporters/prometheus/exporter.go b/exporters/prometheus/exporter.go index 98949d8ca87..04f26e7cb4a 100644 --- a/exporters/prometheus/exporter.go +++ b/exporters/prometheus/exporter.go @@ -53,6 +53,25 @@ type Exporter struct { metric.Reader } +// MarshalLog returns logging data about the Exporter. +func (e *Exporter) MarshalLog() interface{} { + const t = "Prometheus exporter" + + if r, ok := e.Reader.(*metric.ManualReader); ok { + under := r.MarshalLog() + if data, ok := under.(struct { + Type string + Registered bool + Shutdown bool + }); ok { + data.Type = t + return data + } + } + + return struct{ Type string }{Type: t} +} + var _ metric.Reader = &Exporter{} // collector is used to implement prometheus.Collector. @@ -129,6 +148,8 @@ func (c *collector) Collect(ch chan<- prometheus.Metric) { } } + global.Debug("Prometheus exporter export", "Data", metrics) + // Initialize (once) targetInfo and disableTargetInfo. func() { c.mu.Lock() diff --git a/exporters/stdout/stdoutmetric/exporter.go b/exporters/stdout/stdoutmetric/exporter.go index 06846203597..e3d867e00dc 100644 --- a/exporters/stdout/stdoutmetric/exporter.go +++ b/exporters/stdout/stdoutmetric/exporter.go @@ -73,6 +73,9 @@ func (e *exporter) Export(ctx context.Context, data *metricdata.ResourceMetrics) if e.redactTimestamps { redactTimestamps(data) } + + global.Debug("STDOUT exporter export", "Data", data) + return e.encVal.Load().(encoderHolder).Encode(data) } @@ -90,6 +93,10 @@ func (e *exporter) Shutdown(ctx context.Context) error { return ctx.Err() } +func (e *exporter) MarshalLog() interface{} { + return struct{ Type string }{Type: "STDOUT"} +} + func redactTimestamps(orig *metricdata.ResourceMetrics) { for i, sm := range orig.ScopeMetrics { metrics := sm.Metrics diff --git a/sdk/metric/manual_reader.go b/sdk/metric/manual_reader.go index 3864e2f0694..5677003550b 100644 --- a/sdk/metric/manual_reader.go +++ b/sdk/metric/manual_reader.go @@ -157,9 +157,28 @@ func (mr *ManualReader) Collect(ctx context.Context, rm *metricdata.ResourceMetr } rm.ScopeMetrics = append(rm.ScopeMetrics, externalMetrics...) } + + global.Debug("ManualReader collection", "Data", rm) + return unifyErrors(errs) } +// MarshalLog returns logging data about the ManualReader. +func (r *ManualReader) MarshalLog() interface{} { + r.mu.Lock() + down := r.isShutdown + r.mu.Unlock() + return struct { + Type string + Registered bool + Shutdown bool + }{ + Type: "ManualReader", + Registered: r.sdkProducer.Load() != nil, + Shutdown: down, + } +} + // manualReaderConfig contains configuration options for a ManualReader. type manualReaderConfig struct { temporalitySelector TemporalitySelector diff --git a/sdk/metric/periodic_reader.go b/sdk/metric/periodic_reader.go index 17cb1be1104..3ea2c2f0fb2 100644 --- a/sdk/metric/periodic_reader.go +++ b/sdk/metric/periodic_reader.go @@ -115,6 +115,7 @@ func NewPeriodicReader(exporter Exporter, options ...PeriodicReaderOption) *Peri conf := newPeriodicReaderConfig(options) ctx, cancel := context.WithCancel(context.Background()) r := &PeriodicReader{ + interval: conf.interval, timeout: conf.timeout, exporter: exporter, flushCh: make(chan chan error), @@ -144,6 +145,7 @@ type PeriodicReader struct { isShutdown bool externalProducers atomic.Value + interval time.Duration timeout time.Duration exporter Exporter flushCh chan chan error @@ -280,6 +282,9 @@ func (r *PeriodicReader) collect(ctx context.Context, p interface{}, rm *metricd } rm.ScopeMetrics = append(rm.ScopeMetrics, externalMetrics...) } + + global.Debug("PeriodicReader collection", "Data", rm) + return unifyErrors(errs) } @@ -350,3 +355,25 @@ func (r *PeriodicReader) Shutdown(ctx context.Context) error { }) return err } + +// MarshalLog returns logging data about the PeriodicReader. +func (r *PeriodicReader) MarshalLog() interface{} { + r.mu.Lock() + down := r.isShutdown + r.mu.Unlock() + return struct { + Type string + Exporter Exporter + Registered bool + Shutdown bool + Interval time.Duration + Timeout time.Duration + }{ + Type: "PeriodicReader", + Exporter: r.exporter, + Registered: r.sdkProducer.Load() != nil, + Shutdown: down, + Interval: r.interval, + Timeout: r.timeout, + } +} diff --git a/sdk/metric/provider.go b/sdk/metric/provider.go index 7063901607c..49dd071c9d3 100644 --- a/sdk/metric/provider.go +++ b/sdk/metric/provider.go @@ -51,11 +51,19 @@ var _ metric.MeterProvider = (*MeterProvider)(nil) func NewMeterProvider(options ...Option) *MeterProvider { conf := newConfig(options) flush, sdown := conf.readerSignals() - return &MeterProvider{ + + mp := &MeterProvider{ pipes: newPipelines(conf.res, conf.readers, conf.views), forceFlush: flush, shutdown: sdown, } + // Log after creation so all readers show correctly they are registered. + global.Info("MeterProvider created", + "Resource", conf.res, + "Readers", conf.readers, + "Views", len(conf.views), + ) + return mp } // Meter returns a Meter with the given name and configured with options. @@ -83,6 +91,13 @@ func (mp *MeterProvider) Meter(name string, options ...metric.MeterOption) metri Version: c.InstrumentationVersion(), SchemaURL: c.SchemaURL(), } + + global.Info("Meter created", + "Name", s.Name, + "Version", s.Version, + "SchemaURL", s.SchemaURL, + ) + return mp.meters.Lookup(s, func() *meter { return newMeter(s, mp.pipes) })