4

I have a Rails application of moderate complexity running under Apache/Passenger which becomes unresponsive after periods of idleness. It takes several minutes to respond, but can be temporarily revived with a web server restart.

Server load is negligible, and since it's an internal application, there are rarely more than a few concurrent users.

I've tried nginx too, so it's not Apache causing the problem.

There isn't anything useful in the Apache or Rails logs. As per Passenger docs, I sent a SIGABRT and have a stacktrace (below). Its database isn't heavily loaded, and I've tried disabling any background processing which could be causing locks.

SignalException (SIGABRT):
  passenger (3.0.17) lib/phusion_passenger/abstract_request_handler.rb:443:in `block in install_useful_signal_handlers'
  activerecord (3.2.8) lib/active_record/connection_adapters/mysql2_adapter.rb:73:in `call'
  activerecord (3.2.8) lib/active_record/connection_adapters/mysql2_adapter.rb:73:in `ping'
  activerecord (3.2.8) lib/active_record/connection_adapters/mysql2_adapter.rb:73:in `active?'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract_adapter.rb:219:in `verify!'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:327:in `block in checkout_and_verify'
  activesupport (3.2.8) lib/active_support/callbacks.rb:403:in `_run__352340970312725798__checkout__1600727162984137669__callbacks'
  activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
  activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_checkout_callbacks'
  activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:326:in `checkout_and_verify'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:247:in `block (2 levels) in checkout'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:236:in `loop'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:236:in `block in checkout'
  /home/uuuuu/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:233:in `checkout'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:96:in `block in connection'
  /home/uuuuu/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:95:in `connection'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:404:in `retrieve_connection'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_specification.rb:170:in `retrieve_connection'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_specification.rb:144:in `connection'
  activerecord (3.2.8) lib/active_record/query_cache.rb:61:in `call'
  activerecord (3.2.8) lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
  activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `_run__1086758471249540907__call__1600727162984137669__callbacks'
  activesupport (3.2.8) lib/active_support/callbacks.rb:405:in `__run_callback'
  activesupport (3.2.8) lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
  activesupport (3.2.8) lib/active_support/callbacks.rb:81:in `run_callbacks'
  actionpack (3.2.8) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
  railties (3.2.8) lib/rails/rack/logger.rb:26:in `call_app'
  railties (3.2.8) lib/rails/rack/logger.rb:16:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/request_id.rb:22:in `call'
  rack (1.4.1) lib/rack/methodoverride.rb:21:in `call'
  rack (1.4.1) lib/rack/runtime.rb:17:in `call'
  activesupport (3.2.8) lib/active_support/cache/strategy/local_cache.rb:72:in `call'
  rack (1.4.1) lib/rack/lock.rb:15:in `call'
  actionpack (3.2.8) lib/action_dispatch/middleware/static.rb:62:in `call'
  rack-cache (1.2) lib/rack/cache/context.rb:136:in `forward'
  rack-cache (1.2) lib/rack/cache/context.rb:245:in `fetch'
  rack-cache (1.2) lib/rack/cache/context.rb:185:in `lookup'
  rack-cache (1.2) lib/rack/cache/context.rb:66:in `call!'
  rack-cache (1.2) lib/rack/cache/context.rb:51:in `call'
  railties (3.2.8) lib/rails/engine.rb:479:in `call'
  railties (3.2.8) lib/rails/application.rb:223:in `call'
  railties (3.2.8) lib/rails/railtie/configurable.rb:30:in `method_missing'
  rack-pjax (0.6.0) lib/rack/pjax.rb:12:in `call'
  passenger (3.0.17) lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'
  passenger (3.0.17) lib/phusion_passenger/abstract_request_handler.rb:516:in `accept_and_process_next_request'
  passenger (3.0.17) lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'
  passenger (3.0.17) lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'
  passenger (3.0.17) lib/phusion_passenger/rack/application_spawner.rb:171:in `block in handle_spawn_application'
  passenger (3.0.17) lib/phusion_passenger/utils.rb:470:in `safe_fork'
  passenger (3.0.17) lib/phusion_passenger/rack/application_spawner.rb:166:in `handle_spawn_application'
  passenger (3.0.17) lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  passenger (3.0.17) lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  passenger (3.0.17) lib/phusion_passenger/abstract_server.rb:180:in `start'
  passenger (3.0.17) lib/phusion_passenger/rack/application_spawner.rb:129:in `start'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:253:in `block (2 levels) in spawn_rack_application'
  passenger (3.0.17) lib/phusion_passenger/abstract_server_collection.rb:132:in `lookup_or_add'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:246:in `block in spawn_rack_application'
  passenger (3.0.17) lib/phusion_passenger/abstract_server_collection.rb:82:in `block in synchronize'
  :10:in `synchronize'
  passenger (3.0.17) lib/phusion_passenger/abstract_server_collection.rb:79:in `synchronize'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:244:in `spawn_rack_application'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'
  passenger (3.0.17) lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'
  passenger (3.0.17) lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  passenger (3.0.17) lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  passenger (3.0.17) helper-scripts/passenger-spawn-server:99:in `'

database.yml:

production:
  adapter: mysql2
  encoding: utf8
  database: [db]
  host: [host]
  pool: 5
  username: [user]
  password: [pass]
  timeout: 2000

I'm running Ubuntu 12.04.1 LTS, Ruby 1.9.3p194 via RVM, and Passenger 3.0.18.

I've never experienced this issue in development mode under WEBrick.

Tim
  • 49
  • 1
  • 3
  • Is the connection to the database still active when the system hangs? You've got a timeout value of 2000; if the db server decides to drop the connection, it may take until the timeout value before the application notices it. – Jenny D Nov 09 '12 at 12:29
  • Yes, when the app isn't responding there is an open connection to the database. It's usually been sleeping for several minutes, though. – Tim Nov 11 '12 at 11:36
  • I'm having this same issue (on OS X Lion Server) and am curious as to what you have tried so far. Have you tried running older versions of Passenger? Also since info on this issue is scarce, have you tried putting in a ticket with the Phusion developers? While this is getting sorted out, I thought about trying POW on my tiny prod site, even though it's geared for dev use. – alkalinecoffee Nov 14 '12 at 14:22
  • It's been a couple of months. Is this still an open issue for you? – Mark Stosberg Jan 21 '13 at 18:19
  • 1
    I think I exhausted just about everything I could think of except firewall session timeouts. There are a couple of security appliances between the application server and its database, so I began to suspect that idleness of the application could be allowing the MySQL connection to be timed out by the firewall(s). I've been testing my theory by running the same application on AWS Elastic Beanstalk. Whilst I can't guarantee I was right, I've not seen the issue recur in many weeks of testing. – Tim Mar 26 '13 at 20:23

2 Answers2

1

I'm facing the same issue with ruby 2.0.0-p0.

../bundle/ruby/2.0.0/gems/activerecord-3.2.13/lib/active_record/connection_adapters/mysql2_adapter.rb:73:in `ping'

I have tried with unicorn, thin and passenger. This doesn't change anything.

production:
  adapter: mysql2
  database: ***
  username: ***
  password: ***
  host: an IP
  reconnect: true
  wait_timeout: 3 # I've tried with this option and without

Any ideas ?

libmysqlclient 5.1.66-0+squeeze1
mysql-server 5.1.66-0+squeeze1

EDIT

It seems to be a firewall issue with TCP Keepalive. If the TCP Keepalive of the MySQL client is greater than the keepalive of the firewall, the issue can appear.

Details : http://tldp.org/HOWTO/html_single/TCP-Keepalive-HOWTO/

Guillaume Rose
  • 149
  • 1
  • 7
1

I'm using Google Compute Engine and hit exactly this same issue consistently—after about 10 minutes of idleness, requests to my Rails app would completely hang with no obvious logs or indication of what the problem was.

After much debugging and tracing, it turned out to be firewall timeouts—TCP connections from GCE instances are automatically timed out after 10 minutes idle. I successfully fixed this by configuring TCP keepalive to send its first probe at 60 seconds idle (rather than the default 2 hours) so that the long-lived TCP connections to the database stay active. This is also mentioned here: https://cloud.google.com/sql/docs/gce-access

# Set tcp_keepalive_time to 60 seconds and make it permanent across reboots.
$ echo 'net.ipv4.tcp_keepalive_time = 60' | sudo tee -a /etc/sysctl.conf
fotinakis
  • 111
  • 3