Connections hang and time out when running in Celluloid::IO

[tetherit]

I started 2 processes, one just httprb running in a loop:

$ bundle exec rails c production
> loop { TIME { puts HTTP.post('http://127.0.0.1:3001/api/v2/cameras/update', json: {:token=>"test", :id=>"test", :camera=>{:analytics_state=>:ok}}) }; sleep 0.1 }
{"status":"ok"}
  0.000000   0.010000   0.010000 (  0.028937)
{"status":"ok"}
  0.010000   0.000000   0.010000 (  0.011525)
{"status":"ok"}
  0.000000   0.000000   0.000000 (  0.011964)
{"status":"ok"}
...

The other is running inside of eye (which uses celluoid internally). Both processes run identical code, except the latter logs any exception:

  begin
    Http.post(url, json: params)
  rescue => exception
    logger.error "Could not update camera stream state value #{url} #{params}"
    logger.error exception.backtrace
  end

Despite running virtually the same code, the code that runs inside of celluloid is timing out and throwing an exception:

[2017-02-15 23:33:16 +0000] Could not update camera stream state value http://127.0.0.1:3001/api/v2/cameras/update {:token=>"test", :id=>"test", :camera=>{:recording_state=>:ok}}
[2017-02-15 23:33:16 +0000] ["/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/timeout/global.rb:107:in `wait_readable'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/timeout/global.rb:107:in `wait_readable_or_timeout'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/timeout/global.rb:90:in `block in perform_io'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/timeout/global.rb:85:in `loop'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/timeout/global.rb:85:in `perform_io'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/timeout/global.rb:51:in `readpartial'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/connection.rb:212:in `read_more'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/connection.rb:99:in `block in read_headers!'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/connection.rb:98:in `loop'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/connection.rb:98:in `read_headers!'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/client.rb:64:in `perform'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/client.rb:41:in `request'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/http-2.2.1/lib/http/chainable.rb:26:in `post'", "/data/deployer/timeagent/eye/rtsp_checker.rb:21:in `update_camera_stream_status'", "/data/deployer/timeagent/eye/rtsp_checker.rb:64:in `camera_rtsp_stream_working?'", "/data/deployer/timeagent/eye/rtsp_checker.rb:96:in `camera_stream_working?'", "/data/deployer/timeagent/eye/rtsp_checker.rb:120:in `camera_working?'", "/data/deployer/timeagent/eye/helpers.rb:148:in `block (2 levels) in proxy_rtsp'", "/data/deployer/timeagent/vendor/cache/eye-51cdc5f92297/lib/eye/trigger.rb:103:in `instance_exec'", "/data/deployer/timeagent/vendor/cache/eye-51cdc5f92297/lib/eye/trigger.rb:103:in `exec_proc'", "/data/deployer/timeagent/vendor/cache/eye-51cdc5f92297/lib/eye/trigger/starting_guard.rb:28:in `block in check_start'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/celluloid-0.17.3/lib/celluloid/calls.rb:28:in `public_send'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/celluloid-0.17.3/lib/celluloid/calls.rb:28:in `dispatch'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/celluloid-0.17.3/lib/celluloid/call/sync.rb:16:in `dispatch'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/celluloid-0.17.3/lib/celluloid/future.rb:18:in `block in new'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/celluloid-essentials-0.20.5/lib/celluloid/internals/thread_handle.rb:14:in `block in initialize'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/celluloid-0.17.3/lib/celluloid/actor/system.rb:78:in `block in get_thread'", "/data/deployer/timeagent/vendor/bundle/ruby/2.3.0/gems/celluloid-0.17.3/lib/celluloid/group/spawner.rb:50:in `block in instantiate'"]

Any ideas why this is happening? -- More details here: kostya/eye#189

[tarcieri]

Closing as this is more or less a dup of #272

Celluloid::IO is unsupported in recent versions of http.rb due to timeouts, which is probably what you're hitting here.

I've been working on an underlying socket layer abstract enough to accommodate both models while still providing robust timeout support:

https://github.com/socketry/socketry/

There is a WIP PR to convert http.rb to use this library: #377 but it is out of date and needs more work.

[tetherit]

The timeout issue is also preventing requests from being made altogether?

The request takes 0.1 seconds to complete so it shouldn't be timing out but with httprb it is just hanging for 30 seconds before finally dying. This also seems to be intermittent, hmm. Is there any simple workaround to make the request complete?

[tarcieri]

Timeout support is completely broken for Celluloid::IO right now

[tetherit]

Lack of Timeout support is preventing from making requests altogether?

I've switched to Net::HTTP for now with celluloid, but really love http.rb for non celluloid applications :)

[tarcieri]

Yes, timeouts are instrumental to the way the current I/O layer functions