This blog provides information on how to add Uber-go Zap logger to a Golang project

This blog is part of the Golang series.

Table of Content

1.0 Introduction

In many Golang project, we need a good logger option that provides some of the following options

  • Ability to log events to a file, instead of application console.
  • Log Rotation – ability to rotate log files either based on file size, time or interval, etc.
  • Support different log levels. e.g INFO, DEBUG, ERROR, etc.
  • Should print basic information like calling file/function name and line number, time of log, etc.

2.0 Default Go Logger

Before we jump into Uber-go’s Zap package, let us first look at the basic log functionality that is provided by Golang out of the box.
The default logging package provide by Golang is https://golang.org/pkg/log/

2.1 Implementing Go Logger

Implementing a Golang logger is very simple – Create a new log file, and set it as log output location.

2.1.1 Setup up the Logger

We can setup the logger as shown below


func SetupLogger() {
logFileLocation, _ := os.OpenFile("/Users/in-sunit.chatterjee/test.log", os.O_CREATE|os.O_APPEND|os.O_RDWR, 0744)
log.SetOutput(logFileLocation)
}

view raw

SetupLogger.go

hosted with ❤ by GitHub

2.1.2 Using the Logger

Lets write some dummy code that will use the logger.
In our current example we will make a HTTP connection to an URL, and log either the status code / error to the log file.


func simpleHttpGet(url string) {
resp, err := http.Get(url)
if err != nil {
log.Printf("Error fetching url %s : %s", url, err.Error())
} else {
log.Printf("Status Code for %s : %s", url, resp.Status)
resp.Body.Close()
}
}

2.1.3 Logger in action

Now let’s execute above code and see the logger in action.

func main() {
	SetupLogger()
	simpleHttpGet("www.google.com")
	simpleHttpGet("http://www.google.com")
}

When we execute the above code, we can see a test.log created, and following lines added to the log file.

2019/05/24 01:14:13 Error fetching url www.google.com : Get www.google.com: unsupported protocol scheme ""
2019/05/24 01:14:14 Status Code for http://www.google.com : 200 OK

2.2 Pros and Cons of Go Logger

2.2.1 Pros

The biggest advantages is that it is very simple to use. We can set any io.Writer to log output and send write logs to it.

2.2.2 Cons

  • Basic Log Levels only
    • Only has one option for Print. Does not supports multiple levels like INFO/ DEBUG.
  • For Error logging, it has Fatal and Panic
    • Fatal Logging ends program by calling os.Exit(1)
    • Panic Logging throws a panic after writing the log message.
    • It however lacks a ERROR log level, that can log errors without throwing a panic or exiting the program.
  • Lacks log message formatting capabilities – e.g logging caller function name and line number, formatting the date and time format, etc.
  • Does not provides log rotation capabilities.

Top ∆

3.0 Uber-go Zap

Zap is blazing fast, structured, leveled logging in Go.

3.1 Why Uber-go zap

  • It provides both structured logging and printf style logging
  • It is supposedly very fast.

As per documentation by Uber-go Zap, it more performant than comparable structured logging packages — it’s also faster than the standard library.
Following is the benchmarking information published by Zap

Logging a message and 10 fields:

PackageTimeObjects Allocated
⚡️ zap3131 ns/op5 allocs/op
⚡️ zap (sugared)4173 ns/op21 allocs/op
zerolog16154 ns/op90 allocs/op
lion16341 ns/op111 allocs/op
go-kit17049 ns/op126 allocs/op
logrus23662 ns/op142 allocs/op

Logging a static string, without any context or printf-style templating:

PackageTimeObjects Allocated
⚡️ zap361 ns/op0 allocs/op
⚡️ zap (sugared)534 ns/op2 allocs/op
zerolog323 ns/op0 allocs/op
standard library575 ns/op2 allocs/op
go-kit922 ns/op13 allocs/op
lion1413 ns/op10 allocs/op
logrus2291 ns/op27 allocs/op

3.2 Installation

Install zap package by running below command

go get -u go.uber.org/zap

3.3 Setup up Zap Logger

Zap provides two types of loggers – Sugared Logger and Logger.

In contexts where performance is nice, but not critical, use the SugaredLogger. It’s 4-10x faster than other structured logging packages and supports both structured and printf-style logging.

In contexts where every microsecond and every allocation matter, use the Logger. It’s even faster than the SugaredLogger and allocates far less, but it only supports strongly-typed, structured logging.

3.3.1 Logger

  • Create a Logger, by calling zap.NewProduction() / zap.NewDevelopment() or zap.Example()
  • Each of the above will create a logger. The only difference is in the information it will log. e.g the production logger logs the calling function information, date and time, etc by default.
  • Call Info/Error, etc on the Logger.
  • By default the logs will come to the application console.


var logger *zap.Logger
func main() {
InitLogger()
defer logger.Sync()
SimpleHttpGet("www.google.com")
SimpleHttpGet("http://www.google.com")
}
func InitLogger() {
logger, _ = zap.NewProduction()
}
func SimpleHttpGet(url string) {
resp, err := http.Get(url)
if err != nil {
logger.Error(
"Error fetching url..",
zap.String("url", url),
zap.Error(err))
} else {
logger.Info("Success..",
zap.String("statusCode", resp.Status),
zap.String("url", url))
resp.Body.Close()
}
}

In the above code, we have first created a Logger , and then logged messages using the Logger methods like Info/ Error.

The syntax of the logger methods are like this.

func (log *Logger) MethodXXX(msg string, fields ...Field) 

where, MethodXXX is a Variadic function which can be Info / Error/ Debug / Panic, etc. Each of this method takes a message string, and any number of zapcore.Field arguments.
Each zapcore.Field is nothing but a key/value set of arguments.

If we run the above code, it will generate following output

{"level":"error","ts":1558882294.406781,"caller":"basiclogger/UberGoLogger.go:26","msg":"Error fetching url..","url":"www.google.com","error":"Get www.google.com: unsupported protocol scheme ""","stacktrace":"main.SimpleHttpGetnt/Users/in-sunit.chatterjee/learn/GitHub/go/src/LearningGo/examples/logger/basiclogger/UberGoLogger.go:26nmain.mainnt/Users/in-sunit.chatterjee/learn/GitHub/go/src/LearningGo/examples/logger/basiclogger/UberGoLogger.go:13nruntime.mainnt/usr/local/go/src/runtime/proc.go:201"}

{"level":"info","ts":1558882294.665447,"caller":"basiclogger/UberGoLogger.go:31","msg":"Success..","statusCode":"200 OK","url":"http://www.google.com"}

3.3.2 Sugared Logger

Now lets implement the same using a Sugared Logger.

  • Most of the implementation is almost the same.
  • The only difference is we fetch a SugaredLogger from the main logger by calling .Sugar() method on it.
  • Then use the SugaredLogger to log statements in printf style

Following is the modified code to use SugaredLogger instead of Logger.


var sugarLogger *zap.SugaredLogger
func main() {
InitLogger()
defer sugarLogger.Sync()
SimpleHttpGet("www.google.com")
SimpleHttpGet("http://www.google.com")
}
func InitLogger() {
logger, _ := zap.NewProduction()
sugarLogger = logger.Sugar()
}
func SimpleHttpGet(url string) {
sugarLogger.Debugf("Trying to hit GET request for %s", url)
resp, err := http.Get(url)
if err != nil {
sugarLogger.Errorf("Error fetching URL %s : Error = %s", url, err)
} else {
sugarLogger.Infof("Success! statusCode = %s for URL %s", resp.Status, url)
resp.Body.Close()
}
}

When you run the above code, you will see the following output

{"level":"info","ts":1558883371.550854,"caller":"basiclogger/UberGoLogger.go:27","msg":"Error fetching URL www.google.com : Error = Get www.google.com: unsupported protocol scheme """}

{"level":"info","ts":1558883371.77706,"caller":"basiclogger/UberGoLogger.go:29","msg":"Success! statusCode = 200 OK for URL http://www.google.com"}

As you can notice, both the loggers have so far printed output only in JSON structured format.

In the later part of this blog, we will look at SugaredLogger in more detail, and see how we can configure it further.

3.4 Customising the logger

3.4.1 Write to a File instead of console

The first change that we want to do is to write to a file instead of the application console.

  • Instead of creating the logger using a PRESET method like zap.NewProduction(), we will use zap.New(...) method and pass all the configurations manually.
func New(core zapcore.Core, options ...Option) *Logger

zapcore.Core, requires three things – Encoder, WriteSyncer, LogLevel

1. Encoder : An Encoder (how the logs will be written). We will use the out of box NewJSONEncoder(), and use the PRESET ProductionEncoderConfig().

zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())

2. WriterSyncer – specifies where the logs will be written to. We

file, _ := os.Create("./test.log")
writeSyncer := zapcore.AddSync(file)

3. Log Level, at which the logs will be written.

We will modify the Logger code from above section, and rewrite the InitLogger() method. The rest methods – main() / SimpleHttpGet() remains same.


func InitLogger() {
writerSyncer := getLogWriter()
encoder := getEncoder()
core := zapcore.NewCore(encoder, writerSyncer, zapcore.DebugLevel)
logger := zap.New(core)
sugarLogger = logger.Sugar()
}
func getEncoder() zapcore.Encoder {
return zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig())
}
func getLogWriter() zapcore.WriteSyncer {
file, _ := os.Create("./test.log")
return zapcore.AddSync(file)
}

When the main() function from the above section is called with these modified logger configurations then following output will be printed in the file – test.log

➜  LearningGo git:(master) ✗ cat test.log

{"level":"debug","ts":1558897671.680222,"msg":"Trying to hit GET request for www.google.com"}
{"level":"error","ts":1558897671.6803782,"msg":"Error fetching URL www.google.com : Error = Get www.google.com: unsupported protocol scheme """}
{"level":"debug","ts":1558897671.6803992,"msg":"Trying to hit GET request for http://www.google.com"}
{"level":"info","ts":1558897671.974973,"msg":"Success! statusCode = 200 OK for URL http://www.google.com"}

3.4.2 Change Json Encoder to Normal Log Encoder

We now want to change the encoder to a JSON Encoder to a normal Encoder. To do this, we need to change the NewJSONEncoder() to NewConsoleEncoder().

return zapcore.NewConsoleEncoder(zap.NewProductionEncoderConfig())

When the main() function from the above section is called with these modified logger configurations then following output will be printed in the file – test.log

➜  LearningGo git:(master) ✗ cat test.log
1.558898031797767e+09   debug   Trying to hit GET request for www.google.com
1.558898031797886e+09   error   Error fetching URL www.google.com : Error = Get www.google.com: unsupported protocol scheme ""
1.5588980317979e+09     debug   Trying to hit GET request for http://www.google.com
1.5588980320494049e+09  info    Success! statusCode = 200 OK for URL http://www.google.com

3.4.3 Change encoding for time and add caller details

With the change we had done to the configurations, there are two issues

  • Time is displayed in non human readable format. e.g 1.5588980320494049e+09
  • The caller functions details are not being shown in the logs

First thing we do is we will override the default ProductionConfig(), and make following changes

  • Change the Encoding for time.
  • Write the log level in capital letters in the log file.
func getEncoder() zapcore.Encoder {
	encoderConfig := zap.NewProductionEncoderConfig()
	encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
	encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
	return zapcore.NewConsoleEncoder(encoderConfig)
}

Next we will modify the zap logger code, to add the functionality to log calling function information. To do this we will add an Option to zap.New(..) function

logger := zap.New(core, zap.AddCaller())

When the main() function from the above section is called with these modified logger configurations then following output will be printed in the file – test.log

➜  LearningGo git:(master) ✗ cat test.log
2019-05-27T01:06:37.680+0530    DEBUG   basiclogger/UberGoLogger.go:47  Trying to hit GET request for www.google.com
2019-05-27T01:06:37.680+0530    ERROR   basiclogger/UberGoLogger.go:50  Error fetching URL www.google.com : Error = Get www.google.com: unsupported protocol scheme ""
2019-05-27T01:06:37.680+0530    DEBUG   basiclogger/UberGoLogger.go:47  Trying to hit GET request for http://www.google.com
2019-05-27T01:06:37.959+0530    INFO    basiclogger/UberGoLogger.go:52  Success! statusCode = 200 OK for URL http://www.google.com

4.0 Log Rotation using Lumberjack

The only thing missing in this logger is LOG ROTATION functionality.

Zap doesn’t natively support rotating log files

To add log rotation functionality, we will add Lumberjack support to Logger.

4.1 Installation

To install Lumberjack, we will run following command

go get -u github.com/natefinch/lumberjack

4.2. Adding lumberjack support to zap logger

To add Lumberjack support to Zap, we need to modify the WriteSyncer code. We will modify the getLogWriter() function as shown below

func getLogWriter() zapcore.WriteSyncer {
	lumberJackLogger := &lumberjack.Logger{
		Filename: "./test.log",
		MaxSize: 10,
		MaxBackups: 5,
		MaxAge: 30,
		Compress: false,
	}
	return zapcore.AddSync(lumberJackLogger)
}

Lumberjack Logger takes following attributes as input

  • Filename : location of log file
  • MaxSize : maximum size of log file in MBs, before it is rotated
  • MaxBackups : maximum no. of old files to retain
  • MaxAge : maximum number of days it will retain old files
  • Compress : whether to compress/archive old files.

4.3 Testing it all together

After all the above changes the Zap/Lumberjack logger code will look something like this.


var sugarLogger *zap.SugaredLogger
func main() {
InitLogger()
defer sugarLogger.Sync()
SimpleHttpGet("www.google.com")
SimpleHttpGet("http://www.google.com")
}
func InitLogger() {
writerSyncer := getLogWriter()
encoder := getEncoder()
core := zapcore.NewCore(encoder, writerSyncer, zapcore.DebugLevel)
logger := zap.New(core, zap.AddCaller())
sugarLogger = logger.Sugar()
}
func getEncoder() zapcore.Encoder {
encoderConfig := zap.NewProductionEncoderConfig()
encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder
return zapcore.NewConsoleEncoder(encoderConfig)
}
func getLogWriter() zapcore.WriteSyncer {
lumberJackLogger := &lumberjack.Logger{
Filename: "./test.log",
MaxSize: 10,
MaxBackups: 5,
MaxAge: 30,
Compress: false,
}
return zapcore.AddSync(lumberJackLogger)
}
func SimpleHttpGet(url string) {
sugarLogger.Debugf("Trying to hit GET request for %s", url)
resp, err := http.Get(url)
if err != nil {
sugarLogger.Errorf("Error fetching URL %s : Error = %s", url, err)
} else {
sugarLogger.Infof("Success! statusCode = %s for URL %s", resp.Status, url)
resp.Body.Close()
}
}

When above code is executed, it will show following logs in output file – test.log

2019-05-27T01:22:20.197+0530    DEBUG   basiclogger/UberGoLogger.go:52  Trying to hit GET request for www.google.com
2019-05-27T01:22:20.198+0530    ERROR   basiclogger/UberGoLogger.go:55  Error fetching URL www.google.com : Error = Get www.google.com: unsupported protocol scheme ""
2019-05-27T01:22:20.198+0530    DEBUG   basiclogger/UberGoLogger.go:52  Trying to hit GET request for http://www.google.com
2019-05-27T01:22:20.392+0530    INFO    basiclogger/UberGoLogger.go:57  Success! statusCode = 200 OK for URL http://www.google.com

With this we conclude our blog on how to integrate Zap logger in a Go application project.