Handle zap log messages in a test

Zap is one of the most used log libraries for Golang. It is easy, rich and faster, but how to handle the messages logged from zap in our tests?

*all examples are tested with the Zap 1.16.0 and Golang 1.16.2.

If you wondering learn about Zap follow the project on Github.

uber-go/zap

Let’s go!

zaptest != observer

Firstly, Zap has a package called zaptest, this package is used to insert log messages in test functions that use the standard test library (using *testing.T or *testing.B). THIS IS NOT WHAT WE WANT HERE!!!

To handle the log messages from our functions is necessary to use the package observer, described in the documentation as

Package observer provides a zapcore.Core that keeps an in-memory, encoding-agnostic representation of log entries. It’s useful for applications that want to unit test their log output without tying their tests to a particular output encoding.

Let’s go to the examples!

Observing the message

The code above just create a “zap example” and pass it as argument to the function myFunction. This is just a example, you can use different approach here, something like a struct with a field or global variable, follow your heart. But keep in mind that you will change the zapcore default with a core from package observer, for this reason you can’t create the logger and trigger the message in the same function.

func main() {
    logger := zap.NewExample()
    logger.Info("log myFunction")
    // Sorry, you can't test this message with pkg observer =/
}

Testing myFunction:

In this test is created a new zap core with the pkg observer (line 14) and used it to create a new zap instance (line 15). This instance is passed to myFunction (line 18) and all logs are inserted in the variable observedLogs. Finally the logs are “tested” in the lines 21 and 23.

TIP: using testify require you can prevent a panic error, is better to check the length of observedLogs and stop the test if there’re not the expected number of logs.

Handling log with custom fields

In the example above are created 2 log messages, the second use custom fields inside .With(...) . Checking this fields in the test:

The custom fields can be asserted by the field .Context of observed log.

Handling log created by “Zap Sugared”

Zap has a mode “Sugar” that turn more easy and practical the use of the library. Using this the assertion will be a little bit different.

In the test you just need to declare explicitly the type of the field, that here are strings.

Some notes

1. Using the observer you can run tests without mocking the logs messages.
2. Check the log level passed to create the observed core, if you need to handle debug entries use observer.New(zap.DebugLevel).
3. Handling .Fatal messages can be a problem, because this kind of entry trigger a exit(1). Is possible to use the option OnFatal to change this behavior. Check the documentation and this issue closed about it.
4. To handle .Panic messages you need to create some strategy with a Recover() to continue the test without a stop.