>_
GolangStepByStep
Software Engineer

Structured Logging

Log levels, correlation IDs, JSON logs, observability

# What is Structured Logging? (The Sticky Note Analogy)

Imagine you run a giant warehouse. Hundreds of employees process thousands of packages an hour.

Unstructured Logging is like asking your employees to just write a quick sentence on a sticky note every time they touch a package: "Moved a big box to aisle 5," or "Alice dropped package 9283."If you lose a package and have to search through 10,000 messy sticky notes varying in handwriting and grammar, you are doomed.

Structured Logging is like forcing your employees to fill out a strict, digital form. {Action: "Moved", Employee: "Alice", PackageID: 9283, Aisle: 5}. Now, finding the lost package takes exactly zero seconds; you just filter by PackageID == 9283 in your database.

# Level 1: The Old Way vs The New Way (Beginner)

For a decade, Go developers used the standard log package. It spat out raw text strings. If you wanted to include variables, you interpolated them into a string.

import "log"

func ProcessPayment(userID int, amount int) {
    // The Old Way (Unstructured Text)
    // Output: 2024/05/12 10:00:00 Payment processed for user 42 for $100
    log.Printf("Payment processed for user %d for $%d", userID, amount)
}

In Go 1.21, the language finally introduced slog (Structured Logging). Instead of baking variables into a sentence, you pass them as separate key/value pairs!

import "log/slog"

func ProcessPayment(userID int, amount int) {
    // The New Way (Structured Properties)
    // Output: 2024/05/12 10:00:00 INFO Payment processed user_id=42 amount=100
    slog.Info("Payment processed", "user_id", userID, "amount", amount)
}

# Level 2: Logging for Machines (Intermediate)

The real power of structured logging is that we can instantly swap how it formats the output. If we are reading the terminal, text is nice. But if we are sending our output to Datadog, AWS CloudWatch, or Splunk, we want the logs formatted as strict JSON.

We do this by attaching a JSONHandler to the logger.

package main

import (
    "log/slog"
    "os"
)

func main() {
    // 1. Create a JSON Formatter that outputs to standard out
    handler := slog.NewJSONHandler(os.Stdout, nil)
    
    // 2. Build a logger
    logger := slog.New(handler)
    
    // 3. Make this logger the default for the whole app!
    slog.SetDefault(logger)

    // Action!
    slog.Warn("Disk space is low", "disk", "C:/", "free_mb", 500)
}
// OUTPUT:
// {"time":"2023-11-09T15:04:05Z","level":"WARN","msg":"Disk space is low","disk":"C:/","free_mb":500}

Why? The JSON output above can be instantly filtered by external observability systems. You can literally run a query like: "Show me all logs where `level == WARN` and `free_mb < 1000`" and get results instantly!

# Level 3: Context and Correlation IDs (Advanced)

In a busy server, 500 users might be logging in at the exact same second. If an error happens midway through a database call, how do you know which of the 500 users triggered the database error?

In modern systems, the second a request hits your router, you generate a random string called a Correlation ID (or Request ID). You immediately attach this ID to the request's Context, and pass that Context down into all your database and worker functions.

// A custom logger that accepts a Context
func (l *MyLogger) InfoCtx(ctx context.Context, msg string, args ...any) {
    // Attempt to extract our tracing ID from the context
    if reqID, ok := ctx.Value("request_id").(string); ok {
        // Automatically inject the request ID into the log!
        args = append(args, slog.String("req_id", reqID))
    }
    
    // Call standard slog
    slog.Info(msg, args...)
}

func UpdateDatabase(ctx context.Context, query string) {
    // Later, deep in our database package:
    logger.InfoCtx(ctx, "Updating table...", "table", "users")
}

// OUTPUT:
// {"msg":"Updating table...","table":"users","req_id":"ab8x-91je"}

# Level 4: Log Levels and Environment Contexts (Expert)

In local development, you want your terminal to flood with information—SQL queries, debug steps, HTTP headers. In production, printing millions of debug lines a minute will bankrupt you in log storage costs.

We separate this using Log Levels and Environment-based setup.

func InitLogger(env string) {
    var handler slog.Handler

    if env == "production" {
        // PRODUCTION: JSON formatting, WARNING level and above only!
        handler = slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
            Level: slog.LevelWarn,
        })
    } else {
        // LOCAL DEV: Pretty text output, DEBUG level!
        handler = slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
            Level: slog.LevelDebug,
        })
    }

    slog.SetDefault(slog.New(handler))
}

func main() {
    InitLogger("production")

    slog.Debug("This will NOT print in production!")
    slog.Warn("This WILL print!")
}
practice & review