cuatrolabs-auth-ms / CORRELATION_ID_IMPLEMENTATION.md
MukeshKapoor25's picture
feat(logging): Add correlation ID tracing for distributed request tracking
1f7d0a1

Correlation ID Implementation Guide

Overview

Correlation ID logging has been implemented in the AUTH microservice to enable request tracing across distributed systems. This allows you to track a single request as it flows through multiple microservices.

What is a Correlation ID?

A correlation ID is a unique identifier (UUID) that is:

  • Generated for each incoming request (if not already present)
  • Propagated through all logs for that request
  • Passed to downstream services via HTTP headers
  • Returned in response headers for client tracking

Implementation Components

1. Correlation ID Middleware (app/middleware/correlation_id.py)

The middleware handles:

  • Extracting correlation ID from X-Correlation-ID header
  • Generating new UUID if not present
  • Storing in context variable for request lifecycle
  • Adding correlation ID to response headers

2. Logging Integration (app/core/logging.py)

The logging system includes:

  • CorrelationIdFilter: Adds correlation ID to all log records
  • JSON formatter includes correlation_id field
  • All handlers (console, file) have the filter applied

3. HTTP Client Utility (app/utils/http_client.py)

The CorrelationHttpClient class provides methods that automatically propagate correlation IDs to downstream services:

  • get(), post(), put(), delete() methods
  • Automatically includes X-Correlation-ID header

Usage Examples

1. Automatic Logging

All logs automatically include the correlation ID:

from app.core.logging import get_logger

logger = get_logger(__name__)

# This log will automatically include correlation_id
logger.info("Processing user login", extra={"user_id": user_id})

2. Getting Current Correlation ID

from app.middleware.correlation_id import get_correlation_id

correlation_id = get_correlation_id()
logger.info(f"Current correlation ID: {correlation_id}")

3. Making HTTP Calls to Other Services

from app.utils.http_client import CorrelationHttpClient

# Correlation ID is automatically included in headers
response = await CorrelationHttpClient.post(
    url="http://scm-service/api/merchants/list",
    json={"filters": {}}
)

4. Manual Header Propagation

If you need to use a different HTTP client:

from app.middleware.correlation_id import get_correlation_id, CORRELATION_ID_HEADER
import httpx

correlation_id = get_correlation_id()
headers = {CORRELATION_ID_HEADER: correlation_id}

async with httpx.AsyncClient() as client:
    response = await client.get(url, headers=headers)

Log Format

Logs now include the correlation ID in JSON format:

{
  "timestamp": "2024-03-07T10:30:45.123456",
  "level": "INFO",
  "logger": "app.auth.services.service",
  "message": "User login successful",
  "correlation_id": "a1b2c3d4-e5f6-7890-abcd-ef1234567890",
  "module": "service",
  "function": "login_user",
  "line": 123,
  "user_id": "user123"
}

Tracing Requests Across Services

Client Request Flow

  1. Client makes request (optionally with X-Correlation-ID header)
  2. AUTH service receives request
  3. Middleware extracts or generates correlation ID
  4. All logs include correlation ID
  5. AUTH service calls SCM service with correlation ID in header
  6. SCM service logs with same correlation ID
  7. Response includes X-Correlation-ID header

Example: Tracing a Login Request

# Client request
curl -X POST https://api.example.com/auth/login \
  -H "X-Correlation-ID: abc-123" \
  -d '{"email": "user@example.com", "password": "pass"}'

# AUTH service logs (correlation_id: abc-123)
{"timestamp": "...", "correlation_id": "abc-123", "message": "Login request received"}
{"timestamp": "...", "correlation_id": "abc-123", "message": "Validating credentials"}
{"timestamp": "...", "correlation_id": "abc-123", "message": "Fetching user permissions from SCM"}

# SCM service logs (correlation_id: abc-123)
{"timestamp": "...", "correlation_id": "abc-123", "message": "Permission request received"}
{"timestamp": "...", "correlation_id": "abc-123", "message": "Returning user permissions"}

# AUTH service logs (correlation_id: abc-123)
{"timestamp": "...", "correlation_id": "abc-123", "message": "Login successful"}

Searching Logs by Correlation ID

Using grep

# Search all logs for a specific correlation ID
grep "abc-123" logs/app.log

# Search with jq for better formatting
grep "abc-123" logs/app.log | jq '.'

Using log aggregation tools

If using ELK, Splunk, or similar:

correlation_id:"abc-123"

Best Practices

  1. Always use CorrelationHttpClient for inter-service communication
  2. Include correlation ID in error responses for client debugging
  3. Log correlation ID at service boundaries (entry/exit points)
  4. Pass correlation ID to background tasks if they're part of the same logical operation
  5. Don't modify correlation IDs once set - they should remain constant throughout the request lifecycle

Testing

Test Correlation ID Generation

# Request without correlation ID (will be generated)
curl -X GET http://localhost:8002/health -v

# Check response headers for X-Correlation-ID

Test Correlation ID Propagation

# Request with correlation ID
curl -X GET http://localhost:8002/health \
  -H "X-Correlation-ID: test-123" -v

# Verify same ID is returned in response headers

Test Logging

# Make request with known correlation ID
curl -X POST http://localhost:8002/auth/login \
  -H "X-Correlation-ID: test-456" \
  -H "Content-Type: application/json" \
  -d '{"email": "test@example.com", "password": "test"}'

# Check logs
grep "test-456" logs/app.log | jq '.'

Troubleshooting

Correlation ID not appearing in logs

  1. Check that middleware is properly registered in main.py
  2. Verify CorrelationIdFilter is added to all log handlers
  3. Ensure logging is configured before making requests

Correlation ID not propagating to downstream services

  1. Use CorrelationHttpClient instead of direct httpx calls
  2. Verify downstream service supports X-Correlation-ID header
  3. Check that correlation ID is in context (get_correlation_id() returns value)

Different correlation IDs in related logs

  1. Ensure you're not creating new async contexts without propagating correlation ID
  2. For background tasks, explicitly pass correlation ID
  3. Verify middleware is processing requests before other middlewares

Integration with Other Microservices

To implement correlation ID in other microservices (SCM, POS, SPA, etc.):

  1. Copy app/middleware/correlation_id.py to the service
  2. Update app/core/logging.py to include CorrelationIdFilter
  3. Add CorrelationIdMiddleware to main.py
  4. Copy app/utils/http_client.py for HTTP client utilities
  5. Update inter-service calls to use CorrelationHttpClient

Benefits

  • Debugging: Trace requests across multiple services
  • Performance Analysis: Identify bottlenecks in request flow
  • Error Tracking: Link errors across service boundaries
  • Audit Trail: Complete request history for compliance
  • Monitoring: Better observability in distributed systems