From Morose Echidna, 5 Years ago, written in FreeSWITCH.
- view diff
Embed
  1.    ------------------------------------------------------------------------
  2. recv 909 bytes from udp/[192.168.100.31]:35060 at 12:46:28.143480:
  3.    ------------------------------------------------------------------------
  4.    INVITE sip:1000@aio.kazoo SIP/2.0
  5.    Via: SIP/2.0/UDP 192.168.100.31:35060;rport;branch=z9hG4bK1945324121
  6.    From: <sip:athena@aio.kazoo>;tag=1939714079
  7.    To: <sip:1000@aio.kazoo>
  8.    Call-ID: 828301644
  9.    CSeq: 21 INVITE
  10.    Contact: <sip:athena@192.168.100.31:35060>
  11.    Proxy-Authorization: Digest username="athena", realm="aio.kazoo", nonce="c35dbe94-778b-460f-91f9-48a1ba8255f1", uri="sip:1000@aio.kazoo", response="f0c3a81c5a101794f91e10c9a1807f4c", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000001
  12.    Content-Type: application/sdp
  13.   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
  14.    Max-Forwards: 70
  15.    User-Agent: Linphone/3.6.1 (eXosip2/3.6.0)
  16.    Subject: Phone call
  17.    Content-Length:   190
  18.    
  19.    v=0
  20.    o=athena 3857 3282 IN IP4 192.168.100.31
  21.    s=Talk
  22.    c=IN IP4 192.168.100.31
  23.    t=0 0
  24.    m=audio 13706 RTP/AVP 8 101
  25.    a=rtpmap:8 PCMA/8000
  26.    a=rtpmap:101 telephone-event/8000
  27.    a=fmtp:101 0-11
  28.    ------------------------------------------------------------------------
  29. 2019-01-12 18:54:59.105082 [DEBUG] sofia.c:2522 Re-attaching to session 828301644
  30. 2019-01-12 18:54:59.115103 [DEBUG] sofia.c:10092 sofia/sipinterface_1/athena@aio.kazoo receiving invite from 192.168.100.31:35060 version: 1.8.4+git git a0377e9 2018-12-28 07:01:40Z 64bit
  31. 2019-01-12 18:54:59.115103 [DEBUG] sofia.c:10218 1 acls to check for proxy
  32. 2019-01-12 18:54:59.115103 [DEBUG] sofia.c:10223 checking 192.168.100.31 against acl authoritative
  33. 2019-01-12 18:54:59.115103 [DEBUG] sofia.c:10263 IP 192.168.100.31 Rejected by acl "authoritative". Falling back to Digest auth.
  34. 2019-01-12 18:54:59.115103 [DEBUG] kazoo_fetch_agent.c:216 Sending directory XML request (62ecc3a4-6332-41b8-acc2-0742fd1c78c2) to ecallmgr@safarov-dell.home <3.1533.0>
  35. 2019-01-12 18:54:59.295108 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.1533.0>
  36. 2019-01-12 18:54:59.295108 [DEBUG] kazoo_fetch_agent.c:277 Received directory XML (62ecc3a4-6332-41b8-acc2-0742fd1c78c2) after 180ms: <document type="freeswitch/xml"><section name="result" description="Route Not Found"><result status="not found"/></section></document>
  37. 2019-01-12 18:54:59.295108 [WARNING] switch_ivr.c:3912 can't find user [athena@aio.kazoo]
  38. 2019-01-12 18:54:59.295108 [DEBUG] kazoo_fetch_agent.c:216 Sending directory XML request (5e859c79-d601-436f-ac11-d2341894a8a5) to ecallmgr@safarov-dell.home <3.1533.0>
  39. 2019-01-12 18:54:59.495182 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.1533.0>
  40. 2019-01-12 18:54:59.495182 [DEBUG] kazoo_fetch_agent.c:277 Received directory XML (5e859c79-d601-436f-ac11-d2341894a8a5) after 200ms: <document type="freeswitch/xml"><section name="directory"><domain name="aio.kazoo"><user id="athena"><variables><variable name="ecallmgr_Username" value="athena"/><variable name="ecallmgr_Realm" value="aio.kazoo"/><variable name="ecallmgr_Account-ID" value="d5acc8dfb902d5c8be326d26cc2c6105"/><variable name="ecallmgr_Authorizing-ID" value="874e670c6e915894e2455e5820e71e61"/><variable name="ecallmgr_Authorizing-Type" value="device"/><variable name="ecallmgr_Owner-ID" value="8b7113aa4080cb37aaf3ef6f8df82f28"/><variable name="ecallmgr_Account-Realm" value="aio.kazoo"/><variable name="ecallmgr_Account-Name" value="master"/><variable name="presence_id" value="1002@aio.kazoo"/><variable name="ecallmgr_Suppress-Unregister-Notifications" value="true"/><variable name="ecallmgr_Register-Overwrite-Notify" value="false"/></variables><params><param name="password" value="athena"/></params></user></domain></section></document>
  41. 2019-01-12 18:54:59.495182 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/athena@aio.kazoo entering state [received][100]
  42. 2019-01-12 18:54:59.495182 [DEBUG] sofia.c:7301 Remote SDP:
  43. v=0
  44. o=athena 3857 3282 IN IP4 192.168.100.31
  45. s=Talk
  46. c=IN IP4 192.168.100.31
  47. t=0 0
  48. m=audio 13706 RTP/AVP 8 101
  49. a=rtpmap:8 PCMA/8000
  50. a=rtpmap:101 telephone-event/8000
  51. a=fmtp:101 0-11
  52.  
  53. 2019-01-12 18:54:59.495182 [DEBUG] sofia.c:7695 (sofia/sipinterface_1/athena@aio.kazoo) State Change CS_NEW -> CS_INIT
  54. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/athena@aio.kazoo) Running State Change CS_INIT (Cur 1 Tot 238)
  55. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/athena@aio.kazoo) State INIT
  56. 2019-01-12 18:54:59.495182 [DEBUG] mod_sofia.c:93 sofia/sipinterface_1/athena@aio.kazoo SOFIA INIT
  57. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/athena@aio.kazoo Standard INIT
  58. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/athena@aio.kazoo) State Change CS_INIT -> CS_ROUTING
  59. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/athena@aio.kazoo) State INIT going to sleep
  60. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/athena@aio.kazoo) Running State Change CS_ROUTING (Cur 1 Tot 238)
  61. 2019-01-12 18:54:59.495182 [DEBUG] switch_channel.c:2249 (sofia/sipinterface_1/athena@aio.kazoo) Callstate Change DOWN -> RINGING
  62. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/athena@aio.kazoo) State ROUTING
  63. 2019-01-12 18:54:59.495182 [DEBUG] mod_sofia.c:154 sofia/sipinterface_1/athena@aio.kazoo SOFIA ROUTING
  64. 2019-01-12 18:54:59.495182 [DEBUG] switch_core_state_machine.c:236 sofia/sipinterface_1/athena@aio.kazoo Standard ROUTING
  65. 2019-01-12 18:54:59.495182 [INFO] mod_dialplan_xml.c:637 Processing athena <athena>->1000 in context context_2
  66. send 245 bytes to udp/[192.168.100.31]:35060 at 12:46:28.539378:
  67.    ------------------------------------------------------------------------
  68.    SIP/2.0 100 Trying
  69.    Via: SIP/2.0/UDP 192.168.100.31:35060;rport=35060;branch=z9hG4bK1945324121
  70.    From: <sip:athena@aio.kazoo>;tag=1939714079
  71.    To: <sip:1000@aio.kazoo>
  72.    Call-ID: 828301644
  73.    CSeq: 21 INVITE
  74.    User-Agent: 2600hz
  75.    Content-Length: 0
  76.    
  77. 2019-01-12 18:54:59.495182 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 6859
  78.    ------------------------------------------------------------------------
  79. 2019-01-12 18:54:59.495182 [DEBUG] kazoo_fetch_agent.c:216 Sending dialplan XML request (e2ec48ce-f9ea-459a-83b7-b861abed657c) to ecallmgr@safarov-dell.home <3.1492.0>
  80. 2019-01-12 18:54:59.695073 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.1492.0>
  81. 2019-01-12 18:54:59.695073 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(828301644 ecallmgr_Call-Correlation-ID=63714573013-bb908868)
  82. 2019-01-12 18:54:59.695073 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(828301644 ecallmgr_Call-Interaction-ID=63714573013-5b13a7fc)
  83. 2019-01-12 18:54:59.695073 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 6923
  84. 2019-01-12 18:54:59.695073 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 6923
  85. 2019-01-12 18:54:59.705083 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6210.1>
  86. 2019-01-12 18:54:59.705083 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6209.1>
  87. 2019-01-12 18:54:59.705083 [DEBUG] kazoo_fetch_agent.c:277 Received dialplan XML (e2ec48ce-f9ea-459a-83b7-b861abed657c) after 209ms: <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@safarov-dell.home won call control"/><action application="export" data="ecallmgr_Ecallmgr-Node=ecallmgr@safarov-dell.home"/><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=athena|ecallmgr_Suppress-Unregister-Notifications=true|ecallmgr_Register-Overwrite-Notify=false|ecallmgr_Realm=aio.kazoo|ecallmgr_Owner-ID=8b7113aa4080cb37aaf3ef6f8df82f28|ecallmgr_Fetch-ID=e2ec48ce-f9ea-459a-83b7-b861abed657c|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63714573013-5b13a7fc|ecallmgr_Call-Correlation-ID=63714573013-bb908868|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=874e670c6e915894e2455e5820e71e61|ecallmgr_Account-Realm=aio.kazoo|ecallmgr_Account-Name=master|ecallmgr_Account-ID=d5acc8dfb902d5c8be326d26cc2c6105|ecallmgr_CallFlow-ID=8e59f43782b782e0850668019b150010|ecallmgr_Channel-Authorized=true"/><action application="park"/></condition></extension></context></section></document>
  88. Dialplan: sofia/sipinterface_1/athena@aio.kazoo parsing [context_2->park] continue=false
  89. Dialplan: sofia/sipinterface_1/athena@aio.kazoo Absolute Condition [park]
  90. Dialplan: sofia/sipinterface_1/athena@aio.kazoo Action log(NOTICE log|${uuid}|ecallmgr@safarov-dell.home won call control)
  91. Dialplan: sofia/sipinterface_1/athena@aio.kazoo Action export(ecallmgr_Ecallmgr-Node=ecallmgr@safarov-dell.home)
  92. Dialplan: sofia/sipinterface_1/athena@aio.kazoo Action set(ringback=%(2000,4000,440,480))
  93. Dialplan: sofia/sipinterface_1/athena@aio.kazoo Action set(transfer_ringback=%(2000,4000,440,480))
  94. Dialplan: sofia/sipinterface_1/athena@aio.kazoo Action kz_multiset(^^|ecallmgr_Username=athena|ecallmgr_Suppress-Unregister-Notifications=true|ecallmgr_Register-Overwrite-Notify=false|ecallmgr_Realm=aio.kazoo|ecallmgr_Owner-ID=8b7113aa4080cb37aaf3ef6f8df82f28|ecallmgr_Fetch-ID=e2ec48ce-f9ea-459a-83b7-b861abed657c|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63714573013-5b13a7fc|ecallmgr_Call-Correlation-ID=63714573013-bb908868|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=874e670c6e915894e2455e5820e71e61|ecallmgr_Account-Realm=aio.kazoo|ecallmgr_Account-Name=master|ecallmgr_Account-ID=d5acc8dfb902d5c8be326d26cc2c6105|ecallmgr_CallFlow-ID=8e59f43782b782e0850668019b150010|ecallmgr_Channel-Authorized=true)
  95. Dialplan: sofia/sipinterface_1/athena@aio.kazoo Action park()
  96. |--- Dialplan: Processing recursive conditions level:1 [park_recur_1] require-nested=TRUE
  97. |--- Dialplan: sofia/sipinterface_1/athena@aio.kazoo Regex (PASS) [park_recur_1] variable_ecallmgr_Bridge-ID() =~ /^$/ break=on-false
  98. |--- Dialplan: sofia/sipinterface_1/athena@aio.kazoo Action export(ecallmgr_Bridge-ID=${UUID}) INLINE
  99. EXECUTE sofia/sipinterface_1/athena@aio.kazoo export(ecallmgr_Bridge-ID=828301644)
  100. 2019-01-12 18:54:59.705083 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Bridge-ID]=[828301644]
  101. 2019-01-12 18:54:59.705083 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 7437
  102. 2019-01-12 18:54:59.705083 [DEBUG] switch_core_state_machine.c:286 (sofia/sipinterface_1/athena@aio.kazoo) State Change CS_ROUTING -> CS_EXECUTE
  103. 2019-01-12 18:54:59.705083 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/athena@aio.kazoo) State ROUTING going to sleep
  104. 2019-01-12 18:54:59.705083 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/athena@aio.kazoo) Running State Change CS_EXECUTE (Cur 1 Tot 238)
  105. 2019-01-12 18:54:59.705083 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/athena@aio.kazoo) State EXECUTE
  106. 2019-01-12 18:54:59.705083 [DEBUG] mod_sofia.c:209 sofia/sipinterface_1/athena@aio.kazoo SOFIA EXECUTE
  107. 2019-01-12 18:54:59.705083 [DEBUG] switch_core_state_machine.c:328 sofia/sipinterface_1/athena@aio.kazoo Standard EXECUTE
  108. EXECUTE sofia/sipinterface_1/athena@aio.kazoo log(NOTICE log|828301644|ecallmgr@safarov-dell.home won call control)
  109. 2019-01-12 18:54:59.705083 [NOTICE] mod_dptools.c:1792 log|828301644|ecallmgr@safarov-dell.home won call control
  110. 2019-01-12 18:54:59.705083 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 7503
  111. EXECUTE sofia/sipinterface_1/athena@aio.kazoo export(ecallmgr_Ecallmgr-Node=ecallmgr@safarov-dell.home)
  112. 2019-01-12 18:54:59.715083 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Ecallmgr-Node]=[ecallmgr@safarov-dell.home]
  113. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 7571
  114. EXECUTE sofia/sipinterface_1/athena@aio.kazoo set(ringback=%(2000,4000,440,480))
  115. 2019-01-12 18:54:59.715083 [DEBUG] mod_dptools.c:1598 SET sofia/sipinterface_1/athena@aio.kazoo [ringback]=[%(2000,4000,440,480)]
  116. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 7574
  117. EXECUTE sofia/sipinterface_1/athena@aio.kazoo set(transfer_ringback=%(2000,4000,440,480))
  118. 2019-01-12 18:54:59.715083 [DEBUG] mod_dptools.c:1598 SET sofia/sipinterface_1/athena@aio.kazoo [transfer_ringback]=[%(2000,4000,440,480)]
  119. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 7575
  120. EXECUTE sofia/sipinterface_1/athena@aio.kazoo kz_multiset(^^|ecallmgr_Username=athena|ecallmgr_Suppress-Unregister-Notifications=true|ecallmgr_Register-Overwrite-Notify=false|ecallmgr_Realm=aio.kazoo|ecallmgr_Owner-ID=8b7113aa4080cb37aaf3ef6f8df82f28|ecallmgr_Fetch-ID=e2ec48ce-f9ea-459a-83b7-b861abed657c|ecallmgr_Caller-Screen-Bit=true|ecallmgr_Caller-Privacy-Hide-Number=false|ecallmgr_Caller-Privacy-Hide-Name=false|ecallmgr_Call-Interaction-ID=63714573013-5b13a7fc|ecallmgr_Call-Correlation-ID=63714573013-bb908868|ecallmgr_Authorizing-Type=device|ecallmgr_Authorizing-ID=874e670c6e915894e2455e5820e71e61|ecallmgr_Account-Realm=aio.kazoo|ecallmgr_Account-Name=master|ecallmgr_Account-ID=d5acc8dfb902d5c8be326d26cc2c6105|ecallmgr_CallFlow-ID=8e59f43782b782e0850668019b150010|ecallmgr_Channel-Authorized=true)
  121. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Username]=[athena]
  122. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Suppress-Unregister-Notifications]=[true]
  123. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Register-Overwrite-Notify]=[false]
  124. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Realm]=[aio.kazoo]
  125. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Owner-ID]=[8b7113aa4080cb37aaf3ef6f8df82f28]
  126. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Fetch-ID]=[e2ec48ce-f9ea-459a-83b7-b861abed657c]
  127. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Caller-Screen-Bit]=[true]
  128. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Caller-Privacy-Hide-Number]=[false]
  129. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Caller-Privacy-Hide-Name]=[false]
  130. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Call-Interaction-ID]=[63714573013-5b13a7fc]
  131. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Call-Correlation-ID]=[63714573013-bb908868]
  132. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Authorizing-Type]=[device]
  133. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Authorizing-ID]=[874e670c6e915894e2455e5820e71e61]
  134. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Account-Realm]=[aio.kazoo]
  135. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Account-Name]=[master]
  136. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Account-ID]=[d5acc8dfb902d5c8be326d26cc2c6105]
  137. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_CallFlow-ID]=[8e59f43782b782e0850668019b150010]
  138. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [ecallmgr_Channel-Authorized]=[true]
  139. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8514
  140. 2019-01-12 18:54:59.715083 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 9466
  141. EXECUTE sofia/sipinterface_1/athena@aio.kazoo park()
  142. 2019-01-12 18:54:59.897377 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6211.1>
  143. 2019-01-12 18:54:59.916902 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(828301644 ^^~ecallmgr_Username=athena~ecallmgr_Suppress-Unregister-Notifications=true~ecallmgr_Register-Overwrite-Notify=false~ecallmgr_Realm=aio.kazoo~ecallmgr_Owner-ID=8b7113aa4080cb37aaf3ef6f8df82f28~ecallmgr_Fetch-ID=e2ec48ce-f9ea-459a-83b7-b861abed657c~ecallmgr_Caller-Screen-Bit=true~ecallmgr_Caller-Privacy-Hide-Number=false~ecallmgr_Caller-Privacy-Hide-Name=false~ecallmgr_Call-Interaction-ID=63714573013-5b13a7fc~ecallmgr_Call-Correlation-ID=63714573013-bb908868~ecallmgr_Authorizing-Type=device~ecallmgr_Authorizing-ID=874e670c6e915894e2455e5820e71e61~ecallmgr_Account-Realm=aio.kazoo~ecallmgr_Account-Name=master~ecallmgr_Account-ID=d5acc8dfb902d5c8be326d26cc2c6105~ecallmgr_CallFlow-ID=8e59f43782b782e0850668019b150010~ecallmgr_Channel-Authorized=true~ecallmgr_Application-Node=kazoo_apps@safarov-dell.home~ecallmgr_Application-Name=callflow)
  144. 2019-01-12 18:54:59.916902 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 7843
  145. 2019-01-12 18:54:59.945064 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6211.1>
  146. 2019-01-12 18:54:59.945064 [NOTICE] kazoo_node.c:430 log|828301644|executing kz_multiset ^^~effective_caller_id_name=user athena~effective_caller_id_number=1002
  147. 2019-01-12 18:54:59.955280 [DEBUG] switch_ivr.c:625 sofia/sipinterface_1/athena@aio.kazoo Command Execute kz_multiset(^^~effective_caller_id_name=user athena~effective_caller_id_number=1002)
  148. EXECUTE sofia/sipinterface_1/athena@aio.kazoo kz_multiset(^^~effective_caller_id_name=user athena~effective_caller_id_number=1002)
  149. 2019-01-12 18:54:59.955280 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [effective_caller_id_name]=[user athena]
  150. 2019-01-12 18:54:59.955280 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/athena@aio.kazoo SET [effective_caller_id_number]=[1002]
  151. 2019-01-12 18:54:59.955280 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8137
  152. 2019-01-12 18:54:59.955280 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8407
  153. 2019-01-12 18:55:00.145118 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  154. 2019-01-12 18:55:00.155131 [NOTICE] kazoo_node.c:430 log|828301644|executing event Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=3383339d2c53ab77ac7066b7b61ee4cf
  155. 2019-01-12 18:55:00.155131 [DEBUG] switch_ivr.c:625 sofia/sipinterface_1/athena@aio.kazoo Command Execute event(Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=3383339d2c53ab77ac7066b7b61ee4cf)
  156. EXECUTE sofia/sipinterface_1/athena@aio.kazoo event(Event-Subclass=kazoo::noop,Event-Name=CUSTOM,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=noop,kazoo_application_response=3383339d2c53ab77ac7066b7b61ee4cf)
  157. 2019-01-12 18:55:00.165075 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8385
  158. 2019-01-12 18:55:00.165075 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8601
  159. 2019-01-12 18:55:00.355131 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  160. 2019-01-12 18:55:00.355131 [NOTICE] kazoo_node.c:430 log|828301644|executing kz_export ^^~ringback=%(2000,4000,440,480)~transfer_ringback=%(2000,4000,440,480)
  161. 2019-01-12 18:55:00.365124 [DEBUG] switch_ivr.c:625 sofia/sipinterface_1/athena@aio.kazoo Command Execute kz_export(^^~ringback=%(2000,4000,440,480)~transfer_ringback=%(2000,4000,440,480))
  162. EXECUTE sofia/sipinterface_1/athena@aio.kazoo kz_export(^^~ringback=%(2000,4000,440,480)~transfer_ringback=%(2000,4000,440,480))
  163. 2019-01-12 18:55:00.365124 [DEBUG] kazoo_dptools.c:128 sofia/sipinterface_1/athena@aio.kazoo EXPORT [ringback]=[%(2000,4000,440,480)]
  164. 2019-01-12 18:55:00.365124 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ringback]=[%(2000,4000,440,480)]
  165. 2019-01-12 18:55:00.365124 [DEBUG] kazoo_dptools.c:128 sofia/sipinterface_1/athena@aio.kazoo EXPORT [transfer_ringback]=[%(2000,4000,440,480)]
  166. 2019-01-12 18:55:00.365124 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [transfer_ringback]=[%(2000,4000,440,480)]
  167. 2019-01-12 18:55:00.365124 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8430
  168. 2019-01-12 18:55:00.555172 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  169. 2019-01-12 18:55:00.565084 [DEBUG] kazoo_node.c:1344 increased received message buffer size to 2783
  170. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: set continue_on_fail=true
  171. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: export sip_redirect_context=context_2
  172. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: set hangup_after_bridge=true
  173. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: export ecallmgr_Inception=${ecallmgr_Inception}
  174. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: export ecallmgr_Call-Interaction-ID=${ecallmgr_Call-Interaction-ID}
  175. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: export ecallmgr_Call-Correlation-ID=${ecallmgr_Call-Correlation-ID}
  176. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: export nolocal:sip_h_X-ecallmgr_Call-Correlation-ID=${ecallmgr_Call-Correlation-ID}
  177. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: bridge {call_timeout=20,originate_timeout=20,outbound_redirect_fatal='false',bridge_export_vars='hold_music',local_var_clobber='true'}[^^!ecallmgr_Username='safarov'!ecallmgr_Realm='aio.kazoo'!presence_id='safarov@aio.kazoo'!origination_caller_id_number='1002'!origination_caller_id_name='user athena'!origination_callee_id_number='1000'!origination_callee_id_name='Account Admin'!ignore_completed_elsewhere='false'!leg_timeout='20'!sip_h_X-KAZOO-AOR=sip:safarov@aio.kazoo!sip_h_X-KAZOO-INVITE-FORMAT=contact!execute_on_answer_1=kz_multiset ^^~ecallmgr_Media-Recording-Origin=onnet~ecallmgr_Media-Recording-Endpoint-ID=4e952d9f43a4c2e63a0a566a32029f7a~ecallmgr_Media-Recording-ID=201901-c414db92a84521af7420195ee030c8b2~ecallmgr_Media-Name=1723c046430755acbdfb77795b211907.mp3~ecallmgr_Time-Limit=3600~ecallmgr_Media-Recorder=kz_media_recording~record_sample_rate=16000~record_min_sec=0~recording_follow_attxfer=false~recording_follow_transfer=false~RECORD_SOFTWARE=2600Hz, Inc.'s Kazoo~RECORD_STEREO=true~enable_file_write_buffering=false~RECORD_APPEND=true~playback_terminators=none!execute_on_answer_2=unshift media_recordings,/tmp/1723c046430755acbdfb77795b211907.mp3!execute_on_answer_3=unshift ecallmgr_Media-Names,1723c046430755acbdfb77795b211907.mp3!execute_on_answer_4=unshift ecallmgr_Media-Recordings,201901-c414db92a84521af7420195ee030c8b2!execute_on_answer_5=record_session /tmp/1723c046430755acbdfb77795b211907.mp3!ecallmgr_Authorizing-ID='4e952d9f43a4c2e63a0a566a32029f7a'!ecallmgr_Authorizing-Type='device'!ecallmgr_Owner-ID='7441f3b960a700aa29813191c0145888'!ecallmgr_Account-ID='d5acc8dfb902d5c8be326d26cc2c6105'!sdp_secure_savp_only='false'!sip_invite_domain='aio.kazoo'!absolute_codec_string='^^:PCMU:PCMA:H264'!effective_caller_id_number='1002'!effective_caller_id_name='user athena'!effective_callee_id_number='1000'!effective_callee_id_name='Account Admin']sofia/sipinterface_1/safarov@aio.kazoo;fs_path=sip:192.168.100.31:5060
  178. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: event Event-Name=CUSTOM,Event-Subclass=kazoo::masquerade,kazoo_event_name=CHANNEL_EXECUTE_COMPLETE,kazoo_application_name=bridge
  179. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:447 log|828301644|building xferext extension: park
  180. 2019-01-12 18:55:00.565084 [NOTICE] kazoo_node.c:450 log|828301644|transfered call to xferext extension
  181. 2019-01-12 18:55:00.565084 [DEBUG] switch_channel.c:3171 (sofia/sipinterface_1/athena@aio.kazoo) State Change CS_EXECUTE -> CS_ROUTING
  182. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/athena@aio.kazoo) State EXECUTE going to sleep
  183. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/athena@aio.kazoo) Running State Change CS_ROUTING (Cur 1 Tot 238)
  184. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/athena@aio.kazoo) State ROUTING
  185. 2019-01-12 18:55:00.565084 [DEBUG] mod_sofia.c:145 Call appears to be already acknowledged
  186. 2019-01-12 18:55:00.565084 [DEBUG] mod_sofia.c:154 sofia/sipinterface_1/athena@aio.kazoo SOFIA ROUTING
  187. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:236 sofia/sipinterface_1/athena@aio.kazoo Standard ROUTING
  188. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:256 (sofia/sipinterface_1/athena@aio.kazoo) State Change CS_ROUTING -> CS_EXECUTE
  189. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/athena@aio.kazoo) State ROUTING going to sleep
  190. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/athena@aio.kazoo) Running State Change CS_EXECUTE (Cur 1 Tot 238)
  191. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:650 (sofia/sipinterface_1/athena@aio.kazoo) State EXECUTE
  192. 2019-01-12 18:55:00.565084 [DEBUG] mod_sofia.c:209 sofia/sipinterface_1/athena@aio.kazoo SOFIA EXECUTE
  193. 2019-01-12 18:55:00.565084 [DEBUG] switch_core_state_machine.c:328 sofia/sipinterface_1/athena@aio.kazoo Standard EXECUTE
  194. EXECUTE sofia/sipinterface_1/athena@aio.kazoo set(continue_on_fail=true)
  195. 2019-01-12 18:55:00.565084 [DEBUG] mod_dptools.c:1598 SET sofia/sipinterface_1/athena@aio.kazoo [continue_on_fail]=[true]
  196. EXECUTE sofia/sipinterface_1/athena@aio.kazoo export(sip_redirect_context=context_2)
  197. 2019-01-12 18:55:00.565084 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_redirect_context]=[context_2]
  198. EXECUTE sofia/sipinterface_1/athena@aio.kazoo set(hangup_after_bridge=true)
  199. 2019-01-12 18:55:00.565084 [DEBUG] mod_dptools.c:1598 SET sofia/sipinterface_1/athena@aio.kazoo [hangup_after_bridge]=[true]
  200. EXECUTE sofia/sipinterface_1/athena@aio.kazoo export(ecallmgr_Inception=)
  201. 2019-01-12 18:55:00.565084 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Inception]=[UNDEF]
  202. 2019-01-12 18:55:00.565084 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8259
  203. 2019-01-12 18:55:00.585104 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8251
  204. 2019-01-12 18:55:00.585104 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8312
  205. 2019-01-12 18:55:00.595099 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8413
  206. 2019-01-12 18:55:00.595099 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8409
  207. EXECUTE sofia/sipinterface_1/athena@aio.kazoo export(ecallmgr_Call-Interaction-ID=63714573013-5b13a7fc)
  208. 2019-01-12 18:55:00.595099 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Call-Interaction-ID]=[63714573013-5b13a7fc]
  209. 2019-01-12 18:55:00.595099 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8498
  210. EXECUTE sofia/sipinterface_1/athena@aio.kazoo export(ecallmgr_Call-Correlation-ID=63714573013-bb908868)
  211. 2019-01-12 18:55:00.595099 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [ecallmgr_Call-Correlation-ID]=[63714573013-bb908868]
  212. 2019-01-12 18:55:00.595099 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8527
  213. EXECUTE sofia/sipinterface_1/athena@aio.kazoo export(nolocal:sip_h_X-ecallmgr_Call-Correlation-ID=63714573013-bb908868)
  214. 2019-01-12 18:55:00.595099 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [sip_h_X-ecallmgr_Call-Correlation-ID]=[63714573013-bb908868]
  215. 2019-01-12 18:55:00.595099 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 8689
  216. EXECUTE sofia/sipinterface_1/athena@aio.kazoo bridge({call_timeout=20,originate_timeout=20,outbound_redirect_fatal='false',bridge_export_vars='hold_music',local_var_clobber='true'}[^^!ecallmgr_Username='safarov'!ecallmgr_Realm='aio.kazoo'!presence_id='safarov@aio.kazoo'!origination_caller_id_number='1002'!origination_caller_id_name='user athena'!origination_callee_id_number='1000'!origination_callee_id_name='Account Admin'!ignore_completed_elsewhere='false'!leg_timeout='20'!sip_h_X-KAZOO-AOR=sip:safarov@aio.kazoo!sip_h_X-KAZOO-INVITE-FORMAT=contact!execute_on_answer_1=kz_multiset ^^~ecallmgr_Media-Recording-Origin=onnet~ecallmgr_Media-Recording-Endpoint-ID=4e952d9f43a4c2e63a0a566a32029f7a~ecallmgr_Media-Recording-ID=201901-c414db92a84521af7420195ee030c8b2~ecallmgr_Media-Name=1723c046430755acbdfb77795b211907.mp3~ecallmgr_Time-Limit=3600~ecallmgr_Media-Recorder=kz_media_recording~record_sample_rate=16000~record_min_sec=0~recording_follow_attxfer=false~recording_follow_transfer=false~RECORD_SOFTWARE=2600Hz, Inc.'s Kazoo~RECORD_STEREO=true~enable_file_write_buffering=false~RECORD_APPEND=true~playback_terminators=none!execute_on_answer_2=unshift media_recordings,/tmp/1723c046430755acbdfb77795b211907.mp3!execute_on_answer_3=unshift ecallmgr_Media-Names,1723c046430755acbdfb77795b211907.mp3!execute_on_answer_4=unshift ecallmgr_Media-Recordings,201901-c414db92a84521af7420195ee030c8b2!execute_on_answer_5=record_session /tmp/1723c046430755acbdfb77795b211907.mp3!ecallmgr_Authorizing-ID='4e952d9f43a4c2e63a0a566a32029f7a'!ecallmgr_Authorizing-Type='device'!ecallmgr_Owner-ID='7441f3b960a700aa29813191c0145888'!ecallmgr_Account-ID='d5acc8dfb902d5c8be326d26cc2c6105'!sdp_secure_savp_only='false'!sip_invite_domain='aio.kazoo'!absolute_codec_string='^^:PCMU:PCMA:H264'!effective_caller_id_number='1002'!effective_caller_id_name='user athena'!effective_callee_id_number='1000'!effective_callee_id_name='Account Admin']sofia/sipinterface_1/safarov@aio.kazoo;fs_path=sip:192.168.100.31:5060)
  217. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [ecallmgr_Bridge-ID]=[828301644] to event
  218. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [ecallmgr_Ecallmgr-Node]=[ecallmgr@safarov-dell.home] to event
  219. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [ringback]=[%(2000,4000,440,480)] to event
  220. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [transfer_ringback]=[%(2000,4000,440,480)] to event
  221. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [sip_redirect_context]=[context_2] to event
  222. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [ecallmgr_Call-Interaction-ID]=[63714573013-5b13a7fc] to event
  223. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [ecallmgr_Call-Correlation-ID]=[63714573013-bb908868] to event
  224. 2019-01-12 18:55:00.605087 [DEBUG] switch_channel.c:1250 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[export_vars] [sip_h_X-ecallmgr_Call-Correlation-ID]=[63714573013-bb908868] to event
  225. 2019-01-12 18:55:00.605087 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables
  226. 2019-01-12 18:55:00.605087 [DEBUG] switch_ivr_originate.c:2749 Parsing session specific variables
  227. 2019-01-12 18:55:00.605087 [NOTICE] switch_channel.c:1104 New Channel sofia/sipinterface_1/safarov@aio.kazoo [e23a17fd-d54c-4ee9-ad45-23d6326faec5]
  228. 2019-01-12 18:55:00.605087 [DEBUG] mod_sofia.c:5018 (sofia/sipinterface_1/safarov@aio.kazoo) State Change CS_NEW -> CS_INIT
  229. 2019-01-12 18:55:00.605087 [DEBUG] switch_ivr_originate.c:3056 sofia/sipinterface_1/safarov@aio.kazoo Setting leg timeout to 20
  230. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/safarov@aio.kazoo) Running State Change CS_INIT (Cur 2 Tot 239)
  231. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/safarov@aio.kazoo) State INIT
  232. 2019-01-12 18:55:00.605087 [DEBUG] mod_sofia.c:93 sofia/sipinterface_1/safarov@aio.kazoo SOFIA INIT
  233. 2019-01-12 18:55:00.605087 [DEBUG] sofia_glue.c:1271 sip:192.168.100.31:5060 Setting proxy route to sofia/sipinterface_1/safarov@aio.kazoo
  234. 2019-01-12 18:55:00.605087 [DEBUG] sofia_glue.c:1302 sofia/sipinterface_1/safarov@aio.kazoo sending invite version: 1.8.4+git git a0377e9 2018-12-28 07:01:40Z 64bit
  235. Local SDP:
  236. v=0
  237. o=FreeSWITCH 1547287376 1547287377 IN IP4 192.168.100.31
  238. s=FreeSWITCH
  239. c=IN IP4 192.168.100.31
  240. t=0 0
  241. m=audio 31924 RTP/AVP 0 8 101 13
  242. a=rtpmap:0 PCMU/8000
  243. a=rtpmap:8 PCMA/8000
  244. a=rtpmap:101 telephone-event/8000
  245. a=fmtp:101 0-16
  246. a=rtpmap:13 CN/8000
  247. a=ptime:20
  248. a=sendrecv
  249. m=video 19724 RTP/AVP 102
  250. b=AS:1024
  251. a=rtpmap:102 H264/90000
  252. a=sendrecv
  253. a=rtcp-fb:102 ccm fir
  254. a=rtcp-fb:102 ccm tmmbr
  255. a=rtcp-fb:102 nack
  256. a=rtcp-fb:102 nack pli
  257.  
  258. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:40 sofia/sipinterface_1/safarov@aio.kazoo Standard INIT
  259. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:48 (sofia/sipinterface_1/safarov@aio.kazoo) State Change CS_INIT -> CS_ROUTING
  260. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:627 (sofia/sipinterface_1/safarov@aio.kazoo) State INIT going to sleep
  261. send 1461 bytes to udp/[192.168.100.31]:5060 at 12:46:29.648161:
  262.    ------------------------------------------------------------------------
  263.    INVITE sip:safarov@aio.kazoo SIP/2.0
  264.    Via: SIP/2.0/UDP 192.168.100.31:11000;rport;branch=z9hG4bKj20HUFp5K4a9a
  265.    Route: <sip:192.168.100.31:5060>
  266.    Max-Forwards: 69
  267.    From: "user athena" <sip:1002@aio.kazoo>;tag=r7rK3gtHrDa0D
  268.    To: <sip:safarov@aio.kazoo>
  269.    Call-ID: e23a17fd-d54c-4ee9-ad45-23d6326faec5
  270.    CSeq: 133355730 INVITE
  271.    Contact: <sip:mod_sofia@192.168.100.31:11000>
  272.    User-Agent: 2600hz
  273.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  274.    Supported: path, replaces
  275.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  276.    Content-Type: application/sdp
  277.    Content-Disposition: session
  278.    Content-Length: 427
  279.    X-ecallmgr_Call-Correlation-ID: 63714573013-bb908868
  280.    X-KAZOO-AOR: sip:safarov@aio.kazoo
  281.    X-KAZOO-INVITE-FORMAT: contact
  282.    X-FS-Support: update_display,send_info
  283.    Remote-Party-ID: "user athena" <sip:1002@aio.kazoo>;party=calling;screen=yes;privacy=off
  284.    
  285.    v=0
  286.    o=FreeSWITCH 1547287376 1547287377 IN IP4 192.168.100.31
  287.    s=FreeSWITCH
  288.    c=IN IP4 192.168.100.31
  289.    t=0 0
  290.    m=audio 31924 RTP/AVP 0 8 101 13
  291.    a=rtpmap:0 PCMU/8000
  292.    a=rtpmap:8 PCMA/8000
  293.    a=rtpmap:101 telephone-event/8000
  294.    a=fmtp:101 0-16
  295.    a=rtpmap:13 CN/8000
  296.    a=ptime:20
  297.    m=video 19724 RTP/AVP 102
  298.    b=AS:1024
  299.    a=rtpmap:102 H264/90000
  300.    a=rtcp-fb:102 ccm fir
  301.    a=rtcp-fb:102 ccm tmmbr
  302.    a=rtcp-fb:102 nack
  303.    a=rtcp-fb:102 nack pli
  304.    ------------------------------------------------------------------------
  305. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/safarov@aio.kazoo) Running State Change CS_ROUTING (Cur 2 Tot 239)
  306. 2019-01-12 18:55:00.605087 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/safarov@aio.kazoo entering state [calling][0]
  307. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/safarov@aio.kazoo) State ROUTING
  308. 2019-01-12 18:55:00.605087 [DEBUG] mod_sofia.c:154 sofia/sipinterface_1/safarov@aio.kazoo SOFIA ROUTING
  309. 2019-01-12 18:55:00.605087 [DEBUG] switch_ivr_originate.c:67 (sofia/sipinterface_1/safarov@aio.kazoo) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  310. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:643 (sofia/sipinterface_1/safarov@aio.kazoo) State ROUTING going to sleep
  311. 2019-01-12 18:55:00.605087 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 4343
  312. 2019-01-12 18:55:00.605087 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 9337
  313. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/safarov@aio.kazoo) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 239)
  314. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:662 (sofia/sipinterface_1/safarov@aio.kazoo) State CONSUME_MEDIA
  315. 2019-01-12 18:55:00.605087 [DEBUG] switch_core_state_machine.c:662 (sofia/sipinterface_1/safarov@aio.kazoo) State CONSUME_MEDIA going to sleep
  316. recv 329 bytes from udp/[192.168.100.31]:5060 at 12:46:29.653414:
  317.    ------------------------------------------------------------------------
  318.    SIP/2.0 100 Attempting to connect your call
  319.    Via: SIP/2.0/UDP 192.168.100.31:11000;rport=11000;branch=z9hG4bKj20HUFp5K4a9a;received=192.168.100.31
  320.    From: "user athena" <sip:1002@aio.kazoo>;tag=r7rK3gtHrDa0D
  321.    To: <sip:safarov@aio.kazoo>
  322.    Call-ID: e23a17fd-d54c-4ee9-ad45-23d6326faec5
  323.    CSeq: 133355730 INVITE
  324.    Content-Length: 0
  325.    
  326.    ------------------------------------------------------------------------
  327. 2019-01-12 18:55:00.615085 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  328. 2019-01-12 18:55:00.615085 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(e23a17fd-d54c-4ee9-ad45-23d6326faec5 ^^~ecallmgr_Account-ID=d5acc8dfb902d5c8be326d26cc2c6105~ecallmgr_Global-Resource=false~ecallmgr_Channel-Authorized=true)
  329. 2019-01-12 18:55:00.636429 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 9501
  330. 2019-01-12 18:55:00.665065 [INFO] kazoo_node.c:837 exec: kz_uuid_setvar_multi(e23a17fd-d54c-4ee9-ad45-23d6326faec5 ecallmgr_Call-Interaction-ID=63714573013-5b13a7fc)
  331. 2019-01-12 18:55:00.665065 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6261.1>
  332. 2019-01-12 18:55:00.665065 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 9432
  333. 2019-01-12 18:55:00.865158 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  334. recv 449 bytes from udp/[192.168.100.31]:5060 at 12:46:30.310316:
  335.    ------------------------------------------------------------------------
  336.    SIP/2.0 180 Ringing
  337.    Via: SIP/2.0/UDP 192.168.100.31:11000;received=192.168.100.31;rport=11000;branch=z9hG4bKj20HUFp5K4a9a
  338.    From: "user athena" <sip:1002@aio.kazoo>;tag=r7rK3gtHrDa0D
  339.    To: <sip:safarov@aio.kazoo>;tag=jTSUwgb
  340.    Call-ID: e23a17fd-d54c-4ee9-ad45-23d6326faec5
  341.    CSeq: 133355730 INVITE
  342.    User-Agent: LinphoneAndroid/4.0.1 (belle-sip/1.6.3)
  343.    Supported: replaces, outbound, gruu
  344.    Record-route: <sip:192.168.100.31;lr=on;ftag=r7rK3gtHrDa0D>
  345.    
  346.    ------------------------------------------------------------------------
  347. 2019-01-12 18:55:01.275573 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/safarov@aio.kazoo entering state [proceeding][180]
  348. 2019-01-12 18:55:01.275573 [NOTICE] sofia.c:7401 Ring-Ready sofia/sipinterface_1/safarov@aio.kazoo!
  349. 2019-01-12 18:55:01.275573 [DEBUG] switch_channel.c:3354 (sofia/sipinterface_1/safarov@aio.kazoo) Callstate Change DOWN -> RINGING
  350. 2019-01-12 18:55:01.275573 [INFO] switch_ivr_originate.c:1246 Sending early media
  351. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  352. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  353. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  354. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  355. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  356. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  357. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
  358. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
  359. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:3781 Set Codec sofia/sipinterface_1/athena@aio.kazoo PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  360. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/athena@aio.kazoo Original read codec set to PCMA:8
  361. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000
  362. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:5795 sofia/sipinterface_1/athena@aio.kazoo Set 2833 dtmf send payload to 101 recv payload to 101
  363. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:8510 AUDIO RTP [sofia/sipinterface_1/athena@aio.kazoo] 192.168.100.31 port 21624 -> 192.168.100.31 port 13706 codec: 8 ms: 20
  364. 2019-01-12 18:55:01.275573 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 160 bytes per 20ms
  365. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:8814 sofia/sipinterface_1/athena@aio.kazoo Set 2833 dtmf send payload to 101
  366. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:8821 sofia/sipinterface_1/athena@aio.kazoo Set 2833 dtmf receive payload to 101
  367. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:8844 sofia/sipinterface_1/athena@aio.kazoo Set rtp dtmf delay to 40
  368. 2019-01-12 18:55:01.275573 [NOTICE] sofia_media.c:92 Pre-Answer sofia/sipinterface_1/athena@aio.kazoo!
  369. 2019-01-12 18:55:01.275573 [DEBUG] switch_channel.c:3482 (sofia/sipinterface_1/athena@aio.kazoo) Callstate Change RINGING -> EARLY
  370. 2019-01-12 18:55:01.275573 [DEBUG] switch_core_media.c:8493 Audio params are unchanged for sofia/sipinterface_1/athena@aio.kazoo.
  371. 2019-01-12 18:55:01.275573 [DEBUG] mod_sofia.c:2504 Ring SDP:
  372. v=0
  373. o=FreeSWITCH 1547297677 1547297678 IN IP4 192.168.100.31
  374. s=FreeSWITCH
  375. c=IN IP4 192.168.100.31
  376. t=0 0
  377. m=audio 21624 RTP/AVP 8 101
  378. a=rtpmap:8 PCMA/8000
  379. a=rtpmap:101 telephone-event/8000
  380. a=fmtp:101 0-16
  381. a=ptime:20
  382. a=sendrecv
  383.  
  384. 2019-01-12 18:55:01.275573 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 11822
  385. send 1031 bytes to udp/[192.168.100.31]:35060 at 12:46:30.324801:
  386.    ------------------------------------------------------------------------
  387.    SIP/2.0 183 Session Progress
  388.    Via: SIP/2.0/UDP 192.168.100.31:35060;rport=35060;branch=z9hG4bK1945324121
  389.    From: <sip:athena@aio.kazoo>;tag=1939714079
  390.    To: <sip:1000@aio.kazoo>;tag=QyZt1N9DU4KDj
  391.    Call-ID: 828301644
  392.    CSeq: 21 INVITE
  393.    Contact: <sip:1000@192.168.100.31:11000;transport=udp>
  394.    User-Agent: 2600hz
  395.    Accept: application/sdp
  396.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  397.    Supported: path, replaces
  398.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  399.    Content-Type: application/sdp
  400.    Content-Disposition: session
  401.    Content-Length: 224
  402.    Remote-Party-ID: "1000" <sip:1000@aio.kazoo>;party=calling;privacy=off;screen=no
  403.    
  404.    v=0
  405.    o=FreeSWITCH 1547297677 1547297678 IN IP4 192.168.100.31
  406.    s=FreeSWITCH
  407.    c=IN IP4 192.168.100.31
  408.    t=0 0
  409.    m=audio 21624 RTP/AVP 8 101
  410.    a=rtpmap:8 PCMA/8000
  411.    a=rtpmap:101 telephone-event/8000
  412.    a=fmtp:101 0-16
  413.    a=ptime:20
  414.    ------------------------------------------------------------------------
  415. 2019-01-12 18:55:01.287066 [DEBUG] switch_ivr_originate.c:1304 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  416. 2019-01-12 18:55:01.287066 [DEBUG] switch_core_codec.c:223 sofia/sipinterface_1/athena@aio.kazoo Push codec L16:100
  417. 2019-01-12 18:55:01.287066 [DEBUG] switch_ivr_originate.c:1373 Play Ringback Tone [%(2000,4000,440,480)]
  418. 2019-01-12 18:55:01.305080 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/athena@aio.kazoo entering state [early][183]
  419. recv 344 bytes from udp/[192.168.100.31]:5060 at 12:46:30.419286:
  420.    ------------------------------------------------------------------------
  421.    OPTIONS sip:192.168.100.31:11000 SIP/2.0
  422.    Via: SIP/2.0/UDP 192.168.100.31;branch=z9hG4bKbe2.ac219651000000000000000000000000.0
  423.    To: <sip:192.168.100.31:11000>
  424.    From: <sip:sipcheck@safarov-dell.home>;tag=1f6333e227a91274915eae760737b59b-c09b
  425.    CSeq: 10 OPTIONS
  426.    Call-ID: 196225584a61b06c-84@192.168.100.31
  427.    Max-Forwards: 70
  428.    Content-Length: 0
  429.    
  430.    ------------------------------------------------------------------------
  431. send 708 bytes to udp/[192.168.100.31]:5060 at 12:46:30.419910:
  432.    ------------------------------------------------------------------------
  433.    SIP/2.0 200 OK
  434.    Via: SIP/2.0/UDP 192.168.100.31;branch=z9hG4bKbe2.ac219651000000000000000000000000.0
  435.    From: <sip:sipcheck@safarov-dell.home>;tag=1f6333e227a91274915eae760737b59b-c09b
  436.    To: <sip:192.168.100.31:11000>;tag=Sgjc5BBNNp0jS
  437.    Call-ID: 196225584a61b06c-84@192.168.100.31
  438.    CSeq: 10 OPTIONS
  439.    Contact: <sip:192.168.100.31:11000>
  440.    User-Agent: 2600hz
  441.    Accept: application/sdp
  442.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  443.    Supported: path, replaces
  444.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  445.    Content-Length: 0
  446.    
  447.    ------------------------------------------------------------------------
  448. recv 449 bytes from udp/[192.168.100.31]:5060 at 12:46:30.464118:
  449.    ------------------------------------------------------------------------
  450.    SIP/2.0 180 Ringing
  451.    Via: SIP/2.0/UDP 192.168.100.31:11000;received=192.168.100.31;rport=11000;branch=z9hG4bKj20HUFp5K4a9a
  452.    From: "user athena" <sip:1002@aio.kazoo>;tag=r7rK3gtHrDa0D
  453.    To: <sip:safarov@aio.kazoo>;tag=jTSUwgb
  454.    Call-ID: e23a17fd-d54c-4ee9-ad45-23d6326faec5
  455.    CSeq: 133355730 INVITE
  456.    User-Agent: LinphoneAndroid/4.0.1 (belle-sip/1.6.3)
  457.    Supported: replaces, outbound, gruu
  458.    Record-route: <sip:192.168.100.31;lr=on;ftag=r7rK3gtHrDa0D>
  459.    
  460.    ------------------------------------------------------------------------
  461. 2019-01-12 18:55:01.415558 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/safarov@aio.kazoo entering state [proceeding][180]
  462. 2019-01-12 18:55:01.435089 [DEBUG] switch_rtp.c:7550 Correct audio ip/port confirmed.
  463. freeswitch@safarov-dell.home>
  464. freeswitch@safarov-dell.home>
  465. freeswitch@safarov-dell.home>
  466. freeswitch@safarov-dell.home>
  467. freeswitch@safarov-dell.home>
  468. freeswitch@safarov-dell.home>
  469. freeswitch@safarov-dell.home>
  470. freeswitch@safarov-dell.home>
  471. freeswitch@safarov-dell.home>
  472. freeswitch@safarov-dell.home>
  473. freeswitch@safarov-dell.home>
  474. freeswitch@safarov-dell.home>
  475. freeswitch@safarov-dell.home>
  476. freeswitch@safarov-dell.home>
  477. freeswitch@safarov-dell.home>
  478. freeswitch@safarov-dell.home>
  479. freeswitch@safarov-dell.home>
  480. freeswitch@safarov-dell.home>
  481. freeswitch@safarov-dell.home>
  482. freeswitch@safarov-dell.home>
  483. freeswitch@safarov-dell.home>
  484. freeswitch@safarov-dell.home>
  485. freeswitch@safarov-dell.home>
  486. freeswitch@safarov-dell.home>
  487. freeswitch@safarov-dell.home>
  488. freeswitch@safarov-dell.home>
  489. freeswitch@safarov-dell.home>
  490. freeswitch@safarov-dell.home>
  491. freeswitch@safarov-dell.home>
  492. freeswitch@safarov-dell.home>
  493. freeswitch@safarov-dell.home>
  494. freeswitch@safarov-dell.home>
  495. freeswitch@safarov-dell.home>
  496. freeswitch@safarov-dell.home>
  497. recv 897 bytes from udp/[192.168.100.31]:5060 at 12:46:32.573572:
  498.    ------------------------------------------------------------------------
  499.    SIP/2.0 200 Ok
  500.    Via: SIP/2.0/UDP 192.168.100.31:11000;received=192.168.100.31;rport=11000;branch=z9hG4bKj20HUFp5K4a9a
  501.    From: "user athena" <sip:1002@aio.kazoo>;tag=r7rK3gtHrDa0D
  502.    To: <sip:safarov@aio.kazoo>;tag=jTSUwgb
  503.    Call-ID: e23a17fd-d54c-4ee9-ad45-23d6326faec5
  504.    CSeq: 133355730 INVITE
  505.    User-Agent: LinphoneAndroid/4.0.1 (belle-sip/1.6.3)
  506.    Supported: replaces, outbound, gruu
  507.   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
  508.    Contact: <sip:safarov@192.168.100.28:46882;gr=urn:uuid:07286db4-6183-40fe-a86c-90af9ba715d8>;+org.linphone.specs=groupchat
  509.    Content-Type: application/sdp
  510.    Content-Length: 186
  511.    Record-route: <sip:192.168.100.31;lr=on;ftag=r7rK3gtHrDa0D>
  512.    
  513.    v=0
  514.    o=safarov 3496 3343 IN IP4 192.168.100.28
  515.    s=Talk
  516.    c=IN IP4 192.168.100.28
  517.    t=0 0
  518.    m=audio 7076 RTP/AVP 0 8 101
  519.    a=rtpmap:101 telephone-event/8000
  520.    m=video 0 RTP/AVP 0
  521.    a=inactive
  522.    ------------------------------------------------------------------------
  523. 2019-01-12 18:55:03.535418 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/safarov@aio.kazoo entering state [completing][200]
  524. 2019-01-12 18:55:03.535418 [DEBUG] sofia.c:7301 Remote SDP:
  525. v=0
  526. o=safarov 3496 3343 IN IP4 192.168.100.28
  527. s=Talk
  528. c=IN IP4 192.168.100.28
  529. t=0 0
  530. m=audio 7076 RTP/AVP 0 8 101
  531. a=rtpmap:101 telephone-event/8000
  532. m=video 0 RTP/AVP 0
  533.  
  534. 2019-01-12 18:55:03.535418 [NOTICE] sofia.c:7304 Pre-Answer sofia/sipinterface_1/safarov@aio.kazoo!
  535. 2019-01-12 18:55:03.535418 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 11718
  536. 2019-01-12 18:55:03.535418 [DEBUG] switch_channel.c:3482 (sofia/sipinterface_1/safarov@aio.kazoo) Callstate Change RINGING -> EARLY
  537. send 477 bytes to udp/[192.168.100.31]:5060 at 12:46:32.579783:
  538.    ------------------------------------------------------------------------
  539.    ACK sip:safarov@192.168.100.28:46882;gr=urn:uuid:07286db4-6183-40fe-a86c-90af9ba715d8 SIP/2.0
  540.    Via: SIP/2.0/UDP 192.168.100.31:11000;rport;branch=z9hG4bKKBtaXa78gD1Up
  541.    Route: <sip:192.168.100.31;lr=on;ftag=r7rK3gtHrDa0D>
  542.    Max-Forwards: 70
  543.    From: "user athena" <sip:1002@aio.kazoo>;tag=r7rK3gtHrDa0D
  544.    To: <sip:safarov@aio.kazoo>;tag=jTSUwgb
  545.    Call-ID: e23a17fd-d54c-4ee9-ad45-23d6326faec5
  546.    CSeq: 133355730 ACK
  547.    Contact: <sip:mod_sofia@192.168.100.31:11000>
  548.    Content-Length: 0
  549.    
  550.    ------------------------------------------------------------------------
  551. 2019-01-12 18:55:03.535418 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/safarov@aio.kazoo entering state [ready][200]
  552. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_codec.c:248 sofia/sipinterface_1/athena@aio.kazoo Restore previous codec PCMA:8.
  553. 2019-01-12 18:55:03.535418 [DEBUG] switch_ivr_originate.c:3798 Originate Resulted in Success: [sofia/sipinterface_1/safarov@aio.kazoo]
  554. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  555. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  556. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  557. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  558. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  559. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  560. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
  561. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:3781 Set Codec sofia/sipinterface_1/safarov@aio.kazoo PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  562. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_codec.c:111 sofia/sipinterface_1/safarov@aio.kazoo Original read codec set to PCMU:0
  563. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000
  564. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:5795 sofia/sipinterface_1/safarov@aio.kazoo Set 2833 dtmf send payload to 101 recv payload to 101
  565. 2019-01-12 18:55:03.535418 [DEBUG] switch_core_media.c:8510 AUDIO RTP [sofia/sipinterface_1/safarov@aio.kazoo] 192.168.100.31 port 31924 -> 192.168.100.28 port 7076 codec: 0 ms: 20
  566. 2019-01-12 18:55:03.535418 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 160 bytes per 20ms
  567. 2019-01-12 18:55:03.545170 [DEBUG] switch_channel.c:1257 sofia/sipinterface_1/safarov@aio.kazoo EXPORTING[bridge_export_vars] [hold_music]=[local_stream://default] to sofia/sipinterface_1/athena@aio.kazoo
  568. 2019-01-12 18:55:03.545170 [DEBUG] switch_channel.c:1257 sofia/sipinterface_1/athena@aio.kazoo EXPORTING[bridge_export_vars] [hold_music]=[local_stream://default] to sofia/sipinterface_1/safarov@aio.kazoo
  569. 2019-01-12 18:55:03.545170 [DEBUG] switch_core_media.c:8814 sofia/sipinterface_1/safarov@aio.kazoo Set 2833 dtmf send payload to 101
  570. 2019-01-12 18:55:03.545170 [DEBUG] switch_core_media.c:8821 sofia/sipinterface_1/safarov@aio.kazoo Set 2833 dtmf receive payload to 101
  571. 2019-01-12 18:55:03.545170 [DEBUG] switch_core_media.c:8844 sofia/sipinterface_1/safarov@aio.kazoo Set rtp dtmf delay to 40
  572. 2019-01-12 18:55:03.545170 [NOTICE] sofia.c:8429 Channel [sofia/sipinterface_1/safarov@aio.kazoo] has been answered
  573. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14194
  574. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 13117
  575. EXECUTE sofia/sipinterface_1/safarov@aio.kazoo kz_multiset(^^~ecallmgr_Media-Recording-Origin=onnet~ecallmgr_Media-Recording-Endpoint-ID=4e952d9f43a4c2e63a0a566a32029f7a~ecallmgr_Media-Recording-ID=201901-c414db92a84521af7420195ee030c8b2~ecallmgr_Media-Name=1723c046430755acbdfb77795b211907.mp3~ecallmgr_Time-Limit=3600~ecallmgr_Media-Recorder=kz_media_recording~record_sample_rate=16000~record_min_sec=0~recording_follow_attxfer=false~recording_follow_transfer=false~RECORD_SOFTWARE=2600Hz, Inc.s Kazoo~RECORD_STEREO=true~enable_file_write_buffering=false~RECORD_APPEND=true~playback_terminators=none)
  576. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [ecallmgr_Media-Recording-Origin]=[onnet]
  577. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [ecallmgr_Media-Recording-Endpoint-ID]=[4e952d9f43a4c2e63a0a566a32029f7a]
  578. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [ecallmgr_Media-Recording-ID]=[201901-c414db92a84521af7420195ee030c8b2]
  579. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [ecallmgr_Media-Name]=[1723c046430755acbdfb77795b211907.mp3]
  580. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [ecallmgr_Time-Limit]=[3600]
  581. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [ecallmgr_Media-Recorder]=[kz_media_recording]
  582. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [record_sample_rate]=[16000]
  583. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [record_min_sec]=[0]
  584. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [recording_follow_attxfer]=[false]
  585. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [recording_follow_transfer]=[false]
  586. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [RECORD_SOFTWARE]=[2600Hz, Inc.s Kazoo]
  587. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [RECORD_STEREO]=[true]
  588. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [enable_file_write_buffering]=[false]
  589. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [RECORD_APPEND]=[true]
  590. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_dptools.c:81 sofia/sipinterface_1/safarov@aio.kazoo SET [playback_terminators]=[none]
  591. EXECUTE sofia/sipinterface_1/safarov@aio.kazoo unshift(media_recordings,/tmp/1723c046430755acbdfb77795b211907.mp3)
  592. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14497
  593. 2019-01-12 18:55:03.545170 [DEBUG] mod_dptools.c:1598 UNSHIFT sofia/sipinterface_1/safarov@aio.kazoo [media_recordings]=[/tmp/1723c046430755acbdfb77795b211907.mp3]
  594. EXECUTE sofia/sipinterface_1/safarov@aio.kazoo unshift(ecallmgr_Media-Names,1723c046430755acbdfb77795b211907.mp3)
  595. 2019-01-12 18:55:03.545170 [DEBUG] mod_dptools.c:1598 UNSHIFT sofia/sipinterface_1/safarov@aio.kazoo [ecallmgr_Media-Names]=[1723c046430755acbdfb77795b211907.mp3]
  596. 2019-01-12 18:55:03.545170 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 15283
  597. 2019-01-12 18:55:03.555141 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14385
  598. EXECUTE sofia/sipinterface_1/safarov@aio.kazoo unshift(ecallmgr_Media-Recordings,201901-c414db92a84521af7420195ee030c8b2)
  599. 2019-01-12 18:55:03.555141 [DEBUG] mod_dptools.c:1598 UNSHIFT sofia/sipinterface_1/safarov@aio.kazoo [ecallmgr_Media-Recordings]=[201901-c414db92a84521af7420195ee030c8b2]
  600. 2019-01-12 18:55:03.555141 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14460
  601. EXECUTE sofia/sipinterface_1/safarov@aio.kazoo record_session(/tmp/1723c046430755acbdfb77795b211907.mp3)
  602. 2019-01-12 18:55:03.565119 [DEBUG] switch_core_file.c:389 File /tmp/1723c046430755acbdfb77795b211907.mp3 sample rate 16000 doesn't match requested rate 8000
  603. 2019-01-12 18:55:03.565119 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14561
  604. 2019-01-12 18:55:03.578590 [DEBUG] switch_ivr_async.c:1325 Record session sample rate: 8000 -> 16000
  605. 2019-01-12 18:55:03.578590 [DEBUG] switch_core_media_bug.c:962 Attaching BUG to sofia/sipinterface_1/safarov@aio.kazoo
  606. 2019-01-12 18:55:03.578590 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14221
  607. 2019-01-12 18:55:03.578590 [DEBUG] switch_channel.c:3781 (sofia/sipinterface_1/safarov@aio.kazoo) Callstate Change EARLY -> ACTIVE
  608. 2019-01-12 18:55:03.578590 [DEBUG] switch_ivr_bridge.c:1782 (sofia/sipinterface_1/safarov@aio.kazoo) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  609. 2019-01-12 18:55:03.578590 [DEBUG] switch_core_state_machine.c:584 (sofia/sipinterface_1/safarov@aio.kazoo) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 239)
  610. 2019-01-12 18:55:03.578590 [DEBUG] switch_core_state_machine.c:653 (sofia/sipinterface_1/safarov@aio.kazoo) State EXCHANGE_MEDIA
  611. 2019-01-12 18:55:03.578590 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
  612. 2019-01-12 18:55:03.578590 [DEBUG] switch_core_media.c:8493 Audio params are unchanged for sofia/sipinterface_1/athena@aio.kazoo.
  613. 2019-01-12 18:55:03.578590 [DEBUG] mod_sofia.c:881 Local SDP sofia/sipinterface_1/athena@aio.kazoo:
  614. v=0
  615. o=FreeSWITCH 1547297677 1547297679 IN IP4 192.168.100.31
  616. s=FreeSWITCH
  617. c=IN IP4 192.168.100.31
  618. t=0 0
  619. m=audio 21624 RTP/AVP 8 101
  620. a=rtpmap:8 PCMA/8000
  621. a=rtpmap:101 telephone-event/8000
  622. a=fmtp:101 0-16
  623. a=ptime:20
  624. a=sendrecv
  625.  
  626. send 1001 bytes to udp/[192.168.100.31]:35060 at 12:46:32.623668:
  627.    ------------------------------------------------------------------------
  628.    SIP/2.0 200 OK
  629.    Via: SIP/2.0/UDP 192.168.100.31:35060;rport=35060;branch=z9hG4bK1945324121
  630.    From: <sip:athena@aio.kazoo>;tag=1939714079
  631.    To: <sip:1000@aio.kazoo>;tag=QyZt1N9DU4KDj
  632.    Call-ID: 828301644
  633.    CSeq: 21 INVITE
  634.    Contact: <sip:1000@192.168.100.31:11000;transport=udp>
  635.    User-Agent: 2600hz
  636.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  637.    Supported: path, replaces
  638.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  639.    Content-Type: application/sdp
  640.    Content-Disposition: session
  641.    Content-Length: 224
  642.    Remote-Party-ID: "Account Admin" <sip:1000@aio.kazoo>;party=calling;privacy=off;screen=no
  643.    
  644.    v=0
  645.    o=FreeSWITCH 1547297677 1547297678 IN IP4 192.168.100.31
  646.    s=FreeSWITCH
  647.    c=IN IP4 192.168.100.31
  648.    t=0 0
  649.    m=audio 21624 RTP/AVP 8 101
  650.    a=rtpmap:8 PCMA/8000
  651.    a=rtpmap:101 telephone-event/8000
  652.    a=fmtp:101 0-16
  653.    a=ptime:20
  654.    ------------------------------------------------------------------------
  655. 2019-01-12 18:55:03.578590 [NOTICE] switch_ivr_bridge.c:766 Channel [sofia/sipinterface_1/athena@aio.kazoo] has been answered
  656. 2019-01-12 18:55:03.578590 [DEBUG] switch_channel.c:3781 (sofia/sipinterface_1/athena@aio.kazoo) Callstate Change EARLY -> ACTIVE
  657. 2019-01-12 18:55:03.578590 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/athena@aio.kazoo entering state [completed][200]
  658. 2019-01-12 18:55:03.578590 [DEBUG] switch_ivr_async.c:1614 No silence detection configured; assuming start of speech
  659. 2019-01-12 18:55:03.578590 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14472
  660. 2019-01-12 18:55:03.578590 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 4771
  661. 2019-01-12 18:55:03.595715 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14413
  662. 2019-01-12 18:55:03.595715 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 4792
  663. 2019-01-12 18:55:03.595715 [DEBUG] switch_rtp.c:7550 Correct audio ip/port confirmed.
  664. recv 616 bytes from udp/[192.168.100.31]:35060 at 12:46:32.639870:
  665.    ------------------------------------------------------------------------
  666.    ACK sip:1000@192.168.100.31:11000;transport=udp SIP/2.0
  667.    Via: SIP/2.0/UDP 192.168.100.31:35060;rport;branch=z9hG4bK735379788
  668.    From: <sip:athena@aio.kazoo>;tag=1939714079
  669.    To: <sip:1000@aio.kazoo>;tag=QyZt1N9DU4KDj
  670.    Call-ID: 828301644
  671.    CSeq: 21 ACK
  672.    Contact: <sip:athena@192.168.100.31:35060>
  673.    Proxy-Authorization: Digest username="athena", realm="aio.kazoo", nonce="c35dbe94-778b-460f-91f9-48a1ba8255f1", uri="sip:1000@aio.kazoo", response="f0c3a81c5a101794f91e10c9a1807f4c", algorithm=MD5, cnonce="0a4f113b", qop=auth, nc=00000001
  674.    Max-Forwards: 70
  675.    User-Agent: Linphone/3.6.1 (eXosip2/3.6.0)
  676.    Content-Length: 0
  677.    
  678.    ------------------------------------------------------------------------
  679. 2019-01-12 18:55:03.615060 [DEBUG] sofia.c:7291 Channel sofia/sipinterface_1/athena@aio.kazoo entering state [ready][200]
  680. 2019-01-12 18:55:03.615060 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14544
  681. 2019-01-12 18:55:03.638286 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 14751
  682. 2019-01-12 18:55:04.125077 [INFO] mod_shout.c:332 LAME 3.99.5 64bits (http://lame.sf.net)
  683. 2019-01-12 18:55:04.125077 [INFO] mod_shout.c:332 polyphase lowpass filter disabled
  684. freeswitch@safarov-dell.home>
  685. 2019-01-12 18:55:04.515083 [DEBUG] switch_rtp.c:7550 Correct audio ip/port confirmed.
  686. 2019-01-12 18:55:04.515083 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMU:0
  687. freeswitch@safarov-dell.home>
  688. freeswitch@safarov-dell.home>
  689. freeswitch@safarov-dell.home>
  690. freeswitch@safarov-dell.home>
  691. freeswitch@safarov-dell.home>
  692. freeswitch@safarov-dell.home>
  693. freeswitch@safarov-dell.home>
  694. freeswitch@safarov-dell.home>
  695. freeswitch@safarov-dell.home>
  696. freeswitch@safarov-dell.home>
  697. freeswitch@safarov-dell.home>
  698. freeswitch@safarov-dell.home>
  699. freeswitch@safarov-dell.home>
  700. freeswitch@safarov-dell.home>
  701. freeswitch@safarov-dell.home>
  702. freeswitch@safarov-dell.home>
  703. freeswitch@safarov-dell.home>
  704. freeswitch@safarov-dell.home>
  705. freeswitch@safarov-dell.home>
  706. freeswitch@safarov-dell.home>
  707. freeswitch@safarov-dell.home>
  708. freeswitch@safarov-dell.home>
  709. freeswitch@safarov-dell.home>
  710. freeswitch@safarov-dell.home>
  711. freeswitch@safarov-dell.home>
  712. freeswitch@safarov-dell.home>
  713. freeswitch@safarov-dell.home>
  714. freeswitch@safarov-dell.home>
  715. freeswitch@safarov-dell.home>
  716. freeswitch@safarov-dell.home>
  717. freeswitch@safarov-dell.home>
  718. freeswitch@safarov-dell.home>
  719. 2019-01-12 18:55:08.035279 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF *:800
  720. 2019-01-12 18:55:08.035279 [INFO] switch_channel.c:515 RECV DTMF *:800
  721. 2019-01-12 18:55:08.035279 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 4349
  722. 2019-01-12 18:55:08.055141 [DEBUG] switch_rtp.c:5424 Send start packet for [*] ts=2112880210 dur=160/160/800 seq=10621 lw=2112880210
  723. 2019-01-12 18:55:08.075075 [DEBUG] switch_rtp.c:5323 Send middle packet for [*] ts=2112880210 dur=320/320/800 seq=10622 lw=2112880370
  724. 2019-01-12 18:55:08.095066 [DEBUG] switch_rtp.c:5323 Send middle packet for [*] ts=2112880210 dur=480/480/800 seq=10623 lw=2112880530
  725. 2019-01-12 18:55:08.115081 [DEBUG] switch_rtp.c:5323 Send middle packet for [*] ts=2112880210 dur=640/640/800 seq=10624 lw=2112880690
  726. 2019-01-12 18:55:08.135074 [DEBUG] switch_rtp.c:5323 Send end packet for [*] ts=2112880210 dur=800/800/800 seq=10625 lw=2112880690
  727. 2019-01-12 18:55:08.135074 [DEBUG] switch_rtp.c:5323 Send end packet for [*] ts=2112880210 dur=800/800/800 seq=10626 lw=2112880690
  728. 2019-01-12 18:55:08.135074 [DEBUG] switch_rtp.c:5323 Send end packet for [*] ts=2112880210 dur=800/800/800 seq=10627 lw=2112880690
  729. 2019-01-12 18:55:08.135074 [DEBUG] switch_rtp.c:5271 Queue digit delay of 40ms
  730. 2019-01-12 18:55:08.575061 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 2:800
  731. 2019-01-12 18:55:08.575061 [INFO] switch_channel.c:515 RECV DTMF 2:800
  732. 2019-01-12 18:55:08.575061 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 4349
  733. 2019-01-12 18:55:08.595104 [DEBUG] switch_rtp.c:5424 Send start packet for [2] ts=2112884370 dur=160/160/800 seq=10646 lw=2112884370
  734. 2019-01-12 18:55:08.615061 [DEBUG] switch_rtp.c:5323 Send middle packet for [2] ts=2112884370 dur=320/320/800 seq=10647 lw=2112884530
  735. 2019-01-12 18:55:08.635094 [DEBUG] switch_rtp.c:5323 Send middle packet for [2] ts=2112884370 dur=480/480/800 seq=10648 lw=2112884690
  736. 2019-01-12 18:55:08.655061 [DEBUG] switch_rtp.c:5323 Send middle packet for [2] ts=2112884370 dur=640/640/800 seq=10649 lw=2112884850
  737. 2019-01-12 18:55:08.675145 [DEBUG] switch_rtp.c:5323 Send end packet for [2] ts=2112884370 dur=800/800/800 seq=10650 lw=2112884850
  738. 2019-01-12 18:55:08.675145 [DEBUG] switch_rtp.c:5323 Send end packet for [2] ts=2112884370 dur=800/800/800 seq=10651 lw=2112884850
  739. 2019-01-12 18:55:08.675145 [DEBUG] switch_rtp.c:5323 Send end packet for [2] ts=2112884370 dur=800/800/800 seq=10652 lw=2112884850
  740. 2019-01-12 18:55:08.675145 [DEBUG] switch_rtp.c:5271 Queue digit delay of 40ms
  741. 2019-01-12 18:55:09.385175 [NOTICE] kazoo_node.c:430 log|828301644|executing record_session_mask ${media_recordings[0]}
  742. 2019-01-12 18:55:09.395081 [DEBUG] switch_ivr.c:625 sofia/sipinterface_1/athena@aio.kazoo Command Execute record_session_mask(${media_recordings[0]})
  743. EXECUTE sofia/sipinterface_1/athena@aio.kazoo record_session_mask()
  744. 2019-01-12 18:55:09.395081 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 12785
  745. 2019-01-12 18:55:09.585128 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  746. 2019-01-12 18:55:09.585128 [INFO] kazoo_node.c:837 exec: uuid_dump(828301644)
  747. 2019-01-12 18:55:09.785194 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  748. freeswitch@safarov-dell.home>
  749. freeswitch@safarov-dell.home>
  750. freeswitch@safarov-dell.home>
  751. freeswitch@safarov-dell.home>
  752. freeswitch@safarov-dell.home>
  753. freeswitch@safarov-dell.home>
  754. recv 344 bytes from udp/[192.168.100.31]:5060 at 12:46:40.438476:
  755.    ------------------------------------------------------------------------
  756.    OPTIONS sip:192.168.100.31:11000 SIP/2.0
  757.    Via: SIP/2.0/UDP 192.168.100.31;branch=z9hG4bK314.f4d36e32000000000000000000000000.0
  758.    To: <sip:192.168.100.31:11000>
  759.    From: <sip:sipcheck@safarov-dell.home>;tag=1f6333e227a91274915eae760737b59b-caf5
  760.    CSeq: 10 OPTIONS
  761.    Call-ID: 196225584a61b070-84@192.168.100.31
  762.    Max-Forwards: 70
  763.    Content-Length: 0
  764.    
  765.    ------------------------------------------------------------------------
  766. send 708 bytes to udp/[192.168.100.31]:5060 at 12:46:40.438843:
  767.    ------------------------------------------------------------------------
  768.    SIP/2.0 200 OK
  769.    Via: SIP/2.0/UDP 192.168.100.31;branch=z9hG4bK314.f4d36e32000000000000000000000000.0
  770.    From: <sip:sipcheck@safarov-dell.home>;tag=1f6333e227a91274915eae760737b59b-caf5
  771.    To: <sip:192.168.100.31:11000>;tag=tSB566UrjZp5m
  772.    Call-ID: 196225584a61b070-84@192.168.100.31
  773.    CSeq: 10 OPTIONS
  774.    Contact: <sip:192.168.100.31:11000>
  775.    User-Agent: 2600hz
  776.    Accept: application/sdp
  777.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  778.    Supported: path, replaces
  779.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  780.    Content-Length: 0
  781.    
  782.    ------------------------------------------------------------------------
  783. 2019-01-12 18:55:13.615113 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF *:800
  784. 2019-01-12 18:55:13.615113 [INFO] switch_channel.c:515 RECV DTMF *:800
  785. 2019-01-12 18:55:13.615113 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 4349
  786. 2019-01-12 18:55:13.635067 [DEBUG] switch_rtp.c:5424 Send start packet for [*] ts=2112923410 dur=160/160/800 seq=10876 lw=2112923410
  787. 2019-01-12 18:55:13.655108 [DEBUG] switch_rtp.c:5323 Send middle packet for [*] ts=2112923410 dur=320/320/800 seq=10877 lw=2112923570
  788. 2019-01-12 18:55:13.675070 [DEBUG] switch_rtp.c:5323 Send middle packet for [*] ts=2112923410 dur=480/480/800 seq=10878 lw=2112923730
  789. 2019-01-12 18:55:13.695080 [DEBUG] switch_rtp.c:5323 Send middle packet for [*] ts=2112923410 dur=640/640/800 seq=10879 lw=2112923890
  790. 2019-01-12 18:55:13.715086 [DEBUG] switch_rtp.c:5323 Send end packet for [*] ts=2112923410 dur=800/800/800 seq=10880 lw=2112923890
  791. 2019-01-12 18:55:13.715086 [DEBUG] switch_rtp.c:5323 Send end packet for [*] ts=2112923410 dur=800/800/800 seq=10881 lw=2112923890
  792. 2019-01-12 18:55:13.715086 [DEBUG] switch_rtp.c:5323 Send end packet for [*] ts=2112923410 dur=800/800/800 seq=10882 lw=2112923890
  793. 2019-01-12 18:55:13.715086 [DEBUG] switch_rtp.c:5271 Queue digit delay of 40ms
  794. 2019-01-12 18:55:14.075183 [DEBUG] switch_rtp.c:7789 RTP RECV DTMF 3:800
  795. 2019-01-12 18:55:14.075183 [INFO] switch_channel.c:515 RECV DTMF 3:800
  796. 2019-01-12 18:55:14.085103 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 4349
  797. 2019-01-12 18:55:14.095084 [DEBUG] switch_rtp.c:5424 Send start packet for [3] ts=2112926930 dur=160/160/800 seq=10901 lw=2112926930
  798. 2019-01-12 18:55:14.115101 [DEBUG] switch_rtp.c:5323 Send middle packet for [3] ts=2112926930 dur=320/320/800 seq=10902 lw=2112927090
  799. 2019-01-12 18:55:14.135091 [DEBUG] switch_rtp.c:5323 Send middle packet for [3] ts=2112926930 dur=480/480/800 seq=10903 lw=2112927250
  800. 2019-01-12 18:55:14.155576 [DEBUG] switch_rtp.c:5323 Send middle packet for [3] ts=2112926930 dur=640/640/800 seq=10904 lw=2112927410
  801. 2019-01-12 18:55:14.175106 [DEBUG] switch_rtp.c:5323 Send end packet for [3] ts=2112926930 dur=800/800/800 seq=10905 lw=2112927410
  802. 2019-01-12 18:55:14.175106 [DEBUG] switch_rtp.c:5323 Send end packet for [3] ts=2112926930 dur=800/800/800 seq=10906 lw=2112927410
  803. 2019-01-12 18:55:14.175106 [DEBUG] switch_rtp.c:5323 Send end packet for [3] ts=2112926930 dur=800/800/800 seq=10907 lw=2112927410
  804. 2019-01-12 18:55:14.175106 [DEBUG] switch_rtp.c:5271 Queue digit delay of 40ms
  805. freeswitch@safarov-dell.home>
  806. 2019-01-12 18:55:14.885099 [NOTICE] kazoo_node.c:430 log|828301644|executing record_session_unmask ${media_recordings[0]}
  807. 2019-01-12 18:55:14.895888 [DEBUG] switch_ivr.c:625 sofia/sipinterface_1/athena@aio.kazoo Command Execute record_session_unmask(${media_recordings[0]})
  808. EXECUTE sofia/sipinterface_1/athena@aio.kazoo record_session_unmask()
  809. 2019-01-12 18:55:14.895888 [DEBUG] kazoo_event_stream.c:244 increased event stream buffer size to 12789
  810. 2019-01-12 18:55:15.085104 [DEBUG] kazoo_node.c:1319 Sent erlang message to ecallmgr@safarov-dell.home <3.6227.1>
  811. freeswitch@safarov-dell.home>