Re: Debugging on Rails: Reading Stack Traces

dummy@example.com (zuerst) — Wed, 02 Nov 2011 07:01:44 +0000

The brilliant tool valgrind is often able to say more about what is going wrong; it can give a strack trace to the point where things start to go wrong, which might be long time before the program actually crashes. Programs run through valgrind will run an order of magnitude slower and use more memory, but it will be buddyamazingly usable.

Re: Debugging on Rails: Reading Stack Traces

dummy@example.com (Kelli) — Thu, 12 Oct 2006 19:52:37 +0000

I remember the first time I saw one of those. I ended up with a full page error message over a typo and it freaked me out a little bit. I thought I'd managed to really break something. I wasn't used to such thorough error messages. They can be intimidating to a new programmer, but very useful once you start reading them and following the path to the problem, particularly given the way a rails app is broken down.

Debugging on Rails: Reading Stack Traces

dummy@example.com (ryanb) — Thu, 12 Oct 2006 17:57:52 +0000

What is a Stack Trace?

A stack trace is that thing Rails spits out when there is a problem in the code. It might look something like this:

/usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:1506:in `attributes='
/usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:1354:in `initialize_without_callbacks'
/usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/callbacks.rb:236:in `initialize'
#{RAILS_ROOT}/app/controllers/projects_controller.rb:11:in `new'

No doubt about it, this looks scary. But, stack traces are very useful and shouldn't be ignored! They will help you find the problem in your code.

At some point, whether it be in your code or in the rails framework itself, an exception is raised (an error occurred). The stack trace shows exactly where the error occurred and the path it took to get there.

Reading the Stack Trace

Take a look at the top line:

/usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:1506:in `attributes='

This tells you three things (from left to right):
1. The file the error occurred in
2. The line in the file the error occurred
3. The method the error occurred in.

This is what each one is in the example:

File: /usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb
Line: 1506
Method: attributes=

The next line down in the stack trace represents where that method (attributes=) was called. As you can see it was called inside the initialize_without_callbacks method in the same file. If we keep going down we can see the path that was taken to get to the error.

A Simple Example

Let me show you another example, but this time a little simpler. I typed this in irb:

>> def foo
>>   bar
>> end
>>
>> def bar
>>   raise 'test'
>> end
>>
>> foo
RuntimeError: test
        from (irb):5:in `bar'
        from (irb):2:in `foo'
        from (irb):7
        from :0

Here we have two methods: foo and bar. The foo method calls bar, and bar raises an exception. When we call foo, we get the error and the stack trace below it.

Looking at the first line of the stack trace, we see the exception was raised in the 'bar' method on line 5. The next line down shows that the foo method called the bar method on line 2.

Finding the Problem

Now that we know how to read a stack trace, let's go back to the first example and find the problem.

/usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:1506:in `attributes='
/usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:1354:in `initialize_without_callbacks'
/usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/callbacks.rb:236:in `initialize'
#{RAILS_ROOT}/app/controllers/projects_controller.rb:11:in `new'

In this case the exception was raised inside a method in the Rails framework. This is why the file path looks so strange on the first few lines. If we wanted, we can go looking at the active_record/base.rb file it occurred in, but Rails is well tested, and it is more likely the problem exists in our own code.

If we keep going down the stack trace, we see a method was called in our code, specifically the "new" action in the projects_controller.rb. Now we are getting somewhere. I'm guessing I'm passing some value that Rails doesn't expect. Let's take a look at that method:

def new
  @project = Project.new(params[:id])
  @task = Task.new
end

Oh what a stupid mistake I made. For some reason I'm passing params[:id] when creating the Project. I don't know what I was thinking, let me remove that:

def new
  @project = Project.new
  @task = Task.new
end

There we go, no more error! We could have probably found this easy enough without using the stack trace, but it just helped us locate the problem faster. On those tricky to find bugs, the stack trace will become all that much more useful!

TextMate Tip

Here's a tip. If you're using TextMate, go grab the TextMate Footnotes plugin. It will not only give you useful footnotes on each page, but it will also link each line of the stack trace that rails generates. This means you can click the line in the stack trace and the file will open instantly in TextMate, going to the appropriate line in the file. Very useful!

Rails Forum - Ruby on Rails Help and Discussion Forum - Debugging on Rails: Reading Stack Traces

Re: Debugging on Rails: Reading Stack Traces

Re: Debugging on Rails: Reading Stack Traces

Debugging on Rails: Reading Stack Traces