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

StackOverflow https://stackoverflow.com/questions/23184560

Question

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'
Was it helpful?

Solution 2

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.

OTHER TIPS

I was able to successfully authenticate against lon.auth.api.rackspacecloud.com. My guess is that there might be something wrong with the DNS configuration. Let me track someone down to investigate this issue for you.

Kyle

I'm not certain about the specifics on the Rackspace side of things that would result in this. Within excon the resolution to ip happens within Excon::Socket#connect. Not sure how much you know about the nitty-gritty of these things, but thought I would at least point you in that direction in case it might help: https://github.com/geemus/excon/blob/master/lib/excon/socket.rb#L167

That just stays at the socket level at least at presently (we just look this up once at socket connect, and don't propagate it to the data hash). You shouldn't need to override this though (at least in my experience the default behavior is the right one). I'd probably just recommend filing the issue on github against fog at this point (https://github.com/fog/fog/issues/new) so that I can point Rackspace folks at it.

Licensed under: CC-BY-SA with attribution
Not affiliated with StackOverflow
scroll top