Jump to content

jlhughes

Members
 View Profile  See their activity

  • Posts

    31

  • Joined

  • Last visited

  • Days Won

    1

 Content Type 

Profiles

Forums

Resource Library: Monster UI Apps for KAZOO

Events

Downloads

Posts posted by jlhughes

  2. Proxy Causes Termination

    in Hardware Endpoints

    Posted

    Quote

    Dear DG,

    Thank you for your update and provided all the details.

    Our engineers team detected possible cause of reported error and
    we expect proxy server update coming next week.

    As soon as update will be released we will inform you.

    It's time to crack out the wine to celebrate :)

  3. Proxy Causes Termination

    in Hardware Endpoints

    Posted

    19 hours ago, Darren Schreiber said:

    Well let's see what they say first before we celebrate.

     

    I have been in close communication with DIDww, and they have shared that they've accepted the fault and began an internal investigation. They also intend to build a 2600Hz instance and attempt to replicate the error. I would call that rather interesting of a response so far! :) 

  4. Proxy Causes Termination

    in Hardware Endpoints

    Posted

    Darren, 

    You are a gem! thanks so much for pointing me in the right direction. Interesting that you work with DIDww! as an internal telco for Dove Gospel - Global, we had used them for about 4 years until we migrated over to DIDx. The coverage there is pretty crazy! we get DIDs in Uganda lol. 

  5. Proxy Causes Termination

    in Hardware Endpoints

    Posted

    Welp! (hides under a rock), 

    We are using DIDww's appliance software called Call.Center. This is purely due to the simplicity of the deployment onto both workstations and mobile devices, it is cloud based and all you have to do is provide either a barcode (to activate call.center) or a special key. And automatically the credentials and SIP server is managed through a website. 

    On that note as well! when turning off the push feature, the calls route successfully and there is no issue at all. So it could actually be an issue with the push software they have engineered. Interesting huh! 

  6. Proxy Causes Termination

    in Hardware Endpoints

    Posted

    It is a little bit beyond me, and I'm EXTREMELY appreciative for this help: 

    Nov  1 04:33:20 pbx01 kamailio[1766]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received udp request INVITE sip:888100@pbxdg.domain.net:5060;transport=udp
Nov  1 04:33:20 pbx01 kamailio[1766]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source 46.19.210.33:6050 -> SERVERIP:5060
Nov  1 04:33:20 pbx01 kamailio[1766]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|from sip:user_f84u8dn62s@pbxdg.domain.net
Nov  1 04:33:20 pbx01 kamailio[1766]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|to sip:888100@pbxdg.domain.net
Nov  1 04:33:20 pbx01 kamailio[1766]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|originated from external sources
Nov  1 04:33:20 pbx01 kamailio[1766]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|SERVERIP:5060 -> SERVERIP:11000
Nov  1 04:33:20 pbx01 kamailio[1763]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received internal reply 100 Trying
Nov  1 04:33:20 pbx01 kamailio[1763]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source SERVERIP:11000
Nov  1 04:33:20 pbx01 kamailio[1763]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|46.19.210.33:6050
Nov  1 04:33:20 pbx01 kamailio[1826]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|received dialog update for sip:888701@pbxdg.domain.net state confirmed from sip:SERVERIP:11000 at 1509510800/1509510800
Nov  1 04:33:20 pbx01 kamailio[1826]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|skip dialog update for sip:888701@pbxdg.domain.net
Nov  1 04:33:20 pbx01 kamailio[1826]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|skip presence update for sip:888701@pbxdg.domain.net
Nov  1 04:33:20 pbx01 kamailio[1826]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|finished processing dialog update for sip:888701@pbxdg.domain.net state confirmed from sip:SERVERIP:11000 at 1509510800/1509510800/1509510800
Nov  1 04:33:20 pbx01 kamailio[1769]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received internal reply 200 OK
Nov  1 04:33:21 pbx01 kamailio[1769]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source SERVERIP:11000
Nov  1 04:33:21 pbx01 kamailio[1769]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|call setup, now ignoring abnormal termination
Nov  1 04:33:21 pbx01 kamailio[1769]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|46.19.210.33:6050
Nov  1 04:33:21 pbx01 kamailio[1820]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|received dialog update for sip:888701@pbxdg.domain.net state confirmed from sip:SERVERIP:11000 at 1509510801/1509510801
Nov  1 04:33:21 pbx01 kamailio[1820]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|skip dialog update for sip:888701@pbxdg.domain.net
Nov  1 04:33:21 pbx01 kamailio[1820]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|skip presence update for sip:888701@pbxdg.domain.net
Nov  1 04:33:21 pbx01 kamailio[1820]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|finished processing dialog update for sip:888701@pbxdg.domain.net state confirmed from sip:SERVERIP:11000 at 1509510801/1509510801/1509510801
Nov  1 04:33:21 pbx01 kamailio[1760]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received udp request ACK sip:888100@SERVERIP:11000;transport=udp
Nov  1 04:33:21 pbx01 kamailio[1760]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source 46.19.210.33:6050 -> SERVERIP:5060
Nov  1 04:33:21 pbx01 kamailio[1760]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|from sip:user_f84u8dn62s@pbxdg.domain.net
Nov  1 04:33:21 pbx01 kamailio[1760]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|to sip:888100@pbxdg.domain.net
Nov  1 04:33:21 pbx01 kamailio[1760]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|originated from external sources
Nov  1 04:33:21 pbx01 kamailio[1760]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|loose_route in-dialog message
Nov  1 04:33:21 pbx01 kamailio[1760]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|SERVERIP:5060 -> SERVERIP:11000
Nov  1 04:33:25 pbx01 kamailio[1774]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received udp request BYE sip:888100@SERVERIP:11000;transport=udp
Nov  1 04:33:25 pbx01 kamailio[1762]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received udp request REFER sip:888100@SERVERIP:11000;transport=udp
Nov  1 04:33:25 pbx01 kamailio[1774]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source 46.19.210.33:6050 -> SERVERIP:5060
Nov  1 04:33:25 pbx01 kamailio[1774]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|from sip:user_f84u8dn62s@pbxdg.domain.net
Nov  1 04:33:25 pbx01 kamailio[1774]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|to sip:888100@pbxdg.domain.net
Nov  1 04:33:25 pbx01 kamailio[1762]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source 46.19.210.33:6050 -> SERVERIP:5060
Nov  1 04:33:25 pbx01 kamailio[1762]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|from sip:user_f84u8dn62s@pbxdg.domain.net
Nov  1 04:33:25 pbx01 kamailio[1762]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|to sip:888100@pbxdg.domain.net
Nov  1 04:33:25 pbx01 kamailio[1774]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|originated from external sources
Nov  1 04:33:25 pbx01 kamailio[1762]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|originated from external sources
Nov  1 04:33:25 pbx01 kamailio[1774]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|loose_route in-dialog message
Nov  1 04:33:25 pbx01 kamailio[1762]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|loose_route in-dialog message
Nov  1 04:33:25 pbx01 kamailio[1774]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|SERVERIP:5060 -> SERVERIP:11000
Nov  1 04:33:25 pbx01 kamailio[1762]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|SERVERIP:5060 -> SERVERIP:11000
Nov  1 04:33:25 pbx01 kamailio[1771]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received internal reply 500 Internal Server Error
Nov  1 04:33:25 pbx01 kamailio[1771]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source SERVERIP:11000
Nov  1 04:33:25 pbx01 kamailio[1771]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received failure reply 500 <null>
Nov  1 04:33:25 pbx01 kamailio[1771]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|46.19.210.33:6050
Nov  1 04:33:25 pbx01 kamailio[1780]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|start|received internal reply 200 OK
Nov  1 04:33:25 pbx01 kamailio[1780]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|source SERVERIP:11000
Nov  1 04:33:25 pbx01 kamailio[1780]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|pass|46.19.210.33:6050
Nov  1 04:33:25 pbx01 kamailio[1815]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|received dialog update for sip:888701@pbxdg.domain.net state terminated from sip:SERVERIP:11000 at 1509510805/1509510805
Nov  1 04:33:25 pbx01 kamailio[1815]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|skip dialog update for sip:888701@pbxdg.domain.net
Nov  1 04:33:25 pbx01 kamailio[1815]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|skip presence update for sip:888701@pbxdg.domain.net
Nov  1 04:33:25 pbx01 kamailio[1815]: INFO: <script>: 08594CE6-59F94E9000060587-C1811700|log|finished processing dialog update for sip:888701@pbxdg.domain.net state terminated from sip:SERVERIP:11000 at 1509510805/1509510805/1509510805

    Hoping this spreads some light on the issue :)

  7. Proxy Causes Termination

    in Hardware Endpoints

    Posted

    Hey Darren, 

    Call.Center proxy is a feature that enables a SIP account to be handled by Call Center's push feature, it essentially allows calls to be routed through to iPhones and locations where they block the generic SIP port 5060. It is very useful in the areas we have actually deployed 2600hz.  

    recv 1376 bytes from udp/[KAZOOIP]:5060 at 04:33:09.298513:
   ------------------------------------------------------------------------
   INVITE sip:888701@pbxdg.domain.net:5060;transport=udp SIP/2.0
   Record-Route: <sip:KAZOOIP;lr=on;ftag=309022BA-59F94E850003A17D-C1C15700>
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bKfd1a.37859ae0b746929f182e0e4ec2f7fe79.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKpOioMaK2;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>
   CSeq: 10 INVITE
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   Max-Forwards: 50
   User-Agent: call.center proxy
   Content-Type: application/sdp
   Contact: <sip:46.19.210.33:6050;transport=udp>
   Content-Length: 261
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   X-ecallmgr_Account-ID: 75c5b9a0047e65399de45f41258e38e4
   X-ecallmgr_Authorizing-Type: device
   X-ecallmgr_Authorizing-ID: c04a2812eff90b41dd1282c4ffc03998
   X-ecallmgr_Username: user_f84u8dn62s
   X-ecallmgr_Realm: pbxdg.domain.net
   X-ecallmgr_Account-Realm: pbxdg.domain.net
   X-ecallmgr_Account-Name: Dove Gospel - Global
   X-ecallmgr_Presence-ID: 888701@pbxdg.domain.net
   X-ecallmgr_Owner-ID: 9333eab27c60732f233e2b803e7c073b
   
   v=0
   o=sems 838687344 1399990445 IN IP4 46.19.210.33
   s=sems
   c=IN IP4 46.19.210.33
   t=0 0
   m=audio 21162 RTP/AVP 120 8 0 96
   a=rtpmap:120 opus/48000/2
   a=rtpmap:8 PCMA/8000
   a=rtpmap:0 PCMU/8000
   a=rtpmap:96 telephone-event/8000
   a=sendrecv
   a=direction:both
   ------------------------------------------------------------------------
send 498 bytes to udp/[KAZOOIP]:5060 at 04:33:09.299008:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bKfd1a.37859ae0b746929f182e0e4ec2f7fe79.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKpOioMaK2;rport=6050
   Record-Route: <sip:KAZOOIP;lr=on;ftag=309022BA-59F94E850003A17D-C1C15700>
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   CSeq: 10 INVITE
   User-Agent: 2600hz
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:09.295171 [NOTICE] switch_channel.c:1104 New Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [371868A9-59F94E850003A182-C1C15700]
2017-11-01 04:33:09.295171 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_NEW (Cur 1 Tot 485)
2017-11-01 04:33:09.295171 [DEBUG] sofia.c:9873 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net receiving invite from KAZOOIP:5060 version: 1.6.19  64bit
2017-11-01 04:33:09.295171 [DEBUG] sofia.c:9999 1 acls to check for proxy
2017-11-01 04:33:09.295171 [DEBUG] sofia.c:10004 checking KAZOOIP against acl authoritative
2017-11-01 04:33:09.295171 [INFO] sofia.c:10006 KAZOOIP is a proxy according to the authoritative acl
2017-11-01 04:33:09.295171 [DEBUG] sofia.c:10016 network ip is a proxy
2017-11-01 04:33:09.295171 [DEBUG] sofia.c:10020 found auth ip [X-AUTH-IP] header of [46.19.210.33]
2017-11-01 04:33:09.295171 [DEBUG] sofia.c:10044 IP KAZOOIP Rejected by acl "trusted". Falling back to Digest auth.
2017-11-01 04:33:09.295171 [DEBUG] kazoo_fetch_agent.c:216 Sending directory XML request (c350322c-bebd-11e7-b230-cf451ddd7335) to ecallmgr@pbx01.exch1.net <1.1432.0>
2017-11-01 04:33:09.355383 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.1432.0>
2017-11-01 04:33:09.355383 [DEBUG] kazoo_fetch_agent.c:277 Received directory XML (c350322c-bebd-11e7-b230-cf451ddd7335) after 60ms: <document type="freeswitch/xml"><section name="directory"><domain name="pbxdg.domain.net"><user id="user_f84u8dn62s"><variables><variable name="ecallmgr_Account-ID" value="75c5b9a0047e65399de45f41258e38e4"/><variable name="ecallmgr_Authorizing-Type" value="device"/><variable name="ecallmgr_Authorizing-ID" value="c04a2812eff90b41dd1282c4ffc03998"/><variable name="ecallmgr_Username" value="user_f84u8dn62s"/><variable name="ecallmgr_Realm" value="pbxdg.domain.net"/><variable name="ecallmgr_Account-Realm" value="pbxdg.domain.net"/><variable name="ecallmgr_Account-Name" value="Dove Gospel - Global"/><variable name="presence_id" value="888701@pbxdg.domain.net"/><variable name="ecallmgr_Owner-ID" value="9333eab27c60732f233e2b803e7c073b"/></variables><params><param name="password" value="ee61139cd193c08528c84683"/></params></user></domain></section></document>
2017-11-01 04:33:09.355383 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [received][100]
2017-11-01 04:33:09.355383 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=sems 838687344 1399990445 IN IP4 46.19.210.33
s=sems
c=IN IP4 46.19.210.33
t=0 0
m=audio 21162 RTP/AVP 120 8 0 96
a=rtpmap:120 opus/48000/2
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 telephone-event/8000
a=direction:both

2017-11-01 04:33:09.355383 [DEBUG] sofia.c:7486 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_NEW -> CS_INIT
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:603 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State NEW
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_INIT (Cur 1 Tot 485)
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State INIT
2017-11-01 04:33:09.355383 [DEBUG] mod_sofia.c:90 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA INIT
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard INIT
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_INIT -> CS_ROUTING
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State INIT going to sleep
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_ROUTING (Cur 1 Tot 485)
2017-11-01 04:33:09.355383 [DEBUG] switch_channel.c:2249 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change DOWN -> RINGING
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING
2017-11-01 04:33:09.355383 [DEBUG] mod_sofia.c:143 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA ROUTING
2017-11-01 04:33:09.355383 [DEBUG] switch_core_state_machine.c:236 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard ROUTING
2017-11-01 04:33:09.355383 [INFO] mod_dialplan_xml.c:637 Processing user_f84u8dn62s <user_f84u8dn62s>->888701 in context context_2
2017-11-01 04:33:09.355383 [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request (c359fd70-bebd-11e7-b232-cf451ddd7335) to ecallmgr@pbx01.exch1.net <1.1383.0>
2017-11-01 04:33:09.555173 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.1383.0>
2017-11-01 04:33:09.555173 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(371868A9-59F94E850003A182-C1C15700 ecallmgr_Call-Interaction-ID=63676729989-48a2eba5)
2017-11-01 04:33:09.575166 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24298.32>
2017-11-01 04:33:09.575166 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24299.32>
2017-11-01 04:33:09.575166 [DEBUG] kazoo_fetch_agent.c:277 Received dialplan XML (c359fd70-bebd-11e7-b232-cf451ddd7335) after 219ms: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|ecallmgr@pbx01.exch1.net won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=ecallmgr@pbx01.exch1.net"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}" inline="true"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="kz_multiset" data="^^|ecallmgr_Username=user_f84u8dn62s|ecallmgr_Realm=pbxdg.domain.net|presence_id=888701@pbxdg.domain.net|ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b|ecallmgr_Fetch-ID=c359fd70-bebd-11e7-b232-cf451ddd7335|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63676729989-48a2eba5|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998|ecallmgr_Account-Realm=pbxdg.domain.net|ecallmgr_Account-Name=Dove Gospel - Global|ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4|ecallmgr_CallFlow-ID=3033db20be8da86ca844642e7578b780|ecallmgr_Channel-Authorized=true"/><action application="multiunset" data="^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID"/><action application="park"/></condition></extension></context></section></document>
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net parsing [context_2->park] continue=false
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Absolute Condition [park]
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action log(NOTICE log|${uuid}|ecallmgr@pbx01.exch1.net won call control) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action export(ecallmgr_Ecallmgr-Node=ecallmgr@pbx01.exch1.net) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action set(ringback=%(2000,4000,440,480)) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action set(transfer_ringback=%(2000,4000,440,480)) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action kz_multiset(^^|ecallmgr_Username=user_f84u8dn62s|ecallmgr_Realm=pbxdg.domain.net|presence_id=888701@pbxdg.domain.net|ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b|ecallmgr_Fetch-ID=c359fd70-bebd-11e7-b232-cf451ddd7335|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63676729989-48a2eba5|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998|ecallmgr_Account-Realm=pbxdg.domain.net|ecallmgr_Account-Name=Dove Gospel - Global|ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4|ecallmgr_CallFlow-ID=3033db20be8da86ca844642e7578b780|ecallmgr_Channel-Authorized=true) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action park() 
|--- Dialplan: Processing recursive conditions level:1 [park_recur_1] require-nested=TRUE
|--- Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Regex (PASS) [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/ break=on-false
|--- Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action export(ecallmgr_Bridge-ID=${UUID}) INLINE
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net export(ecallmgr_Bridge-ID=371868A9-59F94E850003A182-C1C15700)
2017-11-01 04:33:09.575166 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Bridge-ID]=[371868A9-59F94E850003A182-C1C15700]
2017-11-01 04:33:09.575166 [DEBUG] switch_core_state_machine.c:286 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_ROUTING -> CS_EXECUTE
2017-11-01 04:33:09.575166 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING going to sleep
2017-11-01 04:33:09.575166 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_EXECUTE (Cur 1 Tot 485)
2017-11-01 04:33:09.575166 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State EXECUTE
2017-11-01 04:33:09.575166 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4249
2017-11-01 04:33:09.575166 [DEBUG] mod_sofia.c:198 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA EXECUTE
2017-11-01 04:33:09.575166 [DEBUG] switch_core_state_machine.c:328 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard EXECUTE
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net log(NOTICE log|371868A9-59F94E850003A182-C1C15700|ecallmgr@pbx01.exch1.net won call control)
2017-11-01 04:33:09.575166 [NOTICE] mod_dptools.c:1742 log|371868A9-59F94E850003A182-C1C15700|ecallmgr@pbx01.exch1.net won call control
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net export(ecallmgr_Ecallmgr-Node=ecallmgr@pbx01.exch1.net)
2017-11-01 04:33:09.575166 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Ecallmgr-Node]=[ecallmgr@pbx01.exch1.net]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4311
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net set(ringback=%(2000,4000,440,480))
2017-11-01 04:33:09.575166 [DEBUG] mod_dptools.c:1548 SET sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net set(transfer_ringback=%(2000,4000,440,480))
2017-11-01 04:33:09.575166 [DEBUG] mod_dptools.c:1548 SET sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [transfer_ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net kz_multiset(^^|ecallmgr_Username=user_f84u8dn62s|ecallmgr_Realm=pbxdg.domain.net|presence_id=888701@pbxdg.domain.net|ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b|ecallmgr_Fetch-ID=c359fd70-bebd-11e7-b232-cf451ddd7335|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63676729989-48a2eba5|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998|ecallmgr_Account-Realm=pbxdg.domain.net|ecallmgr_Account-Name=Dove Gospel - Global|ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4|ecallmgr_CallFlow-ID=3033db20be8da86ca844642e7578b780|ecallmgr_Channel-Authorized=true)
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Username]=[user_f84u8dn62s]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Realm]=[pbxdg.domain.net]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [presence_id]=[888701@pbxdg.domain.net]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Owner-ID]=[9333eab27c60732f233e2b803e7c073b]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Fetch-ID]=[c359fd70-bebd-11e7-b232-cf451ddd7335]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Screen-Bit]=[true]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Number]=[false]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Name]=[false]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Call-Interaction-ID]=[63676729989-48a2eba5]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-Type]=[device]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-ID]=[c04a2812eff90b41dd1282c4ffc03998]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Realm]=[pbxdg.domain.net]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Name]=[Dove Gospel - Global]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-ID]=[75c5b9a0047e65399de45f41258e38e4]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_CallFlow-ID]=[3033db20be8da86ca844642e7578b780]
2017-11-01 04:33:09.575166 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Channel-Authorized]=[true]
2017-11-01 04:33:09.585250 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4331
2017-11-01 04:33:09.585250 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4205
2017-11-01 04:33:09.585250 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4307
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID)
2017-11-01 04:33:09.585250 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5111
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net park()
2017-11-01 04:33:09.585250 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5958
2017-11-01 04:33:09.585250 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4460
2017-11-01 04:33:09.615364 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(371868A9-59F94E850003A182-C1C15700 ^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c359fd70-bebd-11e7-b232-cf451ddd7335;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_Call-Interaction-ID=63676729989-48a2eba5;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;ecallmgr_CallFlow-ID=3033db20be8da86ca844642e7578b780;ecallmgr_Channel-Authorized=true;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow)
2017-11-01 04:33:09.645357 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24299.32>
2017-11-01 04:33:09.645357 [NOTICE] kazoo_node.c:430 log|371868A9-59F94E850003A182-C1C15700|executing kz_multiset ^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c359fd70-bebd-11e7-b232-cf451ddd7335;ecallmgr_Channel-Authorized=true;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_CallFlow-ID=3033db20be8da86ca844642e7578b780;ecallmgr_Call-Interaction-ID=63676729989-48a2eba5;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;effective_caller_id_number=888701;effective_caller_id_name=James Hughes 
2017-11-01 04:33:09.665169 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute kz_multiset(^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c359fd70-bebd-11e7-b232-cf451ddd7335;ecallmgr_Channel-Authorized=true;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_CallFlow-ID=3033db20be8da86ca844642e7578b780;ecallmgr_Call-Interaction-ID=63676729989-48a2eba5;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;effective_caller_id_number=888701;effective_caller_id_name=James Hughes)
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net kz_multiset(^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c359fd70-bebd-11e7-b232-cf451ddd7335;ecallmgr_Channel-Authorized=true;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_CallFlow-ID=3033db20be8da86ca844642e7578b780;ecallmgr_Call-Interaction-ID=63676729989-48a2eba5;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;effective_caller_id_number=888701;effective_caller_id_name=James Hughes)
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Username]=[user_f84u8dn62s]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Realm]=[pbxdg.domain.net]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [presence_id]=[888701@pbxdg.domain.net]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Owner-ID]=[9333eab27c60732f233e2b803e7c073b]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Fetch-ID]=[c359fd70-bebd-11e7-b232-cf451ddd7335]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Channel-Authorized]=[true]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Screen-Bit]=[true]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Number]=[false]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Name]=[false]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_CallFlow-ID]=[3033db20be8da86ca844642e7578b780]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Call-Interaction-ID]=[63676729989-48a2eba5]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-Type]=[device]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-ID]=[c04a2812eff90b41dd1282c4ffc03998]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Application-Node]=[kazoo_apps@pbx01.exch1.net]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Application-Name]=[callflow]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Realm]=[pbxdg.domain.net]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Name]=[Dove Gospel - Global]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-ID]=[75c5b9a0047e65399de45f41258e38e4]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [effective_caller_id_number]=[888701]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [effective_caller_id_name]=[James Hughes]
2017-11-01 04:33:09.665169 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4849
2017-11-01 04:33:09.665169 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5784
2017-11-01 04:33:09.845329 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24319.32>
2017-11-01 04:33:09.845329 [NOTICE] kazoo_node.c:430 log|371868A9-59F94E850003A182-C1C15700|executing ring_ready  
2017-11-01 04:33:09.865165 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute ring_ready()
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net ring_ready()
2017-11-01 04:33:09.865165 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net!
send 998 bytes to udp/[KAZOOIP]:5060 at 04:33:09.870144:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bKfd1a.37859ae0b746929f182e0e4ec2f7fe79.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKpOioMaK2;rport=6050
   Record-Route: <sip:KAZOOIP;lr=on;ftag=309022BA-59F94E850003A17D-C1C15700>
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>;tag=49gcKgrc8ZB2S
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   CSeq: 10 INVITE
   Contact: <sip:888701@KAZOOIP:11000;transport=udp>
   User-Agent: 2600hz
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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-Length: 0
   Remote-Party-ID: "888701" <sip:888701@pbxdg.domain.net>;party=calling;privacy=off;screen=no
   
2017-11-01 04:33:09.865165 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net!
   ------------------------------------------------------------------------
2017-11-01 04:33:09.865165 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4103
2017-11-01 04:33:09.885472 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [early][180]
2017-11-01 04:33:10.045333 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24319.32>
2017-11-01 04:33:10.045333 [DEBUG] kazoo_node.c:1344 increased received message buffer size to 2275
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: set continue_on_fail=true
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: export sip_redirect_context=context_2
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: set hangup_after_bridge=true
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: export ecallmgr_Inception=${ecallmgr_Inception}
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: export ecallmgr_Call-Interaction-ID=${ecallmgr_Call-Interaction-ID}
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: bridge {call_timeout=30,originate_timeout=30,outbound_redirect_fatal='false',local_var_clobber='true'}[^^!ecallmgr_Username='user_vrf59sfv4q'!ecallmgr_Realm='pbxdg.domain.net'!presence_id='888701@pbxdg.domain.net'!origination_callee_id_number='888701'!origination_callee_id_name='James Hughes'!leg_timeout='30'!sip_h_X-KAZOO-AOR=sip:user_vrf59sfv4q@pbxdg.domain.net!sip_h_X-KAZOO-INVITE-FORMAT=contact!ecallmgr_Authorizing-ID='b2c525170e891ce12950790e47b5eb9f'!ecallmgr_Authorizing-Type='device'!ecallmgr_Owner-ID='9333eab27c60732f233e2b803e7c073b'!ecallmgr_Account-ID='75c5b9a0047e65399de45f41258e38e4'!sdp_secure_savp_only='true'!sip_invite_domain='pbxdg.domain.net'!absolute_codec_string='^^:PCMU:PCMA'!effective_callee_id_number='888701'!effective_callee_id_name='James Hughes']sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net;fs_path=sip:KAZOOIP,[^^!ecallmgr_Username='user_f84u8dn62s'!ecallmgr_Realm='pbxdg.domain.net'!presence_id='888701@pbxdg.domain.net'!origination_callee_id_number='888701'!origination_callee_id_name='James Hughes'!leg_timeout='30'!sip_h_X-KAZOO-AOR=sip:user_f84u8dn62s@pbxdg.domain.net!sip_h_X-KAZOO-INVITE-FORMAT=contact!ecallmgr_Authorizing-ID='c04a2812eff90b41dd1282c4ffc03998'!ecallmgr_Authorizing-Type='device'!ecallmgr_Owner-ID='9333eab27c60732f233e2b803e7c073b'!ecallmgr_Account-ID='75c5b9a0047e65399de45f41258e38e4'!sdp_secure_savp_only='true'!sip_invite_domain='pbxdg.domain.net'!absolute_codec_string='^^:PCMU:PCMA'!effective_callee_id_number='888701'!effective_callee_id_name='James Hughes']sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net;fs_path=sip:KAZOOIP
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: event Event-Name=CUSTOM,Event-Subclass=kazoo::masquerade,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=bridge
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:447 log|371868A9-59F94E850003A182-C1C15700|building xferext extension: park 
2017-11-01 04:33:10.045333 [NOTICE] kazoo_node.c:450 log|371868A9-59F94E850003A182-C1C15700|transfered call to xferext extension
2017-11-01 04:33:10.065175 [DEBUG] switch_channel.c:3170 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_EXECUTE -> CS_ROUTING
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State EXECUTE going to sleep
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_ROUTING (Cur 1 Tot 485)
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING
2017-11-01 04:33:10.065175 [DEBUG] mod_sofia.c:143 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA ROUTING
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:236 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard ROUTING
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:256 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_ROUTING -> CS_EXECUTE
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING going to sleep
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_EXECUTE (Cur 1 Tot 485)
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State EXECUTE
2017-11-01 04:33:10.065175 [DEBUG] mod_sofia.c:198 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA EXECUTE
2017-11-01 04:33:10.065175 [DEBUG] switch_core_state_machine.c:328 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard EXECUTE
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net set(continue_on_fail=true)
2017-11-01 04:33:10.065175 [DEBUG] mod_dptools.c:1548 SET sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [continue_on_fail]=[true]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net export(sip_redirect_context=context_2)
2017-11-01 04:33:10.065175 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4109
2017-11-01 04:33:10.065175 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_redirect_context]=[context_2]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net set(hangup_after_bridge=true)
2017-11-01 04:33:10.065175 [DEBUG] mod_dptools.c:1548 SET sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [hangup_after_bridge]=[true]
2017-11-01 04:33:10.065175 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4217
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net export(ecallmgr_Inception=)
2017-11-01 04:33:10.065175 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Inception]=[UNDEF]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net export(ecallmgr_Call-Interaction-ID=63676729989-48a2eba5)
2017-11-01 04:33:10.065175 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4112
2017-11-01 04:33:10.075325 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Call-Interaction-ID]=[63676729989-48a2eba5]
2017-11-01 04:33:10.075325 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4110
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net bridge({call_timeout=30,originate_timeout=30,outbound_redirect_fatal='false',local_var_clobber='true'}[^^!ecallmgr_Username='user_vrf59sfv4q'!ecallmgr_Realm='pbxdg.domain.net'!presence_id='888701@pbxdg.domain.net'!origination_callee_id_number='888701'!origination_callee_id_name='James Hughes'!leg_timeout='30'!sip_h_X-KAZOO-AOR=sip:user_vrf59sfv4q@pbxdg.domain.net!sip_h_X-KAZOO-INVITE-FORMAT=contact!ecallmgr_Authorizing-ID='b2c525170e891ce12950790e47b5eb9f'!ecallmgr_Authorizing-Type='device'!ecallmgr_Owner-ID='9333eab27c60732f233e2b803e7c073b'!ecallmgr_Account-ID='75c5b9a0047e65399de45f41258e38e4'!sdp_secure_savp_only='true'!sip_invite_domain='pbxdg.domain.net'!absolute_codec_string='^^:PCMU:PCMA'!effective_callee_id_number='888701'!effective_callee_id_name='James Hughes']sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net;fs_path=sip:KAZOOIP,[^^!ecallmgr_Username='user_f84u8dn62s'!ecallmgr_Realm='pbxdg.domain.net'!presence_id='888701@pbxdg.domain.net'!origination_callee_id_number='888701'!origination_callee_id_name='James Hughes'!leg_timeout='30'!sip_h_X-KAZOO-AOR=sip:user_f84u8dn62s@pbxdg.domain.net!sip_h_X-KAZOO-INVITE-FORMAT=contact!ecallmgr_Authorizing-ID='c04a2812eff90b41dd1282c4ffc03998'!ecallmgr_Authorizing-Type='device'!ecallmgr_Owner-ID='9333eab27c60732f233e2b803e7c073b'!ecallmgr_Account-ID='75c5b9a0047e65399de45f41258e38e4'!sdp_secure_savp_only='true'!sip_invite_domain='pbxdg.domain.net'!absolute_codec_string='^^:PCMU:PCMA'!effective_callee_id_number='888701'!effective_callee_id_name='James Hughes']sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net;fs_path=sip:KAZOOIP)
2017-11-01 04:33:10.075325 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4228
2017-11-01 04:33:10.075325 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net EXPORTING[export_vars] [ecallmgr_Bridge-ID]=[371868A9-59F94E850003A182-C1C15700] to event
2017-11-01 04:33:10.075325 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net EXPORTING[export_vars] [ecallmgr_Ecallmgr-Node]=[ecallmgr@pbx01.exch1.net] to event
2017-11-01 04:33:10.075325 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net EXPORTING[export_vars] [sip_redirect_context]=[context_2] to event
2017-11-01 04:33:10.075325 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net EXPORTING[export_vars] [ecallmgr_Call-Interaction-ID]=[63676729989-48a2eba5] to event
2017-11-01 04:33:10.075325 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-11-01 04:33:10.075325 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
2017-11-01 04:33:10.075325 [NOTICE] switch_channel.c:1104 New Channel sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net [c3c6bfbe-bebd-11e7-b246-cf451ddd7335]
2017-11-01 04:33:10.075325 [DEBUG] mod_sofia.c:4819 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State Change CS_NEW -> CS_INIT
2017-11-01 04:33:10.075325 [DEBUG] switch_ivr_originate.c:2963 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Setting leg timeout to 30
2017-11-01 04:33:10.075325 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Running State Change CS_INIT (Cur 2 Tot 486)
2017-11-01 04:33:10.075325 [NOTICE] switch_channel.c:1104 New Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [c3c6dc38-bebd-11e7-b24c-cf451ddd7335]
2017-11-01 04:33:10.075325 [DEBUG] mod_sofia.c:4819 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_NEW -> CS_INIT
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State INIT
2017-11-01 04:33:10.075325 [DEBUG] mod_sofia.c:90 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net SOFIA INIT
2017-11-01 04:33:10.075325 [DEBUG] switch_ivr_originate.c:2963 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Setting leg timeout to 30
2017-11-01 04:33:10.075325 [DEBUG] sofia_glue.c:1264 sip:KAZOOIP Setting proxy route to sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net
2017-11-01 04:33:10.075325 [DEBUG] sofia_glue.c:1295 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net sending invite version: 1.6.19  64bit
Local SDP:
v=0
o=FreeSWITCH 1509489814 1509489815 IN IP4 KAZOOIP
s=FreeSWITCH
c=IN IP4 KAZOOIP
t=0 0
m=audio 20976 RTP/AVP 0 8 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_INIT (Cur 3 Tot 487)
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Standard INIT
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State Change CS_INIT -> CS_ROUTING
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State INIT going to sleep
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State INIT
2017-11-01 04:33:10.075325 [DEBUG] mod_sofia.c:90 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA INIT
2017-11-01 04:33:10.075325 [DEBUG] sofia_glue.c:1264 sip:KAZOOIP Setting proxy route to sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net
2017-11-01 04:33:10.075325 [DEBUG] sofia_glue.c:1295 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net sending invite version: 1.6.19  64bit
Local SDP:
v=0
o=FreeSWITCH 1509487154 1509487155 IN IP4 KAZOOIP
s=FreeSWITCH
c=IN IP4 KAZOOIP
t=0 0
m=audio 23636 RTP/AVP 0 8 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Running State Change CS_ROUTING (Cur 3 Tot 487)
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard INIT
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_INIT -> CS_ROUTING
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State INIT going to sleep
send 1297 bytes to udp/[KAZOOIP]:5060 at 04:33:10.078991:
   ------------------------------------------------------------------------
   INVITE sip:user_vrf59sfv4q@pbxdg.domain.net SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP:11000;rport;branch=z9hG4bKg6t1eXSN6556B
   Route: <sip:KAZOOIP>
   Max-Forwards: 49
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=5ja5mB9F581mN
   To: <sip:user_vrf59sfv4q@pbxdg.domain.net>
   Call-ID: c3c6bfbe-bebd-11e7-b246-cf451ddd7335
   CSeq: 114419331 INVITE
   Contact: <sip:mod_sofia@KAZOOIP:11000>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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: 268
   X-KAZOO-AOR: sip:user_vrf59sfv4q@pbxdg.domain.net
   X-KAZOO-INVITE-FORMAT: contact
   X-FS-Support: update_display,send_info
   Remote-Party-ID: "James Hughes" <sip:888701@pbxdg.domain.net>;party=calling;screen=yes;privacy=off
   
   v=0
   o=FreeSWITCH 1509489814 1509489815 IN IP4 KAZOOIP
   s=FreeSWITCH
   c=IN IP4 KAZOOIP
   t=0 0
   m=audio 20976 RTP/AVP 0 8 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=rtpmap:13 CN/8000
   a=ptime:20
   ------------------------------------------------------------------------
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State ROUTING
2017-11-01 04:33:10.075325 [DEBUG] mod_sofia.c:143 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net SOFIA ROUTING
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_ROUTING (Cur 3 Tot 487)
2017-11-01 04:33:10.075325 [DEBUG] switch_ivr_originate.c:67 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State ROUTING going to sleep
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING
2017-11-01 04:33:10.075325 [DEBUG] mod_sofia.c:143 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA ROUTING
2017-11-01 04:33:10.075325 [DEBUG] switch_ivr_originate.c:67 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING going to sleep
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 487)
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:662 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State CONSUME_MEDIA
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:662 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State CONSUME_MEDIA going to sleep
send 1297 bytes to udp/[KAZOOIP]:5060 at 04:33:10.079503:
   ------------------------------------------------------------------------
   INVITE sip:user_f84u8dn62s@pbxdg.domain.net SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP:11000;rport;branch=z9hG4bKHFmtgraS3evSQ
   Route: <sip:KAZOOIP>
   Max-Forwards: 49
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=6U3Xp6SK2Hr7g
   To: <sip:user_f84u8dn62s@pbxdg.domain.net>
   Call-ID: c3c6dc38-bebd-11e7-b24c-cf451ddd7335
   CSeq: 114419331 INVITE
   Contact: <sip:mod_sofia@KAZOOIP:11000>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 487)
   Supported: 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: 268
   X-KAZOO-AOR: sip:user_f84u8dn62s@pbxdg.domain.net
   X-KAZOO-INVITE-FORMAT: contact
   X-FS-Support: update_display,send_info
   Remote-Party-ID: "James Hughes" <sip:888701@pbxdg.domain.net>;party=calling;screen=yes;privacy=off
   
   v=0
   o=FreeSWITCH 1509487154 1509487155 IN IP4 KAZOOIP
   s=FreeSWITCH
   c=IN IP4 KAZOOIP
   t=0 0
   m=audio 23636 RTP/AVP 0 8 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=rtpmap:13 CN/8000
   a=ptime:20
   ------------------------------------------------------------------------
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:662 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State CONSUME_MEDIA
2017-11-01 04:33:10.075325 [DEBUG] switch_core_state_machine.c:662 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State CONSUME_MEDIA going to sleep
2017-11-01 04:33:10.075325 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net entering state [calling][0]
2017-11-01 04:33:10.075325 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [calling][0]
recv 348 bytes from udp/[KAZOOIP]:5060 at 04:33:10.080589:
   ------------------------------------------------------------------------
   SIP/2.0 100 Attempting to connect your call
   Via: SIP/2.0/UDP KAZOOIP:11000;rport=11000;branch=z9hG4bKg6t1eXSN6556B;received=KAZOOIP
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=5ja5mB9F581mN
   To: <sip:user_vrf59sfv4q@pbxdg.domain.net>
   Call-ID: c3c6bfbe-bebd-11e7-b246-cf451ddd7335
   CSeq: 114419331 INVITE
   Content-Length: 0
   
   ------------------------------------------------------------------------
recv 348 bytes from udp/[KAZOOIP]:5060 at 04:33:10.080701:
   ------------------------------------------------------------------------
   SIP/2.0 100 Attempting to connect your call
   Via: SIP/2.0/UDP KAZOOIP:11000;rport=11000;branch=z9hG4bKHFmtgraS3evSQ;received=KAZOOIP
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=6U3Xp6SK2Hr7g
   To: <sip:user_f84u8dn62s@pbxdg.domain.net>
   Call-ID: c3c6dc38-bebd-11e7-b24c-cf451ddd7335
   CSeq: 114419331 INVITE
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:10.085174 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24319.32>
2017-11-01 04:33:10.085174 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(c3c6bfbe-bebd-11e7-b246-cf451ddd7335 ^^;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;ecallmgr_Global-Resource=false;ecallmgr_Channel-Authorized=true)
2017-11-01 04:33:10.085174 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24346.32>
2017-11-01 04:33:10.085174 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(c3c6dc38-bebd-11e7-b24c-cf451ddd7335 ^^;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;ecallmgr_Global-Resource=false;ecallmgr_Channel-Authorized=true)
2017-11-01 04:33:10.085174 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24350.32>
2017-11-01 04:33:10.085174 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(c3c6bfbe-bebd-11e7-b246-cf451ddd7335 ecallmgr_Call-Interaction-ID=63676729989-48a2eba5)
2017-11-01 04:33:10.285275 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24319.32>
2017-11-01 04:33:10.285275 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(c3c6dc38-bebd-11e7-b24c-cf451ddd7335 ecallmgr_Call-Interaction-ID=63676729989-48a2eba5)
2017-11-01 04:33:10.485439 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24319.32>
recv 572 bytes from udp/[KAZOOIP]:5060 at 04:33:10.583382:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Via: SIP/2.0/UDP KAZOOIP:11000;rport=11000;received=KAZOOIP;branch=z9hG4bKg6t1eXSN6556B
   Record-Route: <sip:KAZOOIP;lr;ftag=5ja5mB9F581mN>
   Call-ID: c3c6bfbe-bebd-11e7-b246-cf451ddd7335
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=5ja5mB9F581mN
   To: <sip:user_vrf59sfv4q@pbxdg.domain.net>;tag=jy-cN.MOr8AHRLXRSpstujQwjZ2gLCvZ
   CSeq: 114419331 INVITE
   Contact: <sip:user_vrf59sfv4q@49.195.123.218:32106;ob>
   Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
   Content-Length:  0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:10.585175 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net entering state [proceeding][180]
2017-11-01 04:33:10.585175 [NOTICE] sofia.c:7192 Ring-Ready sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net!
2017-11-01 04:33:10.585175 [DEBUG] switch_channel.c:3346 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Callstate Change DOWN -> RINGING
2017-11-01 04:33:10.595315 [INFO] switch_ivr_originate.c:1215 Sending early media
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[opus:116:48000:20:0:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[G7221:115:32000:20:48000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[G7221:107:16000:20:32000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[G722:9:8000:20:64000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[GSM:3:8000:20:13200:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[SPEEX:99:8000:20:24600:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-01 04:33:10.595315 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 96@8000
2017-11-01 04:33:10.605300 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
2017-11-01 04:33:10.605300 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:3061 Set Codec sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net opus/48000 20 ms 960 samples 0 bits 1 channels
2017-11-01 04:33:10.605300 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Original read codec set to opus:116
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:4767 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set 2833 dtmf send payload to 96 recv payload to 96
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net] KAZOOIP port 26362 -> 46.19.210.33 port 21162 codec: 120 ms: 20
2017-11-01 04:33:10.605300 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 960 bytes per 20ms
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:7179 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set 2833 dtmf send payload to 96
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:7186 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set 2833 dtmf receive payload to 96
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:7209 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set rtp dtmf delay to 40
2017-11-01 04:33:10.605300 [NOTICE] sofia_media.c:92 Pre-Answer sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net!
2017-11-01 04:33:10.605300 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5696
2017-11-01 04:33:10.605300 [DEBUG] switch_channel.c:3474 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change RINGING -> EARLY
2017-11-01 04:33:10.605300 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net.
2017-11-01 04:33:10.605300 [DEBUG] mod_sofia.c:2364 Ring SDP:
v=0
o=FreeSWITCH 1509484428 1509484429 IN IP4 KAZOOIP
s=FreeSWITCH
c=IN IP4 KAZOOIP
t=0 0
m=audio 26362 RTP/AVP 120 96
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; minptime=10; maxptime=40
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=sendrecv

2017-11-01 04:33:10.605300 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@48000hz 1 channel 20ms
2017-11-01 04:33:10.605300 [DEBUG] switch_core_codec.c:223 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Push codec L16:100
2017-11-01 04:33:10.605300 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(2000,4000,440,480)]
send 1322 bytes to udp/[KAZOOIP]:5060 at 04:33:10.609333:
   ------------------------------------------------------------------------
   SIP/2.0 183 Session Progress
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bKfd1a.37859ae0b746929f182e0e4ec2f7fe79.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKpOioMaK2;rport=6050
   Record-Route: <sip:KAZOOIP;lr=on;ftag=309022BA-59F94E850003A17D-C1C15700>
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>;tag=49gcKgrc8ZB2S
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   CSeq: 10 INVITE
   Contact: <sip:888701@KAZOOIP:11000;transport=udp>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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: 277
   Remote-Party-ID: "888701" <sip:888701@pbxdg.domain.net>;party=calling;privacy=off;screen=no
   
   v=0
   o=FreeSWITCH 1509484428 1509484429 IN IP4 KAZOOIP
   s=FreeSWITCH
   c=IN IP4 KAZOOIP
   t=0 0
   m=audio 26362 RTP/AVP 120 96
   a=rtpmap:120 opus/48000/2
   a=fmtp:120 useinbandfec=1; minptime=10; maxptime=40
   a=rtpmap:96 telephone-event/8000
   a=fmtp:96 0-16
   a=ptime:20
   ------------------------------------------------------------------------
2017-11-01 04:33:10.625226 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [early][183]
2017-11-01 04:33:10.745250 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
recv 497 bytes from udp/[KAZOOIP]:5060 at 04:33:11.236651:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Record-Route: <sip:KAZOOIP;lr=on;ftag=6U3Xp6SK2Hr7g>
   Via: SIP/2.0/UDP KAZOOIP:11000;received=KAZOOIP;rport=11000;branch=z9hG4bKHFmtgraS3evSQ
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=6U3Xp6SK2Hr7g
   To: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=51D5783F-59F94E8600021596-9719C700
   Call-ID: c3c6dc38-bebd-11e7-b24c-cf451ddd7335
   CSeq: 114419331 INVITE
   Server: call.center proxy
   Contact: <sip:46.19.210.33:6050;transport=udp>
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:11.235205 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [proceeding][180]
2017-11-01 04:33:11.235205 [NOTICE] sofia.c:7192 Ring-Ready sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net!
2017-11-01 04:33:11.235205 [DEBUG] switch_channel.c:3346 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change DOWN -> RINGING
recv 337 bytes from udp/[KAZOOIP]:5060 at 04:33:13.805134:
   ------------------------------------------------------------------------
   OPTIONS sip:KAZOOIP:11000 SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK75c2.28b2d0c2000000000000000000000000.0
   To: <sip:KAZOOIP:11000>
   From: <sip:sipcheck@pbx01.exch1.net>;tag=21d4b410505c1ffc4306a41061c0d07d-9c88
   CSeq: 10 OPTIONS
   Call-ID: 67f8977a2bce85b4-1807@KAZOOIP
   Max-Forwards: 70
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 701 bytes to udp/[KAZOOIP]:5060 at 04:33:13.805728:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK75c2.28b2d0c2000000000000000000000000.0
   From: <sip:sipcheck@pbx01.exch1.net>;tag=21d4b410505c1ffc4306a41061c0d07d-9c88
   To: <sip:KAZOOIP:11000>;tag=74vpr1aQZtetc
   Call-ID: 67f8977a2bce85b4-1807@KAZOOIP
   CSeq: 10 OPTIONS
   Contact: <sip:KAZOOIP:11000>
   User-Agent: 2600hz
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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-Length: 0
   
   ------------------------------------------------------------------------
recv 926 bytes from udp/[KAZOOIP]:5060 at 04:33:14.363691:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP:11000;rport=11000;received=KAZOOIP;branch=z9hG4bKg6t1eXSN6556B
   Record-Route: <sip:KAZOOIP;lr;ftag=5ja5mB9F581mN>
   Call-ID: c3c6bfbe-bebd-11e7-b246-cf451ddd7335
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=5ja5mB9F581mN
   To: <sip:user_vrf59sfv4q@pbxdg.domain.net>;tag=jy-cN.MOr8AHRLXRSpstujQwjZ2gLCvZ
   CSeq: 114419331 INVITE
   Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
   Contact: <sip:user_vrf59sfv4q@49.195.123.218:32106;ob>
   Supported: replaces, 100rel, timer, norefersub
   Content-Type: application/sdp
   Content-Length:   277
   
   v=0
   o=- 3718499590 3718499591 IN IP4 49.195.123.218
   s=pjmedia
   b=AS:117
   t=0 0
   a=X-nat:0
   m=audio 32264 RTP/AVP 0 101
   c=IN IP4 49.195.123.218
   b=TIAS:96000
   a=rtcp:4011 IN IP4 10.1.1.29
   a=sendrecv
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   ------------------------------------------------------------------------
2017-11-01 04:33:14.365175 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net entering state [completing][200]
2017-11-01 04:33:14.365175 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 3718499590 3718499591 IN IP4 49.195.123.218
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 32264 RTP/AVP 0 101
c=IN IP4 49.195.123.218
b=TIAS:96000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4011 IN IP4 10.1.1.29

send 478 bytes to udp/[KAZOOIP]:5060 at 04:33:14.365948:
   ------------------------------------------------------------------------
   ACK sip:user_vrf59sfv4q@49.195.123.218:32106;ob SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP:11000;rport;branch=z9hG4bKjrDKjKUv0QjcK
   Route: <sip:KAZOOIP;lr;ftag=5ja5mB9F581mN>
   Max-Forwards: 70
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=5ja5mB9F581mN
   To: <sip:user_vrf59sfv4q@pbxdg.domain.net>;tag=jy-cN.MOr8AHRLXRSpstujQwjZ2gLCvZ
   Call-ID: c3c6bfbe-bebd-11e7-b246-cf451ddd7335
   CSeq: 114419331 ACK
   Contact: <sip:mod_sofia@KAZOOIP:11000>
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:14.365175 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net entering state [ready][200]
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:3061 Set Codec sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-11-01 04:33:14.365175 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Original read codec set to PCMU:0
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:4767 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net] KAZOOIP port 20976 -> 49.195.123.218 port 32264 codec: 0 ms: 20
2017-11-01 04:33:14.365175 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:7098 Activating RTCP PORT 4011
2017-11-01 04:33:14.365175 [DEBUG] switch_rtp.c:4507 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 4011
2017-11-01 04:33:14.365175 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 49.195.123.218:4011 2
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:7179 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Set 2833 dtmf send payload to 101
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:7186 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Set 2833 dtmf receive payload to 101
2017-11-01 04:33:14.365175 [DEBUG] switch_core_media.c:7209 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Set rtp dtmf delay to 40
2017-11-01 04:33:14.365175 [NOTICE] sofia.c:8218 Channel [sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net] has been answered
2017-11-01 04:33:14.365175 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4273
2017-11-01 04:33:14.365175 [DEBUG] switch_channel.c:3773 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Callstate Change RINGING -> ACTIVE
2017-11-01 04:33:14.385177 [DEBUG] switch_core_codec.c:248 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Restore previous codec opus:116.
2017-11-01 04:33:14.385177 [NOTICE] switch_ivr_originate.c:3612 Hangup sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [CS_CONSUME_MEDIA] [LOSE_RACE]
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_HANGUP (Cur 3 Tot 487)
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:850 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change RINGING -> HANGUP
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State HANGUP
2017-11-01 04:33:14.385177 [DEBUG] mod_sofia.c:438 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net hanging up, cause: LOSE_RACE
2017-11-01 04:33:14.385177 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net.
2017-11-01 04:33:14.385177 [DEBUG] mod_sofia.c:850 Local SDP sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net:
v=0
o=FreeSWITCH 1509484428 1509484430 IN IP4 KAZOOIP
s=FreeSWITCH
c=IN IP4 KAZOOIP
t=0 0
m=audio 26362 RTP/AVP 120 96
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; minptime=10; maxptime=40
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=sendrecv

2017-11-01 04:33:14.385177 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net] has been answered
send 1314 bytes to udp/[KAZOOIP]:5060 at 04:33:14.388964:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bKfd1a.37859ae0b746929f182e0e4ec2f7fe79.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKpOioMaK2;rport=6050
   Record-Route: <sip:KAZOOIP;lr=on;ftag=309022BA-59F94E850003A17D-C1C15700>
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>;tag=49gcKgrc8ZB2S
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   CSeq: 10 INVITE
   Contact: <sip:888701@KAZOOIP:11000;transport=udp>
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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: 277
   Remote-Party-ID: "James Hughes" <sip:888701@pbxdg.domain.net>;party=calling;privacy=off;screen=no
   
   v=0
   o=FreeSWITCH 1509484428 1509484429 IN IP4 KAZOOIP
   s=FreeSWITCH
   c=IN IP4 KAZOOIP
   t=0 0
   m=audio 26362 RTP/AVP 120 96
   a=rtpmap:120 opus/48000/2
   a=fmtp:120 useinbandfec=1; minptime=10; maxptime=40
   a=rtpmap:96 telephone-event/8000
   a=fmtp:96 0-16
   a=ptime:20
   ------------------------------------------------------------------------
2017-11-01 04:33:14.385177 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 6172
2017-11-01 04:33:14.385177 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard HANGUP, cause: LOSE_RACE
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State HANGUP going to sleep
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:619 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_HANGUP -> CS_REPORTING
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_REPORTING (Cur 3 Tot 487)
send 427 bytes to udp/[KAZOOIP]:5060 at 04:33:14.389328:
   ------------------------------------------------------------------------
   CANCEL sip:user_f84u8dn62s@pbxdg.domain.net SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP:11000;rport;branch=z9hG4bKHFmtgraS3evSQ
   Route: <sip:KAZOOIP>
   Max-Forwards: 49
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=6U3Xp6SK2Hr7g
   To: <sip:user_f84u8dn62s@pbxdg.domain.net>
   Call-ID: c3c6dc38-bebd-11e7-b24c-cf451ddd7335
   CSeq: 114419331 CANCEL
   Reason: SIP;cause=200;text="Call completed elsewhere"
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State REPORTING
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:174 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard REPORTING, cause: LOSE_RACE
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State REPORTING going to sleep
2017-11-01 04:33:14.385177 [DEBUG] switch_channel.c:3773 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change EARLY -> ACTIVE
2017-11-01 04:33:14.385177 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [completed][200]
2017-11-01 04:33:14.385177 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net]
recv 368 bytes from udp/[KAZOOIP]:5060 at 04:33:14.390080:
   ------------------------------------------------------------------------
   SIP/2.0 200 canceling
   Via: SIP/2.0/UDP KAZOOIP:11000;rport=11000;branch=z9hG4bKHFmtgraS3evSQ;received=KAZOOIP
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=6U3Xp6SK2Hr7g
   To: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=ab22b7b63d1acec3822f69ec3f877ac8-9d6d
   Call-ID: c3c6dc38-bebd-11e7-b24c-cf451ddd7335
   CSeq: 114419331 CANCEL
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:14.385177 [DEBUG] switch_ivr_bridge.c:1614 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:610 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_REPORTING -> CS_DESTROY
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Running State Change CS_EXCHANGE_MEDIA (Cur 3 Tot 487)
2017-11-01 04:33:14.385177 [DEBUG] switch_core_session.c:1665 Session 487 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Locked, Waiting on external entities
2017-11-01 04:33:14.385177 [NOTICE] switch_core_session.c:1683 Session 487 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Ended
2017-11-01 04:33:14.385177 [NOTICE] switch_core_session.c:1687 Close Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [CS_DESTROY]
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:653 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State EXCHANGE_MEDIA
2017-11-01 04:33:14.385177 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:741 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_DESTROY (Cur 2 Tot 487)
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State DESTROY
2017-11-01 04:33:14.385177 [DEBUG] mod_sofia.c:343 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA DESTROY
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:181 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard DESTROY
2017-11-01 04:33:14.385177 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State DESTROY going to sleep
2017-11-01 04:33:14.385177 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 6673
2017-11-01 04:33:14.385177 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4339
2017-11-01 04:33:14.445248 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
2017-11-01 04:33:14.445248 [NOTICE] switch_core_io.c:1202 Activating write resampler
2017-11-01 04:33:14.485174 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: audio ssrc[148779877] base_seq[29029]
recv 591 bytes from udp/[KAZOOIP]:5060 at 04:33:14.499001:
   ------------------------------------------------------------------------
   ACK sip:888701@KAZOOIP:11000;transport=udp SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bKfd1a.ab6b44c8417cd4835d9bbbdae0d777f4.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bK~xuHba9B;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>;tag=49gcKgrc8ZB2S
   CSeq: 10 ACK
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   Max-Forwards: 50
   User-Agent: call.center proxy
   Contact: <sip:46.19.210.33:6050;transport=udp>
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   
   ------------------------------------------------------------------------
recv 460 bytes from udp/[KAZOOIP]:5060 at 04:33:14.499672:
   ------------------------------------------------------------------------
   SIP/2.0 487 Request terminated
   Record-Route: <sip:KAZOOIP;lr=on;ftag=6U3Xp6SK2Hr7g>
   Via: SIP/2.0/UDP KAZOOIP:11000;received=KAZOOIP;rport=11000;branch=z9hG4bKHFmtgraS3evSQ
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=6U3Xp6SK2Hr7g
   To: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=51D5783F-59F94E8600021596-9719C700
   Call-ID: c3c6dc38-bebd-11e7-b24c-cf451ddd7335
   CSeq: 114419331 INVITE
   Server: call.center proxy
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 405 bytes to udp/[KAZOOIP]:5060 at 04:33:14.499857:
   ------------------------------------------------------------------------
   ACK sip:user_f84u8dn62s@pbxdg.domain.net SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP:11000;rport;branch=z9hG4bKHFmtgraS3evSQ
   Route: <sip:KAZOOIP>
   Max-Forwards: 49
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=6U3Xp6SK2Hr7g
   To: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=51D5783F-59F94E8600021596-9719C700
   Call-ID: c3c6dc38-bebd-11e7-b24c-cf451ddd7335
   CSeq: 114419331 ACK
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:14.505168 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [ready][200]
2017-11-01 04:33:14.505168 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
2017-11-01 04:33:14.505168 [NOTICE] switch_core_io.c:1202 Activating write resampler
2017-11-01 04:33:14.505168 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4383
2017-11-01 04:33:14.525162 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 6704
2017-11-01 04:33:15.645261 [INFO] switch_rtp.c:6700 Auto Changing audio RTCP port from 49.195.123.218:4011 to 49.195.123.218:32265
2017-11-01 04:33:15.645261 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 49.195.123.218:32265 2
recv 1376 bytes from udp/[KAZOOIP]:5060 at 04:33:20.452376:
   ------------------------------------------------------------------------
   INVITE sip:888100@pbxdg.domain.net:5060;transport=udp SIP/2.0
   Record-Route: <sip:KAZOOIP;lr=on;ftag=7BF47C90-59F94E9000060583-C1811700>
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK3b2e.81a7516715465afdd4fcc7bf384a3e5b.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKoAAQxaLu;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>
   CSeq: 10 INVITE
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   Max-Forwards: 50
   User-Agent: call.center proxy
   Content-Type: application/sdp
   Contact: <sip:46.19.210.33:6050;transport=udp>
   Content-Length: 261
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   X-ecallmgr_Account-ID: 75c5b9a0047e65399de45f41258e38e4
   X-ecallmgr_Authorizing-Type: device
   X-ecallmgr_Authorizing-ID: c04a2812eff90b41dd1282c4ffc03998
   X-ecallmgr_Username: user_f84u8dn62s
   X-ecallmgr_Realm: pbxdg.domain.net
   X-ecallmgr_Account-Realm: pbxdg.domain.net
   X-ecallmgr_Account-Name: Dove Gospel - Global
   X-ecallmgr_Presence-ID: 888701@pbxdg.domain.net
   X-ecallmgr_Owner-ID: 9333eab27c60732f233e2b803e7c073b
   
   v=0
   o=sems 110182451 1227842507 IN IP4 46.19.210.33
   s=sems
   c=IN IP4 46.19.210.33
   t=0 0
   m=audio 21168 RTP/AVP 120 8 0 96
   a=rtpmap:120 opus/48000/2
   a=rtpmap:8 PCMA/8000
   a=rtpmap:0 PCMU/8000
   a=rtpmap:96 telephone-event/8000
   a=sendrecv
   a=direction:both
   ------------------------------------------------------------------------
send 498 bytes to udp/[KAZOOIP]:5060 at 04:33:20.452839:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK3b2e.81a7516715465afdd4fcc7bf384a3e5b.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKoAAQxaLu;rport=6050
   Record-Route: <sip:KAZOOIP;lr=on;ftag=7BF47C90-59F94E9000060583-C1811700>
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   CSeq: 10 INVITE
   User-Agent: 2600hz
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:20.445222 [NOTICE] switch_channel.c:1104 New Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [08594CE6-59F94E9000060587-C1811700]
2017-11-01 04:33:20.445222 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_NEW (Cur 3 Tot 488)
2017-11-01 04:33:20.445222 [DEBUG] sofia.c:9873 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net receiving invite from KAZOOIP:5060 version: 1.6.19  64bit
2017-11-01 04:33:20.445222 [DEBUG] sofia.c:9999 1 acls to check for proxy
2017-11-01 04:33:20.445222 [DEBUG] sofia.c:10004 checking KAZOOIP against acl authoritative
2017-11-01 04:33:20.445222 [INFO] sofia.c:10006 KAZOOIP is a proxy according to the authoritative acl
2017-11-01 04:33:20.445222 [DEBUG] sofia.c:10016 network ip is a proxy
2017-11-01 04:33:20.445222 [DEBUG] sofia.c:10020 found auth ip [X-AUTH-IP] header of [46.19.210.33]
2017-11-01 04:33:20.445222 [DEBUG] sofia.c:10044 IP KAZOOIP Rejected by acl "trusted". Falling back to Digest auth.
2017-11-01 04:33:20.445222 [DEBUG] kazoo_fetch_agent.c:216 Sending directory XML request (c9f61fc4-bebd-11e7-b251-cf451ddd7335) to ecallmgr@pbx01.exch1.net <1.1432.0>
2017-11-01 04:33:20.505244 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.1432.0>
2017-11-01 04:33:20.505244 [DEBUG] kazoo_fetch_agent.c:277 Received directory XML (c9f61fc4-bebd-11e7-b251-cf451ddd7335) after 60ms: <document type="freeswitch/xml"><section name="directory"><domain name="pbxdg.domain.net"><user id="user_f84u8dn62s"><variables><variable name="ecallmgr_Account-ID" value="75c5b9a0047e65399de45f41258e38e4"/><variable name="ecallmgr_Authorizing-Type" value="device"/><variable name="ecallmgr_Authorizing-ID" value="c04a2812eff90b41dd1282c4ffc03998"/><variable name="ecallmgr_Username" value="user_f84u8dn62s"/><variable name="ecallmgr_Realm" value="pbxdg.domain.net"/><variable name="ecallmgr_Account-Realm" value="pbxdg.domain.net"/><variable name="ecallmgr_Account-Name" value="Dove Gospel - Global"/><variable name="presence_id" value="888701@pbxdg.domain.net"/><variable name="ecallmgr_Owner-ID" value="9333eab27c60732f233e2b803e7c073b"/></variables><params><param name="password" value="fd52e9a77ee923563ef69629"/></params></user></domain></section></document>
2017-11-01 04:33:20.505244 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [received][100]
2017-11-01 04:33:20.505244 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=sems 110182451 1227842507 IN IP4 46.19.210.33
s=sems
c=IN IP4 46.19.210.33
t=0 0
m=audio 21168 RTP/AVP 120 8 0 96
a=rtpmap:120 opus/48000/2
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 telephone-event/8000
a=direction:both

2017-11-01 04:33:20.505244 [DEBUG] sofia.c:7486 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_NEW -> CS_INIT
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:603 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State NEW
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_INIT (Cur 3 Tot 488)
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State INIT
2017-11-01 04:33:20.505244 [DEBUG] mod_sofia.c:90 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA INIT
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard INIT
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_INIT -> CS_ROUTING
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State INIT going to sleep
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_ROUTING (Cur 3 Tot 488)
2017-11-01 04:33:20.505244 [DEBUG] switch_channel.c:2249 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change DOWN -> RINGING
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING
2017-11-01 04:33:20.505244 [DEBUG] mod_sofia.c:143 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA ROUTING
2017-11-01 04:33:20.505244 [DEBUG] switch_core_state_machine.c:236 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard ROUTING
2017-11-01 04:33:20.505244 [INFO] mod_dialplan_xml.c:637 Processing user_f84u8dn62s <user_f84u8dn62s>->888100 in context context_2
2017-11-01 04:33:20.505244 [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request (c9feeaf0-bebd-11e7-b253-cf451ddd7335) to ecallmgr@pbx01.exch1.net <1.1383.0>
2017-11-01 04:33:20.705253 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.1383.0>
2017-11-01 04:33:20.705253 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(08594CE6-59F94E9000060587-C1811700 ecallmgr_Call-Interaction-ID=63676730000-a0d45d02)
2017-11-01 04:33:20.725174 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24406.32>
2017-11-01 04:33:20.725174 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24407.32>
2017-11-01 04:33:20.725174 [DEBUG] kazoo_fetch_agent.c:277 Received dialplan XML (c9feeaf0-bebd-11e7-b253-cf451ddd7335) after 219ms: <document type="freeswitch/xml"><section name="dialplan" description="Route Park Response"><context name="context_2"><extension name="park"><condition><action application="log" data="NOTICE log|${uuid}|ecallmgr@pbx01.exch1.net won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=ecallmgr@pbx01.exch1.net"/><condition field="variable_ecallmgr_Bridge-ID" expression="^$"><action application="export" data="ecallmgr_Bridge-ID=${UUID}" inline="true"/></condition><action application="set" data="ringback=%(2000,4000,440,480)"/><action application="set" data="transfer_ringback=%(2000,4000,440,480)"/><action application="kz_multiset" data="^^|ecallmgr_Username=user_f84u8dn62s|ecallmgr_Realm=pbxdg.domain.net|presence_id=888701@pbxdg.domain.net|ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b|ecallmgr_Fetch-ID=c9feeaf0-bebd-11e7-b253-cf451ddd7335|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63676730000-a0d45d02|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998|ecallmgr_Account-Realm=pbxdg.domain.net|ecallmgr_Account-Name=Dove Gospel - Global|ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4|ecallmgr_CallFlow-ID=c6222420dbb9f58b6098337266eff6ec|ecallmgr_Channel-Authorized=true"/><action application="multiunset" data="^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID"/><action application="park"/></condition></extension></context></section></document>
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net parsing [context_2->park] continue=false
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Absolute Condition [park]
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action log(NOTICE log|${uuid}|ecallmgr@pbx01.exch1.net won call control) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action export(ecallmgr_Ecallmgr-Node=ecallmgr@pbx01.exch1.net) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action set(ringback=%(2000,4000,440,480)) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action set(transfer_ringback=%(2000,4000,440,480)) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action kz_multiset(^^|ecallmgr_Username=user_f84u8dn62s|ecallmgr_Realm=pbxdg.domain.net|presence_id=888701@pbxdg.domain.net|ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b|ecallmgr_Fetch-ID=c9feeaf0-bebd-11e7-b253-cf451ddd7335|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63676730000-a0d45d02|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998|ecallmgr_Account-Realm=pbxdg.domain.net|ecallmgr_Account-Name=Dove Gospel - Global|ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4|ecallmgr_CallFlow-ID=c6222420dbb9f58b6098337266eff6ec|ecallmgr_Channel-Authorized=true) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID) 
Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action park() 
|--- Dialplan: Processing recursive conditions level:1 [park_recur_1] require-nested=TRUE
|--- Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Regex (PASS) [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/ break=on-false
|--- Dialplan: sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Action export(ecallmgr_Bridge-ID=${UUID}) INLINE
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net export(ecallmgr_Bridge-ID=08594CE6-59F94E9000060587-C1811700)
2017-11-01 04:33:20.725174 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Bridge-ID]=[08594CE6-59F94E9000060587-C1811700]
2017-11-01 04:33:20.725174 [DEBUG] switch_core_state_machine.c:286 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_ROUTING -> CS_EXECUTE
2017-11-01 04:33:20.725174 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State ROUTING going to sleep
2017-11-01 04:33:20.725174 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_EXECUTE (Cur 3 Tot 488)
2017-11-01 04:33:20.725174 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State EXECUTE
2017-11-01 04:33:20.725174 [DEBUG] mod_sofia.c:198 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA EXECUTE
2017-11-01 04:33:20.725174 [DEBUG] switch_core_state_machine.c:328 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard EXECUTE
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net log(NOTICE log|08594CE6-59F94E9000060587-C1811700|ecallmgr@pbx01.exch1.net won call control)
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4249
2017-11-01 04:33:20.725174 [NOTICE] mod_dptools.c:1742 log|08594CE6-59F94E9000060587-C1811700|ecallmgr@pbx01.exch1.net won call control
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net export(ecallmgr_Ecallmgr-Node=ecallmgr@pbx01.exch1.net)
2017-11-01 04:33:20.725174 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Ecallmgr-Node]=[ecallmgr@pbx01.exch1.net]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net set(ringback=%(2000,4000,440,480))
2017-11-01 04:33:20.725174 [DEBUG] mod_dptools.c:1548 SET sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net set(transfer_ringback=%(2000,4000,440,480))
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4311
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4331
2017-11-01 04:33:20.725174 [DEBUG] mod_dptools.c:1548 SET sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [transfer_ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net kz_multiset(^^|ecallmgr_Username=user_f84u8dn62s|ecallmgr_Realm=pbxdg.domain.net|presence_id=888701@pbxdg.domain.net|ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b|ecallmgr_Fetch-ID=c9feeaf0-bebd-11e7-b253-cf451ddd7335|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63676730000-a0d45d02|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998|ecallmgr_Account-Realm=pbxdg.domain.net|ecallmgr_Account-Name=Dove Gospel - Global|ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4|ecallmgr_CallFlow-ID=c6222420dbb9f58b6098337266eff6ec|ecallmgr_Channel-Authorized=true)
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Username]=[user_f84u8dn62s]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Realm]=[pbxdg.domain.net]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [presence_id]=[888701@pbxdg.domain.net]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Owner-ID]=[9333eab27c60732f233e2b803e7c073b]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Fetch-ID]=[c9feeaf0-bebd-11e7-b253-cf451ddd7335]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Screen-Bit]=[true]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Number]=[false]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Name]=[false]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Call-Interaction-ID]=[63676730000-a0d45d02]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-Type]=[device]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-ID]=[c04a2812eff90b41dd1282c4ffc03998]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Realm]=[pbxdg.domain.net]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Name]=[Dove Gospel - Global]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-ID]=[75c5b9a0047e65399de45f41258e38e4]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_CallFlow-ID]=[c6222420dbb9f58b6098337266eff6ec]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Channel-Authorized]=[true]
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4205
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net multiunset(^^;sip_h_X-AUTH-IP;sip_h_X-AUTH-PORT;sip_h_X-ecallmgr_Account-ID;sip_h_X-ecallmgr_Authorizing-Type;sip_h_X-ecallmgr_Authorizing-ID;sip_h_X-ecallmgr_Username;sip_h_X-ecallmgr_Realm;sip_h_X-ecallmgr_Account-Realm;sip_h_X-ecallmgr_Account-Name;sip_h_X-ecallmgr_Presence-ID;sip_h_X-ecallmgr_Owner-ID)
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4307
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net park()
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5111
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5958
2017-11-01 04:33:20.725174 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4460
2017-11-01 04:33:20.765215 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(08594CE6-59F94E9000060587-C1811700 ^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c9feeaf0-bebd-11e7-b253-cf451ddd7335;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_Call-Interaction-ID=63676730000-a0d45d02;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;ecallmgr_CallFlow-ID=c6222420dbb9f58b6098337266eff6ec;ecallmgr_Channel-Authorized=true;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow)
2017-11-01 04:33:20.785222 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24407.32>
2017-11-01 04:33:20.785222 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing kz_multiset ^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c9feeaf0-bebd-11e7-b253-cf451ddd7335;ecallmgr_Channel-Authorized=true;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_CallFlow-ID=c6222420dbb9f58b6098337266eff6ec;ecallmgr_Call-Interaction-ID=63676730000-a0d45d02;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;effective_caller_id_number=888701;effective_caller_id_name=James Hughes 
2017-11-01 04:33:20.785222 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute kz_multiset(^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c9feeaf0-bebd-11e7-b253-cf451ddd7335;ecallmgr_Channel-Authorized=true;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_CallFlow-ID=c6222420dbb9f58b6098337266eff6ec;ecallmgr_Call-Interaction-ID=63676730000-a0d45d02;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;effective_caller_id_number=888701;effective_caller_id_name=James Hughes)
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net kz_multiset(^^;ecallmgr_Username=user_f84u8dn62s;ecallmgr_Realm=pbxdg.domain.net;presence_id=888701@pbxdg.domain.net;ecallmgr_Owner-ID=9333eab27c60732f233e2b803e7c073b;ecallmgr_Fetch-ID=c9feeaf0-bebd-11e7-b253-cf451ddd7335;ecallmgr_Channel-Authorized=true;ecallmgr_Caller-Screen-Bit=true;ecallmgr_Caller-Privacy-Hide-Number=false;ecallmgr_Caller-Privacy-Hide-Name=false;ecallmgr_CallFlow-ID=c6222420dbb9f58b6098337266eff6ec;ecallmgr_Call-Interaction-ID=63676730000-a0d45d02;ecallmgr_Authorizing-Type=device;ecallmgr_Authorizing-ID=c04a2812eff90b41dd1282c4ffc03998;ecallmgr_Application-Node=kazoo_apps@pbx01.exch1.net;ecallmgr_Application-Name=callflow;ecallmgr_Account-Realm=pbxdg.domain.net;ecallmgr_Account-Name=Dove Gospel - Global;ecallmgr_Account-ID=75c5b9a0047e65399de45f41258e38e4;effective_caller_id_number=888701;effective_caller_id_name=James Hughes)
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Username]=[user_f84u8dn62s]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Realm]=[pbxdg.domain.net]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [presence_id]=[888701@pbxdg.domain.net]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Owner-ID]=[9333eab27c60732f233e2b803e7c073b]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Fetch-ID]=[c9feeaf0-bebd-11e7-b253-cf451ddd7335]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Channel-Authorized]=[true]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Screen-Bit]=[true]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Number]=[false]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Caller-Privacy-Hide-Name]=[false]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_CallFlow-ID]=[c6222420dbb9f58b6098337266eff6ec]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Call-Interaction-ID]=[63676730000-a0d45d02]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-Type]=[device]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Authorizing-ID]=[c04a2812eff90b41dd1282c4ffc03998]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Application-Node]=[kazoo_apps@pbx01.exch1.net]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Application-Name]=[callflow]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Realm]=[pbxdg.domain.net]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-Name]=[Dove Gospel - Global]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [ecallmgr_Account-ID]=[75c5b9a0047e65399de45f41258e38e4]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [effective_caller_id_number]=[888701]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [effective_caller_id_name]=[James Hughes]
2017-11-01 04:33:20.785222 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4849
2017-11-01 04:33:20.785222 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 5784
2017-11-01 04:33:20.985249 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
2017-11-01 04:33:20.985249 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing answer  
2017-11-01 04:33:20.985249 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute answer()
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net answer()
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[opus:116:48000:20:0:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[G7221:115:32000:20:48000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[G7221:107:16000:20:32000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[G722:9:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[GSM:3:8000:20:13200:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:2]/[SPEEX:99:8000:20:24600:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 96@8000
2017-11-01 04:33:20.995165 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
2017-11-01 04:33:20.995165 [DEBUG] mod_opus.c:603 Opus encoder: set bitrate to local settings [72000bps]
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:3061 Set Codec sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net opus/48000 20 ms 960 samples 0 bits 1 channels
2017-11-01 04:33:20.995165 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Original read codec set to opus:116
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:4767 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set 2833 dtmf send payload to 96 recv payload to 96
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net] KAZOOIP port 27608 -> 46.19.210.33 port 21168 codec: 120 ms: 20
2017-11-01 04:33:20.995165 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 960 bytes per 20ms
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:7179 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set 2833 dtmf send payload to 96
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:7186 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set 2833 dtmf receive payload to 96
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:7209 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Set rtp dtmf delay to 40
2017-11-01 04:33:20.995165 [NOTICE] sofia_media.c:92 Pre-Answer sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net!
2017-11-01 04:33:20.995165 [DEBUG] switch_channel.c:3474 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change RINGING -> EARLY
2017-11-01 04:33:20.995165 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net.
2017-11-01 04:33:20.995165 [DEBUG] mod_sofia.c:850 Local SDP sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net:
v=0
o=FreeSWITCH 1509483192 1509483193 IN IP4 KAZOOIP
s=FreeSWITCH
c=IN IP4 KAZOOIP
t=0 0
m=audio 27608 RTP/AVP 120 96
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; minptime=10; maxptime=40
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=sendrecv

2017-11-01 04:33:20.995165 [NOTICE] mod_dptools.c:1312 Channel [sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net] has been answered
send 1333 bytes to udp/[KAZOOIP]:5060 at 04:33:20.998986:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK3b2e.81a7516715465afdd4fcc7bf384a3e5b.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKoAAQxaLu;rport=6050
2017-11-01 04:33:20.995165 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4292
   Record-Route: <sip:KAZOOIP;lr=on;ftag=7BF47C90-59F94E9000060583-C1811700>
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>;tag=8DpFtvUtv34cr
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   CSeq: 10 INVITE
   Contact: <sip:888100@KAZOOIP:11000;transport=udp>
   User-Agent: 2600hz
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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: 277
   Remote-Party-ID: "888100" <sip:888100@pbxdg.domain.net>;party=calling;privacy=off;screen=no
   
   v=0
   o=FreeSWITCH 1509483192 1509483193 IN IP4 KAZOOIP
   s=FreeSWITCH
   c=IN IP4 KAZOOIP
   t=0 0
   m=audio 27608 RTP/AVP 120 96
   a=rtpmap:120 opus/48000/2
   a=fmtp:120 useinbandfec=1; minptime=10; maxptime=40
   a=rtpmap:96 telephone-event/8000
   a=fmtp:96 0-16
   a=ptime:20
   ------------------------------------------------------------------------
2017-11-01 04:33:20.995165 [DEBUG] switch_channel.c:3773 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change EARLY -> ACTIVE
2017-11-01 04:33:20.995165 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [completed][200]
2017-11-01 04:33:20.995165 [DEBUG] switch_ivr.c:980 Codec Activated L16@48000hz 1 channels 20ms
2017-11-01 04:33:20.995165 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4354
recv 591 bytes from udp/[KAZOOIP]:5060 at 04:33:21.109686:
   ------------------------------------------------------------------------
   ACK sip:888100@KAZOOIP:11000;transport=udp SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK3b2e.a5aa2236aaf932d11d449b468d06bf55.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKxJuAKapu;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>;tag=8DpFtvUtv34cr
   CSeq: 10 ACK
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   Max-Forwards: 50
   User-Agent: call.center proxy
   Contact: <sip:46.19.210.33:6050;transport=udp>
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   
   ------------------------------------------------------------------------
2017-11-01 04:33:21.115176 [DEBUG] sofia.c:7084 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net entering state [ready][200]
2017-11-01 04:33:21.135209 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
2017-11-01 04:33:21.185193 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
2017-11-01 04:33:21.185193 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing kz_multiset playback_terminators=#*0123456789 
2017-11-01 04:33:21.195243 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute kz_multiset(playback_terminators=#*0123456789)
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net kz_multiset(playback_terminators=#*0123456789)
2017-11-01 04:33:21.195243 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SET [playback_terminators]=[#*0123456789]
2017-11-01 04:33:21.195243 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4324
2017-11-01 04:33:21.195243 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4547
2017-11-01 04:33:21.385285 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
2017-11-01 04:33:21.385285 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing playback ${http_get http://127.0.0.1:15984/account%2F75%2Fc5%2Fb9a0047e65399de45f41258e38e4/ef89902e88c1ae916b0839a0779854df/uploaded_file_63676119931.mp3?rev=2-b9a54446bf51f47f1ee80b327ed1f2f0} 
2017-11-01 04:33:21.395211 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute playback(${http_get http://127.0.0.1:15984/account%2F75%2Fc5%2Fb9a0047e65399de45f41258e38e4/ef89902e88c1ae916b0839a0779854df/uploaded_file_63676119931.mp3?rev=2-b9a54446bf51f47f1ee80b327ed1f2f0})
2017-11-01 04:33:21.395211 [DEBUG] mod_http_cache.c:659 Locked cache
2017-11-01 04:33:21.395211 [DEBUG] mod_http_cache.c:796 Cache HIT: size = 90 (34 MB), hit ratio = 553/643
2017-11-01 04:33:21.395211 [DEBUG] mod_http_cache.c:670 Unlocked cache
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net playback(/usr/share/kazoo-freeswitch/sounds/http_cache/6c/fa4584-bebd-11e7-b22a-cf451ddd7335.mp3)
2017-11-01 04:33:21.395211 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms
2017-11-01 04:33:21.585172 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
2017-11-01 04:33:23.595173 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/share/kazoo-freeswitch/sounds/http_cache/6c/fa4584-bebd-11e7-b22a-cf451ddd7335.mp3
2017-11-01 04:33:23.595173 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4622
2017-11-01 04:33:23.595173 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing event Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=6526d6f4bafb796cca90ba812c157873 
2017-11-01 04:33:23.615220 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute event(Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=6526d6f4bafb796cca90ba812c157873)
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net event(Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=6526d6f4bafb796cca90ba812c157873)
2017-11-01 04:33:23.615220 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4694
2017-11-01 04:33:23.615220 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4790
2017-11-01 04:33:23.795170 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
recv 337 bytes from udp/[KAZOOIP]:5060 at 04:33:23.805025:
   ------------------------------------------------------------------------
   OPTIONS sip:KAZOOIP:11000 SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK85c2.284f2bb7000000000000000000000000.0
   To: <sip:KAZOOIP:11000>
   From: <sip:sipcheck@pbx01.exch1.net>;tag=21d4b410505c1ffc4306a41061c0d07d-08b1
   CSeq: 10 OPTIONS
   Call-ID: 67f8977a2bce85b5-1807@KAZOOIP
   Max-Forwards: 70
   Content-Length: 0
   
   ------------------------------------------------------------------------
send 701 bytes to udp/[KAZOOIP]:5060 at 04:33:23.805495:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK85c2.284f2bb7000000000000000000000000.0
   From: <sip:sipcheck@pbx01.exch1.net>;tag=21d4b410505c1ffc4306a41061c0d07d-08b1
   To: <sip:KAZOOIP:11000>;tag=9pF8UQcyScUZK
   Call-ID: 67f8977a2bce85b5-1807@KAZOOIP
   CSeq: 10 OPTIONS
   Contact: <sip:KAZOOIP:11000>
   User-Agent: 2600hz
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: 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-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:24.625185 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing playback silence_stream://50 
2017-11-01 04:33:24.635171 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute playback(silence_stream://50)
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net playback(silence_stream://50)
2017-11-01 04:33:24.635171 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms
2017-11-01 04:33:24.695164 [DEBUG] switch_ivr_play_say.c:1942 done playing file silence_stream://50
2017-11-01 04:33:24.695164 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4439
2017-11-01 04:33:24.825167 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
2017-11-01 04:33:24.825167 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing event Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=1c5547a5825c7cab7ca2fc6a96ffee01 
2017-11-01 04:33:24.835165 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute event(Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=1c5547a5825c7cab7ca2fc6a96ffee01)
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net event(Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=1c5547a5825c7cab7ca2fc6a96ffee01)
2017-11-01 04:33:24.835165 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4694
2017-11-01 04:33:24.835165 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4790
2017-11-01 04:33:25.025172 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
2017-11-01 04:33:25.025172 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing answer  
2017-11-01 04:33:25.035172 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute answer()
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net answer()
2017-11-01 04:33:25.035172 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4331
2017-11-01 04:33:25.225171 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
2017-11-01 04:33:25.225171 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing playback ${http_get http://127.0.0.1:15984/account%2F75%2Fc5%2Fb9a0047e65399de45f41258e38e4/8dcb826a9d2465a0842b13c6bb2c30a2/uploaded_file_63676719064.mp3?rev=20-48b8bbc7cc2ea2c52ed06b7de54aef3c} 
2017-11-01 04:33:25.235220 [DEBUG] switch_ivr.c:623 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Command Execute playback(${http_get http://127.0.0.1:15984/account%2F75%2Fc5%2Fb9a0047e65399de45f41258e38e4/8dcb826a9d2465a0842b13c6bb2c30a2/uploaded_file_63676719064.mp3?rev=20-48b8bbc7cc2ea2c52ed06b7de54aef3c})
2017-11-01 04:33:25.235220 [DEBUG] mod_http_cache.c:659 Locked cache
2017-11-01 04:33:25.235220 [DEBUG] mod_http_cache.c:796 Cache HIT: size = 90 (34 MB), hit ratio = 554/644
2017-11-01 04:33:25.235220 [DEBUG] mod_http_cache.c:670 Unlocked cache
EXECUTE sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net playback(/usr/share/kazoo-freeswitch/sounds/http_cache/88/5b2e10-bea4-11e7-b037-cf451ddd7335.mp3)
2017-11-01 04:33:25.235220 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur.
2017-11-01 04:33:25.235220 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms
2017-11-01 04:33:25.425177 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
recv 543 bytes from udp/[KAZOOIP]:5060 at 04:33:25.679179:
   ------------------------------------------------------------------------
   BYE sip:888100@KAZOOIP:11000;transport=udp SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK1b2e.ce585754859e443b4764743c20a7b39d.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bK6lM6Datc;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>;tag=8DpFtvUtv34cr
   CSeq: 12 BYE
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   Max-Forwards: 50
   User-Agent: call.center proxy
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   
   ------------------------------------------------------------------------
recv 1287 bytes from udp/[KAZOOIP]:5060 at 04:33:25.682876:
   ------------------------------------------------------------------------
   REFER sip:888100@KAZOOIP:11000;transport=udp SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK4b2e.70b16b32b7c17b8954d52f73378b9395.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKSfzxBaEw;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>;tag=8DpFtvUtv34cr
   CSeq: 11 REFER
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   Max-Forwards: 50
   Refer-To: <sip:888701@pbxdg.domain.net;transport=tcp?Replaces=from-tag%3D2MmjJy6lx0AU9GCxUleos5IZYh1wnS1b%3Bh8f945jJkMIAobkKwGnAEa0QFY.J6bTm%3Bto-tag%3D594447DA-59F94E8500039E2C-9709B700&Require=replaces>
   Referred-By: <sip:user_f84u8dn62s@pbxdg.domain.net>;transport=tcp
   User-Agent: call.center proxy
   Contact: <sip:46.19.210.33:6050;transport=udp>
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   X-ecallmgr_Account-ID: 75c5b9a0047e65399de45f41258e38e4
   X-ecallmgr_Authorizing-Type: device
   X-ecallmgr_Authorizing-ID: c04a2812eff90b41dd1282c4ffc03998
   X-ecallmgr_Username: user_f84u8dn62s
   X-ecallmgr_Realm: pbxdg.domain.net
   X-ecallmgr_Account-Realm: pbxdg.domain.net
   X-ecallmgr_Account-Name: Dove Gospel - Global
   X-ecallmgr_Presence-ID: 888701@pbxdg.domain.net
   X-ecallmgr_Owner-ID: 9333eab27c60732f233e2b803e7c073b
   
   ------------------------------------------------------------------------
send 430 bytes to udp/[KAZOOIP]:5060 at 04:33:25.683064:
   ------------------------------------------------------------------------
   SIP/2.0 500 Internal Server Error
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK4b2e.70b16b32b7c17b8954d52f73378b9395.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKSfzxBaEw;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>;tag=8DpFtvUtv34cr
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   CSeq: 11 REFER
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:25.695176 [NOTICE] sofia.c:1012 Hangup sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [CS_EXECUTE] [NORMAL_CLEARING]
2017-11-01 04:33:25.695176 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/share/kazoo-freeswitch/sounds/http_cache/88/5b2e10-bea4-11e7-b037-cf451ddd7335.mp3
send 566 bytes to udp/[KAZOOIP]:5060 at 04:33:25.697396:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK1b2e.ce585754859e443b4764743c20a7b39d.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bK6lM6Datc;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=7BF47C90-59F94E9000060583-C1811700
   To: <sip:888100@pbxdg.domain.net>;tag=8DpFtvUtv34cr
   Call-ID: 08594CE6-59F94E9000060587-C1811700
   CSeq: 12 BYE
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: path, replaces
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:25.695176 [DEBUG] switch_core_session.c:2815 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-11-01 04:33:25.695176 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4714
2017-11-01 04:33:25.695176 [DEBUG] switch_core_session.c:2815 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State EXECUTE going to sleep
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_HANGUP (Cur 3 Tot 488)
2017-11-01 04:33:25.695176 [DEBUG] switch_ivr.c:666 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net skip receive message [AUDIO_SYNC] (channel is hungup already)
2017-11-01 04:33:25.695176 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4568
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:850 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change ACTIVE -> HANGUP
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State HANGUP
2017-11-01 04:33:25.695176 [DEBUG] mod_sofia.c:438 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net hanging up, cause: NORMAL_CLEARING
2017-11-01 04:33:25.695176 [NOTICE] kazoo_node.c:430 log|08594CE6-59F94E9000060587-C1811700|executing event Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=c57918ba818a6982a08370893db4c5c3 
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard HANGUP, cause: NORMAL_CLEARING
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State HANGUP going to sleep
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:619 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_HANGUP -> CS_REPORTING
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_REPORTING (Cur 3 Tot 488)
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State REPORTING
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:174 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard REPORTING, cause: NORMAL_CLEARING
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State REPORTING going to sleep
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:610 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_REPORTING -> CS_DESTROY
2017-11-01 04:33:25.695176 [DEBUG] switch_core_session.c:1665 Session 488 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Locked, Waiting on external entities
2017-11-01 04:33:25.695176 [NOTICE] switch_core_session.c:1683 Session 488 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Ended
2017-11-01 04:33:25.695176 [NOTICE] switch_core_session.c:1687 Close Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [CS_DESTROY]
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:741 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_DESTROY (Cur 2 Tot 488)
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State DESTROY
2017-11-01 04:33:25.695176 [DEBUG] mod_sofia.c:343 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA DESTROY
2017-11-01 04:33:25.695176 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-11-01 04:33:25.695176 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2017-11-01 04:33:25.695176 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-11-01 04:33:25.695176 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[234] Bytes encoded[21498] Encoded length ms[4680] Average encoded bitrate bps[42996]
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:181 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard DESTROY
2017-11-01 04:33:25.695176 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State DESTROY going to sleep
2017-11-01 04:33:25.695176 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4844
2017-11-01 04:33:25.895169 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.24424.32>
recv 543 bytes from udp/[KAZOOIP]:5060 at 04:33:26.595347:
   ------------------------------------------------------------------------
   BYE sip:888701@KAZOOIP:11000;transport=udp SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK0e1a.dac0aaebe694d5c3f2667ffa2ee6d9e4.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bK2~gpKaIk;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>;tag=49gcKgrc8ZB2S
   CSeq: 11 BYE
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   Max-Forwards: 50
   User-Agent: call.center proxy
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   
   ------------------------------------------------------------------------
2017-11-01 04:33:26.605213 [NOTICE] sofia.c:1012 Hangup sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [CS_EXECUTE] [NORMAL_CLEARING]
send 566 bytes to udp/[KAZOOIP]:5060 at 04:33:26.607594:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP;branch=z9hG4bK0e1a.dac0aaebe694d5c3f2667ffa2ee6d9e4.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bK2~gpKaIk;rport=6050
   From: <sip:user_f84u8dn62s@pbxdg.domain.net>;tag=309022BA-59F94E850003A17D-C1C15700
   To: <sip:888701@pbxdg.domain.net>;tag=49gcKgrc8ZB2S
   Call-ID: 371868A9-59F94E850003A182-C1C15700
   CSeq: 11 BYE
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: path, replaces
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-11-01 04:33:26.605213 [DEBUG] switch_ivr_bridge.c:706 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net ending bridge by request from write function
2017-11-01 04:33:26.605213 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net]
2017-11-01 04:33:26.605213 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net]
2017-11-01 04:33:26.605213 [NOTICE] switch_ivr_bridge.c:904 Hangup sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:653 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State EXCHANGE_MEDIA going to sleep
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Running State Change CS_HANGUP (Cur 2 Tot 488)
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:850 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Callstate Change ACTIVE -> HANGUP
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State HANGUP
2017-11-01 04:33:26.605213 [DEBUG] mod_sofia.c:432 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Overriding SIP cause 480 with 200 from the other leg
2017-11-01 04:33:26.605213 [DEBUG] mod_sofia.c:438 Channel sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net hanging up, cause: NORMAL_CLEARING
2017-11-01 04:33:26.605213 [DEBUG] switch_ivr_bridge.c:1712 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net skip receive message [UNBRIDGE] (channel is hungup already)
2017-11-01 04:33:26.605213 [DEBUG] switch_ivr_bridge.c:1715 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net skip receive message [UNBRIDGE] (channel is hungup already)
2017-11-01 04:33:26.605213 [DEBUG] switch_core_session.c:2815 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State EXECUTE going to sleep
2017-11-01 04:33:26.605213 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_HANGUP (Cur 2 Tot 488)
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Standard HANGUP, cause: NORMAL_CLEARING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State HANGUP going to sleep
2017-11-01 04:33:26.605213 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 6931
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:619 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State Change CS_HANGUP -> CS_REPORTING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:850 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Callstate Change ACTIVE -> HANGUP
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Running State Change CS_REPORTING (Cur 2 Tot 488)
2017-11-01 04:33:26.605213 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 8523
send 681 bytes to udp/[KAZOOIP]:5060 at 04:33:26.610424:
   ------------------------------------------------------------------------
   BYE sip:user_vrf59sfv4q@49.195.123.218:32106;ob SIP/2.0
   Via: SIP/2.0/UDP KAZOOIP:11000;rport;branch=z9hG4bKK16Bmec0X08ye
   Route: <sip:KAZOOIP;lr;ftag=5ja5mB9F581mN>
   Max-Forwards: 70
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=5ja5mB9F581mN
   To: <sip:user_vrf59sfv4q@pbxdg.domain.net>;tag=jy-cN.MOr8AHRLXRSpstujQwjZ2gLCvZ
   Call-ID: c3c6bfbe-bebd-11e7-b246-cf451ddd7335
   CSeq: 114419332 BYE
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: path, replaces
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State HANGUP
   Reason: Q.850;cause=16;text="NORMAL_CLEARING"
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State REPORTING
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:174 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Standard REPORTING, cause: NORMAL_CLEARING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State REPORTING going to sleep
   
   ------------------------------------------------------------------------
2017-11-01 04:33:26.605213 [DEBUG] mod_sofia.c:438 Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net hanging up, cause: NORMAL_CLEARING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:610 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State Change CS_REPORTING -> CS_DESTROY
2017-11-01 04:33:26.605213 [DEBUG] switch_core_session.c:1665 Session 486 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Locked, Waiting on external entities
2017-11-01 04:33:26.605213 [NOTICE] switch_core_session.c:1683 Session 486 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Ended
2017-11-01 04:33:26.605213 [NOTICE] switch_core_session.c:1687 Close Channel sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net [CS_DESTROY]
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard HANGUP, cause: NORMAL_CLEARING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State HANGUP going to sleep
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:619 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_HANGUP -> CS_REPORTING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:741 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) Running State Change CS_DESTROY (Cur 1 Tot 488)
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_REPORTING (Cur 1 Tot 488)
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State DESTROY
2017-11-01 04:33:26.605213 [DEBUG] mod_sofia.c:343 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net SOFIA DESTROY
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State REPORTING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:174 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard REPORTING, cause: NORMAL_CLEARING
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State REPORTING going to sleep
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:181 sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net Standard DESTROY
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_vrf59sfv4q@pbxdg.domain.net) State DESTROY going to sleep
2017-11-01 04:33:26.605213 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4874
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:610 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State Change CS_REPORTING -> CS_DESTROY
2017-11-01 04:33:26.605213 [DEBUG] switch_core_session.c:1665 Session 485 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Locked, Waiting on external entities
2017-11-01 04:33:26.605213 [NOTICE] switch_core_session.c:1683 Session 485 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Ended
2017-11-01 04:33:26.605213 [NOTICE] switch_core_session.c:1687 Close Channel sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net [CS_DESTROY]
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:741 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) Running State Change CS_DESTROY (Cur 0 Tot 488)
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State DESTROY
2017-11-01 04:33:26.605213 [DEBUG] mod_sofia.c:343 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net SOFIA DESTROY
2017-11-01 04:33:26.605213 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[306] PLC[0] FEC[0]
2017-11-01 04:33:26.605213 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2017-11-01 04:33:26.605213 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-11-01 04:33:26.605213 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[795] Bytes encoded[72304] Encoded length ms[15900] Average encoded bitrate bps[38562]
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:181 sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net Standard DESTROY
2017-11-01 04:33:26.605213 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_f84u8dn62s@pbxdg.domain.net) State DESTROY going to sleep
2017-11-01 04:33:26.605213 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 7230
recv 354 bytes from udp/[KAZOOIP]:5060 at 04:33:26.863223:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP KAZOOIP:11000;rport=11000;received=KAZOOIP;branch=z9hG4bKK16Bmec0X08ye
   Call-ID: c3c6bfbe-bebd-11e7-b246-cf451ddd7335
   From: "James Hughes" <sip:888701@pbxdg.domain.net>;tag=5ja5mB9F581mN
   To: <sip:user_vrf59sfv4q@pbxdg.domain.net>;tag=jy-cN.MOr8AHRLXRSpstujQwjZ2gLCvZ
   CSeq: 114419332 BYE
   Content-Length:  0
   
   ------------------------------------------------------------------------

    Here is the full log as requested, I hope it helps shed some light on what may be happening. 

    Please let me know If I can provide anything further. 

  8. Proxy Causes Termination

    in Hardware Endpoints

    Posted · Edited by jlhughes (see edit history)

    Howdy, 

    I am getting issues when using Call.Center's proxy feature. It seems that when initiating a transfer, FreeSwitch actually drops the call:  

       ------------------------------------------------------------------------
recv 1275 bytes from udp/[IP]:5060 at 03:18:00.824837:
   ------------------------------------------------------------------------
   REFER sip:888100@IP:11000;transport=udp SIP/2.0
   Via: SIP/2.0/UDP IP;branch=z9hG4bK308a.85142f451c1c8d5f32ce0ed159a50c8d.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKVCW.QaXp;rport=6050
   From: <sip:user_vrf59sfv4q@DNSName.Com>;tag=49F1CE0E-59F699DF000B94A8-C1A13700
   To: <sip:888100@DNSName.Com>;tag=ySv3v1KtepjeD
   CSeq: 11 REFER
   Call-ID: 189C155E-59F699DF000B94AC-C1A13700
   Max-Forwards: 50
   Refer-To: <sip:888701@DNSName.Com?Replaces=4F519138-59F699CD000AA801-C2019700%3Bfrom-tag%3DyEUGDIGcovzut28rIFIK7dtxnFTCzffj%3Bto-tag%3D1B1DA70C-59F699CD000AA7FC-C2019700&Require=replaces>
   Referred-By: <sip:user_vrf59sfv4q@DNSName.Com>;transport=tcp
   User-Agent: call.center proxy
   Contact: <sip:46.19.210.33:6050;transport=udp>
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050
   X-ecallmgr_Account-ID: 75c5b9a0047e65399de45f41258e38e4
   X-ecallmgr_Authorizing-Type: device
   X-ecallmgr_Authorizing-ID: b2c525170e891ce12950790e47b5eb9f
   X-ecallmgr_Username: user_vrf59sfv4q
   X-ecallmgr_Realm: DNSName.Com
   X-ecallmgr_Account-Realm: DNSName.Com
   X-ecallmgr_Account-Name: Dove Gospel - Global
   X-ecallmgr_Presence-ID: 888701@DNSName.Com
   X-ecallmgr_Owner-ID: 9333eab27c60732f233e2b803e7c073b
   
   ------------------------------------------------------------------------
send 430 bytes to udp/[IP]:5060 at 03:18:00.825072:
   ------------------------------------------------------------------------
   SIP/2.0 500 Internal Server Error
   Via: SIP/2.0/UDP IP;branch=z9hG4bK308a.85142f451c1c8d5f32ce0ed159a50c8d.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bKVCW.QaXp;rport=6050
   From: <sip:user_vrf59sfv4q@DNSName.Com>;tag=49F1CE0E-59F699DF000B94A8-C1A13700
   To: <sip:888100@DNSName.Com>;tag=ySv3v1KtepjeD
   Call-ID: 189C155E-59F699DF000B94AC-C1A13700
   CSeq: 11 REFER
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-10-30 03:18:00.825258 [NOTICE] sofia.c:1012 Hangup sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com [CS_EXECUTE] [NORMAL_CLEARING]
2017-10-30 03:18:00.825258 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/share/kazoo-freeswitch/sounds/http_cache/1f/96a536-bd0e-11e7-a8c9-cf451ddd7335.wav
send 566 bytes to udp/[IP]:5060 at 03:18:00.827746:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP IP;branch=z9hG4bK008a.4b19afb713213e3efb1a3216141f829a.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bK1.E6raeQ;rport=6050
   From: <sip:user_vrf59sfv4q@DNSName.Com>;tag=49F1CE0E-59F699DF000B94A8-C1A13700
   To: <sip:888100@DNSName.Com>;tag=ySv3v1KtepjeD
   Call-ID: 189C155E-59F699DF000B94AC-C1A13700
   CSeq: 12 BYE
   User-Agent: 2600hz
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: path, replaces
   Content-Length: 0
   
   ------------------------------------------------------------------------
2017-10-30 03:18:00.825258 [DEBUG] switch_core_session.c:2815 sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-10-30 03:18:00.825258 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4859
2017-10-30 03:18:00.825258 [DEBUG] switch_core_session.c:2815 sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State EXECUTE going to sleep
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) Running State Change CS_HANGUP (Cur 3 Tot 369)
2017-10-30 03:18:00.825258 [DEBUG] switch_ivr.c:666 sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com skip receive message [AUDIO_SYNC] (channel is hungup already)
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:850 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) Callstate Change ACTIVE -> HANGUP
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State HANGUP
2017-10-30 03:18:00.825258 [DEBUG] mod_sofia.c:438 Channel sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com hanging up, cause: NORMAL_CLEARING
2017-10-30 03:18:00.825258 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4740
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:60 sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com Standard HANGUP, cause: NORMAL_CLEARING
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:852 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State HANGUP going to sleep
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:619 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State Change CS_HANGUP -> CS_REPORTING
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) Running State Change CS_REPORTING (Cur 3 Tot 369)
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State REPORTING
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:174 sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com Standard REPORTING, cause: NORMAL_CLEARING
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:938 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State REPORTING going to sleep
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:610 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State Change CS_REPORTING -> CS_DESTROY
2017-10-30 03:18:00.825258 [DEBUG] switch_core_session.c:1665 Session 369 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) Locked, Waiting on external entities
2017-10-30 03:18:00.825258 [NOTICE] switch_core_session.c:1683 Session 369 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) Ended
2017-10-30 03:18:00.825258 [NOTICE] switch_core_session.c:1687 Close Channel sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com [CS_DESTROY]
2017-10-30 03:18:00.825258 [NOTICE] kazoo_node.c:430 log|189C155E-59F699DF000B94AC-C1A13700|executing event Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=b27907d718d7440bbc16bffd946921cd 
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:741 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) Running State Change CS_DESTROY (Cur 2 Tot 369)
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State DESTROY
2017-10-30 03:18:00.825258 [DEBUG] mod_sofia.c:343 sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com SOFIA DESTROY
2017-10-30 03:18:00.825258 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-10-30 03:18:00.825258 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2017-10-30 03:18:00.825258 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2017-10-30 03:18:00.825258 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[412] Bytes encoded[43377] Encoded length ms[8240] Average encoded bitrate bps[43377]
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:181 sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com Standard DESTROY
2017-10-30 03:18:00.825258 [DEBUG] switch_core_state_machine.c:751 (sofia/sipinterface_1/user_vrf59sfv4q@DNSName.Com) State DESTROY going to sleep
2017-10-30 03:18:00.825258 [DEBUG] kazoo_event_stream.c:245 increased event stream buffer size to 4962
2017-10-30 03:18:01.025167 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@pbx01.exch1.net <1.8478.23>
recv 549 bytes from udp/[IP]:5060 at 03:18:01.165717:
   ------------------------------------------------------------------------
   BYE sip:mod_sofia@IP:11000 SIP/2.0
   Via: SIP/2.0/UDP IP;branch=z9hG4bK9381.2a6afc9075123d2c806c07b2945638f4.0
   Via: SIP/2.0/UDP 46.19.210.33:6050;received=46.19.210.33;branch=z9hG4bK7ia59aQS;rport=6050
   From: <sip:user_vrf59sfv4q@DNSName.Com>;tag=2EA6A39D-59F699CD000A94CC-96C97700
   To: "James Hughes" <sip:888701@DNSName.Com>;tag=tNQ0NNgctjS3e
   CSeq: 10 BYE
   Call-ID: df05075c-bd20-11e7-a9fd-cf451ddd7335
   Max-Forwards: 50
   User-Agent: call.center proxy
   Content-Length: 0
   X-AUTH-IP: 46.19.210.33
   X-AUTH-PORT: 6050

    I have tried adding 46.19.210.33 to SBC but this was not successful, and it seems the highlighted issue has been "Internal Server Error". 

    Could you advise a possible solution? 

     

    Cheers,

    James

×
×
  • Create New...