Should we stop using a global logger?

[buchan...@gmail.com]

In Funnel [1], we've been using a global logger, based on logrus [2]. This has worked fine through the early stages of the project, but it's starting to show a few cracks. In particular, we need to ensure that a request (task) ID is present in all log messages. Solutions to this have grown to be inconsistent:

- We create a child logger instance which has the ID preconfigured, and pass that to some function calls. [3]

- We're looking at passing a context to logging calls, and the logger pulls the ID from context.Value. [4]

- Some calls have been left behind and are still using the global logger.

Other notes:

- A global logger configured to a single task ID won't work, since multiple requests may be handled concurrently.

- Request handling spans multiple packages.

- We're using context extensively, we're ok with using it more.

We're trying to decide whether to stick to a global (singleton) logger, or remove the global logger completely and start passing logger instances everywhere. I think we can make either work, and so far neither is an obvious choice. What do you think?

Global logger:

- seems to be the most common approach

- convenient access

- global singleton might lead to difficulty and inflexibility, e.g. capturing logging in tests, multiple configurations

Logger instances:

- more fields on every type and function that wants to log

- full control over logging in each individual type and function

- clearly stated dependencies for each type/function. I'd say Go idioms tend toward obvious, clear, and powerful over clean, concise, magic.

A third, interesting option might be to add all logging configuration to the context using context.Value, including output, formatting, etc. Global logging functions would pull all needed config from the context. I'm worried this gets into the hotly debated territory of abusing context.Value. On the other hand, we're already passing context everywhere, and this is useful context that crosses API boundaries.

Anywho, would love to get thoughts from the experts out there. Thanks for reading!

Alex

[1] https://github.com/ohsu-comp-bio/funnel

[2] https://github.com/sirupsen/logrus

[3] https://github.com/ohsu-comp-bio/funnel/blob/master/worker/runner.go#L25

[4] https://github.com/ohsu-comp-bio/funnel/pull/194

[Dave Cheney]

> Should we stop using a global logger?

Yes[1]

1. https://dave.cheney.net/2017/01/26/context-is-for-cancelation

[buchan...@gmail.com]

Or, what if...

type FunnelContext interface {
  context.Context
  logger.Logger
}

type RequestHandler struct {
  // No context specific fields here, instance stays reusable across requests
}
func (RequestHandler) Handle(ctx FunnelContext) {}

 

[Tamás Gulácsi]

Yes[1]: your logger is a concrete dependency which should be passed explicitly to the function which logs!

And as the common idiom is to not include Context in struct but pass as the first argument, the logger should be inserted into that Context.

[1] https://peter.bourgon.org/go-best-practices-2016/#logging-and-instrumentation

[snmed]

Hi Dave

I've read about this context.Value topic on several occasion and in your blog post you say context is only for cancelation. But how should one cope with real goroutine specific data, unfortunately i missed always a correct solution for this problem.

Any proposal is welcome

Cheers snmed

[Peter Mogensen]

On 2017-08-25 05:38, buchan...@gmail.com wrote:
> - We create a child logger instance which has the ID preconfigured, and
> pass that to some function calls. [3]

I think several log packages has the feature build in.

> instances everywhere. I think we can make either work, and so far
> neither is an obvious choice. What do you think?

IMHO ideally, you should use local logger instances. But that of course
only becomes gradually more relevant the larger and more modularized the
application becomes.

> A third, interesting option might be to add all logging configuration to
> the context using context.Value,

I'd prefer this option in many cases. However, I probably wouldn't put
formatting preferences into context.Value.

A third way to use flexible logging is to have a global logger registry
like the python "logging" package where each part of the code can
acquire its logger with GetLogger(name). Loggers are then arranged in a
hierarchy so you don't have to configure formatting for each individually.

/Peter

[Henrik Johansson]

How do you code for storing a logger in context.Value? The same usual issues with lacking a shared logger interface happens or did I miss something neat?

--
You received this message because you are subscribed to the Google Groups "golang-nuts" group.
To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Dave Cheney]

On Friday, 25 August 2017 16:02:48 UTC+10, snmed wrote:

Hi Dave

I've read about this context.Value topic on several occasion and in your blog post you say context is only for cancelation. But how should one cope with real goroutine specific data, unfortunately i missed always a correct solution for this problem.

My recommendation is to pass it down from function to function, either as an argument, or as fields accessible from a method. 

[Peter Mogensen]

On 2017-08-25 05:58, Dave Cheney wrote:
>> Should we stop using a global logger?
>
> Yes[1]
>
> 1. https://dave.cheney.net/2017/01/26/context-is-for-cancelation
>

fair point...

It can be very tempting though. Especially dealing with an HTTP
middleware stack where you need handlers to log and automatically add
Req-ID to the logging.
Unless of course, you use a middleware framework designed to make a
logger available.

/Peter

[Peter Mogensen]

On 2017-08-25 08:31, Henrik Johansson wrote:
> How do you code for storing a logger in context.Value? The same usual
> issues with lacking a shared logger interface happens or did I miss
> something neat?
>

I try not to do logging from libraries. So logging (and the logger
interface) is specific to my application.

Internally I would pass loggers as arguments, but using context.Context
becomes relevant when building a middleware stack. So the application
installs both the middleware creating the logger and the handler using
it. (and they then both know the type).
There can be other application specific request-scoped stuff you want to
pass along down the middleware stack - such as
Authentication-ID/Authorization-ID. So there's ususally an application
specific requestcontext and not just a logger.

/Peter

[Henrik Johansson]

Me neither but it can be very neat occasionally.

Agreed and it also applies fine things like Tracing.

But logger? If you change logger implementation you have to have a wrapper or you have to change the type conversions everywhere.

Maybe refactoring tools can help I guess but I miss a common interface for logging. There was some promising work alas no consensus afaik.

[Tamás Gulácsi]

I use "func(...interface{}) error" as the log func interface - that's what go-kit/kit/log provides without an explicit interface.
Does not do much, easy to wrap into any logger but provides structural logging.
With closures, sub-loggers are possible, too.

[Peter Mogensen]

On 2017-08-25 10:45, Henrik Johansson wrote:
> Me neither but it can be very neat occasionally.
>
> Agreed and it also applies fine things like Tracing.
> But logger? If you change logger implementation you have to have a
> wrapper or you have to change the type conversions everywhere.

But isn't that a general problem - regardless of the specific question
of this thread.
I just keep logging concerns for the application. On the rare occasions
logging from a library is useful, I provide an API to set a callback
with a simple generic interface.
Like SetLogger(func(int level, msg string))
If rewriting to change logger implementation is intolerable to the
application, the application could define its own interface to a logging
abstraction.

/Peter

[Henrik Johansson]

Yes it works ok we have done it as well but a common interface wouldbe convenient. Especially when opentracing whose Go libs seems to take off nicely with afaik a common interface. Logging seems even simpler.

I have started to use Zap pervasively and its typed API is very neat.

[Peter Mogensen]

On 2017-08-25 12:53, Henrik Johansson wrote:
> Yes it works ok we have done it as well but a common interface wouldbe
> convenient. Especially when opentracing whose Go libs seems to take off
> nicely with afaik a common interface. Logging seems even simpler.
>
> I have started to use Zap pervasively and its typed API is very neat.

I did a survey involving basically every logger library I could find
some time ago and ended up concluding that non of them had an easy way
to do logging to systemd in the form "<X>message" on stdout/stderr.
(where X is the syslog level).
So we ended up doing our own logging library. I don't think Zap was
around at the time.

Yeah... I know... The log15 author has a point. But I find the result
pretty useful.

/Peter

[Ian Ross]

I have fiound when you start tracing (e.g jaeger by Uber), you start logging properly and realise it should only used when something needs to be done by an admin.