Memory usage growth

[kuinak]

We noticed memory utilization growing on some of our lesser used apps running on Heroku. I looked at our logs, and the only entries I saw were related to Scout. As a test, I decided to deploy 2 versions of the same app. One with Scout enabled, the other without. Memory usage grew very quickly and maxed out after a couple hours on the instance with Scout enabled. On the instance without scout, memory utilization remained stable. Both of these instances received no web traffic during that period. On instances with web traffic, we frequently see timeouts (requests exceeding 30s), presumably due to garbage collection pauses or swapping.

Is this behavior expected?

[dlanderson]

Some more info:

• Unicorn 5.4.0, and Scout 2.4.11
• 1 Unicorn worker
• The apps were completely idle during this time
• Memory does not appear to be affected if even a single request is served
• Gemfile.lock was sent to support address

We're attempting to reproduce the issue.

[itsderek23]

To test, I've started w/a bare-bones Rails 5.2.0 / Ruby 2.5.1 app, running 2 web dynos, but Scout only enabled on web.1.

I'm going to let this run for a bit and see how the memory usage compares.

[itsderek23]

So far memory usage is flat (4 hour period):

@kuinak - have you applied any GC settings that override the Heroku defaults?

[kuinak]

@itsderek23 I reviewed the configuration and didn't see anything different with the GC options (e.g. MALLOC_ARENA_MAX).

However, I did notice that we didn't have any SCOUT_* vars set. I added the free version of the Scout addon to the app and noticed that the following log entry stopped appearing:

2018-07-26T23:16:47.307974+00:00 app[web.1]: [Scout] [07/26/18 23:16:47 +0000 web.1 (23)] INFO : [23:14] Delivering 2 Metrics for 0 requests and 0 Slow Transaction Traces and 0 Job Traces, Recorded from 1 processes.

The web.1 dyno appears to be reporting in the scout dashboard.

I'm wondering if it's a case of the APM failing to report because the key wasn't set, and something being held on to in memory related to your layaway process?

[kuinak]

I removed the Scout addon and turned logging up to debug. It does appear the requests are succeeding, so I'm going to retract my previous thought regarding the layaway process.

[itsderek23]

Thanks @kuinak.

Clarifying:

One with Scout enabled, the other without.

I'm assuming scout_apm was installed in both test cases, correct? The only difference was setting SCOUT_MONITOR=true or monitor: true in the config of the app that showed the memory increase?

[kuinak]

@itsderek23 That's correct. The gem is installed in both branches. The branch with memory growth has monitor: true, the branch without memory growth has monitor: false.

[cschneid]

After some back and forth over email, I'm going to close this issue, although without a really satisfying answer of exactly what's happening.

@kuinak collected heap dumps which showed garbage being created from what looks like code reloading, but all attempts at reproduction on our end failed.

We attempted to reproduce locally with a copy of his Gemfile, but that didn't work. If there's an interaction occurring, it's likely with one of the Gems when it is fully configured, not simply present.

What we found:

• Each garbage collection generation added 3-4mb of usage, the vast majority of which are from activerecord, activesupport and activemodel objects.
• The chart levels off near heroku's memory limit, indicating that its identifiable garbage, and not a true leak.
• The heap dump isn't showing any scout agent objects in the GC'd generations.