Logging in Go: Tips and Tricks for Effective Logging

Logging is an essential part of any software application. It helps developers understand what’s happening inside the application when it’s running, diagnose issues, and monitor performance. In this article, we’ll explore some best practices for logging in Go, including choosing the right log level, structuring log messages, and more.

1. Why logging is important in Go

Logging is an essential tool for developers to understand what’s happening inside an application at runtime. Without logs, it can be challenging to diagnose issues or understand why an application is not performing as expected. Go has a built-in logging package called log that makes it easy to log messages to the console or a file.

package main

import (
	"log"
	"net/http"
)

func main() {
	// Set up a simple HTTP server
	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
		log.Printf("%s %s %s", r.RemoteAddr, r.Method, r.URL)
		w.Write([]byte("Hello, world!"))
	})
	err := http.ListenAndServe(":8080", nil)
	if err != nil {
		log.Fatalf("Failed to start server: %v", err)
	}
}

In this code, we have a simple HTTP server that responds to requests with “Hello, world!” and logs the incoming request's details to the console using the built-in log package. This logging allows us to see what requests are being made to our server, including the remote IP address, HTTP method, and URL. If we encounter any errors while starting the server, we log a fatal message that will cause the program to exit.

Without logging, it would be difficult to know if our server is receiving requests, what requests it's receiving, and whether it's encountering any errors. Logging provides valuable insight into the inner workings of our application and helps us diagnose issues quickly.

2. Choosing the right log level

Go’s logging package allows developers to specify different log levels, including debug, info, warning, error, and fatal. It’s essential to choose the right log level based on the severity of the message. Debug messages should be used for detailed information about what’s happening inside the application, while error messages should be reserved for critical issues that require immediate attention.

package main

import (
    "log"
)

func main() {
    log.Println("Starting application...")
    
    // Some code that generates debug messages
    for i := 0; i < 10; i++ {
        log.Printf("Debug message #%d", i)
    }
    
    // Some code that generates warning messages
    for i := 0; i < 5; i++ {
        log.Printf("Warning message #%d", i)
    }
    
    // Some code that generates an error message
    err := someFunctionThatMightFail()
    if err != nil {
        log.Fatalf("Error: %v", err)
    }
    
    log.Println("Application completed successfully.")
}

func someFunctionThatMightFail() error {
    // Some code that might fail
    return nil
}

In this example, we start by logging a message indicating that the application is starting up. Then, we have some code that generates debug messages, which provide detailed information about what's happening inside the application. We also have some code that generates warning messages, which are less severe than errors but still indicate that something might be wrong. Finally, we have some code that generates an error message, which is used to report critical issues that require immediate attention. If an error occurs, the log.Fatalf() function is used to log the error message and exit the application.

By using different log levels for different types of messages, we can more easily identify and diagnose issues in our application.

3. Structuring log messages

Log messages should be structured in a way that makes it easy to understand what’s happening inside the application. A best practice is to include relevant information, such as the module or package that generated the log message, a timestamp, and the severity level. Here’s an example of a well-structured log message in Go:

package main

import (
	"log"
	"time"
)

func main() {
	// set log prefix
	log.SetPrefix("MYAPP: ")

	// set log flags to include timestamps
	log.SetFlags(log.Ldate | log.Ltime)

	// simulate an error
	err := someFunction()

	// log the error message
	log.Printf("Error occurred in someFunction(): %v", err)
}

func someFunction() error {
	// simulate an error
	return nil
}

In this example, we've used the log.SetPrefix() function to set a prefix for all log messages. This can be helpful in identifying which application or module the log message came from.

We've also used the log.SetFlags() function to include a timestamp in all log messages. This can be helpful in identifying when a particular event occurred.

Finally, we've used the log.Printf() function to log an error message, including the relevant information about where the error occurred and the error message itself.

By structuring log messages in this way, it becomes much easier to understand what's happening inside the application when reviewing log files.

4. Using log rotation

As applications run for extended periods, log files can become quite large, making them challenging to manage. Log rotation is a technique used to manage log files by creating new files and deleting old ones. Go’s logging package supports log rotation out-of-the-box, making it easy to manage log files.

package main

import (
	"log"
	"os"
	"time"
	"gopkg.in/natefinch/lumberjack.v2"
)

func main() {
	// Create a new logger that rotates the log file
	logger := &lumberjack.Logger{
		Filename:   "/var/log/myapp.log",
		MaxSize:    10, // Max size in megabytes
		MaxBackups: 3,  // Max number of old log files to keep
		MaxAge:     28, // Max age in days
		Compress:   true,
	}

	// Set the logger for the standard logger
	log.SetOutput(logger)

	// Write some log messages
	log.Println("This is a log message")
	log.Printf("This is a formatted log message with a timestamp: %s\n", time.Now().Format("2006-01-02 15:04:05"))
	
	// Close the logger when the program exits
	defer logger.Close()
}

In this example, we're using the lumberjack package to rotate the log file. We're specifying that we want to rotate the log file when it reaches a certain size (MaxSize), keep a certain number of old log files (MaxBackups), and delete log files older than a certain age (MaxAge).

We're also setting the logger for the standard logger using log.SetOutput(), so that any calls to log will write to the rotated log file.

Finally, we're using defer to ensure that the logger is closed when the program exits, so that any remaining log messages are written to the log file before the program terminates.

5. Monitoring logs with a centralized system

As applications scale, it can be challenging to manage logs on individual machines. A centralized logging system can help developers manage logs effectively by aggregating logs from multiple machines and making them searchable. Popular centralized logging systems for Go include Logstash, Fluentd, and Graylog.

In this example, we're using the Elasticsearch Go client to send log entries to a Logstash instance. We create a logger object using the built-in log package and log a message. We then use the Elasticsearch Go client to create an index and send the log entry to Elasticsearch. From there, the log can be easily monitored using Kibana, which is part of the Elastic Stack:

package main

import (
	"log"
	"os"

	"github.com/elastic/go-elasticsearch/v7"
	"github.com/elastic/go-elasticsearch/v7/esapi"
)

func main() {
	// create Elasticsearch client
	es, err := elasticsearch.NewDefaultClient()
	if err != nil {
		log.Fatalf("Error creating the client: %s", err)
	}

	// create log entry
	logger := log.New(os.Stdout, "example", log.LstdFlags)
	logger.Println("This is an example log message.")

	// create Elasticsearch index
	indexName := "example-index"
	req := esapi.IndexRequest{
		Index:      indexName,
		DocumentID: "1",
		Body:       nil,
	}
	res, err := req.Do(context.Background(), es)
	if err != nil {
		log.Fatalf("Error getting response: %s", err)
	}
	defer res.Body.Close()
}