Re: [Adhearsion] anyway to call google tts AGI?

830 views

Skip to first unread message

Ben Langfeld

unread,

Nov 21, 2012, 6:53:26 AM11/21/12

to adhea...@googlegroups.com

Check out the adhearsion-asterisk plugin.

Regards,

Ben Langfeld

Em 21 Nov 2012, às 05:56, dayn <oren...@gmail.com> escreveu:

I recently found this.
AGI script for the Asterisk open source PBX which allows you to use Googles' voice synthesis engine to render text to speech.
http://zaf.github.com/asterisk-googletts/

I installed it and it is running ok under asterisk.

My question here is if adhearsion is able to call such asterisk AGI application (in my case, "agi(googletts.agi)").
as far as I read,
http://rubydoc.info/gems/adhearsion/Adhearsion/CallController
http://rubydoc.info/gems/adhearsion/Adhearsion/CallController/Output
it is not able to call AGI application from adhearsion call controller??

If there is any workarounds available, I would like to know.
Thanks

--

dayn

unread,

Nov 21, 2012, 8:59:08 PM11/21/12

to adhea...@googlegroups.com

Thanks, it worked!!

I did it ilke this

vi Gemfile # uncomment adhearsion-asterisk line
bundle install
vi lib/simon_game.rb
# added a line like execute("agi", "asterisk-googletts/googletts.agi","This is a simple google text to speech test in english.","en")

This called googletts.agi successfully, but maybe googletts.agi is not meant to be called like this, and it didn't work.

(but this is just another story)

Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 113, <STDIN> line 21.
Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 114, <STDIN> line 21.
Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 115, <STDIN> line 21.
Use of uninitialized value $_ in length at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 116, <STDIN> line 21.
-- asterisk-googletts/googletts.agi: No text passed for synthesis.

* I don't use perl, and I am not sure what is going on.

I might just write my own gem to download tts mp3, convert and place it to sound directory, so that I can call play with the file name.

Ben Langfeld

unread,

Nov 22, 2012, 2:39:04 AM11/22/12

to adhea...@googlegroups.com

Perhaps you could provide Adhearsion trace logs so we may verify it was called correctly? You should also use #agi rather than

Regards,

Ben Langfeld

--

Ben Langfeld

unread,

Nov 22, 2012, 2:41:12 AM11/22/12

to adhea...@googlegroups.com

That should have said "rather than #execute". Additionally, all of the output you see there are warnings and should not affect operation, although the script could be cleaned up slightly to avoid them.

Regards,

Ben Langfeld

dayn

unread,

Nov 23, 2012, 10:02:17 PM11/23/12

to adhea...@googlegroups.com

--------------------------------

environments

--------------------------------

uname -a

Linux localhost.localdomain 2.6.32-279.el6.i686 #1 SMP Fri Jun 22 10:59:55 UTC 2012 i686 i686 i386 GNU/Linux

/etc/redhat-release

CentOS release 6.3 (Final)

asterisk -V

Asterisk 11.0.1

rbenv version

1.9.3-p327

gem list -d adhearsion

*** LOCAL GEMS ***

adhearsion (2.1.3)

Authors: Jay Phillips, Jason Goecke, Ben Klang, Ben Langfeld

Homepage: http://adhearsion.com

Installed at: /home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1

Adhearsion, open-source telephony development framework

adhearsion-asterisk (1.3.0)

Authors: Ben Langfeld, Taylor Carpenter, Luca Pradovera

Rubyforge: http://rubyforge.org/projects/adhearsion-asterisk

Homepage: http://adhearsion.com

Installed at: /home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1

Asterisk specific features for Adhearsion

adhearsion-loquacious (1.9.3)

Author: Tim Pease

Homepage: http://rubygems.org/gems/loquacious

Installed at: /home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1

Descriptive configuration files for Ruby written in Ruby.

I tried 2 ways.

execute("agi", "asterisk-googletts/googletts.agi","This is a simple google text to speech test in english.","en")

agi("asterisk-googletts/googletts.agi", "This is a simple google text to speech test in english.", "en")

The both methods won't playback any sounds. (running the same agi directly from extensions.conf will do)

hope this helps.

--------------------------------

code run

--------------------------------

execute("agi", "asterisk-googletts/googletts.agi","This is a simple google text to speech test in english.","en")

--------------------------------

asterisk log

--------------------------------

SecurityEvent="ChallengeSent",EventTV="1353725183-699201",Severity="Informational",Service="SIP",EventVersion="1",AccountID="sip:b...@192.168.3.3",SessionID="0xa6eae3c",LocalAddress="IPV4/UDP/192.168.3.3/5060",RemoteAddress="IPV4/UDP/192.168.3.2/57581",Challenge="6435251c"

Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 113, <STDIN> line 21.
Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 114, <STDIN> line 21.
Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 115, <STDIN> line 21.
Use of uninitialized value $_ in length at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 116, <STDIN> line 21.
-- asterisk-googletts/googletts.agi: No text passed for synthesis.

--------------------------------

adhearsion log

--------------------------------

[2012-11-24 11:46:24] DEBUG Adhearsion::Call: b50ac754-02e6-4a91-adaf-e7cf9100b07a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000005", :commandid=>"56690533", :command=>"EXEC agi \"asterisk-googletts/googletts.agi\" \"This is a simple google text to speech test in english.\" \"en\"", :resultcode=>"200", :result=>"Success"}, target_call_id="b50ac754-02e6-4a91-adaf-e7cf9100b07a", component_id=nil, target_mixer_name=nil>
[2012-11-24 11:46:24] DEBUG Adhearsion::Call: b50ac754-02e6-4a91-adaf-e7cf9100b07a: Receiving message: #<Punchblock::Event::Complete reason=#<Punchblock::Component::Asterisk::AGI::Command::Complete::Success code=200, result=0, data="">, recording=nil, target_call_id="b50ac754-02e6-4a91-adaf-e7cf9100b07a", component_id="17c5c30c-784a-4ab6-92b1-ee5274191303", target_mixer_name=nil>

--------------------------------

code run

--------------------------------

agi("asterisk-googletts/googletts.agi", "This is a simple google text to speech test in english.", "en")

--------------------------------

asterisk log

--------------------------------

SecurityEvent="ChallengeSent",EventTV="1353725475-414273",Severity="Informational",Service="SIP",EventVersion="1",AccountID="sip:b...@192.168.3.3",SessionID="0xa6c8f0c",LocalAddress="IPV4/UDP/192.168.3.3/5060",RemoteAddress="IPV4/UDP/192.168.3.2/57581",Challenge="12b9a040"

--------------------------------

adhearsion log

--------------------------------

[2012-11-24 11:51:15] DEBUG Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: Executing command #<Punchblock::Component::Asterisk::AGI::Command name="asterisk-googletts/googletts.agi", params_array=["This is a simple google text to speech test in english.", "en"], target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2012-11-24 11:51:16] DEBUG Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000008", :commandid=>"1390219344", :command=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\""}, target_call_id="a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3", component_id=nil, target_mixer_name=nil>
[2012-11-24 11:51:16] DEBUG Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/bob-00000008", :commandid=>"08c6a7bc-a8df-47d0-a476-c88591ab8877", :result=>"510%20Invalid%20or%20unknown%20command%0A"}, target_call_id="a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3", component_id=nil, target_mixer_name=nil>
[2012-11-24 11:51:16] ERROR Celluloid: Punchblock::Translator::Asterisk::Component::Asterisk::AGICommand crashed!
ArgumentError: The result string did not match the required format.
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/ruby_ami-1.2.5/lib/ruby_ami/agi_result_parser.rb:13:in `initialize'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `new'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `success_reason'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:25:in `handle_ami_event'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `dispatch'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/actor.rb:323:in `block in handle_message'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/tasks/task_fiber.rb:22:in `block in initialize'
[2012-11-24 11:51:16] ERROR Adhearsion::Initializer: <ArgumentError> The result string did not match the required format.
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/ruby_ami-1.2.5/lib/ruby_ami/agi_result_parser.rb:13:in `initialize'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `new'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `success_reason'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:25:in `handle_ami_event'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `dispatch'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/actor.rb:323:in `block in handle_message'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/tasks/task_fiber.rb:22:in `block in initialize'
[2012-11-24 11:51:16] ERROR Celluloid: Punchblock::Translator::Asterisk::Call crashed!
ArgumentError: The result string did not match the required format.
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/ruby_ami-1.2.5/lib/ruby_ami/agi_result_parser.rb:13:in `initialize'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `new'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `success_reason'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:25:in `handle_ami_event'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `dispatch'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/actor.rb:323:in `block in handle_message'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/tasks/task_fiber.rb:22:in `block in initialize'
[2012-11-24 11:51:16] ERROR Adhearsion::Initializer: <ArgumentError> The result string did not match the required format.
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/ruby_ami-1.2.5/lib/ruby_ami/agi_result_parser.rb:13:in `initialize'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `new'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `success_reason'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:25:in `handle_ami_event'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `dispatch'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/actor.rb:323:in `block in handle_message'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/tasks/task_fiber.rb:22:in `block in initialize'
[2012-11-24 11:51:16] DEBUG Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000008", :commandid=>"1390219344", :command=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\"", :resultcode=>"510", :result=>"Invalid or unknown command"}, target_call_id="a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3", component_id=nil, target_mixer_name=nil>
[2012-11-24 11:51:16] DEBUG Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: Receiving message: #<Punchblock::Event::Complete reason=#<Punchblock::Event::Complete::Error details="", name=:error, target_call_id="a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3", component_id="08c6a7bc-a8df-47d0-a476-c88591ab8877", target_mixer_name=nil>, recording=nil, target_call_id="a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3", component_id="08c6a7bc-a8df-47d0-a476-c88591ab8877", target_mixer_name=nil>
[2012-11-24 11:51:16] ERROR Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: <Adhearsion::Error> : #<Punchblock::Component::Asterisk::AGI::Command name="asterisk-googletts/googletts.agi", params_array=["This is a simple google text to speech test in english.", "en"], target_call_id="a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3", component_id="08c6a7bc-a8df-47d0-a476-c88591ab8877", target_mixer_name=nil, state_name=:complete>
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:181:in `execute_component_and_await_completion'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-asterisk-1.3.0/lib/adhearsion/asterisk/call_controller_methods.rb:19:in `agi'
/home/adhearsion/test/lib/simon_game.rb:8:in `run'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:104:in `execute!'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:79:in `block in exec'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:78:in `catch'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:78:in `exec'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:95:in `exec_with_callback'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:89:in `block (2 levels) in bg_exec'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/foundation/exception_handler.rb:5:in `catching_standard_errors'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/adhearsion-2.1.3/lib/adhearsion/call_controller.rb:88:in `block in bg_exec'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/logging-1.8.0/lib/logging/diagnostic_context.rb:323:in `call'
/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/logging-1.8.0/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'
[2012-11-24 11:51:16] DEBUG Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: Receiving message: #<Punchblock::Event::End reason=:error, headers_hash={}, target_call_id="a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3", component_id=nil, target_mixer_name=nil>
[2012-11-24 11:51:16] INFO Adhearsion::Call: a17dc1b8-7bc6-4ecb-8c8a-1bc6fdd202e3: Call ended

Ben Langfeld

unread,

Nov 23, 2012, 10:05:45 PM11/23/12

to adhea...@googlegroups.com

Unfortunately the Adhearsion logs you provided are at debug level. Please drop the log level to trace and post the result.

Regards,

Ben Langfeld

--

dayn

unread,

Nov 24, 2012, 3:36:20 AM11/24/12

to adhea...@googlegroups.com

ok here it is once again

--------------------------------

code run

--------------------------------

execute("agi", "asterisk-googletts/googletts.agi","This is a simple google text to speech test in english.","en")

--------------------------------

asterisk -vvvvvc

--------------------------------

SecurityEvent="ChallengeSent",EventTV="1353745482-955272",Severity="Informational",Service="SIP",EventVersion="1",AccountID="sip:b...@192.168.11.21",SessionID="0xb7501564",LocalAddress="IPV4/UDP/192.168.11.21/5060",RemoteAddress="IPV4/UDP/192.168.11.31/53404",Challenge="19487f93"

== Using SIP RTP CoS mark 5

-- Executing [111@adhearsion:1] AGI("SIP/bob-00000000", "agi:async") in new stack

-- AGI Script Executing Application: (RINGING) Options: ()

-- AGI Script Executing Application: (agi) Options: (asterisk-googletts/googletts.agi)

-- Launched AGI Script /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi

Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 113, <STDIN> line 21.

Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 114, <STDIN> line 21.

Use of uninitialized value $_ in substitution (s///) at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 115, <STDIN> line 21.

Use of uninitialized value $_ in length at /var/lib/asterisk/agi-bin/asterisk-googletts/googletts.agi line 116, <STDIN> line 21.

-- asterisk-googletts/googletts.agi: No text passed for synthesis.

-- <SIP/bob-00000000>AGI Script asterisk-googletts/googletts.agi completed, returning 0

-- Manager 'myuser' from 127.0.0.1, hanging up channel: SIP/bob-00000000

== Spawn extension (adhearsion, 111, 1) exited non-zero on 'SIP/bob-00000000'

-- Executing [h@adhearsion:1] AGI("SIP/bob-00000000", "agi:async") in new stack

== Spawn extension (adhearsion, h, 1) exited non-zero on 'SIP/bob-00000000'

--------------------------------

adhearsion dev.platform.logging.level = :trace

--------------------------------

AHN> [2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] Event: Newchannel

Privilege: call,all

Channel: SIP/bob-00000000

ChannelState: 0

ChannelStateDesc: Down

CallerIDNum: bob

CallerIDName: bob

AccountCode:

Exten: 111

Context: adhearsion

Uniqueid: 1353745482.0

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "AccountCode"=>"", "Exten"=>"111", "Context"=>"adhearsion", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "AccountCode"=>"", "Exten"=>"111", "Context"=>"adhearsion", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: SIPURI

Value: sip:b...@192.168.11.31:53404

Uniqueid: 1353745482.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: SIPDOMAIN

Value: 192.168.11.21

Uniqueid: 1353745482.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: SIPCALLID

Value: fJ3lx6y.rTehc9VwdNtcaXuy1J-vONdV

Uniqueid: 1353745482.0

Event: Newstate

Privilege: call,all

Channel: SIP/bob-00000000

ChannelState: 4

ChannelStateDesc: Ring

CallerIDNum: bob

CallerIDName: bob

ConnectedLineNum:

ConnectedLineName:

Uniqueid: 1353745482.0

Event: Newexten

Privilege: dialplan,all

Channel: SIP/bob-00000000

Context: adhearsion

Extension: 111

Priority: 1

Application: AGI

AppData: agi:async

Uniqueid: 1353745482.0

Event: AsyncAGI

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353745482.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20111%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1236055184%0A%0A

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPURI", "Value"=>"sip:b...@192.168.11.31:53404", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPURI", "Value"=>"sip:b...@192.168.11.31:53404", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPDOMAIN", "Value"=>"192.168.11.21", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPDOMAIN", "Value"=>"192.168.11.21", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPCALLID", "Value"=>"fJ3lx6y.rTehc9VwdNtcaXuy1J-vONdV", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPCALLID", "Value"=>"fJ3lx6y.rTehc9VwdNtcaXuy1J-vONdV", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:42] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Context"=>"adhearsion", "Extension"=>"111", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Context"=>"adhearsion", "Extension"=>"111", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353745482.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20111%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1236055184%0A%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353745482.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20111%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1236055184%0A%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] DEBUG Adhearsion::Call: : Receiving message: #<Punchblock::Event::Offer to="111", from="bob <SIP/bob>", headers={:x_agi_request=>"async", :x_agi_channel=>"SIP/bob-00000000", :x_agi_language=>"en", :x_agi_type=>"SIP", :x_agi_uniqueid=>"1353745482.0", :x_agi_version=>"11.0.1", :x_agi_callerid=>"bob", :x_agi_calleridname=>"bob", :x_agi_callingpres=>"0", :x_agi_callingani2=>"0", :x_agi_callington=>"0", :x_agi_callingtns=>"0", :x_agi_dnid=>"111", :x_agi_rdnis=>"unknown", :x_agi_context=>"adhearsion", :x_agi_extension=>"111", :x_agi_priority=>"1", :x_agi_enhanced=>"0.0", :x_agi_accountcode=>"", :x_agi_threadid=>"-1236055184"}, call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592"

[2012-11-24 17:24:43] INFO Adhearsion::Router: Call 67c58f77-b222-4622-8b21-9e2fb8cc5592 selected route "default" (SimonGame)

[2012-11-24 17:24:43] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Executing command #<Punchblock::Command::Accept headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [QUEUE]: Action: agi

ActionID: e12366e9-a254-43ae-aab0-939cd0f3e84e

Channel: SIP/bob-00000000

Command: EXEC RINGING

CommandID: df7c90da-1ae5-41b5-98aa-8da3670a00ea

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [SEND]: Action: agi

ActionID: e12366e9-a254-43ae-aab0-939cd0f3e84e

Channel: SIP/bob-00000000

Command: EXEC RINGING

CommandID: df7c90da-1ae5-41b5-98aa-8da3670a00ea

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [SEND] Action: agi

ActionID: e12366e9-a254-43ae-aab0-939cd0f3e84e

Channel: SIP/bob-00000000

Command: EXEC RINGING

CommandID: df7c90da-1ae5-41b5-98aa-8da3670a00ea

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV] Response: Success

ActionID: e12366e9-a254-43ae-aab0-939cd0f3e84e

Message: Added AGI command to queue

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"e12366e9-a254-43ae-aab0-939cd0f3e84e", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"e12366e9-a254-43ae-aab0-939cd0f3e84e", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

CommandId: 339052869

Command: EXEC RINGING

Event: AGIExec

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

CommandId: 339052869

Command: EXEC RINGING

ResultCode: 200

Result: Success

Event: AsyncAGI

Privilege: agi,all

SubEvent: Exec

Channel: SIP/bob-00000000

CommandID: df7c90da-1ae5-41b5-98aa-8da3670a00ea

Result: 200%20result%3D0%0A

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"339052869", "Command"=>"EXEC RINGING"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"339052869", "Command"=>"EXEC RINGING"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"339052869", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"339052869", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"df7c90da-1ae5-41b5-98aa-8da3670a00ea", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"df7c90da-1ae5-41b5-98aa-8da3670a00ea", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:43] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000000", :commandid=>"339052869", :command=>"EXEC RINGING"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:43] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000000", :commandid=>"339052869", :command=>"EXEC RINGING", :resultcode=>"200", :result=>"Success"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:43] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/bob-00000000", :commandid=>"df7c90da-1ae5-41b5-98aa-8da3670a00ea", :result=>"200%20result%3D0%0A"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:43] INFO Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Executing controller #<SimonGame call=67c58f77-b222-4622-8b21-9e2fb8cc5592, metadata={}>

[2012-11-24 17:24:43] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Offer to="111", from="bob <SIP/bob>", headers={:x_agi_request=>"async", :x_agi_channel=>"SIP/bob-00000000", :x_agi_language=>"en", :x_agi_type=>"SIP", :x_agi_uniqueid=>"1353745482.0", :x_agi_version=>"11.0.1", :x_agi_callerid=>"bob", :x_agi_calleridname=>"bob", :x_agi_callingpres=>"0", :x_agi_callingani2=>"0", :x_agi_callington=>"0", :x_agi_callingtns=>"0", :x_agi_dnid=>"111", :x_agi_rdnis=>"unknown", :x_agi_context=>"adhearsion", :x_agi_extension=>"111", :x_agi_priority=>"1", :x_agi_enhanced=>"0.0", :x_agi_accountcode=>"", :x_agi_threadid=>"-1236055184"}, call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592"

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Executing command #<Punchblock::Command::Answer headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [QUEUE]: Action: agi

ActionID: 461be3d7-cc13-4398-8acb-3866df6ca798

Channel: SIP/bob-00000000

Command: ANSWER

CommandID: fda1d860-6370-4a6c-94b1-cae0f903b0e0

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [SEND]: Action: agi

ActionID: 461be3d7-cc13-4398-8acb-3866df6ca798

Channel: SIP/bob-00000000

Command: ANSWER

CommandID: fda1d860-6370-4a6c-94b1-cae0f903b0e0

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [SEND] Action: agi

ActionID: 461be3d7-cc13-4398-8acb-3866df6ca798

Channel: SIP/bob-00000000

Command: ANSWER

CommandID: fda1d860-6370-4a6c-94b1-cae0f903b0e0

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] Response: Success

ActionID: 461be3d7-cc13-4398-8acb-3866df6ca798

Message: Added AGI command to queue

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"461be3d7-cc13-4398-8acb-3866df6ca798", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"461be3d7-cc13-4398-8acb-3866df6ca798", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

CommandId: 89360662

Command: ANSWER

Event: Newstate

Privilege: call,all

Channel: SIP/bob-00000000

ChannelState: 6

ChannelStateDesc: Up

CallerIDNum: bob

CallerIDName: bob

ConnectedLineNum:

ConnectedLineName:

Uniqueid: 1353745482.0

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"89360662", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"89360662", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

CommandId: 89360662

Command: ANSWER

ResultCode: 200

Result: Success

Event: AsyncAGI

Privilege: agi,all

SubEvent: Exec

Channel: SIP/bob-00000000

CommandID: fda1d860-6370-4a6c-94b1-cae0f903b0e0

Result: 200%20result%3D0%0A

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"89360662", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"89360662", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"fda1d860-6370-4a6c-94b1-cae0f903b0e0", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"fda1d860-6370-4a6c-94b1-cae0f903b0e0", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000000", :commandid=>"89360662", :command=>"ANSWER"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Newstate", attributes_hash={:privilege=>"call,all", :channel=>"SIP/bob-00000000", :channelstate=>"6", :channelstatedesc=>"Up", :calleridnum=>"bob", :calleridname=>"bob", :connectedlinenum=>"", :connectedlinename=>"", :uniqueid=>"1353745482.0"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Answered headers_hash={}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000000", :commandid=>"89360662", :command=>"ANSWER", :resultcode=>"200", :result=>"Success"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/bob-00000000", :commandid=>"fda1d860-6370-4a6c-94b1-cae0f903b0e0", :result=>"200%20result%3D0%0A"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Executing command #<Punchblock::Component::Asterisk::AGI::Command name="EXEC agi", params_array=["asterisk-googletts/googletts.agi", "This is a simple google text to speech test in english.", "en"], target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [QUEUE]: Action: agi

ActionID: ba2bfc4e-393e-41dd-ae32-c76eb291c5ab

Channel: SIP/bob-00000000

Command: EXEC agi "asterisk-googletts/googletts.agi" "This is a simple google text to speech test in english." "en"

CommandID: b4f32b3c-ed6d-45e2-b316-ff9ce0a9ea0d

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [SEND]: Action: agi

ActionID: ba2bfc4e-393e-41dd-ae32-c76eb291c5ab

Channel: SIP/bob-00000000

Command: EXEC agi "asterisk-googletts/googletts.agi" "This is a simple google text to speech test in english." "en"

CommandID: b4f32b3c-ed6d-45e2-b316-ff9ce0a9ea0d

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [SEND] Action: agi

ActionID: ba2bfc4e-393e-41dd-ae32-c76eb291c5ab

Channel: SIP/bob-00000000

Command: EXEC agi "asterisk-googletts/googletts.agi" "This is a simple google text to speech test in english." "en"

CommandID: b4f32b3c-ed6d-45e2-b316-ff9ce0a9ea0d

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] Response: Success

ActionID: ba2bfc4e-393e-41dd-ae32-c76eb291c5ab

Message: Added AGI command to queue

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"ba2bfc4e-393e-41dd-ae32-c76eb291c5ab", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"ba2bfc4e-393e-41dd-ae32-c76eb291c5ab", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

CommandId: 2106038629

Command: EXEC agi "asterisk-googletts/googletts.agi" "This is a simple google text to speech test in english." "en"

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"2106038629", "Command"=>"EXEC agi \"asterisk-googletts/googletts.agi\" \"This is a simple google text to speech test in english.\" \"en\""}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"2106038629", "Command"=>"EXEC agi \"asterisk-googletts/googletts.agi\" \"This is a simple google text to speech test in english.\" \"en\""}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:44] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000000", :commandid=>"2106038629", :command=>"EXEC agi \"asterisk-googletts/googletts.agi\" \"This is a simple google text to speech test in english.\" \"en\""}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: AGISTATUS

Value: FAILURE

Uniqueid: 1353745482.0

Event: AGIExec

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

CommandId: 2106038629

Command: EXEC agi "asterisk-googletts/googletts.agi" "This is a simple google text to speech test in english." "en"

ResultCode: 200

Result: Success

Event: AsyncAGI

Privilege: agi,all

SubEvent: Exec

Channel: SIP/bob-00000000

CommandID: b4f32b3c-ed6d-45e2-b316-ff9ce0a9ea0d

Result: 200%20result%3D0%0A

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"2106038629", "Command"=>"EXEC agi \"asterisk-googletts/googletts.agi\" \"This is a simple google text to speech test in english.\" \"en\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"2106038629", "Command"=>"EXEC agi \"asterisk-googletts/googletts.agi\" \"This is a simple google text to speech test in english.\" \"en\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"b4f32b3c-ed6d-45e2-b316-ff9ce0a9ea0d", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"b4f32b3c-ed6d-45e2-b316-ff9ce0a9ea0d", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000000", :commandid=>"2106038629", :command=>"EXEC agi \"asterisk-googletts/googletts.agi\" \"This is a simple google text to speech test in english.\" \"en\"", :resultcode=>"200", :result=>"Success"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Complete reason=#<Punchblock::Component::Asterisk::AGI::Command::Complete::Success code=200, result=0, data="">, recording=nil, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id="b4f32b3c-ed6d-45e2-b316-ff9ce0a9ea0d", target_mixer_name=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Finished executing controller #<SimonGame call=67c58f77-b222-4622-8b21-9e2fb8cc5592, metadata={}>

[2012-11-24 17:24:45] INFO Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Hanging up

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Executing command #<Punchblock::Command::Hangup headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [QUEUE]: Action: hangup

ActionID: f09fd6c8-b355-452c-bd00-ea416c57883c

Channel: SIP/bob-00000000

Cause: 16

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [SEND]: Action: hangup

ActionID: f09fd6c8-b355-452c-bd00-ea416c57883c

Channel: SIP/bob-00000000

Cause: 16

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [SEND] Action: hangup

ActionID: f09fd6c8-b355-452c-bd00-ea416c57883c

Channel: SIP/bob-00000000

Cause: 16

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] Event: AsyncAGI

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: AGISTATUS

Value: HANGUP

Uniqueid: 1353745482.0

Event: SoftHangupRequest

Privilege: call,all

Channel: SIP/bob-00000000

Uniqueid: 1353745482.0

Cause: 16

Event: Newexten

Privilege: dialplan,all

Channel: SIP/bob-00000000

Context: adhearsion

Extension: h

Priority: 1

Application: AGI

AppData: agi:async

Uniqueid: 1353745482.0

Event: AsyncAGI

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353745482.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1236055184%0A%0A

Event: AsyncAGI

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: AGISTATUS

Value: HANGUP

Uniqueid: 1353745482.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: RTPAUDIOQOS

Value: ssrc=1830954861;themssrc=310652914;lp=0;rxjitter=0.002696;rxcount=50;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000

Uniqueid: 1353745482.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: RTPAUDIOQOSJITTER

Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;

Uniqueid: 1353745482.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: RTPAUDIOQOSLOSS

Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;

Uniqueid: 1353745482.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: RTPAUDIOQOSRTT

Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;

Uniqueid: 1353745482.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: RTPAUDIOQOS

Value: ssrc=1830954861;themssrc=310652914;lp=0;rxjitter=0.002696;rxcount=50;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000

Uniqueid: 1353745482.0

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] Response: Success

ActionID: f09fd6c8-b355-452c-bd00-ea416c57883c

Message: Channel Hungup

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"f09fd6c8-b355-452c-bd00-ea416c57883c", "Message"=>"Channel Hungup"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"f09fd6c8-b355-452c-bd00-ea416c57883c", "Message"=>"Channel Hungup"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "Uniqueid"=>"1353745482.0", "Cause"=>"16"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "Uniqueid"=>"1353745482.0", "Cause"=>"16"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="SoftHangupRequest", attributes_hash={:privilege=>"call,all", :channel=>"SIP/bob-00000000", :uniqueid=>"1353745482.0", :cause=>"16"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353745482.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1236055184%0A%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Newexten", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/bob-00000000", :context=>"adhearsion", :extension=>"h", :priority=>"1", :application=>"AGI", :appdata=>"agi:async", :uniqueid=>"1353745482.0"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353745482.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1236055184%0A%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000000", :env=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353745482.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1236055184%0A%0A"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1830954861;themssrc=310652914;lp=0;rxjitter=0.002696;rxcount=50;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1830954861;themssrc=310652914;lp=0;rxjitter=0.002696;rxcount=50;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/bob-00000000", :variable=>"RTPAUDIOQOS", :value=>"ssrc=1830954861;themssrc=310652914;lp=0;rxjitter=0.002696;rxcount=50;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", :uniqueid=>"1353745482.0"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/bob-00000000", :variable=>"RTPAUDIOQOSJITTER", :value=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", :uniqueid=>"1353745482.0"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/bob-00000000", :variable=>"RTPAUDIOQOSLOSS", :value=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", :uniqueid=>"1353745482.0"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1353745482.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/bob-00000000", :variable=>"RTPAUDIOQOSRTT", :value=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", :uniqueid=>"1353745482.0"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] Event: Hangup

Privilege: call,all

Channel: SIP/bob-00000000

Uniqueid: 1353745482.0

CallerIDNum: bob

CallerIDName: bob

ConnectedLineNum: <unknown>

ConnectedLineName: <unknown>

AccountCode:

Cause: 16

Cause-txt: Normal Clearing

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "Uniqueid"=>"1353745482.0", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "Uniqueid"=>"1353745482.0", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Hangup", attributes_hash={:privilege=>"call,all", :channel=>"SIP/bob-00000000", :uniqueid=>"1353745482.0", :calleridnum=>"bob", :calleridname=>"bob", :connectedlinenum=>"<unknown>", :connectedlinename=>"<unknown>", :accountcode=>"", :cause=>"16", :cause_txt=>"Normal Clearing"}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] DEBUG Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Receiving message: #<Punchblock::Event::End reason=:hangup, headers_hash={}, target_call_id="67c58f77-b222-4622-8b21-9e2fb8cc5592", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:24:45] INFO Adhearsion::Call: 67c58f77-b222-4622-8b21-9e2fb8cc5592: Call ended

--------------------------------

code run

--------------------------------

agi("asterisk-googletts/googletts.agi", "This is a simple google text to speech test in english.", "en")

--------------------------------

asterisk -vvvvvc

--------------------------------

SecurityEvent="ChallengeSent",EventTV="1353746061-341373",Severity="Informational",Service="SIP",EventVersion="1",AccountID="sip:b...@192.168.11.21",SessionID="0x9370f5c",LocalAddress="IPV4/UDP/192.168.11.21/5060",RemoteAddress="IPV4/UDP/192.168.11.31/53404",Challenge="6df1dbfd"

== Using SIP RTP CoS mark 5

-- Executing [111@adhearsion:1] AGI("SIP/bob-00000000", "agi:async") in new stack

-- AGI Script Executing Application: (RINGING) Options: ()

--------------------------------

adhearsion dev.platform.logging.level = :trace

--------------------------------

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] Event: Newchannel

Privilege: call,all

Channel: SIP/bob-00000000

ChannelState: 0

ChannelStateDesc: Down

CallerIDNum: bob

CallerIDName: bob

AccountCode:

Exten: 111

Context: adhearsion

Uniqueid: 1353746061.0

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "AccountCode"=>"", "Exten"=>"111", "Context"=>"adhearsion", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "AccountCode"=>"", "Exten"=>"111", "Context"=>"adhearsion", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: SIPURI

Value: sip:b...@192.168.11.31:53404

Uniqueid: 1353746061.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: SIPDOMAIN

Value: 192.168.11.21

Uniqueid: 1353746061.0

Event: VarSet

Privilege: dialplan,all

Channel: SIP/bob-00000000

Variable: SIPCALLID

Value: MMSXklalMVMwHNdeoUx2MXt5uKQQG0ed

Uniqueid: 1353746061.0

Event: Newstate

Privilege: call,all

Channel: SIP/bob-00000000

ChannelState: 4

ChannelStateDesc: Ring

CallerIDNum: bob

CallerIDName: bob

ConnectedLineNum:

ConnectedLineName:

Uniqueid: 1353746061.0

Event: Newexten

Privilege: dialplan,all

Channel: SIP/bob-00000000

Context: adhearsion

Extension: 111

Priority: 1

Application: AGI

AppData: agi:async

Uniqueid: 1353746061.0

Event: AsyncAGI

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353746061.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20111%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1234695312%0A%0A

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPURI", "Value"=>"sip:b...@192.168.11.31:53404", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPURI", "Value"=>"sip:b...@192.168.11.31:53404", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPDOMAIN", "Value"=>"192.168.11.21", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPDOMAIN", "Value"=>"192.168.11.21", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPCALLID", "Value"=>"MMSXklalMVMwHNdeoUx2MXt5uKQQG0ed", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Variable"=>"SIPCALLID", "Value"=>"MMSXklalMVMwHNdeoUx2MXt5uKQQG0ed", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Context"=>"adhearsion", "Extension"=>"111", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/bob-00000000", "Context"=>"adhearsion", "Extension"=>"111", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353746061.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20111%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1234695312%0A%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fbob-00000000%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201353746061.0%0Aagi_version%3A%2011.0.1%0Aagi_callerid%3A%20bob%0Aagi_calleridname%3A%20bob%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20111%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20111%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1234695312%0A%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] DEBUG Adhearsion::Call: : Receiving message: #<Punchblock::Event::Offer to="111", from="bob <SIP/bob>", headers={:x_agi_request=>"async", :x_agi_channel=>"SIP/bob-00000000", :x_agi_language=>"en", :x_agi_type=>"SIP", :x_agi_uniqueid=>"1353746061.0", :x_agi_version=>"11.0.1", :x_agi_callerid=>"bob", :x_agi_calleridname=>"bob", :x_agi_callingpres=>"0", :x_agi_callingani2=>"0", :x_agi_callington=>"0", :x_agi_callingtns=>"0", :x_agi_dnid=>"111", :x_agi_rdnis=>"unknown", :x_agi_context=>"adhearsion", :x_agi_extension=>"111", :x_agi_priority=>"1", :x_agi_enhanced=>"0.0", :x_agi_accountcode=>"", :x_agi_threadid=>"-1234695312"}, call_id="05f6d01e-bd1a-4345-abc3-b13426db588e"

[2012-11-24 17:34:21] INFO Adhearsion::Router: Call 05f6d01e-bd1a-4345-abc3-b13426db588e selected route "default" (SimonGame)

[2012-11-24 17:34:21] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Executing command #<Punchblock::Command::Accept headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [QUEUE]: Action: agi

ActionID: 3d095217-a7bc-49ef-8a2a-79ff06f7e459

Channel: SIP/bob-00000000

Command: EXEC RINGING

CommandID: d2c807cd-3d94-4788-8e83-8a5d919852e0

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [SEND]: Action: agi

ActionID: 3d095217-a7bc-49ef-8a2a-79ff06f7e459

Channel: SIP/bob-00000000

Command: EXEC RINGING

CommandID: d2c807cd-3d94-4788-8e83-8a5d919852e0

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [SEND] Action: agi

ActionID: 3d095217-a7bc-49ef-8a2a-79ff06f7e459

Channel: SIP/bob-00000000

Command: EXEC RINGING

CommandID: d2c807cd-3d94-4788-8e83-8a5d919852e0

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] Response: Success

ActionID: 3d095217-a7bc-49ef-8a2a-79ff06f7e459

Message: Added AGI command to queue

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"3d095217-a7bc-49ef-8a2a-79ff06f7e459", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"3d095217-a7bc-49ef-8a2a-79ff06f7e459", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

CommandId: 203790900

Command: EXEC RINGING

Event: AGIExec

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

CommandId: 203790900

Command: EXEC RINGING

ResultCode: 200

Result: Success

Event: AsyncAGI

Privilege: agi,all

SubEvent: Exec

Channel: SIP/bob-00000000

CommandID: d2c807cd-3d94-4788-8e83-8a5d919852e0

Result: 200%20result%3D0%0A

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"203790900", "Command"=>"EXEC RINGING"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"203790900", "Command"=>"EXEC RINGING"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"203790900", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"203790900", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"d2c807cd-3d94-4788-8e83-8a5d919852e0", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"d2c807cd-3d94-4788-8e83-8a5d919852e0", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:21] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000000", :commandid=>"203790900", :command=>"EXEC RINGING"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:21] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000000", :commandid=>"203790900", :command=>"EXEC RINGING", :resultcode=>"200", :result=>"Success"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:21] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/bob-00000000", :commandid=>"d2c807cd-3d94-4788-8e83-8a5d919852e0", :result=>"200%20result%3D0%0A"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:21] INFO Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Executing controller #<SimonGame call=05f6d01e-bd1a-4345-abc3-b13426db588e, metadata={}>

[2012-11-24 17:34:21] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Offer to="111", from="bob <SIP/bob>", headers={:x_agi_request=>"async", :x_agi_channel=>"SIP/bob-00000000", :x_agi_language=>"en", :x_agi_type=>"SIP", :x_agi_uniqueid=>"1353746061.0", :x_agi_version=>"11.0.1", :x_agi_callerid=>"bob", :x_agi_calleridname=>"bob", :x_agi_callingpres=>"0", :x_agi_callingani2=>"0", :x_agi_callington=>"0", :x_agi_callingtns=>"0", :x_agi_dnid=>"111", :x_agi_rdnis=>"unknown", :x_agi_context=>"adhearsion", :x_agi_extension=>"111", :x_agi_priority=>"1", :x_agi_enhanced=>"0.0", :x_agi_accountcode=>"", :x_agi_threadid=>"-1234695312"}, call_id="05f6d01e-bd1a-4345-abc3-b13426db588e"

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Executing command #<Punchblock::Command::Answer headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [QUEUE]: Action: agi

ActionID: 94b3a52a-6b49-4378-af6c-d736701bd5e7

Channel: SIP/bob-00000000

Command: ANSWER

CommandID: 969d92d0-5cac-4933-b078-eefa1af9045f

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [SEND]: Action: agi

ActionID: 94b3a52a-6b49-4378-af6c-d736701bd5e7

Channel: SIP/bob-00000000

Command: ANSWER

CommandID: 969d92d0-5cac-4933-b078-eefa1af9045f

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [SEND] Action: agi

ActionID: 94b3a52a-6b49-4378-af6c-d736701bd5e7

Channel: SIP/bob-00000000

Command: ANSWER

CommandID: 969d92d0-5cac-4933-b078-eefa1af9045f

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] Response: Success

ActionID: 94b3a52a-6b49-4378-af6c-d736701bd5e7

Message: Added AGI command to queue

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"94b3a52a-6b49-4378-af6c-d736701bd5e7", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"94b3a52a-6b49-4378-af6c-d736701bd5e7", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

CommandId: 648333686

Command: ANSWER

Event: Newstate

Privilege: call,all

Channel: SIP/bob-00000000

ChannelState: 6

ChannelStateDesc: Up

CallerIDNum: bob

CallerIDName: bob

ConnectedLineNum:

ConnectedLineName:

Uniqueid: 1353746061.0

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"648333686", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"648333686", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/bob-00000000", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"bob", "CallerIDName"=>"bob", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1353746061.0"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

CommandId: 648333686

Command: ANSWER

ResultCode: 200

Result: Success

Event: AsyncAGI

Privilege: agi,all

SubEvent: Exec

Channel: SIP/bob-00000000

CommandID: 969d92d0-5cac-4933-b078-eefa1af9045f

Result: 200%20result%3D0%0A

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"648333686", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"648333686", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"969d92d0-5cac-4933-b078-eefa1af9045f", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"969d92d0-5cac-4933-b078-eefa1af9045f", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000000", :commandid=>"648333686", :command=>"ANSWER"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Newstate", attributes_hash={:privilege=>"call,all", :channel=>"SIP/bob-00000000", :channelstate=>"6", :channelstatedesc=>"Up", :calleridnum=>"bob", :calleridname=>"bob", :connectedlinenum=>"", :connectedlinename=>"", :uniqueid=>"1353746061.0"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Answered headers_hash={}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000000", :commandid=>"648333686", :command=>"ANSWER", :resultcode=>"200", :result=>"Success"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/bob-00000000", :commandid=>"969d92d0-5cac-4933-b078-eefa1af9045f", :result=>"200%20result%3D0%0A"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Executing command #<Punchblock::Component::Asterisk::AGI::Command name="asterisk-googletts/googletts.agi", params_array=["This is a simple google text to speech test in english.", "en"], target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [QUEUE]: Action: agi

ActionID: 57e438d8-58b2-4761-87cd-37f3ae68becd

Channel: SIP/bob-00000000

Command: asterisk-googletts/googletts.agi "This is a simple google text to speech test in english." "en"

CommandID: 76216ea8-740e-4bac-9094-8ca37976f12c

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [SEND]: Action: agi

ActionID: 57e438d8-58b2-4761-87cd-37f3ae68becd

Channel: SIP/bob-00000000

Command: asterisk-googletts/googletts.agi "This is a simple google text to speech test in english." "en"

CommandID: 76216ea8-740e-4bac-9094-8ca37976f12c

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [SEND] Action: agi

ActionID: 57e438d8-58b2-4761-87cd-37f3ae68becd

Channel: SIP/bob-00000000

Command: asterisk-googletts/googletts.agi "This is a simple google text to speech test in english." "en"

CommandID: 76216ea8-740e-4bac-9094-8ca37976f12c

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] Response: Success

ActionID: 57e438d8-58b2-4761-87cd-37f3ae68becd

Message: Added AGI command to queue

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"57e438d8-58b2-4761-87cd-37f3ae68becd", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"57e438d8-58b2-4761-87cd-37f3ae68becd", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] Event: AGIExec

Privilege: agi,all

SubEvent: Start

Channel: SIP/bob-00000000

CommandId: 720710419

Command: asterisk-googletts/googletts.agi "This is a simple google text to speech test in english." "en"

Event: AGIExec

Privilege: agi,all

SubEvent: End

Channel: SIP/bob-00000000

CommandId: 720710419

Command: asterisk-googletts/googletts.agi "This is a simple google text to speech test in english." "en"

ResultCode: 510

Result: Invalid or unknown command

Event: AsyncAGI

Privilege: agi,all

SubEvent: Exec

Channel: SIP/bob-00000000

CommandID: 76216ea8-740e-4bac-9094-8ca37976f12c

Result: 510%20Invalid%20or%20unknown%20command%0A

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"720710419", "Command"=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\""}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"720710419", "Command"=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\"", "ResultCode"=>"510", "Result"=>"Invalid or unknown command"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/bob-00000000", "CommandId"=>"720710419", "Command"=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\""}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/bob-00000000", "CommandId"=>"720710419", "Command"=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\"", "ResultCode"=>"510", "Result"=>"Invalid or unknown command"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/bob-00000000", :commandid=>"720710419", :command=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\""}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/bob-00000000", :commandid=>"720710419", :command=>"asterisk-googletts/googletts.agi \"This is a simple google text to speech test in english.\" \"en\"", :resultcode=>"510", :result=>"Invalid or unknown command"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"76216ea8-740e-4bac-9094-8ca37976f12c", "Result"=>"510%20Invalid%20or%20unknown%20command%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/bob-00000000", "CommandID"=>"76216ea8-740e-4bac-9094-8ca37976f12c", "Result"=>"510%20Invalid%20or%20unknown%20command%0A"}, text_body=nil, events=nil, action=nil>

[2012-11-24 17:34:22] ERROR Celluloid: Punchblock::Translator::Asterisk::Component::Asterisk::AGICommand crashed!

ArgumentError: The result string did not match the required format.

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/ruby_ami-1.2.5/lib/ruby_ami/agi_result_parser.rb:13:in `initialize'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `new'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `success_reason'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:25:in `handle_ami_event'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `dispatch'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/actor.rb:323:in `block in handle_message'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/tasks/task_fiber.rb:22:in `block in initialize'

[2012-11-24 17:34:22] ERROR Adhearsion::Initializer: <ArgumentError> The result string did not match the required format.

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/ruby_ami-1.2.5/lib/ruby_ami/agi_result_parser.rb:13:in `initialize'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `new'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:59:in `success_reason'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/punchblock-1.6.1/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:25:in `handle_ami_event'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/calls.rb:57:in `dispatch'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/actor.rb:323:in `block in handle_message'

/home/adhearsion/.rbenv/versions/1.9.3-p327/lib/ruby/gems/1.9.1/gems/celluloid-0.12.3/lib/celluloid/tasks/task_fiber.rb:22:in `block in initialize'

[2012-11-24 17:34:22] DEBUG Adhearsion::Call: 05f6d01e-bd1a-4345-abc3-b13426db588e: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/bob-00000000", :commandid=>"76216ea8-740e-4bac-9094-8ca37976f12c", :result=>"510%20Invalid%20or%20unknown%20command%0A"}, target_call_id="05f6d01e-bd1a-4345-abc3-b13426db588e", component_id=nil, target_mixer_name=nil>

[2012-11-24 17:34:22] ERROR Celluloid: Punchblock::Translator::Asterisk::Call crashed!