How to beat the shit out of the errors in your “Rails App”

When things get really crazy in rails…

Well I've been spending a lot of time finding answers on Stack Overflow lately. From what I read, most of the questions come from unexperienced developers. It’s not easy to understand their questions because they often lack code examples, stack-traces or application logs. Because of that I’ve to keep digging deeper for the right answers. I thought that it might be better to write what i've learned in a post, so everyone has a chance to pick it up all at once.

First Things First

When working with Ruby on Rails application you will have to learn a lot of stuff to master debugging. There are so many moving parts in a Rails app, it’s not just another MVC…

  • Views (Partials, Layouts, Templating-Engines)
  • Controllers (Actions, Filter)
  • Models (Relations, AREL, Callbacks, Database-Systems)
  • Mailers
  • Routes (REST, HTTP-Verbs, Constraints)
  • Environments and Initializers
  • Caching (Redis, Memcached)
  • Assets (CSS, SASS, JavaScript, CoffeeScript, Pipelining)
  • Bundler and dependency management
  • Tests (RSpec, Capybara)
  • gems, plugins and engines used in the app

WOW, that is a LOT and I probably forgot some stuff…

Because of this overwhelming complexity, it is very important to know the basic tools that come with Rails.

Rake

Rake is a blessing for Ruby, It’s like the Make Utility for Unix. It’s basically a build-tool that handles tasks. It has become the swiss-army-knife of Ruby and Rails. So make sure you know when it can be useful for you! The basic commands are rake -T to get a list of public commands and rake -D to get the full description of the tasks. If one of the commands fail, you can pass the — trace option to see what rake is doing under the hood and find possible error causes.

Here is a list of useful commands that I use when running into strange errors during development:

rake routes
rake middleware
rake assets:clobber
rake assets:clean
rake tmp:clear
rake log:clear

Reading stack-traces

It is happening to me all the time. The application spits out an error and I have no clue what is going on. Providing meaningful error messages is one of most neglected parts in writing maintainable software. On average, Ruby is very helpful in that regard, Rails is not! Nevertheless, you should always read the errors and stack-traces because they contain helpful information like the source file and the line number where an error was caused. It even provides information about the context, like the calling object and the call-stack when the error happened.

Let me give you an example exception:

undefined local variable or method `role' for #<Cucumber::Rails::World:0xc4722f8> (NameError)
./features/step_definitions/event_steps.rb:10:in `create_visitor'
./features/step_definitions/event_steps.rb:14:in `create_user'
./features/step_definitions/kid_steps.rb:107:in `/^I am exists as a parent$/'
features/manage_kids.feature:11:in `And I am exists as a parent'

What I can see at a glance:

  • it’s about cucumber
  • we are in a step definition
  • the context object is of class Cucumber::Rails::World
  • there should be a role but it is not available
  • calling create_visitor caused this error
  • the source of create_visitor is in event_steps.rb on line 10

The source code that matches this error is this:

# event_steps.rb
def create_visitor
@visitor ||= {
:email => "user@example.com",
:password => "test123",
:password_confirmation => "test123",
:role => Role.find_by_name(role.to_s) # this is line 10
}
end

It is just an excerpt of the code, so it’s a good idea to add real line-numbers or an anchor so other people know where we are. In this example, this would not even be necessary, because role is only called once. Without knowing anything about the source, I can immediately see that the author wanted to use something that is not there.

So possible solutions to this might be to use @role or maybe @visitor.roleor to have a method called role or pass it in as a parameter to that method. If the test has run successfully before doing any changes, the error was probably introduced by some changes you did and should be easy to find.
So always make sure your test suite passes before writing new code.

I also use better_errors to avoid switching between browser and my code editor during debugging also it’s a nice gem to beautify the ugly stack-traces.

Side Note

Never throw away exception information unless there is a good reason! Swallowing exceptions causes a lot of pain for people that have to maintain the running application, so please at least log the error message when you rescue from something.

Reading code

One of the key skills for writing code is reading code in the first place. Whether it is code I wrote some time ago, code of my co workers or library code. It’s super important to understand the code at hand and the code that my application is executing. Compared to other languages, where one has to deal with compiled sources, it’s incredibly easy to have a look at ruby sources. I often run bundle open some_gem to look at the source or when you are not using bundler run gem env and look at GEM PATHS where your gems are installed

gem env
RubyGems Environment:
- RUBYGEMS VERSION: 2.1.5
- RUBY VERSION: 2.0.0 (2013-06-27 patchlevel 247) [x86_64-darwin12.4.0]
[...]
- GEM PATHS:
- /Users/paule/.rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0
[...]
subl ~/.rbenv/versions/2.0.0-p247/lib/ruby/gems/2.0.0/gems/rails-4.0.0/

I also often use dash to get method documentation.

Debugging the running server

Rails coding is often CMD+R driven. I sit in front of the browser and reload the page to see if something happens… Unluckily it does not work the way I expected, so what to do next?

It’s in the logs stupid!

When I am working on a Ruby or Rails application i like to run stuff in iTerm2 with split views. One session for running spec, rails or the console and one session with the corresponding logs with tail -f log/development.log

Logs help with a lot of stuff and are a powerful tool to debug your running code. Things that can be extracted from the logs:

Direct Error Information

  • error-messages
  • complete stack-traces
  • logged warnings or errors (attribute accessible warnings, deprecations)

Context Information

  • request parameters
  • request types (html, json, xhr…)
  • response codes
  • sql queries
  • rendered views and partials
  • callback informations

Since Rails introduced the asset pipeline, logs became pretty useless, because they were cluttered with asset calls. Disabling those logs does not need any ugly middleware monkey patches anymore because you can use the quiet_assets gem for this purpose!

One thing that I do to pimp my logs to be even more useful is to use the tagged logger that was introduced in Rails 3.2. It allows you to put even more context information into the log like the session-id and request-id:

# application.rb
config.log_tags = [
:host,
:remote_ip,
lambda { |request| "#{request.uuid}"[0..15] },
lambda { |request| "#{request.cookie_jar["_on_ruby_session"]}"[0..15] },
]

Quick inspects

There are a couple of “workflows” which I tend to use in my everyday debugging, starting with simply adding p some_object, puts some_object.inspect or logger.debug some_object calls randomly to the code. For view templates i use = debug(some_object). This helps in about 50% of the error cases because it gives me enough context to find the problem quickly.

Another thing is putting a raise some_object.to_s into the code. This is especially helpful if I want to find out when and how some part of the code is executed. Callbacks are a good example where this is a nice shorthand method for debugging.

Insight tools

A running Rails server can provide a lot of useful information for debugging, especially if you query it with the right helpers. Rails 4 already comes with some better error reporting and a route helper that can be accessed through navigating to an unknown route. I use the /routes path for this purpose:

This functionality can be improved with a nice UI and a mini Rails console running in your browser if you add Better Errors and the Binding of Caller gem. These tools allow you to dive right into the error context and find out what might have went wrong. Combining this with raising my own errors gives me a lot of flexibility to quickly get to the point where I assume that something fishy is going on in the code.

When you are doing a lot of ActionMailer related stuff, you probably want to install the Letter Opener gem to develop and inspect your E-Mails.

The debugger

Having tools like Better Errors is super nice, but they are only suited for usage in the Browser. This is not always possible and I fall back to real debuggers that allow for moving around in the call-stack and inspecting objects at runtime.

The ruby-debug gem was the go-to-guy for a long time in Ruby land. It was a PITA to get this up and running in latest Ruby versions. That’s why I use the IRB replacement pry with a lot of extensions like pry-debugger or pry-nav. If you want to hook into a remote Rails process (ie. running rails via foreman) you can hook into it with pry-remote. Have a look at the Pry Railscast for more information.

Debugging through the console

The console is very important for me when writing new or changing existing code. I often create new finders and scopes in the console directly. A very important command in the console is reload!. It reloads all the code in the current session, similar to what happens when you hit CMD+R in the browser:

reload!; something_i_changed_in_the_editor.check_if_it_works

A thing that I find very helpful when stuck in a debugging session is the method.source_location functionality introduced in Ruby 1.9. It allows me to see where a method is defined:

user.method(:url).source_location
=> ["/Users/paule/Documents/rails/on_ruby/app/models/user.rb", 39]

Use the force Luke

I like to use pry-rails as my default Rails Console. It enables me to browse source code, inspect objects and do a lot of other crazy stuff. Just type help in a pry session to see what commands are available. My favorite command is wtf? which shows the last raised exception and stack-trace.

Debugging through testing

I love test driven development! It is an everyday part of my programming routine. The only thing that I hate when doing TDD in Rails is the slow feedback loop. I don’t like using tools like spork or zeus as they introduce a lot of complexity and make debugging even harder.

So my approach to get away with minimal turnaround time is to start my new expectations by writing something like this:

describe User do
it "does crazy stuff" do
pry
end
end

This rspec expectation will just open a new pry session where I can start coding right away, exploring my test with direct feedback from executing the code I want to test. This eliminates all the iteration- and startup time when running red/green cycles. It is especially useful when I don't know exactly how something should function in the first place…

Debugging capybara

The last pattern is super useful when writing acceptance tests in capybara! I always forget how to use capybara expectations and matchers, because I write only a few of those tests. This is mainly due to the test pyramid and me being a backend developer.

There are also a lot more moving parts in acceptance tests, especially when running JavaScript tests in a headless browser. It’s super useful when you can just check page.body or temper with X-PATH expressions directly in the pry session.

If there is some strange behavior during test execution, I just put a breakpoint somewhere in the test and call save_and_open_page or even better: print out current_url and open the running test instance directly in the browser!

Don't forget to check out my next article on handful of useful tools for debugging rails apps.

Lastly, this is my first post on Medium. If you found it useful, it would mean a lot if you hit the Recommend button ⇩ ☺
Show your support

Clapping shows how much you appreciated Manish’s story.