- FreeSWITCH-users - FreeSWITCH Mailing Lists

FreeSWITCH 1.4.8 Released!
by Ken Rice 22 Sep '14

22 Sep '14

Greetings FreeSWITCHers! FreeSWITCH 1.4.8 is here! This release addresses many bugs, updates in the Conference Stereo code, as well as updates to Verto. Also addressed in this release are updates to all the sounds files! Everything is available now via http://files.freeswitch.org/ or via the Debian and Yum Repos! See https://confluence.freeswitch.org for most information on installing from deps or rpms! Also, don¹t forget to join the Docs team tomorrow at 2PM Central if you want to help getting all the docs updated! -- Ken http://www.FreeSWITCH.org http://www.ClueCon.com http://www.OSTAG.org irc.freenode.net #freeswitch Twitter: @FreeSWITCH

1 0

Freeswitch error - Progress Time out Duration 5 sec.
by Charles Bujold 22 Sep '14

22 Sep '14

Hello, We are running Freeswitch 1.4.8 on Ubuntu 12.04 LTS and encountering with some very specific telephone numbers (currently 2 telephone numbers) a disconnect when trying to call them or them calling us. (99%) of the calls work flawlessly). The symptom is that when we call the number it connects and the call is immediately dropped before we hear the first ring. From their side when they call us we see Freeswitch accept the call go through the process and before it starts ringing we see the error: Progress time out duration 5 seconds. I presume it is due to some delay in establishing the call final routing but how can I tell Freeswitch to add a few more seconds before giving up? Or is it some other issue? Any help would be greatly appreciated. Thanks in advance. cjb

2 1

Re: [Freeswitch-users] FreeSWITCH not sending BYE
by Kamrul Khan 22 Sep '14

22 Sep '14

Its in public network. OK. heres the log after setting log level to 9 . Please check the below console log. Hope it gives some more clues. 2014-09-18 17:39:10.825909 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/alice@fs.mydomain.comnua.c:645 nua_bye() nua: nua_bye: enteringnua_stack.c:529 nua_signal() nua(0x7f16a83a5240): sent signal r_bye2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:58 sofia/internal/alice(a)fs.mydomain.com Standard HANGUP, cause: NORMAL_CLEARINGnua_stack.c:569 nua_stack_signal() nua(0x7f16a83a5240): recv signal r_bye2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/alice(a)fs.mydomain.com) State HANGUP going to sleepnua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: enteringsoa.c:403 soa_set_params() soa_set_params(static::0x7f16b0135890, ...) calledsoa.c:1784 soa_terminate() soa_terminate(static::0x7f16b0135890) calledsoa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f16b0135890) callednta.c:2665 nta_tpn_by_url() nta: selecting scheme sipnta.c:8132 outgoing_prepare_send() nta outgoing create: no transport protocolnta.c:1348 set_timeout() nta: timer shortened to 5000 ms2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_HANGUP -> CS_REPORTINGnua_stack.c:271 nua_stack_event() nua(0x7f16a83a5240): event r_bye 503 No transport2014-09-18 17:39:10.825909 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK]nua_session.c:4137 signal_call_state_change() nua(0x7f16a83a5240): call state changed: terminating -> terminatednua_stack.c:271 nua_stack_event() nua(0x7f16a83a5240): event i_state 503 to BYEnua_stack.c:271 nua_stack_event() nua(0x7f16a83a5240): event i_terminated 503 to BYEnua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f16a83a5240): removing session usagesoa.c:356 soa_destroy() soa_destroy(static::0x7f16b0135890) callednta.c:4468 nta_leg_destroy() nta_leg_destroy(0x7f16b40f0940)nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f16a83a5240nua_stack.c:359 nua_application_event() nua: nua_application_event: enteringnua_stack.c:359 nua_application_event() nua: nua_application_event: enteringnua_stack.c:359 nua_application_event() nua: nua_application_event: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:342 nua_handle_bind() nua: nua_handle_bind: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: entering2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_REPORTINGnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:921 nua_handle_destroy() nua: nua_handle_destroy: enteringnua_stack.c:529 nua_signal() nua(0x7f16a83a5240): sent signal r_destroynua_stack.c:569 nua_stack_signal() nua(0x7f16a83a5240): recv signal r_destroynta.c:4468 nta_leg_destroy() nta_leg_destroy((nil)) From: freeswitch-users-request(a)lists.freeswitch.org Subject: FreeSWITCH-users Digest, Vol 99, Issue 165 To: freeswitch-users(a)lists.freeswitch.org Date: Fri, 19 Sep 2014 02:10:52 +0400 Send FreeSWITCH-users mailing list submissions to freeswitch-users(a)lists.freeswitch.org To subscribe or unsubscribe via the World Wide Web, visit http://lists.freeswitch.org/mailman/listinfo/freeswitch-users or, via email, send a message with subject or body 'help' to freeswitch-users-request(a)lists.freeswitch.org You can reach the person managing the list at freeswitch-users-owner(a)lists.freeswitch.org When replying, please edit your Subject line so it is more specific than "Re: Contents of FreeSWITCH-users digest..." --Forwarded Message Attachment-- From: brian(a)freeswitch.org To: freeswitch-users(a)lists.freeswitch.org Date: Thu, 18 Sep 2014 17:10:20 -0500 Subject: Re: [Freeswitch-users] FreeSWITCH not sending BYE sofia loglevel all 9 Is this local network or over the public internet? On Thu, Sep 18, 2014 at 4:52 PM, Kamrul Khan <dodul(a)live.com> wrote: I checked the sofia debug. Didnt get anything interesting. Is there some other reason why it might be happening ? From: freeswitch-users-request(a)lists.freeswitch.org Subject: FreeSWITCH-users Digest, Vol 99, Issue 162 To: freeswitch-users(a)lists.freeswitch.org Date: Fri, 19 Sep 2014 00:13:50 +0400 Send FreeSWITCH-users mailing list submissions to freeswitch-users(a)lists.freeswitch.org To subscribe or unsubscribe via the World Wide Web, visit http://lists.freeswitch.org/mailman/listinfo/freeswitch-users or, via email, send a message with subject or body 'help' to freeswitch-users-request(a)lists.freeswitch.org You can reach the person managing the list at freeswitch-users-owner(a)lists.freeswitch.org When replying, please edit your Subject line so it is more specific than "Re: Contents of FreeSWITCH-users digest..." --Forwarded Message Attachment-- From: steveayre(a)gmail.com To: freeswitch-users(a)lists.freeswitch.org Date: Thu, 18 Sep 2014 21:12:48 +0100 Subject: Re: [Freeswitch-users] FreeSWITCH not sending BYE Turn on the sofia stack debugging - perhaps that'll show an error within the stack where the stack is told to send bye but fails to do so. On 18 September 2014 17:52, Kamrul Khan <dodul(a)live.com> wrote: Hi,As you can see from the trace all the other packets are passing fine. Its just the BYE message thats not being sent. I just found the below line from my console log:2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/alice(a)fs.mydomain.com So, the log says its sending BYE, but in reality it sends nothing. Any idea whats happening? please help. --Forwarded Message Attachment-- From: mike(a)jerris.com To: freeswitch-users(a)lists.freeswitch.org Date: Wed, 17 Sep 2014 21:32:03 -0400 Subject: Re: [Freeswitch-users] FreeSWITCH not sending BYE something is wrong here... all of the sip packets are coming from and going to the IP address of the freeswitch box? On Sep 17, 2014, at 7:06 PM, Kamrul Khan <dodul(a)live.com> wrote: Hi, Im using freeswitch version 1.4.6. Its not sending back any BYE message. So the caller side thinks call is still alive. The scenario is like the below: Alice(10.1.1.1) ---> Freeswitch(172.16.0.150)--->Bob(10.2.1.1) If the call is terminated by Bob. Bob sends BYE to Freeswitch. but, Freeswitch simply sends back a 200 OK to BOB and drops the call. Doesnt send back any BYE to Alice. Therefore, Alice thinks the Call is still alive. How to fix this. HELP!!! Check my My SIP TRACE: ------------------------------------------------------------------------ recv 2234 bytes from udp/[172.16.0.150]:5063 at 16:48:42.959303: ------------------------------------------------------------------------ INVITE sip:+12345678@fs.mydomain.com SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Contact: "Alice"<sip:alice@10.1.1.2:64649;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr";received="sip:10.1.1.2:64649;transport=WS" Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 INVITE Content-Type: application/sdp Content-Length: 1262 Max-Forwards: 69 User-Agent: IM-client/OMA1.0 sipML5-v1.0.0.0 Organization: Dingaling.ca Path: <sip:172.16.0.150:5063;lr> v=0 o=Mozilla-SIPUA-31.0 322 1 IN IP4 0.0.0.0 s=Doubango Telecom - firefox t=0 0 a=ice-ufrag:17e36105 a=ice-pwd:35179857c2c39018fb82455091801d8a a=fingerprint:sha-256 68:54:EE:EF:A0:BF:93:B9:B6:63:18:0F:C1:A1:BE:5C:6F:49:11:67:1A:88:2D:DC:20:09:80:92:A4:4C:5A:F1 m=audio 60678 UDP/TLS/RTP/SAVPF 109 0 8 101 c=IN IP4 172.16.0.150 a=rtpmap:109 opus/48000/2 a=ptime:20 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=setup:actpass a=candidate:0 1 UDP 2128609535 172.16.1.188 54467 typ host a=candidate:2 1 UDP 1692467199 10.1.1.2 54467 typ srflx raddr 172.16.1.188 rport 54467 a=candidate:5 1 UDP 2128543999 192.168.56.1 54468 typ host a=candidate:10 1 UDP 2128478463 192.168.232.1 54469 typ host a=candidate:15 1 UDP 2128412927 192.168.146.1 54470 typ host a=candidate:0 2 UDP 2128609534 172.16.1.188 54471 typ host a=candidate:1 2 UDP 1692467198 10.1.1.2 54471 typ srflx raddr 172.16.1.188 rport 54471 a=candidate:5 2 UDP 2128543998 192.168.56.1 54472 typ host a=candidate:10 2 UDP 2128478462 192.168.232.1 54473 typ host a=candidate:15 2 UDP 2128412926 192.168.146.1 54474 typ host a=rtcp-mux a=nortpproxy:yes ------------------------------------------------------------------------ send 619 bytes to udp/[172.16.0.150]:5063 at 16:48:42.959974: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:42.945889 [NOTICE] switch_channel.c:1053 New Channel sofia/internal/alice(a)fs.mydomain.com[76f1d37a-b4c0-4247-9fb2-45cf6eadd969] 2014-09-17 16:48:42.945889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.945889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.945889 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_NEW 2014-09-17 16:48:42.945889 [DEBUG] sofia.c:8367 sofia/internal/alice(a)fs.mydomain.com receiving invite from 172.16.0.150:5063 version: 1.4.6 git 9479729 2014-06-03 19:35:16Z 64bit 2014-09-17 16:48:42.945889 [DEBUG] sofia.c:8534 IP 172.16.0.150 Rejected by acl "domains". Falling back to Digest auth. 2014-09-17 16:48:42.945889 [DEBUG] switch_core_state_machine.c:489 (sofia/internal/alice(a)fs.mydomain.com) State NEW send 1069 bytes to udp/[172.16.0.150]:5063 at 16:48:42.962202: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=80Ny99e7gvpUj Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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 Proxy-Authenticate: Digest realm="fs.mydomain.com", nonce="4c15231c-896a-4131-b7c2-621ab8342e9a", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:42.945889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.945889 [DEBUG] sofia.c:2033 detaching session 76f1d37a-b4c0-4247-9fb2-45cf6eadd969 recv 615 bytes from udp/[172.16.0.150]:5063 at 16:48:42.998781: ------------------------------------------------------------------------ ACK sip:+12345678@fs.mydomain.com SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=80Ny99e7gvpUj Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 ACK Content-Length: 0 Max-Forwards: 69 Path: <sip:172.16.0.150:5063;lr> ------------------------------------------------------------------------ recv 2543 bytes from udp/[172.16.0.150]:5063 at 16:48:43.004244: ------------------------------------------------------------------------ INVITE sip:+12345678@fs.mydomain.com SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Contact: "Alice"<sip:alice@10.1.1.2:64649;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr";received="sip:10.1.1.2:64649;transport=WS" Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE Content-Type: application/sdp Content-Length: 1262 Max-Forwards: 69 Proxy-Authorization: Digest username="alice",realm="fs.mydomain.com",nonce="4c15231c-896a-4131-b7c2-621ab8342e9a",uri="sip:+12345678@fs.mydomain.com",response="3f71cf991c76159a30fe0fbea938cbb9",algorithm=MD5,cnonce="8dabac05b6f0a365d085158868220703",qop=auth,nc=00000001 User-Agent: IM-client/OMA1.0 sipML5-v1.0.0.0 Organization: Dingaling.ca Path: <sip:172.16.0.150:5063;lr> v=0 o=Mozilla-SIPUA-31.0 322 1 IN IP4 0.0.0.0 s=Doubango Telecom - firefox t=0 0 a=ice-ufrag:17e36105 a=ice-pwd:35179857c2c39018fb82455091801d8a a=fingerprint:sha-256 68:54:EE:EF:A0:BF:93:B9:B6:63:18:0F:C1:A1:BE:5C:6F:49:11:67:1A:88:2D:DC:20:09:80:92:A4:4C:5A:F1 m=audio 38168 UDP/TLS/RTP/SAVPF 109 0 8 101 c=IN IP4 172.16.0.150 a=rtpmap:109 opus/48000/2 a=ptime:20 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=setup:actpass a=candidate:0 1 UDP 2128609535 172.16.1.188 54467 typ host a=candidate:2 1 UDP 1692467199 10.1.1.2 54467 typ srflx raddr 172.16.1.188 rport 54467 a=candidate:5 1 UDP 2128543999 192.168.56.1 54468 typ host a=candidate:10 1 UDP 2128478463 192.168.232.1 54469 typ host a=candidate:15 1 UDP 2128412927 192.168.146.1 54470 typ host a=candidate:0 2 UDP 2128609534 172.16.1.188 54471 typ host a=candidate:1 2 UDP 1692467198 10.1.1.2 54471 typ srflx raddr 172.16.1.188 rport 54471 a=candidate:5 2 UDP 2128543998 192.168.56.1 54472 typ host a=candidate:10 2 UDP 2128478462 192.168.232.1 54473 typ host a=candidate:15 2 UDP 2128412926 192.168.146.1 54474 typ host a=rtcp-mux a=nortpproxy:yes ------------------------------------------------------------------------ send 619 bytes to udp/[172.16.0.150]:5063 at 16:48:43.005058: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:42.985935 [DEBUG] sofia.c:2138 Re-attaching to session 76f1d37a-b4c0-4247-9fb2-45cf6eadd969 2014-09-17 16:48:42.985935 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.985935 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.005913 [DEBUG] sofia.c:8367 sofia/internal/alice(a)fs.mydomain.com receiving invite from 172.16.0.150:5063 version: 1.4.6 git 9479729 2014-06-03 19:35:16Z 64bit 2014-09-17 16:48:43.005913 [DEBUG] sofia.c:8534 IP 172.16.0.150 Rejected by acl "domains". Falling back to Digest auth. 2014-09-17 16:48:43.285898 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [received][100] 2014-09-17 16:48:43.285898 [DEBUG] sofia.c:6239 Remote SDP: v=0 o=Mozilla-SIPUA-31.0 322 1 IN IP4 0.0.0.0 s=Doubango Telecom - firefox t=0 0 a=ice-ufrag:17e36105 a=ice-pwd:35179857c2c39018fb82455091801d8a a=fingerprint:sha-256 68:54:EE:EF:A0:BF:93:B9:B6:63:18:0F:C1:A1:BE:5C:6F:49:11:67:1A:88:2D:DC:20:09:80:92:A4:4C:5A:F1 m=audio 38168 UDP/TLS/RTP/SAVPF 109 0 8 101 c=IN IP4 172.16.0.150 a=rtpmap:109 opus/48000/2 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=setup:actpass a=candidate:0 1 UDP 2128609535 172.16.1.188 54467 typ host a=candidate:2 1 UDP 1692467199 10.1.1.2 54467 typ srflx raddr 172.16.1.188 rport 54467 a=candidate:5 1 UDP 2128543999 192.168.56.1 54468 typ host a=candidate:10 1 UDP 2128478463 192.168.232.1 54469 typ host a=candidate:15 1 UDP 2128412927 192.168.146.1 54470 typ host a=candidate:0 2 UDP 2128609534 172.16.1.188 54471 typ host a=candidate:1 2 UDP 1692467198 10.1.1.2 54471 typ srflx raddr 172.16.1.188 rport 54471 a=candidate:5 2 UDP 2128543998 192.168.56.1 54472 typ host a=candidate:10 2 UDP 2128478462 192.168.232.1 54473 typ host a=candidate:15 2 UDP 2128412926 192.168.146.1 54474 typ host a=rtcp-mux a=nortpproxy:yes 2014-09-17 16:48:43.285898 [DEBUG] sofia.c:6494 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_NEW -> CS_INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/alice(a)fs.mydomain.com) State INIT 2014-09-17 16:48:43.285898 [DEBUG] mod_sofia.c:87 sofia/internal/alice(a)fs.mydomain.com SOFIA INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:40 sofia/internal/alice(a)fs.mydomain.com Standard INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_INIT -> CS_ROUTING 2014-09-17 16:48:43.285898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/alice(a)fs.mydomain.com) State INIT going to sleep 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_ROUTING 2014-09-17 16:48:43.285898 [DEBUG] switch_channel.c:2180 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change DOWN -> RINGING 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/alice(a)fs.mydomain.com) State ROUTING 2014-09-17 16:48:43.285898 [DEBUG] mod_sofia.c:123 sofia/internal/alice(a)fs.mydomain.com SOFIA ROUTING 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:164 sofia/internal/alice(a)fs.mydomain.com Standard ROUTING 2014-09-17 16:48:43.285898 [INFO] mod_dialplan_xml.c:558 Processing Alice <alice>->+12345678 in context dal-ingress Dialplan: sofia/internal/alice(a)fs.mydomain.com parsing [dal-ingress->3a05956905ca41e2b43170968d44398e] continue=false Dialplan: sofia/internal/alice(a)fs.mydomain.com Absolute Condition [3a05956905ca41e2b43170968d44398e] Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(dal-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(dal-Language=en) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(effective_caller_id_number=17783315100) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(effective_caller_id_name=Alice) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_rh_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_ph_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_bye_h_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Time-Limit=118) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Time-Limit-Bye=you-have-reached-the-time-limit-for-this-call) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Time-Limit-Warnings=60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(nolocal:execute_on_answer=lua mod_callmgr/on-bridge.lua) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Report-URL=http://todo-kkhan.dlcworldwide.com/index.php/internal… Dialplan: sofia/internal/alice(a)fs.mydomain.com Action event(Event-Subclass=callmgr::call_uuid,Event-Name=CUSTOM) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_h_Route=<sip:172.16.0.150:5063>) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action bridge(sofia/gateway/bobspecial/0000100912345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/bob/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/navigata/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/lesnet/12345678;fs_path=sip:172.16.0.150:5063) 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:214 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_ROUTING -> CS_EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/alice(a)fs.mydomain.com) State ROUTING going to sleep 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:533 (sofia/internal/alice(a)fs.mydomain.com) State EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:178 sofia/internal/alice(a)fs.mydomain.com SOFIA EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:256 sofia/internal/alice(a)fs.mydomain.com Standard EXECUTE EXECUTE sofia/internal/alice(a)fs.mydomain.com export(dal-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [dal-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(dal-Language=en) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [dal-Language]=[en] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(effective_caller_id_number=17783315100) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [effective_caller_id_number]=[17783315100] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(effective_caller_id_name=Alice) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [effective_caller_id_name]=[Alice] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_rh_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_rh_X-DAL-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_ph_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_ph_X-DAL-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_bye_h_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_bye_h_X-DAL-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Time-Limit=118) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Time-Limit]=[118] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Time-Limit-Bye=you-have-reached-the-time-limit-for-this-call) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Time-Limit-Bye]=[you-have-reached-the-time-limit-for-this-call] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Time-Limit-Warnings=60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Time-Limit-Warnings]=[60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(nolocal:execute_on_answer=lua mod_callmgr/on-bridge.lua) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) (REMOTE ONLY) [execute_on_answer]=[lua mod_callmgr/on-bridge.lua] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Report-URL=http://todo-kkhan.dlcworldwide.com/index.php/internal… 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Report-URL]=[http://todo-kkhan.dlcworldwide.com/index.php/internal/] EXECUTE sofia/internal/alice(a)fs.mydomain.com event(Event-Subclass=callmgr::call_uuid,Event-Name=CUSTOM) EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_h_Route=<sip:172.16.0.150:5063>) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_h_Route]=[<sip:172.16.0.150:5063>] EXECUTE sofia/internal/alice@fs.mydomain.combridge(sofia/gateway/bobspecial/0000100912345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/bob/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/navigata/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/lesnet/12345678;fs_path=sip:172.16.0.150:5063) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [dal-UUID]=[3a05956905ca41e2b43170968d44398e] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [dal-Language]=[en] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Time-Limit]=[118] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Time-Limit-Bye]=[you-have-reached-the-time-limit-for-this-call] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Time-Limit-Warnings]=[60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [execute_on_answer]=[lua mod_callmgr/on-bridge.lua] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Report-URL]=[http://todo-kkhan.dlcworldwide.com/index.php/internal/] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_ivr_originate.c:2078 Parsing global variables 2014-09-17 16:48:43.705898 [NOTICE] switch_channel.c:1053 New Channel sofia/internal/0000100912345678 [3b3c0b87-2c5b-42a0-9a78-90449685f296] 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:4565 (sofia/internal/0000100912345678) State Change CS_NEW -> CS_INIT 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:4635 [zrtp_passthru] Setting a-leg inherit_codec=true 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:4638 [zrtp_passthru] Setting b-leg absolute_codec_string='opus@48000h@20i,PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b' 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_INIT 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/0000100912345678) State INIT 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:87 sofia/internal/0000100912345678 SOFIA INIT 2014-09-17 16:48:43.705898 [DEBUG] sofia_glue.c:1197 sip:172.16.0.150:5063 Setting proxy route to sofia/internal/0000100912345678 2014-09-17 16:48:43.705898 [DEBUG] sofia_glue.c:1226 sofia/internal/0000100912345678 sending invite version: 1.4.6 git 9479729 2014-06-03 19:35:16Z 64bit Local SDP: v=0 o=FreeSWITCH 1410967571 1410967572 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 m=audio 26552 RTP/AVP 109 0 8 101 13 a=rtpmap:109 opus/48000/2 a=fmtp:109 useinbandfec=1;usedtx=1;maxaveragebitrate=30000;ptime=20;minptime=20;maxptime=20;samplerate=48000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:40 sofia/internal/0000100912345678 Standard INIT 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/0000100912345678) State Change CS_INIT -> CS_ROUTING 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/0000100912345678) State INIT going to sleep 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_ROUTING 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/0000100912345678) State ROUTING 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:123 sofia/internal/0000100912345678 SOFIA ROUTING 2014-09-17 16:48:43.705898 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/0000100912345678) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/0000100912345678) State ROUTING going to sleep 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_CONSUME_MEDIA 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:545 (sofia/internal/0000100912345678) State CONSUME_MEDIA 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:545 (sofia/internal/0000100912345678) State CONSUME_MEDIA going to sleep send 1513 bytes to udp/[172.16.0.150]:5063 at 16:48:43.720773: ------------------------------------------------------------------------ INVITE sip:0000100912345678@10.2.1.1 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.150:6090;rport;branch=z9hG4bKDytKNrBp1aDrQ Route: <sip:172.16.0.150:5063> Route: <sip:172.16.0.150:5063> Max-Forwards: 68 From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1> Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE Contact: <sip:gw+bobspecial@172.16.0.150:6090;transport=udp;gw=bobspecial> User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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: 390 X-FS-Support: update_display,send_info Remote-Party-ID: "Alice" <sip:17783315100@10.2.1.1>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1410967571 1410967572 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 m=audio 26552 RTP/AVP 109 0 8 101 13 a=rtpmap:109 opus/48000/2 a=fmtp:109 useinbandfec=1;usedtx=1;maxaveragebitrate=30000;ptime=20;minptime=20;maxptime=20;samplerate=48000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [calling][0] recv 577 bytes from udp/[172.16.0.150]:5063 at 16:48:43.819920: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.16.0.150:6090;rport=6090;branch=z9hG4bKDytKNrBp1aDrQ Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1> Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE User-Agent: bobPBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <sip:0000100912345678@10.2.1.1:5060> Content-Length: 0 ------------------------------------------------------------------------ recv 917 bytes from udp/[172.16.0.150]:5063 at 16:48:46.221310: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 172.16.0.150:6090;rport=6090;branch=z9hG4bKDytKNrBp1aDrQ Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE User-Agent: bobPBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <sip:0000100912345678@10.2.1.1:5060> Content-Type: application/sdp Content-Length: 282 v=0 o=root 27411 27411 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=nortpproxy:yes ------------------------------------------------------------------------ 2014-09-17 16:48:46.205889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:46.205889 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [proceeding][183] 2014-09-17 16:48:46.205889 [DEBUG] sofia.c:6239 Remote SDP: v=0 o=root 27411 27411 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=nortpproxy:yes 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[opus:116:48000:20:0] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3437 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMA:8:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[opus:116:48000:20:0] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3437 Audio Codec Compare [PCMA:8:8000:20:64000] ++++ is saved as a match 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3309 Set telephone-event payload to 101 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:2343 Set Codec sofia/internal/0000100912345678 PCMU/8000 20 ms 160 samples 64000 bits 2014-09-17 16:48:46.205889 [DEBUG] switch_core_codec.c:111 sofia/internal/0000100912345678 Original read codec set to PCMU:0 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3617 Set 2833 dtmf send payload to 101 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:4842 AUDIO RTP [sofia/internal/0000100912345678] 10.1.1.1 port 26552 -> 172.16.0.150 port 49198 codec: 0 ms: 20 2014-09-17 16:48:46.205889 [DEBUG] switch_rtp.c:3351 Starting timer [soft] 160 bytes per 20ms 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5189 Set 2833 dtmf send payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5195 Set 2833 dtmf receive payload to 101 2014-09-17 16:48:46.225921 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/0000100912345678! 2014-09-17 16:48:46.225921 [DEBUG] switch_channel.c:3391 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_channel.c:3395 (sofia/internal/0000100912345678) Callstate Change DOWN -> EARLY 2014-09-17 16:48:46.225921 [DEBUG] switch_ivr_originate.c:412 Setting codec string onsofia/internal/alice(a)fs.mydomain.com to PCMU@8000h@20i 2014-09-17 16:48:46.225921 [INFO] switch_ivr_originate.c:3500 Sending early media 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [opus:109:48000:20:0]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3437 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3309 Set telephone-event payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2343 Set Codec sofia/internal/alice(a)fs.mydomain.comPCMU/8000 20 ms 160 samples 64000 bits 2014-09-17 16:48:46.225921 [DEBUG] switch_core_codec.c:111 sofia/internal/alice(a)fs.mydomain.com Original read codec set to PCMU:0 2014-09-17 16:48:46.225921 [WARNING] switch_core_media.c:2548 NO candidate ACL defined, Defaulting to wan.auto 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 172.16.1.188:54467 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 172.16.1.188:54467 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: srflx addr: 10.1.1.2:54467 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2581 Choose audio Candidate cid: 1 proto: UDP type: srflx addr: 10.1.1.2:54467 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 192.168.56.1:54468 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.56.1:54468 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 192.168.232.1:54469 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.232.1:54469 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 192.168.146.1:54470 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.146.1:54470 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 172.16.1.188:54471 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 172.16.1.188:54471 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: srflx addr: 10.1.1.2:54471 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2581 Choose audio Candidate cid: 2 proto: UDP type: srflx addr: 10.1.1.2:54471 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 192.168.56.1:54472 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.56.1:54472 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 192.168.232.1:54473 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.232.1:54473 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 192.168.146.1:54474 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.146.1:54474 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2710 setting remote audio ice addr to 10.1.1.2:54467 based on candidate 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2730 setting remote rtcp audio addr to 10.1.1.2:54471 based on candidate 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3626 Set 2833 dtmf send/recv payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:4842 AUDIO RTP [sofia/internal/alice(a)fs.mydomain.com] 10.1.1.1 port 24858 -> 10.1.1.2 port 54467 codec: 0 ms: 20 2014-09-17 16:48:46.225921 [DEBUG] switch_rtp.c:3351 Starting timer [soft] 160 bytes per 20ms 2014-09-17 16:48:46.225921 [INFO] switch_core_media.c:5011 Activating Audio ICE 2014-09-17 16:48:46.225921 [NOTICE] switch_rtp.c:3792 Activating RTP audio ICE: 17e36105:JMJwWUvXyYRgIAHV 10.1.1.2:54467 2014-09-17 16:48:46.225921 [INFO] switch_core_media.c:5054 Activating RTCP PORT 54471 2014-09-17 16:48:46.225921 [DEBUG] switch_rtp.c:3697 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 54471 2014-09-17 16:48:46.225921 [DEBUG] switch_rtp.c:2170 Setting RTCP remote addr to 10.1.1.2:54471 2014-09-17 16:48:46.225921 [INFO] switch_core_media.c:5064 Activating RTCP ICE 2014-09-17 16:48:46.225921 [NOTICE] switch_rtp.c:3792 Activating RTCP audio ICE: 17e36105:JMJwWUvXyYRgIAHV 10.1.1.2:54471 2014-09-17 16:48:46.225921 [INFO] switch_rtp.c:2895 Activate RTP/RTCP audio DTLS client 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5189 Set 2833 dtmf send payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5195 Set 2833 dtmf receive payload to 101 2014-09-17 16:48:46.225921 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/alice(a)fs.mydomain.com! 2014-09-17 16:48:46.225921 [DEBUG] switch_channel.c:3395 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change RINGING -> EARLY 2014-09-17 16:48:46.225921 [DEBUG] mod_sofia.c:2222 Ring SDP: v=0 o=FreeSWITCH 1410969268 1410969269 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:2725252931 1 udp 659136 10.1.1.1 24858 typ host generation 0 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_ivr_originate.c:3551 Originate Resulted in Success: [sofia/internal/0000100912345678] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_ivr_bridge.c:1460 (sofia/internal/0000100912345678) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] send 2056 bytes to udp/[172.16.0.150]:5063 at 16:48:46.238673: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=99eQB5Zae5cee Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE Contact: <sip:+12345678@172.16.0.150:6090;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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: 799 X-DAL-UUID: 3a05956905ca41e2b43170968d44398e Remote-Party-ID: "Outbound Call" <sip:5063@fs.mydomain.com>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1410969268 1410969269 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:2725252931 1 udp 659136 10.1.1.1 24858 typ host generation 0 ------------------------------------------------------------------------ 2014-09-17 16:48:46.225921 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_state_machine.c:536 (sofia/internal/0000100912345678) State EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] mod_sofia.c:592 SOFIA EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [early][183] 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:2718 Changing audio DTLS state from HANDSHAKE to SETUP 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:2626 audio Fingerprint Verified. 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:3168 Activating Audio Secure RTP SEND 2014-09-17 16:48:47.305892 [DEBUG] switch_core_sqldb.c:2568 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:3146 Activating Audio Secure RTP RECV 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:2666 Changing audio DTLS state from SETUP to READY 2014-09-17 16:48:47.305892 [DEBUG] switch_core_sqldb.c:2568 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2014-09-17 16:48:47.545899 [INFO] switch_rtp.c:5554 Auto Changing port from 172.16.0.150:49198 to 10.1.1.1:49198 recv 903 bytes from udp/[172.16.0.150]:5063 at 16:48:54.507821: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.0.150:6090;rport=6090;branch=z9hG4bKDytKNrBp1aDrQ Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE User-Agent: bobPBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <sip:0000100912345678@10.2.1.1:5060> Content-Type: application/sdp Content-Length: 282 v=0 o=root 27411 27412 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=nortpproxy:yes ------------------------------------------------------------------------ 2014-09-17 16:48:54.505900 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.505900 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.526003 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [completing][200] 2014-09-17 16:48:54.526003 [DEBUG] sofia.c:6239 Remote SDP: v=0 o=root 27411 27412 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=nortpproxy:yes send 538 bytes to udp/[172.16.0.150]:5063 at 16:48:54.528674: ------------------------------------------------------------------------ ACK sip:0000100912345678@10.2.1.1:5060 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.150:6090;rport;branch=z9hG4bKe7KcQKvSyK3aK Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Max-Forwards: 70 From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 ACK Contact: <sip:gw+bobspecial@172.16.0.150:6090;transport=udp;gw=bobspecial> Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:54.526003 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.526003 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.526003 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [ready][200] 2014-09-17 16:48:54.545977 [DEBUG] switch_channel.c:3631 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK] 2014-09-17 16:48:54.545977 [NOTICE] sofia.c:6996 Channel [sofia/internal/0000100912345678] has been answered EXECUTE sofia/internal/0000100912345678 lua(mod_callmgr/on-bridge.lua) 2014-09-17 16:48:54.545977 [ERR] mod_lua.cpp:203 cannot open /home/kkhan/fsdevel/scripts/mod_callmgr/on-bridge.lua: No such file or directory 2014-09-17 16:48:54.545977 [DEBUG] switch_cpp.cpp:1056 sofia/internal/0000100912345678 destroy/unlink session from object 2014-09-17 16:48:54.545977 [DEBUG] switch_channel.c:3685 (sofia/internal/0000100912345678) Callstate Change EARLY -> ACTIVE 2014-09-17 16:48:54.545977 [DEBUG] mod_sofia.c:778 Local SDP sofia/internal/alice(a)fs.mydomain.com: v=0 o=FreeSWITCH 1410969268 1410969270 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:6961800946 1 udp 659136 10.1.1.1 24858 typ host generation 0 2014-09-17 16:48:54.545977 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.545977 [NOTICE] switch_ivr_bridge.c:496 Channel [sofia/internal/alice(a)fs.mydomain.com] has been answered send 2017 bytes to udp/[172.16.0.150]:5063 at 16:48:54.553616: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=99eQB5Zae5cee Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE Contact: <sip:+12345678@172.16.0.150:6090;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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: 799 X-DAL-UUID: 3a05956905ca41e2b43170968d44398e Remote-Party-ID: "Outbound Call" <sip:5063@fs.mydomain.com>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1410969268 1410969269 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:2725252931 1 udp 659136 10.1.1.1 24858 typ host generation 0 ------------------------------------------------------------------------ 2014-09-17 16:48:54.545977 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.545977 [DEBUG] switch_channel.c:3685 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change EARLY -> ACTIVE 2014-09-17 16:48:54.545977 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [completed][200] recv 1223 bytes from udp/[172.16.0.150]:5063 at 16:48:54.586519: ------------------------------------------------------------------------ ACK sip:+12345678@172.16.0.150:6090;transport=udp SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.b4fd273e140b6bfb8c10132eb6625886.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKsqO0MlTVFcWedViMF5yV;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=99eQB5Zae5cee Contact: "Alice"<sip:alice@10.1.1.2:64649;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr";received="sip:10.1.1.2:64649;transport=WS" Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 ACK Content-Length: 0 Max-Forwards: 69 Proxy-Authorization: Digest username="alice",realm="fs.mydomain.com",nonce="4c15231c-896a-4131-b7c2-621ab8342e9a",uri="sip:+12345678@172.16.0.150:6090;transport=udp",response="975327290415140c922c22a1c4c00f88",algorithm=MD5,cnonce="8dabac05b6f0a365d085158868220703",qop=auth,nc=00000002 User-Agent: IM-client/OMA1.0 sipML5-v1.0.0.0 Organization: Dingaling.ca Path: <sip:172.16.0.150:5063;lr> ------------------------------------------------------------------------ 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.585908 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [ready][200] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:969 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:969 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] recv 774 bytes from udp/[172.16.0.150]:5063 at 16:49:00.467309: ------------------------------------------------------------------------ BYE sip:gw+bobspecial@172.16.0.150:6090;transport=udp;gw=bobspecial SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK728.eb6d8a9209ac4e3ce276af87552fe9b7.0 Via: SIP/2.0/UDP 10.1.1.1:5063;rport=5063;branch=z9hG4bK728.5817c2e90986f57eeba11ed14bd3f311.0 Via: SIP/2.0/UDP 10.2.1.1:5060;rport=5060;branch=z9hG4bK11bbf59f From: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 To: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 102 BYE User-Agent: bobPBX Max-Forwards: 68 Content-Length: 0 Path: <sip:172.16.0.150:5063;lr> Path: <sip:172.16.0.150:5063;lr> ------------------------------------------------------------------------ 2014-09-17 16:49:00.465894 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [NOTICE] sofia.c:926 Hangup sofia/internal/0000100912345678 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2014-09-17 16:49:00.485939 [DEBUG] switch_channel.c:3218 Send signal sofia/internal/0000100912345678 [KILL] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] send 725 bytes to udp/[172.16.0.150]:5063 at 16:49:00.487587: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK728.eb6d8a9209ac4e3ce276af87552fe9b7.0;received=172.16.0.150 Via: SIP/2.0/UDP 10.1.1.1:5063;rport=5063;branch=z9hG4bK728.5817c2e90986f57eeba11ed14bd3f311.0 Via: SIP/2.0/UDP 10.2.1.1:5060;rport=5060;branch=z9hG4bK11bbf59f From: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 To: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 102 BYE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:659 BRIDGE THREAD DONE [sofia/internal/0000100912345678] 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:689 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:536 (sofia/internal/0000100912345678) State EXCHANGE_MEDIA going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:733 (sofia/internal/0000100912345678) Callstate Change ACTIVE -> HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/0000100912345678) State HANGUP 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:413 Channel sofia/internal/0000100912345678 hanging up, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:58 sofia/internal/0000100912345678 Standard HANGUP, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/0000100912345678) State HANGUP going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/0000100912345678) State Change CS_HANGUP -> CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/0000100912345678) State REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:102 sofia/internal/0000100912345678 Standard REPORTING, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/0000100912345678) State REPORTING going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:496 (sofia/internal/0000100912345678) State Change CS_REPORTING -> CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1614 Session 104 (sofia/internal/0000100912345678) Locked, Waiting on external entities 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:578 sofia/internal/0000100912345678 ending bridge by request from write function 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:659 BRIDGE THREAD DONE [sofia/internal/alice(a)fs.mydomain.com] 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:689 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1632 Session 104 (sofia/internal/0000100912345678) Ended 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1636 Close Channel sofia/internal/0000100912345678 [CS_DESTROY] 2014-09-17 16:49:00.485939 [NOTICE] switch_core_state_machine.c:313 sofia/internal/alice(a)fs.mydomain.com has executed the last dialplan instruction, hanging up. 2014-09-17 16:49:00.485939 [NOTICE] switch_core_state_machine.c:315 Hangup sofia/internal/alice(a)fs.mydomain.com[CS_EXECUTE] [NORMAL_CLEARING] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/0000100912345678) Running State Change CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/0000100912345678) State DESTROY 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:323 sofia/internal/0000100912345678 SOFIA DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_channel.c:3218 Send signal sofia/internal/alice(a)fs.mydomain.com [KILL] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:109 sofia/internal/0000100912345678 Standard DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/0000100912345678) State DESTROY going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:533 (sofia/internal/alice(a)fs.mydomain.com) State EXECUTE going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:733 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change ACTIVE -> HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/alice(a)fs.mydomain.com) State HANGUP 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:407 sofia/internal/alice(a)fs.mydomain.com Overriding SIP cause 480 with 200 from the other leg 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:413 Channel sofia/internal/alice(a)fs.mydomain.com hanging up, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/alice(a)fs.mydomain.com 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:58 sofia/internal/alice(a)fs.mydomain.com Standard HANGUP, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/alice(a)fs.mydomain.com) State HANGUP going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_HANGUP -> CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/alice(a)fs.mydomain.com) State REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:102 sofia/internal/alice(a)fs.mydomain.com Standard REPORTING, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/alice(a)fs.mydomain.com) State REPORTING going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:496 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_REPORTING -> CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1614 Session 103 (sofia/internal/alice(a)fs.mydomain.com) Locked, Waiting on external entities 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1632 Session 103 (sofia/internal/alice(a)fs.mydomain.com) Ended 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1636 Close Channel sofia/internal/alice(a)fs.mydomain.com[CS_DESTROY] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/alice(a)fs.mydomain.com) State DESTROY 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:323 sofia/internal/alice(a)fs.mydomain.com SOFIA DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:109 sofia/internal/alice(a)fs.mydomain.com Standard DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/alice(a)fs.mydomain.com) State DESTROY going to sleep From: freeswitch-users-request(a)lists.freeswitch.org Subject: FreeSWITCH-users Digest, Vol 99, Issue 146 To: freeswitch-users(a)lists.freeswitch.org Date: Thu, 18 Sep 2014 02:29:41 +0400 Send FreeSWITCH-users mailing list submissions to freeswitch-users(a)lists.freeswitch.org To subscribe or unsubscribe via the World Wide Web, visit http://lists.freeswitch.org/mailman/listinfo/freeswitch-users or, via email, send a message with subject or body 'help' to freeswitch-users-request(a)lists.freeswitch.org You can reach the person managing the list at freeswitch-users-owner(a)lists.freeswitch.org When replying, please edit your Subject line so it is more specific than "Re: Contents of FreeSWITCH-users digest..." --Forwarded Message Attachment-- From: wstephen80(a)gmail.com To: freeswitch-users(a)lists.freeswitch.org Date: Wed, 17 Sep 2014 22:58:23 +0200 Subject: Re: [Freeswitch-users] Call released with a 200 OK I have a trace of one leg only I can try to capture both legs.But a 200 OK with a Reason header is a valid SIP message (below 200 OK forwarded by FreeSWITCH) ? Frame 5: 957 bytes on wire (7656 bits), 957 bytes captured (7656 bits)Ethernet II, Src: Hewlett-_f3:e9:2c (3c:d9:2b:f3:e9:2c), Dst: JuniperN_f6:ce:27 (78:19:f7:f6:ce:27)Internet Protocol Version 4, Src: FreeSWITCH_IP (FreeSWITCH_IP), Dst: CUSTOMER_IP (CUSTOMER_IP)User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)Session Initiation Protocol (200) Status-Line: SIP/2.0 200 OK Message Header Via: SIP/2.0/UDP CUSTOMER_IP:5060;branch=z9hG4bK00E0F510095D15ED848E0A88725A Max-Forwards: 63 From: <sip:cg@FreeSWITCH_IP>;tag=00E0F510095D15ED848E7A60E97C To: <sip:cd@FreeSWITCH_IP>;tag=5881vaN1reajB Call-ID: ae8f80003582-5417017f-60871148-3ad46cc0-745bf31(a)127.0.0.1 CSeq: 14398 INVITE Contact: <sip:cd@FreeSWITCH_IP:5060;transport=udp> User-Agent: FS_1.2 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Type: application/sdp Content-Disposition: session Content-Length: 217 Message Body On Wed, Sep 17, 2014 at 10:09 PM, Steven Ayre <steveayre(a)gmail.com> wrote: Can you post the sip trace for the call (all legs) On 17 September 2014 19:54, Stephen Wilde <wstephen80(a)gmail.com> wrote: Anyone can help me on that? Stephen On Tue, Sep 16, 2014 at 9:58 PM, Stephen Wilde <wstephen80(a)gmail.com> wrote: I have a strange issue: some calls are dropped with a 200 OK containing the "Reason" header. Is this valid?The message flow is: CUSTOMER ---- FS INVITE -> <- 100 Trying <- 180 Ringing <- 200 OK (containing the Reason Header) ACK -> after some seconds... BYE ->BYE ->BYE ->BYE ->BYE -> The 200 OK sent by FreeSwitch contain a "Reason Header": Reason: Q.850;cause=16;text="NORMAL_CLEARING" And the call seems dropped and not connected in FreeSWITCH.For the customer side the call seems connected with 200 OK (the customer ignore the Reason).After some seconds, the customer try to disconnect the call with BYE but these messages are ignored by Freeswitch because the call was been already dropped. It's valid the Reason inside the 200 OK? It's possible that this 200 OK has been forwarded by Freeswitch from the outbound leg.Any advice for that? Stephen _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org --Forwarded Message Attachment-- From: steveayre(a)gmail.com To: freeswitch-users(a)lists.freeswitch.org Date: Wed, 17 Sep 2014 23:28:37 +0100 Subject: Re: [Freeswitch-users] Call released with a 200 OK rfc3326 - I believe it's valid in any packet, you can potentially have a Reason passed back before the end of the call. It's the BYE that's hanging up the call not the 200 OK, but that could be an interop problem where a device doesn't expect the Reason in the 200 OK. On 17 September 2014 21:58, Stephen Wilde <wstephen80(a)gmail.com> wrote: I have a trace of one leg only I can try to capture both legs.But a 200 OK with a Reason header is a valid SIP message (below 200 OK forwarded by FreeSWITCH) ? Frame 5: 957 bytes on wire (7656 bits), 957 bytes captured (7656 bits)Ethernet II, Src: Hewlett-_f3:e9:2c (3c:d9:2b:f3:e9:2c), Dst: JuniperN_f6:ce:27 (78:19:f7:f6:ce:27)Internet Protocol Version 4, Src: FreeSWITCH_IP (FreeSWITCH_IP), Dst: CUSTOMER_IP (CUSTOMER_IP)User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)Session Initiation Protocol (200) Status-Line: SIP/2.0 200 OK Message Header Via: SIP/2.0/UDP CUSTOMER_IP:5060;branch=z9hG4bK00E0F510095D15ED848E0A88725A Max-Forwards: 63 From: <sip:cg@FreeSWITCH_IP>;tag=00E0F510095D15ED848E7A60E97C To: <sip:cd@FreeSWITCH_IP>;tag=5881vaN1reajB Call-ID: ae8f80003582-5417017f-60871148-3ad46cc0-745bf31(a)127.0.0.1 CSeq: 14398 INVITE Contact: <sip:cd@FreeSWITCH_IP:5060;transport=udp> User-Agent: FS_1.2 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Type: application/sdp Content-Disposition: session Content-Length: 217 Message Body On Wed, Sep 17, 2014 at 10:09 PM, Steven Ayre <steveayre(a)gmail.com> wrote: Can you post the sip trace for the call (all legs) On 17 September 2014 19:54, Stephen Wilde <wstephen80(a)gmail.com> wrote: Anyone can help me on that? Stephen On Tue, Sep 16, 2014 at 9:58 PM, Stephen Wilde <wstephen80(a)gmail.com> wrote: I have a strange issue: some calls are dropped with a 200 OK containing the "Reason" header. Is this valid?The message flow is: CUSTOMER ---- FS INVITE -> <- 100 Trying <- 180 Ringing <- 200 OK (containing the Reason Header) ACK -> after some seconds... BYE ->BYE ->BYE ->BYE ->BYE -> The 200 OK sent by FreeSwitch contain a "Reason Header": Reason: Q.850;cause=16;text="NORMAL_CLEARING" And the call seems dropped and not connected in FreeSWITCH.For the customer side the call seems connected with 200 OK (the customer ignore the Reason).After some seconds, the customer try to disconnect the call with BYE but these messages are ignored by Freeswitch because the call was been already dropped. It's valid the Reason inside the 200 OK? It's possible that this 200 OK has been forwarded by Freeswitch from the outbound leg.Any advice for that? Stephen _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org -- Brian West brian(a)freeswitch.org Twitter: @FreeSWITCH , @briankwest http://www.freeswitchbook.com http://www.freeswitchcookbook.com T:+19184209001 | F:+19184209002 | M:+1918424WEST (9378) iNUM:+883 5100 1420 9001 | ISN:410*543 | Skype:briankwest

4 3

Re: [Freeswitch-users] FreeSWITCH-users Digest, Vol 99, Issue 167
by Kamrul Khan 22 Sep '14

22 Sep '14

***Guessing it's either having trouble parsing this or sending to 10.1.1.2 How to detect or troubleshoot that? I got the below in my console log: 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/alice(a)fs.mydomain.comDoesn't it mean its parsing correctly ? (just a guess)***Looks like your packet trace receives from Alice on 172.16.0.150 which is FS - I assume you have a proxy inbetween?10.1.1.2 is my proxy server. Theres no proxy server in-between 10.1.1.2 and freeswitch. If it is the proxy issue, why only BYE is not being sent, All other packets are working perfectly. --Forwarded Message Attachment-- From: steveayre(a)gmail.com To: freeswitch-users(a)lists.freeswitch.org Date: Fri, 19 Sep 2014 12:30:17 +0100 Subject: Re: [Freeswitch-users] FreeSWITCH not sending BYE BYE gets sent to the Contact header. Contact: "Alice"<sip:alice@10.1.1.2:64649;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr";received="sip:10.1.1.2:64649;transport=WS" Guessing it's either having trouble parsing this or sending to 10.1.1.2 Looks like your packet trace receives from Alice on 172.16.0.150 which is FS - I assume you have a proxy inbetween? On 19 September 2014 00:49, Kamrul Khan <dodul(a)live.com> wrote: Its in public network. OK. heres the log after setting log level to 9 . Please check the below console log. Hope it gives some more clues. 2014-09-18 17:39:10.825909 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/alice@fs.mydomain.comnua.c:645 nua_bye() nua: nua_bye: enteringnua_stack.c:529 nua_signal() nua(0x7f16a83a5240): sent signal r_bye2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:58 sofia/internal/alice(a)fs.mydomain.com Standard HANGUP, cause: NORMAL_CLEARINGnua_stack.c:569 nua_stack_signal() nua(0x7f16a83a5240): recv signal r_bye2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/alice(a)fs.mydomain.com) State HANGUP going to sleepnua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: enteringsoa.c:403 soa_set_params() soa_set_params(static::0x7f16b0135890, ...) calledsoa.c:1784 soa_terminate() soa_terminate(static::0x7f16b0135890) calledsoa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f16b0135890) callednta.c:2665 nta_tpn_by_url() nta: selecting scheme sipnta.c:8132 outgoing_prepare_send() nta outgoing create: no transport protocolnta.c:1348 set_timeout() nta: timer shortened to 5000 ms2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_HANGUP -> CS_REPORTINGnua_stack.c:271 nua_stack_event() nua(0x7f16a83a5240): event r_bye 503 No transport2014-09-18 17:39:10.825909 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK]nua_session.c:4137 signal_call_state_change() nua(0x7f16a83a5240): call state changed: terminating -> terminatednua_stack.c:271 nua_stack_event() nua(0x7f16a83a5240): event i_state 503 to BYEnua_stack.c:271 nua_stack_event() nua(0x7f16a83a5240): event i_terminated 503 to BYEnua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f16a83a5240): removing session usagesoa.c:356 soa_destroy() soa_destroy(static::0x7f16b0135890) callednta.c:4468 nta_leg_destroy() nta_leg_destroy(0x7f16b40f0940)nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f16a83a5240nua_stack.c:359 nua_application_event() nua: nua_application_event: enteringnua_stack.c:359 nua_application_event() nua: nua_application_event: enteringnua_stack.c:359 nua_application_event() nua: nua_application_event: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:342 nua_handle_bind() nua: nua_handle_bind: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: entering2014-09-18 17:39:10.825909 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_REPORTINGnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:921 nua_handle_destroy() nua: nua_handle_destroy: enteringnua_stack.c:529 nua_signal() nua(0x7f16a83a5240): sent signal r_destroynua_stack.c:569 nua_stack_signal() nua(0x7f16a83a5240): recv signal r_destroynta.c:4468 nta_leg_destroy() nta_leg_destroy((nil)) From: freeswitch-users-request(a)lists.freeswitch.org Subject: FreeSWITCH-users Digest, Vol 99, Issue 165 To: freeswitch-users(a)lists.freeswitch.org Date: Fri, 19 Sep 2014 02:10:52 +0400 Send FreeSWITCH-users mailing list submissions to freeswitch-users(a)lists.freeswitch.org To subscribe or unsubscribe via the World Wide Web, visit http://lists.freeswitch.org/mailman/listinfo/freeswitch-users or, via email, send a message with subject or body 'help' to freeswitch-users-request(a)lists.freeswitch.org You can reach the person managing the list at freeswitch-users-owner(a)lists.freeswitch.org When replying, please edit your Subject line so it is more specific than "Re: Contents of FreeSWITCH-users digest..." --Forwarded Message Attachment-- From: brian(a)freeswitch.org To: freeswitch-users(a)lists.freeswitch.org Date: Thu, 18 Sep 2014 17:10:20 -0500 Subject: Re: [Freeswitch-users] FreeSWITCH not sending BYE sofia loglevel all 9 Is this local network or over the public internet? On Thu, Sep 18, 2014 at 4:52 PM, Kamrul Khan <dodul(a)live.com> wrote: I checked the sofia debug. Didnt get anything interesting. Is there some other reason why it might be happening ? From: freeswitch-users-request(a)lists.freeswitch.org Subject: FreeSWITCH-users Digest, Vol 99, Issue 162 To: freeswitch-users(a)lists.freeswitch.org Date: Fri, 19 Sep 2014 00:13:50 +0400 Send FreeSWITCH-users mailing list submissions to freeswitch-users(a)lists.freeswitch.org To subscribe or unsubscribe via the World Wide Web, visit http://lists.freeswitch.org/mailman/listinfo/freeswitch-users or, via email, send a message with subject or body 'help' to freeswitch-users-request(a)lists.freeswitch.org You can reach the person managing the list at freeswitch-users-owner(a)lists.freeswitch.org When replying, please edit your Subject line so it is more specific than "Re: Contents of FreeSWITCH-users digest..." --Forwarded Message Attachment-- From: steveayre(a)gmail.com To: freeswitch-users(a)lists.freeswitch.org Date: Thu, 18 Sep 2014 21:12:48 +0100 Subject: Re: [Freeswitch-users] FreeSWITCH not sending BYE Turn on the sofia stack debugging - perhaps that'll show an error within the stack where the stack is told to send bye but fails to do so. On 18 September 2014 17:52, Kamrul Khan <dodul(a)live.com> wrote: Hi,As you can see from the trace all the other packets are passing fine. Its just the BYE message thats not being sent. I just found the below line from my console log:2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/alice(a)fs.mydomain.com So, the log says its sending BYE, but in reality it sends nothing. Any idea whats happening? please help. --Forwarded Message Attachment-- From: mike(a)jerris.com To: freeswitch-users(a)lists.freeswitch.org Date: Wed, 17 Sep 2014 21:32:03 -0400 Subject: Re: [Freeswitch-users] FreeSWITCH not sending BYE something is wrong here... all of the sip packets are coming from and going to the IP address of the freeswitch box? On Sep 17, 2014, at 7:06 PM, Kamrul Khan <dodul(a)live.com> wrote: Hi, Im using freeswitch version 1.4.6. Its not sending back any BYE message. So the caller side thinks call is still alive. The scenario is like the below: Alice(10.1.1.1) ---> Freeswitch(172.16.0.150)--->Bob(10.2.1.1) If the call is terminated by Bob. Bob sends BYE to Freeswitch. but, Freeswitch simply sends back a 200 OK to BOB and drops the call. Doesnt send back any BYE to Alice. Therefore, Alice thinks the Call is still alive. How to fix this. HELP!!! Check my My SIP TRACE: ------------------------------------------------------------------------ recv 2234 bytes from udp/[172.16.0.150]:5063 at 16:48:42.959303: ------------------------------------------------------------------------ INVITE sip:+12345678@fs.mydomain.com SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Contact: "Alice"<sip:alice@10.1.1.2:64649;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr";received="sip:10.1.1.2:64649;transport=WS" Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 INVITE Content-Type: application/sdp Content-Length: 1262 Max-Forwards: 69 User-Agent: IM-client/OMA1.0 sipML5-v1.0.0.0 Organization: Dingaling.ca Path: <sip:172.16.0.150:5063;lr> v=0 o=Mozilla-SIPUA-31.0 322 1 IN IP4 0.0.0.0 s=Doubango Telecom - firefox t=0 0 a=ice-ufrag:17e36105 a=ice-pwd:35179857c2c39018fb82455091801d8a a=fingerprint:sha-256 68:54:EE:EF:A0:BF:93:B9:B6:63:18:0F:C1:A1:BE:5C:6F:49:11:67:1A:88:2D:DC:20:09:80:92:A4:4C:5A:F1 m=audio 60678 UDP/TLS/RTP/SAVPF 109 0 8 101 c=IN IP4 172.16.0.150 a=rtpmap:109 opus/48000/2 a=ptime:20 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=setup:actpass a=candidate:0 1 UDP 2128609535 172.16.1.188 54467 typ host a=candidate:2 1 UDP 1692467199 10.1.1.2 54467 typ srflx raddr 172.16.1.188 rport 54467 a=candidate:5 1 UDP 2128543999 192.168.56.1 54468 typ host a=candidate:10 1 UDP 2128478463 192.168.232.1 54469 typ host a=candidate:15 1 UDP 2128412927 192.168.146.1 54470 typ host a=candidate:0 2 UDP 2128609534 172.16.1.188 54471 typ host a=candidate:1 2 UDP 1692467198 10.1.1.2 54471 typ srflx raddr 172.16.1.188 rport 54471 a=candidate:5 2 UDP 2128543998 192.168.56.1 54472 typ host a=candidate:10 2 UDP 2128478462 192.168.232.1 54473 typ host a=candidate:15 2 UDP 2128412926 192.168.146.1 54474 typ host a=rtcp-mux a=nortpproxy:yes ------------------------------------------------------------------------ send 619 bytes to udp/[172.16.0.150]:5063 at 16:48:42.959974: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:42.945889 [NOTICE] switch_channel.c:1053 New Channel sofia/internal/alice(a)fs.mydomain.com[76f1d37a-b4c0-4247-9fb2-45cf6eadd969] 2014-09-17 16:48:42.945889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.945889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.945889 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_NEW 2014-09-17 16:48:42.945889 [DEBUG] sofia.c:8367 sofia/internal/alice(a)fs.mydomain.com receiving invite from 172.16.0.150:5063 version: 1.4.6 git 9479729 2014-06-03 19:35:16Z 64bit 2014-09-17 16:48:42.945889 [DEBUG] sofia.c:8534 IP 172.16.0.150 Rejected by acl "domains". Falling back to Digest auth. 2014-09-17 16:48:42.945889 [DEBUG] switch_core_state_machine.c:489 (sofia/internal/alice(a)fs.mydomain.com) State NEW send 1069 bytes to udp/[172.16.0.150]:5063 at 16:48:42.962202: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=80Ny99e7gvpUj Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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 Proxy-Authenticate: Digest realm="fs.mydomain.com", nonce="4c15231c-896a-4131-b7c2-621ab8342e9a", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:42.945889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.945889 [DEBUG] sofia.c:2033 detaching session 76f1d37a-b4c0-4247-9fb2-45cf6eadd969 recv 615 bytes from udp/[172.16.0.150]:5063 at 16:48:42.998781: ------------------------------------------------------------------------ ACK sip:+12345678@fs.mydomain.com SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK92c.41e977c95ac87d15f0c4b613d3349799.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKQ3XukR17yfTyWXoEF01daB399SarZSUQ;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=80Ny99e7gvpUj Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10769 ACK Content-Length: 0 Max-Forwards: 69 Path: <sip:172.16.0.150:5063;lr> ------------------------------------------------------------------------ recv 2543 bytes from udp/[172.16.0.150]:5063 at 16:48:43.004244: ------------------------------------------------------------------------ INVITE sip:+12345678@fs.mydomain.com SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Contact: "Alice"<sip:alice@10.1.1.2:64649;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr";received="sip:10.1.1.2:64649;transport=WS" Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE Content-Type: application/sdp Content-Length: 1262 Max-Forwards: 69 Proxy-Authorization: Digest username="alice",realm="fs.mydomain.com",nonce="4c15231c-896a-4131-b7c2-621ab8342e9a",uri="sip:+12345678@fs.mydomain.com",response="3f71cf991c76159a30fe0fbea938cbb9",algorithm=MD5,cnonce="8dabac05b6f0a365d085158868220703",qop=auth,nc=00000001 User-Agent: IM-client/OMA1.0 sipML5-v1.0.0.0 Organization: Dingaling.ca Path: <sip:172.16.0.150:5063;lr> v=0 o=Mozilla-SIPUA-31.0 322 1 IN IP4 0.0.0.0 s=Doubango Telecom - firefox t=0 0 a=ice-ufrag:17e36105 a=ice-pwd:35179857c2c39018fb82455091801d8a a=fingerprint:sha-256 68:54:EE:EF:A0:BF:93:B9:B6:63:18:0F:C1:A1:BE:5C:6F:49:11:67:1A:88:2D:DC:20:09:80:92:A4:4C:5A:F1 m=audio 38168 UDP/TLS/RTP/SAVPF 109 0 8 101 c=IN IP4 172.16.0.150 a=rtpmap:109 opus/48000/2 a=ptime:20 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=setup:actpass a=candidate:0 1 UDP 2128609535 172.16.1.188 54467 typ host a=candidate:2 1 UDP 1692467199 10.1.1.2 54467 typ srflx raddr 172.16.1.188 rport 54467 a=candidate:5 1 UDP 2128543999 192.168.56.1 54468 typ host a=candidate:10 1 UDP 2128478463 192.168.232.1 54469 typ host a=candidate:15 1 UDP 2128412927 192.168.146.1 54470 typ host a=candidate:0 2 UDP 2128609534 172.16.1.188 54471 typ host a=candidate:1 2 UDP 1692467198 10.1.1.2 54471 typ srflx raddr 172.16.1.188 rport 54471 a=candidate:5 2 UDP 2128543998 192.168.56.1 54472 typ host a=candidate:10 2 UDP 2128478462 192.168.232.1 54473 typ host a=candidate:15 2 UDP 2128412926 192.168.146.1 54474 typ host a=rtcp-mux a=nortpproxy:yes ------------------------------------------------------------------------ send 619 bytes to udp/[172.16.0.150]:5063 at 16:48:43.005058: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com> Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:42.985935 [DEBUG] sofia.c:2138 Re-attaching to session 76f1d37a-b4c0-4247-9fb2-45cf6eadd969 2014-09-17 16:48:42.985935 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:42.985935 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.005913 [DEBUG] sofia.c:8367 sofia/internal/alice(a)fs.mydomain.com receiving invite from 172.16.0.150:5063 version: 1.4.6 git 9479729 2014-06-03 19:35:16Z 64bit 2014-09-17 16:48:43.005913 [DEBUG] sofia.c:8534 IP 172.16.0.150 Rejected by acl "domains". Falling back to Digest auth. 2014-09-17 16:48:43.285898 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [received][100] 2014-09-17 16:48:43.285898 [DEBUG] sofia.c:6239 Remote SDP: v=0 o=Mozilla-SIPUA-31.0 322 1 IN IP4 0.0.0.0 s=Doubango Telecom - firefox t=0 0 a=ice-ufrag:17e36105 a=ice-pwd:35179857c2c39018fb82455091801d8a a=fingerprint:sha-256 68:54:EE:EF:A0:BF:93:B9:B6:63:18:0F:C1:A1:BE:5C:6F:49:11:67:1A:88:2D:DC:20:09:80:92:A4:4C:5A:F1 m=audio 38168 UDP/TLS/RTP/SAVPF 109 0 8 101 c=IN IP4 172.16.0.150 a=rtpmap:109 opus/48000/2 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=setup:actpass a=candidate:0 1 UDP 2128609535 172.16.1.188 54467 typ host a=candidate:2 1 UDP 1692467199 10.1.1.2 54467 typ srflx raddr 172.16.1.188 rport 54467 a=candidate:5 1 UDP 2128543999 192.168.56.1 54468 typ host a=candidate:10 1 UDP 2128478463 192.168.232.1 54469 typ host a=candidate:15 1 UDP 2128412927 192.168.146.1 54470 typ host a=candidate:0 2 UDP 2128609534 172.16.1.188 54471 typ host a=candidate:1 2 UDP 1692467198 10.1.1.2 54471 typ srflx raddr 172.16.1.188 rport 54471 a=candidate:5 2 UDP 2128543998 192.168.56.1 54472 typ host a=candidate:10 2 UDP 2128478462 192.168.232.1 54473 typ host a=candidate:15 2 UDP 2128412926 192.168.146.1 54474 typ host a=rtcp-mux a=nortpproxy:yes 2014-09-17 16:48:43.285898 [DEBUG] sofia.c:6494 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_NEW -> CS_INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/alice(a)fs.mydomain.com) State INIT 2014-09-17 16:48:43.285898 [DEBUG] mod_sofia.c:87 sofia/internal/alice(a)fs.mydomain.com SOFIA INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:40 sofia/internal/alice(a)fs.mydomain.com Standard INIT 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_INIT -> CS_ROUTING 2014-09-17 16:48:43.285898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/alice(a)fs.mydomain.com) State INIT going to sleep 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_ROUTING 2014-09-17 16:48:43.285898 [DEBUG] switch_channel.c:2180 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change DOWN -> RINGING 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/alice(a)fs.mydomain.com) State ROUTING 2014-09-17 16:48:43.285898 [DEBUG] mod_sofia.c:123 sofia/internal/alice(a)fs.mydomain.com SOFIA ROUTING 2014-09-17 16:48:43.285898 [DEBUG] switch_core_state_machine.c:164 sofia/internal/alice(a)fs.mydomain.com Standard ROUTING 2014-09-17 16:48:43.285898 [INFO] mod_dialplan_xml.c:558 Processing Alice <alice>->+12345678 in context dal-ingress Dialplan: sofia/internal/alice(a)fs.mydomain.com parsing [dal-ingress->3a05956905ca41e2b43170968d44398e] continue=false Dialplan: sofia/internal/alice(a)fs.mydomain.com Absolute Condition [3a05956905ca41e2b43170968d44398e] Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(dal-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(dal-Language=en) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(effective_caller_id_number=17783315100) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(effective_caller_id_name=Alice) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_rh_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_ph_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_bye_h_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Time-Limit=118) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Time-Limit-Bye=you-have-reached-the-time-limit-for-this-call) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Time-Limit-Warnings=60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(nolocal:execute_on_answer=lua mod_callmgr/on-bridge.lua) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action export(DAL-Report-URL=http://todo-kkhan.dlcworldwide.com/index.php/internal… Dialplan: sofia/internal/alice(a)fs.mydomain.com Action event(Event-Subclass=callmgr::call_uuid,Event-Name=CUSTOM) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action set(sip_h_Route=<sip:172.16.0.150:5063>) Dialplan: sofia/internal/alice(a)fs.mydomain.com Action bridge(sofia/gateway/bobspecial/0000100912345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/bob/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/navigata/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/lesnet/12345678;fs_path=sip:172.16.0.150:5063) 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:214 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_ROUTING -> CS_EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/alice(a)fs.mydomain.com) State ROUTING going to sleep 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:533 (sofia/internal/alice(a)fs.mydomain.com) State EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:178 sofia/internal/alice(a)fs.mydomain.com SOFIA EXECUTE 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:256 sofia/internal/alice(a)fs.mydomain.com Standard EXECUTE EXECUTE sofia/internal/alice(a)fs.mydomain.com export(dal-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [dal-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(dal-Language=en) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [dal-Language]=[en] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(effective_caller_id_number=17783315100) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [effective_caller_id_number]=[17783315100] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(effective_caller_id_name=Alice) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [effective_caller_id_name]=[Alice] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_rh_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_rh_X-DAL-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_ph_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_ph_X-DAL-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_bye_h_X-DAL-UUID=3a05956905ca41e2b43170968d44398e) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_bye_h_X-DAL-UUID]=[3a05956905ca41e2b43170968d44398e] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Time-Limit=118) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Time-Limit]=[118] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Time-Limit-Bye=you-have-reached-the-time-limit-for-this-call) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Time-Limit-Bye]=[you-have-reached-the-time-limit-for-this-call] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Time-Limit-Warnings=60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Time-Limit-Warnings]=[60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(nolocal:execute_on_answer=lua mod_callmgr/on-bridge.lua) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) (REMOTE ONLY) [execute_on_answer]=[lua mod_callmgr/on-bridge.lua] EXECUTE sofia/internal/alice(a)fs.mydomain.com export(DAL-Report-URL=http://todo-kkhan.dlcworldwide.com/index.php/internal… 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1245 EXPORT (export_vars) [DAL-Report-URL]=[http://todo-kkhan.dlcworldwide.com/index.php/internal/] EXECUTE sofia/internal/alice(a)fs.mydomain.com event(Event-Subclass=callmgr::call_uuid,Event-Name=CUSTOM) EXECUTE sofia/internal/alice(a)fs.mydomain.com set(sip_h_Route=<sip:172.16.0.150:5063>) 2014-09-17 16:48:43.705898 [DEBUG] mod_dptools.c:1435 sofia/internal/alice(a)fs.mydomain.com SET [sip_h_Route]=[<sip:172.16.0.150:5063>] EXECUTE sofia/internal/alice@fs.mydomain.combridge(sofia/gateway/bobspecial/0000100912345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/bob/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/navigata/12345678;fs_path=sip:172.16.0.150:5063|sofia/gateway/lesnet/12345678;fs_path=sip:172.16.0.150:5063) 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [dal-UUID]=[3a05956905ca41e2b43170968d44398e] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [dal-Language]=[en] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Time-Limit]=[118] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Time-Limit-Bye]=[you-have-reached-the-time-limit-for-this-call] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Time-Limit-Warnings]=[60@aleg:you-have-one-minute-remaining,300@aleg:you-have-five-minutes-remaining-for-this-call] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [execute_on_answer]=[lua mod_callmgr/on-bridge.lua] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_channel.c:1199 sofia/internal/alice(a)fs.mydomain.comEXPORTING[export_vars] [DAL-Report-URL]=[http://todo-kkhan.dlcworldwide.com/index.php/internal/] to event 2014-09-17 16:48:43.705898 [DEBUG] switch_ivr_originate.c:2078 Parsing global variables 2014-09-17 16:48:43.705898 [NOTICE] switch_channel.c:1053 New Channel sofia/internal/0000100912345678 [3b3c0b87-2c5b-42a0-9a78-90449685f296] 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:4565 (sofia/internal/0000100912345678) State Change CS_NEW -> CS_INIT 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:4635 [zrtp_passthru] Setting a-leg inherit_codec=true 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:4638 [zrtp_passthru] Setting b-leg absolute_codec_string='opus@48000h@20i,PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b' 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_INIT 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/0000100912345678) State INIT 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:87 sofia/internal/0000100912345678 SOFIA INIT 2014-09-17 16:48:43.705898 [DEBUG] sofia_glue.c:1197 sip:172.16.0.150:5063 Setting proxy route to sofia/internal/0000100912345678 2014-09-17 16:48:43.705898 [DEBUG] sofia_glue.c:1226 sofia/internal/0000100912345678 sending invite version: 1.4.6 git 9479729 2014-06-03 19:35:16Z 64bit Local SDP: v=0 o=FreeSWITCH 1410967571 1410967572 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 m=audio 26552 RTP/AVP 109 0 8 101 13 a=rtpmap:109 opus/48000/2 a=fmtp:109 useinbandfec=1;usedtx=1;maxaveragebitrate=30000;ptime=20;minptime=20;maxptime=20;samplerate=48000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:40 sofia/internal/0000100912345678 Standard INIT 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/0000100912345678) State Change CS_INIT -> CS_ROUTING 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:510 (sofia/internal/0000100912345678) State INIT going to sleep 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_ROUTING 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/0000100912345678) State ROUTING 2014-09-17 16:48:43.705898 [DEBUG] mod_sofia.c:123 sofia/internal/0000100912345678 SOFIA ROUTING 2014-09-17 16:48:43.705898 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/0000100912345678) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:526 (sofia/internal/0000100912345678) State ROUTING going to sleep 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_CONSUME_MEDIA 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:545 (sofia/internal/0000100912345678) State CONSUME_MEDIA 2014-09-17 16:48:43.705898 [DEBUG] switch_core_state_machine.c:545 (sofia/internal/0000100912345678) State CONSUME_MEDIA going to sleep send 1513 bytes to udp/[172.16.0.150]:5063 at 16:48:43.720773: ------------------------------------------------------------------------ INVITE sip:0000100912345678@10.2.1.1 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.150:6090;rport;branch=z9hG4bKDytKNrBp1aDrQ Route: <sip:172.16.0.150:5063> Route: <sip:172.16.0.150:5063> Max-Forwards: 68 From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1> Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE Contact: <sip:gw+bobspecial@172.16.0.150:6090;transport=udp;gw=bobspecial> User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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: 390 X-FS-Support: update_display,send_info Remote-Party-ID: "Alice" <sip:17783315100@10.2.1.1>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1410967571 1410967572 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 m=audio 26552 RTP/AVP 109 0 8 101 13 a=rtpmap:109 opus/48000/2 a=fmtp:109 useinbandfec=1;usedtx=1;maxaveragebitrate=30000;ptime=20;minptime=20;maxptime=20;samplerate=48000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2014-09-17 16:48:43.705898 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:43.705898 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [calling][0] recv 577 bytes from udp/[172.16.0.150]:5063 at 16:48:43.819920: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.16.0.150:6090;rport=6090;branch=z9hG4bKDytKNrBp1aDrQ Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1> Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE User-Agent: bobPBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <sip:0000100912345678@10.2.1.1:5060> Content-Length: 0 ------------------------------------------------------------------------ recv 917 bytes from udp/[172.16.0.150]:5063 at 16:48:46.221310: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 172.16.0.150:6090;rport=6090;branch=z9hG4bKDytKNrBp1aDrQ Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE User-Agent: bobPBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <sip:0000100912345678@10.2.1.1:5060> Content-Type: application/sdp Content-Length: 282 v=0 o=root 27411 27411 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=nortpproxy:yes ------------------------------------------------------------------------ 2014-09-17 16:48:46.205889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:46.205889 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [proceeding][183] 2014-09-17 16:48:46.205889 [DEBUG] sofia.c:6239 Remote SDP: v=0 o=root 27411 27411 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=nortpproxy:yes 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[opus:116:48000:20:0] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3437 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMA:8:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[opus:116:48000:20:0] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3437 Audio Codec Compare [PCMA:8:8000:20:64000] ++++ is saved as a match 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3309 Set telephone-event payload to 101 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:2343 Set Codec sofia/internal/0000100912345678 PCMU/8000 20 ms 160 samples 64000 bits 2014-09-17 16:48:46.205889 [DEBUG] switch_core_codec.c:111 sofia/internal/0000100912345678 Original read codec set to PCMU:0 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:3617 Set 2833 dtmf send payload to 101 2014-09-17 16:48:46.205889 [DEBUG] switch_core_media.c:4842 AUDIO RTP [sofia/internal/0000100912345678] 10.1.1.1 port 26552 -> 172.16.0.150 port 49198 codec: 0 ms: 20 2014-09-17 16:48:46.205889 [DEBUG] switch_rtp.c:3351 Starting timer [soft] 160 bytes per 20ms 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5189 Set 2833 dtmf send payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5195 Set 2833 dtmf receive payload to 101 2014-09-17 16:48:46.225921 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/0000100912345678! 2014-09-17 16:48:46.225921 [DEBUG] switch_channel.c:3391 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_channel.c:3395 (sofia/internal/0000100912345678) Callstate Change DOWN -> EARLY 2014-09-17 16:48:46.225921 [DEBUG] switch_ivr_originate.c:412 Setting codec string onsofia/internal/alice(a)fs.mydomain.com to PCMU@8000h@20i 2014-09-17 16:48:46.225921 [INFO] switch_ivr_originate.c:3500 Sending early media 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [opus:109:48000:20:0]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3437 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3383 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3309 Set telephone-event payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2343 Set Codec sofia/internal/alice(a)fs.mydomain.comPCMU/8000 20 ms 160 samples 64000 bits 2014-09-17 16:48:46.225921 [DEBUG] switch_core_codec.c:111 sofia/internal/alice(a)fs.mydomain.com Original read codec set to PCMU:0 2014-09-17 16:48:46.225921 [WARNING] switch_core_media.c:2548 NO candidate ACL defined, Defaulting to wan.auto 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 172.16.1.188:54467 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 172.16.1.188:54467 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: srflx addr: 10.1.1.2:54467 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2581 Choose audio Candidate cid: 1 proto: UDP type: srflx addr: 10.1.1.2:54467 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 192.168.56.1:54468 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.56.1:54468 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 192.168.232.1:54469 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.232.1:54469 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 1 proto: UDP type: host addr: 192.168.146.1:54470 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.146.1:54470 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 172.16.1.188:54471 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 172.16.1.188:54471 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: srflx addr: 10.1.1.2:54471 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2581 Choose audio Candidate cid: 2 proto: UDP type: srflx addr: 10.1.1.2:54471 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 192.168.56.1:54472 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.56.1:54472 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 192.168.232.1:54473 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.232.1:54473 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:2572 Checking Candidate cid: 2 proto: UDP type: host addr: 192.168.146.1:54474 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2586 Save audio Candidate cid: 2 proto: UDP type: host addr: 192.168.146.1:54474 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2710 setting remote audio ice addr to 10.1.1.2:54467 based on candidate 2014-09-17 16:48:46.225921 [NOTICE] switch_core_media.c:2730 setting remote rtcp audio addr to 10.1.1.2:54471 based on candidate 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:3626 Set 2833 dtmf send/recv payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:4842 AUDIO RTP [sofia/internal/alice(a)fs.mydomain.com] 10.1.1.1 port 24858 -> 10.1.1.2 port 54467 codec: 0 ms: 20 2014-09-17 16:48:46.225921 [DEBUG] switch_rtp.c:3351 Starting timer [soft] 160 bytes per 20ms 2014-09-17 16:48:46.225921 [INFO] switch_core_media.c:5011 Activating Audio ICE 2014-09-17 16:48:46.225921 [NOTICE] switch_rtp.c:3792 Activating RTP audio ICE: 17e36105:JMJwWUvXyYRgIAHV 10.1.1.2:54467 2014-09-17 16:48:46.225921 [INFO] switch_core_media.c:5054 Activating RTCP PORT 54471 2014-09-17 16:48:46.225921 [DEBUG] switch_rtp.c:3697 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 54471 2014-09-17 16:48:46.225921 [DEBUG] switch_rtp.c:2170 Setting RTCP remote addr to 10.1.1.2:54471 2014-09-17 16:48:46.225921 [INFO] switch_core_media.c:5064 Activating RTCP ICE 2014-09-17 16:48:46.225921 [NOTICE] switch_rtp.c:3792 Activating RTCP audio ICE: 17e36105:JMJwWUvXyYRgIAHV 10.1.1.2:54471 2014-09-17 16:48:46.225921 [INFO] switch_rtp.c:2895 Activate RTP/RTCP audio DTLS client 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5189 Set 2833 dtmf send payload to 101 2014-09-17 16:48:46.225921 [DEBUG] switch_core_media.c:5195 Set 2833 dtmf receive payload to 101 2014-09-17 16:48:46.225921 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/alice(a)fs.mydomain.com! 2014-09-17 16:48:46.225921 [DEBUG] switch_channel.c:3395 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change RINGING -> EARLY 2014-09-17 16:48:46.225921 [DEBUG] mod_sofia.c:2222 Ring SDP: v=0 o=FreeSWITCH 1410969268 1410969269 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:2725252931 1 udp 659136 10.1.1.1 24858 typ host generation 0 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_ivr_originate.c:3551 Originate Resulted in Success: [sofia/internal/0000100912345678] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_ivr_bridge.c:1460 (sofia/internal/0000100912345678) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] send 2056 bytes to udp/[172.16.0.150]:5063 at 16:48:46.238673: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=99eQB5Zae5cee Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE Contact: <sip:+12345678@172.16.0.150:6090;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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: 799 X-DAL-UUID: 3a05956905ca41e2b43170968d44398e Remote-Party-ID: "Outbound Call" <sip:5063@fs.mydomain.com>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1410969268 1410969269 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:2725252931 1 udp 659136 10.1.1.1 24858 typ host generation 0 ------------------------------------------------------------------------ 2014-09-17 16:48:46.225921 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:46.225921 [DEBUG] switch_core_state_machine.c:536 (sofia/internal/0000100912345678) State EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] mod_sofia.c:592 SOFIA EXCHANGE_MEDIA 2014-09-17 16:48:46.225921 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [early][183] 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:2718 Changing audio DTLS state from HANDSHAKE to SETUP 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:2626 audio Fingerprint Verified. 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:3168 Activating Audio Secure RTP SEND 2014-09-17 16:48:47.305892 [DEBUG] switch_core_sqldb.c:2568 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:3146 Activating Audio Secure RTP RECV 2014-09-17 16:48:47.305892 [INFO] switch_rtp.c:2666 Changing audio DTLS state from SETUP to READY 2014-09-17 16:48:47.305892 [DEBUG] switch_core_sqldb.c:2568 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2014-09-17 16:48:47.545899 [INFO] switch_rtp.c:5554 Auto Changing port from 172.16.0.150:49198 to 10.1.1.1:49198 recv 903 bytes from udp/[172.16.0.150]:5063 at 16:48:54.507821: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.0.150:6090;rport=6090;branch=z9hG4bKDytKNrBp1aDrQ Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 INVITE User-Agent: bobPBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <sip:0000100912345678@10.2.1.1:5060> Content-Type: application/sdp Content-Length: 282 v=0 o=root 27411 27412 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=nortpproxy:yes ------------------------------------------------------------------------ 2014-09-17 16:48:54.505900 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.505900 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.526003 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [completing][200] 2014-09-17 16:48:54.526003 [DEBUG] sofia.c:6239 Remote SDP: v=0 o=root 27411 27412 IN IP4 172.16.0.150 s=session c=IN IP4 172.16.0.150 t=0 0 m=audio 49198 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=nortpproxy:yes send 538 bytes to udp/[172.16.0.150]:5063 at 16:48:54.528674: ------------------------------------------------------------------------ ACK sip:0000100912345678@10.2.1.1:5060 SIP/2.0 Via: SIP/2.0/UDP 172.16.0.150:6090;rport;branch=z9hG4bKe7KcQKvSyK3aK Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Max-Forwards: 70 From: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S To: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 65160997 ACK Contact: <sip:gw+bobspecial@172.16.0.150:6090;transport=udp;gw=bobspecial> Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:48:54.526003 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.526003 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.526003 [DEBUG] sofia.c:6229 Channel sofia/internal/0000100912345678 entering state [ready][200] 2014-09-17 16:48:54.545977 [DEBUG] switch_channel.c:3631 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK] 2014-09-17 16:48:54.545977 [NOTICE] sofia.c:6996 Channel [sofia/internal/0000100912345678] has been answered EXECUTE sofia/internal/0000100912345678 lua(mod_callmgr/on-bridge.lua) 2014-09-17 16:48:54.545977 [ERR] mod_lua.cpp:203 cannot open /home/kkhan/fsdevel/scripts/mod_callmgr/on-bridge.lua: No such file or directory 2014-09-17 16:48:54.545977 [DEBUG] switch_cpp.cpp:1056 sofia/internal/0000100912345678 destroy/unlink session from object 2014-09-17 16:48:54.545977 [DEBUG] switch_channel.c:3685 (sofia/internal/0000100912345678) Callstate Change EARLY -> ACTIVE 2014-09-17 16:48:54.545977 [DEBUG] mod_sofia.c:778 Local SDP sofia/internal/alice(a)fs.mydomain.com: v=0 o=FreeSWITCH 1410969268 1410969270 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:6961800946 1 udp 659136 10.1.1.1 24858 typ host generation 0 2014-09-17 16:48:54.545977 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.545977 [NOTICE] switch_ivr_bridge.c:496 Channel [sofia/internal/alice(a)fs.mydomain.com] has been answered send 2017 bytes to udp/[172.16.0.150]:5063 at 16:48:54.553616: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.2784592c8ddaf1dddc7bcb9bbcbecd6a.0;received=172.16.0.150 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKJtOEBT8qZTFStRrzMZcGKo1Tq8iXUdFm;rport=64649 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=99eQB5Zae5cee Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 INVITE Contact: <sip:+12345678@172.16.0.150:6090;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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: 799 X-DAL-UUID: 3a05956905ca41e2b43170968d44398e Remote-Party-ID: "Outbound Call" <sip:5063@fs.mydomain.com>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1410969268 1410969269 IN IP4 10.1.1.1 s=FreeSWITCH c=IN IP4 10.1.1.1 t=0 0 a=msid-semantic: WMS RDPCOY3SmIJZRpeBKriKXkk9aND4STSA m=audio 24858 UDP/TLS/RTP/SAVPF 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=fingerprint:sha-256 91:E9:37:67:75:A4:28:C0:E6:DB:6B:2B:B7:A6:5E:5C:B5:2D:99:89:CF:26:44:FA:D0:82:A0:9C:F2:A2:84:94 a=rtcp-mux a=rtcp:24858 IN IP4 10.1.1.1 a=ssrc:271344810 cname:nx21mWJyvjncyrD8 a=ssrc:271344810 msid:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a0 a=ssrc:271344810 mslabel:RDPCOY3SmIJZRpeBKriKXkk9aND4STSA a=ssrc:271344810 label:RDPCOY3SmIJZRpeBKriKXkk9aND4STSAa0 a=ice-ufrag:JMJwWUvXyYRgIAHV a=ice-pwd:XAN9nnyIxMLV4fUDRtZEdlrB a=candidate:2725252931 1 udp 659136 10.1.1.1 24858 typ host generation 0 ------------------------------------------------------------------------ 2014-09-17 16:48:54.545977 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.545977 [DEBUG] switch_channel.c:3685 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change EARLY -> ACTIVE 2014-09-17 16:48:54.545977 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [completed][200] recv 1223 bytes from udp/[172.16.0.150]:5063 at 16:48:54.586519: ------------------------------------------------------------------------ ACK sip:+12345678@172.16.0.150:6090;transport=udp SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=ws;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK22c.b4fd273e140b6bfb8c10132eb6625886.0 Via: SIP/2.0/WS df7jal23ls0d.invalid;received=10.1.1.2;branch=z9hG4bKsqO0MlTVFcWedViMF5yV;rport=64649 From: "Alice"<sip:alice@fs.mydomain.com>;tag=tKWvsNl5oHT5STgFSpWU To: <sip:+12345678@fs.mydomain.com>;tag=99eQB5Zae5cee Contact: "Alice"<sip:alice@10.1.1.2:64649;rtcweb-breaker=no;click2call=no;transport=ws>;+g.oma.sip-im;+sip.ice;language="en,fr";received="sip:10.1.1.2:64649;transport=WS" Call-ID: cdff3f60-5133-6104-9f7a-f50b516b2f32 CSeq: 10770 ACK Content-Length: 0 Max-Forwards: 69 Proxy-Authorization: Digest username="alice",realm="fs.mydomain.com",nonce="4c15231c-896a-4131-b7c2-621ab8342e9a",uri="sip:+12345678@172.16.0.150:6090;transport=udp",response="975327290415140c922c22a1c4c00f88",algorithm=MD5,cnonce="8dabac05b6f0a365d085158868220703",qop=auth,nc=00000002 User-Agent: IM-client/OMA1.0 sipML5-v1.0.0.0 Organization: Dingaling.ca Path: <sip:172.16.0.150:5063;lr> ------------------------------------------------------------------------ 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:48:54.585908 [DEBUG] sofia.c:6229 Channel sofia/internal/alice(a)fs.mydomain.com entering state [ready][200] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:969 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:48:54.585908 [DEBUG] switch_core_session.c:969 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] recv 774 bytes from udp/[172.16.0.150]:5063 at 16:49:00.467309: ------------------------------------------------------------------------ BYE sip:gw+bobspecial@172.16.0.150:6090;transport=udp;gw=bobspecial SIP/2.0 Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Record-Route: <sip:10.1.1.1:5063;transport=udp;lr=on> Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK728.eb6d8a9209ac4e3ce276af87552fe9b7.0 Via: SIP/2.0/UDP 10.1.1.1:5063;rport=5063;branch=z9hG4bK728.5817c2e90986f57eeba11ed14bd3f311.0 Via: SIP/2.0/UDP 10.2.1.1:5060;rport=5060;branch=z9hG4bK11bbf59f From: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 To: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 102 BYE User-Agent: bobPBX Max-Forwards: 68 Content-Length: 0 Path: <sip:172.16.0.150:5063;lr> Path: <sip:172.16.0.150:5063;lr> ------------------------------------------------------------------------ 2014-09-17 16:49:00.465894 [DEBUG] switch_core_session.c:1052 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [NOTICE] sofia.c:926 Hangup sofia/internal/0000100912345678 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2014-09-17 16:49:00.485939 [DEBUG] switch_channel.c:3218 Send signal sofia/internal/0000100912345678 [KILL] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] send 725 bytes to udp/[172.16.0.150]:5063 at 16:49:00.487587: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.1.1.1:5063;branch=z9hG4bK728.eb6d8a9209ac4e3ce276af87552fe9b7.0;received=172.16.0.150 Via: SIP/2.0/UDP 10.1.1.1:5063;rport=5063;branch=z9hG4bK728.5817c2e90986f57eeba11ed14bd3f311.0 Via: SIP/2.0/UDP 10.2.1.1:5060;rport=5060;branch=z9hG4bK11bbf59f From: <sip:0000100912345678@10.2.1.1>;tag=as5129a390 To: "Alice" <sip:bob@10.2.1.1>;tag=aK8FD0geBe30S Call-ID: 9e1e4217-b95f-1232-dcb8-0015e9bb72e2 CSeq: 102 BYE User-Agent: FreeSWITCH-mod_sofia/1.4.6+git~20140603T193516Z~9479729340~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:659 BRIDGE THREAD DONE [sofia/internal/0000100912345678] 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:689 Send signal sofia/internal/alice(a)fs.mydomain.com [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:536 (sofia/internal/0000100912345678) State EXCHANGE_MEDIA going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:733 (sofia/internal/0000100912345678) Callstate Change ACTIVE -> HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/0000100912345678) State HANGUP 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:413 Channel sofia/internal/0000100912345678 hanging up, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:58 sofia/internal/0000100912345678 Standard HANGUP, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/0000100912345678) State HANGUP going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/0000100912345678) State Change CS_HANGUP -> CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/0000100912345678) Running State Change CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/0000100912345678) State REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:102 sofia/internal/0000100912345678 Standard REPORTING, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/0000100912345678) State REPORTING going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:496 (sofia/internal/0000100912345678) State Change CS_REPORTING -> CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1614 Session 104 (sofia/internal/0000100912345678) Locked, Waiting on external entities 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:578 sofia/internal/0000100912345678 ending bridge by request from write function 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:659 BRIDGE THREAD DONE [sofia/internal/alice(a)fs.mydomain.com] 2014-09-17 16:49:00.485939 [DEBUG] switch_ivr_bridge.c:689 Send signal sofia/internal/0000100912345678 [BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:907 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1632 Session 104 (sofia/internal/0000100912345678) Ended 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1636 Close Channel sofia/internal/0000100912345678 [CS_DESTROY] 2014-09-17 16:49:00.485939 [NOTICE] switch_core_state_machine.c:313 sofia/internal/alice(a)fs.mydomain.com has executed the last dialplan instruction, hanging up. 2014-09-17 16:49:00.485939 [NOTICE] switch_core_state_machine.c:315 Hangup sofia/internal/alice(a)fs.mydomain.com[CS_EXECUTE] [NORMAL_CLEARING] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/0000100912345678) Running State Change CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/0000100912345678) State DESTROY 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:323 sofia/internal/0000100912345678 SOFIA DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_channel.c:3218 Send signal sofia/internal/alice(a)fs.mydomain.com [KILL] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:109 sofia/internal/0000100912345678 Standard DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/0000100912345678) State DESTROY going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:533 (sofia/internal/alice(a)fs.mydomain.com) State EXECUTE going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:733 (sofia/internal/alice(a)fs.mydomain.com) Callstate Change ACTIVE -> HANGUP 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/alice(a)fs.mydomain.com) State HANGUP 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:407 sofia/internal/alice(a)fs.mydomain.com Overriding SIP cause 480 with 200 from the other leg 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:413 Channel sofia/internal/alice(a)fs.mydomain.com hanging up, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/alice(a)fs.mydomain.com 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:58 sofia/internal/alice(a)fs.mydomain.com Standard HANGUP, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/alice(a)fs.mydomain.com) State HANGUP going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:502 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_HANGUP -> CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:470 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/alice(a)fs.mydomain.com) State REPORTING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:102 sofia/internal/alice(a)fs.mydomain.com Standard REPORTING, cause: NORMAL_CLEARING 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:821 (sofia/internal/alice(a)fs.mydomain.com) State REPORTING going to sleep 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:496 (sofia/internal/alice(a)fs.mydomain.com) State Change CS_REPORTING -> CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1387 Send signal sofia/internal/alice(a)fs.mydomain.com[BREAK] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_session.c:1614 Session 103 (sofia/internal/alice(a)fs.mydomain.com) Locked, Waiting on external entities 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1632 Session 103 (sofia/internal/alice(a)fs.mydomain.com) Ended 2014-09-17 16:49:00.485939 [NOTICE] switch_core_session.c:1636 Close Channel sofia/internal/alice(a)fs.mydomain.com[CS_DESTROY] 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:624 (sofia/internal/alice(a)fs.mydomain.com) Running State Change CS_DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/alice(a)fs.mydomain.com) State DESTROY 2014-09-17 16:49:00.485939 [DEBUG] mod_sofia.c:323 sofia/internal/alice(a)fs.mydomain.com SOFIA DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:109 sofia/internal/alice(a)fs.mydomain.com Standard DESTROY 2014-09-17 16:49:00.485939 [DEBUG] switch_core_state_machine.c:634 (sofia/internal/alice(a)fs.mydomain.com) State DESTROY going to sleep From: freeswitch-users-request(a)lists.freeswitch.org Subject: FreeSWITCH-users Digest, Vol 99, Issue 146 To: freeswitch-users(a)lists.freeswitch.org Date: Thu, 18 Sep 2014 02:29:41 +0400 Send FreeSWITCH-users mailing list submissions to freeswitch-users(a)lists.freeswitch.org To subscribe or unsubscribe via the World Wide Web, visit http://lists.freeswitch.org/mailman/listinfo/freeswitch-users or, via email, send a message with subject or body 'help' to freeswitch-users-request(a)lists.freeswitch.org You can reach the person managing the list at freeswitch-users-owner(a)lists.freeswitch.org When replying, please edit your Subject line so it is more specific than "Re: Contents of FreeSWITCH-users digest..." --Forwarded Message Attachment-- From: wstephen80(a)gmail.com To: freeswitch-users(a)lists.freeswitch.org Date: Wed, 17 Sep 2014 22:58:23 +0200 Subject: Re: [Freeswitch-users] Call released with a 200 OK I have a trace of one leg only I can try to capture both legs.But a 200 OK with a Reason header is a valid SIP message (below 200 OK forwarded by FreeSWITCH) ? Frame 5: 957 bytes on wire (7656 bits), 957 bytes captured (7656 bits)Ethernet II, Src: Hewlett-_f3:e9:2c (3c:d9:2b:f3:e9:2c), Dst: JuniperN_f6:ce:27 (78:19:f7:f6:ce:27)Internet Protocol Version 4, Src: FreeSWITCH_IP (FreeSWITCH_IP), Dst: CUSTOMER_IP (CUSTOMER_IP)User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)Session Initiation Protocol (200) Status-Line: SIP/2.0 200 OK Message Header Via: SIP/2.0/UDP CUSTOMER_IP:5060;branch=z9hG4bK00E0F510095D15ED848E0A88725A Max-Forwards: 63 From: <sip:cg@FreeSWITCH_IP>;tag=00E0F510095D15ED848E7A60E97C To: <sip:cd@FreeSWITCH_IP>;tag=5881vaN1reajB Call-ID: ae8f80003582-5417017f-60871148-3ad46cc0-745bf31(a)127.0.0.1 CSeq: 14398 INVITE Contact: <sip:cd@FreeSWITCH_IP:5060;transport=udp> User-Agent: FS_1.2 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Type: application/sdp Content-Disposition: session Content-Length: 217 Message Body On Wed, Sep 17, 2014 at 10:09 PM, Steven Ayre <steveayre(a)gmail.com> wrote: Can you post the sip trace for the call (all legs) On 17 September 2014 19:54, Stephen Wilde <wstephen80(a)gmail.com> wrote: Anyone can help me on that? Stephen On Tue, Sep 16, 2014 at 9:58 PM, Stephen Wilde <wstephen80(a)gmail.com> wrote: I have a strange issue: some calls are dropped with a 200 OK containing the "Reason" header. Is this valid?The message flow is: CUSTOMER ---- FS INVITE -> <- 100 Trying <- 180 Ringing <- 200 OK (containing the Reason Header) ACK -> after some seconds... BYE ->BYE ->BYE ->BYE ->BYE -> The 200 OK sent by FreeSwitch contain a "Reason Header": Reason: Q.850;cause=16;text="NORMAL_CLEARING" And the call seems dropped and not connected in FreeSWITCH.For the customer side the call seems connected with 200 OK (the customer ignore the Reason).After some seconds, the customer try to disconnect the call with BYE but these messages are ignored by Freeswitch because the call was been already dropped. It's valid the Reason inside the 200 OK? It's possible that this 200 OK has been forwarded by Freeswitch from the outbound leg.Any advice for that? Stephen _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org --Forwarded Message Attachment-- From: steveayre(a)gmail.com To: freeswitch-users(a)lists.freeswitch.org Date: Wed, 17 Sep 2014 23:28:37 +0100 Subject: Re: [Freeswitch-users] Call released with a 200 OK rfc3326 - I believe it's valid in any packet, you can potentially have a Reason passed back before the end of the call. It's the BYE that's hanging up the call not the 200 OK, but that could be an interop problem where a device doesn't expect the Reason in the 200 OK. On 17 September 2014 21:58, Stephen Wilde <wstephen80(a)gmail.com> wrote: I have a trace of one leg only I can try to capture both legs.But a 200 OK with a Reason header is a valid SIP message (below 200 OK forwarded by FreeSWITCH) ? Frame 5: 957 bytes on wire (7656 bits), 957 bytes captured (7656 bits)Ethernet II, Src: Hewlett-_f3:e9:2c (3c:d9:2b:f3:e9:2c), Dst: JuniperN_f6:ce:27 (78:19:f7:f6:ce:27)Internet Protocol Version 4, Src: FreeSWITCH_IP (FreeSWITCH_IP), Dst: CUSTOMER_IP (CUSTOMER_IP)User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)Session Initiation Protocol (200) Status-Line: SIP/2.0 200 OK Message Header Via: SIP/2.0/UDP CUSTOMER_IP:5060;branch=z9hG4bK00E0F510095D15ED848E0A88725A Max-Forwards: 63 From: <sip:cg@FreeSWITCH_IP>;tag=00E0F510095D15ED848E7A60E97C To: <sip:cd@FreeSWITCH_IP>;tag=5881vaN1reajB Call-ID: ae8f80003582-5417017f-60871148-3ad46cc0-745bf31(a)127.0.0.1 CSeq: 14398 INVITE Contact: <sip:cd@FreeSWITCH_IP:5060;transport=udp> User-Agent: FS_1.2 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Type: application/sdp Content-Disposition: session Content-Length: 217 Message Body On Wed, Sep 17, 2014 at 10:09 PM, Steven Ayre <steveayre(a)gmail.com> wrote: Can you post the sip trace for the call (all legs) On 17 September 2014 19:54, Stephen Wilde <wstephen80(a)gmail.com> wrote: Anyone can help me on that? Stephen On Tue, Sep 16, 2014 at 9:58 PM, Stephen Wilde <wstephen80(a)gmail.com> wrote: I have a strange issue: some calls are dropped with a 200 OK containing the "Reason" header. Is this valid?The message flow is: CUSTOMER ---- FS INVITE -> <- 100 Trying <- 180 Ringing <- 200 OK (containing the Reason Header) ACK -> after some seconds... BYE ->BYE ->BYE ->BYE ->BYE -> The 200 OK sent by FreeSwitch contain a "Reason Header": Reason: Q.850;cause=16;text="NORMAL_CLEARING" And the call seems dropped and not connected in FreeSWITCH.For the customer side the call seems connected with 200 OK (the customer ignore the Reason).After some seconds, the customer try to disconnect the call with BYE but these messages are ignored by Freeswitch because the call was been already dropped. It's valid the Reason inside the 200 OK? It's possible that this 200 OK has been forwarded by Freeswitch from the outbound leg.Any advice for that? Stephen _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org -- Brian West brian(a)freeswitch.org Twitter: @FreeSWITCH , @briankwest http://www.freeswitchbook.com http://www.freeswitchcookbook.com T:+19184209001 | F:+19184209002 | M:+1918424WEST (9378) iNUM:+883 5100 1420 9001 | ISN:410*543 | Skype:briankwest _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting(a)freeswitch.org http://www.freeswitchsolutions.com Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com FreeSWITCH-users mailing list FreeSWITCH-users(a)lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org

2 2

Advertizing SIP address on websites.
by Karl Schmidt 22 Sep '14

22 Sep '14

There is a way - and standards for showing ones SIP address on websites. I could be nice for overseas customers. Only, I don't see anyone else doing it and thus I figure there are probably some good reasons not to do it. I don't want to do this if it will create problems - anyone been down this road? -- -------------------------------------------------------------------------------- Karl Schmidt EMail Karl(a)xtronics.com Transtronics, Inc. WEB http://secure.transtronics.com 3209 West 9th Street Ph (785) 841-3089 Lawrence, KS 66049 FAX (785) 841-3089 As a bright friend explained as to why he doesn't watch any TV; All we have is time - best not to waste it. kps --------------------------------------------------------------------------------

4 6

Re: [Freeswitch-users] Multi Tenant (Company), User unable to register ( SIP/2.0 403 Forbidden)
by Ahmed Habiba 22 Sep '14

22 Sep '14

I’ve go through the book however I was not able to identify the issue, my configuration is as below: 1-Directory folder as below: root@:/usr/local/freeswitch/conf/directory# ls -ltr total 16 -rw-r--r-- 1 root root 2925 Aug 27 12:17 default.xml drwxr-xr-x 2 root root 4096 Sep 19 20:47 default -rw-r--r-- 1 root root 835 Sep 20 16:27 company-a.org.xml drwxr-xr-x 2 root root 4096 Sep 20 16:50 company-a.org 2-company-a.org.xml: root@:/usr/local/freeswitch/conf/directory# cat company-a.org.xml <include>  <domain name="company-a.org"> <params> <param name="dial-string" value="{presence_id=${dialed_user}@${dialed_domain}}${sofia_contact(${dialed_user}@${dialed_domain})}"/> </params> <variables> <variable name="record_stereo" value="true"/> <variable name="default_gateway" value="$${default_provider}"/> <variable name="default_areacode" value="$${default_areacode}"/> <variable name="transfer_fallback_extension" value="operator"/> <variable name="user_context" value="company-a.org"/> </variables> <groups> <group name="company-a.org"> <users> <X-PRE-PROCESS cmd="include" data="company-a.org/*.xml"/> </users> </group> </groups> </domain> </include> 3-company-a.org.xml: root@:/usr/local/freeswitch/conf/directory# ls -l company-a.org total 100 -rw-r--r-- 1 root root 851 Sep 20 16:50 1000.xml -rw-r--r-- 1 root root 751 Aug 27 12:17 1001.xml -rw-r--r-- 1 root root 751 Aug 27 12:17 1002.xml -rw-r--r-- 1 root root 751 Aug 27 12:17 1003.xml -rw-r--r-- 1 root root 751 Aug 27 12:17 1004.xml -rw-r--r-- 1 root root 751 Aug 27 12:17 1005.xml -rw-r--r-- 1 root root 751 Aug 27 12:17 1006.xml 4- in internal.xml I commented the below lines: root@openerp:/usr/local/freeswitch/conf/sip_profiles# vi internal.xml       5-In zoiper client I use 1000(a)company-a.org as a user name instead of 1000. and finally I still getting SIP/2.0 403 Forbidden Your help is always appreciated. Thanks in advance, Ahmed Habiba. From: Stanislav Sinyagin <ssinyagin(a)gmail.com> Subject: Re: [Freeswitch-users] Multi Tenant (Company), User unable to register ( SIP/2.0 403 Forbidden) Date: September 21, 2014 at 11:37:10 PM GMT+3 To: FreeSWITCH Users Help <freeswitch-users(a)lists.freeswitch.org> Reply-To: FreeSWITCH Users Help <freeswitch-users(a)lists.freeswitch.org> Have you read the freeswitch book? It gives answers to most questions. Also you haven't given a clue how your configuration looks like, so what kind of help do you expect? Of course you can easily find someone who can set up your server for money... Although the book is usually enough. On Sep 21, 2014 9:36 PM, "Ahmed habiba" <ahabiba(a)gmail.com> wrote: What would be the extra value of FusionPBX if I'm not able to use the back-end manual configuration. Your kind help will be appreciated. Thanks, Ahmed Habiba. ------------------------------------- From: Luis Daniel Lucio Quiroz <luis.daniel.lucio(a)gmail.com> To: FreeSWITCH Users Help <freeswitch-users(a)lists.freeswitch.org> Cc: Date: Sat, 20 Sep 2014 18:33:38 -0400 Subject: Re: [Freeswitch-users] Multi Tenant (Company), User unable to register ( SIP/2.0 403 Forbidden) Have you consider to use FusionPBX? On Sep 20, 2014 5:36 PM, "Ahmed Habiba" <ahabiba(a)gmail.com> wrote: Hello Everybody, I’ve been trying to configure FreeSWITCH in multi tenant mode however I always get “403 Forbidden” during user registration, I use the same tutorial on wiki as is with name and paramters "https://wiki.freeswitch.org/wiki/Multiple_Companies” with consideration that my network scenario is as below: [FreeSWITCH(real IP)]<———>[Internet]<———>[NAT]<———>[Client] Your kind help will be appreciated. Thanks and Best Regards, Ahmed Habiba.

3 3

Re: [Freeswitch-users] Multi Tenant (Company), User unable to register ( SIP/2.0 403 Forbidden)
by Ahmed habiba 21 Sep '14

21 Sep '14

What would be the extra value of FusionPBX if I'm not able to use the back-end manual configuration. Your kind help will be appreciated. Thanks, Ahmed Habiba. ------------------------------------- From: Luis Daniel Lucio Quiroz <luis.daniel.lucio(a)gmail.com> To: FreeSWITCH Users Help <freeswitch-users(a)lists.freeswitch.org> Cc: Date: Sat, 20 Sep 2014 18:33:38 -0400 Subject: Re: [Freeswitch-users] Multi Tenant (Company), User unable to register ( SIP/2.0 403 Forbidden) Have you consider to use FusionPBX? On Sep 20, 2014 5:36 PM, "Ahmed Habiba" <ahabiba(a)gmail.com> wrote: Hello Everybody, I’ve been trying to configure FreeSWITCH in multi tenant mode however I always get “403 Forbidden” during user registration, I use the same tutorial on wiki as is with name and paramters " https://wiki.freeswitch.org/wiki/Multiple_Companies” with consideration that my network scenario is as below: [FreeSWITCH(real IP)]<———>[Internet]<———>[NAT]<———>[Client] Your kind help will be appreciated. Thanks and Best Regards, Ahmed Habiba.

2 1

FreeSWITCH with rabbit mq
by Andre Demattia 21 Sep '14

21 Sep '14

Hi has anyone used FreeSWITCH with your cdrs going to rabbitmq? Will the rabbit mq interfere with FreeSWITCH? Like take up TCP ports? Or impact performance? Thanks Andre

6 11

Multi Tenant (Company), User unable to register ( SIP/2.0 403 Forbidden)
by Ahmed Habiba 20 Sep '14

20 Sep '14

Hello Everybody, I’ve been trying to configure FreeSWITCH in multi tenant mode however I always get “403 Forbidden” during user registration, I use the same tutorial on wiki as is with name and paramters "https://wiki.freeswitch.org/wiki/Multiple_Companies” with consideration that my network scenario is as below: [FreeSWITCH(real IP)]<———>[Internet]<———>[NAT]<———>[Client] Your kind help will be appreciated. Thanks and Best Regards, Ahmed Habiba.

2 1

param name in dialplan
by Aqs Younas 20 Sep '14

20 Sep '14

Hi, Could we set param name variables defined in conf.xml file in default.xml. Like i want to set global_heartbeat (which is used to set in nibblebill.conf.xml file) in my dialplan/default.xml file. <param name="global_heartbeat" value="25"/> Is it possible? if yes, then how?

2 1