Add info/debug logging to the metric SDK (#4315)

* 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 <cheung.zhy.csu@gmail.com> Co-authored-by: Robert Pająk <pellared@hotmail.com>
open-telemetry · Jul 17, 2023 · 7467923 · 7467923
1 parent d18f201
commit 7467923
Show file tree

Hide file tree

Showing 8 changed files with 109 additions and 3 deletions.
diff --git 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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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)
 	})