Could you put this into a pastebin entry? Also, for completeness, could you enable sip trace as well? That will probably have all the info you need to figure out what's happening. Be sure to use FreeSWITCH Log for the syntax highlighting so that these old eyes can more easily see what's going on. Thanks! -MC On Tue, Mar 12, 2013 at 12:14 AM, Sayyed Mohammad Emami Razavi < emamirazavi@gmail.com> wrote:
Two extensions 401 and 403 are registered by Twinkle! 401 calls 403 but 403 does not ring and 401 does not listen ring back, but FS thinks them ringing! I had not this problem beforehand, This server has two ethernet cards, #1 for connecting to trunk and #2 for connecting to local network.(I have no problem in network routing and I've tested all things) These two extensions are registered at local network (192.168.54.69) What is the problem? My freeswitch log is below:
2013-03-12 13:56:51.741964 [NOTICE] switch_channel.c:968 New Channel sofia/sipinterface_6/401@192.168.54.69[5ab2118c-8aff-11e2-bd72-4f1eb6844087] 2013-03-12 13:56:51.741964 [DEBUG] switch_core_session.c:975 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.741964 [DEBUG] switch_core_session.c:975 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.741964 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_NEW 2013-03-12 13:56:51.741964 [DEBUG] switch_core_state_machine.c:433 (sofia/sipinterface_6/401@192.168.54.69) State NEW 2013-03-12 13:56:51.761967 [DEBUG] switch_core_session.c:975 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.761967 [DEBUG] sofia.c:1719 detaching session 5ab2118c-8aff-11e2-bd72-4f1eb6844087 2013-03-12 13:56:51.761967 [DEBUG] sofia.c:1811 Re-attaching to session 5ab2118c-8aff-11e2-bd72-4f1eb6844087 2013-03-12 13:56:51.761967 [DEBUG] switch_core_session.c:975 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.761967 [DEBUG] switch_core_session.c:975 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.781957 [DEBUG] sofia.c:5574 Channel sofia/sipinterface_6/401@192.168.54.69 entering state [received][100] 2013-03-12 13:56:51.781957 [DEBUG] sofia.c:5585 Remote SDP: v=0 o=twinkle 799456135 497926540 IN IP4 192.168.1.102 s=- c=IN IP4 192.168.1.102 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20
2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:98:16000:20:0]/[G722:9:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:98:16000:20:0]/[PCMU:0:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:98:16000:20:0]/[PCMA:8:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:98:16000:20:0]/[GSM:3:8000:20:13200] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:97:8000:20:0]/[G722:9:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:97:8000:20:0]/[PCMU:0:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:97:8000:20:0]/[PCMA:8:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [speex:97:8000:20:0]/[GSM:3:8000:20:13200] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2013-03-12 13:56:51.781957 [DEBUG] sofia_glue.c:5137 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2013-03-12 13:56:51.801956 [DEBUG] sofia_glue.c:3093 Set Codec sofia/sipinterface_6/401@192.168.54.69 PCMA/8000 20 ms 160 samples 64000 bits 2013-03-12 13:56:51.801956 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_6/401@192.168.54.69 Original read codec set to PCMA:8 2013-03-12 13:56:51.801956 [DEBUG] sofia_glue.c:5266 Set 2833 dtmf send/recv payload to 101 2013-03-12 13:56:51.801956 [DEBUG] sofia.c:5818 (sofia/sipinterface_6/ 401@192.168.54.69) State Change CS_NEW -> CS_INIT 2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_INIT 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454 (sofia/sipinterface_6/401@192.168.54.69) State INIT 2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:86 sofia/sipinterface_6/ 401@192.168.54.69 SOFIA INIT 2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:126 (sofia/sipinterface_6/ 401@192.168.54.69) State Change CS_INIT -> CS_ROUTING 2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454 (sofia/sipinterface_6/401@192.168.54.69) State INIT going to sleep 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_ROUTING 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:2003 (sofia/sipinterface_6/401@192.168.54.69) Callstate Change DOWN -> RINGING 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_6/401@192.168.54.69) State ROUTING 2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:149 sofia/sipinterface_6/ 401@192.168.54.69 SOFIA ROUTING 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:117 sofia/sipinterface_6/401@192.168.54.69 Standard ROUTING 2013-03-12 13:56:51.801956 [INFO] mod_dialplan_xml.c:557 Processing Parsa <401>->403 in context context_1 Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->conditioning_callerid] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (PASS) [conditioning_callerid] ${internal_caller_id_number}(401) =~ /^.+$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(effective_caller_id_name=${internal_caller_id_name}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(effective_caller_id_number=${internal_caller_id_number}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->conditioning_callrecord] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Absolute Condition [conditioning_callrecord] Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RECORD_TITLE=Recording ${destination_number} ${caller_id_number} ${strftime(%Y-%m-%d %H:%M)}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RECORD_COPYRIGHT=(c) 2010 VoIP, Inc.) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RECORD_SOFTWARE=blue.box) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RECORD_ARTIST=2600hz) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RECORD_COMMENT=Automatically recorded via FreeSWITCH with blue.box) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RECORD_DATE=${strftime(%Y-%m-%d %H:%M)}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RECORD_STEREO=true) Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->postroute_global] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Absolute Condition [postroute_global] Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->preanswer_callrecord_outbound] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [preanswer_callrecord_outbound] ${callrecord_outbound}() =~ /^.+$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_17] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_17] destination_number(403) =~ /^334$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_18] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_18] destination_number(403) =~ /^496$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_23] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_23] destination_number(403) =~ /^4101$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_13] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_13] destination_number(403) =~ /^288|223$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_25] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_25] destination_number(403) =~ /^422$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_27] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_27] destination_number(403) =~ /^0[^0][0-9]{9}$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_28] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_28] destination_number(403) =~ /^401$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_29] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_29] destination_number(403) =~ /^402$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_30] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (PASS) [main_number_30] destination_number(403) =~ /^403$/ break=on-false Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(call_timeout=30) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(ringback=local_stream://moh) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action export(sip_callee_id_name=m.emami) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action export(sip_callee_id_number=403) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action bridge(user/ 403@192.168.54.69) Dialplan: sofia/sipinterface_6/401@192.168.54.69 Action hangup() Dialplan: sofia/sipinterface_6/401@192.168.54.69 parsing [context_1->main_number_31] continue=true Dialplan: sofia/sipinterface_6/401@192.168.54.69 Regex (FAIL) [main_number_31] destination_number(403) =~ /^497$/ break=on-false 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:167 (sofia/sipinterface_6/401@192.168.54.69) State Change CS_ROUTING -> CS_EXECUTE 2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_6/401@192.168.54.69) State ROUTING going to sleep 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_EXECUTE 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:477 (sofia/sipinterface_6/401@192.168.54.69) State EXECUTE 2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:242 sofia/sipinterface_6/ 401@192.168.54.69 SOFIA EXECUTE 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:209 sofia/sipinterface_6/401@192.168.54.69 Standard EXECUTE EXECUTE sofia/sipinterface_6/401@192.168.54.69set(effective_caller_id_name=Parsa Moshrefi) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [effective_caller_id_name]=[Parsa Moshrefi] EXECUTE sofia/sipinterface_6/401@192.168.54.69set(effective_caller_id_number=401) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [effective_caller_id_number]=[401] EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_TITLE=Recording 403 401 2013-03-12 13:56) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RECORD_TITLE]=[Recording 403 401 2013-03-12 13:56] EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_COPYRIGHT=(c) 2010 VoIP, Inc.) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RECORD_COPYRIGHT]=[(c) 2010 VoIP, Inc.] EXECUTE sofia/sipinterface_6/401@192.168.54.69set(RECORD_SOFTWARE=blue.box) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RECORD_SOFTWARE]=[blue.box] EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_ARTIST=2600hz) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RECORD_ARTIST]=[2600hz] EXECUTE sofia/sipinterface_6/401@192.168.54.69set(RECORD_COMMENT=Automatically recorded via FreeSWITCH with blue.box) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RECORD_COMMENT]=[Automatically recorded via FreeSWITCH with blue.box] EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_DATE=2013-03-12 13:56) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RECORD_DATE]=[2013-03-12 13:56] EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RECORD_STEREO=true) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RECORD_STEREO]=[true] EXECUTE sofia/sipinterface_6/401@192.168.54.69hash(insert/192.168.54.69-spymap/401/5ab2118c-8aff-11e2-bd72-4f1eb6844087) EXECUTE sofia/sipinterface_6/401@192.168.54.69hash(insert/192.168.54.69-last_dial/401/403) EXECUTE sofia/sipinterface_6/401@192.168.54.69hash(insert/192.168.54.69-last_dial/global/5ab2118c-8aff-11e2-bd72-4f1eb6844087) EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(RFC2822_DATE=Tue, 12 Mar 2013 13:56:51 ) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [RFC2822_DATE]=[Tue, 12 Mar 2013 13:56:51 ] EXECUTE sofia/sipinterface_6/401@192.168.54.69 set(call_timeout=30) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [call_timeout]=[30] EXECUTE sofia/sipinterface_6/401@192.168.54.69set(ringback=local_stream://moh) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [ringback]=[local_stream://moh] EXECUTE sofia/sipinterface_6/401@192.168.54.69set(transfer_ringback=local_stream://moh) 2013-03-12 13:56:51.801956 [DEBUG] mod_dptools.c:1344 sofia/sipinterface_6/ 401@192.168.54.69 SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/sipinterface_6/401@192.168.54.69export(sip_callee_id_name=m.emami) 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1135 EXPORT (export_vars) [sip_callee_id_name]=[m.emami] EXECUTE sofia/sipinterface_6/401@192.168.54.69export(sip_callee_id_number=403) 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1135 EXPORT (export_vars) [sip_callee_id_number]=[403] EXECUTE sofia/sipinterface_6/401@192.168.54.69 bridge(user/ 403@192.168.54.69) 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089 sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars] [sip_callee_id_name]=[m.emami] to event 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089 sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars] [sip_callee_id_number]=[403] to event 2013-03-12 13:56:51.801956 [DEBUG] switch_ivr_originate.c:2022 Parsing global variables 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089 sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars] [sip_callee_id_name]=[m.emami] to event 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:1089 sofia/sipinterface_6/401@192.168.54.69 EXPORTING[export_vars] [sip_callee_id_number]=[403] to event 2013-03-12 13:56:51.801956 [DEBUG] switch_ivr_originate.c:2022 Parsing global variables 2013-03-12 13:56:51.801956 [DEBUG] switch_event.c:1608 Parsing variable [presence_id]=[403@192.168.54.69] 2013-03-12 13:56:51.801956 [NOTICE] switch_channel.c:968 New Channel sofia/sipinterface_6/sip:403@192.168.1.115[5abc3f36-8aff-11e2-bd8e-4f1eb6844087] 2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:4961 (sofia/sipinterface_6/ sip:403@192.168.1.115) State Change CS_NEW -> CS_INIT 2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK] 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_INIT 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454 (sofia/sipinterface_6/sip:403@192.168.1.115) State INIT 2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:86 sofia/sipinterface_6/ sip:403@192.168.1.115 SOFIA INIT 2013-03-12 13:56:51.801956 [DEBUG] sofia_glue.c:2647 Local SDP: v=0 o=FreeSWITCH 1363059707 1363059708 IN IP4 192.168.54.69 s=FreeSWITCH c=IN IP4 192.168.54.69 t=0 0 m=audio 24304 RTP/AVP 8 9 0 3 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv
2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:126 (sofia/sipinterface_6/ sip:403@192.168.1.115) State Change CS_INIT -> CS_ROUTING 2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK] 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:454 (sofia/sipinterface_6/sip:403@192.168.1.115) State INIT going to sleep 2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:975 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK] 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_ROUTING 2013-03-12 13:56:51.801956 [DEBUG] switch_channel.c:2003 (sofia/sipinterface_6/sip:403@192.168.1.115) Callstate Change DOWN -> RINGING 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_6/sip:403@192.168.1.115) State ROUTING 2013-03-12 13:56:51.801956 [DEBUG] mod_sofia.c:149 sofia/sipinterface_6/ sip:403@192.168.1.115 SOFIA ROUTING 2013-03-12 13:56:51.801956 [DEBUG] switch_ivr_originate.c:67 (sofia/sipinterface_6/sip:403@192.168.1.115) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2013-03-12 13:56:51.801956 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK] 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:470 (sofia/sipinterface_6/sip:403@192.168.1.115) State ROUTING going to sleep 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_CONSUME_MEDIA 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:489 (sofia/sipinterface_6/sip:403@192.168.1.115) State CONSUME_MEDIA 2013-03-12 13:56:51.801956 [DEBUG] switch_core_state_machine.c:489 (sofia/sipinterface_6/sip:403@192.168.1.115) State CONSUME_MEDIA going to sleep 2013-03-12 13:56:51.801956 [DEBUG] sofia.c:5574 Channel sofia/sipinterface_6/sip:403@192.168.1.115 entering state [calling][0] 2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:2994 (sofia/sipinterface_6/sip:403@192.168.1.115) Callstate Change RINGING -> HANGUP 2013-03-12 13:57:21.001969 [NOTICE] switch_ivr_originate.c:3351 Hangup sofia/sipinterface_6/sip:403@192.168.1.115 [CS_CONSUME_MEDIA] [NO_ANSWER] 2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_HANGUP 2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:3017 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [KILL] 2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK] 2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:667 (sofia/sipinterface_6/sip:403@192.168.1.115) State HANGUP 2013-03-12 13:57:21.001969 [DEBUG] mod_sofia.c:503 Channel sofia/sipinterface_6/sip:403@192.168.1.115 hanging up, cause: NO_ANSWER 2013-03-12 13:57:21.001969 [NOTICE] switch_ivr_originate.c:2608 Cannot create outgoing channel of type [user] cause: [NO_ANSWER] 2013-03-12 13:57:21.001969 [DEBUG] switch_ivr_originate.c:3533 Originate Resulted in Error Cause: 19 [NO_ANSWER] 2013-03-12 13:57:21.001969 [INFO] mod_dptools.c:3055 Originate Failed. Cause: NO_ANSWER EXECUTE sofia/sipinterface_6/401@192.168.54.69 hangup() 2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:2994 (sofia/sipinterface_6/401@192.168.54.69) Callstate Change RINGING -> HANGUP 2013-03-12 13:57:21.001969 [NOTICE] mod_dptools.c:1150 Hangup sofia/sipinterface_6/401@192.168.54.69 [CS_EXECUTE] [NORMAL_CLEARING] 2013-03-12 13:57:21.001969 [DEBUG] switch_channel.c:3017 Send signal sofia/sipinterface_6/401@192.168.54.69 [KILL] 2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:57:21.001969 [DEBUG] switch_core_session.c:2689 sofia/sipinterface_6/401@192.168.54.69 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:477 (sofia/sipinterface_6/401@192.168.54.69) State EXECUTE going to sleep 2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_HANGUP 2013-03-12 13:57:21.001969 [DEBUG] switch_core_state_machine.c:667 (sofia/sipinterface_6/401@192.168.54.69) State HANGUP 2013-03-12 13:57:21.001969 [DEBUG] mod_sofia.c:503 Channel sofia/sipinterface_6/401@192.168.54.69 hanging up, cause: NORMAL_CLEARING 2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:562 Sending CANCEL to sofia/sipinterface_6/sip:403@192.168.1.115 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:48 sofia/sipinterface_6/sip:403@192.168.1.115 Standard HANGUP, cause: NO_ANSWER 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:667 (sofia/sipinterface_6/sip:403@192.168.1.115) State HANGUP going to sleep 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:446 (sofia/sipinterface_6/sip:403@192.168.1.115) State Change CS_HANGUP -> CS_REPORTING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK] 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_REPORTING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749 (sofia/sipinterface_6/sip:403@192.168.1.115) State REPORTING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:92 sofia/sipinterface_6/sip:403@192.168.1.115 Standard REPORTING, cause: NO_ANSWER 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749 (sofia/sipinterface_6/sip:403@192.168.1.115) State REPORTING going to sleep 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:440 (sofia/sipinterface_6/sip:403@192.168.1.115) State Change CS_REPORTING -> CS_DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/sip:403@192.168.1.115 [BREAK] 2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1499 Session 48 (sofia/sipinterface_6/sip:403@192.168.1.115) Locked, Waiting on external entities 2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1517 Session 48 (sofia/sipinterface_6/sip:403@192.168.1.115) Ended 2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1521 Close Channel sofia/sipinterface_6/sip:403@192.168.1.115 [CS_DESTROY] 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:556 (sofia/sipinterface_6/sip:403@192.168.1.115) Callstate Change HANGUP -> DOWN 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:559 (sofia/sipinterface_6/sip:403@192.168.1.115) Running State Change CS_DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569 (sofia/sipinterface_6/sip:403@192.168.1.115) State DESTROY 2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:396 sofia/sipinterface_6/ sip:403@192.168.1.115 SOFIA DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:99 sofia/sipinterface_6/sip:403@192.168.1.115 Standard DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569 (sofia/sipinterface_6/sip:403@192.168.1.115) State DESTROY going to sleep 2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:633 Responding to INVITE with: 480 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:48 sofia/sipinterface_6/401@192.168.54.69 Standard HANGUP, cause: NORMAL_CLEARING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:667 (sofia/sipinterface_6/401@192.168.54.69) State HANGUP going to sleep 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:446 (sofia/sipinterface_6/401@192.168.54.69) State Change CS_HANGUP -> CS_REPORTING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:415 (sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_REPORTING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749 (sofia/sipinterface_6/401@192.168.54.69) State REPORTING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:92 sofia/sipinterface_6/401@192.168.54.69 Standard REPORTING, cause: NORMAL_CLEARING 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:749 (sofia/sipinterface_6/401@192.168.54.69) State REPORTING going to sleep 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:440 (sofia/sipinterface_6/401@192.168.54.69) State Change CS_REPORTING -> CS_DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1291 Send signal sofia/sipinterface_6/401@192.168.54.69 [BREAK] 2013-03-12 13:57:21.021986 [DEBUG] switch_core_session.c:1499 Session 47 (sofia/sipinterface_6/401@192.168.54.69) Locked, Waiting on external entities 2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1517 Session 47 (sofia/sipinterface_6/401@192.168.54.69) Ended 2013-03-12 13:57:21.021986 [NOTICE] switch_core_session.c:1521 Close Channel sofia/sipinterface_6/401@192.168.54.69 [CS_DESTROY] 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:556 (sofia/sipinterface_6/401@192.168.54.69) Callstate Change HANGUP -> DOWN 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:559 (sofia/sipinterface_6/401@192.168.54.69) Running State Change CS_DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569 (sofia/sipinterface_6/401@192.168.54.69) State DESTROY 2013-03-12 13:57:21.021986 [DEBUG] mod_sofia.c:396 sofia/sipinterface_6/ 401@192.168.54.69 SOFIA DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:99 sofia/sipinterface_6/401@192.168.54.69 Standard DESTROY 2013-03-12 13:57:21.021986 [DEBUG] switch_core_state_machine.c:569 (sofia/sipinterface_6/401@192.168.54.69) State DESTROY going to sleep
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Michael S Collins Twitter: @mercutioviz http://www.FreeSWITCH.org http://www.ClueCon.com http://www.OSTAG.org