3 minute read

In the 21st century, any decent software project must use a logger. One of the worst presents a software engineer can receive is a project using print statements. This is wrong. We all know that. If you are writing projects in Go or you have just started with this language it can be difficult to find guidelines about what logger solution is the best.

The Golang ecosystem is large and unexplored. When I started using Go I checked some existing solutions and I even considered implementing my own logging until I found zerolog. Zerolog is efficient, easy to use, customizable, and returns JSON outputs. This is particularly interesting for easily processable log outputs.

The following examples contain the basics for any project. The code is available in Github for further details I hope it may serve you as a guideline.

Basic Logging

Zerolog offers seven levels of log entries from Panic to Trace. The most basic message sets the log level and prints the message using JSON format.

package main

import(
	"github.com/rs/zerolog/log"
)

func main() {
	levels()
}

func levels() {
    // Panic of fatal messages stop the execution flow
    // log.Panic().Msg("This is a panic message")
    // log.Fatal().Msg("This is a fatal message")
    log.Error().Msg("This is an error message")
    log.Warn().Msg("This is a warning message")
    log.Info().Msg("This is an information message")
    log.Debug().Msg("This is a debug message")
    log.Trace().Msg("This is a trace message")
}
{"level":"error","time":"2020-09-18T17:51:49+02:00","message":"This is an error message"}
{"level":"warn","time":"2020-09-18T17:51:49+02:00","message":"This is a warning message"}
{"level":"info","time":"2020-09-18T17:51:49+02:00","message":"This is an information message"}
{"level":"debug","time":"2020-09-18T17:51:49+02:00","message":"This is a debug message"}
{"level":"trace","time":"2020-09-18T17:51:49+02:00","message":"This is a trace message"}

Change Log Levels

Not every execution requires the same level of logging. For example, you can go from a Debug level to a less verbose level like Info.

func setGlobalLevel() {
    zerolog.SetGlobalLevel(zerolog.DebugLevel)

    log.Debug().Msg("Debug message is displayed")
    log.Info().Msg("Info Message is displayed")

    zerolog.SetGlobalLevel(zerolog.InfoLevel)
    log.Debug().Msg("Degug message is no longer displayed")
    log.Info().Msg("Info message is displayed")
}

Notice that in the output the second debug message is ignored because we have upgraded the logging level.

{"level":"debug","time":"2020-09-18T17:54:44+02:00","message":"Debug message is displayed"}
{"level":"info","time":"2020-09-18T17:54:44+02:00","message":"Info Message is displayed"}
{"level":"info","time":"2020-09-18T17:54:44+02:00","message":"Info message is displayed"}

Structured Output

Because we are using the always-easy-to change JSON format, we can have additional fields in every logging entry apart from the textual message.

func structured() {
    log.Info().Str("mystr","this is a string").Msg("")
    log.Info().Int("myint",1234).Msg("")
    log.Info().Int("myint",1234).Str("str","some string").Msg("And a regular message")
}
{"level":"info","mystr":"this is a string","time":"2020-09-18T17:57:39+02:00"}
{"level":"info","myint":1234,"time":"2020-09-18T17:57:39+02:00"}
{"level":"info","myint":1234,"str":"some string","time":"2020-09-18T17:57:39+02:00","message":"And a regular message"}

Logging Errors

Logging errors is similar to adding extra fields as shown above.

func logError() {
    err := errors.New("there as an error")

    log.Error().Err(err).Msg("this is the way to log errors")
}
{"level":"error","error":"there as an error","time":"2020-09-18T17:58:35+02:00","message":"this is the way to log errors"}

Subloggers

We can have several log instances running simultaneously. This is particularly useful when we deploy new components in our code that require additional information to be displayed. In this example, we have a sublogger that always displays the name of the component.

func sublogger() {

    mainLogger := zerolog.New(os.Stderr).With().Logger()
    mainLogger.Info().Msg("This is the output from the main logger")

    subLogger := mainLogger.With().Str("component","componentA").Logger()
    subLogger.Info().Msg("This is the the extended output from the sublogger")
}
{"level":"info","message":"This is the output from the main logger"}
{"level":"info","component":"componentA","message":"This is the the extended output from the sublogger"}

File Output

The previous examples use the standard output. To store the output in a file, we only have to instantiate a logger with the descriptor of a new file.

func fileOutput() {
    // create a temp file
    tempFile, err := ioutil.TempFile(os.TempDir(),"deleteme")
    if err != nil {
        // Can we log an error before we have our logger? :)
        log.Error().Err(err).Msg("there was an error creating a temporary file four our log")
    }
    fileLogger := zerolog.New(tempFile).With().Logger()
    fileLogger.Info().Msg("This is an entry from my log")

    fmt.Printf("The log file is allocated at %s\n", tempFile.Name())
}
The log file is allocated at /var/folders/6h/xffhh45j077157cb5mbk48zh0000gp/T/deleteme981120707

The log is directly sent to a temporary file allocated at the temporary folder in the system.

Pretty Logging

Zerolog offers a decorator with a more visual output specially designed for consoles. I do recommend this option for command line interfaces (CLI).

func prettyConsole() {
    log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr})

    log.Error().Msg("This is an error message")
    log.Warn().Msg("This is a warning message")
    log.Info().Msg("This is an information message")
    log.Debug().Msg("This is a debug message")
}

Zerolog pretty console output

Summary

From a small project to a large solution, logs are always necessary. Zerolog has good performance and is easy to use. You have no excuses to use it in your projects from the very beginning and stop using print statements.

Thanks for reading.