simplifies error handling, uses internal logger by default

CHANGELOG.md

@@ -17,12 +17,14 @@ This project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm
   - The following struct types moved and are replaced with type aliases, since they are exposed to the user: `Observation`, `Measurement`.
   - The No-op implementations of sync and async instruments are no longer exported, new functions `sdkapi.NewNoopAsyncInstrument()` and `sdkapi.NewNoopSyncInstrument()` are provided instead. (#2271)
 - Update the SDK `BatchSpanProcessor` to export all queued spans when `ForceFlush` is called. (#2080, #2335)
+- The default ErrorHandler now uses the internal logger.  The default of logging to stderr is unchanged.
 
 ### Added
 
 - Add the `"go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetricgrpc".WithGRPCConn` option so the exporter can reuse an existing gRPC connection. (#2002)
 - Added a new `schema` module to help parse Schema Files in OTEP 0152 format. (#2267)
 - Added a new `MapCarrier` to the `go.opentelemetry.io/otel/propagation` package to hold propagated coss-cutting concerns as a `map[string]string` held in memory. (#2334)
+- Added an internal Logger.  This can be used by the SDK and API to provide users with feedback of the internal state. To enable verbose logs configure the logger which will print V(1) logs.  For debugging information confgure to print V(5) logs.
 
 ## [1.1.0] - 2021-10-27
 

handler.go

@@ -15,10 +15,9 @@
 package otel // import "go.opentelemetry.io/otel"
 
 import (
-	"log"
-	"os"
 	"sync"
-	"sync/atomic"
+
+	"go.opentelemetry.io/otel/internal/debug"
 )
 
 var (
@@ -26,79 +25,61 @@ var (
 	// throughout an OpenTelemetry instrumented project. When a user
 	// specified ErrorHandler is registered (`SetErrorHandler`) all calls to
 	// `Handle` and will be delegated to the registered ErrorHandler.
-	globalErrorHandler = defaultErrorHandler()
-
+	globalErrorHandler = &errorHandlerDelegate{
+		delegate: &defaultErrorHandler{},
+	}
 	// delegateErrorHandlerOnce ensures that a user provided ErrorHandler is
 	// only ever registered once.
 	delegateErrorHandlerOnce sync.Once
 
 	// Compile-time check that delegator implements ErrorHandler.
-	_ ErrorHandler = (*delegator)(nil)
+	_ ErrorHandler = (*errorHandlerDelegate)(nil)
+	_ ErrorHandler = (*defaultErrorHandler)(nil)
 )
 
-type holder struct {
-	eh ErrorHandler
+// errorHandlerDelegate is a box type to enable updating of all handlers returned by GetErrorHandler()
+type errorHandlerDelegate struct {
+	delegate ErrorHandler
 }
 
-func defaultErrorHandler() *atomic.Value {
-	v := &atomic.Value{}
-	v.Store(holder{eh: &delegator{l: log.New(os.Stderr, "", log.LstdFlags)}})
-	return v
+func (h *errorHandlerDelegate) setDelegate(d ErrorHandler) {
+	h.delegate = d
 }
 
-// delegator logs errors if no delegate is set, otherwise they are delegated.
-type delegator struct {
-	delegate atomic.Value
-
-	l *log.Logger
-}
-
-// setDelegate sets the ErrorHandler delegate.
-func (h *delegator) setDelegate(d ErrorHandler) {
-	// It is critical this is guarded with delegateErrorHandlerOnce, if it is
-	// called again with a different concrete type it will panic.
-	h.delegate.Store(d)
-}
-
-// Handle logs err if no delegate is set, otherwise it is delegated.
-func (h *delegator) Handle(err error) {
-	if d := h.delegate.Load(); d != nil {
-		d.(ErrorHandler).Handle(err)
+// Handle handles any error deemed irremediable by an OpenTelemetry component.
+func (h *errorHandlerDelegate) Handle(err error) {
+	if h == nil {
 		return
 	}
-	h.l.Print(err)
+	h.delegate.Handle(err)
 }
 
+// defaultErrorHandler utilizes the internal logger to manage the messages.
+type defaultErrorHandler struct{}
+
+func (h *defaultErrorHandler) Handle(err error) {
+	debug.Error(err, "")
+}
+
+// DiscardErrorHandler drops all errors.
+// Use `SetErrorHandler(DiscardErrorHandler{})` to disable error handling
+type DiscardErrorHandler struct{}
+
+func (DiscardErrorHandler) Handle(error) {}
+
 // GetErrorHandler returns the global ErrorHandler instance.
 //
 // The default ErrorHandler instance returned will log all errors to STDERR
 // until an override ErrorHandler is set with SetErrorHandler. All
 // ErrorHandler returned prior to this will automatically forward errors to
 // the set instance instead of logging.
-//
-// Subsequent calls to SetErrorHandler after the first will not forward errors
-// to the new ErrorHandler for prior returned instances.
 func GetErrorHandler() ErrorHandler {
-	return globalErrorHandler.Load().(holder).eh
+	return globalErrorHandler
 }
 
 // SetErrorHandler sets the global ErrorHandler to h.
-//
-// The first time this is called all ErrorHandler previously returned from
-// GetErrorHandler will send errors to h instead of the default logging
-// ErrorHandler. Subsequent calls will set the global ErrorHandler, but not
-// delegate errors to h.
 func SetErrorHandler(h ErrorHandler) {
-	delegateErrorHandlerOnce.Do(func() {
-		current := GetErrorHandler()
-		if current == h {
-			return
-		}
-		if internalHandler, ok := current.(*delegator); ok {
-			internalHandler.setDelegate(h)
-		}
-	})
-	globalErrorHandler.Store(holder{eh: h})
+	globalErrorHandler.setDelegate(h)
 }
 
 // Handle is a convenience function for ErrorHandler().Handle(err)

handler_test.go

@@ -15,39 +15,20 @@
 package otel
 
 import (
-	"bytes"
 	"errors"
-	"io/ioutil"
-	"log"
+	"strings"
 	"sync"
-	"sync/atomic"
 	"testing"
 
 	"github.com/stretchr/testify/suite"
 )
 
-type errLogger []string
-
-func (l *errLogger) Write(p []byte) (int, error) {
-	msg := bytes.TrimRight(p, "\n")
-	(*l) = append(*l, string(msg))
-	return len(msg), nil
+type errLogger struct {
+	errs []string
 }
 
-func (l *errLogger) Reset() {
-	*l = errLogger([]string{})
-}
-
-func (l *errLogger) Got() []string {
-	return []string(*l)
-}
-
-type logger struct {
-	l *log.Logger
-}
-
-func (l *logger) Handle(err error) {
-	l.l.Print(err)
+func (l *errLogger) Handle(err error) {
+	l.errs = append(l.errs, err.Error())
 }
 
 func causeErr(text string) {
@@ -62,76 +43,85 @@ type HandlerTestSuite struct {
 }
 
 func (s *HandlerTestSuite) SetupSuite() {
-	s.errLogger = new(errLogger)
-	s.origHandler = globalErrorHandler.Load().(holder).eh
+	s.errLogger = &errLogger{errs: []string{}}
+	s.origHandler = globalErrorHandler.delegate
 
-	globalErrorHandler.Store(holder{eh: &delegator{l: log.New(s.errLogger, "", 0)}})
+	globalErrorHandler.delegate = s.errLogger
 }
 
 func (s *HandlerTestSuite) TearDownSuite() {
-	globalErrorHandler.Store(holder{eh: s.origHandler})
+	globalErrorHandler.delegate = s.origHandler
 	delegateErrorHandlerOnce = sync.Once{}
 }
 
 func (s *HandlerTestSuite) SetupTest() {
-	s.errLogger.Reset()
+	s.errLogger.errs = []string{}
+	SetErrorHandler(s.errLogger)
 }
 
-func (s *HandlerTestSuite) TearDownTest() {
-	globalErrorHandler.Store(holder{eh: &delegator{l: log.New(s.errLogger, "", 0)}})
-	delegateErrorHandlerOnce = sync.Once{}
+func (s *HandlerTestSuite) TearDownTest() {}
+
+type bufferedErrorHandler struct {
+	buf *strings.Builder
+}
+
+func (h *bufferedErrorHandler) Handle(err error) {
+	if h.buf != nil {
+		h.buf = &strings.Builder{}
+	}
+	h.buf.WriteString(err.Error())
 }
 
 func (s *HandlerTestSuite) TestGlobalHandler() {
 	errs := []string{"one", "two"}
 	GetErrorHandler().Handle(errors.New(errs[0]))
 	Handle(errors.New(errs[1]))
-	s.Assert().Equal(errs, s.errLogger.Got())
+	s.Assert().Equal(errs, s.errLogger.errs)
 }
 
 func (s *HandlerTestSuite) TestDelegatedHandler() {
 	eh := GetErrorHandler()
 
-	newErrLogger := new(errLogger)
-	SetErrorHandler(&logger{l: log.New(newErrLogger, "", 0)})
+	newErrLogger := &errLogger{errs: []string{}}
+	SetErrorHandler(newErrLogger)
 
 	errs := []string{"TestDelegatedHandler"}
 	eh.Handle(errors.New(errs[0]))
-	s.Assert().Equal(errs, newErrLogger.Got())
-}
-
-func (s *HandlerTestSuite) TestSettingDefaultIsANoOp() {
-	SetErrorHandler(GetErrorHandler())
-	d := globalErrorHandler.Load().(holder).eh.(*delegator)
-	s.Assert().Nil(d.delegate.Load())
+	s.Assert().Equal(errs, newErrLogger.errs)
 }
 
 func (s *HandlerTestSuite) TestNoDropsOnDelegate() {
 	causeErr("")
-	s.Require().Len(s.errLogger.Got(), 1)
+	s.Require().Len(s.errLogger.errs, 1)
 
 	// Change to another Handler. We are testing this is loss-less.
-	newErrLogger := new(errLogger)
-	secondary := &logger{
-		l: log.New(newErrLogger, "", 0),
-	}
-	SetErrorHandler(secondary)
+	newErrLogger := &errLogger{errs: []string{}}
+	SetErrorHandler(newErrLogger)
 
 	causeErr("")
-	s.Assert().Len(s.errLogger.Got(), 1, "original Handler used after delegation")
-	s.Assert().Len(newErrLogger.Got(), 1, "new Handler not used after delegation")
+	s.Assert().Len(s.errLogger.errs, 1, "original Handler used after delegation")
+	s.Assert().Len(newErrLogger.errs, 1, "new Handler not used after delegation")
 }
 
 func (s *HandlerTestSuite) TestAllowMultipleSets() {
-	notUsed := new(errLogger)
-
-	secondary := &logger{l: log.New(notUsed, "", 0)}
+	secondary := &errLogger{errs: []string{}}
 	SetErrorHandler(secondary)
-	s.Require().Same(GetErrorHandler(), secondary, "new Handler not set")
+	s.Require().Same(GetErrorHandler().(*errorHandlerDelegate).delegate, secondary, "new Handler not set")
 
-	tertiary := &logger{l: log.New(notUsed, "", 0)}
+	tertiary := &errLogger{errs: []string{}}
 	SetErrorHandler(tertiary)
-	s.Assert().Same(GetErrorHandler(), tertiary, "user Handler not overridden")
+	s.Assert().Same(GetErrorHandler().(*errorHandlerDelegate).delegate, tertiary, "user Handler not overridden")
+}
+
+func (s *HandlerTestSuite) TestGetErrorHandlerAlwaysIsCurrent() {
+	orig := GetErrorHandler()
+
+	newErrLogger := &errLogger{errs: []string{}}
+	SetErrorHandler(newErrLogger)
+
+	orig.Handle(errors.New("error"))
+
+	s.Assert().Len(newErrLogger.errs, 1, "original Handler did not update")
 }
 
 func TestHandlerTestSuite(t *testing.T) {
@@ -139,17 +129,16 @@ func TestHandlerTestSuite(t *testing.T) {
 }
 
 func BenchmarkErrorHandler(b *testing.B) {
-	primary := &delegator{l: log.New(ioutil.Discard, "", 0)}
-	secondary := &logger{l: log.New(ioutil.Discard, "", 0)}
-	tertiary := &logger{l: log.New(ioutil.Discard, "", 0)}
-
-	globalErrorHandler.Store(holder{eh: primary})
+	primary := DiscardErrorHandler{}
+	secondary := DiscardErrorHandler{}
+	tertiary := DiscardErrorHandler{}
 
 	err := errors.New("BenchmarkErrorHandler")
 
 	b.ReportAllocs()
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
+		SetErrorHandler(primary)
 		GetErrorHandler().Handle(err)
 		Handle(err)
 
@@ -161,11 +150,6 @@ func BenchmarkErrorHandler(b *testing.B) {
 		GetErrorHandler().Handle(err)
 		Handle(err)
 
-		b.StopTimer()
-		primary.delegate = atomic.Value{}
-		globalErrorHandler.Store(holder{eh: primary})
-		delegateErrorHandlerOnce = sync.Once{}
-		b.StartTimer()
 	}
 
 	b.StopTimer()
@@ -182,7 +166,7 @@ func BenchmarkGetDefaultErrorHandler(b *testing.B) {
 }
 
 func BenchmarkGetDelegatedErrorHandler(b *testing.B) {
-	SetErrorHandler(&logger{l: log.New(ioutil.Discard, "", 0)})
+	SetErrorHandler(DiscardErrorHandler{})
 
 	b.ReportAllocs()
 	b.ResetTimer()
@@ -195,9 +179,7 @@ func BenchmarkGetDelegatedErrorHandler(b *testing.B) {
 }
 
 func BenchmarkDefaultErrorHandlerHandle(b *testing.B) {
-	globalErrorHandler.Store(holder{
-		eh: &delegator{l: log.New(ioutil.Discard, "", 0)},
-	})
+	SetErrorHandler(DiscardErrorHandler{})
 
 	eh := GetErrorHandler()
 	err := errors.New("BenchmarkDefaultErrorHandlerHandle")
@@ -214,7 +196,7 @@ func BenchmarkDefaultErrorHandlerHandle(b *testing.B) {
 
 func BenchmarkDelegatedErrorHandlerHandle(b *testing.B) {
 	eh := GetErrorHandler()
-	SetErrorHandler(&logger{l: log.New(ioutil.Discard, "", 0)})
+	SetErrorHandler(DiscardErrorHandler{})
 	err := errors.New("BenchmarkDelegatedErrorHandlerHandle")
 
 	b.ReportAllocs()
@@ -228,7 +210,7 @@ func BenchmarkDelegatedErrorHandlerHandle(b *testing.B) {
 }
 
 func BenchmarkSetErrorHandlerDelegation(b *testing.B) {
-	alt := &logger{l: log.New(ioutil.Discard, "", 0)}
+	alt := DiscardErrorHandler{}
 
 	b.ReportAllocs()
 	b.ResetTimer()
@@ -243,8 +225,8 @@ func BenchmarkSetErrorHandlerDelegation(b *testing.B) {
 
 func BenchmarkSetErrorHandlerNoDelegation(b *testing.B) {
 	eh := []ErrorHandler{
-		&logger{l: log.New(ioutil.Discard, "", 0)},
-		&logger{l: log.New(ioutil.Discard, "", 0)},
+		DiscardErrorHandler{},
+		DiscardErrorHandler{},
 	}
 	mod := len(eh)
 	// Do not measure delegation.
@@ -261,6 +243,7 @@ func BenchmarkSetErrorHandlerNoDelegation(b *testing.B) {
 }
 
 func reset() {
-	globalErrorHandler = defaultErrorHandler()
-	delegateErrorHandlerOnce = sync.Once{}
+	globalErrorHandler = &errorHandlerDelegate{
+		delegate: &defaultErrorHandler{},
+	}
 }

internal/debug/debug.go

@@ -15,15 +15,27 @@
 package debug // import "go.opentelemetry.io/otel/internal/debug"
 
 import (
+	"log"
+	"os"
+
 	"github.com/go-logr/logr"
+	"github.com/go-logr/stdr"
 )
 
-var Log logr.Logger = logr.Discard()
+var globalLoggger logr.Logger = stdr.New(log.New(os.Stderr, "", log.LstdFlags|log.Lshortfile))
+
+func SetLogger(l logr.Logger) {
+	globalLoggger = l
+}
 
 func Info(msg string, keysAndValues ...interface{}) {
-	Log.Info(msg, keysAndValues...)
+	globalLoggger.V(1).Info(msg, keysAndValues...)
 }
 
 func Error(err error, msg string, keysAndValues ...interface{}) {
-	Log.Error(err, msg, keysAndValues...)
+	globalLoggger.Error(err, msg, keysAndValues...)
+}
+
+func Debug(msg string, keysAndValues ...interface{}) {
+	globalLoggger.V(5).Info(msg, keysAndValues...)
 }

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 {
-		debug.Log.V(5).Info("exporting spans", "count", len(bsp.batch))
+		debug.Info("exporting spans", "count", len(bsp.batch))
 		err := bsp.e.ExportSpans(ctx, bsp.batch)
 
 		// A new batch is always created after exporting, even if the batch failed to be exported.