ruby-on-railspapercliprackspace-cloudfogexcon

When saving a file to RackSpace CloudFiles using Paperclip/Fog, a timeout occurs, when connecting to odd IP address


I have an app that stores images on RackSpace CloudFiles using Paperclip. It's been working fine, but recently it won't save files. The error that occurs is:

Excon::Errors::SocketError (Connection timed out - connect(2) for 94.236.107.224:443 (Errno::ETIMEDOUT)):

In excon/socket.rb I have added some debugging to see the content of @data at the point the request is made. This is:

{
  :chunk_size        => 1048576, 
  :ciphers           => "HIGH:!SSLv2:!aNULL:!eNULL:!3DES", 
  :connect_timeout   => 60, 
  :debug_request     => false, 
  :debug_response    => true, 
  :headers           => {"User-Agent" => "fog/1.22.0"}, 
  :idempotent        => false, 
  :instrumentor_name => "excon", 
  :middlewares       => [Excon::Middleware::ResponseParser, Excon::Middleware::Expects, Excon::Middleware::Idempotent, Excon::Middleware::Instrumentor, Excon::Middleware::Mock],
  :mock              => false,
  :nonblock          => true,
  :omit_default_port => false,
  :persistent        => false,
  :read_timeout      => 60,
  :retry_limit       => 4,
  :ssl_verify_peer   => true,
  :tcp_nodelay       => false,
  :uri_parser        => URI,
  :write_timeout     => 60,
  :host              => "lon.auth.api.rackspacecloud.com",
  :path              => "/v2.0",
  :port              => 443,
  :query             => nil,
  :scheme            => "https",
  :user              => nil,
  :password          => nil
}

The host is lon.auth.api.rackspacecloud.com, which resolves to 92.52.64.197 (on the server, as well as locally).

However the error is because the connection to 94.236.107.224 times out. A reverse lookup on that IP shows it is also associated with the auth hostname:

$ host 94.236.107.224
224.107.236.94.in-addr.arpa domain name pointer lon.auth.api.rackspacecloud.com.

I presume this IP is no longer in use for the auth service, but I can't see why it's being connected to at all.

So I need to know:

  1. Why is the bad IP being connected to, when it doesn't show up in the log?
  2. How do I fix this so that the correct server is used?

Here is the full error that occurs:

Completed 500 Internal Server Error in 15437.6ms

Excon::Errors::SocketError (Connection timed out - connect(2) for 94.236.107.224:443 (Errno::ETIMEDOUT)):
  excon (0.33.0) lib/excon/socket.rb:220:in `connect_nonblock'
  excon (0.33.0) lib/excon/socket.rb:220:in `rescue in block in connect'
  excon (0.33.0) lib/excon/socket.rb:189:in `block in connect'
  excon (0.33.0) lib/excon/socket.rb:185:in `each'
  excon (0.33.0) lib/excon/socket.rb:185:in `connect'
  excon (0.33.0) lib/excon/ssl_socket.rb:131:in `connect'
  excon (0.33.0) lib/excon/socket.rb:28:in `initialize'
  excon (0.33.0) lib/excon/ssl_socket.rb:9:in `initialize'
  excon (0.33.0) lib/excon/connection.rb:414:in `new'
  excon (0.33.0) lib/excon/connection.rb:414:in `socket'
  excon (0.33.0) lib/excon/connection.rb:126:in `request_call'
  excon (0.33.0) lib/excon/middlewares/mock.rb:42:in `request_call'
  excon (0.33.0) lib/excon/middlewares/instrumentor.rb:22:in `request_call'
  excon (0.33.0) lib/excon/middlewares/base.rb:15:in `request_call'
  excon (0.33.0) lib/excon/middlewares/base.rb:15:in `request_call'
  excon (0.33.0) lib/excon/middlewares/base.rb:15:in `request_call'
  excon (0.33.0) lib/excon/connection.rb:269:in `request'
  fog-core (1.22.0) lib/fog/core/connection.rb:56:in `request'
  fog (1.22.0) lib/fog/rackspace/service.rb:34:in `request_without_retry'
  fog (1.22.0) lib/fog/rackspace/requests/identity/create_token.rb:15:in `create_token'
  fog (1.22.0) lib/fog/rackspace/identity.rb:41:in `authenticate'
  fog (1.22.0) lib/fog/rackspace/identity.rb:79:in `initialize'
  fog-core (1.22.0) lib/fog/core/service.rb:115:in `new'
  fog-core (1.22.0) lib/fog/core/service.rb:115:in `new'
  fog (1.22.0) lib/fog/rackspace/service.rb:116:in `authenticate_v2'
  fog (1.22.0) lib/fog/rackspace/service.rb:30:in `authenticate'
  fog (1.22.0) lib/fog/rackspace/storage.rb:88:in `authenticate'
  fog (1.22.0) lib/fog/rackspace/storage.rb:419:in `initialize'
  fog-core (1.22.0) lib/fog/core/service.rb:115:in `new'
  fog-core (1.22.0) lib/fog/core/service.rb:115:in `new'
  fog-core (1.22.0) lib/fog/storage.rb:26:in `new'
  paperclip (3.4.2) lib/paperclip/storage/fog.rb:208:in `connection'
  paperclip (3.4.2) lib/paperclip/storage/fog.rb:218:in `directory'
  paperclip (3.4.2) lib/paperclip/storage/fog.rb:100:in `block in flush_writes'
  paperclip (3.4.2) lib/paperclip/storage/fog.rb:96:in `each'
  paperclip (3.4.2) lib/paperclip/storage/fog.rb:96:in `flush_writes'
  paperclip (3.4.2) lib/paperclip/attachment.rb:221:in `save'
  paperclip (3.4.2) lib/paperclip/instance_methods.rb:17:in `block in save_attached_files'
  paperclip (3.4.2) lib/paperclip/instance_methods.rb:10:in `block in each_attachment'
  paperclip (3.4.2) lib/paperclip/instance_methods.rb:9:in `each'
  paperclip (3.4.2) lib/paperclip/instance_methods.rb:9:in `each_attachment'
  paperclip (3.4.2) lib/paperclip/instance_methods.rb:16:in `save_attached_files'
  activesupport (3.2.17) lib/active_support/callbacks.rb:449:in `_run__806665839013247154__save__3701132647492051879__callbacks'
  activesupport (3.2.17) lib/active_support/callbacks.rb:405:in `__run_callback'
  activesupport (3.2.17) lib/active_support/callbacks.rb:385:in `_run_save_callbacks'
  activesupport (3.2.17) lib/active_support/callbacks.rb:81:in `run_callbacks'
  activerecord (3.2.17) lib/active_record/callbacks.rb:264:in `create_or_update'
  activerecord (3.2.17) lib/active_record/persistence.rb:84:in `save'
  activerecord (3.2.17) lib/active_record/validations.rb:50:in `save'
  activerecord (3.2.17) lib/active_record/attribute_methods/dirty.rb:22:in `save'
  activerecord (3.2.17) lib/active_record/transactions.rb:259:in `block (2 levels) in save'
  activerecord (3.2.17) lib/active_record/transactions.rb:313:in `block in with_transaction_returning_status'
  activerecord (3.2.17) lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
  activerecord (3.2.17) lib/active_record/transactions.rb:208:in `transaction'
  activerecord (3.2.17) lib/active_record/transactions.rb:311:in `with_transaction_returning_status'
  activerecord (3.2.17) lib/active_record/transactions.rb:259:in `block in save'
  activerecord (3.2.17) lib/active_record/transactions.rb:270:in `rollback_active_record_state!'
  activerecord (3.2.17) lib/active_record/transactions.rb:258:in `save'
  activeadmin (0.5.1) lib/active_admin/resource_controller/callbacks.rb:28:in `block in save_resource'
  activeadmin (0.5.1) lib/active_admin/callbacks.rb:78:in `run_save_callbacks'
  activeadmin (0.5.1) lib/active_admin/resource_controller/callbacks.rb:27:in `save_resource'
  activeadmin (0.5.1) lib/active_admin/resource_controller/callbacks.rb:22:in `block in create_resource'
  activeadmin (0.5.1) lib/active_admin/callbacks.rb:78:in `run_create_callbacks'
  activeadmin (0.5.1) lib/active_admin/resource_controller/callbacks.rb:21:in `create_resource'
  inherited_resources (1.4.1) lib/inherited_resources/actions.rb:33:in `create'
  activeadmin (0.5.1) lib/active_admin/resource_controller/actions.rb:48:in `create'
  actionpack (3.2.17) lib/action_controller/metal/implicit_render.rb:4:in `send_action'
  actionpack (3.2.17) lib/abstract_controller/base.rb:167:in `process_action'
  actionpack (3.2.17) lib/action_controller/metal/rendering.rb:10:in `process_action'
  actionpack (3.2.17) lib/abstract_controller/callbacks.rb:18:in `block in process_action'
  activesupport (3.2.17) lib/active_support/callbacks.rb:458:in `_run__2901337515923689909__process_action__4396305873998292606__callbacks'
  activesupport (3.2.17) lib/active_support/callbacks.rb:405:in `__run_callback'
  activesupport (3.2.17) lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
  activesupport (3.2.17) lib/active_support/callbacks.rb:81:in `run_callbacks'
  actionpack (3.2.17) lib/abstract_controller/callbacks.rb:17:in `process_action'
  actionpack (3.2.17) lib/action_controller/metal/rescue.rb:29:in `process_action'
  actionpack (3.2.17) lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
  activesupport (3.2.17) lib/active_support/notifications.rb:123:in `block in instrument'
  activesupport (3.2.17) lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  activesupport (3.2.17) lib/active_support/notifications.rb:123:in `instrument'
  actionpack (3.2.17) lib/action_controller/metal/instrumentation.rb:29:in `process_action'
  actionpack (3.2.17) lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
  activerecord (3.2.17) lib/active_record/railties/controller_runtime.rb:18:in `process_action'
  actionpack (3.2.17) lib/abstract_controller/base.rb:121:in `process'
  actionpack (3.2.17) lib/abstract_controller/rendering.rb:45:in `process'
  actionpack (3.2.17) lib/action_controller/metal.rb:203:in `dispatch'
  actionpack (3.2.17) lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
  actionpack (3.2.17) lib/action_controller/metal.rb:246:in `block in action'
  actionpack (3.2.17) lib/action_dispatch/routing/route_set.rb:73:in `call'
  actionpack (3.2.17) lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
  actionpack (3.2.17) lib/action_dispatch/routing/route_set.rb:36:in `call'
  journey (1.0.4) lib/journey/router.rb:68:in `block in call'
  journey (1.0.4) lib/journey/router.rb:56:in `each'
  journey (1.0.4) lib/journey/router.rb:56:in `call'
  actionpack (3.2.17) lib/action_dispatch/routing/route_set.rb:608:in `call'
  rack-google_analytics (1.0.2) lib/rack/google_analytics.rb:5:in `call'
  warden (1.2.3) lib/warden/manager.rb:35:in `block in call'
  warden (1.2.3) lib/warden/manager.rb:34:in `catch'
  warden (1.2.3) lib/warden/manager.rb:34:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
  rack (1.4.5) lib/rack/etag.rb:23:in `call'
  rack (1.4.5) lib/rack/conditionalget.rb:35:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/head.rb:14:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/params_parser.rb:21:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/flash.rb:242:in `call'
  rack (1.4.5) lib/rack/session/abstract/id.rb:210:in `context'
  rack (1.4.5) lib/rack/session/abstract/id.rb:205:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/cookies.rb:341:in `call'
  activerecord (3.2.17) lib/active_record/query_cache.rb:64:in `call'
  activerecord (3.2.17) lib/active_record/connection_adapters/abstract/connection_pool.rb:479:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
  activesupport (3.2.17) lib/active_support/callbacks.rb:405:in `_run__1208023080139519486__call__3701132647492051879__callbacks'
  activesupport (3.2.17) lib/active_support/callbacks.rb:405:in `__run_callback'
  activesupport (3.2.17) lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
  activesupport (3.2.17) lib/active_support/callbacks.rb:81:in `run_callbacks'
  actionpack (3.2.17) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
  railties (3.2.17) lib/rails/rack/logger.rb:32:in `call_app'
  railties (3.2.17) lib/rails/rack/logger.rb:16:in `block in call'
  activesupport (3.2.17) lib/active_support/tagged_logging.rb:22:in `tagged'
  railties (3.2.17) lib/rails/rack/logger.rb:16:in `call'
  actionpack (3.2.17) lib/action_dispatch/middleware/request_id.rb:22:in `call'
  rack (1.4.5) lib/rack/methodoverride.rb:21:in `call'
  rack (1.4.5) lib/rack/runtime.rb:17:in `call'
  activesupport (3.2.17) lib/active_support/cache/strategy/local_cache.rb:72:in `call'
  rack (1.4.5) lib/rack/lock.rb:15:in `call'
  rack-cache (1.2) lib/rack/cache/context.rb:136:in `forward'
  rack-cache (1.2) lib/rack/cache/context.rb:143:in `pass'
  rack-cache (1.2) lib/rack/cache/context.rb:155:in `invalidate'
  rack-cache (1.2) lib/rack/cache/context.rb:71:in `call!'
  rack-cache (1.2) lib/rack/cache/context.rb:51:in `call'
  railties (3.2.17) lib/rails/engine.rb:484:in `call'
  railties (3.2.17) lib/rails/application.rb:231:in `call'
  railties (3.2.17) lib/rails/railtie/configurable.rb:30:in `method_missing'
  /opt/chef/embedded/lib/ruby/gems/1.9.1/gems/passenger-4.0.35/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request'
  /opt/chef/embedded/lib/ruby/gems/1.9.1/gems/passenger-4.0.35/lib/phusion_passenger/request_handler/thread_handler.rb:142:in `accept_and_process_next_request'
  /opt/chef/embedded/lib/ruby/gems/1.9.1/gems/passenger-4.0.35/lib/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
  /opt/chef/embedded/lib/ruby/gems/1.9.1/gems/passenger-4.0.35/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads'

Solution

  • Thanks to @geemus, @Kyle-Rames, and @AshWilson for clues to the puzzle.

    RS support told me to change the auth server to lon.identity.api.rackspacecloud.com which I did but then saw the error:

    Unknown region :dfw for service cloudFiles. Please use one of the following regions: :lon
    

    Setting the region with rackspace_region: :lon in paperclip_defaults.rb sorted that, and got things working again.