Example code deadlocks when sending an action

[joshaidan]

When I tried executing code similar to the example in the README.md, i.e.:

require 'ruby_ami'

def handle_event(event, stream)
  case event.name
  when 'FullyBooted'
    puts "The connection was successful. Originating a call."
    response = stream.send_action 'QueueStatus', 'Queue' => queue
    puts "The call origination resulted in #{response.inspect}"
  end
end

stream = RubyAMI::Stream.new '127.0.0.1', 5038, 'manager', 'password',
                              ->(e, stream) { handle_event e, stream },
                              Logger.new(STDOUT), 10

Celluloid::Actor.join(stream)

It seems to deadlock during the send_action call. My hunch is that this example given was originally written for when ruby_ami was using EventMachine instead of Celluloid. I suspect it deadlocks because when send_action is called inside handle_event, the connection.wait that's gets called blocks the thread (or actor or whatever it's called) that should be reading the socket. Hence it's waiting for a response it can't get, it deadlocks.

I was able to fix it by moving the stream.send_action outside of handle_event and put a sleep before it to make sure AMI was fully booted. But I wanted to find out if my theory was correct, and if we should update the README.md with a working example. (If that's the case I can submit a PR)

[benlangfeld]

It shouldn't deadlock; the Stream actor should pause the task. This feels more like an implementation bug rather than a documentation bug.

[joshaidan]

So running this script:

require 'ruby_ami'

def handle_event(event, stream)
  case event.name
  when 'FullyBooted'
    puts "The connection was successful. Originating a call."
    response = stream.send_action 'QueueStatus', 'Queue' => 'queuename'
    puts "The call origination resulted in #{response.inspect}"
  end
end

stream = RubyAMI::Stream.new 'hostname', 5038, 'manager', 'password',
                              ->(e, stream) { handle_event e, stream },
                              Logger.new(STDOUT), 10

Celluloid::Actor.join(stream)

I get the following:

D, [2016-12-02T23:14:52.205966 #29331] DEBUG -- : Starting up...
D, [2016-12-02T23:14:52.246813 #29331] DEBUG -- : [SEND] Action: login
ActionID: dde2506e-9039-49d8-a214-4386a81464a9
Username: manager
Secret: password
Events: On


READING DATA
D, [2016-12-02T23:14:52.264443 #29331] DEBUG -- : [RECV] Asterisk Call Manager/1.3
Response: Success

READING DATA
D, [2016-12-02T23:14:52.264784 #29331] DEBUG -- : [RECV] ActionID: dde2506e-9039-49d8-a214-4386a81464a9
Message: Authentication accepted


D, [2016-12-02T23:14:52.265354 #29331] DEBUG -- : [RECV] #<RubyAMI::Response headers={"ActionID"=>"dde2506e-9039-49d8-a214-4386a81464a9", "Message"=>"Authentication accepted"}, text_body=nil, events=[]>
READING DATA
D, [2016-12-02T23:14:52.265548 #29331] DEBUG -- : [RECV] Event: FullyBooted
Privilege: system,all
Status: Fully Booted


D, [2016-12-02T23:14:52.265912 #29331] DEBUG -- : [RECV] #<RubyAMI::Event name="FullyBooted", headers={"Privilege"=>"system,all", "Status"=>"Fully Booted"}, text_body=nil, events=[]>
The connection was successful. Originating a call.
D, [2016-12-02T23:14:52.266491 #29331] DEBUG -- : [SEND] Action: queuestatus
ActionID: 1603220e-0f63-4627-8330-82216d5f2d12
Queue: queuename

Then it just stops.

In stream.rb I added a puts "READING DATA inside loop { receive_data @socket.readpartial(4096) } to see if the loop is running. I also had ngrep running on port 5038 to see if there's any AMI traffic from the asterisk server and there is.

If I comment out the send_action line and the response.inspect line the in the script it runs fine and processes data.

Let me know if there's anything else you need me to do. I'll continue to troubleshoot this myself.

[joshaidan]

So, if I change the call to:

response = stream.async.send_action 'QueueStatus', 'Queue' => 'queuename'

This seems to resolve the deadlock, and the call works correctly. Not sure if this is the correct fix; I got a lot of learning about Celluloid to do.

[benjaminfauchald]

Did you ever solve this? Seems like putting this async will just have a bunch of connections going until they time out? Doesn't seem very effective?

[joshaidan]

Hey, sorry it's been maybe about a year and a half since I submitted this so my memory isn't entirely fresh. I submitted PR #41 which has my proposed fix, but also adds a unit test which recreates the issue if we can come up with a better solution.

[awh-tokyo]

2.5 years later and I'm completely in the dark as to how I'd send an action (and get a response) in response to an event. When a queue member signs in or out, I'd like to get a list of who all is in the queue. I can't for the life of me figure out how I'd do that with this library.

[ThomasSevestre]

In case it helps...
You can try my eventmachine branch if you want : https://github.com/ThomasSevestre/ruby_ami/tree/eventmachine

[awh-tokyo]

@ThomasSevestre Any chance you'd consider releasing your eventmachine branch as a separate gem? I just ran into this problem again.

[ThomasSevestre]

@awh-tokyo I've sent you an email on awh@awh.org