From nevian, 7 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. recv 1094 bytes from udp/[10.23.154.63]:6060 at 12:34:02.546373:
  2.    ------------------------------------------------------------------------
  3.    INVITE sip:62987%23401077@10.23.154.100:6060 SIP/2.0
  4.    Via: SIP/2.0/UDP 10.23.154.63:6060;branch=z9hG4bKe129742e55e6
  5.    From: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>;tag=193729~27154efa-6325-45a2-9e47-67e5d9302ebc-237774854
  6.    To: <sip:62987%23401077@10.23.154.100>
  7.    Date: Fri, 07 Oct 2016 09:34:02 GMT
  8.    Call-ID: 2d3d2680-7f716c0a-c20e-3f40000a@10.23.154.63
  9.    Supported: 100rel,timer,resource-priority,replaces
  10.    Min-SE:  1800
  11.    User-Agent: Cisco-CP7942G/9.3.1
  12.   Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
  13.    CSeq: 101 INVITE
  14.    Expires: 180
  15.    Allow-Events: presence, kpml
  16.    Supported: X-cisco-srtp-fallback,X-cisco-original-called
  17.    Call-Info: <sip:10.23.154.63:6060>;method="NOTIFY;Event=telephone-event;Duration=500"
  18.    Cisco-Guid: 0758982272-0000065536-0000045237-1061158922
  19.    Session-Expires:  1800
  20.    P-Asserted-Identity: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>
  21.    Remote-Party-ID: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>;party=calling;screen=yes;privacy=off
  22.    Contact: <sip:12550@10.23.154.63:6060>
  23.    Max-Forwards: 69
  24.    Content-Length: 0
  25.    
  26.    ------------------------------------------------------------------------
  27. send 407 bytes to udp/[10.23.154.63]:6060 at 12:34:02.546642:
  28.    ------------------------------------------------------------------------
  29.    SIP/2.0 100 Trying
  30.    Via: SIP/2.0/UDP 10.23.154.63:6060;branch=z9hG4bKe129742e55e6
  31.    From: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>;tag=193729~27154efa-6325-45a2-9e47-67e5d9302ebc-237774854
  32.    To: <sip:62987%23401077@10.23.154.100>
  33.    Call-ID: 2d3d2680-7f716c0a-c20e-3f40000a@10.23.154.63
  34.    CSeq: 101 INVITE
  35.    User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20160707T165535Z~be13536ac9~64bit
  36.    Content-Length: 0
  37.    
  38.    ------------------------------------------------------------------------
  39. 2016-10-07 12:34:02.527575 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/12550@10.23.154.63 [2d3d2680-7f716c0a-c20e-3f40000a@10.23.154.63]
  40. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_NEW
  41. 2016-10-07 12:34:02.527575 [DEBUG] sofia.c:9519 sofia/internal/12550@10.23.154.63 receiving invite from 10.23.154.63:6060 version: 1.7.0 git be13536 2016-07-07 16:55:35Z 64bit
  42. 2016-10-07 12:34:02.527575 [DEBUG] sofia.c:9631 IP 10.23.154.63 Approved by acl "internal_unauth[]". Access Granted.
  43. 2016-10-07 12:34:02.527575 [DEBUG] sofia.c:6937 Channel sofia/internal/12550@10.23.154.63 entering state [received][100]
  44. 2016-10-07 12:34:02.527575 [DEBUG] sofia.c:7432 (sofia/internal/12550@10.23.154.63) State Change CS_NEW -> CS_INIT
  45. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/12550@10.23.154.63) State NEW
  46. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_INIT
  47. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/12550@10.23.154.63) State INIT
  48. 2016-10-07 12:34:02.527575 [DEBUG] mod_sofia.c:90 sofia/internal/12550@10.23.154.63 SOFIA INIT
  49. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:40 sofia/internal/12550@10.23.154.63 Standard INIT
  50. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/12550@10.23.154.63) State Change CS_INIT -> CS_ROUTING
  51. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/12550@10.23.154.63) State INIT going to sleep
  52. 2016-10-07 12:34:02.527575 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_ROUTING
  53. 2016-10-07 12:34:02.527575 [DEBUG] switch_channel.c:2249 (sofia/internal/12550@10.23.154.63) Callstate Change DOWN -> RINGING
  54. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/12550@10.23.154.63) State ROUTING
  55. 2016-10-07 12:34:02.547569 [DEBUG] mod_sofia.c:143 sofia/internal/12550@10.23.154.63 SOFIA ROUTING
  56. 2016-10-07 12:34:02.547569 [ERR] mod_xml_radius.c:933 Result of true match: 10.23.154.100 == ^8\.8\.8\.8
  57. 2016-10-07 12:34:02.547569 [INFO] mod_xml_radius.c:986 mod_xml_radius:  Accounting Start success
  58. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:236 sofia/internal/12550@10.23.154.63 Standard ROUTING
  59. 2016-10-07 12:34:02.547569 [INFO] mod_dialplan_xml.c:637 Processing IT, Юрьев Сергей <12550>->62987#401077 in context public
  60. Dialplan: sofia/internal/12550@10.23.154.63 parsing [public->common_variables] continue=true
  61. Dialplan: sofia/internal/12550@10.23.154.63 Absolute Condition [common_variables]
  62. Dialplan: sofia/internal/12550@10.23.154.63 Action set(default_language=en)
  63. Dialplan: sofia/internal/12550@10.23.154.63 parsing [public->call_debug] continue=true
  64. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  65. Dialplan: sofia/internal/12550@10.23.154.63 parsing [public->gateway_inbound] continue=false
  66. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [gateway_inbound] ${target_context}() =~ /^[a-z]/ break=on-false
  67. Dialplan: sofia/internal/12550@10.23.154.63 parsing [public->from_mts-tascom] continue=false
  68. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [from_mts-tascom] network_addr(10.23.154.63) =~ /^82\.204\.25[45]/ break=on-false
  69. Dialplan: sofia/internal/12550@10.23.154.63 parsing [public->from_partner] continue=false
  70. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [from_partner] network_addr(10.23.154.63) =~ /^172\.17\.2\.3$/ break=on-false
  71. Dialplan: sofia/internal/12550@10.23.154.63 parsing [public->from_cucm] continue=false
  72. Dialplan: sofia/internal/12550@10.23.154.63 Regex (PASS) [from_cucm] network_addr(10.23.154.63) =~ /^10\.23\.154\.6[1-6]$/ break=on-false
  73. Dialplan: sofia/internal/12550@10.23.154.63 Action export(suppress_cng=true)
  74. Dialplan: sofia/internal/12550@10.23.154.63 Action transfer(${destination_number} XML internal)
  75. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/12550@10.23.154.63) State Change CS_ROUTING -> CS_EXECUTE
  76. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/12550@10.23.154.63) State ROUTING going to sleep
  77. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_EXECUTE
  78. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/12550@10.23.154.63) State EXECUTE
  79. 2016-10-07 12:34:02.547569 [DEBUG] mod_sofia.c:198 sofia/internal/12550@10.23.154.63 SOFIA EXECUTE
  80. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:328 sofia/internal/12550@10.23.154.63 Standard EXECUTE
  81. EXECUTE sofia/internal/12550@10.23.154.63 set(default_language=en)
  82. 2016-10-07 12:34:02.547569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/12550@10.23.154.63 [default_language]=[en]
  83. EXECUTE sofia/internal/12550@10.23.154.63 export(suppress_cng=true)
  84. 2016-10-07 12:34:02.547569 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [suppress_cng]=[true]
  85. EXECUTE sofia/internal/12550@10.23.154.63 transfer(62987#401077 XML internal)
  86. span style="color: goldenrod; font-weight: bold;"> 2016-10-07 12:34:02.547569 [DEBUG] switch_ivr.c:2160 (sofia/internal/12550@10.23.154.63) State Change CS_EXECUTE -> CS_ROUTING
  87. 2016-10-07 12:34:02.547569 [NOTICE] switch_ivr.c:2167 Transfer sofia/internal/12550@10.23.154.63 to XML[62987#401077@internal]
  88. span style="color: goldenrod; font-weight: bold;"> 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/12550@10.23.154.63) State EXECUTE going to sleep
  89. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_ROUTING
  90. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/12550@10.23.154.63) State ROUTING
  91. 2016-10-07 12:34:02.547569 [DEBUG] mod_sofia.c:143 sofia/internal/12550@10.23.154.63 SOFIA ROUTING
  92. 2016-10-07 12:34:02.547569 [ERR] mod_xml_radius.c:933 Result of true match: 10.23.154.100 == ^8\.8\.8\.8
  93. 2016-10-07 12:34:02.547569 [INFO] mod_xml_radius.c:986 mod_xml_radius:  Accounting Start success
  94. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:236 sofia/internal/12550@10.23.154.63 Standard ROUTING
  95. 2016-10-07 12:34:02.547569 [INFO] mod_dialplan_xml.c:637 Processing IT, Юрьев Сергей <12550>->62987#401077 in context internal
  96. Dialplan: sofia/internal/12550@10.23.154.63 parsing [internal->common_variables] continue=true
  97. Dialplan: sofia/internal/12550@10.23.154.63 Absolute Condition [common_variables]
  98. Dialplan: sofia/internal/12550@10.23.154.63 Action set(default_language=en)
  99. Dialplan: sofia/internal/12550@10.23.154.63 parsing [internal->call_debug] continue=true
  100. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  101. Dialplan: sofia/internal/12550@10.23.154.63 parsing [internal->mts_tascom] continue=false
  102. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [mts_tascom] destination_number(62987#401077) =~ /^(17[0-5]\d\d)$/ break=on-false
  103. Dialplan: sofia/internal/12550@10.23.154.63 parsing [internal->cucm] continue=false
  104. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [cucm] destination_number(62987#401077) =~ /^17[0-5]\d\d$/ break=on-true
  105. Dialplan: sofia/internal/12550@10.23.154.63 Regex (FAIL) [cucm] destination_number(62987#401077) =~ /^(?:1700#)?([1245678]\d{4}$|04\d{2,3}|555)$/ break=on-false
  106. Dialplan: sofia/internal/12550@10.23.154.63 parsing [internal->partner] continue=false
  107. Dialplan: sofia/internal/12550@10.23.154.63 Regex (PASS) [partner] destination_number(62987#401077) =~ /^62987#(\d+)$/ break=on-false
  108. Dialplan: sofia/internal/12550@10.23.154.63 Action set(hangup_after_bridge=true)
  109. Dialplan: sofia/internal/12550@10.23.154.63 Action set(inherit_codec=true)
  110. Dialplan: sofia/internal/12550@10.23.154.63 Action export(origination_callee_id_name=partner)
  111. Dialplan: sofia/internal/12550@10.23.154.63 Action set(effective_caller_id_name=_undef_)
  112. Dialplan: sofia/internal/12550@10.23.154.63 Action bridge(sofia/gateway/partner/401077)
  113. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/12550@10.23.154.63) State Change CS_ROUTING -> CS_EXECUTE
  114. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/12550@10.23.154.63) State ROUTING going to sleep
  115. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_EXECUTE
  116. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/12550@10.23.154.63) State EXECUTE
  117. 2016-10-07 12:34:02.547569 [DEBUG] mod_sofia.c:198 sofia/internal/12550@10.23.154.63 SOFIA EXECUTE
  118. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:328 sofia/internal/12550@10.23.154.63 Standard EXECUTE
  119. EXECUTE sofia/internal/12550@10.23.154.63 set(default_language=en)
  120. 2016-10-07 12:34:02.547569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/12550@10.23.154.63 [default_language]=[en]
  121. EXECUTE sofia/internal/12550@10.23.154.63 set(hangup_after_bridge=true)
  122. 2016-10-07 12:34:02.547569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/12550@10.23.154.63 [hangup_after_bridge]=[true]
  123. EXECUTE sofia/internal/12550@10.23.154.63 set(inherit_codec=true)
  124. 2016-10-07 12:34:02.547569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/12550@10.23.154.63 [inherit_codec]=[true]
  125. EXECUTE sofia/internal/12550@10.23.154.63 export(origination_callee_id_name=partner)
  126. 2016-10-07 12:34:02.547569 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[partner]
  127. EXECUTE sofia/internal/12550@10.23.154.63 set(effective_caller_id_name=_undef_)
  128. 2016-10-07 12:34:02.547569 [DEBUG] mod_dptools.c:1519 SET sofia/internal/12550@10.23.154.63 [effective_caller_id_name]=[_undef_]
  129. EXECUTE sofia/internal/12550@10.23.154.63 bridge(sofia/gateway/partner/401077)
  130. 2016-10-07 12:34:02.547569 [DEBUG] switch_channel.c:1250 sofia/internal/12550@10.23.154.63 EXPORTING[export_vars] [suppress_cng]=[true] to event
  131. 2016-10-07 12:34:02.547569 [DEBUG] switch_channel.c:1250 sofia/internal/12550@10.23.154.63 EXPORTING[export_vars] [origination_callee_id_name]=[partner] to event
  132. 2016-10-07 12:34:02.547569 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
  133. 2016-10-07 12:34:02.547569 [NOTICE] switch_channel.c:1104 New Channel sofia/external/401077 [7ae98307-febf-4184-b5aa-9ed8efbeb0df]
  134. 2016-10-07 12:34:02.547569 [DEBUG] mod_sofia.c:4758 (sofia/external/401077) State Change CS_NEW -> CS_INIT
  135. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:543 (sofia/external/401077) Running State Change CS_INIT
  136. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:586 (sofia/external/401077) State INIT
  137. 2016-10-07 12:34:02.547569 [DEBUG] mod_sofia.c:90 sofia/external/401077 SOFIA INIT
  138. 2016-10-07 12:34:02.547569 [DEBUG] sofia_glue.c:1249 sofia/external/401077 sending invite version: 1.7.0 git be13536 2016-07-07 16:55:35Z 64bit
  139. Local SDP:
  140. v=0
  141. o=FreeSWITCH 1475802844 1475802845 IN IP4 83.y.y.y
  142. s=FreeSWITCH
  143. c=IN IP4 83.y.y.y
  144. t=0 0
  145. m=audio 29998 RTP/AVP 18 8 0 102 3 101
  146. a=rtpmap:18 G729/8000
  147. a=rtpmap:8 PCMA/8000
  148. a=rtpmap:0 PCMU/8000
  149. a=rtpmap:102 iLBC/8000
  150. a=fmtp:102 mode=30
  151. a=rtpmap:3 GSM/8000
  152. a=rtpmap:101 telephone-event/8000
  153. a=fmtp:101 0-16
  154. a=ptime:20
  155. a=sendrecv
  156.  
  157. send 1107 bytes to tcp/[172.17.2.3]:6060 at 12:34:02.556030:
  158.    ------------------------------------------------------------------------
  159.    INVITE sip:401077@172.17.2.3:6060;transport=tcp SIP/2.0
  160.    Via: SIP/2.0/TCP 83.y.y.y:6060;rport;branch=z9hG4bKc8Ht2Kp31H71K
  161.    Max-Forwards: 67
  162.    From: <sip:12550@83.y.y.y>;tag=7yF4v9SvF0KNK
  163.    To: <sip:401077@172.17.2.3:6060>
  164.    Call-ID: 0628366d-0714-1235-a38f-00505692d797
  165.    CSeq: 97580357 INVITE
  166.    Contact: <sip:gw+partner@83.y.y.y:6060;tport=tcp;transport=tcp;gw=partner>
  167.    User-Agent: ES FS SBC
  168.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, NOTIFY
  169.    Supported: timer, path, replaces
  170.    Allow-Events: talk, hold, conference, refer
  171.    Content-Type: application/sdp
  172.    Content-Disposition: session
  173.    Content-Length: 345
  174.    X-FS-Support: update_display,send_info
  175.    Remote-Party-ID: <sip:12550@83.y.y.y>;party=calling;screen=yes;privacy=off
  176.    
  177.    v=0
  178.    o=FreeSWITCH 1475802844 1475802845 IN IP4 83.y.y.y
  179.    s=FreeSWITCH
  180.    c=IN IP4 83.y.y.y
  181.    t=0 0
  182.    m=audio 29998 RTP/AVP 18 8 0 102 3 101
  183.    a=rtpmap:18 G729/8000
  184.    a=rtpmap:8 PCMA/8000
  185.    a=rtpmap:0 PCMU/8000
  186.    a=rtpmap:102 iLBC/8000
  187.    a=fmtp:102 mode=30
  188.    a=rtpmap:3 GSM/8000
  189.    a=rtpmap:101 telephone-event/8000
  190.    a=fmtp:101 0-16
  191.    a=ptime:20
  192.    ------------------------------------------------------------------------
  193. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:40 sofia/external/401077 Standard INIT
  194. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:48 (sofia/external/401077) State Change CS_INIT -> CS_ROUTING
  195. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:586 (sofia/external/401077) State INIT going to sleep
  196. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:543 (sofia/external/401077) Running State Change CS_ROUTING
  197. 2016-10-07 12:34:02.547569 [DEBUG] sofia.c:6937 Channel sofia/external/401077 entering state [calling][0]
  198. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:602 (sofia/external/401077) State ROUTING
  199. 2016-10-07 12:34:02.547569 [DEBUG] mod_sofia.c:143 sofia/external/401077 SOFIA ROUTING
  200. 2016-10-07 12:34:02.547569 [DEBUG] switch_ivr_originate.c:67 (sofia/external/401077) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  201. 2016-10-07 12:34:02.547569 [ERR] mod_xml_radius.c:933 Result of true match: 172.17.2.3:6060 == ^8\.8\.8\.8
  202. 2016-10-07 12:34:02.547569 [INFO] mod_xml_radius.c:986 mod_xml_radius:  Accounting Start success
  203. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:602 (sofia/external/401077) State ROUTING going to sleep
  204. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:543 (sofia/external/401077) Running State Change CS_CONSUME_MEDIA
  205. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:621 (sofia/external/401077) State CONSUME_MEDIA
  206. 2016-10-07 12:34:02.547569 [DEBUG] switch_core_state_machine.c:621 (sofia/external/401077) State CONSUME_MEDIA going to sleep
  207. recv 302 bytes from tcp/[172.17.2.3]:6060 at 12:34:02.573853:
  208.    ------------------------------------------------------------------------
  209.    SIP/2.0 100 Trying
  210.    From: <sip:12550@83.y.y.y>;tag=7yF4v9SvF0KNK
  211.    To: <sip:401077@172.17.2.3:6060>
  212.    Call-ID: 0628366d-0714-1235-a38f-00505692d797
  213.    CSeq: 97580357 INVITE
  214.    Via: SIP/2.0/TCP 83.y.y.y:6060;branch=z9hG4bKc8Ht2Kp31H71K
  215.    Server: Avaya CM/R016x.03.0.124.0
  216.    Content-Length:     0
  217.    
  218.    ------------------------------------------------------------------------
  219. recv 769 bytes from tcp/[172.17.2.3]:6060 at 12:34:02.578066:
  220.    ------------------------------------------------------------------------
  221.    SIP/2.0 180 Ringing
  222.    From: <sip:12550@83.y.y.y>;tag=7yF4v9SvF0KNK
  223.    To: <sip:401077@172.17.2.3>;tag=06c11229d9ee614675724fb1600
  224.    Call-ID: 0628366d-0714-1235-a38f-00505692d797
  225.    CSeq: 97580357 INVITE
  226.    Via: SIP/2.0/TCP 83.y.y.y:6060;branch=z9hG4bKc8Ht2Kp31H71K
  227.    Supported: histinfo,join,replaces,sdp-anat,timer
  228.   Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,INFO,UPDATE
  229.    Contact: <sip:172.17.2.3:6060;transport=tcp>
  230.    Accept-Language: uk
  231.    Record-Route: <sip:172.17.2.3:6060;transport=tcp;lr>
  232.    Server: Avaya CM/R016x.03.0.124.0
  233.    Content-Type: application/sdp
  234.    Content-Length:   180
  235.    
  236.    v=0
  237.    o=- 1475832842 2 IN IP4 172.17.2.3
  238.    s=-
  239.    c=IN IP4 172.17.2.4
  240.    b=AS:64
  241.    t=0 0
  242.    m=audio 2308 RTP/AVP 8 101
  243.    a=rtpmap:8 PCMA/8000
  244.    a=rtpmap:101 telephone-event/8000
  245.    a=ptime:20
  246.    ------------------------------------------------------------------------
  247. 2016-10-07 12:34:02.567566 [DEBUG] sofia.c:6937 Channel sofia/external/401077 entering state [proceeding][180]
  248. 2016-10-07 12:34:02.567566 [DEBUG] sofia.c:6947 Remote SDP:
  249. v=0
  250. o=- 1475832842 2 IN IP4 172.17.2.3
  251. s=-
  252. c=IN IP4 172.17.2.4
  253. b=AS:64
  254. t=0 0
  255. m=audio 2308 RTP/AVP 8 101
  256. a=rtpmap:8 PCMA/8000
  257. a=rtpmap:101 telephone-event/8000
  258. a=ptime:20
  259.  
  260. recv 946 bytes from tcp/[172.17.2.3]:6060 at 12:34:05.214055:
  261.    ------------------------------------------------------------------------
  262.    SIP/2.0 200 OK
  263.    From: <sip:12550@83.y.y.y>;tag=7yF4v9SvF0KNK
  264.    To: <sip:401077@172.17.2.3>;tag=06c11229d9ee614675724fb1600
  265.    Call-ID: 0628366d-0714-1235-a38f-00505692d797
  266.    CSeq: 97580357 INVITE
  267.    Via: SIP/2.0/TCP 83.y.y.y:6060;branch=z9hG4bKc8Ht2Kp31H71K
  268.    Supported: histinfo,join,replaces,sdp-anat,timer
  269.   Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,INFO,UPDATE
  270.    Contact: "Unk" <sip:401077@172.17.2.3:6060;transport=tcp>
  271.    Accept-Language: uk
  272.    P-Asserted-Identity: "Unk" <sip:401077@invalid.unknown.domain>
  273.    Record-Route: <sip:172.17.2.3:6060;transport=tcp;lr>
  274.    Require: timer
  275.    Server: Avaya CM/R016x.03.0.124.0
  276.    Session-Expires: 1200;refresher=uas
  277.    Content-Type: application/sdp
  278.    Content-Length:   180
  279.    
  280.    v=0
  281.    o=- 1475832842 2 IN IP4 172.17.2.3
  282.    s=-
  283.    c=IN IP4 172.17.2.4
  284.    b=AS:64
  285.    t=0 0
  286.    m=audio 2308 RTP/AVP 8 101
  287.    a=rtpmap:8 PCMA/8000
  288.    a=rtpmap:101 telephone-event/8000
  289.    a=ptime:20
  290.    ------------------------------------------------------------------------
  291. 2016-10-07 12:34:05.207572 [INFO] sofia.c:1255 sofia/external/401077 Update Callee ID to "Unk" <401077>
  292. 2016-10-07 12:34:05.207572 [DEBUG] sofia.c:6937 Channel sofia/external/401077 entering state [completing][200]
  293. 2016-10-07 12:34:05.207572 [DEBUG] sofia.c:6944 Duplicate SDP
  294. v=0
  295. o=- 1475832842 2 IN IP4 172.17.2.3
  296. s=-
  297. c=IN IP4 172.17.2.4
  298. b=AS:64
  299. t=0 0
  300. m=audio 2308 RTP/AVP 8 101
  301. a=rtpmap:8 PCMA/8000
  302. a=rtpmap:101 telephone-event/8000
  303. a=ptime:20
  304.  
  305. send 475 bytes to tcp/[172.17.2.3]:6060 at 12:34:05.214933:
  306.    ------------------------------------------------------------------------
  307.    ACK sip:401077@172.17.2.3:6060;transport=tcp SIP/2.0
  308.    Via: SIP/2.0/TCP 83.y.y.y:6060;rport;branch=z9hG4bKDHBK4e76ytXmF
  309.    Route: <sip:172.17.2.3:6060;transport=tcp;lr>
  310.    Max-Forwards: 70
  311.    From: <sip:12550@83.y.y.y>;tag=7yF4v9SvF0KNK
  312.    To: <sip:401077@172.17.2.3:6060>;tag=06c11229d9ee614675724fb1600
  313.    Call-ID: 0628366d-0714-1235-a38f-00505692d797
  314.    CSeq: 97580357 ACK
  315.    Contact: <sip:gw+partner@83.y.y.y:6060;tport=tcp;transport=tcp;gw=partner>
  316.    Content-Length: 0
  317.    
  318.    ------------------------------------------------------------------------
  319. 2016-10-07 12:34:05.207572 [DEBUG] sofia.c:6937 Channel sofia/external/401077 entering state [ready][200]
  320. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4373 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
  321. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4373 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  322. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4428 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  323. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4373 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  324. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4373 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[iLBC:97:8000:30:13330:1]
  325. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4373 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
  326. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4289 Set telephone-event payload to 101@8000
  327. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:3086 Set Codec sofia/external/401077 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  328. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_codec.c:111 sofia/external/401077 Original read codec set to PCMA:8
  329. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4642 Set telephone-event payload to 101@8000
  330. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:4701 sofia/external/401077 Set 2833 dtmf send payload to 101 recv payload to 101
  331. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:6508 AUDIO RTP [sofia/external/401077] 83.y.y.y port 29998 -> 172.17.2.4 port 2308 codec: 8 ms: 20
  332. 2016-10-07 12:34:05.207572 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  333. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:6807 sofia/external/401077 Set 2833 dtmf send payload to 101
  334. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:6814 sofia/external/401077 Set 2833 dtmf receive payload to 101
  335. 2016-10-07 12:34:05.207572 [DEBUG] switch_core_media.c:6837 sofia/external/401077 Set rtp dtmf delay to 40
  336. 2016-10-07 12:34:05.207572 [NOTICE] sofia.c:7969 Channel [sofia/external/401077] has been answered
  337. 2016-10-07 12:34:05.207572 [DEBUG] switch_channel.c:3770 (sofia/external/401077) Callstate Change DOWN -> ACTIVE
  338. 2016-10-07 12:34:05.207572 [DEBUG] switch_ivr_originate.c:410 Setting codec string on sofia/internal/12550@10.23.154.63 to PCMA@8000h@20i
  339. send 966 bytes to udp/[10.23.154.63]:6060 at 12:34:05.223126:
  340.    ------------------------------------------------------------------------
  341.    SIP/2.0 200 OK
  342.    Via: SIP/2.0/UDP 10.23.154.63:6060;branch=z9hG4bKe129742e55e6
  343.    From: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>;tag=193729~27154efa-6325-45a2-9e47-67e5d9302ebc-237774854
  344.    To: <sip:62987%23401077@10.23.154.100>;tag=01pQ6Fe4jj5rQ
  345.    Call-ID: 2d3d2680-7f716c0a-c20e-3f40000a@10.23.154.63
  346.    CSeq: 101 INVITE
  347.    Contact: <sip:mod_sofia@10.23.154.100:6060>
  348.    User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20160707T165535Z~be13536ac9~64bit
  349.    Accept: application/sdp
  350.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, PRACK, NOTIFY
  351.    Require: timer
  352.    Supported: precondition, 100rel, timer, path, replaces
  353.    Allow-Events: talk, hold, conference, refer
  354.    Session-Expires: 1800;refresher=uac
  355.    Content-Type: application/sdp
  356.    Content-Disposition: session
  357.    Content-Length: 180
  358.    
  359.    v=0
  360.    o=- 1475832842 2 IN IP4 172.17.2.3
  361.    s=-
  362.    c=IN IP4 172.17.2.4
  363.    b=AS:64
  364.    t=0 0
  365.    m=audio 2308 RTP/AVP 8 101
  366.    a=rtpmap:8 PCMA/8000
  367.    a=rtpmap:101 telephone-event/8000
  368.    a=ptime:20
  369.    ------------------------------------------------------------------------
  370. 2016-10-07 12:34:05.207572 [DEBUG] mod_sofia.c:762 3PCC-PROXY, Sent a 200 OK, waiting for ACK
  371. 2016-10-07 12:34:05.207572 [DEBUG] sofia.c:6937 Channel sofia/internal/12550@10.23.154.63 entering state [completed][200]
  372. recv 706 bytes from udp/[10.23.154.63]:6060 at 12:34:05.226757:
  373.    ------------------------------------------------------------------------
  374.    ACK sip:mod_sofia@10.23.154.100:6060 SIP/2.0
  375.    Via: SIP/2.0/UDP 10.23.154.63:6060;branch=z9hG4bKe12a126dba3
  376.    From: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>;tag=193729~27154efa-6325-45a2-9e47-67e5d9302ebc-237774854
  377.    To: <sip:62987%23401077@10.23.154.100>;tag=01pQ6Fe4jj5rQ
  378.    Date: Fri, 07 Oct 2016 09:34:02 GMT
  379.    Call-ID: 2d3d2680-7f716c0a-c20e-3f40000a@10.23.154.63
  380.    Max-Forwards: 70
  381.    CSeq: 101 ACK
  382.    Allow-Events: presence, kpml
  383.    Content-Type: application/sdp
  384.    Content-Length: 221
  385.    
  386.    v=0
  387.    o=CiscoSystemsCCM-SIP 193729 1 IN IP4 10.23.154.63
  388.    s=SIP Call
  389.    c=IN IP4 10.228.8.167
  390.    b=AS:64
  391.    t=0 0
  392.    m=audio 17284 RTP/AVP 8 101
  393.    a=rtpmap:8 PCMA/8000
  394.    a=ptime:20
  395.    a=rtpmap:101 telephone-event/8000
  396.    a=fmtp:101 0-15
  397.    ------------------------------------------------------------------------
  398. 2016-10-07 12:34:05.227567 [DEBUG] sofia.c:6937 Channel sofia/internal/12550@10.23.154.63 entering state [ready][200]
  399. 2016-10-07 12:34:05.227567 [DEBUG] sofia.c:6947 Remote SDP:
  400. v=0
  401. o=CiscoSystemsCCM-SIP 193729 1 IN IP4 10.23.154.63
  402. s=SIP Call
  403. c=IN IP4 10.228.8.167
  404. b=AS:64
  405. t=0 0
  406. m=audio 17284 RTP/AVP 8 101
  407. a=rtpmap:8 PCMA/8000
  408. a=rtpmap:101 telephone-event/8000
  409. a=fmtp:101 0-15
  410. a=ptime:20
  411.  
  412. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:4373 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  413. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:4428 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  414. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:4289 Set telephone-event payload to 101@8000
  415. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:3086 Set Codec sofia/internal/12550@10.23.154.63 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  416. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_codec.c:111 sofia/internal/12550@10.23.154.63 Original read codec set to PCMA:8
  417. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:4642 Set telephone-event payload to 101@8000
  418. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:4701 sofia/internal/12550@10.23.154.63 Set 2833 dtmf send payload to 101 recv payload to 101
  419. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:6508 AUDIO RTP [sofia/internal/12550@10.23.154.63] 10.23.154.100 port 29956 -> 10.228.8.167 port 17284 codec: 8 ms: 20
  420. 2016-10-07 12:34:05.227567 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
  421. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:6807 sofia/internal/12550@10.23.154.63 Set 2833 dtmf send payload to 101
  422. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:6814 sofia/internal/12550@10.23.154.63 Set 2833 dtmf receive payload to 101
  423. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_media.c:6837 sofia/internal/12550@10.23.154.63 Set rtp dtmf delay to 40
  424. 2016-10-07 12:34:05.227567 [NOTICE] sofia.c:7969 Channel [sofia/internal/12550@10.23.154.63] has been answered
  425. 2016-10-07 12:34:05.227567 [DEBUG] switch_channel.c:3770 (sofia/internal/12550@10.23.154.63) Callstate Change RINGING -> ACTIVE
  426. 2016-10-07 12:34:05.227567 [DEBUG] sofia.c:7978 3PCC-PROXY, Got my ACK
  427. 2016-10-07 12:34:05.227567 [DEBUG] mod_sofia.c:780 3PCC-PROXY, Done waiting for ACK
  428. 2016-10-07 12:34:05.227567 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/external/401077]
  429. 2016-10-07 12:34:05.227567 [DEBUG] switch_ivr_bridge.c:1599 (sofia/external/401077) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  430. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_state_machine.c:543 (sofia/external/401077) Running State Change CS_EXCHANGE_MEDIA
  431. 2016-10-07 12:34:05.227567 [DEBUG] switch_core_state_machine.c:612 (sofia/external/401077) State EXCHANGE_MEDIA
  432. 2016-10-07 12:34:05.227567 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
  433. 2016-10-07 12:34:05.267571 [DEBUG] switch_rtp.c:6711 Correct audio ip/port confirmed.
  434. recv 555 bytes from udp/[10.23.154.63]:6060 at 12:34:12.247720:
  435.    ------------------------------------------------------------------------
  436.    BYE sip:mod_sofia@10.23.154.100:6060 SIP/2.0
  437.    Via: SIP/2.0/UDP 10.23.154.63:6060;branch=z9hG4bKe12c62a97be8
  438.    From: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>;tag=193729~27154efa-6325-45a2-9e47-67e5d9302ebc-237774854
  439.    To: <sip:62987%23401077@10.23.154.100>;tag=01pQ6Fe4jj5rQ
  440.    Date: Fri, 07 Oct 2016 09:34:02 GMT
  441.    Call-ID: 2d3d2680-7f716c0a-c20e-3f40000a@10.23.154.63
  442.    User-Agent: Cisco-CP7942G/9.3.1
  443.    Max-Forwards: 70
  444.    P-Asserted-Identity: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>
  445.    CSeq: 102 BYE
  446.    Reason: Q.850;cause=16
  447.    Content-Length: 0
  448.    
  449.    ------------------------------------------------------------------------
  450. 2016-10-07 12:34:12.247582 [NOTICE] sofia.c:988 Hangup sofia/internal/12550@10.23.154.63 [CS_EXECUTE] [NORMAL_CLEARING]
  451. send 554 bytes to udp/[10.23.154.63]:6060 at 12:34:12.250153:
  452.    ------------------------------------------------------------------------
  453.    SIP/2.0 200 OK
  454.    Via: SIP/2.0/UDP 10.23.154.63:6060;branch=z9hG4bKe12c62a97be8
  455.    From: "IT, Юрьев Сергей" <sip:12550@10.23.154.63>;tag=193729~27154efa-6325-45a2-9e47-67e5d9302ebc-237774854
  456.    To: <sip:62987%23401077@10.23.154.100>;tag=01pQ6Fe4jj5rQ
  457.    Call-ID: 2d3d2680-7f716c0a-c20e-3f40000a@10.23.154.63
  458.    CSeq: 102 BYE
  459.    User-Agent: FreeSWITCH-mod_sofia/1.7.0+git~20160707T165535Z~be13536ac9~64bit
  460.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, PRACK, NOTIFY
  461.    Supported: precondition, 100rel, timer, path, replaces
  462.    Content-Length: 0
  463.    
  464.    ------------------------------------------------------------------------
  465. 2016-10-07 12:34:12.247582 [DEBUG] switch_ivr_bridge.c:785 BRIDGE THREAD DONE [sofia/internal/12550@10.23.154.63]
  466. 2016-10-07 12:34:12.247582 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/12550@10.23.154.63 ending bridge by request from write function
  467. 2016-10-07 12:34:12.247582 [DEBUG] switch_ivr_bridge.c:785 BRIDGE THREAD DONE [sofia/external/401077]
  468. 2016-10-07 12:34:12.247582 [NOTICE] switch_ivr_bridge.c:889 Hangup sofia/external/401077 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  469. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:612 (sofia/external/401077) State EXCHANGE_MEDIA going to sleep
  470. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:543 (sofia/external/401077) Running State Change CS_HANGUP
  471. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:809 (sofia/external/401077) Callstate Change ACTIVE -> HANGUP
  472. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:811 (sofia/external/401077) State HANGUP
  473. 2016-10-07 12:34:12.247582 [DEBUG] mod_sofia.c:432 sofia/external/401077 Overriding SIP cause 480 with 200 from the other leg
  474. 2016-10-07 12:34:12.247582 [DEBUG] mod_sofia.c:438 Channel sofia/external/401077 hanging up, cause: NORMAL_CLEARING
  475. 2016-10-07 12:34:12.247582 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/401077
  476. send 551 bytes to tcp/[172.17.2.3]:6060 at 12:34:12.256689:
  477.    ------------------------------------------------------------------------
  478.    BYE sip:401077@172.17.2.3:6060;transport=tcp SIP/2.0
  479.    Via: SIP/2.0/TCP 83.y.y.y:6060;rport;branch=z9hG4bKet4B69Qav3K7a
  480.    Route: <sip:172.17.2.3:6060;transport=tcp;lr>
  481.    Max-Forwards: 70
  482.    From: <sip:12550@83.y.y.y>;tag=7yF4v9SvF0KNK
  483.    To: <sip:401077@172.17.2.3:6060>;tag=06c11229d9ee614675724fb1600
  484.    Call-ID: 0628366d-0714-1235-a38f-00505692d797
  485.    CSeq: 97580358 BYE
  486.    User-Agent: ES FS SBC
  487.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, NOTIFY
  488.    Supported: timer, path, replaces
  489.    Reason: Q.850;cause=16
  490.    Content-Length: 0
  491.    
  492.    ------------------------------------------------------------------------
  493. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:60 sofia/external/401077 Standard HANGUP, cause: NORMAL_CLEARING
  494. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:811 (sofia/external/401077) State HANGUP going to sleep
  495. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:578 (sofia/external/401077) State Change CS_HANGUP -> CS_REPORTING
  496. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:543 (sofia/external/401077) Running State Change CS_REPORTING
  497. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:897 (sofia/external/401077) State REPORTING
  498. 2016-10-07 12:34:12.247582 [ERR] mod_xml_radius.c:933 Result of true match: 172.17.2.3 == ^8\.8\.8\.8
  499. 2016-10-07 12:34:12.247582 [DEBUG] switch_ivr_bridge.c:1697 sofia/external/401077 skip receive message [UNBRIDGE] (channel is hungup already)
  500. 2016-10-07 12:34:12.247582 [DEBUG] switch_ivr_bridge.c:1700 sofia/internal/12550@10.23.154.63 skip receive message [UNBRIDGE] (channel is hungup already)
  501. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_session.c:2797 sofia/internal/12550@10.23.154.63 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  502. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/12550@10.23.154.63) State EXECUTE going to sleep
  503. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_HANGUP
  504. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/12550@10.23.154.63) Callstate Change ACTIVE -> HANGUP
  505. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/12550@10.23.154.63) State HANGUP
  506. 2016-10-07 12:34:12.247582 [DEBUG] mod_sofia.c:438 Channel sofia/internal/12550@10.23.154.63 hanging up, cause: NORMAL_CLEARING
  507. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:60 sofia/internal/12550@10.23.154.63 Standard HANGUP, cause: NORMAL_CLEARING
  508. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/12550@10.23.154.63) State HANGUP going to sleep
  509. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/12550@10.23.154.63) State Change CS_HANGUP -> CS_REPORTING
  510. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/12550@10.23.154.63) Running State Change CS_REPORTING
  511. 2016-10-07 12:34:12.247582 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/12550@10.23.154.63) State REPORTING
  512. 2016-10-07 12:34:12.247582 [ERR] mod_xml_radius.c:933 Result of true match: 10.23.154.100 == ^8\.8\.8\.8
  513. 2016-10-07 12:34:12.247582 [INFO] mod_xml_radius.c:1044 mod_xml_radius:  Accounting Stop success
  514. 2016-10-07 12:34:12.247582 [INFO] mod_xml_radius.c:1044 mod_xml_radius:  Accounting Stop success
  515. recv 327 bytes from tcp/[172.17.2.3]:6060 at 12:34:12.292046:
  516.    ------------------------------------------------------------------------
  517.    SIP/2.0 200 OK
  518.    From: <sip:12550@83.y.y.y>;tag=7yF4v9SvF0KNK
  519.    To: <sip:401077@172.17.2.3:6060>;tag=06c11229d9ee614675724fb1600
  520.    Call-ID: 0628366d-0714-1235-a38f-00505692d797
  521.    CSeq: 97580358 BYE
  522.    Via: SIP/2.0/TCP 83.y.y.y:6060;branch=z9hG4bKet4B69Qav3K7a
  523.    Server: Avaya CM/R016x.03.0.124.0
  524.    Content-Length:     0
  525.    
  526.    ------------------------------------------------------------------------
  527. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_state_machine.c:174 sofia/external/401077 Standard REPORTING, cause: NORMAL_CLEARING
  528. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_state_machine.c:897 (sofia/external/401077) State REPORTING going to sleep
  529. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_state_machine.c:569 (sofia/external/401077) State Change CS_REPORTING -> CS_DESTROY
  530. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_session.c:1647 Session 8722 (sofia/external/401077) Locked, Waiting on external entities
  531. 2016-10-07 12:34:12.327578 [NOTICE] switch_core_session.c:1665 Session 8722 (sofia/external/401077) Ended
  532. 2016-10-07 12:34:12.327578 [NOTICE] switch_core_session.c:1669 Close Channel sofia/external/401077 [CS_DESTROY]
  533. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_state_machine.c:700 (sofia/external/401077) Running State Change CS_DESTROY
  534. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_state_machine.c:710 (sofia/external/401077) State DESTROY
  535. 2016-10-07 12:34:12.327578 [DEBUG] mod_sofia.c:343 sofia/external/401077 SOFIA DESTROY
  536. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_state_machine.c:181 sofia/external/401077 Standard DESTROY
  537. 2016-10-07 12:34:12.327578 [DEBUG] switch_core_state_machine.c:710 (sofia/external/401077) State DESTROY going to sleep
  538. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_state_machine.c:174 sofia/internal/12550@10.23.154.63 Standard REPORTING, cause: NORMAL_CLEARING
  539. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/12550@10.23.154.63) State REPORTING going to sleep
  540. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/12550@10.23.154.63) State Change CS_REPORTING -> CS_DESTROY
  541. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_session.c:1647 Session 8721 (sofia/internal/12550@10.23.154.63) Locked, Waiting on external entities
  542. 2016-10-07 12:34:12.367587 [NOTICE] switch_core_session.c:1665 Session 8721 (sofia/internal/12550@10.23.154.63) Ended
  543. 2016-10-07 12:34:12.367587 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/12550@10.23.154.63 [CS_DESTROY]
  544. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/12550@10.23.154.63) Running State Change CS_DESTROY
  545. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/12550@10.23.154.63) State DESTROY
  546. 2016-10-07 12:34:12.367587 [DEBUG] mod_sofia.c:343 sofia/internal/12550@10.23.154.63 SOFIA DESTROY
  547. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_state_machine.c:181 sofia/internal/12550@10.23.154.63 Standard DESTROY
  548. 2016-10-07 12:34:12.367587 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/12550@10.23.154.63) State DESTROY going to sleep
  549.