No Busy Tone and No Announcement Messages on ISDN-VoIP SIP Calls
[Freeswitch-users] No Busy Tone and No Announcement Messages on ISDN-VoIP SIP Calls Michael Collins msc <mailto:freeswitch-users%40lists.freeswitch.org?Subject=%5BFreeswitch-users% 5D%20No%20Busy%20Tone%20and%20No%20Announcement%20Messages%20on%0A%20ISDN-Vo IP%20SIP%20Calls&In-Reply-To=018101cb80a8%24bda43ef0%2438ecbcd0%24%40com> at freeswitch.org Wed Nov 10 09:53:09 PST 2010 * Previous message: [Freeswitch-users] <http://lists.freeswitch.org/pipermail/freeswitch-users/2010-November/064962 .html> No Busy Tone and No Announcement Messages on ISDN-VoIP SIP Calls * Next message: [Freeswitch-users] <http://lists.freeswitch.org/pipermail/freeswitch-users/2010-November/064965 .html> trap ## * Messages sorted by: [ <http://lists.freeswitch.org/pipermail/freeswitch-users/2010-November/date.h tml#65110> date ] [ <http://lists.freeswitch.org/pipermail/freeswitch-users/2010-November/thread .html#65110> thread ] [ <http://lists.freeswitch.org/pipermail/freeswitch-users/2010-November/subjec t.html#65110> subject ] [ <http://lists.freeswitch.org/pipermail/freeswitch-users/2010-November/author .html#65110> author ] _____ Hi Michael, The brief network diagram is like this. TDM---Cisco gateway--(SIP)-Freeswitch---IP Phones Cisco gateway and Freeswitch are on the same subnet. Below is the console log (calling from 31754129 to 92882810(this number is a wrong number)). 2010-11-11 11:30:59.210916 [NOTICE] switch_channel.c:779 New Channel sofia/internal/31754129@203.194.134.81:5060 [f3f06789-8c87-4982-956c-6f2b3317af72] 2010-11-11 11:30:59.210916 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/31754129@203.194.134.81:5060) Running State Change CS_NEW 2010-11-11 11:30:59.214961 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/31754129@203.194.134.81:5060) State NEW 2010-11-11 11:30:59.230913 [DEBUG] sofia.c:4455 Channel sofia/internal/31754129@203.194.134.81:5060 entering state [received][100] 2010-11-11 11:30:59.230913 [DEBUG] sofia.c:4466 Remote SDP: v=0 o=DBLE 1289446299 1289446299 IN IP4 10.0.166.181 s=DBLE c=IN IP4 10.0.166.181 t=0 0 m=audio 16384 RTP/AVP 18 4 0 3 8 101 a=rtpmap:18 G729/8000 a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 2010-11-11 11:30:59.230913 [DEBUG] sofia_glue.c:4000 Audio Codec Compare [G729:18:8000:20]/[PCMU:0:8000:20] 2010-11-11 11:30:59.230913 [DEBUG] sofia_glue.c:4000 Audio Codec Compare [G729:18:8000:20]/[PCMA:8:8000:20] 2010-11-11 11:30:59.230913 [DEBUG] sofia_glue.c:4000 Audio Codec Compare [G723:4:8000:20]/[PCMU:0:8000:20] 2010-11-11 11:30:59.230913 [DEBUG] sofia_glue.c:4000 Audio Codec Compare [G723:4:8000:20]/[PCMA:8:8000:20] 2010-11-11 11:30:59.230913 [DEBUG] sofia_glue.c:4000 Audio Codec Compare [PCMU:0:8000:20]/[PCMU:0:8000:20] 2010-11-11 11:30:59.230913 [DEBUG] sofia_glue.c:2533 Set Codec sofia/internal/31754129@203.194.134.81:5060 PCMU/8000 20 ms 160 samples 2010-11-11 11:30:59.230913 [DEBUG] sofia_glue.c:4096 Set 2833 dtmf send/recv payload to 101 2010-11-11 11:30:59.230913 [DEBUG] sofia.c:4626 (sofia/internal/31754129@203.194.134.81:5060) State Change CS_NEW -> CS_INIT 2010-11-11 11:30:59.230913 [DEBUG] switch_core_session.c:1047 Send signal sofia/internal/31754129@203.194.134.81:5060 [BREAK] 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/31754129@203.194.134.81:5060) Running State Change CS_INIT 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/31754129@203.194.134.81:5060) State INIT 2010-11-11 11:30:59.234925 [DEBUG] mod_sofia.c:83 sofia/internal/31754129@203.194.134.81:5060 SOFIA INIT 2010-11-11 11:30:59.234925 [DEBUG] mod_sofia.c:123 (sofia/internal/31754129@203.194.134.81:5060) State Change CS_INIT -> CS_ROUTING 2010-11-11 11:30:59.234925 [DEBUG] switch_core_session.c:1047 Send signal sofia/internal/31754129@203.194.134.81:5060 [BREAK] 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/31754129@203.194.134.81:5060) State INIT going to sleep 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/31754129@203.194.134.81:5060) Running State Change CS_ROUTING 2010-11-11 11:30:59.234925 [DEBUG] switch_channel.c:1517 (sofia/internal/31754129@203.194.134.81:5060) Callstate Change DOWN -> RINGING 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/31754129@203.194.134.81:5060) State ROUTING 2010-11-11 11:30:59.234925 [DEBUG] mod_sofia.c:146 sofia/internal/31754129@203.194.134.81:5060 SOFIA ROUTING 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:77 sofia/internal/31754129@203.194.134.81:5060 Standard ROUTING 2010-11-11 11:30:59.234925 [INFO] mod_dialplan_xml.c:331 Processing 31754129 <31754129>->92882810 in context default Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->unloop] continue=false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->tod_example] continue=true Dialplan: sofia/internal/31754129@203.194.134.81:5060 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Action set(open=true) Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/31754129@203.194.134.81:5060 Date/Time Match (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->pizza_demo] continue=false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (FAIL) [pizza_demo] destination_number(92882810) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->local.example.com] continue=false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (FAIL) [local.example.com] ${toll_allow}() =~ /local/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->domestic.example.com] continue=false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (FAIL) [domestic.example.com] ${toll_allow}() =~ /domestic/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->international.example.com] continue=false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (FAIL) [international.example.com] ${toll_allow}() =~ /international/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 parsing [default->NWT_DID_outbound_31754129] continue=false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (PASS) [NWT_DID_outbound_31754129] caller_id_number(31754129) =~ /31754129/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Regex (PASS) [NWT_DID_outbound_31754129] destination_number(92882810) =~ /^(\d{8})$/ break=on-false Dialplan: sofia/internal/31754129@203.194.134.81:5060 Action set(ringback=${hk-ring}) Dialplan: sofia/internal/31754129@203.194.134.81:5060 Action bridge(sofia/external/92882810@203.194.134.80) 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/31754129@203.194.134.81:5060) State Change CS_ROUTING -> CS_EXECUTE 2010-11-11 11:30:59.234925 [DEBUG] switch_core_session.c:1047 Send signal sofia/internal/31754129@203.194.134.81:5060 [BREAK] 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/31754129@203.194.134.81:5060) State ROUTING going to sleep 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/31754129@203.194.134.81:5060) Running State Change CS_EXECUTE 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/31754129@203.194.134.81:5060) State EXECUTE 2010-11-11 11:30:59.234925 [DEBUG] mod_sofia.c:239 sofia/internal/31754129@203.194.134.81:5060 SOFIA EXECUTE 2010-11-11 11:30:59.234925 [DEBUG] switch_core_state_machine.c:157 sofia/internal/31754129@203.194.134.81:5060 Standard EXECUTE EXECUTE sofia/internal/31754129@203.194.134.81:5060 set(open=true) 2010-11-11 11:30:59.234925 [DEBUG] mod_dptools.c:854 sofia/internal/31754129@203.194.134.81:5060 SET [open]=[true] EXECUTE sofia/internal/31754129@203.194.134.81:5060 set(ringback=%(400,200,440,480);%(400,3000,440,480)) 2010-11-11 11:30:59.234925 [DEBUG] mod_dptools.c:854 sofia/internal/31754129@203.194.134.81:5060 SET [ringback]=[%(400,200,440,480);%(400,3000,440,480)] EXECUTE sofia/internal/31754129@203.194.134.81:5060 bridge(sofia/external/92882810@203.194.134.80) 2010-11-11 11:30:59.234925 [NOTICE] switch_channel.c:779 New Channel sofia/external/92882810@203.194.134.80 [dca9cd37-7593-417c-82fc-10d98bd90b16] 2010-11-11 11:30:59.243107 [DEBUG] mod_sofia.c:3950 (sofia/external/92882810@203.194.134.80) State Change CS_NEW -> CS_INIT 2010-11-11 11:30:59.243107 [DEBUG] switch_core_session.c:1047 Send signal sofia/external/92882810@203.194.134.80 [BREAK] 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:314 (sofia/external/92882810@203.194.134.80) Running State Change CS_INIT 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:338 (sofia/external/92882810@203.194.134.80) State INIT 2010-11-11 11:30:59.243107 [DEBUG] mod_sofia.c:83 sofia/external/92882810@203.194.134.80 SOFIA INIT 2010-11-11 11:30:59.243107 [DEBUG] mod_sofia.c:123 (sofia/external/92882810@203.194.134.80) State Change CS_INIT -> CS_ROUTING 2010-11-11 11:30:59.243107 [DEBUG] switch_core_session.c:1047 Send signal sofia/external/92882810@203.194.134.80 [BREAK] 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:338 (sofia/external/92882810@203.194.134.80) State INIT going to sleep 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:314 (sofia/external/92882810@203.194.134.80) Running State Change CS_ROUTING 2010-11-11 11:30:59.243107 [DEBUG] switch_channel.c:1517 (sofia/external/92882810@203.194.134.80) Callstate Change DOWN -> RINGING 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:341 (sofia/external/92882810@203.194.134.80) State ROUTING 2010-11-11 11:30:59.243107 [DEBUG] mod_sofia.c:146 sofia/external/92882810@203.194.134.80 SOFIA ROUTING 2010-11-11 11:30:59.243107 [DEBUG] sofia.c:4455 Channel sofia/external/92882810@203.194.134.80 entering state [calling][0] 2010-11-11 11:30:59.243107 [DEBUG] switch_ivr_originate.c:66 (sofia/external/92882810@203.194.134.80) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2010-11-11 11:30:59.243107 [DEBUG] switch_core_session.c:1047 Send signal sofia/external/92882810@203.194.134.80 [BREAK] 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:341 (sofia/external/92882810@203.194.134.80) State ROUTING going to sleep 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:314 (sofia/external/92882810@203.194.134.80) Running State Change CS_CONSUME_MEDIA 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:360 (sofia/external/92882810@203.194.134.80) State CONSUME_MEDIA 2010-11-11 11:30:59.243107 [DEBUG] switch_core_state_machine.c:360 (sofia/external/92882810@203.194.134.80) State CONSUME_MEDIA going to sleep 2010-11-11 11:30:59.726960 [INFO] sofia.c:709 sofia/external/90226864@203.194.134.80 Update Callee ID to "90226864" <90226864> 2010-11-11 11:30:59.726960 [DEBUG] sofia.c:4455 Channel sofia/external/90226864@203.194.134.80 entering state [proceeding][180] 2010-11-11 11:30:59.726960 [NOTICE] sofia.c:4527 Ring-Ready sofia/external/90226864@203.194.134.80! 2010-11-11 11:30:59.738964 [INFO] switch_ivr_originate.c:1079 Sending early media 2010-11-11 11:30:59.738964 [DEBUG] sofia_glue.c:2773 AUDIO RTP [sofia/internal/31754156@203.194.134.81] 203.194.134.81 port 30158 -> 120.83.66.232 port 16430 codec: 0 ms: 30 2010-11-11 11:30:59.738964 [DEBUG] switch_rtp.c:1417 Starting timer [soft] 240 bytes per 30ms 2010-11-11 11:30:59.742998 [DEBUG] sofia_glue.c:2983 Set 2833 dtmf send payload to 101 2010-11-11 11:30:59.742998 [DEBUG] sofia_glue.c:2988 Set 2833 dtmf receive payload to 101 2010-11-11 11:30:59.742998 [DEBUG] mod_sofia.c:2168 Ring SDP: v=0 o=FreeSWITCH 1289416101 1289416102 IN IP4 203.194.134.81 s=FreeSWITCH c=IN IP4 203.194.134.81 t=0 0 m=audio 30158 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:30 a=sendrecv 2010-11-11 11:30:59.742998 [NOTICE] mod_sofia.c:2171 Pre-Answer sofia/internal/31754156@203.194.134.81! 2010-11-11 11:30:59.742998 [DEBUG] switch_channel.c:2444 (sofia/internal/31754156@203.194.134.81) Callstate Change RINGING -> EARLY 2010-11-11 11:30:59.742998 [DEBUG] switch_core_session.c:666 Send signal sofia/internal/31754156@203.194.134.81 [BREAK] 2010-11-11 11:30:59.742998 [DEBUG] switch_ivr_originate.c:1128 Raw Codec Activation Success L16@8000hz 1 channel 30ms 2010-11-11 11:30:59.742998 [DEBUG] switch_core_codec.c:116 sofia/internal/31754156@203.194.134.81 Push codec L16:10 2010-11-11 11:30:59.742998 [DEBUG] switch_ivr_originate.c:1193 Play Ringback Tone [%(400,200,440,480);%(400,3000,440,480)] 2010-11-11 11:30:59.742998 [DEBUG] sofia.c:4450 Channel sofia/internal/31754156@203.194.134.81 skipping state [early][183] 2010-11-11 11:31:00.083016 [INFO] switch_rtp.c:2521 Auto Changing port from 120.83.66.232:16430 to 120.83.66.232:24822 2010-11-11 11:31:00.382989 [INFO] sofia.c:709 sofia/external/92882810@203.194.134.80 Update Callee ID to "92882810" <92882810> 2010-11-11 11:31:00.382989 [DEBUG] sofia.c:4455 Channel sofia/external/92882810@203.194.134.80 entering state [proceeding][180] 2010-11-11 11:31:00.382989 [NOTICE] sofia.c:4527 Ring-Ready sofia/external/92882810@203.194.134.80! 2010-11-11 11:31:00.391009 [INFO] switch_ivr_originate.c:1079 Sending early media 2010-11-11 11:31:00.391009 [DEBUG] sofia_glue.c:2773 AUDIO RTP [sofia/internal/31754129@203.194.134.81:5060] 203.194.134.81 port 21858 -> 10.0.166.181 port 16384 codec: 0 ms: 20 2010-11-11 11:31:00.391009 [DEBUG] switch_rtp.c:1417 Starting timer [soft] 160 bytes per 20ms 2010-11-11 11:31:00.394994 [DEBUG] sofia_glue.c:2983 Set 2833 dtmf send payload to 101 2010-11-11 11:31:00.394994 [DEBUG] sofia_glue.c:2988 Set 2833 dtmf receive payload to 101 2010-11-11 11:31:00.394994 [DEBUG] mod_sofia.c:2168 Ring SDP: v=0 o=FreeSWITCH 1289424402 1289424403 IN IP4 203.194.134.81 s=FreeSWITCH c=IN IP4 203.194.134.81 t=0 0 m=audio 21858 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2010-11-11 11:31:00.394994 [NOTICE] mod_sofia.c:2171 Pre-Answer sofia/internal/31754129@203.194.134.81:5060! 2010-11-11 11:31:00.394994 [DEBUG] switch_channel.c:2444 (sofia/internal/31754129@203.194.134.81:5060) Callstate Change RINGING -> EARLY 2010-11-11 11:31:00.394994 [DEBUG] switch_core_session.c:666 Send signal sofia/internal/31754129@203.194.134.81:5060 [BREAK] 2010-11-11 11:31:00.394994 [DEBUG] switch_ivr_originate.c:1128 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2010-11-11 11:31:00.394994 [DEBUG] switch_core_codec.c:116 sofia/internal/31754129@203.194.134.81:5060 Push codec L16:10 2010-11-11 11:31:00.394994 [DEBUG] switch_ivr_originate.c:1193 Play Ringback Tone [%(400,200,440,480);%(400,3000,440,480)] 2010-11-11 11:31:00.400593 [DEBUG] sofia.c:4450 Channel sofia/internal/31754129@203.194.134.81:5060 skipping state [early][183] internal/31754129@203.194.134.81:5060 Restore previous codec PCMU:0. 2010-11-11 11:31:59.010658 [DEBUG] switch_channel.c:2357 (sofia/external/92882810@203.194.134.80) Callstate Change RINGING -> HANGUP 2010-11-11 11:31:59.010658 [NOTICE] switch_ivr_originate.c:3307 Hangup sofia/external/92882810@203.194.134.80 [CS_CONSUME_MEDIA] [NO_ANSWER] 2010-11-11 11:31:59.010658 [DEBUG] switch_channel.c:2373 Send signal sofia/external/92882810@203.194.134.80 [KILL] 2010-11-11 11:31:59.010658 [DEBUG] switch_core_session.c:1047 Send signal sofia/external/92882810@203.194.134.80 [BREAK] 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:314 (sofia/external/92882810@203.194.134.80) Running State Change CS_HANGUP 2010-11-11 11:31:59.010658 [INFO] mod_dptools.c:2411 Originate Failed. Cause: NO_ANSWER 2010-11-11 11:31:59.010658 [NOTICE] switch_core_state_machine.c:185 sofia/internal/31754129@203.194.134.81:5060 has executed the last dialplan instruction, hanging up. 2010-11-11 11:31:59.010658 [DEBUG] switch_channel.c:2357 (sofia/internal/31754129@203.194.134.81:5060) Callstate Change EARLY -> HANGUP 2010-11-11 11:31:59.010658 [NOTICE] switch_core_state_machine.c:187 Hangup sofia/internal/31754129@203.194.134.81:5060 [CS_EXECUTE] [NORMAL_CLEARING] 2010-11-11 11:31:59.010658 [DEBUG] switch_channel.c:2373 Send signal sofia/internal/31754129@203.194.134.81:5060 [KILL] 2010-11-11 11:31:59.010658 [DEBUG] switch_core_session.c:1047 Send signal sofia/internal/31754129@203.194.134.81:5060 [BREAK] 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/31754129@203.194.134.81:5060) State EXECUTE going to sleep 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/31754129@203.194.134.81:5060) Running State Change CS_HANGUP 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/31754129@203.194.134.81:5060) State HANGUP 2010-11-11 11:31:59.010658 [DEBUG] mod_sofia.c:457 Channel sofia/internal/31754129@203.194.134.81:5060 hanging up, cause: NORMAL_CLEARING 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:535 (sofia/external/92882810@203.194.134.80) State HANGUP 2010-11-11 11:31:59.010658 [DEBUG] mod_sofia.c:457 Channel sofia/external/92882810@203.194.134.80 hanging up, cause: NO_ANSWER 2010-11-11 11:31:59.010658 [DEBUG] mod_sofia.c:510 Sending CANCEL to sofia/external/92882810@203.194.134.80 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:46 sofia/external/92882810@203.194.134.80 Standard HANGUP, cause: NO_ANSWER 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:535 (sofia/external/92882810@203.194.134.80) State HANGUP going to sleep 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:333 (sofia/external/92882810@203.194.134.80) State Change CS_HANGUP -> CS_REPORTING 2010-11-11 11:31:59.010658 [DEBUG] switch_core_session.c:1047 Send signal sofia/external/92882810@203.194.134.80 [BREAK] 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:314 (sofia/external/92882810@203.194.134.80) Running State Change CS_REPORTING 2010-11-11 11:31:59.010658 [DEBUG] switch_core_state_machine.c:595 (sofia/external/92882810@203.194.134.80) State REPORTING 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:53 sofia/external/92882810@203.194.134.80 Standard REPORTING, cause: NO_ANSWER 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:595 (sofia/external/92882810@203.194.134.80) State REPORTING going to sleep 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:327 (sofia/external/92882810@203.194.134.80) State Change CS_REPORTING -> CS_DESTROY 2010-11-11 11:31:59.014663 [DEBUG] switch_core_session.c:1047 Send signal sofia/external/92882810@203.194.134.80 [BREAK] 2010-11-11 11:31:59.014663 [DEBUG] switch_core_session.c:1210 Session 6351 (sofia/external/92882810@203.194.134.80) Locked, Waiting on external entities 2010-11-11 11:31:59.014663 [NOTICE] switch_core_session.c:1228 Session 6351 (sofia/external/92882810@203.194.134.80) Ended 2010-11-11 11:31:59.014663 [NOTICE] switch_core_session.c:1230 Close Channel sofia/external/92882810@203.194.134.80 [CS_DESTROY] 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:427 (sofia/external/92882810@203.194.134.80) Callstate Change HANGUP -> DOWN 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:430 (sofia/external/92882810@203.194.134.80) Running State Change CS_DESTROY 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:440 (sofia/external/92882810@203.194.134.80) State DESTROY 2010-11-11 11:31:59.014663 [DEBUG] mod_sofia.c:362 sofia/external/92882810@203.194.134.80 SOFIA DESTROY 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:60 sofia/external/92882810@203.194.134.80 Standard DESTROY 2010-11-11 11:31:59.014663 [DEBUG] switch_core_state_machine.c:440 (sofia/external/92882810@203.194.134.80) State DESTROY going to sleep 2010-11-11 11:31:59.034666 [DEBUG] mod_sofia.c:519 Responding to INVITE with: 480 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:46 sofia/internal/31754129@203.194.134.81:5060 Standard HANGUP, cause: NORMAL_CLEARING 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/31754129@203.194.134.81:5060) State HANGUP going to sleep 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/31754129@203.194.134.81:5060) State Change CS_HANGUP -> CS_REPORTING 2010-11-11 11:31:59.034666 [DEBUG] switch_core_session.c:1047 Send signal sofia/internal/31754129@203.194.134.81:5060 [BREAK] 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/31754129@203.194.134.81:5060) Running State Change CS_REPORTING 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/31754129@203.194.134.81:5060) State REPORTING 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:53 sofia/internal/31754129@203.194.134.81:5060 Standard REPORTING, cause: NORMAL_CLEARING 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/31754129@203.194.134.81:5060) State REPORTING going to sleep 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/31754129@203.194.134.81:5060) State Change CS_REPORTING -> CS_DESTROY 2010-11-11 11:31:59.034666 [DEBUG] switch_core_session.c:1047 Send signal sofia/internal/31754129@203.194.134.81:5060 [BREAK] 2010-11-11 11:31:59.034666 [DEBUG] switch_core_session.c:1210 Session 6350 (sofia/internal/31754129@203.194.134.81:5060) Locked, Waiting on external entities 2010-11-11 11:31:59.034666 [NOTICE] switch_core_session.c:1228 Session 6350 (sofia/internal/31754129@203.194.134.81:5060) Ended 2010-11-11 11:31:59.034666 [NOTICE] switch_core_session.c:1230 Close Channel sofia/internal/31754129@203.194.134.81:5060 [CS_DESTROY] 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:427 (sofia/internal/31754129@203.194.134.81:5060) Callstate Change HANGUP -> DOWN 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/31754129@203.194.134.81:5060) Running State Change CS_DESTROY 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/31754129@203.194.134.81:5060) State DESTROY 2010-11-11 11:31:59.034666 [DEBUG] mod_sofia.c:362 sofia/internal/31754129@203.194.134.81:5060 SOFIA DESTROY 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:60 sofia/internal/31754129@203.194.134.81:5060 Standard DESTROY 2010-11-11 11:31:59.034666 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/31754129@203.194.134.81:5060) State DESTROY going to sleep Thanks Raymond You've left out a lot of information, like how are these devices connected? and what shows up in the console log? -MC On Tue, Nov 9, 2010 at 11:27 PM, Raymond Chan <raymondchan at commverge.com <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users> >wrote:
Hi all,
We are using Freeswitch and using Cisco 2811 as gateway, we have SIP phones registered in our Freeswitch and trying to call a non-exit number (mobile number). We found the SIP phone still has ringtone. When we use PSTN to call that number, there is announcement that "this number does not exist." We cannot make the SIP phone has the same announcement. But it success when we calling a land-line non exist number. Busy tone is generated.
Below are the Cisco debug and highlight the 2 different ISDN disconnect cause code. Do I need to configure anything in the Freeswitch?
---------------------------------------------------------------------------- ----------------------------------------------------
Calling non-exist mobile number:
*Nov 10 05:54:24.019: %ISDN-6-DISCONNECT: Interface Serial0/0/0:22 disconnected from 95127917 , call lasted 205 seconds
*Nov 10 05:54:51.727: //216086/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
Call Entry Is Not Found
*Nov 10 05:54:51.731: //-1/DE6E855A8453/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=31754251
----- ccCallInfo IE subfields -----
cisco-ani=31754251
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=92882810
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=-1
*Nov 10 05:54:51.731:
//-1/DE6E855A8453/CCAPI/cc_api_call_setup_ind_common:
Interface=0x451F6154, Call Info(
Calling Number=31754251(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=92882810(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=0, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=216086
*Nov 10 05:54:51.731: //216086/DE6E855A8453/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=31754251(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=92882810(TON=Unknown, NPI=Unknown))
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/cc_process_call_setup_ind:
Event=0x456648F0
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/ccCallSetContext:
Context=0x467619B4
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/cc_process_call_setup_ind:
CCAPI handed cid 216086 with tag 0 to app "_ManagedAppProcess_Default"
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=1, Params=0x4740AA5C, Progress
Indication=ORIGINATING
SIDE IS NON ISDN(3)
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/ccCheckClipClir:
In: Calling Number=31754251(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/ccCheckClipClir:
Out: Calling Number=31754251(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/ccCallSetupRequest:
Destination Pattern=.T, Called Number=92882810, Digit Strip=FALSE
*Nov 10 05:54:51.735: //216086/DE6E855A8453/CCAPI/ccCallSetupRequest:
Calling Number=31754251(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=92882810(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=31754251
Account Number=31754251, Final Destination Flag=TRUE,
Guid=DE6E855A-EBC5-11DF-8453-C1363B6B99C1, Outgoing Dial-peer=1
*Nov 10 05:54:51.739: //216086/DE6E855A8453/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=31754251
----- ccCallInfo IE subfields -----
cisco-ani=31754251
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=92882810
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=-1
*Nov 10 05:54:51.739: //216086/DE6E855A8453/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x456ACB10, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=31754251(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=92882810(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Nov 10 05:54:51.739: //216087/DE6E855A8453/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Nov 10 05:54:51.739: //216087/DE6E855A8453/CCAPI/ccCallSetContext:
Context=0x4740AA0C
*Nov 10 05:54:51.739: //216086/DE6E855A8453/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=1
*Nov 10 05:54:51.779: //216087/DE6E855A8453/CCAPI/cc_api_call_proceeding:
Interface=0x456ACB10, Progress Indication=NULL(0)
*Nov 10 05:54:52.947: //216087/DE6E855A8453/CCAPI/cc_api_call_alert:
Interface=0x456ACB10, Progress Indication=NULL(0), Signal Indication=NOT PRESENT(255)
*Nov 10 05:54:52.947: //216087/DE6E855A8453/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
*Nov 10 05:54:52.947: //216086/DE6E855A8453/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=NOT PRESENT(255)
*Nov 10 05:54:52.947: //216086/DE6E855A8453/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, AlertSent=TRUE)
*Nov 10 05:55:50.971: //216086/DE6E855A8453/CCAPI/cc_api_call_disconnected:
Cause Value=16, Interface=0x451F6154, Call Id=216086
*Nov 10 05:55:50.971: //216086/DE6E855A8453/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=16, Retry Count=0)
*Nov 10 05:55:50.971: //216087/DE6E855A8453/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Nov 10 05:55:50.971: //216087/DE6E855A8453/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Nov 10 05:55:50.971: //216087/DE6E855A8453/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Nov 10 05:55:50.975: //216086/DE6E855A8453/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
*Nov 10 05:55:50.975: //216086/DE6E855A8453/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Nov 10 05:55:50.983: //216086/DE6E855A8453/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x451F6154, Tag=0x0, Call Id=216086,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Nov 10 05:55:50.983: //216086/DE6E855A8453/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
---------------------------------------------------------------------------- ---------------------------------------------
Calling non-exist land line number:
cvghk-vgw1#sh log
Syslog logging: enabled (11 messages dropped, 74 messages rate-limited,
68247 flushes, 0 overruns, xml disabled, filtering disabled)
Console logging: level debugging, 2492150 messages logged, xml disabled,
filtering disabled
Monitor logging: level debugging, 0 messages logged, xml disabled,
filtering disabled
Buffer logging: level debugging, 2285346 messages logged, xml
disabled,
filtering disabled
Logging Exception size (4096 bytes)
Count and timestamp logging messages: disabled
No active filter modules.
Trap logging: level informational, 109823 message lines logged
Log Buffer (8000 bytes):
*Nov 10 06:01:45.127: //216094/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
Call Entry Is Not Found
*Nov 10 06:01:45.127: //-1/D4D5BF13845B/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=31754250
----- ccCallInfo IE subfields -----
cisco-ani=31754250
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=22222222
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=-1
*Nov 10 06:01:45.127:
//-1/D4D5BF13845B/CCAPI/cc_api_call_setup_ind_common:
Interface=0x451F6154, Call Info(
Calling Number=31754250(TON=Unknown, NPI=Unknown, Screening=User, Passed, Pre sentation=Allowed),
Called Number=22222222(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=T RUE,
Incoming Dial-peer=0, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALS E), Call Id=216094
*Nov 10 06:01:45.131: //216094/D4D5BF13845B/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=31754250(TON=Unknown, NPI=Unknown, Screening=User, P assed, Presentation=Allowed),
Called Number=22222222(TON=Unknown, NPI=Unknown))
*Nov 10 06:01:45.131: //216094/D4D5BF13845B/CCAPI/cc_process_call_setup_ind:
Event=0x45661160
*Nov 10 06:01:45.131: //216094/D4D5BF13845B/CCAPI/ccCallSetContext:
Context=0x48B4C074
*Nov 10 06:01:45.131: //216094/D4D5BF13845B/CCAPI/cc_process_call_setup_ind:
CCAPI handed cid 216094 with tag 0 to app "_ManagedAppProcess_Default"
*Nov 10 06:01:45.131: //216094/D4D5BF13845B/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Nov 10 06:01:45.135: //216094/D4D5BF13845B/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=1, Params=0x46AD67F0, Progress
Indication=ORIGINATING
SIDE IS NON ISDN(3)
*Nov 10 06:01:45.135: //216094/D4D5BF13845B/CCAPI/ccCheckClipClir:
In: Calling Number=31754250(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed)
*Nov 10 06:01:45.135: //216094/D4D5BF13845B/CCAPI/ccCheckClipClir:
Out: Calling Number=31754250(TON=Unknown, NPI=Unknown, Screening=User, Passed , Presentation=Allowed)
*Nov 10 06:01:45.135: //216094/D4D5BF13845B/CCAPI/ccCallSetupRequest:
Destination Pattern=.T, Called Number=22222222, Digit Strip=FALSE
*Nov 10 06:01:45.135: //216094/D4D5BF13845B/CCAPI/ccCallSetupRequest:
Calling Number=31754250(TON=Unknown, NPI=Unknown, Screening=User, Passed, Pre
sentation=Allowed),
Called Number=22222222(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=31754250
Account Number=31754250, Final Destination Flag=TRUE,
Guid=D4D5BF13-EBC6-11DF-845B-C1363B6B99C1, Outgoing Dial-peer=1
*Nov 10 06:01:45.135: //216094/D4D5BF13845B/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=31754250
----- ccCallInfo IE subfields -----
cisco-ani=31754250
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=1
dest=22222222
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=-1
*Nov 10 06:01:45.135: //216094/D4D5BF13845B/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x456ACB10, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=31754250(TON=Unknown, NPI=Unknown, Screening=User, Passed, Presentation=Allowed),
Called Number=22222222(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=1, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=,
tg_label_flag=0,
Appl ication Call Id=)
*Nov 10 06:01:45.139: //216095/D4D5BF13845B/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Nov 10 06:01:45.139: //216095/D4D5BF13845B/CCAPI/ccCallSetContext:
Context=0x46AD67A0
*Nov 10 06:01:45.139: //216094/D4D5BF13845B/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=1
*Nov 10 06:01:45.183: //216095/D4D5BF13845B/CCAPI/cc_api_call_proceeding:
Interface=0x456ACB10, Progress Indication=NULL(0)
*Nov 10 06:01:45.443: //216095/D4D5BF13845B/CCAPI/cc_api_call_disconnected:
Cause Value=1, Interface=0x456ACB10, Call Id=216095
*Nov 10 06:01:45.443: //216095/D4D5BF13845B/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=1, Retry Count=0)
*Nov 10 06:01:45.443: //216095/D4D5BF13845B/CCAPI/ccCallSetAAA_Accounting:
Accounting=0, Call Id=216095
*Nov 10 06:01:45.443: //216095/D4D5BF13845B/CCAPI/ccCallDisconnect:
Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Ca use=1)
*Nov 10 06:01:45.443: //216095/D4D5BF13845B/CCAPI/ccCallDisconnect:
Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
*Nov 10 06:01:45.443: //216095/D4D5BF13845B/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
*Nov 10 06:01:45.463: //216095/D4D5BF13845B/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x456ACB10, Tag=0x0, Call Id=216095,
Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
*Nov 10 06:01:45.463: //216095/D4D5BF13845B/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Nov 10 06:01:45.463: //216094/D4D5BF13845B/CCAPI/ccCallDisconnect:
Cause Value=1, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Ca use=0)
*Nov 10 06:01:45.463: //216094/D4D5BF13845B/CCAPI/ccCallDisconnect:
Cause Value=1, Call Entry(Responsed=TRUE, Cause Value=1)
*Nov 10 06:01:45.471: //216094/D4D5BF13845B/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x451F6154, Tag=0x0, Call Id=216094,
Call Entry(Disconnect Cause=1, Voice Class Cause Code=0, Retry Count=0)
Please help.
Thanks
Raymond Chan
Technical Manager (Hong Kong and Macau)
Commverge Solutions Limited
Mobile: +852 98403073
Direct: +852 29022420
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users at lists.freeswitch.org <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org <http://www.freeswitch.org/>
participants (1)
-
Raymond Chan