In Go version 1.21 or above, there is a new standard library feature called structured logging (Slog). Just like its name, Slog helps us record our output in a more well-defined format (usually JSON), which adds a level of organization and consistency to application logs, making them easier to process. The log bounded into Key-Value pair logging pattern, it will help us enable rapid parsing, filtering, and analysis of logs, addressing the crucial need for efficient debugging.

Photo by Maarten van den Heuvel on Unsplash

Why Slog?

As you know, there were many other logging libraries in Go such as Zap, Zerolog, Logrus, etc. But Why Slog?

Ease of use. Slog has implemented express key-value pairs logging method, so the implementation was concise and easy to understand for programmer
High performance. The API has been designed to minimize allocation and locking. It provides an alternative to alternating keys and values that is more cumbersome but faster (similar to Zap’s Fields).
Integration with runtime tracing. The Go team is developing an improved runtime tracing system. Logs from this package will be incorporated seamlessly into those traces, giving developers the ability to correlate their program’s actions with the behavior of the runtime.

But we also can integrate with 3rd party logging library, and let’s discuss this in next section.

How Slog Works?

From the above diagram, we divide it into 2 sides, Input and Output.

The Slog Input is the API provided by slog to users. Unfortunately, Slog still does not extract the Logger interface like log package. Instead, it defines a Logger structure and provides the methods as shown in logger.go . This means we still impossible to unify the input API.

Through the input method, slog encapsulates the log content and related attribute information into a slog.Record type instance, and then passes it to the output of slog.

If you are using the 3rd party log package and you want to use the slog output, you will need to encapsulate it so it can output slog.Record and pass it to the slog backend, Here’s example for Zap, more detail regarding the PR.

The existence of Slog handler interface makes the output of Slog more scalable. In addition to using the two built-in Handler implementations provided by Slog: TextHandler and JSONHandler, we can also define or completely customize the backend Handler based on the third-party log package.

Slog has built-in two most commonly used Handlers: TextHandler and JSONHandler. As the name, TextHandler outputs the log as a line of text like the standard library log package; while JSONHandler outputs the log content and various attributes in JSON format.

Introduction — Input

I know its really cool, let’s dive in regarding how to use Slog start from user input side first.

For use it, you can import it directly for go version 1.21 / above

import "log/slog"

Or you can get it with this command

go get golang.org/x/exp/slog

The log/slog package provides structured logging functionality, where logging includes time, log level, message, and various other attributes represented as key-value pairs.

The log/slog package defines a Logger structure, which provides several methods for printing logs of different levels. Each Logger is associated with a Handler. The Logger’s print log method creates a log based on the parameters and passes it to the Handler. The Handler decides how to process the log. The log printing functions provided by the log/slog package, such as Info, Warn, Error, Debug are implemented by calling the relevant methods in the default Logger.

package main

import (
 "log/slog"
)

func main() {
 slog.Info("Hello World", "value", 1)
}

$ go run main.go
2023/09/10 10:31:23 INFO Hello World value=1

A log record consists of a time, level, message, and a set of key-value pairs, where the key is a string and the value can be of any type.

The Info function is implemented by calling the relevant methods of the default Logger. Let’s take a look at the definition of the Info function：

NB: the related code for below can be found in here:

// Info calls Logger.Info on the default logger.
func Info(msg string, args ...any) {
 Default().log(context.Background(), LevelInfo, msg, args...)
}

We can see that the log method in the Logger object returned by the Default function. The Default function is defined as follows:

func Default() *Logger { return defaultLogger.Load().(*Logger) }

defaultLogger is type of atomic.Value, which stores the default Logger type. This default Logger type is stored through the init function. The init function is defined as follows:

func init() {
 defaultLogger.Store(New(newDefaultHandler(loginternal.DefaultOutput)))
}

The default Logger functions for printing logs include Debug, Warn and Error. In addition to these convenient functions, there is also a Log function that accepts a log level parameter. Let’s take a look at a below example:

package main

import (
	"context"
	"log/slog"
)

func main() {
	slog.Log(context.Background(), slog.LevelInfo, "Hello World", "value", 1)
}

$ go run main.go
2023/09/10 11:21:13 INFO Hello World value=1

We can see that the effect is the same as calling the Info function directly.

Besides of Info function, there are some other Logger type as below:

type Logger struct {
 handler Handler // for structured logging
}

And for the default Slog level is defined into 4 type: Debug, Info, Warn, Error. For more detail can see here

We also have Attr fields that was key-value pair that helps us doing logging more cleanable. The Attr fields also support multiple type to do the logging, to stay updated kindly refer to here:

String 
Int64 
Int 
Uint64 
Float64 
Bool 
Time 
Duration

Example:

package main

import (
 "log/slog"
 "os"

 "github.com/google/uuid"
)

func main() {
 textHandler := slog.NewTextHandler(os.Stdout, nil)
 logger := slog.New(textHandler)

 // Generate a new random UUID
 newUUID := uuid.New()
 // Convert the UUID to a string
 uuidString := newUUID.String()

 logger.Info("Sample Request",
 slog.String("request-id", uuidString),
 slog.Int("value", 123),
 slog.String("ip", "127.0.0.1"),
 )
}

$ go run main.go
time=2023-09-10T23:00:00.000Z level=INFO msg="Sample Request" request-id=0757130c-43c6-4b1b-9234-da16116e7fe4 value=123 ip=127.0.0.1

Also we can group attributes under a single key

package main

import (
 "log/slog"
 "os"

 "github.com/google/uuid"
)

func main() {
 textHandler := slog.NewTextHandler(os.Stdout, nil)
 logger := slog.New(textHandler)

 // Generate a new random UUID
 newUUID := uuid.New()
 // Convert the UUID to a string
 uuidString := newUUID.String()

 logger.Info("Sample Request",
 slog.String("request-id", uuidString),
 slog.Group("datas",
 slog.Int("value1", 10),
 slog.String("value2", "sampledata"),
 slog.Bool("value3", false)),
 slog.String("ip", "127.0.0.1"),
 )
}

$ go run main.go
time=2023-09-10T23:00:00.000Z level=INFO msg="Sample Request" request-id=ada8c841-230c-45c5-9fd7-34793e9fed3b datas.value1=10 datas.value2=sampledata datas.value3=false ip=127.0.0.1

Introduction — Output

By default there are two recording formats that provided by Slog: text and JSON.

Text Handler
Let’s create one text handler and one new logger.

package main 
 
import ( 
 "os" 
 "log/slog"
) 
 
func main() { 
 textHandler := slog.NewTextHandler(os.Stdout, nil) 
 logger := slog.New(textHandler) 
 
 logger.Info("Hello World") 
}

$ go run main.go
2023/09/10 11:40:32 INFO msg="Hello World"

We can see that logs are output in the form of key-value pairs. This is often called the logfmt format. Many log analysis tools can handle logs in logfmt format. Logfmt is also a human-readable log format.

JSON Handler

package main 
 
import ( 
 "os" 
 "log/slog"
) 
 
func main() { 
 jsonHandler := slog.NewJSONHandler(os.Stdout, nil) // The Diff is in here
 logger := slog.New(jsonHandler) 
 
 logger.Info("Hello World") 
}

$ go run main.go
{"time":"2023-09-10T11:42:18.245678+07:00","level":"INFO","msg":"Hello World"}

Customized Usage

Fun enough right? I also created more customized usage in my project, Repo link Click Here. Anw Please give me a star if feel useful. haha

In Summary Here’s What i’m Doing

logger.go:
- Defines a configuration struct Config for logging settings.
- Defines a sub-configuration struct GrayScaleConfig for grayscale logging settings.
- Defines a RequestLogger struct that includes a logger and its configuration.
- Defines option functions to configure the RequestLogger.
- Provides a NewRequestLogger function to create a new logger instance with specified options.

agent.go:
- Provides methods for logging messages based on different log levels.
- Implements grayscale logging and custom log levels.
- Determines whether a log message should be logged based on configuration.

attribute_builder.go:
- Defines an AttributeBuilder struct for creating log attributes.
- Provides methods to add various types of attributes (string, int, duration, bool, map).
- Allows building a slice of log attributes.

helper.go:
- Provides helper functions related to HTTP status codes and request ID generation.
- Determines the log level based on HTTP status codes.
- Generates a unique request ID if configured.
- Writes log messages to a file if text log writing is enabled.

gin/gin.go:
- Implements a request logger specifically for the Gin web framework.
- Defines a GinRequestLogger struct that wraps a general RequestLogger.
- Provides middleware for Gin that logs HTTP requests.
- Sets response headers and logs request attributes.
- Integrates with the general RequestLogger for log writing.

Okay, lets dive in one by one.

logger.go

this file is use for file initialization of Slog. and in here i wrapped it with slog.Logger struct and have some configuration


type Config struct {
 WithRequestID bool
 LogFilePaths map[slog.Level]string
 EnableWriteTxtLog bool
 CustomLogLevels []slog.Level
 GrayScale GrayScaleConfig
 mu sync.Mutex
}

type GrayScaleConfig struct {
 Enabled bool
 Threshold int
 Percentage int
 TotalRequests int
 TotalRequestsMux sync.Mutex
}

type RequestLogger struct {
 Logger *slog.Logger
 Config Config
}


func NewRequestLogger(logger *slog.Logger, options ...Option) (*RequestLogger, error) {
 rl := &RequestLogger{
 Logger: logger,
 }

 for _, option := range options {
 option(rl)
 }

 return rl, nil
}

i’m using optional function parameter pattern so we can dynamically set the value, Example:


type Option func(*RequestLogger)

func WithRequestID() Option {
 return func(rl *RequestLogger) {
 rl.Config.WithRequestID = true
 }
}

agent.go

in this file i more likely doing things that customized like greyscale logging, and customized log.

package logger

import "log/slog"

const (
 LevelSamplingDebug = slog.Level(-8)
)

func (rl *RequestLogger) Log(level slog.Level, msg string, attrs ...slog.Attr) {
 if level != LevelSamplingDebug {
 rl.WriteLogIntoTxt(level, msg, attrs...)
 } else if rl.shouldLog(level) {
 rl.WriteLogIntoTxt(level, msg, attrs...)
 }
}

func (rl *RequestLogger) shouldLog(level slog.Level) bool {
 for _, customLevel := range rl.Config.CustomLogLevels {
 if level == customLevel {
 if rl.Config.GrayScale.Enabled {
 if rl.isGrayScaleRequest() {
 return true
 }
 return false
 }
 return true
 }
 }
 return false
}

func (rl *RequestLogger) isGrayScaleRequest() bool {
 rl.Config.GrayScale.TotalRequestsMux.Lock()
 defer rl.Config.GrayScale.TotalRequestsMux.Unlock()

 totalRequests := rl.Config.GrayScale.TotalRequests
 grayScaleThreshold := rl.Config.GrayScale.Threshold
 grayScalePercentage := rl.Config.GrayScale.Percentage

 if totalRequests > 0 && grayScaleThreshold > 0 {
 percentage := (totalRequests * 100) / grayScaleThreshold
 return percentage <= grayScalePercentage
 }
 return false
}

The reason i create new level slog because i don’t want it merge with normal debug level since it was for sampling — and it can be 100% disabled in Production ENV to reduce storage usage. And also we can enabled it to do debugging in Production ENV with grayscale / fully log implementation.

attribute_builder.go

As it’s name, i’m implementing Builder Pattern for helping agent.go to create it’s attribute.

package logger

import (
 "log/slog"
 "time"
)

type AttributeBuilder struct {
 attrs []slog.Attr
}

func NewAttributeBuilder(RequestId string) *AttributeBuilder {
 return &AttributeBuilder{
 []slog.Attr{
 slog.String("request-id", RequestId),
 },
 }
}

func (b *AttributeBuilder) WithString(key string, value string) *AttributeBuilder {
 b.attrs = append(b.attrs, slog.String(key, value))
 return b
}

func (b *AttributeBuilder) WithInt(key string, value int) *AttributeBuilder {
 b.attrs = append(b.attrs, slog.Int(key, value))
 return b
}

func (b *AttributeBuilder) WithDuration(key string, value time.Duration) *AttributeBuilder {
 b.attrs = append(b.attrs, slog.Duration(key, value))
 return b
}

func (b *AttributeBuilder) WithBool(key string, value bool) *AttributeBuilder {
 b.attrs = append(b.attrs, slog.Bool(key, value))
 return b
}

func (b *AttributeBuilder) WithMap(key string, values map[string]string) *AttributeBuilder {
 for k, v := range values {
 b.attrs = append(b.attrs, slog.String(k, v))
 }
 return b
}

func (b *AttributeBuilder) Build() []slog.Attr {
 return b.attrs
}

helper.go

this file basically helper for generating request id, write log into txt file, determine http log level. the reason i’m doing this is more likely Single-responsibility principle

package logger

import (
 "fmt"
 "log/slog"
 "net/http"
 "os"

 "github.com/google/uuid"
)

const (
 StatusOK = http.StatusOK
 StatusCreated = http.StatusCreated
 StatusAccepted = http.StatusAccepted
 DefaultLogPath = "log.txt"
)

func (rl *RequestLogger) DetermineHttpLogLevel(status int) slog.Level {
 switch {
 case status == StatusOK ||
 status == StatusCreated ||
 status == StatusAccepted:
 return slog.LevelInfo
 default:
 return slog.LevelError
 }
}

func (rl *RequestLogger) GenerateRequestID() (string, error) {
 if rl.Config.WithRequestID {
 id, err := uuid.NewRandom()
 if err != nil {
 return "", err
 }
 return id.String(), nil
 }
 return "", nil
}

func (rl *RequestLogger) WriteLogIntoTxt(level slog.Level, msg string, attrs ...slog.Attr) {
 if rl.Config.EnableWriteTxtLog {
 logFileDir, ok := rl.Config.LogFilePaths[level]
 if !ok || logFileDir == "" {
 logFileDir = DefaultLogPath
 }

 file, err := os.OpenFile(logFileDir, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
 if err == nil {
 defer file.Close()
 logLine := fmt.Sprintf("[%s] %s", level, msg)
 for _, attr := range attrs {
 logLine += " " + fmt.Sprint(attr)
 }
 logLine += "\n"

 file.WriteString(logLine)
 }
 }
}

gin/gin.go

the reason i split it into another directory is because i want more flexibility in define new middleware in the future without function name conflict, so for example i’m adding new middleware like echo / something else i only need create new folder like echo/echo.go instead. this file i’m implementing middleware logging for gin http routing. in another words, all of request that have been done would be logged with my custom defined slog struct implementation.

package gin

import (
 "log/slog"
 "time"

 "github.com/gin-gonic/gin"

 "scalable-go-movie/middleware/logger"
)

type GinRequestLogger struct {
 *logger.RequestLogger
}

func NewGinRequestLogger(rl *logger.RequestLogger) *GinRequestLogger {
 return &GinRequestLogger{
 RequestLogger: rl,
 }
}

func (grl *GinRequestLogger) Middleware() gin.HandlerFunc {
 return func(c *gin.Context) {
 start := time.Now()
 path := c.Request.URL.Path

 requestID, _ := grl.RequestLogger.GenerateRequestID()
 grl.setHeader(c, requestID)

 defer func() {
 end := time.Now()
 latency := end.Sub(start)

 level := grl.RequestLogger.DetermineHttpLogLevel(c.Writer.Status())
 attrs := grl.buildAttributes(c, path, requestID, latency, level)
 grl.LogWithContext(c, level, "request:", attrs...)
 }()

 c.Next()
 }
}

func (rl *GinRequestLogger) setHeader(c *gin.Context, requestID string) {
 if rl.Config.WithRequestID {
 c.Header("X-Request-ID", requestID)
 }
}

func (grl *GinRequestLogger) buildAttributes(c *gin.Context, path, requestID string, latency time.Duration, level slog.Level) []slog.Attr {
 var GinRequestID string
 if grl.Config.WithRequestID {
 GinRequestID = requestID
 }
 attrs := logger.NewAttributeBuilder(GinRequestID).
 WithInt("status", c.Writer.Status()).
 WithString("method", c.Request.Method).
 WithString("path", path).
 WithDuration("latency", latency).
 WithString("user-agent", c.Request.UserAgent()).
 Build()
 return attrs
}

func (grl *GinRequestLogger) LogWithContext(c *gin.Context, level slog.Level, msg string, attrs ...slog.Attr) {
 grl.RequestLogger.WriteLogIntoTxt(level, msg, attrs...)
 grl.Logger.LogAttrs(c, level, msg, attrs...)
}

func (rl *GinRequestLogger) GetRequestID(c *gin.Context) string {
 if rl.Config.WithRequestID {
 return c.GetHeader("X-Request-ID")
 }
 return ""
}

I hope you can use this as a reference in your future development. If you have any questions, you can reach me on my linkedin. Thanks for reading, and have a great day!

Structured Logging In Go 1.21