Repository: newrelic/newrelic-client-go
Pull request #586 (2020-12-30 18:55:57)

chore(logging): move StructuredLogger to a private logger


Patch:
diff --git a/internal/http/client.go b/internal/http/client.go
index 7acefd8..81e8d89 100644
--- a/internal/http/client.go
+++ b/internal/http/client.go
@@ -14,6 +14,7 @@ import (
 
 	retryablehttp "github.com/hashicorp/go-retryablehttp"
 
+	"github.com/newrelic/newrelic-client-go/internal/logging"
 	"github.com/newrelic/newrelic-client-go/internal/version"
 	"github.com/newrelic/newrelic-client-go/pkg/config"
 	nrErrors "github.com/newrelic/newrelic-client-go/pkg/errors"
@@ -45,6 +46,8 @@ type Client struct {
 	compressor RequestCompressor
 
 	errorValue ErrorResponse
+
+	logger logging.Logger
 }
 
 // NewClient is used to create a new instance of Client.
@@ -84,11 +87,20 @@ func NewClient(cfg config.Config) Client {
 	// Disable logging in go-retryablehttp since we are logging requests directly here
 	r.Logger = nil
 
+	// Use the logger from the configuration or use a default NewStructuredLogger.
+	var logger logging.Logger
+	if cfg.Logger != nil {
+		logger = cfg.Logger
+	} else {
+		logger = logging.NewStructuredLogger()
+	}
+
 	client := Client{
 		authStrategy: &ClassicV2Authorizer{},
 		client:       r,
 		config:       cfg,
 		errorValue:   &DefaultErrorResponse{},
+		logger:       logger,
 	}
 
 	switch cfg.Compression {
@@ -320,8 +332,7 @@ func (c *Client) Do(req *Request) (*http.Response, error) {
 	var errorValue ErrorResponse
 	var body []byte
 
-	logger := c.config.GetLogger()
-	logger.Debug("performing request", "method", req.method, "url", req.url)
+	c.logger.Debug("performing request", "method", req.method, "url", req.url)
 
 	for i := 0; ; i++ {
 		var shouldRetry bool
@@ -378,8 +389,6 @@ func (c *Client) innerDo(req *Request, errorValue ErrorResponse, i int) (*http.R
 		return nil, nil, false, err
 	}
 
-	logger := c.config.GetLogger()
-
 	logHeaders, err := logCleanHeaderMarshalJSON(r.Header)
 	if err != nil {
 		return nil, nil, false, err
@@ -395,20 +404,20 @@ func (c *Client) innerDo(req *Request, errorValue ErrorResponse, i int) (*http.R
 				return nil, nil, false, marshalErr
 			}
 
-			logger.Trace("request details",
+			c.logger.Trace("request details",
 				"headers", logNice(string(logHeaders)),
 				"query", logNice(x.Query),
 				"variables", string(logVariables),
 			)
 		case "string":
-			logger.Trace("request details", "headers", string(logHeaders), "body", logNice(req.reqBody.(string)))
+			c.logger.Trace("request details", "headers", string(logHeaders), "body", logNice(req.reqBody.(string)))
 		}
 	} else {
-		logger.Trace("request details", "headers", string(logHeaders))
+		c.logger.Trace("request details", "headers", string(logHeaders))
 	}
 
 	if i > 0 {
-		logger.Debug(fmt.Sprintf("retrying request (attempt %d)", i), "method", req.method, "url", r.URL)
+		c.logger.Debug(fmt.Sprintf("retrying request (attempt %d)", i), "method", req.method, "url", r.URL)
 	}
 
 	resp, retryErr := c.client.Do(r)
@@ -433,7 +442,7 @@ func (c *Client) innerDo(req *Request, errorValue ErrorResponse, i int) (*http.R
 		return resp, body, false, err
 	}
 
-	logger.Trace("request completed", "method", req.method, "url", r.URL, "status_code", resp.StatusCode, "headers", string(logHeaders), "body", string(body))
+	c.logger.Trace("request completed", "method", req.method, "url", r.URL, "status_code", resp.StatusCode, "headers", string(logHeaders), "body", string(body))
 
 	_ = json.Unmarshal(body, &errorValue)
 
@@ -447,7 +456,7 @@ func (c *Client) innerDo(req *Request, errorValue ErrorResponse, i int) (*http.R
 
 	remain := c.client.RetryMax - i
 	if remain <= 0 {
-		logger.Debug(fmt.Sprintf("giving up after %d attempts", c.client.RetryMax), "method", req.method, "url", r.URL)
+		c.logger.Debug(fmt.Sprintf("giving up after %d attempts", c.client.RetryMax), "method", req.method, "url", r.URL)
 		return resp, body, false, nil
 	}
 
diff --git a/internal/logging/logger.go b/internal/logging/logger.go
index 88bbc2c..7aa311c 100644
--- a/internal/logging/logger.go
+++ b/internal/logging/logger.go
@@ -7,4 +7,5 @@ type Logger interface {
 	Info(string, ...interface{})
 	Debug(string, ...interface{})
 	Trace(string, ...interface{})
+	SetLevel(string)
 }
diff --git a/internal/logging/mock_logger.go b/internal/logging/mock_logger.go
new file mode 100644
index 0000000..83ffa80
--- /dev/null
+++ b/internal/logging/mock_logger.go
@@ -0,0 +1,37 @@
+package logging
+
+import "testing"
+
+type MockLogger struct {
+	t *testing.T
+}
+
+func NewMockLogger(t *testing.T) *MockLogger {
+	return &MockLogger{t: t}
+}
+
+// Error logs an error message.
+func (l MockLogger) Error(msg string, fields ...interface{}) {
+	l.t.Errorf(msg, fields...)
+}
+
+// Warn logs an warning message.
+func (l MockLogger) Warn(msg string, fields ...interface{}) {
+	l.t.Logf(msg, fields...)
+}
+
+// Info logs an info message.
+func (l MockLogger) Info(msg string, fields ...interface{}) {
+	l.t.Logf(msg, fields...)
+}
+
+// Debug logs a debug message.
+func (l MockLogger) Debug(msg string, fields ...interface{}) {
+}
+
+// Trace logs a trace message.
+func (l MockLogger) Trace(msg string, fields ...interface{}) {
+}
+
+func (l MockLogger) SetLevel(logLevel string) {
+}
diff --git a/internal/logging/structured_logger.go b/internal/logging/structured_logger.go
index dc2e632..1395f5c 100644
--- a/internal/logging/structured_logger.go
+++ b/internal/logging/structured_logger.go
@@ -12,69 +12,67 @@ var (
 )
 
 // StructuredLogger is a logger based on logrus.
-type StructuredLogger struct{}
+type StructuredLogger struct {
+	logger *log.Logger
+}
 
 // NewStructuredLogger creates a new structured logger.
-func NewStructuredLogger() StructuredLogger {
-	return StructuredLogger{}
+func NewStructuredLogger() *StructuredLogger {
+	return &StructuredLogger{
+		logger: log.New(),
+	}
 }
 
-// SetLogLevel allows the log level to be set.
-func (l StructuredLogger) SetLogLevel(logLevel string) StructuredLogger {
-	if logLevel == "" {
-		logLevel = defaultLogLevel
+// SetLevel allows the log level to be set.
+func (l StructuredLogger) SetLevel(levelName string) {
+	if levelName == "" {
+		levelName = defaultLogLevel
 	}
 
-	level, err := log.ParseLevel(logLevel)
+	level, err := log.ParseLevel(levelName)
 	if err != nil {
-		log.Warn(fmt.Sprintf("could not parse log level '%s', logging will proceed at %s level", logLevel, defaultLogLevel))
+		l.logger.Warn(fmt.Sprintf("could not parse log level '%s', logging will proceed at %s level", levelName, defaultLogLevel))
 		level, _ = log.ParseLevel(defaultLogLevel)
 	}
 
-	log.SetLevel(level)
-
-	return l
+	l.logger.SetLevel(level)
 }
 
 // LogJSON determines whether or not to format the logs as JSON.
-func (l StructuredLogger) LogJSON(value bool) StructuredLogger {
+func (l StructuredLogger) SetLogJSON(value bool) {
 	if value {
-		log.SetFormatter(&log.JSONFormatter{})
+		l.logger.SetFormatter(&log.JSONFormatter{})
 	}
-
-	return l
 }
 
 // SetDefaultFields sets fields to be logged on every use of the logger.
-func (l StructuredLogger) SetDefaultFields(defaultFields map[string]string) StructuredLogger {
-	log.AddHook(&defaultFieldHook{})
-
-	return l
+func (l StructuredLogger) SetDefaultFields(defaultFields map[string]string) {
+	l.logger.AddHook(&defaultFieldHook{})
 }
 
 // Error logs an error message.
 func (l StructuredLogger) Error(msg string, fields ...interface{}) {
-	log.WithFields(createFieldMap(fields)).Error(msg)
+	l.logger.WithFields(createFieldMap(fields)).Error(msg)
 }
 
 // Warn logs an warning message.
 func (l StructuredLogger) Warn(msg string, fields ...interface{}) {
-	log.WithFields(createFieldMap(fields)).Warn(msg)
+	l.logger.WithFields(createFieldMap(fields)).Warn(msg)
 }
 
 // Info logs an info message.
 func (l StructuredLogger) Info(msg string, fields ...interface{}) {
-	log.WithFields(createFieldMap(fields)).Info(msg)
+	l.logger.WithFields(createFieldMap(fields)).Info(msg)
 }
 
 // Debug logs a debug message.
 func (l StructuredLogger) Debug(msg string, fields ...interface{}) {
-	log.WithFields(createFieldMap(fields)).Debug(msg)
+	l.logger.WithFields(createFieldMap(fields)).Debug(msg)
 }
 
 // Trace logs a trace message.
 func (l StructuredLogger) Trace(msg string, fields ...interface{}) {
-	log.WithFields(createFieldMap(fields)).Trace(msg)
+	l.logger.WithFields(createFieldMap(fields)).Trace(msg)
 }
 
 func createFieldMap(fields ...interface{}) map[string]interface{} {
diff --git a/newrelic/newrelic.go b/newrelic/newrelic.go
index 422b135..96f085b 100644
--- a/newrelic/newrelic.go
+++ b/newrelic/newrelic.go
@@ -54,46 +54,54 @@ type NewRelic struct {
 
 // New returns a collection of New Relic APIs.
 func New(opts ...ConfigOption) (*NewRelic, error) {
-	config := config.New()
+	cfg := config.New()
 
 	// Loop through config options
 	for _, fn := range opts {
 		if nil != fn {
-			if err := fn(&config); err != nil {
+			if err := fn(&cfg); err != nil {
 				return nil, err
 			}
 		}
 	}
 
-	if config.PersonalAPIKey == "" && config.AdminAPIKey == "" && config.InsightsInsertKey == "" {
+	if cfg.PersonalAPIKey == "" && cfg.AdminAPIKey == "" && cfg.InsightsInsertKey == "" {
 		return nil, errors.New("must use at least one of: ConfigPersonalAPIKey, ConfigAdminAPIKey, ConfigInsightsInsertKey")
 	}
 
+	if cfg.Logger == nil {
+		cfg.Logger = cfg.GetLogger()
+	}
+
 	nr := &NewRelic{
-		config: config,
-
-		Accounts:        accounts.New(config),
-		Alerts:          alerts.New(config),
-		APIAccess:       apiaccess.New(config),
-		APM:             apm.New(config),
-		Cloud:           cloud.New(config),
-		Dashboards:      dashboards.New(config),
-		Edge:            edge.New(config),
-		Entities:        entities.New(config),
-		Events:          events.New(config),
-		EventsToMetrics: eventstometrics.New(config),
-		Logs:            logs.New(config),
-		NerdGraph:       nerdgraph.New(config),
-		NerdStorage:     nerdstorage.New(config),
-		Nrdb:            nrdb.New(config),
-		Plugins:         plugins.New(config),
-		Synthetics:      synthetics.New(config),
-		Workloads:       workloads.New(config),
+		config: cfg,
+
+		Accounts:        accounts.New(cfg),
+		Alerts:          alerts.New(cfg),
+		APIAccess:       apiaccess.New(cfg),
+		APM:             apm.New(cfg),
+		Cloud:           cloud.New(cfg),
+		Dashboards:      dashboards.New(cfg),
+		Edge:            edge.New(cfg),
+		Entities:        entities.New(cfg),
+		Events:          events.New(cfg),
+		EventsToMetrics: eventstometrics.New(cfg),
+		Logs:            logs.New(cfg),
+		NerdGraph:       nerdgraph.New(cfg),
+		NerdStorage:     nerdstorage.New(cfg),
+		Nrdb:            nrdb.New(cfg),
+		Plugins:         plugins.New(cfg),
+		Synthetics:      synthetics.New(cfg),
+		Workloads:       workloads.New(cfg),
 	}
 
 	return nr, nil
 }
 
+func (nr *NewRelic) SetLogLevel(levelName string) {
+	nr.config.Logger.SetLevel(levelName)
+}
+
 // ConfigOption configures the Config when provided to NewApplication.
 // https://docs.newrelic.com/docs/apis/get-started/intro-apis/types-new-relic-api-keys
 type ConfigOption func(*config.Config) error
diff --git a/pkg/config/config.go b/pkg/config/config.go
index 5f07270..a6dc28c 100644
--- a/pkg/config/config.go
+++ b/pkg/config/config.go
@@ -96,11 +96,12 @@ func (c *Config) GetLogger() logging.Logger {
 		return c.Logger
 	}
 
-	l := logging.NewStructuredLogger().
-		SetDefaultFields(map[string]string{"newrelic-client-go": version.Version}).
-		LogJSON(c.LogJSON).
-		SetLogLevel(c.LogLevel)
+	l := logging.NewStructuredLogger()
+	l.SetDefaultFields(map[string]string{"newrelic-client-go": version.Version})
+	l.SetLogJSON(c.LogJSON)
+	l.SetLevel(c.LogLevel)
+
+	// c.Logger = l
 
-	c.Logger = l
 	return l
 }
diff --git a/pkg/events/events_batch.go b/pkg/events/events_batch.go
index b083f42..f357565 100644
--- a/pkg/events/events_batch.go
+++ b/pkg/events/events_batch.go
@@ -5,8 +5,6 @@ import (
 	"context"
 	"errors"
 	"time"
-
-	log "github.com/sirupsen/logrus"
 )
 
 // BatchMode enables the Events client to accept, queue, and post
@@ -34,7 +32,7 @@ func (e *Events) BatchMode(ctx context.Context, accountID int, opts ...BatchConf
 	go func() {
 		err := e.watchdog(ctx)
 		if err != nil {
-			log.Errorf("watchdog returned error: %v", err)
+			e.logger.Error("watchdog returned error", "error", err)
 		}
 	}()
 
@@ -45,7 +43,7 @@ func (e *Events) BatchMode(ctx context.Context, accountID int, opts ...BatchConf
 		go func(id int) {
 			err := e.batchWorker(ctx, id)
 			if err != nil {
-				log.Errorf("batch worker returned error: %v", err)
+				e.logger.Error("batch worker returned error", "error", err)
 			}
 		}(x)
 	}
diff --git a/pkg/logs/logs_batch.go b/pkg/logs/logs_batch.go
index f72fe68..a7d9c4f 100644
--- a/pkg/logs/logs_batch.go
+++ b/pkg/logs/logs_batch.go
@@ -5,8 +5,6 @@ import (
 	"errors"
 	"fmt"
 	"time"
-
-	log "github.com/sirupsen/logrus"
 )
 
 // BatchMode enables the Logs client to accept, queue, and post
@@ -34,7 +32,7 @@ func (e *Logs) BatchMode(ctx context.Context, accountID int, opts ...BatchConfig
 	go func() {
 		err := e.watchdog(ctx)
 		if err != nil {
-			log.Errorf("watchdog returned error: %v", err)
+			e.logger.Error(fmt.Sprintf("watchdog returned error: %v", err))
 		}
 	}()
 
@@ -43,10 +41,10 @@ func (e *Logs) BatchMode(ctx context.Context, accountID int, opts ...BatchConfig
 		e.flushQueue[x] = make(chan bool, 1)
 
 		go func(id int) {
-			log.Tracef("inside anonymous function")
+			e.logger.Trace("inside anonymous function")
 			err := e.batchWorker(ctx, id)
 			if err != nil {
-				log.Errorf("batch worker returned error: %v", err)
+				e.logger.Error(fmt.Sprintf("batch worker returned error: %v", err))
 			}
 		}(x)
 	}
@@ -101,13 +99,13 @@ func BatchConfigTimeout(seconds int) BatchConfigOption {
 // EnqueueLogEntry handles the queueing. Only works in batch mode. If you wish to be able to avoid blocking
 // forever until the log can be queued, provide a ctx with a deadline or timeout as this function will
 // bail when ctx.Done() is closed and return and error.
-func (e *Logs) EnqueueLogEntry(ctx context.Context, log interface{}) (err error) {
+func (e *Logs) EnqueueLogEntry(ctx context.Context, msg interface{}) (err error) {
 	if e.logQueue == nil {
 		return errors.New("queueing not enabled for this client")
 	}
 
 	select {
-	case e.logQueue <- log:
+	case e.logQueue <- msg:
 		e.logger.Trace("EnqueueLogEntry: log entry queued ")
 		return nil
 	case <-ctx.Done():


Test patch:
diff --git a/internal/http/client_test.go b/internal/http/client_test.go
index 8d1c0fc..242c6c2 100644
--- a/internal/http/client_test.go
+++ b/internal/http/client_test.go
@@ -10,7 +10,9 @@ import (
 	"time"
 
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 
+	"github.com/newrelic/newrelic-client-go/internal/logging"
 	"github.com/newrelic/newrelic-client-go/pkg/config"
 	"github.com/newrelic/newrelic-client-go/pkg/errors"
 	mock "github.com/newrelic/newrelic-client-go/pkg/testhelpers"
@@ -27,6 +29,7 @@ func TestConfig(t *testing.T) {
 	testTransport := http.DefaultTransport
 
 	tc := config.New()
+
 	tc.HTTPTransport = testTransport
 	tc.Region().SetRestBaseURL(testRestURL)
 	tc.ServiceName = testServiceName
@@ -35,12 +38,13 @@ func TestConfig(t *testing.T) {
 
 	c := NewClient(tc)
 
-	assert.Equal(t, &testTimeout, c.config.Timeout)
-	assert.Equal(t, testRestURL, c.config.Region().RestURL())
-	assert.Equal(t, mock.UserAgent, c.config.UserAgent)
-	assert.Equal(t, c.config.ServiceName, testServiceName+"|newrelic-client-go")
+	require.NotNil(t, c.logger)
+	require.Equal(t, &testTimeout, c.config.Timeout)
+	require.Equal(t, testRestURL, c.config.Region().RestURL())
+	require.Equal(t, mock.UserAgent, c.config.UserAgent)
+	require.Equal(t, c.config.ServiceName, testServiceName+"|newrelic-client-go")
 
-	assert.Same(t, testTransport, c.config.HTTPTransport)
+	require.Same(t, testTransport, c.config.HTTPTransport)
 }
 
 func TestConfigDefaults(t *testing.T) {
@@ -54,6 +58,17 @@ func TestConfigDefaults(t *testing.T) {
 	assert.Equal(t, c.config.ServiceName, testServiceName+"|newrelic-client-go")
 }
 
+func TestConfigLogger(t *testing.T) {
+	t.Parallel()
+	tc := mock.NewTestConfig(t, nil)
+
+	tc.Logger = logging.NewMockLogger(t)
+
+	c := NewClient(tc)
+	// The logger used should be the same as the config
+	require.Same(t, tc.Logger, c.logger)
+}
+
 func TestDefaultErrorValue(t *testing.T) {
 	t.Parallel()
 	c := NewTestAPIClient(t, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
diff --git a/internal/logging/mock_logger_test.go b/internal/logging/mock_logger_test.go
new file mode 100644
index 0000000..d0cc289
--- /dev/null
+++ b/internal/logging/mock_logger_test.go
@@ -0,0 +1,8 @@
+package logging
+
+import "testing"
+
+func TestMockLogger(t *testing.T) {
+	var l Logger = MockLogger{t: t}
+	l.Info("testing")
+}
diff --git a/internal/logging/structured_logger_test.go b/internal/logging/structured_logger_test.go
new file mode 100644
index 0000000..4534aa4
--- /dev/null
+++ b/internal/logging/structured_logger_test.go
@@ -0,0 +1,49 @@
+// +build unit
+
+package logging
+
+import (
+	"testing"
+
+	log "github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+)
+
+func TestNewStructuredLogger_private(t *testing.T) {
+	t.Parallel()
+
+	logrusLevel := log.GetLevel()
+
+	l := NewStructuredLogger()
+
+	l.SetLevel("debug")
+
+	// Make sure that the global logrus level is left unchanged.
+	assert.Equal(t, log.GetLevel(), logrusLevel)
+
+	loggerLevel := l.logger.GetLevel()
+	assert.Equal(t, loggerLevel, log.DebugLevel)
+}
+
+func TestSetLevel(t *testing.T) {
+	t.Parallel()
+	l := NewStructuredLogger()
+
+	defaultLevel, err := log.ParseLevel(defaultLogLevel)
+
+	l.SetLevel("")
+	loggerLevel := l.logger.GetLevel()
+
+	assert.NoError(t, err)
+	assert.Equal(t, loggerLevel, defaultLevel)
+
+	l.SetLevel("notdebug")
+	loggerLevel = l.logger.GetLevel()
+	assert.Equal(t, loggerLevel, defaultLevel)
+
+}
+
+func TestStructuredLogger_interface(t *testing.T) {
+	var l Logger = NewStructuredLogger()
+	l.Info("testing")
+}
diff --git a/newrelic/newrelic_test.go b/newrelic/newrelic_test.go
index 34b1bae..ebce99f 100644
--- a/newrelic/newrelic_test.go
+++ b/newrelic/newrelic_test.go
@@ -9,7 +9,9 @@ import (
 	"time"
 
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 
+	"github.com/newrelic/newrelic-client-go/internal/logging"
 	"github.com/newrelic/newrelic-client-go/pkg/config"
 )
 
@@ -54,6 +56,18 @@ func TestNew_keys(t *testing.T) {
 	assert.NotNil(t, nrE)
 }
 
+func TestNew_configOptionLogger(t *testing.T) {
+	t.Parallel()
+
+	mockLogger := logging.NewMockLogger(t)
+
+	nr, err := New(ConfigPersonalAPIKey(testAPIkey), ConfigLogger(mockLogger))
+	require.NotNil(t, nr)
+	require.NoError(t, err)
+	require.NotNil(t, nr.config.Logger)
+	require.Same(t, nr.config.Logger, mockLogger)
+}
+
 func TestNew_configOptionError(t *testing.T) {
 	t.Parallel()
 
@@ -185,6 +199,7 @@ func TestNew_optionSyntheticsBaseURL(t *testing.T) {
 	assert.NotNil(t, nr)
 	assert.NoError(t, err)
 }
+
 func TestNew_optionNerdGraphBaseURL(t *testing.T) {
 	t.Parallel()
 
@@ -227,18 +242,19 @@ func (t *TestLogger) Warn(s string, a ...interface{})  {}
 func (t *TestLogger) Info(s string, a ...interface{})  {}
 func (t *TestLogger) Debug(s string, a ...interface{}) {}
 func (t *TestLogger) Trace(s string, a ...interface{}) {}
+func (t *TestLogger) SetLevel(s string)                {}
 
 func TestNew_optionLogger(t *testing.T) {
 	t.Parallel()
 
 	nr, err := New(ConfigPersonalAPIKey(testAPIkey), ConfigLogger(nil))
-	assert.Nil(t, nr)
-	assert.Error(t, errors.New("logger can not be nil"), err)
-
-	testLogger := TestLogger{}
+	require.Nil(t, nr)
+	require.Error(t, errors.New("logger can not be nil"), err)
 
-	nr, err = New(ConfigPersonalAPIKey(testAPIkey), ConfigLogger(&testLogger))
+	var testLogger logging.Logger = &TestLogger{}
 
-	assert.NotNil(t, nr)
-	assert.NoError(t, err)
+	nr, err = New(ConfigPersonalAPIKey(testAPIkey), ConfigLogger(testLogger))
+	require.NotNil(t, nr)
+	require.NoError(t, err)
+	require.Same(t, nr.config.Logger, testLogger)
 }