Rails 6 reports object allocations while rendering

Recently, Rails 6 added allocations feature to ActiveSupport::Notifications::Event. Using this feature, an event subscriber can see how many number of objects were allocated during the event's start time and end time. We have written in detail about this feature here.

By taking the benefit of this feature, Rails 6 now reports the allocations made while rendering a view template, a partial and a collection.

1Started GET "/articles" for ::1 at 2019-04-15 17:24:09 +0530
2Processing by ArticlesController#index as HTML
3Rendering articles/index.html.erb within layouts/application
4Rendered shared/\_ad_banner.html.erb (Duration: 0.1ms | Allocations: 6)
5Article Load (1.3ms) SELECT "articles".\* FROM "articles"
6↳ app/views/articles/index.html.erb:5
7Rendered collection of articles/\_article.html.erb [100 times] (Duration: 6.1ms | Allocations: 805)
8Rendered articles/index.html.erb within layouts/application (Duration: 17.6ms | Allocations: 3901)
9Completed 200 OK in 86ms (Views: 83.6ms | ActiveRecord: 1.3ms | Allocations: 29347)
Copy

Notice the Allocations: information in the above logs.

We can see that

• 6 objects were allocated while rendering shared/_ad_banner.html.erb view partial,
• 805 objects were allocated while rendering a collection of 100 articles/_article.html.erb view partials,
• and 3901 objects were allocated while rendering articles/index.html.erb view template.

We can use this information to understand how much time was spent while rendering a view template and how many objects were allocated in the process' memory between the time when that view template had started rendering and the time when that view template had finished rendering.

To learn more about this feature, please check rails/rails#34136.

Note that we can also collect this information by subscribing to Action View hooks.

1ActiveSupport::Notifications.subscribe /^render\_.+.action_view\$/ do |event|
2views_path = Rails.root.join("app/views/").to_s
3template_identifier = event.payload[:identifier]
4template_name = template_identifier.sub(views_path, "")
5message = "[#{event.name}] #{template_name} (Allocations: #{event.allocations})"
6
7ViewAllocationsLogger.log(message)
8end
Copy

This should log something like this.

1[render_partial.action_view] shared/\_ad_banner.html.erb (Allocations: 43)
2
3[render_collection.action_view] articles/\_article.html.erb (Allocations: 842)
4
5[render_template.action_view] articles/index.html.erb (Allocations: 4108)
Copy