Skip to content

Commit

Permalink
Merge pull request #481 from go-kit/unexport-log-context
Browse files Browse the repository at this point in the history
log: Unexport Context
  • Loading branch information
ChrisHines authored Mar 6, 2017
2 parents 43a8a37 + 44aed65 commit b71ceaa
Show file tree
Hide file tree
Showing 16 changed files with 187 additions and 214 deletions.
71 changes: 35 additions & 36 deletions README.md
Original file line number Diff line number Diff line change
@@ -1,20 +1,22 @@
# package log

`package log` provides a minimal interface for structured logging in services.
It may be wrapped to encode conventions, enforce type-safety, provide leveled logging, and so on.
It can be used for both typical application log events, and log-structured data streams.
It may be wrapped to encode conventions, enforce type-safety, provide leveled
logging, and so on. It can be used for both typical application log events,
and log-structured data streams.

## Structured logging

Structured logging is, basically, conceding to the reality that logs are _data_,
and warrant some level of schematic rigor.
Using a stricter, key/value-oriented message format for our logs,
containing contextual and semantic information,
makes it much easier to get insight into the operational activity of the systems we build.
Consequently, `package log` is of the strong belief that
"[the benefits of structured logging outweigh the minimal effort involved](https://www.thoughtworks.com/radar/techniques/structured-logging)".
Structured logging is, basically, conceding to the reality that logs are
_data_, and warrant some level of schematic rigor. Using a stricter,
key/value-oriented message format for our logs, containing contextual and
semantic information, makes it much easier to get insight into the
operational activity of the systems we build. Consequently, `package log` is
of the strong belief that "[the benefits of structured logging outweigh the
minimal effort involved](https://www.thoughtworks.com/radar/techniques/structured-logging)".

Migrating from unstructured to structured logging is probably a lot easier than you'd expect.
Migrating from unstructured to structured logging is probably a lot easier
than you'd expect.

```go
// Unstructured
Expand All @@ -37,17 +39,17 @@ logger.Log("question", "what is the meaning of life?", "answer", 42)
// question="what is the meaning of life?" answer=42
```

### Log contexts
### Contextual Loggers

```go
func main() {
var logger log.Logger
logger = log.NewLogfmtLogger(log.NewSyncWriter(os.Stderr))
logger = log.NewContext(logger).With("instance_id", 123)
logger = log.With(logger, "instance_id", 123)

logger.Log("msg", "starting")
NewWorker(log.NewContext(logger).With("component", "worker")).Run()
NewSlacker(log.NewContext(logger).With("component", "slacker")).Run()
NewWorker(log.With(logger, "component", "worker")).Run()
NewSlacker(log.With(logger, "component", "slacker")).Run()
}

// Output:
Expand Down Expand Up @@ -77,9 +79,8 @@ func main() {
// {"msg":"I sure like pie","ts":"2016/01/01 12:34:56"}
```

Or, if, for legacy reasons,
you need to pipe all of your logging through the stdlib log package,
you can redirect Go kit logger to the stdlib logger.
Or, if, for legacy reasons, you need to pipe all of your logging through the
stdlib log package, you can redirect Go kit logger to the stdlib logger.

```go
logger := kitlog.NewLogfmtLogger(kitlog.StdlibWriter{})
Expand All @@ -94,7 +95,7 @@ logger.Log("legacy", true, "msg", "at least it's something")
```go
var logger log.Logger
logger = log.NewLogfmtLogger(log.NewSyncWriter(os.Stderr))
logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
logger = log.With(logger, "ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)

logger.Log("msg", "hello")

Expand All @@ -104,7 +105,7 @@ logger.Log("msg", "hello")

## Supported output formats

- [Logfmt](https://brandur.org/logfmt)
- [Logfmt](https://brandur.org/logfmt) ([see also](https://blog.codeship.com/logfmt-a-log-format-thats-easy-to-read-and-write))
- JSON

## Enhancements
Expand All @@ -117,27 +118,25 @@ type Logger interface {
}
```

This interface, and its supporting code like [log.Context](https://godoc.org/github.com/go-kit/kit/log#Context),
is the product of much iteration and evaluation.
For more details on the evolution of the Logger interface,
see [The Hunt for a Logger Interface](http://go-talks.appspot.com/github.com/ChrisHines/talks/structured-logging/structured-logging.slide#1),
a talk by [Chris Hines](https://github.com/ChrisHines).
This interface, and its supporting code like is the product of much iteration
and evaluation. For more details on the evolution of the Logger interface,
see [The Hunt for a Logger Interface](http://go-talks.appspot.com/github.com/ChrisHines/talks/structured-logging/structured-logging.slide#1),
a talk by [Chris Hines](https://github.com/ChrisHines).
Also, please see
[#63](https://github.com/go-kit/kit/issues/63),
[#76](https://github.com/go-kit/kit/pull/76),
[#131](https://github.com/go-kit/kit/issues/131),
[#157](https://github.com/go-kit/kit/pull/157),
[#164](https://github.com/go-kit/kit/issues/164), and
[#252](https://github.com/go-kit/kit/pull/252)
to review historical conversations about package log and the Logger interface.
[#63](https://github.com/go-kit/kit/issues/63),
[#76](https://github.com/go-kit/kit/pull/76),
[#131](https://github.com/go-kit/kit/issues/131),
[#157](https://github.com/go-kit/kit/pull/157),
[#164](https://github.com/go-kit/kit/issues/164), and
[#252](https://github.com/go-kit/kit/pull/252)
to review historical conversations about package log and the Logger interface.

Value-add packages and suggestions,
like improvements to [the leveled logger](https://godoc.org/github.com/go-kit/kit/log/levels),
are of course welcome.
Good proposals should
like improvements to [the leveled logger](https://godoc.org/github.com/go-kit/kit/log/level),
are of course welcome. Good proposals should

- Be composable with [log.Context](https://godoc.org/github.com/go-kit/kit/log#Context),
- Not break the behavior of [log.Caller](https://godoc.org/github.com/go-kit/kit/log#Caller) in any wrapped context, and
- Be composable with [contextual loggers](https://godoc.org/github.com/go-kit/kit/log#With),
- Not break the behavior of [log.Caller](https://godoc.org/github.com/go-kit/kit/log#Caller) in any wrapped contextual loggers, and
- Be friendly to packages that accept only an unadorned log.Logger.

## Benchmarks & comparisons
Expand Down
4 changes: 2 additions & 2 deletions benchmark_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@ import (
)

func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) {
lc := log.NewContext(logger).With("common_key", "common_value")
lc := log.With(logger, "common_key", "common_value")
b.ReportAllocs()
b.ResetTimer()
for i := 0; i < b.N; i++ {
Expand All @@ -17,5 +17,5 @@ func benchmarkRunner(b *testing.B, logger log.Logger, f func(log.Logger)) {

var (
baseMessage = func(logger log.Logger) { logger.Log("foo_key", "foo_value") }
withMessage = func(logger log.Logger) { log.NewContext(logger).With("a", "b").Log("c", "d") }
withMessage = func(logger log.Logger) { log.With(logger, "a", "b").Log("c", "d") }
)
16 changes: 8 additions & 8 deletions deprecated_levels/levels.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@ import "github.com/go-kit/kit/log"
// want a different set of levels, you can create your own levels type very
// easily, and you can elide the configuration.
type Levels struct {
ctx *log.Context
logger log.Logger
levelKey string

// We have a choice between storing level values in string fields or
Expand All @@ -34,7 +34,7 @@ type Levels struct {
// New creates a new leveled logger, wrapping the passed logger.
func New(logger log.Logger, options ...Option) Levels {
l := Levels{
ctx: log.NewContext(logger),
logger: logger,
levelKey: "level",

debugValue: "debug",
Expand All @@ -52,7 +52,7 @@ func New(logger log.Logger, options ...Option) Levels {
// With returns a new leveled logger that includes keyvals in all log events.
func (l Levels) With(keyvals ...interface{}) Levels {
return Levels{
ctx: l.ctx.With(keyvals...),
logger: log.With(l.logger, keyvals...),
levelKey: l.levelKey,
debugValue: l.debugValue,
infoValue: l.infoValue,
Expand All @@ -64,27 +64,27 @@ func (l Levels) With(keyvals ...interface{}) Levels {

// Debug returns a debug level logger.
func (l Levels) Debug() log.Logger {
return l.ctx.WithPrefix(l.levelKey, l.debugValue)
return log.WithPrefix(l.logger, l.levelKey, l.debugValue)
}

// Info returns an info level logger.
func (l Levels) Info() log.Logger {
return l.ctx.WithPrefix(l.levelKey, l.infoValue)
return log.WithPrefix(l.logger, l.levelKey, l.infoValue)
}

// Warn returns a warning level logger.
func (l Levels) Warn() log.Logger {
return l.ctx.WithPrefix(l.levelKey, l.warnValue)
return log.WithPrefix(l.logger, l.levelKey, l.warnValue)
}

// Error returns an error level logger.
func (l Levels) Error() log.Logger {
return l.ctx.WithPrefix(l.levelKey, l.errorValue)
return log.WithPrefix(l.logger, l.levelKey, l.errorValue)
}

// Crit returns a critical level logger.
func (l Levels) Crit() log.Logger {
return l.ctx.WithPrefix(l.levelKey, l.critValue)
return log.WithPrefix(l.logger, l.levelKey, l.critValue)
}

// Option sets a parameter for leveled loggers.
Expand Down
34 changes: 17 additions & 17 deletions doc.go
Original file line number Diff line number Diff line change
Expand Up @@ -35,14 +35,15 @@
// idea to log simple values without formatting them. This practice allows
// the chosen logger to encode values in the most appropriate way.
//
// Log Context
// Contextual Loggers
//
// A log context stores keyvals that it includes in all log events. Building
// appropriate log contexts reduces repetition and aids consistency in the
// resulting log output. We can use a context to improve the RunTask example.
// A contextual logger stores keyvals that it includes in all log events.
// Building appropriate contextual loggers reduces repetition and aids
// consistency in the resulting log output. With and WithPrefix add context to
// a logger. We can use With to improve the RunTask example.
//
// func RunTask(task Task, logger log.Logger) string {
// logger = log.NewContext(logger).With("taskID", task.ID)
// logger = log.With(logger, "taskID", task.ID)
// logger.Log("event", "starting task")
// ...
// taskHelper(task.Cmd, logger)
Expand All @@ -51,19 +52,18 @@
// }
//
// The improved version emits the same log events as the original for the
// first and last calls to Log. The call to taskHelper highlights that a
// context may be passed as a logger to other functions. Each log event
// created by the called function will include the task.ID even though the
// function does not have access to that value. Using log contexts this way
// simplifies producing log output that enables tracing the life cycle of
// individual tasks. (See the Context example for the full code of the
// above snippet.)
// first and last calls to Log. Passing the contextual logger to taskHelper
// enables each log event created by taskHelper to include the task.ID even
// though taskHelper does not have access to that value. Using contextual
// loggers this way simplifies producing log output that enables tracing the
// life cycle of individual tasks. (See the Contextual example for the full
// code of the above snippet.)
//
// Dynamic Context Values
// Dynamic Contextual Values
//
// A Valuer function stored in a log context generates a new value each time
// the context logs an event. The Valuer example demonstrates how this
// feature works.
// A Valuer function stored in a contextual logger generates a new value each
// time an event is logged. The Valuer example demonstrates how this feature
// works.
//
// Valuers provide the basis for consistently logging timestamps and source
// code location. The log package defines several valuers for that purpose.
Expand All @@ -72,7 +72,7 @@
// entries contain a timestamp and source location looks like this:
//
// logger := log.NewLogfmtLogger(log.NewSyncWriter(os.Stdout))
// logger = log.NewContext(logger).With("ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
// logger = log.With(logger, "ts", log.DefaultTimestampUTC, "caller", log.DefaultCaller)
//
// Concurrent Safety
//
Expand Down
8 changes: 4 additions & 4 deletions example_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ func Example_basic() {
// taskID=1 event="task complete"
}

func Example_context() {
func Example_contextual() {
logger := log.NewLogfmtLogger(os.Stdout)

type Task struct {
Expand All @@ -43,7 +43,7 @@ func Example_context() {
}

RunTask := func(task Task, logger log.Logger) {
logger = log.NewContext(logger).With("taskID", task.ID)
logger = log.With(logger, "taskID", task.ID)
logger.Log("event", "starting task")

taskHelper(task.Cmd, logger)
Expand All @@ -68,7 +68,7 @@ func Example_valuer() {
return count
}

logger = log.NewContext(logger).With("count", log.Valuer(counter))
logger = log.With(logger, "count", log.Valuer(counter))

logger.Log("call", "first")
logger.Log("call", "second")
Expand All @@ -88,7 +88,7 @@ func Example_debugInfo() {
return baseTime
}

logger = log.NewContext(logger).With("time", log.Timestamp(mockTime), "caller", log.DefaultCaller)
logger = log.With(logger, "time", log.Timestamp(mockTime), "caller", log.DefaultCaller)

logger.Log("call", "first")
logger.Log("call", "second")
Expand Down
2 changes: 1 addition & 1 deletion json_logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ func TestJSONLoggerCaller(t *testing.T) {
t.Parallel()
buf := &bytes.Buffer{}
logger := log.NewJSONLogger(buf)
logger = log.NewContext(logger).With("caller", log.DefaultCaller)
logger = log.With(logger, "caller", log.DefaultCaller)

if err := logger.Log(); err != nil {
t.Fatal(err)
Expand Down
6 changes: 3 additions & 3 deletions level/benchmark_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,13 +17,13 @@ func Benchmark(b *testing.B) {
return l
}},
{"TimeContext", func(l log.Logger) log.Logger {
return log.NewContext(l).With("time", log.DefaultTimestampUTC)
return log.With(l, "time", log.DefaultTimestampUTC)
}},
{"CallerContext", func(l log.Logger) log.Logger {
return log.NewContext(l).With("caller", log.DefaultCaller)
return log.With(l, "caller", log.DefaultCaller)
}},
{"TimeCallerReqIDContext", func(l log.Logger) log.Logger {
return log.NewContext(l).With("time", log.DefaultTimestampUTC, "caller", log.DefaultCaller, "reqID", 29)
return log.With(l, "time", log.DefaultTimestampUTC, "caller", log.DefaultCaller, "reqID", 29)
}},
}

Expand Down
2 changes: 1 addition & 1 deletion level/example_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,7 @@ func Example_basic() {
// setup logger with level filter
logger := log.NewLogfmtLogger(os.Stdout)
logger = level.NewFilter(logger, level.AllowInfo())
logger = log.NewContext(logger).With("caller", log.DefaultCaller)
logger = log.With(logger, "caller", log.DefaultCaller)

// use level helpers to log at different levels
level.Error(logger).Log("err", errors.New("bad data"))
Expand Down
8 changes: 4 additions & 4 deletions level/level.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,22 +4,22 @@ import "github.com/go-kit/kit/log"

// Error returns a logger that includes a Key/ErrorValue pair.
func Error(logger log.Logger) log.Logger {
return log.NewContext(logger).WithPrefix(Key(), ErrorValue())
return log.WithPrefix(logger, Key(), ErrorValue())
}

// Warn returns a logger that includes a Key/WarnValue pair.
func Warn(logger log.Logger) log.Logger {
return log.NewContext(logger).WithPrefix(Key(), WarnValue())
return log.WithPrefix(logger, Key(), WarnValue())
}

// Info returns a logger that includes a Key/InfoValue pair.
func Info(logger log.Logger) log.Logger {
return log.NewContext(logger).WithPrefix(Key(), InfoValue())
return log.WithPrefix(logger, Key(), InfoValue())
}

// Debug returns a logger that includes a Key/DebugValue pair.
func Debug(logger log.Logger) log.Logger {
return log.NewContext(logger).WithPrefix(Key(), DebugValue())
return log.WithPrefix(logger, Key(), DebugValue())
}

// NewFilter wraps next and implements level filtering. See the commentary on
Expand Down
4 changes: 2 additions & 2 deletions level/level_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -144,7 +144,7 @@ func TestLevelContext(t *testing.T) {
var logger log.Logger
logger = log.NewLogfmtLogger(&buf)
logger = level.NewFilter(logger, level.AllowAll())
logger = log.NewContext(logger).With("caller", log.DefaultCaller)
logger = log.With(logger, "caller", log.DefaultCaller)

level.Info(logger).Log("foo", "bar")
if want, have := `level=info caller=level_test.go:149 foo=bar`, strings.TrimSpace(buf.String()); want != have {
Expand All @@ -159,7 +159,7 @@ func TestContextLevel(t *testing.T) {
// 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 = log.With(logger, "caller", log.Caller(5))
logger = level.NewFilter(logger, level.AllowAll())

level.Info(logger).Log("foo", "bar")
Expand Down
Loading

0 comments on commit b71ceaa

Please sign in to comment.