ok so if it's not deflect, what is it that I need to use. what is the proper setup to get the scenario that I have going. or is it possible at all to get it going? -- Georges Boulos NGN/VoIP Emerging Technologies Bell Canada (http://www.bell.ca) On Jan 30, 2014, at 12:03 PM, <freeswitch-users-request@lists.freeswitch.org> wrote:
Send FreeSWITCH-users mailing list submissions to freeswitch-users@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@lists.freeswitch.org
You can reach the person managing the list at freeswitch-users-owner@lists.freeswitch.org
When replying, please edit your Subject line so it is more specific than "Re: Contents of FreeSWITCH-users digest..." Today's Topics:
1. Re: Want to use REFER to do transfers (Brian West) 2. Re: codec configuration ignored by freeswitch (Giuseppe Cardone) 3. Re: codec configuration ignored by freeswitch (Brian West) 4. Re: Want to use REFER to do transfers (Michel Brabants) 5. Re: trans-coding is not working (thomas peterseil)
From: Brian West <brian@freeswitch.org> Subject: Re: [Freeswitch-users] Want to use REFER to do transfers Date: January 30, 2014 10:56:49 AM EST To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org> Reply-To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org>
deflect is freeswitch acting as the endpoint and sending the refer itself, so using deflect would result in this:
bell SBC -> FreeSWITCH
No endpoint involvement and you’re sending a refer to the SBC which is mostly
-- Brian West brian@freeswitch.org FreeSWITCH Solutions, LLC PO BOX 2531 Brookfield, WI 53008-2531 Twitter: @FreeSWITCH , @briankwest http://www.freeswitchbook.com http://www.freeswitchcookbook.com
T: +1.918.420.9001 | F: +1.918.420.9002 | M: +1.918.424.WEST iNUM: +883 5100 1420 9001 ISN: 410*543 Skype:briankwest PGP Key: http://www.bkw.org/key.txt (AB93356707C76CED)
On Jan 30, 2014, at 9:42 AM, Georges Boulos <georges.boulos@bell.ca> wrote:
Hey Brian,
Thank you for replying, hope this answers your question.
here is the call flow
bell SBC -> FreeSwitch -> EndPoint
when the Endpoints answers the call, I want to be able to hit transfer on the end point and do a blind or assisted transfer.
-- Georges Boulos NGN/VoIP Emerging Technologies Bell Canada (http://www.bell.ca)
Tel: 613.781.9016 Cell: 613.859.7420 georges.boulos@bell.ca 1501 Bank St, Ottawa, ON, K1H 7Z1
From: Giuseppe Cardone <g.cardone@unidata.it> Subject: Re: [Freeswitch-users] codec configuration ignored by freeswitch Date: January 30, 2014 10:22:46 AM EST To: freeswitch-users@lists.freeswitch.org Reply-To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org>
Anyone have any suggestions on this ?
Many thanks, Giuseppe
----- Messaggio originale -----
Da: "Giuseppe Cardone" <g.cardone@unidata.it> A: freeswitch-users@lists.freeswitch.org Inviato: Mercoledì, 29 gennaio 2014 18:47:41 Oggetto: codec configuration ignored by freeswitch
Hello,
I have tried to configure a limited set of two codecs for outbound calls. I first tried with the parameters described in the documentation in a sip_profile and then in a dialplan and then in vars.xml.
However, each time the set of codecs seems to be overwritten and the original list offered by the calling UA is applied.
I am new to FS and suspect I am missing something quite simple, can anyone lend a hand in suggesting what would cause the described behaviour ?
Here is the essential part of the log showing the absolute_codec_string first applied:
EXECUTE sofia/internal/390742850020@217.72.102.128:5070 set(absolute_codec_string=PCMA,G729) 2014-01-29 17:17:40.290655 [DEBUG] mod_dptools.c:1402 sofia/internal/390742850020@217.72.102.128:5070 SET [absolute_codec_string]=[PCMA,G729] EXECUTE sofia/internal/390742850020@217.72.102.128:5070 bridge(sofia/gateway/unidata_dev/+390144750000) 2014-01-29 17:17:40.290655 [DEBUG] switch_channel.c:1198 sofia/internal/390742850020@217.72.102.128:5070 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 29 Jan 2014 17:17:40 +0100] to event 2014-01-29 17:17:40.290655 [DEBUG] switch_ivr_originate.c:2060 Parsing global variables 2014-01-29 17:17:40.290655 [NOTICE] switch_channel.c:1052 New Channel sofia/external/+390144750000 [e00a6dde-8900-11e3-8b08-0b2b96c9cf60] 2014-01-29 17:17:40.290655 [DEBUG] mod_sofia.c:5231 (sofia/external/+390144750000) State Change CS_NEW -> CS_INIT 2014-01-29 17:17:40.290655 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/+390144750000 [BREAK]
and then overwritten:
2014-01-29 17:17:40.290655 [DEBUG] mod_sofia.c:5301 [zrtp_passthru] Setting a-leg inherit_codec=true 2014-01-29 17:17:40.290655 [DEBUG] mod_sofia.c:5304 [zrtp_passthru] Setting b-leg absolute_codec_string='G722@8000h@20i@64000b,PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b,GSM@8000h@20i@13200b' 2014-01-29 17:17:40.290655 [DEBUG] switch_core_state_machine.c:415 (sofia/external/+390144750000) Running State Change CS_INIT 2014-01-29 17:17:40.290655 [DEBUG] switch_core_state_machine.c:454 (sofia/external/+390144750000) State INIT 2014-01-29 17:17:40.290655 [DEBUG] mod_sofia.c:87 sofia/external/+390144750000 SOFIA INIT 2014-01-29 17:17:40.290655 [DEBUG] sofia_glue.c:2739 Local SDP:
Thanks in advance for your help.
Regards, Giuseppe
From: Brian West <brian@freeswitch.org> Subject: Re: [Freeswitch-users] codec configuration ignored by freeswitch Date: January 30, 2014 11:03:49 AM EST To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org> Reply-To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org>
When it appears as if the codec is ignored, chances are you don’t have said codec loaded. -- Brian West brian@freeswitch.org FreeSWITCH Solutions, LLC PO BOX 2531 Brookfield, WI 53008-2531 Twitter: @FreeSWITCH , @briankwest http://www.freeswitchbook.com http://www.freeswitchcookbook.com
T: +1.918.420.9001 | F: +1.918.420.9002 | M: +1.918.424.WEST iNUM: +883 5100 1420 9001 ISN: 410*543 Skype:briankwest PGP Key: http://www.bkw.org/key.txt (AB93356707C76CED)
On Jan 30, 2014, at 9:22 AM, Giuseppe Cardone <g.cardone@unidata.it> wrote:
Anyone have any suggestions on this ?
Many thanks, Giuseppe
From: Michel Brabants <michel.brabants@gmail.com> Subject: Re: [Freeswitch-users] Want to use REFER to do transfers Date: January 30, 2014 11:54:41 AM EST To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org> Reply-To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org>
Hey Georges,
as far as I know it isn't possible to pass through the refer towards your SBC for an ongoing call if that is what you mean (put freeswitch out of the signalling path). I'm looking into it myself, so if there is a solution for this present in Freeswitch, I'm also interested.
I once found a variable to optimize the signalling, but I never looked deeper into it to see what it exactly does.
Else, I'll have to look into it in the future and implement a patch, which will hopefully get accepted then :).
Kind regards,
Michel
On Thu, Jan 30, 2014 at 4:56 PM, Brian West <brian@freeswitch.org> wrote: deflect is freeswitch acting as the endpoint and sending the refer itself, so using deflect would result in this:
bell SBC -> FreeSWITCH
No endpoint involvement and you’re sending a refer to the SBC which is mostly
-- Brian West brian@freeswitch.org FreeSWITCH Solutions, LLC PO BOX 2531 Brookfield, WI 53008-2531 Twitter: @FreeSWITCH , @briankwest http://www.freeswitchbook.com http://www.freeswitchcookbook.com
T: +1.918.420.9001 | F: +1.918.420.9002 | M: +1.918.424.WEST iNUM: +883 5100 1420 9001 ISN: 410*543 Skype:briankwest PGP Key: http://www.bkw.org/key.txt (AB93356707C76CED)
On Jan 30, 2014, at 9:42 AM, Georges Boulos <georges.boulos@bell.ca> wrote:
Hey Brian,
Thank you for replying, hope this answers your question.
here is the call flow
bell SBC -> FreeSwitch -> EndPoint
when the Endpoints answers the call, I want to be able to hit transfer on the end point and do a blind or assisted transfer.
-- Georges Boulos NGN/VoIP Emerging Technologies Bell Canada (http://www.bell.ca)
Tel: 613.781.9016 Cell: 613.859.7420 georges.boulos@bell.ca 1501 Bank St, Ottawa, ON, K1H 7Z1
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
From: thomas peterseil <thomas.peterseil@gmail.com> Subject: Re: [Freeswitch-users] trans-coding is not working Date: January 30, 2014 12:02:50 PM EST To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org> Reply-To: FreeSWITCH Users Help <freeswitch-users@lists.freeswitch.org>
hello, here are the logs from the cli with sip trace on with this problem:
-------------------- freeswitch@internal> recv 2305 bytes from udp/[192.168.5.10]:20842 at 16:53:06.430550: ------------------------------------------------------------------------ PUBLISH sip:1000@192.168.65.98 SIP/2.0 Via: SIP/2.0/UDP 192.168.129.229:2425;rport;branch=z9hG4bKPj18e288b0ce3340a59a0ce2d3134fe4c5 Max-Forwards: 70 From: "thomas" <sip:1000@192.168.65.98>;tag=00d8d7ddf78c4a3f9627c52a06e68272 To: "thomas" <sip:1000@192.168.65.98> Call-ID: 08af2532df5f4c058b66de677cb88f3a CSeq: 1 PUBLISH Event: presence Expires: 600 SIP-If-Match: FBwNeu9F User-Agent: Blink 0.6.0 (Windows) Content-Type: application/pidf+xml Content-Length: 1825
<?xml version='1.0' encoding='UTF-8'?> <presence xmlns:c="urn:ietf:params:xml:ns:pidf:cipid" xmlns:dm="urn:ietf:params:xml:ns:pidf:data-model" xmlns:agp-caps="urn:ag-projects:xml:ns:pidf:caps" xmlns:caps="urn:ietf:params:xml:ns:pidf:caps" xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid" xmlns:agp-pidf="urn:ag-projects:xml:ns:pidf" xmlns="urn:ietf:params:xml:ns:pidf" entity="sip%3A1000%40192.168.65.98"><tuple id="SID-ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99"><status><basic>open</basic><agp-pidf:extended>busy</agp-pidf:extended></status><caps:servcaps><caps:audio>true</caps:audio><caps:message>false</caps:message><caps:text>false</caps:text><agp-caps:file-transfer>false</agp-caps:file-transfer><agp-caps:screen-sharing-server>false</agp-caps:screen-sharing-server><agp-caps:screen-sharing-client>false</agp-caps:screen-sharing-client></caps:servcaps><c:display-name>thomas</c:display-name><agp-pidf:device-info id="ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99"><agp-pidf:description>OPTI-10</agp-pidf:description><agp-pidf:user-agent>:user-agent><agp-pidf:time-offset>60</agp-pidf:time-offset></agp-pidf:device-info><rpid:user-input idle-threshold="600">active</rpid:user-input><dm:deviceID>ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99</dm:deviceID><contact>sip%3A1000%40192.168.65.98</contact><note>On the phone</note><timestamp>2014-01-30T17:53:03.589000+01:00</timestamp></tuple><dm:person id="PID-3dadb95a5ce54f457c35c3c2a9ddf52a"><rpid:activities><rpid:busy/></rpid:activities><dm:timestamp>2014-01-30T17:53:03.589000+01:00</dm:timestamp></dm:person><dm:device id="DID-ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99"><dm:deviceID>ef6d4e1c-bb74-4bd9-8c55-1aeda5750f99</dm:deviceID><dm:note>Blink 0.6.0 (Windows) at OPTI-10</dm:note><dm:timestamp>2014-01-30T17:53:03.589000+01:00</dm:timestamp></dm:device></presence> ------------------------------------------------------------------------ send 778 bytes to udp/[192.168.5.10]:20842 at 16:53:06.432299: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.129.229:2425;rport=20842;branch=z9hG4bKPj18e288b0ce3340a59a0ce2d3134fe4c5;received=192.168.5.10 From: "thomas" <sip:1000@192.168.65.98>;tag=00d8d7ddf78c4a3f9627c52a06e68272 To: "thomas" <sip:1000@192.168.65.98>;tag=2p634jB77Byac Call-ID: 08af2532df5f4c058b66de677cb88f3a CSeq: 1 PUBLISH Contact: <sip:192.168.65.98> Expires: 600 User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer SIP-ETag: yTJwnz2d Content-Length: 0
------------------------------------------------------------------------ recv 828 bytes from udp/[192.168.5.10]:20842 at 16:53:06.446771: ------------------------------------------------------------------------ INVITE sip:1001@192.168.65.98 SIP/2.0 Via: SIP/2.0/UDP 192.168.129.229:2425;rport;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727 Max-Forwards: 70 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98> Contact: <sip:49583627@192.168.129.229:2425> Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22405 INVITE Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER Supported: 100rel, replaces, norefersub, gruu User-Agent: Blink 0.6.0 (Windows) Content-Type: application/sdp Content-Length: 239
v=0 o=- 3600093183 3600093183 IN IP4 192.168.129.229 s=Blink 0.6.0 (Windows) c=IN IP4 192.168.129.229 t=0 0 m=audio 50040 RTP/AVP 8 96 a=rtcp:50041 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=sendrecv ------------------------------------------------------------------------ send 383 bytes to udp/[192.168.5.10]:20842 at 16:53:06.447052: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.129.229:2425;rport=20842;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727;received=192.168.5.10 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98> Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22405 INVITE User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:06.442538 [NOTICE] switch_channel.c:1052 New Channel sofia/internal/1000@192.168.65.98 [505cd4ee-eb6f-4b1b-91e5-2988258e9410] 2014-01-30 17:53:06.442538 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.442538 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.442538 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1000@192.168.65.98) Running State Change CS_NEW 2014-01-30 17:53:06.442538 [DEBUG] sofia.c:7834 sofia/internal/1000@192.168.65.98 receiving invite from 192.168.5.10:20842 version: 1.2.18 -1 64bit 2014-01-30 17:53:06.442538 [DEBUG] sofia.c:7985 IP 192.168.5.10 Rejected by acl "domains". Falling back to Digest auth. send 883 bytes to udp/[192.168.5.10]:20842 at 16:53:06.447832: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.129.229:2425;rport=20842;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727;received=192.168.5.10 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98>;tag=3ZZv6Dva5mmXQ Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22405 INVITE User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="192.168.65.98", nonce="6e75dcd4-79e3-4562-97a4-c88fc292cd6f", algorithm=MD5, qop="auth" Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:06.442538 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.442538 [DEBUG] sofia.c:1794 detaching session 505cd4ee-eb6f-4b1b-91e5-2988258e9410 2014-01-30 17:53:06.442538 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/1000@192.168.65.98) State NEW recv 391 bytes from udp/[192.168.5.10]:20842 at 16:53:06.452970: ------------------------------------------------------------------------ ACK sip:1001@192.168.65.98 SIP/2.0 Via: SIP/2.0/UDP 192.168.129.229:2425;rport;branch=z9hG4bKPjdcf4691faf2f47248598a01604325727 Max-Forwards: 70 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98>;tag=3ZZv6Dva5mmXQ Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22405 ACK User-Agent: Blink 0.6.0 (Windows) Content-Length: 0
------------------------------------------------------------------------ recv 1098 bytes from udp/[192.168.5.10]:20842 at 16:53:06.475581: ------------------------------------------------------------------------ INVITE sip:1001@192.168.65.98 SIP/2.0 Via: SIP/2.0/UDP 192.168.129.229:2425;rport;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c Max-Forwards: 70 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98> Contact: <sip:49583627@192.168.129.229:2425> Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22406 INVITE Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER Supported: 100rel, replaces, norefersub, gruu User-Agent: Blink 0.6.0 (Windows) Proxy-Authorization: Digest username="1000", realm="192.168.65.98", nonce="6e75dcd4-79e3-4562-97a4-c88fc292cd6f", uri="sip:1001@192.168.65.98", response="c388584cea57037857fa19d191927a33", algorithm=MD5, cnonce="4bffd2f3ec9944cf806aae69bb6d87e6", qop=auth, nc=00000001 Content-Type: application/sdp Content-Length: 239
v=0 o=- 3600093183 3600093183 IN IP4 192.168.129.229 s=Blink 0.6.0 (Windows) c=IN IP4 192.168.129.229 t=0 0 m=audio 50040 RTP/AVP 8 96 a=rtcp:50041 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=sendrecv ------------------------------------------------------------------------ send 383 bytes to udp/[192.168.5.10]:20842 at 16:53:06.475828: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.129.229:2425;rport=20842;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c;received=192.168.5.10 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98> Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22406 INVITE User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:06.463222 [DEBUG] sofia.c:1886 Re-attaching to session 505cd4ee-eb6f-4b1b-91e5-2988258e9410 2014-01-30 17:53:06.463222 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.463222 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.482481 [DEBUG] sofia.c:7834 sofia/internal/1000@192.168.65.98 receiving invite from 192.168.5.10:20842 version: 1.2.18 -1 64bit 2014-01-30 17:53:06.482481 [DEBUG] sofia.c:7985 IP 192.168.5.10 Rejected by acl "domains". Falling back to Digest auth. 2014-01-30 17:53:06.482481 [DEBUG] sofia.c:5779 Channel sofia/internal/1000@192.168.65.98 entering state [received][100] 2014-01-30 17:53:06.482481 [DEBUG] sofia.c:5792 Remote SDP: v=0 o=- 3600093183 3600093183 IN IP4 192.168.129.229 s=Blink 0.6.0 (Windows) c=IN IP4 192.168.129.229 t=0 0 m=audio 50040 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=rtcp:50041
2014-01-30 17:53:06.482481 [DEBUG] sofia.c:6039 (sofia/internal/1000@192.168.65.98) State Change CS_NEW -> CS_INIT 2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1000@192.168.65.98) Running State Change CS_INIT 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/1000@192.168.65.98) State INIT 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:87 sofia/internal/1000@192.168.65.98 SOFIA INIT 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:127 (sofia/internal/1000@192.168.65.98) State Change CS_INIT -> CS_ROUTING 2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/1000@192.168.65.98) State INIT going to sleep 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1000@192.168.65.98) Running State Change CS_ROUTING 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:2165 (sofia/internal/1000@192.168.65.98) Callstate Change DOWN -> RINGING 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1000@192.168.65.98) State ROUTING 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:150 sofia/internal/1000@192.168.65.98 SOFIA ROUTING 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:117 sofia/internal/1000@192.168.65.98 Standard ROUTING 2014-01-30 17:53:06.482481 [INFO] mod_dialplan_xml.c:558 Processing thomas <1000>->1001 in context default Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->unloop] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1000@192.168.65.98 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1000@192.168.65.98 Action set(open=true) Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1000@192.168.65.98 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->redial] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->global] continue=true Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/1000@192.168.65.98 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [global] ${switch_r_sdp}(v=0 o=- 3600093183 3600093183 IN IP4 192.168.129.229 s=Blink 0.6.0 (Windows) c=IN IP4 192.168.129.229 t=0 0 m=audio 50040 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=rtcp:50041 ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never Dialplan: sofia/internal/1000@192.168.65.98 Absolute Condition [global] Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1000@192.168.65.98 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->call_return] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->del-group] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->add-group] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1000@192.168.65.98 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1000@192.168.65.98 Action export(dialed_extension=1001) Dialplan: sofia/internal/1000@192.168.65.98 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1000@192.168.65.98 Action bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1000@192.168.65.98 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1000@192.168.65.98 Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/1000@192.168.65.98 Action set(ringback=${us-ring}) Dialplan: sofia/internal/1000@192.168.65.98 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1000@192.168.65.98 Action set(call_timeout=30) Dialplan: sofia/internal/1000@192.168.65.98 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1000@192.168.65.98 Action set(continue_on_fail=true) Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1000@192.168.65.98 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/internal/1000@192.168.65.98 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1000@192.168.65.98 Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1000@192.168.65.98 Action answer() Dialplan: sofia/internal/1000@192.168.65.98 Action sleep(1000) Dialplan: sofia/internal/1000@192.168.65.98 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1000@192.168.65.98) State Change CS_ROUTING -> CS_EXECUTE 2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1000@192.168.65.98) State ROUTING going to sleep 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1000@192.168.65.98) Running State Change CS_EXECUTE 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1000@192.168.65.98) State EXECUTE 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:243 sofia/internal/1000@192.168.65.98 SOFIA EXECUTE 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1000@192.168.65.98 Standard EXECUTE EXECUTE sofia/internal/1000@192.168.65.98 set(open=true) 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402 sofia/internal/1000@192.168.65.98 SET [open]=[true] EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-spymap/1000/505cd4ee-eb6f-4b1b-91e5-2988258e9410) EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-last_dial/1000/1001) EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-last_dial/global/505cd4ee-eb6f-4b1b-91e5-2988258e9410) EXECUTE sofia/internal/1000@192.168.65.98 export(RFC2822_DATE=Thu, 30 Jan 2014 17:53:06 +0100) 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1244 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100] EXECUTE sofia/internal/1000@192.168.65.98 export(dialed_extension=1001) 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1244 EXPORT (export_vars) [dialed_extension]=[1001] EXECUTE sofia/internal/1000@192.168.65.98 bind_meta_app(1 b s execute_extension::dx XML features) 2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1000@192.168.65.98 bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/1000.2014-01-30-17-53-06.wav) 2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *2 record_session::/var/lib/freeswitch/recordings/1000.2014-01-30-17-53-06.wav EXECUTE sofia/internal/1000@192.168.65.98 bind_meta_app(3 b s execute_extension::cf XML features) 2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1000@192.168.65.98 bind_meta_app(4 b s execute_extension::att_xfer XML features) 2014-01-30 17:53:06.482481 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/internal/1000@192.168.65.98 set(ringback=%(2000,4000,440,480)) 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402 sofia/internal/1000@192.168.65.98 SET [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/internal/1000@192.168.65.98 set(transfer_ringback=local_stream://moh) 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402 sofia/internal/1000@192.168.65.98 SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1000@192.168.65.98 set(call_timeout=30) 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402 sofia/internal/1000@192.168.65.98 SET [call_timeout]=[30] EXECUTE sofia/internal/1000@192.168.65.98 set(hangup_after_bridge=true) 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402 sofia/internal/1000@192.168.65.98 SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1000@192.168.65.98 set(continue_on_fail=true) 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402 sofia/internal/1000@192.168.65.98 SET [continue_on_fail]=[true] EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-call_return/1001/1000) EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-last_dial_ext/1001/505cd4ee-eb6f-4b1b-91e5-2988258e9410) EXECUTE sofia/internal/1000@192.168.65.98 set(called_party_callgroup=techsupport) 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402 sofia/internal/1000@192.168.65.98 SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-last_dial_ext/techsupport/505cd4ee-eb6f-4b1b-91e5-2988258e9410) EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-last_dial_ext/global/505cd4ee-eb6f-4b1b-91e5-2988258e9410) EXECUTE sofia/internal/1000@192.168.65.98 hash(insert/192.168.65.98-last_dial/techsupport/505cd4ee-eb6f-4b1b-91e5-2988258e9410) EXECUTE sofia/internal/1000@192.168.65.98 bridge(user/1001@192.168.65.98) 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198 sofia/internal/1000@192.168.65.98 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100] to event 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198 sofia/internal/1000@192.168.65.98 EXPORTING[export_vars] [dialed_extension]=[1001] to event 2014-01-30 17:53:06.482481 [DEBUG] switch_ivr_originate.c:2061 Parsing global variables 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198 sofia/internal/1000@192.168.65.98 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100] to event 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198 sofia/internal/1000@192.168.65.98 EXPORTING[export_vars] [dialed_extension]=[1001] to event 2014-01-30 17:53:06.482481 [DEBUG] switch_ivr_originate.c:2061 Parsing global variables 2014-01-30 17:53:06.482481 [DEBUG] switch_event.c:1661 Parsing variable [sip_invite_domain]=[192.168.65.98] 2014-01-30 17:53:06.482481 [DEBUG] switch_event.c:1661 Parsing variable [presence_id]=[1001@192.168.65.98] 2014-01-30 17:53:06.482481 [NOTICE] switch_channel.c:1052 New Channel sofia/internal/sip:1001@192.168.65.124:3588 [cab230d1-27d2-443c-b531-81dac71c027c] 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:5231 (sofia/internal/sip:1001@192.168.65.124:3588) State Change CS_NEW -> CS_INIT 2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:5301 [zrtp_passthru] Setting a-leg inherit_codec=true 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:5304 [zrtp_passthru] Setting b-leg absolute_codec_string='PCMA@8000h@20i@64000b' 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.65.124:3588) Running State Change CS_INIT 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/sip:1001@192.168.65.124:3588) State INIT 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:87 sofia/internal/sip:1001@192.168.65.124:3588 SOFIA INIT 2014-01-30 17:53:06.482481 [DEBUG] sofia_glue.c:2738 sofia/internal/sip:1001@192.168.65.124:3588 sending invite version: 1.2.18 -1 64bit Local SDP: v=0 o=FreeSWITCH 1391074358 1391074359 IN IP4 192.168.65.98 s=FreeSWITCH c=IN IP4 192.168.65.98 t=0 0 m=audio 26428 RTP/AVP 8 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv
send 1185 bytes to udp/[192.168.65.124]:3588 at 16:53:06.501475: ------------------------------------------------------------------------ INVITE sip:1001@192.168.65.124:3588;rinstance=c88f5661c51fa917 SIP/2.0 Via: SIP/2.0/UDP 192.168.65.98;rport;branch=z9hG4bK27cZcy3ZyrZjj Max-Forwards: 69 From: "Extension 1000" <sip:1000@192.168.65.98>;tag=5Hjea4XHZ602e To: <sip:1001@192.168.65.124:3588;rinstance=c88f5661c51fa917> Call-ID: d5227656-0471-1232-bd8c-08002740dafd CSeq: 55214329 INVITE Contact: <sip:mod_sofia@192.168.65.98:5060> User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 203 X-FS-Support: update_display,send_info Remote-Party-ID: "Extension 1000" <sip:1000@192.168.65.98>;party=calling;screen=yes;privacy=off
v=0 o=FreeSWITCH 1391074358 1391074359 IN IP4 192.168.65.98 s=FreeSWITCH c=IN IP4 192.168.65.98 t=0 0 m=audio 26428 RTP/AVP 8 101 13 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:127 (sofia/internal/sip:1001@192.168.65.124:3588) State Change CS_INIT -> CS_ROUTING 2014-01-30 17:53:06.482481 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/sip:1001@192.168.65.124:3588) State INIT going to sleep 2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.65.124:3588) Running State Change CS_ROUTING 2014-01-30 17:53:06.502511 [DEBUG] sofia.c:5779 Channel sofia/internal/sip:1001@192.168.65.124:3588 entering state [calling][0] 2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/sip:1001@192.168.65.124:3588) State ROUTING 2014-01-30 17:53:06.502511 [DEBUG] mod_sofia.c:150 sofia/internal/sip:1001@192.168.65.124:3588 SOFIA ROUTING 2014-01-30 17:53:06.502511 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:1001@192.168.65.124:3588) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2014-01-30 17:53:06.502511 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/sip:1001@192.168.65.124:3588) State ROUTING going to sleep 2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.65.124:3588) Running State Change CS_CONSUME_MEDIA 2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:490 (sofia/internal/sip:1001@192.168.65.124:3588) State CONSUME_MEDIA 2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:490 (sofia/internal/sip:1001@192.168.65.124:3588) State CONSUME_MEDIA going to sleep recv 312 bytes from udp/[192.168.65.124]:3588 at 16:53:06.583154: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.65.98;rport=5060;branch=z9hG4bK27cZcy3ZyrZjj To: <sip:1001@192.168.65.124:3588;rinstance=c88f5661c51fa917> From: "Extension 1000" <sip:1000@192.168.65.98>;tag=5Hjea4XHZ602e Call-ID: d5227656-0471-1232-bd8c-08002740dafd CSeq: 55214329 INVITE Content-Length: 0
------------------------------------------------------------------------ recv 438 bytes from udp/[192.168.65.124]:3588 at 16:53:06.618431: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.65.98;rport=5060;branch=z9hG4bK27cZcy3ZyrZjj Contact: <sip:1001@192.168.65.124:3588> To: <sip:1001@192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41 From: "Extension 1000"<sip:1000@192.168.65.98>;tag=5Hjea4XHZ602e Call-ID: d5227656-0471-1232-bd8c-08002740dafd CSeq: 55214329 INVITE User-Agent: X-Lite release 4.5.5 stamp 71241 Allow-Events: hold, talk Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:06.602764 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:06.602764 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:06.602764 [DEBUG] sofia.c:5779 Channel sofia/internal/sip:1001@192.168.65.124:3588 entering state [proceeding][180] 2014-01-30 17:53:06.602764 [NOTICE] sofia.c:5874 Ring-Ready sofia/internal/sip:1001@192.168.65.124:3588! 2014-01-30 17:53:06.602764 [DEBUG] switch_channel.c:3239 (sofia/internal/sip:1001@192.168.65.124:3588) Callstate Change DOWN -> RINGING 2014-01-30 17:53:06.622431 [INFO] switch_ivr_originate.c:1191 Sending early media 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5276 Audio Codec Compare [PCMA:8:8000:20:64000]/[G722:9:8000:20:64000] 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5276 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5276 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3184 Set Codec sofia/internal/1000@192.168.65.98 PCMA/8000 20 ms 160 samples 64000 bits 2014-01-30 17:53:06.622431 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.65.98 Original read codec set to PCMA:8 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:5445 Set 2833 dtmf send/recv payload to 96 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3443 AUDIO RTP [sofia/internal/1000@192.168.65.98] 192.168.65.98 port 17870 -> 192.168.129.229 port 50040 codec: 8 ms: 20 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:2033 Starting timer [soft] 160 bytes per 20ms 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: START SESSION INITIALIZATION. sID=0. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: ZID=633061383431363264366363. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: Loading User's profile: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: allowclear: OFF 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: autosecure: ON 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: disclose_bit: OFF 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: signal. role: Unknown 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: TTL: 4294967295 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: SAS schemes: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 B256 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 B32 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: Ciphers: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 AES3 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 AES1 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: PK schemes: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 EC25 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 DH3k 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 DH2k 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 Mult 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: ATL: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 HS32 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: Hashes: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 S256 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: Session initialization - DONE. sID=0.
2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: ATTACH NEW STREAM to sID=0: 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp]: Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: Empty slot was found - initializing new stream with ID=0. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: Preparing ZRTP Hello according to the Session profile. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp main]: ATTACH NEW STREAM - DONE. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp engine]: START STREAM ID=0 mode=CLEAR state=ACTIVE. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp]: Stream ID=0 CLEAR switching <ACTIVE> ---> <START>. 2014-01-30 17:53:06.622431 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42140 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3710 Set 2833 dtmf send payload to 96 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf receive payload to 96 2014-01-30 17:53:06.622431 [DEBUG] sofia_glue.c:3743 sofia/internal/1000@192.168.65.98 Set rtp dtmf delay to 40 2014-01-30 17:53:06.622431 [NOTICE] sofia_glue.c:4354 Pre-Answer sofia/internal/1000@192.168.65.98! 2014-01-30 17:53:06.622431 [DEBUG] switch_channel.c:3365 (sofia/internal/1000@192.168.65.98) Callstate Change RINGING -> EARLY 2014-01-30 17:53:06.622431 [DEBUG] mod_sofia.c:2885 Ring SDP: v=0 o=FreeSWITCH 1391082916 1391082917 IN IP4 192.168.65.98 s=FreeSWITCH c=IN IP4 192.168.65.98 t=0 0 m=audio 17870 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ptime:20 a=sendrecv
send 1169 bytes to udp/[192.168.5.10]:20842 at 16:53:06.630060: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.129.229:2425;rport=20842;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c;received=192.168.5.10 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98>;tag=48rN88ce2XagK Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22406 INVITE Contact: <sip:1001@192.168.65.98:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 219 Remote-Party-ID: "1001" <sip:1001@192.168.65.98>;party=calling;privacy=off;screen=no
v=0 o=FreeSWITCH 1391082916 1391082917 IN IP4 192.168.65.98 s=FreeSWITCH c=IN IP4 192.168.65.98 t=0 0 m=audio 17870 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ptime:20 ------------------------------------------------------------------------ 2014-01-30 17:53:06.622431 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.622431 [DEBUG] sofia.c:5779 Channel sofia/internal/1000@192.168.65.98 entering state [early][183] 2014-01-30 17:53:06.622431 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:06.622431 [DEBUG] switch_ivr_originate.c:1248 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2014-01-30 17:53:06.622431 [DEBUG] switch_core_codec.c:219 sofia/internal/1000@192.168.65.98 Push codec L16:70 2014-01-30 17:53:06.622431 [DEBUG] switch_ivr_originate.c:1316 Play Ringback Tone [%(2000,4000,440,480)] 2014-01-30 17:53:06.682455 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42141 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:06.782481 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42142 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:06.882499 [INFO] switch_rtp.c:3730 Auto Changing port from 192.168.129.229:50040 to 192.168.5.10:53756 2014-01-30 17:53:06.982476 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42143 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:07.182473 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42144 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:07.383303 [DEBUG] switch_rtp.c:948 [ zrtp engine]: WARNING! HELLO have been resent 5 times without a response. Raising ZRTP_EVENT_NO_ZRTP_QUICK event. ID=0 2014-01-30 17:53:07.383303 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42145 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:07.582444 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42146 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:07.782471 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42147 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:08.002871 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42148 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:08.203152 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42149 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:08.402496 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42150 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:08.602538 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42151 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:08.803222 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42152 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:09.022481 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42153 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:09.222457 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42154 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:09.422492 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42155 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:09.622497 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42156 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:09.842523 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42157 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:10.043027 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42158 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:10.242993 [DEBUG] switch_rtp.c:948 [ zrtp utils]: Send <HELLO> ssrc=1427653722 seq=42159 size=144. Stream 0:CLEAR:START 2014-01-30 17:53:10.442488 [DEBUG] switch_rtp.c:948 [ zrtp engine]: WARNING! HELLO Max retransmissions count reached (20 retries). ID=0 2014-01-30 17:53:10.442488 [DEBUG] switch_rtp.c:948 [ zrtp]: Stream ID=0 CLEAR switching <START> ---> <NOZRTP>. recv 455 bytes from udp/[192.168.65.124]:3588 at 16:53:11.401846: ------------------------------------------------------------------------ SIP/2.0 488 Not Acceptable Here Via: SIP/2.0/UDP 192.168.65.98;rport=5060;branch=z9hG4bK27cZcy3ZyrZjj To: <sip:1001@192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41 From: "Extension 1000"<sip:1000@192.168.65.98>;tag=5Hjea4XHZ602e Call-ID: d5227656-0471-1232-bd8c-08002740dafd CSeq: 55214329 INVITE User-Agent: X-Lite release 4.5.5 stamp 71241 Warning: 305 devnull "SDP: Incompatible media format: no common codec" Content-Length: 0
------------------------------------------------------------------------ send 384 bytes to udp/[192.168.65.124]:3588 at 16:53:11.403623: ------------------------------------------------------------------------ ACK sip:1001@192.168.65.124:3588;rinstance=c88f5661c51fa917 SIP/2.0 Via: SIP/2.0/UDP 192.168.65.98;rport;branch=z9hG4bK27cZcy3ZyrZjj Max-Forwards: 69 From: "Extension 1000" <sip:1000@192.168.65.98>;tag=5Hjea4XHZ602e To: <sip:1001@192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41 Call-ID: d5227656-0471-1232-bd8c-08002740dafd CSeq: 55214329 ACK Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:11.407504 [DEBUG] sofia.c:5779 Channel sofia/internal/sip:1001@192.168.65.124:3588 entering state [terminated][488] 2014-01-30 17:53:11.407504 [NOTICE] sofia.c:6623 Hangup sofia/internal/sip:1001@192.168.65.124:3588 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION] 2014-01-30 17:53:11.407504 [DEBUG] switch_channel.c:3184 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [KILL] 2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.65.124:3588) Running State Change CS_HANGUP 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/sip:1001@192.168.65.124:3588) State HANGUP 2014-01-30 17:53:11.407504 [DEBUG] mod_sofia.c:506 Channel sofia/internal/sip:1001@192.168.65.124:3588 hanging up, cause: INCOMPATIBLE_DESTINATION 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:1001@192.168.65.124:3588 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/sip:1001@192.168.65.124:3588) State HANGUP going to sleep 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:690 (sofia/internal/sip:1001@192.168.65.124:3588) Callstate Change RINGING -> HANGUP 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:447 (sofia/internal/sip:1001@192.168.65.124:3588) State Change CS_HANGUP -> CS_REPORTING 2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1001@192.168.65.124:3588) Running State Change CS_REPORTING 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/sip:1001@192.168.65.124:3588) State REPORTING 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:1001@192.168.65.124:3588 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/sip:1001@192.168.65.124:3588) State REPORTING going to sleep 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:441 (sofia/internal/sip:1001@192.168.65.124:3588) State Change CS_REPORTING -> CS_DESTROY 2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1001@192.168.65.124:3588 [BREAK] 2014-01-30 17:53:11.407504 [DEBUG] switch_core_session.c:1559 Session 2 (sofia/internal/sip:1001@192.168.65.124:3588) Locked, Waiting on external entities 2014-01-30 17:53:11.424472 [DEBUG] switch_core_codec.c:244 sofia/internal/1000@192.168.65.98 Restore previous codec PCMA:8. 2014-01-30 17:53:11.424472 [DEBUG] switch_ivr_originate.c:3639 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2014-01-30 17:53:11.424472 [NOTICE] switch_ivr_originate.c:2662 Cannot create outgoing channel of type [user] cause: [INCOMPATIBLE_DESTINATION] 2014-01-30 17:53:11.424472 [DEBUG] switch_ivr_originate.c:3639 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2014-01-30 17:53:11.424472 [INFO] mod_dptools.c:3201 Originate Failed. Cause: INCOMPATIBLE_DESTINATION EXECUTE sofia/internal/1000@192.168.65.98 answer() 2014-01-30 17:53:11.424472 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1000@192.168.65.98: v=0 o=FreeSWITCH 1391082916 1391082918 IN IP4 192.168.65.98 s=FreeSWITCH c=IN IP4 192.168.65.98 t=0 0 m=audio 17870 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ptime:20 a=sendrecv
send 1139 bytes to udp/[192.168.5.10]:20842 at 16:53:11.430754: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.129.229:2425;rport=20842;branch=z9hG4bKPjd2684561262d4d288280a129a7f9846c;received=192.168.5.10 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98>;tag=48rN88ce2XagK Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22406 INVITE Contact: <sip:1001@192.168.65.98:5060;transport=udp> User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, conference, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 219 Remote-Party-ID: "Outbound Call" <sip:1001@192.168.65.98>;party=calling;privacy=off;screen=no
v=0 o=FreeSWITCH 1391082916 1391082917 IN IP4 192.168.65.98 s=FreeSWITCH c=IN IP4 192.168.65.98 t=0 0 m=audio 17870 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ptime:20 ------------------------------------------------------------------------ 2014-01-30 17:53:11.424472 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:11.424472 [DEBUG] sofia.c:5779 Channel sofia/internal/1000@192.168.65.98 entering state [completed][200] 2014-01-30 17:53:11.424472 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:11.424472 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1000@192.168.65.98] has been answered 2014-01-30 17:53:11.424472 [DEBUG] switch_channel.c:3644 (sofia/internal/1000@192.168.65.98) Callstate Change EARLY -> ACTIVE EXECUTE sofia/internal/1000@192.168.65.98 sleep(1000) 2014-01-30 17:53:11.424472 [NOTICE] switch_core_session.c:1577 Session 2 (sofia/internal/sip:1001@192.168.65.124:3588) Ended 2014-01-30 17:53:11.424472 [NOTICE] switch_core_session.c:1581 Close Channel sofia/internal/sip:1001@192.168.65.124:3588 [CS_DESTROY] 2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:566 (sofia/internal/sip:1001@192.168.65.124:3588) Callstate Change HANGUP -> DOWN 2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/sip:1001@192.168.65.124:3588) Running State Change CS_DESTROY 2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1001@192.168.65.124:3588) State DESTROY 2014-01-30 17:53:11.424472 [DEBUG] mod_sofia.c:399 sofia/internal/sip:1001@192.168.65.124:3588 SOFIA DESTROY 2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:1001@192.168.65.124:3588 Standard DESTROY 2014-01-30 17:53:11.424472 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1001@192.168.65.124:3588) State DESTROY going to sleep recv 410 bytes from udp/[192.168.5.10]:20842 at 16:53:11.464680: ------------------------------------------------------------------------ ACK sip:1001@192.168.65.98:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.129.229:2425;rport;branch=z9hG4bKPjdd90edd2522045c79127fa96e72c6487 Max-Forwards: 70 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98>;tag=48rN88ce2XagK Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22406 ACK User-Agent: Blink 0.6.0 (Windows) Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:11.488073 [DEBUG] sofia.c:5779 Channel sofia/internal/1000@192.168.65.98 entering state [ready][200] EXECUTE sofia/internal/1000@192.168.65.98 bridge(loopback/app=voicemail:default 192.168.65.98 1001) 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1765 (sofia/internal/1000@192.168.65.98) Callstate Change ACTIVE -> RING_WAIT 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1198 sofia/internal/1000@192.168.65.98 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 30 Jan 2014 17:53:06 +0100] to event 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1198 sofia/internal/1000@192.168.65.98 EXPORTING[export_vars] [dialed_extension]=[1001] to event 2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_originate.c:2061 Parsing global variables 2014-01-30 17:53:12.442539 [NOTICE] switch_channel.c:1052 New Channel loopback/app=voicemail:default 192.168.65.98 1001-a [0ec9cff0-d6ff-48f7-8cbe-4b18a663e7cb] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:157 loopback/app=voicemail:default 192.168.65.98 1001-a setup codec PCMA/8000/20 2014-01-30 17:53:12.442539 [NOTICE] switch_channel.c:1050 Rename Channel loopback/app=voicemail:default 192.168.65.98 1001-a->loopback/voicemail-a [0ec9cff0-d6ff-48f7-8cbe-4b18a663e7cb] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:1158 (loopback/voicemail-a) State Change CS_NEW -> CS_INIT 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-a) Running State Change CS_INIT 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455 (loopback/voicemail-a) State INIT 2014-01-30 17:53:12.442539 [NOTICE] switch_channel.c:1052 New Channel loopback/voicemail-b [89b050fa-b391-488f-882b-ca3607f1dabd] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:157 loopback/voicemail-b setup codec PCMA/8000/20 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:272 (loopback/voicemail-b) State Change CS_NEW -> CS_INIT 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-b [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:357 (loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455 (loopback/voicemail-a) State INIT going to sleep 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-a) Running State Change CS_ROUTING 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471 (loopback/voicemail-a) State ROUTING 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:389 loopback/voicemail-a CHANNEL ROUTING 2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_originate.c:67 (loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471 (loopback/voicemail-a) State ROUTING going to sleep 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:490 (loopback/voicemail-a) State CONSUME_MEDIA 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:648 CHANNEL CONSUME_MEDIA 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:490 (loopback/voicemail-a) State CONSUME_MEDIA going to sleep 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-b) Running State Change CS_INIT 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455 (loopback/voicemail-b) State INIT 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:357 (loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-b [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:455 (loopback/voicemail-b) State INIT going to sleep 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-b) Running State Change CS_ROUTING 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:2165 (loopback/voicemail-b) Callstate Change DOWN -> RINGING 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471 (loopback/voicemail-b) State ROUTING 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:389 loopback/voicemail-b CHANNEL ROUTING 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:408 (loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-b [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:471 (loopback/voicemail-b) State ROUTING going to sleep 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-b) Running State Change CS_EXECUTE 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:478 (loopback/voicemail-b) State EXECUTE 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:431 loopback/voicemail-b CHANNEL EXECUTE 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:209 loopback/voicemail-b Standard EXECUTE EXECUTE loopback/voicemail-b pre_answer() 2014-01-30 17:53:12.442539 [NOTICE] mod_loopback.c:945 Pre-Answer loopback/voicemail-a! 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:3361 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:3365 (loopback/voicemail-a) Callstate Change DOWN -> EARLY 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:871 Send signal loopback/voicemail-b [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:12.442539 [NOTICE] mod_dptools.c:1260 Pre-Answer loopback/voicemail-b! 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:3365 (loopback/voicemail-b) Callstate Change RINGING -> EARLY EXECUTE loopback/voicemail-b voicemail(default 192.168.65.98 1001) 2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_originate.c:3495 Originate Resulted in Success: [loopback/voicemail-a] 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1969 (sofia/internal/1000@192.168.65.98) Callstate Change RING_WAIT -> ACTIVE 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:871 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] switch_ivr_bridge.c:1426 (loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2014-01-30 17:53:12.442539 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA 2014-01-30 17:53:12.442539 [DEBUG] switch_core_state_machine.c:481 (loopback/voicemail-a) State EXCHANGE_MEDIA 2014-01-30 17:53:12.442539 [DEBUG] mod_loopback.c:610 CHANNEL LOOPBACK 2014-01-30 17:53:12.542890 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en] 2014-01-30 17:53:12.542890 [DEBUG] switch_ivr_play_say.c:251 Handle play-file:[voicemail/vm-person.wav] (en:en) 2014-01-30 17:53:12.542890 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 2014-01-30 17:53:13.922469 [DEBUG] switch_ivr_play_say.c:1717 done playing file /usr/share/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav 2014-01-30 17:53:14.023721 [DEBUG] switch_ivr_play_say.c:251 Handle say:[1001] (en:en) 2014-01-30 17:53:14.023721 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 2014-01-30 17:53:16.263327 [DEBUG] switch_ivr_play_say.c:1717 done playing file file_string://digits/1.wav!digits/0.wav!digits/0.wav!digits/1.wav 2014-01-30 17:53:16.363379 [DEBUG] switch_ivr_play_say.c:251 Handle play-file:[voicemail/vm-not_available.wav] (en:en) 2014-01-30 17:53:16.363379 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 2014-01-30 17:53:17.342459 [DEBUG] switch_ivr_play_say.c:1717 done playing file /usr/share/freeswitch/sounds/en/us/callie/voicemail/vm-not_available.wav 2014-01-30 17:53:17.442546 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en] 2014-01-30 17:53:17.442546 [DEBUG] switch_ivr_play_say.c:251 Handle play-file:[voicemail/vm-record_message.wav] (en:en) 2014-01-30 17:53:17.442546 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms recv 410 bytes from udp/[192.168.5.10]:20842 at 16:53:18.270540: ------------------------------------------------------------------------ BYE sip:1001@192.168.65.98:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.129.229:2425;rport;branch=z9hG4bKPje4e3e31a701c4d77b2b7d5dde2de9f6d Max-Forwards: 70 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98>;tag=48rN88ce2XagK Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22407 BYE User-Agent: Blink 0.6.0 (Windows) Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:18.262629 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:18.283431 [NOTICE] sofia.c:737 Hangup sofia/internal/1000@192.168.65.98 [CS_EXECUTE] [NORMAL_CLEARING] 2014-01-30 17:53:18.283431 [DEBUG] switch_channel.c:3184 Send signal sofia/internal/1000@192.168.65.98 [KILL] 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1000@192.168.65.98 [BREAK] send 552 bytes to udp/[192.168.5.10]:20842 at 16:53:18.284629: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.129.229:2425;rport=20842;branch=z9hG4bKPje4e3e31a701c4d77b2b7d5dde2de9f6d;received=192.168.5.10 From: "thomas" <sip:1000@192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a To: <sip:1001@192.168.65.98>;tag=48rN88ce2XagK Call-ID: bb25748be1f94505a7132e68f5576bae CSeq: 22407 BYE User-Agent: FreeSWITCH-mod_sofia/1.2.18-1~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Content-Length: 0
------------------------------------------------------------------------ 2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD DONE [sofia/internal/1000@192.168.65.98] 2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:658 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:557 sofia/internal/1000@192.168.65.98 ending bridge by request from write function 2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD DONE [loopback/voicemail-a] 2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:658 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:18.283431 [NOTICE] switch_ivr_bridge.c:719 Hangup loopback/voicemail-a [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL] 2014-01-30 17:53:18.283431 [DEBUG] switch_channel.c:3184 Send signal loopback/voicemail-a [KILL] 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:481 (loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-a) Running State Change CS_HANGUP 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679 (loopback/voicemail-a) State HANGUP 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:535 loopback/voicemail-a CHANNEL HANGUP 2014-01-30 17:53:18.283431 [NOTICE] mod_loopback.c:551 Hangup loopback/voicemail-b [CS_EXECUTE] [ORIGINATOR_CANCEL] 2014-01-30 17:53:18.283431 [DEBUG] switch_channel.c:3184 Send signal loopback/voicemail-b [KILL] 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-b [BREAK] 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:48 loopback/voicemail-a Standard HANGUP, cause: ORIGINATOR_CANCEL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679 (loopback/voicemail-a) State HANGUP going to sleep 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:690 (loopback/voicemail-a) Callstate Change EARLY -> HANGUP 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:447 (loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-a) Running State Change CS_REPORTING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762 (loopback/voicemail-a) State REPORTING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:92 loopback/voicemail-a Standard REPORTING, cause: ORIGINATOR_CANCEL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762 (loopback/voicemail-a) State REPORTING going to sleep 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:441 (loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-a [BREAK] 2014-01-30 17:53:18.283431 [DEBUG] mod_loopback.c:588 loopback/voicemail-a CHANNEL KILL 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1559 Session 3 (loopback/voicemail-a) Locked, Waiting on external entities 2014-01-30 17:53:18.283431 [DEBUG] switch_ivr_bridge.c:1527 sofia/internal/1000@192.168.65.98 skip receive message [UNBRIDGE] (channel is hungup already) 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:2810 sofia/internal/1000@192.168.65.98 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1000@192.168.65.98) State EXECUTE going to sleep 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1000@192.168.65.98) Running State Change CS_HANGUP 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/1000@192.168.65.98) State HANGUP 2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:500 sofia/internal/1000@192.168.65.98 Overriding SIP cause 480 with 488 from the other leg 2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1000@192.168.65.98 hanging up, cause: NORMAL_CLEARING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1000@192.168.65.98 Standard HANGUP, cause: NORMAL_CLEARING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/1000@192.168.65.98) State HANGUP going to sleep 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:690 (sofia/internal/1000@192.168.65.98) Callstate Change ACTIVE -> HANGUP 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:447 (sofia/internal/1000@192.168.65.98) State Change CS_HANGUP -> CS_REPORTING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1000@192.168.65.98) Running State Change CS_REPORTING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/1000@192.168.65.98) State REPORTING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:92 sofia/internal/1000@192.168.65.98 Standard REPORTING, cause: NORMAL_CLEARING 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/1000@192.168.65.98) State REPORTING going to sleep 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:441 (sofia/internal/1000@192.168.65.98) State Change CS_REPORTING -> CS_DESTROY 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1000@192.168.65.98 [BREAK] 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1559 Session 1 (sofia/internal/1000@192.168.65.98) Locked, Waiting on external entities 2014-01-30 17:53:18.283431 [NOTICE] switch_core_session.c:1577 Session 1 (sofia/internal/1000@192.168.65.98) Ended 2014-01-30 17:53:18.283431 [NOTICE] switch_core_session.c:1581 Close Channel sofia/internal/1000@192.168.65.98 [CS_DESTROY] 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:566 (sofia/internal/1000@192.168.65.98) Callstate Change HANGUP -> DOWN 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/1000@192.168.65.98) Running State Change CS_DESTROY 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/1000@192.168.65.98) State DESTROY 2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:399 sofia/internal/1000@192.168.65.98 SOFIA DESTROY 2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp engine]: STOP STREAM ID=0 mode=CLEAR state=NOZRTP. 2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp]: Stream ID=0 UNKNOWN switching <NONE> ---> <NONE>. 2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2014-01-30 17:53:18.283431 [DEBUG] switch_rtp.c:948 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:99 sofia/internal/1000@192.168.65.98 Standard DESTROY 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/1000@192.168.65.98) State DESTROY going to sleep 2014-01-30 17:53:18.302529 [DEBUG] switch_ivr_play_say.c:1717 done playing file /usr/share/freeswitch/sounds/en/us/callie/voicemail/vm-record_message.wav 2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:2810 loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:478 (loopback/voicemail-b) State EXECUTE going to sleep 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-b) Running State Change CS_HANGUP 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:679 (loopback/voicemail-b) State HANGUP 2014-01-30 17:53:18.302529 [DEBUG] mod_loopback.c:535 loopback/voicemail-b CHANNEL HANGUP 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:48 loopback/voicemail-b Standard HANGUP, cause: ORIGINATOR_CANCEL 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:679 (loopback/voicemail-b) State HANGUP going to sleep 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:690 (loopback/voicemail-b) Callstate Change EARLY -> HANGUP 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:447 (loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING 2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-b [BREAK] 2014-01-30 17:53:18.302529 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:415 (loopback/voicemail-b) Running State Change CS_REPORTING 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:762 (loopback/voicemail-b) State REPORTING 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:92 loopback/voicemail-b Standard REPORTING, cause: ORIGINATOR_CANCEL 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:762 (loopback/voicemail-b) State REPORTING going to sleep 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:441 (loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY 2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:1351 Send signal loopback/voicemail-b [BREAK] 2014-01-30 17:53:18.302529 [DEBUG] mod_loopback.c:588 loopback/voicemail-b CHANNEL KILL 2014-01-30 17:53:18.302529 [DEBUG] switch_core_session.c:1559 Session 4 (loopback/voicemail-b) Locked, Waiting on external entities 2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1577 Session 4 (loopback/voicemail-b) Ended 2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1581 Close Channel loopback/voicemail-b [CS_DESTROY] 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:566 (loopback/voicemail-b) Callstate Change HANGUP -> DOWN 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:569 (loopback/voicemail-b) Running State Change CS_DESTROY 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579 (loopback/voicemail-b) State DESTROY 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:99 loopback/voicemail-b Standard DESTROY 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579 (loopback/voicemail-b) State DESTROY going to sleep 2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1577 Session 3 (loopback/voicemail-a) Ended 2014-01-30 17:53:18.302529 [NOTICE] switch_core_session.c:1581 Close Channel loopback/voicemail-a [CS_DESTROY] 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:566 (loopback/voicemail-a) Callstate Change HANGUP -> DOWN 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:569 (loopback/voicemail-a) Running State Change CS_DESTROY 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579 (loopback/voicemail-a) State DESTROY 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:99 loopback/voicemail-a Standard DESTROY 2014-01-30 17:53:18.302529 [DEBUG] switch_core_state_machine.c:579 (loopback/voicemail-a) State DESTROY going to sleep recv 2307 bytes from udp/[192.168.5.10]:20842 at 16:53:18.329959:
--------------------- one client (blink, 1000) supports only PCMA, the other client (bria, 1001) supports only PCMU. i didnt touch the default config of the freeswitch on a debian system.
thank you very much for help!
best, thomas
2014-01-28 Brian West <brian@freeswitch.org>:
Logs, with sip trace on please.
-- Brian West brian@freeswitch.org FreeSWITCH Solutions, LLC PO BOX 2531 Brookfield, WI 53008-2531 Twitter: @FreeSWITCH , @briankwest http://www.freeswitchbook.com http://www.freeswitchcookbook.com
T: +1.918.420.9001 | F: +1.918.420.9002 | M: +1.918.424.WEST iNUM: +883 5100 1420 9001 ISN: 410*543 Skype:briankwest PGP Key: http://www.bkw.org/key.txt (AB93356707C76CED)
On Jan 28, 2014, at 9:13 AM, thomas peterseil <thomas.peterseil@gmail.com> wrote:
i have the same problem. i am running a FS with the default config 1000 supports only PCMA and 1001 only PCMU (one client is blink, the other jitsi), the call between 1000 and 1001 doesnt work. as soon as i enable the same codecs on both clients, it works without any problem. thanks a lot for your help!
best regards, thomas
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org