[Freeswitch-users] Oneway audio issues in freeswitch

Jai Rangi jprangi at gmail.com
Thu Feb 18 01:01:30 MSK 2016


Hello Dave,
Sorry for the delay, have been out of office.

Attached the the debug log file, with siptrace on. This is coming from
default configuration. I can confirm the issue happens only when this line
is commented out.

    <param name="auto-jitterbuffer-msec" value="60"/>

Not sure if this qualifies for bug, I can open a ticket in Jira.

Thank you,

-Jai


On Sat, Feb 13, 2016 at 7:49 PM, Dave Horton <dave at dchorton.com> wrote:

> Redo with sofia global siptrace on so we can see the SIP messaging
> On Feb 13, 2016, at 12:45 PM, Jai Rangi <jprangi at didforsale.com> wrote:
>
> Hello Ken,
> Thank for look in this. Attached are debug logs. SIP Traces were not
> molested, except the public IPs were changed. As of writing of this email,
> the issue is isolated to 1.6.x.
> Not sure if anyone else has tested this on latest version. But easy to
> reproduce. Just download grandstream Wave, available to IOS and Andriod and
> try to call any extension directly. Curious to see if any one can come with
> different result.
>
> *Jai Rangi*
> Cebod Technologies LLC dba DIDforSale/Cebod Telecom
> O 949-471-0102 <O%20949-471-0101> | C 949-419-7634 <C%20949-742-2666> | F
> 949-269-0449 / 949-232-1410 | jprangi at didforsale.com  www.cebod.com |
> www.didforsale.com |3200 Bristol St Suite 615, Costa Mesa, CA 92626  |
>
>
>
>
>
>
> On Thu, Feb 11, 2016 at 8:36 AM, Ken Rice <krice at freeswitch.org> wrote:
>
>> without logs of a call doing this at debug level with a complete
>> unmolested sip trace in line its a little hard to speculate whats going on
>> here
>>
>> On Thu, Feb 11, 2016 at 10:28 AM, mohammed shafeeque <shafeeq.v at gmail.com
>> > wrote:
>>
>>> Surprised that no one else experienced this problem. Can anyone give any
>>> hint. Really Dont want to move back to 1.4.x
>>>
>>> On Thu, Feb 11, 2016 at 7:44 AM, Luis Daniel Lucio Quiroz <
>>> luis.daniel.lucio at gmail.com> wrote:
>>>
>>>> As a rule of dumb, try turning on rport
>>>> Le 10 févr. 2016 8:55 PM, "Ítalo Rossi" <italo at freeswitch.org> a
>>>> écrit :
>>>>
>>>>> You need to look at the sip signaling to see what's going on
>>>>>
>>>>> On Wed, Feb 10, 2016 at 5:59 PM, mohammed shafeeque <
>>>>> shafeeq.v at gmail.com> wrote:
>>>>>
>>>>>> Hello All
>>>>>>
>>>>>> We are getting one way audio issues with some softphones and
>>>>>> grandstream phones behind nat registerd to our freeswitch server.
>>>>>>
>>>>>> Here is scenario:
>>>>>> Grandstream call any extensions (one way audio)
>>>>>> Any extension call Grandstream ( Audio works just fine)
>>>>>>
>>>>>> We have tried multiple softphones and the result is same.
>>>>>>
>>>>>> Everything was working fine with 1.4.18 and 1.6.2. We were having
>>>>>> DTMF issue with 1.6.2, upgraded to 1.6.5 and now one way audio issue
>>>>>> started with an upgrade to freeswitch.
>>>>>>
>>>>>> Any help or hint will be much appreciated.
>>>>>>
>>>>>> Thank you,
>>>>>>
>>>>>>
>>>>>>
>>>>>> _________________________________________________________________________
>>>>>> Professional FreeSWITCH Consulting Services:
>>>>>> consulting at freeswitch.org
>>>>>> http://www.freeswitchsolutions.com
>>>>>>
>>>>>> Official FreeSWITCH Sites
>>>>>> http://www.freeswitch.org
>>>>>> http://confluence.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
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> Ítalo Rossi
>>>>> italo at freeswitch.org
>>>>>
>>>>>
>>>>> _________________________________________________________________________
>>>>> Professional FreeSWITCH Consulting Services:
>>>>> consulting at freeswitch.org
>>>>> http://www.freeswitchsolutions.com
>>>>>
>>>>> Official FreeSWITCH Sites
>>>>> http://www.freeswitch.org
>>>>> http://confluence.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
>>>>>
>>>>
>>>>
>>>> _________________________________________________________________________
>>>> Professional FreeSWITCH Consulting Services:
>>>> consulting at freeswitch.org
>>>> http://www.freeswitchsolutions.com
>>>>
>>>> Official FreeSWITCH Sites
>>>> http://www.freeswitch.org
>>>> http://confluence.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
>>>>
>>>
>>>
>>> _________________________________________________________________________
>>> Professional FreeSWITCH Consulting Services:
>>> consulting at freeswitch.org
>>> http://www.freeswitchsolutions.com
>>>
>>> Official FreeSWITCH Sites
>>> http://www.freeswitch.org
>>> http://confluence.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
>>>
>>
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://confluence.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.log.goodcall.txt><freeswitch.log.badcall.txt>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.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
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20160217/42e3e0fe/attachment-0001.html 
-------------- next part --------------
2016-02-17 13:47:25.637398 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/var/log/freeswitch/cdr-csv/Master.csv
2016-02-17 13:47:25.637398 [NOTICE] mod_logfile.c:213 New log started.
recv 864 bytes from udp/[66.166.9.194]:39164 at 13:47:27.794790:
   ------------------------------------------------------------------------
   INVITE sip:1001 at 216.209.211.222 SIP/2.0
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK281160191;rport
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 40 INVITE
   Contact: <sip:1000 at 10.0.1.12:40886>
   Max-Forwards: 70
   User-Agent: Grandstream Wave/IOS 1.0.19
   Privacy: none
   P-Preferred-Identity: <sip:1000 at 216.209.211.222>
   Supported: replaces, path, timer, eventlist
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Type: application/sdp
   Accept: application/sdp, application/dtmf-relay
   Content-Length:   230
   
   v=0
   o=1000 8000 8000 IN IP4 10.0.1.12
   s=SIP Call
   c=IN IP4 10.0.1.12
   t=0 0
   m=audio 10270 RTP/AVP 0 8 101
   a=sendrecv
   a=rtpmap:0 PCMU/8000
   a=ptime:20
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   ------------------------------------------------------------------------
send 310 bytes to udp/[66.166.9.194]:39164 at 13:47:27.795559:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK281160191;rport=39164;received=66.166.9.194
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 40 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Content-Length: 0
   
   ------------------------------------------------------------------------
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.777377 [NOTICE] switch_channel.c:1101 New Channel sofia/internal/1000 at 216.209.211.222 [4008c053-8780-4987-b84f-010b67013bda]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.777377 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at 216.209.211.222) Running State Change CS_NEW
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.777377 [DEBUG] sofia.c:9248 sofia/internal/1000 at 216.209.211.222 receiving invite from 66.166.9.194:39164 version: 1.6.6  64bit
2016-02-17 13:47:27.777377 [DEBUG] sofia.c:9415 IP 66.166.9.194 Rejected by acl "domains". Falling back to Digest auth.
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.797388 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/1000 at 216.209.211.222) State NEW
send 814 bytes to udp/[66.166.9.194]:39164 at 13:47:27.798293:
   ------------------------------------------------------------------------
   SIP/2.0 407 Proxy Authentication Required
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK281160191;rport=39164;received=66.166.9.194
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=Drpp4yp9j1X2m
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 40 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Proxy-Authenticate: Digest realm="216.209.211.222", nonce="696ccc87-c214-4a8a-870f-7e3d69ca016d", algorithm=MD5, qop="auth"
   Content-Length: 0
   
   ------------------------------------------------------------------------
2016-02-17 13:47:27.797388 [DEBUG] sofia.c:2147 detaching session 4008c053-8780-4987-b84f-010b67013bda
recv 267 bytes from udp/[66.166.9.194]:39164 at 13:47:27.843925:
   ------------------------------------------------------------------------
   ACK sip:1001 at 216.209.211.222 SIP/2.0
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK281160191;rport
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=Drpp4yp9j1X2m
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 40 ACK
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 1111 bytes from udp/[66.166.9.194]:39164 at 13:47:27.860855:
   ------------------------------------------------------------------------
   INVITE sip:1001 at 216.209.211.222 SIP/2.0
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK1578402832;rport
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 41 INVITE
   Contact: <sip:1000 at 10.0.1.12:40886>
   Proxy-Authorization: Digest username="1000", realm="216.209.211.222", nonce="696ccc87-c214-4a8a-870f-7e3d69ca016d", uri="sip:1001 at 216.209.211.222", response="73ea6df6242e1f2e5cc6e4d6bad9be3e", algorithm=MD5, cnonce="15059615", qop=auth, nc=00000006
   Max-Forwards: 70
   User-Agent: Grandstream Wave/IOS 1.0.19
   Privacy: none
   P-Preferred-Identity: <sip:1000 at 216.209.211.222>
   Supported: replaces, path, timer, eventlist
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Type: application/sdp
   Accept: application/sdp, application/dtmf-relay
   Content-Length:   230
   
   v=0
   o=1000 8000 8000 IN IP4 10.0.1.12
   s=SIP Call
   c=IN IP4 10.0.1.12
   t=0 0
   m=audio 10270 RTP/AVP 0 8 101
   a=sendrecv
   a=rtpmap:0 PCMU/8000
   a=ptime:20
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   ------------------------------------------------------------------------
send 311 bytes to udp/[66.166.9.194]:39164 at 13:47:27.862041:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK1578402832;rport=39164;received=66.166.9.194
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 41 INVITE
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Content-Length: 0
   
   ------------------------------------------------------------------------
2016-02-17 13:47:27.857368 [DEBUG] sofia.c:2255 Re-attaching to session 4008c053-8780-4987-b84f-010b67013bda
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] sofia.c:9248 sofia/internal/1000 at 216.209.211.222 receiving invite from 66.166.9.194:39164 version: 1.6.6  64bit
2016-02-17 13:47:27.877397 [DEBUG] sofia.c:9415 IP 66.166.9.194 Rejected by acl "domains". Falling back to Digest auth.
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] sofia.c:10549 Setting NAT mode based on nat.auto
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] sofia.c:6760 Channel sofia/internal/1000 at 216.209.211.222 entering state [received][100]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] sofia.c:6770 Remote SDP:
4008c053-8780-4987-b84f-010b67013bda v=0
4008c053-8780-4987-b84f-010b67013bda o=1000 8000 8000 IN IP4 10.0.1.12
4008c053-8780-4987-b84f-010b67013bda s=SIP Call
4008c053-8780-4987-b84f-010b67013bda c=IN IP4 10.0.1.12
4008c053-8780-4987-b84f-010b67013bda t=0 0
4008c053-8780-4987-b84f-010b67013bda m=audio 10270 RTP/AVP 0 8 101
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:0 PCMU/8000
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:8 PCMA/8000
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:101 telephone-event/8000
4008c053-8780-4987-b84f-010b67013bda a=fmtp:101 0-15
4008c053-8780-4987-b84f-010b67013bda a=ptime:20
4008c053-8780-4987-b84f-010b67013bda 
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] sofia.c:7125 (sofia/internal/1000 at 216.209.211.222) State Change CS_NEW -> CS_INIT
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at 216.209.211.222) Running State Change CS_INIT
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1000 at 216.209.211.222) State INIT
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_sofia.c:88 sofia/internal/1000 at 216.209.211.222 SOFIA INIT
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000 at 216.209.211.222 Standard INIT
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000 at 216.209.211.222) State Change CS_INIT -> CS_ROUTING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1000 at 216.209.211.222) State INIT going to sleep
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at 216.209.211.222) Running State Change CS_ROUTING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_channel.c:2247 (sofia/internal/1000 at 216.209.211.222) Callstate Change DOWN -> RINGING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1000 at 216.209.211.222) State ROUTING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_sofia.c:141 sofia/internal/1000 at 216.209.211.222 SOFIA ROUTING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:166 sofia/internal/1000 at 216.209.211.222 Standard ROUTING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1001 in context default
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->unloop] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->tod_example] continue=true
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Date/Time Match (PASS) [tod_example] break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action set(open=true)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->holiday_example] continue=true
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Date/TimeMatch (FAIL) [holiday_example] break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->global-intercept] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->group-intercept] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->intercept-ext] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->redial] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->global] continue=true
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [global] ${default_password}(qwerty at 123$) =~ /^1234$/ break=never
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [global] ${switch_r_sdp}(v=0
4008c053-8780-4987-b84f-010b67013bda o=1000 8000 8000 IN IP4 10.0.1.12
4008c053-8780-4987-b84f-010b67013bda s=SIP Call
4008c053-8780-4987-b84f-010b67013bda c=IN IP4 10.0.1.12
4008c053-8780-4987-b84f-010b67013bda t=0 0
4008c053-8780-4987-b84f-010b67013bda m=audio 10270 RTP/AVP 0 8 101
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:0 PCMU/8000
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:8 PCMA/8000
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:101 telephone-event/8000
4008c053-8780-4987-b84f-010b67013bda a=fmtp:101 0-15
4008c053-8780-4987-b84f-010b67013bda a=ptime:20
4008c053-8780-4987-b84f-010b67013bda ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Absolute Condition [global]
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-last_dial/global/${uuid})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->snom-demo-2] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->snom-demo-1] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->eavesdrop] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->eavesdrop] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->call_return] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->del-group] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->add-group] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->call-group-simo] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->call-group-order] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->extension-intercom] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 parsing [default->Local_Extension] continue=false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action export(dialed_extension=1001)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action bind_meta_app(1 b s execute_extension::dx XML features)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action bind_meta_app(3 b s execute_extension::cf XML features)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action set(ringback=${us-ring})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action set(transfer_ringback=local_stream://moh)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action set(call_timeout=30)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action set(hangup_after_bridge=true)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action set(continue_on_fail=true)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action bridge(user/${dialed_extension}@${domain_name})
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action answer()
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action sleep(1000)
4008c053-8780-4987-b84f-010b67013bda Dialplan: sofia/internal/1000 at 216.209.211.222 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/1000 at 216.209.211.222) State Change CS_ROUTING -> CS_EXECUTE
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1000 at 216.209.211.222) State ROUTING going to sleep
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at 216.209.211.222) Running State Change CS_EXECUTE
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:539 (sofia/internal/1000 at 216.209.211.222) State EXECUTE
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_sofia.c:196 sofia/internal/1000 at 216.209.211.222 SOFIA EXECUTE
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_core_state_machine.c:258 sofia/internal/1000 at 216.209.211.222 Standard EXECUTE
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 set(open=true)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at 216.209.211.222 [open]=[true]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-spymap/1000/4008c053-8780-4987-b84f-010b67013bda)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-last_dial/1000/1001)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-last_dial/global/4008c053-8780-4987-b84f-010b67013bda)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 export(RFC2822_DATE=Wed, 17 Feb 2016 13:47:27 -0800)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_channel.c:1293 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 17 Feb 2016 13:47:27 -0800]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 export(dialed_extension=1001)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] switch_channel.c:1293 EXPORT (export_vars) [dialed_extension]=[1001]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 bind_meta_app(1 b s execute_extension::dx XML features)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [INFO] switch_ivr_async.c:4152 Bound B-Leg: *1 execute_extension::dx XML features
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 bind_meta_app(2 b s record_session::/usr/local/freeswitch/var/lib/freeswitch/recordings/1000.2016-02-17-13-47-27.wav)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [INFO] switch_ivr_async.c:4152 Bound B-Leg: *2 record_session::/usr/local/freeswitch/var/lib/freeswitch/recordings/1000.2016-02-17-13-47-27.wav
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 bind_meta_app(3 b s execute_extension::cf XML features)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [INFO] switch_ivr_async.c:4152 Bound B-Leg: *3 execute_extension::cf XML features
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 bind_meta_app(4 b s execute_extension::att_xfer XML features)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [INFO] switch_ivr_async.c:4152 Bound B-Leg: *4 execute_extension::att_xfer XML features
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 set(ringback=%(2000,4000,440,480))
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at 216.209.211.222 [ringback]=[%(2000,4000,440,480)]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 set(transfer_ringback=local_stream://moh)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at 216.209.211.222 [transfer_ringback]=[local_stream://moh]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 set(call_timeout=30)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at 216.209.211.222 [call_timeout]=[30]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 set(hangup_after_bridge=true)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.877397 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at 216.209.211.222 [hangup_after_bridge]=[true]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 set(continue_on_fail=true)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at 216.209.211.222 [continue_on_fail]=[true]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-call_return/1001/1000)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-last_dial_ext/1001/4008c053-8780-4987-b84f-010b67013bda)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 set(called_party_callgroup=techsupport)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] mod_dptools.c:1498 SET sofia/internal/1000 at 216.209.211.222 [called_party_callgroup]=[techsupport]
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-last_dial_ext/techsupport/4008c053-8780-4987-b84f-010b67013bda)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-last_dial_ext/global/4008c053-8780-4987-b84f-010b67013bda)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 hash(insert/216.209.211.222-last_dial/techsupport/4008c053-8780-4987-b84f-010b67013bda)
4008c053-8780-4987-b84f-010b67013bda EXECUTE sofia/internal/1000 at 216.209.211.222 bridge(user/1001 at 216.209.211.222)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] switch_channel.c:1247 sofia/internal/1000 at 216.209.211.222 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 17 Feb 2016 13:47:27 -0800] to event
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] switch_channel.c:1247 sofia/internal/1000 at 216.209.211.222 EXPORTING[export_vars] [dialed_extension]=[1001] to event
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] switch_ivr_originate.c:2128 Parsing global variables
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] switch_channel.c:1247 sofia/internal/1000 at 216.209.211.222 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 17 Feb 2016 13:47:27 -0800] to event
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] switch_channel.c:1247 sofia/internal/1000 at 216.209.211.222 EXPORTING[export_vars] [dialed_extension]=[1001] to event
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:27.897386 [DEBUG] switch_ivr_originate.c:2128 Parsing global variables
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [NOTICE] switch_channel.c:1101 New Channel sofia/internal/1001 at 10.0.1.2:40886 [15df2523-1e92-49ca-bf21-bbf07d51c29e]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] mod_sofia.c:4776 (sofia/internal/1001 at 10.0.1.2:40886) State Change CS_NEW -> CS_INIT
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001 at 10.0.1.2:40886) Running State Change CS_INIT
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1001 at 10.0.1.2:40886) State INIT
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] mod_sofia.c:88 sofia/internal/1001 at 10.0.1.2:40886 SOFIA INIT
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] sofia_glue.c:1228 sip:1001 at 66.166.9.194:41958 Setting proxy route to sofia/internal/1001 at 10.0.1.2:40886
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] sofia_glue.c:1257 sofia/internal/1001 at 10.0.1.2:40886 sending invite version: 1.6.6  64bit
15df2523-1e92-49ca-bf21-bbf07d51c29e Local SDP:
15df2523-1e92-49ca-bf21-bbf07d51c29e v=0
15df2523-1e92-49ca-bf21-bbf07d51c29e o=FreeSWITCH 1455713039 1455713040 IN IP4 216.209.211.222
15df2523-1e92-49ca-bf21-bbf07d51c29e s=FreeSWITCH
15df2523-1e92-49ca-bf21-bbf07d51c29e c=IN IP4 216.209.211.222
15df2523-1e92-49ca-bf21-bbf07d51c29e t=0 0
15df2523-1e92-49ca-bf21-bbf07d51c29e m=audio 32608 RTP/AVP 0 8 101
15df2523-1e92-49ca-bf21-bbf07d51c29e a=rtpmap:0 PCMU/8000
15df2523-1e92-49ca-bf21-bbf07d51c29e a=rtpmap:8 PCMA/8000
15df2523-1e92-49ca-bf21-bbf07d51c29e a=rtpmap:101 telephone-event/8000
15df2523-1e92-49ca-bf21-bbf07d51c29e a=fmtp:101 0-16
15df2523-1e92-49ca-bf21-bbf07d51c29e a=ptime:20
15df2523-1e92-49ca-bf21-bbf07d51c29e a=sendrecv
15df2523-1e92-49ca-bf21-bbf07d51c29e 
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001 at 10.0.1.2:40886 Standard INIT
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001 at 10.0.1.2:40886) State Change CS_INIT -> CS_ROUTING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1001 at 10.0.1.2:40886) State INIT going to sleep
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001 at 10.0.1.2:40886) Running State Change CS_ROUTING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1001 at 10.0.1.2:40886) State ROUTING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] mod_sofia.c:141 sofia/internal/1001 at 10.0.1.2:40886 SOFIA ROUTING
send 1185 bytes to udp/[66.166.9.194]:41958 at 13:47:27.912034:
   ------------------------------------------------------------------------
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001 at 10.0.1.2:40886) State Change CS_ROUTING -> CS_CONSUME_MEDIA
   INVITE sip:1001 at 10.0.1.2:40886 SIP/2.0
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1001 at 10.0.1.2:40886) State ROUTING going to sleep
   Via: SIP/2.0/UDP 216.209.211.222;rport;branch=z9hG4bK38Xat6Z71UHUN
   Route: <sip:1001 at 66.166.9.194:41958>
   Max-Forwards: 69
   From: "Extension 1000" <sip:1000 at 216.209.211.222>;tag=Fa977mrgDKa8B
   To: <sip:1001 at 10.0.1.2:40886>
   Call-ID: e124e149-5062-1234-9bb4-c6827b410b7a
   CSeq: 87536759 INVITE
   Contact: <sip:mod_sofia at 216.209.211.222:5060>
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Privacy: none
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 246
   X-FS-Support: update_display,send_info
   P-Asserted-Identity: "Extension 1000" <sip:1000 at 216.209.211.222>
   
   v=0
   o=FreeSWITCH 1455713039 1455713040 IN IP4 216.209.211.222
   s=FreeSWITCH
   c=IN IP4 216.209.211.222
   t=0 0
   m=audio 32608 RTP/AVP 0 8 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001 at 10.0.1.2:40886) Running State Change CS_CONSUME_MEDIA
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] sofia.c:6760 Channel sofia/internal/1001 at 10.0.1.2:40886 entering state [calling][0]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:551 (sofia/internal/1001 at 10.0.1.2:40886) State CONSUME_MEDIA
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:27.897386 [DEBUG] switch_core_state_machine.c:551 (sofia/internal/1001 at 10.0.1.2:40886) State CONSUME_MEDIA going to sleep
recv 450 bytes from udp/[66.166.9.194]:41958 at 13:47:28.028660:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 216.209.211.222;rport=5060;branch=z9hG4bK38Xat6Z71UHUN
   From: "Extension 1000" <sip:1000 at 216.209.211.222>;tag=Fa977mrgDKa8B
   To: <sip:1001 at 10.0.1.2:40886>
   Call-ID: e124e149-5062-1234-9bb4-c6827b410b7a
   CSeq: 87536759 INVITE
   Supported: replaces, path, eventlist
   User-Agent: Grandstream Wave/IOS 1.0.19
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 535 bytes from udp/[66.166.9.194]:41958 at 13:47:28.036530:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP 216.209.211.222;rport=5060;branch=z9hG4bK38Xat6Z71UHUN
   From: "Extension 1000" <sip:1000 at 216.209.211.222>;tag=Fa977mrgDKa8B
   To: <sip:1001 at 10.0.1.2:40886>;tag=2072085022
   Call-ID: e124e149-5062-1234-9bb4-c6827b410b7a
   CSeq: 87536759 INVITE
   Contact: <sip:1001 at 10.0.1.2:40886>
   Supported: replaces, path, timer, eventlist
   User-Agent: Grandstream Wave/IOS 1.0.19
   Allow-Events: talk, hold
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Length: 0
   
   ------------------------------------------------------------------------
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:28.037389 [DEBUG] sofia.c:6760 Channel sofia/internal/1001 at 10.0.1.2:40886 entering state [proceeding][180]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:28.037389 [NOTICE] sofia.c:6862 Ring-Ready sofia/internal/1001 at 10.0.1.2:40886!
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:28.037389 [DEBUG] switch_channel.c:3340 (sofia/internal/1001 at 10.0.1.2:40886) Callstate Change DOWN -> RINGING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [INFO] switch_ivr_originate.c:1216 Sending early media
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4216 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4216 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4077 Set telephone-event payload to 101 at 8000
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:2906 Set Codec sofia/internal/1000 at 216.209.211.222 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_codec.c:111 sofia/internal/1000 at 216.209.211.222 Original read codec set to PCMU:0
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4429 Set telephone-event payload to 101 at 8000
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:4485 sofia/internal/1000 at 216.209.211.222 Set 2833 dtmf send payload to 101 recv payload to 101
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:6033 AUDIO RTP [sofia/internal/1000 at 216.209.211.222] 216.209.211.222 port 25166 -> 10.0.1.12 port 10270 codec: 0 ms: 20
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_rtp.c:3802 Starting timer [soft] 160 bytes per 20ms
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:1939 Setting Jitterbuffer to 60ms (3 frames) (50 max frames)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:6332 sofia/internal/1000 at 216.209.211.222 Set 2833 dtmf send payload to 101
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:6339 sofia/internal/1000 at 216.209.211.222 Set 2833 dtmf receive payload to 101
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [DEBUG] switch_core_media.c:6362 sofia/internal/1000 at 216.209.211.222 Set rtp dtmf delay to 40
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.037389 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000 at 216.209.211.222!
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.057400 [DEBUG] switch_channel.c:3468 (sofia/internal/1000 at 216.209.211.222) Callstate Change RINGING -> EARLY
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.057400 [DEBUG] mod_sofia.c:2330 Ring SDP:
4008c053-8780-4987-b84f-010b67013bda v=0
4008c053-8780-4987-b84f-010b67013bda o=FreeSWITCH 1455720482 1455720483 IN IP4 216.209.211.222
4008c053-8780-4987-b84f-010b67013bda s=FreeSWITCH
4008c053-8780-4987-b84f-010b67013bda c=IN IP4 216.209.211.222
4008c053-8780-4987-b84f-010b67013bda t=0 0
4008c053-8780-4987-b84f-010b67013bda m=audio 25166 RTP/AVP 0 101
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:0 PCMU/8000
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:101 telephone-event/8000
4008c053-8780-4987-b84f-010b67013bda a=fmtp:101 0-16
4008c053-8780-4987-b84f-010b67013bda a=ptime:20
4008c053-8780-4987-b84f-010b67013bda a=sendrecv
4008c053-8780-4987-b84f-010b67013bda 
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.057400 [DEBUG] switch_ivr_originate.c:1274 Raw Codec Activation Success L16 at 8000hz 1 channel 20ms
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.057400 [DEBUG] switch_core_codec.c:221 sofia/internal/1000 at 216.209.211.222 Push codec L16:100
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.057400 [DEBUG] switch_ivr_originate.c:1343 Play Ringback Tone [%(2000,4000,440,480)]
send 1072 bytes to udp/[66.166.9.194]:39164 at 13:47:28.060325:
   ------------------------------------------------------------------------
   SIP/2.0 183 Session Progress
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK1578402832;rport=39164;received=66.166.9.194
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=e1FF6S7cgamNg
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 41 INVITE
   Contact: <sip:1001 at 216.209.211.222:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 222
   P-Asserted-Identity: "1001" <sip:1001 at 216.209.211.222>
   
   v=0
   o=FreeSWITCH 1455720482 1455720483 IN IP4 216.209.211.222
   s=FreeSWITCH
   c=IN IP4 216.209.211.222
   t=0 0
   m=audio 25166 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.077397 [DEBUG] sofia.c:6760 Channel sofia/internal/1000 at 216.209.211.222 entering state [early][183]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:28.817431 [INFO] switch_rtp.c:6616 Auto Changing audio port from 10.0.1.12:10270 to 66.166.9.194:38124
recv 767 bytes from udp/[66.166.9.194]:41958 at 13:47:30.718270:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 216.209.211.222;rport=5060;branch=z9hG4bK38Xat6Z71UHUN
   From: "Extension 1000" <sip:1000 at 216.209.211.222>;tag=Fa977mrgDKa8B
   To: <sip:1001 at 10.0.1.2:40886>;tag=2072085022
   Call-ID: e124e149-5062-1234-9bb4-c6827b410b7a
   CSeq: 87536759 INVITE
   Contact: <sip:1001 at 10.0.1.2:40886>
   Supported: replaces, path, timer, eventlist
   User-Agent: Grandstream Wave/IOS 1.0.19
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Type: application/sdp
   Content-Length:   228
   
   v=0
   o=1001 8001 8000 IN IP4 10.0.1.2
   s=SIP Call
   c=IN IP4 10.0.1.2
   t=0 0
   m=audio 35544 RTP/AVP 0 8 101
   a=sendrecv
   a=rtpmap:0 PCMU/8000
   a=ptime:20
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   ------------------------------------------------------------------------
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] sofia.c:6760 Channel sofia/internal/1001 at 10.0.1.2:40886 entering state [completing][200]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] sofia.c:6770 Remote SDP:
15df2523-1e92-49ca-bf21-bbf07d51c29e v=0
15df2523-1e92-49ca-bf21-bbf07d51c29e o=1001 8001 8000 IN IP4 10.0.1.2
15df2523-1e92-49ca-bf21-bbf07d51c29e s=SIP Call
15df2523-1e92-49ca-bf21-bbf07d51c29e c=IN IP4 10.0.1.2
15df2523-1e92-49ca-bf21-bbf07d51c29e t=0 0
15df2523-1e92-49ca-bf21-bbf07d51c29e m=audio 35544 RTP/AVP 0 8 101
15df2523-1e92-49ca-bf21-bbf07d51c29e a=rtpmap:0 PCMU/8000
15df2523-1e92-49ca-bf21-bbf07d51c29e a=rtpmap:8 PCMA/8000
15df2523-1e92-49ca-bf21-bbf07d51c29e a=rtpmap:101 telephone-event/8000
15df2523-1e92-49ca-bf21-bbf07d51c29e a=fmtp:101 0-15
15df2523-1e92-49ca-bf21-bbf07d51c29e a=ptime:20
15df2523-1e92-49ca-bf21-bbf07d51c29e 
send 367 bytes to udp/[66.166.9.194]:41958 at 13:47:30.723049:
   ------------------------------------------------------------------------
   ACK sip:1001 at 10.0.1.2:40886 SIP/2.0
   Via: SIP/2.0/UDP 216.209.211.222;rport;branch=z9hG4bK4HQ3U1gBZ47DH
   Max-Forwards: 70
   From: "Extension 1000" <sip:1000 at 216.209.211.222>;tag=Fa977mrgDKa8B
   To: <sip:1001 at 10.0.1.2:40886>;tag=2072085022
   Call-ID: e124e149-5062-1234-9bb4-c6827b410b7a
   CSeq: 87536759 ACK
   Contact: <sip:mod_sofia at 216.209.211.222:5060>
   Content-Length: 0
   
   ------------------------------------------------------------------------
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] sofia.c:6760 Channel sofia/internal/1001 at 10.0.1.2:40886 entering state [ready][200]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4216 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4216 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4077 Set telephone-event payload to 101 at 8000
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:2906 Set Codec sofia/internal/1001 at 10.0.1.2:40886 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_codec.c:111 sofia/internal/1001 at 10.0.1.2:40886 Original read codec set to PCMU:0
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4429 Set telephone-event payload to 101 at 8000
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:4485 sofia/internal/1001 at 10.0.1.2:40886 Set 2833 dtmf send payload to 101 recv payload to 101
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:6033 AUDIO RTP [sofia/internal/1001 at 10.0.1.2:40886] 216.209.211.222 port 32608 -> 10.0.1.2 port 35544 codec: 0 ms: 20
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_rtp.c:3802 Starting timer [soft] 160 bytes per 20ms
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:1939 Setting Jitterbuffer to 60ms (3 frames) (50 max frames)
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:6332 sofia/internal/1001 at 10.0.1.2:40886 Set 2833 dtmf send payload to 101
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:6339 sofia/internal/1001 at 10.0.1.2:40886 Set 2833 dtmf receive payload to 101
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_core_media.c:6362 sofia/internal/1001 at 10.0.1.2:40886 Set rtp dtmf delay to 40
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [NOTICE] sofia.c:7724 Channel [sofia/internal/1001 at 10.0.1.2:40886] has been answered
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.717395 [DEBUG] switch_channel.c:3767 (sofia/internal/1001 at 10.0.1.2:40886) Callstate Change RINGING -> ACTIVE
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [DEBUG] switch_core_codec.c:246 sofia/internal/1000 at 216.209.211.222 Restore previous codec PCMU:0.
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [DEBUG] mod_sofia.c:799 Local SDP sofia/internal/1000 at 216.209.211.222:
4008c053-8780-4987-b84f-010b67013bda v=0
4008c053-8780-4987-b84f-010b67013bda o=FreeSWITCH 1455720482 1455720484 IN IP4 216.209.211.222
4008c053-8780-4987-b84f-010b67013bda s=FreeSWITCH
4008c053-8780-4987-b84f-010b67013bda c=IN IP4 216.209.211.222
4008c053-8780-4987-b84f-010b67013bda t=0 0
4008c053-8780-4987-b84f-010b67013bda m=audio 25166 RTP/AVP 0 101
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:0 PCMU/8000
4008c053-8780-4987-b84f-010b67013bda a=rtpmap:101 telephone-event/8000
4008c053-8780-4987-b84f-010b67013bda a=fmtp:101 0-16
4008c053-8780-4987-b84f-010b67013bda a=ptime:20
4008c053-8780-4987-b84f-010b67013bda a=sendrecv
4008c053-8780-4987-b84f-010b67013bda 
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [NOTICE] switch_ivr_originate.c:3550 Channel [sofia/internal/1000 at 216.209.211.222] has been answered
send 1094 bytes to udp/[66.166.9.194]:39164 at 13:47:30.743468:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK1578402832;rport=39164;received=66.166.9.194
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=e1FF6S7cgamNg
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 41 INVITE
   Contact: <sip:1001 at 216.209.211.222:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Require: timer
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Session-Expires: 120;refresher=uac
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 222
   P-Asserted-Identity: "Outbound Call" <sip:1001 at 216.209.211.222>
   
   v=0
   o=FreeSWITCH 1455720482 1455720483 IN IP4 216.209.211.222
   s=FreeSWITCH
   c=IN IP4 216.209.211.222
   t=0 0
   m=audio 25166 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [DEBUG] switch_channel.c:3767 (sofia/internal/1000 at 216.209.211.222) Callstate Change EARLY -> ACTIVE
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [DEBUG] sofia.c:6760 Channel sofia/internal/1000 at 216.209.211.222 entering state [completed][200]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [DEBUG] switch_ivr_originate.c:3608 Originate Resulted in Success: [sofia/internal/1001 at 10.0.1.2:40886]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [DEBUG] switch_ivr_originate.c:3608 Originate Resulted in Success: [sofia/internal/1001 at 10.0.1.2:40886]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.737383 [DEBUG] switch_core_media.c:9156 sofia/internal/1001 at 10.0.1.2:40886 PAUSE Jitterbuffer
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.737383 [DEBUG] switch_core_media.c:9156 sofia/internal/1000 at 216.209.211.222 PAUSE Jitterbuffer
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.737383 [DEBUG] switch_ivr_bridge.c:1591 (sofia/internal/1001 at 10.0.1.2:40886) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.737383 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001 at 10.0.1.2:40886) Running State Change CS_EXCHANGE_MEDIA
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.737383 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/1001 at 10.0.1.2:40886) State EXCHANGE_MEDIA
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:30.737383 [DEBUG] mod_sofia.c:613 SOFIA EXCHANGE_MEDIA
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:30.757403 [DEBUG] switch_rtp.c:6654 Correct audio ip/port confirmed.
send 1094 bytes to udp/[66.166.9.194]:39164 at 13:47:31.244642:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK1578402832;rport=39164;received=66.166.9.194
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=e1FF6S7cgamNg
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 41 INVITE
   Contact: <sip:1001 at 216.209.211.222:5060;transport=udp>
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Require: timer
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
   Session-Expires: 120;refresher=uac
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 222
   P-Asserted-Identity: "Outbound Call" <sip:1001 at 216.209.211.222>
   
   v=0
   o=FreeSWITCH 1455720482 1455720483 IN IP4 216.209.211.222
   s=FreeSWITCH
   c=IN IP4 216.209.211.222
   t=0 0
   m=audio 25166 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
recv 764 bytes from udp/[66.166.9.194]:39164 at 13:47:31.321742:
   ------------------------------------------------------------------------
   ACK sip:1001 at 216.209.211.222:5060;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK145924562;rport
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=e1FF6S7cgamNg
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 41 ACK
   Contact: <sip:1000 at 10.0.1.12:40886>
   Proxy-Authorization: Digest username="1000", realm="216.209.211.222", nonce="696ccc87-c214-4a8a-870f-7e3d69ca016d", uri="sip:1001 at 216.209.211.222", response="73ea6df6242e1f2e5cc6e4d6bad9be3e", algorithm=MD5, cnonce="15059615", qop=auth, nc=00000006
   Max-Forwards: 70
   Supported: replaces, path, timer, eventlist
   User-Agent: Grandstream Wave/IOS 1.0.19
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 764 bytes from udp/[66.166.9.194]:39164 at 13:47:31.327208:
   ------------------------------------------------------------------------
   ACK sip:1001 at 216.209.211.222:5060;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK145924562;rport
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=e1FF6S7cgamNg
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 41 ACK
   Contact: <sip:1000 at 10.0.1.12:40886>
   Proxy-Authorization: Digest username="1000", realm="216.209.211.222", nonce="696ccc87-c214-4a8a-870f-7e3d69ca016d", uri="sip:1001 at 216.209.211.222", response="73ea6df6242e1f2e5cc6e4d6bad9be3e", algorithm=MD5, cnonce="15059615", qop=auth, nc=00000006
   Max-Forwards: 70
   Supported: replaces, path, timer, eventlist
   User-Agent: Grandstream Wave/IOS 1.0.19
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Length: 0
   
   ------------------------------------------------------------------------
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:31.317425 [DEBUG] sofia.c:6760 Channel sofia/internal/1000 at 216.209.211.222 entering state [ready][200]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:31.517381 [INFO] switch_rtp.c:6616 Auto Changing audio port from 10.0.1.2:35544 to 66.166.9.194:46630
recv 519 bytes from udp/[66.166.9.194]:39164 at 13:47:37.588043:
   ------------------------------------------------------------------------
   BYE sip:1001 at 216.209.211.222:5060;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK1092657280;rport
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=e1FF6S7cgamNg
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 42 BYE
   Contact: <sip:1000 at 10.0.1.12:40886>
   Max-Forwards: 70
   Supported: replaces, path, timer, eventlist
   User-Agent: Grandstream Wave/IOS 1.0.19
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Length: 0
   
   ------------------------------------------------------------------------
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [NOTICE] sofia.c:952 Hangup sofia/internal/1000 at 216.209.211.222 [CS_EXECUTE] [NORMAL_CLEARING]
send 466 bytes to udp/[66.166.9.194]:39164 at 13:47:37.598615:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 10.0.1.12:40886;branch=z9hG4bK1092657280;rport=39164;received=66.166.9.194
   From: <sip:1000 at 216.209.211.222>;tag=243846933
   To: <sip:1001 at 216.209.211.222>;tag=e1FF6S7cgamNg
   Call-ID: 930817686-40886-5 at BA.A.B.BC
   CSeq: 42 BYE
   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Content-Length: 0
   
   ------------------------------------------------------------------------
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD DONE [sofia/internal/1000 at 216.209.211.222]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_ivr_bridge.c:699 sofia/internal/1000 at 216.209.211.222 ending bridge by request from write function
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD DONE [sofia/internal/1001 at 10.0.1.2:40886]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [NOTICE] switch_ivr_bridge.c:881 Hangup sofia/internal/1001 at 10.0.1.2:40886 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/1001 at 10.0.1.2:40886) State EXCHANGE_MEDIA going to sleep
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001 at 10.0.1.2:40886) Running State Change CS_HANGUP
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1001 at 10.0.1.2:40886) Callstate Change ACTIVE -> HANGUP
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_ivr_bridge.c:1689 sofia/internal/1001 at 10.0.1.2:40886 skip receive message [UNBRIDGE] (channel is hungup already)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_ivr_bridge.c:1692 sofia/internal/1000 at 216.209.211.222 skip receive message [UNBRIDGE] (channel is hungup already)
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001 at 10.0.1.2:40886) State HANGUP
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] mod_sofia.c:425 sofia/internal/1001 at 10.0.1.2:40886 Overriding SIP cause 480 with 200 from the other leg
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] mod_sofia.c:431 Channel sofia/internal/1001 at 10.0.1.2:40886 hanging up, cause: NORMAL_CLEARING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_session.c:2796 sofia/internal/1000 at 216.209.211.222 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:539 (sofia/internal/1000 at 216.209.211.222) State EXECUTE going to sleep
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at 216.209.211.222) Running State Change CS_HANGUP
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1000 at 216.209.211.222) Callstate Change ACTIVE -> HANGUP
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000 at 216.209.211.222) State HANGUP
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] mod_sofia.c:431 Channel sofia/internal/1000 at 216.209.211.222 hanging up, cause: NORMAL_CLEARING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] mod_sofia.c:484 Sending BYE to sofia/internal/1001 at 10.0.1.2:40886
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001 at 10.0.1.2:40886 Standard HANGUP, cause: NORMAL_CLEARING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001 at 10.0.1.2:40886) State HANGUP going to sleep
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:508 (sofia/internal/1001 at 10.0.1.2:40886) State Change CS_HANGUP -> CS_REPORTING
send 559 bytes to udp/[66.166.9.194]:41958 at 13:47:37.609113:
   ------------------------------------------------------------------------
   BYE sip:1001 at 10.0.1.2:40886 SIP/2.0
   Via: SIP/2.0/UDP 216.209.211.222;rport;branch=z9hG4bK5tgvXv1evDy0c
   Max-Forwards: 70
   From: "Extension 1000" <sip:1000 at 216.209.211.222>;tag=Fa977mrgDKa8B
   To: <sip:1001 at 10.0.1.2:40886>;tag=2072085022
   Call-ID: e124e149-5062-1234-9bb4-c6827b410b7a
   CSeq: 87536760 BYE15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001 at 10.0.1.2:40886) Running State Change CS_REPORTING

   User-Agent: FreeSWITCH-mod_sofia/1.6.6~64bit
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Reason: Q.850;cause=16;text="NORMAL_CLEARING"
   Content-Length: 0
   
   ------------------------------------------------------------------------
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1001 at 10.0.1.2:40886) State REPORTING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1001 at 10.0.1.2:40886 Standard REPORTING, cause: NORMAL_CLEARING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1001 at 10.0.1.2:40886) State REPORTING going to sleep
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/1001 at 10.0.1.2:40886) State Change CS_REPORTING -> CS_DESTROY
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_session.c:1646 Session 7 (sofia/internal/1001 at 10.0.1.2:40886) Locked, Waiting on external entities
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [NOTICE] switch_core_session.c:1664 Session 7 (sofia/internal/1001 at 10.0.1.2:40886) Ended
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/1001 at 10.0.1.2:40886 [CS_DESTROY]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000 at 216.209.211.222 Standard HANGUP, cause: NORMAL_CLEARING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000 at 216.209.211.222) State HANGUP going to sleep
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:508 (sofia/internal/1000 at 216.209.211.222) State Change CS_HANGUP -> CS_REPORTING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/1001 at 10.0.1.2:40886) Running State Change CS_DESTROY
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001 at 10.0.1.2:40886) State DESTROY
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] mod_sofia.c:341 sofia/internal/1001 at 10.0.1.2:40886 SOFIA DESTROY
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1000 at 216.209.211.222) Running State Change CS_REPORTING
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1001 at 10.0.1.2:40886 Standard DESTROY
15df2523-1e92-49ca-bf21-bbf07d51c29e 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001 at 10.0.1.2:40886) State DESTROY going to sleep
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1000 at 216.209.211.222) State REPORTING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1000 at 216.209.211.222 Standard REPORTING, cause: NORMAL_CLEARING
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1000 at 216.209.211.222) State REPORTING going to sleep
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/1000 at 216.209.211.222) State Change CS_REPORTING -> CS_DESTROY
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_session.c:1646 Session 6 (sofia/internal/1000 at 216.209.211.222) Locked, Waiting on external entities
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [NOTICE] switch_core_session.c:1664 Session 6 (sofia/internal/1000 at 216.209.211.222) Ended
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/1000 at 216.209.211.222 [CS_DESTROY]
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/1000 at 216.209.211.222) Running State Change CS_DESTROY
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000 at 216.209.211.222) State DESTROY
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] mod_sofia.c:341 sofia/internal/1000 at 216.209.211.222 SOFIA DESTROY
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1000 at 216.209.211.222 Standard DESTROY
4008c053-8780-4987-b84f-010b67013bda 2016-02-17 13:47:37.597418 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000 at 216.209.211.222) State DESTROY going to sleep
recv 501 bytes from udp/[66.166.9.194]:41958 at 13:47:37.651003:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 216.209.211.222;rport=5060;branch=z9hG4bK5tgvXv1evDy0c
   From: "Extension 1000" <sip:1000 at 216.209.211.222>;tag=Fa977mrgDKa8B
   To: <sip:1001 at 10.0.1.2:40886>;tag=2072085022
   Call-ID: e124e149-5062-1234-9bb4-c6827b410b7a
   CSeq: 87536760 BYE
   Contact: <sip:1001 at 10.0.1.2:40886>
   Supported: replaces, path, timer, eventlist
   User-Agent: Grandstream Wave/IOS 1.0.19
   Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
   Content-Length: 0
   
   ------------------------------------------------------------------------
2016-02-17 13:47:41.537380 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/var/log/freeswitch/cdr-csv/1000.csv
2016-02-17 13:47:41.537380 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/var/log/freeswitch/cdr-csv/Master.csv


Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list