🚧 Under Construction! Full version coming soon! 🚧

Rails Maze

Rails Tome: Production Debugging

Rails Tome: Production Debugging

Published on

Production bugs are like ancient curses: invisible, persistent, and always triggered by ‘nothing changing.’ This tome won’t save you, but it’ll make you feel slightly more in control.

Welcome, brave soul. You deployed on a Friday, promising a smooth release. Now your app is haunted, production data is slowly mutating, and your sanity frays as you scour logs for any trace of hope that might let you sleep tonight. Fear not! The Tome of Production Debugging has spells, stack traces, and side-effect sorcery to help.

⚠️ CAUTION! ⚠️ We will be working with some extremely sharp tools in this article. It's recommended that you do NOT deploy code with ANY of these hacks in it, as eval-type actions are major security risks. It's recommended that you use rails c and stick strictly to read-only calls.

Logging

If you're in emergency triage mode, feel free to skip ahead to the code snippets. This section is for the calm before (or after) the storm.

Before diving into the arcane wizardry, it is important to start with the basics. In order to figure out how to solve a problem, you must first understand it. The most reliable way to do this is to ensure that you are providing logs that mean something and provide enough context to be useful in a crisis.

Rails comes with the ability to tag logs so you can easily search for them using whatever log analysis tool you prefer. This can be done using Rails.logger.tagged. For example:

Rails.logger.tagged("UserID: #{user.id}") { Rails.logger.info("Started processing") }

# Will write to the logs like...
# [UserID: 123] [RequestID: 45fa2] Started processing

This can be an absolute life-saver if you took the time to set these up in key areas of your code. It can very easily turn situations where you are log fishing into traceable narratives and gives you predictable strings to filter on when production gets weird.

Automatic Request ID Logging

If you'd like to establish a stronger default tagging system without resorting to third-party tools, you can establish global log_tags preemptively using Rails::Rack::Logger and ActionDispatch::RequestId middleware that will help keep things more transparent in your controller actions. This will allow you to trace the request_id back through the logs so you can follow the full request lifecycle more closely.

You can do that with something like this setup. Feel free to add any other request or response data, but be careful about adding too much! Always be aware of PII and try to keep your logs precise :

# config/initializers/logger.rb

Rails.application.configure do
  config.log_tags = [
    ->(req) { "RequestID: #{req.request_id}" },
    ->(req) { "UserID: #{Current.user&.id || 'guest'}" }
  ]
end

You will need to establish a class similar to the one below that inherits from ActiveSupport::CurrentAttributes, which is the way that rails handles thread-safe global state. If you want to learn more about it, here are the docs:

# app/models/current.rb
# Could also go into a utils directory. It doesn't have to be a 'model'. 

class Current < ActiveSupport::CurrentAttributes
  attribute :user
end

Then in your ApplicationController:

class ApplicationController < ActionController::Base
  before_action :set_current_user

  def set_current_user
    Current.user = current_user if defined?(current_user)
  end
end

Now, you will have log entries that look something more like this:

[RequestID: 0a1b2c3d4e] [UserID: 42] Started GET "/posts"

Global Use Tagged Logger

If you'd like to establish a robust global logging solution, you can write a tagged logger utility that can be included into any context for ease of use.

First, we need to establish the base logging utility class. You can call this globally:

# lib/tagged_logger.rb
class TaggedLogger
  def self.logger
    base = Rails.logger
    ActiveSupport::TaggedLogging.new(base)
  end

  def self.tagged(tags = {}, &block)
    formatted_tags = tags.map { |k, v| "#{k.to_s.titleize.gsub(' ', '')}: #{v}" }
    logger.tagged(*formatted_tags, &block)
  end
end

Note: We titleize and clean tag keys so that user_id: 42 becomes [UserID: 42]. Feel free to adjust formatting to your preference.

From here, you can invoke it using code similar to this. The block is for extra flexibility and to provide more context to specific log actions. Sometimes, you simply need more contextual information!

TaggedLogger.tagged(user_id: user.id, job: self.class.name) do
  Rails.logger.info("Starting processing...")
end

# [UserID: 42] [Job: SomeJobClass] Starting processing...

You can also add it as a wrapper to override or established logging behavior in other places. For example, we can override logger on ActiveJob::Base with our custom logger:

class ApplicationJob < ActiveJob::Base
  def logger
    TaggedLogger.logger
  end
end

Then, in your jobs:

logger.tagged("Job: #{self.class.name}") do
  logger.info("Doing stuff")
end

# [Job: SomeJobClass] Doing stuff

This ensures a consistent logging experience across all your background processing.

Remember that in order to get the correct logging behavior, you will need to ultimately make sure that the logger is wrapped in ActiveSupport::TaggedLogging to get the tagged output Otherwise, you will just end up with normal logs without the [Tag: Value] pieces!

You can ensure that this is set globally by wrapping the logger in an initializer:

Rails.logger = ActiveSupport::TaggedLogging.new(Logger.new(STDOUT))
Rails Maze Logo Divider

Console Setup & Safe Debugging Environment

If you want to work with a model directly and you want to be extra safe, you can always set readonly!:

user = User.find(42)
user.readonly!
user.save  # => Raises ActiveRecord::ReadOnlyRecord

Use rails c --sandbox

Passing the --sandbox flag is an often-overlooked but profoundly powerful feature. This provides you with a few distinct advantages:

  • Starts a Rails console in a database transaction.

  • All changes will be rolled back on exit, making it perfect for experimentation — just avoid APIs or filesystem side effects.

rails console --sandbox
User.create!(email: "test@example.com")
# => Inserts the user

User.count
# => Includes the new user

exit
# => Transaction rolls back automatically

This is ideal for testing validations, model callbacks, or ActiveRecord behavior without risking persistent changes.

Use binding.irb

Sometimes you need to be able to set debug breakpoints and inspect runtime state. This can be extremely powerful and doesn't require a gem like pry, making it safe for environments where minimal dependencies are ideal.

  • Drops into an interactive IRB session at the exact line it’s called.

  • Execution pauses and waits for your input.

  • Gives you access to all local variables and method context.

class SomeService
  def perform
    puts "before debug"
    binding.irb  # Execution will pause here
    puts "after debug"
  end
end

When that line of code is run, regardless of context, the Rails process will pause and provide you with an IRB prompt. Used with care, this gives you real-time observability and can be a production debugging superpower. When combined with runtime patches, scoped queries, or read-only mode, you can significantly increase your productivity while remaining as cognizant of production data integrity as possible.

Rails Maze Logo Divider

Temporary Method & Scope Injection

Use class_eval for Temporary Methods

Use class_eval to dynamically add read-only helper methods to a model.

Great for better inspection during debugging — no source file edits required.

User.class_eval do
  def debug_info
    "#{email} - signed up at #{created_at}"
  end
end

Use instance_eval to Explore or Temporarily Modify a Specific Object

Good when you don't want to affect the global class behavior. instance_eval lets you inject behavior into one specific object, without affecting the whole class.

user = User.find(42)

user.instance_eval do
  def debug_info
    "#{email} - signed up at #{created_at}"
  end
end

Add Temporary Scopes via class_eval or define_method

Need a custom scope just for your session? Particularly useful when debugging association issues or narrowing down noisy datasets without having to construct large queries in the console directly.

# Using class_eval
User.class_eval do
  scope :recent_signups, -> { where("created_at > ?", 1.week.ago) }
end

User.recent_signups
# Using define_singleton_method
User.define_singleton_method(:recent_signups) do
  where("created_at > ?", 1.week.ago)
end

User.recent_signups
Rails Maze Logo Divider

Monkey Patching & Behavior Overrides

Monkey-Patch Behavior in Console

⚠️ CAUTION! ⚠️ Be extremely careful! If you have tangled callbacks or tightly coupled code, this can be unexpectedly destructive. These techniques should be used for data recovery or debugging purposes. Never use these in normal flow!

You can override any method to help you debug. Sometimes, bugs hide behind tightly coupled or poorly scoped logic and you just need to bypass it.

User.class_eval do
  def self.enabled?
    true
  end
end

Bypass ActiveRecord Validations and Callbacks

You can force persistence of corrupted or partial data by skipping callbacks entirely:

user.save(validate: false)

You can also run callbacks manually:

user.run_callbacks(:create) { }
Rails Maze Logo Divider

Live Inspection & Logging

Enable Raw SQL Logging

Sometimes Rails scopes will lie about their intent. You can inspect the raw SQL to help debug instead:

ActiveRecord::Base.logger.level = Logger::DEBUG

Using tap for Non-Intrusive Inspection

You can insert debug output in the middle of method chains using tap. Ideal for inspecting queries or deeply chained method invocations.

Before discovering tap, you might’ve done something like this:

last_signed_in_users = User.where(active: true)
           .order("last_sign_in_at DESC")
           .limit(10)

last_signed_in_users.inspect
# => Some console output, you are probably looking for an ID or something...
# Then going to check the actual .first result...
last_signed_in_users.first.inspect

Not very fun to work with and pretty inefficient. Instead, you can chain it all together for a more complete picture on what's happening when the queries actually fire:

user = User.where(active: true)
           .order("last_sign_in_at DESC")
           .limit(10)
           .tap { |relation| puts "[DEBUG] SQL: #{relation.to_sql}" }
           .first

Bypassing Method Visibility

⚠️ CAUTION! ⚠️ send is dangerous! Always double-check that the side effects of calling methods will not brick production data. Generally, you should try to use public_send when possible, but can still be a trap if the interfaces on your objects are not designed with proper access control in mind.

This is a powerful tool for being able to inspect internal state and see what private and protected methods are doing:

user.send(:calculate_discount)      # ignores method visibility
user.public_send(:full_name)       # respects method visibility

This becomes especially potent when combined with binding.irb or object patching. Use with surgical precision — this tool can bypass method boundaries that exist for a reason.

Imagine that you have a Post model with a slug that is set before_save:

class Post < ApplicationRecord
  before_save :generate_slug

  private

  def generate_slug
    self.slug ||= title.parameterize
  end
end

You suspect that something is going wrong when generating the slug, but it's a private method. Instead of triggering full save, we can instead check the method return value directly:

post = Post.new(title: "Top 10 Shrek Moments")

post.send(:generate_slug)
puts post.slug
# => "top-10-shrek-moments"
Rails Maze Logo Divider

Tracing Execution Flow

TracePoint for Hooking into Ruby Internals

TracePoint is one of Ruby’s most powerful and underutilized introspection tools. You can trace events like method calls or returns directly from the Ruby VM without having to make any changes to the source code.

It shines when tracking method usage or debugging complex Rails behaviors like silent callbacks or skipped logic.

trace = TracePoint.new(:call, :return) do |tp|
  puts "[#{tp.event}] #{tp.defined_class}##{tp.method_id}"
end

trace.enable

# Example method to trigger it:
def greet(name)
  "Hello, #{name}"
end

greet("world")

trace.disable

# Gives an output like...
# [call] Object#greet
# [return] Object#greet

If you want to cut down on the noise, you can further filter for specific targets using something like this:

trace = TracePoint.new(:call) do |tp|
  if tp.defined_class == User && tp.method_id == :save
    puts "[CALL] #{tp.defined_class}##{tp.method_id} at #{tp.path}:#{tp.lineno}"
  end
end

trace.enable
User.new.save
trace.disable

This only triggers when User#save is called and works very well for tracking Rails lifecycle methods. This is extremely useful for tracking errant callback behavior!

Deep Dive with Kernel#set_trace_func

⚠️ CAUTION! ⚠️ This is extremely slow, but you can use it to trace everything that is happening in Ruby.

This is about as extreme as you can get with introspection in Ruby, but there are some cases where you need this level of granularity. It’s best reserved for situations where stack traces are missing and monkey patches may be interfering with control flow.

set_trace_func proc { |event, file, line, id, binding, klass|
  puts "#{event} #{klass}##{id} at #{file}:#{line}"
}

# you can stop tracing using:
set_trace_func(nil)

For example:

def greet(name)
  "Hello, #{name}"
end

greet("world")

With set_trace_func enabled, you'd get output like:

call Object#greet at app.rb:1
line Object#greet at app.rb:2
return Object#greet at app.rb:2
Rails Maze Logo Divider

Memory & Object Introspection

Using ObjectSpace.each_object to Inspect Live Memory

You can easily find and inspect live objects of a certain type. This can be a highly effective tool for uncovering memory leaks, revealing cache bloat, and can help find zombie instances.

ObjectSpace.each_object(User) do |user|
  puts user.email
end
Rails Maze Logo Divider

True Emergency Tools

⚠️ CAUTION! ⚠️ These are all extremely destructive or have the potential to significantly change the way that the current Rails instance is running! Only use these in dire circumstances or with thoughtful oversight. I would recommend you to pair with another developer before running these commands.

  1. You can kill individual Puma worker threads with:

    Puma.stats Puma::Cluster::Worker.new(0).stop
    
  2. You can force garbage collection immediately:

    GC.start
    
  3. You can flush Redis manually:

    $redis.flushdb
    
  4. You can manually clear ActiveRecord cache:

    ActiveRecord::Base.clear_active_connections!
    
  5. You can force reloading I18n translations:

    I18n.reload!
    

Epilogue

You’ve made it through the fog — symbols traced, logs deciphered, ghosts temporarily banished. The Tome has lent you its pages, but the true magic lies in knowing when to wield these spells... and when to close the console and walk away.

Production never sleeps. Neither will you. But now you’re armed not just with commands, but with clarity, context, and a few well-placed taps. You’ve learned how to trace shadows through logs, patch reality in memory, and extract meaning from chaos without bringing the whole system down (hopefully).

You won't always fix things on the first try (or the second) but you'll break less in the process. And when the next incident comes knocking at 2 a.m., you won’t just panic. You’ll open the console… and cast binding.irb.


Continue Learning