A stumbling block for many people when debugging is reading the stack trace. Today I’d like to discuss this important skill.

What is a Stack Trace?

What is a stack trace? According to Wikipedia: “In computing, a stack trace… is a report of the active stack frames at a certain point in time during the execution of a program.” It’s the answer to the question: “when this system is being observed, what is happening?” Reading stack traces is a core programming skill.

I compare reading stack traces to troubleshooting a component of a car. Imagine that you can’t open your car’s automatic window. Should you remove the door panel and replace the motor that lowers it?

That might work, but no, you should not— yet. There are multiple explanations for this problem, and the motor is just one:

  • The electrical power to the car might be off
  • The window might be stuck or obstructed
  • The window control might be broken or missing
  • The electrical line that powers the motor might be faulty
  • (And finally) the motor might be broken

Your mechanic uses a checklist like this, perhaps just mentally, to ensure the action being taken is the right one.

Debugging works the same way. Isolating the issue to the frontend, backend, data layer, infrastructure, or even your computer, is the only way to ensure you’re fixing the right problem.

Reading a Real Stack Trace

Let’s look at a real stack trace! This is Ruby code. Ruby is famous for its readability, so if you aren’t a Rubyist, please try to follow along anyway. Some Rubyists some might consider this example too simple, but I’ve seen a stack trace like stop engineers in their tracks dozens of times.

This printed in my Chrome Network Tab after an endpoint returned 500.

NoMethodError at /api/delivery_estimates
================================================

undefined method 'each' for nil:NilClass

app/views/platform/api/delivery_estimates/index.v1.jbuilder, line 20
-------------------------------------------------------------------------

   15     end
   16   end
   17   
   18   json.postal_code postal_code
   19   
>  20   json.estimates @estimators.each do |estimator|
   21     json.name estimator.service_name
   22     json.get_it_by estimator.estimate.earliest_promised_delivery_on
   23     json.get_it_by_latest estimator.estimate.latest_promised_delivery_on
   24     json.schedule estimator.evaluated_schedule
   25   

App backtrace
-------------

- app/views/platform/api/delivery_estimates/index.v1.jbuilder:20:in `_354605b230fb799e61b9ae5b2d0a1b7d'
- lib/logbook/rails_ext/action_controller/metal/instrumentation.rb:22:in `block in process_action'
- lib/logbook/rails_ext/action_controller/metal/instrumentation.rb:21:in `process_action'
- app/middleware/ensure_session_id.rb:17:in `call'
- lib/pinterest_catalog_proxy.rb:17:in `perform_request'
- lib/sitemap_proxy.rb:22:in `perform_request'
- lib/logbook/rails_ext/rack/logger.rb:12:in `call_app'

Full backtrace
--------------

- app/views/platform/api/delivery_estimates/index.v1.jbuilder:20:in `_354605b230fb799e61b9ae5b2d0a1b7d'
- actionview (4.2.11.3) lib/action_view/template.rb:145:in `block in render'
- activesupport (4.2.11.3) lib/active_support/notifications.rb:166:in `instrument'
- actionview (4.2.11.3) lib/action_view/template.rb:337:in `instrument'
- actionview (4.2.11.3) lib/action_view/template.rb:143:in `render'
- deface (1.0.2) lib/deface/action_view_extensions.rb:41:in `render'
- actionview (4.2.11.3) lib/action_view/renderer/template_renderer.rb:54:in `block (2 levels) in render_template'
- actionview (4.2.11.3) lib/action_view/renderer/abstract_renderer.rb:39:in `block in instrument'
- activesupport (4.2.11.3) lib/active_support/notifications.rb:164:in `block in instrument'
- activesupport (4.2.11.3) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
...lots of extra lines omitted 😅

Where to start? Look at the first word of the trace:

NoMethodError

This is a common Ruby error that means you tried to call a method that does not exist on an object. And in Ruby, we know that everything is an object, even nil. This is important!

Next:

undefined method 'each' for nil:NilClass

Quite communicative! Something in the code is nil and we tried to call .each on it, which is “undefined.” Can Ruby code iterate over something that’s undefined? No, it can’t.

Next, we get an actual line of code:

app/views/platform/api/delivery_estimates/index.v1.jbuilder, line 20

Jump to that line quickly. Here it is:

json.estimates @estimators.each do |estimator|

Remember, we were trying to call .each on nil. There’s only one .each here which narrows it down. And what is it being called on? @estimators. This code doesn’t seem to think that that @estimators can be nil. But it is.

We now have one job: find out where @estimators is being set and reason about how it can be nil. That’s the bug. We’re done debugging and now on to solving the problem.

Getting Better by Verbalizing the Stack Trace

After you acquire this knowledge, a neat trick is to stop and verbalize what’s happening. For this example, I’d say:

“When we ask for estimates, our view tries to iterate over a collection of estimators. That collection can be nil, and Ruby code can’t iterate over nil, so the API crashes.”

An imperfect summary, perhaps, but it’s a lot better than where we started.

Conclusion

Most of the stack trace is noise. Potentially relevant and interesting noise, but noise nonetheless. Follow your gut. If you’re reading lib/active_support/notifications/instrumenter.rb:20, the last line I shared of the full stack trace, you’re probably off track. Your code is likely causing the issue because it’s almost always your fault.

Good luck honing this vital skill.