Documentation

Debugging

Overview

Effective debugging techniques are essential for identifying and resolving issues in your application. This guide covers debugging strategies, tools, and best practices for Go web applications.

Logging

Structured Logging

import (
    "log/slog"
    "os"
)

func setupLogger(level string) *slog.Logger {
    var logLevel slog.Level
    switch level {
    case "debug":
        logLevel = slog.LevelDebug
    case "info":
        logLevel = slog.LevelInfo
    case "warn":
        logLevel = slog.LevelWarn
    case "error":
        logLevel = slog.LevelError
    default:
        logLevel = slog.LevelInfo
    }

    handler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
        Level: logLevel,
    })

    return slog.New(handler)
}

// Usage in services
func (h *GardenHandler) Create(ctx context.Context, garden *mdl.Garden, mod *handler.HandlerMod) (*mdl.Garden, error) {
    logger := slog.With(
        "operation", "garden_create",
        "user_id", garden.UserId,
        "garden_name", garden.Name,
    )

    logger.Info("Creating garden", "garden", garden)

    createdGarden, err := h.baseHandler.Create(ctx, garden, mod)
    if err != nil {
        logger.Error("Failed to create garden", "error", err)
        return nil, err
    }

    logger.Info("Garden created successfully", "garden_id", createdGarden.Id)
    return createdGarden, nil
}

Request Logging Middleware

func RequestLoggingMiddleware(logger *slog.Logger) gin.HandlerFunc {
    return func(c *gin.Context) {
        start := time.Now()
        path := c.Request.URL.Path
        method := c.Request.Method

        // Create request ID for tracing
        requestID := generateRequestID()
        c.Set("request_id", requestID)

        logger.Info("Request started",
            "request_id", requestID,
            "method", method,
            "path", path,
            "client_ip", c.ClientIP(),
            "user_agent", c.Request.UserAgent(),
        )

        c.Next()

        duration := time.Since(start)
        status := c.Writer.Status()

        logEntry := logger.With(
            "request_id", requestID,
            "method", method,
            "path", path,
            "status", status,
            "duration_ms", duration.Milliseconds(),
        )

        if status >= 400 {
            logEntry.Error("Request completed with error")
        } else {
            logEntry.Info("Request completed successfully")
        }
    }
}

func generateRequestID() string {
    b := make([]byte, 8)
    rand.Read(b)
    return hex.EncodeToString(b)
}

Context-Aware Logging

type contextKey string

const loggerKey = contextKey("logger")

func WithLogger(ctx context.Context, logger *slog.Logger) context.Context {
    return context.WithValue(ctx, loggerKey, logger)
}

func LoggerFromContext(ctx context.Context) *slog.Logger {
    if logger, ok := ctx.Value(loggerKey).(*slog.Logger); ok {
        return logger
    }
    return slog.Default()
}

// Usage in services
func (f *GardenFetcher) FindOneById(ctx context.Context, id string, mod *fetcher.FetcherMod) (*mdl.Garden, bool, error) {
    logger := LoggerFromContext(ctx).With("operation", "find_garden", "garden_id", id)

    logger.Debug("Fetching garden from database")

    garden, exists, err := f.baseFetcher.FindOneById(ctx, id, mod)
    if err != nil {
        logger.Error("Database error while fetching garden", "error", err)
        return nil, false, err
    }

    if !exists {
        logger.Debug("Garden not found")
        return nil, false, nil
    }

    logger.Debug("Garden found successfully")
    return garden, true, nil
}

Error Handling

Error Wrapping and Context

import "errors"
import "fmt"

// Custom error types
type ValidationError struct {
    Field   string
    Message string
    Value   interface{}
}

func (e *ValidationError) Error() string {
    return fmt.Sprintf("validation error on field '%s': %s", e.Field, e.Message)
}

type DatabaseError struct {
    Operation string
    Table     string
    Err       error
}

func (e *DatabaseError) Error() string {
    return fmt.Sprintf("database error during %s on table %s: %v", e.Operation, e.Table, e.Err)
}

func (e *DatabaseError) Unwrap() error {
    return e.Err
}

// Error wrapping in services
func (h *GardenHandler) Create(ctx context.Context, garden *mdl.Garden, mod *handler.HandlerMod) (*mdl.Garden, error) {
    createdGarden, err := h.baseHandler.Create(ctx, garden, mod)
    if err != nil {
        return nil, &DatabaseError{
            Operation: "create",
            Table:     "gardens",
            Err:       err,
        }
    }

    return createdGarden, nil
}

// Error handling in controllers
func (gc *GardenController) Create(c *gin.Context) {
    form := &forms.CreateGardenForm{}
    if err := c.ShouldBindJSON(form); err != nil {
        gc.handleError(c, err)
        return
    }

    output, err := gc.createGardenMae.Execute(c.Request.Context(), &maes.CreateGardenMaeInput{
        Form: form,
    })

    if err != nil {
        gc.handleError(c, err)
        return
    }

    c.JSON(201, gin.H{"garden": output.Garden})
}

func (gc *GardenController) handleError(c *gin.Context, err error) {
    logger := LoggerFromContext(c.Request.Context())

    var validationErr *ValidationError
    var dbErr *DatabaseError

    switch {
    case errors.As(err, &validationErr):
        logger.Warn("Validation error", "field", validationErr.Field, "message", validationErr.Message)
        c.JSON(400, gin.H{
            "error": "Validation failed",
            "field": validationErr.Field,
            "message": validationErr.Message,
        })

    case errors.As(err, &dbErr):
        logger.Error("Database error", "operation", dbErr.Operation, "table", dbErr.Table, "error", dbErr.Err)
        c.JSON(500, gin.H{"error": "Internal server error"})

    default:
        logger.Error("Unexpected error", "error", err)
        c.JSON(500, gin.H{"error": "Internal server error"})
    }
}

Panic Recovery

func PanicRecoveryMiddleware(logger *slog.Logger) gin.HandlerFunc {
    return func(c *gin.Context) {
        defer func() {
            if err := recover(); err != nil {
                // Log the panic with stack trace
                stack := make([]byte, 4096)
                length := runtime.Stack(stack, false)

                logger.Error("Panic recovered",
                    "error", err,
                    "request_id", c.GetString("request_id"),
                    "path", c.Request.URL.Path,
                    "method", c.Request.Method,
                    "stack", string(stack[:length]),
                )

                // Return error response
                if !c.Writer.Written() {
                    c.JSON(500, gin.H{"error": "Internal server error"})
                }

                c.Abort()
            }
        }()

        c.Next()
    }
}

Development Tools

Debug Mode Configuration

func setupDebugMode(router *gin.Engine, config *config.Config) {
    if config.Debug {
        // Enable debug logging
        gin.SetMode(gin.DebugMode)

        // Add debug endpoints
        debug := router.Group("/debug")
        {
            debug.GET("/vars", debugVarsHandler)
            debug.GET("/pprof/*any", gin.WrapH(http.DefaultServeMux))
            debug.GET("/config", debugConfigHandler)
            debug.GET("/routes", debugRoutesHandler)
        }
    } else {
        gin.SetMode(gin.ReleaseMode)
    }
}

func debugVarsHandler(c *gin.Context) {
    vars := map[string]interface{}{
        "goroutines": runtime.NumGoroutine(),
        "memory":     getMemoryStats(),
        "uptime":     time.Since(startTime),
        "version":    version,
    }
    c.JSON(200, vars)
}

func getMemoryStats() map[string]interface{} {
    var m runtime.MemStats
    runtime.ReadMemStats(&m)

    return map[string]interface{}{
        "alloc_mb":      bToMb(m.Alloc),
        "total_alloc_mb": bToMb(m.TotalAlloc),
        "sys_mb":        bToMb(m.Sys),
        "num_gc":        m.NumGC,
    }
}

func bToMb(b uint64) uint64 {
    return b / 1024 / 1024
}

Hot Reload with Air

# air.dev.toml
root = "."
testdata_dir = "testdata"
tmp_dir = "tmp"

[build]
  args_bin = []
  bin = "./app"
  cmd = "go build -o ./app ./main.go"
  delay = 1000
  exclude_dir = ["assets", "tmp", "vendor", "testdata"]
  exclude_file = []
  exclude_regex = ["_test.go"]
  exclude_unchanged = false
  follow_symlink = false
  full_bin = ""
  include_dir = []
  include_ext = ["go", "tpl", "tmpl", "html"]
  kill_delay = "0s"
  log = "build-errors.log"
  send_interrupt = false
  stop_on_root = false

[color]
  app = ""
  build = "yellow"
  main = "magenta"
  runner = "green"
  watcher = "cyan"

[log]
  time = false

[misc]
  clean_on_exit = false

[screen]
  clear_on_rebuild = false

Profiling and Performance

CPU and Memory Profiling

import (
    _ "net/http/pprof"
    "net/http"
    "runtime/pprof"
)

// Enable pprof endpoints
func enableProfiling(router *gin.Engine) {
    pprof := router.Group("/debug/pprof")
    {
        pprof.GET("/", gin.WrapF(http.HandlerFunc(pprof.Index)))
        pprof.GET("/cmdline", gin.WrapF(http.HandlerFunc(pprof.Cmdline)))
        pprof.GET("/profile", gin.WrapF(http.HandlerFunc(pprof.Profile)))
        pprof.POST("/symbol", gin.WrapF(http.HandlerFunc(pprof.Symbol)))
        pprof.GET("/symbol", gin.WrapF(http.HandlerFunc(pprof.Symbol)))
        pprof.GET("/trace", gin.WrapF(http.HandlerFunc(pprof.Trace)))
        pprof.GET("/allocs", gin.WrapH(pprof.Handler("allocs")))
        pprof.GET("/block", gin.WrapH(pprof.Handler("block")))
        pprof.GET("/goroutine", gin.WrapH(pprof.Handler("goroutine")))
        pprof.GET("/heap", gin.WrapH(pprof.Handler("heap")))
        pprof.GET("/mutex", gin.WrapH(pprof.Handler("mutex")))
        pprof.GET("/threadcreate", gin.WrapH(pprof.Handler("threadcreate")))
    }
}

// Custom profiling middleware
func ProfilingMiddleware() gin.HandlerFunc {
    return func(c *gin.Context) {
        if c.Query("profile") == "true" {
            // Start CPU profiling
            f, err := os.Create(fmt.Sprintf("cpu_profile_%d.prof", time.Now().Unix()))
            if err != nil {
                log.Printf("Could not create CPU profile: %v", err)
                c.Next()
                return
            }
            defer f.Close()

            if err := pprof.StartCPUProfile(f); err != nil {
                log.Printf("Could not start CPU profile: %v", err)
                c.Next()
                return
            }
            defer pprof.StopCPUProfile()
        }

        c.Next()
    }
}

Performance Monitoring

type PerformanceMonitor struct {
    requestDurations sync.Map
    slowRequests     []SlowRequest
    mutex           sync.RWMutex
}

type SlowRequest struct {
    Path     string
    Method   string
    Duration time.Duration
    Time     time.Time
}

func (pm *PerformanceMonitor) RecordRequest(path, method string, duration time.Duration) {
    // Track slow requests (>1 second)
    if duration > time.Second {
        pm.mutex.Lock()
        pm.slowRequests = append(pm.slowRequests, SlowRequest{
            Path:     path,
            Method:   method,
            Duration: duration,
            Time:     time.Now(),
        })

        // Keep only last 100 slow requests
        if len(pm.slowRequests) > 100 {
            pm.slowRequests = pm.slowRequests[1:]
        }
        pm.mutex.Unlock()
    }

    // Track average durations
    key := fmt.Sprintf("%s %s", method, path)
    if existing, ok := pm.requestDurations.Load(key); ok {
        avg := existing.(time.Duration)
        newAvg := (avg + duration) / 2
        pm.requestDurations.Store(key, newAvg)
    } else {
        pm.requestDurations.Store(key, duration)
    }
}

func (pm *PerformanceMonitor) GetSlowRequests() []SlowRequest {
    pm.mutex.RLock()
    defer pm.mutex.RUnlock()

    result := make([]SlowRequest, len(pm.slowRequests))
    copy(result, pm.slowRequests)
    return result
}

Database Debugging

Query Logging

type QueryLogger struct {
    logger *slog.Logger
    minDuration time.Duration
}

func NewQueryLogger(logger *slog.Logger, minDuration time.Duration) *QueryLogger {
    return &QueryLogger{
        logger: logger,
        minDuration: minDuration,
    }
}

func (ql *QueryLogger) LogQuery(query string, args []interface{}, duration time.Duration, err error) {
    logEntry := ql.logger.With(
        "query", query,
        "args", args,
        "duration_ms", duration.Milliseconds(),
    )

    if err != nil {
        logEntry.Error("Query failed", "error", err)
    } else if duration > ql.minDuration {
        logEntry.Warn("Slow query detected")
    } else {
        logEntry.Debug("Query executed")
    }
}

// Wrapper for database operations
func (f *GardenFetcher) QueryWithLogging(ctx context.Context, query string, args ...interface{}) (*sql.Rows, error) {
    start := time.Now()
    rows, err := f.db.QueryContext(ctx, query, args...)
    duration := time.Since(start)

    f.queryLogger.LogQuery(query, args, duration, err)

    return rows, err
}

Transaction Debugging

type DebuggingTx struct {
    *sql.Tx
    logger *slog.Logger
    startTime time.Time
    queries []QueryInfo
}

type QueryInfo struct {
    Query    string
    Args     []interface{}
    Duration time.Duration
    Error    error
}

func (dtx *DebuggingTx) ExecContext(ctx context.Context, query string, args ...interface{}) (sql.Result, error) {
    start := time.Now()
    result, err := dtx.Tx.ExecContext(ctx, query, args...)
    duration := time.Since(start)

    dtx.queries = append(dtx.queries, QueryInfo{
        Query:    query,
        Args:     args,
        Duration: duration,
        Error:    err,
    })

    dtx.logger.Debug("Transaction query executed",
        "query", query,
        "args", args,
        "duration_ms", duration.Milliseconds(),
        "error", err,
    )

    return result, err
}

func (dtx *DebuggingTx) Commit() error {
    err := dtx.Tx.Commit()
    totalDuration := time.Since(dtx.startTime)

    dtx.logger.Info("Transaction committed",
        "total_duration_ms", totalDuration.Milliseconds(),
        "query_count", len(dtx.queries),
        "error", err,
    )

    return err
}

func (dtx *DebuggingTx) Rollback() error {
    err := dtx.Tx.Rollback()
    totalDuration := time.Since(dtx.startTime)

    dtx.logger.Info("Transaction rolled back",
        "total_duration_ms", totalDuration.Milliseconds(),
        "query_count", len(dtx.queries),
        "error", err,
    )

    return err
}

Remote Debugging

Debug Endpoints

func RegisterDebugEndpoints(router *gin.Engine, container *container.Container) {
    debug := router.Group("/debug")
    debug.Use(AuthMiddleware()) // Protect debug endpoints

    debug.GET("/health", func(c *gin.Context) {
        health := map[string]interface{}{
            "status": "ok",
            "time": time.Now(),
            "version": version,
        }

        // Check database connection
        if err := container.DB.Ping(); err != nil {
            health["database"] = "error: " + err.Error()
            c.JSON(500, health)
            return
        }
        health["database"] = "ok"

        c.JSON(200, health)
    })

    debug.GET("/metrics", func(c *gin.Context) {
        var m runtime.MemStats
        runtime.ReadMemStats(&m)

        metrics := map[string]interface{}{
            "memory": map[string]interface{}{
                "alloc_mb": bToMb(m.Alloc),
                "sys_mb": bToMb(m.Sys),
                "num_gc": m.NumGC,
            },
            "goroutines": runtime.NumGoroutine(),
            "cpu_count": runtime.NumCPU(),
        }

        c.JSON(200, metrics)
    })

    debug.GET("/config", func(c *gin.Context) {
        // Return safe config values (no secrets)
        safeConfig := map[string]interface{}{
            "environment": container.Config.Environment,
            "port": container.Config.Port,
            "database_driver": container.Config.Database.Driver,
            "debug_mode": container.Config.Debug,
        }

        c.JSON(200, safeConfig)
    })
}

Error Reporting

type ErrorReporter struct {
    logger *slog.Logger
    webhook string // Slack/Discord webhook URL
}

func (er *ErrorReporter) ReportError(ctx context.Context, err error, metadata map[string]interface{}) {
    requestID := ctx.Value("request_id")
    userID := ctx.Value("user_id")

    errorInfo := map[string]interface{}{
        "error": err.Error(),
        "request_id": requestID,
        "user_id": userID,
        "timestamp": time.Now(),
        "metadata": metadata,
    }

    // Log locally
    er.logger.Error("Error reported", errorInfo)

    // Send to external service (Slack, Discord, etc.)
    if er.webhook != "" {
        go er.sendToWebhook(errorInfo)
    }
}

func (er *ErrorReporter) sendToWebhook(errorInfo map[string]interface{}) {
    message := fmt.Sprintf("🚨 Error Report\n```json\n%s\n```",
        mustMarshalJSON(errorInfo))

    payload := map[string]string{
        "text": message,
    }

    jsonData, _ := json.Marshal(payload)
    http.Post(er.webhook, "application/json", bytes.NewBuffer(jsonData))
}

Debugging Best Practices

Development Workflow

  1. Use structured logging with consistent field names
  2. Add request IDs for tracing requests across services
  3. Log at appropriate levels (debug, info, warn, error)
  4. Use error wrapping to preserve error context
  5. Enable debug endpoints in development
  6. Profile regularly to identify performance bottlenecks

Production Debugging

  1. Never log sensitive data (passwords, tokens, personal info)
  2. Use centralized logging (ELK stack, CloudWatch, etc.)
  3. Implement health checks and monitoring
  4. Set up alerting for critical errors
  5. Maintain observability with metrics and tracing

Common Debugging Scenarios

# View memory profile
go tool pprof http://localhost:8080/debug/pprof/heap

# View CPU profile
go tool pprof http://localhost:8080/debug/pprof/profile?seconds=30

# View goroutines
go tool pprof http://localhost:8080/debug/pprof/goroutine

# Check slow queries
grep "SLOW QUERY" logs/app.log

# Monitor request patterns
grep "Request completed" logs/app.log | tail -100

Effective debugging practices help you identify issues quickly and maintain application stability in both development and production environments.