Skip to content

Commit

Permalink
Log level improvements (#126)
Browse files Browse the repository at this point in the history 
Simplify log level usage by converting log level parameters to constant enum type.  This type mirrors `logrus.Level` exactly so it can be easily converted (e.g. `level := tracing.Level(logrus.GetLevel())`).

**Breaking Change**: This is a breaking change to the `tracing.WithLevel()` option.

Fix documentation around meaning of level numbers.

Tag spans with `log.level=<name>` and `log.levelNum=<n>`.

Using `StartScopeError()` will also tag span in error status.
  • Loading branch information
@Baliedge
Baliedge authored Aug 16, 2022
1 parent 9faf51f commit e174b74
Show file tree
Hide file tree
Showing 6 changed files with 97 additions and 66 deletions.
11 changes: 4 additions & 7 deletions tracing/README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -125,17 +125,14 @@ severity. Spans that do not meed the minimum severity are simply dropped and
not exported.

Log level is passed with option `tracing.WithLevel()` as a numeric
[RFC5424](https://www.rfc-editor.org/rfc/rfc5424) log level (0-7).
log level (0-6): Panic, Fatal, Error, Warning, Info, Debug, Trace.

As a convenience, you may use log level constants from Logrus, like so:
As a convenience, use constants, such as `tracing.DebugLevel`:

```go
import (
"github.com/mailgun/holster/v4/tracing"
"github.com/sirupsen/logrus"
)
import "github.com/mailgun/holster/v4/tracing"

level := int64(logrus.DebugLevel)
level := tracing.DebugLevel
err := tracing.InitTracing(ctx, "my library name", tracing.WithLevel(level))
```

Expand Down
35 changes: 17 additions & 18 deletions tracing/dummy_span_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,6 @@ import (
"testing"

"github.com/mailgun/holster/v4/tracing"
"github.com/sirupsen/logrus"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/mock"
"github.com/stretchr/testify/require"
Expand All @@ -23,7 +22,7 @@ func TestDummySpan(t *testing.T) {
mockProcessor := new(MockSpanProcessor)
mockProcessor.On("Shutdown", mock.Anything).Once().Return(nil)

level := int64(logrus.InfoLevel)
level := tracing.InfoLevel
setupMockTracerProvider(t, level, mockProcessor)

// Call code.
Expand All @@ -49,11 +48,11 @@ func TestDummySpan(t *testing.T) {
Run(func(args mock.Arguments) {
s := args.Get(0).(sdktrace.ReadOnlySpan)
assertReadOnlySpanNoError(t, s)
assertHasLogLevel(t, int64(logrus.InfoLevel), s)
assertHasLogLevel(t, tracing.InfoLevel, s)
})
mockProcessor.On("Shutdown", mock.Anything).Once().Return(nil)

level := int64(logrus.InfoLevel)
level := tracing.InfoLevel
setupMockTracerProvider(t, level, mockProcessor)

// Call code.
Expand Down Expand Up @@ -86,20 +85,20 @@ func TestDummySpan(t *testing.T) {
Run(func(args mock.Arguments) {
s := args.Get(0).(sdktrace.ReadOnlySpan)
assertReadOnlySpanNoError(t, s)
assertHasLogLevel(t, int64(logrus.InfoLevel), s)
assertHasLogLevel(t, tracing.InfoLevel, s)
firstSpan = s
})
mockProcessor.On("OnEnd", matchLeafSpan).
Once().
Run(func(args mock.Arguments) {
s := args.Get(0).(sdktrace.ReadOnlySpan)
assertReadOnlySpanNoError(t, s)
assertHasLogLevel(t, int64(logrus.InfoLevel), s)
assertHasLogLevel(t, tracing.InfoLevel, s)
leafSpan = s
})
mockProcessor.On("Shutdown", mock.Anything).Once().Return(nil)

level := int64(logrus.InfoLevel)
level := tracing.InfoLevel
setupMockTracerProvider(t, level, mockProcessor)

// Call code.
Expand Down Expand Up @@ -131,11 +130,11 @@ func TestDummySpan(t *testing.T) {
Run(func(args mock.Arguments) {
s := args.Get(0).(sdktrace.ReadOnlySpan)
assertReadOnlySpanNoError(t, s)
assertHasLogLevel(t, int64(logrus.InfoLevel), s)
assertHasLogLevel(t, tracing.InfoLevel, s)
})
mockProcessor.On("Shutdown", mock.Anything).Once().Return(nil)

level := int64(logrus.InfoLevel)
level := tracing.InfoLevel
setupMockTracerProvider(t, level, mockProcessor)

// Call code.
Expand Down Expand Up @@ -172,20 +171,20 @@ func TestDummySpan(t *testing.T) {
Run(func(args mock.Arguments) {
s := args.Get(0).(sdktrace.ReadOnlySpan)
assertReadOnlySpanNoError(t, s)
assertHasLogLevel(t, int64(logrus.InfoLevel), s)
assertHasLogLevel(t, tracing.InfoLevel, s)
firstSpan = s
})
mockProcessor.On("OnEnd", matchLeafSpan).
Once().
Run(func(args mock.Arguments) {
s := args.Get(0).(sdktrace.ReadOnlySpan)
assertReadOnlySpanNoError(t, s)
assertHasLogLevel(t, int64(logrus.InfoLevel), s)
assertHasLogLevel(t, tracing.InfoLevel, s)
leafSpan = s
})
mockProcessor.On("Shutdown", mock.Anything).Once().Return(nil)

level := int64(logrus.InfoLevel)
level := tracing.InfoLevel
setupMockTracerProvider(t, level, mockProcessor)

// Call code.
Expand All @@ -210,7 +209,7 @@ func TestDummySpan(t *testing.T) {
})
}

func assertHasLogLevel(t *testing.T, expectedLogLevel int64, s sdktrace.ReadOnlySpan) {
func assertHasLogLevel(t *testing.T, expectedLogLevel tracing.Level, s sdktrace.ReadOnlySpan) {
level, ok := levelFromReadOnlySpan(s)
if !ok {
t.Error("Error: Expected span log level to be defined")
Expand All @@ -228,17 +227,17 @@ func assertReadOnlySpanNoError(t *testing.T, s sdktrace.ReadOnlySpan) {
}
}

func levelFromReadOnlySpan(s sdktrace.ReadOnlySpan) (int64, bool) {
func levelFromReadOnlySpan(s sdktrace.ReadOnlySpan) (tracing.Level, bool) {
for _, attr := range s.Attributes() {
if string(attr.Key) == tracing.LogLevelKey {
return attr.Value.AsInt64(), true
if string(attr.Key) == tracing.LogLevelNumKey {
return tracing.Level(attr.Value.AsInt64()), true
}
}

return 0, false
return tracing.Level(0), false
}

func setupMockTracerProvider(t *testing.T, level int64, mockProcessor *MockSpanProcessor) {
func setupMockTracerProvider(t *testing.T, level tracing.Level, mockProcessor *MockSpanProcessor) {
t.Setenv("OTEL_EXPORTERS", "none")
ctx := context.Background()
opts := []tracing.TracingOption{
Expand Down
54 changes: 43 additions & 11 deletions tracing/level.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,36 +3,58 @@ package tracing
import (
"context"

"github.com/sirupsen/logrus"
"go.opentelemetry.io/otel/attribute"
sdktrace "go.opentelemetry.io/otel/sdk/trace"
"go.opentelemetry.io/otel/trace"
)

type Level uint64

// LevelTracerProvider wraps a TracerProvider to apply log level processing.
// Tag spans with `log.level=n`, where `n` is numeric log level 0-7 (RFC5424).
// Tag spans with `log.level` and `log.levelNum=n`, where `n` is numeric log
// level 0-6 (Panic, Fatal, Error, Warn, Info, Debug, Trace).
// If span log level is lower severity than threshold, create a `DummySpan`
// instead.
// `DummySpan` behaves like an alias of its next non-dummy ancestor, but get
// filtered out because does not get exported. Nested spans containing a mix
// of real and `DummySpan` will be linked as if the `DummySpan` never happened.
// `DummySpan` behaves like an alias of its next non-dummy ancestor, but gets
// filtered out and omitted from export. Nested spans containing a mix of real
// and `DummySpan` will be linked as if the `DummySpan` never happened.
type LevelTracerProvider struct {
*sdktrace.TracerProvider
level int64
level Level
}

// LevelTracer is created by `LevelTracerProvider`.
type LevelTracer struct {
trace.Tracer
level int64
level Level
}

// LogLevelKey is the span attribute key for storing numeric log level.
const LogLevelKey = "log.level"
const LogLevelNumKey = "log.levelNum"

const (
PanicLevel Level = iota
FatalLevel
ErrorLevel
WarnLevel
InfoLevel
DebugLevel
TraceLevel
)

var logLevelCtxKey struct{}
var logLevelNames = []string{
"PANIC",
"FATAL",
"ERROR",
"WARNING",
"INFO",
"DEBUG",
"TRACE",
}

func NewLevelTracerProvider(level int64, opts ...sdktrace.TracerProviderOption) *LevelTracerProvider {
func NewLevelTracerProvider(level Level, opts ...sdktrace.TracerProviderOption) *LevelTracerProvider {
tp := sdktrace.NewTracerProvider(opts...)

return &LevelTracerProvider{
Expand All @@ -51,7 +73,7 @@ func (tp *LevelTracerProvider) Tracer(libraryName string, opts ...trace.TracerOp

func (t *LevelTracer) Start(ctx context.Context, spanName string, opts ...trace.SpanStartOption) (context.Context, trace.Span) {
// Check log level.
ctxLevel, hasLevel := ctx.Value(logLevelCtxKey).(int64)
ctxLevel, hasLevel := ctx.Value(logLevelCtxKey).(Level)
if hasLevel {
// Prevent log level parameter from propagating to child spans.
ctx = context.WithValue(ctx, logLevelCtxKey, nil)
Expand All @@ -60,12 +82,22 @@ func (t *LevelTracer) Start(ctx context.Context, spanName string, opts ...trace.
return newDummySpan(ctx)
}
} else {
ctxLevel = int64(logrus.InfoLevel)
ctxLevel = InfoLevel
}

// Pass-through.
spanCtx, span := t.Tracer.Start(ctx, spanName, opts...)
span.SetAttributes(attribute.Int64(LogLevelKey, ctxLevel))
span.SetAttributes(
attribute.Int64(LogLevelNumKey, int64(ctxLevel)),
attribute.String(LogLevelKey, logLevelName(ctxLevel)),
)

return spanCtx, span
}

func logLevelName(level Level) string {
if level >= 0 && level <= 6 {
return logLevelNames[level]
}
return ""
}
6 changes: 2 additions & 4 deletions tracing/option.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -42,13 +42,11 @@ func (o *ResourceOption) apply(state *initState) {
}

type LevelTracingOption struct {
level int64
level Level
}

// WithLevel passes a log level to InitTracing.
// `level` is RFC5424 numeric log level (0-7).
// For convenience, use logrus constants, such as: `int64(logrus.InfoLevel)`
func WithLevel(level int64) *LevelTracingOption {
func WithLevel(level Level) *LevelTracingOption {
return &LevelTracingOption{
level: level,
}
Expand Down
Loading

0 comments on commit e174b74

Please sign in to comment.