Heroku Error R14 (Memory quota exceeded): How do I solve this?

37,623

Solution 1

I had this problem .. to solved using find_in_batches.

If someone still has this error i will put the code here. As it takes long time to run, i found a progress_bar gem that help the user. will let it here too cause i think its mandatory in almost every case.

bar = ProgressBar.new( total )
Texto.find_in_batches(:batch_size => 100) do |textos|
    textos.each{| texto | 
        ...do_stuff...
    }
    bar.increment! textos.size
end

Progress Bar: https://github.com/paul/progress_bar/issues

Solution 2

Look for code with 'Model.all.each do |something|' and replace with Model.find_each do |something|. This will save memory by loading chunks of your model into memory instead of the entire model all at once.

Also, look for opportunities to use in_groups_of or :limit to decrease the number of objects that are saved in memory at one time.

EDIT: for_each -> find_each.

Solution 3

Also, the WEB_CONCURRENCY heroku config can cause this. For example, I have an app running 2 1x dynos. If I use sensible_defaults (another heroku config), it defaults WEB_CONCURRENCY to 2 (based on my dynos). This causes a ton of R14 errors in my logs. If I turn off sensible_defaults, and set WEB_CONCURRENCY=1...the problem goes away.

If you don't set WEB_CONCURRENCY, and you don't use sensible_defaults, and you followed the server (Im using Puma) set up via heroku docs...you'll likely have a line in puma.rb that looks like this:

workers Integer(ENV['WEB_CONCURRENCY'] || 3)  

If thats the case, then WEB_CONCURRENCY isn't set...so it will be 3, which is using even more memory.

In console:

// review existing config settings.

heroku config

// IF sensible_defaults is enabled.

heroku config:set sensible_defaults=disabled

// set WEB_CONCURRENCY

heroku config:set WEB_CONCURRENCY=1

// monitor logs for R14 errors.

Solution 4

Heroku specifies a RAM limit per dyno in its Acceptable Use Policy.

You could use memprof, specifically Memprof::Middleware, to help find out what's allocating all the memory in your app during requests. This is really only suitable for use in a non-production environment, since it'll slow down your app.

It's common for a Rails app to be allocating many ActiveRecord objects, so you might look for places where you're doing Model.find(:all).select{...}, or similar queries that pull a lot of records from the DB and then process them in Ruby. Better would be to use where to limit what is returned to the Rails app using SQL.

Solution 5

I was using Mongoid and in my case it was from the 'identity map' being enabled in a non-web request process (so the identity map was never getting cleared and kept growing). Setting Mongoid.identity_map_enabled = false in that process solved the problem.

Share:
37,623
jamesc
Author by

jamesc

U.K. based developer working with Ruby on Rails, Ruby, Android SDK, Java and passionate about technology. Currently proud to be providing a UK based Ukrainian refugee support group with a rails CMS project Ukrainian refugee project

Updated on July 09, 2022

Comments

  • jamesc
    jamesc almost 2 years

    I have a Rails 3.1 app on Heroku. I am seeing a lot of these errors:

    Error R14 (Memory quota exceeded)

    Typically the preceding log entry is showing:

    Process running mem=522M(102.1%)

    This does vary a little but never by much and can occur after almost any URL request, so it's not related to a specific controller action as far as I can tell.

    This is a classic block of log entries:

    2012-01-16T02:35:57+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=55ms status=401 bytes=27
    2012-01-16T02:35:58+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=155ms status=200 bytes=1
    2012-01-16T02:36:02+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=13ms status=401 bytes=27
    2012-01-16T02:36:02+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=147ms status=200 bytes=1
    2012-01-16T02:36:09+00:00 heroku[router]: POST prizequiz.herokuapp.com/mobile_users dyno=web.1 queue=0 wait=0ms service=87ms status=201 bytes=624
    2012-01-16T02:36:11+00:00 heroku[router]: GET prizequiz.herokuapp.com/quizzes/1/questions dyno=web.1 queue=0 wait=0ms service=5ms status=401 bytes=27
    2012-01-16T02:36:11+00:00 heroku[router]: GET prizequiz.herokuapp.com/quizzes/1/questions dyno=web.1 queue=0 wait=0ms service=290ms status=200 bytes=81412
    2012-01-16T02:36:15+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=10ms status=401 bytes=27
    2012-01-16T02:36:16+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=67ms status=200 bytes=1
    2012-01-16T02:36:33+00:00 heroku[router]: POST prizequiz.herokuapp.com/quizzes/1/scores dyno=web.1 queue=0 wait=0ms service=10ms status=401 bytes=27
    2012-01-16T02:36:33+00:00 heroku[router]: POST prizequiz.herokuapp.com/quizzes/1/scores dyno=web.1 queue=0 wait=0ms service=132ms status=201 bytes=230
    2012-01-16T02:36:55+00:00 heroku[web.1]: Process running mem=522M(102.1%)
    2012-01-16T02:36:55+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-16T02:37:17+00:00 app[web.1]: 
    2012-01-16T02:37:17+00:00 app[web.1]: 
    2012-01-16T02:37:17+00:00 app[web.1]: Started POST "/quizzes/1/scores" for 177.53.80.25 at 2012-01-16 02:37:17 +0000
    2012-01-16T02:37:17+00:00 app[web.1]: cache: [POST /quizzes/1/scores] invalidate, pass
    2012-01-16T02:37:17+00:00 app[web.1]: 
    2012-01-16T02:37:17+00:00 app[web.1]: 
    2012-01-16T02:37:17+00:00 app[web.1]: Started POST "/quizzes/1/scores" for 177.53.80.25 at 2012-01-16 02:37:17 +0000
    2012-01-16T02:37:17+00:00 app[web.1]: cache: [POST /quizzes/1/scores] invalidate, pass
    2012-01-16T02:37:17+00:00 heroku[router]: POST prizequiz.herokuapp.com/quizzes/1/scores dyno=web.1 queue=0 wait=0ms service=44ms status=201 bytes=230
    2012-01-16T02:37:17+00:00 heroku[web.1]: Process running mem=522M(102.1%)
    2012-01-16T02:37:17+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-16T02:37:17+00:00 heroku[router]: POST prizequiz.herokuapp.com/quizzes/1/scores dyno=web.1 queue=0 wait=0ms service=16ms status=401 bytes=27
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: Started GET "/quizzes/1/scores/current_game" for 177.53.80.25 at 2012-01-16 02:37:20 +0000
    2012-01-16T02:37:20+00:00 app[web.1]: cache: [GET /quizzes/1/scores/current_game] miss
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: Started GET "/quizzes/1/scores/current_game" for 177.53.80.25 at 2012-01-16 02:37:20 +0000
    2012-01-16T02:37:20+00:00 heroku[router]: GET prizequiz.herokuapp.com/quizzes/1/scores/current_game dyno=web.1 queue=0 wait=0ms service=8ms status=401 bytes=27
    2012-01-16T02:37:20+00:00 app[web.1]: cache: [GET /quizzes/1/scores/current_game] miss
    2012-01-16T02:37:20+00:00 heroku[router]: GET prizequiz.herokuapp.com/quizzes/1/scores/current_game dyno=web.1 queue=0 wait=0ms service=6ms status=401 bytes=27
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: Started POST "/quizzes/1/scores" for 177.53.80.25 at 2012-01-16 02:37:20 +0000
    2012-01-16T02:37:20+00:00 heroku[router]: POST prizequiz.herokuapp.com/quizzes/1/scores dyno=web.1 queue=0 wait=0ms service=33ms status=401 bytes=27
    2012-01-16T02:37:20+00:00 app[web.1]: cache: [POST /quizzes/1/scores] invalidate, pass
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: Started GET "/quizzes/1/scores/current_game" for 177.53.80.25 at 2012-01-16 02:37:20 +0000
    2012-01-16T02:37:20+00:00 app[web.1]: 
    2012-01-16T02:37:20+00:00 app[web.1]: 
    

    I have New Relic installed but have been unable to identify anything of any use.

    Will gladly supply more info if needed. I also have an outstanding support request on Heroku for this but as yet (2 days marked as urgent) I have had no response.

    Adding web dynos makes no difference.

    UPDATE, I have added the oink gem and this is a sample result

    2012-01-26T08:24:25+00:00 app[web.1]: 
    2012-01-26T08:24:25+00:00 app[web.1]: 
    2012-01-26T08:24:25+00:00 app[web.1]: Started PUT "/mobile_users/1" for 110.49.234.219 at 2012-01-26 08:24:25 +0000
    2012-01-26T08:24:26+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:24:26+00:00 app[web.1]: Memory usage: 286276 | PID: 16
    2012-01-26T08:24:26+00:00 app[web.1]: Instantiation Breakdown: Total: 2 | MobileUser: 2
    2012-01-26T08:24:26+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:24:26+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:24:26+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=460ms status=200 bytes=1
    2012-01-26T08:24:38+00:00 heroku[web.1]: Process running mem=537M(104.9%)
    2012-01-26T08:24:38+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:24:43+00:00 app[web.1]: 
    2012-01-26T08:24:43+00:00 app[web.1]: 
    2012-01-26T08:24:43+00:00 app[web.1]: Started PUT "/mobile_users/1" for 103.1.165.23 at 2012-01-26 08:24:43 +0000
    2012-01-26T08:24:43+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=544ms status=401 bytes=27
    2012-01-26T08:24:43+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:24:43+00:00 app[web.1]: Memory usage: 288876 | PID: 19
    2012-01-26T08:24:43+00:00 app[web.1]: Instantiation Breakdown: Total: 0
    2012-01-26T08:24:43+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:24:43+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:24:47+00:00 app[web.1]: 
    2012-01-26T08:24:47+00:00 app[web.1]: 
    2012-01-26T08:24:47+00:00 app[web.1]: Started PUT "/mobile_users/1" for 103.1.165.23 at 2012-01-26 08:24:47 +0000
    2012-01-26T08:24:48+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:24:48+00:00 app[web.1]: Memory usage: 286412 | PID: 16
    2012-01-26T08:24:48+00:00 app[web.1]: Instantiation Breakdown: Total: 2 | MobileUser: 2
    2012-01-26T08:24:48+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:24:48+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=432ms status=200 bytes=1
    2012-01-26T08:24:48+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:24:59+00:00 heroku[web.1]: Process running mem=537M(104.9%)
    2012-01-26T08:24:59+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:25:20+00:00 heroku[web.1]: Process running mem=537M(104.9%)
    2012-01-26T08:25:20+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:25:41+00:00 heroku[web.1]: Process running mem=537M(104.9%)
    2012-01-26T08:25:41+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:26:32+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=34ms status=401 bytes=27
    2012-01-26T08:27:04+00:00 app[web.1]: 
    2012-01-26T08:27:04+00:00 app[web.1]: 
    2012-01-26T08:27:04+00:00 app[web.1]: Started PUT "/mobile_users/1" for 103.1.165.23 at 2012-01-26 08:27:04 +0000
    2012-01-26T08:27:04+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:27:04+00:00 app[web.1]: Memory usage: 288876 | PID: 19
    2012-01-26T08:27:04+00:00 app[web.1]: Instantiation Breakdown: Total: 2 | MobileUser: 2
    2012-01-26T08:27:04+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:27:04+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:27:04+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=337ms status=200 bytes=1
    2012-01-26T08:27:05+00:00 heroku[web.1]: Process running mem=537M(104.9%)
    2012-01-26T08:27:05+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:27:26+00:00 heroku[web.1]: Process running mem=537M(104.9%)
    2012-01-26T08:27:26+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:27:48+00:00 heroku[web.1]: Process running mem=537M(104.9%)
    2012-01-26T08:27:48+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:28:08+00:00 heroku[web.1]: Process running mem=537M(105.0%)
    2012-01-26T08:28:08+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:28:29+00:00 heroku[web.1]: Process running mem=537M(105.0%)
    2012-01-26T08:28:29+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:28:51+00:00 heroku[web.1]: Process running mem=537M(105.0%)
    2012-01-26T08:28:51+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:29:08+00:00 app[web.1]: 
    2012-01-26T08:29:08+00:00 app[web.1]: 
    2012-01-26T08:29:08+00:00 app[web.1]: Started PUT "/mobile_users/1" for 85.26.234.218 at 2012-01-26 08:29:08 +0000
    2012-01-26T08:29:08+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:29:08+00:00 app[web.1]: Memory usage: 382404 | PID: 13
    2012-01-26T08:29:08+00:00 app[web.1]: Instantiation Breakdown: Total: 0
    2012-01-26T08:29:08+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:29:08+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:29:08+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=86ms status=401 bytes=27
    2012-01-26T08:29:09+00:00 app[web.1]: 
    2012-01-26T08:29:09+00:00 app[web.1]: 
    2012-01-26T08:29:09+00:00 app[web.1]: Started PUT "/mobile_users/1" for 85.26.234.218 at 2012-01-26 08:29:09 +0000
    2012-01-26T08:29:09+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:29:09+00:00 app[web.1]: Memory usage: 382404 | PID: 13
    2012-01-26T08:29:09+00:00 app[web.1]: Instantiation Breakdown: Total: 2 | MobileUser: 2
    2012-01-26T08:29:09+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:29:09+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:29:09+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=160ms status=200 bytes=1
    2012-01-26T08:29:11+00:00 app[web.1]: 
    2012-01-26T08:29:11+00:00 app[web.1]: 
    2012-01-26T08:29:11+00:00 app[web.1]: Started PUT "/mobile_users/1" for 85.26.234.218 at 2012-01-26 08:29:11 +0000
    2012-01-26T08:29:11+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=101ms status=401 bytes=27
    2012-01-26T08:29:11+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:29:11+00:00 app[web.1]: Memory usage: 382404 | PID: 13
    2012-01-26T08:29:11+00:00 app[web.1]: Instantiation Breakdown: Total: 0
    2012-01-26T08:29:11+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:29:11+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:29:12+00:00 app[web.1]: 
    2012-01-26T08:29:12+00:00 app[web.1]: 
    2012-01-26T08:29:12+00:00 app[web.1]: Started PUT "/mobile_users/1" for 85.26.234.218 at 2012-01-26 08:29:12 +0000
    2012-01-26T08:29:12+00:00 heroku[web.1]: Process running mem=537M(105.0%)
    2012-01-26T08:29:12+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    2012-01-26T08:29:12+00:00 app[web.1]: Oink Action: mobile_users#update
    2012-01-26T08:29:12+00:00 app[web.1]: Memory usage: 288876 | PID: 19
    2012-01-26T08:29:12+00:00 app[web.1]: Instantiation Breakdown: Total: 2 | MobileUser: 2
    2012-01-26T08:29:12+00:00 app[web.1]: Oink Log Entry Complete
    2012-01-26T08:29:12+00:00 app[web.1]: cache: [PUT /mobile_users/1] invalidate, pass
    2012-01-26T08:29:12+00:00 heroku[router]: PUT prizequiz.herokuapp.com/mobile_users/1 dyno=web.1 queue=0 wait=0ms service=169ms status=200 bytes=1
    2012-01-26T08:29:33+00:00 heroku[web.1]: Process running mem=537M(105.0%)
    2012-01-26T08:29:33+00:00 heroku[web.1]: Error R14 (Memory quota exceeded)
    

    I have no idea what that proves other than it seems I am not using as much memory as Heroku thinks I am Memory usage: 288876 vs Process running mem=537M(105.0%)

    • Frederick Cheung
      Frederick Cheung over 12 years
      Does this happen on every request or only after a few requests (ie are you just using too much memory or are you leaking memory)?
    • jamesc
      jamesc over 12 years
      Judging by the log entries (Posted above) It does not appear to be every request
    • Frederick Cheung
      Frederick Cheung over 12 years
      Are you using any serialized attributes in frequently loaded models?
    • jamesc
      jamesc over 12 years
      Hhhmmm! Yes, I have serialized attributes in extremely frequently loaded models but I'm not actually referencing them at the moment. I am serialising the request object Could this be an issue?
    • Frederick Cheung
      Frederick Cheung over 12 years
      If you have a serialised attribute, then it will always be unserialized when the object is loaded There is a bug in currently available version of ruby 1.9.2 that means that YAML.load leaks memory if you are using the psych engine. Coincidentally I blogged about this a few days ago: spacevatican.org/2012/1/26/memory-leak-in-yaml-on-ruby-1-9-2
    • jamesc
      jamesc over 12 years
      I have removed all serialisation methods but no change. Thanks for the link and the info though, much appreciated and I learned something new.
    • John Hinnegan
      John Hinnegan about 12 years
      For anyone else finding this, the comment by @FrederickCheung should be taken witha grain of salt. The Psych engine of YAML leaks memory (or did at least). However, Heroku doesn't include Psych in their build of ruby, so you fall back to using Sych. I ran this down and confirmed with Heorku. And no, I still have not found the source of my memory leak.
  • jamesc
    jamesc over 12 years
    Thankyou, I will pull the db to my dev box and have a look at memprof. wouldn't reading all the data and processing in ruby add a huge processing overhead over SomeModel.where(:some_condition).includes(:children) requests (Which is about as heavy as my app gets from a data retrieval point of view) or have I misunderstood?
  • jamesc
    jamesc over 12 years
    Hmmm! memprof does not support Ruby 1.9x so that's not really an option, thanks for the tip though
  • rkb
    rkb over 12 years
    You could install 1.8.7 on your local machine (using rvm) just to test. Might be worthwhile, since your memory use will still probably be pathological even with a different interpreter. I'll edit my response--I did indeeed mean to say that using where would be better than doing select in Ruby.
  • Stephen Corwin
    Stephen Corwin over 11 years
    Can I ask what specifically this answered helped you solve? I'm having a very similar problem, and I don't have very many places in my app where I would expect find_in_batches to make any kind of a difference...
  • stupied4ever
    stupied4ever over 11 years
    In my case i had a: Texto.all.each do | texto | ...do_stuff... end this Texto.All was the problem cause i had many texts and select them all caused the Error R14 (Memory quota exceeded)
  • James Roscoe
    James Roscoe almost 11 years
    find_in_batches overrides any order you had intended to apply (uses order(:id) instead) so this won't work in cases where you want to iterate over your results in a particular order.
  • netwire
    netwire over 9 years
    Thanks Brian. This is very useful. It turns on Mongoid wrote: It is important to note that you should never be using the identity map when executing background jobs, rake tasks, etc. unless you really know that not many documents will be loaded and memory consumption will be low. Otherwise it's a server takedown waiting to happen. In these cases it's best to wrap your task or job in a unit of work. mongoid.org/en/mongoid/v3/identity_map.html
  • svelandiag
    svelandiag over 8 years
    Thanks, in my case I was using Unicorn, and yes disable sensible_defaults and set WEB_CONCURRENCY to 1 did the trick, thanks
  • Necromancer
    Necromancer over 3 years
    I don't run console like you. But somehow your command saved me, Thanks man. I still don't know why this command solve my memory problem. Could you please tell me what the meaning of run.6654?
  • Kumar
    Kumar over 2 years
    This looks like it fixed for us too. Thanks again.
  • Scott
    Scott almost 2 years
    This helped. My workers were running 2 intensive jobs at once that didn't need to, so by making this value 1, they run one after the other and don't hit the limit.