See also the reference implementation of this interface in ventu-io/slog.
Logging is central to any production quality code and there are many logging modules for Go. Surprisingly, none of the most commonly used ones provides a clean separation between the interface and the implementation of logging. If there are ones on the market, the author apparently has not found one. Guaranteeing consistent logging at the library level for libraries coming from different development teams is, therefore, next to impossible.
Java developers have had the solution for a long while now: a combination of SLF4J (simple logging facade for java) and one of the implementations such as logback or log4j etc.
The slf
module provides for Go what SLF4J does for Java: a clean logging facade with no implementation and a factory that any code can use to pull a logger configured at the start of the application. It then goes a step further and defines a structured logging facade rather than a "simple" one.
The design adopts ideas from apex/log, which itself was inspired by logrus: both good modules for structured logging, yet failing exactly at the point of providing any generic interface to logging to which different implementations could be adopted. Generally speaking, this is not a substitute for either of the latter, they both can be adopted to work behind this interface. However, an independent implementation matching the interface is also provided separately in ventu-io/slog. It provides context-specific log levels, concurrent and sequential log processing, a text/terminal log entry handler for coloured output with custom formatting of log entries using Go text/template
and custom time format. At the moment it also provides a JSON log entry handler and more handlers can be added extrnally or will be added in due course.
The API is fairly confined and straightforward, so it is worth looking into the code while adopting it. However, the general concept can be outlined as follows:
- an implementation is set once at the init of the main application by calling
slf.Set(logFactory)
; - context-specific logger instances, e.g. those for a package, a struct or a module, are retrieved from the factory using
slf.WithContext(contextDef)
. The interface prescribes at least one structured field,context
; - these can then be used with fields to define the structure of log entries or even without any further fields, just like a plain vanilla logger. Arbitrary fields are accepted via
WithField("key", value)
orWithFields(slf.Fields{"key": value})
and the predefined ones viaWithError(err)
orWithCaller(slf.CallerShort)
; - leveled log entries can be generated with or without a formatter,
logger.Debugf("%v", "message")
andlogger.Info("message")
; - the interface defines 5 serializable log levels
DEBUG
,INFO
,WARN
,ERROR
,PANIC
,FATAL
(TRACE
is explicitly excluded); - finally, each log entry can be followed by a
Trace
method, which is supposed to log execution time counting from the last log entry by the same logger using the same log level as the last log entry. Using it withdefer
provides a clean mechanism to trace the execution times of methods in one line.
The interface defines no structure of the actual log entry, nor the mechanism of how the log levels are set to the contexts (if at all), nor log entry handler interface, nor the actual log entry handlers. All these entities are what libraries using the logger do not care about and are only of concern for the application putting the libraries together. Therefore, all of these are deferred to the actual implementation used in the application (and are for example defined in the reference slog implementation).
As mentioned above, there is no need to bind any implementation of SLF into a library. The slf
module provides a Noop
implementation by default, that is the one with No-Operation, which will make sure your library does not panic on missing logging implementation. The factory methods and all the logging routines will work as is, yet no output will be generated. Two exceptions are the Panic
command, which will panic even though no log output will be generated, and Fatal
, which will call os.Exit(1)
even though no log output will be generated.
One should be careful not to initialise any context logger, that is the one obtained with slf.WithContext
, in the init
or into a package-level variable directly, as this will return an instance of the Noop
implementation before the factory could be reset to use an actual logging implementation in the main application. However, the following three approaches are all valid:
-
define a package-level function to retrieve a context logger, e.g.
func logger() slf.StructuredLogger { return slf.WithContext("app.package") } func HandleRequest(req Request) (err error) { defer logger().WithField("request", req).Info("processing request").Trace(&err) return handle(req) }
-
define a logger within a struct (the approach adopted by the author):
type RequestHandler struct { logger slf.StructuredLogger } func New() *RequestHandler { return &RequestHandler{ logger: slf.WithContext("app.package"), } } func (rh *RequestHandler) Handle(req Request) (err error) { defer rh.logger.WithField("request", req).Info("processing request").Trace(&err) return handle(req) }
-
finally, get a context logger directly at the point where you need it. The reference implementation reuses an earlier created logger for the context, however, it comes at a cost of verbosity of your code and going through locking of resources at the implementation level:
func HandleRequest(req Request) (err error) { defer slf.WithContext("app.package").WithField("request", req).Info("processing request").Trace(err) return handle(req) }
Further examples for the use of the facade include:
-
logging without any fields (except for
context
):logger.Debugf("done %v", "for now")
-
deriving a new loggers in the same context with further added fields:
logger1 := logger0.WithField("A", a).WithField("B", b) logger1.WithError(err).Warn("handling error")
-
adding or supressing caller information without altering the parent logger
logger1 := logger0.WithCaller(slf.CallerLong) logger2 := logger1.WithCaller(slf.CallerNone) logger1.Info("with caller") logger2.Info("without caller")
-
using
Trace
accepts a pointer to an error. This is done so that the call can be defined indefer
, which will get an optional error during the execution (nil is accepted).
The initialisation clause of an end-user application is where the actual implementation needs to be configured, and only here. The configuration could look like this if the reference slog implementation is used (for the sake of clarity). Other implementation will have their own initialisation logic, but the overall idea will remain the same:
func init() {
// define a basic stderr log entry handler, or any other log entry handler of choice
bh := basic.New()
// optionally define the format (this here is the default one)
bh.SetTemplate("{{.Time}} [\033[{{.Color}}m{{.Level}}\033[0m] {{.Context}}{{if .Caller}} ({{.Caller}}){{end}}: {{.Message}}{{if .Error}} (\033[31merror: {{.Error}}\033[0m){{end}} {{.Fields}}")
// initialise and configure the SLF implementation
lf := slog.New()
// set common log level to INFO
lf.SetLevel(slf.LevelInfo)
// set log level for specific contexts to DEBUG
lf.SetLevel(slf.LevelDebug, "app.package1", "app.package2")
lf.AddEntryHandler(bh)
lf.AddEntryHandler(json.New(os.Stderr))
// make this into the one used by all the libraries
slf.Set(lf)
}
Given the above setup the log output of the application can look like this:
-
for the JSON logger:
{ "timestamp": "2016-03-26T17:41:14.5517", "level": "WARN", "message": "Error while subscribing. Retrying in 30s", "error": "read: connection reset by peer", "fields": { "context": "probe.agent.task.Subscribe" } }
-
for the basic text logger (with coloured INFO if output to a terminal):
17:41:14.551 [WARN] probe.agent.task.Subscribe: Error while subscribing. Retrying in 30s (error: read: connection reset by peer)
Copyright (c) 2016 Ventu.io, Oleg Sklyar, contributors.
Distributed under a MIT style license found in the LICENSE file.