Skip to content

Latest commit

Β 

History

History
586 lines (423 loc) Β· 17.2 KB

File metadata and controls

586 lines (423 loc) Β· 17.2 KB

πŸ“ Logging Guide

Consistent, emoji-enhanced logging patterns and configuration across all Discogsography services

🏠 Back to Main | πŸ“š Documentation Index | πŸ“‹ Emoji Guide

πŸ“– Overview

Discogsography uses a standardized logging approach with emoji prefixes for visual clarity and quick issue identification. All services use consistent logging controlled by the LOG_LEVEL environment variable.

Logging Flow

flowchart LR
    subgraph "Service"
        Code[Application Code]
        Logger[Logger Instance]
    end

    subgraph "Outputs"
        Console[Console Output<br/>with Emojis]
        File[Log Files<br/>/logs/*.log]
    end

    subgraph "Analysis"
        Monitor[Real-time Monitoring]
        Debug[Debug Analysis]
        Errors[Error Tracking]
    end

    Code -->|logger.info/error/warn| Logger
    Logger --> Console
    Logger --> File

    Console --> Monitor
    File --> Debug
    File --> Errors

    style Code fill:#e3f2fd,stroke:#2196f3,stroke-width:2px
    style Console fill:#e8f5e9,stroke:#4caf50,stroke-width:2px
    style File fill:#fff3e0,stroke:#ff9800,stroke-width:2px
Loading

βš™οΈ Configuration

Environment Variable

All services in the Discogsography platform use the LOG_LEVEL environment variable for consistent logging control.

Supported Log Levels

Level Description Use Case
DEBUG Detailed diagnostic information Development and troubleshooting
INFO General informational messages Production (default)
WARNING Warning messages for potential issues Production monitoring
ERROR Error messages for failures Production alerts
CRITICAL Critical errors requiring immediate attention Production alerts

Default: If LOG_LEVEL is not set, all services default to INFO.

Setting Log Level

# Development with debug logging
export LOG_LEVEL=DEBUG

# Production with info logging (default)
export LOG_LEVEL=INFO

# Error-only logging
export LOG_LEVEL=ERROR

Docker Compose

services:
  my-service:
    environment:
      LOG_LEVEL: INFO

Docker Run

docker run -e LOG_LEVEL=DEBUG discogsography/service:latest

Service-Specific Implementation

Python Services

All Python services (api, brainzgraphinator, brainztableinator, common, dashboard, explore, graphinator, insights, mcp-server, schema-init, tableinator) use structlog configured via setup_logging() from common/config.py. Use structlog.get_logger() β€” not logging.getLogger():

import structlog
from common import setup_logging

# Call once at service startup β€” reads LOG_LEVEL from environment, defaults to INFO
setup_logging("service_name", log_file=Path("/logs/service.log"))

# Get a logger in any module
logger = structlog.get_logger(__name__)
logger.info("πŸš€ Service starting...")

Features:

  • Structured JSON logging with emoji indicators
  • Correlation IDs from contextvars
  • Service-specific context (name, environment)
  • File and console output
  • Automatic suppression of verbose third-party logs

Extractor

The Rust extractor uses Rust's tracing framework and maps Python log levels to Rust equivalents:

Python Level Rust Level Notes
DEBUG debug Detailed diagnostic info
INFO info General messages (default)
WARNING warn Warning messages
ERROR error Error messages
CRITICAL error Mapped to error (Rust has no critical)

Configuration:

# Debug logging
LOG_LEVEL=DEBUG cargo run

# Production logging
LOG_LEVEL=INFO cargo run

Implementation (main.rs):

let log_level = std::env::var("LOG_LEVEL")
    .unwrap_or_else(|_| "INFO".to_string())
    .to_uppercase();

let rust_level = match log_level.as_str() {
    "DEBUG" => "debug",
    "INFO" => "info",
    "WARNING" | "WARN" => "warn",
    "ERROR" => "error",
    "CRITICAL" => "error",
    _ => "info"
};

πŸ“‹ Log Format

Python Services (JSON)

{
  "timestamp": "2024-01-15T10:30:45.123456Z",
  "level": "info",
  "logger": "graphinator",
  "event": "πŸš€ Service starting...",
  "service": "graphinator",
  "environment": "production",
  "lineno": 1210
}

Extractor (JSON)

{
  "timestamp": "2024-01-15T10:30:45.123456Z",
  "level": "INFO",
  "target": "extractor",
  "message": "πŸš€ Starting Rust-based Discogs data extractor with high performance",
  "line": 59
}

🎨 Emoji Pattern

Format: logger.{level}("{emoji} {message}")

  • Always include exactly one space after the emoji
  • Use consistent emojis for similar operations
  • Choose emojis that visually represent the action

πŸ“š Emoji Reference

πŸš€ Service Lifecycle

Emoji Usage Example
πŸš€ Service startup logger.info("πŸš€ Starting extractor service...")
πŸ›‘ Service shutdown logger.info("πŸ›‘ Shutting down gracefully")
πŸ”§ Configuration/Setup logger.info("πŸ”§ Configuring database connections")
πŸ₯ Health check server logger.info("πŸ₯ Health server started on port 8000")

βœ… Success & Completion

Emoji Usage Example
βœ… Operation success logger.info("βœ… All files processed successfully")
πŸ’Ύ Data saved logger.info("πŸ’Ύ Saved 1000 records to database")
πŸ“‹ Metadata loaded logger.info("πŸ“‹ Loaded configuration from disk")
πŸ†• New version/data logger.info("πŸ†• Found new Discogs data release")

❌ Errors & Warnings

Emoji Usage Example
❌ Error occurred logger.error("❌ Failed to connect to database")
⚠️ Warning logger.warning("⚠️ Retry attempt 3/5")
🚨 Critical issue logger.critical("🚨 Out of memory")
⏩ Skipped operation logger.info("⏩ Skipped duplicate record")

πŸ”„ Processing & Progress

Emoji Usage Example
πŸ”„ Processing logger.info("πŸ”„ Processing batch 5/10")
⏳ Waiting logger.info("⏳ Waiting for messages...")
πŸ“Š Progress/Stats logger.info("πŸ“Š Processed 5000/10000 records")
⏰ Scheduled task logger.info("⏰ Running periodic check")

πŸ“₯ Data Operations

Emoji Usage Example
πŸ“₯ Download start logger.info("πŸ“₯ Starting download of releases.xml")
⬇️ Downloading logger.info("⬇️ Downloaded 50MB/200MB")
πŸ“„ File operation logger.info("πŸ“„ Created output.json")
πŸ” Searching/Query execution logger.info("πŸ” Checking for updates...") or logger.debug("πŸ” Executing Neo4j query")

πŸ”— Service Connections

Emoji Usage Example
🐰 RabbitMQ logger.info("🐰 Connected to RabbitMQ")
πŸ”— Neo4j logger.info("πŸ”— Connected to Neo4j database")
🐘 PostgreSQL logger.info("🐘 Connected to PostgreSQL")
🌐 Network/API logger.info("🌐 Fetching from Discogs API")
πŸ“‘ Database index setup logger.info("πŸ“‘ Neo4j indexes created/verified")

πŸ’» Implementation Examples

Basic Service Startup

import structlog

logger = structlog.get_logger(__name__)  # Use structlog, not logging.getLogger()


async def start_service():
    logger.info("πŸš€ Starting dashboard service")

    try:
        logger.info("πŸ”§ Initializing database connections")
        await init_databases()
        logger.info("βœ… Database connections established")

        logger.info("πŸ₯ Starting health check server on port 8000")
        await start_health_server()

        logger.info("⏳ Waiting for messages...")
        await process_messages()

    except Exception as e:
        logger.error(f"❌ Service startup failed: {e}")
        raise
    finally:
        logger.info("πŸ›‘ Shutting down service")

Progress Tracking

async def process_batch(items: list[dict]) -> None:
    total = len(items)

    for i, item in enumerate(items, 1):
        if i % 1000 == 0:
            logger.info(f"πŸ“Š Processed {i}/{total} items")

        try:
            await process_item(item)
        except DuplicateError:
            logger.debug(f"⏩ Skipped duplicate item {item['id']}")
        except Exception as e:
            logger.warning(f"⚠️ Failed to process item {item['id']}: {e}")

    logger.info(f"βœ… Batch processing complete: {total} items")

Connection Management

async def connect_services():
    # RabbitMQ
    logger.info("🐰 Connecting to RabbitMQ...")
    try:
        await connect_rabbitmq()
        logger.info("🐰 RabbitMQ connection established")
    except Exception as e:
        logger.error(f"❌ RabbitMQ connection failed: {e}")
        raise

    # Neo4j
    logger.info("πŸ”— Connecting to Neo4j...")
    try:
        await connect_neo4j()
        logger.info("πŸ”— Neo4j connection established")
    except Exception as e:
        logger.error(f"❌ Neo4j connection failed: {e}")
        raise

Download Operations

async def download_file(url: str, filename: str):
    logger.info(f"πŸ“₯ Starting download: {filename}")

    try:
        total_size = await get_file_size(url)
        downloaded = 0

        async for chunk in download_chunks(url):
            downloaded += len(chunk)
            progress = (downloaded / total_size) * 100

            if progress % 10 == 0:  # Log every 10%
                logger.info(f"⬇️ Downloading {filename}: {progress:.0f}%")

        logger.info(f"βœ… Download complete: {filename}")
        logger.info(f"πŸ“„ Saved to: {filename}")

    except Exception as e:
        logger.error(f"❌ Download failed: {e}")
        raise

🎯 Best Practices

1. Appropriate Log Levels

# DEBUG - Detailed diagnostic info
logger.debug("πŸ” Checking cache for key: user_123")

# INFO - General informational messages
logger.info("πŸš€ Service started successfully")

# WARNING - Warning conditions
logger.warning("⚠️ Queue depth exceeding threshold")

# ERROR - Error conditions
logger.error("❌ Database connection lost")

# CRITICAL - Critical conditions
logger.critical("🚨 System out of memory")

2. Structured Context

# Include relevant context
logger.info(f"πŸ’Ύ Saved artist: id={artist_id}, name={artist_name}")

# Use structured logging where appropriate
logger.info(
    "πŸ“Š Processing stats", extra={"processed": 1000, "failed": 5, "duration": 45.2}
)

3. Consistent Formatting

# βœ… Good: Consistent format
logger.info("πŸš€ Starting service")
logger.info("πŸ”§ Loading configuration")
logger.info("βœ… Service ready")

# ❌ Bad: Inconsistent format
logger.info("πŸš€Starting service")  # Missing space
logger.info("πŸ”§  Loading configuration")  # Extra space
logger.info("Service ready")  # Missing emoji

4. Error Context

try:
    result = await risky_operation()
except SpecificError as e:
    # Include operation context
    logger.error(f"❌ Failed to process record {record_id}: {e}")
    # Re-raise or handle appropriately
    raise
except Exception as e:
    # Log unexpected errors with full context
    logger.exception(f"❌ Unexpected error in operation: {e}")
    raise

πŸ”§ Advanced Configuration

Basic Setup

All services use setup_logging() from common.config, which configures structlog with JSON output, reads LOG_LEVEL from the environment, and sets up file + console handlers:

import structlog
from pathlib import Path
from common import setup_logging

# Call once at service startup
setup_logging("service_name", log_file=Path("/logs/service_name.log"))

# Get a logger in each module
logger = structlog.get_logger(__name__)

πŸ’‘ Tip: Never call logging.basicConfig() directly in a service β€” setup_logging() handles everything including structlog configuration, third-party log suppression, and log file rotation.

JSON Logging (Production)

JSON logging is handled automatically by structlog via setup_logging(). The configured JSONRenderer uses orjson for efficient serialization. No custom JSONFormatter is needed.

πŸ” Troubleshooting

Service not respecting LOG_LEVEL

  1. Check environment variable is set:

    docker exec <container> printenv LOG_LEVEL
  2. Verify service startup logs:

    docker logs <container> | head -20
  3. Check for explicit level parameter (Python):

    # This overrides LOG_LEVEL
    setup_logging("service", level="WARNING")

Too much logging in production

  1. Set LOG_LEVEL=WARNING or LOG_LEVEL=ERROR
  2. Check third-party library log levels are suppressed (handled automatically)

Not enough logging for debugging

  1. Set LOG_LEVEL=DEBUG
  2. Restart the service
  3. Monitor logs: docker logs -f <container>

πŸ“Š Log Analysis

Finding Errors

# Using just command
just check-errors

# Manual grep
grep "❌" logs/*.log

# Count errors by type
grep -o "❌ [^:]*" logs/*.log | sort | uniq -c

Progress Tracking

# Monitor extractor progress (Rust β€” uses Docker logging only, no file-based log)
docker-compose logs extractor-discogs | grep "πŸ“Š" | tail -n 10

# Check completion
grep "βœ…" logs/*.log | grep "complete"

🚫 Anti-Patterns

# ❌ Don't: No emoji
logger.info("Starting service")

# ❌ Don't: Wrong emoji for context
logger.error("βœ… Connection failed")  # Success emoji for error

# ❌ Don't: Multiple spaces
logger.info("πŸš€  Starting service")

# ❌ Don't: Emoji at end
logger.info("Starting service πŸš€")

# ❌ Don't: Multiple emojis
logger.info("πŸš€ πŸ”§ Starting and configuring")

πŸ”„ Migration Notes

From RUST_LOG (Extractor)

Old:

environment:
  RUST_LOG: extractor=info,lapin=warn

New:

environment:
  LOG_LEVEL: INFO

From Verbose Flag (Extractor)

Old:

cargo run --verbose

New:

LOG_LEVEL=DEBUG cargo run

πŸ“ Best Practices Summary

  1. Development: Use DEBUG for detailed diagnostic information
  2. Staging: Use INFO to match production behavior
  3. Production: Use INFO or WARNING depending on volume
  4. Incident Response: Temporarily set to DEBUG for affected services
  5. Case Insensitive: LOG_LEVEL values are case-insensitive (debug == DEBUG)
  6. Container Logs: All logs go to stdout/stderr for container orchestration
  7. File Logs: Python services also write to /logs/<service>.log inside containers

πŸ“š Quick Reference Card

Lifecycle: πŸš€ Start | πŸ›‘ Stop | πŸ”§ Configure | πŸ₯ Health
Success:   βœ… Complete | πŸ’Ύ Saved | πŸ“‹ Loaded | πŸ†• New
Errors:    ❌ Error | ⚠️ Warning | 🚨 Critical | ⏩ Skip
Progress:  πŸ”„ Processing | ⏳ Waiting | πŸ“Š Stats | ⏰ Scheduled
Data:      πŸ“₯ Download | ⬇️ Downloading | πŸ“„ File | πŸ” Search/Query
Services:  🐰 RabbitMQ | πŸ”— Neo4j | 🐘 PostgreSQL | 🌐 Network

πŸ’‘ Tip: Set LOG_LEVEL=DEBUG to see detailed diagnostic logs including database queries marked with πŸ”

πŸ”— Related Documentation


Last Updated: 2026-03-07

Remember: Consistent logging makes debugging easier and operations smoother! 🎯