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.

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

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.

ActiveSupport::Notifications.subscribe /^render\_.+.action_view\$/ do |event|
views_path = Rails.root.join("app/views/").to_s
template_identifier = event.payload[:identifier]
template_name = template_identifier.sub(views_path, "")
message = "[#{event.name}] #{template_name} (Allocations: #{event.allocations})"

ViewAllocationsLogger.log(message)
end

This should log something like this.

[render_partial.action_view] shared/\_ad_banner.html.erb (Allocations: 43)

[render_collection.action_view] articles/\_article.html.erb (Allocations: 842)

[render_template.action_view] articles/index.html.erb (Allocations: 4108)