Logging interface (#82)

* Replace seelog logger with internal logger.

The seelog logger had various drawbacks:
- not easily user configurable (e.g. can't disable, can't write to a
  file, can't write to stderr, can't write to json, etc)
- uses global seelog instance which can conflict w/ other packages
  or user's logger

The replacement logger uses a simple Logger interface:

type Logger interface {
	Log(level LogLevel, msg fmt.Stringer)
}

Rather than a separate method for each log level, the level is passed
as an argument. This makes it easy/possible to add more log levels in
the future. The lowest log level is now "debug" instead of seelog's
"trace" (seemed mildly confusing to have a log method named "trace" in
a cloud tracing package).

We use a fmt.Stringer so any log message serialization can be deferred
until the message is actually written.

There is a default Logger implementation the user can use via
NewDefaultLogger(io.Writer, LogLevel) to create a logger that writes
log messages of at least a certain log level to a specified io.Writer.

The logger defaults to a stdout writer of min level "info".

The "xraylog" package is the user visible logging API. It contains
"xray" in the package name so it doesn't annoyingly look like every
other "logger" package (e.g. to goimports). The user can set a new
logger using xray.SetLogger().

The actual logging instance and logging wrapper methods are in an
internal "logger" package hidden from the user. There are
Info(...interface{}) and Infof(string, ...interface{}) varieties for
each log level. In addition there is a DebugDeferred(func() string)
takes an arbitrary function (which won't get called unless the log
message is actually logged).

* Add README.md note about logger interface

* Synchronize log messages in default logger.

Use a mutex to synchronize calls to underling io.Writer. This avoids
log message interleaving and potentially worse race conditions,
depending on what the writer is.

Also tweak the invalid LogLevel String() to be UNKNOWNLOGLEVEL instead
of just UNKNOWN so it is easier to understand what is unknown if it
ever shows up.

README.md

@@ -204,6 +204,31 @@ func init() {
 }
 ```
 
+**Logger**
+
+xray uses an interface for its logger:
+
+```go
+type Logger interface {
+  Log(level LogLevel, msg fmt.Stringer)
+}
+
+const (
+  LogLevelDebug LogLevel = iota + 1
+  LogLevelInfo
+  LogLevelWarn
+  LogLevelError
+)
+```
+
+The default logger logs to stdout at "info" and above. To change the logger, call `xray.SetLogger(myLogger)`. There is a default logger implementation that writes to an `io.Writer` from a specified minimum log level. For example, to log to stderr at "error" and above:
+
+```go
+xray.SetLogger(xraylog.NewDefaultLogger(os.Stderr, xraylog.LogLevelError))
+```
+
+Note that the `xray.Config{}` fields `LogLevel` and `LogFormat` are deprecated and no longer have any effect.
+
 ## License
 
 The AWS X-Ray SDK for Go is licensed under the Apache 2.0 License. See LICENSE and NOTICE.txt for more information.

awsplugins/beanstalk/beanstalk.go

@@ -12,8 +12,8 @@ import (
 	"encoding/json"
 	"io/ioutil"
 
+	"github.com/aws/aws-xray-sdk-go/internal/logger"
 	"github.com/aws/aws-xray-sdk-go/internal/plugins"
-	log "github.com/cihub/seelog"
 )
 
 const Origin = "AWS::ElasticBeanstalk::Environment"
@@ -29,14 +29,14 @@ func addPluginMetadata(pluginmd *plugins.PluginMetadata) {
 
 	rawConfig, err := ioutil.ReadFile(ebConfigPath)
 	if err != nil {
-		log.Errorf("Unable to read Elastic Beanstalk configuration file %s: %v", ebConfigPath, err)
+		logger.Errorf("Unable to read Elastic Beanstalk configuration file %s: %v", ebConfigPath, err)
 		return
 	}
 
 	config := &plugins.BeanstalkMetadata{}
 	err = json.Unmarshal(rawConfig, config)
 	if err != nil {
-		log.Errorf("Unable to unmarshal Elastic Beanstalk configuration file %s: %v", ebConfigPath, err)
+		logger.Errorf("Unable to unmarshal Elastic Beanstalk configuration file %s: %v", ebConfigPath, err)
 		return
 	}
 

awsplugins/ec2/ec2.go

@@ -11,8 +11,8 @@ package ec2
 import (
 	"github.com/aws/aws-sdk-go/aws/ec2metadata"
 	"github.com/aws/aws-sdk-go/aws/session"
+	"github.com/aws/aws-xray-sdk-go/internal/logger"
 	"github.com/aws/aws-xray-sdk-go/internal/plugins"
-	log "github.com/cihub/seelog"
 )
 
 const Origin = "AWS::EC2::Instance"
@@ -26,13 +26,13 @@ func Init() {
 func addPluginMetadata(pluginmd *plugins.PluginMetadata) {
 	session, e := session.NewSession()
 	if e != nil {
-		log.Errorf("Unable to create a new ec2 session: %v", e)
+		logger.Errorf("Unable to create a new ec2 session: %v", e)
 		return
 	}
 	client := ec2metadata.New(session)
 	doc, err := client.GetInstanceIdentityDocument()
 	if err != nil {
-		log.Errorf("Unable to read EC2 instance metadata: %v", err)
+		logger.Errorf("Unable to read EC2 instance metadata: %v", err)
 		return
 	}
 

awsplugins/ecs/ecs.go

@@ -11,8 +11,8 @@ package ecs
 import (
 	"os"
 
+	"github.com/aws/aws-xray-sdk-go/internal/logger"
 	"github.com/aws/aws-xray-sdk-go/internal/plugins"
-	log "github.com/cihub/seelog"
 )
 
 const Origin = "AWS::ECS::Container"
@@ -27,7 +27,7 @@ func addPluginMetadata(pluginmd *plugins.PluginMetadata) {
 	hostname, err := os.Hostname()
 
 	if err != nil {
-		log.Errorf("Unable to retrieve hostname from OS. %v", err)
+		logger.Errorf("Unable to retrieve hostname from OS. %v", err)
 		return
 	}
 

daemoncfg/daemon_config.go

@@ -13,8 +13,7 @@ import (
 	"strconv"
 	"strings"
 
-	log "github.com/cihub/seelog"
-
+	"github.com/aws/aws-xray-sdk-go/internal/logger"
 	"github.com/pkg/errors"
 )
 
@@ -69,7 +68,7 @@ func GetDaemonEndpointsFromString(dAddr string) (*DaemonEndpoints, error) {
 	// Try to get the X-Ray daemon address from an environment variable
 	if envDaemonAddr := os.Getenv("AWS_XRAY_DAEMON_ADDRESS"); envDaemonAddr != "" {
 		daemonAddr = envDaemonAddr
-		log.Infof("using daemon endpoints from environment variable AWS_XRAY_DAEMON_ADDRESS: %v", envDaemonAddr)
+		logger.Infof("using daemon endpoints from environment variable AWS_XRAY_DAEMON_ADDRESS: %v", envDaemonAddr)
 	} else if dAddr != "" {
 		daemonAddr = dAddr
 	}
@@ -85,12 +84,9 @@ func resolveAddress(dAddr string) (*DaemonEndpoints, error) {
 		return parseSingleForm(addr[0])
 	} else if len(addr) == 2 {
 		return parseDoubleForm(addr)
-
 	} else {
 		return nil, errors.New("invalid daemon address: " + dAddr)
 	}
-
-	return nil, nil
 }
 
 func parseDoubleForm(addr []string) (*DaemonEndpoints, error) {

internal/logger/logger.go

@@ -0,0 +1,78 @@
+// Copyright 2017-2017 Amazon.com, Inc. or its affiliates. All Rights Reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License"). You may not use this file except in compliance with the License. A copy of the License is located at
+//
+//     http://aws.amazon.com/apache2.0/
+//
+// or in the "license" file accompanying this file. This file is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions and limitations under the License.
+
+package logger
+
+import (
+	"fmt"
+	"os"
+
+	"github.com/aws/aws-xray-sdk-go/xraylog"
+)
+
+// This internal pacakge hides the actual logging functions from the user.
+
+// The Logger instance used by xray to log. Set via xray.SetLogger().
+var Logger xraylog.Logger = xraylog.NewDefaultLogger(os.Stdout, xraylog.LogLevelInfo)
+
+func Debugf(format string, args ...interface{}) {
+	Logger.Log(xraylog.LogLevelDebug, printfArgs{format, args})
+}
+
+func Debug(args ...interface{}) {
+	Logger.Log(xraylog.LogLevelDebug, printArgs(args))
+}
+
+func DebugDeferred(fn func() string) {
+	Logger.Log(xraylog.LogLevelDebug, stringerFunc(fn))
+}
+
+func Infof(format string, args ...interface{}) {
+	Logger.Log(xraylog.LogLevelInfo, printfArgs{format, args})
+}
+
+func Info(args ...interface{}) {
+	Logger.Log(xraylog.LogLevelInfo, printArgs(args))
+}
+
+func Warnf(format string, args ...interface{}) {
+	Logger.Log(xraylog.LogLevelWarn, printfArgs{format, args})
+}
+
+func Warn(args ...interface{}) {
+	Logger.Log(xraylog.LogLevelWarn, printArgs(args))
+}
+
+func Errorf(format string, args ...interface{}) {
+	Logger.Log(xraylog.LogLevelError, printfArgs{format, args})
+}
+
+func Error(args ...interface{}) {
+	Logger.Log(xraylog.LogLevelError, printArgs(args))
+}
+
+type printfArgs struct {
+	format string
+	args   []interface{}
+}
+
+func (p printfArgs) String() string {
+	return fmt.Sprintf(p.format, p.args...)
+}
+
+type printArgs []interface{}
+
+func (p printArgs) String() string {
+	return fmt.Sprint([]interface{}(p)...)
+}
+
+type stringerFunc func() string
+
+func (sf stringerFunc) String() string {
+	return sf()
+}

internal/logger/logger_test.go

@@ -0,0 +1,83 @@
+// Copyright 2017-2017 Amazon.com, Inc. or its affiliates. All Rights Reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License"). You may not use this file except in compliance with the License. A copy of the License is located at
+//
+//     http://aws.amazon.com/apache2.0/
+//
+// or in the "license" file accompanying this file. This file is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions and limitations under the License.
+
+package logger
+
+import (
+	"bytes"
+	"strings"
+	"testing"
+
+	"github.com/aws/aws-xray-sdk-go/xraylog"
+)
+
+func TestLogger(t *testing.T) {
+	oldLogger := Logger
+	defer func() { Logger = oldLogger }()
+
+	var buf bytes.Buffer
+
+	// filter properly by level
+	Logger = xraylog.NewDefaultLogger(&buf, xraylog.LogLevelWarn)
+
+	Debug("debug")
+	Info("info")
+	Warn("warn")
+	Error("error")
+
+	gotLines := strings.Split(strings.TrimSpace(buf.String()), "\n")
+	if len(gotLines) != 2 {
+		t.Fatalf("got %d lines", len(gotLines))
+	}
+
+	if !strings.Contains(gotLines[0], "[WARN] warn") {
+		t.Error("expected first line to be warn")
+	}
+
+	if !strings.Contains(gotLines[1], "[ERROR] error") {
+		t.Error("expected second line to be warn")
+	}
+}
+
+func TestDeferredDebug(t *testing.T) {
+	oldLogger := Logger
+	defer func() { Logger = oldLogger }()
+
+	var buf bytes.Buffer
+
+	Logger = xraylog.NewDefaultLogger(&buf, xraylog.LogLevelInfo)
+
+	var called bool
+	DebugDeferred(func() string {
+		called = true
+		return "deferred"
+	})
+
+	if called {
+		t.Error("deferred should not have been called")
+	}
+
+	if buf.String() != "" {
+		t.Errorf("unexpected log contents: %s", buf.String())
+	}
+
+	Logger = xraylog.NewDefaultLogger(&buf, xraylog.LogLevelDebug)
+
+	DebugDeferred(func() string {
+		called = true
+		return "deferred"
+	})
+
+	if !called {
+		t.Error("deferred should have been called")
+	}
+
+	if !strings.Contains(buf.String(), "[DEBUG] deferred") {
+		t.Errorf("expected deferred message, got %s", buf.String())
+	}
+}

strategy/ctxmissing/ctxmissing_test.go

@@ -9,30 +9,14 @@
 package ctxmissing
 
 import (
-	log "github.com/cihub/seelog"
-	"github.com/stretchr/testify/assert"
+	"bytes"
 	"strings"
 	"testing"
-)
-
-type LogWriter struct {
-	Logs []string
-}
-
-func (sw *LogWriter) Write(p []byte) (n int, err error) {
-	sw.Logs = append(sw.Logs, string(p))
-	return len(p), nil
-}
 
-func LogSetup() *LogWriter {
-	writer := &LogWriter{}
-	logger, err := log.LoggerFromWriterWithMinLevelAndFormat(writer, log.TraceLvl, "%Ns [%Level] %Msg")
-	if err != nil {
-		panic(err)
-	}
-	log.ReplaceLogger(logger)
-	return writer
-}
+	"github.com/aws/aws-xray-sdk-go/internal/logger"
+	"github.com/aws/aws-xray-sdk-go/xraylog"
+	"github.com/stretchr/testify/assert"
+)
 
 func TestDefaultRuntimeErrorStrategy(t *testing.T) {
 	defer func() {
@@ -45,8 +29,13 @@ func TestDefaultRuntimeErrorStrategy(t *testing.T) {
 }
 
 func TestDefaultLogErrorStrategy(t *testing.T) {
-	logger := LogSetup()
+	oldLogger := logger.Logger
+	defer func() { logger.Logger = oldLogger }()
+
+	var buf bytes.Buffer
+	logger.Logger = xraylog.NewDefaultLogger(&buf, xraylog.LogLevelDebug)
+
 	l := NewDefaultLogErrorStrategy()
 	l.ContextMissing("TestLogError")
-	assert.True(t, strings.Contains(logger.Logs[0], "Suppressing AWS X-Ray context missing panic: TestLogError"))
+	assert.True(t, strings.Contains(buf.String(), "Suppressing AWS X-Ray context missing panic: TestLogError"))
 }

strategy/ctxmissing/default_context_missing.go

@@ -8,9 +8,7 @@
 
 package ctxmissing
 
-import (
-	log "github.com/cihub/seelog"
-)
+import "github.com/aws/aws-xray-sdk-go/internal/logger"
 
 // RuntimeErrorStrategy provides the AWS_XRAY_CONTEXT_MISSING
 // environment variable value for enabling the runtime error
@@ -50,5 +48,5 @@ func (dr *DefaultRuntimeErrorStrategy) ContextMissing(v interface{}) {
 // ContextMissing logs an error message when the
 // segment context is missing.
 func (dl *DefaultLogErrorStrategy) ContextMissing(v interface{}) {
-	log.Errorf("Suppressing AWS X-Ray context missing panic: %v", v)
+	logger.Errorf("Suppressing AWS X-Ray context missing panic: %v", v)
 }