2013-05-14 23:47:29.292757 [NOTICE] switch_channel.c:978 New Channel sofia/external/sco...@176.122.224.219:5080 [1c441dbc-bccf-11e2-8c38-59c26ec8a8fe]2013-05-14 23:47:29.292757 [DEBUG] switch_core_session.c:1005 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:29.292757 [DEBUG] switch_core_session.c:1005 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:29.292757 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sco...@176.122.224.219:5080) Running State Change CS_NEW2013-05-14 23:47:29.292757 [DEBUG] switch_core_state_machine.c:433 (sofia/external/sco...@176.122.224.219:5080) State NEW2013-05-14 23:47:29.312761 [DEBUG] sofia.c:5742 Channel sofia/external/sco...@176.122.224.219:5080 entering state [received][100]2013-05-14 23:47:29.312761 [DEBUG] sofia.c:5751 Remote SDP:v=0o=3cxVCE 368782185 282552360 IN IP4 62.21.79.134s=3cxVCE Audio Callc=IN IP4 62.21.79.134t=0 0m=audio 40040 RTP/AVP 0 8 3 101a=rtpmap:0 PCMU/8000a=rtpmap:8 PCMA/8000a=rtpmap:3 GSM/8000a=rtpmap:101 telephone-event/8000a=fmtp:101 0-15a=ptime:20m=video 40028 RTP/AVP 34c=IN IP4 62.21.79.134a=rtpmap:34 H263/90000a=fmtp:34 QCIF=1;CIF=1;SQCIF=1;CIF4=12013-05-14 23:47:29.312761 [DEBUG] sofia.c:5964 (sofia/external/sco...@176.122.224.219:5080) State Change CS_NEW -> CS_INIT2013-05-14 23:47:29.312761 [DEBUG] switch_core_session.c:1340 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:29.312761 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sco...@176.122.224.219:5080) Running State Change CS_INIT2013-05-14 23:47:29.312761 [DEBUG] switch_core_state_machine.c:454 (sofia/external/sco...@176.122.224.219:5080) State INIT2013-05-14 23:47:29.312761 [DEBUG] mod_sofia.c:87 sofia/external/sco...@176.122.224.219:5080 SOFIA INIT2013-05-14 23:47:29.312761 [DEBUG] mod_sofia.c:114 (sofia/external/sco...@176.122.224.219:5080) State Change CS_INIT -> CS_ROUTING2013-05-14 23:47:29.312761 [DEBUG] switch_core_session.c:1340 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:29.312761 [DEBUG] switch_core_state_machine.c:454 (sofia/external/sco...@176.122.224.219:5080) State INIT going to sleep2013-05-14 23:47:29.312761 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sco...@176.122.224.219:5080) Running State Change CS_ROUTING2013-05-14 23:47:29.312761 [DEBUG] switch_channel.c:2034 (sofia/external/sco...@176.122.224.219:5080) Callstate Change DOWN -> RINGING2013-05-14 23:47:29.312761 [DEBUG] switch_core_state_machine.c:470 (sofia/external/sco...@176.122.224.219:5080) State ROUTING2013-05-14 23:47:29.312761 [DEBUG] mod_sofia.c:137 sofia/external/sco...@176.122.224.219:5080 SOFIA ROUTING2013-05-14 23:47:29.312761 [DEBUG] switch_core_state_machine.c:117 sofia/external/sco...@176.122.224.219:5080 Standard ROUTING2013-05-14 23:47:29.312761 [INFO] mod_dialplan_xml.c:558 Processing scorpio <scorpio>->48608578764 in context publicDialplan: sofia/external/sco...@176.122.224.219:5080 parsing [public->unloop] continue=falseDialplan: sofia/external/sco...@176.122.224.219:5080 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-falseDialplan: sofia/external/sco...@176.122.224.219:5080 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-falseDialplan: sofia/external/sco...@176.122.224.219:5080 parsing [public->outside_call] continue=trueDialplan: sofia/external/sco...@176.122.224.219:5080 Absolute Condition [outside_call]Dialplan: sofia/external/sco...@176.122.224.219:5080 Action set(outside_call=true)Dialplan: sofia/external/sco...@176.122.224.219:5080 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})Dialplan: sofia/external/sco...@176.122.224.219:5080 parsing [public->call_debug] continue=trueDialplan: sofia/external/sco...@176.122.224.219:5080 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=neverDialplan: sofia/external/sco...@176.122.224.219:5080 parsing [public->public_extensions] continue=falseDialplan: sofia/external/sco...@176.122.224.219:5080 Regex (FAIL) [public_extensions] destination_number(48608578764) =~ /^(10[01][0-9])$/ break=on-falseDialplan: sofia/external/sco...@176.122.224.219:5080 parsing [public->public_did] continue=falseDialplan: sofia/external/sco...@176.122.224.219:5080 Regex (FAIL) [public_did] destination_number(48608578764) =~ /^(5551212)$/ break=on-false2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:167 (sofia/external/sco...@176.122.224.219:5080) State Change CS_ROUTING -> CS_EXECUTE2013-05-14 23:47:29.921544 [DEBUG] switch_core_session.c:1340 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:470 (sofia/external/sco...@176.122.224.219:5080) State ROUTING going to sleep2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sco...@176.122.224.219:5080) Running State Change CS_EXECUTE2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:477 (sofia/external/sco...@176.122.224.219:5080) State EXECUTE2013-05-14 23:47:29.921544 [DEBUG] mod_sofia.c:230 sofia/external/sco...@176.122.224.219:5080 SOFIA EXECUTE2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:209 sofia/external/sco...@176.122.224.219:5080 Standard EXECUTEEXECUTE sofia/external/sco...@176.122.224.219:5080 set(outside_call=true)2013-05-14 23:47:29.921544 [DEBUG] mod_dptools.c:1373 sofia/external/sco...@176.122.224.219:5080 SET [outside_call]=[true]EXECUTE sofia/external/sco...@176.122.224.219:5080 export(RFC2822_DATE=Tue, 14 May 2013 23:47:29 +0400)2013-05-14 23:47:29.921544 [DEBUG] switch_channel.c:1145 EXPORT (export_vars) [RFC2822_DATE]=[Tue, 14 May 2013 23:47:29 +0400]2013-05-14 23:47:29.921544 [NOTICE] switch_core_state_machine.c:262 sofia/external/sco...@176.122.224.219:5080 has executed the last dialplan instruction, hanging up.2013-05-14 23:47:29.921544 [NOTICE] switch_core_state_machine.c:264 Hangup sofia/external/sco...@176.122.224.219:5080 [CS_EXECUTE] [NORMAL_CLEARING]2013-05-14 23:47:29.921544 [DEBUG] switch_channel.c:3096 Send signal sofia/external/sco...@176.122.224.219:5080 [KILL]2013-05-14 23:47:29.921544 [DEBUG] switch_core_session.c:1340 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:477 (sofia/external/sco...@176.122.224.219:5080) State EXECUTE going to sleep2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sco...@176.122.224.219:5080) Running State Change CS_HANGUP2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:676 (sofia/external/sco...@176.122.224.219:5080) State HANGUP2013-05-14 23:47:29.921544 [DEBUG] mod_sofia.c:463 Channel sofia/external/sco...@176.122.224.219:5080 hanging up, cause: NORMAL_CLEARING2013-05-14 23:47:29.921544 [DEBUG] mod_sofia.c:597 Responding to INVITE with: 4802013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:48 sofia/external/sco...@176.122.224.219:5080 Standard HANGUP, cause: NORMAL_CLEARING2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:676 (sofia/external/sco...@176.122.224.219:5080) State HANGUP going to sleep2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:689 (sofia/external/sco...@176.122.224.219:5080) Callstate Change RINGING -> HANGUP2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:446 (sofia/external/sco...@176.122.224.219:5080) State Change CS_HANGUP -> CS_REPORTING2013-05-14 23:47:29.921544 [DEBUG] switch_core_session.c:1340 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sco...@176.122.224.219:5080) Running State Change CS_REPORTING2013-05-14 23:47:29.921544 [DEBUG] switch_core_state_machine.c:761 (sofia/external/sco...@176.122.224.219:5080) State REPORTING2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:92 sofia/external/sco...@176.122.224.219:5080 Standard REPORTING, cause: NORMAL_CLEARING2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:761 (sofia/external/sco...@176.122.224.219:5080) State REPORTING going to sleep2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:440 (sofia/external/sco...@176.122.224.219:5080) State Change CS_REPORTING -> CS_DESTROY2013-05-14 23:47:30.721640 [DEBUG] switch_core_session.c:1340 Send signal sofia/external/sco...@176.122.224.219:5080 [BREAK]2013-05-14 23:47:30.721640 [DEBUG] switch_core_session.c:1548 Session 22 (sofia/external/sco...@176.122.224.219:5080) Locked, Waiting on external entities2013-05-14 23:47:30.721640 [NOTICE] switch_core_session.c:1566 Session 22 (sofia/external/sco...@176.122.224.219:5080) Ended2013-05-14 23:47:30.721640 [NOTICE] switch_core_session.c:1570 Close Channel sofia/external/sco...@176.122.224.219:5080 [CS_DESTROY]2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:565 (sofia/external/sco...@176.122.224.219:5080) Callstate Change HANGUP -> DOWN2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:568 (sofia/external/sco...@176.122.224.219:5080) Running State Change CS_DESTROY2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:578 (sofia/external/sco...@176.122.224.219:5080) State DESTROY2013-05-14 23:47:30.721640 [DEBUG] mod_sofia.c:373 sofia/external/sco...@176.122.224.219:5080 SOFIA DESTROY2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:99 sofia/external/sco...@176.122.224.219:5080 Standard DESTROY2013-05-14 23:47:30.721640 [DEBUG] switch_core_state_machine.c:578 (sofia/external/sco...@176.122.224.219:5080) State DESTROY going to sleep