It doesn’t matter how easy programming language is to use, it’s very likely that sooner or later we encounter some bugs in our code. Luckily, Rails provides many useful tools which can help us to deal with them.
In this post I’m going to look through four interesting debugging tools:
- Active Record Backtrace SQL Queries Plugin
With help of Logger, Byebug, and Pry-Byebug, we will fix the same problem, so you don’t need to read the whole tutorial if you’re going to use just one. Using Active Record Backtrace Plugin is also worth seeing, additionally.
However, I will show you all of the different ways of usage for debugging things to allow you to discover your own preferences easier and show you the different ideas behind debugging.
Before focusing on real examples, here are some general tips that should be used before beginning any debugging.
1. Always read error messages.
Carefully reading error messages may give us essential information, which allows us to understand what a problem is, including: what class/method does the error reference, what is the class/type of the object, if object is nil, if you call a method on this class/type of object, or what lines of code should be investigated.
2. In the stack trace, pay close attention to the code lines that come from your project.
There are lines starting with
app/… . In most cases, your own code generates a problem.
If you already know this, we move on to Rails debugging.
Ruby on Rails Debugging
Below is a page from an application that isn’t working correctly, and we’ll try to fix it. There is a list of clothes with prices, sizes, and categories that they belong to. The application must be able to lock the chosen size of clothes, which is not in the inventory.
Steps to lock a clothing size:
- Check the checkboxes in a row.
- Click the button “Lock sizes” in the same row.
- The last updated record should be shown in the top of the products list.
Problem to solve?
After clicking the “Lock sizes” button, the chosen clothing type (“Destroyed Drawstring Jeans”) is shown on the top of the list, but checkboxes are unchecked again. This means we made a mistake somewhere in our code and our record is not saved properly to the database. We’ll find out why by using cool Rails debugging tools.
Let’s dive into the code and see how this page works. Here is the view with the table containing the clothes.
Inside the body we render
The code for locking clothing sizes is in the
lock method reads params, which we send using
lock_sizes() method looks like this:
We pass the
product_id to the method, look for checkboxes with class containing the sent
product_id and create
hash sizes with info about the locking sizes. Using
console.log(sizes) in the
lock_sizes() method we can see hash content:
After that, we send an
ajax request to the
lock method in the
ProductsController with product id and previously created
sizes hash. Then, in the controller lock method we update the
locked_by_size field in the database for a product and re-render
product_list with new products by sending the partial to the html element.
However, there aren’t any error messages. Therefore, we need to review logs.
When our server still is running in the console, we can get the following output:
What does logs tell us?
What kind of request did the server receive and which controller action was invoked? In our case, there is
lock method in the
ProductsController. We can see parameters sent to the method and many queries executed by the controller. Logs also inform us about ran scripts (lock.js.erb) and rendered views (partial view _product_list.html.erb).
Active Record Backtrace SQL Queries Plugin
If the information about queries isn’t clean enough, we can use the active record-backtrace-sql-queries plugin. It’s helpful to track down where queries are being executed in application.
Add the module to
Now we only need to require the module from the initializer. Add the code below to the
config/lib/query_tracer.rb and restart the server.
In the console, we get additional logs sources of SQL queries. It helps to avoid going through your code looking for the location of a problem, and we are now able to see exactly where queries are performed.
At first glance the parameters are sent properly. So why we can’t save the record?
A very useful Rails feature is the capability to save information to log files at runtime that you can use to output messages. However, it can be very difficult and time consuming to debug full error logs in the production environment when application logs are choked by many irrelevant messages.
Please note that in production mode, you need to specifically switch logging to debug in order to see detailed information. Luckily, we can easily configure logging. Rails has a separate log file for each runtime environment, and I will give you a few tips how to use it.
config/application.rb or any other environment file you can change the configuration for logging.
To specify a logger:
To set the log level:
Log messages are saved into the respective log files depending on log level, and only messages at that level or higher will be printed. The are six available log levels:
For example, as a developer, you will probably want to know the internal program state. In this case you should set the Logger to
:debug level. However, in a production system, you should use
To write a log message with an explicit level:
There is the configuration I used for our application:
We don’t really need to set the log level to
:debug, because it’s set by default in all environments.
config/environment.rb add the code below:
When we run the server the output we get:
Logger’s level is set to
:debug so all messages are printed. For instance, if we use
:warn level only warning, error and fatal messages will be recorded, as they have an equal or higher level.
Logger provides a few cool features. One of them is setting the format of log messages.
Add formatter to the
Now, after restarting the server and viewing the index page, we see formatted logs that give us additional information about time, date and a log level.
Let’s now use Logger in the
ProductsController lock method!
So far, we only knew there was something wrong with saving records to the database. A wise decision would be to check the state of the chosen product before and after an update. To do that, we won’t need to format logs, so for now we will comment it.
Add 4 and 6 lines to the lock method.
We can use
Rails.logger.debug because our class inherits it from
Inspect method is one of views that helps generate human-readable data from any object. Other ways to inspect the object are
In the console, we see our added messages.
As you can see, there are differences in the
locked_by size field type. We finally found the source of the bug! The problem is that we don’t convert string to symbol in the
locked_sizes_hash. That’s why we can’t overwrite this data in the database. What we need to do now is add
to_sym method in the lock method.
Change the lock method:
Run Rails console and update all product to the initial state:
Then restart the server and try to lock a product size in the browser. Now
locked_by_size field type is the same as before and after update.
We see that the data has been saved correctly.
Congratulations! You found and fixed the bug!
You now know how Logger works. Let’s find out how to use another useful Rails debugging tool.
When your code is behaving in a way you don’t expect it to, it may take too much time printing to the console and looking for the source of the problem. If you want to overview inside of your code while it executes, a better choice would be using a debugger.
I’m going to show you two easy to use debuggers: Byebug and Pry-Byebug.
Debuggers offer many useful commands. Here are the most common kinds:
To get a list of commands, or information about a specific command, you can always use
help in the console.
Byebug is the default debugger in Rails >= 4.2.0. If you use a lower version to install byebug, use command, and then restart the server if it’s running.
gem install byebug
You can add
byebug method anywhere in your code. The execution will stop there, and you will be dropped into a debug console.
Let’s add byebug to our
When you use
lock method execution stopping at the point, the byebug will set, and you will be dropped into an interactive shell.
We start to check if the parameters passed to the lock method are permitted.
It returns false and indicates that there is something wrong. Use
params to print all content.
Let’s try to find out what’s going on.
Byebug gives us the ability to inspect variables. When we write
locked_sizes_hash in the console, we get a nil. Why? Because the line we assign the data to the variable isn’t executed yet.
The arrow points to the line of code which will be executed next.
next in the console and then use the
The arrow points to the line below it and we have an access to the hash content. We can also check the state of the
@product variable before saving changes to the database, as we’ll set it before calling the lock method. We can run any Ruby code here, so let’s print only the
Before the update, data had an initial state. We can go into methods using the
step command. It’s really useful when you run your own methods. That way, you can inspect the variables inside.
step and then run
var args to see arguments passed to the
If you want to go back to the previous frame type
up. By running the
list method, we get information of where we currently are.
next method again to update the
@product and inspect the
locked_by_size field that belongs to the
Great! We found the bug again by using Byebug debugger!
To stop debugging, just run
The basic setup of Pry-Byebug is as simple as installing byebug.
gem ‘pry-byebug’ to the Gemfile and run
bundle install in the console.
After successfully installing the gem, use
binding.pry command in our
Then restart the server, if it’s still running. Execution will stop in the first statement after the command.
As you can see, Pry-Byebug compared with Byebug colors the syntax, but it’s almost the same.
First, we will check parameters sent to the
We get ‘false’ again. This time, we will try to set a breakpoint to stop the code execution at the desired location, instead of executing line by line using
break [number]. The number indicates a number of a line. In this case it’s
Let’s inspect the
locked_sizes_hash variable by typing it in the console. We get a nil because we still didn’t assign anything to the variable.
As you can see, the execution was stopped in the 17 line, and we can now get the hash content.
The next step will be inspecting
@product before call an update method. Check the
lock_by_size field that we’re interested in.
We have a hash that consists of symbols and boolean values.
step command to get into the update method. Pry-binding doesn’t support
var args as byebug does, so to check the passing data, we type the name of the method attributes.
Data we pass to the function will have strings instead of symbols. We can guess that our
@product won’t be updated properly.
If we don’t know where we currently are in a code, (for example: we run too many commands and we don’t see the exact code) using the
whereami command is very handy. View the source code of the method you are currently within.
Come back to the previous method using
up command, and check the state of the
locked_by_size field again.
As we thought, the
locked_by_size field was saved with the wrong data. The good thing is that you know how to use the Pry-Byebug debugger now, and you fixed the bug one more time!
You’re very persistent if you managed to get to the end of this post. 🙂 I hope this tutorial was useful for you Thank you for following along and happy debugging!