future/async doesn't seem to be async

[fkchang]

Hi. I'm not sure if I'm using this right, but shouldn't these be handled asyncrhonously?

require 'angelo'

class HelloApp < Angelo::Base

  task :do_stuff do
    time_of_request = Time.now
    Kernel.sleep 10
    time_after = Time.now
    "Hello to you, too. #{time_of_request}- #{time_after}"
  end

  get "/" do
    puts "processing"
    f = future :do_stuff
    f.value
  end
end

HelloApp.run!

When I hit it, they are usually serviced 10 sec apart. Occasionally one gets serviced w/in 3 sec.

Perhaps I did not use future correctly? Thank you

[kenichi]

hi @fkchang. thanks for using angelo! i think the main problem here is using Kernel.sleep instead of Celluloid.sleep. i was able to do this by just removing the Kernel. part but you may want to be more specific.

if you try that, it should work the way you expect. lemme know how it works out for you.

[fkchang]

Hi @kenichi Thanks for the quick response. I switched to Celluloid.sleep and I get the same behavior, i.e, after doing 4 requests back to back, watching the output of the angelo program, I see "processing" show up not immediately after 4 times, but about 10 seconds apart, except for the last one. The sleep is to simulate the actual function which is a socket based exchange that could take up to 10 sec, to see whether angelo can meet my response needs. Am I expecting the wrong behavior?

[kenichi]

@fkchang interesting. i used your example with the latest code on master, and i only removed the Kernel. bit from the sleep line. In another IRB session, i did:

> Array.new(5).map { Thread.new { system('curl http://127.0.0.1:4567') } }.each &:join
Hello to you, too. 2017-02-14 11:42:42 -0800- 2017-02-14 11:42:52 -0800
Hello to you, too. 2017-02-14 11:42:42 -0800- 2017-02-14 11:42:52 -0800
Hello to you, too. 2017-02-14 11:42:42 -0800- 2017-02-14 11:42:52 -0800
Hello to you, too. 2017-02-14 11:42:42 -0800- 2017-02-14 11:42:52 -0800
Hello to you, too. 2017-02-14 11:42:42 -0800- 2017-02-14 11:42:52 -0800
=> [#<Thread:0x007fec78255ca8@(irb):3 dead>, #<Thread:0x007fec78255898@(irb):3 dead>, #<Thread:0x007fec78254d80@(irb):3 dead>, #<Thread:0x007fec78254b78@(irb):3 dead>, #<Thread:0x007fec782549c0@(irb):3 dead>]

> Array.new(5).map { Thread.new { system('curl http://127.0.0.1:4567') } }.each &:join
Hello to you, too. 2017-02-14 11:42:59 -0800- 2017-02-14 11:43:09 -0800
Hello to you, too. 2017-02-14 11:42:59 -0800- 2017-02-14 11:43:09 -0800
Hello to you, too. 2017-02-14 11:42:59 -0800- 2017-02-14 11:43:09 -0800
Hello to you, too. 2017-02-14 11:42:59 -0800- 2017-02-14 11:43:09 -0800
Hello to you, too. 2017-02-14 11:42:59 -0800- 2017-02-14 11:43:09 -0800
=> [#<Thread:0x007fec781350a8@(irb):4 dead>, #<Thread:0x007fec78134f68@(irb):4 dead>, #<Thread:0x007fec78134e50@(irb):4 dead>, #<Thread:0x007fec78134978@(irb):4 dead>, #<Thread:0x007fec78134860@(irb):4 dead>]

as you can see, i did it twice, for a total of ten requests. each time, all 5 returned after 10 seconds:

I, [2017-02-14T11:42:40.788832 #21212]  INFO -- : Angelo 0.5.1
I, [2017-02-14T11:42:40.788917 #21212]  INFO -- : listening on 127.0.0.1:4567
processing
processing
processing
processing
processing
I, [2017-02-14T11:42:52.772821 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:42:52.773679 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:42:52.774223 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:42:52.776345 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:42:52.776780 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
processing
processing
processing
processing
processing
I, [2017-02-14T11:43:09.087179 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:43:09.087920 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:43:09.088536 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:43:09.089521 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71
I, [2017-02-14T11:43:09.092244 #21212]  INFO -- : 127.0.0.1 - - "GET / HTTP/1.1" 200 71

regarding what the sleep is intending to simulate, an angelo server is a reel server, which is a celluloid::io reactor. if a task blocks on IO, e.g. waiting for a response from a socket, celluloid::io reactor will only work correctly with Celluloid::IO::TCPSocket types. some http clients allow you to specify socket class to use. the http gem was what i used to recommend, but it stopped using these. see also #59 and the example therein.