Okay, I upgraded to 1.0.5pre9 and tried this test again and I do not see the WARNING in the Freeswitch log. However, it still behaves the same way. That is, the internal callee rings for about 12 seconds, then stops ringing, and the PSTN caller just hears ringback for about 60 seconds and is not given the opportunity to leave voice mail. In contrast, an internal-to-internal call will go to voice mail after 30 seconds. I put a new 11595 log into the pastebin. Is there some Sangoma Wanpipe driver (or Freeswitch) setting that would correct this? Best Regards, Jerry
_____ From: Anthony Minessale [mailto:anthony.miness...@gmail.com] Sent: Tuesday, November 03, 2009 2:23 PM To: freeswitch-users@lists.freeswitch.org Subject: Re: [Freeswitch-users] WARNING On Inbound Call Question can you try the same thing with the latest trunk or pre-release tarball. On Tue, Nov 3, 2009 at 3:35 PM, Jerry Richards <jerry.richa...@teotech.com> wrote: I have my Freeswitch server with an installed Sangoma A101D card. Most everything works okay, however, when I get an inbound call from the PSTN, I see the following warning show up in the log. Additionally, the caller (on the PSTN) does not hear ringback, and if the call is not answered within about 12 seconds, the call ends (so it doesn't go to voice mail). If I make a call from one internal phone to another, then it will go to voice mail after 30 seconds. Here are the two warnings: [WARNING] ss7_boost_client.c:218 TX EVENT (N): CALL_START_ACK:(81) [w1g1] Rc=0 CSid=0 Seq=11 [WARNING] mod_openzap.c:761 VETO Changing state on 1:1 from PROGRESS to PROGRESS_MEDIA Here is the log of the warning upon an inbound call: freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> 2009-11-02 09:06:01.664835 [WARNING] ozmod_ss7_boost.c:1141 RX EVENT: CALL_START:(80) [w1g1] CSid=0 Seq=12 Cn=[N/A] Cd=[5384] Ci=[4253813176] 2009-11-02 09:06:01.665824 [DEBUG] ozmod_ss7_boost.c:655 Changing state on 1:1 from DOWN to RING 2009-11-02 09:06:01.665824 [DEBUG] ozmod_ss7_boost.c:841 1:1 STATE [RING] 2009-11-02 09:06:01.665824 [DEBUG] mod_openzap.c:1481 got clear channel sig [START] 2009-11-02 09:06:01.665824 [DEBUG] mod_openzap.c:344 Set codec PCMU 20ms 2009-11-02 09:06:01.665824 [DEBUG] mod_openzap.c:1184 Connect inbound channel OpenZAP/1:1/5384 2009-11-02 09:06:01.665824 [NOTICE] switch_channel.c:602 New Channel OpenZAP/1:1/5384 [b678f311-ab74-4cc1-afac-b83d89a53132] 2009-11-02 09:06:01.665824 [DEBUG] mod_openzap.c:1192 (OpenZAP/1:1/5384) State Change CS_NEW -> CS_INIT 2009-11-02 09:06:01.665824 [DEBUG] switch_core_session.c:932 Send signal OpenZAP/1:1/5384 [BREAK] 2009-11-02 09:06:01.665824 [DEBUG] switch_core_state_machine.c:398 (OpenZAP/1:1/5384) Running State Change CS_INIT 2009-11-02 09:06:01.665824 [DEBUG] switch_core_state_machine.c:481 (OpenZAP/1:1/5384) State INIT 2009-11-02 09:06:01.665824 [DEBUG] mod_openzap.c:368 (OpenZAP/1:1/5384) State Change CS_INIT -> CS_ROUTING 2009-11-02 09:06:01.665824 [DEBUG] switch_core_session.c:932 Send signal OpenZAP/1:1/5384 [BREAK] 2009-11-02 09:06:01.665824 [DEBUG] switch_core_state_machine.c:481 (OpenZAP/1:1/5384) State INIT going to sleep 2009-11-02 09:06:01.665824 [DEBUG] switch_core_state_machine.c:398 (OpenZAP/1:1/5384) Running State Change CS_ROUTING 2009-11-02 09:06:01.665824 [DEBUG] switch_core_state_machine.c:484 (OpenZAP/1:1/5384) State ROUTING 2009-11-02 09:06:01.665824 [DEBUG] mod_openzap.c:391 OpenZAP/1:1/5384 CHANNEL ROUTING 2009-11-02 09:06:01.665824 [DEBUG] switch_core_state_machine.c:78 OpenZAP/1:1/5384 Standard ROUTING 2009-11-02 09:06:01.665824 [INFO] mod_dialplan_xml.c:315 Processing 4253813176->5384 in context default Dialplan: OpenZAP/1:1/5384 parsing [default->unloop] continue=false Dialplan: OpenZAP/1:1/5384 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->tod_example] continue=true Dialplan: OpenZAP/1:1/5384 Absolute Condition [tod_example] Dialplan: OpenZAP/1:1/5384 Action set(open=true) Dialplan: OpenZAP/1:1/5384 parsing [default->SangomaPRI] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [SangomaPRI] destination_number(5384) =~ /^9(\d+)$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->global-intercept] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [global-intercept] destination_number(5384) =~ /^(5380)$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->group-intercept] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [group-intercept] destination_number(5384) =~ /^\*8$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->intercept-ext] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [intercept-ext] destination_number(5384) =~ /^\*\*(\d+)$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->redial] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [redial] destination_number(5384) =~ /^870$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->global] continue=true Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: OpenZAP/1:1/5384 Absolute Condition [global] Dialplan: OpenZAP/1:1/5384 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: OpenZAP/1:1/5384 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_numbe r}) Dialplan: OpenZAP/1:1/5384 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: OpenZAP/1:1/5384 parsing [default->snom-demo-2] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [snom-demo-2] destination_number(5384) =~ /^9001$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->snom-demo-1] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [snom-demo-1] destination_number(5384) =~ /^9000$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->eavesdrop] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [eavesdrop] destination_number(5384) =~ /^88(.*)$|^\*0(.*)$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->eavesdrop] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [eavesdrop] destination_number(5384) =~ /^779$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->call_return] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [call_return] destination_number(5384) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->del-group] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [del-group] destination_number(5384) =~ /^80(\d{2})$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->add-group] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [add-group] destination_number(5384) =~ /^81(\d{2})$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->call-group-simo] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [call-group-simo] destination_number(5384) =~ /^82(\d{2})$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->call-group-order] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [call-group-order] destination_number(5384) =~ /^83(\d{2})$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->extension-intercom] continue=false Dialplan: OpenZAP/1:1/5384 Regex (FAIL) [extension-intercom] destination_number(5384) =~ /^8(5[34][8901][0-9])$/ break=on-false Dialplan: OpenZAP/1:1/5384 parsing [default->Local_Extension] continue=false Dialplan: OpenZAP/1:1/5384 Regex (PASS) [Local_Extension] destination_number(5384) =~ /^(5[34][8901][0-9])$/ break=on-false Dialplan: OpenZAP/1:1/5384 Action set(dialed_extension=5384) Dialplan: OpenZAP/1:1/5384 Action export(dialed_extension=5384) Dialplan: OpenZAP/1:1/5384 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: OpenZAP/1:1/5384 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strft ime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: OpenZAP/1:1/5384 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: OpenZAP/1:1/5384 Action set(ringback=${us-ring}) Dialplan: OpenZAP/1:1/5384 Action set(transfer_ringback=local_stream://moh) Dialplan: OpenZAP/1:1/5384 Action set(call_timeout=30) Dialplan: OpenZAP/1:1/5384 Action set(hangup_after_bridge=true) Dialplan: OpenZAP/1:1/5384 Action set(continue_on_fail=true) Dialplan: OpenZAP/1:1/5384 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_numbe r}) Dialplan: OpenZAP/1:1/5384 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: OpenZAP/1:1/5384 Action set(called_party_callgroup=${user_data(${dialed_extensi...@${domain_name} var callgroup)}) Dialplan: OpenZAP/1:1/5384 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: OpenZAP/1:1/5384 Action bridge(user/${dialed_extensi...@${domain_name}) Dialplan: OpenZAP/1:1/5384 Action answer() Dialplan: OpenZAP/1:1/5384 Action sleep(1000) Dialplan: OpenZAP/1:1/5384 Action voicemail(default ${domain_name} ${dialed_extension}) 2009-11-02 09:06:01.666685 [DEBUG] switch_core_state_machine.c:114 (OpenZAP/1:1/5384) State Change CS_ROUTING -> CS_EXECUTE 2009-11-02 09:06:01.666685 [DEBUG] switch_core_session.c:932 Send signal OpenZAP/1:1/5384 [BREAK] 2009-11-02 09:06:01.666685 [DEBUG] switch_core_state_machine.c:484 (OpenZAP/1:1/5384) State ROUTING going to sleep 2009-11-02 09:06:01.666685 [DEBUG] switch_core_state_machine.c:398 (OpenZAP/1:1/5384) Running State Change CS_EXECUTE 2009-11-02 09:06:01.666685 [DEBUG] switch_core_state_machine.c:491 (OpenZAP/1:1/5384) State EXECUTE 2009-11-02 09:06:01.666685 [DEBUG] mod_openzap.c:408 OpenZAP/1:1/5384 CHANNEL EXECUTE 2009-11-02 09:06:01.666685 [DEBUG] switch_core_state_machine.c:151 OpenZAP/1:1/5384 Standard EXECUTE EXECUTE OpenZAP/1:1/5384 set(open=true) 2009-11-02 09:06:01.666685 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [open]=[true] EXECUTE OpenZAP/1:1/5384 hash(insert/192.168.72.141-spymap/4253813176/b678f311-ab74-4cc1-afac-b83d89a 53132) EXECUTE OpenZAP/1:1/5384 hash(insert/192.168.72.141-last_dial/4253813176/5384) EXECUTE OpenZAP/1:1/5384 hash(insert/192.168.72.141-last_dial/global/b678f311-ab74-4cc1-afac-b83d89a5 3132) EXECUTE OpenZAP/1:1/5384 set(dialed_extension=5384) 2009-11-02 09:06:01.667682 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [dialed_extension]=[5384] EXECUTE OpenZAP/1:1/5384 export(dialed_extension=5384) 2009-11-02 09:06:01.667682 [DEBUG] mod_dptools.c:886 EXPORT [dialed_extension]=[5384] EXECUTE OpenZAP/1:1/5384 bind_meta_app(1 b s execute_extension::dx XML features) 2009-11-02 09:06:01.667682 [INFO] switch_ivr_async.c:1795 Bound B-Leg: 1 execute_extension::dx XML features EXECUTE OpenZAP/1:1/5384 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/4253813176.2009-11-02-09-06 -01.wav) 2009-11-02 09:06:01.668708 [INFO] switch_ivr_async.c:1795 Bound B-Leg: 2 record_session::/usr/local/freeswitch/recordings/4253813176.2009-11-02-09-06 -01.wav EXECUTE OpenZAP/1:1/5384 bind_meta_app(3 b s execute_extension::cf XML features) 2009-11-02 09:06:01.668708 [INFO] switch_ivr_async.c:1795 Bound B-Leg: 3 execute_extension::cf XML features EXECUTE OpenZAP/1:1/5384 set(ringback=%(2000,4000,440.0,480.0)) 2009-11-02 09:06:01.668708 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [ringback]=[%(2000,4000,440.0,480.0)] EXECUTE OpenZAP/1:1/5384 set(transfer_ringback=local_stream://moh) 2009-11-02 09:06:01.668708 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [transfer_ringback]=[local_stream://moh] EXECUTE OpenZAP/1:1/5384 set(call_timeout=30) 2009-11-02 09:06:01.668708 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [call_timeout]=[30] EXECUTE OpenZAP/1:1/5384 set(hangup_after_bridge=true) 2009-11-02 09:06:01.669681 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [hangup_after_bridge]=[true] EXECUTE OpenZAP/1:1/5384 set(continue_on_fail=true) 2009-11-02 09:06:01.669681 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [continue_on_fail]=[true] EXECUTE OpenZAP/1:1/5384 hash(insert/192.168.72.141-call_return/5384/4253813176) EXECUTE OpenZAP/1:1/5384 hash(insert/192.168.72.141-last_dial_ext/5384/b678f311-ab74-4cc1-afac-b83d89 a53132) EXECUTE OpenZAP/1:1/5384 set(called_party_callgroup=techsupport) 2009-11-02 09:06:01.670679 [DEBUG] mod_dptools.c:748 OpenZAP/1:1/5384 SET [called_party_callgroup]=[techsupport] EXECUTE OpenZAP/1:1/5384 hash(insert/192.168.72.141-last_dial/techsupport/b678f311-ab74-4cc1-afac-b83 d89a53132) EXECUTE OpenZAP/1:1/5384 bridge(user/5...@192.168.72.141) 2009-11-02 09:06:01.671683 [DEBUG] switch_ivr_originate.c:1027 variable string 0 = [presence_id=5...@192.168.72.141] 2009-11-02 09:06:01.671683 [NOTICE] switch_channel.c:602 New Channel sofia/internal/sip:5...@192.168.72.163:5060 [9e7b8fae-6194-430c-951b-948ebd2c2a3b] 2009-11-02 09:06:01.671683 [DEBUG] mod_sofia.c:2811 (sofia/internal/sip:5...@192.168.72.163:5060) State Change CS_NEW -> CS_INIT 2009-11-02 09:06:01.672688 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/sip:5...@192.168.72.163:5060 [BREAK] 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:5...@192.168.72.163:5060) Running State Change CS_INIT 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:481 (sofia/internal/sip:5...@192.168.72.163:5060) State INIT 2009-11-02 09:06:01.672688 [DEBUG] mod_sofia.c:83 sofia/internal/sip:5...@192.168.72.163:5060 SOFIA INIT 2009-11-02 09:06:01.672688 [DEBUG] mod_sofia.c:111 (sofia/internal/sip:5...@192.168.72.163:5060) State Change CS_INIT -> CS_ROUTING 2009-11-02 09:06:01.672688 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/sip:5...@192.168.72.163:5060 [BREAK] 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:481 (sofia/internal/sip:5...@192.168.72.163:5060) State INIT going to sleep 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:5...@192.168.72.163:5060) Running State Change CS_ROUTING 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:484 (sofia/internal/sip:5...@192.168.72.163:5060) State ROUTING 2009-11-02 09:06:01.672688 [DEBUG] mod_sofia.c:130 sofia/internal/sip:5...@192.168.72.163:5060 SOFIA ROUTING 2009-11-02 09:06:01.672688 [DEBUG] switch_ivr_originate.c:63 (sofia/internal/sip:5...@192.168.72.163:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2009-11-02 09:06:01.672688 [DEBUG] switch_core_session.c:932 Send signal sofia/internal/sip:5...@192.168.72.163:5060 [BREAK] 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:484 (sofia/internal/sip:5...@192.168.72.163:5060) State ROUTING going to sleep 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/sip:5...@192.168.72.163:5060) Running State Change CS_CONSUME_MEDIA 2009-11-02 09:06:01.672688 [DEBUG] sofia.c:3289 Channel sofia/internal/sip:5...@192.168.72.163:5060 entering state [calling][0] 2009-11-02 09:06:01.672688 [DEBUG] switch_core_state_machine.c:503 (sofia/internal/sip:5...@192.168.72.163:5060) State CONSUME_MEDIA 2009-11-02 09:06:01.672688 [DEBUG] switch_ivr_originate.c:1701 OpenZAP/1:1/5384 receive message [PROGRESS] 2009-11-02 09:06:01.673742 [DEBUG] mod_openzap.c:759 Changing state on 1:1 from RING to PROGRESS 2009-11-02 09:06:01.674787 [DEBUG] ozmod_ss7_boost.c:841 1:1 STATE [PROGRESS] 2009-11-02 09:06:01.675844 [WARNING] ss7_boost_client.c:218 TX EVENT (N): CALL_START_ACK:(81) [w1g1] Rc=0 CSid=0 Seq=11 2009-11-02 09:06:01.684776 [WARNING] mod_openzap.c:761 VETO Changing state on 1:1 from PROGRESS to PROGRESS_MEDIA 2009-11-02 09:06:01.684776 [DEBUG] switch_core_session.c:630 Send signal OpenZAP/1:1/5384 [BREAK] 2009-11-02 09:06:01.684776 [NOTICE] switch_ivr_originate.c:1701 Pre-Answer OpenZAP/1:1/5384! 2009-11-02 09:06:01.684776 [DEBUG] switch_ivr_originate.c:1718 Raw Codec Activation Success l...@8000hz 1 channel 20ms 2009-11-02 09:06:01.684776 [DEBUG] switch_ivr_originate.c:1777 Play Ringback Tone [%(2000,4000,440.0,480.0)] 2009-11-02 09:06:01.693835 [DEBUG] sofia.c:3289 Channel sofia/internal/sip:5...@192.168.72.163:5060 entering state [proceeding][180] 2009-11-02 09:06:01.693835 [NOTICE] sofia.c:3353 Ring-Ready sofia/internal/sip:5...@192.168.72.163:5060! 2009-11-02 09:06:01.705777 [DEBUG] switch_core_io.c:649 OpenZAP/1:1/5384 receive message [TRANSCODING_NECESSARY] freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> freeswi...@teoproxy.greyhawk.tonecommander.com> Best Regards, Jerry _______________________________________________ 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 -- Anthony Minessale II FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire AIM: anthm MSN:anthony_miness...@hotmail.com <mailto:msn%3aanthony_miness...@hotmail.com> GTALK/JABBER/PAYPAL:anthony.miness...@gmail.com <mailto:paypal%3aanthony.miness...@gmail.com> IRC: irc.freenode.net #freeswitch FreeSWITCH Developer Conference sip:8...@conference.freeswitch.org <mailto:sip%3a...@conference.freeswitch.org> iax:gu...@conference.freeswitch.org/888 googletalk:conf+...@conference.freeswitch.org <mailto:googletalk%3aconf%2b...@conference.freeswitch.org> pstn:213-799-1400
_______________________________________________ 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