Ruby memory, ActiveRecord and Draper
Tags: ruby, rails, activerecord, draper
Published: 2019-01-23 14:42:23

---
title: Ruby memory, ActiveRecord and Draper
published: true
description: 
tags: #ruby #rails #activeRecord #draper
---

At Appaloosa we often process CSV. When we process thousands of CSV lines of users that need to be added to (or removed from) a group, we are seeing a huge increase in memory. Sometimes the Heroku dynos cannot manage it.

We will explain how we jump from this when processing 4_000 users (look at blue line but also time):

![](https://cdn-images-1.medium.com/max/2000/1*zrMYSVUKpuAmSBDqHVHx8g.png)

To that:

![](https://cdn-images-1.medium.com/max/2000/1*KOcjkjqmc4oeAiTgjCyp6g.png)

## memory profiler

We used [stackprof](https://github.com/tmm1/stackprof), [memory_profiler](https://github.com/SamSaffron/memory_profiler). We look at tool like [speedscope](https://github.com/jlfwong/speedscope) for stackprof results and always it point at heavy use of ActiveRecord. Also we noticed in “Allocated String Report” of memory_profiler a string allocated multiples times.

With 4000 users:

    Allocated String Report
    -----------------------------------
       1619100  "decorated?"
       1619100  .rvm/gems/ruby-2.5.3@app/gems/activerecord-5.2.1/lib/active_record/attribute_methods.rb:279

## "decorated?" where does it come from?

It’s instantiated here: `.rvm/gems/ruby-2.5.3@app/gems/activerecord-5.2.1/lib/active_record/attribute_methods.rb:281`

{% gist https://gist.github.com/benoittgt/201c6905f35dc323625b65e750d01ada %}

If we add a `puts caller` when `"decorated?"` is instantiated we have this:

{% gist https://gist.github.com/benoittgt/483523c4243bb542459fbb0807469477 %}

First we didn’t understand how we can jump from Draper to `active_record/associations/collection_association.rb` like:

{% gist https://gist.github.com/benoittgt/3aa22e2a351fcd5ee3741f1c1d6f18c6 %}

The code on Draper [part](https://github.com/drapergem/draper/blob/ed62f5555148b997eeb9feb365dd3dffcdb3d903/lib/draper/decoratable/equality.rb#L21) is:

{% gist https://gist.github.com/benoittgt/f11627c459948fbd8f8205fd2e46754a %}

Then the code in `active_record/associations/collection_association.rb:281` looks like:

{% gist https://gist.github.com/benoittgt/d3c85980731d2368157dea989f84e6a3 %}

We jump from `index = @target.index(record)` to `Draper::Decoratable::Equality.==` 🤔.

## But how?

[Christophe Maximin](https://github.com/christophemaximin) (thanks a lot, Christophe) came with this answer:
> *(Wild guess by just reading the AR code) Because if the same user (same primary key) is already in users, it just replaces that old object with the new object you’re passing with <<, which is why it needs to know the index of the old one. And to know if records are the same, it needs to call ==.*

If you want a full example of how it is called, you can use `[TracePoint]`(https://ruby-doc.org/core-2.5.3/TracePoint.html). Without and with having `==` in Integer:

{% gist https://gist.github.com/benoittgt/9c616682ace4f823fba07a65028f660e %}

> *Tracepoint “Establishes proc as the handler for tracing” calls `:call:` for call to Ruby method `:c_call:` for a call to a C-language routine*

## What happens on a real app?

To be sure we were not testing a side effect of our app, we created a [new rails app](https://github.com/benoittgt/ar_and_draper_allocation/tree/with_draper_and_concat), with 2 models, Draper installed. Then [we monkey patched `add_to_target`](https://github.com/benoittgt/ar_and_draper_allocation/blob/with_draper_and_concat/lib/core_extensions.rb) for ActiveRecord.

{% gist https://gist.github.com/benoittgt/689a381be060e6315ad2b3aa00119e2c %}

We put the code to reproduce the concatenation in a [rake task](https://github.com/benoittgt/ar_and_draper_allocation/blob/with_draper_and_concat/lib/tasks/concat_records.rake).

If we add two records `rails concat_records:comments[2]` on the second record we have this interesting result:

{% gist https://gist.github.com/benoittgt/df1f67d0c966d98d84be9a9e59951ecb %}

We can see that we are calling `index`, then `Draper::Decoratable::Equality` (that override `==`), then `ActiveRecord:Core`, etc...

The issue is when the array of record we concat contains lot’s of ActiveRecord objects. Every time we add one element, we redo all of those calls. Also Draper in is `Equality` method add more calls, and one of the call adds `:decorated?` string. All of this chain have a cost.

Let’s measure it.

## Measuring allocation with Draper, without Draper, without concatenation

## With Draper ([branch](https://github.com/benoittgt/ar_and_draper_allocation))

Draper gem installed. No decorators defined but `==` is overridden by Draper as we can see.

{% gist https://gist.github.com/benoittgt/db00021637942e618a1c48a17510f4bc %}

{% gist https://gist.github.com/benoittgt/8e5cb2781bb7353266a52728f661c082 %}

If we run a measure with `memory_profiler`: `rails concat_records:comments[2000]`. We get:

    Total allocated: 327.93 MB (4862043 objects)

    Total retained:  17.67 MB (172370 objects)

And we can see also:

    Allocated String Report

    -----------------------------------

    1999000  "decorated?"

    1999000  .rvm/gems/ruby-2.5.3/gems/activerecord-5.2.1/lib/active_record/attribute_methods.rb:282

## Without Draper ([branch](https://github.com/benoittgt/ar_and_draper_allocation/tree/no_draper))

First we don’t have any more the very present allocated string `"decorated?"`. First allocated string is `””` with 40185 occurrences. That’s a gain of 1 958 815 strings.

    Allocated String Report

    -----------------------------------

    40185  ""

    24000  .rvm/gems/ruby-2.5.3/gems/activesupport-5.2.1/lib/active_support/tagged_logging.rb:23

If we run a measure with `memory_profiler` `rails` `concat_records:comments[2000]`. We get:

    Total allocated: 247.97 MB (2863011 objects)

    Total retained:  17.67 MB (172370 objects)

It’s little bit better.

## Without concat but with Draper ([branch](https://github.com/benoittgt/ar_and_draper_allocation/tree/draper_no_concat))

Same as before without Draper we don’t have any more very present allocated string `"decorated?"`:

    Allocated String Report

    -----------------------------------

    40185  ""

    24000  .rvm/gems/ruby-2.5.3/gems/activesupport-5.2.1/lib/active_support/tagged_logging.rb:23

And…

    Total allocated: 218.73 MB (2377978 objects)

    Total retained:  31.95 kB (284 objects)

This is a huge gain but we don’t validate that we don’t create a duplicated entry into the join table. But this is something easy to handle.

## How this can happening?

* If their is a `distinct` on the association scope like this:

{% gist https://gist.github.com/benoittgt/7824ea87f504a6bcbc787104fec44fca %}

* Then when ActiveRecord needs to concatenate. It will call `@target.index(record)`. If `@target` have a lot's of elements this will consume more some CPU and memory.

* And if Draper is installed this will add extra cost because Draper override `==` called from `index`. This override will allocate extra strings we don't need (`"decorated?"`).

Looking in `index` plus using Draper is a logarithmic cost for iteration per second and memory. More element you have in `"target"` slower it gets.

**So careful when using `distinct` in a scope. Also careful with Draper.**

Here is a diagram of what is happening

![Diagram of index search and Draper override](https://cdn-images-1.medium.com/max/2000/1*B-2lE_aQCJpVcW1Iv2CRng.png)*Diagram of index search and Draper override*

In our code base the patch looks like:

![](https://cdn-images-1.medium.com/max/2000/1*KQSCCiEKZMxYqmWNKdYm8g.png)

## Thanks

Thanks to Appaloosa Team, Christophe Maximin, Ryuta Kamizono (kamipo), Nate Berkopec and the Rails Speed Community Slack.

👋

You should subscribe to our blog to be notified whenever a new article is available!

This article was written by [Benoit Tigeot](https://www.twitter.com/benoit_tgt) of [Appaloosa](https://www.appaloosa-store.com/)’s dev team.