Learn Ruby on Rails Book

How to interpret a stacktrace

What is a stack trace

Stack trace or backtrace is a representation of the call stack at any point of time while running the program.

Stack trace will be printed when an exception is raised. So let's raise an error with a few method calls to understand it.

To see a very simple stack trace open rails console and paste the following code.

1def capitalize_name(name)
2  name.upcase
3end
4
5def print_name
6  name = 1
7  capitalize_name name
8end
9puts print_name

You should have got the following output on your console:

1irb(main):001:1*  def capitalize_name(name)
2irb(main):002:1*    name.upcase
3irb(main):003:0>  end
4=> :capitalize_name
5irb(main):004:0>
6irb(main):005:1* def print_name
7irb(main):006:1*   name = 1
8irb(main):007:1*   capitalize_name name
9irb(main):008:0> end
10=> :print_name
11irb(main):009:0> puts print_name
12Traceback (most recent call last):
13        3: from (irb):9
14        2: from (irb):6:in `print_name'
15        1: from (irb):2:in `capitalize_name'
16NoMethodError (undefined method `upcase' for 1:Integer)

It is very evident from the stack trace that the method capitalize_name is at the top of the call stack and encountered an error NoMethodError (undefined method upcase' for 1:Integer) at (irb):2, and print_name is at the position 2 of the stack.

How to log stack trace of an exception

If we want to log the stack trace of the exception rescued in our application, we need to set up a logger first.

Rails makes use of the ActiveSupport::Logger class to write log information. Other loggers, such as Log4r, may also be substituted.

You can specify an alternative logger in config/application.rb or any other environment file, for example:

1config.logger = Logger.new(STDOUT)

Or you can use the following

1config.logger = Log4r::Logger.new("Application Log")

The following will iterate through each line of backtrace and logs to log file.

1begin
2  raise
3rescue => e
4  logger.error e.message
5  e.backtrace.each { |line| logger.error line }
6end

Interpreting Rails stack trace

Let's change the task controller's show method as follows:

1def show
2 render status: :OK, json: { task: @task }
3end

Now try to edit an existing task, check the console of your browser, and we can see a 500 error message. We can see an error page in the preview of particular a request in Network tab. The lines after Application Trace | Framework Trace | Full Trace is our stack trace.

1
2ArgumentError in TasksController#show
3
4Unrecognized status code :OK
5
6Extracted source (around line #21):
7
819
920  def show
1021    render status: :OK, json: { task: @task }
1122  end
1223
1324  def update
14
15
16
17
18Rails.root: /Users/admin/learnROR/Granite-Revamp
19
20Application Trace | Framework Trace | Full Trace
21app/controllers/tasks_controller.rb:21:in `show'
22

The above error message says Unrecognized status code :OK, but 200 OK is a standard status code part of http as we know. So let us check why Rails has raised such an error. But the problem is that there is no stack trace printed for us, in order to debug.

Rails isn't showing the framework stack trace by default, since it has a silencer enabled to show only the app directory stack trace and to skip the Rails stack trace. So let's remove the silencers.

open config/initializers/backtrace_silencers.rb and uncomment the following line:

1 Rails.backtrace_cleaner.remove_silencers!

Initializer files are loaded only once when the Rails server is started. Always restart the server, when any of the initializer files are modified. For further information check the documentation.

So let's restart the Rails server and try editing the task once again:

1
2ArgumentError in TasksController#show
3
4Unrecognized status code :OK
5
6Extracted source (around line #583):
7581  def status_code(status)
8582    if status.is_a?(Symbol)
9583      SYMBOL_TO_STATUS_CODE.fetch(status) { raise ArgumentError, "Unrecognized status code #{status.inspect}" }
10584    else
11585      status.to_i
12586  end
13
14Rails.root: /Users/admin/learnROR/Granite-Revamp
15
16Application Trace | Framework Trace | Full Trace
17rack (2.2.3) lib/rack/utils.rb:583:in `block in status_code'
18rack (2.2.3) lib/rack/utils.rb:583:in `fetch'
19rack (2.2.3) lib/rack/utils.rb:583:in `status_code'
20actionpack (6.0.4) lib/action_controller/metal/rendering.rb:96:in `_normalize_options'
21actionpack (6.0.4) lib/abstract_controller/rendering.rb:119:in `_normalize_render'
22actionpack (6.0.4) lib/abstract_controller/rendering.rb:24:in `render'
23actionpack (6.0.4) lib/action_controller/metal/rendering.rb:36:in `render'
24actionpack (6.0.4) lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
25activesupport (6.0.4) lib/active_support/core_ext/benchmark.rb:14:in `block in ms'
26/Users/rojinpaul/.rbenv/versions/2.7.2/lib/ruby/2.7.0/benchmark.rb:308:in `realtime'
27activesupport (6.0.4) lib/active_support/core_ext/benchmark.rb:14:in `ms'
28actionpack (6.0.4) lib/action_controller/metal/instrumentation.rb:44:in `block in render'
29actionpack (6.0.4) lib/action_controller/metal/instrumentation.rb:84:in `cleanup_view_runtime'
30activerecord (6.0.4) lib/active_record/railties/controller_runtime.rb:34:in `cleanup_view_runtime'
31actionpack (6.0.4) lib/action_controller/metal/instrumentation.rb:43:in `render'
32app/controllers/tasks_controller.rb:21:in `show'
33actionpack (6.0.4) lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
34actionpack (6.0.4) lib/abstract_controller/base.rb:195:in `process_action'

We can look at the first line of stack trace, and it shows:

rack (2.2.3) lib/rack/utils.rb:583:in block in status_code'`

So this is an error from rack version 2.2.3, go to github rack repo and select the tag 2.2.3 and navigate to lib/rack/utils.rb.

Line 583 is calling a method SYMBOL_TO_STATUS_CODE. If we look into the code we can see they have already defined all the status codes in HTTP_STATUS_CODES, and there is a 200 => 'OK' in the list. But in the SYMBOL_TO_STATUS_CODE method it is getting down cased(Refer here). So we have to use ok symbol instead of OK.

1def show
2 render status: :ok, json: { task: @task }
3end

We are not committing any of these changes.

1git checkout -f app/controllers/tasks_controller.rb
2git checkout -f config/initializers/backtrace_silencers.rb

Video on how to interpret a stack trace

Chris Oliver of gorails has posted a nice video on how to interpret a stack trace.

⌘K
    to navigateEnterto select Escto close
    Previous
    Next