Gin Logging Strategies

When building web applications with Gin, proper logging is essential for monitoring application behavior, debugging issues, and tracking performance. In this tutorial, we'll explore various logging strategies for Gin applications, from basic built-in logging to advanced customizations.

Introduction to Logging in Gin

Logging is the process of recording events that occur during the execution of your application. In a web server context, this typically includes:

• Incoming HTTP requests
• Response status codes and times
• Error conditions and exceptions
• Performance metrics

Gin provides built-in middleware for logging, but also allows for extensive customization to meet specific requirements. Effective logging strategies help you understand what's happening in your application and quickly identify issues when they arise.

Basic Logging with Gin's Default Logger

Gin comes with a built-in logger middleware that provides basic request logging capabilities.

Using the Default Logger

go

package main

import (
  "github.com/gin-gonic/gin"
)

func main() {
  // Creates a router with default middleware:
  // logger and recovery middleware
  router := gin.Default()

  router.GET("/ping", func(c *gin.Context) {
    c.JSON(200, gin.H{
      "message": "pong",
    })
  })

  router.Run(":8080")
}

When you run this application and make requests, you'll see log output similar to:

[GIN] 2023/04/12 - 15:03:27 | 200 |     198.235µs |    127.0.0.1 | GET      "/ping"

This log entry includes:

• Timestamp
• Status code (200)
• Latency (198.235µs)
• Client IP (127.0.0.1)
• HTTP method (GET)
• Path ("/ping")

Creating a New Router without Default Middleware

If you want more control over which middleware is included, you can use gin.New() instead of gin.Default():

go

router := gin.New()
// Manually add the logger middleware
router.Use(gin.Logger())

Customizing the Gin Logger

The default logger is helpful, but you might need to customize its behavior for your specific requirements.

Custom Log Format

You can customize the log format using gin.LoggerWithFormatter:

go

package main

import (
  "fmt"
  "time"
  
  "github.com/gin-gonic/gin"
)

func main() {
  router := gin.New()
  
  // Define custom logger format
  router.Use(gin.LoggerWithFormatter(func(param gin.LogFormatterParams) string {
    // Custom format
    return fmt.Sprintf("[GIN] %s - [%s] \"%s %s %s %d %s \"%s\" %s\"\n",
      param.TimeStamp.Format(time.RFC1123),
      param.ClientIP,
      param.Method,
      param.Path,
      param.Request.Proto,
      param.StatusCode,
      param.Latency,
      param.Request.UserAgent(),
      param.ErrorMessage,
    )
  }))
  
  router.Use(gin.Recovery())
  
  router.GET("/ping", func(c *gin.Context) {
    c.JSON(200, gin.H{
      "message": "pong",
    })
  })
  
  router.Run(":8080")
}

With this custom formatter, your logs will look like:

[GIN] Wed, 12 Apr 2023 15:10:27 EDT - [127.0.0.1] "GET /ping HTTP/1.1 200 198.235µs "Mozilla/5.0..." "

Logging to a File Instead of Console

To log to a file instead of the console, you can redirect the output:

go

package main

import (
  "io"
  "os"
  
  "github.com/gin-gonic/gin"
)

func main() {
  // Create log file
  f, _ := os.Create("gin.log")
  
  // Use io.MultiWriter to write logs to both file and console
  gin.DefaultWriter = io.MultiWriter(f, os.Stdout)
  
  // If you need to write the logs to file only
  // gin.DefaultWriter = f
  
  router := gin.Default()
  
  router.GET("/ping", func(c *gin.Context) {
    c.JSON(200, gin.H{
      "message": "pong",
    })
  })
  
  router.Run(":8080")
}

Integrating with External Logging Libraries

For more advanced logging needs, you might want to use a dedicated logging library instead of Gin's built-in logger.

Using Logrus with Gin

Logrus is a popular structured logger for Go, offering features like log levels, formatters, and hooks.

go

package main

import (
  "time"
  
  "github.com/gin-gonic/gin"
  "github.com/sirupsen/logrus"
)

func main() {
  // Setup Logrus
  log := logrus.New()
  log.SetFormatter(&logrus.JSONFormatter{})
  
  // Create a Gin router without any middleware
  router := gin.New()
  
  // Create custom middleware using Logrus
  router.Use(func(c *gin.Context) {
    // Start timer
    startTime := time.Now()
    
    // Process request
    c.Next()
    
    // Calculate latency
    latency := time.Since(startTime)
    
    // Log request details
    log.WithFields(logrus.Fields{
      "status":     c.Writer.Status(),
      "method":     c.Request.Method,
      "path":       c.Request.URL.Path,
      "ip":         c.ClientIP(),
      "latency":    latency,
      "user_agent": c.Request.UserAgent(),
    }).Info("incoming request")
  })
  
  // Recovery middleware
  router.Use(gin.Recovery())
  
  router.GET("/ping", func(c *gin.Context) {
    c.JSON(200, gin.H{
      "message": "pong",
    })
  })
  
  router.Run(":8080")
}

This will produce structured JSON logs:

json

{"ip":"127.0.0.1","latency":356851,"level":"info","method":"GET","msg":"incoming request","path":"/ping","status":200,"time":"2023-04-12T15:20:42-04:00","user_agent":"Mozilla/5.0..."}

Using Zap with Gin

Zap is a fast, structured, leveled logging library:

go

package main

import (
  "time"
  
  "github.com/gin-gonic/gin"
  "go.uber.org/zap"
)

func main() {
  // Initialize Zap logger
  logger, _ := zap.NewProduction()
  defer logger.Sync() // Flushes buffer, if any
  
  // Create a Gin router without any middleware
  router := gin.New()
  
  // Use custom Zap logger middleware
  router.Use(func(c *gin.Context) {
    start := time.Now()
    path := c.Request.URL.Path
    
    // Process request
    c.Next()
    
    // Log request details
    logger.Info("incoming request",
      zap.Int("status", c.Writer.Status()),
      zap.String("method", c.Request.Method),
      zap.String("path", path),
      zap.String("ip", c.ClientIP()),
      zap.Duration("latency", time.Since(start)),
      zap.String("user-agent", c.Request.UserAgent()),
    )
  })
  
  // Recovery middleware
  router.Use(gin.Recovery())
  
  router.GET("/ping", func(c *gin.Context) {
    c.JSON(200, gin.H{
      "message": "pong",
    })
  })
  
  router.Run(":8080")
}

Advanced Logging Patterns

Let's explore some more advanced logging patterns that can be useful in production applications.

Request-Scoped Logging

Sometimes you want to attach specific information to logs related to a particular request:

go

package main

import (
  "github.com/gin-gonic/gin"
  "github.com/google/uuid"
  "github.com/sirupsen/logrus"
)

func main() {
  log := logrus.New()
  log.SetFormatter(&logrus.JSONFormatter{})
  
  router := gin.New()
  
  // Middleware to attach a request ID to the context
  router.Use(func(c *gin.Context) {
    requestID := uuid.New().String()
    c.Set("RequestID", requestID)
    
    // Create a request-scoped logger
    requestLogger := log.WithField("request_id", requestID)
    c.Set("Logger", requestLogger)
    
    requestLogger.Info("Request started")
    
    c.Next()
    
    requestLogger.WithField("status", c.Writer.Status()).
      Info("Request completed")
  })
  
  router.GET("/api/users/:id", func(c *gin.Context) {
    // Get request-scoped logger
    logger, _ := c.Get("Logger")
    reqLogger := logger.(*logrus.Entry)
    
    userID := c.Param("id")
    reqLogger.WithField("user_id", userID).Info("Retrieving user info")
    
    // Your logic here
    c.JSON(200, gin.H{"user_id": userID, "name": "Test User"})
  })
  
  router.Run(":8080")
}

Conditional Logging Based on Status Codes

You might want to use different log levels based on response status:

go

package main

import (
  "time"
  
  "github.com/gin-gonic/gin"
  "github.com/sirupsen/logrus"
)

func main() {
  log := logrus.New()
  log.SetFormatter(&logrus.JSONFormatter{})
  
  router := gin.New()
  
  router.Use(func(c *gin.Context) {
    startTime := time.Now()
    
    // Process request
    c.Next()
    
    latency := time.Since(startTime)
    status := c.Writer.Status()
    
    logFields := logrus.Fields{
      "status":     status,
      "method":     c.Request.Method,
      "path":       c.Request.URL.Path,
      "ip":         c.ClientIP(),
      "latency":    latency,
      "user_agent": c.Request.UserAgent(),
    }
    
    // Log with appropriate level based on status code
    if status >= 500 {
      log.WithFields(logFields).Error("Server error")
    } else if status >= 400 {
      log.WithFields(logFields).Warn("Client error")
    } else {
      log.WithFields(logFields).Info("Success")
    }
  })
  
  router.Use(gin.Recovery())
  
  router.GET("/success", func(c *gin.Context) {
    c.JSON(200, gin.H{"status": "success"})
  })
  
  router.GET("/client-error", func(c *gin.Context) {
    c.JSON(400, gin.H{"error": "bad request"})
  })
  
  router.GET("/server-error", func(c *gin.Context) {
    c.JSON(500, gin.H{"error": "internal server error"})
  })
  
  router.Run(":8080")
}

Real-World Example: Complete Logging System

Let's put everything together in a complete logging system for a real-world application:

go

package main

import (
  "io"
  "os"
  "time"
  
  "github.com/gin-gonic/gin"
  "github.com/google/uuid"
  "github.com/sirupsen/logrus"
)

// Logger is a custom logger with fields
type Logger struct {
  *logrus.Logger
}

// Setup initializes the logger
func setupLogger() *Logger {
  l := logrus.New()
  
  // Use JSON formatter for structured logging
  l.SetFormatter(&logrus.JSONFormatter{
    TimestampFormat: time.RFC3339,
  })
  
  // Write to both file and stdout
  logFile, _ := os.OpenFile("application.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
  l.SetOutput(io.MultiWriter(os.Stdout, logFile))
  
  // Set log level (can be configured from environment)
  l.SetLevel(logrus.InfoLevel)
  
  return &Logger{l}
}

// LoggerMiddleware attaches a request-scoped logger to the context
func LoggerMiddleware(logger *Logger) gin.HandlerFunc {
  return func(c *gin.Context) {
    // Generate a unique ID for this request
    requestID := uuid.New().String()
    c.Set("RequestID", requestID)
    
    // Add the request ID to response headers
    c.Writer.Header().Set("X-Request-ID", requestID)
    
    // Create a request-scoped logger with common fields
    requestLogger := logger.WithFields(logrus.Fields{
      "request_id": requestID,
      "client_ip":  c.ClientIP(),
      "method":     c.Request.Method,
      "path":       c.Request.URL.Path,
    })
    
    c.Set("Logger", requestLogger)
    
    // Record request start time for latency calculation
    startTime := time.Now()
    
    // Log the beginning of the request
    requestLogger.Info("Request started")
    
    // Process request
    c.Next()
    
    // Calculate and log latency
    latency := time.Since(startTime)
    status := c.Writer.Status()
    
    // Add status and latency to fields
    requestLogger = requestLogger.WithFields(logrus.Fields{
      "status":  status,
      "latency": latency,
    })
    
    // Log with appropriate level based on status
    switch {
    case status >= 500:
      requestLogger.Error("Server error response")
    case status >= 400:
      requestLogger.Warn("Client error response")
    default:
      requestLogger.Info("Request completed successfully")
    }
  }
}

// GetRequestLogger extracts the request logger from context
func GetRequestLogger(c *gin.Context) *logrus.Entry {
  logger, exists := c.Get("Logger")
  if !exists {
    // Fallback to default logger if none in context
    return logrus.NewEntry(logrus.StandardLogger())
  }
  return logger.(*logrus.Entry)
}

func main() {
  logger := setupLogger()
  
  router := gin.New()
  
  // Add our custom logger middleware
  router.Use(LoggerMiddleware(logger))
  
  // Add recovery middleware
  router.Use(gin.Recovery())
  
  // Define API endpoints
  router.GET("/api/users", func(c *gin.Context) {
    log := GetRequestLogger(c)
    log.Info("Fetching users list")
    
    // Simulate database operation
    time.Sleep(100 * time.Millisecond)
    
    c.JSON(200, gin.H{
      "users": []gin.H{
        {"id": 1, "name": "Alice"},
        {"id": 2, "name": "Bob"},
      },
    })
  })
  
  router.GET("/api/error", func(c *gin.Context) {
    log := GetRequestLogger(c)
    log.WithField("cause", "simulation").Error("Simulating an error")
    
    c.JSON(500, gin.H{"error": "Internal server error"})
  })
  
  logger.Info("Starting server on port 8080")
  router.Run(":8080")
}

This comprehensive example includes:

1. Structured JSON logging
2. Request ID tracking
3. Request-scoped logging
4. Different log levels based on response status
5. Latency tracking
6. Both file and console output
7. A helper function to easily retrieve the logger

Summary

Effective logging is essential for monitoring, debugging, and maintaining web applications built with Gin. In this tutorial, we explored various logging strategies, from the built-in logger to integration with external libraries like Logrus and Zap.

Key takeaways:

• Gin's built-in logger provides basic request logging
• The logger can be customized to change the format or output destination
• For more advanced logging needs, external libraries like Logrus or Zap integrate well with Gin
• Request-scoped logging helps track operations across an entire request lifecycle
• Structured logging makes it easier to parse and analyze logs

By implementing proper logging strategies, you'll have better visibility into your application's behavior and be able to troubleshoot issues more efficiently.

Additional Resources

• Gin Framework Documentation
• Logrus Library
• Zap Logger

Exercises

1. Modify the default Gin logger to include the request body size in the logs.
2. Create a middleware that logs slow requests (taking more than 500ms) at the warning level.
3. Implement a system that redacts sensitive information (like passwords or tokens) from request logs.
4. Create a custom recovery middleware that logs detailed information about panics.
5. Implement a middleware that logs different metrics based on the route pattern (e.g., more detailed logs for admin routes).