[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
zhi sun
sunzhimailbox at gmail.com
Thu Sep 27 05:52:11 MSD 2012
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 at 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 at 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 at mydev.mydomain.com> 2012-09-27 09:47:19.413468 [NOTICE]
switch_channel.c:951 New Channel
sofia/internal/1010 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.413468 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/1010 at 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 at 192.168.0.100) State NEW
2012-09-27 09:47:19.413468 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/1010 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/1010 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/1010 at 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 at 192.168.0.100) State INIT
2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:86 sofia/internal/
1010 at 192.168.0.100 SOFIA INIT
2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:126 (sofia/internal/
1010 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/1010 at 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 at 192.168.0.100) Running State Change CS_ROUTING
2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1964 (sofia/internal/
1010 at 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 at 192.168.0.100) State ROUTING
2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:149 sofia/internal/
1010 at 192.168.0.100 SOFIA ROUTING
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:117
sofia/internal/1010 at 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 at 192.168.0.100 parsing [default->unloop]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->tod_example]
continue=true
Dialplan: sofia/internal/1010 at 192.168.0.100 Date/Time Match (PASS)
[tod_example] break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 Action set(open=true)
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->holiday_example] continue=true
Dialplan: sofia/internal/1010 at 192.168.0.100 Date/TimeMatch (FAIL)
[holiday_example] break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [global-intercept]
destination_number(5002) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [group-intercept]
destination_number(5002) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->intercept-ext] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [intercept-ext]
destination_number(5002) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->redial]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [redial]
destination_number(5002) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->global]
continue=true
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [global]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1010 at 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 at 192.168.0.100 Absolute Condition [global]
Dialplan: sofia/internal/1010 at 192.168.0.100 Action
hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1010 at 192.168.0.100 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1010 at 192.168.0.100 Action
hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1010 at 192.168.0.100 Action
export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->snom-demo-2]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [snom-demo-2]
destination_number(5002) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->snom-demo-1]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [snom-demo-1]
destination_number(5002) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [eavesdrop]
destination_number(5002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->eavesdrop]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [eavesdrop]
destination_number(5002) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->call_return]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [call_return]
destination_number(5002) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->del-group]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [del-group]
destination_number(5002) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->add-group]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [add-group]
destination_number(5002) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->call-group-simo] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [call-group-simo]
destination_number(5002) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->call-group-order] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [call-group-order]
destination_number(5002) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->extension-intercom] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[extension-intercom] destination_number(5002) =~ /^8(10[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [Local_Extension]
destination_number(5002) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->Local_Extension_Skinny] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[Local_Extension_Skinny] destination_number(5002) =~ /^(11[01][0-9])$/
break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->group_dial_sales] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [group_dial_sales]
destination_number(5002) =~ /^2000$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->group_dial_support] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[group_dial_support] destination_number(5002) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->group_dial_billing] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[group_dial_billing] destination_number(5002) =~ /^2002$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->operator]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [operator]
destination_number(5002) =~ /^(operator|0)$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->vmain]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [vmain]
destination_number(5002) =~ /^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->sip_uri]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [sip_uri]
destination_number(5002) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->nb_conferences] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [nb_conferences]
destination_number(5002) =~ /^(30\d{2})$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->wb_conferences] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [wb_conferences]
destination_number(5002) =~ /^(31\d{2})$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->uwb_conferences] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [uwb_conferences]
destination_number(5002) =~ /^(32\d{2})$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->cdquality_conferences] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[cdquality_conferences] destination_number(5002) =~ /^(33\d{2})$/
break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/internal/1010 at 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 at 192.168.0.100 parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[mad_boss_intercom] destination_number(5002) =~ /^0911$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->mad_boss_intercom] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[mad_boss_intercom] destination_number(5002) =~ /^0912$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->mad_boss]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [mad_boss]
destination_number(5002) =~ /^0913$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->ivr_demo]
continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [ivr_demo]
destination_number(5002) =~ /^5000$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->dynamic_conference] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
[dynamic_conference] destination_number(5002) =~ /^5001$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
[default->dynamic_conference] continue=false
Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (PASS)
[dynamic_conference] destination_number(5002) =~ /^5002$/ break=on-false
Dialplan: sofia/internal/1010 at 192.168.0.100 Action
conference(bridge:mydynaconf:sofia/${use_profile}/1002 at 192.168.0.100)
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:167
(sofia/internal/1010 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/1010 at 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 at 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 at 192.168.0.100) State EXECUTE
2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:242 sofia/internal/
1010 at 192.168.0.100 SOFIA EXECUTE
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:209
sofia/internal/1010 at 192.168.0.100 Standard EXECUTE
EXECUTE sofia/internal/1010 at 192.168.0.100 set(open=true)
2012-09-27 09:47:19.453469 [DEBUG] mod_dptools.c:1319 sofia/internal/
1010 at 192.168.0.100 SET [open]=[true]
EXECUTE sofia/internal/1010 at 192.168.0.100hash(insert/192.168.0.100-spymap/1010/45f8ccbe-0845-11e2-b58c-8d63071eb0f5)
EXECUTE sofia/internal/1010 at 192.168.0.100hash(insert/192.168.0.100-last_dial/1010/5002)
EXECUTE sofia/internal/1010 at 192.168.0.100hash(insert/192.168.0.100-last_dial/global/45f8ccbe-0845-11e2-b58c-8d63071eb0f5)
EXECUTE sofia/internal/1010 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.100!
2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:3092 (sofia/internal/
1010 at 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 at 192.168.0.100 [BREAK]
EXECUTE sofia/internal/1010 at 192.168.0.100conference(bridge:mydynaconf:sofia/internal/
1002 at 192.168.0.100)
2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/1010 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel sofia/internal/
1010 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:3351 (sofia/internal/
1010 at 192.168.0.100) Callstate Change EARLY -> ACTIVE
2012-09-27 09:47:19.453469 [NOTICE] mod_conference.c:7211 Channel
[sofia/internal/1010 at 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 at 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 at 192.168.0.100 [46000434-0845-11e2-b598-8d63071eb0f5]
2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:4879 (sofia/internal/
1002 at 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 at 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 at 8000h@20i at 13200b,PCMU at 8000h@20i at 64000b
,PCMA at 8000h@20i at 64000b'
2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/1010 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel sofia/internal/
1010 at 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 at 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 at 192.168.0.100) State INIT
2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:86 sofia/internal/
1002 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/1002 at 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 at 192.168.0.100) Running State Change CS_ROUTING
2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1964 (sofia/internal/
1002 at 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 at 192.168.0.100) State ROUTING
2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:149 sofia/internal/
1002 at 192.168.0.100 SOFIA ROUTING
2012-09-27 09:47:19.453469 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/1002 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/1002 at 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 at 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 at 192.168.0.100) State CONSUME_MEDIA
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:465
(sofia/internal/1002 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel sofia/internal/
1002 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/0000000000 at 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 at 192.168.0.100) State NEW
2012-09-27 09:47:19.473478 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/0000000000 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/0000000000 at 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 at 192.168.0.100) State INIT
2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:86 sofia/internal/
0000000000 at 192.168.0.100 SOFIA INIT
2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:126 (sofia/internal/
0000000000 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:437
(sofia/internal/0000000000 at 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 at 192.168.0.100) Running State Change CS_ROUTING
2012-09-27 09:47:19.493470 [DEBUG] switch_channel.c:1964 (sofia/internal/
0000000000 at 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 at 192.168.0.100) State ROUTING
2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:149 sofia/internal/
0000000000 at 192.168.0.100 SOFIA ROUTING
2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:117
sofia/internal/0000000000 at 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 at 192.168.0.100 parsing [public->unloop]
continue=false
Dialplan: sofia/internal/0000000000 at 192.168.0.100 Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/0000000000 at 192.168.0.100 Regex (PASS) [unloop]
${sip_looped_call}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/0000000000 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:446
(sofia/internal/0000000000 at 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 at 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 at 192.168.0.100) State EXECUTE
2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:242 sofia/internal/
0000000000 at 192.168.0.100 SOFIA EXECUTE
2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:209
sofia/internal/0000000000 at 192.168.0.100 Standard EXECUTE
EXECUTE sofia/internal/0000000000 at 192.168.0.100 deflect(1002)
2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/0000000000 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/1002 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] sofia.c:7308 Process REFER to [
1002 at 192.168.0.100]
2012-09-27 09:47:19.493470 [DEBUG] switch_ivr.c:1742 (sofia/internal/
1010 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:759 Send signal
sofia/internal/1010 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [NOTICE] switch_ivr.c:1748 Transfer
sofia/internal/1010 at 192.168.0.100 to XML[1002 at default]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/0000000000 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/0000000000 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/1002 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_channel.c:2950 (sofia/internal/
1002 at 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 at 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 at 192.168.0.100 [KILL]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/1002 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/1002 at 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 at 192.168.0.100) Callstate Change ACTIVE -> HANGUP
2012-09-27 09:47:19.513472 [NOTICE] mod_conference.c:6617 Hangup
sofia/internal/1010 at 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 at 192.168.0.100) State HANGUP
2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:483 Channel sofia/internal/
1002 at 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 at 192.168.0.100 [KILL]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/1010 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:2553
sofia/internal/1010 at 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 at 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 at 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 at 192.168.0.100
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:48
sofia/internal/1002 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/1002 at 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 at 192.168.0.100) State REPORTING
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:92
sofia/internal/1002 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:638
(sofia/internal/1010 at 192.168.0.100) State HANGUP
2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1415 Session 5
(sofia/internal/1002 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:532 Sending BYE to
sofia/internal/1010 at 192.168.0.100
2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1433 Session 5
(sofia/internal/1002 at 192.168.0.100) Ended
2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1437 Close
Channel sofia/internal/1002 at 192.168.0.100 [CS_DESTROY]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:48
sofia/internal/1010 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/1010 at 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 at 192.168.0.100) State REPORTING
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:527
(sofia/internal/1002 at 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 at 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 at 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 at 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 at 192.168.0.100) State DESTROY
2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:376 sofia/internal/
1002 at 192.168.0.100 SOFIA DESTROY
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:99
sofia/internal/1002 at 192.168.0.100 Standard DESTROY
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/1002 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1415 Session 4
(sofia/internal/1010 at 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 at 192.168.0.100) Ended
2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1437 Close
Channel sofia/internal/1010 at 192.168.0.100 [CS_DESTROY]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:527
(sofia/internal/1010 at 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 at 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 at 192.168.0.100) State DESTROY
2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:376 sofia/internal/
1010 at 192.168.0.100 SOFIA DESTROY
2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:905 Send signal
sofia/internal/0000000000 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:99
sofia/internal/1010 at 192.168.0.100 Standard DESTROY
2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/1010 at 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 at 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 at 192.168.0.100) Callstate Change RINGING -> HANGUP
2012-09-27 09:47:19.593467 [NOTICE] sofia.c:420 Hangup sofia/internal/
0000000000 at 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 at 192.168.0.100 [KILL]
2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1210 Send signal
sofia/internal/0000000000 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:2553
sofia/internal/0000000000 at 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 at 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 at 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 at 192.168.0.100) State HANGUP
2012-09-27 09:47:19.593467 [DEBUG] mod_sofia.c:483 Channel sofia/internal/
0000000000 at 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 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:398
(sofia/internal/0000000000 at 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 at 192.168.0.100) State REPORTING
2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:92
sofia/internal/0000000000 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1415 Session 6
(sofia/internal/0000000000 at 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 at 192.168.0.100) Ended
2012-09-27 09:47:19.593467 [NOTICE] switch_core_session.c:1437 Close
Channel sofia/internal/0000000000 at 192.168.0.100 [CS_DESTROY]
2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:527
(sofia/internal/0000000000 at 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 at 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 at 192.168.0.100) State DESTROY
2012-09-27 09:47:19.593467 [DEBUG] mod_sofia.c:376 sofia/internal/
0000000000 at 192.168.0.100 SOFIA DESTROY
2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:99
sofia/internal/0000000000 at 192.168.0.100 Standard DESTROY
2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:540
(sofia/internal/0000000000 at 192.168.0.100) State DESTROY going to sleep
============================================================================
2012/9/27 zhi sun <sunzhimailbox at 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 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.533467 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/1010 at 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 at 192.168.0.100) State NEW
> 2012-09-27 09:34:07.533467 [DEBUG] switch_core_session.c:905 Send signal
> sofia/internal/1010 at 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 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_session.c:905 Send signal
> sofia/internal/1010 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/1010 at 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 at 192.168.0.100) State INIT
> 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:86 sofia/internal/
> 1010 at 192.168.0.100 SOFIA INIT
> 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:126 (sofia/internal/
> 1010 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:437
> (sofia/internal/1010 at 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 at 192.168.0.100) Running State Change CS_ROUTING
> 2012-09-27 09:34:07.573471 [DEBUG] switch_channel.c:1964 (sofia/internal/
> 1010 at 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 at 192.168.0.100) State ROUTING
> 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:149 sofia/internal/
> 1010 at 192.168.0.100 SOFIA ROUTING
> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:117
> sofia/internal/1010 at 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 at 192.168.0.100 parsing [default->unloop]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->tod_example] continue=true
> Dialplan: sofia/internal/1010 at 192.168.0.100 Date/Time Match (PASS)
> [tod_example] break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action set(open=true)
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->holiday_example] continue=true
> Dialplan: sofia/internal/1010 at 192.168.0.100 Date/TimeMatch (FAIL)
> [holiday_example] break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->global-intercept] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [global-intercept] destination_number(0911) =~ /^886$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->group-intercept] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [group-intercept] destination_number(0911) =~ /^\*8$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->intercept-ext] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [intercept-ext]
> destination_number(0911) =~ /^\*\*(\d+)$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->redial]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [redial]
> destination_number(0911) =~ /^(redial|870)$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->global]
> continue=true
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [global]
> ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/internal/1010 at 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 at 192.168.0.100 Absolute Condition [global]
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
>
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> hash(insert/${domain_name}-last_dial/global/${uuid})
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->snom-demo-2] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [snom-demo-2]
> destination_number(0911) =~ /^9001$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->snom-demo-1] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [snom-demo-1]
> destination_number(0911) =~ /^9000$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->eavesdrop]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [eavesdrop]
> destination_number(0911) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->eavesdrop]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [eavesdrop]
> destination_number(0911) =~ /^779$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->call_return] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [call_return]
> destination_number(0911) =~ /^\*69$|^869$|^lcr$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->del-group]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [del-group]
> destination_number(0911) =~ /^80(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->add-group]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [add-group]
> destination_number(0911) =~ /^81(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->call-group-simo] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [call-group-simo] destination_number(0911) =~ /^82(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->call-group-order] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [call-group-order] destination_number(0911) =~ /^83(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->extension-intercom] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [extension-intercom] destination_number(0911) =~ /^8(10[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->Local_Extension] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [Local_Extension] destination_number(0911) =~ /^(10[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->Local_Extension_Skinny] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [Local_Extension_Skinny] destination_number(0911) =~ /^(11[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->group_dial_sales] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [group_dial_sales] destination_number(0911) =~ /^2000$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->group_dial_support] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [group_dial_support] destination_number(0911) =~ /^2001$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->group_dial_billing] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [group_dial_billing] destination_number(0911) =~ /^2002$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->operator]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [operator]
> destination_number(0911) =~ /^(operator|0)$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->vmain]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [vmain]
> destination_number(0911) =~ /^vmain$|^4000$|^\*98$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing [default->sip_uri]
> continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [sip_uri]
> destination_number(0911) =~ /^sip:(.*)$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->nb_conferences] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [nb_conferences]
> destination_number(0911) =~ /^(30\d{2})$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->wb_conferences] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL) [wb_conferences]
> destination_number(0911) =~ /^(31\d{2})$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->uwb_conferences] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [uwb_conferences] destination_number(0911) =~ /^(32\d{2})$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->cdquality_conferences] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (FAIL)
> [cdquality_conferences] destination_number(0911) =~ /^(33\d{2})$/
> break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 parsing
> [default->freeswitch_public_conf_via_sip] continue=false
> Dialplan: sofia/internal/1010 at 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 at 192.168.0.100 parsing
> [default->mad_boss_intercom] continue=false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Regex (PASS)
> [mad_boss_intercom] destination_number(0911) =~ /^0911$/ break=on-false
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> set(conference_auto_outcall_caller_id_name=Mad Boss1)
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> set(conference_auto_outcall_caller_id_number=0911)
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> set(conference_auto_outcall_timeout=60)
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> set(conference_auto_outcall_flags=mute)
> Dialplan: sofia/internal/1010 at 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 at 192.168.0.100 Action
> set(sip_exclude_contact=${network_addr})
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> conference_set_auto_outcall(${group_call(sales)})
> Dialplan: sofia/internal/1010 at 192.168.0.100 Action
> conference(madboss_intercom1 at default+flags{endconf|deaf})
> 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:167
> (sofia/internal/1010 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:446
> (sofia/internal/1010 at 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 at 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 at 192.168.0.100) State EXECUTE
> 2012-09-27 09:34:07.593468 [DEBUG] mod_sofia.c:242 sofia/internal/
> 1010 at 192.168.0.100 SOFIA EXECUTE
> 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:209
> sofia/internal/1010 at 192.168.0.100 Standard EXECUTE
> EXECUTE sofia/internal/1010 at 192.168.0.100 set(open=true)
> 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/
> 1010 at 192.168.0.100 SET [open]=[true]
> EXECUTE sofia/internal/1010 at 192.168.0.100hash(insert/192.168.0.100-spymap/1010/6dfa8876-0843-11e2-b574-8d63071eb0f5)
> EXECUTE sofia/internal/1010 at 192.168.0.100hash(insert/192.168.0.100-last_dial/1010/0911)
> EXECUTE sofia/internal/1010 at 192.168.0.100hash(insert/192.168.0.100-last_dial/global/6dfa8876-0843-11e2-b574-8d63071eb0f5)
> EXECUTE sofia/internal/1010 at 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 at 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 at 192.168.0.100 SET [conference_auto_outcall_caller_id_name]=[Mad
> Boss1]
> EXECUTE sofia/internal/1010 at 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 at 192.168.0.100 SET [conference_auto_outcall_caller_id_number]=[0911]
> EXECUTE sofia/internal/1010 at 192.168.0.100set(conference_auto_outcall_timeout=60)
> 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/
> 1010 at 192.168.0.100 SET [conference_auto_outcall_timeout]=[60]
> EXECUTE sofia/internal/1010 at 192.168.0.100set(conference_auto_outcall_flags=mute)
> 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 sofia/internal/
> 1010 at 192.168.0.100 SET [conference_auto_outcall_flags]=[mute]
> EXECUTE sofia/internal/1010 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.100!
> 2012-09-27 09:34:07.593468 [DEBUG] switch_channel.c:3092 (sofia/internal/
> 1010 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:905 Send signal
> sofia/internal/1010 at 192.168.0.100 [BREAK]
> EXECUTE sofia/internal/1010 at 192.168.0.100conference_set_auto_outcall([sip_invite_domain=192.168.0.100,presence_id=
> 1000 at 192.168.0.100]sofia/internal/sip:1000 at 192.168.0.20:5060
> ,[sip_invite_domain=192.168.0.100,presence_id=1001 at 192.168.0.100
> ]error/user_not_registered,[sip_invite_domain=192.168.0.100,presence_id=
> 1002 at 192.168.0.100
> ]error/user_not_registered,[sip_invite_domain=192.168.0.100,presence_id=
> 1003 at 192.168.0.100
> ]error/user_not_registered,[sip_invite_domain=192.168.0.100,presence_id=
> 1004 at 192.168.0.100]error/user_not_registered)
> 2012-09-27 09:34:07.593468 [DEBUG] sofia.c:6282 Channel sofia/internal/
> 1010 at 192.168.0.100 entering state [early][183]
> EXECUTE sofia/internal/1010 at 192.168.0.100conference(madboss_intercom1 at default
> +flags{endconf|deaf})
> 2012-09-27 09:34:07.593468 [DEBUG] mod_sofia.c:836 Local SDP
> sofia/internal/1010 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.593468 [DEBUG] switch_channel.c:3351 (sofia/internal/
> 1010 at 192.168.0.100) Callstate Change EARLY -> ACTIVE
> 2012-09-27 09:34:07.593468 [NOTICE] mod_conference.c:7211 Channel
> [sofia/internal/1010 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.593468 [DEBUG] sofia.c:6282 Channel sofia/internal/
> 1010 at 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 at 8000hz 1 channel 20ms
> 2012-09-27 09:34:07.593468 [DEBUG] mod_conference.c:7137 Raw Codec
> Activation Success L16 at 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 at 192.168.0.100 Push codec L16:70
> 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 sofia/internal/
> 1010 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.613471 [DEBUG] switch_core_session.c:905 Send signal
> sofia/internal/1010 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.613471 [DEBUG] switch_core_session.c:905 Send signal
> sofia/internal/1010 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:07.633467 [DEBUG] sofia.c:6282 Channel sofia/internal/
> 1010 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:10.753468 [DEBUG] switch_channel.c:2950 (sofia/internal/
> 1010 at 192.168.0.100) Callstate Change ACTIVE -> HANGUP
> 2012-09-27 09:34:10.753468 [NOTICE] sofia.c:711 Hangup sofia/internal/
> 1010 at 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 at 192.168.0.100 [KILL]
> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1210 Send signal
> sofia/internal/1010 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.100) State HANGUP
> 2012-09-27 09:34:10.753468 [DEBUG] mod_sofia.c:483 Channel sofia/internal/
> 1010 at 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 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:398
> (sofia/internal/1010 at 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 at 192.168.0.100) State REPORTING
> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:92
> sofia/internal/1010 at 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 at 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 at 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 at 192.168.0.100 [BREAK]
> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1415 Session 3
> (sofia/internal/1010 at 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 at 192.168.0.100) Ended
> 2012-09-27 09:34:10.753468 [NOTICE] switch_core_session.c:1437 Close
> Channel sofia/internal/1010 at 192.168.0.100 [CS_DESTROY]
> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:527
> (sofia/internal/1010 at 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 at 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 at 192.168.0.100) State DESTROY
> 2012-09-27 09:34:10.753468 [DEBUG] mod_sofia.c:376 sofia/internal/
> 1010 at 192.168.0.100 SOFIA DESTROY
> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:99
> sofia/internal/1010 at 192.168.0.100 Standard DESTROY
> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:540
> (sofia/internal/1010 at 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 at 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 at 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 at 192.168.0.100 to XML[1010 at default]
>>> 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal
>>> sofia/internal/0000000000 at 192.168.0.100 [BREAK]
>>> 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal
>>> sofia/internal/0000000000 at 192.168.0.100 [BREAK]
>>> 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal
>>> sofia/internal/1010 at 192.168.0.100 [BREAK]
>>> 2012-09-26 15:37:10.993469 [DEBUG] switch_channel.c:2950 (sofia/internal/
>>> 1010 at 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 at 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 at 192.168.0.100 [KILL]
>>> 2012-09-26 15:37:10.993469 [DEBUG] switch_core_session.c:1210 Send
>>> signal sofia/internal/1010 at 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 at 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 at 192.168.0.100) Callstate Change ACTIVE -> HANGUP
>>> 2012-09-26 15:37:10.993469 [NOTICE] mod_conference.c:6629 Hangup
>>> sofia/internal/1000 at 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 at 192.168.0.100 [KILL]
>>> 2012-09-26 15:37:10.993469 [DEBUG] switch_core_state_machine.c:638
>>> (sofia/internal/1010 at 192.168.0.100) State HANGUP
>>> 2012-09-26 15:37:10.993469 [DEBUG] switch_core_session.c:1210 Send
>>> signal sofia/internal/1000 at 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 at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>>
>>>
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://wiki.freeswitch.org
>>> http://www.cluecon.com
>>>
>>> FreeSWITCH-dev mailing list
>>> FreeSWITCH-dev at 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 at hotmail.com
>> GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
>> IRC: irc.freenode.net #freeswitch
>>
>> FreeSWITCH Developer Conference
>> sip:888 at conference.freeswitch.org
>> googletalk:conf+888 at conference.freeswitch.org
>> pstn:+19193869900
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>>
>>
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://wiki.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-dev mailing list
>> FreeSWITCH-dev at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
>> http://www.freeswitch.org
>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-dev/attachments/20120927/9c498cc9/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-dev
mailing list