A bug in software can be disruptive, elusive, maddening, and invasive. Indeed, a developer often needs the tenacity of Edison to find and fix an issue.
But grit isn't the only asset a developer requires. One also needs information to debug code: What are the symptoms and effects of the issue? What is its frequency? Pervasiveness? Provenance? The evidence and artifacts of a bug — a core dump, stack trace, log, or test case — are invaluable.
Let's explore a few techniques and tools readily available to Ruby and Rails developers for gathering and investigating evidence of an issue. Data can't supplant tenacity, but it can help to ease your efforts (and spare you your sleep).
Use Environment Variables to Tune Your Tools in Rails
Rails provides some excellent tools to peer into a running application, including a configurable Logger to capture diagnostics of its own and any that you'd like to add. Rails also provides a verbose query log to pinpoint the origin of database queries and a verbose enqueue log to illuminate where background jobs are queued. The latter two logs are enabled by default in the development
environment; you can enable both in other environments with two statements.
##
# In any initializer... enable the verbose query log to see the file
# name and line number of the code initiating each query
ActiveRecord.verbose_query_logs = true
##
# In config/application.rb or any environment initializer, enable the
# queueing log to find where each job is enqueued
config.active_job.verbose_enqueue_logs = true
A lesser-known log option available since Rails 7 annotates each SQL query with comments. If you add the following to config/application.rb
or any environment file:
##
# Add to config/application.rb or any environment initializer file
config.active_record.query_log_tags_enabled = true
Your query log is automatically amended with the application name, controller name, action name, or background job name. The following sample output comes directly from Rails's debugging guide:
Article Load (0.2ms) SELECT "articles".* FROM "articles"
/*application='Blog',controller='articles',action='index'*/
Article Update (0.3ms) UPDATE "articles" SET "title" = ?, "updated_at" = ? WHERE "posts"."id" = ?
/*application='Blog',job='ImproveTitleJob'*/
[["title", "Improved Rails debugging guide"], ["updated_at", "2022-10-16 20:25:40.091371"], ["id", 1]]
You likely do not want to enable all these features in production. Log generation can be costly in terms of memory and time (finite resources for an application under load).
However, there are exceptions. You may want to briefly enable an on-demand feature, especially when debugging in development and test modes. Rather than alter code (and perhaps redeploy) to enable or disable a diagnostic, use environment variables to control state. In some environments, such as Heroku, changing the setting of an environment variable does not mandate a new deployment.
For example, you can define a set of variables to control logging and verbosity.
Variable Name | Purpose | Values |
---|---|---|
COMMENTED_QUERY_LOG |
Enable comments in query log | Non-blank value enables feature |
LOG_ALL |
Enable all logging features | Non-blank value enables feature |
LOG_LEVEL |
Control the threshold for log messages |
debug , info , warn , error , fatal , unknown (from most verbose to least verbose order) |
VERBOSE_ENQUEUE_LOG |
Display where jobs are queued | Non-blank value enables feature |
VERBOSE_QUERY_LOG |
Show the origin of each Active Record query | Non-blank value enables feature |
For convenience, create a small class to query configuration settings.
##
# Put this in a file such as config/initializers/env_configuration.rb
class EnvironmentConfiguration
def self.enabled?(envvar)
Rails.env.development? ||
ENV.fetch('LOG_ALL', nil).present? ||
ENV.fetch(envvar.to_s, nil).present?
end
end
Now use the variables and the code to set logging features in config/application.rb
:
##
# Centralize configuration of all logging features in config/application.rb
#
module MyApplication
class Application < Rails::Application
# . . .
ActiveRecord.verbose_query_logs = EnvironmentConfiguration.enabled?('VERBOSE_QUERY_LOG')
config.active_job.verbose_enqueue_logs = EnvironmentConfiguration.enabled?('VERBOSE_ENQUEUE_LOG')
config.active_record.query_log_tags_enabled = EnvironmentConfiguration.enabled?('COMMENTED_QUERY_LOG')
config.log_level = (ENV.fetch('LOG_LEVEL', nil).presence || 'info').to_sym
end
end
Use your shell, a dotenv file, your continuous integration, or hosting and deployment platform to set each option. You can also use a feature on demand. Simply start the application with the environment variable defined on the command line.
LOG_ALL=on LOG_LEVEL=debug bundle exec rails s
Tune Puma for Development
Building on the previous section, let's look at how to use environment variables to tailor your Puma configuration for debugging in the development environment.
Typically, Puma is configured to maximize throughput in production, running multiple workers and many threads per worker. In development, you want the opposite: one worker, one thread, and a very long timeout to allow for interactive debugging. Each of those is a parameter you can tune.
Alter config/puma.rb
to reflect the following code.
##
# Control thread count with environment variables.
# Each environment setting, if set, is always a string. Use `Integer` to
# convert the string to an integer value.
#
max_threads_count = Integer ENV.fetch('PUMA_MAX_THREADS', 5)
min_threads_count = Integer ENV.fetch('PUMA_MIN_THREADS, max_threads_count)
threads min_threads_count, max_threads_count
##
# Specify the duration Puma waits before terminating a worker.
# The default is 30 seconds.
#
worker_timeout Integer ENV.fetch('PUMA_WORKER_TIMEOUT', 30)
##
# Set the number of workers
worker_count = Integer ENV.fetch('PUMA_WEB_CONCURRENCY, 2)
workers worker_count
preload_app! if worker_count.positive?
You can now configure the three environment variables to control Puma in each environment. In development, set the values to optimize for interactive debugging.
export PUMA_MAX_THREADS=1
export PUMA_WORKERS=0
export PUMA_WEB_CONCURRENCY=0
export PUMA_WORKER_TIMEOUT=3600
If you want to validate your Puma settings, set the environment variable PUMA_LOG_CONFIG=true
and start your application. Puma emits its active configuration on startup.
=> Booting Puma
=> Rails 6.1.7.7 application starting in development
=> Run `bin/rails server --help` for more startup options
Configuration:
. . .
- environment: development
- max_threads: 5
- min_threads: 5
- worker_timeout: 3600
- workers: 0
Coincidentally, the default Puma configuration in the most recent Rails release is similar to what's shown here (thanks to Nate Matykiewicz for the tip).
Run Background Jobs Inline
A Rails application of any complexity typically leverages background jobs to run compute-intensive and (relatively) long-running tasks. Background jobs run asynchronously, disconnected from the request/response cycle. Ideal candidates for "out of band" processing include generating reports, sending emails, and interacting with third-party APIs. But the asynchronous nature of jobs also complicates debugging.
To simplify troubleshooting, run jobs immediately in your local development and test environments. In immediate mode, jobs are not queued, but instead execute instantaneously. Running in the "foreground", you can set breakpoints and inspect state interactively.
Let's look at an example using Delayed Job, a popular and easy-to-manage queueing backend for Active Job. Delayed Job provides a setting to enable queueing. By default, the setting is true
and jobs are queued as per usual. However, if set to false
, jobs run immediately.
Add the following code to your application in config/initializers/delayed_job.rb
:
Delayed::Worker.delay_jobs = ENV.fetch('DELAYED_JOBS_DISABLE_JOB_QUEUES', false).blank?
If DELAYED_JOBS_DISABLE_JOB_QUEUES
is set to any value, queueing is disabled. If the environment variable is blank or not defined, queueing is enabled.
Next, in your shell, on the command line, or in your dot files, set
DELAYED_JOBS_DISABLE_JOB_QUEUES
as needed.
# Set the variable in the current shell
export DELAYED_JOBS_DISABLE_JOB_QUEUES=true
# Set the variable only for the current command
DELAYED_JOBS_DISABLE_JOB_QUEUES=true rails s
# In .env.development, .env.local, and/or .env.test, add the line...
DELAYED_JOBS_DISABLE_JOB_QUEUES=true
Set the environment variable to nothing or delete the environment variable to restore queueing.
# Set the variable to blank
export DELAYED_JOBS_DISABLE_JOB_QUEUES=
# Remove the variable from the environment
unset DELAYED_JOBS_DISABLE_JOB_QUEUES
There are no rules for naming environment variables. Choose names meaningful to you. One helpful convention to categorize variables is to add a package name as a prefix, such as PUMA_
and DELAYED_JOB_
. The former indicates variables affecting Puma; the latter connotes variables used by Delayed Job.
Peer Into Network Calls
Like background jobs, Rails applications can also consume application
programming interfaces (APIs). APIs provide access to external services, such as GraphQL databases, e-commerce transactions, and public data sources.
Here's another example to conditionally emit HTTP requests and responses from the Net::HTTP
library. If the environment variable DEBUG_HTTP
is set to any non-blank value, the outgoing request and inbound responses are printed to STDOUT
.
def construct_uri(hostname:, path:, port:, params: {}, protocol: 'https')
target =
Addressable::URI.new.tap do |uri|
uri.hostname = hostname
uri.path = path
uri.port = port
uri.query_values = params
uri.scheme = protocol
end
URI.parse target
end
def debug?
ENV.fetch['DEBUG_HTTP'].present?
end
def request
uri = construct_uri(...)
Net::HTTP.new(uri.host, uri.port).tap do |http|
http.set_debug_output($stdout) if debug?
http.use_ssl = uri.scheme == "https"
end
end
To see the network activity, simply start the application with
the environment variable defined on the command line.
DEBUG_HTTP=on bundle exec rails s
The debug?
method provides some abstraction from the actual flag implementation. It, and the rest of this code, can form a base class for all your network requests, as shown in this gist taken from production code.
Add Ruby Gems to Your Toolbox
The universe of Ruby gems is vast: it's impossible to cover all the great gems available for debugging. Instead, let's look at a few tools you can add today for an instant boost. You'll likely add each of these to all your projects.
-
awesome_print
andtable_print
create rich, readable inspections of Ruby data structures, including Active Record models. You can use either gem in code or from the console.
Here is an example of a model emitted by awesome_print
in the console:
> ap User.find_by(email: 'george@bigbrother.gov')
#<User:0x00000001163482f0> {
:account_balance => 0.0,
:confirmed_at => Mon, 11 Mar 2024 12:29:30.000000000 EDT -04:00,
:created_at => Mon, 11 Mar 2024 12:29:30.000000000 EDT -04:00,
:email => "george@bigbrother.gov",
:encrypted_password => "992c45d528f9b445de3d6653e14d3e6165171944",
:first_name => "George",
:last_name => "Orwell",
:sign_in_count => 0,
:state => "active"
}
Instead of p
, use ap
to show the enhanced output. awesome_print lists attributes in alphabetical order, one attribute per line, among other niceties.
-
better_errors
replaces the standard Rails error page with an enhanced stack backtrace, parameter list, and an interactive console where you can probe the stack frame and variables at the scene of the exception. You can also tie source code links to your favorite editor. Here is code to tiebetter_errors
to Visual Studio Code:
if Rails.env.development?
BetterErrors.editor =
if (ENV['BETTER_ERRORS_EDITOR'].presence || ENV['EDITOR']) =~ /vscode/i
proc { |file, line| "vscode://file#{file}:#{line}" }
else
:macvim
end
end
Run export BETTER_ERRORS_EDITOR=vscode
in your shell and restart the Rails server. Now links to files open automatically in Visual Studio.
- Keep the
faker
andfactory_bot
gems (or their alternatives) in both the testing and development groups in Gemfile. Both are invaluable if you need to generate data quickly in the console.
group :development, :test do
# other gems
# ...
gem 'factory_bot'
gem 'faker'
end
One more idea: If you use AppSignal as your application monitoring tool, it has features to interpret your logs and pinpoint the source of errors. See Debugging in Ruby with AppSignal for more details.
Debugging is a Skill
Debugging code is something of an art, and like any creative endeavor, the more practice you have, the better you become.
Debug while pairing with another developer, especially an experienced developer. If your partner is willing, think out loud together and exchange hunches and insights.
Go forth and hack!
P.S. If you'd like to read Ruby Magic posts as soon as they get off the press, subscribe to our Ruby Magic newsletter and never miss a single post!
Top comments (0)