September 2012 - FreeSWITCH-users - FreeSWITCH Mailing Lists

FSClient
by Ms Farzaneh Maleki 30 Sep '12

30 Sep '12

I am a beginner in freeswitch. I installed an image from 2600hz.com that included CentOS, freeswitch and bluebox. I installed FSClient on 2 clients I connect to freeswitch by using bluebox (ServerIp/bluebox) and set to device in it and assign numbers to them. After adding account in FSClient, when I dial the number of other client in fsclient, It does not work. I also active the SIP protocol in CentOS firewall What should I do? Regards, Farzaneh

2 1

TEST
by Brian West 29 Sep '12

29 Sep '12

TEST -- Brian West brian(a)freeswitch.org FreeSWITCH Solutions, LLC PO BOX PO BOX 2531 Brookfield, WI 53008-2531 Twitter: @FreeSWITCH_Wire T: +1.918.420.9266 | F: +1.918.420.9267 | M: +1.918.424.WEST iNUM: +883 5100 1420 9266 UK: +44 20 3298 4900 ISN: 410*543

3 2

Just a community Reminder...
by Ken Rice 28 Sep '12

28 Sep '12

Hey Guys, Don¹t forget to join us today on the FreeSWITCH conference bridge starting at 4PM Eastern for the Friday Free For All... Presenter: NO ONE Topic: Whatever Reason: Because We Can Pop on the bridge, come and go as you please and hang out with other FreeSWITCH users and some of the developers too... Access the bridge just like the Weekly Wed Conf call. -- Ken http://www.FreeSWITCH.org http://www.ClueCon.com http://www.OSTAG.org irc.freenode.net #freeswitch

1 0

Empty wiki and my head
by Valery Kalinin 28 Sep '12

28 Sep '12

I cannot find any documentation for these modules: mod_abstraction mod_sonar mod_html5 mod_xml_scgi What they do and how to use them?

4 4

Hacking FS issue
by Todd Bailey 28 Sep '12

28 Sep '12

Hey All, I just got an email from Frontier that there were several attempts to make international calls. I checked the log file and verified that somehow someone was able to get access to FS from the internet. here is a sample of the log [m[36m2012-09-23 16:30:29.916821 [NOTICE] switch_channel.c:941 New Channel sofia/internal/1000(a)50.47.85.167 [af778857-0188-4ed2-a82a-94ae749a02cb] [m[32m2012-09-23 16:30:29.916821 [INFO] mod_dialplan_xml.c:485 Processing 1000 <1000>->01137168521352 in context default [m[36m2012-09-23 16:30:29.936831 [NOTICE] switch_channel.c:941 New Channel sofia/internal/01137168521352@192.168.1.5:5061 [d1243a78-c464-45fa-9215-e7b85e1221fc] [m[36m2012-09-23 16:30:29.956842 [NOTICE] sofia.c:6132 Ring-Ready sofia/internal/01137168521352@192.168.1.5:5061! [m[36m2012-09-23 16:30:29.956842 [NOTICE] mod_sofia.c:2572 Ring-Ready sofia/internal/1000(a)50.47.85.167! [m[36m2012-09-23 16:30:29.956842 [NOTICE] switch_ivr_originate.c:519 Ring Ready sofia/internal/1000(a)50.47.85.167! [m[36m2012-09-23 16:30:32.936826 [NOTICE] sofia.c:6777 Channel [sofia/internal/01137168521352@192.168.1.5:5061] has been answered [m[36m2012-09-23 16:30:32.956825 [NOTICE] sofia_glue.c:4176 Pre-Answer sofia/internal/1000(a)50.47.85.167! [m[36m2012-09-23 16:30:32.956825 [NOTICE] switch_ivr_originate.c:3303 Channel [sofia/internal/1000(a)50.47.85.167] has been answered [m[36m2012-09-23 16:30:52.356865 [N[m[36m2012-09-23 16:30:29.916821 [NOTICE] switch_channel.c:941 New Channel sofia/internal/1000(a)50.47.85.167 [af778857-0188-4ed2-a82a-94ae749a02cb] [m[32m2012-09-23 16:30:29.916821 [INFO] mod_dialplan_xml.c:485 Processing 1000 <1000>->01137168521352 in context default [m[36m2012-09-23 16:30:29.936831 [NOTICE] switch_channel.c:941 New Channel sofia/internal/01137168521352@192.168.1.5:5061 [d1243a78-c464-45fa-9215-e7b85e1221fc] [m[36m2012-09-23 16:30:29.956842 [NOTICE] sofia.c:6132 Ring-Ready sofia/internal/01137168521352@192.168.1.5:5061! [m[36m2012-09-23 16:30:29.956842 [NOTICE] mod_sofia.c:2572 Ring-Ready sofia/internal/1000(a)50.47.85.167! [m[36m2012-09-23 16:30:29.956842 [NOTICE] switch_ivr_originate.c:519 Ring Ready sofia/internal/1000(a)50.47.85.167! [m[36m2012-09-23 16:30:32.936826 [NOTICE] sofia.c:6777 Channel [sofia/internal/01137168521352@192.168.1.5:5061] has been answered [m[36m2012-09-23 16:30:32.956825 [NOTICE] sofia_glue.c:4176 Pre-Answer sofia/internal/1000(a)50.47.85.167! [m[36m2012-09-23 16:30:32.956825 [NOTICE] switch_ivr_originate.c:3303 Channel [sofia/internal/1000(a)50.47.85.167] has been answered [m[36m2012-09-23 16:30:52.356865 [NOTICE] switch_channel.c:941 New Channel sofia/internal/1000(a)50.47.85.167 [4576bc76-144a-4f6f-8915-871b511c374d] [m[32m2012-09-23 16:30:52.376830 [INFO] mod_dialplan_xml.c:485 Processing 1000 <1000>->01137168905352 in context defaultOTICE] switch_channel.c:941 New Channel sofia/internal/1000(a)50.47.85.167 [4576bc76-144a-4f6f-8915-871b511c374d] [m[32m2012-09-23 16:30:52.376830 [INFO] mod_dialplan_xml.c:485 Processing 1000 <1000>->01137168905352 in context default At this point I'm at a loss how this is happening as I have multiple firewalls in place that limit port access. Can someone provide a few pointers on how to better secure FS running on Linux systems? thanks -- - - - Best Regards, - - Todd Bailey - -

11 20

xml_curl
by Miha 28 Sep '12

28 Sep '12

Hi, I am using xml_curl for dialplan. For programing language I am using PHP. How can I access variables like Caller-Destination-Number, Channel-Name, variables with -, because in php I can not use - for variables. I can only access variables which are defined like variable_sip_full_from etc. Thanks for help! Miha

3 3

USER_NOT_REGISTERED when freeswtch is registered at another freeswitch.
by Peter Steinbach 28 Sep '12

28 Sep '12

Hello, I have 2 Freeswitch boxes. Box 2 is registering as number 400 via VPN to box 1 (like a regular phone). I can see in the sip_registrations database that the phone is registered. And Box2 shows " vpn::sip1.mydomain.com gateway sip:400@10.8.0.1:5075 REGED So at the first glance everything seems ok. However in my vpn profile sofia status profile internalvpn the Freeswitch box2 is not shown as a registration entry. I think this is the reason why we receive the following when we try to call the box 2 (number 400): EXECUTE sofia/internal/200(a)sip1.mydomain.com bridge({sip_invite_domain=sip1.mydomain.com}user/400(a)sip1.mydomain.com) 2012-09-27 23:09:58.149196 [DEBUG] switch_channel.c:1062 sofia/internal/200(a)sip1.mydomain.com EXPORTING[export_vars] [dialed_ext]=[400] to event 2012-09-27 23:09:58.149196 [DEBUG] switch_ivr_originate.c:1961 Parsing global variables 2012-09-27 23:09:58.149196 [DEBUG] switch_event.c:1478 Parsing variable [sip_invite_domain]=[sip1.mydomain.com] 2012-09-27 23:09:58.169252 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/200(a)sip1.mydomain.com [BREAK] 2012-09-27 23:09:58.269299 [DEBUG] switch_channel.c:1062 sofia/internal/200(a)sip1.mydomain.com EXPORTING[export_vars] [dialed_ext]=[400] to event 2012-09-27 23:09:58.269299 [DEBUG] switch_ivr_originate.c:1961 Parsing global variables 2012-09-27 23:09:58.269299 [DEBUG] switch_event.c:1478 Parsing variable [presence_id]=[400(a)sip1.mydomain.com] 2012-09-27 23:09:58.269299 [DEBUG] switch_event.c:1478 Parsing variable [transfer_fallback_extension]=[400] 2012-09-27 23:09:58.269299 [DEBUG] sofia.c:6040 Channel sofia/internal/200(a)sip1.mydomain.com entering state [early][180] 2012-09-27 23:09:58.269299 [NOTICE] switch_ivr_originate.c:2544 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] freeswitch@internal> sofia_contact 400 error/user_not_registered freeswitch@internal> sofia_contact 200 sofia/internal/sip:200@192.168.178.105:2048;line=1vz0u23u;fs_nat=yes;fs_path=sip%3A200%40217.24.xx.xxx%3A20393%3Bline%3D1vz0u23u So 200 seems ok, 400 not. When I look at the contact field in the sip_registrations table, I see "user"<sip:gw+sip1.mydomain.com@10.8.0.42:5080;transport=udp;gw=sip1.mydomain.com> so this does not reflect the number 400. Here is my gateway config from box2 which registers at box1 (sip1.mydomain.com) # cat sip1.xml <include> <gateway name="sip1.mydomain.com"> <param name="from-domain" value="sip1.mydomain.com"/> <param name="username" value="400"/> <param name="from-user" value="400"/> <param name="extension" value="400"/> <param name="realm" value="sip1.mydomain.com"/>  <param name="proxy" value="10.8.0.1:5075"/> <param name="password" value="xxxxxxxx"/> <param name="expire-seconds" value="3600"/> <param name="register" value="true"/> <param name="register-transport" value="udp"/> <param name="retry-seconds" value="20"/> <param name="caller-id-in-from" value="true"/> </gateway> </include> My question is: How can I change the gateway definition, so that box2 shows up as a regular registration with number 400? Or am I missing something different? -- With kind regards Peter Steinbach Telefaks Services GmbH mailto:lists (att) telefaks.de Internet: www.telefaks.de

4 6

Saving phone information from a Polycom IP501
by Todd Bailey 27 Sep '12

27 Sep '12

Just wondering if it's possible to download data from a phone and save it into separate files or into a database? I just save a number into the phone and it occurred to me the minute I have to reboot or power cycle the phone, all contact info will be lost. If possible, I'd like to store the contact information and call history into a database for future reference, and perhaps being able to store that information into my email and contact management application (currently Evolution)

3 4

Fwd: [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
by zhi sun 27 Sep '12

27 Sep '12

just forward this email to users group, in case anyone else have encountered the same problem! thanks for your help -zhisun ---------- Forwarded message ---------- From: zhi sun <sunzhimailbox(a)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(a)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(a)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(a)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(a)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(a)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(a)192.168.0.100! >> 2012-09-27 14:58:47.293472 [NOTICE] mod_conference.c:7211 Channel [ >> sofia/internal/1001(a)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(a)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(a)192.168.0.100 binding '*' to 'deaf mute' >> 2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 >> sofia/internal/1001(a)192.168.0.100 binding '9' to 'energy up' >> 2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 >> sofia/internal/1001(a)192.168.0.100 binding '8' to 'energy equ' >> 2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 >> sofia/internal/1001(a)192.168.0.100 binding '7' to 'energy dn' >> 2012-09-27 14:58:47.293472 [INFO] mod_conference.c:8869 >> sofia/internal/1001(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)mydev.mydomain.com> 2012-09-27 09:47:19.413468 [NOTICE] >> switch_channel.c:951 New Channel sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.413468 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State NEW >> 2012-09-27 09:47:19.413468 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State INIT >> 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:86 >> sofia/internal/1010(a)192.168.0.100 SOFIA INIT >> 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:126 ( >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437 ( >> sofia/internal/1010(a)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(a)192.168.0.100) Running State Change CS_ROUTING >> 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1964 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State ROUTING >> 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:149 >> sofia/internal/1010(a)192.168.0.100 SOFIA ROUTING >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:117 >> sofia/internal/1010(a)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(a)192.168.0.100 parsing [default->unloop] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (PASS) [unloop] >> ${unroll_loops}(true) =~ /^true$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [unloop] >> ${sip_looped_call}() =~ /^true$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->tod_example] continue=true >> Dialplan: sofia/internal/1010(a)192.168.0.100 Date/Time Match (PASS) >> [tod_example] break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action set(open=true) >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->holiday_example] continue=true >> Dialplan: sofia/internal/1010(a)192.168.0.100 Date/TimeMatch (FAIL) >> [holiday_example] break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->global-intercept] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [global-intercept] destination_number(5002) =~ /^886$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group-intercept] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group-intercept] destination_number(5002) =~ /^\*8$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->intercept-ext] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [intercept-ext] >> destination_number(5002) =~ /^\*\*(\d+)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->redial] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [redial] >> destination_number(5002) =~ /^(redial|870)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->global] >> continue=true >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [global] >> ${call_debug}(false) =~ /^true$/ break=never >> Dialplan: sofia/internal/1010(a)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(a)192.168.0.100 Absolute Condition [global] >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) >> >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> hash(insert/${domain_name}-last_dial/global/${uuid}) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->snom-demo-2] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [snom-demo-2] >> destination_number(5002) =~ /^9001$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->snom-demo-1] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [snom-demo-1] >> destination_number(5002) =~ /^9000$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->eavesdrop] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [eavesdrop] >> destination_number(5002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->eavesdrop] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [eavesdrop] >> destination_number(5002) =~ /^779$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->call_return] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [call_return] >> destination_number(5002) =~ /^\*69$|^869$|^lcr$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->del-group] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [del-group] >> destination_number(5002) =~ /^80(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->add-group] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [add-group] >> destination_number(5002) =~ /^81(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->call-group-simo] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [call-group-simo] destination_number(5002) =~ /^82(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->call-group-order] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [call-group-order] destination_number(5002) =~ /^83(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->extension-intercom] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [extension-intercom] destination_number(5002) =~ /^8(10[01][0-9])$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->Local_Extension] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [Local_Extension] destination_number(5002) =~ /^(10[01][0-9])$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->Local_Extension_Skinny] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [Local_Extension_Skinny] destination_number(5002) =~ /^(11[01][0-9])$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group_dial_sales] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group_dial_sales] destination_number(5002) =~ /^2000$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group_dial_support] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group_dial_support] destination_number(5002) =~ /^2001$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group_dial_billing] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group_dial_billing] destination_number(5002) =~ /^2002$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->operator] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [operator] >> destination_number(5002) =~ /^(operator|0)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->vmain] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [vmain] >> destination_number(5002) =~ /^vmain$|^4000$|^\*98$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->sip_uri] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [sip_uri] >> destination_number(5002) =~ /^sip:(.*)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->nb_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [nb_conferences] destination_number(5002) =~ /^(30\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->wb_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [wb_conferences] destination_number(5002) =~ /^(31\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->uwb_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [uwb_conferences] destination_number(5002) =~ /^(32\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->cdquality_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [cdquality_conferences] destination_number(5002) =~ /^(33\d{2})$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->freeswitch_public_conf_via_sip] continue=false >> Dialplan: sofia/internal/1010(a)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(a)192.168.0.100 parsing >> [default->mad_boss_intercom] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [mad_boss_intercom] destination_number(5002) =~ /^0911$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->mad_boss_intercom] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [mad_boss_intercom] destination_number(5002) =~ /^0912$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->mad_boss] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [mad_boss] >> destination_number(5002) =~ /^0913$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->ivr_demo] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [ivr_demo] >> destination_number(5002) =~ /^5000$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->dynamic_conference] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [dynamic_conference] destination_number(5002) =~ /^5001$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->dynamic_conference] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (PASS) >> [dynamic_conference] destination_number(5002) =~ /^5002$/ break=on-false >> Dialplan: sofia/internal/1010(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446 ( >> sofia/internal/1010(a)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(a)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(a)192.168.0.100) State EXECUTE >> 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:242 >> sofia/internal/1010(a)192.168.0.100 SOFIA EXECUTE >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:209 >> sofia/internal/1010(a)192.168.0.100 Standard EXECUTE >> EXECUTE sofia/internal/1010(a)192.168.0.100 set(open=true) >> 2012-09-27 09:47:19.453469 [DEBUG] mod_dptools.c:1319 >> sofia/internal/1010(a)192.168.0.100 SET [open]=[true] >> EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-spymap/1010/45f8ccbe-0845-11e2-b58c-8d63071eb0f5) >> EXECUTE sofia/internal/1010(a)192.168.0.100hash(insert/192.168.0.100-last_dial/1010/5002) >> EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-last_dial/global/45f8ccbe-0845-11e2-b58c-8d63071eb0f5) >> EXECUTE sofia/internal/1010(a)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(a)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(a)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(a)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(a)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(a)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(a)192.168.0.100! >> 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:3092 ( >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> EXECUTE sofia/internal/1010(a)192.168.0.100 conference(bridge:mydynaconf: >> sofia/internal/1002(a)192.168.0.100) >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel >> sofia/internal/1010(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:3351 ( >> sofia/internal/1010(a)192.168.0.100) Callstate Change EARLY -> ACTIVE >> 2012-09-27 09:47:19.453469 [NOTICE] mod_conference.c:7211 Channel [ >> sofia/internal/1010(a)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(a)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(a)192.168.0.100 [46000434-0845-11e2-b598-8d63071eb0f5] >> 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:4879 ( >> sofia/internal/1002(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel >> sofia/internal/1010(a)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(a)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(a)192.168.0.100) State INIT >> 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:86 >> sofia/internal/1002(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:437 ( >> sofia/internal/1002(a)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(a)192.168.0.100) Running State Change CS_ROUTING >> 2012-09-27 09:47:19.453469 [DEBUG] switch_channel.c:1964 ( >> sofia/internal/1002(a)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(a)192.168.0.100) State ROUTING >> 2012-09-27 09:47:19.453469 [DEBUG] mod_sofia.c:149 >> sofia/internal/1002(a)192.168.0.100 SOFIA ROUTING >> 2012-09-27 09:47:19.453469 [DEBUG] switch_ivr_originate.c:67 ( >> sofia/internal/1002(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:446 ( >> sofia/internal/1002(a)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(a)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(a)192.168.0.100) State CONSUME_MEDIA >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:465 ( >> sofia/internal/1002(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] sofia.c:6282 Channel >> sofia/internal/1002(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.453469 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/0000000000(a)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(a)192.168.0.100) State NEW >> 2012-09-27 09:47:19.473478 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/0000000000(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/0000000000(a)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(a)192.168.0.100) State INIT >> 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:86 >> sofia/internal/0000000000(a)192.168.0.100 SOFIA INIT >> 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:126 ( >> sofia/internal/0000000000(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:437 ( >> sofia/internal/0000000000(a)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(a)192.168.0.100) Running State Change CS_ROUTING >> 2012-09-27 09:47:19.493470 [DEBUG] switch_channel.c:1964 ( >> sofia/internal/0000000000(a)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(a)192.168.0.100) State ROUTING >> 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:149 >> sofia/internal/0000000000(a)192.168.0.100 SOFIA ROUTING >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:117 >> sofia/internal/0000000000(a)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(a)192.168.0.100 parsing >> [public->unloop] continue=false >> Dialplan: sofia/internal/0000000000(a)192.168.0.100 Regex (PASS) [unloop] >> ${unroll_loops}(true) =~ /^true$/ break=on-false >> Dialplan: sofia/internal/0000000000(a)192.168.0.100 Regex (PASS) [unloop] >> ${sip_looped_call}(true) =~ /^true$/ break=on-false >> Dialplan: sofia/internal/0000000000(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:446 ( >> sofia/internal/0000000000(a)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(a)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(a)192.168.0.100) State EXECUTE >> 2012-09-27 09:47:19.493470 [DEBUG] mod_sofia.c:242 >> sofia/internal/0000000000(a)192.168.0.100 SOFIA EXECUTE >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_state_machine.c:209 >> sofia/internal/0000000000(a)192.168.0.100 Standard EXECUTE >> EXECUTE sofia/internal/0000000000(a)192.168.0.100 deflect(1002) >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/0000000000(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1002(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] sofia.c:7308 Process REFER to [ >> 1002(a)192.168.0.100] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_ivr.c:1742 ( >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:759 Send signal >> sofia/internal/1010(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [NOTICE] switch_ivr.c:1748 Transfer >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/0000000000(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.493470 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1002(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_channel.c:2950 ( >> sofia/internal/1002(a)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(a)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(a)192.168.0.100 [KILL] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal >> sofia/internal/1002(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1002(a)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(a)192.168.0.100) Callstate Change ACTIVE -> HANGUP >> 2012-09-27 09:47:19.513472 [NOTICE] mod_conference.c:6617 Hangup >> sofia/internal/1010(a)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(a)192.168.0.100) State HANGUP >> 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:483 Channel >> sofia/internal/1002(a)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(a)192.168.0.100 [KILL] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1210 Send signal >> sofia/internal/1010(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:2553 >> sofia/internal/1010(a)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(a)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(a)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(a)192.168.0.100 >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:48 >> sofia/internal/1002(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1002(a)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(a)192.168.0.100) State REPORTING >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:92 >> sofia/internal/1002(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:638 ( >> sofia/internal/1010(a)192.168.0.100) State HANGUP >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1415 Session 5 ( >> sofia/internal/1002(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:532 Sending BYE to >> sofia/internal/1010(a)192.168.0.100 >> 2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1433 Session 5 ( >> sofia/internal/1002(a)192.168.0.100) Ended >> 2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1437 Close >> Channel sofia/internal/1002(a)192.168.0.100 [CS_DESTROY] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:48 >> sofia/internal/1010(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State REPORTING >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:527 ( >> sofia/internal/1002(a)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(a)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(a)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(a)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(a)192.168.0.100) State DESTROY >> 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:376 >> sofia/internal/1002(a)192.168.0.100 SOFIA DESTROY >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:99 >> sofia/internal/1002(a)192.168.0.100 Standard DESTROY >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540 ( >> sofia/internal/1002(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:1415 Session 4 ( >> sofia/internal/1010(a)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(a)192.168.0.100) Ended >> 2012-09-27 09:47:19.513472 [NOTICE] switch_core_session.c:1437 Close >> Channel sofia/internal/1010(a)192.168.0.100 [CS_DESTROY] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:527 ( >> sofia/internal/1010(a)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(a)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(a)192.168.0.100) State DESTROY >> 2012-09-27 09:47:19.513472 [DEBUG] mod_sofia.c:376 >> sofia/internal/1010(a)192.168.0.100 SOFIA DESTROY >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/0000000000(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:99 >> sofia/internal/1010(a)192.168.0.100 Standard DESTROY >> 2012-09-27 09:47:19.513472 [DEBUG] switch_core_state_machine.c:540 ( >> sofia/internal/1010(a)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(a)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(a)192.168.0.100) Callstate Change RINGING -> >> HANGUP >> 2012-09-27 09:47:19.593467 [NOTICE] sofia.c:420 Hangup >> sofia/internal/0000000000(a)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(a)192.168.0.100 [KILL] >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1210 Send signal >> sofia/internal/0000000000(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:2553 >> sofia/internal/0000000000(a)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(a)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(a)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(a)192.168.0.100) State HANGUP >> 2012-09-27 09:47:19.593467 [DEBUG] mod_sofia.c:483 Channel >> sofia/internal/0000000000(a)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(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/0000000000(a)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(a)192.168.0.100) State REPORTING >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:92 >> sofia/internal/0000000000(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_session.c:1415 Session 6 ( >> sofia/internal/0000000000(a)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(a)192.168.0.100) Ended >> 2012-09-27 09:47:19.593467 [NOTICE] switch_core_session.c:1437 Close >> Channel sofia/internal/0000000000(a)192.168.0.100 [CS_DESTROY] >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:527 ( >> sofia/internal/0000000000(a)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(a)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(a)192.168.0.100) State DESTROY >> 2012-09-27 09:47:19.593467 [DEBUG] mod_sofia.c:376 >> sofia/internal/0000000000(a)192.168.0.100 SOFIA DESTROY >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:99 >> sofia/internal/0000000000(a)192.168.0.100 Standard DESTROY >> 2012-09-27 09:47:19.593467 [DEBUG] switch_core_state_machine.c:540 ( >> sofia/internal/0000000000(a)192.168.0.100) State DESTROY going to sleep >> >> ============================================================================ >> >> >> >> >> 2012/9/27 zhi sun <sunzhimailbox(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.533467 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State NEW >> 2012-09-27 09:34:07.533467 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State INIT >> 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:86 >> sofia/internal/1010(a)192.168.0.100 SOFIA INIT >> 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:126 ( >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:437 ( >> sofia/internal/1010(a)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(a)192.168.0.100) Running State Change CS_ROUTING >> 2012-09-27 09:34:07.573471 [DEBUG] switch_channel.c:1964 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State ROUTING >> 2012-09-27 09:34:07.573471 [DEBUG] mod_sofia.c:149 >> sofia/internal/1010(a)192.168.0.100 SOFIA ROUTING >> 2012-09-27 09:34:07.573471 [DEBUG] switch_core_state_machine.c:117 >> sofia/internal/1010(a)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(a)192.168.0.100 parsing [default->unloop] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (PASS) [unloop] >> ${unroll_loops}(true) =~ /^true$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [unloop] >> ${sip_looped_call}() =~ /^true$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->tod_example] continue=true >> Dialplan: sofia/internal/1010(a)192.168.0.100 Date/Time Match (PASS) >> [tod_example] break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action set(open=true) >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->holiday_example] continue=true >> Dialplan: sofia/internal/1010(a)192.168.0.100 Date/TimeMatch (FAIL) >> [holiday_example] break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->global-intercept] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [global-intercept] destination_number(0911) =~ /^886$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group-intercept] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group-intercept] destination_number(0911) =~ /^\*8$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->intercept-ext] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [intercept-ext] >> destination_number(0911) =~ /^\*\*(\d+)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->redial] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [redial] >> destination_number(0911) =~ /^(redial|870)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->global] >> continue=true >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [global] >> ${call_debug}(false) =~ /^true$/ break=never >> Dialplan: sofia/internal/1010(a)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(a)192.168.0.100 Absolute Condition [global] >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) >> >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> hash(insert/${domain_name}-last_dial/global/${uuid}) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->snom-demo-2] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [snom-demo-2] >> destination_number(0911) =~ /^9001$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->snom-demo-1] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [snom-demo-1] >> destination_number(0911) =~ /^9000$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->eavesdrop] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [eavesdrop] >> destination_number(0911) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->eavesdrop] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [eavesdrop] >> destination_number(0911) =~ /^779$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->call_return] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [call_return] >> destination_number(0911) =~ /^\*69$|^869$|^lcr$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->del-group] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [del-group] >> destination_number(0911) =~ /^80(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->add-group] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [add-group] >> destination_number(0911) =~ /^81(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->call-group-simo] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [call-group-simo] destination_number(0911) =~ /^82(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->call-group-order] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [call-group-order] destination_number(0911) =~ /^83(\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->extension-intercom] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [extension-intercom] destination_number(0911) =~ /^8(10[01][0-9])$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->Local_Extension] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [Local_Extension] destination_number(0911) =~ /^(10[01][0-9])$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->Local_Extension_Skinny] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [Local_Extension_Skinny] destination_number(0911) =~ /^(11[01][0-9])$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group_dial_sales] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group_dial_sales] destination_number(0911) =~ /^2000$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group_dial_support] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group_dial_support] destination_number(0911) =~ /^2001$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->group_dial_billing] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [group_dial_billing] destination_number(0911) =~ /^2002$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->operator] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [operator] >> destination_number(0911) =~ /^(operator|0)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->vmain] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [vmain] >> destination_number(0911) =~ /^vmain$|^4000$|^\*98$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing [default->sip_uri] >> continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) [sip_uri] >> destination_number(0911) =~ /^sip:(.*)$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->nb_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [nb_conferences] destination_number(0911) =~ /^(30\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->wb_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [wb_conferences] destination_number(0911) =~ /^(31\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->uwb_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [uwb_conferences] destination_number(0911) =~ /^(32\d{2})$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->cdquality_conferences] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (FAIL) >> [cdquality_conferences] destination_number(0911) =~ /^(33\d{2})$/ >> break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 parsing >> [default->freeswitch_public_conf_via_sip] continue=false >> Dialplan: sofia/internal/1010(a)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(a)192.168.0.100 parsing >> [default->mad_boss_intercom] continue=false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Regex (PASS) >> [mad_boss_intercom] destination_number(0911) =~ /^0911$/ break=on-false >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> set(conference_auto_outcall_caller_id_name=Mad Boss1) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> set(conference_auto_outcall_caller_id_number=0911) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> set(conference_auto_outcall_timeout=60) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> set(conference_auto_outcall_flags=mute) >> Dialplan: sofia/internal/1010(a)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(a)192.168.0.100 Action >> set(sip_exclude_contact=${network_addr}) >> Dialplan: sofia/internal/1010(a)192.168.0.100 Action >> conference_set_auto_outcall(${group_call(sales)}) >> Dialplan: sofia/internal/1010(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:446 ( >> sofia/internal/1010(a)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(a)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(a)192.168.0.100) State EXECUTE >> 2012-09-27 09:34:07.593468 [DEBUG] mod_sofia.c:242 >> sofia/internal/1010(a)192.168.0.100 SOFIA EXECUTE >> 2012-09-27 09:34:07.593468 [DEBUG] switch_core_state_machine.c:209 >> sofia/internal/1010(a)192.168.0.100 Standard EXECUTE >> EXECUTE sofia/internal/1010(a)192.168.0.100 set(open=true) >> 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 >> sofia/internal/1010(a)192.168.0.100 SET [open]=[true] >> EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-spymap/1010/6dfa8876-0843-11e2-b574-8d63071eb0f5) >> EXECUTE sofia/internal/1010(a)192.168.0.100hash(insert/192.168.0.100-last_dial/1010/0911) >> EXECUTE sofia/internal/1010@192.168.0.100hash(insert/192.168.0.100-last_dial/global/6dfa8876-0843-11e2-b574-8d63071eb0f5) >> EXECUTE sofia/internal/1010(a)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(a)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(a)192.168.0.100 SET >> [conference_auto_outcall_caller_id_name]=[Mad Boss1] >> EXECUTE sofia/internal/1010(a)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(a)192.168.0.100 SET >> [conference_auto_outcall_caller_id_number]=[0911] >> EXECUTE sofia/internal/1010(a)192.168.0.100set(conference_auto_outcall_timeout=60) >> 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 >> sofia/internal/1010(a)192.168.0.100 SET >> [conference_auto_outcall_timeout]=[60] >> EXECUTE sofia/internal/1010(a)192.168.0.100set(conference_auto_outcall_flags=mute) >> 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 >> sofia/internal/1010(a)192.168.0.100 SET >> [conference_auto_outcall_flags]=[mute] >> EXECUTE sofia/internal/1010@192.168.0.100set(conference_auto_outcall_prefix={sip_auto_answer=true,execute_on_answer='bind_meta_app >> 2 a s1 transfer::intercept:6dfa8876-0843-11e2-b574-8d63071eb0f5 inline'}) >> 2012-09-27 09:34:07.593468 [DEBUG] mod_dptools.c:1319 >> sofia/internal/1010(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)192.168.0.100! >> 2012-09-27 09:34:07.593468 [DEBUG] switch_channel.c:3092 ( >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.593468 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)192.168.0.100 [BREAK] >> EXECUTE sofia/internal/1010@192.168.0.100conference_set_auto_outcall([sip_invite_domain=192.168.0.100, >> presence_id=1000@192.168.0.100]sofia/internal/sip:1000@192.168.0.20:5060< >> http://sip:1000@192.168.0.20:5060> ,[sip_invite_domain=192.168.0.100, >> presence_id=1001(a)192.168.0.100]error/user_not_registered >> ,[sip_invite_domain=192.168.0.100, >> presence_id=1002(a)192.168.0.100]error/user_not_registered >> ,[sip_invite_domain=192.168.0.100, >> presence_id=1003(a)192.168.0.100]error/user_not_registered >> ,[sip_invite_domain=192.168.0.100, >> presence_id=1004(a)192.168.0.100]error/user_not_registered) >> 2012-09-27 09:34:07.593468 [DEBUG] sofia.c:6282 Channel >> sofia/internal/1010(a)192.168.0.100 entering state [early][183] >> EXECUTE sofia/internal/1010@192.168.0.100conference(madboss_intercom1@default >> +flags{endconf|deaf}) >> 2012-09-27 09:34:07.593468 [DEBUG] mod_sofia.c:836 Local SDP >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.593468 [DEBUG] switch_channel.c:3351 ( >> sofia/internal/1010(a)192.168.0.100) Callstate Change EARLY -> ACTIVE >> 2012-09-27 09:34:07.593468 [NOTICE] mod_conference.c:7211 Channel [ >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.593468 [DEBUG] sofia.c:6282 Channel >> sofia/internal/1010(a)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(a)192.168.0.100 Push codec L16:70 >> 2012-09-27 09:34:07.593468 [INFO] mod_conference.c:8869 >> sofia/internal/1010(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.613471 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.613471 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:07.633467 [DEBUG] sofia.c:6282 Channel >> sofia/internal/1010(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:10.753468 [DEBUG] switch_channel.c:2950 ( >> sofia/internal/1010(a)192.168.0.100) Callstate Change ACTIVE -> HANGUP >> 2012-09-27 09:34:10.753468 [NOTICE] sofia.c:711 Hangup >> sofia/internal/1010(a)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(a)192.168.0.100 [KILL] >> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1210 Send signal >> sofia/internal/1010(a)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(a)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(a)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(a)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(a)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(a)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(a)192.168.0.100) State HANGUP >> 2012-09-27 09:34:10.753468 [DEBUG] mod_sofia.c:483 Channel >> sofia/internal/1010(a)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(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:398 ( >> sofia/internal/1010(a)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(a)192.168.0.100) State REPORTING >> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:92 >> sofia/internal/1010(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_session.c:1415 Session 3 ( >> sofia/internal/1010(a)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(a)192.168.0.100) Ended >> 2012-09-27 09:34:10.753468 [NOTICE] switch_core_session.c:1437 Close >> Channel sofia/internal/1010(a)192.168.0.100 [CS_DESTROY] >> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:527 ( >> sofia/internal/1010(a)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(a)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(a)192.168.0.100) State DESTROY >> 2012-09-27 09:34:10.753468 [DEBUG] mod_sofia.c:376 >> sofia/internal/1010(a)192.168.0.100 SOFIA DESTROY >> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:99 >> sofia/internal/1010(a)192.168.0.100 Standard DESTROY >> 2012-09-27 09:34:10.753468 [DEBUG] switch_core_state_machine.c:540 ( >> sofia/internal/1010(a)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(a)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(a)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(a)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(a)192.168.0.100 [BREAK] >> 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/0000000000(a)192.168.0.100 [BREAK] >> 2012-09-26 15:37:10.973469 [DEBUG] switch_core_session.c:905 Send signal >> sofia/internal/1010(a)192.168.0.100 [BREAK] >> 2012-09-26 15:37:10.993469 [DEBUG] switch_channel.c:2950 ( >> sofia/internal/1010(a)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(a)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(a)192.168.0.100 [KILL] >> 2012-09-26 15:37:10.993469 [DEBUG] switch_core_session.c:1210 Send signal >> sofia/internal/1010(a)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(a)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(a)192.168.0.100) Callstate Change ACTIVE -> HANGUP >> 2012-09-26 15:37:10.993469 [NOTICE] mod_conference.c:6629 Hangup >> sofia/internal/1000(a)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(a)192.168.0.100 [KILL] >> 2012-09-26 15:37:10.993469 [DEBUG] switch_core_state_machine.c:638 ( >> sofia/internal/1010(a)192.168.0.100) State HANGUP >> 2012-09-26 15:37:10.993469 [DEBUG] switch_core_session.c:1210 Send signal >> sofia/internal/1000(a)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(a)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(a)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(a)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(a)lists.freeswitch.org >> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev >> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev >> http://www.freeswitch.org >> >> >

2 1

Freeswitch as RTP <=> SRTP translator
by Аnton Тeihrib 27 Sep '12

27 Sep '12

Hi all! In my case all sip clients uses SRTP, but VoIP provider accepts only RTP packets. I'm thinking about using freeswitch between them, like so: client <=SRTP=> freeswitch <=RTP=> VoIP provider. Is it possible? If so please give me some direction how to implement this setup. Thanks a lot in advance.

3 4