[Freeswitch-users] Want to use REFER to do transfers
Georges Boulos
georges.boulos at bell.ca
Fri Jan 31 00:08:30 MSK 2014
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 at lists.freeswitch.org> wrote:
> Send FreeSWITCH-users mailing list submissions to
> freeswitch-users at 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 at lists.freeswitch.org
>
> You can reach the person managing the list at
> freeswitch-users-owner at 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 at 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 at lists.freeswitch.org>
> Reply-To: FreeSWITCH Users Help <freeswitch-users at 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 at 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 at 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 at bell.ca
>> 1501 Bank St, Ottawa, ON, K1H 7Z1
>>
>
>
>
>
>
>
> From: Giuseppe Cardone <g.cardone at unidata.it>
> Subject: Re: [Freeswitch-users] codec configuration ignored by freeswitch
> Date: January 30, 2014 10:22:46 AM EST
> To: freeswitch-users at lists.freeswitch.org
> Reply-To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
>
>
> Anyone have any suggestions on this ?
>
> Many thanks,
> Giuseppe
>
> ----- Messaggio originale -----
>> Da: "Giuseppe Cardone" <g.cardone at unidata.it>
>> A: freeswitch-users at 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 at 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 at 217.72.102.128:5070 SET
>> [absolute_codec_string]=[PCMA,G729]
>> EXECUTE sofia/internal/390742850020 at 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 at 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 at 8000h@20i at 64000b,PCMU at 8000h@20i at 64000b,PCMA at 8000h@20i at 64000b,GSM at 8000h@20i at 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 at 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 at lists.freeswitch.org>
> Reply-To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
>
>
> When it appears as if the codec is ignored, chances are you don’t have said codec loaded.
> --
> Brian West
> brian at 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 at unidata.it> wrote:
>
>> Anyone have any suggestions on this ?
>>
>> Many thanks,
>> Giuseppe
>
>
>
>
> From: Michel Brabants <michel.brabants at 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 at lists.freeswitch.org>
> Reply-To: FreeSWITCH Users Help <freeswitch-users at 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 at 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 at 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 at 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 at bell.ca
> > 1501 Bank St, Ottawa, ON, K1H 7Z1
> >
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at 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 at 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 at lists.freeswitch.org>
> Reply-To: FreeSWITCH Users Help <freeswitch-users at lists.freeswitch.org>
>
>
> hello,
> here are the logs from the cli with sip trace on with this problem:
>
> --------------------
> freeswitch at internal>
> recv 2305 bytes from udp/[192.168.5.10]:20842 at 16:53:06.430550:
> ------------------------------------------------------------------------
> PUBLISH sip:1000 at 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 at 192.168.65.98>;tag=00d8d7ddf78c4a3f9627c52a06e68272
> To: "thomas" <sip:1000 at 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 at 192.168.65.98>;tag=00d8d7ddf78c4a3f9627c52a06e68272
> To: "thomas" <sip:1000 at 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 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 192.168.65.98>
> Contact: <sip:49583627 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 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 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.442538 [DEBUG] switch_core_session.c:1016 Send
> signal sofia/internal/1000 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.442538 [DEBUG] switch_core_state_machine.c:415
> (sofia/internal/1000 at 192.168.65.98) Running State Change CS_NEW
> 2014-01-30 17:53:06.442538 [DEBUG] sofia.c:7834
> sofia/internal/1000 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 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 at 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 at 192.168.65.98) State NEW
> recv 391 bytes from udp/[192.168.5.10]:20842 at 16:53:06.452970:
> ------------------------------------------------------------------------
> ACK sip:1001 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 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 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 192.168.65.98>
> Contact: <sip:49583627 at 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 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.463222 [DEBUG] switch_core_session.c:1016 Send
> signal sofia/internal/1000 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.482481 [DEBUG] sofia.c:7834
> sofia/internal/1000 at 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 at 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 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415
> (sofia/internal/1000 at 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 at 192.168.65.98) State INIT
> 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:87
> sofia/internal/1000 at 192.168.65.98 SOFIA INIT
> 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:127
> (sofia/internal/1000 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455
> (sofia/internal/1000 at 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 at 192.168.65.98) Running State Change CS_ROUTING
> 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:2165
> (sofia/internal/1000 at 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 at 192.168.65.98) State ROUTING
> 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:150
> sofia/internal/1000 at 192.168.65.98 SOFIA ROUTING
> 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:117
> sofia/internal/1000 at 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 at 192.168.65.98 parsing [default->unloop]
> continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (PASS) [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->tod_example] continue=true
> Dialplan: sofia/internal/1000 at 192.168.65.98 Date/Time Match (PASS)
> [tod_example] break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(open=true)
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->holiday_example] continue=true
> Dialplan: sofia/internal/1000 at 192.168.65.98 Date/TimeMatch (FAIL)
> [holiday_example] break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->global-intercept] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
> [global-intercept] destination_number(1001) =~ /^886$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->group-intercept] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
> [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->intercept-ext] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
> [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/
> break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing [default->redial]
> continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [redial]
> destination_number(1001) =~ /^(redial|870)$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing [default->global]
> continue=true
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [global]
> ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/internal/1000 at 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 at 192.168.65.98 Regex (PASS) [global]
> ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED
> NEGOTIATION)/ break=on-false
> Dialplan: sofia/internal/1000 at 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 at 192.168.65.98 Absolute Condition [global]
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-last_dial/global/${uuid})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->snom-demo-2] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [snom-demo-2]
> destination_number(1001) =~ /^9001$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->snom-demo-1] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [snom-demo-1]
> destination_number(1001) =~ /^9000$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->eavesdrop] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [eavesdrop]
> destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->eavesdrop] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [eavesdrop]
> destination_number(1001) =~ /^779$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->call_return] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [call_return]
> destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->del-group] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [del-group]
> destination_number(1001) =~ /^80(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->add-group] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL) [add-group]
> destination_number(1001) =~ /^81(\d{2})$/ break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->call-group-simo] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
> [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/
> break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->call-group-order] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
> [call-group-order] destination_number(1001) =~ /^83(\d{2})$/
> break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->extension-intercom] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (FAIL)
> [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 parsing
> [default->Local_Extension] continue=false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Regex (PASS)
> [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/
> break=on-false
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action export(dialed_extension=1001)
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action bind_meta_app(1 b s
> execute_extension::dx XML features)
> Dialplan: sofia/internal/1000 at 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 at 192.168.65.98 Action bind_meta_app(3 b s
> execute_extension::cf XML features)
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action bind_meta_app(4 b s
> execute_extension::att_xfer XML features)
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(ringback=${us-ring})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> set(transfer_ringback=local_stream://moh)
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(call_timeout=30)
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(hangup_after_bridge=true)
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action set(continue_on_fail=true)
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
> var callgroup)})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-last_dial_ext/global/${uuid})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action
> bridge(user/${dialed_extension}@${domain_name})
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action answer()
> Dialplan: sofia/internal/1000 at 192.168.65.98 Action sleep(1000)
> Dialplan: sofia/internal/1000 at 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 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:471
> (sofia/internal/1000 at 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 at 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 at 192.168.65.98) State EXECUTE
> 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:243
> sofia/internal/1000 at 192.168.65.98 SOFIA EXECUTE
> 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:209
> sofia/internal/1000 at 192.168.65.98 Standard EXECUTE
> EXECUTE sofia/internal/1000 at 192.168.65.98 set(open=true)
> 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
> sofia/internal/1000 at 192.168.65.98 SET [open]=[true]
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-spymap/1000/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-last_dial/1000/1001)
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-last_dial/global/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
> EXECUTE sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.65.98 SET
> [ringback]=[%(2000,4000,440,480)]
> EXECUTE sofia/internal/1000 at 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 at 192.168.65.98 SET
> [transfer_ringback]=[local_stream://moh]
> EXECUTE sofia/internal/1000 at 192.168.65.98 set(call_timeout=30)
> 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
> sofia/internal/1000 at 192.168.65.98 SET [call_timeout]=[30]
> EXECUTE sofia/internal/1000 at 192.168.65.98 set(hangup_after_bridge=true)
> 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
> sofia/internal/1000 at 192.168.65.98 SET [hangup_after_bridge]=[true]
> EXECUTE sofia/internal/1000 at 192.168.65.98 set(continue_on_fail=true)
> 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
> sofia/internal/1000 at 192.168.65.98 SET [continue_on_fail]=[true]
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-call_return/1001/1000)
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-last_dial_ext/1001/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
> EXECUTE sofia/internal/1000 at 192.168.65.98
> set(called_party_callgroup=techsupport)
> 2014-01-30 17:53:06.482481 [DEBUG] mod_dptools.c:1402
> sofia/internal/1000 at 192.168.65.98 SET
> [called_party_callgroup]=[techsupport]
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-last_dial_ext/techsupport/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-last_dial_ext/global/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
> EXECUTE sofia/internal/1000 at 192.168.65.98
> hash(insert/192.168.65.98-last_dial/techsupport/505cd4ee-eb6f-4b1b-91e5-2988258e9410)
> EXECUTE sofia/internal/1000 at 192.168.65.98 bridge(user/1001 at 192.168.65.98)
> 2014-01-30 17:53:06.482481 [DEBUG] switch_channel.c:1198
> sofia/internal/1000 at 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 at 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 at 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 at 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 at 192.168.65.98]
> 2014-01-30 17:53:06.482481 [NOTICE] switch_channel.c:1052 New Channel
> sofia/internal/sip:1001 at 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 at 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 at 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 at 8000h@20i at 64000b'
> 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:415
> (sofia/internal/sip:1001 at 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 at 192.168.65.124:3588) State INIT
> 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:87
> sofia/internal/sip:1001 at 192.168.65.124:3588 SOFIA INIT
> 2014-01-30 17:53:06.482481 [DEBUG] sofia_glue.c:2738
> sofia/internal/sip:1001 at 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 at 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 at 192.168.65.98>;tag=5Hjea4XHZ602e
> To: <sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>
> Call-ID: d5227656-0471-1232-bd8c-08002740dafd
> CSeq: 55214329 INVITE
> Contact: <sip:mod_sofia at 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 at 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 at 192.168.65.124:3588 [BREAK]
> 2014-01-30 17:53:06.482481 [DEBUG] mod_sofia.c:127
> (sofia/internal/sip:1001 at 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 at 192.168.65.124:3588 [BREAK]
> 2014-01-30 17:53:06.482481 [DEBUG] switch_core_state_machine.c:455
> (sofia/internal/sip:1001 at 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 at 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 at 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 at 192.168.65.124:3588) State ROUTING
> 2014-01-30 17:53:06.502511 [DEBUG] mod_sofia.c:150
> sofia/internal/sip:1001 at 192.168.65.124:3588 SOFIA ROUTING
> 2014-01-30 17:53:06.502511 [DEBUG] switch_ivr_originate.c:67
> (sofia/internal/sip:1001 at 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 at 192.168.65.124:3588 [BREAK]
> 2014-01-30 17:53:06.502511 [DEBUG] switch_core_state_machine.c:471
> (sofia/internal/sip:1001 at 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 at 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 at 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 at 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 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>
> From: "Extension 1000" <sip:1000 at 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 at 192.168.65.124:3588>
> To: <sip:1001 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41
> From: "Extension 1000"<sip:1000 at 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 at 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 at 192.168.65.124:3588 [BREAK]
> 2014-01-30 17:53:06.602764 [DEBUG] sofia.c:5779 Channel
> sofia/internal/sip:1001 at 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 at 192.168.65.124:3588!
> 2014-01-30 17:53:06.602764 [DEBUG] switch_channel.c:3239
> (sofia/internal/sip:1001 at 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 at 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 at 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 at 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 at 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 at 192.168.65.98!
> 2014-01-30 17:53:06.622431 [DEBUG] switch_channel.c:3365
> (sofia/internal/1000 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 192.168.65.98>;tag=48rN88ce2XagK
> Call-ID: bb25748be1f94505a7132e68f5576bae
> CSeq: 22406 INVITE
> Contact: <sip:1001 at 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 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.622431 [DEBUG] sofia.c:5779 Channel
> sofia/internal/1000 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:06.622431 [DEBUG] switch_ivr_originate.c:1248 Raw
> Codec Activation Success L16 at 8000hz 1 channel 20ms
> 2014-01-30 17:53:06.622431 [DEBUG] switch_core_codec.c:219
> sofia/internal/1000 at 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 at 192.168.65.124:3588;rinstance=c88f5661c51fa917>;tag=c5d7df41
> From: "Extension 1000"<sip:1000 at 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 at 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 at 192.168.65.98>;tag=5Hjea4XHZ602e
> To: <sip:1001 at 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 at 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 at 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 at 192.168.65.124:3588 [BREAK]
> 2014-01-30 17:53:11.407504 [DEBUG] sofia.c:5779 Channel
> sofia/internal/sip:1001 at 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 at 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 at 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 at 192.168.65.124:3588 [BREAK]
> 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:415
> (sofia/internal/sip:1001 at 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 at 192.168.65.124:3588) State HANGUP
> 2014-01-30 17:53:11.407504 [DEBUG] mod_sofia.c:506 Channel
> sofia/internal/sip:1001 at 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 at 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 at 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 at 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 at 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 at 192.168.65.124:3588 [BREAK]
> 2014-01-30 17:53:11.407504 [DEBUG] switch_core_state_machine.c:415
> (sofia/internal/sip:1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.65.98 answer()
> 2014-01-30 17:53:11.424472 [DEBUG] mod_sofia.c:866 Local SDP
> sofia/internal/1000 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 192.168.65.98>;tag=48rN88ce2XagK
> Call-ID: bb25748be1f94505a7132e68f5576bae
> CSeq: 22406 INVITE
> Contact: <sip:1001 at 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 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:11.424472 [DEBUG] sofia.c:5779 Channel
> sofia/internal/1000 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:11.424472 [NOTICE] mod_dptools.c:1225 Channel
> [sofia/internal/1000 at 192.168.65.98] has been answered
> 2014-01-30 17:53:11.424472 [DEBUG] switch_channel.c:3644
> (sofia/internal/1000 at 192.168.65.98) Callstate Change EARLY -> ACTIVE
> EXECUTE sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 192.168.65.124:3588) State DESTROY
> 2014-01-30 17:53:11.424472 [DEBUG] mod_sofia.c:399
> sofia/internal/sip:1001 at 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 at 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 at 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 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send
> signal sofia/internal/1000 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:11.464095 [DEBUG] switch_core_session.c:1016 Send
> signal sofia/internal/1000 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:11.488073 [DEBUG] sofia.c:5779 Channel
> sofia/internal/1000 at 192.168.65.98 entering state [ready][200]
> EXECUTE sofia/internal/1000 at 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 at 192.168.65.98) Callstate Change ACTIVE ->
> RING_WAIT
> 2014-01-30 17:53:12.442539 [DEBUG] switch_channel.c:1198
> sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 8000hz 1 channels 20ms
> recv 410 bytes from udp/[192.168.5.10]:20842 at 16:53:18.270540:
> ------------------------------------------------------------------------
> BYE sip:1001 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:18.283431 [NOTICE] sofia.c:737 Hangup
> sofia/internal/1000 at 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 at 192.168.65.98 [KILL]
> 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1351 Send
> signal sofia/internal/1000 at 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 at 192.168.65.98>;tag=1753abc633294d3c8e2a69fd3a1ee28a
> To: <sip:1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.65.98) State HANGUP
> 2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:500
> sofia/internal/1000 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:415
> (sofia/internal/1000 at 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 at 192.168.65.98) State REPORTING
> 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:92
> sofia/internal/1000 at 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 at 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 at 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 at 192.168.65.98 [BREAK]
> 2014-01-30 17:53:18.283431 [DEBUG] switch_core_session.c:1559 Session
> 1 (sofia/internal/1000 at 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 at 192.168.65.98) Ended
> 2014-01-30 17:53:18.283431 [NOTICE] switch_core_session.c:1581 Close
> Channel sofia/internal/1000 at 192.168.65.98 [CS_DESTROY]
> 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:566
> (sofia/internal/1000 at 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 at 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 at 192.168.65.98) State DESTROY
> 2014-01-30 17:53:18.283431 [DEBUG] mod_sofia.c:399
> sofia/internal/1000 at 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 at 192.168.65.98 Standard DESTROY
> 2014-01-30 17:53:18.283431 [DEBUG] switch_core_state_machine.c:579
> (sofia/internal/1000 at 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 at freeswitch.org>:
>> Logs, with sip trace on please.
>>
>> --
>> Brian West
>> brian at 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 at 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 at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>>
>>
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://wiki.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at 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 at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140130/b4bba640/attachment-0001.html
Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users
mailing list