The two most common performance symptoms are with throughput or timeouts.
An application's maximum throughput can be measured by how many requests per second it serves; New Relic reports this number as "rpm," which means "requests per minute." Throughput will be limited by how long the average request takes to process and how may servers are available to handle processes. Heroku calls these servers "dynos."
Application timeouts are caused by excessively long response times. Even if the application's average response time is fast, one or two actions may be too slow, which means users will be unable to use those actions. On queueing systems like Heroku, other users' requests for faster actions may also be queued behind the slow action, so one slow action can cause others to time out. This means that every action must be fast in order for a user to receive quick response times.
The two most common causes for poor performance are N+1 query problems and unindexed queries.
An action that doesn't do eager loading will perform N+1 queries. For example, if you find a set of posts and want to display the username for the user that corresponds to each post:
- You can use eager loading to perform two queries (one for the posts, and one for all the users)
- Without eager loading, you perform N+1 queries (one for the posts, and then N queries: one for each users)
Querying a large table without indexes can also cause problems. Without an index, the database has to scan the entire table, which takes a long time.
We can use New Relic to find either of these issues.
Sign into New Relic for the application you're debugging. If it's a Heroku application, you can do this from My Apps: click on the application you want to debug, open the "Add-ons" menu, and click "New Relic." Once you're signed into New Relic, click on "Web transactions."
By default, New Relic will display "Most time consuming" actions. This is a combination of how slow an action is with how often that action is used. Improving performance for the most time consuming action will increase the application's throughput.
You can also display actions with the "Slowest average response time." This finds the actions that take the longest to run without taking into account how often the action is used. If users are experiencing timeouts (usually in the form of Heroku H12 errors on Heroku), improving performance for these actions can solve them.
Once you've identified which action you want to improve, click on it. The "Performance breakdown" tab will display where the time is being spent for most requests to this action. If you see that the average calls per transaction to a database query is high, you probably have an N+1 problem. If you see a single database query that takes a long time, you may have an unindexed query.
Under the "Overview" tab, there may also be a list of "Slow transactions." Clicking one of these will give you a detailed view of what happened during a particular slow request.
Once you've identified the problem using web transactions, it's time to use New Relic developer mode.
This works best with a production dump and a specific URL to debug, but it will also work with sufficient development data.
If you don't have New Relic set up for your application, or if you're using the Heroku addon, you'll need to set it up for development.
First, add the "newrelic_rpm" gem to your Gemfile and rebundle.
Next, you'll need a New Relic configuration file. If you're only worried about it in development, you can use this minimal configuration:
development:
monitor_mode: false
developer_mode: true
After setting it up, restart your server.
Visit the local URL that you want to debug, and then open "/newrelic" in a new tab. This will show the New Relic developer mode home page. Click on a URL in the list to show performance information.
After viewing the overview, click the "SQL" tab. This this the easiest place to find your N+1 or slow query problem. If you see the same query over and over, it's an N+1 problem. If there's a single query that takes a lot of time, you're probably missing an index.
If you can spot a slow query or N+1 problem right away, adding indexes or eager loading will likely fix the issue. If not, you'll have to do a little debugging.
Sometimes, it's difficult to tell which part of the application is the culprit. Using New Relic tracers, you can break up the time it takes to perform a request to tell which code is responsible.
New Relic reports two times for each traced block: the total time, and the exclusive time. The total time is how long it took from when execution entered that block to when it left, including any other traces within the block. The exclusive time is how long it took to run that block minus any other traces within the block. For example, if a method executes a query that takes 1 second and then it takes that method another second to process the results of the query, the total execution time is two seconds, but the exclusive time is only one second. In order to accurately identify the source of a performance issue, it's important to find blocks that are responsible for a large part of exclusive time.
New Relic will SQL calls by default, but you'll have to tell it what other
blocks you'd like trace. The easiest way to add a tracer is to trace the
execution time for a method. The newrelic_rpm gem adds a class-level method
called add_method_tracer that accepts the name of the method.
Here's the best way to identify where execution time is coming from:
- Add a method tracer to the method you're debugging.
- Run the action
- Look in New Relic to see how much exclusive time the action takes.
- Repeat this process for other methods that method calls.
Start by adding a method tracer to the controller action you're debugging. After repeating this several times, the "Details" tab in New Relic should show a nice tree of where the execution time was spent.
If you want to trace execution time for just part of a method, you can add a tracer to a Ruby block:
self.class.trace_execution_scoped(['English description']) do
# code to trace
end