Skip to content

Commit

Permalink
Merge pull request #93 from instana/expose_logger
Browse files Browse the repository at this point in the history
Pluggable logger
  • Loading branch information
Andrew Slotin authored Mar 25, 2020
2 parents 194c1e2 + 256aae0 commit 8727880
Show file tree
Hide file tree
Showing 16 changed files with 697 additions and 319 deletions.
57 changes: 57 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,63 @@ var sensor = instana.NewSensor("my-service")

A full example can be found under the examples folder in [example/webserver/instana/http.go](./example/webserver/instana/http.go).

### Log Output

The Go sensor uses a leveled logger to log internal errors and diagnostic information. The default `logger.Logger` uses `log.Logger`
configured with `log.Lstdflags` as a backend and writes messages to `os.Stderr`. By default this logger only prints out the `ERROR` level
messages unless the environment variable `INSTANA_DEBUG` is set.

To change the min log level in runtime it is recommended to configure and inject an instance of `instana.LeveledLogger` instead of using
the deprecated `instana.SetLogLevel()` method:

```go
l := logger.New(log.New(os.Stderr, "", os.Lstdflags))
instana.SetLogger(l)

// ...

l.SetLevel(logger.WarnLevel)
```

The `logger.LeveledLogger` interface is implemented by such popular logging libraries as [`github.com/sirupsen/logrus`](https://github.com/sirupsen/logrus) and [`go.uber.org/zap`](https://go.uber.org/zap), so they can be used as a replacement.

**Note**: the value of `INSTANA_DEBUG` environment variable does not affect custom loggers. You'd need to explicitly check whether it's set
and enable the debug logging while onfiguring your logger:

```go
import (
instana "github.com/instana/go-sensor"
"github.com/sirupsen/logrus"
)

func main() {
// initialize Instana sensor
instana.InitSensor(&instana.Options{Service: SERVICE})

// initialize and configure the logger
logger := logrus.New()
logger.Level = logrus.InfoLevel

// check if INSTANA_DEBUG is set and set the log level to DEBUG if needed
if _, ok := os.LookupEnv("INSTANA_DEBUG"); ok {
logger.Level = logrus.DebugLevel
}

// use logrus to log the Instana Go sensor messages
instana.SetLogger(logger)

// ...
}
```

The Go sensor [AutoProfile™](#autoprofile) by default uses the same logger as the sensor itself, however it can be configured to
use its own, for example to write messages with different tags/prefix or use a different logging level. The following snippet
demonstrates how to configure the custom logger for autoprofiler:

```
autoprofile.SetLogger(autoprofileLogger)
```

### Trace Context Propagation

Instana Go sensor provides an API to propagate the trace context throughout the call chain:
Expand Down
22 changes: 18 additions & 4 deletions adapters.go
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ type ContextSensitiveFunc func(span ot.Span, ctx context.Context)
// Sensor is used to inject tracing information into requests
type Sensor struct {
tracer ot.Tracer
logger LeveledLogger
}

// NewSensor creates a new instana.Sensor
Expand All @@ -29,14 +30,27 @@ func NewSensor(serviceName string) *Sensor {

// NewSensorWithTracer returns a new instana.Sensor that uses provided tracer to report spans
func NewSensorWithTracer(tracer ot.Tracer) *Sensor {
return &Sensor{tracer: tracer}
return &Sensor{
tracer: tracer,
logger: defaultLogger,
}
}

// Tracer returns the tracer instance for this sensor
func (s *Sensor) Tracer() ot.Tracer {
return s.tracer
}

// Logger returns the logger instance for this sensor
func (s *Sensor) Logger() LeveledLogger {
return s.logger
}

// SetLogger sets the logger for this sensor
func (s *Sensor) SetLogger(l LeveledLogger) {
s.logger = l
}

// TraceHandler is similar to TracingHandler in regards, that it wraps an existing http.HandlerFunc
// into a named instance to support capturing tracing information and data. The returned values are
// compatible with handler registration methods, e.g. http.Handle()
Expand Down Expand Up @@ -119,11 +133,11 @@ func (s *Sensor) WithTracingSpan(operationName string, w http.ResponseWriter, re
case nil:
opts = append(opts, ext.RPCServerOption(wireContext))
case ot.ErrSpanContextNotFound:
log.debug("no span context provided with %s %s", req.Method, req.URL.Path)
s.Logger().Debug("no span context provided with ", req.Method, " ", req.URL.Path)
case ot.ErrUnsupportedFormat:
log.info("unsupported span context format provided with %s %s", req.Method, req.URL.Path)
s.Logger().Info("unsupported span context format provided with ", req.Method, " ", req.URL.Path)
default:
log.warn("failed to extract span context from the request:", err)
s.Logger().Warn("failed to extract span context from the request:", err)
}

if ps, ok := SpanFromContext(req.Context()); ok {
Expand Down
8 changes: 2 additions & 6 deletions adapters_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -233,12 +233,8 @@ func TestWithTracingSpan_WithWireContext(t *testing.T) {

rec := httptest.NewRecorder()
req := httptest.NewRequest("GET", "/test", nil)

traceID, err := instana.ID2Header(1234567890)
require.NoError(t, err)

parentSpanID, err := instana.ID2Header(1)
require.NoError(t, err)
traceID := instana.FormatID(1234567890)
parentSpanID := instana.FormatID(1)

req.Header.Set(instana.FieldT, traceID)
req.Header.Set(instana.FieldS, parentSpanID)
Expand Down
20 changes: 8 additions & 12 deletions agent.go
Original file line number Diff line number Diff line change
Expand Up @@ -54,6 +54,13 @@ func (r *agentS) init() {
r.setFrom(&fromS{})
}

func (r *agentS) initFsm() *fsmS {
ret := &fsmS{agent: r}
ret.init()

return ret
}

func (r *agentS) makeURL(prefix string) string {
return r.makeHostURL(r.host, prefix)
}
Expand Down Expand Up @@ -153,7 +160,7 @@ func (r *agentS) fullRequestResponse(url string, method string, data interface{}
// this is the time where the entity is registering in the Instana
// backend and it will return 404 until it's done.
if !r.sensor.agent.fsm.fsm.Is("announced") {
log.info(err, url)
r.sensor.logger.Info(err, url)
}
}

Expand All @@ -171,14 +178,3 @@ func (r *agentS) setHost(host string) {
func (r *agentS) reset() {
r.fsm.reset()
}

func (r *sensorS) initAgent() *agentS {

log.debug("initializing agent")

ret := new(agentS)
ret.sensor = r
ret.init()

return ret
}
19 changes: 18 additions & 1 deletion autoprofile/auto_profiler.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package autoprofile
import (
"github.com/instana/go-sensor/autoprofile/internal"
"github.com/instana/go-sensor/autoprofile/internal/logger"
instalogger "github.com/instana/go-sensor/logger"
)

var (
Expand Down Expand Up @@ -33,8 +34,24 @@ var (
)

// SetLogLevel sets the min log level for autoprofiler
//
// Deprecated: use autoprofile.SetLogger() to set the logger and configure the min log level directly
func SetLogLevel(level int) {
logger.SetLogLevel(logger.Level(level))
switch logger.Level(level) {
case logger.ErrorLevel:
logger.SetLogLevel(instalogger.ErrorLevel)
case logger.WarnLevel:
logger.SetLogLevel(instalogger.WarnLevel)
case logger.InfoLevel:
logger.SetLogLevel(instalogger.InfoLevel)
default:
logger.SetLogLevel(instalogger.DebugLevel)
}
}

// SetLogger sets the leveled logger to use to output the diagnostic messages and errors
func SetLogger(l logger.LeveledLogger) {
logger.SetLogger(l)
}

// Enable enables the auto profiling (disabled by default)
Expand Down
71 changes: 31 additions & 40 deletions autoprofile/internal/logger/logger.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,8 @@
package logger

import l "log"
import (
instalogger "github.com/instana/go-sensor/logger"
)

// Level is the log level
type Level uint8
Expand All @@ -13,61 +15,50 @@ const (
DebugLevel
)

var defaultLogger *logWrapper = &logWrapper{DebugLevel}
var defaultLogger LeveledLogger = instalogger.New(nil)

// LeveledLogger is an interface of a generic logger that support different message levels.
// By default instana.Sensor uses logger.Logger with log.Logger as an output, however this
// interface is also compatible with such popular loggers as github.com/sirupsen/logrus.Logger
// and go.uber.org/zap.SugaredLogger
type LeveledLogger interface {
Debug(v ...interface{})
Info(v ...interface{})
Warn(v ...interface{})
Error(v ...interface{})
}

// SetLogLevel configures the min log level for autoprofile defaultLogger
func SetLogLevel(level Level) {
defaultLogger.logLevel = level
func SetLogLevel(level instalogger.Level) {
l, ok := defaultLogger.(*instalogger.Logger)
if !ok {
return
}

l.SetLevel(level)
}

// SetLogger sets the leveled logger to use to output the diagnostic messages and errors
func SetLogger(l LeveledLogger) {
defaultLogger = l
}

// Debug writes log message with defaultLogger.Debug level
func Debug(v ...interface{}) {
defaultLogger.debug(v...)
defaultLogger.Debug(v...)
}

// Info writes log message with defaultLogger.Info level
func Info(v ...interface{}) {
defaultLogger.info(v...)
defaultLogger.Info(v...)
}

// Warn writes log message with defaultLogger.Warn level
func Warn(v ...interface{}) {
defaultLogger.warn(v...)
defaultLogger.Warn(v...)
}

// Error writes log message with defaultLogger.Error level
func Error(v ...interface{}) {
defaultLogger.error(v...)
}

type logWrapper struct {
logLevel Level
}

func (lw *logWrapper) makeV(prefix string, v ...interface{}) []interface{} {
return append([]interface{}{prefix}, v...)
}

func (lw *logWrapper) debug(v ...interface{}) {
if lw.logLevel >= DebugLevel {
l.Println(lw.makeV("DEBUG: instana:", v...)...)
}
}

func (lw *logWrapper) info(v ...interface{}) {
if lw.logLevel >= InfoLevel {
l.Println(lw.makeV("INFO: instana:", v...)...)
}
}

func (lw *logWrapper) warn(v ...interface{}) {
if lw.logLevel >= WarnLevel {
l.Println(lw.makeV("WARN: instana:", v...)...)
}
}

func (lw *logWrapper) error(v ...interface{}) {
if lw.logLevel >= ErrorLevel {
l.Println(lw.makeV("ERROR: instana:", v...)...)
}
defaultLogger.Error(v...)
}
Loading

0 comments on commit 8727880

Please sign in to comment.