Search
⌘K
    to navigateEnterto select Escto close

    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.1.4.1) lib/action_controller/metal/rendering.rb:96:in `_normalize_options'
    21actionpack (6.1.4.1) lib/abstract_controller/rendering.rb:119:in `_normalize_render'
    22actionpack (6.1.4.1) lib/abstract_controller/rendering.rb:24:in `render'
    23actionpack (6.1.4.1) lib/action_controller/metal/rendering.rb:36:in `render'
    24actionpack (6.1.4.1) lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
    25activesupport (6.1.4.1) lib/active_support/core_ext/benchmark.rb:14:in `block in ms'
    26/Users/rojinpaul/.rbenv/versions/3.0.2/lib/ruby/3.0.2/benchmark.rb:308:in `realtime'
    27activesupport (6.1.4.1) lib/active_support/core_ext/benchmark.rb:14:in `ms'
    28actionpack (6.1.4.1) lib/action_controller/metal/instrumentation.rb:44:in `block in render'
    29actionpack (6.1.4.1) lib/action_controller/metal/instrumentation.rb:84:in `cleanup_view_runtime'
    30activerecord (6.1.4.1) lib/active_record/railties/controller_runtime.rb:34:in `cleanup_view_runtime'
    31actionpack (6.1.4.1) lib/action_controller/metal/instrumentation.rb:43:in `render'
    32app/controllers/tasks_controller.rb:21:in `show'
    33actionpack (6.1.4.1) lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
    34actionpack (6.1.4.1) 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.

    Previous
    Next