From jungle-boogie, 6 Years ago, written in FreeSWITCH.
- go back
Embed
Viewing differences between and google voice with sip trace enabled
  1. +OK Global siptrace on
  2. recv 739 bytes from tcp/[45.55.163.124]:5060 at 22:11:16.771020:
  3.    ------------------------------------------------------------------------
  4.    INVITE sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW SIP/2.0
  5.    Max-Forwards: 19
  6.    Via: SIP/2.0/TCP 45.55.163.124:5060;alias;rport;branch=z9hG4bK1059959625
  7.    From: "TULSA, OK" <sip:9185330000@45.55.163.124>;tag=916891763
  8.    To: <sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW>
  9.    Call-ID: 1538561599@45.55.163.124
  10.    CSeq: 644 INVITE
  11.    User-Agent: GVGW
  12.    Contact: <sip:9185330000@45.55.163.124:5060>
  13.   Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO
  14.    Content-Type: application/sdp
  15.    Content-Length: 208
  16.  
  17.    v=0
  18.    o=yate 1501391476 1501391476 IN IP4 45.55.163.124
  19.    s=SIP Call
  20.    c=IN IP4 45.55.163.124
  21.    t=0 0
  22.    m=audio 28740 RTP/AVP 0 3 101
  23.    a=rtpmap:0 PCMU/8000
  24.    a=rtpmap:3 GSM/8000
  25.    a=rtpmap:101 telephone-event/8000
  26.    ------------------------------------------------------------------------
  27. 2017-07-29 22:11:16.762439 [NOTICE] switch_channel.c:1104 New Channel sofia/external/9185330000@45.55.163.124 [83ec6834-74e5-11e7-b772-c1f435f54e69]
  28. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_NEW (Cur 1 Tot 182)
  29. 2017-07-29 22:11:16.762439 [DEBUG] sofia.c:10067 sofia/external/9185330000@45.55.163.124 receiving invite from 45.55.163.124:5060 version: 1.9.0 git 144d373 2017-07-28 23:05:50Z 32bit
  30. 2017-07-29 22:11:16.762439 [DEBUG] sofia.c:7283 Channel sofia/external/9185330000@45.55.163.124 entering state [received][100]
  31. 2017-07-29 22:11:16.762439 [DEBUG] sofia.c:7293 Remote SDP:
  32. v=0
  33. o=yate 1501391476 1501391476 IN IP4 45.55.163.124
  34. s=SIP Call
  35. c=IN IP4 45.55.163.124
  36. t=0 0
  37. m=audio 28740 RTP/AVP 0 3 101
  38. a=rtpmap:0 PCMU/8000
  39. a=rtpmap:3 GSM/8000
  40. a=rtpmap:101 telephone-event/8000
  41.  
  42. 2017-07-29 22:11:16.762439 [DEBUG] sofia.c:7685 (sofia/external/9185330000@45.55.163.124) State Change CS_NEW -> CS_INIT
  43. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:603 (sofia/external/9185330000@45.55.163.124) State NEW
  44. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_INIT (Cur 1 Tot 182)
  45. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:627 (sofia/external/9185330000@45.55.163.124) State INIT
  46. 2017-07-29 22:11:16.762439 [DEBUG] mod_sofia.c:93 sofia/external/9185330000@45.55.163.124 SOFIA INIT
  47. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:40 sofia/external/9185330000@45.55.163.124 Standard INIT
  48. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:48 (sofia/external/9185330000@45.55.163.124) State Change CS_INIT -> CS_ROUTING
  49. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:627 (sofia/external/9185330000@45.55.163.124) State INIT going to sleep
  50. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_ROUTING (Cur 1 Tot 182)
  51. 2017-07-29 22:11:16.762439 [DEBUG] switch_channel.c:2249 (sofia/external/9185330000@45.55.163.124) Callstate Change DOWN -> RINGING
  52. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:643 (sofia/external/9185330000@45.55.163.124) State ROUTING
  53. 2017-07-29 22:11:16.762439 [DEBUG] mod_sofia.c:154 sofia/external/9185330000@45.55.163.124 SOFIA ROUTING
  54. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:236 sofia/external/9185330000@45.55.163.124 Standard ROUTING
  55. 2017-07-29 22:11:16.762439 [INFO] mod_dialplan_xml.c:637 Processing TULSA, OK <9185330000>->12130000000 in context public
  56. send 380 bytes to tcp/[45.55.163.124]:5060 at 22:11:16.779170:
  57.    ------------------------------------------------------------------------
  58.    SIP/2.0 100 Trying
  59.    Via: SIP/2.0/TCP 45.55.163.124:5060;alias;rport=5060;branch=z9hG4bK1059959625
  60.    From: "TULSA, OK" <sip:9185330000@45.55.163.124>;tag=916891763
  61.    To: <sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW>
  62.    Call-ID: 1538561599@45.55.163.124
  63.    CSeq: 644 INVITE
  64.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170728T230550Z~144d3733cf~32bit
  65.    Content-Length: 0
  66.  
  67.    ------------------------------------------------------------------------
  68. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->unloop] continue=false
  69. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  70. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  71. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->outside_call] continue=true
  72. Dialplan: sofia/external/9185330000@45.55.163.124 Absolute Condition [outside_call]
  73. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(outside_call=true)
  74. Dialplan: sofia/external/9185330000@45.55.163.124 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  75. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->call_debug] continue=true
  76. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  77. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->public_extensions] continue=false
  78. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [public_extensions] destination_number(12130000000) =~ /^(10[01][0-9])$/ break=on-false
  79. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->public_did] continue=false
  80. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [public_did] destination_number(12130000000) =~ /^15123330880$/ break=on-false
  81. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->public_did] continue=false
  82. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [public_did] destination_number(12130000000) =~ /^17023024016$/ break=on-false
  83. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->public_did] continue=false
  84. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [public_did] destination_number(12130000000) =~ /^883510009027723$/ break=on-false
  85. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->public_did] continue=false
  86. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [public_did] destination_number(12130000000) =~ /^\+12109412600$/ break=on-false
  87. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [public->public_did] continue=false
  88. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (PASS) [public_did] destination_number(12130000000) =~ /^12130000000$/ break=on-false
  89. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(domain_name=192.168.0.137)
  90. Dialplan: sofia/external/9185330000@45.55.163.124 Action transfer(2600 XML default)
  91. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:286 (sofia/external/9185330000@45.55.163.124) State Change CS_ROUTING -> CS_EXECUTE
  92. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:643 (sofia/external/9185330000@45.55.163.124) State ROUTING going to sleep
  93. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_EXECUTE (Cur 1 Tot 182)
  94. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:650 (sofia/external/9185330000@45.55.163.124) State EXECUTE
  95. 2017-07-29 22:11:16.762439 [DEBUG] mod_sofia.c:209 sofia/external/9185330000@45.55.163.124 SOFIA EXECUTE
  96. 2017-07-29 22:11:16.762439 [DEBUG] switch_core_state_machine.c:328 sofia/external/9185330000@45.55.163.124 Standard EXECUTE
  97. EXECUTE sofia/external/9185330000@45.55.163.124 set(outside_call=true)
  98. 2017-07-29 22:11:16.782603 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [outside_call]=[true]
  99. EXECUTE sofia/external/9185330000@45.55.163.124 export(RFC2822_DATE=Sat, 29 Jul 2017 22:11:16 -0700)
  100. 2017-07-29 22:11:16.782603 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 29 Jul 2017 22:11:16 -0700]
  101. EXECUTE sofia/external/9185330000@45.55.163.124 set(domain_name=192.168.0.137)
  102. 2017-07-29 22:11:16.782603 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [domain_name]=[192.168.0.137]
  103. EXECUTE sofia/external/9185330000@45.55.163.124 transfer(2600 XML default)
  104. 2017-07-29 22:11:16.782603 [DEBUG] switch_ivr.c:2194 (sofia/external/9185330000@45.55.163.124) State Change CS_EXECUTE -> CS_ROUTING
  105. 2017-07-29 22:11:16.782603 [NOTICE] switch_ivr.c:2201 Transfer sofia/external/9185330000@45.55.163.124 to XML[2600@default]
  106. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:650 (sofia/external/9185330000@45.55.163.124) State EXECUTE going to sleep
  107. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_ROUTING (Cur 1 Tot 182)
  108. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:643 (sofia/external/9185330000@45.55.163.124) State ROUTING
  109. 2017-07-29 22:11:16.782603 [DEBUG] mod_sofia.c:145 Call appears to be already acknowledged
  110. 2017-07-29 22:11:16.782603 [DEBUG] mod_sofia.c:154 sofia/external/9185330000@45.55.163.124 SOFIA ROUTING
  111. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:236 sofia/external/9185330000@45.55.163.124 Standard ROUTING
  112. 2017-07-29 22:11:16.782603 [INFO] mod_dialplan_xml.c:637 Processing TULSA, OK <9185330000>->2600 in context default
  113. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->unloop] continue=false
  114. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  115. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  116. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->tod_example] continue=true
  117. Dialplan: sofia/external/9185330000@45.55.163.124 Date/TimeMatch (FAIL) [tod_example] break=on-false
  118. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->holiday_example] continue=true
  119. Dialplan: sofia/external/9185330000@45.55.163.124 Date/TimeMatch (FAIL) [holiday_example] break=on-false
  120. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->global-intercept] continue=false
  121. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [global-intercept] destination_number(2600) =~ /^886$/ break=on-false
  122. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->group-intercept] continue=false
  123. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [group-intercept] destination_number(2600) =~ /^\*8$/ break=on-false
  124. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->intercept-ext] continue=false
  125. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [intercept-ext] destination_number(2600) =~ /^\*\*(\d+)$/ break=on-false
  126. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->redial] continue=false
  127. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [redial] destination_number(2600) =~ /^(redial|870)$/ break=on-false
  128. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->global] continue=true
  129. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
  130. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [global] ${default_password}() =~ /^1234$/ break=never
  131. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
  132. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
  133. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [global] ${switch_r_sdp}(v=0
  134. o=yate 1501391476 1501391476 IN IP4 45.55.163.124
  135. s=SIP Call
  136. c=IN IP4 45.55.163.124
  137. t=0 0
  138. m=audio 28740 RTP/AVP 0 3 101
  139. a=rtpmap:0 PCMU/8000
  140. a=rtpmap:3 GSM/8000
  141. a=rtpmap:101 telephone-event/8000
  142. ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
  143. Dialplan: sofia/external/9185330000@45.55.163.124 Absolute Condition [global]
  144. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
  145. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
  146. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-last_dial/global/${uuid})
  147. Dialplan: sofia/external/9185330000@45.55.163.124 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
  148. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->snom-demo-2] continue=false
  149. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [snom-demo-2] destination_number(2600) =~ /^9001$/ break=on-false
  150. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->snom-demo-1] continue=false
  151. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [snom-demo-1] destination_number(2600) =~ /^9000$/ break=on-false
  152. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->eavesdrop] continue=false
  153. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [eavesdrop] destination_number(2600) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
  154. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->eavesdrop] continue=false
  155. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [eavesdrop] destination_number(2600) =~ /^779$/ break=on-false
  156. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->call_return] continue=false
  157. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [call_return] destination_number(2600) =~ /^\*69$|^869$|^lcr$/ break=on-false
  158. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->del-group] continue=false
  159. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [del-group] destination_number(2600) =~ /^80(\d{2})$/ break=on-false
  160. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->add-group] continue=false
  161. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [add-group] destination_number(2600) =~ /^81(\d{2})$/ break=on-false
  162. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->call-group-simo] continue=false
  163. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [call-group-simo] destination_number(2600) =~ /^82(\d{2})$/ break=on-false
  164. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->call-group-order] continue=false
  165. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [call-group-order] destination_number(2600) =~ /^83(\d{2})$/ break=on-false
  166. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->extension-intercom] continue=false
  167. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (FAIL) [extension-intercom] destination_number(2600) =~ /^8(10[01][0-9])$/ break=on-false
  168. Dialplan: sofia/external/9185330000@45.55.163.124 parsing [default->Local_Extension] continue=false
  169. Dialplan: sofia/external/9185330000@45.55.163.124 Regex (PASS) [Local_Extension] destination_number(2600) =~ /^(26[01][0-9]|phone|mobile)$/ break=on-false
  170. Dialplan: sofia/external/9185330000@45.55.163.124 Action export(dialed_extension=2600)
  171. Dialplan: sofia/external/9185330000@45.55.163.124 Action bind_meta_app(1 b s execute_extension::dx XML features)
  172. Dialplan: sofia/external/9185330000@45.55.163.124 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
  173. Dialplan: sofia/external/9185330000@45.55.163.124 Action bind_meta_app(3 b s execute_extension::cf XML features)
  174. Dialplan: sofia/external/9185330000@45.55.163.124 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
  175. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(ringback=${us-ring})
  176. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(transfer_ringback=local_stream://moh)
  177. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(call_timeout=30)
  178. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(hangup_after_bridge=true)
  179. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(continue_on_fail=true)
  180. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
  181. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
  182. Dialplan: sofia/external/9185330000@45.55.163.124 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
  183. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
  184. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
  185. Dialplan: sofia/external/9185330000@45.55.163.124 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
  186. Dialplan: sofia/external/9185330000@45.55.163.124 Action bridge(user/${user_data(${destination_number}@${domain_name} attr id)})
  187. Dialplan: sofia/external/9185330000@45.55.163.124 Action answer()
  188. Dialplan: sofia/external/9185330000@45.55.163.124 Action sleep(1000)
  189. Dialplan: sofia/external/9185330000@45.55.163.124 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
  190. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:286 (sofia/external/9185330000@45.55.163.124) State Change CS_ROUTING -> CS_EXECUTE
  191. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:643 (sofia/external/9185330000@45.55.163.124) State ROUTING going to sleep
  192. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_EXECUTE (Cur 1 Tot 182)
  193. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:650 (sofia/external/9185330000@45.55.163.124) State EXECUTE
  194. 2017-07-29 22:11:16.782603 [DEBUG] mod_sofia.c:209 sofia/external/9185330000@45.55.163.124 SOFIA EXECUTE
  195. 2017-07-29 22:11:16.782603 [DEBUG] switch_core_state_machine.c:328 sofia/external/9185330000@45.55.163.124 Standard EXECUTE
  196. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-spymap/9185330000/83ec6834-74e5-11e7-b772-c1f435f54e69)
  197. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-last_dial/9185330000/2600)
  198. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-last_dial/global/83ec6834-74e5-11e7-b772-c1f435f54e69)
  199. EXECUTE sofia/external/9185330000@45.55.163.124 export(RFC2822_DATE=Sat, 29 Jul 2017 22:11:16 -0700)
  200. 2017-07-29 22:11:16.802469 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 29 Jul 2017 22:11:16 -0700]
  201. EXECUTE sofia/external/9185330000@45.55.163.124 export(dialed_extension=2600)
  202. 2017-07-29 22:11:16.802469 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[2600]
  203. EXECUTE sofia/external/9185330000@45.55.163.124 bind_meta_app(1 b s execute_extension::dx XML features)
  204. 2017-07-29 22:11:16.802469 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *1 execute_extension::dx XML features
  205. EXECUTE sofia/external/9185330000@45.55.163.124 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/9185330000.2017-07-29-22-11-16.wav)
  206. 2017-07-29 22:11:16.802469 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/9185330000.2017-07-29-22-11-16.wav
  207. EXECUTE sofia/external/9185330000@45.55.163.124 bind_meta_app(3 b s execute_extension::cf XML features)
  208. 2017-07-29 22:11:16.802469 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *3 execute_extension::cf XML features
  209. EXECUTE sofia/external/9185330000@45.55.163.124 bind_meta_app(4 b s execute_extension::att_xfer XML features)
  210. 2017-07-29 22:11:16.802469 [INFO] switch_ivr_async.c:4260 Bound B-Leg: *4 execute_extension::att_xfer XML features
  211. EXECUTE sofia/external/9185330000@45.55.163.124 set(ringback=%(2000,4000,440,480))
  212. 2017-07-29 22:11:16.802469 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [ringback]=[%(2000,4000,440,480)]
  213. EXECUTE sofia/external/9185330000@45.55.163.124 set(transfer_ringback=local_stream://moh)
  214. 2017-07-29 22:11:16.802469 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [transfer_ringback]=[local_stream://moh]
  215. EXECUTE sofia/external/9185330000@45.55.163.124 set(call_timeout=30)
  216. 2017-07-29 22:11:16.802469 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [call_timeout]=[30]
  217. EXECUTE sofia/external/9185330000@45.55.163.124 set(hangup_after_bridge=true)
  218. 2017-07-29 22:11:16.822454 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [hangup_after_bridge]=[true]
  219. EXECUTE sofia/external/9185330000@45.55.163.124 set(continue_on_fail=true)
  220. 2017-07-29 22:11:16.822454 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [continue_on_fail]=[true]
  221. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-call_return/2600/9185330000)
  222. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-last_dial_ext/2600/83ec6834-74e5-11e7-b772-c1f435f54e69)
  223. EXECUTE sofia/external/9185330000@45.55.163.124 set(called_party_callgroup=homephone)
  224. 2017-07-29 22:11:16.822454 [DEBUG] mod_dptools.c:1588 SET sofia/external/9185330000@45.55.163.124 [called_party_callgroup]=[homephone]
  225. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-last_dial_ext/homephone/83ec6834-74e5-11e7-b772-c1f435f54e69)
  226. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-last_dial_ext/global/83ec6834-74e5-11e7-b772-c1f435f54e69)
  227. EXECUTE sofia/external/9185330000@45.55.163.124 hash(insert/192.168.0.137-last_dial/homephone/83ec6834-74e5-11e7-b772-c1f435f54e69)
  228. EXECUTE sofia/external/9185330000@45.55.163.124 bridge(user/2600)
  229. 2017-07-29 22:11:16.822454 [DEBUG] switch_channel.c:1250 sofia/external/9185330000@45.55.163.124 EXPORTING[export_vars] [RFC2822_DATE]=[Sat, 29 Jul 2017 22:11:16 -0700] to event
  230. 2017-07-29 22:11:16.822454 [DEBUG] switch_channel.c:1250 sofia/external/9185330000@45.55.163.124 EXPORTING[export_vars] [RFC2822_DATE]=[Sat, 29 Jul 2017 22:11:16 -0700] to event
  231. 2017-07-29 22:11:16.822454 [DEBUG] switch_channel.c:1250 sofia/external/9185330000@45.55.163.124 EXPORTING[export_vars] [dialed_extension]=[2600] to event
  232. 2017-07-29 22:11:16.822454 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
  233. 2017-07-29 22:11:16.842465 [DEBUG] switch_channel.c:1250 sofia/external/9185330000@45.55.163.124 EXPORTING[export_vars] [RFC2822_DATE]=[Sat, 29 Jul 2017 22:11:16 -0700] to event
  234. 2017-07-29 22:11:16.842465 [DEBUG] switch_channel.c:1250 sofia/external/9185330000@45.55.163.124 EXPORTING[export_vars] [RFC2822_DATE]=[Sat, 29 Jul 2017 22:11:16 -0700] to event
  235. 2017-07-29 22:11:16.842465 [DEBUG] switch_channel.c:1250 sofia/external/9185330000@45.55.163.124 EXPORTING[export_vars] [dialed_extension]=[2600] to event
  236. 2017-07-29 22:11:16.842465 [DEBUG] switch_ivr_originate.c:2147 Parsing global variables
  237. 2017-07-29 22:11:16.842465 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/2600@192.168.0.12 [83f80248-74e5-11e7-b792-c1f435f54e69]
  238. 2017-07-29 22:11:16.842465 [DEBUG] mod_sofia.c:5026 (sofia/internal/2600@192.168.0.12) State Change CS_NEW -> CS_INIT
  239. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2600@192.168.0.12) Running State Change CS_INIT (Cur 2 Tot 183)
  240. 2017-07-29 22:11:16.842465 [NOTICE] switch_ivr_originate.c:2856 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
  241. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/2600@192.168.0.12) State INIT
  242. 2017-07-29 22:11:16.842465 [DEBUG] mod_sofia.c:93 sofia/internal/2600@192.168.0.12 SOFIA INIT
  243. 2017-07-29 22:11:16.842465 [DEBUG] sofia_glue.c:1298 sofia/internal/2600@192.168.0.12 sending invite version: 1.9.0 git 144d373 2017-07-28 23:05:50Z 32bit
  244. Local SDP:
  245. v=0
  246. o=FreeSWITCH 1501362548 1501362549 IN IP4 192.168.0.137
  247. s=FreeSWITCH
  248. c=IN IP4 192.168.0.137
  249. t=0 0
  250. m=audio 28928 RTP/AVP 0 101
  251. a=rtpmap:0 PCMU/8000
  252. a=rtpmap:101 telephone-event/8000
  253. a=fmtp:101 0-16
  254. a=ptime:20
  255. a=sendrecv
  256.  
  257. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2600@192.168.0.12 Standard INIT
  258. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2600@192.168.0.12) State Change CS_INIT -> CS_ROUTING
  259. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/2600@192.168.0.12) State INIT going to sleep
  260. send 1172 bytes to udp/[192.168.0.12]:5060 at 22:11:16.857963:
  261.    ------------------------------------------------------------------------
  262.    INVITE sip:2600@192.168.0.12 SIP/2.0
  263.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKvc62ggQ4p5B2B
  264.    Max-Forwards: 17
  265.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  266.    To: <sip:2600@192.168.0.12>
  267.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  268.    CSeq: 110359674 INVITE
  269.    Contact: <sip:mod_sofia@192.168.0.137:5060>
  270.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170728T230550Z~144d3733cf~32bit
  271.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  272.    Supported: timer, path, replaces
  273.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
  274.    Content-Type: application/sdp
  275.    Content-Disposition: session
  276.    Content-Length: 222
  277.    X-FS-Support: update_display,send_info
  278. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2600@192.168.0.12) Running State Change CS_ROUTING (Cur 2 Tot 183)
  279.    Remote-Party-ID: "TULSA, OK" <sip:9185330000@192.168.0.137>;party=calling;screen=yes;privacy=off
  280.  
  281.    v=0
  282.    o=FreeSWITCH 1501362548 1501362549 IN IP4 192.168.0.137
  283.    s=FreeSWITCH
  284.    c=IN IP4 192.168.0.137
  285.    t=0 0
  286.    m=audio 28928 RTP/AVP 0 101
  287.    a=rtpmap:0 PCMU/8000
  288.    a=rtpmap:101 telephone-event/8000
  289.    a=fmtp:101 0-16
  290.    a=ptime:20
  291.    ------------------------------------------------------------------------
  292. 2017-07-29 22:11:16.842465 [DEBUG] sofia.c:7283 Channel sofia/internal/2600@192.168.0.12 entering state [calling][0]
  293. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/2600@192.168.0.12) State ROUTING
  294. 2017-07-29 22:11:16.842465 [DEBUG] mod_sofia.c:154 sofia/internal/2600@192.168.0.12 SOFIA ROUTING
  295. 2017-07-29 22:11:16.842465 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/2600@192.168.0.12) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  296. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/2600@192.168.0.12) State ROUTING going to sleep
  297. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2600@192.168.0.12) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 183)
  298. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/2600@192.168.0.12) State CONSUME_MEDIA
  299. 2017-07-29 22:11:16.842465 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/2600@192.168.0.12) State CONSUME_MEDIA going to sleep
  300. recv 414 bytes from udp/[192.168.0.12]:5060 at 22:11:16.874674:
  301.    ------------------------------------------------------------------------
  302.    SIP/2.0 100 Trying
  303.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKvc62ggQ4p5B2B
  304.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  305.    To: "jungle boogie" <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  306.    CSeq: 110359674 INVITE
  307.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  308.    Contact: <sip:2600@192.168.0.12>
  309.    User-Agent: PolycomVVX-VVX_410-UA/5.5.1.12442
  310.    Accept-Language: en
  311.    Content-Length: 0
  312.  
  313.    ------------------------------------------------------------------------
  314. recv 451 bytes from udp/[192.168.0.12]:5060 at 22:11:16.970617:
  315.    ------------------------------------------------------------------------
  316.    SIP/2.0 180 Ringing
  317.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKvc62ggQ4p5B2B
  318.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  319.    To: "jungle boogie" <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  320.    CSeq: 110359674 INVITE
  321.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  322.    Contact: <sip:2600@192.168.0.12>
  323.    User-Agent: PolycomVVX-VVX_410-UA/5.5.1.12442
  324.    Allow-Events: conference,talk,hold
  325.    Accept-Language: en
  326.    Content-Length: 0
  327.  
  328.    ------------------------------------------------------------------------
  329. 2017-07-29 22:11:16.962452 [DEBUG] sofia.c:7283 Channel sofia/internal/2600@192.168.0.12 entering state [proceeding][180]
  330. 2017-07-29 22:11:16.962452 [NOTICE] sofia.c:7391 Ring-Ready sofia/internal/2600@192.168.0.12!
  331. 2017-07-29 22:11:16.982477 [DEBUG] switch_channel.c:3354 (sofia/internal/2600@192.168.0.12) Callstate Change DOWN -> RINGING
  332. 2017-07-29 22:11:16.982477 [INFO] switch_ivr_originate.c:1220 Sending early media
  333. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  334. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  335. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  336. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  337. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  338. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
  339. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
  340. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  341. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  342. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5031 Set telephone-event payload to 101@8000
  343. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:3430 Set Codec sofia/external/9185330000@45.55.163.124 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  344. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_codec.c:111 sofia/external/9185330000@45.55.163.124 Original read codec set to PCMU:0
  345. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
  346. 2017-07-29 22:11:16.982477 [DEBUG] switch_core_media.c:5432 sofia/external/9185330000@45.55.163.124 Set 2833 dtmf send payload to 101 recv payload to 101
  347. 2017-07-29 22:11:17.122542 [DEBUG] switch_nat.c:508 mapped public port 22720 protocol UDP to localport 22720
  348. 2017-07-29 22:11:17.122542 [DEBUG] switch_core_media.c:8149 AUDIO RTP [sofia/external/9185330000@45.55.163.124] 192.168.0.137 port 22720 -> 45.55.163.124 port 28740 codec: 0 ms: 20
  349. 2017-07-29 22:11:17.122542 [DEBUG] switch_rtp.c:4164 Starting timer [soft] 160 bytes per 20ms
  350. 2017-07-29 22:11:17.122542 [DEBUG] switch_core_media.c:8452 sofia/external/9185330000@45.55.163.124 Set 2833 dtmf send payload to 101
  351. 2017-07-29 22:11:17.122542 [DEBUG] switch_core_media.c:8459 sofia/external/9185330000@45.55.163.124 Set 2833 dtmf receive payload to 101
  352. 2017-07-29 22:11:17.122542 [DEBUG] switch_core_media.c:8482 sofia/external/9185330000@45.55.163.124 Set rtp dtmf delay to 40
  353. 2017-07-29 22:11:17.122542 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/9185330000@45.55.163.124!
  354. 2017-07-29 22:11:17.122542 [DEBUG] switch_channel.c:3482 (sofia/external/9185330000@45.55.163.124) Callstate Change RINGING -> EARLY
  355. 2017-07-29 22:11:17.122542 [DEBUG] switch_core_media.c:8132 Audio params are unchanged for sofia/external/9185330000@45.55.163.124.
  356. 2017-07-29 22:11:17.122542 [DEBUG] mod_sofia.c:2512 Ring SDP:
  357. v=0
  358. o=FreeSWITCH 1501368757 1501368758 IN IP4 freeswitch.example.com
  359. s=FreeSWITCH
  360. c=IN IP4 freeswitch.example.com
  361. t=0 0
  362. m=audio 22720 RTP/AVP 0 101
  363. a=rtpmap:0 PCMU/8000
  364. a=rtpmap:101 telephone-event/8000
  365. a=fmtp:101 0-16
  366. a=ptime:20
  367. a=sendrecv
  368.  
  369. 2017-07-29 22:11:17.122542 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@8000hz 1 channel 20ms
  370. 2017-07-29 22:11:17.122542 [DEBUG] switch_core_codec.c:223 sofia/external/9185330000@45.55.163.124 Push codec L16:100
  371. 2017-07-29 22:11:17.122542 [DEBUG] switch_ivr_originate.c:1347 Play Ringback Tone [%(2000,4000,440,480)]
  372. send 1064 bytes to tcp/[45.55.163.124]:5060 at 22:11:17.137745:
  373.    ------------------------------------------------------------------------
  374.    SIP/2.0 183 Session Progress
  375.    Via: SIP/2.0/TCP 45.55.163.124:5060;alias;rport=5060;branch=z9hG4bK1059959625
  376.    From: "TULSA, OK" <sip:9185330000@45.55.163.124>;tag=916891763
  377.    To: <sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW>;tag=SNgK5vtHUKjtj
  378.    Call-ID: 1538561599@45.55.163.124
  379.    CSeq: 644 INVITE
  380.    Contact: <sip:gw+GVGW@freeswitch.example.com:5080;transport=udp>
  381.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170728T230550Z~144d3733cf~32bit
  382.    Accept: application/sdp
  383.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  384.    Supported: timer, path, replaces
  385.    Allow-Events: talk, hold, conference, refer
  386.    Content-Type: application/sdp
  387.    Content-Disposition: session
  388.    Content-Length: 232
  389.    Remote-Party-ID: "12130000000" <sip:12130000000@freeswitch.example.com>;party=calling;privacy=off;screen=no
  390.  
  391.    v=0
  392.    o=FreeSWITCH 1501368757 1501368758 IN IP4 freeswitch.example.com
  393.    s=FreeSWITCH
  394.    c=IN IP4 freeswitch.example.com
  395.    t=0 0
  396.    m=audio 22720 RTP/AVP 0 101
  397.    a=rtpmap:0 PCMU/8000
  398.    a=rtpmap:101 telephone-event/8000
  399.    a=fmtp:101 0-16
  400.    a=ptime:20
  401.    ------------------------------------------------------------------------
  402. 2017-07-29 22:11:17.142459 [DEBUG] sofia.c:7283 Channel sofia/external/9185330000@45.55.163.124 entering state [early][183]
  403. recv 792 bytes from udp/[192.168.0.12]:5060 at 22:11:19.123125:
  404.    ------------------------------------------------------------------------
  405.    SIP/2.0 200 OK
  406.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKvc62ggQ4p5B2B
  407.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  408.    To: "jungle boogie" <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  409.    CSeq: 110359674 INVITE
  410.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  411.    Contact: <sip:2600@192.168.0.12>
  412.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
  413.    Supported: replaces,100rel
  414.    User-Agent: PolycomVVX-VVX_410-UA/5.5.1.12442
  415.    Allow-Events: conference,talk,hold
  416.    Accept-Language: en
  417.    Content-Type: application/sdp
  418.    Content-Length: 187
  419.  
  420.    v=0
  421.    o=- 1501391478 1501391478 IN IP4 192.168.0.12
  422.    s=Polycom IP Phone
  423.    c=IN IP4 192.168.0.12
  424.    t=0 0
  425.    m=audio 2244 RTP/AVP 0 101
  426.    a=rtpmap:0 PCMU/8000
  427.    a=rtpmap:101 telephone-event/8000
  428.    ------------------------------------------------------------------------
  429. 2017-07-29 22:11:19.122439 [DEBUG] sofia.c:7283 Channel sofia/internal/2600@192.168.0.12 entering state [completing][200]
  430. 2017-07-29 22:11:19.122439 [DEBUG] sofia.c:7293 Remote SDP:
  431. v=0
  432. o=- 1501391478 1501391478 IN IP4 192.168.0.12
  433. s=Polycom IP Phone
  434. c=IN IP4 192.168.0.12
  435. t=0 0
  436. m=audio 2244 RTP/AVP 0 101
  437. a=rtpmap:0 PCMU/8000
  438. a=rtpmap:101 telephone-event/8000
  439.  
  440. send 372 bytes to udp/[192.168.0.12]:5060 at 22:11:19.134098:
  441.    ------------------------------------------------------------------------
  442.    ACK sip:2600@192.168.0.12 SIP/2.0
  443.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKXNZUjB87Ke2mQ
  444.    Max-Forwards: 70
  445.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  446.    To: <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  447.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  448.    CSeq: 110359674 ACK
  449.    Contact: <sip:mod_sofia@192.168.0.137:5060>
  450.    Content-Length: 0
  451.  
  452.    ------------------------------------------------------------------------
  453. 2017-07-29 22:11:19.122439 [DEBUG] sofia.c:7283 Channel sofia/internal/2600@192.168.0.12 entering state [ready][200]
  454. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  455. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  456. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:5031 Set telephone-event payload to 101@8000
  457. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:3430 Set Codec sofia/internal/2600@192.168.0.12 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  458. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_codec.c:111 sofia/internal/2600@192.168.0.12 Original read codec set to PCMU:0
  459. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
  460. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:5432 sofia/internal/2600@192.168.0.12 Set 2833 dtmf send payload to 101 recv payload to 101
  461. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:8149 AUDIO RTP [sofia/internal/2600@192.168.0.12] 192.168.0.137 port 28928 -> 192.168.0.12 port 2244 codec: 0 ms: 20
  462. 2017-07-29 22:11:19.122439 [DEBUG] switch_rtp.c:4164 Starting timer [soft] 160 bytes per 20ms
  463. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:8452 sofia/internal/2600@192.168.0.12 Set 2833 dtmf send payload to 101
  464. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:8459 sofia/internal/2600@192.168.0.12 Set 2833 dtmf receive payload to 101
  465. 2017-07-29 22:11:19.122439 [DEBUG] switch_core_media.c:8482 sofia/internal/2600@192.168.0.12 Set rtp dtmf delay to 40
  466. 2017-07-29 22:11:19.142477 [NOTICE] sofia.c:8419 Channel [sofia/internal/2600@192.168.0.12] has been answered
  467. 2017-07-29 22:11:19.142477 [DEBUG] switch_core_codec.c:248 sofia/external/9185330000@45.55.163.124 Restore previous codec PCMU:0.
  468. 2017-07-29 22:11:19.142477 [DEBUG] switch_core_media.c:8132 Audio params are unchanged for sofia/external/9185330000@45.55.163.124.
  469. 2017-07-29 22:11:19.142477 [DEBUG] mod_sofia.c:881 Local SDP sofia/external/9185330000@45.55.163.124:
  470. v=0
  471. o=FreeSWITCH 1501368757 1501368759 IN IP4 freeswitch.example.com
  472. s=FreeSWITCH
  473. c=IN IP4 freeswitch.example.com
  474. t=0 0
  475. m=audio 22720 RTP/AVP 0 101
  476. a=rtpmap:0 PCMU/8000
  477. a=rtpmap:101 telephone-event/8000
  478. a=fmtp:101 0-16
  479. a=ptime:20
  480. a=sendrecv
  481.  
  482. send 1020 bytes to tcp/[45.55.163.124]:5060 at 22:11:19.149180:
  483.    ------------------------------------------------------------------------
  484.    SIP/2.0 200 OK
  485.    Via: SIP/2.0/TCP 45.55.163.124:5060;alias;rport=5060;branch=z9hG4bK1059959625
  486.    From: "TULSA, OK" <sip:9185330000@45.55.163.124>;tag=916891763
  487.    To: <sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW>;tag=SNgK5vtHUKjtj
  488.    Call-ID: 1538561599@45.55.163.124
  489.    CSeq: 644 INVITE
  490.    Contact: <sip:gw+GVGW@freeswitch.example.com:5080;transport=udp>
  491.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170728T230550Z~144d3733cf~32bit
  492.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  493.    Supported: timer, path, replaces
  494.    Allow-Events: talk, hold, conference, refer
  495.    Content-Type: application/sdp
  496.    Content-Disposition: session
  497.    Content-Length: 232
  498.    Remote-Party-ID: "Outbound Call" <sip:2600@freeswitch.example.com>;party=calling;privacy=off;screen=no
  499.  
  500.    v=0
  501.    o=FreeSWITCH 1501368757 1501368758 IN IP4 freeswitch.example.com
  502.    s=FreeSWITCH
  503.    c=IN IP4 freeswitch.example.com
  504.    t=0 0
  505.    m=audio 22720 RTP/AVP 0 101
  506.    a=rtpmap:0 PCMU/8000
  507.    a=rtpmap:101 telephone-event/8000
  508.    a=fmtp:101 0-16
  509.    a=ptime:20
  510.    ------------------------------------------------------------------------
  511. 2017-07-29 22:11:19.142477 [NOTICE] switch_ivr_originate.c:3652 Channel [sofia/external/9185330000@45.55.163.124] has been answered
  512. 2017-07-29 22:11:19.142477 [DEBUG] switch_channel.c:3781 (sofia/internal/2600@192.168.0.12) Callstate Change RINGING -> ACTIVE
  513. 2017-07-29 22:11:19.142477 [DEBUG] switch_channel.c:3781 (sofia/external/9185330000@45.55.163.124) Callstate Change EARLY -> ACTIVE
  514. 2017-07-29 22:11:19.142477 [DEBUG] sofia.c:7283 Channel sofia/external/9185330000@45.55.163.124 entering state [completed][200]
  515. 2017-07-29 22:11:19.142477 [DEBUG] switch_ivr_originate.c:3710 Originate Resulted in Success: [sofia/internal/2600@192.168.0.12]
  516. 2017-07-29 22:11:19.162461 [DEBUG] switch_ivr_originate.c:3710 Originate Resulted in Success: [sofia/internal/2600@192.168.0.12]
  517. 2017-07-29 22:11:19.162461 [DEBUG] switch_ivr_bridge.c:1744 (sofia/internal/2600@192.168.0.12) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  518. 2017-07-29 22:11:19.162461 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2600@192.168.0.12) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 183)
  519. 2017-07-29 22:11:19.162461 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/2600@192.168.0.12) State EXCHANGE_MEDIA
  520. 2017-07-29 22:11:19.162461 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
  521. recv 436 bytes from tcp/[45.55.163.124]:5060 at 22:11:19.267307:
  522.    ------------------------------------------------------------------------
  523.    ACK sip:gw+GVGW@freeswitch.example.com:5080;transport=udp SIP/2.0
  524.    Via: SIP/2.0/TCP 45.55.163.124:5060;alias;rport;branch=z9hG4bK973542075
  525.    From: "TULSA, OK" <sip:9185330000@45.55.163.124>;tag=916891763
  526.    To: <sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW>;tag=SNgK5vtHUKjtj
  527.    Call-ID: 1538561599@45.55.163.124
  528.    CSeq: 644 ACK
  529.    Max-Forwards: 19
  530.    Contact: <sip:9185330000@45.55.163.124:5060>
  531.    User-Agent: GVGW
  532.    Content-Length: 0
  533.  
  534.    ------------------------------------------------------------------------
  535. 2017-07-29 22:11:19.262445 [DEBUG] switch_rtp.c:7338 Correct audio ip/port confirmed.
  536. 2017-07-29 22:11:19.282554 [DEBUG] sofia.c:7283 Channel sofia/external/9185330000@45.55.163.124 entering state [ready][200]
  537. send 932 bytes to udp/[192.168.0.12]:5060 at 22:11:19.301092:
  538.    ------------------------------------------------------------------------
  539.    UPDATE sip:2600@192.168.0.12 SIP/2.0
  540.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKyyrmm6rBHQr7j
  541.    Max-Forwards: 70
  542.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  543.    To: <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  544.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  545.    CSeq: 110359675 UPDATE
  546.    Contact: <sip:mod_sofia@192.168.0.137:5060>
  547.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170728T230550Z~144d3733cf~32bit
  548.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  549.    Supported: timer, path, replaces
  550.    Content-Type: application/sdp
  551.    Content-Disposition: session
  552.    Content-Length: 222
  553.    P-Asserted-Identity: "TULSA, OK" <9185330000>
  554.  
  555.    v=0
  556.    o=FreeSWITCH 1501362548 1501362549 IN IP4 192.168.0.137
  557.    s=FreeSWITCH
  558.    c=IN IP4 192.168.0.137
  559.    t=0 0
  560.    m=audio 28928 RTP/AVP 0 101
  561.    a=rtpmap:0 PCMU/8000
  562.    a=rtpmap:101 telephone-event/8000
  563.    a=fmtp:101 0-16
  564.    a=ptime:20
  565.    ------------------------------------------------------------------------
  566. 2017-07-29 22:11:19.302474 [DEBUG] sofia.c:7283 Channel sofia/internal/2600@192.168.0.12 entering state [calling][0]
  567. recv 630 bytes from udp/[192.168.0.12]:5060 at 22:11:19.320683:
  568.    ------------------------------------------------------------------------
  569.    SIP/2.0 200 OK
  570.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKyyrmm6rBHQr7j
  571.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  572.    To: "jungle boogie" <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  573.    CSeq: 110359675 UPDATE
  574.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  575.    Contact: <sip:2600@192.168.0.12>
  576.    User-Agent: PolycomVVX-VVX_410-UA/5.5.1.12442
  577.    Accept-Language: en
  578.    Content-Type: application/sdp
  579.    Content-Length: 187
  580.  
  581.    v=0
  582.    o=- 1501391478 1501391478 IN IP4 192.168.0.12
  583.    s=Polycom IP Phone
  584.    c=IN IP4 192.168.0.12
  585.    t=0 0
  586.    m=audio 2244 RTP/AVP 0 101
  587.    a=rtpmap:0 PCMU/8000
  588.    a=rtpmap:101 telephone-event/8000
  589.    ------------------------------------------------------------------------
  590. 2017-07-29 22:11:19.322471 [DEBUG] sofia.c:7283 Channel sofia/internal/2600@192.168.0.12 entering state [ready][200]
  591. 2017-07-29 22:11:19.322471 [DEBUG] sofia.c:7290 Duplicate SDP
  592. v=0
  593. o=- 1501391478 1501391478 IN IP4 192.168.0.12
  594. s=Polycom IP Phone
  595. c=IN IP4 192.168.0.12
  596. t=0 0
  597. m=audio 2244 RTP/AVP 0 101
  598. a=rtpmap:0 PCMU/8000
  599. a=rtpmap:101 telephone-event/8000
  600.  
  601. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  602. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5170 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  603. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  604. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  605. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5115 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  606. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5031 Set telephone-event payload to 101@8000
  607. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
  608. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:5432 sofia/internal/2600@192.168.0.12 Set 2833 dtmf send payload to 101 recv payload to 101
  609. 2017-07-29 22:11:19.342497 [DEBUG] sofia.c:8262 Processing updated SDP
  610. 2017-07-29 22:11:19.342497 [DEBUG] switch_core_media.c:8132 Audio params are unchanged for sofia/internal/2600@192.168.0.12.
  611. recv 487 bytes from tcp/[45.55.163.124]:5060 at 22:11:19.506054:
  612.    ------------------------------------------------------------------------
  613.    BYE sip:gw+GVGW@freeswitch.example.com:5080;transport=udp SIP/2.0
  614.    Call-ID: 1538561599@45.55.163.124
  615.    From: <sip:9185330000@45.55.163.124>;tag=916891763
  616.    To: <sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW>;tag=SNgK5vtHUKjtj
  617.    P-RTP-Stat: PS=0,OS=0,PR=108,OR=17280,PL=0
  618.    Via: SIP/2.0/TCP 45.55.163.124:5060;alias;rport;branch=z9hG4bK198276461
  619.    CSeq: 645 BYE
  620.    User-Agent: GVGW
  621.    Max-Forwards: 70
  622.   Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO
  623.    Content-Length: 0
  624.  
  625.    ------------------------------------------------------------------------
  626. 2017-07-29 22:11:19.522526 [NOTICE] sofia.c:1079 Hangup sofia/external/9185330000@45.55.163.124 [CS_EXECUTE] [NORMAL_CLEARING]
  627. send 502 bytes to tcp/[45.55.163.124]:5060 at 22:11:19.535354:
  628.    ------------------------------------------------------------------------
  629.    SIP/2.0 200 OK
  630.    Via: SIP/2.0/TCP 45.55.163.124:5060;alias;rport=5060;branch=z9hG4bK198276461
  631.    From: <sip:9185330000@45.55.163.124>;tag=916891763
  632.    To: <sip:gw+GVGW@freeswitch.example.com:5080;transport=tcp;gw=GVGW>;tag=SNgK5vtHUKjtj
  633.    Call-ID: 1538561599@45.55.163.124
  634.    CSeq: 645 BYE
  635.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170728T230550Z~144d3733cf~32bit
  636.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  637.    Supported: timer, path, replaces
  638.    Content-Length: 0
  639.  
  640.    ------------------------------------------------------------------------
  641. 2017-07-29 22:11:19.522526 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/external/9185330000@45.55.163.124]
  642. 2017-07-29 22:11:19.522526 [DEBUG] switch_ivr_bridge.c:825 sofia/external/9185330000@45.55.163.124 ending bridge by request from write function
  643. 2017-07-29 22:11:19.542459 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/2600@192.168.0.12]
  644. 2017-07-29 22:11:19.542459 [NOTICE] switch_ivr_bridge.c:1034 Hangup sofia/internal/2600@192.168.0.12 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  645. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/2600@192.168.0.12) State EXCHANGE_MEDIA going to sleep
  646. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2600@192.168.0.12) Running State Change CS_HANGUP (Cur 2 Tot 183)
  647. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2600@192.168.0.12) Callstate Change ACTIVE -> HANGUP
  648. 2017-07-29 22:11:19.542459 [DEBUG] switch_ivr_bridge.c:1843 sofia/internal/2600@192.168.0.12 skip receive message [TRANSFER] (channel is hungup already)
  649. 2017-07-29 22:11:19.542459 [DEBUG] switch_ivr_bridge.c:1846 sofia/external/9185330000@45.55.163.124 skip receive message [TRANSFER] (channel is hungup already)
  650. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/2600@192.168.0.12) State HANGUP
  651. 2017-07-29 22:11:19.542459 [DEBUG] mod_sofia.c:443 sofia/internal/2600@192.168.0.12 Overriding SIP cause 480 with 200 from the other leg
  652. 2017-07-29 22:11:19.542459 [DEBUG] mod_sofia.c:449 Channel sofia/internal/2600@192.168.0.12 hanging up, cause: NORMAL_CLEARING
  653. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_session.c:2885 sofia/external/9185330000@45.55.163.124 skip receive message [PHONE_EVENT] (channel is hungup already)
  654. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:650 (sofia/external/9185330000@45.55.163.124) State EXECUTE going to sleep
  655. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_HANGUP (Cur 2 Tot 183)
  656. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:850 (sofia/external/9185330000@45.55.163.124) Callstate Change ACTIVE -> HANGUP
  657. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:852 (sofia/external/9185330000@45.55.163.124) State HANGUP
  658. 2017-07-29 22:11:19.542459 [DEBUG] mod_sofia.c:449 Channel sofia/external/9185330000@45.55.163.124 hanging up, cause: NORMAL_CLEARING
  659. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:60 sofia/external/9185330000@45.55.163.124 Standard HANGUP, cause: NORMAL_CLEARING
  660. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:852 (sofia/external/9185330000@45.55.163.124) State HANGUP going to sleep
  661. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:619 (sofia/external/9185330000@45.55.163.124) State Change CS_HANGUP -> CS_REPORTING
  662. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9185330000@45.55.163.124) Running State Change CS_REPORTING (Cur 2 Tot 183)
  663. 2017-07-29 22:11:19.542459 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/2600@192.168.0.12
  664. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:60 sofia/internal/2600@192.168.0.12 Standard HANGUP, cause: NORMAL_CLEARING
  665. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/2600@192.168.0.12) State HANGUP going to sleep
  666. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:938 (sofia/external/9185330000@45.55.163.124) State REPORTING
  667. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/2600@192.168.0.12) State Change CS_HANGUP -> CS_REPORTING
  668. send 640 bytes to udp/[192.168.0.12]:5060 at 22:11:19.554862:
  669.    ------------------------------------------------------------------------
  670.    BYE sip:2600@192.168.0.12 SIP/2.0
  671.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKZ7HDp19ee0ete
  672.    Max-Forwards: 70
  673.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  674.    To: <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  675.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  676.    CSeq: 110359676 BYE
  677.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170728T230550Z~144d3733cf~32bit
  678.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  679.    Supported: timer, path, replaces
  680.    Reason: Q.850;cause=16;text="NORMAL_CLEARING"
  681.    Content-Length: 0
  682.    P-RTP-Stat: PS=0,OS=0,PR=108,OR=17280,PL=0
  683.  
  684.    ------------------------------------------------------------------------
  685. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2600@192.168.0.12) Running State Change CS_REPORTING (Cur 2 Tot 183)
  686. 2017-07-29 22:11:19.542459 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/2600@192.168.0.12) State REPORTING
  687. recv 407 bytes from udp/[192.168.0.12]:5060 at 22:11:19.570575:
  688.    ------------------------------------------------------------------------
  689.    SIP/2.0 200 OK
  690.    Via: SIP/2.0/UDP 192.168.0.137;rport;branch=z9hG4bKZ7HDp19ee0ete
  691.    From: "TULSA, OK" <sip:9185330000@192.168.0.137>;tag=gBDSptpK0j5cS
  692.    To: "jungle boogie" <sip:2600@192.168.0.12>;tag=1C93D4ED-1D331DFE
  693.    CSeq: 110359676 BYE
  694.    Call-ID: 5b57784a-ef88-1235-0696-b827eb21ced5
  695.    Contact: <sip:2600@192.168.0.12>
  696.    User-Agent: PolycomVVX-VVX_410-UA/5.5.1.12442
  697.    Accept-Language: en
  698.    Content-Length: 0
  699.  
  700.    ------------------------------------------------------------------------
  701. 2017-07-29 22:11:19.582509 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("TULSA, OK","9185330000","2600","default","2017-07-29 22:11:16","2017-07-29 22:11:19",
  702. "2017-07-29 22:11:19",3, 0, 0,"NORMAL_CLEARING","83f80248-74e5-11e7-b792-c1f435f54e69","","2600","PCMU","PCMU",
  703. "send_bye","9185330000","homephone","ANSWER")
  704. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:174 sofia/internal/2600@192.168.0.12 Standard REPORTING, cause: NORMAL_CLEARING
  705. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/2600@192.168.0.12) State REPORTING going to sleep
  706. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/2600@192.168.0.12) State Change CS_REPORTING -> CS_DESTROY
  707. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_session.c:1713 Session 183 (sofia/internal/2600@192.168.0.12) Locked, Waiting on external entities
  708. 2017-07-29 22:11:19.582509 [NOTICE] switch_core_session.c:1731 Session 183 (sofia/internal/2600@192.168.0.12) Ended
  709. 2017-07-29 22:11:19.582509 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/2600@192.168.0.12 [CS_DESTROY]
  710. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/2600@192.168.0.12) Running State Change CS_DESTROY (Cur 1 Tot 183)
  711. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/2600@192.168.0.12) State DESTROY
  712. 2017-07-29 22:11:19.582509 [DEBUG] mod_sofia.c:354 sofia/internal/2600@192.168.0.12 SOFIA DESTROY
  713. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:181 sofia/internal/2600@192.168.0.12 Standard DESTROY
  714. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/2600@192.168.0.12) State DESTROY going to sleep
  715. 2017-07-29 22:11:19.582509 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("TULSA, OK","9185330000","2600","default","2017-07-29 22:11:16","2017-07-29 22:11:19",
  716. "2017-07-29 22:11:19",3, 0, 0,"NORMAL_CLEARING","83ec6834-74e5-11e7-b772-c1f435f54e69","83f80248-74e5-11e7-b792-c1f435f54e69","","PCMU","PCMU",
  717. "recv_bye","9185330000","","ANSWER")
  718. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:174 sofia/external/9185330000@45.55.163.124 Standard REPORTING, cause: NORMAL_CLEARING
  719. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:938 (sofia/external/9185330000@45.55.163.124) State REPORTING going to sleep
  720. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_state_machine.c:610 (sofia/external/9185330000@45.55.163.124) State Change CS_REPORTING -> CS_DESTROY
  721. 2017-07-29 22:11:19.582509 [DEBUG] switch_core_session.c:1713 Session 182 (sofia/external/9185330000@45.55.163.124) Locked, Waiting on external entities
  722. 2017-07-29 22:11:19.582509 [NOTICE] switch_core_session.c:1731 Session 182 (sofia/external/9185330000@45.55.163.124) Ended
  723. 2017-07-29 22:11:19.582509 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/9185330000@45.55.163.124 [CS_DESTROY]
  724. 2017-07-29 22:11:19.602490 [DEBUG] switch_core_state_machine.c:741 (sofia/external/9185330000@45.55.163.124) Running State Change CS_DESTROY (Cur 0 Tot 183)
  725. 2017-07-29 22:11:19.602490 [DEBUG] switch_core_state_machine.c:751 (sofia/external/9185330000@45.55.163.124) State DESTROY
  726. 2017-07-29 22:11:19.602490 [DEBUG] mod_sofia.c:354 sofia/external/9185330000@45.55.163.124 SOFIA DESTROY
  727. 2017-07-29 22:11:19.662461 [DEBUG] switch_nat.c:568 unmapped public port 22720 protocol UDP to localport 22720
  728. 2017-07-29 22:11:19.742470 [DEBUG] switch_core_state_machine.c:181 sofia/external/9185330000@45.55.163.124 Standard DESTROY
  729. 2017-07-29 22:11:19.742470 [DEBUG] switch_core_state_machine.c:751 (sofia/external/9185330000@45.55.163.124) State DESTROY going to sleep
  730.  
  731.