g.722 --> SPEEX/16000 or SPEEX/32000 transcoding issue
Hi, Using the FusionPBX ISO (FreeSWITCH 1.0.4) I find I cannot make a call which requires transcoding from g.722 (or other codec which declares 8kHz sampling rate in the SDP) to SPEEX/16000 or SPEEX/32000. If the calling extension uses only g.722, alaw, ulaw, etc, then only the SPEEX/8000 narrowband variety of SPEEX is offered to the recipient extension in the SDP of the SIP invite. If the call is initiated the other way round - e.g. Client using SPEEX/32000 --> FreeSWITCH --> Client using g.722, then the call is transcoded with no problem. I am wondering if this is the intended behaviour, to avoid transcoding narrowband --> wideband. However what I am finding is that transcodinig g722/8000 (wideband) to SPEEX (wideband or ultrawideband) does not seem to work. I would be most grateful if anyone were able to let me know if there is a configuration option I can set to alter this behavious and allow the full range of SPEEX sampling rates to be offered in the SDP to the receiving party, regardless of the codec used by the calling party. Also, is this perhaps different in a more recent version? Many thanks Bruce
I would recommend you contact the FusionPBX project as 1.0.4 is no longer supported by our team as we are about to release 1.0.5 this week. /b On Feb 9, 2010, at 2:03 PM, Bruce Hopkins wrote:
Using the FusionPBX ISO (FreeSWITCH 1.0.4) I find I cannot make a call which requires transcoding from g.722 (or other codec which declares 8kHz sampling rate in the SDP) to SPEEX/16000 or SPEEX/32000.
OK, many thanks for the extremely swift response Brian. I will try to get up and running as soon as I can with 1.0.5 and see if the issue goes away. thanks again Bruce On 9 February 2010 20:59, Brian West <brian@freeswitch.org> wrote:
I would recommend you contact the FusionPBX project as 1.0.4 is no longer supported by our team as we are about to release 1.0.5 this week.
/b
On Feb 9, 2010, at 2:03 PM, Bruce Hopkins wrote:
Using the FusionPBX ISO (FreeSWITCH 1.0.4) I find I cannot make a call
which requires transcoding from g.722 (or other codec which declares 8kHz sampling rate in the SDP) to SPEEX/16000 or SPEEX/32000.
_______________________________________________ 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
What you're saying makes little or no sense to me even on 1.0.4, Can you pastebin your logs? /b On Feb 9, 2010, at 3:15 PM, Bruce Hopkins wrote:
OK, many thanks for the extremely swift response Brian.
I will try to get up and running as soon as I can with 1.0.5 and see if the issue goes away.
thanks again Bruce
Willdo, To clarify in brief though, the scenario which occurs and causes the call to fail is: SIP client 1 (g.722 enabled only ) -----> INVITE (with SDP offer: Media Attribute (a): rtpmap:9 g722/8000 ) -->FreeSWITCH ---> INVITE (with SDP offer including a bunch of codecs including rtpmap: rtpmap:98 SPEEX/8000 but crucially *not* including SPEEX/16000 or SPEEX/32000) ---> SIP client 2 (with only SPEEX/16000 or SPEEX/32000 enabled). The second SIP client does not get offered a codec it can accept, so SIP client 1 is sent a method 488 "Not Acceptable Here" message and the calling party gets directed to the voicemail for the other SIP client. By contrast, there is no problem calling SPEEX/32000 --> SPEEX/32000 or calling SPEEX/16000 --> SPEEX/16000. there is also no problem calling SPEEX/32000 --> g.722/8000. I am wondering if the problem is that FreeSWITCH is interpreting g.722 as being a narrowband (8kHz sample rate) codec, due to the historic anomaly of it presenting g722/8000 in the SDP even though it in fact uses 16kHz sampling, and for that reason not wanting to offer a 16kHz sample rate codec to the second SIP client? I suggest this as I also found trying to call alaw --> SPEEX/16000 does not work, for example. Here is the log file for the scenario which does not work (g.722 client trying to call Speex wideband client). Please let me know if a Wireshark trace would be helpful. 2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5224 0 acls to check for proxy 2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5242 network ip is a proxy [0] 2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5270 IP 192.168.10.131 Rejected by acl "domains". Falling back to Digest auth. 2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5224 0 acls to check for proxy 2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5242 network ip is a proxy [0] 2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5270 IP 192.168.10.131 Rejected by acl "domains". Falling back to Digest auth. 2010-02-09 21:49:32.794074 [NOTICE] switch_channel.c:613 New Channel sofia/internal/60002@192.168.10.30 [66610a8c-aec9-48ca-9b67-aafdcd3e3d08] 2010-02-09 21:49:32.794074 [DEBUG] sofia.c:3727 Channel sofia/internal/ 60002@192.168.10.30 entering state [received][100] 2010-02-09 21:49:32.794074 [DEBUG] sofia.c:3738 Remote SDP: v=0 o=- 5 2 IN IP4 192.168.10.131 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.10.131 t=0 0 m=audio 25592 RTP/AVP 9 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2010-02-09 21:49:32.794074 [DEBUG] sofia_glue.c:3305 Audio Codec Compare [G722:9:8000:20]/[G722:9:8000:20] 2010-02-09 21:49:32.795079 [DEBUG] sofia_glue.c:2143 Set Codec sofia/internal/60002@192.168.10.30 G722/8000 20 ms 160 samples 2010-02-09 21:49:32.795079 [DEBUG] sofia_glue.c:3261 Set 2833 dtmf payload to 101 2010-02-09 21:49:32.795079 [DEBUG] sofia.c:3885 (sofia/internal/ 60002@192.168.10.30) State Change CS_NEW -> CS_INIT 2010-02-09 21:49:32.795079 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_INIT 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/60002@192.168.10.30) State INIT 2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:83 sofia/internal/ 60002@192.168.10.30 SOFIA INIT 2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:111 (sofia/internal/ 60002@192.168.10.30) State Change CS_INIT -> CS_ROUTING 2010-02-09 21:49:32.795079 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/60002@192.168.10.30) State INIT going to sleep 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_ROUTING 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/60002@192.168.10.30) State ROUTING 2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:132 sofia/internal/ 60002@192.168.10.30 SOFIA ROUTING 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:78 sofia/internal/60002@192.168.10.30 Standard ROUTING 2010-02-09 21:49:32.795079 [INFO] mod_dialplan_xml.c:408 Processing 60002->1001 in context default Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unloop] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->tod_example] continue=true Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [tod_example] ${strftime(%w)}(2) =~ /^([1-5])$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [tod_example] ${strftime(%H%M)}(2149) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^\*886$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->redial] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [redial] destination_number(1001) =~ /^\*870$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->global] continue=true Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${network_addr}(192.168.10.131) =~ /^$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 ANTI-Action set(use_profile=${cond(${acl(${network_addr} rfc1918)} == true ? nat : default)}) Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [global] ${numbering_plan}() =~ /^$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 Action set_user(default@${domain_name}) Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 Absolute Condition [global] Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^\*9001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^\*9000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^\*88(.*)$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^\*779$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call_privacy] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call_privacy] destination_number(1001) =~ /^\*67(\d+)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call_return] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->del-group] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [del-group] destination_number(1001) =~ /^\*80(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->add-group] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [add-group] destination_number(1001) =~ /^\*81(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^\*82(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^\*83(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^\*8(\d{4})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_5digits] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_5digits] destination_number(1001) =~ /^\*99(\d{5})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_4digits] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_4digits] destination_number(1001) =~ /^\*99(\d{4})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_3digits] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_3digits] destination_number(1001) =~ /^\*99(\d{3})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->pizza_demo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [pizza_demo] destination_number(1001) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->2001] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [2001] destination_number(1001) =~ /^2001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Call via asterisk-pbx1] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [Call via asterisk-pbx1] destination_number(1001) =~ /269065/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->pizza_demo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [pizza_demo] destination_number(1001) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->5002] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [5002] destination_number(1001) =~ /^5002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->7002] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [7002] destination_number(1001) =~ /^7002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->DISA] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [DISA] destination_number(1001) =~ /^\*(3472)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Recordings] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [Recordings] destination_number(1001) =~ /^\*(732673)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->7002.park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [7002.park] destination_number(1001) =~ /^\*7002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_sales] destination_number(1001) =~ /^\*2000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_support] destination_number(1001) =~ /^\*2001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_billing] destination_number(1001) =~ /^\*2002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->vmain2] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [vmain2] destination_number(1001) =~ /^vmain2$|^\*97$|^\*4000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->vmain] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [vmain] destination_number(1001) =~ /^vmain$|^\*98$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [sip_uri] destination_number(1001) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [nb_conferences] destination_number(1001) =~ /^\*(30\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [wb_conferences] destination_number(1001) =~ /^\*(31\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [uwb_conferences] destination_number(1001) =~ /^\*(32\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [cdquality_conferences] destination_number(1001) =~ /^\*(33\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(1001) =~ /^\*9(888|1616|3232)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss_intercom] destination_number(1001) =~ /^\*0911$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss_intercom] destination_number(1001) =~ /^\*0912$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss] destination_number(1001) =~ /^\*0913$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ivr_demo] destination_number(1001) =~ /^\*5000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [dynamic_conference] destination_number(1001) =~ /^\*5001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [rtp_multicast_page] destination_number(1001) =~ /^\*pagegroup$|^\*7243/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /^\*5900$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /^\*5901$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /park\+(\d+)/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /^parking$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /callpark/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /pickup/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->wait] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [wait] destination_number(1001) =~ /^wait$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->fax_receive] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [fax_receive] destination_number(1001) =~ /^\*9978$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->fax_transmit] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [fax_transmit] destination_number(1001) =~ /^\*9979$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_180] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_180] destination_number(1001) =~ /^\*9980$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_183_uk_ring] destination_number(1001) =~ /^\*9981$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_183_music_ring] destination_number(1001) =~ /^\*9982$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(1001) =~ /^\*9983$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_post_answer_music] destination_number(1001) =~ /^\*9984$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ClueCon] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ClueCon] destination_number(1001) =~ /^\*9991$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->show_info] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [show_info] destination_number(1001) =~ /^\*9992$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->video_record] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [video_record] destination_number(1001) =~ /^\*9993$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->video_playback] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [video_playback] destination_number(1001) =~ /^\*9994$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->delay_echo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [delay_echo] destination_number(1001) =~ /^\*9995$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->echo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [echo] destination_number(1001) =~ /^\*9996$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->milliwatt] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [milliwatt] destination_number(1001) =~ /^\*9997$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->tone_stream] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [tone_stream] destination_number(1001) =~ /^\*9998$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [zrtp_enrollement] destination_number(1001) =~ /^\*9787$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->hold_music] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [hold_music] destination_number(1001) =~ /^\*9999$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [Local_Extension] destination_number(1001) =~ /(^\d{6}$|\d{5}$|^\d{4}$|^\d{3}$)/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Action set(dialed_extension=1001) Dialplan: sofia/internal/60002@192.168.10.30 Action export(dialed_extension=1001) Dialplan: sofia/internal/60002@192.168.10.30 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/60002@192.168.10.30 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/60002@192.168.10.30 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/60002@192.168.10.30 Action set(ringback=${us-ring}) Dialplan: sofia/internal/60002@192.168.10.30 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/60002@192.168.10.30 Action set(call_timeout=30) Dialplan: sofia/internal/60002@192.168.10.30 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/60002@192.168.10.30 Action set(continue_on_fail=true) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/60002@192.168.10.30 Action answer() Dialplan: sofia/internal/60002@192.168.10.30 Action sleep(1000) Dialplan: sofia/internal/60002@192.168.10.30 Action voicemail(default ${domain_name} ${dialed_extension}) 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:122 (sofia/internal/60002@192.168.10.30) State Change CS_ROUTING -> CS_EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/60002@192.168.10.30) State ROUTING going to sleep 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/60002@192.168.10.30) State EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] mod_sofia.c:181 sofia/internal/ 60002@192.168.10.30 SOFIA EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:159 sofia/internal/60002@192.168.10.30 Standard EXECUTE EXECUTE sofia/internal/60002@192.168.10.30 set(use_profile=default) 2010-02-09 21:49:32.798073 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [use_profile]=[default] EXECUTE sofia/internal/60002@192.168.10.30 set_user(default@192.168.10.30) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-spymap/60002/66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial/60002/1001) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial/global/66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30 set(dialed_extension=1001) 2010-02-09 21:49:32.857126 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [dialed_extension]=[1001] EXECUTE sofia/internal/60002@192.168.10.30 export(dialed_extension=1001) 2010-02-09 21:49:32.858075 [DEBUG] mod_dptools.c:851 EXPORT [dialed_extension]=[1001] EXECUTE sofia/internal/60002@192.168.10.30 bind_meta_app(1 b s execute_extension::dx XML features) 2010-02-09 21:49:32.858075 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 1 execute_extension::dx XML features EXECUTE sofia/internal/60002@192.168.10.30 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/60002.2010-02-09-21-49-32.wav) 2010-02-09 21:49:32.858075 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 2 record_session::/usr/local/freeswitch/recordings/60002.2010-02-09-21-49-32.wav EXECUTE sofia/internal/60002@192.168.10.30 bind_meta_app(3 b s execute_extension::cf XML features) 2010-02-09 21:49:32.859074 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 3 execute_extension::cf XML features EXECUTE sofia/internal/60002@192.168.10.30 set(ringback=%(2000, 4000, 440.0, 480.0)) 2010-02-09 21:49:32.859074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [ringback]=[%(2000, 4000, 440.0, 480.0)] EXECUTE sofia/internal/60002@192.168.10.30set(transfer_ringback=local_stream://moh) 2010-02-09 21:49:32.859074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/60002@192.168.10.30 set(call_timeout=30) 2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [call_timeout]=[30] EXECUTE sofia/internal/60002@192.168.10.30 set(hangup_after_bridge=true) 2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/60002@192.168.10.30 set(continue_on_fail=true) 2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [continue_on_fail]=[true] EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-call_return/1001/60002) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial_ext/1001/66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30 set(called_party_callgroup=) 2010-02-09 21:49:32.870074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [called_party_callgroup]=[UNDEF] EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial//66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30 bridge(user/1001@192.168.10.30) 2010-02-09 21:49:32.905073 [DEBUG] switch_ivr_originate.c:1735 variable string 0 = [presence_id=1001@192.168.10.30] 2010-02-09 21:49:32.905073 [NOTICE] switch_channel.c:613 New Channel sofia/internal/sip:1001@192.168.10.192:41080[df7cf235-f0e4-406a-83a5-dd2d681bb278] 2010-02-09 21:49:32.905073 [DEBUG] mod_sofia.c:3142 (sofia/internal/ sip:1001@192.168.10.192:41080) State Change CS_NEW -> CS_INIT 2010-02-09 21:49:32.905073 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:32.906075 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_INIT 2010-02-09 21:49:32.906075 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:1001@192.168.10.192:41080) State INIT 2010-02-09 21:49:32.906075 [DEBUG] mod_sofia.c:83 sofia/internal/ sip:1001@192.168.10.192:41080 SOFIA INIT 2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:111 (sofia/internal/ sip:1001@192.168.10.192:41080) State Change CS_INIT -> CS_ROUTING 2010-02-09 21:49:32.907184 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:32.907184 [DEBUG] sofia.c:3727 Channel sofia/internal/ sip:1001@192.168.10.192:41080 entering state [calling][0] 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:1001@192.168.10.192:41080) State INIT going to sleep 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_ROUTING 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:1001@192.168.10.192:41080) State ROUTING 2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:132 sofia/internal/ sip:1001@192.168.10.192:41080 SOFIA ROUTING 2010-02-09 21:49:32.907184 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1001@192.168.10.192:41080) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2010-02-09 21:49:32.907184 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:1001@192.168.10.192:41080) State ROUTING going to sleep 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_CONSUME_MEDIA 2010-02-09 21:49:33.023071 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/sip:1001@192.168.10.192:41080) State CONSUME_MEDIA 2010-02-09 21:49:33.023071 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/sip:1001@192.168.10.192:41080) State CONSUME_MEDIA going to sleep 2010-02-09 21:49:33.329319 [DEBUG] sofia.c:3727 Channel sofia/internal/ sip:1001@192.168.10.192:41080 entering state [terminated][488] 2010-02-09 21:49:33.329319 [NOTICE] sofia.c:4331 Hangup sofia/internal/ sip:1001@192.168.10.192:41080 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.329319 [DEBUG] switch_channel.c:1912 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [KILL] 2010-02-09 21:49:33.329319 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:33.329319 [DEBUG] switch_core_state_machine.c:459 sofia/internal/sip:1001@192.168.10.192:41080 thread mismatch skipping state handler. 2010-02-09 21:49:33.329319 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_HANGUP 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/sip:1001@192.168.10.192:41080) State HANGUP 2010-02-09 21:49:33.330075 [DEBUG] mod_sofia.c:352 sofia/internal/ sip:1001@192.168.10.192:41080 Overriding SIP cause 488 with 488 from the other leg 2010-02-09 21:49:33.330075 [DEBUG] mod_sofia.c:358 Channel sofia/internal/ sip:1001@192.168.10.192:41080 hanging up, cause: INCOMPATIBLE_DESTINATION 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:1001@192.168.10.192:41080 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/sip:1001@192.168.10.192:41080) State HANGUP going to sleep 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/sip:1001@192.168.10.192:41080) State Change CS_HANGUP -> CS_REPORTING 2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_REPORTING 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1001@192.168.10.192:41080) State REPORTING 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:1001@192.168.10.192:41080 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1001@192.168.10.192:41080) State REPORTING going to sleep 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/sip:1001@192.168.10.192:41080) State Change CS_REPORTING -> CS_DESTROY 2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:1136 Session 2 (sofia/internal/sip:1001@192.168.10.192:41080) Locked, Waiting on external entities 2010-02-09 21:49:33.331072 [DEBUG] switch_ivr_originate.c:3009 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.331072 [NOTICE] switch_core_session.c:1154 Session 2 (sofia/internal/sip:1001@192.168.10.192:41080) Ended 2010-02-09 21:49:33.331072 [NOTICE] switch_core_session.c:1156 Close Channel sofia/internal/sip:1001@192.168.10.192:41080 [CS_DESTROY] 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_DESTROY 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/sip:1001@192.168.10.192:41080) State DESTROY 2010-02-09 21:49:33.331072 [DEBUG] mod_sofia.c:293 sofia/internal/ sip:1001@192.168.10.192:41080 SOFIA DESTROY 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:1001@192.168.10.192:41080 Standard DESTROY 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/sip:1001@192.168.10.192:41080) State DESTROY going to sleep 2010-02-09 21:49:33.331072 [ERR] switch_ivr_originate.c:2249 Cannot create outgoing channel of type [user] cause: [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.331072 [DEBUG] switch_ivr_originate.c:3009 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.331072 [INFO] mod_dptools.c:2294 Originate Failed. Cause: INCOMPATIBLE_DESTINATION EXECUTE sofia/internal/60002@192.168.10.30 answer() 2010-02-09 21:49:33.332075 [DEBUG] mod_dptools.c:658 sofia/internal/ 60002@192.168.10.30 receive message [ANSWER] 2010-02-09 21:49:33.332075 [DEBUG] sofia_glue.c:2381 AUDIO RTP [sofia/internal/60002@192.168.10.30] 192.168.10.30 port 27634 -> 192.168.10.131 port 25592 codec: 9 ms: 20 2010-02-09 21:49:33.332075 [DEBUG] switch_rtp.c:1167 Starting timer [soft] 160 bytes per 20ms 2010-02-09 21:49:33.333080 [DEBUG] mod_sofia.c:571 Local SDP sofia/internal/ 60002@192.168.10.30: v=0 o=FreeSWITCH 1265704739 1265704740 IN IP4 192.168.10.30 s=FreeSWITCH c=IN IP4 192.168.10.30 t=0 0 m=audio 27634 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2010-02-09 21:49:33.333080 [DEBUG] sofia.c:3727 Channel sofia/internal/ 60002@192.168.10.30 entering state [completed][200] 2010-02-09 21:49:33.333080 [DEBUG] switch_core_session.c:645 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:33.333080 [NOTICE] mod_dptools.c:658 Channel [sofia/internal/60002@192.168.10.30] has been answered 2010-02-09 21:49:33.333080 [DEBUG] switch_channel.c:182 sofia/internal/ 60002@192.168.10.30 receive message [AUDIO_SYNC] EXECUTE sofia/internal/60002@192.168.10.30 sleep(1000) 2010-02-09 21:49:33.334081 [DEBUG] switch_channel.c:182 sofia/internal/ 60002@192.168.10.30 receive message [AUDIO_SYNC] 2010-02-09 21:49:33.395069 [DEBUG] switch_rtp.c:2004 Correct ip/port confirmed. 2010-02-09 21:49:33.455069 [DEBUG] sofia.c:3727 Channel sofia/internal/ 60002@192.168.10.30 entering state [ready][200] EXECUTE sofia/internal/60002@192.168.10.30 voicemail(default 192.168.10.30 1001) 2010-02-09 21:49:34.335070 [DEBUG] mod_voicemail.c:730 [default] rwlock 2010-02-09 21:49:34.370083 [DEBUG] switch_channel.c:182 sofia/internal/ 60002@192.168.10.30 receive message [AUDIO_SYNC] 2010-02-09 21:49:34.475070 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en] 2010-02-09 21:49:34.475070 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-person.wav] (en:en) 2010-02-09 21:49:34.523070 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:34.524073 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:34.526072 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:35.875063 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:35.995062 [DEBUG] switch_ivr_play_say.c:273 Handle say:[1001] (en:en) 2010-02-09 21:49:36.027062 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:36.027062 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:36.028065 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:36.455072 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:36.460061 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:36.460061 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:36.461074 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:36.995060 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:36.995060 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:36.995060 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:36.995060 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:37.535061 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:37.535061 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:37.535061 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:37.535061 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:37.995060 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:38.095060 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-not_available.wav] (en:en) 2010-02-09 21:49:38.118060 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:38.119063 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:38.120062 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:39.075057 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:39.175057 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en] 2010-02-09 21:49:39.177086 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-record_message.wav] (en:en) 2010-02-09 21:49:39.181967 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:39.181967 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:39.192068 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:40.999151 [NOTICE] sofia.c:329 Hangup sofia/internal/ 60002@192.168.10.30 [CS_EXECUTE] [NORMAL_CLEARING] 2010-02-09 21:49:40.999151 [DEBUG] switch_channel.c:1912 Send signal sofia/internal/60002@192.168.10.30 [KILL] 2010-02-09 21:49:40.999151 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:40.999151 [DEBUG] switch_core_state_machine.c:459 sofia/internal/60002@192.168.10.30 thread mismatch skipping state handler. 2010-02-09 21:49:41.015049 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/60002@192.168.10.30) State EXECUTE going to sleep 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_HANGUP 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/60002@192.168.10.30) State HANGUP 2010-02-09 21:49:41.114049 [DEBUG] mod_sofia.c:352 sofia/internal/ 60002@192.168.10.30 Overriding SIP cause 480 with 488 from the other leg 2010-02-09 21:49:41.114049 [DEBUG] mod_sofia.c:358 Channel sofia/internal/ 60002@192.168.10.30 hanging up, cause: NORMAL_CLEARING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:46 sofia/internal/60002@192.168.10.30 Standard HANGUP, cause: NORMAL_CLEARING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/60002@192.168.10.30) State HANGUP going to sleep 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/60002@192.168.10.30) State Change CS_HANGUP -> CS_REPORTING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_REPORTING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/60002@192.168.10.30) State REPORTING 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:53 sofia/internal/60002@192.168.10.30 Standard REPORTING, cause: NORMAL_CLEARING 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/60002@192.168.10.30) State REPORTING going to sleep 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/60002@192.168.10.30) State Change CS_REPORTING -> CS_DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:41.129049 [DEBUG] switch_core_session.c:1136 Session 1 (sofia/internal/60002@192.168.10.30) Locked, Waiting on external entities 2010-02-09 21:49:41.129049 [NOTICE] switch_core_session.c:1154 Session 1 (sofia/internal/60002@192.168.10.30) Ended 2010-02-09 21:49:41.129049 [NOTICE] switch_core_session.c:1156 Close Channel sofia/internal/60002@192.168.10.30 [CS_DESTROY] 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/60002@192.168.10.30) Running State Change CS_DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/60002@192.168.10.30) State DESTROY 2010-02-09 21:49:41.129049 [DEBUG] mod_sofia.c:293 sofia/internal/ 60002@192.168.10.30 SOFIA DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:60 sofia/internal/60002@192.168.10.30 Standard DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/60002@192.168.10.30) State DESTROY going to sleep On 9 February 2010 21:18, Brian West <brian@freeswitch.org> wrote:
What you're saying makes little or no sense to me even on 1.0.4, Can you pastebin your logs?
/b
On Feb 9, 2010, at 3:15 PM, Bruce Hopkins wrote:
OK, many thanks for the extremely swift response Brian.
I will try to get up and running as soon as I can with 1.0.5 and see if the issue goes away.
thanks again Bruce
_______________________________________________ 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
You need to allow SPEEX@8000h,SPEEX@16000h,SPEEX@32000h /b On Feb 9, 2010, at 3:55 PM, Bruce Hopkins wrote:
Willdo,
To clarify in brief though, the scenario which occurs and causes the call to fail is:
SIP client 1 (g.722 enabled only ) -----> INVITE (with SDP offer: Media Attribute (a): rtpmap:9 g722/8000 ) -->FreeSWITCH
---> INVITE (with SDP offer including a bunch of codecs including rtpmap: rtpmap:98 SPEEX/8000 but crucially not including SPEEX/16000 or SPEEX/32000)
---> SIP client 2 (with only SPEEX/16000 or SPEEX/32000 enabled).
The second SIP client does not get offered a codec it can accept, so SIP client 1 is sent a method 488 "Not Acceptable Here" message and the calling party gets directed to the voicemail for the other SIP client.
By contrast, there is no problem calling SPEEX/32000 --> SPEEX/32000 or calling SPEEX/16000 --> SPEEX/16000.
there is also no problem calling SPEEX/32000 --> g.722/8000.
I am wondering if the problem is that FreeSWITCH is interpreting g.722 as being a narrowband (8kHz sample rate) codec, due to the historic anomaly of it presenting g722/8000 in the SDP even though it in fact uses 16kHz sampling, and for that reason not wanting to offer a 16kHz sample rate codec to the second SIP client?
I suggest this as I also found trying to call alaw --> SPEEX/16000 does not work, for example.
Aha - I will try this now. At the moment I only have SPEEX without anything like @8000h or 16000h. Thanks in advance, as I am sure you have spotted my noob error ! Bruce On 9 February 2010 22:00, Brian West <brian@freeswitch.org> wrote:
You need to allow SPEEX@8000h,SPEEX@16000h,SPEEX@32000h
/b
On Feb 9, 2010, at 3:55 PM, Bruce Hopkins wrote:
Willdo,
To clarify in brief though, the scenario which occurs and causes the call to fail is:
SIP client 1 (g.722 enabled only ) -----> INVITE (with SDP offer: Media Attribute (a): rtpmap:9 g722/8000 ) -->FreeSWITCH
---> INVITE (with SDP offer including a bunch of codecs including rtpmap: rtpmap:98 SPEEX/8000 but crucially not including SPEEX/16000 or SPEEX/32000)
---> SIP client 2 (with only SPEEX/16000 or SPEEX/32000 enabled).
The second SIP client does not get offered a codec it can accept, so SIP client 1 is sent a method 488 "Not Acceptable Here" message and the calling party gets directed to the voicemail for the other SIP client.
By contrast, there is no problem calling SPEEX/32000 --> SPEEX/32000 or calling SPEEX/16000 --> SPEEX/16000.
there is also no problem calling SPEEX/32000 --> g.722/8000.
I am wondering if the problem is that FreeSWITCH is interpreting g.722 as being a narrowband (8kHz sample rate) codec, due to the historic anomaly of it presenting g722/8000 in the SDP even though it in fact uses 16kHz sampling, and for that reason not wanting to offer a 16kHz sample rate codec to the second SIP client?
I suggest this as I also found trying to call alaw --> SPEEX/16000 does not work, for example.
_______________________________________________ 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
Hi again Brian, I can confirm that having followed your advice, it now works perfectly. Many, many thanks for your extraordinarily quick and comprehensive help with this. Best wishes Bruce On 9 February 2010 22:13, Bruce Hopkins <jbrucehopkins@gmail.com> wrote:
Aha - I will try this now. At the moment I only have SPEEX without anything like @8000h or 16000h.
Thanks in advance, as I am sure you have spotted my noob error !
Bruce
On 9 February 2010 22:00, Brian West <brian@freeswitch.org> wrote:
You need to allow SPEEX@8000h,SPEEX@16000h,SPEEX@32000h
/b
On Feb 9, 2010, at 3:55 PM, Bruce Hopkins wrote:
Willdo,
To clarify in brief though, the scenario which occurs and causes the call to fail is:
SIP client 1 (g.722 enabled only ) -----> INVITE (with SDP offer: Media Attribute (a): rtpmap:9 g722/8000 ) -->FreeSWITCH
---> INVITE (with SDP offer including a bunch of codecs including rtpmap: rtpmap:98 SPEEX/8000 but crucially not including SPEEX/16000 or SPEEX/32000)
---> SIP client 2 (with only SPEEX/16000 or SPEEX/32000 enabled).
The second SIP client does not get offered a codec it can accept, so SIP client 1 is sent a method 488 "Not Acceptable Here" message and the calling party gets directed to the voicemail for the other SIP client.
By contrast, there is no problem calling SPEEX/32000 --> SPEEX/32000 or calling SPEEX/16000 --> SPEEX/16000.
there is also no problem calling SPEEX/32000 --> g.722/8000.
I am wondering if the problem is that FreeSWITCH is interpreting g.722 as being a narrowband (8kHz sample rate) codec, due to the historic anomaly of it presenting g722/8000 in the SDP even though it in fact uses 16kHz sampling, and for that reason not wanting to offer a 16kHz sample rate codec to the second SIP client?
I suggest this as I also found trying to call alaw --> SPEEX/16000 does not work, for example.
_______________________________________________ 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
I think I see the problem: In the log is the following: 2010-02-09 21:49:36.995060 [WARNING] switch_core_file.c:177 Sample rate doesn't match However, surely this is incorrect, as g.722 and SPEEX/16000 in fact both do use the same sample rate of 16kHz g.722 might not look like it from the SDP which announces g722/8000 - but this is a historical error in the RFC. Bruce On 9 February 2010 21:55, Bruce Hopkins <jbrucehopkins@gmail.com> wrote:
Willdo,
To clarify in brief though, the scenario which occurs and causes the call to fail is:
SIP client 1 (g.722 enabled only ) -----> INVITE (with SDP offer: Media Attribute (a): rtpmap:9 g722/8000 ) -->FreeSWITCH
---> INVITE (with SDP offer including a bunch of codecs including rtpmap: rtpmap:98 SPEEX/8000 but crucially *not* including SPEEX/16000 or SPEEX/32000)
---> SIP client 2 (with only SPEEX/16000 or SPEEX/32000 enabled).
The second SIP client does not get offered a codec it can accept, so SIP client 1 is sent a method 488 "Not Acceptable Here" message and the calling party gets directed to the voicemail for the other SIP client.
By contrast, there is no problem calling SPEEX/32000 --> SPEEX/32000 or calling SPEEX/16000 --> SPEEX/16000.
there is also no problem calling SPEEX/32000 --> g.722/8000.
I am wondering if the problem is that FreeSWITCH is interpreting g.722 as being a narrowband (8kHz sample rate) codec, due to the historic anomaly of it presenting g722/8000 in the SDP even though it in fact uses 16kHz sampling, and for that reason not wanting to offer a 16kHz sample rate codec to the second SIP client?
I suggest this as I also found trying to call alaw --> SPEEX/16000 does not work, for example.
Here is the log file for the scenario which does not work (g.722 client trying to call Speex wideband client). Please let me know if a Wireshark trace would be helpful.
2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5224 0 acls to check for proxy 2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5242 network ip is a proxy [0] 2010-02-09 21:49:32.784387 [DEBUG] sofia.c:5270 IP 192.168.10.131 Rejected by acl "domains". Falling back to Digest auth. 2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5224 0 acls to check for proxy 2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5242 network ip is a proxy [0] 2010-02-09 21:49:32.791074 [DEBUG] sofia.c:5270 IP 192.168.10.131 Rejected by acl "domains". Falling back to Digest auth. 2010-02-09 21:49:32.794074 [NOTICE] switch_channel.c:613 New Channel sofia/internal/60002@192.168.10.30 [66610a8c-aec9-48ca-9b67-aafdcd3e3d08] 2010-02-09 21:49:32.794074 [DEBUG] sofia.c:3727 Channel sofia/internal/ 60002@192.168.10.30 entering state [received][100] 2010-02-09 21:49:32.794074 [DEBUG] sofia.c:3738 Remote SDP: v=0 o=- 5 2 IN IP4 192.168.10.131 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.10.131 t=0 0 m=audio 25592 RTP/AVP 9 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15
2010-02-09 21:49:32.794074 [DEBUG] sofia_glue.c:3305 Audio Codec Compare [G722:9:8000:20]/[G722:9:8000:20] 2010-02-09 21:49:32.795079 [DEBUG] sofia_glue.c:2143 Set Codec sofia/internal/60002@192.168.10.30 G722/8000 20 ms 160 samples 2010-02-09 21:49:32.795079 [DEBUG] sofia_glue.c:3261 Set 2833 dtmf payload to 101 2010-02-09 21:49:32.795079 [DEBUG] sofia.c:3885 (sofia/internal/ 60002@192.168.10.30) State Change CS_NEW -> CS_INIT 2010-02-09 21:49:32.795079 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_INIT 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/60002@192.168.10.30) State INIT 2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:83 sofia/internal/ 60002@192.168.10.30 SOFIA INIT 2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:111 (sofia/internal/ 60002@192.168.10.30) State Change CS_INIT -> CS_ROUTING 2010-02-09 21:49:32.795079 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/60002@192.168.10.30) State INIT going to sleep 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_ROUTING 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/60002@192.168.10.30) State ROUTING 2010-02-09 21:49:32.795079 [DEBUG] mod_sofia.c:132 sofia/internal/ 60002@192.168.10.30 SOFIA ROUTING 2010-02-09 21:49:32.795079 [DEBUG] switch_core_state_machine.c:78 sofia/internal/60002@192.168.10.30 Standard ROUTING 2010-02-09 21:49:32.795079 [INFO] mod_dialplan_xml.c:408 Processing 60002->1001 in context default Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unloop] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->tod_example] continue=true Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [tod_example] ${strftime(%w)}(2) =~ /^([1-5])$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [tod_example] ${strftime(%H%M)}(2149) =~ /^((09|1[0-7])[0-5][0-9]|1800)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^\*886$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->redial] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [redial] destination_number(1001) =~ /^\*870$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->global] continue=true Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${network_addr}(192.168.10.131) =~ /^$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 ANTI-Action set(use_profile=${cond(${acl(${network_addr} rfc1918)} == true ? nat : default)}) Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [global] ${numbering_plan}() =~ /^$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 Action set_user(default@${domain_name})
Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/60002@192.168.10.30 Absolute Condition [global] Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^\*9001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^\*9000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^\*88(.*)$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^\*779$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call_privacy] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call_privacy] destination_number(1001) =~ /^\*67(\d+)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call_return] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->del-group] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [del-group] destination_number(1001) =~ /^\*80(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->add-group] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [add-group] destination_number(1001) =~ /^\*81(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^\*82(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^\*83(\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^\*8(\d{4})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_5digits] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_5digits] destination_number(1001) =~ /^\*99(\d{5})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_4digits] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_4digits] destination_number(1001) =~ /^\*99(\d{4})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->send_to_voicemail_3digits] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [send_to_voicemail_3digits] destination_number(1001) =~ /^\*99(\d{3})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->pizza_demo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [pizza_demo] destination_number(1001) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->2001] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [2001] destination_number(1001) =~ /^2001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Call via asterisk-pbx1] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [Call via asterisk-pbx1] destination_number(1001) =~ /269065/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->pizza_demo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [pizza_demo] destination_number(1001) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->5002] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [5002] destination_number(1001) =~ /^5002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->7002] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [7002] destination_number(1001) =~ /^7002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->DISA] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [DISA] destination_number(1001) =~ /^\*(3472)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Recordings] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [Recordings] destination_number(1001) =~ /^\*(732673)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->7002.park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [7002.park] destination_number(1001) =~ /^\*7002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_sales] destination_number(1001) =~ /^\*2000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_support] destination_number(1001) =~ /^\*2001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [group_dial_billing] destination_number(1001) =~ /^\*2002$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->vmain2] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [vmain2] destination_number(1001) =~ /^vmain2$|^\*97$|^\*4000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->vmain] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [vmain] destination_number(1001) =~ /^vmain$|^\*98$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [sip_uri] destination_number(1001) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [nb_conferences] destination_number(1001) =~ /^\*(30\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [wb_conferences] destination_number(1001) =~ /^\*(31\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [uwb_conferences] destination_number(1001) =~ /^\*(32\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [cdquality_conferences] destination_number(1001) =~ /^\*(33\d{2})$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(1001) =~ /^\*9(888|1616|3232)$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss_intercom] destination_number(1001) =~ /^\*0911$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss_intercom] destination_number(1001) =~ /^\*0912$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->mad_boss] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [mad_boss] destination_number(1001) =~ /^\*0913$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ivr_demo] destination_number(1001) =~ /^\*5000$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [dynamic_conference] destination_number(1001) =~ /^\*5001$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [rtp_multicast_page] destination_number(1001) =~ /^\*pagegroup$|^\*7243/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /^\*5900$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /^\*5901$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /park\+(\d+)/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /^parking$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->park] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [park] destination_number(1001) =~ /callpark/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->unpark] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [unpark] destination_number(1001) =~ /pickup/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->wait] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [wait] destination_number(1001) =~ /^wait$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->fax_receive] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [fax_receive] destination_number(1001) =~ /^\*9978$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->fax_transmit] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [fax_transmit] destination_number(1001) =~ /^\*9979$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_180] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_180] destination_number(1001) =~ /^\*9980$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_183_uk_ring] destination_number(1001) =~ /^\*9981$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_183_music_ring] destination_number(1001) =~ /^\*9982$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(1001) =~ /^\*9983$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ringback_post_answer_music] destination_number(1001) =~ /^\*9984$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->ClueCon] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [ClueCon] destination_number(1001) =~ /^\*9991$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->show_info] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [show_info] destination_number(1001) =~ /^\*9992$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->video_record] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [video_record] destination_number(1001) =~ /^\*9993$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->video_playback] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [video_playback] destination_number(1001) =~ /^\*9994$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->delay_echo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [delay_echo] destination_number(1001) =~ /^\*9995$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->echo] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [echo] destination_number(1001) =~ /^\*9996$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->milliwatt] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [milliwatt] destination_number(1001) =~ /^\*9997$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->tone_stream] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [tone_stream] destination_number(1001) =~ /^\*9998$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [zrtp_enrollement] destination_number(1001) =~ /^\*9787$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->hold_music] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (FAIL) [hold_music] destination_number(1001) =~ /^\*9999$/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/60002@192.168.10.30 Regex (PASS) [Local_Extension] destination_number(1001) =~ /(^\d{6}$|\d{5}$|^\d{4}$|^\d{3}$)/ break=on-false Dialplan: sofia/internal/60002@192.168.10.30 Action set(dialed_extension=1001) Dialplan: sofia/internal/60002@192.168.10.30 Action export(dialed_extension=1001) Dialplan: sofia/internal/60002@192.168.10.30 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/60002@192.168.10.30 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
Dialplan: sofia/internal/60002@192.168.10.30 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/60002@192.168.10.30 Action set(ringback=${us-ring}) Dialplan: sofia/internal/60002@192.168.10.30 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/60002@192.168.10.30 Action set(call_timeout=30) Dialplan: sofia/internal/60002@192.168.10.30 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/60002@192.168.10.30 Action set(continue_on_fail=true) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/60002@192.168.10.30 Action db(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/60002@192.168.10.30 Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/60002@192.168.10.30 Action answer() Dialplan: sofia/internal/60002@192.168.10.30 Action sleep(1000) Dialplan: sofia/internal/60002@192.168.10.30 Action voicemail(default ${domain_name} ${dialed_extension}) 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:122 (sofia/internal/60002@192.168.10.30) State Change CS_ROUTING -> CS_EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/60002@192.168.10.30) State ROUTING going to sleep 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/60002@192.168.10.30) State EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] mod_sofia.c:181 sofia/internal/ 60002@192.168.10.30 SOFIA EXECUTE 2010-02-09 21:49:32.798073 [DEBUG] switch_core_state_machine.c:159 sofia/internal/60002@192.168.10.30 Standard EXECUTE EXECUTE sofia/internal/60002@192.168.10.30 set(use_profile=default) 2010-02-09 21:49:32.798073 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [use_profile]=[default] EXECUTE sofia/internal/60002@192.168.10.30 set_user(default@192.168.10.30) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-spymap/60002/66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial/60002/1001) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial/global/66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30 set(dialed_extension=1001) 2010-02-09 21:49:32.857126 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [dialed_extension]=[1001] EXECUTE sofia/internal/60002@192.168.10.30 export(dialed_extension=1001) 2010-02-09 21:49:32.858075 [DEBUG] mod_dptools.c:851 EXPORT [dialed_extension]=[1001] EXECUTE sofia/internal/60002@192.168.10.30 bind_meta_app(1 b s execute_extension::dx XML features) 2010-02-09 21:49:32.858075 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 1 execute_extension::dx XML features EXECUTE sofia/internal/60002@192.168.10.30 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/60002.2010-02-09-21-49-32.wav) 2010-02-09 21:49:32.858075 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 2 record_session::/usr/local/freeswitch/recordings/60002.2010-02-09-21-49-32.wav EXECUTE sofia/internal/60002@192.168.10.30 bind_meta_app(3 b s execute_extension::cf XML features) 2010-02-09 21:49:32.859074 [INFO] switch_ivr_async.c:2174 Bound B-Leg: 3 execute_extension::cf XML features EXECUTE sofia/internal/60002@192.168.10.30 set(ringback=%(2000, 4000, 440.0, 480.0)) 2010-02-09 21:49:32.859074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [ringback]=[%(2000, 4000, 440.0, 480.0)] EXECUTE sofia/internal/60002@192.168.10.30set(transfer_ringback=local_stream://moh) 2010-02-09 21:49:32.859074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/60002@192.168.10.30 set(call_timeout=30) 2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [call_timeout]=[30] EXECUTE sofia/internal/60002@192.168.10.30 set(hangup_after_bridge=true) 2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/60002@192.168.10.30 set(continue_on_fail=true) 2010-02-09 21:49:32.860074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [continue_on_fail]=[true] EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-call_return/1001/60002) EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial_ext/1001/66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30 set(called_party_callgroup=) 2010-02-09 21:49:32.870074 [DEBUG] mod_dptools.c:768 sofia/internal/ 60002@192.168.10.30 SET [called_party_callgroup]=[UNDEF] EXECUTE sofia/internal/60002@192.168.10.30db(insert/192.168.10.30-last_dial//66610a8c-aec9-48ca-9b67-aafdcd3e3d08) EXECUTE sofia/internal/60002@192.168.10.30 bridge(user/1001@192.168.10.30) 2010-02-09 21:49:32.905073 [DEBUG] switch_ivr_originate.c:1735 variable string 0 = [presence_id=1001@192.168.10.30] 2010-02-09 21:49:32.905073 [NOTICE] switch_channel.c:613 New Channel sofia/internal/sip:1001@192.168.10.192:41080[df7cf235-f0e4-406a-83a5-dd2d681bb278] 2010-02-09 21:49:32.905073 [DEBUG] mod_sofia.c:3142 (sofia/internal/ sip:1001@192.168.10.192:41080) State Change CS_NEW -> CS_INIT 2010-02-09 21:49:32.905073 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:32.906075 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_INIT 2010-02-09 21:49:32.906075 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:1001@192.168.10.192:41080) State INIT 2010-02-09 21:49:32.906075 [DEBUG] mod_sofia.c:83 sofia/internal/ sip:1001@192.168.10.192:41080 SOFIA INIT 2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:111 (sofia/internal/ sip:1001@192.168.10.192:41080) State Change CS_INIT -> CS_ROUTING 2010-02-09 21:49:32.907184 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:32.907184 [DEBUG] sofia.c:3727 Channel sofia/internal/ sip:1001@192.168.10.192:41080 entering state [calling][0] 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:1001@192.168.10.192:41080) State INIT going to sleep 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_ROUTING 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:1001@192.168.10.192:41080) State ROUTING 2010-02-09 21:49:32.907184 [DEBUG] mod_sofia.c:132 sofia/internal/ sip:1001@192.168.10.192:41080 SOFIA ROUTING 2010-02-09 21:49:32.907184 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1001@192.168.10.192:41080) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2010-02-09 21:49:32.907184 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:1001@192.168.10.192:41080) State ROUTING going to sleep 2010-02-09 21:49:32.907184 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_CONSUME_MEDIA 2010-02-09 21:49:33.023071 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/sip:1001@192.168.10.192:41080) State CONSUME_MEDIA 2010-02-09 21:49:33.023071 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/sip:1001@192.168.10.192:41080) State CONSUME_MEDIA going to sleep 2010-02-09 21:49:33.329319 [DEBUG] sofia.c:3727 Channel sofia/internal/ sip:1001@192.168.10.192:41080 entering state [terminated][488] 2010-02-09 21:49:33.329319 [NOTICE] sofia.c:4331 Hangup sofia/internal/ sip:1001@192.168.10.192:41080 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.329319 [DEBUG] switch_channel.c:1912 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [KILL] 2010-02-09 21:49:33.329319 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:33.329319 [DEBUG] switch_core_state_machine.c:459 sofia/internal/sip:1001@192.168.10.192:41080 thread mismatch skipping state handler. 2010-02-09 21:49:33.329319 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_HANGUP 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/sip:1001@192.168.10.192:41080) State HANGUP 2010-02-09 21:49:33.330075 [DEBUG] mod_sofia.c:352 sofia/internal/ sip:1001@192.168.10.192:41080 Overriding SIP cause 488 with 488 from the other leg 2010-02-09 21:49:33.330075 [DEBUG] mod_sofia.c:358 Channel sofia/internal/ sip:1001@192.168.10.192:41080 hanging up, cause: INCOMPATIBLE_DESTINATION 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:1001@192.168.10.192:41080 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/sip:1001@192.168.10.192:41080) State HANGUP going to sleep 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/sip:1001@192.168.10.192:41080) State Change CS_HANGUP -> CS_REPORTING 2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_REPORTING 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1001@192.168.10.192:41080) State REPORTING 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:1001@192.168.10.192:41080 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1001@192.168.10.192:41080) State REPORTING going to sleep 2010-02-09 21:49:33.330075 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/sip:1001@192.168.10.192:41080) State Change CS_REPORTING -> CS_DESTROY 2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/sip:1001@192.168.10.192:41080 [BREAK] 2010-02-09 21:49:33.330075 [DEBUG] switch_core_session.c:1136 Session 2 (sofia/internal/sip:1001@192.168.10.192:41080) Locked, Waiting on external entities 2010-02-09 21:49:33.331072 [DEBUG] switch_ivr_originate.c:3009 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.331072 [NOTICE] switch_core_session.c:1154 Session 2 (sofia/internal/sip:1001@192.168.10.192:41080) Ended 2010-02-09 21:49:33.331072 [NOTICE] switch_core_session.c:1156 Close Channel sofia/internal/sip:1001@192.168.10.192:41080 [CS_DESTROY] 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/sip:1001@192.168.10.192:41080) Running State Change CS_DESTROY 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/sip:1001@192.168.10.192:41080) State DESTROY 2010-02-09 21:49:33.331072 [DEBUG] mod_sofia.c:293 sofia/internal/ sip:1001@192.168.10.192:41080 SOFIA DESTROY 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:1001@192.168.10.192:41080 Standard DESTROY 2010-02-09 21:49:33.331072 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/sip:1001@192.168.10.192:41080) State DESTROY going to sleep 2010-02-09 21:49:33.331072 [ERR] switch_ivr_originate.c:2249 Cannot create outgoing channel of type [user] cause: [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.331072 [DEBUG] switch_ivr_originate.c:3009 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2010-02-09 21:49:33.331072 [INFO] mod_dptools.c:2294 Originate Failed. Cause: INCOMPATIBLE_DESTINATION EXECUTE sofia/internal/60002@192.168.10.30 answer() 2010-02-09 21:49:33.332075 [DEBUG] mod_dptools.c:658 sofia/internal/ 60002@192.168.10.30 receive message [ANSWER] 2010-02-09 21:49:33.332075 [DEBUG] sofia_glue.c:2381 AUDIO RTP [sofia/internal/60002@192.168.10.30] 192.168.10.30 port 27634 -> 192.168.10.131 port 25592 codec: 9 ms: 20 2010-02-09 21:49:33.332075 [DEBUG] switch_rtp.c:1167 Starting timer [soft] 160 bytes per 20ms 2010-02-09 21:49:33.333080 [DEBUG] mod_sofia.c:571 Local SDP sofia/internal/60002@192.168.10.30: v=0 o=FreeSWITCH 1265704739 1265704740 IN IP4 192.168.10.30 s=FreeSWITCH c=IN IP4 192.168.10.30 t=0 0 m=audio 27634 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv
2010-02-09 21:49:33.333080 [DEBUG] sofia.c:3727 Channel sofia/internal/ 60002@192.168.10.30 entering state [completed][200] 2010-02-09 21:49:33.333080 [DEBUG] switch_core_session.c:645 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:33.333080 [NOTICE] mod_dptools.c:658 Channel [sofia/internal/60002@192.168.10.30] has been answered 2010-02-09 21:49:33.333080 [DEBUG] switch_channel.c:182 sofia/internal/ 60002@192.168.10.30 receive message [AUDIO_SYNC] EXECUTE sofia/internal/60002@192.168.10.30 sleep(1000) 2010-02-09 21:49:33.334081 [DEBUG] switch_channel.c:182 sofia/internal/ 60002@192.168.10.30 receive message [AUDIO_SYNC] 2010-02-09 21:49:33.395069 [DEBUG] switch_rtp.c:2004 Correct ip/port confirmed. 2010-02-09 21:49:33.455069 [DEBUG] sofia.c:3727 Channel sofia/internal/ 60002@192.168.10.30 entering state [ready][200] EXECUTE sofia/internal/60002@192.168.10.30 voicemail(default 192.168.10.30 1001) 2010-02-09 21:49:34.335070 [DEBUG] mod_voicemail.c:730 [default] rwlock 2010-02-09 21:49:34.370083 [DEBUG] switch_channel.c:182 sofia/internal/ 60002@192.168.10.30 receive message [AUDIO_SYNC] 2010-02-09 21:49:34.475070 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en] 2010-02-09 21:49:34.475070 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-person.wav] (en:en) 2010-02-09 21:49:34.523070 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:34.524073 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:34.526072 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:35.875063 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:35.995062 [DEBUG] switch_ivr_play_say.c:273 Handle say:[1001] (en:en) 2010-02-09 21:49:36.027062 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:36.027062 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:36.028065 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:36.455072 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:36.460061 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:36.460061 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:36.461074 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:36.995060 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:36.995060 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:36.995060 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:36.995060 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:37.535061 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:37.535061 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:37.535061 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:37.535061 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:37.995060 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:38.095060 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-not_available.wav] (en:en) 2010-02-09 21:49:38.118060 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:38.119063 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:38.120062 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:39.075057 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:39.175057 [DEBUG] switch_ivr_play_say.c:118 No language specified - Using [en] 2010-02-09 21:49:39.177086 [DEBUG] switch_ivr_play_say.c:273 Handle play-file:[voicemail/vm-record_message.wav] (en:en) 2010-02-09 21:49:39.181967 [WARNING] switch_core_file.c:177 Sample rate doesn't match 2010-02-09 21:49:39.181967 [DEBUG] switch_ivr_play_say.c:1154 Codec Activated L16@16000hz 1 channels 20ms 2010-02-09 21:49:39.192068 [DEBUG] switch_core_io.c:652 sofia/internal/ 60002@192.168.10.30 receive message [TRANSCODING_NECESSARY] 2010-02-09 21:49:40.999151 [NOTICE] sofia.c:329 Hangup sofia/internal/ 60002@192.168.10.30 [CS_EXECUTE] [NORMAL_CLEARING] 2010-02-09 21:49:40.999151 [DEBUG] switch_channel.c:1912 Send signal sofia/internal/60002@192.168.10.30 [KILL] 2010-02-09 21:49:40.999151 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:40.999151 [DEBUG] switch_core_state_machine.c:459 sofia/internal/60002@192.168.10.30 thread mismatch skipping state handler. 2010-02-09 21:49:41.015049 [DEBUG] switch_ivr_play_say.c:1446 done playing file 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/60002@192.168.10.30) State EXECUTE going to sleep 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_HANGUP 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/60002@192.168.10.30) State HANGUP 2010-02-09 21:49:41.114049 [DEBUG] mod_sofia.c:352 sofia/internal/ 60002@192.168.10.30 Overriding SIP cause 480 with 488 from the other leg 2010-02-09 21:49:41.114049 [DEBUG] mod_sofia.c:358 Channel sofia/internal/ 60002@192.168.10.30 hanging up, cause: NORMAL_CLEARING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:46 sofia/internal/60002@192.168.10.30 Standard HANGUP, cause: NORMAL_CLEARING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:488 (sofia/internal/60002@192.168.10.30) State HANGUP going to sleep 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/60002@192.168.10.30) State Change CS_HANGUP -> CS_REPORTING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/60002@192.168.10.30) Running State Change CS_REPORTING 2010-02-09 21:49:41.114049 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/60002@192.168.10.30) State REPORTING 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:53 sofia/internal/60002@192.168.10.30 Standard REPORTING, cause: NORMAL_CLEARING 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/60002@192.168.10.30) State REPORTING going to sleep 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/60002@192.168.10.30) State Change CS_REPORTING -> CS_DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_session.c:999 Send signal sofia/internal/60002@192.168.10.30 [BREAK] 2010-02-09 21:49:41.129049 [DEBUG] switch_core_session.c:1136 Session 1 (sofia/internal/60002@192.168.10.30) Locked, Waiting on external entities 2010-02-09 21:49:41.129049 [NOTICE] switch_core_session.c:1154 Session 1 (sofia/internal/60002@192.168.10.30) Ended 2010-02-09 21:49:41.129049 [NOTICE] switch_core_session.c:1156 Close Channel sofia/internal/60002@192.168.10.30 [CS_DESTROY] 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/60002@192.168.10.30) Running State Change CS_DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/60002@192.168.10.30) State DESTROY 2010-02-09 21:49:41.129049 [DEBUG] mod_sofia.c:293 sofia/internal/ 60002@192.168.10.30 SOFIA DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:60 sofia/internal/60002@192.168.10.30 Standard DESTROY 2010-02-09 21:49:41.129049 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/60002@192.168.10.30) State DESTROY going to sleep
On 9 February 2010 21:18, Brian West <brian@freeswitch.org> wrote:
What you're saying makes little or no sense to me even on 1.0.4, Can you pastebin your logs?
/b
On Feb 9, 2010, at 3:15 PM, Bruce Hopkins wrote:
OK, many thanks for the extremely swift response Brian.
I will try to get up and running as soon as I can with 1.0.5 and see if the issue goes away.
thanks again Bruce
_______________________________________________ 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
Nope we don't look at that... that isn't the problem. The issue is you haven't allowed SPEEX@16000h or SPEEX@32000h You can't just allow SPEEX... it can't figure out what you mean by just SPEEX. See previous email. /b On Feb 9, 2010, at 4:04 PM, Bruce Hopkins wrote:
g.722 might not look like it from the SDP which announces g722/8000 - but this is a historical error in the RFC.
Bruce
This means you're playing a wav file that doesn't match so it has to resample it... Please open up vars.xml and read thru the codec docs there in the XML directly. It will explain the codecs and how to allow them in various ptimes and rates as you need to do in your case. Its got nothing to do with G722/8000 or anything to do with the file you're playing (which isn't matching the channel sample rate so it has to resample so at the very least it works. Run the "file" util on your wav file and see what its real rate is. /b On Feb 9, 2010, at 4:04 PM, Bruce Hopkins wrote:
2010-02-09 21:49:36.995060 [WARNING] switch_core_file.c:177 Sample rate doesn't match
participants (2)
-
Brian West
-
Bruce Hopkins