dimanche 15 octobre 2017

Connection timeout for SOCKSProxy Calls in resque Rails production mode

i have simple background job that runs using resque-pool which makes certain socksproxy call. This works fine when i start the resque-pool in Rails development mode as soon as i change to production mode i hit connection timeout with background job

The same code works when executed in

  • Rails Console in Production mode
  • Standalone ruby script invoked from command line

calls are something like:

req = Net::HTTP::Get.new(uri.request_uri)
response = Net::HTTP.SOCKSProxy(@socks_server, @socks_port).start(uri.host, uri.port) do |http|
    http.request(req)
end

Investigation:

when this call happens in net/http.rb

TCPSocket.open(conn_address, conn_port, @local_host, @local_port)

i found that in production mode worker child process instead of loading TCPSocket class from socksify-1.7.0/lib/socksify.rb it is still loading from ruby provided resolv-replace.rb. Not sure why though.

Error i see:

Connection timed out - connect(2) for "" port 6455: /usr/lib/ruby/gems/2.1.0/gems/socksify-1.7.0/lib/socksify.rb:178:in initialize' /usr/lib/ruby/gems/2.1.0/gems/socksify-1.7.0/lib/socksify.rb:178:in initialize' /usr/lib/ruby/2.1.0/resolv-replace.rb:23:in initialize' /usr/lib/ruby/2.1.0/net/http.rb:879:inopen' /usr/lib/ruby/2.1.0/net/http.rb:879:in block in connect' /usr/lib/ruby/2.1.0/timeout.rb:76:intimeout' /usr/lib/ruby/2.1.0/net/http.rb:878:in connect' /usr/lib/ruby/2.1.0/net/http.rb:863:indo_start' /usr/lib/ruby/2.1.0/net/http.rb:852:in start' /usr/lib/ruby/2.1.0/net/http.rb:583:instart' /usr/lib/ruby/gems/2.1.0/gems/retries-0.0.5/lib/retries.rb:46:in call' /usr/lib/ruby/gems/2.1.0/gems/retries-0.0.5/lib/retries.rb:46:in with_retries' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/job.rb:177:in block (3 levels) in perform' /usr/lib/ruby/gems/2.1.0/gems/newrelic_rpm-3.16.2.321/lib/new_relic/agent/instrumentation/resque.rb:41:in block in around_perform_with_monitoring' /usr/lib/ruby/gems/2.1.0/gems/newrelic_rpm-3.16.2.321/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:363:in `perform_action_with_newrelic_trace'

/usr/lib/ruby/gems/2.1.0/gems/newrelic_rpm-3.16.2.321/lib/new_relic/agent/instrumentation/resque.rb:33:in around_perform_with_monitoring' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/job.rb:176:in block (2 levels) in perform' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/job.rb:172:in call' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/job.rb:172:in block (3 levels) in perform' ../app/jobs/resque_hooks.rb:15:in around_perform_job_duration' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/job.rb:172:in block (2 levels) in perform' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/job.rb:184:in call' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/job.rb:184:in perform' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/worker.rb:290:in perform' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/worker.rb:229:in block in work' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/worker.rb:206:in loop' /usr/lib/ruby/gems/2.1.0/gems/resque-1.26.0/lib/resque/worker.rb:206:in work' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:396:in block in spawn_worker!' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:389:in fork' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:389:in spawn_worker!' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:367:in block in spawn_missing_workers_for' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:366:in times' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:366:in spawn_missing_workers_for' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:352:in block in maintain_worker_count' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:350:in each' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:350:in maintain_worker_count' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:263:in start' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool.rb:89:in run' /usr/lib/ruby/gems/2.1.0/gems/resque-pool-0.6.0/lib/resque/pool/tasks.rb:17:in block (2 levels) in ' /usr/lib/ruby/gems/2.1.0/gems/rake-11.2.2/lib/rake/task.rb:248:in call' /usr/lib/ruby/gems/2.1.0/gems/rake-11.2.2/lib/rake/task.rb:248:in block in execute' /usr/lib/ruby/gems/2.1.0/gems/rake-11.2.2/lib/rake/task.rb:243:in each' /usr/lib/ruby/gems/2.1.0/gems/rake-11.2.2/lib/rake/task.rb:243:in execute' /usr/lib/ruby/gems/2.1.0/gems/airbrake-5.5.0/lib/airbrake/rake/task_ext.rb:19:in execute' /usr/lib/ruby/gems/2.1.0/gems/rake-11.2.2/lib/rake/task.rb:187:in block in invoke_with_call_chain' /usr/lib/ruby/2.1.0/monitor.rb:211:in mon_synchronize' /usr/lib/ruby/gems/2.1.0/gems/rake-11.2.2/lib/rake/task.rb:180:in invoke_with_call_chain

Aucun commentaire:

Enregistrer un commentaire