Introduce default internal logger

Tracer is now initialized with an internal logger
implementation if ELASTIC_APM_LOG_FILE is specified.
Without setting this environment variable, logging
is disabled as before.

Setting ELASTIC_APM_LOG_FILE to stdout or stderr will
cause logging to write to stdout/stderr respectively.
Otherwise, specifying a file path will cause that file
to be created/truncated and written to.

By default, only errors will be logged. Setting
ELASTIC_APM_LOG_LEVEL to "debug" will cause debug
messages to be printed in addition.

CHANGELOG.md

@@ -32,6 +32,7 @@
  - End HTTP client spans on response body closure (#289)
  - module/apmgrpc requires Go 1.9+ (#300)
  - Invalid tag key characters are replaced with underscores (#308)
+ - `ELASTIC_APM_LOG_FILE` and `ELASTIC_APM_LOG_LEVEL` introduced (#313)
 
 ## [v0.5.2](https://github.com/elastic/apm-agent-go/releases/tag/v0.5.2)
 

docs/configuration.asciidoc

@@ -330,19 +330,36 @@ HTTPS connection to the APM server. Verification can be disabled by
 changing this setting to `false`.
 
 [float]
-[[config-debug]]
-=== `ELASTIC_APM_DEBUG`
+[[config-log-file]]
+=== `ELASTIC_APM_LOG_FILE`
 
 [options="header"]
 |============
-| Environment         | Default
-| `ELASTIC_APM_DEBUG` |
+| Environment            | Default
+| `ELASTIC_APM_LOG_FILE` |
 |============
 
-`ELASTIC_APM_DEBUG` can be used to debug issues with the Elastic APM Go agent
-or your instrumentation. The value should be a comma-separated list of key=value
-debug directives. Currently we support just one: `log=1`.
+`ELASTIC_APM_LOG_FILE` specifies the output file for the agent's default, internal
+logger. The file will be created, or truncated if it exists, when the process starts.
+By default, logging is disabled. You must specify `ELASTIC_APM_LOG_FILE` to enable
+it. This environment variable will be ignored if a logger is configured programatically.
 
-By setting `ELASTIC_APM_DEBUG="log=1"`, the Go agent will log messages to the
-terminal, as well as to the tracer's programatically configured logger, if any.
+There are two special file names that the agent recognizes: `stdout` and `stderr`.
+These will configure the logger to write to standard output and standard error
+respectively.
 
+[float]
+[[config-log-level]]
+=== `ELASTIC_APM_LOG_LEVEL`
+
+[options="header"]
+|============
+| Environment             | Default
+| `ELASTIC_APM_LOG_LEVEL` | `"error"`
+|============
+
+`ELASTIC_APM_LOG_LEVEL` specifies the log level for the agent's default, internal
+logger. The only two levels used by the logger are "error" and "debug". By default,
+logging is disabled. You must specify `ELASTIC_APM_LOG_FILE` to enable it.
+
+This environment variable will be ignored if a logger is configured programatically.

internal/apmlog/logger.go

@@ -0,0 +1,85 @@
+package apmlog
+
+import (
+	"io"
+	"log"
+	"os"
+	"strings"
+	"sync"
+
+	"github.com/rs/zerolog"
+)
+
+var (
+	// DefaultLogger is the default Logger to use, if ELASTIC_APM_LOG_* are specified.
+	DefaultLogger Logger
+)
+
+func init() {
+	fileStr := strings.TrimSpace(os.Getenv("ELASTIC_APM_LOG_FILE"))
+	if fileStr == "" {
+		return
+	}
+
+	var logWriter io.Writer
+	switch strings.ToLower(fileStr) {
+	case "stdout":
+		logWriter = os.Stdout
+	case "stderr":
+		logWriter = os.Stderr
+	default:
+		f, err := os.Create(fileStr)
+		if err != nil {
+			log.Printf("failed to create %q: %s (disabling logging)", fileStr, err)
+			return
+		}
+		logWriter = &syncFile{File: f}
+	}
+
+	const defaultLevel = zerolog.ErrorLevel
+	logger := zerolog.New(logWriter)
+	if levelStr := strings.TrimSpace(os.Getenv("ELASTIC_APM_LOG_LEVEL")); levelStr != "" {
+		level, err := zerolog.ParseLevel(strings.ToLower(levelStr))
+		if err != nil {
+			log.Printf("invalid ELASTIC_APM_LOG_LEVEL %q, falling back to %q", levelStr, defaultLevel)
+			level = defaultLevel
+		}
+		logger = logger.Level(level)
+	} else {
+		logger = logger.Level(defaultLevel)
+	}
+	DefaultLogger = zerologLogger{l: logger}
+}
+
+// Logger provides methods for logging.
+type Logger interface {
+	Debugf(format string, args ...interface{})
+	Errorf(format string, args ...interface{})
+}
+
+type zerologLogger struct {
+	l zerolog.Logger
+}
+
+// Debugf logs a message with log.Printf, with a DEBUG prefix.
+func (l zerologLogger) Debugf(format string, args ...interface{}) {
+	l.l.Debug().Timestamp().Msgf(format, args...)
+}
+
+// Errorf logs a message with log.Printf, with an ERROR prefix.
+func (l zerologLogger) Errorf(format string, args ...interface{}) {
+	l.l.Error().Timestamp().Msgf(format, args...)
+}
+
+type syncFile struct {
+	mu sync.Mutex
+	*os.File
+}
+
+// Write calls f.File.Write with f.mu held, to protect  multiple Tracers
+// in the same process from one another.
+func (f *syncFile) Write(data []byte) (int, error) {
+	f.mu.Lock()
+	defer f.mu.Unlock()
+	return f.File.Write(data)
+}

tracer.go

@@ -11,7 +11,7 @@ import (
 	"time"
 
 	"go.elastic.co/apm/internal/apmconfig"
-	"go.elastic.co/apm/internal/apmdebug"
+	"go.elastic.co/apm/internal/apmlog"
 	"go.elastic.co/apm/internal/iochan"
 	"go.elastic.co/apm/internal/ringbuffer"
 	"go.elastic.co/apm/internal/wildcard"
@@ -263,8 +263,8 @@ func newTracer(opts options) *Tracer {
 		cfg.preContext = defaultPreContext
 		cfg.postContext = defaultPostContext
 		cfg.metricsGatherers = []MetricsGatherer{newBuiltinMetricsGatherer(t)}
-		if apmdebug.DebugLog {
-			cfg.logger = apmdebug.LogLogger{}
+		if apmlog.DefaultLogger != nil {
+			cfg.logger = apmlog.DefaultLogger
 		}
 	}
 	return t
@@ -346,14 +346,11 @@ func (t *Tracer) SetContextSetter(setter stacktrace.ContextSetter) {
 
 // SetLogger sets the Logger to be used for logging the operation of
 // the tracer.
+//
+// The tracer is initialized with a default logger configured with the
+// environment variables ELASTIC_APM_LOG_FILE and ELASTIC_APM_LOG_LEVEL.
+// Calling SetLogger will replace the default logger.
 func (t *Tracer) SetLogger(logger Logger) {
-	if apmdebug.DebugLog {
-		if logger == nil {
-			logger = apmdebug.LogLogger{}
-		} else {
-			logger = apmdebug.ChainedLogger{apmdebug.LogLogger{}, logger}
-		}
-	}
 	t.sendConfigCommand(func(cfg *tracerConfig) {
 		cfg.logger = logger
 	})