freeswitch@ubu> 2014-09-02 20:17:32.104953 [NOTICE] switch_channel.c:1054 New Channel sofia/profile5090/pap2@192.168.1.71:5090 [d7d1fa84-3318-11e4-b0fe-9d44aa9c85fb] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1052 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1052 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/pap2@192.168.1.71:5090) Running State Change CS_NEW 2014-09-02 20:17:32.104953 [DEBUG] sofia.c:8342 sofia/profile5090/pap2@192.168.1.71:5090 receiving invite from 192.168.1.106:5061 version: 1.5.13b git 795d974 2014-05-27 16:20:29Z 64bit 2014-09-02 20:17:32.104953 [DEBUG] sofia.c:6204 Channel sofia/profile5090/pap2@192.168.1.71:5090 entering state [received][100] 2014-09-02 20:17:32.104953 [DEBUG] sofia.c:6214 Remote SDP: v=0 o=- 238173 238173 IN IP4 192.168.1.106 s=- c=IN IP4 192.168.1.106 t=0 0 m=audio 16414 RTP/AVP 4 100 101 a=rtpmap:4 G723/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 2014-09-02 20:17:32.104953 [DEBUG] sofia.c:6469 (sofia/profile5090/pap2@192.168.1.71:5090) State Change CS_NEW -> CS_INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:486 (sofia/profile5090/pap2@192.168.1.71:5090) State NEW 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/pap2@192.168.1.71:5090) Running State Change CS_INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:507 (sofia/profile5090/pap2@192.168.1.71:5090) State INIT 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:87 sofia/profile5090/pap2@192.168.1.71:5090 SOFIA INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:40 sofia/profile5090/pap2@192.168.1.71:5090 Standard INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:48 (sofia/profile5090/pap2@192.168.1.71:5090) State Change CS_INIT -> CS_ROUTING 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:507 (sofia/profile5090/pap2@192.168.1.71:5090) State INIT going to sleep 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/pap2@192.168.1.71:5090) Running State Change CS_ROUTING 2014-09-02 20:17:32.104953 [DEBUG] switch_channel.c:2178 (sofia/profile5090/pap2@192.168.1.71:5090) Callstate Change DOWN -> RINGING 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:523 (sofia/profile5090/pap2@192.168.1.71:5090) State ROUTING 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:123 sofia/profile5090/pap2@192.168.1.71:5090 SOFIA ROUTING 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:164 sofia/profile5090/pap2@192.168.1.71:5090 Standard ROUTING 2014-09-02 20:17:32.104953 [INFO] mod_dialplan_xml.c:558 Processing PAP2 ->1213xxxxxxx in context fromUAs Dialplan: sofia/profile5090/pap2@192.168.1.71:5090 parsing [fromUAs->test_codec_issue] continue=false Dialplan: sofia/profile5090/pap2@192.168.1.71:5090 Regex (PASS) [test_codec_issue] destination_number(1213xxxxxxx) =~ /^1.*/ break=on-false Dialplan: sofia/profile5090/pap2@192.168.1.71:5090 Action set(continue_on_fail=true) Dialplan: sofia/profile5090/pap2@192.168.1.71:5090 Action set(proxy_media=true) Dialplan: sofia/profile5090/pap2@192.168.1.71:5090 Action bridge([leg_timeout=60,process_cdr=false,execute_on_answer=sched_hangup +6 alloted_timeout,sip_auth_username=XXXXXXX,sip_auth_password=XXXXXXX,origination_caller_id_number=1223334444]sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:214 (sofia/profile5090/pap2@192.168.1.71:5090) State Change CS_ROUTING -> CS_EXECUTE 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:523 (sofia/profile5090/pap2@192.168.1.71:5090) State ROUTING going to sleep 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/pap2@192.168.1.71:5090) Running State Change CS_EXECUTE 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:530 (sofia/profile5090/pap2@192.168.1.71:5090) State EXECUTE 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:178 sofia/profile5090/pap2@192.168.1.71:5090 SOFIA EXECUTE 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:256 sofia/profile5090/pap2@192.168.1.71:5090 Standard EXECUTE EXECUTE sofia/profile5090/pap2@192.168.1.71:5090 set(continue_on_fail=true) 2014-09-02 20:17:32.104953 [DEBUG] mod_dptools.c:1435 sofia/profile5090/pap2@192.168.1.71:5090 SET [continue_on_fail]=[true] EXECUTE sofia/profile5090/pap2@192.168.1.71:5090 set(proxy_media=true) 2014-09-02 20:17:32.104953 [DEBUG] mod_dptools.c:1435 sofia/profile5090/pap2@192.168.1.71:5090 SET [proxy_media]=[true] EXECUTE sofia/profile5090/pap2@192.168.1.71:5090 bridge([leg_timeout=60,process_cdr=false,execute_on_answer=sched_hangup +6 alloted_timeout,sip_auth_username=XXXXXXX,sip_auth_password=XXXXXXX,origination_caller_id_number=1223334444]sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) 2014-09-02 20:17:32.104953 [DEBUG] switch_ivr_originate.c:2078 Parsing global variables 2014-09-02 20:17:32.104953 [DEBUG] switch_ivr_originate.c:2525 Parsing session specific variables 2014-09-02 20:17:32.104953 [DEBUG] switch_event.c:1687 Parsing variable [leg_timeout]=[60] 2014-09-02 20:17:32.104953 [DEBUG] switch_event.c:1687 Parsing variable [process_cdr]=[false] 2014-09-02 20:17:32.104953 [DEBUG] switch_event.c:1687 Parsing variable [execute_on_answer]=[sched_hangup +6 alloted_timeout] 2014-09-02 20:17:32.104953 [DEBUG] switch_event.c:1687 Parsing variable [sip_auth_username]=[XXXXXXX] 2014-09-02 20:17:32.104953 [DEBUG] switch_event.c:1687 Parsing variable [sip_auth_password]=[XXXXXXX] 2014-09-02 20:17:32.104953 [DEBUG] switch_event.c:1687 Parsing variable [origination_caller_id_number]=[1223334444] 2014-09-02 20:17:32.104953 [NOTICE] switch_channel.c:1054 New Channel sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [d7d2c4c8-3318-11e4-b105-9d44aa9c85fb] 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:4565 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State Change CS_NEW -> CS_INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:4635 [zrtp_passthru] Setting a-leg inherit_codec=true 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:4638 [zrtp_passthru] Setting b-leg absolute_codec_string='G723@8000h@30i@6300b' 2014-09-02 20:17:32.104953 [DEBUG] switch_ivr_originate.c:2819 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 Setting leg timeout to 60 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Running State Change CS_INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:507 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State INIT 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:87 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 SOFIA INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_media.c:7406 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 Patched SDP --- v=0 o=- 238173 238173 IN IP4 192.168.1.106 s=- c=IN IP4 192.168.1.106 t=0 0 m=audio 16414 RTP/AVP 4 100 101 a=rtpmap:4 G723/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 +++ v=0 o=FreeSWITCH 1878787317 1878787318 IN IP4 192.168.1.71 s=FreeSWITCH c=IN IP4 192.168.1.71 t=0 0 m=audio 18600 RTP/AVP 4 100 101 a=rtpmap:4 G723/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 2014-09-02 20:17:32.104953 [DEBUG] sofia_glue.c:1226 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 sending invite version: 1.5.13b git 795d974 2014-05-27 16:20:29Z 64bit Local SDP: v=0 o=FreeSWITCH 1878787317 1878787318 IN IP4 192.168.1.71 s=FreeSWITCH c=IN IP4 192.168.1.71 t=0 0 m=audio 18600 RTP/AVP 4 100 101 a=rtpmap:4 G723/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:40 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 Standard INIT 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:48 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State Change CS_INIT -> CS_ROUTING 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:507 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State INIT going to sleep 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Running State Change CS_ROUTING 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:523 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State ROUTING 2014-09-02 20:17:32.104953 [DEBUG] mod_sofia.c:123 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 SOFIA ROUTING 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1052 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_ivr_originate.c:67 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2014-09-02 20:17:32.104953 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:523 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State ROUTING going to sleep 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Running State Change CS_CONSUME_MEDIA 2014-09-02 20:17:32.104953 [DEBUG] sofia.c:6204 Channel sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 entering state [calling][0] 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:542 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State CONSUME_MEDIA 2014-09-02 20:17:32.104953 [DEBUG] switch_core_state_machine.c:542 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State CONSUME_MEDIA going to sleep 2014-09-02 20:17:32.124661 [DEBUG] switch_core_session.c:1052 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:32.124661 [DEBUG] switch_core_session.c:1052 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:32.124661 [DEBUG] sofia.c:6204 Channel sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 entering state [calling][0] 2014-09-02 20:17:35.684689 [DEBUG] switch_core_session.c:1052 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:35.684689 [DEBUG] switch_core_session.c:1052 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:35.684689 [DEBUG] sofia.c:6204 Channel sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 entering state [proceeding][183] 2014-09-02 20:17:35.684689 [DEBUG] sofia.c:6214 Remote SDP: v=0 o=Sippy 145628396 1 IN IP4 SIP.PROVIDER.TLD s=- t=0 0 m=audio 59134 RTP/AVP 4 101 c=IN IP4 SIP.PROVIDER.TLD a=rtpmap:4 G723/8000 a=fmtp:4 annexa=yes a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 2014-09-02 20:17:35.684689 [DEBUG] switch_core_media.c:7406 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 Patched SDP --- v=0 o=FreeSWITCH 1878787317 1878787318 IN IP4 192.168.1.71 s=FreeSWITCH c=IN IP4 192.168.1.71 t=0 0 m=audio 18600 RTP/AVP 4 100 101 a=rtpmap:4 G723/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 +++ v=0 o=FreeSWITCH 1878787317 1878787319 IN IP4 192.168.1.71 s=FreeSWITCH c=IN IP4 192.168.1.71 t=0 0 m=audio 18600 RTP/AVP 4 100 101 a=rtpmap:4 G723/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 2014-09-02 20:17:35.684689 [WARNING] switch_core_codec.c:703 Codec G723 Exists but not at the desired implementation. 8000hz 20ms 2014-09-02 20:17:35.684689 [ERR] switch_core_media.c:2285 Can't load codec? 2014-09-02 20:17:35.684689 [NOTICE] switch_core_media.c:2286 Hangup sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION] 2014-09-02 20:17:35.684689 [DEBUG] switch_channel.c:3216 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [KILL] 2014-09-02 20:17:35.684689 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Running State Change CS_HANGUP 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:730 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Callstate Change DOWN -> HANGUP 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:732 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State HANGUP 2014-09-02 20:17:35.684689 [DEBUG] mod_sofia.c:413 Channel sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 hanging up, cause: INCOMPATIBLE_DESTINATION 2014-09-02 20:17:35.684689 [DEBUG] mod_sofia.c:475 Sending CANCEL to sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:58 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:732 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State HANGUP going to sleep 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:499 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State Change CS_HANGUP -> CS_REPORTING 2014-09-02 20:17:35.684689 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Running State Change CS_REPORTING 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:818 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State REPORTING 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:102 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:818 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State REPORTING going to sleep 2014-09-02 20:17:35.684689 [DEBUG] switch_core_state_machine.c:493 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State Change CS_REPORTING -> CS_DESTROY 2014-09-02 20:17:35.684689 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [BREAK] 2014-09-02 20:17:35.684689 [DEBUG] switch_core_session.c:1614 Session 2 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Locked, Waiting on external entities 2014-09-02 20:17:35.704667 [DEBUG] switch_ivr_originate.c:3694 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2014-09-02 20:17:35.704667 [NOTICE] switch_core_session.c:1632 Session 2 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Ended 2014-09-02 20:17:35.704667 [NOTICE] switch_core_session.c:1636 Close Channel sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 [CS_DESTROY] 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:618 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Callstate Change HANGUP -> DOWN 2014-09-02 20:17:35.704667 [INFO] mod_dptools.c:3234 Originate Failed. Cause: INCOMPATIBLE_DESTINATION 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:621 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) Running State Change CS_DESTROY 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:631 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State DESTROY 2014-09-02 20:17:35.704667 [NOTICE] switch_core_state_machine.c:313 sofia/profile5090/pap2@192.168.1.71:5090 has executed the last dialplan instruction, hanging up. 2014-09-02 20:17:35.704667 [DEBUG] mod_sofia.c:323 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 SOFIA DESTROY 2014-09-02 20:17:35.704667 [NOTICE] switch_core_state_machine.c:315 Hangup sofia/profile5090/pap2@192.168.1.71:5090 [CS_EXECUTE] [NORMAL_CLEARING] 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:109 sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060 Standard DESTROY 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:631 (sofia/profile5090/0111213xxxxxxx@SIP.PROVIDER.TLD:5060) State DESTROY going to sleep 2014-09-02 20:17:35.704667 [DEBUG] switch_channel.c:3216 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [KILL] 2014-09-02 20:17:35.704667 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:530 (sofia/profile5090/pap2@192.168.1.71:5090) State EXECUTE going to sleep 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/pap2@192.168.1.71:5090) Running State Change CS_HANGUP 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:730 (sofia/profile5090/pap2@192.168.1.71:5090) Callstate Change RINGING -> HANGUP 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:732 (sofia/profile5090/pap2@192.168.1.71:5090) State HANGUP 2014-09-02 20:17:35.704667 [DEBUG] mod_sofia.c:413 Channel sofia/profile5090/pap2@192.168.1.71:5090 hanging up, cause: NORMAL_CLEARING 2014-09-02 20:17:35.704667 [DEBUG] mod_sofia.c:547 Responding to INVITE with: 480 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:58 sofia/profile5090/pap2@192.168.1.71:5090 Standard HANGUP, cause: NORMAL_CLEARING 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:732 (sofia/profile5090/pap2@192.168.1.71:5090) State HANGUP going to sleep 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:499 (sofia/profile5090/pap2@192.168.1.71:5090) State Change CS_HANGUP -> CS_REPORTING 2014-09-02 20:17:35.704667 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:467 (sofia/profile5090/pap2@192.168.1.71:5090) Running State Change CS_REPORTING 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:818 (sofia/profile5090/pap2@192.168.1.71:5090) State REPORTING 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:102 sofia/profile5090/pap2@192.168.1.71:5090 Standard REPORTING, cause: NORMAL_CLEARING 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:818 (sofia/profile5090/pap2@192.168.1.71:5090) State REPORTING going to sleep 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:493 (sofia/profile5090/pap2@192.168.1.71:5090) State Change CS_REPORTING -> CS_DESTROY 2014-09-02 20:17:35.704667 [DEBUG] switch_core_session.c:1387 Send signal sofia/profile5090/pap2@192.168.1.71:5090 [BREAK] 2014-09-02 20:17:35.704667 [DEBUG] switch_core_session.c:1614 Session 1 (sofia/profile5090/pap2@192.168.1.71:5090) Locked, Waiting on external entities 2014-09-02 20:17:35.704667 [NOTICE] switch_core_session.c:1632 Session 1 (sofia/profile5090/pap2@192.168.1.71:5090) Ended 2014-09-02 20:17:35.704667 [NOTICE] switch_core_session.c:1636 Close Channel sofia/profile5090/pap2@192.168.1.71:5090 [CS_DESTROY] 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:618 (sofia/profile5090/pap2@192.168.1.71:5090) Callstate Change HANGUP -> DOWN 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:621 (sofia/profile5090/pap2@192.168.1.71:5090) Running State Change CS_DESTROY 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:631 (sofia/profile5090/pap2@192.168.1.71:5090) State DESTROY 2014-09-02 20:17:35.704667 [DEBUG] mod_sofia.c:323 sofia/profile5090/pap2@192.168.1.71:5090 SOFIA DESTROY 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:109 sofia/profile5090/pap2@192.168.1.71:5090 Standard DESTROY 2014-09-02 20:17:35.704667 [DEBUG] switch_core_state_machine.c:631 (sofia/profile5090/pap2@192.168.1.71:5090) State DESTROY going to sleep