Rails logs provide useful information indicating where queries are being fired from along with any custom logging information. We can utilise the query logs indicating line numbers to identify performance bottlenecks.
There are quite a few gems available to find out performance bottlenecks. Bullet helps identify N+1 queries in the application. It also help with removing unused eager loading of associations. While such gems help identify performance bottlenecks, sometimes it’s rather difficult to identify bottlenecks if the queries being fired are not N+1 queries, but they are being called multiple times from different workflows.
Rails provides a configuration option
It is enabled by default in applications > Rails 5.2
with line numbers firing the query in Rails logs.
Below is the sample log generated in log file.
In this case, it’s easier to identify the source of the problem.
i.e. we need to look at
We can add eager loading to resolve this particular issue.
It can be quite overwhelming to find out which parts of our code are causing bottlenecks.
In such cases, we can use a simple bash command given below to find out which lines are getting called most number of times.
Assuming we are looking in log files of
The line above lists down log lines in sorted manner
with line numbers which are logged most number of times
at the last with count showing how many times it’s being called.
Posting a sample output of the command given above.
As we can see it clearly states which query is being fired huge number of times in the application. We can utilize this information effectively to find out which lines are hogging our application.
Often times, we need to optimize performance of certain parts / workflows of our application. In such case, we can respwan the log file.
Execute the workflow by restarting
rails server and execute the command given above to find out issues
in a particular session.
Subscribe to Ruby in Rails
Get the latest posts delivered right to your inbox