Frappe Core Logging

Frappe Logging & Error Tracking

Three Logging Mechanisms

---

Decision Tree

Need to log something?
│
├─ Application logging (info, debug, warnings)?
│  └─ frappe.logger("my_module").info("message")
│     → Writes to sites/{site}/logs/my_module.log
│
├─ Error that admins should see in Desk UI?
│  └─ frappe.log_error(title="Short desc", message=traceback)
│     → Creates Error Log document (queryable, auto-cleanup)
│
├─ Quick debug during development?
│  └─ frappe.errprint(variable) — shows in console
│     → NEVER leave in production code
│
├─ Track all HTTP requests?
│  └─ Set enable_frappe_logger: true in site_config.json
│     → Logs to frappe.web.log
│
├─ Performance monitoring?
│  └─ Set monitor: true in site_config.json
│     → Logs to monitor.json.log (JSON, per-request metrics)
│
└─ External error tracking (Sentry)?
   └─ Set FRAPPE_SENTRY_DSN environment variable
      → Auto-captures unhandled exceptions

---

Quick Reference: frappe.logger()

# Get a logger for your module (ALWAYS specify module name)
logger = frappe.logger("my_app")

# Standard Python logging levels
logger.debug("Detailed diagnostic info")
logger.info("Normal operations: processed 50 records")
logger.warning("Something unexpected but recoverable")
logger.error("Operation failed", exc_info=True)
logger.critical("System-level failure")

# Full signature
frappe.logger(
    module=None,          # Logger name + log filename
    with_more_info=False, # Auto-log request form_dict
    allow_site=True,      # Log under site's logs/ directory
    filter=None,          # Custom logging.Filter
    max_size=100_000,     # Max bytes per log file (100KB default)
    file_count=20         # Rotated files retained (20 default)
)

Log location: sites/{site}/logs/{module}.log Rotation: RotatingFileHandler — 100KB per file, 20 backups (~2MB total per logger)

Default Log Levels

# Change level dynamically
frappe.utils.logger.set_log_level("DEBUG")

---

Quick Reference: frappe.log_error()

# ALWAYS use keyword arguments (title/message can swap otherwise)
frappe.log_error(
    title="Payment gateway timeout",          # Short description (140 chars max)
    message=frappe.get_traceback(),            # Full error details
    reference_doctype="Payment Entry",        # Related DocType
    reference_name="PE-00001"                 # Related document
)

# Minimal — auto-captures current traceback
try:
    risky_operation()
except Exception:
    frappe.log_error(title="Operation failed")

Error Log cleanup: Auto-deletes after 30 days. Manual: frappe.whitelist: clear_error_logs()

Auto-Captured Exceptions

Unhandled exceptions (HTTP 500+) are automatically logged to Error Log.

Excluded from auto-capture:

• frappe.AuthenticationError
• frappe.CSRFTokenError
• frappe.SecurityException
• frappe.InReadOnlyMode

---

Production Configuration

site_config.json Keys

Environment Variables

Production Log Files

---

Anti-Patterns

---

Version Differences

---

Reference Files

• Logger API & Patterns — frappe.logger() advanced usage
• Error Tracking — Error Log, Sentry, monitoring

Error Tracking — Error Log, Sentry, Monitoring

Error Log DocType

Creating Error Log Entries

# ALWAYS use keyword arguments
frappe.log_error(
    title="Short description",              # 140 chars max
    message="Full traceback or details",    # Unlimited
    reference_doctype="Sales Order",        # Optional: related DocType
    reference_name="SO-00001"               # Optional: related document
)

# Minimal — auto-captures current traceback
try:
    process_order(order)
except Exception:
    frappe.log_error(title=f"Order processing failed: {order.name}")

# With explicit traceback
import traceback
try:
    risky_call()
except Exception:
    frappe.log_error(
        title="External API failure",
        message=frappe.get_traceback(with_context=True)
    )

Error Log Schema

Querying Error Logs

# Recent errors for a specific module
errors = frappe.get_all("Error Log",
    filters={"method": ["like", "%payment%"]},
    fields=["name", "method", "creation"],
    order_by="creation desc",
    limit=10
)

# Errors for a specific document
errors = frappe.get_all("Error Log",
    filters={
        "reference_doctype": "Sales Order",
        "reference_name": "SO-00001"
    }
)

Cleanup

# Auto-cleanup: 30 days default
from frappe.core.doctype.error_log.error_log import ErrorLog
ErrorLog.clear_old_logs(days=30)

# Manual full cleanup (System Manager only)
# Via Desk: Error Log list → Menu → Clear Error Logs
# Via API: frappe.client.clear_error_logs()

Auto-Captured Exceptions

Unhandled exceptions returning HTTP 500+ are automatically captured.

NOT auto-captured:

• frappe.AuthenticationError — expected for login failures
• frappe.CSRFTokenError — expected for token mismatches
• frappe.SecurityException — expected for access violations
• frappe.InReadOnlyMode — expected during maintenance

Disable auto-capture:

// site_config.json
{"disable_error_snapshot": true}

---

Sentry Integration

Setup

# Set DSN as environment variable
export FRAPPE_SENTRY_DSN="https://key@sentry.io/project"

# Optional: database monitoring
export ENABLE_SENTRY_DB_MONITORING=1

# Optional: performance tracing
export SENTRY_TRACING_SAMPLE_RATE=0.1    # 10% of requests

# Optional: profiling
export SENTRY_PROFILING_SAMPLE_RATE=0.01  # 1% of requests

Requirement: enable_telemetry system setting must be enabled.

What Gets Captured

• Unhandled exceptions (excluding ValidationError, PermissionError)
• Request context (JSON body, form data — auto-sanitized)
• User and site identification
• SQL queries as spans (when DB monitoring enabled)
• Trace ID propagation via X-Frappe-Request-Id header

Filtered Exceptions (NOT sent to Sentry)

FILTERED_EXCEPTIONS = [
    frappe.AuthenticationError,
    frappe.CSRFTokenError,
    frappe.SecurityException,
    frappe.ValidationError,      # User input errors
    frappe.PermissionError,      # Access control
]

---

Request Monitoring

Enable

// site_config.json
{"monitor": true}

What Gets Logged

HTTP Requests:

• Timestamp, UUID, trace_id
• Duration (microseconds)
• Client IP, HTTP method, path
• Response status code, size

Background Jobs:

• Method name, queue
• Duration, wait time
• Success/failure

Output

JSON lines in logs/monitor.json.log. Data buffered in Redis, flushed periodically. Max 1M entries in Redis before trimming.

Parsing Monitor Data

import json

with open("logs/monitor.json.log") as f:
    for line in f:
        entry = json.loads(line)
        if entry.get("duration", 0) > 5_000_000:  # > 5 seconds
            print(f"Slow request: {entry['path']} took {entry['duration']/1e6:.1f}s")

---

Request Logging

Enable

// site_config.json
{"enable_frappe_logger": true}

Output

Logs to logs/frappe.web.log with fields:

• Site name, remote IP, PID
• Username, URL, HTTP method
• Scheme, HTTP status code

---

Debug Helpers (Development Only)

# Print to console (development only — NOT for production)
frappe.errprint(variable)    # → stderr + frappe.error_log (request-scoped)
frappe.log("debug message")  # → stderr + frappe.debug_log (request-scoped)

# These are returned in API responses during development:
# frappe.error_log → response.exc
# frappe.debug_log → response._debug_messages

NEVER use frappe.errprint() or frappe.log() in production code. They are request-scoped debug helpers that don't persist.

---

Common Production Setup

// site_config.json — recommended production settings
{
    "enable_frappe_logger": true,
    "monitor": true,
    "logging": 0
}

# Environment — recommended for production
export FRAPPE_SENTRY_DSN="https://..."
export SENTRY_TRACING_SAMPLE_RATE=0.05

# For Docker/containers
export FRAPPE_STREAM_LOGGING=1

Logger API & Patterns — frappe.logger()

Basic Usage

# ALWAYS specify module name — creates separate log file per module
logger = frappe.logger("my_app")

# Standard Python logging API
logger.debug("Processing batch of 100 items")
logger.info("Successfully synced 50 records")
logger.warning("API rate limit approaching: 80% used")
logger.error("Payment gateway returned 503", exc_info=True)
logger.critical("Database connection pool exhausted")

Logger Parameters

frappe.logger(
    module="my_app",       # → sites/{site}/logs/my_app.log
    with_more_info=False,  # True → appends form_dict to each log line
    allow_site=True,       # True → site-level logs; str → specific site
    filter=None,           # Custom logging.Filter function
    max_size=100_000,      # 100KB per file (default)
    file_count=20          # 20 backup files (default)
)

Common Patterns

Module-Level Logger

# In your app's Python module — create once, reuse everywhere
import frappe

def process_payments():
    logger = frappe.logger("payment_gateway")
    logger.info("Starting payment batch processing")

    for payment in payments:
        try:
            result = gateway.charge(payment)
            logger.debug(f"Payment {payment.name}: {result.status}")
        except Exception as e:
            logger.error(f"Payment {payment.name} failed: {e}", exc_info=True)
            # Also create visible Error Log for admin
            frappe.log_error(
                title=f"Payment failed: {payment.name}",
                reference_doctype="Payment Entry",
                reference_name=payment.name
            )

    logger.info(f"Batch complete: {len(payments)} payments processed")

Background Job Logging

def sync_inventory():
    logger = frappe.logger("inventory_sync", max_size=500_000, file_count=10)
    logger.info("Inventory sync started")

    try:
        items = fetch_from_erp()
        logger.info(f"Fetched {len(items)} items from ERP")

        for item in items:
            update_stock(item)

        logger.info("Inventory sync completed successfully")
    except Exception:
        logger.error("Inventory sync failed", exc_info=True)
        frappe.log_error(title="Inventory sync failed")
        raise

Request Context Logging

# with_more_info=True → SiteContextFilter adds form_dict to logs
logger = frappe.logger("api_audit", with_more_info=True)
logger.info("API endpoint accessed")
# Log output includes: site name + sanitized request data
# Sensitive fields (password, token, secret, key, pwd) auto-masked as "********"

Custom Filter

import logging

class MinLevelFilter(logging.Filter):
    def __init__(self, min_level):
        self.min_level = min_level

    def filter(self, record):
        return record.levelno >= self.min_level

# Only log WARNING and above for this specific logger
logger = frappe.logger("noisy_module", filter=MinLevelFilter(logging.WARNING))

Stream Logging (Docker/Container)

For containerized deployments where file logging is impractical:

# Environment variable — all loggers go to stderr instead of files
export FRAPPE_STREAM_LOGGING=1

This replaces RotatingFileHandler with a StreamHandler(stderr).

Changing Log Level at Runtime

# Set globally — clears all cached loggers
frappe.utils.logger.set_log_level("DEBUG")

# Affects all subsequent frappe.logger() calls
# Reset by restarting workers/gunicorn

Log File Locations

frappe-bench/
├── logs/                          # Bench-level (all sites)
│   ├── frappe.log                 # Default frappe logger
│   ├── frappe.web.log             # HTTP request log
│   ├── web.error.log              # Supervisor HTTP errors
│   ├── worker.error.log           # Supervisor job errors
│   └── monitor.json.log           # Performance metrics
└── sites/
    └── mysite.localhost/
        └── logs/                  # Site-level
            ├── my_app.log         # frappe.logger("my_app")
            ├── payment_gateway.log
            └── inventory_sync.log

Database Query Logging

# Log a specific query's execution time
result = frappe.db.sql("SELECT ...", debug=True)
# Prints: query text + execution time via frappe.log()

# Log ALL queries (site_config.json)
# "logging": 2
# WARNING: massive I/O — development only!