Skip to content

Instantly share code, notes, and snippets.

@benlangfeld

benlangfeld/gist:ea9ef8a68194d7b45d01 Secret

Created December 18, 2013 17:01
Show Gist options
  • Save benlangfeld/ea9ef8a68194d7b45d01 to your computer and use it in GitHub Desktop.
Save benlangfeld/ea9ef8a68194d7b45d01 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
gistfile1.txt
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Timestamp: 1387386061.940307
Channel: SIP/192.168.1.126-00000006
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
AccountCode:
Exten: usera
Context: adhearsion
Uniqueid: 1387386061.9
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386061.940332
Channel: SIP/192.168.1.126-00000006
Variable: SIPURI
Value: sip:30128964@10.203.175.1:57994
Uniqueid: 1387386061.9
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386061.940336
Channel: SIP/192.168.1.126-00000006
Variable: SIPDOMAIN
Value: asterisk.local-dev.mojolingo.com
Uniqueid: 1387386061.9
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386061.940338
Channel: SIP/192.168.1.126-00000006
Variable: SIPCALLID
Value: b1c.RsTfGfPM94X-kQA5ZK0f3UousMjI
Uniqueid: 1387386061.9
Event: Newstate
Privilege: call,all
Timestamp: 1387386061.940456
Channel: SIP/192.168.1.126-00000006
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386061.9
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386061.940307", "Channel"=>"SIP/192.168.1.126-00000006", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "AccountCode"=>"", "Exten"=>"usera", "Context"=>"adhearsion", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386061.940332", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"SIPURI", "Value"=>"sip:30128964@10.203.175.1:57994", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386061.940336", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"SIPDOMAIN", "Value"=>"asterisk.local-dev.mojolingo.com", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386061.940338", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"SIPCALLID", "Value"=>"b1c.RsTfGfPM94X-kQA5ZK0f3UousMjI", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386061.940456", "Channel"=>"SIP/192.168.1.126-00000006", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386061.940913
Channel: SIP/192.168.1.126-00000006
Context: adhearsion
Extension: usera
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386061.9
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386061.941092
SubEvent: Start
Channel: SIP/192.168.1.126-00000006
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000006%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386061.9%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:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386061.940913", "Channel"=>"SIP/192.168.1.126-00000006", "Context"=>"adhearsion", "Extension"=>"usera", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386061.941092", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000006", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000006%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386061.9%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:01:01] DEBUG Adhearsion::Call: @: Receiving message: #<Punchblock::Event::Offer target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", 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-00000006", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386061.9", "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:01:01] INFO Adhearsion::Router: Call 2b78b186-9364-4e53-ac0a-c82e89802924 selected route "default" (#<Proc:0x007fb8245adb40@/Users/ben/Desktop/foo/config/adhearsion.rb:30>)
[2013-12-18 15:01:01] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: 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:01:01] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: d22a7451-9fb6-438a-8a47-ed0f4ed7cb96
Channel: SIP/192.168.1.126-00000006
Command: EXEC RINGING
CommandID: 1cad5fe3-e57c-4b84-939d-4d7cdc2c6d06
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: d22a7451-9fb6-438a-8a47-ed0f4ed7cb96
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"d22a7451-9fb6-438a-8a47-ed0f4ed7cb96", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386062.041462
SubEvent: Start
Channel: SIP/192.168.1.126-00000006
CommandId: 1191320511
Command: EXEC RINGING
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.041462", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"1191320511", "Command"=>"EXEC RINGING"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386062.042005
SubEvent: End
Channel: SIP/192.168.1.126-00000006
CommandId: 1191320511
Command: EXEC RINGING
ResultCode: 200
Result: Success
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.042005", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"1191320511", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386062.042309
SubEvent: Exec
Channel: SIP/192.168.1.126-00000006
CommandID: 1cad5fe3-e57c-4b84-939d-4d7cdc2c6d06
Result: 200%20result%3D0%0A
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.042309", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000006", "CommandID"=>"1cad5fe3-e57c-4b84-939d-4d7cdc2c6d06", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:01:01] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.041462", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"1191320511", "Command"=>"EXEC RINGING"}>
[2013-12-18 15:01:01] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.042005", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"1191320511", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:01:01] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.042309", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000006", "CommandID"=>"1cad5fe3-e57c-4b84-939d-4d7cdc2c6d06", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:01:01] INFO Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Executing controller #<Adhearsion::CallController call=2b78b186-9364-4e53-ac0a-c82e89802924, metadata={}>
[2013-12-18 15:01:01] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: 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:01:01] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Offer target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", 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-00000006", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386061.9", "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:01:01] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: 956806a5-bdd0-40fa-84db-01eb8ac15072
Channel: SIP/192.168.1.126-00000006
Command: ANSWER
CommandID: 3d41f114-5eff-4740-869d-0bab6d6aaf72
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 956806a5-bdd0-40fa-84db-01eb8ac15072
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:01:01] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"956806a5-bdd0-40fa-84db-01eb8ac15072", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:01:02] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386062.142781
SubEvent: Start
Channel: SIP/192.168.1.126-00000006
CommandId: 857421118
Command: ANSWER
[2013-12-18 15:01:02] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.142781", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"857421118", "Command"=>"ANSWER"}, text_body=nil, events=[]>
[2013-12-18 15:01:02] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Timestamp: 1387386062.143183
Channel: SIP/192.168.1.126-00000006
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386061.9
Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386062.146835
From: 10.203.175.1:50055
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)
Event: AGIExec
Privilege: agi,all
Timestamp: 1387386062.155622
SubEvent: End
Channel: SIP/192.168.1.126-00000006
CommandId: 857421118
Command: ANSWER
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386062.155761
SubEvent: Exec
Channel: SIP/192.168.1.126-00000006
CommandID: 3d41f114-5eff-4740-869d-0bab6d6aaf72
Result: 200%20result%3D0%0A
[2013-12-18 15:01:02] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386062.143183", "Channel"=>"SIP/192.168.1.126-00000006", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:02] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386062.146835", "From"=>"10.203.175.1:50055", "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:01:02] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.155622", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"857421118", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:01:02] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.155761", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000006", "CommandID"=>"3d41f114-5eff-4740-869d-0bab6d6aaf72", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:01:02] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.142781", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"857421118", "Command"=>"ANSWER"}>
[2013-12-18 15:01:02] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386062.143183", "Channel"=>"SIP/192.168.1.126-00000006", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386061.9"}>
[2013-12-18 15:01:02] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.155622", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000006", "CommandId"=>"857421118", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:01:02] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Answered target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:01:02] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386062.155761", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000006", "CommandID"=>"3d41f114-5eff-4740-869d-0bab6d6aaf72", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:01:02] INFO Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Controller terminating
[2013-12-18 15:01:02] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Finished executing controller #<Adhearsion::CallController call=2b78b186-9364-4e53-ac0a-c82e89802924, metadata={}>
[2013-12-18 15:01:02] INFO Adhearsion::Router::Route: Call routing completed, keeping the call alive at controller/router request.
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Timestamp: 1387386065.422975
Channel: SIP/192.168.1.126-00000007
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
AccountCode:
Exten: usera
Context: adhearsion
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.423001
Channel: SIP/192.168.1.126-00000007
Variable: SIPURI
Value: sip:30128964@10.203.175.1:57994
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.423004
Channel: SIP/192.168.1.126-00000007
Variable: SIPDOMAIN
Value: asterisk.local-dev.mojolingo.com
Uniqueid: 1387386065.10
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.422975", "Channel"=>"SIP/192.168.1.126-00000007", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "AccountCode"=>"", "Exten"=>"usera", "Context"=>"adhearsion", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.423001", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"SIPURI", "Value"=>"sip:30128964@10.203.175.1:57994", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.423004", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"SIPDOMAIN", "Value"=>"asterisk.local-dev.mojolingo.com", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.423006
Channel: SIP/192.168.1.126-00000007
Variable: SIPCALLID
Value: 56RKM.G28DB-BsPKGOLEnFQgDIb4rYhQ
Uniqueid: 1387386065.10
Event: Newstate
Privilege: call,all
Timestamp: 1387386065.423483
Channel: SIP/192.168.1.126-00000007
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386065.10
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386065.423684
Channel: SIP/192.168.1.126-00000007
Context: adhearsion
Extension: usera
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386065.10
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386065.423822
SubEvent: Start
Channel: SIP/192.168.1.126-00000007
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000007%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.10%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:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.423006", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"SIPCALLID", "Value"=>"56RKM.G28DB-BsPKGOLEnFQgDIb4rYhQ", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.423483", "Channel"=>"SIP/192.168.1.126-00000007", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.423684", "Channel"=>"SIP/192.168.1.126-00000007", "Context"=>"adhearsion", "Extension"=>"usera", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.423822", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000007%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.10%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:01:05] DEBUG Adhearsion::Call: @: Receiving message: #<Punchblock::Event::Offer target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", 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-00000007", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386065.10", "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:01:05] INFO Adhearsion::Router: Call 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b selected route "default" (#<Proc:0x007fb8245adb40@/Users/ben/Desktop/foo/config/adhearsion.rb:30>)
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: 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:01:05] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: a439b3a4-d441-44e1-8f7c-46e3a71c81cb
Channel: SIP/192.168.1.126-00000007
Command: EXEC RINGING
CommandID: 7b40052d-3e41-4140-9fca-58ff24099099
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: a439b3a4-d441-44e1-8f7c-46e3a71c81cb
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"a439b3a4-d441-44e1-8f7c-46e3a71c81cb", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386065.524972
SubEvent: Start
Channel: SIP/192.168.1.126-00000007
CommandId: 717931569
Command: EXEC RINGING
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.524972", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"717931569", "Command"=>"EXEC RINGING"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386065.525682
SubEvent: End
Channel: SIP/192.168.1.126-00000007
CommandId: 717931569
Command: EXEC RINGING
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386065.525761
SubEvent: Exec
Channel: SIP/192.168.1.126-00000007
CommandID: 7b40052d-3e41-4140-9fca-58ff24099099
Result: 200%20result%3D0%0A
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.525682", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"717931569", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.525761", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000007", "CommandID"=>"7b40052d-3e41-4140-9fca-58ff24099099", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.524972", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"717931569", "Command"=>"EXEC RINGING"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.525682", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"717931569", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.525761", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000007", "CommandID"=>"7b40052d-3e41-4140-9fca-58ff24099099", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:01:05] INFO Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Executing controller #<Adhearsion::CallController call=31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b, metadata={}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: 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:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Offer target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", 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-00000007", "X-agi_language"=>"en", "X-agi_type"=>"SIP", "X-agi_uniqueid"=>"1387386065.10", "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:01:05] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: 696bb0ed-2f19-4b2d-b8e0-638630f0b4e2
Channel: SIP/192.168.1.126-00000007
Command: ANSWER
CommandID: d22c898c-8bef-4ef7-98c2-b60ec7e768af
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] ActionID: 696bb0ed-2f19-4b2d-b8e0-638630f0b4e2
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"696bb0ed-2f19-4b2d-b8e0-638630f0b4e2", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386065.626655
SubEvent: Start
Channel: SIP/192.168.1.126-00000007
CommandId: 745271792
Command: ANSWER
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.626655", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"745271792", "Command"=>"ANSWER"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Timestamp: 1387386065.627028
Channel: SIP/192.168.1.126-00000007
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386065.10
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.627028", "Channel"=>"SIP/192.168.1.126-00000007", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386065.630254
From: 10.203.175.1:50057
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)
Event: AGIExec
Privilege: agi,all
Timestamp: 1387386065.638564
SubEvent: End
Channel: SIP/192.168.1.126-00000007
CommandId: 745271792
Command: ANSWER
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386065.638765
SubEvent: Exec
Channel: SIP/192.168.1.126-00000007
CommandID: d22c898c-8bef-4ef7-98c2-b60ec7e768af
Result: 200%20result%3D0%0A
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386065.630254", "From"=>"10.203.175.1:50057", "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:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.638564", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"745271792", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.638765", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000007", "CommandID"=>"d22c898c-8bef-4ef7-98c2-b60ec7e768af", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.626655", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"745271792", "Command"=>"ANSWER"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.627028", "Channel"=>"SIP/192.168.1.126-00000007", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.638564", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"745271792", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.638765", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000007", "CommandID"=>"d22c898c-8bef-4ef7-98c2-b60ec7e768af", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Answered target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}>
[2013-12-18 15:01:05] INFO Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: We already have a call (2b78b186-9364-4e53-ac0a-c82e89802924). Lets join to it!
[2013-12-18 15:01:05] INFO Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Joining to 2b78b186-9364-4e53-ac0a-c82e89802924
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: 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="2b78b186-9364-4e53-ac0a-c82e89802924", mixer_name=nil, direction=nil, media=nil>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: 634cb5d2-f618-484b-bc01-75074f359df7
Channel: SIP/192.168.1.126-00000007
Command: EXEC Bridge "SIP/192.168.1.126-00000006"
CommandID: 50216ae7-7c86-4363-93bf-c8c71a2204b3
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 634cb5d2-f618-484b-bc01-75074f359df7
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Message: Added AGI command to queue
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"634cb5d2-f618-484b-bc01-75074f359df7", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
Timestamp: 1387386065.672960
SubEvent: Start
Channel: SIP/192.168.1.126-00000007
CommandId: 394223285
Command: EXEC Bridge "SIP/192.168.1.126-00000006"
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.672960", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"394223285", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000006\""}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Timestamp: 1387386065.673234
Channel: Bridge/SIP/192.168.1.126-00000006
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum:
CallerIDName:
AccountCode:
Exten:
Context:
Uniqueid: 1387386065.11
Event: MusicOnHold
Privilege: call,all
Timestamp: 1387386065.673316
State: Stop
Channel: SIP/192.168.1.126-00000006
UniqueID: 1387386061.9
Event: Newstate
Privilege: call,all
Timestamp: 1387386065.673475
Channel: Bridge/SIP/192.168.1.126-00000006
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum:
CallerIDName:
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1387386065.11
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673234", "Channel"=>"Bridge/SIP/192.168.1.126-00000006", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.672960", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"394223285", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000006\""}>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="MusicOnHold", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673316", "State"=>"Stop", "Channel"=>"SIP/192.168.1.126-00000006", "UniqueID"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673475", "Channel"=>"Bridge/SIP/192.168.1.126-00000006", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Masquerade
Privilege: call,all
Timestamp: 1387386065.673718
Clone: SIP/192.168.1.126-00000006
CloneState: Up
Original: Bridge/SIP/192.168.1.126-00000006
OriginalState: Up
Event: Rename
Privilege: call,all
Timestamp: 1387386065.673846
Channel: SIP/192.168.1.126-00000006
Newname: SIP/192.168.1.126-00000006<MASQ>
Uniqueid: 1387386061.9
Event: Rename
Privilege: call,all
Timestamp: 1387386065.673967
Channel: Bridge/SIP/192.168.1.126-00000006
Newname: SIP/192.168.1.126-00000006
Uniqueid: 1387386065.11
Event: Rename
Privilege: call,all
Timestamp: 1387386065.674098
Channel: SIP/192.168.1.126-00000006<MASQ>
Newname: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Uniqueid: 1387386061.9
Event: NewCallerid
Privilege: call,all
Timestamp: 1387386065.674228
Channel: SIP/192.168.1.126-00000006
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
Uniqueid: 1387386065.11
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386065.674436
SubEvent: End
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.674462
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386061.9
Event: SoftHangupRequest
Privilege: call,all
Timestamp: 1387386065.674484
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Uniqueid: 1387386061.9
Cause: 16
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386065.674498
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Context: adhearsion
Extension: h
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386061.9
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386065.674544
SubEvent: Start
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Env: agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2F192.168.1.126-00000006%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201387386061.9%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
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386065.674550
SubEvent: End
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.674555
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386061.9
Event: Hangup
Privilege: call,all
Timestamp: 1387386065.675287
Channel: Bridge/SIP/192.168.1.126-00000006<ZOMBIE>
Uniqueid: 1387386061.9
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown
Event: BridgeExec
Privilege: call,all
Timestamp: 1387386065.675464
Response: Success
Channel1: SIP/192.168.1.126-00000007
Channel2: SIP/192.168.1.126-00000006
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.675659
Channel: SIP/192.168.1.126-00000007
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000006
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.675782
Channel: SIP/192.168.1.126-00000006
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000007
Uniqueid: 1387386065.11
Event: NewAccountCode
Privilege: call,all
Timestamp: 1387386065.675917
Channel: SIP/192.168.1.126-00000006
Uniqueid: 1387386065.11
AccountCode:
OldAccountCode:
Event: Bridge
Privilege: call,all
Timestamp: 1387386065.675998
Bridgestate: Link
Bridgetype: core
Channel1: SIP/192.168.1.126-00000007
Channel2: SIP/192.168.1.126-00000006
Uniqueid1: 1387386065.10
Uniqueid2: 1387386065.11
CallerID1: 30128964
CallerID2: 30128964
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.676087
Channel: SIP/192.
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Masquerade", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673718", "Clone"=>"SIP/192.168.1.126-00000006", "CloneState"=>"Up", "Original"=>"Bridge/SIP/192.168.1.126-00000006", "OriginalState"=>"Up"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673846", "Channel"=>"SIP/192.168.1.126-00000006", "Newname"=>"SIP/192.168.1.126-00000006<MASQ>", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="MusicOnHold", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673316", "State"=>"Stop", "Channel"=>"SIP/192.168.1.126-00000006", "UniqueID"=>"1387386061.9"}>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673967", "Channel"=>"Bridge/SIP/192.168.1.126-00000006", "Newname"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.674098", "Channel"=>"SIP/192.168.1.126-00000006<MASQ>", "Newname"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.674228", "Channel"=>"SIP/192.168.1.126-00000006", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "Uniqueid"=>"1387386065.11", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.674436", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.674462", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.674484", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Uniqueid"=>"1387386061.9", "Cause"=>"16"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.674498", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.674544", "SubEvent"=>"Start", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2F192.168.1.126-00000006%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201387386061.9%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:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.674550", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.674555", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386061.9"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675287", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Uniqueid"=>"1387386061.9", "CallerIDNum"=>"<unknown>", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="BridgeExec", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675464", "Response"=>"Success", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.675659", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.675782", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675917", "Channel"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.11", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675998", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006", "Uniqueid1"=>"1387386065.10", "Uniqueid2"=>"1387386065.11", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] 168.1.126-00000007
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000006
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.676170
Channel: SIP/192.168.1.126-00000007
Variable: BRIDGEPVTCALLID
Value: b1c.RsTfGfPM94X-kQA5ZK0f3UousMjI
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.676255
Channel: SIP/192.168.1.126-00000006
Variable: BRIDGEPEER
Value: SIP/192.168.1.126-00000007
Uniqueid: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386065.676337
Channel: SIP/192.168.1.126-00000006
Variable: BRIDGEPVTCALLID
Value: 56RKM.G28DB-BsPKGOLEnFQgDIb4rYhQ
Uniqueid: 1387386065.11
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676087", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676170", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"b1c.RsTfGfPM94X-kQA5ZK0f3UousMjI", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Rename", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.673846", "Channel"=>"SIP/192.168.1.126-00000006", "Newname"=>"SIP/192.168.1.126-00000006<MASQ>", "Uniqueid"=>"1387386061.9"}>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676255", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676337", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"56RKM.G28DB-BsPKGOLEnFQgDIb4rYhQ", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="NewCallerid", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.674228", "Channel"=>"SIP/192.168.1.126-00000006", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "Uniqueid"=>"1387386065.11", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.674436", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.674544", "SubEvent"=>"Start", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2F192.168.1.126-00000006%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201387386061.9%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:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386065.674550", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/192.168.1.126-00000006<ZOMBIE>"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="BridgeExec", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675464", "Response"=>"Success", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="BridgeExec", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675464", "Response"=>"Success", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.675659", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.675782", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675998", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006", "Uniqueid1"=>"1387386065.10", "Uniqueid2"=>"1387386065.11", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="NewAccountCode", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675917", "Channel"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.11", "AccountCode"=>"", "OldAccountCode"=>""}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386065.675998", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006", "Uniqueid1"=>"1387386065.10", "Uniqueid2"=>"1387386065.11", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676087", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676170", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"b1c.RsTfGfPM94X-kQA5ZK0f3UousMjI", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676255", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386065.676337", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"56RKM.G28DB-BsPKGOLEnFQgDIb4rYhQ", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Joined target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="2b78b186-9364-4e53-ac0a-c82e89802924", mixer_name=nil>
[2013-12-18 15:01:05] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Joined target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", mixer_name=nil>
[2013-12-18 15:01:05] INFO Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Joined to call 2b78b186-9364-4e53-ac0a-c82e89802924
[2013-12-18 15:01:05] INFO Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Joined to call 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386065.870776
From: 10.203.175.1:50057
PT: 200(Sender Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 1757
SequenceNumberCycles: 0
IAJitter: 0
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:01:05] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386065.870776", "From"=>"10.203.175.1:50057", "PT"=>"200(Sender Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"1757", "SequenceNumberCycles"=>"0", "IAJitter"=>"0", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:01:07] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386067.495809
From: 10.203.175.1:50055
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:01:07] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386067.495809", "From"=>"10.203.175.1:50055", "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:01:10] TRACE Punchblock::Connection::Asterisk: [RECV] Event: RTCPReceived
Privilege: reporting,all
Timestamp: 1387386071.013187
From: 10.203.175.1:50057
PT: 200(Sender Report)
ReceptionReports: 1
SenderSSRC: 0
FractionLost: 0
PacketsLost: 0
HighestSequence: 2013
SequenceNumberCycles: 0
IAJitter: 38
LastSR: 0.0000000000
DLSR: 0.0000(sec)
[2013-12-18 15:01:10] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="RTCPReceived", headers={"Privilege"=>"reporting,all", "Timestamp"=>"1387386071.013187", "From"=>"10.203.175.1:50057", "PT"=>"200(Sender Report)", "ReceptionReports"=>"1", "SenderSSRC"=>"0", "FractionLost"=>"0", "PacketsLost"=>"0", "HighestSequence"=>"2013", "SequenceNumberCycles"=>"0", "IAJitter"=>"38", "LastSR"=>"0.0000000000", "DLSR"=>"0.0000(sec)"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677044
Channel: SIP/192.168.1.126-00000007
Variable: RTPAUDIOQOS
Value: ssrc=1777391919;themssrc=628790338;lp=0;rxjitter=0.000752;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677057
Channel: SIP/192.168.1.126-00000006
Variable: RTPAUDIOQOSBRIDGED
Value: ssrc=1777391919;themssrc=628790338;lp=0;rxjitter=0.000752;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386065.11
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677044", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1777391919;themssrc=628790338;lp=0;rxjitter=0.000752;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677057", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=1777391919;themssrc=628790338;lp=0;rxjitter=0.000752;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677063
Channel: SIP/192.168.1.126-00000007
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: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677066
Channel: SIP/192.168.1.126-00000006
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: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677070
Channel: SIP/192.168.1.126-00000007
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: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677073
Channel: SIP/192.168.1.126-00000006
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: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677076
Channel: SIP/192.168.1.126-00000007
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677078
Channel: SIP/192.168.1.126-00000006
Variable: RTPAUDIOQOSRTTBRIDGED
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677083
Channel: SIP/192.168.1.126-00000006
Variable: RTPAUDIOQOS
Value: ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677085
Channel: SIP/192.168.1.126-00000007
Variable: RTPAUDIOQOSBRIDGED
Value: ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677089
Channel: SIP/192.168.1.126-00000006
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: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677092
Channel: SIP/192.168.1.126-00000007
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: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677096
Channel: SIP/192.168.1.126-00000006
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: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677098
Channel: SIP/192.168.1.126-00000007
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: 1387386065.10
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677101
Channel: SIP/192.168.1.126-00000006
Variable:
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677063", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677066", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677070", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677073", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677076", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677078", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677044", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1777391919;themssrc=628790338;lp=0;rxjitter=0.000752;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677057", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=1777391919;themssrc=628790338;lp=0;rxjitter=0.000752;rxcount=3;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677083", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677085", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677089", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677092", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677096", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677098", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.677103
Channel: SIP/192.168.1.126-00000007
Variable: RTPAUDIOQOSRTTBRIDGED
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386065.10
Event: HangupRequest
Privilege: call,all
Timestamp: 1387386072.677113
Channel: SIP/192.168.1.126-00000007
Uniqueid: 1387386065.10
Event: Bridge
Privilege: call,all
Timestamp: 1387386072.678587
Bridgestate: Unlink
Bridgetype: core
Channel1: SIP/192.168.1.126-00000007
Channel2: SIP/192.168.1.126-00000006
Uniqueid1: 1387386065.10
Uniqueid2: 1387386065.11
CallerID1: 30128964
CallerID2: 30128964
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.678731
Channel: SIP/192.168.1.126-00000007
Variable: BRIDGERESULT
Value: SUCCESS
Uniqueid: 1387386065.10
Event: AGIExec
Privilege: agi,all
Timestamp: 1387386072.678914
SubEvent: End
Channel: SIP/192.168.1.126-00000007
CommandId: 394223285
Command: EXEC Bridge "SIP/192.168.1.126-00000006"
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386072.679004
SubEvent: Exec
Channel: SIP/192.168.1.126-00000007
CommandID: 50216ae7-7c86-4363-93bf-c8c71a2204b3
Result: 200%20result%3D0%0A
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386072.679092
SubEvent: End
Channel: SIP/192.168.1.126-00000007
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.679199
Channel: SIP/192.168.1.126-00000007
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386065.10
Event: SoftHangupRequest
Privilege: call,all
Timestamp: 1387386072.679355
Channel: SIP/192.168.1.126-00000007
Uniqueid: 1387386065.10
Cause: 16
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386072.679500
Channel: SIP/192.168.1.126-00000007
Context: adhearsion
Extension: h
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386065.10
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386072.679669
SubEvent: Start
Channel: SIP/192.168.1.126-00000007
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000007%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.10%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: 1387386072.679788
SubEvent: End
Channel: SIP/192.168.1.126-00000007
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.679913
Channel: SIP/192.168.1.126-00000007
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386065.10
Event: Hangup
Privilege: call,all
Timestamp: 1387386072.680017
Channel: SIP/192.168.1.126-00000007
Uniqueid: 1387386065.10
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown
Event: SoftHangupRequest
Privilege: call,all
Timestamp: 1387386072.680329
Channel: SIP/192.168.1.126-00000006
Uniqueid: 1387386065.11
Cause: 16
Event: Newexten
Privilege: dialplan,all
Timestamp: 1387386072.680476
Channel: SIP/192.168.1.126-00000006
Context: adhearsion
Extension: h
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1387386065.11
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386072.680644
SubEvent: Start
Channel: SIP/192.168.1.126-00000006
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000006%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.11%0Aagi_version%3A%2011.6.0%0Aagi_callerid%3A%2030128964%0Aagi_calleridname%3A%20Ben%20Langfeld%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677101", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677103", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="HangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.677113", "Channel"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677063", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.678587", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006", "Uniqueid1"=>"1387386065.10", "Uniqueid2"=>"1387386065.11", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.678731", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.678914", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"394223285", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000006\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679004", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000007", "CommandID"=>"50216ae7-7c86-4363-93bf-c8c71a2204b3", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679092", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.679199", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.679355", "Channel"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.10", "Cause"=>"16"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.679500", "Channel"=>"SIP/192.168.1.126-00000007", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679669", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000007%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.10%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:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679788", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.679913", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386065.10"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.680017", "Channel"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.10", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.680329", "Channel"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.11", "Cause"=>"16"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.680476", "Channel"=>"SIP/192.168.1.126-00000006", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] 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%20140706710189824%0A%0A
Event: AsyncAGI
Privilege: agi,all
Timestamp: 1387386072.680782
SubEvent: End
Channel: SIP/192.168.1.126-00000006
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.680905
Channel: SIP/192.168.1.126-00000006
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.681035
Channel: SIP/192.168.1.126-00000006
Variable: RTPAUDIOQOS
Value: ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.681125
Channel: SIP/192.168.1.126-00000006
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: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.681240
Channel: SIP/192.168.1.126-00000006
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: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.681352
Channel: SIP/192.168.1.126-00000006
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1387386065.11
Event: VarSet
Privilege: dialplan,all
Timestamp: 1387386072.681476
Channel: SIP/192.168.1.126-00000006
Variable: RTPAUDIOQOS
Value: ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1387386065.11
Event: Hangup
Privilege: call,all
Timestamp: 1387386072.681754
Channel: SIP/192.168.1.126-00000006
Uniqueid: 1387386065.11
CallerIDNum: 30128964
CallerIDName: Ben Langfeld
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.680644", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000006", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000006%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.11%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%20140706710189824%0A%0A"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677066", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.680782", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000006"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.680905", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677070", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681035", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681125", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681240", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681352", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681476", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.681754", "Channel"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.11", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=[]>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677073", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677076", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677078", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677085", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677092", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677083", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677089", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677098", "Channel"=>"SIP/192.168.1.126-00000007", "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"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677096", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677101", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.677103", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.678587", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006", "Uniqueid1"=>"1387386065.10", "Uniqueid2"=>"1387386065.11", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="HangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.677113", "Channel"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Bridge", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.678587", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/192.168.1.126-00000007", "Channel2"=>"SIP/192.168.1.126-00000006", "Uniqueid1"=>"1387386065.10", "Uniqueid2"=>"1387386065.11", "CallerID1"=>"30128964", "CallerID2"=>"30128964"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.678731", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AGIExec", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.678914", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007", "CommandId"=>"394223285", "Command"=>"EXEC Bridge \"SIP/192.168.1.126-00000006\"", "ResultCode"=>"200", "Result"=>"Success"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679004", "SubEvent"=>"Exec", "Channel"=>"SIP/192.168.1.126-00000007", "CommandID"=>"50216ae7-7c86-4363-93bf-c8c71a2204b3", "Result"=>"200%20result%3D0%0A"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679092", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.679199", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.679355", "Channel"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.10", "Cause"=>"16"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.679500", "Channel"=>"SIP/192.168.1.126-00000007", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679669", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000007", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000007%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.10%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:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.679788", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000007"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.679913", "Channel"=>"SIP/192.168.1.126-00000007", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386065.10"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.680329", "Channel"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.11", "Cause"=>"16"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.680017", "Channel"=>"SIP/192.168.1.126-00000007", "Uniqueid"=>"1387386065.10", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Newexten", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.680476", "Channel"=>"SIP/192.168.1.126-00000006", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.680644", "SubEvent"=>"Start", "Channel"=>"SIP/192.168.1.126-00000006", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F192.168.1.126-00000006%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201387386065.11%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%20140706710189824%0A%0A"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="AsyncAGI", headers={"Privilege"=>"agi,all", "Timestamp"=>"1387386072.680782", "SubEvent"=>"End", "Channel"=>"SIP/192.168.1.126-00000006"}>
[2013-12-18 15:01:12] WARN Celluloid: Terminating task: type=:call, meta={:method_name=>:process_ami_event}, status=:callwait
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.680905", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681035", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681125", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681240", "Channel"=>"SIP/192.168.1.126-00000006", "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"=>"1387386065.11"}>
[2013-12-18 15:01:12] WARN Celluloid: Terminating task: type=:call, meta={:method_name=>:process_ami_event}, status=:callwait
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681352", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="VarSet", headers={"Privilege"=>"dialplan,all", "Timestamp"=>"1387386072.681476", "Channel"=>"SIP/192.168.1.126-00000006", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=368221124;themssrc=1872804959;lp=0;rxjitter=0.004696;rxcount=177;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1387386065.11"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, name="Hangup", headers={"Privilege"=>"call,all", "Timestamp"=>"1387386072.681754", "Channel"=>"SIP/192.168.1.126-00000006", "Uniqueid"=>"1387386065.11", "CallerIDNum"=>"30128964", "CallerIDName"=>"Ben Langfeld", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}>
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Receiving message: #<Punchblock::Event::End target_call_id="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}, reason=:hangup, platform_code="0">
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::End target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}, reason=:hangup, platform_code="0">
[2013-12-18 15:01:12] INFO Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Call ended due to hangup
[2013-12-18 15:01:12] INFO Adhearsion::Call: 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b@: Call ended due to hangup
[2013-12-18 15:01:12] DEBUG Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Receiving message: #<Punchblock::Event::Unjoined target_call_id="2b78b186-9364-4e53-ac0a-c82e89802924", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri="31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b", mixer_name=nil>
[2013-12-18 15:01:12] INFO Adhearsion::Call: 2b78b186-9364-4e53-ac0a-c82e89802924@: Unjoined from call 31ecd2d1-0f8d-4de9-93aa-42c6ee97f98b
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment