Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

log/experimental_level #357

Merged
merged 7 commits into from
Sep 7, 2016
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
65 changes: 65 additions & 0 deletions log/experimental_level/benchmark_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,65 @@
package level_test

import (
"io/ioutil"
"testing"

"github.com/go-kit/kit/log"
"github.com/go-kit/kit/log/experimental_level"
)

func BenchmarkNopBaseline(b *testing.B) {
benchmarkRunner(b, log.NewNopLogger())
}

func BenchmarkNopDisallowedLevel(b *testing.B) {
benchmarkRunner(b, level.New(log.NewNopLogger(), level.Config{
Allowed: level.AllowInfoAndAbove(),
}))
}

func BenchmarkNopAllowedLevel(b *testing.B) {
benchmarkRunner(b, level.New(log.NewNopLogger(), level.Config{
Allowed: level.AllowAll(),
}))
}

func BenchmarkJSONBaseline(b *testing.B) {
benchmarkRunner(b, log.NewJSONLogger(ioutil.Discard))
}

func BenchmarkJSONDisallowedLevel(b *testing.B) {
benchmarkRunner(b, level.New(log.NewJSONLogger(ioutil.Discard), level.Config{
Allowed: level.AllowInfoAndAbove(),
}))
}

func BenchmarkJSONAllowedLevel(b *testing.B) {
benchmarkRunner(b, level.New(log.NewJSONLogger(ioutil.Discard), level.Config{
Allowed: level.AllowAll(),
}))
}

func BenchmarkLogfmtBaseline(b *testing.B) {
benchmarkRunner(b, log.NewLogfmtLogger(ioutil.Discard))
}

func BenchmarkLogfmtDisallowedLevel(b *testing.B) {
benchmarkRunner(b, level.New(log.NewLogfmtLogger(ioutil.Discard), level.Config{
Allowed: level.AllowInfoAndAbove(),
}))
}

func BenchmarkLogfmtAllowedLevel(b *testing.B) {
benchmarkRunner(b, level.New(log.NewLogfmtLogger(ioutil.Discard), level.Config{
Allowed: level.AllowAll(),
}))
}

func benchmarkRunner(b *testing.B, logger log.Logger) {
b.ResetTimer()
b.ReportAllocs()
for i := 0; i < b.N; i++ {
level.Debug(logger).Log("foo", "bar")
}
}
27 changes: 27 additions & 0 deletions log/experimental_level/doc.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
// Package level is an EXPERIMENTAL levelled logging package. The API will
// definitely have breaking changes and may be deleted altogether. Be warned!
//
// To use the level package, create a logger as per normal in your func main,
// and wrap it with level.New.
//
// var logger log.Logger
// logger = log.NewLogfmtLogger(os.Stderr)
// logger = level.New(logger, level.Config{Allowed: level.AllowInfoAndAbove}) // <--
// logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC)
//
// Then, at the callsites, use one of the level.Debug, Info, Warn, or Error
// helper methods to emit leveled log events.
//
// logger.Log("foo", "bar") // as normal, no level
// level.Debug(logger).Log("request_id", reqID, "trace_data", trace.Get())
// if value > 100 {
// level.Error(logger).Log("value", value)
// }
//
// The leveled logger allows precise control over what should happen if a log
// event is emitted without a level key, or if a squelched level is used. Check
// the Config struct for details. And, you can easily use non-default level
// values: create new string constants for whatever you want to change, pass
// them explicitly to the Config struct, and write your own level.Foo-style
// helper methods.
package level
146 changes: 146 additions & 0 deletions log/experimental_level/level.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,146 @@
package level

import (
"github.com/go-kit/kit/log"
)

var (
levelKey = "level"
errorLevelValue = "error"
warnLevelValue = "warn"
infoLevelValue = "info"
debugLevelValue = "debug"
)

// AllowAll is an alias for AllowDebugAndAbove.
func AllowAll() []string {
return AllowDebugAndAbove()
}

// AllowDebugAndAbove allows all of the four default log levels.
// Its return value may be provided as the Allowed parameter in the Config.
func AllowDebugAndAbove() []string {
return []string{errorLevelValue, warnLevelValue, infoLevelValue, debugLevelValue}
}

// AllowInfoAndAbove allows the default info, warn, and error log levels.
// Its return value may be provided as the Allowed parameter in the Config.
func AllowInfoAndAbove() []string {
return []string{errorLevelValue, warnLevelValue, infoLevelValue}
}

// AllowWarnAndAbove allows the default warn and error log levels.
// Its return value may be provided as the Allowed parameter in the Config.
func AllowWarnAndAbove() []string {
return []string{errorLevelValue, warnLevelValue}
}

// AllowErrorOnly allows only the default error log level.
// Its return value may be provided as the Allowed parameter in the Config.
func AllowErrorOnly() []string {
return []string{errorLevelValue}
}

// AllowNone allows none of the default log levels.
// Its return value may be provided as the Allowed parameter in the Config.
func AllowNone() []string {
return []string{}
}

// Error returns a logger with the level key set to ErrorLevelValue.
func Error(logger log.Logger) log.Logger {
return log.NewContext(logger).With(levelKey, errorLevelValue)
}

// Warn returns a logger with the level key set to WarnLevelValue.
func Warn(logger log.Logger) log.Logger {
return log.NewContext(logger).With(levelKey, warnLevelValue)
}

// Info returns a logger with the level key set to InfoLevelValue.
func Info(logger log.Logger) log.Logger {
return log.NewContext(logger).With(levelKey, infoLevelValue)
}

// Debug returns a logger with the level key set to DebugLevelValue.
func Debug(logger log.Logger) log.Logger {
return log.NewContext(logger).With(levelKey, debugLevelValue)
}

// Config parameterizes the leveled logger.
type Config struct {
// Allowed enumerates the accepted log levels. If a log event is encountered
// with a level key set to a value that isn't explicitly allowed, the event
// will be squelched, and ErrNotAllowed returned.
Allowed []string

// ErrNotAllowed is returned to the caller when Log is invoked with a level
// key that hasn't been explicitly allowed. By default, ErrNotAllowed is
// nil; in this case, the log event is squelched with no error.
ErrNotAllowed error

// SquelchNoLevel will squelch log events with no level key, so that they
// don't proceed through to the wrapped logger. If SquelchNoLevel is set to
// true and a log event is squelched in this way, ErrNoLevel is returned to
// the caller.
SquelchNoLevel bool

// ErrNoLevel is returned to the caller when SquelchNoLevel is true, and Log
// is invoked without a level key. By default, ErrNoLevel is nil; in this
// case, the log event is squelched with no error.
ErrNoLevel error
}

// New wraps the logger and implements level checking. See the commentary on the
// Config object for a detailed description of how to configure levels.
func New(next log.Logger, config Config) log.Logger {
return &logger{
next: next,
allowed: makeSet(config.Allowed),
errNotAllowed: config.ErrNotAllowed,
squelchNoLevel: config.SquelchNoLevel,
errNoLevel: config.ErrNoLevel,
}
}

type logger struct {
next log.Logger
allowed map[string]struct{}
errNotAllowed error
squelchNoLevel bool
errNoLevel error
}

func (l *logger) Log(keyvals ...interface{}) error {
var hasLevel, levelAllowed bool
for i := 0; i < len(keyvals); i += 2 {
if k, ok := keyvals[i].(string); !ok || k != levelKey {
continue
}
hasLevel = true
if i >= len(keyvals) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What is this check for? Unless I'm missing something I believe this is always false.

continue
}
v, ok := keyvals[i+1].(string)
if !ok {
continue
}
_, levelAllowed = l.allowed[v]
break
}
if !hasLevel && l.squelchNoLevel {
return l.errNoLevel
}
if hasLevel && !levelAllowed {
return l.errNotAllowed
}
return l.next.Log(keyvals...)
}

func makeSet(a []string) map[string]struct{} {
m := make(map[string]struct{}, len(a))
for _, s := range a {
m[s] = struct{}{}
}
return m
}
154 changes: 154 additions & 0 deletions log/experimental_level/level_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,154 @@
package level_test

import (
"bytes"
"errors"
"strings"
"testing"

"github.com/go-kit/kit/log"
"github.com/go-kit/kit/log/experimental_level"
)

func TestVariousLevels(t *testing.T) {
for _, testcase := range []struct {
allowed []string
want string
}{
{
level.AllowAll(),
strings.Join([]string{
`{"level":"debug","this is":"debug log"}`,
`{"level":"info","this is":"info log"}`,
`{"level":"warn","this is":"warn log"}`,
`{"level":"error","this is":"error log"}`,
}, "\n"),
},
{
level.AllowDebugAndAbove(),
strings.Join([]string{
`{"level":"debug","this is":"debug log"}`,
`{"level":"info","this is":"info log"}`,
`{"level":"warn","this is":"warn log"}`,
`{"level":"error","this is":"error log"}`,
}, "\n"),
},
{
level.AllowInfoAndAbove(),
strings.Join([]string{
`{"level":"info","this is":"info log"}`,
`{"level":"warn","this is":"warn log"}`,
`{"level":"error","this is":"error log"}`,
}, "\n"),
},
{
level.AllowWarnAndAbove(),
strings.Join([]string{
`{"level":"warn","this is":"warn log"}`,
`{"level":"error","this is":"error log"}`,
}, "\n"),
},
{
level.AllowErrorOnly(),
strings.Join([]string{
`{"level":"error","this is":"error log"}`,
}, "\n"),
},
{
level.AllowNone(),
``,
},
} {
var buf bytes.Buffer
logger := level.New(log.NewJSONLogger(&buf), level.Config{Allowed: testcase.allowed})

level.Debug(logger).Log("this is", "debug log")
level.Info(logger).Log("this is", "info log")
level.Warn(logger).Log("this is", "warn log")
level.Error(logger).Log("this is", "error log")

if want, have := testcase.want, strings.TrimSpace(buf.String()); want != have {
t.Errorf("given Allowed=%v: want\n%s\nhave\n%s", testcase.allowed, want, have)
}
}
}

func TestErrNotAllowed(t *testing.T) {
myError := errors.New("squelched!")
logger := level.New(log.NewNopLogger(), level.Config{
Allowed: level.AllowWarnAndAbove(),
ErrNotAllowed: myError,
})

if want, have := myError, level.Info(logger).Log("foo", "bar"); want != have {
t.Errorf("want %#+v, have %#+v", want, have)
}

if want, have := error(nil), level.Warn(logger).Log("foo", "bar"); want != have {
t.Errorf("want %#+v, have %#+v", want, have)
}
}

func TestErrNoLevel(t *testing.T) {
myError := errors.New("no level specified")

var buf bytes.Buffer
logger := level.New(log.NewJSONLogger(&buf), level.Config{
SquelchNoLevel: true,
ErrNoLevel: myError,
})

if want, have := myError, logger.Log("foo", "bar"); want != have {
t.Errorf("want %v, have %v", want, have)
}
if want, have := ``, strings.TrimSpace(buf.String()); want != have {
t.Errorf("want %q, have %q", want, have)
}
}

func TestAllowNoLevel(t *testing.T) {
var buf bytes.Buffer
logger := level.New(log.NewJSONLogger(&buf), level.Config{
SquelchNoLevel: false,
ErrNoLevel: errors.New("I should never be returned!"),
})

if want, have := error(nil), logger.Log("foo", "bar"); want != have {
t.Errorf("want %v, have %v", want, have)
}
if want, have := `{"foo":"bar"}`, strings.TrimSpace(buf.String()); want != have {
t.Errorf("want %q, have %q", want, have)
}
}

func TestLevelContext(t *testing.T) {
var buf bytes.Buffer

// Wrapping the level logger with a context allows users to use
// log.DefaultCaller as per normal.
var logger log.Logger
logger = log.NewLogfmtLogger(&buf)
logger = level.New(logger, level.Config{Allowed: level.AllowAll()})
logger = log.NewContext(logger).With("caller", log.DefaultCaller)

level.Info(logger).Log("foo", "bar")
if want, have := `caller=level_test.go:134 level=info foo=bar`, strings.TrimSpace(buf.String()); want != have {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oof, this looks brittle... If anyone adds/removes non-zero number of lines above this, the line number will get out of sync.

t.Errorf("want %q, have %q", want, have)
}
}

func TestContextLevel(t *testing.T) {
var buf bytes.Buffer

// Wrapping a context with the level logger still works, but requires users
// to specify a higher callstack depth value.
var logger log.Logger
logger = log.NewLogfmtLogger(&buf)
logger = log.NewContext(logger).With("caller", log.Caller(5))
logger = level.New(logger, level.Config{Allowed: level.AllowAll()})

level.Info(logger).Log("foo", "bar")
if want, have := `caller=level_test.go:150 level=info foo=bar`, strings.TrimSpace(buf.String()); want != have {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same brittle comment.

t.Errorf("want %q, have %q", want, have)
}
}
Loading