Skip to content

Commit

Permalink
* refactored packages: middlewares and exporters now at the top level
Browse files Browse the repository at this point in the history
* added unit tests for the log and tracer packages
* fixed a few issues with propagating fields in traces
* added more options to expose the full set of zap settings

Signed-off-by: Frederic BIDON <fredbi@yahoo.com>
  • Loading branch information
fredbi committed Nov 28, 2023
1 parent 28b9076 commit 487e7a2
Show file tree
Hide file tree
Showing 32 changed files with 792 additions and 81 deletions.
75 changes: 64 additions & 11 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -21,31 +21,84 @@ Tested to be compatible wih Datadog tracing.

The main idea is to unify logging and tracing, and insulate the app layer from the intricacies of tracing.

This repo provides a few wrappers around a zap.Logger:
This repo provides a few wrappers around a `zap.Logger`:
* a logger factory based on zap logger, with a convenient builder to link logs to trace spans
* a logger builder, e.g. to initialize a root logger for your service
* a simple middleware to trace a `http.Handler`

### Exporters
### Usage

Various opencensus exporters.
* influxdb: export opencensus metrics to an influxdb sink
* amplitude (experimental): propagate trace event to the amplitude API
```go
import (
"context"

TODOs:
* [] opentelemetry/opentracing
"github.com/fredbi/go-trace/log"
"go.opencensus.io/trace"
)

ctx := context.Background()
zlg, closer := log.MustGetLogger("root") // builds a named zap logger with sensible defaults
defer closer()

lgf := log.NewFactory(zlg) // builds a logger with trace propagation

ctx, span := trace.StartSpan(ctx, "span name")
defer span.End()
lg := lgf.For(ctx)

lg.Info("log propagated as a trace span")
```

## Tracing

Simple utilities to instrument tracing inside apps.
Simple utilities to instrument tracing inside apps with minimal boiler-plate.


```go
import (
"context"

"github.com/fredbi/go-trace/log"
"github.com/fredbi/go-trace/trace"
)

type loggable struct {
lgf log.Factory
}

func (l *loggable) Logger() log.Factory {
return l.lgf
}

[Example Usage](https://github.com/fredbi/go-trace/blob/master/tracer/example_test.go)
zlg := log.MustGetLogger("root") // builds a named zap logger with sensible defaults
lgf := log.NewFactory(zlg) // builds a logger with trace propagation
component := loggable{lfg: lgf}

#### Middleware
ctx, span, lg := tracer.StartSpan(context.Background(), component) // the span is named automatically from the calling function
defer span.End()

lg.Info("log propagated as a trace span")
```

[Full example](https://github.com/fredbi/go-trace/blob/master/tracer/example_test.go)

## Middleware

* `log/middleware/LogRequests` logs all requests from a http server, using the logger factory
* `tracer.Middleware` wraps the `ochttp` opencensus plugin in a more convenient middleware.

TODOs:
* [] expose middlewares from a the top level package

## Exporters

Various opencensus exporters (as a separate module).
* influxdb: export opencensus metrics to an influxdb sink
* amplitude (experimental): propagate trace event to the amplitude API

TODOs:
* [] opentelemetry/opentracing
* [] reorganize module at the top level

## Credits

Much inspired by prior art from @casualjim. Thanks so much.
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
// Package amplitude exposes an exporter to route
// span traces to the Amplitude API.
// span traces to the Amplitude API, with some filteting.
//
// This is experimental and not optimized for production usage.
package amplitude
File renamed without changes.
File renamed without changes.
File renamed without changes.
File renamed without changes.
File renamed without changes.
8 changes: 4 additions & 4 deletions log/exporters/go.mod → exporters/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -12,10 +12,10 @@ require (

require (
github.com/davecgh/go-spew v1.1.1 // indirect
github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e // indirect
github.com/hashicorp/go-cleanhttp v0.5.1 // indirect
github.com/hashicorp/go-retryablehttp v0.7.0 // indirect
github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da // indirect
github.com/hashicorp/go-cleanhttp v0.5.2 // indirect
github.com/hashicorp/go-retryablehttp v0.7.5 // indirect
github.com/pmezard/go-difflib v1.0.0 // indirect
go.uber.org/multierr v1.10.0 // indirect
go.uber.org/multierr v1.11.0 // indirect
gopkg.in/yaml.v3 v3.0.1 // indirect
)
8 changes: 8 additions & 0 deletions log/exporters/go.sum → exporters/go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,8 @@ github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7
github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b/go.mod h1:SBH7ygxi8pfUlaOkMMuAQtPIUF8ecWP5IEl/CR7VP2Q=
github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e h1:1r7pUrabqp18hOBcwBwiTsbnFeTZHV9eER/QT5JVZxY=
github.com/golang/groupcache v0.0.0-20200121045136-8c9f03a8e57e/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc=
github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da h1:oI5xCqsCo564l8iNU+DwB5epxmsaqB+rhGL0m5jtYqE=
github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da/go.mod h1:cIg4eruTrX1D+g88fzRXU5OdNfaM+9IcxsU14FzY7Hc=
github.com/golang/mock v1.1.1/go.mod h1:oTYuIxOrZwtPieC+H1uAHpcLFnEyAGVDL/k47Jfbm0A=
github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
github.com/golang/protobuf v1.3.2/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
Expand All @@ -34,10 +36,14 @@ github.com/google/go-cmp v0.5.7/go.mod h1:n+brtR0CgQNWTVd5ZUFpTBC8YFBDLK/h/bpaJ8
github.com/google/uuid v1.1.2/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
github.com/hashicorp/go-cleanhttp v0.5.1 h1:dH3aiDG9Jvb5r5+bYHsikaOUIpcM0xvgMXVoDkXMzJM=
github.com/hashicorp/go-cleanhttp v0.5.1/go.mod h1:JpRdi6/HCYpAwUzNwuwqhbovhLtngrth3wmdIIUrZ80=
github.com/hashicorp/go-cleanhttp v0.5.2 h1:035FKYIWjmULyFRBKPs8TBQoi0x6d9G4xc9neXJWAZQ=
github.com/hashicorp/go-cleanhttp v0.5.2/go.mod h1:kO/YDlP8L1346E6Sodw+PrpBSV4/SoxCXGY6BqNFT48=
github.com/hashicorp/go-hclog v0.9.2 h1:CG6TE5H9/JXsFWJCfoIVpKFIkFe6ysEuHirp4DxCsHI=
github.com/hashicorp/go-hclog v0.9.2/go.mod h1:5CU+agLiy3J7N7QjHK5d05KxGsuXiQLrjA0H7acj2lQ=
github.com/hashicorp/go-retryablehttp v0.7.0 h1:eu1EI/mbirUgP5C8hVsTNaGZreBDlYiwC1FZWkvQPQ4=
github.com/hashicorp/go-retryablehttp v0.7.0/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY=
github.com/hashicorp/go-retryablehttp v0.7.5 h1:bJj+Pj19UZMIweq/iie+1u5YCdGrnxCT9yvm0e+Nd5M=
github.com/hashicorp/go-retryablehttp v0.7.5/go.mod h1:Jy/gPYAdjqffZ/yFGCFV2doI5wjtH1ewM9u8iYVjtX8=
github.com/influxdata/influxdb v1.11.2 h1:qOF3uQN1mDfJNEKwbAgJsqehf8IXgKok2vlGm736oGo=
github.com/influxdata/influxdb v1.11.2/go.mod h1:eUMkLTE2vQwvSk6KGMrTBLKPaqSuczuelGbggigMPFw=
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
Expand All @@ -60,6 +66,8 @@ go.uber.org/goleak v1.2.0 h1:xqgm/S+aQvhWFTtR0XK3Jvg7z8kGV8P4X14IzwN3Eqk=
go.uber.org/goleak v1.2.0/go.mod h1:XJYK+MuIchqpmGmUSAzotztawfKvYLUIgg7guXrwVUo=
go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ=
go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0=
go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
go.uber.org/zap v1.26.0 h1:sI7k6L95XOKS281NhVKOFCUNIvv9e0w4BF8N3u+tCRo=
go.uber.org/zap v1.26.0/go.mod h1:dtElttAiwGvoJ/vj4IwHBS/gXsEu/pZ50mUIRWuG0so=
golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
Expand Down
File renamed without changes.
File renamed without changes.
File renamed without changes.
File renamed without changes.
File renamed without changes.
File renamed without changes.
3 changes: 2 additions & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -7,15 +7,16 @@ require (
github.com/stretchr/testify v1.8.4
go.opencensus.io v0.24.0
go.uber.org/zap v1.26.0
gopkg.in/DataDog/dd-trace-go.v1 v1.58.0
)

require (
github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc // indirect
github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da // indirect
github.com/google/go-cmp v0.5.9 // indirect
github.com/kr/pretty v0.3.0 // indirect
github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 // indirect
go.uber.org/multierr v1.11.0 // indirect
golang.org/x/net v0.17.0 // indirect
gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 // indirect
gopkg.in/yaml.v3 v3.0.1 // indirect
)
6 changes: 2 additions & 4 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -34,8 +34,8 @@ github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMyw
github.com/google/go-cmp v0.4.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
github.com/google/go-cmp v0.5.0/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
github.com/google/go-cmp v0.5.3/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI=
github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
github.com/google/go-cmp v0.5.9/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
github.com/google/uuid v1.1.2/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo=
github.com/kr/pretty v0.3.0 h1:WgNl7dwNpEZ6jJ9k1snq4pZsg7DOEN8hP9Xw0Tsjwk0=
Expand Down Expand Up @@ -117,8 +117,6 @@ google.golang.org/protobuf v1.22.0/go.mod h1:EGpADcykh3NcUnDUJcl1+ZksZNG86OlYog2
google.golang.org/protobuf v1.23.0/go.mod h1:EGpADcykh3NcUnDUJcl1+ZksZNG86OlYog2l/sGQquU=
google.golang.org/protobuf v1.23.1-0.20200526195155-81db48ad09cc/go.mod h1:EGpADcykh3NcUnDUJcl1+ZksZNG86OlYog2l/sGQquU=
google.golang.org/protobuf v1.25.0/go.mod h1:9JNX74DMeImyA3h4bdi1ymwjUzf21/xIlbajtzgsN7c=
gopkg.in/DataDog/dd-trace-go.v1 v1.58.0 h1:ixIUarsu0RrOt7xfdrE5YSFvjgaWsP3cC3G342jTIuw=
gopkg.in/DataDog/dd-trace-go.v1 v1.58.0/go.mod h1:SmnEjjV9ZQr4MWRSUYEpoPyNtmtRK5J6UuJdAma+Yxw=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15 h1:YR8cESwS4TdDjEe65xsg0ogRM/Nc3DYOhEAlW+xobZo=
Expand Down
30 changes: 19 additions & 11 deletions log/constructors.go
Original file line number Diff line number Diff line change
Expand Up @@ -8,21 +8,22 @@ import (
"go.uber.org/zap/zapcore"
)

// MustGetLogger creates a named zap logger, typically to inject into a service runtime as the root logger.
// MustGetLogger creates a named zap logger, typically injected into a service runtime as the root logger.
//
// This function returns a configured zap.Logger and a closing function to sync logs upon exit.
//
// It panics upon failures, such as invalid log level, or incapacity to build the underlying logger.
// It panics upon failures, such as an invalid log level, or incapacity to build the underlying logger.
func MustGetLogger(name string, opts ...LoggerOption) (*zap.Logger, func()) {
options := defaultLoggerOptions(opts)
lc := zap.NewProductionConfig()
lc := options.seedConfig()
if err := options.applyToConfig(&lc); err != nil {
panic(fmt.Sprintf("parsing log level: %v", err))
}

zlg := zap.Must(
lc.Build(zap.AddCallerSkip(options.callerSkip)),
)
lc.Build(
append(options.zapOpts, zap.AddCallerSkip(options.callerSkip))...,
))
zlg = zlg.Named(name)
options.applyToLogger(zlg)

Expand All @@ -33,26 +34,33 @@ func MustGetLogger(name string, opts ...LoggerOption) (*zap.Logger, func()) {
// a logger factory or its underlying *zap.Logger into the tested components.
//
// It is configurable from the "DEBUG_TEST" environment variable: if set, logging
// is enabled. Otherwise, logging is just muted, allowing to keep test verbosity low.
// is enabled. Otherwise, logging is muted, allowing to keep test verbosity low.
//
// Typical usage:
//
// DEBUG_TEST=1 go test -v ./...
func GetTestLoggerConfig(opts ...LoggerOption) (Factory, *zap.Logger, error) {
isDebug := os.Getenv("DEBUG_TEST") != ""
options := defaultLoggerOptions(opts)

var zlg *zap.Logger
if !isDebug {
zlg = zap.NewNop()

return NewFactory(zlg), zlg, nil
}

lc := zap.NewDevelopmentConfig()
lc := options.seedTestConfig()
lc.Level = zap.NewAtomicLevelAt(zap.DebugLevel)
lc.EncoderConfig.EncodeDuration = zapcore.StringDurationEncoder
lg, err := lc.Build(zap.AddCallerSkip(1))
zlg, err := lc.Build(
append(options.zapOpts, zap.AddCallerSkip(options.callerSkip))...,
)
if err != nil {
return Factory{}, nil, err
}
zlg = zlg.Named("test")
options.applyToLogger(zlg)
zlg = lg

factory := NewFactory(zlg)

Expand All @@ -61,8 +69,8 @@ func GetTestLoggerConfig(opts ...LoggerOption) (Factory, *zap.Logger, error) {

// MustGetTestLoggerConfig is a wrapper around GetTestLoggerConfig that panics
// if an error is encountered.
func MustGetTestLoggerConfig() (Factory, *zap.Logger) {
fl, zlg, err := GetTestLoggerConfig()
func MustGetTestLoggerConfig(opts ...LoggerOption) (Factory, *zap.Logger) {
fl, zlg, err := GetTestLoggerConfig(opts...)
if err != nil {
panic(fmt.Sprintf("could not acquire test logger: %v", err))
}
Expand Down
76 changes: 76 additions & 0 deletions log/constructors_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,76 @@
package log

import (
"sync"
"testing"

"github.com/stretchr/testify/require"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"go.uber.org/zap/zaptest/observer"
)

func TestMustGetLogger(t *testing.T) {
const appName = "my_app"
observed, observedLogs := observer.New(zapcore.DebugLevel)

zlog, closer := MustGetLogger(
appName,
WithZapOptions(zap.WrapCore(func(c zapcore.Core) zapcore.Core {
// forwards logged entries to an observable sink
return zapcore.NewTee(c, observed)
})),
)
defer closer()

zlog.Info("test", zap.String("context", "x"))

entries := observedLogs.All()
require.Len(t, entries, 1)
entry := entries[0]

require.Equal(t, zapcore.InfoLevel, entry.Level)
require.NotEmpty(t, entry.Time)
require.Equal(t, appName, entry.LoggerName)
require.Equal(t, "test", entry.Message)
require.Len(t, entry.Context, 1)
}

var testMux sync.Mutex

func TestMustGetTestLogger(t *testing.T) {
testMux.Lock()
defer testMux.Unlock()

t.Run("with no env", mustGetTestLogger(""))

t.Run("with env", mustGetTestLogger("1"))
}

func mustGetTestLogger(env string) func(*testing.T) {
return func(t *testing.T) {
t.Setenv("DEBUG_TEST", env)

observed, observedLogs := observer.New(zapcore.DebugLevel)

zlf, zlg := MustGetTestLoggerConfig(
WithZapOptions(zap.WrapCore(func(c zapcore.Core) zapcore.Core {
return zapcore.NewTee(c, observed)
})),
)
require.NotNil(t, zlf)
require.NotNil(t, zlg)

l := zlf.Bg()
l.Info("test")

entries := observedLogs.All()
if env == "" {
require.Len(t, entries, 0)

return
}

require.Len(t, entries, 1)
}
}
44 changes: 44 additions & 0 deletions log/examples_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,44 @@
package log_test

import (
"context"
"os"

"github.com/fredbi/go-trace/log"
"go.opencensus.io/trace"
)

func ExampleMustGetLogger() {
const appName = "my_app"

zlog, closer := log.MustGetLogger(
appName,
log.WithLevel("debug"),
log.WithOutput(log.Stdout),
)

zlog.Debug("test")
defer closer()
}

func ExampleNewFactory() {
ctx := context.Background()
zlg, closer := log.MustGetLogger("root") // builds a named zap logger with sensible defaults
defer closer()

lgf := log.NewFactory(zlg) // builds a logger with trace propagation

ctx, span := trace.StartSpan(ctx, "span name")
defer span.End()
lg := lgf.For(ctx)

lg.Info("log propagated as a trace span")
}

func ExampleMustGetTestLoggerConfig() {
os.Setenv("DEBUG_TEST", "1")
zlf, zlg := log.MustGetTestLoggerConfig()

zlg.Info("this is a logger visible only when DEBUG_TEST is set, e.g. for local testing")
zlf.Bg().Info("this is a logger factory only visble when DEBUG_TEST is set, e.g. for local testing")
}
Loading

0 comments on commit 487e7a2

Please sign in to comment.