- FreeSWITCH-users - FreeSWITCH Mailing Lists

Segmentation fault while starting freeswitch.
by vinay saini 26 Feb '14

26 Feb '14

Hi, I have installed freeswitch in centos 6.4 from the rpm , and the freeswitch version is freeswitch-1.4.2-0 but i face problem when starting it. It is giving Segmentation fault while staring Starting freeswitch: chown: cannot access `/var/log/freeswitch/*': No such > file or directory > /etc/init.d/functions: line 181: 20622 Segmentation fault (core > dumped) $cgroup $nice runuser -s /bin/bash $user -c "$corelimit >/dev/null > 2>&1 ; $*" > [FAILED] > > can any one help me to resolve this problem. thanks, vinay

2 1

Re: [Freeswitch-users] performance
by Keith 26 Feb '14

26 Feb '14

Hi Brian, Thanks for your reply, not sure I follow what you mean by git bisect?? Sorry I am a bit new to a lot of this? Are you saying to compare the GIT versions? Cheers Keith

2 1

Re: [Freeswitch-users] Performance
by Keith 26 Feb '14

26 Feb '14

Well I did have FS bridging to an asterisk box behind it, but wanted to check it wasn't the FS box which was the problem to did a simple dial plan with some music playing back. The interesting thing is, I used one of the latest GIT versions and managed to get 1000 calls, but I would expect with the hardware i have to get even more. I would rather use a stable version of the software, it's just bizare that newer hardware with much higher spec doesn't perform as well. Thanks, Keith

2 1

Call Hanging up on receiving 302 from SIP endpoint
by Akhil Chandra 25 Feb '14

25 Feb '14

Hello everyone, Looks like I have a strange problem at hand. A SIP user/ extension has forwarded his phone to his mobile number. 1. When another user( ie extension) calls the SIP user, the call is forwarded to forwarded number after getting 302 redirect. 2. However, if I call from PSTN into the SIP user, the call hangs up after getting the 302 message. Not sure whats going on. I have the <param name="manual-redirect" value="true"/> in the SIP profile for the extension. NB: I have 2 profiles, one for extensions and one for SIP trunk. Just wanted to separate the ports. Nothing else. But the SIP profile for trunk does not have the manual-redirect set to true. Regards, Akhil

2 3

Remote XML files
by Richard Mace 25 Feb '14

25 Feb '14

Hi All, I am presuming that the Windows version of FreeSWITCH loads all of it's XML files into memory when it starts up and that if the XML file were actually located on another server on the same LAN that that would be OK and wouldn't hinder normal operation? Richard

2 7

Re: [Freeswitch-users] Performance
by Keith 25 Feb '14

25 Feb '14

Hi, So I installed the latest GIT version of Freeswitch and managed to get a massive increase in simultaneous calls, 200 to 1500. The question is, how can I find out why this is, as I am not 100% happy running with a non production version. Cheers Keith

2 1

Export A leg SIP From header domain to B leg
by Andrés Souto 25 Feb '14

25 Feb '14

Hi, I have a FreeSWITCH working with multiple domains. All the calls reach FS via a Kamailio SIP proxy. Kamailio is responsible for the registrations and for authenticating calls. Also note I'm using a lua script for both dialplan and directory. The problem I having is that FS always changes the From header domain to the FS local IP when doing the bridge. Instead of this, I want it to keep the original domain. I read this can be achieved adding {sip_invite_domain=${sip_from_host}} or {sip_from_uri=${sip_from_uri}} when doing the bridge but it doesn't work for me. When I put the From header domain to any string but the right one, FS sends it without any problem but when I put it to the right one generates this event instead: 'Event-Name: REQUEST_PARAMS Core-UUID: cf6163aa-9d52-11e3-b059-cb6d0ba086d1 FreeSWITCH-Hostname: debian-vpbx1 FreeSWITCH-Switchname: debian-vpbx1 FreeSWITCH-IPv4: 192.168.0.201 FreeSWITCH-IPv6: %3A%3A1 Event-Date-Local: 2014-02-24%2018%3A02%3A03 Event-Date-GMT: Mon,%2024%20Feb%202014%2017%3A02%3A03%20GMT Event-Date-Timestamp: 1393261323308597 Event-Calling-File: sofia_reg.c Event-Calling-Function: sofia_reg_handle_sip_r_challenge Event-Calling-Line-Number: 2214 Event-Sequence: 4813 action: reverse-auth-lookup sip_call_id: 396aa31b-1818-1232-e484-080027254469 key: id user: 1001 domain: vpbx1.ur ' This occurs when extension 1000 is calling extension 1001. I tried with no luck to answer the event but anyway the event doesn't make sense to me... As is said in the wiki, I'm using internal profile with the force-*-domain options commented:    and also: <param name="auth-calls" value="false"/> Thank you! -- *Andrés Souto* VoIP Engineer @ Quobis <http://www.quobis.com/> | e: andres.souto(a)quobis.com | t: +34902999465

1 1

Problem with sending Invite from Freeswitch to the carrier.
by vinay 25 Feb '14

25 Feb '14

hi, I have successfully installed freeswitch and it is working fine while calling from one sip device to other. but I face problem when I make a outbound call using gateway. According to freeswitch log I can see that freeswitch is getting gateway configuration and it is suppose to send INVITE to the gateway,but the problem is that freeswitch is not sending any INVITE to the gateway. these are the fs_cli logs INVITE sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com> SIP/2.0 Record-Route: <sip:88.80.160.31;lr=on;ftag= aW0i4G-.8DI9G4pbsNbl8EWP1fY76mxz> Via: SIP/2.0/UDP 88.80.160.31;branch=z9hG4bKd602.9af44717.0 Via: SIP/2.0/UDP 112.196.33.74:11220;rport=62926;branch=z9hG4bKPj.w0giarvUkQ67HPw3uK5Z6NsdtAUWvEV From: <sip:user1@sip.test.com <mailto:sip%3Auser1@sip.test.com>>;tag=aW0i4G-.8DI9G4pbsNbl8EWP1fY76mxz To: <sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com>> Contact: <sip:user1@112.196.33.74:62926;ob> Call-ID: 0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO CSeq: 26826 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: CSipSimple_A89-15/r2330 Proxy-Authorization: Digest username="user1", realm="sip.test.com <http://sip.test.com>", nonce="2da67792-9ddb-11e3-ae8b-69d00812b6c2", uri="sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com>", response="894cfec80fc7a1c04b2ad7b46eb1c4c5", algorithm=MD5, cnonce="y6HH8DROqT9Ue8iZVcHNFRyB.LGnEDII", qop=auth, nc=00000001 Content-Type: application/sdp Content-Length: 344 X-AUTH-IP: 112.196.33.74 v=0 o=- 3602293864 3602293864 IN IP4 112.196.33.74 s=pjmedia c=IN IP4 112.196.33.74 t=0 0 m=audio 4226 RTP/AVP 99 0 8 101 c=IN IP4 112.196.33.74 a=rtcp:9246 IN IP4 112.196.33.74 a=sendrecv a=rtpmap:99 SILK/24000 a=fmtp:99 useinbandfec=0 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ------------------------------------------------------------------------ send 469 bytes to udp/[88.80.160.31]:5060 at 05:10:44.257584: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 88.80.160.31;branch=z9hG4bKd602.9af44717.0 Via: SIP/2.0/UDP 112.196.33.74:11220;rport=62926;branch=z9hG4bKPj.w0giarvUkQ67HPw3uK5Z6NsdtAUWvEV Record-Route: <sip:88.80.160.31;lr=on;ftag=aW0i4G-.8DI9G4pbsNbl8EWP1fY76mxz> From: <sip:user1@sip.test.com <mailto:sip%3Auser1@sip.test.com>>;tag=aW0i4G-.8DI9G4pbsNbl8EWP1fY76mxz To: <sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com>> Call-ID: 0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO CSeq: 26826 INVITE User-Agent: 2600hz Content-Length: 0 ------------------------------------------------------------------------ 2014-02-25 00:10:44.243689 [DEBUG] sofia.c:1937 Re-attaching to session 0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO 2014-02-25 00:10:44.243689 [DEBUG] switch_core_session.c:1048 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:44.243689 [DEBUG] switch_core_session.c:1048 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:44.263688 [DEBUG] sofia.c:8156 1 acls to check for proxy 2014-02-25 00:10:44.263688 [DEBUG] sofia.c:8161 checking 88.80.160.31 against acl authoritative 2014-02-25 00:10:44.263688 [INFO] sofia.c:8163 88.80.160.31 is a proxy according to the authoritative acl 2014-02-25 00:10:44.263688 [DEBUG] sofia.c:8173 network ip is a proxy 2014-02-25 00:10:44.263688 [DEBUG] sofia.c:8177 found auth ip [X-AUTH-IP] header of [112.196.33.74] 2014-02-25 00:10:44.263688 [DEBUG] sofia.c:8201 IP 88.80.160.31 Rejected by acl "trusted". Falling back to Digest auth. 2014-02-25 00:10:44.263688 [DEBUG] kazoo_fetch_agent.c:216 Sending directory XML request (2dc8752c-9ddb-11e3-ae8c-69d00812b6c2) to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.1184.0> 2014-02-25 00:10:44.263688 [DEBUG] kazoo_node.c:1091 Sent erlang message to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.1184.0> 2014-02-25 00:10:44.383689 [DEBUG] kazoo_fetch_agent.c:277 Received directory XML (2dc8752c-9ddb-11e3-ae8c-69d00812b6c2) after 120ms: <document type="freeswitch/xml"><section name="directory"><domain name="sip.test.com <http://sip.test.com>"><user id="user1"><variables><variable name="ecallmgr_Inception" value="on-net"/><variable name="ecallmgr_Authorizing-Type" value="device"/><variable name="ecallmgr_Authorizing-ID" value="3b46b4ceec6bb18dd8985792d7b5693e"/><variable name="ecallmgr_Account-ID" value="502cc62fa8097dd6d753fea7c7ef91a1"/><variable name="ecallmgr_Realm" value="sip.test.com <http://sip.test.com>"/><variable name="ecallmgr_Username" value="user1"/></variables><params><param name="password" value="user1"/></params></user></domain></section></document> 2014-02-25 00:10:44.383689 [DEBUG] sofia.c:5889 Channel sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> entering state [received][100] 2014-02-25 00:10:44.383689 [DEBUG] sofia.c:5899 Remote SDP: v=0 o=- 3602293864 3602293864 IN IP4 112.196.33.74 s=pjmedia c=IN IP4 112.196.33.74 t=0 0 m=audio 4226 RTP/AVP 99 0 8 101 c=IN IP4 112.196.33.74 a=rtpmap:99 SILK/24000 a=fmtp:99 useinbandfec=0 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtcp:9246 IN IP4 112.196.33.74 2014-02-25 00:10:44.383689 [DEBUG] sofia.c:6144 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State Change CS_NEW -> CS_INIT 2014-02-25 00:10:44.383689 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Running State Change CS_INIT 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:507 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State INIT 2014-02-25 00:10:44.383689 [DEBUG] mod_sofia.c:87 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SOFIA INIT 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Standard INIT 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State Change CS_INIT -> CS_ROUTING 2014-02-25 00:10:44.383689 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:507 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State INIT going to sleep 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Running State Change CS_ROUTING 2014-02-25 00:10:44.383689 [DEBUG] switch_channel.c:2179 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Callstate Change DOWN -> RINGING 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:523 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State ROUTING 2014-02-25 00:10:44.383689 [DEBUG] mod_sofia.c:123 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SOFIA ROUTING 2014-02-25 00:10:44.383689 [DEBUG] switch_core_state_machine.c:164 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Standard ROUTING 2014-02-25 00:10:44.383689 [INFO] mod_dialplan_xml.c:558 Processing user1 <user1>->+918146234576 in context context_2 2014-02-25 00:10:44.383689 [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request (2ddb9918-9ddb-11e3-ae8e-69d00812b6c2) to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.1185.0> 2014-02-25 00:10:44.403683 [DEBUG] kazoo_node.c:1091 Sent erlang message to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.1185.0> 2014-02-25 00:10:44.543689 [DEBUG] kazoo_fetch_agent.c:277 Received dialplan XML (2ddb9918-9ddb-11e3-ae8e-69d00812b6c2) after 160ms: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl>"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="park"/></condition></extension></context></section></document> Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> parsing [context_2->park] continue=false |--- Dialplan: Processing recursive conditions level:1 [park_recur_1] require-nested=TRUE |--- Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Regex (PASS) [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/ break=on-false |--- Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Action export(ecallmgr_Bridge-ID=${UUID}) Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Absolute Condition [park] Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Action log(NOTICE log|${uuid}|ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> won call control) Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Action export(ecallmgr_Ecallmgr-Node=ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl>) Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Action set(ringback=%(2000,4000,440,480)) Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Action set(transfer_ringback=%(2000,4000,440,480)) Dialplan: sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Action park() 2014-02-25 00:10:44.543689 [DEBUG] switch_core_state_machine.c:214 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State Change CS_ROUTING -> CS_EXECUTE 2014-02-25 00:10:44.543689 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:44.543689 [DEBUG] switch_core_state_machine.c:523 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State ROUTING going to sleep 2014-02-25 00:10:44.543689 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Running State Change CS_EXECUTE 2014-02-25 00:10:44.543689 [DEBUG] switch_core_state_machine.c:530 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State EXECUTE 2014-02-25 00:10:44.543689 [DEBUG] mod_sofia.c:178 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SOFIA EXECUTE 2014-02-25 00:10:44.543689 [DEBUG] switch_core_state_machine.c:256 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Standard EXECUTE EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> export(ecallmgr_Bridge-ID=0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO) 2014-02-25 00:10:44.543689 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [ecallmgr_Bridge-ID]=[0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO] EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> log(NOTICE log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> won call control) 2014-02-25 00:10:44.543689 [NOTICE] mod_dptools.c:1634 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> won call control EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> export(ecallmgr_Ecallmgr-Node=ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl>) 2014-02-25 00:10:44.543689 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [ecallmgr_Ecallmgr-Node]=[ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl>] EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> set(ringback=%(2000,4000,440,480)) 2014-02-25 00:10:44.543689 [DEBUG] mod_dptools.c:1402 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SET [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> set(transfer_ringback=%(2000,4000,440,480)) 2014-02-25 00:10:44.543689 [DEBUG] mod_dptools.c:1402 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SET [transfer_ringback]=[%(2000,4000,440,480)] EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> park() 2014-02-25 00:10:44.543689 [DEBUG] kazoo_node.c:1091 Sent erlang message to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.11883.4> 2014-02-25 00:10:44.563813 [INFO] kazoo_node.c:627 exec: uuid_setvar_multi(0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO ecallmgr_Channel-Authorized=true;ecallmgr_Account-ID=502cc62fa8097dd6d753fea7c7ef91a1) 2014-02-25 00:10:44.563813 [DEBUG] kazoo_node.c:1091 Sent erlang message to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.11883.4> 2014-02-25 00:10:44.723684 [INFO] kazoo_node.c:627 exec: uuid_setvar_multi(0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO effective_caller_id_name=Martin;effective_caller_id_number=+xxxxxxxxxxx;eca… <http://sip.test.com>;ecallmgr_Account-ID=502cc62fa8097dd6d753fea7c7ef91a1;ecallmgr_Authorizing-ID=3b46b4ceec6bb18dd8985792d7b5693e;ecallmgr_Authorizing-Type=device;ecallmgr_Inception=on-net;ecallmgr_Fetch-ID=2ddb9918-9ddb-11e3-ae8e-69d00812b6c2) 2014-02-25 00:10:44.723684 [DEBUG] kazoo_node.c:1091 Sent erlang message to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.11912.4> freeswitch@internal> 2014-02-25 00:10:45.043686 [NOTICE] kazoo_node.c:302 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|building xferext extension: set ignore_display_updates=true 2014-02-25 00:10:45.043686 [NOTICE] kazoo_node.c:302 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|building xferext extension: set continue_on_fail=true 2014-02-25 00:10:45.043686 [NOTICE] kazoo_node.c:302 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|building xferext extension: export sip_redirect_context=context_2 2014-02-25 00:10:45.043686 [NOTICE] kazoo_node.c:302 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|building xferext extension: bridge {ignore_display_updates='true',ecallmgr_Account-ID='502cc62fa8097dd6d753fea7c7ef91a1',ecallmgr_Reseller-ID='cf9c1c7b7a5d5894bc0c0fbc9420c403',effective_caller_id_number='+xxxxxxxxxxx',effective_caller_id_name='Martin',origination_caller_id_number='+xxxxxxxxxxx',origination_caller_id_name='Martin',ignore_early_media='false',local_var_clobber='true'}[sip_auth_password='xxxxxxxxxxxx',sip_auth_username='xxxxxxxxxxx',ecallmgr_Global-Resource='false',ecallmgr_Resource-ID='b50436c83efa77bb94e1241c872fa7c0',absolute_codec_string='^^:PCMU:PCMA:G722:G7221@16000h:G7221@32000h',leg_progress_timeout='60',effective_callee_id_number='+918146234576',effective_callee_id_name='918146234576']sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> 2014-02-25 00:10:45.043686 [NOTICE] kazoo_node.c:302 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|building xferext extension: event Event-Name=CUSTOM,Event-Subclass=whistle::masquerade,whistle_event_name=CHANNEL_EXECUTE_COMPLETE,whistle_application_name=bridge 2014-02-25 00:10:45.043686 [NOTICE] kazoo_node.c:302 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|building xferext extension: park 2014-02-25 00:10:45.043686 [NOTICE] kazoo_node.c:305 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|transfered call to xferext extension 2014-02-25 00:10:45.043686 [DEBUG] switch_core_session.c:1183 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:45.043686 [DEBUG] switch_channel.c:3098 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State Change CS_EXECUTE -> CS_ROUTING 2014-02-25 00:10:45.043686 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:530 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State EXECUTE going to sleep 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Running State Change CS_ROUTING 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:523 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State ROUTING 2014-02-25 00:10:45.063687 [DEBUG] mod_sofia.c:123 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SOFIA ROUTING 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:164 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Standard ROUTING 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:184 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State Change CS_ROUTING -> CS_EXECUTE 2014-02-25 00:10:45.063687 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:523 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State ROUTING going to sleep 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Running State Change CS_EXECUTE 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:530 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State EXECUTE 2014-02-25 00:10:45.063687 [DEBUG] mod_sofia.c:178 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SOFIA EXECUTE 2014-02-25 00:10:45.063687 [DEBUG] switch_core_state_machine.c:256 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Standard EXECUTE EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> set(ignore_display_updates=true) 2014-02-25 00:10:45.063687 [DEBUG] mod_dptools.c:1402 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SET [ignore_display_updates]=[true] EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> set(continue_on_fail=true) 2014-02-25 00:10:45.063687 [DEBUG] mod_dptools.c:1402 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> SET [continue_on_fail]=[true] EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> export(sip_redirect_context=context_2) 2014-02-25 00:10:45.063687 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [sip_redirect_context]=[context_2] EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> bridge({ignore_display_updates='true',ecallmgr_Account-ID='502cc62fa8097dd6d753fea7c7ef91a1',ecallmgr_Reseller-ID='cf9c1c7b7a5d5894bc0c0fbc9420c403',effective_caller_id_number='+xxxxxxxxxxx',effective_caller_id_name='Martin',origination_caller_id_number='+xxxxxxxxxxx',origination_caller_id_name='Martin',ignore_early_media='false',local_var_clobber='true'}[sip_auth_password='xxxxxxxxxxxx',sip_auth_username='xxxxxxxxxxx',ecallmgr_Global-Resource='false',ecallmgr_Resource-ID='b50436c83efa77bb94e1241c872fa7c0',absolute_codec_string='^^:PCMU:PCMA:G722:G7221@16000h:G7221@32000h',leg_progress_timeout='60',effective_callee_id_number='+918146234576',effective_callee_id_name='918146234576']sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) 2014-02-25 00:10:45.083685 [DEBUG] switch_channel.c:1201 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> EXPORTING[export_vars] [ecallmgr_Bridge-ID]=[0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO] to event 2014-02-25 00:10:45.083685 [DEBUG] switch_channel.c:1201 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> EXPORTING[export_vars] [ecallmgr_Ecallmgr-Node]=[ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl>] to event 2014-02-25 00:10:45.083685 [DEBUG] switch_channel.c:1201 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> EXPORTING[export_vars] [sip_redirect_context]=[context_2] to event 2014-02-25 00:10:45.083685 [DEBUG] switch_ivr_originate.c:2071 Parsing global variables 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [ignore_display_updates]=[true] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [ecallmgr_Account-ID]=[502cc62fa8097dd6d753fea7c7ef91a1] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [ecallmgr_Reseller-ID]=[cf9c1c7b7a5d5894bc0c0fbc9420c403] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [effective_caller_id_number]=[+xxxxxxxxxxx] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [effective_caller_id_name]=[Martin] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [origination_caller_id_number]=[+xxxxxxxxxxx] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [origination_caller_id_name]=[Martin] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [ignore_early_media]=[false] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [local_var_clobber]=[true] 2014-02-25 00:10:45.083685 [DEBUG] switch_ivr_originate.c:2518 Parsing session specific variables 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [sip_auth_password]=[xxxxxxxxxxxx] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [sip_auth_username]=[xxxxxxxxxxx] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [ecallmgr_Global-Resource]=[false] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [ecallmgr_Resource-ID]=[b50436c83efa77bb94e1241c872fa7c0] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [absolute_codec_string]=[^^:PCMU:PCMA:G722:G7221@16000h:G7221@32000h] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [leg_progress_timeout]=[60] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [effective_callee_id_number]=[+918146234576] 2014-02-25 00:10:45.083685 [DEBUG] switch_event.c:1687 Parsing variable [effective_callee_id_name]=[918146234576] 2014-02-25 00:10:45.083685 [NOTICE] switch_channel.c:1055 New Channel sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [2e446736-9ddb-11e3-ae9b-69d00812b6c2] 2014-02-25 00:10:45.083685 [DEBUG] mod_sofia.c:4456 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State Change CS_NEW -> CS_INIT 2014-02-25 00:10:45.083685 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.083685 [DEBUG] switch_ivr_originate.c:2821 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> Setting leg progress timeout to 60 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Running State Change CS_INIT 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:507 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State INIT 2014-02-25 00:10:45.083685 [DEBUG] mod_sofia.c:87 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> SOFIA INIT 2014-02-25 00:10:45.083685 [INFO] switch_nat.c:590 NAT port mapping disabled 2014-02-25 00:10:45.083685 [DEBUG] sofia_glue.c:1225 Local SDP: v=0 o=FreeSWITCH 1393277355 1393277356 IN IP4 31.220.27.158 s=FreeSWITCH c=IN IP4 31.220.27.158 t=0 0 m=audio 27690 RTP/AVP 0 8 9 98 99 101 13 a=rtpmap:98 G7221/16000 a=fmtp:98 bitrate=32000 a=rtpmap:99 G7221/32000 a=fmtp:99 bitrate=48000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> Standard INIT 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State Change CS_INIT -> CS_ROUTING 2014-02-25 00:10:45.083685 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:507 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State INIT going to sleep 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Running State Change CS_ROUTING 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:523 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State ROUTING 2014-02-25 00:10:45.083685 [DEBUG] mod_sofia.c:123 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> SOFIA ROUTING 2014-02-25 00:10:45.083685 [DEBUG] switch_ivr_originate.c:67 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2014-02-25 00:10:45.083685 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:523 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State ROUTING going to sleep 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Running State Change CS_CONSUME_MEDIA 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:542 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State CONSUME_MEDIA 2014-02-25 00:10:45.083685 [DEBUG] switch_core_state_machine.c:542 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State CONSUME_MEDIA going to sleep 2014-02-25 00:10:45.083685 [INFO] kazoo_node.c:627 exec: uuid_setvar_multi(2e446736-9ddb-11e3-ae9b-69d00812b6c2 ecallmgr_Channel-Authorized=true;ecallmgr_Global-Resource=false;ecallmgr_Reseller-ID=cf9c1c7b7a5d5894bc0c0fbc9420c403;ecallmgr_Account-ID=502cc62fa8097dd6d753fea7c7ef91a1) 2014-02-25 00:10:45.083685 [DEBUG] kazoo_node.c:1091 Sent erlang message to ecallmgr(a)kaz2.test.nl <mailto:ecallmgr@kaz2.test.nl> <2.11955.4> 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1048 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.103685 [DEBUG] sofia.c:5889 Channel sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> entering state [calling][0] 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1048 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1048 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1048 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.103685 [DEBUG] sofia.c:5889 Channel sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> entering state [terminated][503] 2014-02-25 00:10:45.103685 [NOTICE] sofia.c:6733 Hangup sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2014-02-25 00:10:45.103685 [DEBUG] switch_channel.c:3212 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [KILL] 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Running State Change CS_HANGUP 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:731 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State HANGUP 2014-02-25 00:10:45.103685 [DEBUG] mod_sofia.c:413 Channel sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> hanging up, cause: NORMAL_TEMPORARY_FAILURE 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:58 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:731 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State HANGUP going to sleep 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:744 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Callstate Change DOWN -> HANGUP 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:499 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State Change CS_HANGUP -> CS_REPORTING 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Running State Change CS_REPORTING 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:816 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State REPORTING 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:102 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:816 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State REPORTING going to sleep 2014-02-25 00:10:45.103685 [DEBUG] switch_core_state_machine.c:493 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State Change CS_REPORTING -> CS_DESTROY 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [BREAK] 2014-02-25 00:10:45.103685 [DEBUG] switch_core_session.c:1591 Session 15 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Locked, Waiting on external entities 2014-02-25 00:10:45.123885 [DEBUG] switch_ivr_originate.c:3678 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2014-02-25 00:10:45.123885 [INFO] mod_dptools.c:3244 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> event(Event-Name=CUSTOM,Event-Subclass=whistle::masquerade,whistle_event_name=CHANNEL_EXECUTE_COMPLETE,whistle_application_name=bridge) EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> park() 2014-02-25 00:10:45.123885 [NOTICE] switch_core_session.c:1609 Session 15 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Ended 2014-02-25 00:10:45.123885 [NOTICE] switch_core_session.c:1613 Close Channel sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> [CS_DESTROY] 2014-02-25 00:10:45.123885 [DEBUG] switch_core_state_machine.c:618 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Callstate Change HANGUP -> DOWN 2014-02-25 00:10:45.123885 [DEBUG] switch_core_state_machine.c:621 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) Running State Change CS_DESTROY 2014-02-25 00:10:45.123885 [DEBUG] switch_core_state_machine.c:631 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State DESTROY 2014-02-25 00:10:45.123885 [DEBUG] mod_sofia.c:323 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> SOFIA DESTROY 2014-02-25 00:10:45.123885 [DEBUG] switch_core_state_machine.c:109 sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net> Standard DESTROY 2014-02-25 00:10:45.123885 [DEBUG] switch_core_state_machine.c:631 (sofia/sipinterface_1/+918146234576(a)sip.sipnl.net <mailto:918146234576@sip.sipnl.net>) State DESTROY going to sleep 2014-02-25 00:10:45.183685 [NOTICE] kazoo_node.c:285 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|executing pre_answer 2014-02-25 00:10:45.183685 [DEBUG] switch_core_session.c:1183 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:45.183685 [DEBUG] switch_ivr.c:615 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Command Execute pre_answer() EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> pre_answer() 2014-02-25 00:10:45.183685 [INFO] mod_dptools.c:1260 Sending early media 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [SILK:99:24000:20:0]/[G7221:115:32000:20:48000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [SILK:99:24000:20:0]/[G7221:107:16000:20:32000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [SILK:99:24000:20:0]/[G722:9:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [SILK:99:24000:20:0]/[PCMU:0:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [SILK:99:24000:20:0]/[PCMA:8:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [SILK:99:24000:20:0]/[GSM:3:8000:20:13200] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3220 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMA:8:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMU:0:8000:20:64000]/[GSM:3:8000:20:13200] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:115:32000:20:48000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMA:8:8000:20:64000]/[G7221:107:16000:20:32000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3220 Audio Codec Compare [PCMA:8:8000:20:64000] ++++ is saved as a match 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3166 Audio Codec Compare [PCMA:8:8000:20:64000]/[GSM:3:8000:20:13200] 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3092 Set telephone-event payload to 101 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:2125 Set Codec sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> PCMU/8000 20 ms 160 samples 64000 bits 2014-02-25 00:10:45.183685 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Original read codec set to PCMU:0 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:3398 Set 2833 dtmf send/recv payload to 101 2014-02-25 00:10:45.183685 [INFO] switch_nat.c:590 NAT port mapping disabled 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:4586 AUDIO RTP [sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>] 31.220.27.158 port 20696 -> 112.196.33.74 port 4226 codec: 0 ms: 20 2014-02-25 00:10:45.183685 [DEBUG] switch_rtp.c:3068 Starting timer [soft] 160 bytes per 20ms 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:4930 Set 2833 dtmf send payload to 101 2014-02-25 00:10:45.183685 [DEBUG] switch_core_media.c:4936 Set 2833 dtmf receive payload to 101 2014-02-25 00:10:45.183685 [NOTICE] sofia_media.c:92 Pre-Answer sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>! 2014-02-25 00:10:45.183685 [DEBUG] switch_channel.c:3405 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Callstate Change RINGING -> EARLY 2014-02-25 00:10:45.183685 [DEBUG] mod_sofia.c:2099 Ring SDP: v=0 o=FreeSWITCH 1393284349 1393284350 IN IP4 31.220.27.158 s=FreeSWITCH c=IN IP4 31.220.27.158 t=0 0 m=audio 20696 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2014-02-25 00:10:45.183685 [DEBUG] switch_core_session.c:903 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:45.183685 [DEBUG] switch_ivr.c:959 Codec Activated L16@8000hz 1 channels 20ms send 1297 bytes to udp/[88.80.160.31]:5060 at 05:10:45.197608: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 88.80.160.31;branch=z9hG4bKd602.9af44717.0 Via: SIP/2.0/UDP 112.196.33.74:11220;rport=62926;branch=z9hG4bKPj.w0giarvUkQ67HPw3uK5Z6NsdtAUWvEV Record-Route: <sip:88.80.160.31;lr=on;ftag=aW0i4G-.8DI9G4pbsNbl8EWP1fY76mxz> From: <sip:user1@sip.test.com <mailto:sip%3Auser1@sip.test.com>>;tag=aW0i4G-.8DI9G4pbsNbl8EWP1fY76mxz To: <sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com>>;tag=0KtN4j4SvttFc Call-ID: 0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO CSeq: 26826 INVITE Contact: <sip:+918146234576@31.220.27.158:11000;transport=udp> User-Agent: 2600hz Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: precondition, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 222 Remote-Party-ID: "+918146234576" <sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com>>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1393284349 1393284350 IN IP4 31.220.27.158 s=FreeSWITCH c=IN IP4 31.220.27.158 t=0 0 m=audio 20696 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2014-02-25 00:10:45.183685 [DEBUG] switch_core_session.c:1048 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:45.183685 [DEBUG] sofia.c:5889 Channel sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> entering state [early][183] 2014-02-25 00:10:45.303686 [NOTICE] kazoo_node.c:285 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|executing playback ${http_get(http://127.0.0.1:15984/system_media/fault-can_not_be_completed_at_this_time/fault-can_not_be_completed_at_this_time.wav <http://127.0.0.1:15984/system_media/fault-can_not_be_completed_at_this_time…>)} 2014-02-25 00:10:45.303686 [DEBUG] switch_core_session.c:1183 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:45.303686 [DEBUG] switch_ivr.c:615 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Command Execute playback(${http_get(http://127.0.0.1:15984/system_media/fault-can_not_be_completed_at_this_time/fault-can_not_be_completed_at_this_time.wav) <http://127.0.0.1:15984/system_media/fault-can_not_be_completed_at_this_time…>}) 2014-02-25 00:10:45.323688 [DEBUG] mod_http_cache.c:523 Locked cache 2014-02-25 00:10:45.323688 [DEBUG] mod_http_cache.c:651 Cache HIT: size = 1 (0 MB), hit ratio = 8/9 2014-02-25 00:10:45.323688 [DEBUG] mod_http_cache.c:534 Unlocked cache EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> playback(/usr/share/freeswitch/http_cache/39/6c5fb6-9d53-11e3-adae-69d00812b6c2.wav) 2014-02-25 00:10:45.323688 [DEBUG] switch_core_file.c:216 File /usr/share/freeswitch/http_cache/39/6c5fb6-9d53-11e3-adae-69d00812b6c2.wav sample rate 16000 doesn't match requested rate 8000 2014-02-25 00:10:45.323688 [DEBUG] switch_ivr_play_say.c:1315 Codec Activated L16@8000hz 1 channels 20ms 2014-02-25 00:10:46.603692 [INFO] switch_rtp.c:5174 Auto Changing port from 112.196.33.74:4226 <http://112.196.33.74:4226> to 112.196.33.74:62840 <http://112.196.33.74:62840> 2014-02-25 00:10:49.503708 [DEBUG] switch_ivr_play_say.c:1719 done playing file /usr/share/freeswitch/http_cache/39/6c5fb6-9d53-11e3-adae-69d00812b6c2.wav 2014-02-25 00:10:49.503708 [NOTICE] kazoo_node.c:285 log|0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO|executing respond 503 Normal temporary failure 2014-02-25 00:10:49.503708 [DEBUG] switch_core_session.c:1183 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:49.543698 [DEBUG] switch_ivr.c:615 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Command Execute respond(503 Normal temporary failure) EXECUTE sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> respond(503 Normal temporary failure) 2014-02-25 00:10:49.543698 [DEBUG] mod_sofia.c:1919 Responding with 503 [Normal temporary failure] 2014-02-25 00:10:49.543698 [NOTICE] mod_sofia.c:1978 Hangup sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2014-02-25 00:10:49.543698 [DEBUG] switch_channel.c:3212 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [KILL] 2014-02-25 00:10:49.543698 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] 2014-02-25 00:10:49.543698 [DEBUG] switch_core_session.c:2852 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2014-02-25 00:10:49.543698 [DEBUG] switch_ivr.c:658 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> skip receive message [AUDIO_SYNC] (channel is hungup already) 2014-02-25 00:10:49.543698 [DEBUG] switch_core_session.c:2852 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:530 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State EXECUTE going to sleep 2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Running State Change CS_HANGUP 2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:731 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State HANGUP 2014-02-25 00:10:49.543698 [DEBUG] mod_sofia.c:407 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Overriding SIP cause 503 with 503 from the other leg 2014-02-25 00:10:49.543698 [DEBUG] mod_sofia.c:413 Channel sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> hanging up, cause: NORMAL_TEMPORARY_FAILURE 2014-02-25 00:10:49.543698 [DEBUG] mod_sofia.c:553 Responding to INVITE with: 503 2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:58 sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:731 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State HANGUP going to sleep 2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:744 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Callstate Change EARLY -> HANGUP 2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:499 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) State Change CS_HANGUP -> CS_REPORTING 2014-02-25 00:10:49.543698 [DEBUG] switch_core_session.c:1383 Send signal sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com> [BREAK] send 910 bytes to udp/[88.80.160.31]:5060 at 05:10:49.558765: ------------------------------------------------------------------------ SIP/2.0 503 Normal temporary failure Via: SIP/2.0/UDP 88.80.160.31;branch=z9hG4bKd602.9af44717.0 Via: SIP/2.0/UDP 112.196.33.74:11220;rport=62926;branch=z9hG4bKPj.w0giarvUkQ67HPw3uK5Z6NsdtAUWvEV From: <sip:user1@sip.test.com <mailto:sip%3Auser1@sip.test.com>>;tag=aW0i4G-.8DI9G4pbsNbl8EWP1fY76mxz To: <sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com>>;tag=0KtN4j4SvttFc Call-ID: 0v4twiSX8ZbXhaUtGh2KBbEpHgQyJmqO CSeq: 26826 INVITE User-Agent: 2600hz2014-02-25 00:10:49.543698 [DEBUG] switch_core_state_machine.c:467 (sofia/sipinterface_1/user1(a)sip.test.com <mailto:user1@sip.test.com>) Running State Change CS_REPORTING Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: precondition, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Reason: Q.850;cause=41;text="NORMAL_TEMPORARY_FAILURE" Content-Length: 0 Remote-Party-ID: "+918146234576" <sip:+918146234576@sip.test.com <mailto:sip%3A%2B918146234576@sip.test.com>>;party=calling;privacy=off;screen=no can anyone tell me what is the problem and how to solve it. regards, vinay

2 1

Performance optimization and stack size value
by Kevin Mathy 25 Feb '14

25 Feb '14

Hi List, I'm trying to make my FS server more performant and reliable, and I found the FS's wiki page telling that I can change some "ulimit" values on my system, like the Stack Size. So, I've changed in the init script the "ulimit -s" value to 8192, but now when I start freeswitch I've got the following error message : > Error: stacksize 8192 is not optimal: run ulimit -s 240 from your shell > before starting the application. > auto-adjusting stack size for optimal performance... So when I check the status : > freeswitch@10.84.9.41@internal> status > UP 0 years, 0 days, 0 hours, 0 minutes, 6 seconds, 661 milliseconds, 592 > microseconds > FreeSWITCH (Version 1.3.17 git 16289ce 2013-03-14 03:24:25Z) is ready > 0 session(s) since startup > 0 session(s) - 0 out of max 30 per sec > 1000 session(s) max > min idle cpu 0.00/100.00 > Current Stack Size/Max 240K/8192K It seems that the 8192 value isn't set and is rollbacked to 240... I've got exactly the same result when the init script is filled with "ulimit -s 240". Do you have any idea about how to have the stack size increased ? Thanks a lot, *Bien cordialement, Best Regards, **Kevin MATHY* | Ingénieur VoIP --

5 6

Problem with sending Invite from Freeswitch to the carrier.
by Georgi Stefanov 25 Feb '14

25 Feb '14

Check this out 2014-02-25 00:10:44.263688 [DEBUG] sofia.c:8201 IP 88.80.160.31 Rejected by acl "trusted". Falling back to Digest auth. May be it is good idea to configure access control list via acl.conf.xml file

1 0