10

Our Rails 4.0 application (Ruby 2.1.2) is running on Nginx with Puma 2.9.0.

I recently noticed that all requests to our application hang after a while (usually 1 or 2 days).

When checking the log, which is set to debug mode, I noticed the following log stack up:

[2014-10-11T00:02:31.727382 #23458]  INFO -- : Started GET "/" for ...

It does mean that requests actually hit the Rails app but somehow it isn't proceeded, while normally it would be:

I, [2014-10-11T00:02:31.727382 #23458]  INFO -- : Started GET "/" for ....
I, [2014-10-11T00:02:31.729393 #23458]  INFO -- : Processing by HomeController#index as HTML

My puma config is the following:

threads 16,32
workers 4

Our application is only for internal usage as now, so the RPM is very low, and none of the requests are take longer than 2s.

What is/are the reasons that could lead to this problem? (puma config, database connection, etc.)

Thank you in advance.

Update: After installing the gem rack_timer to log the time spent on each middleware, I realized that our requests has been stuck at the ActiveRecord::QueryCache when the hang occurred, with huge amount of time on it:

Rack Timer (incoming) -- ActiveRecord::QueryCache: 925626.7731189728 ms

I removed this middleware for now and it seems to be back to normal. However, I understand the purpose of this middleware is to increase the performance, so removing it is just a temporary solution. Please help me find out the possible cause of this issue.

FYI, we're using mysql (5.1.67) with adapter mysql2 (0.3.13)

Anna S
  • 157
  • 1
  • 9
VinhBS
  • 677
  • 8
  • 17
  • 1
    Does your cache keys match up; because if not, then all you'll be doing is adding to the cache, which will hinder performance due to the size of the cache. – Bowersbros Oct 21 '14 at 10:27
  • Seeing a similar issue with Postgres/ Ruby 2.1.3/ Puma 2.8.2 – Ponny Dec 18 '14 at 23:23
  • similar issue, webrick/ruby 2.2.1/postgres. Any solutions? – radubogdan Aug 28 '15 at 10:41
  • 1
    Please read this thread https://github.com/puma/puma/issues/961 and http://stackoverflow.com/questions/36961700/puma-stops-running-for-rails-app-on-ec2-instance-with-nginx-using-capistrano-ca – Jagdish Sep 28 '16 at 19:06
  • @VinhBS Do you have some memory logs? (e.g. if you are on Heroku it would be easy to see). It's probably blocking because there is no more memory available and then it times out – Dorian Jan 31 '17 at 08:17
  • Are you really using MySQL 5.1? – Purefan Feb 09 '17 at 15:22
  • Can you guys try Phusion Passenger? I always has memory problem with Puma on Heroku. – Victor Castro Feb 13 '17 at 11:57

1 Answers1

1

It could be a symptom of RAM starvation due to the query cache getting too big. We saw this in one of our apps running on Heroku. The default query cache is set to 1000. Lowering the limit eased the RAM usage for us with no noticeable performance degradation:

database.yml:

default: &default
  adapter: postgresql
  pool: <%= ENV["DB_POOL"] || ENV['MAX_THREADS'] || 5 %>
  timeout: 5000
  port: 5432
  host: localhost
  statement_limit: <%= ENV["DB_STATEMENT_LIMIT"] || 200 %>

However searching for "activerecord querycache slow" returns other causes, such as perhaps outdated versions of Ruby or Puma or rack-timeout: https://stackoverflow.com/a/44158724/126636

Or maybe a too large value for read_timeout: https://stackoverflow.com/a/30526430/126636

jemminger
  • 5,133
  • 4
  • 26
  • 47