Logging & Structured Logs

Metadata

1. Overview

What problem does it solve?

When you write a single application, print("User logged in") is enough to see what's happening. You can just tail the file on the server.

When you have 50 microservices running on 500 servers, processing 10,000 requests per second, a plain text print statement is useless. If a user complains their checkout failed, how do you find their specific error among 50 million lines of text spread across 500 hard drives?

Centralized, Structured Logging solves this by enforcing a machine-readable format (usually JSON) for all logs, automatically shipping them to a central database (like Elasticsearch), and allowing engineers to query them instantly.

What breaks without it?

• Blindness: When an outage happens at 3 AM, engineers have no idea why it's happening. Mean Time To Recovery (MTTR) skyrockets from 5 minutes to 5 hours.
• Lost Revenue: A silent bug might prevent 5% of users from checking out. Without logs, you won't know until users complain on Twitter.

2. Motivation

In the 2000s, sysadmins used tools like grep and awk to manually search through massive /var/log/syslog files.

As the Cloud and Microservices took over, servers became ephemeral (they scale up and down dynamically). If a server scales down, its local log files are deleted forever.

The industry needed to centralize logs. This birthed the ELK Stack (Elasticsearch, Logstash, Kibana) and SaaS products like Datadog and Splunk. However, parsing plain text with Regular Expressions (Regex) proved too slow and fragile. The industry shifted to Structured Logging, where applications write logs natively in JSON, so the logging database doesn't have to parse anything.

3. Real-World Usage

4. Prerequisites

5. Visual Explanation

Plain Text vs Structured

Plain Text Log: [INFO] 2024-04-25 10:15:32 - User 8475 purchased item 9912 for $45.00 in 120ms

Problem: To find all purchases over $40, you have to write a complex Regex to extract the number after the $ sign.

Structured Log (JSON):

{
  "level": "INFO",
  "timestamp": "2024-04-25T10:15:32Z",
  "event": "purchase_completed",
  "user_id": 8475,
  "item_id": 9912,
  "amount_usd": 45.00,
  "duration_ms": 120
}

Solution: The logging database instantly indexes the amount_usd field. You can query amount_usd > 40 in milliseconds.

Centralized Logging Architecture

%%{init: {'theme': 'base', 'themeVariables': { 'primaryColor': '#ffcc00', 'edgeLabelBackground':'#ffffff'}}}%%
graph TD
    classDef app fill:#f9f9f9,stroke:#333,stroke-width:2px;
    classDef agent fill:#d4edda,stroke:#28a745,stroke-width:2px;
    classDef db fill:#cce5ff,stroke:#007bff,stroke-width:2px;

    subgraph Server 1
        A1[App Instance 1]:::app -- "stdout (JSON)" --> FA1(Fluentd / Filebeat Agent):::agent
    end
    
    subgraph Server 2
        A2[App Instance 2]:::app -- "stdout (JSON)" --> FA2(Fluentd / Filebeat Agent):::agent
    end

    FA1 -- "Batches over HTTP/TCP" --> ES[(Elasticsearch Cluster)]:::db
    FA2 -- "Batches over HTTP/TCP" --> ES
    
    User[On-call Engineer] --> |"Query: user_id=123 AND level=ERROR"| Kibana[Kibana Dashboard]:::app
    Kibana --> ES

6. Internal Working

The Log Lifecycle

1. Emission: The application code uses a logging library (e.g., zap in Go, pino in Node.js, Logback in Java) to write JSON strings to stdout (standard output).
2. Collection (The Agent): A background process on the server (like FluentBit or Filebeat) reads the stdout stream. It never touches the application code.
3. Buffering: The agent batches the logs in memory or on disk to prevent overwhelming the network.
4. Shipping: The agent sends the batch over the network to the central aggregator.
5. Indexing: Elasticsearch receives the JSON, parses the keys, and builds an Inverted Index (making text searchable) and B-Trees (making numbers sortable).
6. Querying: Engineers use dashboards to visualize the data.

Log Levels

Logs must be categorized so you can filter out the noise.

• DEBUG: Extremely detailed info for local development. Never turned on in production (too expensive).
• INFO: Normal business events (e.g., user logged in, order placed).
• WARN: Something unexpected happened, but the system recovered (e.g., retry attempt 2 triggered).
• ERROR: A request failed. Requires investigation.
• FATAL / PANIC: The entire application crashed. Wakes up the on-call engineer instantly.

7. Implementation

Why Go? Go's standard library introduced log/slog (Structured Logging) natively in Go 1.21. Uber's zap logger for Go is also famous for pioneering zero-allocation, ultra-high-performance JSON logging.

/*
032 - Structured Logging
Demonstrates the difference between unstructured and structured logging,
using Go's built-in `log/slog` package.
*/
package main

import (
	"log"
	"log/slog"
	"os"
	"time"
)

func main() {
	// ── 1. The Old Way: Unstructured Plain Text ──
	
	userID := 8475
	itemID := 9912
	amount := 45.00
	duration := 120 * time.Millisecond

	log.Println("--- The Old Way (Plain Text) ---")
	// This is hard to parse and index in a database
	log.Printf("[INFO] User %d purchased item %d for $%.2f in %v", userID, itemID, amount, duration)


	// ── 2. The New Way: Structured JSON ──

	// Initialize a JSON handler writing to standard output
	logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
		Level: slog.LevelInfo, // Only log INFO and above (ignore DEBUG)
	}))

	// Set it as the default logger for the whole application
	slog.SetDefault(logger)

	log.Println("\n--- The New Way (Structured JSON) ---")

	// The message is static. The variables are passed as Key-Value pairs.
	slog.Info("purchase_completed",
		slog.Int("user_id", userID),
		slog.Int("item_id", itemID),
		slog.Float64("amount_usd", amount),
		slog.String("duration_ms", "120"),
	)

	// Simulating an Error
	slog.Error("payment_failed",
		slog.Int("user_id", userID),
		slog.String("gateway", "stripe"),
		slog.String("error", "insufficient_funds"),
	)

	// Simulating Debug (This will NOT print because we set LevelInfo above)
	slog.Debug("fetching_user_profile",
		slog.Int("user_id", userID),
	)
	
	// ── 3. Contextual Logging ──
	// In a real web server, you attach context (like a request ID) to the logger
	// so you don't have to pass it into every single function manually.
	
	reqLogger := logger.With(slog.String("request_id", "req-abc-123"))
	
	log.Println("\n--- Contextual Logger ---")
	reqLogger.Info("validating_cart")
	reqLogger.Info("applying_discount", slog.String("code", "SUMMER20"))
}

Sample Output

--- The Old Way (Plain Text) ---
2024/04/25 14:05:12 [INFO] User 8475 purchased item 9912 for $45.00 in 120ms

--- The New Way (Structured JSON) ---
{"time":"2024-04-25T14:05:12.123Z","level":"INFO","msg":"purchase_completed","user_id":8475,"item_id":9912,"amount_usd":45,"duration_ms":"120"}
{"time":"2024-04-25T14:05:12.123Z","level":"ERROR","msg":"payment_failed","user_id":8475,"gateway":"stripe","error":"insufficient_funds"}

--- Contextual Logger ---
{"time":"2024-04-25T14:05:12.123Z","level":"INFO","msg":"validating_cart","request_id":"req-abc-123"}
{"time":"2024-04-25T14:05:12.123Z","level":"INFO","msg":"applying_discount","request_id":"req-abc-123","code":"SUMMER20"}

Notice how the Contextual Logger automatically included the request_id in both log lines without us explicitly typing it the second time.

8. Complexity

9. Trade-offs

10. Production Evolution

11. Common Bugs

12. Interview Questions

1. Why is plain text logging an anti-pattern in microservices? Hint: You can't effectively search, filter, or index plain text across thousands of servers. JSON structured logging solves this.

2. What is Log Sampling and why is it necessary? Hint: Ingestion costs for tools like Splunk/Datadog are huge. Logging every successful HTTP request at scale is too expensive. We sample (log 1% of successful requests) to get statistical visibility while saving money.

3. What is the ELK stack? Hint: Elasticsearch (the database/search engine), Logstash (the agent that collects and parses logs), Kibana (the UI dashboard to query the logs).

13. Used By (Downstream Blocks)

• 033 Monitoring & Alerting — You can create alerts based on log metrics (e.g., "Page me if ERROR logs spike 500% in 1 minute").
• 034 Distributed Tracing — The next evolution of logging. Instead of isolated logs, you link logs across multiple microservices using a shared trace_id.

14. Used In (Case Studies)

15. Related Blocks

16. Try It Yourself

Exercise 1: PII Masking

Create a wrapper around the slog.Info function. If any of the provided keys are "password", "ssn", or "credit_card", replace the value with "***" before passing it to the actual logger.

Exercise 2: Pretty Console Output

Raw JSON is annoying to read during local development. Write a custom slog.Handler that checks os.Getenv("ENV"). If it's "production", output JSON. If it's "local", parse the attributes and print a colorful, human-readable plain text string using ANSI color codes.

Website Metadata