5979f626837d]
2013-03-27 21:18:07.495839 [DEBUG] switch_core_session.c:975 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.495839 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/IMSI410071190004419@127.0.0.1) Running State Change CS_NEW
2013-03-27 21:18:07.495839 [DEBUG] switch_core_session.c:975 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.495839 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/IMSI410071190004419@127.0.0.1) State NEW
2013-03-27 21:18:07.515818 [DEBUG] sofia.c:7697 IP 127.0.0.1 Approved by acl "domains[]". Access Granted.
2013-03-27 21:18:07.515818 [DEBUG] sofia.c:5597 Channel sofia/internal/IMSI410071190004419@127.0.0.1 entering state [received][100]
2013-03-27 21:18:07.515818 [DEBUG] sofia.c:5608 Remote SDP:
v=0
o=IMSI410071190004419 0 0 IN IP4 127.0.0.1
s=Talk Time
t=0 0
m=audio 16502 RTP/AVP 3
c=IN IP4 127.0.0.1
a=rtpmap:3 GSM/8000

2013-03-27 21:18:07.515818 [DEBUG] sofia.c:5821 (sofia/internal/IMSI410071190004419@127.0.0.1) State Change CS_NEW -> CS_INIT
2013-03-27 21:18:07.515818 [DEBUG] switch_core_session.c:1310 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/IMSI410071190004419@127.0.0.1) Running State Change CS_INIT
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/IMSI410071190004419@127.0.0.1) State INIT
2013-03-27 21:18:07.515818 [DEBUG] mod_sofia.c:86 sofia/internal/IMSI410071190004419@127.0.0.1 SOFIA INIT
2013-03-27 21:18:07.515818 [DEBUG] mod_sofia.c:126 (sofia/internal/IMSI410071190004419@127.0.0.1) State Change CS_INIT -> CS_ROUTING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_session.c:1310 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/IMSI410071190004419@127.0.0.1) State INIT going to sleep
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/IMSI410071190004419@127.0.0.1) Running State Change CS_ROUTING
2013-03-27 21:18:07.515818 [DEBUG] switch_channel.c:2012 (sofia/internal/IMSI410071190004419@127.0.0.1) Callstate Change DOWN -> RINGING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/IMSI410071190004419@127.0.0.1) State ROUTING
2013-03-27 21:18:07.515818 [DEBUG] mod_sofia.c:149 sofia/internal/IMSI410071190004419@127.0.0.1 SOFIA ROUTING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:117 sofia/internal/IMSI410071190004419@127.0.0.1 Standard ROUTING
2013-03-27 21:18:07.515818 [INFO] mod_dialplan_xml.c:557 Processing IMSI410071190004419 <IMSI410071190004419>->2222 in context public
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 parsing [public->unloop] continue=false
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 parsing [public->outside_call] continue=true
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Absolute Condition [outside_call]
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Action set(outside_call=true)
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 parsing [public->call_debug] continue=true
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 parsing [public->public_extensions] continue=false
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Regex (FAIL) [public_extensions] destination_number(2222) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 parsing [public->public_did] continue=false
Dialplan: sofia/internal/IMSI410071190004419@127.0.0.1 Regex (FAIL) [public_did] destination_number(2222) =~ /^(5551212)$/ break=on-false
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/IMSI410071190004419@127.0.0.1) State Change CS_ROUTING -> CS_EXECUTE
2013-03-27 21:18:07.515818 [DEBUG] switch_core_session.c:1310 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/IMSI410071190004419@127.0.0.1) State ROUTING going to sleep
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/IMSI410071190004419@127.0.0.1) Running State Change CS_EXECUTE
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:477 (sofia/internal/IMSI410071190004419@127.0.0.1) State EXECUTE
2013-03-27 21:18:07.515818 [DEBUG] mod_sofia.c:242 sofia/internal/IMSI410071190004419@127.0.0.1 SOFIA EXECUTE
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:209 sofia/internal/IMSI410071190004419@127.0.0.1 Standard EXECUTE
EXECUTE sofia/internal/IMSI410071190004419@127.0.0.1 set(outside_call=true)
2013-03-27 21:18:07.515818 [DEBUG] mod_dptools.c:1367 sofia/internal/IMSI410071190004419@127.0.0.1 SET [outside_call]=[true]
EXECUTE sofia/internal/IMSI410071190004419@127.0.0.1 export(RFC2822_DATE=Wed, 27 Mar 2013 21:18:07 +0500)
2013-03-27 21:18:07.515818 [DEBUG] switch_channel.c:1143 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 27 Mar 2013 21:18:07 +0500]
2013-03-27 21:18:07.515818 [NOTICE] switch_core_state_machine.c:262 sofia/internal/IMSI410071190004419@127.0.0.1 has executed the last dialplan instruction, hanging up.
2013-03-27 21:18:07.515818 [DEBUG] switch_channel.c:3011 (sofia/internal/IMSI410071190004419@127.0.0.1) Callstate Change RINGING -> HANGUP
2013-03-27 21:18:07.515818 [NOTICE] switch_core_state_machine.c:264 Hangup sofia/internal/IMSI410071190004419@127.0.0.1 [CS_EXECUTE] [NORMAL_CLEARING]
2013-03-27 21:18:07.515818 [DEBUG] switch_channel.c:3034 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [KILL]
2013-03-27 21:18:07.515818 [DEBUG] switch_core_session.c:1310 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:477 (sofia/internal/IMSI410071190004419@127.0.0.1) State EXECUTE going to sleep
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/IMSI410071190004419@127.0.0.1) Running State Change CS_HANGUP
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:676 (sofia/internal/IMSI410071190004419@127.0.0.1) State HANGUP
2013-03-27 21:18:07.515818 [DEBUG] mod_sofia.c:503 Channel sofia/internal/IMSI410071190004419@127.0.0.1 hanging up, cause: NORMAL_CLEARING
2013-03-27 21:18:07.515818 [DEBUG] mod_sofia.c:633 Responding to INVITE with: 480
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:48 sofia/internal/IMSI410071190004419@127.0.0.1 Standard HANGUP, cause: NORMAL_CLEARING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:676 (sofia/internal/IMSI410071190004419@127.0.0.1) State HANGUP going to sleep
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/IMSI410071190004419@127.0.0.1) State Change CS_HANGUP -> CS_REPORTING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_session.c:1310 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/IMSI410071190004419@127.0.0.1) Running State Change CS_REPORTING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:758 (sofia/internal/IMSI410071190004419@127.0.0.1) State REPORTING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:92 sofia/internal/IMSI410071190004419@127.0.0.1 Standard REPORTING, cause: NORMAL_CLEARING
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:758 (sofia/internal/IMSI410071190004419@127.0.0.1) State REPORTING going to sleep
2013-03-27 21:18:07.515818 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/IMSI410071190004419@127.0.0.1) State Change CS_REPORTING -> CS_DESTROY
2013-03-27 21:18:07.515818 [DEBUG] switch_core_session.c:1310 Send signal sofia/internal/IMSI410071190004419@127.0.0.1 [BREAK]
2013-03-27 21:18:07.515818 [DEBUG] switch_core_session.c:1518 Session 44 (sofia/internal/IMSI410071190004419@127.0.0.1) Locked, Waiting on external entities
2013-03-27 21:18:07.515818 [NOTICE] switch_core_session.c:1536 Session 44 (sofia/internal/IMSI410071190004419@127.0.0.1) Ended
2013-03-27 21:18:07.515818 [NOTICE] switch_core_session.c:1540 Close Channel sofia/internal/IMSI410071190004419@127.0.0.1 [CS_DESTROY]
2013-03-27 21:18:07.525838 [DEBUG] switch_core_state_machine.c:565 (sofia/internal/IMSI410071190004419@127.0.0.1) Callstate Change HANGUP -> DOWN
2013-03-27 21:18:07.525838 [DEBUG] switch_core_state_machine.c:568 (sofia/internal/IMSI410071190004419@127.0.0.1) Running State Change CS_DESTROY
2013-03-27 21:18:07.525838 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/IMSI410071190004419@127.0.0.1) State DESTROY
2013-03-27 21:18:07.525838 [DEBUG] mod_sofia.c:396 sofia/internal/IMSI410071190004419@127.0.0.1 SOFIA DESTROY
2013-03-27 21:18:07.525838 [DEBUG] switch_core_state_machine.c:99 sofia/internal/IMSI410071190004419@127.0.0.1 Standard DESTROY
2013-03-27 21:18:07.525838 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/IMSI410071190004419@127.0.0.1) State DESTROY going to sleep