---------- Forwarded message ----------
From:
zhi sun <sunzhimailbox@gmail.com>
Date: 2012/9/27
Subject: 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
To:
freeswitch-dev@lists.freeswitch.org
what i am concerning is how to make the version 1.2.3, as well as the latest git version works for 0911 and 5001 in default.xml, although the version 1.0.6 only works partly on this issue.
this problem is very easy to reproduce!!!!
2012/9/27 zhi sun
<sunzhimailbox@gmail.com>
thank ken for your response.
how to update the configs? do you mean the conf folder? i am new to freeswitch.
what i have done is just use the conf created by make install command.
since i set different installation path by using ./configure --prefix=/my/path, either ver 1.2.3 or ver 1.0.6 has different conf folder i think.
at least, i believe that the config with the version 1.2.3 is shipped with ver 1.2.3.
thanks,
-zhisun
2012/9/27 Ken Rice
<krice@freeswitch.org>
Did you update your configs? 1.0.6 is so old and has more issues then I can count... And configs have been update to resolve problems...
On 9/27/12 2:02 AM, "zhi sun" <sunzhimailbox@gmail.com> wrote:
further testing results:
- for version 1.0.6, the 0911 works, but 5001 doesn't.
- for version 1.2.3 and 1.3, both 0911 and 5001 doesn't work.
the following are logs for 0911, version 1.2.3
the 1000,1001,1002,1003 should be called!!!!
==============================================
2012-09-27 14:58:47.233466 [NOTICE] switch_channel.c:951 New Channel sofia/internal/1001@192.168.0.100 [c8c8f364-0870-11e2-bd7f-df6c04573b9b]
2012-09-27 14:58:47.273467 [INFO] mod_dialplan_xml.c:485 Processing 1001 <1001>->0911 in context default
2012-09-27 14:58:47.293472 [INFO] switch_core_session.c:2392 Sending early media
2012-09-27 14:58:47.293472 [NOTICE] sofia_glue.c:4226 Pre-Answer sofia/internal/1001@192.168.0.100!
2012-09-27 14:58:47.293472 [NOTICE] mod_conference.c:7211 Channel [sofia/internal/1001@192.168.0.100] has been answered
2012-09-27 14:58:47.293472 [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 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '0' to 'mute'
2012-09-27 14:58:47.293472 [INFO] switch_ivr_async.c:194 Digit parser mod_conference: Setting realm to 'conf'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '*' to 'deaf mute'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '9' to 'energy up'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '8' to 'energy equ'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '7' to 'energy dn'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '3' to 'vol talk up'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '2' to 'vol talk zero'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '1' to 'vol talk dn'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '6' to 'vol listen up'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '5' to 'vol listen zero'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '4' to 'vol listen dn'
2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 sofia/internal/1001@192.168.0.100 binding '#' to 'hangup'
2012-09-27 14:58:47.293472 [ERR] switch_ivr_originate.c:2440 Parse Error!
2012-09-27 14:58:47.293472 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1001@192.168.0.100]error
2012-09-27 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER
2012-09-27 14:58:47.293472 [ERR] switch_ivr_originate.c:2440 Parse Error!
2012-09-27 14:58:47.293472 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1000@192.168.0.100]sofia
2012-09-27 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER
2012-09-27 14:58:47.293472 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1002@192.168.0.100]sofia
2012-09-27 14:58:47.293472 [NOTICE] switch_ivr_originate.c:2591 Cannot create outgoing channel of type [presence_id=1002@192.168.0.100]sofia] cause: [CHAN_NOT_IMPLEMENTED]
2012-09-27 14:58:47.293472 [ERR] switch_ivr_originate.c:2440 Parse Error!
2012-09-27 14:58:47.293472 [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 14:58:47.293472 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1003@192.168.0.100]error
2012-09-27 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED
2012-09-27 14:58:47.293472 [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 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED
2012-09-27 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER
2012-09-27 14:58:47.293472 [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 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED
2012-09-27 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED
2012-09-27 14:58:47.293472 [ERR] switch_ivr_originate.c:2440 Parse Error!
2012-09-27 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER
2012-09-27 14:58:47.293472 [ERR] switch_core_session.c:408 Could not locate channel type presence_id=1004@192.168.0.100]error
2012-09-27 14:58:47.293472 [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 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: CHAN_NOT_IMPLEMENTED
2012-09-27 14:58:47.293472 [ERR] switch_ivr_originate.c:2440 Parse Error!
2012-09-27 14:58:47.293472 [ERR] mod_conference.c:6614 Cannot create outgoing channel, cause: DESTINATION_OUT_OF_ORDER
========================================================
2012/9/27 zhi sun <sunzhimailbox@gmail.com>
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.100 hash(insert/192.168.0.100-spymap/1010/45f8ccbe-0845-11e2-b58c-8d63071eb0f5)
EXECUTE sofia/internal/1010@192.168.0.100 hash(insert/192.168.0.100-last_dial/1010/5002)
EXECUTE sofia/internal/1010@192.168.0.100 hash(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.100 conference(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.100 hash(insert/192.168.0.100-spymap/1010/6dfa8876-0843-11e2-b574-8d63071eb0f5)
EXECUTE sofia/internal/1010@192.168.0.100 hash(insert/192.168.0.100-last_dial/1010/0911)
EXECUTE sofia/internal/1010@192.168.0.100 hash(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.100 set(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.100 set(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.100 set(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.100 set(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.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'})
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.100 set(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.100 conference_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 <http://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.100 conference(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
--
Ken
http://www.FreeSWITCH.org
http://www.ClueCon.com
http://www.OSTAG.org
irc.freenode.net #freeswitch
_________________________________________________________________________
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