PG::UnableToSend, Connection timed out

Issue #170 resolved
Former user created an issue

Using Ruby 2.0.0-p247, Rails 4.0.0 and pg 0.16.0 connecting to an off-host Postgres 9.2 server, any request to my production environment after a long pause results in something like the following:

A PG::UnableToSend occurred in pages#index:

could not send data to server: Connection timed out

Before I do the obvious and set the timeout variable to something higher, is there some other way you would recommend avoiding this error?

Comments (9)

  1. Lars Kanis

    Not offhandedly. If I understand correctly, the db connection first works and breaks after a longer idle time? You could also play with keepalives parameters in the database.yml. Could you also post the stack trace (the framework part)?

  2. johnmichaelbradley

    Sorry for posting anonymously. When it happens again I will post a stack trace. Also, if I restart Postgres I receive the following error:

    PG::AdminShutdown: FATAL: terminating connection due to administrator command SSL connection has been closed unexpectedly (followed by a SQL statement)

    I can't seem to find where I can rescue from this. Here is the stack trace:

    activerecord (4.0.0) lib/active_record/connection_adapters/postgresql_adapter.rb:768:in exec' activerecord (4.0.0) lib/active_record/connection_adapters/postgresql_adapter.rb:768:inexec_no_cache' activerecord (4.0.0) lib/active_record/connection_adapters/postgresql/database_statements.rb:138:in block in exec_query' activerecord (4.0.0) lib/active_record/connection_adapters/abstract_adapter.rb:425:inblock in log' activesupport (4.0.0) lib/active_support/notifications/instrumenter.rb:20:in instrument' activerecord (4.0.0) lib/active_record/connection_adapters/abstract_adapter.rb:420:inlog' activerecord (4.0.0) lib/active_record/connection_adapters/postgresql/database_statements.rb:137:in exec_query' activerecord (4.0.0) lib/active_record/connection_adapters/postgresql_adapter.rb:885:inselect' activerecord (4.0.0) lib/active_record/connection_adapters/abstract/database_statements.rb:24:in select_all' activerecord (4.0.0) lib/active_record/connection_adapters/abstract/query_cache.rb:61:inblock in select_all' activerecord (4.0.0) lib/active_record/connection_adapters/abstract/query_cache.rb:76:in cache_sql' activerecord (4.0.0) lib/active_record/connection_adapters/abstract/query_cache.rb:61:inselect_all' activerecord (4.0.0) lib/active_record/querying.rb:36:in find_by_sql' activerecord (4.0.0) lib/active_record/relation.rb:585:inexec_queries' activerecord (4.0.0) lib/active_record/relation.rb:471:in load' activerecord (4.0.0) lib/active_record/relation.rb:220:into_a' activerecord (4.0.0) lib/active_record/relation.rb:598:in exec_queries' activerecord (4.0.0) lib/active_record/relation.rb:471:inload' activerecord (4.0.0) lib/active_record/relation.rb:220:in to_a' activerecord (4.0.0) lib/active_record/relation/finder_methods.rb:325:infind_first' activerecord (4.0.0) lib/active_record/relation/finder_methods.rb:90:in first' activerecord-deprecated_finders (1.0.3) lib/active_record/deprecated_finders/relation.rb:129:infirst' orm_adapter (0.4.0) lib/orm_adapter/adapters/active_record.rb:17:in get' devise (3.0.0) lib/devise/models/authenticatable.rb:208:inserialize_from_session' devise (3.0.0) lib/devise.rb:439:in block (2 levels) in configure_warden!' warden (1.2.3) lib/warden/session_serializer.rb:34:infetch' warden (1.2.3) lib/warden/proxy.rb:212:in user' warden (1.2.3) lib/warden/proxy.rb:318:in_perform_authentication' warden (1.2.3) lib/warden/proxy.rb:127:in authenticate!' devise (3.0.0) lib/devise/rails/routes.rb:425:inblock in constraints_for' actionpack (4.0.0) lib/action_dispatch/routing/mapper.rb:37:in call' actionpack (4.0.0) lib/action_dispatch/routing/mapper.rb:37:inblock in matches?' actionpack (4.0.0) lib/action_dispatch/routing/mapper.rb:35:in each' actionpack (4.0.0) lib/action_dispatch/routing/mapper.rb:35:inall?' actionpack (4.0.0) lib/action_dispatch/routing/mapper.rb:35:in matches?' actionpack (4.0.0) lib/action_dispatch/routing/mapper.rb:44:incall' actionpack (4.0.0) lib/action_dispatch/journey/router.rb:71:in block in call' actionpack (4.0.0) lib/action_dispatch/journey/router.rb:59:ineach' actionpack (4.0.0) lib/action_dispatch/journey/router.rb:59:in call' actionpack (4.0.0) lib/action_dispatch/routing/route_set.rb:655:incall' railties (4.0.0) lib/rails/engine.rb:511:in call' railties (4.0.0) lib/rails/railtie/configurable.rb:30:inmethod_missing' actionpack (4.0.0) lib/action_dispatch/journey/router.rb:71:in block in call' actionpack (4.0.0) lib/action_dispatch/journey/router.rb:59:ineach' actionpack (4.0.0) lib/action_dispatch/journey/router.rb:59:in call' actionpack (4.0.0) lib/action_dispatch/routing/route_set.rb:655:incall' exception_notification (4.0.0) lib/exception_notification/rack.rb:28:in call' warden (1.2.3) lib/warden/manager.rb:35:inblock in call' warden (1.2.3) lib/warden/manager.rb:34:in catch' warden (1.2.3) lib/warden/manager.rb:34:incall' rack (1.5.2) lib/rack/etag.rb:23:in call' rack (1.5.2) lib/rack/conditionalget.rb:25:incall' rack (1.5.2) lib/rack/head.rb:11:in call' actionpack (4.0.0) lib/action_dispatch/middleware/params_parser.rb:27:incall' actionpack (4.0.0) lib/action_dispatch/middleware/flash.rb:241:in call' rack (1.5.2) lib/rack/session/abstract/id.rb:225:incontext' rack (1.5.2) lib/rack/session/abstract/id.rb:220:in call' actionpack (4.0.0) lib/action_dispatch/middleware/cookies.rb:486:incall' activerecord (4.0.0) lib/active_record/query_cache.rb:36:in call' activerecord (4.0.0) lib/active_record/connection_adapters/abstract/connection_pool.rb:626:incall' activerecord (4.0.0) lib/active_record/migration.rb:369:in call' actionpack (4.0.0) lib/action_dispatch/middleware/callbacks.rb:29:inblock in call' activesupport (4.0.0) lib/active_support/callbacks.rb:373:in _run__2022500092884512127__call__callbacks' activesupport (4.0.0) lib/active_support/callbacks.rb:80:inrun_callbacks' actionpack (4.0.0) lib/action_dispatch/middleware/callbacks.rb:27:in call' actionpack (4.0.0) lib/action_dispatch/middleware/reloader.rb:64:incall' actionpack (4.0.0) lib/action_dispatch/middleware/remote_ip.rb:76:in call' actionpack (4.0.0) lib/action_dispatch/middleware/debug_exceptions.rb:17:incall' actionpack (4.0.0) lib/action_dispatch/middleware/show_exceptions.rb:30:in call' railties (4.0.0) lib/rails/rack/logger.rb:38:incall_app' railties (4.0.0) lib/rails/rack/logger.rb:21:in block in call' activesupport (4.0.0) lib/active_support/tagged_logging.rb:67:inblock in tagged' activesupport (4.0.0) lib/active_support/tagged_logging.rb:25:in tagged' activesupport (4.0.0) lib/active_support/tagged_logging.rb:67:intagged' railties (4.0.0) lib/rails/rack/logger.rb:21:in call' actionpack (4.0.0) lib/action_dispatch/middleware/request_id.rb:21:incall' rack (1.5.2) lib/rack/methodoverride.rb:21:in call' rack (1.5.2) lib/rack/runtime.rb:17:incall' rack (1.5.2) lib/rack/lock.rb:17:in call' actionpack (4.0.0) lib/action_dispatch/middleware/static.rb:64:incall' actionpack (4.0.0) lib/action_dispatch/middleware/ssl.rb:24:in call' railties (4.0.0) lib/rails/engine.rb:511:incall' railties (4.0.0) lib/rails/application.rb:97:in call' railties (4.0.0) lib/rails/railtie/configurable.rb:30:inmethod_missing' passenger (4.0.10) lib/phusion_passenger/rack/thread_handler_extension.rb:77:in process_request' passenger (4.0.10) lib/phusion_passenger/request_handler/thread_handler.rb:140:inaccept_and_process_next_request' passenger (4.0.10) lib/phusion_passenger/request_handler/thread_handler.rb:108:in main_loop' passenger (4.0.10) lib/phusion_passenger/request_handler.rb:441:inblock (3 levels) in start_threads'

  3. Tilmann Singer

    Try setting keepalives as I just posted on the google group to avoid the problem.

    However, it seems you are not running into an infinitely hanging process after a timeout, but just into a 'normal' immediate exception being thrown. I thought that rails is supposed to recover from that by catching the exception and manually trying to reconnect, but when I researched it I got lost in various discussions around that issue. I'm not sure what the current state in rails is, it might be that it is intended but broken.

    Also note that the exception was masked before 0.16 - I saw "PG::Error result has been cleared" or something like that, and after upgrading to 0.16 PG::UnableToSend.

    The mysql2 adapter allows to set a 'reconnect: true' config parameter.

  4. Tilmann Singer

    (I'm only mentioning the mysql2 parameter for reference, not meaning to say ruby-pg should have it too. As someone else posted, I think on the ruby-pg mailing list, the driver is not the right place for an automatic reconnect because of potential session state that needs to be restored. It should be in the app, e.g. in rails)

  5. Log in to comment