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
- Use structured logging with consistent field names
- Add request IDs for tracing requests across services
- Log at appropriate levels (debug, info, warn, error)
- Use error wrapping to preserve error context
- Enable debug endpoints in development
- Profile regularly to identify performance bottlenecks
Production Debugging
- Never log sensitive data (passwords, tokens, personal info)
- Use centralized logging (ELK stack, CloudWatch, etc.)
- Implement health checks and monitoring
- Set up alerting for critical errors
- 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.