Re: [Freeswitch-dev] :how to let the version 2.1.3 as well as the latest (from git) work for the 0911 and 5001 dialplan? there is no problem with version 1.06

in addition to previous email, i also try the following: - add a new diaplan (5002) similar to 5001 in default.xml <extension name="dynamic_conference"> <condition field="destination_number" expression="^5002$"> <action application="conference" data="bridge:mydynaconf:sofia/${use_profile}/1002@192.168.0.100"/> </condition> </extension> - reloadxml - then call 5002 from 1010 sip client, - the same problem happens PS: it works fine on version 1.06 ========================================================== freeswitch@mydev.mydomain.com> reloadxml +OK [Success] 2012-09-27 09:46:46.613468 [INFO] mod_enum.c:871 ENUM Reloaded 2012-09-27 09:46:46.613468 [INFO] switch_time.c:1163 Timezone reloaded 530 definitions freeswitch@mydev.mydomain.com> 2012-09-27 09:47:19.413468 [NOTICE] switch_channel.c:951 New Channel sofia/internal/1010@192.168.0.100[45f8ccbe-0845-11e2-b58c-8d63071eb0f5] 2012-09-27 09:47:19.413468 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.413468 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_NEW 2012-09-27 09:47:19.413468 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1010@192.168.0.100) State NEW 2012-09-27 09:47:19.413468 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.433469 [DEBUG] sofia.c:8412 IP 192.168.0.10 Rejected by acl "domains". Falling back to Digest auth. 2012-09-27 09:47:19.433469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.433469 [DEBUG] sofia.c:1728 detaching session 45f8ccbe-0845-11e2-b58c-8d63071eb0f5 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:1820 Re-attaching to session 45f8ccbe-0845-11e2-b58c-8d63071eb0f5 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:8412 IP 192.168.0.10 Rejected by acl "domains". Falling back to Digest auth. 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1010@192.168.0.100 entering state [received][100] 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6293 Remote SDP: v=0 o=1010 3519 3519 IN IP4 192.168.0.10 s=Talk c=IN IP4 192.168.0.10 t=0 0 m=audio 7078 RTP/AVP 112 111 110 3 0 8 101 a=rtpmap:112 speex/32000 a=fmtp:112 vbr=on a=rtpmap:111 speex/16000 a=fmtp:111 vbr=on a=rtpmap:110 speex/8000 a=fmtp:110 vbr=on a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6506 (sofia/internal/ 1010@192.168.0.100) State Change CS_NEW -> CS_INIT 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_INIT 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/1010@192.168.0.100) State INIT 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:86 sofia/internal/ 1010@192.168.0.100 SOFIA INIT 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:126 (sofia/internal/ 1010@192.168.0.100) State Change CS_INIT -> CS_ROUTING 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/1010@192.168.0.100) State INIT going to sleep 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_ROUTING 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1964 (sofia/internal/ 1010@192.168.0.100) Callstate Change DOWN -> RINGING 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/1010@192.168.0.100) State ROUTING 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:149 sofia/internal/ 1010@192.168.0.100 SOFIA ROUTING 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:117 sofia/internal/1010@192.168.0.100 Standard ROUTING 2012-09-27 09:47:19.453469 [INFO] mod_dialplan_xml.c:485 Processing 1010 <1010>->5002 in context default Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->unloop] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1010@192.168.0.100 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1010@192.168.0.100 Action set(open=true) Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1010@192.168.0.100 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [global-intercept] destination_number(5002) =~ /^886$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group-intercept] destination_number(5002) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [intercept-ext] destination_number(5002) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->redial] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [redial] destination_number(5002) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->global] continue=true Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/1010@192.168.0.100 Absolute Condition [global] Dialplan: sofia/internal/1010@192.168.0.100 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1010@192.168.0.100 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1010@192.168.0.100 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1010@192.168.0.100 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [snom-demo-2] destination_number(5002) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [snom-demo-1] destination_number(5002) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [eavesdrop] destination_number(5002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [eavesdrop] destination_number(5002) =~ /^779$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->call_return] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [call_return] destination_number(5002) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->del-group] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [del-group] destination_number(5002) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->add-group] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [add-group] destination_number(5002) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [call-group-simo] destination_number(5002) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [call-group-order] destination_number(5002) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [extension-intercom] destination_number(5002) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [Local_Extension] destination_number(5002) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [Local_Extension_Skinny] destination_number(5002) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group_dial_sales] destination_number(5002) =~ /^2000$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group_dial_support] destination_number(5002) =~ /^2001$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group_dial_billing] destination_number(5002) =~ /^2002$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->operator] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [operator] destination_number(5002) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->vmain] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [vmain] destination_number(5002) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [sip_uri] destination_number(5002) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [nb_conferences] destination_number(5002) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [wb_conferences] destination_number(5002) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [uwb_conferences] destination_number(5002) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [cdquality_conferences] destination_number(5002) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(5002) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [mad_boss_intercom] destination_number(5002) =~ /^0911$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [mad_boss_intercom] destination_number(5002) =~ /^0912$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->mad_boss] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [mad_boss] destination_number(5002) =~ /^0913$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [ivr_demo] destination_number(5002) =~ /^5000$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [dynamic_conference] destination_number(5002) =~ /^5001$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (PASS) [dynamic_conference] destination_number(5002) =~ /^5002$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 Action conference(bridge:mydynaconf:sofia/${use_profile}/1002@192.168.0.100) 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1010@192.168.0.100) State Change CS_ROUTING -> CS_EXECUTE 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/1010@192.168.0.100) State ROUTING going to sleep 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_EXECUTE 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/1010@192.168.0.100) State EXECUTE 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:242 sofia/internal/ 1010@192.168.0.100 SOFIA EXECUTE 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1010@192.168.0.100 Standard EXECUTE EXECUTE sofia/internal/1010@192.168.0.100 set(open=true) 2012-09-27 09:47:19.453469 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [open]=[true] EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-spymap/1010/45f8ccbe-0845-11e2-b58c-8d63071eb0f5) EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-last_dial/1010/5002) EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-last_dial/global/45f8ccbe-0845-11e2-b58c-8d63071eb0f5) EXECUTE sofia/internal/1010@192.168.0.100 export(RFC2822_DATE=Thu, 27 Sep 2012 09:47:19 +0800) 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1118 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 27 Sep 2012 09:47:19 +0800] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:2390 Application conference Requires media! pre_answering channel sofia/internal/ 1010@192.168.0.100 2012-09-27 09:47:19.453469 [INFO] switch_core_session.c:2392 Sending early media 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[G722:9:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[PCMU:0:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[PCMA:8:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[GSM:3:8000:20:13200] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[G722:9:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[PCMU:0:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[PCMA:8:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[GSM:3:8000:20:13200] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[G722:9:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[PCMU:0:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[PCMA:8:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[GSM:3:8000:20:13200] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[G722:9:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[PCMU:0:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[PCMA:8:8000:20:64000] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[GSM:3:8000:20:13200] 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:3077 Set Codec sofia/internal/1010@192.168.0.100 GSM/8000 20 ms 160 samples 13200 bits 2012-09-27 09:47:19.453469 [DEBUG] switch_core_codec.c:111 sofia/internal/ 1010@192.168.0.100 Original read codec set to GSM:3 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:5219 Set 2833 dtmf send/recv payload to 101 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:3327 AUDIO RTP [sofia/internal/1010@192.168.0.100] 192.168.0.100 port 31092 -> 192.168.0.10 port 7078 codec: 3 ms: 20 2012-09-27 09:47:19.453469 [DEBUG] switch_rtp.c:1927 Starting timer [soft] 160 bytes per 20ms 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:3591 Set 2833 dtmf send payload to 101 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:3597 Set 2833 dtmf receive payload to 101 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:3624 sofia/internal/ 1010@192.168.0.100 Set rtp dtmf delay to 40 2012-09-27 09:47:19.453469 [NOTICE] sofia_glue.c:4226 Pre-Answer sofia/internal/1010@192.168.0.100! 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:3092 (sofia/internal/ 1010@192.168.0.100) Callstate Change RINGING -> EARLY 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:2730 Ring SDP: v=0 o=FreeSWITCH 1348679347 1348679348 IN IP4 192.168.0.100 s=FreeSWITCH c=IN IP4 192.168.0.100 t=0 0 m=audio 31092 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:759 Send signal sofia/internal/1010@192.168.0.100 [BREAK] EXECUTE sofia/internal/1010@192.168.0.100conference(bridge:mydynaconf:sofia/internal/ 1002@192.168.0.100) 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1010@192.168.0.100 entering state [early][183] 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:836 Local SDP sofia/internal/ 1010@192.168.0.100: v=0 o=FreeSWITCH 1348679347 1348679349 IN IP4 192.168.0.100 s=FreeSWITCH c=IN IP4 192.168.0.100 t=0 0 m=audio 31092 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:759 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:3351 (sofia/internal/ 1010@192.168.0.100) Callstate Change EARLY -> ACTIVE 2012-09-27 09:47:19.453469 [NOTICE] mod_conference.c:7211 Channel [sofia/internal/1010@192.168.0.100] has been answered 2012-09-27 09:47:19.453469 [INFO] mod_conference.c:8315 using channel sound prefix: /home/sunzhi/sunzhi/freeswitch/freeswitch-1.2.3/rel/sounds/en/us/callie 2012-09-27 09:47:19.453469 [DEBUG] mod_conference.c:1922 Setup timer success interval: 20 samples: 160 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1072 sofia/internal/ 1010@192.168.0.100 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 27 Sep 2012 09:47:19 +0800] to event 2012-09-27 09:47:19.453469 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:47:19.453469 [NOTICE] switch_channel.c:951 New Channel sofia/internal/1002@192.168.0.100 [46000434-0845-11e2-b598-8d63071eb0f5] 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:4879 (sofia/internal/ 1002@192.168.0.100) State Change CS_NEW -> CS_INIT 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:4954 [zrtp_passthru] Setting a-leg inherit_codec=true 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:4957 [zrtp_passthru] Setting b-leg absolute_codec_string='GSM@8000h@20i@13200b,PCMU@8000h@20i@64000b ,PCMA@8000h@20i@64000b' 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1010@192.168.0.100 entering state [completed][200] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1002@192.168.0.100) Running State Change CS_INIT 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/1002@192.168.0.100) State INIT 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:86 sofia/internal/ 1002@192.168.0.100 SOFIA INIT 2012-09-27 09:47:19.453469 [DEBUG] sofia_glue.c:2637 Local SDP: v=0 o=FreeSWITCH 1348687005 1348687006 IN IP4 192.168.0.100 s=FreeSWITCH c=IN IP4 192.168.0.100 t=0 0 m=audio 23434 RTP/AVP 3 0 8 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:126 (sofia/internal/ 1002@192.168.0.100) State Change CS_INIT -> CS_ROUTING 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/1002@192.168.0.100) State INIT going to sleep 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1002@192.168.0.100) Running State Change CS_ROUTING 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1964 (sofia/internal/ 1002@192.168.0.100) Callstate Change DOWN -> RINGING 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/1002@192.168.0.100) State ROUTING 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:149 sofia/internal/ 1002@192.168.0.100 SOFIA ROUTING 2012-09-27 09:47:19.453469 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1002@192.168.0.100) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/1002@192.168.0.100) State ROUTING going to sleep 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1002@192.168.0.100) Running State Change CS_CONSUME_MEDIA 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/1002@192.168.0.100) State CONSUME_MEDIA 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:465 (sofia/internal/1002@192.168.0.100) State CONSUME_MEDIA going to sleep 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1002@192.168.0.100 entering state [calling][0] 2012-09-27 09:47:19.453469 [NOTICE] switch_channel.c:951 New Channel sofia/internal/0000000000@192.168.0.100[46006712-0845-11e2-b59c-8d63071eb0f5] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/0000000000@192.168.0.100) Running State Change CS_NEW 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/0000000000@192.168.0.100) State NEW 2012-09-27 09:47:19.473478 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] sofia.c:8412 IP 192.168.0.100 Rejected by acl "domains". Falling back to Digest auth. 2012-09-27 09:47:19.493470 [DEBUG] sofia.c:6282 Channel sofia/internal/ 0000000000@192.168.0.100 entering state [received][100] 2012-09-27 09:47:19.493470 [DEBUG] sofia.c:6293 Remote SDP: v=0 o=FreeSWITCH 1348687005 1348687006 IN IP4 192.168.0.100 s=FreeSWITCH c=IN IP4 192.168.0.100 t=0 0 m=audio 23434 RTP/AVP 3 0 8 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2012-09-27 09:47:19.493470 [DEBUG] sofia.c:6506 (sofia/internal/ 0000000000@192.168.0.100) State Change CS_NEW -> CS_INIT 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/0000000000@192.168.0.100) Running State Change CS_INIT 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/0000000000@192.168.0.100) State INIT 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:86 sofia/internal/ 0000000000@192.168.0.100 SOFIA INIT 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:126 (sofia/internal/ 0000000000@192.168.0.100) State Change CS_INIT -> CS_ROUTING 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/0000000000@192.168.0.100) State INIT going to sleep 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/0000000000@192.168.0.100) Running State Change CS_ROUTING 2012-09-27 09:47:19.493470 [DEBUG] switch_channel.c:1964 (sofia/internal/ 0000000000@192.168.0.100) Callstate Change DOWN -> RINGING 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/0000000000@192.168.0.100) State ROUTING 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:149 sofia/internal/ 0000000000@192.168.0.100 SOFIA ROUTING 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:117 sofia/internal/0000000000@192.168.0.100 Standard ROUTING 2012-09-27 09:47:19.493470 [INFO] mod_dialplan_xml.c:485 Processing FreeSWITCH <0000000000>->1002 in context public Dialplan: sofia/internal/0000000000@192.168.0.100 parsing [public->unloop] continue=false Dialplan: sofia/internal/0000000000@192.168.0.100 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/0000000000@192.168.0.100 Regex (PASS) [unloop] ${sip_looped_call}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/0000000000@192.168.0.100 Action deflect(${destination_number}) 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/0000000000@192.168.0.100) State Change CS_ROUTING -> CS_EXECUTE 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/0000000000@192.168.0.100) State ROUTING going to sleep 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/0000000000@192.168.0.100) Running State Change CS_EXECUTE 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/0000000000@192.168.0.100) State EXECUTE 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:242 sofia/internal/ 0000000000@192.168.0.100 SOFIA EXECUTE 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:209 sofia/internal/0000000000@192.168.0.100 Standard EXECUTE EXECUTE sofia/internal/0000000000@192.168.0.100 deflect(1002) 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] sofia.c:7308 Process REFER to [ 1002@192.168.0.100] 2012-09-27 09:47:19.493470 [DEBUG] switch_ivr.c:1742 (sofia/internal/ 1010@192.168.0.100) State Change CS_EXECUTE -> CS_ROUTING 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:759 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [NOTICE] switch_ivr.c:1748 Transfer sofia/internal/1010@192.168.0.100 to XML[1002@default] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_channel.c:2950 (sofia/internal/ 1002@192.168.0.100) Callstate Change RINGING -> HANGUP 2012-09-27 09:47:19.513472 [NOTICE] switch_ivr_originate.c:3326 Hangup sofia/internal/1002@192.168.0.100 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL] 2012-09-27 09:47:19.513472 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/1002@192.168.0.100 [KILL] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1002@192.168.0.100) Running State Change CS_HANGUP 2012-09-27 09:47:19.513472 [DEBUG] switch_ivr_originate.c:3502 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2012-09-27 09:47:19.513472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: ORIGINATOR_CANCEL 2012-09-27 09:47:19.513472 [DEBUG] switch_channel.c:2950 (sofia/internal/ 1010@192.168.0.100) Callstate Change ACTIVE -> HANGUP 2012-09-27 09:47:19.513472 [NOTICE] mod_conference.c:6617 Hangup sofia/internal/1010@192.168.0.100 [CS_ROUTING] [ORIGINATOR_CANCEL] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/1002@192.168.0.100) State HANGUP 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:483 Channel sofia/internal/ 1002@192.168.0.100 hanging up, cause: ORIGINATOR_CANCEL 2012-09-27 09:47:19.513472 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/1010@192.168.0.100 [KILL] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:2553 sofia/internal/1010@192.168.0.100 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/1010@192.168.0.100) State EXECUTE going to sleep 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_HANGUP 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:542 Sending CANCEL to sofia/internal/1002@192.168.0.100 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1002@192.168.0.100 Standard HANGUP, cause: ORIGINATOR_CANCEL 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/1002@192.168.0.100) State HANGUP going to sleep 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/1002@192.168.0.100) State Change CS_HANGUP -> CS_REPORTING 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1002@192.168.0.100) Running State Change CS_REPORTING 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/1002@192.168.0.100) State REPORTING 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:92 sofia/internal/1002@192.168.0.100 Standard REPORTING, cause: ORIGINATOR_CANCEL 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/1002@192.168.0.100) State REPORTING going to sleep 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/1002@192.168.0.100) State Change CS_REPORTING -> CS_DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1002@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/1010@192.168.0.100) State HANGUP 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1415 Session 5 (sofia/internal/1002@192.168.0.100) Locked, Waiting on external entities 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:483 Channel sofia/internal/ 1010@192.168.0.100 hanging up, cause: ORIGINATOR_CANCEL 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:532 Sending BYE to sofia/internal/1010@192.168.0.100 2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1433 Session 5 (sofia/internal/1002@192.168.0.100) Ended 2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/1002@192.168.0.100 [CS_DESTROY] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1010@192.168.0.100 Standard HANGUP, cause: ORIGINATOR_CANCEL 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/1010@192.168.0.100) State HANGUP going to sleep 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/1010@192.168.0.100) State Change CS_HANGUP -> CS_REPORTING 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_REPORTING 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/1010@192.168.0.100) State REPORTING 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/1002@192.168.0.100) Callstate Change HANGUP -> DOWN 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:92 sofia/internal/1010@192.168.0.100 Standard REPORTING, cause: ORIGINATOR_CANCEL 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/1010@192.168.0.100) State REPORTING going to sleep 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1002@192.168.0.100) Running State Change CS_DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/1002@192.168.0.100) State DESTROY 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:376 sofia/internal/ 1002@192.168.0.100 SOFIA DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:99 sofia/internal/1002@192.168.0.100 Standard DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/1002@192.168.0.100) State DESTROY going to sleep 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/1010@192.168.0.100) State Change CS_REPORTING -> CS_DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1415 Session 4 (sofia/internal/1010@192.168.0.100) Locked, Waiting on external entities 2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1433 Session 4 (sofia/internal/1010@192.168.0.100) Ended 2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/1010@192.168.0.100 [CS_DESTROY] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/1010@192.168.0.100) Callstate Change HANGUP -> DOWN 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1010@192.168.0.100) Running State Change CS_DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/1010@192.168.0.100) State DESTROY 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:376 sofia/internal/ 1010@192.168.0.100 SOFIA DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:99 sofia/internal/1010@192.168.0.100 Standard DESTROY 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/1010@192.168.0.100) State DESTROY going to sleep 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.533467 [DEBUG] mod_conference.c:2461 Write Lock ON 2012-09-27 09:47:19.533467 [DEBUG] mod_conference.c:2464 Write Lock OFF 2012-09-27 09:47:19.593467 [DEBUG] switch_channel.c:2950 (sofia/internal/ 0000000000@192.168.0.100) Callstate Change RINGING -> HANGUP 2012-09-27 09:47:19.593467 [NOTICE] sofia.c:420 Hangup sofia/internal/ 0000000000@192.168.0.100 [CS_EXECUTE] [BLIND_TRANSFER] 2012-09-27 09:47:19.593467 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/0000000000@192.168.0.100 [KILL] 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:2553 sofia/internal/0000000000@192.168.0.100 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/0000000000@192.168.0.100) State EXECUTE going to sleep 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/0000000000@192.168.0.100) Running State Change CS_HANGUP 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/0000000000@192.168.0.100) State HANGUP 2012-09-27 09:47:19.593467 [DEBUG] mod_sofia.c:483 Channel sofia/internal/ 0000000000@192.168.0.100 hanging up, cause: BLIND_TRANSFER 2012-09-27 09:47:19.593467 [DEBUG] mod_sofia.c:613 Responding to INVITE with: 480 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:48 sofia/internal/0000000000@192.168.0.100 Standard HANGUP, cause: BLIND_TRANSFER 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/0000000000@192.168.0.100) State HANGUP going to sleep 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/0000000000@192.168.0.100) State Change CS_HANGUP -> CS_REPORTING 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/0000000000@192.168.0.100) Running State Change CS_REPORTING 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/0000000000@192.168.0.100) State REPORTING 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:92 sofia/internal/0000000000@192.168.0.100 Standard REPORTING, cause: BLIND_TRANSFER 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/0000000000@192.168.0.100) State REPORTING going to sleep 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/0000000000@192.168.0.100) State Change CS_REPORTING -> CS_DESTROY 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1415 Session 6 (sofia/internal/0000000000@192.168.0.100) Locked, Waiting on external entities 2012-09-27 09:47:19.593467 [NOTICE] switch_core_session.c:1433 Session 6 (sofia/internal/0000000000@192.168.0.100) Ended 2012-09-27 09:47:19.593467 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/0000000000@192.168.0.100 [CS_DESTROY] 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/0000000000@192.168.0.100) Callstate Change HANGUP -> DOWN 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/0000000000@192.168.0.100) Running State Change CS_DESTROY 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/0000000000@192.168.0.100) State DESTROY 2012-09-27 09:47:19.593467 [DEBUG] mod_sofia.c:376 sofia/internal/ 0000000000@192.168.0.100 SOFIA DESTROY 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:99 sofia/internal/0000000000@192.168.0.100 Standard DESTROY 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/0000000000@192.168.0.100) State DESTROY going to sleep ============================================================================ 2012/9/27 zhi sun <sunzhimailbox@gmail.com>

thanks for response, the detailed debug log as below:

version 2.1.3

there are two sip client: 1002, 1010

i can call 1002 from 1010 successfully.

then i try to call 0911 from 1010, as you know the 1002 is a member of sales group, the 0911 will try to out call 1002 according the rule in default.xml

============================================= 2012-09-27 09:34:07.533467 [NOTICE] switch_channel.c:951 New Channel sofia/internal/1010@192.168.0.100 [6dfa8876-0843-11e2-b574-8d63071eb0f5] 2012-09-27 09:34:07.533467 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.533467 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_NEW 2012-09-27 09:34:07.533467 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1010@192.168.0.100) State NEW 2012-09-27 09:34:07.533467 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.553467 [DEBUG] sofia.c:8412 IP 192.168.0.10 Rejected by acl "domains". Falling back to Digest auth. 2012-09-27 09:34:07.553467 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.553467 [DEBUG] sofia.c:1728 detaching session 6dfa8876-0843-11e2-b574-8d63071eb0f5 2012-09-27 09:34:07.573471 [DEBUG] sofia.c:1820 Re-attaching to session 6dfa8876-0843-11e2-b574-8d63071eb0f5 2012-09-27 09:34:07.573471 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.573471 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.573471 [DEBUG] sofia.c:8412 IP 192.168.0.10 Rejected by acl "domains". Falling back to Digest auth. 2012-09-27 09:34:07.573471 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1010@192.168.0.100 entering state [received][100] 2012-09-27 09:34:07.573471 [DEBUG] sofia.c:6293 Remote SDP: v=0 o=1010 3118 3118 IN IP4 192.168.0.10 s=Talk c=IN IP4 192.168.0.10 t=0 0 m=audio 7078 RTP/AVP 112 111 110 3 0 8 101 a=rtpmap:112 speex/32000 a=fmtp:112 vbr=on a=rtpmap:111 speex/16000 a=fmtp:111 vbr=on a=rtpmap:110 speex/8000 a=fmtp:110 vbr=on a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11

2012-09-27 09:34:07.573471 [DEBUG] sofia.c:6506 (sofia/internal/ 1010@192.168.0.100) State Change CS_NEW -> CS_INIT 2012-09-27 09:34:07.573471 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_INIT 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/1010@192.168.0.100) State INIT 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:86 sofia/internal/ 1010@192.168.0.100 SOFIA INIT 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:126 (sofia/internal/ 1010@192.168.0.100) State Change CS_INIT -> CS_ROUTING 2012-09-27 09:34:07.573471 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:437 (sofia/internal/1010@192.168.0.100) State INIT going to sleep 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_ROUTING 2012-09-27 09:34:07.573471 [DEBUG] switch_channel.c:1964 (sofia/internal/ 1010@192.168.0.100) Callstate Change DOWN -> RINGING 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/1010@192.168.0.100) State ROUTING 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:149 sofia/internal/ 1010@192.168.0.100 SOFIA ROUTING 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:117 sofia/internal/1010@192.168.0.100 Standard ROUTING 2012-09-27 09:34:07.573471 [INFO] mod_dialplan_xml.c:485 Processing 1010 <1010>->0911 in context default Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->unloop] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1010@192.168.0.100 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1010@192.168.0.100 Action set(open=true) Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1010@192.168.0.100 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [global-intercept] destination_number(0911) =~ /^886$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group-intercept] destination_number(0911) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [intercept-ext] destination_number(0911) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->redial] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [redial] destination_number(0911) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->global] continue=true Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/1010@192.168.0.100 Absolute Condition [global] Dialplan: sofia/internal/1010@192.168.0.100 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1010@192.168.0.100 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})

Dialplan: sofia/internal/1010@192.168.0.100 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1010@192.168.0.100 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [snom-demo-2] destination_number(0911) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [snom-demo-1] destination_number(0911) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [eavesdrop] destination_number(0911) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [eavesdrop] destination_number(0911) =~ /^779$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->call_return] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [call_return] destination_number(0911) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->del-group] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [del-group] destination_number(0911) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->add-group] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [add-group] destination_number(0911) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [call-group-simo] destination_number(0911) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [call-group-order] destination_number(0911) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [extension-intercom] destination_number(0911) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [Local_Extension] destination_number(0911) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [Local_Extension_Skinny] destination_number(0911) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group_dial_sales] destination_number(0911) =~ /^2000$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group_dial_support] destination_number(0911) =~ /^2001$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [group_dial_billing] destination_number(0911) =~ /^2002$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->operator] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [operator] destination_number(0911) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->vmain] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [vmain] destination_number(0911) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [sip_uri] destination_number(0911) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [nb_conferences] destination_number(0911) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [wb_conferences] destination_number(0911) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [uwb_conferences] destination_number(0911) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [cdquality_conferences] destination_number(0911) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(0911) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/1010@192.168.0.100 Regex (PASS) [mad_boss_intercom] destination_number(0911) =~ /^0911$/ break=on-false Dialplan: sofia/internal/1010@192.168.0.100 Action set(conference_auto_outcall_caller_id_name=Mad Boss1) Dialplan: sofia/internal/1010@192.168.0.100 Action set(conference_auto_outcall_caller_id_number=0911) Dialplan: sofia/internal/1010@192.168.0.100 Action set(conference_auto_outcall_timeout=60) Dialplan: sofia/internal/1010@192.168.0.100 Action set(conference_auto_outcall_flags=mute) Dialplan: sofia/internal/1010@192.168.0.100 Action set(conference_auto_outcall_prefix={sip_auto_answer=true,execute_on_answer='bind_meta_app 2 a s1 transfer::intercept:${uuid} inline'}) Dialplan: sofia/internal/1010@192.168.0.100 Action set(sip_exclude_contact=${network_addr}) Dialplan: sofia/internal/1010@192.168.0.100 Action conference_set_auto_outcall(${group_call(sales)}) Dialplan: sofia/internal/1010@192.168.0.100 Action conference(madboss_intercom1@default+flags{endconf|deaf}) 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1010@192.168.0.100) State Change CS_ROUTING -> CS_EXECUTE 2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:446 (sofia/internal/1010@192.168.0.100) State ROUTING going to sleep 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_EXECUTE 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/1010@192.168.0.100) State EXECUTE 2012-09-27 09:34:07.593468 [DEBUG] mod_sofia.c:242 sofia/internal/ 1010@192.168.0.100 SOFIA EXECUTE 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1010@192.168.0.100 Standard EXECUTE EXECUTE sofia/internal/1010@192.168.0.100 set(open=true) 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [open]=[true] EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-spymap/1010/6dfa8876-0843-11e2-b574-8d63071eb0f5) EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-last_dial/1010/0911) EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-last_dial/global/6dfa8876-0843-11e2-b574-8d63071eb0f5) EXECUTE sofia/internal/1010@192.168.0.100 export(RFC2822_DATE=Thu, 27 Sep 2012 09:34:07 +0800) 2012-09-27 09:34:07.593468 [DEBUG] switch_channel.c:1118 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 27 Sep 2012 09:34:07 +0800] EXECUTE sofia/internal/1010@192.168.0.100set(conference_auto_outcall_caller_id_name=Mad Boss1) 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [conference_auto_outcall_caller_id_name]=[Mad Boss1] EXECUTE sofia/internal/1010@192.168.0.100set(conference_auto_outcall_caller_id_number=0911) 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [conference_auto_outcall_caller_id_number]=[0911] EXECUTE sofia/internal/1010@192.168.0.100set(conference_auto_outcall_timeout=60) 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [conference_auto_outcall_timeout]=[60] EXECUTE sofia/internal/1010@192.168.0.100set(conference_auto_outcall_flags=mute) 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [conference_auto_outcall_flags]=[mute] EXECUTE sofia/internal/1010@192.168.0.100set(conference_auto_outcall_prefix={sip_auto_answer=true,execute_on_answer='bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline'}) 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [conference_auto_outcall_prefix]=[{sip_auto_answer=true,execute_on_answer='bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline'}] EXECUTE sofia/internal/1010@192.168.0.100set(sip_exclude_contact=192.168.0.10) 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/ 1010@192.168.0.100 SET [sip_exclude_contact]=[192.168.0.10] 2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:2390 Application conference_set_auto_outcall Requires media! pre_answering channel sofia/internal/1010@192.168.0.100 2012-09-27 09:34:07.593468 [INFO] switch_core_session.c:2392 Sending early media 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[G722:9:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[PCMU:0:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[PCMA:8:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:112:32000:20:0]/[GSM:3:8000:20:13200] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[G722:9:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[PCMU:0:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[PCMA:8:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:111:16000:20:0]/[GSM:3:8000:20:13200] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[G722:9:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[PCMU:0:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[PCMA:8:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [speex:110:8000:20:0]/[GSM:3:8000:20:13200] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[G722:9:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[PCMU:0:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[PCMA:8:8000:20:64000] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5094 Audio Codec Compare [GSM:3:8000:20:13200]/[GSM:3:8000:20:13200] 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:3077 Set Codec sofia/internal/1010@192.168.0.100 GSM/8000 20 ms 160 samples 13200 bits 2012-09-27 09:34:07.593468 [DEBUG] switch_core_codec.c:111 sofia/internal/ 1010@192.168.0.100 Original read codec set to GSM:3 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:5219 Set 2833 dtmf send/recv payload to 101 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:3327 AUDIO RTP [sofia/internal/1010@192.168.0.100] 192.168.0.100 port 19426 -> 192.168.0.10 port 7078 codec: 3 ms: 20 2012-09-27 09:34:07.593468 [DEBUG] switch_rtp.c:1927 Starting timer [soft] 160 bytes per 20ms 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:3591 Set 2833 dtmf send payload to 101 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:3597 Set 2833 dtmf receive payload to 101 2012-09-27 09:34:07.593468 [DEBUG] sofia_glue.c:3624 sofia/internal/ 1010@192.168.0.100 Set rtp dtmf delay to 40 2012-09-27 09:34:07.593468 [NOTICE] sofia_glue.c:4226 Pre-Answer sofia/internal/1010@192.168.0.100! 2012-09-27 09:34:07.593468 [DEBUG] switch_channel.c:3092 (sofia/internal/ 1010@192.168.0.100) Callstate Change RINGING -> EARLY 2012-09-27 09:34:07.593468 [DEBUG] mod_sofia.c:2730 Ring SDP: v=0 o=FreeSWITCH 1348690221 1348690222 IN IP4 192.168.0.100 s=FreeSWITCH c=IN IP4 192.168.0.100 t=0 0 m=audio 19426 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv

2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:759 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] EXECUTE sofia/internal/1010@192.168.0.100conference_set_auto_outcall([sip_invite_domain=192.168.0.100,presence_id= 1000@192.168.0.100]sofia/internal/sip:1000@192.168.0.20:5060 ,[sip_invite_domain=192.168.0.100,presence_id=1001@192.168.0.100 ]error/user_not_registered,[sip_invite_domain=192.168.0.100,presence_id= 1002@192.168.0.100 ]error/user_not_registered,[sip_invite_domain=192.168.0.100,presence_id= 1003@192.168.0.100 ]error/user_not_registered,[sip_invite_domain=192.168.0.100,presence_id= 1004@192.168.0.100]error/user_not_registered) 2012-09-27 09:34:07.593468 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1010@192.168.0.100 entering state [early][183] EXECUTE sofia/internal/1010@192.168.0.100conference(madboss_intercom1@default +flags{endconf|deaf}) 2012-09-27 09:34:07.593468 [DEBUG] mod_sofia.c:836 Local SDP sofia/internal/1010@192.168.0.100: v=0 o=FreeSWITCH 1348690221 1348690223 IN IP4 192.168.0.100 s=FreeSWITCH c=IN IP4 192.168.0.100 t=0 0 m=audio 19426 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv

2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:759 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.593468 [DEBUG] switch_channel.c:3351 (sofia/internal/ 1010@192.168.0.100) Callstate Change EARLY -> ACTIVE 2012-09-27 09:34:07.593468 [NOTICE] mod_conference.c:7211 Channel [sofia/internal/1010@192.168.0.100] has been answered 2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.593468 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1010@192.168.0.100 entering state [completed][200] 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8315 using channel sound prefix: /home/sunzhi/sunzhi/freeswitch/freeswitch-1.2.3/rel/sounds/en/us/callie 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:7092 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:7137 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:1922 Setup timer success interval: 20 samples: 160 2012-09-27 09:34:07.593468 [DEBUG] switch_core_codec.c:219 sofia/internal/ 1010@192.168.0.100 Push codec L16:70 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '0' to 'mute' 2012-09-27 09:34:07.593468 [INFO] switch_ivr_async.c:194 Digit parser mod_conference: Setting realm to 'conf' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bab8 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '*' to 'deaf mute' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding */conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bae8 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '9' to 'energy up' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bb18 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '8' to 'energy equ' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bb48 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '7' to 'energy dn' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bb78 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '3' to 'vol talk up' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bba8 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '2' to 'vol talk zero' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bbd8 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '1' to 'vol talk dn' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bc08 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '6' to 'vol listen up' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bc38 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '5' to 'vol listen zero' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bc68 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '4' to 'vol listen dn' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bc98 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/ 1010@192.168.0.100 binding '#' to 'hangup' 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_async.c:288 Digit parser mod_conference: binding #/conf/0 callback: 0x7f7bcbde4640 data: 0x7f7b8002bcc8 2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:759 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:3474 Setup timer soft success interval: 20 samples: 160 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2425 Parsing session specific variables 2012-09-27 09:34:07.593468 [ERR] switch_ivr_originate.c:2440 Parse Error! 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1000@192.168.0.100]sofia 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2425 Parsing session specific variables 2012-09-27 09:34:07.593468 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [presence_id=1000@192.168.0.100]sofia] cause: [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 66 [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [ERR] switch_ivr_originate.c:2440 Parse Error! 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER 2012-09-27 09:34:07.593468 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1001@192.168.0.100]error 2012-09-27 09:34:07.593468 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [presence_id=1001@192.168.0.100]error] cause: [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 66 [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2425 Parsing session specific variables 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [ERR] switch_ivr_originate.c:2440 Parse Error! 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER 2012-09-27 09:34:07.593468 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1002@192.168.0.100]error 2012-09-27 09:34:07.593468 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [presence_id=1002@192.168.0.100]error] cause: [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2425 Parsing session specific variables 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 66 [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:6815 Launching BG Thread for outcall 2012-09-27 09:34:07.593468 [ERR] switch_ivr_originate.c:2440 Parse Error! 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2005 Parsing global variables 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER 2012-09-27 09:34:07.593468 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1003@192.168.0.100]error 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [presence_id=1003@192.168.0.100]error] cause: [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [sip_auto_answer]=[true] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] switch_event.c:1569 Parsing variable [execute_on_answer]=[bind_meta_app 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 66 [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:2425 Parsing session specific variables 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED 2012-09-27 09:34:07.593468 [ERR] switch_ivr_originate.c:2440 Parse Error! 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] 2012-09-27 09:34:07.593468 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1004@192.168.0.100]error 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER 2012-09-27 09:34:07.593468 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [presence_id=1004@192.168.0.100]error] cause: [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [DEBUG] switch_ivr_originate.c:3508 Originate Resulted in Error Cause: 66 [CHAN_NOT_IMPLEMENTED] 2012-09-27 09:34:07.593468 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED 2012-09-27 09:34:07.613471 [DEBUG] mod_local_stream.c:417 Opening Stream [moh/8000] 8000hz 2012-09-27 09:34:07.613471 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.613471 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.613471 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:07.633467 [DEBUG] sofia.c:6282 Channel sofia/internal/ 1010@192.168.0.100 entering state [ready][200] 2012-09-27 09:34:07.693467 [DEBUG] switch_rtp.c:3596 Correct ip/port confirmed. 2012-09-27 09:34:07.713468 [DEBUG] mod_conference.c:4288 Queueing file 'tone_stream://%(500,0,640)' for play 2012-09-27 09:34:10.733467 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:10.753468 [DEBUG] switch_channel.c:2950 (sofia/internal/ 1010@192.168.0.100) Callstate Change ACTIVE -> HANGUP 2012-09-27 09:34:10.753468 [NOTICE] sofia.c:711 Hangup sofia/internal/ 1010@192.168.0.100 [CS_EXECUTE] [NORMAL_CLEARING] 2012-09-27 09:34:10.753468 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/1010@192.168.0.100 [KILL] 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:10.753468 [DEBUG] mod_conference.c:3777 Channel leaving conference, cause: NORMAL_CLEARING 2012-09-27 09:34:10.753468 [DEBUG] mod_conference.c:7645 sofia/internal/ 1010@192.168.0.100 skip receive message [UNBRIDGE] (channel is hungup already) 2012-09-27 09:34:10.753468 [DEBUG] switch_core_codec.c:244 sofia/internal/ 1010@192.168.0.100 Restore previous codec GSM:3. 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:2553 sofia/internal/1010@192.168.0.100 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:453 (sofia/internal/1010@192.168.0.100) State EXECUTE going to sleep 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_HANGUP 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/1010@192.168.0.100) State HANGUP 2012-09-27 09:34:10.753468 [DEBUG] mod_sofia.c:483 Channel sofia/internal/ 1010@192.168.0.100 hanging up, cause: NORMAL_CLEARING 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1010@192.168.0.100 Standard HANGUP, cause: NORMAL_CLEARING 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/1010@192.168.0.100) State HANGUP going to sleep 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:429 (sofia/internal/1010@192.168.0.100) State Change CS_HANGUP -> CS_REPORTING 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_REPORTING 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/1010@192.168.0.100) State REPORTING 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:92 sofia/internal/1010@192.168.0.100 Standard REPORTING, cause: NORMAL_CLEARING 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:703 (sofia/internal/1010@192.168.0.100) State REPORTING going to sleep 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:423 (sofia/internal/1010@192.168.0.100) State Change CS_REPORTING -> CS_DESTROY 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1415 Session 3 (sofia/internal/1010@192.168.0.100) Locked, Waiting on external entities 2012-09-27 09:34:10.753468 [NOTICE] switch_core_session.c:1433 Session 3 (sofia/internal/1010@192.168.0.100) Ended 2012-09-27 09:34:10.753468 [NOTICE] switch_core_session.c:1437 Close Channel sofia/internal/1010@192.168.0.100 [CS_DESTROY] 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:527 (sofia/internal/1010@192.168.0.100) Callstate Change HANGUP -> DOWN 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:530 (sofia/internal/1010@192.168.0.100) Running State Change CS_DESTROY 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/1010@192.168.0.100) State DESTROY 2012-09-27 09:34:10.753468 [DEBUG] mod_sofia.c:376 sofia/internal/ 1010@192.168.0.100 SOFIA DESTROY 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:99 sofia/internal/1010@192.168.0.100 Standard DESTROY 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:540 (sofia/internal/1010@192.168.0.100) State DESTROY going to sleep 2012-09-27 09:34:10.773471 [NOTICE] mod_conference.c:2369 Ending pending outcall channels for Conference: 'madboss_intercom1' 2012-09-27 09:34:10.773471 [DEBUG] mod_conference.c:2461 Write Lock ON 2012-09-27 09:34:10.773471 [DEBUG] mod_conference.c:2464 Write Lock OFF

======================================================================

2012/9/27 Anthony Minessale <anthony.minessale@gmail.com>

...

That is not nearly enough log file, you need to supply the entire log of the call in full debug mode

On Wed, Sep 26, 2012 at 8:13 AM, zhi sun <sunzhimailbox@gmail.com> wrote:

...

in the default diaplan, the 0911 conference call that make a out call to a group doesn't work for the latest and version 2.1.3. the out call always failed because of CHAN_NOT_IMPLEMENTED,

but it works fine for version 1.06

the same problem happens with the 5001 in dialplan (default.xml)

it is very easy to reproduce this issue: i just get the correct version, make, make install, make cd-sounds-install.

the log with problem looks like below:

===========================================

2012-09-26 15:37:10.973469 [NOTICE] switch_ivr.c:1748 Transfer sofia/internal/1000@192.168.0.100 to XML[1010@default] 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/0000000000@192.168.0.100 [BREAK] 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-26 15:37:10.993469 [DEBUG] switch_channel.c:2950 (sofia/internal/ 1010@192.168.0.100) Callstate Change RINGING -> HANGUP 2012-09-26 15:37:10.993469 [NOTICE] switch_ivr_originate.c:3330 Hangup sofia/internal/1010@192.168.0.100 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL] 2012-09-26 15:37:10.993469 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/1010@192.168.0.100 [KILL] 2012-09-26 15:37:10.993469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1010@192.168.0.100 [BREAK] 2012-09-26 15:37:10.993469 [DEBUG] switch_ivr_originate.c:3506 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2012-09-26 15:37:10.993469 [DEBUG] switch_core_state_machine.c:398 (sofia/internal/1010@192.168.0.100) Running State Change CS_HANGUP 2012-09-26 15:37:10.993469 [ERR] mod_conference.c:6626 Cannot create outgoing channel, cause: ORIGINATOR_CANCEL 2012-09-26 15:37:10.993469 [DEBUG] switch_channel.c:2950 (sofia/internal/ 1000@192.168.0.100) Callstate Change ACTIVE -> HANGUP 2012-09-26 15:37:10.993469 [NOTICE] mod_conference.c:6629 Hangup sofia/internal/1000@192.168.0.100 [CS_ROUTING] [ORIGINATOR_CANCEL] 2012-09-26 15:37:10.993469 [DEBUG] switch_channel.c:2973 Send signal sofia/internal/1000@192.168.0.100 [KILL] 2012-09-26 15:37:10.993469 [DEBUG] switch_core_state_machine.c:638 (sofia/internal/1010@192.168.0.100) State HANGUP 2012-09-26 15:37:10.993469 [DEBUG] switch_core_session.c:1210 Send signal sofia/internal/1000@192.168.0.100 [BREAK]

============================================

i am new to freeswitch, Is there anything i missed to let the version 2.1.3 as well as the latest (from git) work for the 0911 and 5001 dialplan? both of them make an out call from a conference.

thanks -zhisun

_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com

Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com

FreeSWITCH-dev mailing list FreeSWITCH-dev@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev http://www.freeswitch.org

-- Anthony Minessale II

FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire

AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch

FreeSWITCH Developer Conference sip:888@conference.freeswitch.org googletalk:conf+888@conference.freeswitch.org pstn:+19193869900

_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com

Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com

FreeSWITCH-dev mailing list FreeSWITCH-dev@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev http://www.freeswitch.org