How to Read a Stack Trace
- 4 minutes read - 696 wordsA 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? 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 dismantle the door and replace the motor that lowers it? That might work, but no, you should not. There are multiple explanations for this problem and the motor is just one. Permit me a few non-mechanic explanations:
- 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.
Example
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 stacktrace like mystify people dozens of times.
For context, 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. Important!
Next:
undefined method 'each' for nil:NilClass
Quite communicative! Something in the code is nil
and we tried to call
.each
on it. Can Ruby iterate over nil
? 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 consider that @estimators
can be nil
, but it can.
We now have one job: find out where @estimators
is being set and understand
how it can be nil
. That is the bug. We’re done debugging and now solving
the problem.
Takeaways
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, which the API can’t handle.”
An imperfect summary, perhaps, but it’s a lot better than “the magic computer is doing magic things.”
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.
Happy debugging.