log.With does not compose well with log.Levels

[ChrisHines]

Context

I would like the ability to do something like this:

var Log log.Logger

func HandleTask(taskID int) error {
    logger := log.With(Log, "task", taskID)
    logger.Info("event", "start")
    ...
    logger.Debug("event", "query", "query", query)
    if err := doQuery(query); err != nil {
        logger.Error("event", "query", "err", err)
        return err
    }
    ...
    logger.Info("event", "done")
}

The important aspect of my example is the re-use of logging context across multiple severity levels.

The problem

As it stands now, package log encourages us to implement log levels via multiple Loggers each with a different level context created by a call to log.With. Unfortunately this approach makes it cumbersome to create additional contextual loggers on top of the leveled loggers. For example:

var lvls = log.NewLevels()

func HandleTask(taskID int) error {
    dlog := log.With(lvls.Debug, "task", taskID)
    ilog := log.With(lvls.Info, "task", taskID)
    elog := log.With(lvls.Error, "task", taskID)

    ilog.Log("event", "start")
    ...
    dlog.Log("event", "query", "query", query)
    if err := doQuery(query); err != nil {
        elog.Log("event", "query", "err", err)
        return err
    }
    ...
    ilog.Log("event", "done")
}

In addition to being cumbersome, each call to log.With costs allocations.

Challenge

Can we find a good way to avoid the need for multiple calls to log.With when doing leveled logging?

[peterbourgon]

The obvious way is to canonize some levels into the interface definition, but I'd like to avoid that...

[peterbourgon]

We could define a new interface with canonized levels, with constructors that can wrap a logger...

[ChrisHines]

How would log.With compose with the new interface you propose?

[peterbourgon]

Not well :) Could probably dream up a special-case solution, like

type Foo interface {
    Info(keyvals ...interface{})
    Warn(keyvals ...interface{})
    Error(keyvals ...interface{})

    With(keyvals ...interface{}) Foo
}

But that feels awkward, opposite of the existing API.

[peterbourgon]

In general I'm struggling to embrace and extend log.With semantics...

[peterbourgon]

@ChrisHines, what do you think about the approach described in this README?

[ChrisHines]

@peterbourgon What do you think of this?

func With(keyvals ...interface{}) Context {
    c := Context{}
    return c.With(keyvals...)
}

type Context []interface{}

func (c Context) With(keyvals ...interface{}) Context {
    n := len(c)
    return append(c[:n:n], keyvals...)
}

func (c Context) LogTo(logger Logger) error {
    ctx := c
    if containsValuer(ctx) {
        ctx = append(Context{}, ctx...)
        bindValues(ctx)
    }
    return logger.Log(ctx...)
}

The above code would get used like this:

ctx := log.With("a", 123)
...
ctx = ctx.With("b", "c")
...
ctx.With("msg", "message").LogTo(logger)

[peterbourgon]

On first read I resisted the idea of manipulating a first-order Context object and logging it "to" a destination, but after rolling it around a little bit, it feels like it could reasonable. Any reason not to s/LogTo/Log/? Thinking out loud a little bit: we're flying pretty close to an encoder or writer API, I wonder if it doesn't make sense to make that more explicit, with something like

type Logger interface {
    Log(Context) error
}

func (c Context) Log(dst Logger) error {
    return dst.Log(c)
}

...which raises the question of where best to put the valuer stuff. It feels strange to have it only occur when you context.Log(logger), and get ignored if you logger.Log(context). Maybe your version, having the logger take a keyvals, makes that more explicit.