crentist crentist - 10 days ago 5
Ruby Question

Rails 4 Error R14 on Heroku (Memory Quota Exceeded)

I have been getting the (apparently common) Error R14, not sure when it started but noticed after installing the Papertrail add-on. I also added oink after seeing others mentioning it. I have tried everything others have tried in other SO questions but I can't seem to find the problem / memory leak.

Error R14 (Memory quota exceeded)
heroku/web.1: Process running mem=587M(114.7%)


When I see this, to temporarily fix this, I run
heroku restart
which works for a while but I want to fix this problem permanently.

From what I can see in Papertrail, the app just keeps loading the same page (home page) over and over again (and its not user traffic):

app/web.1: Completed 200 OK in 436ms (Views: 45.5ms | ActiveRecord: 386.2ms)
app/web.1: May 25 18:14:52 5d2105e1-d799-4496-a2af-3785e78998db rails[9]: Oink Action: static_pages#home
app/web.1: May 25 18:14:52 5d2105e1-d799-4496-a2af-3785e78998db rails[9]: Memory usage: 378860 | PID: 19
app/web.1: May 25 18:14:52 5d2105e1-d799-4496-a2af-3785e78998db rails[9]: Oink Log Entry Complete
heroku/web.1: source=web.1 dyno=heroku.25566769.9d9a3da0-db4c-4b51-bc53-b69be9e43cb7 sample#memory_total=209.86MB sample#memory_rss=209.83MB sample#memory_cache=0.02MB sample#memory_swap=0.00MB sample#memory_pgpgin=59278pages sample#memory_pgpgout=5555pages


and after 2 minutes:

heroku/web.1: source=web.1 dyno=heroku.25566769.9d9a3da0-db4c-4b51-bc53-b69be9e43cb7 sample#memory_total=293.73MB sample#memory_rss=291.94MB sample#memory_cache=0.02MB sample#memory_swap=1.77MB sample#memory_pgpgin=80890pages sample#memory_pgpgout=6147pages `


I also enabled
heroku labs:enable log-runtime-metrics
from instructions from another question here and from Heroku here

I have also added the New Relic add-on and this is what I see in the Monitoring > Instances tab:

For the Last 7 Days:
last 7 days

For the Last 24 Hours:
last 24 hours

I am confused as you can see after 5/24 the memory usage went down and has since stayed down, but in the logs it shows memory being used
mem=587M(114.7%)
and in the last 24 hours an average of 150M, so I don't understand what is happening. I hope someone can help. Thanks.

Update 1: Added Gemfile



#Gemfile
source 'https://rubygems.org'
ruby '2.1.1'
gem 'rails', '4.1.1'

gem 'puma', '~> 2.8.2'
gem 'turbolinks', '~> 2.2.2'
gem 'pg', '~> 0.17.1'
gem 'rack-attack', '~> 4.0.1'
gem 'memcachier'
gem 'dalli', '~> 2.7.1'
gem 'oink'
gem 'fog', '~> 1.22.0'
gem 'activeadmin', github: 'gregbell/active_admin'
gem 'dynamic_sitemaps', '~> 2.0.0'
gem 'whenever', :require => false
gem 'cancancan', '~> 1.8.0'
gem 'mini_magick', '~> 3.7.0'
gem 'carrierwave', '~> 0.10.0'
gem 'devise', '~> 3.2.4'
gem 'rolify', '~> 3.4.0'
gem 'simple_form', '~> 3.0.2'
gem 'cocoon', '~> 1.2.6'
gem 'friendly_id', '~> 5.0.3'
gem 'nokogiri', '~> 1.6.2.1'
gem 'kaminari'
gem 'impressionist', '~> 1.5.1'
gem 'validate_url'
gem 'searchkick', '~> 0.7.5'
gem 'meta-tags', '~> 2.0.0'
gem 'newrelic_rpm'


group :assets do
gem 'sass-rails', '~> 4.0.3'
gem 'bootstrap-sass', '~> 3.1.1.1'
gem 'uglifier', '~> 2.5.0'
gem 'coffee-rails', '~> 4.0.1'
gem 'asset_sync'
#gem 'jquery-turbolinks'
gem 'jquery-rails'
gem 'jbuilder', '~> 2.0.7'
end

group :production do
gem 'rails_12factor'
end


Update 2: Changed server from Puma to Unicorn



It was pretty simple, following the directions here. And this is what it looks like now, which seems good, but I suspect it was because the application was restarted:
last30mins

# after heroku restart
heroku/web.1: source=web.1 dyno=heroku.25566769.3770e52a-ddf3-485a-a88a-ac4fd54ab640 sample#memory_total=123.62MB

# after 4 minutes
heroku/web.1: source=web.1 dyno=heroku.25566769.3770e52a-ddf3-485a-a88a-ac4fd54ab640 sample#memory_total=276.48MB


Update 3: Lowered the amount of Unicorn workers to 2



After doing that, this is the average memory usage per dyno/instance for the past 6 hours according to New Relic:
lasy6hoursafter

And the output in PaperTrain (and also tried LogEntries) was this:

app/web.1: May 26 19:54:08 21ae35ee-5656-4254-9f12-5dc6bb59efa1 rails[6]: Memory usage: 426076 | PID: 6
app/web.1: May 26 19:54:08 21ae35ee-5656-4254-9f12-5dc6bb59efa1 rails[6]: Oink Log Entry Complete
heroku/web.1: source=web.1 dyno=heroku.25566769.21ae35ee-5656-4254-9f12-5dc6bb59efa1 sample#load_avg_1m=0.00 sample#load_avg_5m=0.00 sample#load_avg_15m=0.00
heroku/web.1: source=web.1 dyno=heroku.25566769.21ae35ee-5656-4254-9f12-5dc6bb59efa1 sample#memory_total=431.99MB sample#memory_rss=406.85MB sample#memory_cache=0.10MB sample#memory_swap=25.04MB sample#memory_pgpgin=198612pages sample#memory_pgpgout=94432pages


I checked the logs, and after 1 hour I was getting the R14 error and now it has been been going up very little, almost holding steady at 432MB and have not gotten the error anymore. So this seems to have fixed the problem! I will update over time if this changes.

Answer

If Papertrail is causing a problem, try a different add on. I've been using LogEntries without much of a problem. https://addons.heroku.com/#logging

Also try to lower your Unicorn worker processes so it uses lower total memory. Instead of the default of 3 (per box/dyno), try 2.

https://devcenter.heroku.com/articles/rails-unicorn#unicorn-worker-processes

You can also run a memory profiler on your app:

http://timetobleed.com/memprof-a-ruby-level-memory-profiler/

https://www.ruby-toolbox.com/search?utf8=%E2%9C%93&q=profile

Comments