[ENHANCEMENT] Add Structured Logging with Log Levels

[1234-ad]

🔧 Enhancement: Add Structured Logging with Log Levels

Description

The current logging implementation uses simple fmt.Println and log.Printf statements, which makes it difficult to:

• Filter logs by severity
• Parse logs programmatically
• Integrate with log aggregation systems
• Debug production issues effectively

Current Issues

1. Inconsistent Logging

// Mix of fmt.Println and log.Printf
fmt.Println("[ERROR] ~ Retrieving Heimdall Token: ", err.Error())
log.Printf("%s:\t%s - %q %s %d %s\n", logLevel, ...)

2. No Log Levels

• Can't filter by severity (DEBUG, INFO, WARN, ERROR)
• All logs treated equally
• Hard to reduce verbosity in production

3. Not Structured

// Unstructured string concatenation
fmt.Println("[ERROR] ~ Validating Heimdall Token ~", tokenString, ": ", err.Error())

Should be:

{
  "level": "error",
  "msg": "Validating Heimdall Token",
  "token": "***",
  "error": "connection timeout",
  "timestamp": "2024-01-10T12:00:00Z"
}

4. Sensitive Data Exposure

// Logs full token string
fmt.Println("[ERROR] ~ Validating Heimdall Token ~", tokenString, ": ", err.Error())

Should redact sensitive information.

Recommended Solution

Option 1: Use slog (Go 1.21+ Standard Library)

import (
    "log/slog"
    "os"
)

var logger *slog.Logger

func init() {
    // JSON structured logging
    logger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
        Level: slog.LevelInfo,
    }))
}

// Usage
logger.Error("Validating Heimdall Token",
    "token", redactToken(tokenString),
    "error", err,
    "username", username,
)

Option 2: Use zerolog (Popular Third-Party)

go get github.com/rs/zerolog

import (
    "github.com/rs/zerolog"
    "github.com/rs/zerolog/log"
)

func init() {
    zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
}

// Usage
log.Error().
    Str("token", redactToken(tokenString)).
    Err(err).
    Str("username", username).
    Msg("Validating Heimdall Token")

Option 3: Use zap (High Performance)

go get go.uber.org/zap

import "go.uber.org/zap"

var logger *zap.Logger

func init() {
    logger, _ = zap.NewProduction()
    defer logger.Sync()
}

// Usage
logger.Error("Validating Heimdall Token",
    zap.String("token", redactToken(tokenString)),
    zap.Error(err),
    zap.String("username", username),
)

Proposed Implementation (Using slog)

package main

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

var logger *slog.Logger

func initLogger() {
    logLevel := os.Getenv("LOG_LEVEL")
    var level slog.Level
    
    switch strings.ToUpper(logLevel) {
    case "DEBUG":
        level = slog.LevelDebug
    case "INFO":
        level = slog.LevelInfo
    case "WARN":
        level = slog.LevelWarn
    case "ERROR":
        level = slog.LevelError
    default:
        level = slog.LevelInfo
    }

    logger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
        Level: level,
    }))
}

// Redact sensitive information
func redactToken(token string) string {
    if len(token) <= 8 {
        return "***"
    }
    return token[:4] + "..." + token[len(token)-4:]
}

// Updated register function
func register(res http.ResponseWriter, req *http.Request) {
    cookie, err := req.Cookie("heimdall")
    if err != nil {
        logger.Error("Retrieving Heimdall Token",
            "error", err,
            "ip", req.Header.Get("X-Real-IP"),
        )
        http.Error(res, "[ERROR] ~ Retrieving Heimdall Token", http.StatusUnauthorized)
        return
    }
    
    tokenString := cookie.Value
    logger.Debug("Processing registration",
        "token", redactToken(tokenString),
    )
    
    // ... rest of the code with structured logging
}

// Updated LoggerMiddleware
func LoggerMiddleware(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        recorder := &responseRecorder{w, http.StatusOK, 0}
        next.ServeHTTP(recorder, r)

        logFunc := logger.Info
        if recorder.status >= 400 {
            logFunc = logger.Error
        }

        logFunc("HTTP Request",
            "method", r.Method,
            "path", r.RequestURI,
            "status", recorder.status,
            "ip", r.Header.Get("X-Real-IP"),
        )
    })
}

Benefits

Current	With Structured Logging
❌ Hard to parse	✅ JSON format, easy to parse
❌ No filtering	✅ Filter by level (DEBUG, INFO, ERROR)
❌ Sensitive data exposed	✅ Automatic redaction
❌ No context	✅ Rich context (user, IP, etc.)
❌ Hard to search	✅ Easy to search and aggregate

Example Output

Before

[ERROR] ~ Validating Heimdall Token ~ eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9... :  connection timeout

After

{
  "time": "2024-01-10T12:00:00Z",
  "level": "ERROR",
  "msg": "Validating Heimdall Token",
  "token": "eyJh...VCJ9",
  "error": "connection timeout",
  "ip": "192.168.1.1",
  "username": "student123"
}

Integration with Log Aggregation

Structured logs work seamlessly with:

• ELK Stack (Elasticsearch, Logstash, Kibana)
• Grafana Loki
• Datadog
• CloudWatch Logs
• Splunk

Environment Configuration

Add to .env.example:

# Logging
LOG_LEVEL=INFO  # DEBUG, INFO, WARN, ERROR
LOG_FORMAT=json # json or text

Migration Path

1. Phase 1: Add structured logging alongside existing logs
2. Phase 2: Gradually replace fmt.Println with logger calls
3. Phase 3: Remove old logging statements
4. Phase 4: Add log aggregation integration

Testing

func TestLogging(t *testing.T) {
    // Capture log output
    var buf bytes.Buffer
    logger = slog.New(slog.NewJSONHandler(&buf, nil))
    
    logger.Error("Test error", "key", "value")
    
    // Parse JSON output
    var logEntry map[string]interface{}
    json.Unmarshal(buf.Bytes(), &logEntry)
    
    assert.Equal(t, "ERROR", logEntry["level"])
    assert.Equal(t, "Test error", logEntry["msg"])
}

References

• Go slog Package
• Structured Logging Best Practices
• 12-Factor App Logs

Priority

MEDIUM - Important for production observability and debugging.

---

Benefits: Better debugging, easier monitoring, production-ready logging.