vjkoskela/gosteno

go-steno

Implementation of ArpNetworking's LogbackSteno for Go. Extends Sirupsen's logrus logging implementation with a Steno compatible Formatter as well as providing named Logger instances and a fluent log builder.

Dependency

First, retrieve the library into your workspace:

go> go get github.com/vjkoskela/gosteno

To use the library in your project(s) simply import it:

import "github.com/vjkoskela/gosteno"

Formatter

Create the formatter as follows:

var formatter *gosteno.Formatter = gosteno.NewFormatter()

The gosteno.Formatter supports a subset of the options available in LogbackSteno:

• LogEventName - Set the default event name. The default is "log".
• InjectContextProcess - Add the process identifier to the context block. The default is true.
• InjectContextHost - Add the host name to the context block. The default is true.
• InjectContextLogger - Add the logger name to the context block. The default is false. (1)

Note 1: Injecting additional key-value pairs into context is not strictly compliant with the current definition of Steno.

These may be configured after instantiating the Formatter. For example:

formatter.SetInjectContextLogger(true)

Logrus

The underlying logging implementation is logrus. At minimum you must set the formatter; however, you may also want to configure the writer and minimum output level. For example to configure the global logger instance:

logrus.SetOutput(os.Stdout)
logrus.SetFormatter(formatter)
logrus.SetLevel(logrus.DebugLevel)

Alternatively, you may create a new logrus logger and configure that. For example:

var logrusLogger *logrus.Logger = &logrus.Logger{
    Out: os.Stdout,
    Formatter: formatter,
    Level: logrus.ErrorLevel,
}

Logger

Instantiate a named Logger instance for each particular logging context. By default the Logger is bound to the global default logrus logger instance. For example:

var logger *gosteno.Logger = gosteno.GetLogger("http.server")

Alternatively, you may bind a Logger instance to particular logrus logger instance:

var logger *gosteno.Logger = gosteno.GetLoggerForLogger("http.server", logrusLogger)

Log Builder

Aside from providing a full set of logging methods compatible with Go's standard logging and with the logrus logger, gosteno.Logger also provides access to buildable logs:

logger.DebugBuilder().SetMessage("This is a log builder debug message").Log()

logger.InfoBuilder().SetEvent("my_event").SetMessage("This is a log builder info message with event").Log()

logger.WarnBuilder().
        SetEvent("my_event").
        SetMessage("This is a warn builder info message with event and error").
        SetError(errors.New("This is also another error")).
        Log()

logger.ErrorBuilder().
        SetEvent("my_event").
        SetMessage("This is a log builder info message with event, error, data and context").
        SetError(errors.New("This is also another error")).
        AddContext("requestId", uuid.New()).
        AddData("userId", uuid.New()).
        Log()

This produces output like this:

{"time":"2016-01-08T17:45:35.895560313-08:00","name":"log","level":"debug","data":{"message":"This is a log builder debug message"},"context":{"host":"Mac-Pro.local","processId":"16358","logger":"examples.main"},"id":"e4c0f58d-74c1-425e-8f8c-017f03bc0171","version":"0"}
{"time":"2016-01-08T17:45:35.895584789-08:00","name":"my_event","level":"info","data":{"message":"This is a log builder info message with event"},"context":{"host":"Mac-Pro.local","processId":"16358","logger":"examples.main"},"id":"5f7acb89-c498-4b30-b0d4-248de0d8e060","version":"0"}
{"time":"2016-01-08T17:45:35.895611498-08:00","name":"my_event","level":"warn","data":{"message":"This is a warn builder info message with event and error"},"context":{"host":"Mac-Pro.local","processId":"16358","logger":"examples.main"},"exception":{"type":"error","message":"This is also another error","backtrace":[]},"id":"b75fd67c-2831-4aff-8dff-277393da6eed","version":"0"}
{"time":"2016-01-08T17:45:35.895643617-08:00","name":"my_event","level":"crit","data":{"message":"This is a log builder info message with event, error, data and context","userId":"bb486dfd-d7c5-4e3f-8391-c39d9fee6cac"},"context":{"requestId":"3186ea94-bca3-4a75-8ba2-b01151e9935c","host":"Mac-Pro.local","processId":"16358","logger":"examples.main"},"exception":{"type":"error","message":"This is also another error","backtrace":[]},"id":"67c13e4d-12de-4ae4-8606-271d6e4ae13f","version":"0"}

For more examples please see performance.go.

Performance

Some very non-scientific relative benchmarking was performed against the Arpnetworking LogbackSteno Java implementation.

Go with error, mind you it's effectively just a string with no stack trace:

Elapsed 2.236446 seconds
Elapsed 2.198458 seconds
Elapsed 2.356763 seconds
Elapsed 2.196019 seconds
Elapsed 2.206734 seconds

Average = 2.238884 seconds

Java with exception for error, which includes the message and a stack trace:

Elapsed 10.815678 seconds
Elapsed 11.896151 seconds
Elapsed 10.839127 seconds
Elapsed 11.803035 seconds
Elapsed 10.903178 seconds

Average = 11.2514338 seconds

Java without exception for error:

Elapsed 2.790097 seconds
Elapsed 1.639426 seconds
Elapsed 1.470144 seconds
Elapsed 1.612253 seconds
Elapsed 1.575005 seconds

Average = 1.817385 seconds

The gosteno implementation is 5.025 times faster when exceptions are logged in Java and 1.232 times slower when they are not. The cost of stack trace generation and encoding in Java is not surprising; however, the scale of the improvement with it disabled is. Finally, although this is neither a complete nor rigorous performance test it does provide an interesting baseline. The next step would be to compare serialization times including complex data structures as that will simulate real world usage more closely.

Details:

• JDK/JRE version 1.8.0_66
• GO version 1.5.2
• 3.5 Ghz 6-Core Intel Xeon E5
• 32 GB 1866 Mhz DDR ECC
• Mac OS X with El Capitan
• Loggers configured to stdout redirected in bash to /dev/null

Development

To build the library locally you must satisfy these prerequisites:

• Go

Next, fork the repository, get and build:

Getting and Building:

go> go get github.com/$USER/gosteno
go> go install github.com/$USER/gosteno

Testing:

go> go test -coverprofile=coverage.out github.com/$USER/gosteno
go> go tool cover -html=coverage.out

To use the local forked version in your project simply import it:

import "github.com/$USER/gosteno"

Note: The above assumes $USER is the name of your Github organization containing the fork.

License

Published under Apache Software License 2.0, see LICENSE

© Ville Koskela, 2016

gosteno's Issues

Change Formatter to use GoRoutines

The formatter can utilize goroutines for the encoding of:

• root
• context
• data

Then the context and data can be appended to root and it can be closed. The basic performance test should be rerun to see if this has any impact. The change should be abandoned if it has a negative impact (but none is expected).

Create Host/Process Provider

Wrap the host and process id in the formatter behind provider interfaces with default implementations based on the calls in os. This will facilitate improvements in the testing of the host and process id injection in formatter_test.go.

Additional Unit Tests

Complete unit test of the library.

logger_test:

• Test Fatal and Panic methods using a mock logrus logger.
• Test no-op stub methods from standard logger.
• Test output method to info w/o stack trace method from standard logger.

formatter_test:

* Test log event name set/unset
* Test on/off logger
* Test on/off process id
* Test on/off host
* Context empty
* Data empty
* Complex context
* Complex data
* Level mapping
* Message set/unset
* Error set/unset

• Test catastropic failure resulting in no log message.
• Test data/context serialization failure resulting in skeleton message.

Optional File and Line Injection

The file and line of the originating statement should be optionally included in the context. There is a logrus fork with this feature here:

https://github.com/jeffizhungry/logrus

Also Facebook has released a library which claims to simplify interactions withe the Go stack especially around GoRoutines. It can be found here:

https://github.com/facebookgo/stack