Blog

Performance Profiling for your Rails App with Rack-mini-profiler

Placeholder Avatar
Lucas Caton
January 22, 2019

Whether you are a veteran Ruby on Rails developer or relatively new, the rapid application development framework that is Rails focuses on quickly getting things up and running. Sooner or later it’s likely that your speed of development has made a great product, but the speed leaves a bit to be desired - and your code needs optimisation.

But now you need to know what to optimise.

Rack Mini Profiler helps you to easily detect Database issues, Memory issues and Time spent by gems/libs.

This tool was designed to run in production but it also works fine in development. However, you will need to make a few tweaks to development. NOTE: Rails development mode specifies reloading classes on every request, this will have an effect on your profile metrics.

In this blog, I wanted to show how you can use this tool to detect some common Rails performance issues.

Installing Rack-mini-profiler

Let’s add the following gems: Gemfile ... gem 'rack-mini-profiler' gem 'flamegraph' gem 'stackprof' gem 'memory_profiler'

Now, start the server - you should see the speed badge in the top-left corner. Next, we’ll make the application behave as it would in a production environment. First, change the Rack-mini-profiler storage to memory instead of filesystem: config/initializers/rack_mini_profiler.rb ```

Rack::MiniProfiler.config.storage = Rack::MiniProfiler::MemoryStore ```

Next, disable SSL in the local environment: config/environments/production.rb ```

config.force_ssl = false ```

Now, let’s run the database setup, compile assets and set the secret key base: ```

rails db:reset RAILS_ENV=production rails assets:precompile RAILS_ENV=production rails s RAILS_ENV=production SECRET_KEY_BASE=secret ```

Speed Badge

By visiting the root url you will see the speed badge, it will show you how much time it took the application to render. It also shows you the time spent in the layout, views and partials. Clicking the badge will show some detailed information: duration (ms), shows you the total request time. query, shows you how many queries you are generating. % in sql shows you what percentage of time is spent in SQL (Using a production database copy or something similar will be much better than using a development database data). Dom Content Loaded Event shows you how much time between receiving a response and finishing loading all the content. (The less the better, optimizing the front-end will make this time decrease).

Now, let’s inspect the SQL links to see what we got.

You will see the rendering time by partial and also the time spent in the query and the query itself and the line where the query was executed. If the SQL query is expensive you may consider fixing/removing it or probably caching it to resolve the problem. Sometimes it may be nothing more than a missing include.

Flamegraph

Adding ?pp=flamegraph to the URL query string, the application will render the flamegraph chart. Y is the stack level, while X is the time. Simple right?

Scroll to see more details in the chart.

On the bottom of the page you will see some boxes with different colours, the percentage is the % of the time the request spent inside that stack frame. Each application shows different metrics, you may have some gem helpers in the view.

Let’s say number_to_phone, and you have 100 records on the page calling this helper in each partial, which will represent more time to render each partial. One solution could be to stop using the Rails helper and allow JavaScript do the job. This way the flamegraph will not complain about the time spent by that slow helper. Sometimes you will find there are helpers or methods that are more expensive than you thought, in those cases you could write your own light implementation.

Garbage Collection Profiling

Debugging memory issues in production is simple with rack-mini-profiler. Here’s how:

profile-gc

Adding ?pp=profile-gc to the URL query string, will generate a crazy-long output. Go for a coffee while it finishes, it takes time. :-) Find the New bytes allocated outside of Ruby heaps section. If this number is greater than 8 MB you may want to start investigating to see what’s going on in that particular request because something is consuming a lot of memory. Now, let’s go to the ObjectSpace delta caused by request section, Say you have String : 7300 which means that you have 7300 more Strings after this request. Next the ObjectSpace stats section. This is the total number of Objects, by Class, alive in the VM. You probably find listed the MIME::Type or MIME::Types::Container this is because there could be a gem in your Gemfile who is using an old version of the ruby-mime-types gem. This could be fixed by setting up a newer version of the ruby-mime-types gem in your Gemfile. Finally the String stats section.

This is the number of times a string was allocated. If a string is allocated an abnormally large amount of times, This can be decreased by moving the string(s) to frozen CONSTANTS. Imagine you have the string “hello” allocated 3000 times in a request. To fix this allocation we move the “hello” string to a constant, now you just have only one allocation for that string instead of 3000.

Profile-memory

Adding ?pp=profile-memory to the URL query string, tells us which line of code is allocating a given object. We are interested on the “retained” objects (scroll down in the output and you will find the “retained” section), this kind of object will stick after the request is finished. This is a common location for Ruby object leaks.

Exceptions are Slow

Adding ?pp=trace-exceptions to the URL query string, returns all the spots where your application raises exceptions. Avoid using exceptions as a form of flow control since exceptions are slow. Instead of raising exceptions all over the place, you could delegate the exception handling to a class, this class will return something to the end user as soon as possible. Slow: catch A -> raise B -> catch B -> raise C -> catch C -> return Fast: catch A -> handle exception & return > Sometimes the Fast option isn’t possible, but you should always aim for it. Exceptions should not be expected, think about it… now repeat after me: “I will not raise exceptions everywhere to drive my Ruby applications”.

Conclusion

Rack-mini-profiler has different tools for you to debug and profile your Rack based applications like Rails. Now that you know a bit about each tool you should be able to start fixing that slow page you have been always trying to fix.

Final Thoughts and Next Steps

Adding rack-Mini-profiler in production and development environments will help you sort-out performance issues easily, you learned how to set it up in development. Remember that your development environment must act like your production environment or at least be very similar. Use rack-mini-profiler to see the queries your pages are generating, make sure you are not controlling your application flow with Ruby exceptions. Most common Rails issues are related to slow SQL queries, large responses from your Rails app, waiting for third party APIs, lack of background jobs and the list can go on.

Now you should be ready to tackle the common ones and then, when you master rack-mini-profiler, it will be easy for you to resolve many performance issues.