Logging Guide for CipherSwarm#

Overview#

CipherSwarm uses structured logging to provide comprehensive observability across all components of the system. This guide explains the logging infrastructure, formats, and best practices for debugging and monitoring.

Purpose#

Structured logging in CipherSwarm serves several key purposes:

• Debugging: Quickly identify and diagnose issues in development and production
• Monitoring: Track system health, performance, and agent behavior
• Auditing: Maintain records of important state changes and user actions
• Integration: Compatible with log aggregation services (ELK, Datadog, Splunk, etc.)

Benefits#

• Consistent Format: All logs use predictable, parseable formats with [LogType] prefixes
• Rich Context: Logs include relevant IDs, timestamps, and contextual information
• Sensitive Data Protection: Automatic filtering of passwords, tokens, and plaintext hashes
• Performance: Minimal overhead with efficient JSON serialization
• Searchability: Easy to query and filter logs by type and context

Lograge Configuration#

CipherSwarm uses Lograge to transform Rails request logs into structured JSON format.

Enabled Environments#

• ✅ Production: Fully enabled for production monitoring
• ✅ Development: Enabled to match production behavior
• ❌ Test: Disabled to avoid test pollution

JSON Format Structure#

Each HTTP request generates a single-line JSON log entry:

{
  "method": "GET",
  "path": "/campaigns/1",
  "format": "html",
  "controller": "CampaignsController",
  "action": "show",
  "status": 200,
  "duration": 45.23,
  "view": 32.1,
  "db": 8.45,
  "allocations": 15234,
  "host": "localhost:3000",
  "request_id": "abc123...",
  "user_agent": "Mozilla/5.0...",
  "ip": "192.168.1.100",
  "time": "2026-01-07T21:00:00.000Z",
  "user_id": 5,
  "agent_id": null,
  "task_id": null,
  "attack_id": null
}

Custom Payload Fields#

Lograge is configured to extract additional context from each request:

• user_id: Extracted from Devise current_user for web UI requests
• agent_id: Extracted from @agent, params[:agent_id], or authorization token
• task_id: Extracted from @task or params[:task_id]
• attack_id: Extracted from @attack, @task.attack, or params[:attack_id]

Ignored Paths#

The following paths are filtered out to reduce log noise:

• Health Checks: Rails::HealthController#show (no value in monitoring)
• Assets: /assets/* paths (handled by CDN/web server in production)

Configuration File#

Location: config/initializers/lograge.rb

Rails.application.configure do
  config.lograge.enabled = Rails.env.production? || Rails.env.development?
  config.lograge.formatter = Lograge::Formatters::Json.new
  config.lograge.custom_payload do |controller|
    {
      host: controller.request.host,
      request_id: controller.request.request_id,
      user_agent: controller.request.user_agent,
      ip: controller.request.remote_ip,
      time: Time.current,
      user_id: controller.try(:current_user)&.id,
      agent_id: controller.instance_variable_get(:@agent)&.id ||
                controller.params[:agent_id] ||
                controller.request.headers["Authorization"]&.split&.last&.then { |token| Agent.find_by(token: token)&.id },
      task_id: controller.instance_variable_get(:@task)&.id || controller.params[:task_id],
      attack_id: controller.instance_variable_get(:@attack)&.id ||
                 controller.instance_variable_get(:@task)&.attack_id ||
                 controller.params[:attack_id]
    }
  end
end

Exception Sanitization (Log-Injection Defense)#

The lograge custom_options lambda also emits exception_class, exception_message, and the first five backtrace frames when a request raises. To prevent log injection from attacker-controlled error text, the message is:

• Stripped of \r/\n so it cannot break the single-line JSON envelope.
• Coerced to a String (so a raw exception Class cannot surface).
• Truncated to 500 characters (EXCEPTION_MESSAGE_MAX_LEN) to bound log volume.

The pinning is enforced by spec/initializers/lograge_spec.rb so regressions are caught at CI time.

Sidekiq Background Job Logs#

CipherSwarm's Sidekiq workers emit single-line JSON via the formatter shipped with Sidekiq 8.x. The format mirrors lograge so the same log pipeline can ingest both layers without bespoke parsers.

Configuration File#

Location: config/initializers/sidekiq.rb

Sidekiq.configure_server do |config|
  config.logger = Sidekiq::Logger.new($stdout, level: Logger::INFO)
  config.logger.formatter = Sidekiq::Logger::Formatters::JSON.new
end

JSON Format Structure#

{
  "ts": "2026-05-15T10:00:01.234Z",
  "pid": 12,
  "tid": "abc",
  "lvl": "INFO",
  "msg": "start",
  "ctx": {
    "class": "ProcessHashListJob",
    "jid": "5f4dcc3b",
    "queue": "ingest"
  }
}

Argument Redaction#

Sidekiq 8.x's JobLogger never logs job arguments at any level — only the lifecycle markers (start, done, fail) plus the per-job context hash (jid, class, logged_job_attributes). Verified against sidekiq-8.1.5/lib/sidekiq/job_logger.rb. The :info level here is the standard production setting, not a redaction control.

Jobs that need to log argument context — for example ApplicationJob's discard_on handler — must run arguments through ActiveSupport::ParameterFilter.new(Rails.application.config.filter_parameters) before writing. See app/jobs/application_job.rb for the canonical pattern.

Backtrace Access for Postmortem#

Sidekiq's default ERROR_HANDLER emits ex.detailed_message (class + message, no backtrace) at the standard log level. The backtrace is only included when the logger is set to :debug. If you need a backtrace for a novel exception:

1. Edit config/initializers/sidekiq.rb and change level: Logger::INFO to level: Logger::DEBUG.
2. Restart the Sidekiq process (docker compose restart sidekiq in dev; orchestrator-specific in prod).
3. Reproduce the error.
4. Revert the change once you have what you need — DEBUG roughly doubles log volume.

The default stays at :info because backtraces from common, well-understood errors create more noise than signal in production.

Production Noise Suppression#

In production, ActionMailer and ActionCable are pinned to log level WARN — DEBUG/INFO per-event chatter is dropped, but WARN/ERROR/FATAL still reach $stdout and the JSON log stream:

• ActionMailer: per-delivery INFO lines disappear. Delivery failures still surface because raise_delivery_errors defaults to true (Rails 8.x default — verify on future upgrades) — raised SMTP errors propagate through the request stack and reach lograge's exception payload.
• ActionCable: per-subscribe/unsubscribe INFO chatter disappears, but cable connection rejections and channel errors at WARN+ still log. Cable subsystem WARN+ events do NOT route through controllers — they only surface via this logger, which is why we preserve WARN+ rather than dropping the logger entirely.

See config/environments/production.rb.

Useful jq Queries#

These are recipes for slicing the local docker compose logs JSON stream. For aggregator-side queries (Datadog/Splunk/Loki DSL) see the Common Queries section under Production Monitoring further down.

The structured JSON output is greppable, but most operator tasks compose more cleanly with jq. Examples:

# All HTTP requests that returned 5xx
docker compose logs web | jq -c 'select(.status >= 500)'

# All Sidekiq events for a specific job class
docker compose logs sidekiq | jq -c 'select(.ctx.class == "ProcessHashListJob")'

# Sidekiq errors only
docker compose logs sidekiq | jq -c 'select(.lvl == "ERROR")'

# Cross-layer correlation by agent_id (web only — Sidekiq does not carry agent_id today)
docker compose logs web | jq -c 'select(.agent_id == 7)'

# Slow requests above 1s
docker compose logs web | jq -c 'select(.duration > 1000)'

Log Types and Formats#

CipherSwarm uses four main log type prefixes to categorize different logging scenarios.

[APIRequest] Logs#

Tracks the lifecycle of API requests from start to completion.

START Log#

Logged at the beginning of each API request (before authentication).

Format:

[APIRequest] START - Agent {agent_id} - {method} {path} - {timestamp}

Example:

[APIRequest] START - Agent 42 - POST /api/v1/client/tasks/123/submit_status - 2026-01-07T21:00:00.000Z
[APIRequest] START - Agent unknown - GET /api/v1/client/configuration - 2026-01-07T21:00:05.000Z

Fields:

• agent_id: Authenticated agent ID or "unknown" if authentication hasn't occurred yet
• method: HTTP method (GET, POST, PATCH, DELETE)
• path: Request path
• timestamp: ISO 8601 timestamp

COMPLETE Log#

Logged after each API request completes (after response is rendered).

Format:

[APIRequest] COMPLETE - Agent {agent_id} - {method} {path} - Status {status} - Duration {duration}ms - {timestamp}

Example:

[APIRequest] COMPLETE - Agent 42 - POST /api/v1/client/tasks/123/submit_status - Status 204 - Duration 45.23ms - 2026-01-07T21:00:00.050Z
[APIRequest] COMPLETE - Agent unknown - GET /api/v1/client/configuration - Status 401 - Duration 12.34ms - 2026-01-07T21:00:05.015Z

Fields:

• agent_id: Authenticated agent ID or "unknown" for failed authentication
• method: HTTP method
• path: Request path
• status: HTTP response status code
• duration: Request duration in milliseconds (calculated from START time)
• timestamp: ISO 8601 timestamp

When They Appear#

• START: Before authenticate_agent callback in BaseController
• COMPLETE: After update_last_seen callback in BaseController
• Frequency: One START + one COMPLETE log per API request

Implementation#

Location: app/controllers/api/v1/base_controller.rb

before_action :log_api_request_start
after_action :log_api_request_complete

def log_api_request_start
  @api_request_start_time = Time.current
  agent_id = @agent&.id || "unknown"
  Rails.logger.info("[APIRequest] START - Agent #{agent_id} - #{request.method} #{request.path} - #{@api_request_start_time}")
rescue StandardError => e
  Rails.logger.error("Failed to log API request start: #{e.message}")
end

def log_api_request_complete
  agent_id = @agent&.id || "unknown"
  duration_ms = if @api_request_start_time
                  ((Time.current - @api_request_start_time) * 1000).round(2)
                else
                  "N/A"
                end
  Rails.logger.info("[APIRequest] COMPLETE - Agent #{agent_id} - #{request.method} #{request.path} - Status #{response.status} - Duration #{duration_ms}ms - #{Time.current}")
rescue StandardError => e
  Rails.logger.error("Failed to log API request completion: #{e.message}")
end

[APIError] Logs#

Tracks errors that occur during API request processing.

Error Types#

Format#

General:

[APIError] {ERROR_TYPE} - Agent {agent_id} - {method} {path} - Error: {message} - {timestamp}

With Context:

[APIError] {ERROR_TYPE} - Agent {agent_id} - Task {task_id} - Errors: {error_messages} - {timestamp}
[APIError] {ERROR_TYPE} - Agent {agent_id} - Attack {attack_id} - Errors: {error_messages} - {timestamp}

With Backtrace (UNHANDLED_ERROR):

[APIError] UNHANDLED_ERROR - Agent {agent_id} - {method} {path} - Error: {error_class} - {error_message} - Backtrace: {first_5_lines} - {timestamp}

Examples#

[APIError] JSON_PARSE_ERROR - Agent 42 - POST /api/v1/client/tasks/123/submit_status - Error: unexpected token at '{invalid json}' - 2026-01-07T21:00:00.000Z

[APIError] VALIDATION_ERROR - Agent 42 - POST /api/v1/client/agents/42 - Model: Agent - Errors: Name can't be blank - 2026-01-07T21:00:00.000Z

[APIError] TASK_ACCEPT_FAILED - Agent 42 - Task 123 - Errors: State transition failed - 2026-01-07T21:00:00.000Z

[APIError] UNHANDLED_ERROR - Agent 42 - GET /api/v1/client/tasks/new - Error: NoMethodError - undefined method `foo' for nil:NilClass - Backtrace: app/controllers/api/v1/client/tasks_controller.rb:45:in `new'\n... - 2026-01-07T21:00:00.000Z

When They Appear#

• When rescue_from blocks catch exceptions in BaseController
• When specific error conditions are detected in controller actions
• For all API errors that return 4xx or 5xx status codes

Implementation#

Errors are caught and logged in app/controllers/api/v1/base_controller.rb and individual controller actions.

Task Error Logging Helper#

For task-related API errors, the TaskErrorHandling concern provides a centralized logging helper method:

Location: app/controllers/concerns/task_error_handling.rb

# Logs an API error for a task-related operation in a consistent structured format.
# Centralizes the [APIError] log pattern used across task state transition failures.
#
# @param code [String] The error code (e.g., "TASK_ABANDON_FAILED", "ATTACK_ACCEPT_FAILED")
# @param agent [Agent] The agent involved in the operation
# @param task [Task] The task involved in the operation
# @param error_messages [Array<String>, String] Error message(s) to include
def log_task_api_error(code, agent, task, error_messages)
  messages = Array(error_messages).join(", ")

  Rails.logger.error(
    "[APIError] #{code} - Agent #{agent.id} - Task #{task.id} - " \
    "Errors: #{messages} - #{Time.current}"
  )
end

Usage Example:

Instead of inline logging:

# ❌ Avoid: Inline logging (duplicates format string)
Rails.logger.error("[APIError] TASK_ABANDON_FAILED - Agent #{@agent.id} - Task #{@task.id} - Errors: #{@task.errors.full_messages.join(', ')} - #{Time.current}")

Use the helper method:

# ✅ Preferred: Use the helper method
log_task_api_error("TASK_ABANDON_FAILED", @agent, @task, @task.errors.full_messages)

This helper is used in TasksController for all task-related error logging:

• TASK_ABANDON_FAILED
• TASK_ACCEPT_FAILED
• ATTACK_ACCEPT_FAILED
• TASK_EXHAUST_FAILED

[AgentLifecycle] Logs#

Tracks important agent state transitions and lifecycle events.

Event Types#

Formats#

Connect:

[AgentLifecycle] connect: agent_id={id} state_change={old}->{new} last_seen_at={time} ip={ip} timestamp={time}

Disconnect:

[AgentLifecycle] disconnect: agent_id={id} state_change={old}->{new} last_seen_at={time} ip={ip} timestamp={time}

Shutdown:

[AgentLifecycle] shutdown: agent_id={id} state_change={old}->{new} running_tasks_abandoned={count} timestamp={time}
[AgentLifecycle] shutdown_success: agent_id={id} state={state} timestamp={time}
[AgentLifecycle] shutdown_failed: agent_id={id} state={state} errors={error_messages} timestamp={time}

Reconnect:

[AgentLifecycle] reconnect: agent_id={id} state_change={old}->{new} last_seen_at={time} ip={ip} timestamp={time}

Heartbeat Timeout:

[AgentLifecycle] heartbeat_timeout: agent_id={id} state_change={old}->{new} last_seen_at={time} threshold={config} timestamp={time}
[AgentLifecycle] heartbeat_threshold_exceeded: agent_id={id} last_seen_at={time} threshold={config} timestamp={time}

Benchmark Complete:

[AgentLifecycle] benchmark_complete: agent_id={id} state_change={old}->{new} benchmark_count={count} timestamp={time}

Examples#

[AgentLifecycle] connect: agent_id=42 state_change=pending->active last_seen_at=2026-01-07T21:00:00.000Z ip=192.168.1.100 timestamp=2026-01-07T21:00:00.000Z

[AgentLifecycle] shutdown: agent_id=42 state_change=active->offline running_tasks_abandoned=3 timestamp=2026-01-07T21:05:00.000Z
[AgentLifecycle] shutdown_success: agent_id=42 state=offline timestamp=2026-01-07T21:05:00.100Z

[AgentLifecycle] reconnect: agent_id=42 state_change=offline->active last_seen_at=2026-01-07T21:10:00.000Z ip=192.168.1.100 timestamp=2026-01-07T21:10:00.000Z

[AgentLifecycle] heartbeat_timeout: agent_id=42 state_change=active->offline last_seen_at=2026-01-07T19:00:00.000Z threshold=3600 timestamp=2026-01-07T21:00:00.000Z

[AgentLifecycle] benchmark_complete: agent_id=42 state_change=active->benchmarked benchmark_count=15 timestamp=2026-01-07T21:00:00.000Z

When They Appear#

• When agent state transitions occur via state machine callbacks
• After important agent operations complete
• When timeout thresholds are exceeded

Implementation#

Location: app/models/agent.rb

Lifecycle events are logged in state machine after_transition callbacks:

state_machine :state do
  after_transition on: :shutdown do |agent, transition|
    # Log shutdown event
  end

  after_transition on: :activate do |agent, transition|
    # Log connect event
  end

  # ... etc
end

[BroadcastError] Logs#

Tracks failures in Turbo Stream broadcasts to prevent application crashes.

Format#

[BroadcastError] Model: {model_name} - Record ID: {record_id} - Error: {error_message}
Backtrace:
{first_5_backtrace_lines}

Example#

[BroadcastError] Model: Agent - Record ID: 42 - Error: Connection refused - connect(2) for "localhost" port 6379
Backtrace:
/path/to/redis/client.rb:123:in `connect'
/path/to/turbo/broadcastable.rb:45:in `broadcast_refresh'
app/models/agent.rb:234:in `block in <class:Agent>'
app/controllers/agents_controller.rb:67:in `update'
...

When They Appear#

• When Turbo Stream broadcasts fail (Redis connection issues, network problems, etc.)
• During model updates that trigger broadcasts_refreshes or similar broadcasts
• Should be rare in production but critical to catch

Affected Models#

Models that include SafeBroadcasting concern:

• Agent
• Task
• Attack
• Campaign
• User
• AgentError
• HashList
• Project
• HashcatBenchmark
• WordList
• RuleList
• MaskList

Implementation#

Location: app/models/concerns/safe_broadcasting.rb

module SafeBroadcasting
  extend ActiveSupport::Concern

  included do
    after_commit :safe_broadcast_refresh, if: :previously_new_record?
    after_update_commit :safe_broadcast_update
  end

  private

  def safe_broadcast(method)
    send(method)
  rescue StandardError => e
    Rails.logger.error("[BroadcastError] Model: #{self.class.name} - Record ID: #{id} - Error: #{e.message}")
    Rails.logger.error("Backtrace:\n#{e.backtrace.first(5).join("\n")}")
  end

  def safe_broadcast_refresh
    safe_broadcast(:broadcast_refresh)
  end

  def safe_broadcast_update
    safe_broadcast(:broadcast_update)
  end
end

Sensitive Data Filtering#

CipherSwarm automatically filters sensitive parameters from all logs to protect user data.

Filtered Parameters#

The following parameter names (or partial matches) are filtered:

How Filtering Works#

Rails' built-in ActiveSupport::ParameterFilter automatically replaces filtered values with [FILTERED] in logs.

Before filtering:

{
  "user": {
    "email": "user@example.com",
    "password": "supersecret123",
    "name": "John Doe"
  },
  "agent": {
    "token": "abc123xyz789"
  }
}

After filtering:

{
  "user": {
    "email": "[FILTERED]",
    "password": "[FILTERED]",
    "name": "John Doe"
  },
  "agent": {
    "token": "[FILTERED]"
  }
}

Configuration#

Location: config/initializers/filter_parameter_logging.rb

Rails.application.config.filter_parameters += %i[
  passw email secret token _key crypt salt certificate otp ssn cvv cvc plain_text hash_value
]

Verification#

To verify sensitive data is filtered:

1. Development Testing:

   ⧉

   just dev
   # Make requests with sensitive data
   # Search logs for actual values (should not appear)
   grep -r "supersecret123" log/
   # Should return no results
   

2. Log Review:

   • Review logs after authentication requests
   • Review logs after crack submissions
   • Verify passwords, tokens, and plaintext hashes show as [FILTERED]

3. Automated Testing:

   • RSpec tests verify filtering is configured
   • Integration tests verify sensitive data doesn't appear in log output

Development Testing#

Enabling Lograge in Development#

Lograge is already enabled in development to match production behavior. No configuration changes needed.

Viewing Logs#

Start the development server:

just dev

Logs will appear in the terminal with JSON format (single line per request).

Testing Specific Scenarios#

Test API Request Logging#

# In terminal 1: Start server
just dev

# In terminal 2: Make API requests
curl -H "Authorization: Bearer YOUR_AGENT_TOKEN" \
  http://localhost:3000/api/v1/client/configuration

# Check logs for:
# [APIRequest] START - Agent X - GET /api/v1/client/configuration
# [APIRequest] COMPLETE - Agent X - GET /api/v1/client/configuration - Status 200 - Duration XXms

Test Agent Lifecycle Logging#

# Create agent and trigger state transitions
rails console

agent = Agent.create!(name: "Test Agent", ...)
agent.activate # Check for [AgentLifecycle] connect log
agent.shutdown # Check for [AgentLifecycle] shutdown log

Test Broadcast Error Handling#

# Temporarily stop Redis
brew services stop redis

# Update a model
rails console
agent = Agent.first
agent.update(name: "New Name")

# Check for [BroadcastError] log (application should continue working)

# Restart Redis
brew services start redis

Verifying Sensitive Data Filtering#

# Make request with sensitive data
curl -X POST http://localhost:3000/api/v1/client/tasks/123/submit_crack \
  -H "Authorization: Bearer TOKEN" \
  -H "Content-Type: application/json" \
  -d '{"hash": "abc123", "plain_text": "password123"}'

# Search logs for plaintext (should not appear)
grep "password123" log/development.log
# Should return no results

Production Monitoring#

Log Aggregation Services#

CipherSwarm's structured JSON logs are compatible with:

• ELK Stack (Elasticsearch, Logstash, Kibana)
• Datadog
• Splunk
• Papertrail
• Loggly
• CloudWatch (AWS)
• Stackdriver (GCP)

Common Queries#

For local Docker-compose stdout streams, see the Useful jq Queries section earlier in this doc. The recipes below are aggregator-side queries (Datadog/Splunk/Loki).

Find All API Errors#

[APIError]

Find Agent Connection Issues#

[AgentLifecycle] AND (heartbeat_timeout OR disconnect OR shutdown_failed)

Find Broadcast Failures#

[BroadcastError]

Find Slow API Requests#

[APIRequest] COMPLETE AND Duration > 1000ms

Find Authentication Failures#

[APIRequest] COMPLETE AND Status 401

Find Specific Agent Activity#

[APIRequest] AND "Agent 42"

[AgentLifecycle] AND "agent_id=42"

Recommended Alerts#

Critical Alerts#

• Unhandled Errors: Any [APIError] UNHANDLED_ERROR log
• Agent Shutdown Failures: Any [AgentLifecycle] shutdown_failed log
• High Error Rate: More than 10 [APIError] logs per minute

Warning Alerts#

• Broadcast Failures: More than 5 [BroadcastError] logs per minute
• Agent Timeouts: More than 5 [AgentLifecycle] heartbeat_timeout logs per hour
• Authentication Failures: More than 20 failed auth attempts per minute (potential attack)

Performance Alerts#

• Slow API Requests: Average API duration > 500ms over 5 minutes
• High API Volume: More than 1000 API requests per minute (capacity planning)

Recommended Dashboards#

API Performance Dashboard#

• API request volume (requests per minute)
• API response time (p50, p95, p99)
• API error rate (errors per minute)
• API status code distribution

Agent Activity Dashboard#

• Active agents count
• Agent connections per hour
• Agent disconnections per hour
• Agent heartbeat timeouts per hour
• Agent state distribution

Error Dashboard#

• Error rate by type
• Top 10 error messages
• Error rate by agent
• Error rate by endpoint

Broadcast Health Dashboard#

• Broadcast error rate
• Broadcast errors by model
• Time since last broadcast error

Best Practices#

When to Add Logging#

✅ Do Log:

• State transitions (agent, task, attack, campaign)
• API request start and completion
• Errors and exceptions
• Important business events (crack submission, task completion)
• Performance-critical operations

❌ Don't Log:

• Inside tight loops (performance impact)
• Sensitive data (passwords, tokens, plaintext)
• Excessive debug information in production
• Every database query (use tools like Bullet instead)

Log Level Guidelines#

• info: Normal operations, state transitions, API requests
• warn: Degraded performance, approaching thresholds, recoverable errors
• error: Errors that prevent operations, unhandled exceptions
• debug: Detailed diagnostic information (development only)

Structured Logging Format#

Always use the [LogType] prefix format:

Rails.logger.info("[AgentLifecycle] connect: agent_id=#{agent.id} state_change=#{from}->#{to} timestamp=#{Time.current}")

Not:

Rails.logger.info("Agent #{agent.id} connected") # ❌ Unstructured, hard to parse

Centralizing Log Patterns#

When the same log format is used in multiple places, extract it to a helper method:

# ✅ Good: Centralized in a concern
def log_task_api_error(code, agent, task, error_messages)
  messages = Array(error_messages).join(", ")
  Rails.logger.error("[APIError] #{code} - Agent #{agent.id} - Task #{task.id} - Errors: #{messages} - #{Time.current}")
end

# Usage
log_task_api_error("TASK_ABANDON_FAILED", @agent, @task, @task.errors.full_messages)

Benefits:

• Consistency: Ensures all logs of the same type use identical formatting
• Maintainability: Single place to update format if needed
• Testability: Easier to test log patterns in isolation
• DRY: Reduces code duplication across controllers

See TaskErrorHandling#log_task_api_error in the APIError Implementation section for a real example.

Including Context#

Always include relevant IDs and timestamps:

Rails.logger.error("[APIError] VALIDATION_ERROR - Agent #{@agent.id} - Task #{@task.id} - Errors: #{@task.errors.full_messages.join(', ')} - #{Time.current}")

Error Handling#

Always rescue logging failures to prevent application crashes:

def log_api_request_start
  # ... logging code ...
rescue StandardError => e
  Rails.logger.error("Failed to log API request start: #{e.message}")
end

Testing Logging#

Always test that important events are logged:

it "logs agent shutdown" do
  agent = create(:agent, state: "active")
  expect(Rails.logger).to receive(:info).with(/\[AgentLifecycle\] shutdown:/)
  agent.shutdown
end

Troubleshooting#

Logs Not Appearing#

1. Check Lograge is enabled:

   ⧉

   # In rails console
   Rails.application.config.lograge.enabled
   # Should return true
   

2. Check log level:

   ⧉

   Rails.logger.level
   # Should return 1 (info) or lower
   

3. Check log output location:

   ⧉

   Rails.logger.instance_variable_get(:@logdev).filename
   # Should show log file path
   

Excessive Log Volume#

1. Reduce log level in production:

   ⧉

   config.log_level = :warn
   

2. Add more ignored paths to Lograge configuration

3. Implement log sampling for high-volume endpoints

Logs Missing Context#

1. Verify custom_payload is configured in Lograge initializer
2. Check instance variables are set before logging
3. Add more context to log messages

Performance Impact#

If logging impacts performance:

1. Use log level filtering (don't log debug in production)
2. Move expensive operations out of log statements
3. Use background jobs for complex logging
4. Implement log sampling for high-volume events

Resources#

• Lograge Documentation
• Rails Logging Guide
• Structured Logging Best Practices
• CipherSwarm AGENTS.md