How to Troubleshoot Ruby Applications

Troubleshooting is a critical skill for developers and DevOps. As our software grows more sophisticated, our problems do too. The cloud adds a new layer of complexity since we need to know how to find a problem that doesn’t occur locally, but has cropped up on a remote system.

In this tutorial, we’ll look at how to troubleshoot Ruby applications. We’ll use a small Rails application that provides a RESTful API, but the concepts are applicable to any Ruby app.

Ruby Environment

Requirements

This sample code was written with Ruby 2.3.7 and Rails 5.2.2. All of the troubleshooting techniques we’ll use work on the command line on any operating system that supports Ruby or Rails, but I’ll be using a Mac. We’ll stick to the command line and tools that are part of the Ruby environment.

For testing the sample REST service, I’ll use HTTPie, a command line web testing tool. You can install it on any operating system in a few minutes.

Sample app

Our Rails application has an API for creating, reading, updating, and deleting (CRUD) todos. The sample code is here. (Note that it’s a very basic project and is only intended to act as an example for these exercises.)

CRUD is Rails’ bread-and-butter, so our sample application doesn’t have a lot of code. That’s deliberate: we want to focus on the process of troubleshooting, so the code is only really here to give us a common frame of reference. Here’s the heart of the application, our todos controller:

# app/controllers/todos_controller.rb
class TodosController < ApplicationController
    before_action :set_todo, only: %i[show update destroy]

    # GET /todos
    def index
        @todos = Todo.all
        json_response(@todos)
    end

    # POST /todos
    def create
    @todo = Todo.create!(todo_params)
        json_response(@todo, :created)
    end

    # GET /todos/:id
    def show
        json_respond(@todo)
    end

    # PUT /todos/:id
    def update
        @todo.update(todo_params)
        head :no_content
    end

    # DELETE /todos/:id
    def destroy
        @todo.destroy
        head :no_content
    end

    private
    def todo_params
        # whitelist params
        params.permit(:description, :done)
    end

    def set_todo
        @todo = Todo.find(params[:id])
    end
end

You may see that there’s already a bug in there. We’ll look at different ways to isolate it.

Here is the API:

Troubleshooting vs. debugging

Before we get started, let’s revisit an earlier post about the difference between troubleshooting and debugging. In that post we said:

Troubleshooting is a process that helps people identify issues or problems occurring in a system. Troubleshooting tends to exist at a higher level than debugging and applies to many components of a system. It’s a process of parsing out the items that are causing problems.

Troubleshooting involves looking at an entire system. It can include networking, hardware, configuration, or any other aspect of an entire software stack. When we say we’re troubleshooting a Ruby application, we’re implying that we’ve already done some of the work and isolated the problem.

Debugging is usually confined to a single application and focuses on mistakes in code. Debugging can be thought of as a subset of troubleshooting. We’ll be using some debugging tools, but only after looking at other, more basic tools.

Let’s get started!

The first problem

Let’s start by running the Rails application and making a few requests. We’ll keep it simple by running the app inside the project directory from the command line.

If you haven’t already, start with a database migration.

$ rails db:migrate
== 20181214203309 CreateTodos: migrating ======================================
-- create_table(:todos)
-> 0.0013s
== 20181214203309 CreateTodos: migrated (0.0013s) =============================

Then, start the server.

$ rails s
=> Booting Puma
=> Rails 5.2.2 application starting in development
=> Run `rails server -h` for more startup options
Puma starting in single mode...
* Version 3.12.0 (ruby 2.3.7-p456), codename: Llamas in Pajamas
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://0.0.0.0:3000
Use Ctrl-C to stop

Open another terminal session and list todo items.

$ http :3000/todos
HTTP/1.1 200 OK
Cache-Control: max-age=0, private, must-revalidate
Content-Type: application/json; charset=utf-8
ETag: W/"4f53cda18c2baa0c0354bb5f9a3ecbe5"
Transfer-Encoding: chunked
X-Request-Id: 372b8a5b-7a15-4fa0-a2e6-3f7296d8e8dc
X-Runtime: 0.055747
[]

That looks good. We have a fresh database, so there are no entries in it.

So let’s add one.

$ http POST :3000/todos description='Replace doors on limo, ashtrays full' done=0
HTTP/1.1 201 Created
Cache-Control: max-age=0, private, must-revalidate
Content-Type: application/json; charset=utf-8
ETag: W/"80324273f77112b41a90f4eb681f95e3"
Transfer-Encoding: chunked
X-Request-Id: 9098696f-c829-4996-947f-f7a52445f842
X-Runtime: 0.013235
{
"created_at": "2018-12-15T18:46:47.908Z",
"description": "Replace doors on limo, ashtrays full",
"done": 0,
"id": 1,
"updated_at": "2018-12-15T18:46:47.908Z"
}

The service returned a 201 response code, as well as the contents of a new todo record. We seem to be working fine.

Now, let’s list items again and make sure our new record is there.

$ http :3000/todos
HTTP/1.1 200 OK
Cache-Control: max-age=0, private, must-revalidate
Content-Type: application/json; charset=utf-8
ETag: W/"dde364b3a91df1edc24d8ac4ae824126"
Transfer-Encoding: chunked
X-Request-Id: a2238bb8-dd9a-416e-b330-6dbb89a0b848
X-Runtime: 0.012879
[
{
"created_at": "2018-12-15T18:46:47.908Z",
"description": "Replace doors on limo, ashtrays full",
"done": 0,
"id": 1,
"updated_at": "2018-12-15T18:46:47.908Z"
}
]

Let’s try to retrieve a record that doesn’t exist.

$ http :3000/todos/2
HTTP/1.1 500 Internal Server Error
Cache-Control: no-cache
Content-Type: application/json; charset=utf-8
Transfer-Encoding: chunked
X-Request-Id: 6f40d072-0e42-4f86-b0da-f3132a6686d9
X-Runtime: 0.005357
{
"message": "Couldn't find Todo with 'id'=2"
}

Looks good. So let’s try to retrieve a valid record.

$ http :3000/todos/1
(Several pages of HTML code)

This request failed. We have found our problem. Let’s get started with troubleshooting.

Logging and error messages

Our best troubleshooting tools are error messages and logs. The reason they’re the best is simple: they’re fast.. Our first bug produced two error messages. One of them was completely useless, the other tells us exactly where the problem is.

An even easier way to see both logs and errors in one trace view, is by using Retrace for Ruby.

Error messages

When we made a request for a single todo, HTTPie got back an HTML document with more than 3000 lines of code. This isn’t useful for a REST client. A better service would only return request headers. Let’s make the request again and tell HTTPie to only print the headers.

$ http --headers :3000/todos/1
HTTP/1.1 500 Internal Server Error
Content-Type: text/html; charset=UTF-8
Transfer-Encoding: chunked
X-Request-Id: b25d3793-7a7e-4690-8512-c146fed55a10
X-Runtime: 0.483818
X-Web-Console-Mount-Point: /__web_console
X-Web-Console-Session-Id: 91657a4c7434d1ec9668688ed635cbcd

That’s better. We know that the server had an internal problem resolving our request.

So our first step in troubleshooting an application is making it easier to troubleshoot by providing users with useful information. We’ll cover this further in a few moments.

Let’s look at what the Rails app had to say about the request.

Started GET "/todos/1" for 127.0.0.1 at 2018-12-15 14:03:21 -0500
Processing by TodosController#show as */*
Parameters: {"id"=>"1"}
Todo Load (0.2ms) SELECT "todos".* FROM "todos" WHERE "todos"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]]
↳ app/controllers/todos_controller.rb:44
Completed 500 Internal Server Error in 52ms (ActiveRecord: 0.2ms)
NoMethodError (undefined method `json_respond' for #<TodosController:0x00007faea706c478>
Did you mean? json_response):
app/controllers/todos_controller.rb:21:in `show'

Ruby told us exactly what the problem was, right down to the line of code! Rails logged enough of a stack trace that we can see the file and line where the error occurred.

def show
    json_respond(@todo)
end

The code above should be this:

def show
    json_response(@todo)
end

But don’t fix it yet.

The Rails logger

Our code has no log messages. We’re relying on Ruby and Rails to log what’s happening for us. That’s good enough for this bug, but it’s not what we need in a production application. Let’s set up some basic logging and reproduce this bug again.

Both Ruby and Rails have built-in logging frameworks. It was Rails’ logger that told us where the error was. Rails creates an instance of its ActiveSupport::Logger as part of initialization and uses it to log both standard output and a file named after the current environment.

Take a look at the log file from the server console. (Stop the server if you haven’t already.)

$ cat log/development.log
Started GET "/todos/1" for 127.0.0.1 at 2018-12-15 14:03:21 -0500
Processing by TodosController#show as */*
Parameters: {"id"=>"1"}
Todo Load (0.2ms) SELECT "todos".* FROM "todos" WHERE "todos"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]]
↳ app/controllers/todos_controller.rb:44
Completed 500 Internal Server Error in 52ms (ActiveRecord: 0.2ms)
NoMethodError (undefined method `json_respond' for #<TodosController:0x00007faea706c478>
Did you mean? json_response):
app/controllers/todos_controller.rb:21:in `show'

The log file contains the same information we saw on the console. There is where we would find messages on a server that we’re running as a background process or in a Docker container.

So why don’t we take advantage of logging? The sample controller doesn’t have any log messages at all. Let’s add a message to see how we could make this application easier to troubleshoot.

Go to app/controllers/todos_controller.rb and modify the index method.

def index
    @todos = Todo.all
    logger.debug "Returning all todos: " + @todos.inspect
    json_response(@todos)
end

We have access to an instance of the default logger. So we call its info method with a description of what we’re returning to the application.

Let’s modify our broken method too.

def show
    logger.debug "Returning a todo: " + @todo.inspect
    json_respond(@todo)
end

Before we test, let’s make one more change. Open config/environments/development.rb and add a line.

Rails.application.configure do
    (Leave the current contents be)
    config.log_level = :debug
end

This sets the default logger to debug mode, so we know that the logger will print our messages.

Now, try to retrieve all todos. You’ll see this log message in between the ones Rails adds:

Returning all todos: #<ActiveRecord::Relation [#]>

Next, try to receive item #1 again.

Returning a todo: #<Todo id: 1, description: "Replace doors on limo, ashtrays full", done: 0, created_at: "2018-12-15 18:46:47", updated_at: "2018-12-15 18:46:47">

We see our log message, and then the error. This would help us isolate an error that Ruby didn’t point out for us.

Formatting log messages

The log messages we’ve been looking at are fine when we’re watching the log file for errors. But what happens when we’re asked to troubleshoot a problem that happened in the past? We need timestamps and a format that’s easier to search and scan. Let’s add a log formatter to make the logs more useful.

First, create a new class and add it to the project’s lib directory.

# lib/message_formatter.rb
class MessageFormatter < ActiveSupport::Logger::SimpleFormatter
    def call(severity, time, progname, msg)
        formatted_severity = sprintf("%-5s",severity.to_s)
        formatted_time = time.strftime("%Y-%m-%d %H:%M:%S")
        "[#{formatted_severity} #{formatted_time} #{$}] : #{progname} #{msg}n"
    end
end

We’re extending the ActiveSupport::Logger::SimpleFormatter class and adding our logging formats. You can do something similar with the standard Ruby logger if you’re not using Rails.

Next, configure your environment to use this logger in config/environments/development.rb. You can add the new line right next to the one we added earlier.

config.log_formatter = MessageFormatter.new
config.log_level = :debug

Now, restart the service and make a few requests.

[INFO 2018-12-16 12:19:45 79243] : Started GET "/todos" for 127.0.0.1 at 2018-12-16 12:19:45 -0500
[DEBUG 2018-12-16 12:19:45 79243] : (0.1ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
[DEBUG 2018-12-16 12:19:45 79243] : ↳ /usr/local/bin/ruby/2.3.0/gems/activerecord-5.2.2/lib/active_record/log_subscriber.rb:98
[INFO 2018-12-16 12:19:45 79243] : Processing by TodosController#index as */*
[DEBUG 2018-12-16 12:19:45 79243] : Todo Load (0.6ms) SELECT "todos".* FROM "todos" LIMIT ? [["LIMIT", 11]]
[DEBUG 2018-12-16 12:19:45 79243] : ↳ app/controllers/todos_controller.rb:10
[DEBUG 2018-12-16 12:19:45 79243] : Returning all todos: #<ActiveRecord::Relation [#<Todo id: 1, description: "Replace doors on limo, ashtrays full", done: 0, created_at: "2018-12-15 18:46:47", updated_at: "2018-12-15 18:46:47">]>
[DEBUG 2018-12-16 12:19:45 79243] : Todo Load (0.2ms) SELECT "todos".* FROM "todos"
[DEBUG 2018-12-16 12:19:45 79243] : ↳ app/controllers/concerns/response.rb:3
[INFO 2018-12-16 12:19:45 79243] : Completed 200 OK in 55ms (Views: 1.4ms | ActiveRecord: 1.4ms)

Now our log messages have a format that’s easier to read and parse.

Exception handlers

Improving our logging and error messages goes a long way toward making this application easier to troubleshoot. But we’re still returning an HTML document to our REST client when an error occurs. This leaves the client with no useful information to report to us when they encounter a problem.

There are ways to build RESTful services in Rails that avoid this issue, but we’re going to illustrate another troubleshooting concept: exception handling. Our application is throwing a NoMethodError exception. Since our code doesn’t catch it, Rails logs it. Then the Rails web server is returning a default error page. We need to fix that.

Rails has a mechanism for installing a default exception handler. The application has one in app/controllers/concerns/exception_handler.rb.

# app/controllers/concerns/exception_handler.rb
module ExceptionHandler
# provides the more graceful `included` method
extend ActiveSupport::Concern
    included do
        rescue_from ActiveRecord::RecordNotFound do |e|
            json_response({ message: e.message }, :not_found)
        end
        rescue_from ActiveRecord::RecordInvalid do |e|
            json_response({ message: e.message }, :unprocessable_entity)
        end
    end
end

This class defines handlers for exceptions thrown inside ActiveRecord code. If the service can’t find a record, it returns a useful error. This class has the same effect as putting a begin/rescue block inside every method in our controller class.

ExceptionHandler is why retrieving record #2 worked earlier: the RecordNotFound exception throws before NoMethodError, so the exception handler takes over!

Let’s modify this to capture the error for us.

module ExceptionHandler
# provides the more graceful `included` method
extend ActiveSupport::Concern
    included do
        rescue_from ActiveRecord::RecordNotFound do |e|
            json_response({ message: e.message }, :not_found)
        end
        rescue_from ActiveRecord::RecordInvalid do |e|
            json_response({ message: e.message }, :unprocessable_entity)
        end
        rescue_from Exception do |e|
            json_response({ message: e.message }, :server_error)
        end
    end
end

We added a handler for all exceptions. Let’s try to retrieve item #1 again.

$ http :3000/todos/1
HTTP/1.1 500 Internal Server Error
Cache-Control: no-cache
Content-Type: application/json; charset=utf-8
Transfer-Encoding: chunked
X-Request-Id: ec5338ee-8507-43fe-bf74-317e50153fd9
X-Runtime: 0.072745
{
"message": "undefined method `json_respond' for #<TodosController:0x00007ff07d91a580>nDid you mean? json_response"
}

That’s much better.

Typically, we wouldn’t trap all exceptions in an application. We want a program to terminate on an unexpected error instead of consuming it. But this is a temporary patch you can add to help isolate and capture a particularly tricky error.

Delete or comment out the rescue block for Exception. We’re going to use a different technique for isolating the bug next in the section about debugging below.

Centralizing Ruby errors and logs

As we have been discussing, your application logs and exceptions are critical to your ability to troubleshoot application problems. We highly recommend using a centralized logging and error tracking tool, like Retrace, to help you collect all of this important data.

These tools are designed to easily work with Ruby on Rails and other programming languages. They enable you to get alerts when a new exception occurs, high error rates, and more. You can also view and search across all of your application logging in one place.

Debugging a Ruby application

Sometimes error messages and exception handlers aren’t enough. We need to get inside our code and see what’s happening. We need a debugger. Let’s install a debugger and use it to get inside our controller class while it’s running.

Byebug with Rails

Byebug is a gem that works identically with Rails or generic Ruby applications. It’s already installed by default with any Rails 5 project. Take a look at the development section of your Gemfile.

group :development, :test do
    # Call 'byebug' anywhere in the code to stop execution and get a debugger console
    gem 'byebug', platforms: [:mri, :mingw, :x64_mingw]
end

It’s already there. So we can add a call to byebug where we want the debugger to run. Let’s act as if we haven’t found our bug yet.

def show
    byebug
    logger.debug "Returning a todo: " + @todo.inspect
    json_respond(@todo)
end

We’re ready to run a debugger session.

Starting a ByeBug session

Next, run the Rails server and request item #1 again.

$ rails s
=> Booting Puma
=> Rails 5.2.2 application starting in development
=> Run `rails server -h` for more startup options
Puma starting in single mode...
* Version 3.12.0 (ruby 2.3.7-p456), codename: Llamas in Pajamas
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://0.0.0.0:3000
Use Ctrl-C to stop
Started GET "/todos/1" for 127.0.0.1 at 2018-12-15 16:53:25 -0500
(0.2ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
↳ /usr/local/bin/ruby/2.3.0/gems/activerecord-5.2.2/lib/active_record/log_subscriber.rb:98
Processing by TodosController#show as */*
Parameters: {"id"=>"1"}
Todo Load (0.2ms) SELECT "todos".* FROM "todos" WHERE "todos"."id" = ? LIMIT ? [["id", 1], ["LIMIT", 1]]
↳ app/controllers/todos_controller.rb:47
[18, 27] in /Users/egoebelbecker/Code/rails/todo-service/app/controllers/todos_controller.rb
18: end
19:
20: # GET /todos/:id
21: def show
22: byebug
=> 23: logger.debug "Returning a todo: " + @todo.inspect
24: json_respond(@todo)
25: end
26:
27: # PUT /todos/:id
(byebug)

The server starts up as usual. When it receives a request that enters the show method, byebug takes over.

The debugger displays ten lines of code, with the arrow pointing to where the application is stopped right in the middle. This is our context. Note that if you take your time, HTTPie will complain about the server taking too long and exit with an error. That’s fine, we don’t need it to reproduce our bug.

Before we start, take a look at Byebug’s interactive help.

(byebug) help
break -- Sets breakpoints in the source code
catch -- Handles exception catchpoints
condition -- Sets conditions on breakpoints
continue -- Runs until program ends, hits a breakpoint or reaches a line
debug -- Spawns a subdebugger
delete -- Deletes breakpoints
disable -- Disables breakpoints or displays
display -- Evaluates expressions every time the debugger stops
down -- Moves to a lower frame in the stack trace
edit -- Edits source files
enable -- Enables breakpoints or displays
finish -- Runs the program until frame returns
frame -- Moves to a frame in the call stack
help -- Helps you using byebug
history -- Shows byebug's history of commands
info -- Shows several informations about the program being debugged
interrupt -- Interrupts the program
irb -- Starts an IRB session
kill -- Sends a signal to the current process
list -- Lists lines of source code
method -- Shows methods of an object, class or module
next -- Runs one or more lines of code
pry -- Starts a Pry session
quit -- Exits byebug
restart -- Restarts the debugged program
save -- Saves current byebug session to a file
set -- Modifies byebug settings
show -- Shows byebug settings
source -- Restores a previously saved byebug session
step -- Steps into blocks or methods one or more times
thread -- Commands to manipulate threads
tracevar -- Enables tracing of a global variable
undisplay -- Stops displaying all or some expressions when program stops
untracevar -- Stops tracing a global variable
up -- Moves to a higher frame in the stack trace
var -- Shows variables and its values
where -- Displays the backtrace

If you’ve used GDB or DBX before, Byebug should look familiar.

Let’s start by proceeding through the app until we reach the bug.

Stepping through a class

Use next to proceed to the next line of code.

(byebug) next
Returning a todo: #<Todo id: 1, description: "Replace doors on limo, ashtrays full", done: 0, created_at: "2018-12-15 18:46:47", updated_at: "2018-12-15 18:46:47">
[19, 28] in /Users/egoebelbecker/Code/rails/todo-service/app/controllers/todos_controller.rb
19:
20: # GET /todos/:id
21: def show
22: byebug
23: logger.debug "Returning a todo: " + @todo.inspect
=> 24: json_respond(@todo)
25: end
26:
27: # PUT /todos/:id

We see the log message, and the stack pointer advances. Let’s keep going.

(byebug) next
[19, 28] in /usr/local/bin/ruby/2.3.0/gems/actionpack-5.2.2/lib/action_controller/metal/rescue.rb
19:
20: private
21: def process_action(*args)
22: super
23: rescue Exception => exception
=> 24: request.env["action_dispatch.show_detailed_exceptions"] ||= show_detailed_exceptions?
25: rescue_with_handler(exception) || raise
26: end
27: end
28: end

We’re inside an exception handler!

Displaying data

Even though we disabled our exception handler, we still stepped into one that Rails installs. The error is named exception. Let’s view it.

(byebug) exception
1: exception = #<NoMethodError: undefined method `json_respond' for #<TodosController:0x00007fd37605dce0>
Did you mean? json_response>

You can examine any expression by entering its name. There’s the error. It’s the same one we’ve been dealing with.

We can see all of the variables in the current context.

(byebug) instance_variables
[:@_routes, :@_request, :@_response, :@_lookup_context, :@_action_name, :@_response_body, :@_params, :@todo, :@_config]

Try examining a few of them before moving on.

Start the process over. First, kill the current session.

(byebug) kill
Really kill? (y/n) y
Killed: 9

Now, start the server again and make the request. Next, when the debug session opens, try displaying the @todo object instead of only viewing it.

[18, 27] in /Users/egoebelbecker/Code/rails/todo-service/app/controllers/todos_controller.rb
18: end
19:
20: # GET /todos/:id
21: def show
22: byebug
=> 23: logger.debug "Returning a todo: " + @todo.inspect
24: json_respond(@todo)
25: end
26:
27: # PUT /todos/:id
(byebug) display @todo
1: @todo = #<Todo id: 1, description: "Replace doors on limo, ashtrays full", done: 0, created_at: "2018-12-15 18:46:47", updated_at: "2018-12-15 18:46:47">
(byebug) display @todo.description
2: @todo.description = "Replace doors on limo, ashtrays full"
(byebug)

We use display to print any variable as we walk through a program.

Stepping into the stack

Next, try to step into the program instead of using next.

(byebug) step
1: @todo = #<Todo id: 1, description: "Replace doors on limo, ashtrays full", done: 0, created_at: "2018-12-15 18:46:47", updated_at: "2018-12-15 18:46:47">
2: @todo.description = "Replace doors on limo, ashtrays full"
[110, 119] in /usr/local/bin/ruby/2.3.0/gems/activesupport-5.2.2/lib/active_support/configurable.rb
110: options = names.extract_options!
111:
112: names.each do |name|
113: raise NameError.new("invalid config attribute name") unless /A[_A-Za-z]w*z/.match?(name)
114:
=> 115: reader, reader_line = "def #{name}; config.#{name}; end", __LINE__
116: writer, writer_line = "def #{name}=(value); config.#{name} = value; end", __LINE__
117:
118: singleton_class.class_eval reader, __FILE__, reader_line
119: singleton_class.class_eval writer, __FILE__, writer_line

First, note that our displayed variables stayed with us.

Step takes us into the call stack. We stepped from the call to log the current @todo into configuration code. Let’s view our current backtrace.

(byebug) where
--> #0 ActiveSupport::Configurable::ClassMethods.config at /usr/local/bin/ruby/2.3.0/gems/activesupport-5.2.2/lib/active_support/configurable.rb:36
#1 ActiveSupport::Configurable.config at /usr/local/bin/ruby/2.3.0/gems/activesupport-5.2.2/lib/active_support/configurable.rb:147
#2 ActionController::API.logger at /usr/local/bin/ruby/2.3.0/gems/activesupport-5.2.2/lib/active_support/configurable.rb:115
#3 TodosController.show at /Users/egoebelbecker/Code/rails/todo-service/app/controllers/todos_controller.rb:23
#4 ActionController::BasicImplicitRender.send_action(method#String, *args#Array) at /usr/local/bin/ruby/2.3.0/gems/actionpack-5.2.2/lib/action_controller/metal/basic_implicit_render.rb:6
...

We’re four calls away from the log statement. The program is deep into the stack, so I trimmed the output.

Catching exceptions

In this case, we already know where Ruby throws the exception in our code and why. Sometimes that’s not always clear. It’s possible that it’s thrown deep on the stack or not always in the same place. Fortunately, we can catch exceptions with Byebug.

Start another session and request todo #1. When Byebug starts, tell it to catch NoMethodError.

[18, 27] in /Users/egoebelbecker/Code/rails/todo-service/app/controllers/todos_controller.rb
18: end
19:
20: # GET /todos/:id
21: def show
22: byebug
=> 23: logger.debug "Returning a todo: " + @todo.inspect
24: json_respond(@todo)
25: end
26:
27: # PUT /todos/:id
(byebug) catch NoMethodError
Catching exception NoMethodError.
Then, tell it to continue.
(byebug) continue
Returning a todo: #<Todo id: 1, description: "Replace doors on limo, ashtrays full", done: 0, created_at: "2018-12-15 18:46:47", updated_at: "2018-12-15 18:46:47">
Catchpoint at /Users/egoebelbecker/Code/rails/todo-service/app/controllers/todos_controller.rb:24: `undefined method `json_respond' for #<TodosController:0x00007fcc6223e598>
Did you mean? json_response'
[19, 28] in /Users/egoebelbecker/Code/rails/todo-service/app/controllers/todos_controller.rb
19:
20: # GET /todos/:id
21: def show
22: byebug
23: logger.debug "Returning a todo: " + @todo.inspect
=> 24: json_respond(@todo)
25: end
26:
27: # PUT /todos/:id
28: def update
(byebug)

Continue restarts execution. When NoMethodError is thrown, byebug stops execution again and puts us exactly where Ruby threw it. So instead of stopping inside the exception handler, we’re at the unknown method.

This is a handy technique for getting Byebug to take you to the problem when you don’t know where it is.

An ounce of prevention

Troubleshooting is a process that starts before you have a problem. Useful error messages and user-friendly logs can go a long way toward making fault isolation easier.

Retrace makes troubleshooting even easier. You can use Retrace to monitor your Ruby application’s performance, redirect logs to a web console, and track errors as they occur, giving you a whole new set of insights to optimize your application.

Sign up for a trial account and start monitoring your applications today.

Improve Your Code with Retrace APM

Stackify's APM tools are used by thousands of .NET, Java, PHP, Node.js, Python, & Ruby developers all over the world.
Explore Retrace's product features to learn more.

• App Performance Management
• Code Profiling
• Error Tracking
• Centralized Logging
• App & Server Metrics

Learn More

Author

Eric

More articles by Eric