Level logging difficult to work with

[kris-runzer]

logger := log.NewLogfmtLogger(os.Stderr)
logger = log.NewContext(logger).With("caller", log.DefaultCaller)
lvlLogger := levels.New(logger)
lvlLogger.Info("hi", "there")

In the output you will get: caller=levels.go:72

This is fixed by using log.Caller(4) instead of log.DefaultCaller but makes passing and extending the logger harder than it should be.

[kris-runzer]

Additionally, an issue we are running into is we want to use levels.Levels​ everywhere... but a lot of the go-kit boilerplate works on using ​log.Logger​ (httptransport.Server/Client for example). We can't get back from a ​levels.Logger​ to a log.Logger very easily; we have to pass around multiple variations of the logger.

[ChrisHines]

I think (but haven't tried it yet) we can resolve these tensions if we change the Levels API to return log.Loggers instead of doing the logging directly.

For example if we change:

// Debug logs a debug event along with keyvals.
func (l Levels) Debug(keyvals ...interface{}) error {
    return l.ctx.WithPrefix(l.levelKey, l.debugValue).Log(keyvals...)
}

to

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

The stack depth will again be correct and you can convert any specific level into a log.Logger and pass it to code expecting a log.Logger easily.

Usages would change from:

lvls.Debug("k1", v1, "k2", v2)

to

lvls.Debug().Log("k1", v1, "k2", v2)

Which is not quite as clean, but I don't find it offensive given the power it brings. Thoughts?

[kris-runzer]

That would make this more powerful. Only thing I'd still question is that i would pass lvls.Debug() to httptransport.Server{} as an example.

The logging level may not make sense for all logging; unless there is a strict contract that only errors are logged by these instances? Then i can just pass lvls.Error()

Is it not possible to make the levels.Levels have a .Log(...) or just expose it's underlying log.Logger?

[ChrisHines]

Perhaps, although I would first suggest that code should just use the Logger passed to levels.New in the first place? Wrapping and unwrapping smells bad, but maybe it is the most pragmatic solution.

[kris-runzer]

So I've had the night to think about this and I'm leaning towards lvls.Debug().Log("k1", v1, "k2", v2) being a nice solution to this problem.

As for the problem I'm currently facing; I did a refactor of code organization that has allowed me to easily have levels.Levels on the stuff I write and log.Logger when I'm dealing with go-kit. Since all the go-kit loggers are "error loggers" (correct me if I'm wrong) my solution to get levels there was to just use a custom .With("level", "error") on those.

I'm happy with this solution but I feel that a better approach does exists although I can't place my finger on what it should be at this time.

[sevein]

Nothing to add other than saying that I've run into the same issues and the solution suggested would work for me.

[tommyminds]

Is there any news on this? The proposed lvls.Debug().Log("k1", v1, "k2", v2) would solve the problems I'm having with the level logging nicely.

[ChrisHines]

There seems to be general agreement with the proposed solution, and no objections, so I have created a PR to make the suggested change. Those interested, please review.