Skip to content

Instantly share code, notes, and snippets.

@benlangfeld
Created December 18, 2013 17:04
Show Gist options
  • Save benlangfeld/597662aaa5f2b3450cd6 to your computer and use it in GitHub Desktop.
Save benlangfeld/597662aaa5f2b3450cd6 to your computer and use it in GitHub Desktop.
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Timestamp: 1387386243.369257
Channel: SIP/192.168.1.126-00000008
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
AccountCode:
Exten: usera
Context: adhearsion
Uniqueid: 1387386243.12
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386243.369257
Channel: SIP/192.168.1.126-00000008
Variable: SIPURI
Value: sip:30128964@10.203.175.1:57994
Uniqueid: 1387386243.12
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386243.369257
Channel: SIP/192.168.1.126-00000008
Variable: SIPDOMAIN
Value: asterisk.local-dev.mojolingo.com
Uniqueid: 1387386243.12
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386243.369258
Channel: SIP/192.168.1.126-00000008
Variable: SIPCALLID
Value: yUV3Zo9c-9LIkZUi3vQZaTWZlI.rEe87
Uniqueid: 1387386243.12
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386243.369257", "Channel"=>"SIP/192.168.1.126-00000008", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "AccountCode"=>"", "Exten"=>"usera", "Context"=>"adhearsion", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386243.369257", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"SIPURI", "Value"=>"sip:30128964@10.203.175.1:57994", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386243.369257", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"SIPDOMAIN", "Value"=>"asterisk.local-dev.mojolingo.com", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386243.369258", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"SIPCALLID", "Value"=>"yUV3Zo9c-9LIkZUi3vQZaTWZlI.rEe87", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Timestamp: 1387386243.369258
Channel: SIP/192.168.1.126-00000008
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386243.12
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386243.369653
Channel: SIP/192.168.1.126-00000008
Context: adhearsion
Extension: usera
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386243.12
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386243.369842
SubEvent: Start
Channel: SIP/192.168.1.126-00000008
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000008%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386243.12%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20usera%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20usera%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20140706710189824%0A%0A
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386243.369258", "Channel"=>"SIP/192.168.1.126-00000008", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386243.369653", "Channel"=>"SIP/192.168.1.126-00000008", "Context"=>"adhearsion", "Extension"=>"usera", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.369842", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000008", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000008%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386243.12%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20usera%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20usera%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20140706710189824%0A%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: @: Receiving message: #<Punchblock::Event::Offer target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={"X-agi_request"=>"async", "X-agi_channel"=>"SIP/192.168.1.126-00000008", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386243.12", "X-agi_version"=>"11.6.0", "X-agi_callerid"=>"30128964", "X-agi_calleridname"=>"Ben Langfeld", "X-agi_callingpres"=>"0", "X-agi_callingani2"=>"0", "X-agi_callington"=>"0", "X-agi_callingtns"=>"0", "X-agi_dnid"=>"usera", "X-agi_rdnis"=>"unknown", "X-agi_context"=>"adhearsion", "X-agi_extension"=>"usera", "X-agi_priority"=>"1", "X-agi_enhanced"=>"0.0", "X-agi_accountcode"=>"", "X-agi_threadid"=>"140706710189824"}, to="usera", from="Ben Langfeld <SIP/30128964>">
[2013-12-18 15:04:03] INFO Adhearsion::Router: Call cc29af75-578f-4206-8c76-358c704635e4 selected route "default" (#<Proc:0x007fb8245adb40@/Users/ben/Desktop/foo/config/adhearsion.rb:30>)
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Executing command #<Punchblock::Command::Accept target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: ac964828-ff6e-498c-a296-1f8a828f0a2e
Channel: SIP/192.168.1.126-00000008
Command: EXEC RINGING
CommandID: c3f96812-a05f-428a-b73d-cfa9f1ef6c13
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] ActionID: ac964828-ff6e-498c-a296-1f8a828f0a2e
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"ac964828-ff6e-498c-a296-1f8a828f0a2e", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386243.470202
SubEvent: Start
Channel: SIP/192.168.1.126-00000008
CommandId: 52346296
Command: EXEC RINGING
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.470202", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"52346296", "Command"=>"EXEC RINGING"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386243.470783
SubEvent: End
Channel: SIP/192.168.1.126-00000008
CommandId: 52346296
Command: EXEC RINGING
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386243.470951
SubEvent: Exec
Channel: SIP/192.168.1.126-00000008
CommandID: c3f96812-a05f-428a-b73d-cfa9f1ef6c13
Result: 200%20result%3D0%0A
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.470783", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"52346296", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.470951", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000008", "CommandID"=>"c3f96812-a05f-428a-b73d-cfa9f1ef6c13", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.470202", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"52346296", "Command"=>"EXEC RINGING"}>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.470783", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"52346296", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.470951", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000008", "CommandID"=>"c3f96812-a05f-428a-b73d-cfa9f1ef6c13", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:04:03] INFO Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Executing controller #<Adhearsion::CallController call=cc29af75-578f-4206-8c76-358c704635e4, metadata={}>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Executing command #<Punchblock::Command::Answer target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Offer target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={"X-agi_request"=>"async", "X-agi_channel"=>"SIP/192.168.1.126-00000008", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386243.12", "X-agi_version"=>"11.6.0", "X-agi_callerid"=>"30128964", "X-agi_calleridname"=>"Ben Langfeld", "X-agi_callingpres"=>"0", "X-agi_callingani2"=>"0", "X-agi_callington"=>"0", "X-agi_callingtns"=>"0", "X-agi_dnid"=>"usera", "X-agi_rdnis"=>"unknown", "X-agi_context"=>"adhearsion", "X-agi_extension"=>"usera", "X-agi_priority"=>"1", "X-agi_enhanced"=>"0.0", "X-agi_accountcode"=>"", "X-agi_threadid"=>"140706710189824"}, to="usera", from="Ben Langfeld <SIP/30128964>">
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: 376cc27f-aada-40a3-96b6-b64efb8e2c13
Channel: SIP/192.168.1.126-00000008
Command: ANSWER
CommandID: 4af25d0a-6dff-47f9-8947-83e0550715ad
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] ActionID: 376cc27f-aada-40a3-96b6-b64efb8e2c13
Message: Added AGI command to queue
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"376cc27f-aada-40a3-96b6-b64efb8e2c13", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386243.571340
SubEvent: Start
Channel: SIP/192.168.1.126-00000008
CommandId: 137463263
Command: ANSWER
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.571340", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"137463263", "Command"=>"ANSWER"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Timestamp: 1387386243.571686
Channel: SIP/192.168.1.126-00000008
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386243.12
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386243.571686", "Channel"=>"SIP/192.168.1.126-00000008", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.571340", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"137463263", "Command"=>"ANSWER"}>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386243.574476
From: 10.203.175.1:50059
PT: 201(Receiver Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 0
SequenceNumberCycles: 0
IAJitter: 0
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386243.574476", "From"=>"10.203.175.1:50059", "PT"=>"201(Receiver Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"0", "SequenceNumberCycles"=>"0", "IAJitter"=>"0", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386243.571686", "Channel"=>"SIP/192.168.1.126-00000008", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386243.12"}>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Answered target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386243.590097
SubEvent: End
Channel: SIP/192.168.1.126-00000008
CommandId: 137463263
Command: ANSWER
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386243.590241
SubEvent: Exec
Channel: SIP/192.168.1.126-00000008
CommandID: 4af25d0a-6dff-47f9-8947-83e0550715ad
Result: 200%20result%3D0%0A
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.590097", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"137463263", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.590241", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000008", "CommandID"=>"4af25d0a-6dff-47f9-8947-83e0550715ad", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.590097", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000008", "CommandId"=>"137463263", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386243.590241", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000008", "CommandID"=>"4af25d0a-6dff-47f9-8947-83e0550715ad", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:04:03] INFO Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Controller terminating
[2013-12-18 15:04:03] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Finished executing controller #<Adhearsion::CallController call=cc29af75-578f-4206-8c76-358c704635e4, metadata={}>
[2013-12-18 15:04:03] INFO Adhearsion::Router::Route: Call routing completed, keeping the call alive at controller/router request.
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386249.023086
From: 10.203.175.1:50059
PT: 200(Sender Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 0
SequenceNumberCycles: 0
IAJitter: 0
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386249.023086", "From"=>"10.203.175.1:50059", "PT"=>"200(Sender Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"0", "SequenceNumberCycles"=>"0", "IAJitter"=>"0", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Timestamp: 1387386249.092215
Channel: SIP/192.168.1.126-00000009
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
AccountCode:
Exten: usera
Context: adhearsion
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.092241
Channel: SIP/192.168.1.126-00000009
Variable: SIPURI
Value: sip:30128964@10.203.175.1:57994
Uniqueid: 1387386249.13
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.092215", "Channel"=>"SIP/192.168.1.126-00000009", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "AccountCode"=>"", "Exten"=>"usera", "Context"=>"adhearsion", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.092241", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"SIPURI", "Value"=>"sip:30128964@10.203.175.1:57994", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.092245
Channel: SIP/192.168.1.126-00000009
Variable: SIPDOMAIN
Value: asterisk.local-dev.mojolingo.com
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.092247
Channel: SIP/192.168.1.126-00000009
Variable: SIPCALLID
Value: LxKVORpcgbdB3JnooGLGpAwdkF5yalkL
Uniqueid: 1387386249.13
Event: Newstate
Privilege: call,all
Timestamp: 1387386249.092374
Channel: SIP/192.168.1.126-00000009
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386249.13
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386249.093075
Channel: SIP/192.168.1.126-00000009
Context: adhearsion
Extension: usera
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386249.13
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386249.093262
SubEvent: Start
Channel: SIP/192.168.1.126-00000009
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000009%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386249.13%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20usera%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20usera%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20140706707494656%0A%0A
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.092245", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"SIPDOMAIN", "Value"=>"asterisk.local-dev.mojolingo.com", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.092247", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"SIPCALLID", "Value"=>"LxKVORpcgbdB3JnooGLGpAwdkF5yalkL", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.092374", "Channel"=>"SIP/192.168.1.126-00000009", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.093075", "Channel"=>"SIP/192.168.1.126-00000009", "Context"=>"adhearsion", "Extension"=>"usera", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.093262", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000009%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386249.13%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20usera%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20usera%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20140706707494656%0A%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:08] DEBUG Adhearsion::Call: @: Receiving message: #<Punchblock::Event::Offer target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={"X-agi_request"=>"async", "X-agi_channel"=>"SIP/192.168.1.126-00000009", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386249.13", "X-agi_version"=>"11.6.0", "X-agi_callerid"=>"30128964", "X-agi_calleridname"=>"Ben Langfeld", "X-agi_callingpres"=>"0", "X-agi_callingani2"=>"0", "X-agi_callington"=>"0", "X-agi_callingtns"=>"0", "X-agi_dnid"=>"usera", "X-agi_rdnis"=>"unknown", "X-agi_context"=>"adhearsion", "X-agi_extension"=>"usera", "X-agi_priority"=>"1", "X-agi_enhanced"=>"0.0", "X-agi_accountcode"=>"", "X-agi_threadid"=>"140706707494656"}, to="usera", from="Ben Langfeld <SIP/30128964>">
[2013-12-18 15:04:08] INFO Adhearsion::Router: Call 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820 selected route "default" (#<Proc:0x007fb8245adb40@/Users/ben/Desktop/foo/config/adhearsion.rb:30>)
[2013-12-18 15:04:08] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Executing command #<Punchblock::Command::Accept target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: 37841bf9-9a81-4b77-bd20-b48a38ebd29f
Channel: SIP/192.168.1.126-00000009
Command: EXEC RINGING
CommandID: 672b711b-07fc-44cc-84ff-db88df8ace7b
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] ActionID: 37841bf9-9a81-4b77-bd20-b48a38ebd29f
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"37841bf9-9a81-4b77-bd20-b48a38ebd29f", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386249.194550
SubEvent: Start
Channel: SIP/192.168.1.126-00000009
CommandId: 1895128072
Command: EXEC RINGING
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.194550", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1895128072", "Command"=>"EXEC RINGING"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386249.194991
SubEvent: End
Channel: SIP/192.168.1.126-00000009
CommandId: 1895128072
Command: EXEC RINGING
ResultCode: 200
Result: Success
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.194991", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1895128072", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386249.195157
SubEvent: Exec
Channel: SIP/192.168.1.126-00000009
CommandID: 672b711b-07fc-44cc-84ff-db88df8ace7b
Result: 200%20result%3D0%0A
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.195157", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000009", "CommandID"=>"672b711b-07fc-44cc-84ff-db88df8ace7b", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.194550", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1895128072", "Command"=>"EXEC RINGING"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.194991", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1895128072", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.195157", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000009", "CommandID"=>"672b711b-07fc-44cc-84ff-db88df8ace7b", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:04:09] INFO Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Executing controller #<Adhearsion::CallController call=2af8e8f3-07c6-4c8c-86b8-66bd6d65e820, metadata={}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Executing command #<Punchblock::Command::Answer target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Offer target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={"X-agi_request"=>"async", "X-agi_channel"=>"SIP/192.168.1.126-00000009", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386249.13", "X-agi_version"=>"11.6.0", "X-agi_callerid"=>"30128964", "X-agi_calleridname"=>"Ben Langfeld", "X-agi_callingpres"=>"0", "X-agi_callingani2"=>"0", "X-agi_callington"=>"0", "X-agi_callingtns"=>"0", "X-agi_dnid"=>"usera", "X-agi_rdnis"=>"unknown", "X-agi_context"=>"adhearsion", "X-agi_extension"=>"usera", "X-agi_priority"=>"1", "X-agi_enhanced"=>"0.0", "X-agi_accountcode"=>"", "X-agi_threadid"=>"140706707494656"}, to="usera", from="Ben Langfeld <SIP/30128964>">
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: ef5d8e40-c52c-48fc-b366-9131c7145d46
Channel: SIP/192.168.1.126-00000009
Command: ANSWER
CommandID: a8f12a05-f791-44a7-a8a3-18e77914b819
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] ActionID: ef5d8e40-c52c-48fc-b366-9131c7145d46
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"ef5d8e40-c52c-48fc-b366-9131c7145d46", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386249.295562
SubEvent: Start
Channel: SIP/192.168.1.126-00000009
CommandId: 1117686332
Command: ANSWER
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.295562", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1117686332", "Command"=>"ANSWER"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Timestamp: 1387386249.296159
Channel: SIP/192.168.1.126-00000009
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386249.13
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.296159", "Channel"=>"SIP/192.168.1.126-00000009", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.295562", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1117686332", "Command"=>"ANSWER"}>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386249.299636
From: 10.203.175.1:50061
PT: 201(Receiver Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 0
SequenceNumberCycles: 0
IAJitter: 0
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386249.299636", "From"=>"10.203.175.1:50061", "PT"=>"201(Receiver Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"0", "SequenceNumberCycles"=>"0", "IAJitter"=>"0", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.296159", "Channel"=>"SIP/192.168.1.126-00000009", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Answered target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386249.313302
SubEvent: End
Channel: SIP/192.168.1.126-00000009
CommandId: 1117686332
Command: ANSWER
ResultCode: 200
Result: Success
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.313302", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1117686332", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386249.313479
SubEvent: Exec
Channel: SIP/192.168.1.126-00000009
CommandID: a8f12a05-f791-44a7-a8a3-18e77914b819
Result: 200%20result%3D0%0A
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.313479", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000009", "CommandID"=>"a8f12a05-f791-44a7-a8a3-18e77914b819", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.313302", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"1117686332", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.313479", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000009", "CommandID"=>"a8f12a05-f791-44a7-a8a3-18e77914b819", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:04:09] INFO Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: We already have a call (cc29af75-578f-4206-8c76-358c704635e4). Lets join to it!
[2013-12-18 15:04:09] INFO Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Joining to cc29af75-578f-4206-8c76-358c704635e4
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Executing command #<Punchblock::Command::Join target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="cc29af75-578f-4206-8c76-358c704635e4", mixer_name=nil, direction=nil, media=nil>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: 563d35b5-3867-49ac-a2a1-ffb6001aef55
Channel: SIP/192.168.1.126-00000009
Command: EXEC Bridge "SIP/192.168.1.126-00000008"
CommandID: 9f76ce20-301c-433e-9498-8954da3faf34
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] ActionID: 563d35b5-3867-49ac-a2a1-ffb6001aef55
Message: Added AGI command to queue
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"563d35b5-3867-49ac-a2a1-ffb6001aef55", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386249.348275
SubEvent: Start
Channel: SIP/192.168.1.126-00000009
CommandId: 26979069
Command: EXEC Bridge "SIP/192.168.1.126-00000008"
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.348275", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"26979069", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000008\""}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Timestamp: 1387386249.348552
Channel: Bridge/SIP/192.168.1.126-00000008
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum:
CallerIDName:
AccountCode:
Exten:
Context:
Uniqueid: 1387386249.14
Event: MusicOnHold
Privilege: call,all
Timestamp: 1387386249.348644
State: Stop
Channel: SIP/192.168.1.126-00000008
UniqueID: 1387386243.12
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.348552", "Channel"=>"Bridge/SIP/192.168.1.126-00000008", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="MusicOnHold", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.348644", "State"=>"Stop", "Channel"=>"SIP/192.168.1.126-00000008", "UniqueID"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Timestamp: 1387386249.348786
Channel: Bridge/SIP/192.168.1.126-00000008
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum:
CallerIDName:
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386249.14
Event: Masquerade
Privilege: call,all
Timestamp: 1387386249.348997
Clone: SIP/192.168.1.126-00000008
CloneState: Up
Original: Bridge/SIP/192.168.1.126-00000008
OriginalState: Up
Event: Rename
Privilege: call,all
Timestamp: 1387386249.349126
Channel: SIP/192.168.1.126-00000008
Newname: SIP/192.168.1.126-00000008<MASQ>
Uniqueid: 1387386243.12
Event: Rename
Privilege: call,all
Timestamp: 1387386249.349197
Channel: Bridge/SIP/192.168.1.126-00000008
Newname: SIP/192.168.1.126-00000008
Uniqueid: 1387386249.14
Event: Rename
Privilege: call,all
Timestamp: 1387386249.349378
Channel: SIP/192.168.1.126-00000008<MASQ>
Newname: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Uniqueid: 1387386243.12
Event: NewCallerid
Privilege: call,all
Timestamp: 1387386249.349465
Channel: SIP/192.168.1.126-00000008
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
Uniqueid: 1387386249.14
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386249.349640
SubEvent: End
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.349660
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386243.12
Event: SoftHangupRequest
Privilege: call,all
Timestamp: 1387386249.349677
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Uniqueid: 1387386243.12
Cause: 16
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386249.349691
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Context: adhearsion
Extension: h
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386243.12
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386249.349736
SubEvent: Start
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Env: agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2F192.168.1.126-00000008%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201387386243.12%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%20unknown%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%2067%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%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%20140706710189824%0A%0A
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.348786", "Channel"=>"Bridge/SIP/192.168.1.126-00000008", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Masquerade", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.348997", "Clone"=>"SIP/192.168.1.126-00000008", "CloneState"=>"Up", "Original"=>"Bridge/SIP/192.168.1.126-00000008", "OriginalState"=>"Up"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.348275", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"26979069", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000008\""}>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.349126", "Channel"=>"SIP/192.168.1.126-00000008", "Newname"=>"SIP/192.168.1.126-00000008<MASQ>", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.349197", "Channel"=>"Bridge/SIP/192.168.1.126-00000008", "Newname"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.349378", "Channel"=>"SIP/192.168.1.126-00000008<MASQ>", "Newname"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="MusicOnHold", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.348644", "State"=>"Stop", "Channel"=>"SIP/192.168.1.126-00000008", "UniqueID"=>"1387386243.12"}>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.349465", "Channel"=>"SIP/192.168.1.126-00000008", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "Uniqueid"=>"1387386249.14", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.349640", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.349660", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.349677", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Uniqueid"=>"1387386243.12", "Cause"=>"16"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.349691", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.349736", "SubEvent"=>"Start", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2F192.168.1.126-00000008%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201387386243.12%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%20unknown%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%2067%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%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%20140706710189824%0A%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386249.349740
SubEvent: End
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.349746
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386243.12
Event: Hangup
Privilege: call,all
Timestamp: 1387386249.350242
Channel: Bridge/SIP/192.168.1.126-00000008<ZOMBIE>
Uniqueid: 1387386243.12
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown
Event: BridgeExec
Privilege: call,all
Timestamp: 1387386249.350396
Response: Success
Channel1: SIP/192.168.1.126-00000009
Channel2: SIP/192.168.1.126-00000008
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.350533
Channel: SIP/192.168.1.126-00000009
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000008
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.350619
Channel: SIP/192.168.1.126-00000008
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000009
Uniqueid: 1387386249.14
Event: NewAccountCode
Privilege: call,all
Timestamp: 1387386249.350749
Channel: SIP/192.168.1.126-00000008
Uniqueid: 1387386249.14
AccountCode:
OldAccountCode:
Event: Bridge
Privilege: call,all
Timestamp: 1387386249.350883
Bridgestate: Link
Bridgetype: core
Channel1: SIP/192.168.1.126-00000009
Channel2: SIP/192.168.1.126-00000008
Uniqueid1: 1387386249.13
Uniqueid2: 1387386249.14
CallerID1: 30128964
CallerID2: 30128964
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.351011
Channel: SIP/192.168.1.126-00000009
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000008
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.351168
Channel: SIP/192.168.1.126-00000009
Variable: BRIDGEPVTCALLID
Value: yUV3Zo9c-9LIkZUi3vQZaTWZlI.rEe87
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.351240
Channel: SIP/192.168.1.126-00000008
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000009
Uniqueid: 1387386249.14
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386249.351424
Channel: SIP/192.168.1.126-00000008
Variable: BRIDGEPVTCALLID
Value: LxKVORpcgbdB3JnooGLGpAwdkF5yalkL
Uniqueid: 1387386249.14
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.349740", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.349126", "Channel"=>"SIP/192.168.1.126-00000008", "Newname"=>"SIP/192.168.1.126-00000008<MASQ>", "Uniqueid"=>"1387386243.12"}>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.349746", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386243.12"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350242", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Uniqueid"=>"1387386243.12", "CallerIDNum"=>"<unknown>", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="BridgeExec", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350396", "Response"=>"Success", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.350533", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.350619", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350749", "Channel"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.14", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350883", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008", "Uniqueid1"=>"1387386249.13", "Uniqueid2"=>"1387386249.14", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351011", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351168", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"yUV3Zo9c-9LIkZUi3vQZaTWZlI.rEe87", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351240", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351424", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"LxKVORpcgbdB3JnooGLGpAwdkF5yalkL", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="NewCallerid", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.349465", "Channel"=>"SIP/192.168.1.126-00000008", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "Uniqueid"=>"1387386249.14", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.349640", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.349736", "SubEvent"=>"Start", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2F192.168.1.126-00000008%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201387386243.12%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%20unknown%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%2067%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%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%20140706710189824%0A%0A"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386249.349740", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000008<ZOMBIE>"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="BridgeExec", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350396", "Response"=>"Success", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="BridgeExec", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350396", "Response"=>"Success", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.350533", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.350619", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="NewAccountCode", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350749", "Channel"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.14", "AccountCode"=>"", "OldAccountCode"=>""}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350883", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008", "Uniqueid1"=>"1387386249.13", "Uniqueid2"=>"1387386249.14", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386249.350883", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008", "Uniqueid1"=>"1387386249.13", "Uniqueid2"=>"1387386249.14", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351011", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351168", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"yUV3Zo9c-9LIkZUi3vQZaTWZlI.rEe87", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351240", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386249.351424", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"LxKVORpcgbdB3JnooGLGpAwdkF5yalkL", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Joined target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", mixer_name=nil>
[2013-12-18 15:04:09] INFO Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Joined to call 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820
[2013-12-18 15:04:09] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Joined target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="cc29af75-578f-4206-8c76-358c704635e4", mixer_name=nil>
[2013-12-18 15:04:09] INFO Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Joined to call cc29af75-578f-4206-8c76-358c704635e4
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386249.546006
From: 10.203.175.1:50061
PT: 200(Sender Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 24082
SequenceNumberCycles: 0
IAJitter: 0
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:04:09] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386249.546006", "From"=>"10.203.175.1:50061", "PT"=>"200(Sender Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"24082", "SequenceNumberCycles"=>"0", "IAJitter"=>"0", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665493
Channel: SIP/192.168.1.126-00000008
Variable: RTPAUDIOQOS
Value: ssrc=1127457931;themssrc=29401307;lp=0;rxjitter=0.004789;rxcount=289;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386249.14
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665507
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOSBRIDGED
Value: ssrc=1127457931;themssrc=29401307;lp=0;rxjitter=0.004789;rxcount=289;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386249.13
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665493", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1127457931;themssrc=29401307;lp=0;rxjitter=0.004789;rxcount=289;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665507", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=1127457931;themssrc=29401307;lp=0;rxjitter=0.004789;rxcount=289;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665512
Channel: SIP/192.168.1.126-00000008
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: 1387386249.14
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665515
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOSJITTERBRIDGED
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: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665519
Channel: SIP/192.168.1.126-00000008
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: 1387386249.14
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665522
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOSLOSSBRIDGED
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: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665526
Channel: SIP/192.168.1.126-00000008
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386249.14
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665528
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOSRTTBRIDGED
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665532
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOS
Value: ssrc=897891596;themssrc=958252073;lp=0;rxjitter=0.000771;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665535
Channel: SIP/192.168.1.126-00000008
Variable: RTPAUDIOQOSBRIDGED
Value: ssrc=897891596;themssrc=958252073;lp=0;rxjitter=0.000771;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386249.14
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665512", "Channel"=>"SIP/192.168.1.126-00000008", "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"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665515", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "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"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665519", "Channel"=>"SIP/192.168.1.126-00000008", "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"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665522", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "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"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665526", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665528", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665532", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=897891596;themssrc=958252073;lp=0;rxjitter=0.000771;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665535", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=897891596;themssrc=958252073;lp=0;rxjitter=0.000771;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665493", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1127457931;themssrc=29401307;lp=0;rxjitter=0.004789;rxcount=289;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665507", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=1127457931;themssrc=29401307;lp=0;rxjitter=0.004789;rxcount=289;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665539
Channel: SIP/192.168.1.126-00000009
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: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665542
Channel: SIP/192.168.1.126-00000008
Variable: RTPAUDIOQOSJITTERBRIDGED
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: 1387386249.14
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665546
Channel: SIP/192.168.1.126-00000009
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: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665548
Channel: SIP/192.168.1.126-00000008
Variable: RTPAUDIOQOSLOSSBRIDGED
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: 1387386249.14
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665551
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.665553
Channel: SIP/192.168.1.126-00000008
Variable: RTPAUDIOQOSRTTBRIDGED
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386249.14
Event: HangupRequest
Privilege: call,all
Timestamp: 1387386253.665560
Channel: SIP/192.168.1.126-00000008
Uniqueid: 1387386249.14
Event: Bridge
Privilege: call,all
Timestamp: 1387386253.667976
Bridgestate: Unlink
Bridgetype: core
Channel1: SIP/192.168.1.126-00000009
Channel2: SIP/192.168.1.126-00000008
Uniqueid1: 1387386249.13
Uniqueid2: 1387386249.14
CallerID1: 30128964
CallerID2: 30128964
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386253.668006
Channel: SIP/192.168.1.126-00000009
Variable: BRIDGERESULT
Value: SUCCESS
Uniqueid: 1387386249.13
Event: Hangup
Privilege: call,all
Timestamp: 1387386253.668381
Channel: SIP/192.168.1.126-00000008
Uniqueid: 1387386249.14
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown
Event: AGIExec
Privilege: agi,all
Timestamp: 1387386253.668633
SubEvent: End
Channel: SIP/192.168.1.126-00000009
CommandId: 26979069
Command: EXEC Bridge "SIP/192.168.1.126-00000008"
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386253.668648
SubEvent: Exec
Channel: SIP/192.168.1.126-00000009
CommandID: 9f76ce20-301c-433e-9498-8954da3faf34
Result: 200%20result%3D0%0A
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665539", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665542", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "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"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665546", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665548", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "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"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665551", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665553", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665512", "Channel"=>"SIP/192.168.1.126-00000008", "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"=>"1387386249.14"}>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="HangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386253.665560", "Channel"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.14"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386253.667976", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008", "Uniqueid1"=>"1387386249.13", "Uniqueid2"=>"1387386249.14", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.668006", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386253.668381", "Channel"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.14", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386253.668633", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"26979069", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000008\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386253.668648", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000009", "CommandID"=>"9f76ce20-301c-433e-9498-8954da3faf34", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665515", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "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"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665519", "Channel"=>"SIP/192.168.1.126-00000008", "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"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665522", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "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"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665526", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665528", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665535", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=897891596;themssrc=958252073;lp=0;rxjitter=0.000771;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665532", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=897891596;themssrc=958252073;lp=0;rxjitter=0.000771;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665539", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665542", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "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"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665546", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665551", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665548", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "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"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.665553", "Channel"=>"SIP/192.168.1.126-00000008", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386253.667976", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008", "Uniqueid1"=>"1387386249.13", "Uniqueid2"=>"1387386249.14", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="HangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386253.665560", "Channel"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.14"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386253.667976", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000009", "Channel2"=>"SIP/192.168.1.126-00000008", "Uniqueid1"=>"1387386249.13", "Uniqueid2"=>"1387386249.14", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:04:13] WARN Celluloid: Terminating task: type=:call, meta={:method_name=>:process_ami_event}, status=:callwait
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386253.668006", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386253.668381", "Channel"=>"SIP/192.168.1.126-00000008", "Uniqueid"=>"1387386249.14", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386253.668633", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009", "CommandId"=>"26979069", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000008\"", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386253.668648", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000009", "CommandID"=>"9f76ce20-301c-433e-9498-8954da3faf34", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Unjoined target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="cc29af75-578f-4206-8c76-358c704635e4", mixer_name=nil>
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::End target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}, reason=:hangup, platform_code="0">
[2013-12-18 15:04:13] INFO Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Unjoined from call cc29af75-578f-4206-8c76-358c704635e4
[2013-12-18 15:04:13] INFO Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Call ended due to hangup
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Receiving message: #<Punchblock::Event::Unjoined target_call_id="cc29af75-578f-4206-8c76-358c704635e4", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", mixer_name=nil>
[2013-12-18 15:04:13] INFO Adhearsion::Call: cc29af75-578f-4206-8c76-358c704635e4@: Unjoined from call 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820
[2013-12-18 15:04:13] INFO Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Controller terminating
[2013-12-18 15:04:13] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Finished executing controller #<Adhearsion::CallController call=2af8e8f3-07c6-4c8c-86b8-66bd6d65e820, metadata={}>
[2013-12-18 15:04:13] INFO Adhearsion::Router::Route: Call routing completed, keeping the call alive at controller/router request.
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386253.864534
From: 10.203.175.1:50061
PT: 200(Sender Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 24287
SequenceNumberCycles: 0
IAJitter: 38
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:04:13] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386253.864534", "From"=>"10.203.175.1:50061", "PT"=>"200(Sender Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"24287", "SequenceNumberCycles"=>"0", "IAJitter"=>"38", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:04:18] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386258.427149
From: 10.203.175.1:50061
PT: 200(Sender Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 24287
SequenceNumberCycles: 0
IAJitter: 38
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:04:18] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386258.427149", "From"=>"10.203.175.1:50061", "PT"=>"200(Sender Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"24287", "SequenceNumberCycles"=>"0", "IAJitter"=>"38", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386261.668437
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOS
Value: ssrc=897891596;themssrc=958252073;lp=216;rxjitter=0.004679;rxcount=403;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386249.13
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668437", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=897891596;themssrc=958252073;lp=216;rxjitter=0.004679;rxcount=403;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386261.668452
Channel: SIP/192.168.1.126-00000009
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: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386261.668457
Channel: SIP/192.168.1.126-00000009
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: 1387386249.13
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386261.668461
Channel: SIP/192.168.1.126-00000009
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386249.13
Event: HangupRequest
Privilege: call,all
Timestamp: 1387386261.668470
Channel: SIP/192.168.1.126-00000009
Uniqueid: 1387386249.13
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668452", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668457", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668461", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="HangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386261.668470", "Channel"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386261.669311
SubEvent: End
Channel: SIP/192.168.1.126-00000009
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386261.669339
Channel: SIP/192.168.1.126-00000009
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386249.13
Event: SoftHangupRequest
Privilege: call,all
Timestamp: 1387386261.669364
Channel: SIP/192.168.1.126-00000009
Uniqueid: 1387386249.13
Cause: 16
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386261.669379
Channel: SIP/192.168.1.126-00000009
Context: adhearsion
Extension: h
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386249.13
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386261.669425
SubEvent: Start
Channel: SIP/192.168.1.126-00000009
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000009%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386249.13%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20usera%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%20140706707494656%0A%0A
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386261.669432
SubEvent: End
Channel: SIP/192.168.1.126-00000009
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386261.669438
Channel: SIP/192.168.1.126-00000009
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386249.13
Event: Hangup
Privilege: call,all
Timestamp: 1387386261.669459
Channel: SIP/192.168.1.126-00000009
Uniqueid: 1387386249.13
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386261.669311", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.669339", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668437", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=897891596;themssrc=958252073;lp=216;rxjitter=0.004679;rxcount=403;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386261.669364", "Channel"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.13", "Cause"=>"16"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.669379", "Channel"=>"SIP/192.168.1.126-00000009", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386261.669425", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000009%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386249.13%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20usera%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%20140706707494656%0A%0A"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386261.669432", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.669438", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386249.13"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386261.669459", "Channel"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.13", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=[]>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668452", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668457", "Channel"=>"SIP/192.168.1.126-00000009", "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"=>"1387386249.13"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.668461", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="HangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386261.668470", "Channel"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386261.669311", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.669339", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386261.669364", "Channel"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.13", "Cause"=>"16"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.669379", "Channel"=>"SIP/192.168.1.126-00000009", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386261.669425", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000009", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000009%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386249.13%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20usera%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%20140706707494656%0A%0A"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386261.669432", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000009"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386261.669438", "Channel"=>"SIP/192.168.1.126-00000009", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386249.13"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386261.669459", "Channel"=>"SIP/192.168.1.126-00000009", "Uniqueid"=>"1387386249.13", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}>
[2013-12-18 15:04:21] DEBUG Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Receiving message: #<Punchblock::Event::End target_call_id="2af8e8f3-07c6-4c8c-86b8-66bd6d65e820", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}, reason=:hangup, platform_code="0">
[2013-12-18 15:04:21] INFO Adhearsion::Call: 2af8e8f3-07c6-4c8c-86b8-66bd6d65e820@: Call ended due to hangup
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment