From Voluminous Tapir, 6 Years ago, written in FreeSWITCH.
- go back
Embed
Viewing differences between and nga911 pre-procesing
  1.    ------------------------------------------------------------------------
  2. recv 1515 bytes from udp/[10.0.9.55]:5060 at 12:09:19.660430:
  3.    ------------------------------------------------------------------------
  4.    INVITE sip:12134237681@office.nga911.com:15080 SIP/2.0
  5.    Record-Route: <sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>
  6.    Record-Route: <sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>
  7.    Record-Route: <sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
  8.    Record-Route: <sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
  9.    Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
  10.    Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
  11.    v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
  12.    Max-Forwards:44
  13.    f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
  14.    t:<sip:12134237681@office.nga911.com:15080>
  15.    i:17fab07d-716b-1236-7a88-02420a0f0c04
  16.    CSeq:117500215 INVITE
  17.    m:<sip:mod_sofia@10.15.12.4:5082;alias=10.15.12.4~55742~2>
  18.   Allow:INVITE,ACK,BYE,CANCEL,OPTIONS,MESSAGE,INFO,UPDATE,NOTIFY
  19.    k:timer,path,replaces
  20.    u:talk,hold,conference,refer
  21.    Privacy:none
  22.    c:application/sdp
  23.    Content-Disposition:session
  24.    l:333
  25.    P-Asserted-Identity:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>
  26.    X-AUTH-IP: 192.76.120.10
  27.    X-AUTH-PORT: 36831
  28.    
  29.    v=0
  30.    o=Telnyx 1515647013 1515647014 IN IP4 64.16.248.242
  31.    s=Telnyx
  32.    c=IN IP4 64.16.248.242
  33.    t=0 0
  34.    m=audio 25546 RTP/AVP 9 0 8 18 101 13
  35.    a=rtpmap:9 G722/8000
  36.    a=rtpmap:0 PCMU/8000
  37.    a=rtpmap:8 PCMA/8000
  38.    a=rtpmap:18 G729/8000
  39.    a=fmtp:18 annexb=no
  40.    a=rtpmap:101 telephone-event/8000
  41.    a=fmtp:101 0-16
  42.    a=rtpmap:13 CN/8000
  43.    a=ptime:20
  44.    ------------------------------------------------------------------------
  45. send 865 bytes to udp/[10.0.9.55]:5060 at 12:09:19.660679:
  46.    ------------------------------------------------------------------------
  47.    SIP/2.0 100 Trying
  48.    Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
  49.    Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
  50.    v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
  51.    Record-Route: <sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>
  52.    Record-Route: <sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>
  53.    Record-Route: <sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
  54.    Record-Route: <sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
  55.    f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
  56.    t:<sip:12134237681@office.nga911.com:15080>
  57.    i:17fab07d-716b-1236-7a88-02420a0f0c04
  58.    CSeq:117500215 INVITE
  59.    User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
  60.    Content-Length: 0
  61.    
  62.    ------------------------------------------------------------------------
  63. 2018-01-11 12:09:19.655466 [NOTICE] switch_channel.c:1104 New Channel sofia/external-kamailio/12013992990@sip.telnyx.com [5e07cf5b-2b87-4075-8430-34de18f707c4]
  64. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_NEW (Cur 2 Tot 356)
  65. 2018-01-11 12:09:19.655466 [DEBUG] sofia.c:9873 sofia/external-kamailio/12013992990@sip.telnyx.com receiving invite from 10.0.9.55:5060 version: 1.6.19+git git f858a27 2017-12-24 07:46:49Z 64bit
  66. 2018-01-11 12:09:19.655466 [DEBUG] sofia.c:7084 Channel sofia/external-kamailio/12013992990@sip.telnyx.com entering state [received][100]
  67. 2018-01-11 12:09:19.655466 [DEBUG] sofia.c:7094 Remote SDP:
  68. v=0
  69. o=Telnyx 1515647013 1515647014 IN IP4 64.16.248.242
  70. s=Telnyx
  71. c=IN IP4 64.16.248.242
  72. t=0 0
  73. m=audio 25546 RTP/AVP 9 0 8 18 101 13
  74. a=rtpmap:9 G722/8000
  75. a=rtpmap:0 PCMU/8000
  76. a=rtpmap:8 PCMA/8000
  77. a=rtpmap:18 G729/8000
  78. a=fmtp:18 annexb=no
  79. a=rtpmap:101 telephone-event/8000
  80. a=fmtp:101 0-16
  81. a=rtpmap:13 CN/8000
  82. a=ptime:20
  83.  
  84. 2018-01-11 12:09:19.655466 [DEBUG] sofia.c:7486 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_NEW -> CS_INIT
  85. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:603 (sofia/external-kamailio/12013992990@sip.telnyx.com) State NEW
  86. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_INIT (Cur 2 Tot 356)
  87. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:627 (sofia/external-kamailio/12013992990@sip.telnyx.com) State INIT
  88. 2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:90 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA INIT
  89. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:40 sofia/external-kamailio/12013992990@sip.telnyx.com Standard INIT
  90. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:48 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_INIT -> CS_ROUTING
  91. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:627 (sofia/external-kamailio/12013992990@sip.telnyx.com) State INIT going to sleep
  92. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_ROUTING (Cur 2 Tot 356)
  93. 2018-01-11 12:09:19.655466 [DEBUG] switch_channel.c:2249 (sofia/external-kamailio/12013992990@sip.telnyx.com) Callstate Change DOWN -> RINGING
  94. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:643 (sofia/external-kamailio/12013992990@sip.telnyx.com) State ROUTING
  95. 2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:143 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA ROUTING
  96. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:236 sofia/external-kamailio/12013992990@sip.telnyx.com Standard ROUTING
  97. 2018-01-11 12:09:19.655466 [INFO] mod_dialplan_xml.c:637 Processing Sergey Safarov <12013992990>->12134237681 in context e911
  98. Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com parsing [e911->911] continue=false
  99. Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com Regex (PASS) [911] destination_number(12134237681) =~ /^1(\d{10})$/ break=on-false
  100. Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com Action set(sip_nat_detected=false)
  101. Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com Action python(dialplan)
  102. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:286 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_ROUTING -> CS_EXECUTE
  103. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:643 (sofia/external-kamailio/12013992990@sip.telnyx.com) State ROUTING going to sleep
  104. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_EXECUTE (Cur 2 Tot 356)
  105. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:650 (sofia/external-kamailio/12013992990@sip.telnyx.com) State EXECUTE
  106. 2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:198 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA EXECUTE
  107. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:328 sofia/external-kamailio/12013992990@sip.telnyx.com Standard EXECUTE
  108. EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com set(sip_nat_detected=false)
  109. 2018-01-11 12:09:19.655466 [DEBUG] mod_dptools.c:1548 SET sofia/external-kamailio/12013992990@sip.telnyx.com [sip_nat_detected]=[false]
  110. EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com python(dialplan)
  111. 2018-01-11 12:09:19.655466 [NOTICE] mod_python.c:212 Invoking py module: dialplan
  112. 2018-01-11 12:09:19.655466 [DEBUG] mod_python.c:283 Call python script
  113. 2018-01-11 12:09:19.655466 [DEBUG] switch_cpp.cpp:1112 sofia/external-kamailio/12013992990@sip.telnyx.com destroy/unlink session from object
  114. EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com info()
  115. 2018-01-11 12:09:19.655466 [INFO] mod_dptools.c:1761 CHANNEL_DATA:
  116. Channel-State: [CS_EXECUTE]
  117. Channel-Call-State: [RINGING]
  118. Channel-State-Number: [4]
  119. Channel-Name: [sofia/external-kamailio/12013992990@sip.telnyx.com]
  120. Unique-ID: [5e07cf5b-2b87-4075-8430-34de18f707c4]
  121. Call-Direction: [inbound]
  122. Presence-Call-Direction: [inbound]
  123. Channel-HIT-Dialplan: [true]
  124. Channel-Call-UUID: [5e07cf5b-2b87-4075-8430-34de18f707c4]
  125. Answer-State: [ringing]
  126. Caller-Direction: [inbound]
  127. Caller-Logical-Direction: [inbound]
  128. Caller-Username: [12013992990]
  129. Caller-Dialplan: [XML]
  130. Caller-Caller-ID-Name: [Sergey Safarov]
  131. Caller-Caller-ID-Number: [12013992990]
  132. Caller-Orig-Caller-ID-Name: [Sergey Safarov]
  133. Caller-Orig-Caller-ID-Number: [12013992990]
  134. Caller-Network-Addr: [10.0.9.55]
  135. Caller-ANI: [12013992990]
  136. Caller-Destination-Number: [12134237681]
  137. Caller-Unique-ID: [5e07cf5b-2b87-4075-8430-34de18f707c4]
  138. Caller-Source: [mod_sofia]
  139. Caller-Context: [e911]
  140. Caller-Channel-Name: [sofia/external-kamailio/12013992990@sip.telnyx.com]
  141. Caller-Profile-Index: [1]
  142. Caller-Profile-Created-Time: [1515672559655466]
  143. Caller-Channel-Created-Time: [1515672559655466]
  144. Caller-Channel-Answered-Time: [0]
  145. Caller-Channel-Progress-Time: [0]
  146. Caller-Channel-Progress-Media-Time: [0]
  147. Caller-Channel-Hangup-Time: [0]
  148. Caller-Channel-Transfer-Time: [0]
  149. Caller-Channel-Resurrect-Time: [0]
  150. Caller-Channel-Bridged-Time: [0]
  151. Caller-Channel-Last-Hold: [0]
  152. Caller-Channel-Hold-Accum: [0]
  153. Caller-Screen-Bit: [true]
  154. Caller-Privacy-Hide-Name: [false]
  155. Caller-Privacy-Hide-Number: [false]
  156. variable_direction: [inbound]
  157. variable_uuid: [5e07cf5b-2b87-4075-8430-34de18f707c4]
  158. variable_session_id: [356]
  159. variable_sip_from_user: [12013992990]
  160. variable_sip_from_uri: [12013992990@sip.telnyx.com]
  161. variable_sip_from_host: [sip.telnyx.com]
  162. variable_video_media_flow: [sendrecv]
  163. variable_audio_media_flow: [sendrecv]
  164. variable_channel_name: [sofia/external-kamailio/12013992990@sip.telnyx.com]
  165. variable_sip_call_id: [17fab07d-716b-1236-7a88-02420a0f0c04]
  166. variable_ep_codec_string: [mod_spandsp.G722@8000h@20i@64000b,CORE_PCM_MODULE.PCMU@8000h@20i@64000b,CORE_PCM_MODULE.PCMA@8000h@20i@64000b]
  167. variable_sip_local_network_addr: [10.0.9.50]
  168. variable_sip_network_ip: [10.0.9.55]
  169. variable_sip_network_port: [5060]
  170. variable_sip_invite_stamp: [1515672559655466]
  171. variable_sip_received_ip: [10.0.9.55]
  172. variable_sip_received_port: [5060]
  173. variable_sip_via_protocol: [udp]
  174. variable_sip_from_user_stripped: [12013992990]
  175. variable_sip_from_tag: [a1QtHc31jj5XH]
  176. variable_sofia_profile_name: [external-kamailio]
  177. variable_recovery_profile_name: [external-kamailio]
  178. variable_sip_P-Asserted-Identity: [12013992990]
  179. variable_sip_cid_type: [pid]
  180. variable_sip_invite_route_uri: [<sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>,<sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>,<sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>,<sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>]
  181. variable_sip_invite_record_route: [<sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>,<sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>,<sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>,<sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>]
  182. variable_sip_full_via: [SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1,SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec,SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr]
  183. variable_sip_recover_via: [SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1,SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec,SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr]
  184. variable_sip_from_display: [Sergey Safarov]
  185. variable_sip_full_from: ["Sergey Safarov" <sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH]
  186. variable_sip_full_to: [<sip:12134237681@office.nga911.com:15080>]
  187. variable_sip_allow: [INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, NOTIFY]
  188. variable_sip_req_user: [12134237681]
  189. variable_sip_req_port: [15080]
  190. variable_sip_req_uri: [12134237681@office.nga911.com:15080]
  191. variable_sip_req_host: [office.nga911.com]
  192. variable_sip_to_user: [12134237681]
  193. variable_sip_to_port: [15080]
  194. variable_sip_to_uri: [12134237681@office.nga911.com:15080]
  195. variable_sip_to_host: [office.nga911.com]
  196. variable_sip_contact_params: [alias=10.15.12.4~55742~2]
  197. variable_sip_contact_user: [mod_sofia]
  198. variable_sip_contact_port: [5082]
  199. variable_sip_contact_uri: [mod_sofia@10.15.12.4:5082]
  200. variable_sip_contact_host: [10.15.12.4]
  201. variable_rtp_use_codec_string: [OPUS,G722,PCMU,PCMA,VP8]
  202. variable_sip_via_host: [10.0.9.55]
  203. variable_max_forwards: [44]
  204. variable_sip_Privacy: [none]
  205. variable_sip_h_X-AUTH-IP: [192.76.120.10]
  206. variable_sip_h_X-AUTH-PORT: [36831]
  207. variable_switch_r_sdp: [v=0
  208. o=Telnyx 1515647013 1515647014 IN IP4 64.16.248.242
  209. s=Telnyx
  210. c=IN IP4 64.16.248.242
  211. t=0 0
  212. m=audio 25546 RTP/AVP 9 0 8 18 101 13
  213. a=rtpmap:9 G722/8000
  214. a=rtpmap:0 PCMU/8000
  215. a=rtpmap:8 PCMA/8000
  216. a=rtpmap:18 G729/8000
  217. a=fmtp:18 annexb=no
  218. a=rtpmap:101 telephone-event/8000
  219. a=fmtp:101 0-16
  220. a=rtpmap:13 CN/8000
  221. a=ptime:20
  222. ]
  223. variable_endpoint_disposition: [DELAYED NEGOTIATION]
  224. variable_DP_MATCH: [ARRAY::12134237681|:2134237681]
  225. variable_call_uuid: [5e07cf5b-2b87-4075-8430-34de18f707c4]
  226. variable_sip_nat_detected: [false]
  227. variable_current_application: [info]
  228.  
  229.  
  230. 2018-01-11 12:09:19.655466 [NOTICE] switch_core_session.c:1683 Session 354 (sofia/external-kamailio/12013992990@sip.telnyx.com) Ended
  231. 2018-01-11 12:09:19.655466 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external-kamailio/12013992990@sip.telnyx.com [CS_DESTROY]
  232. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:741 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_DESTROY (Cur 1 Tot 356)
  233. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:751 (sofia/external-kamailio/12013992990@sip.telnyx.com) State DESTROY
  234. 2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:343 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA DESTROY
  235. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:181 sofia/external-kamailio/12013992990@sip.telnyx.com Standard DESTROY
  236. 2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:751 (sofia/external-kamailio/12013992990@sip.telnyx.com) State DESTROY going to sleep
  237. 2018-01-11 12:09:19.895537 [INFO] switch_cpp.cpp:1365 token: eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEyOCwiaXNzIjoiaHR0cHM6Ly9jc3AubmdhOTExLmNvbS9nZWFyX2FwaS9hdXRoZW50aWNhdGUiLCJpYXQiOjE1MTU2NzI1NTksImV4cCI6MTUxNTczMjU1OSwibmJmIjoxNTE1NjcyNTU5LCJqdGkiOiJzeDRJNm9BV2RqWDZ3elg1In0.qirCUoGn5nm7Ubf4WSytFX9Aq7AelXS98rUMPtyz2HY
  238. 2018-01-11 12:09:19.895537 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('csp_token', 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEyOCwiaXNzIjoiaHR0cHM6Ly9jc3AubmdhOTExLmNvbS9nZWFyX2FwaS9hdXRoZW50aWNhdGUiLCJpYXQiOjE1MTU2NzI1NTksImV4cCI6MTUxNTczMjU1OSwibmJmIjoxNTE1NjcyNTU5LCJqdGkiOiJzeDRJNm9BV2RqWDZ3elg1In0.qirCUoGn5nm7Ubf4WSytFX9Aq7AelXS98rUMPtyz2HY')
  239. 2018-01-11 12:09:20.115447 [INFO] switch_cpp.cpp:1365 esinetEntryRoutes url: http://csp.nga911.com/api/
  240. esinetEntryRoutes/entry/12134237681
  241. 2018-01-11 12:09:20.115447 [INFO] switch_cpp.cpp:1365 esinetEntryRoutes: {u'message': u'Entry Route retrieval failed.', u'data': [], u'success': False}
  242. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_session.c:2647 Application playback Requires media! pre_answering channel sofia/external-kamailio/12013992990@sip.telnyx.com
  243. 2018-01-11 12:09:20.115447 [INFO] switch_core_session.c:2649 Sending early media
  244. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
  245. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  246. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
  247. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  248. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  249. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
  250. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  251. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  252. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  253. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  254. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
  255. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
  256. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  257. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  258. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  259. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
  260. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
  261. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  262. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  263. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  264. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external-kamailio/12013992990@sip.telnyx.com G722/8000 20 ms 160 samples 64000 bits 1 channels
  265. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_codec.c:111 sofia/external-kamailio/12013992990@sip.telnyx.com Original read codec set to G722:9
  266. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  267. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4767 sofia/external-kamailio/12013992990@sip.telnyx.com Set 2833 dtmf send payload to 101 recv payload to 101
  268. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external-kamailio/12013992990@sip.telnyx.com] 172.18.0.12 port 18352 -> 64.16.248.242 port 25546 codec: 9 ms: 20
  269. 2018-01-11 12:09:20.115447 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
  270. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:7180 sofia/external-kamailio/12013992990@sip.telnyx.com Set 2833 dtmf send payload to 101
  271. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:7187 sofia/external-kamailio/12013992990@sip.telnyx.com Set 2833 dtmf receive payload to 101
  272. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:7210 sofia/external-kamailio/12013992990@sip.telnyx.com Set rtp dtmf delay to 40
  273. 2018-01-11 12:09:20.115447 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external-kamailio/12013992990@sip.telnyx.com!
  274. 2018-01-11 12:09:20.115447 [DEBUG] switch_channel.c:3474 (sofia/external-kamailio/12013992990@sip.telnyx.com) Callstate Change RINGING -> EARLY
  275. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/external-kamailio/12013992990@sip.telnyx.com.
  276. 2018-01-11 12:09:20.115447 [DEBUG] mod_sofia.c:2364 Ring SDP:
  277. v=0
  278. o=FreeSWITCH 1515654208 1515654209 IN IP4 34.214.12.24
  279. s=FreeSWITCH
  280. c=IN IP4 34.214.12.24
  281. t=0 0
  282. m=audio 18352 RTP/AVP 9 101
  283. a=rtpmap:9 G722/8000
  284. a=rtpmap:101 telephone-event/8000
  285. a=fmtp:101 0-16
  286. a=ptime:20
  287. a=sendrecv
  288.  
  289. EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com playback(error)
  290. 2018-01-11 12:09:20.115447 [ERR] mod_native_file.c:74 Error opening /usr/share/freeswitch/sounds/en/us/callie/error.G722
  291. send 1502 bytes to udp/[10.0.9.55]:5060 at 12:09:20.121044:
  292.    ------------------------------------------------------------------------
  293.    SIP/2.0 183 Session Progress
  294.    Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
  295.    Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
  296.    v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
  297.    Record-Route: <sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>
  298.    Record-Route: <sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>
  299.    Record-Route: <sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
  300.    Record-Route: <sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
  301.    f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
  302.    To: <sip:12134237681@office.nga911.com:15080>;tag=jHa17jcp7XrtH
  303.    i:17fab07d-716b-1236-7a88-02420a0f0c04
  304.    CSeq:117500215 INVITE
  305.    Contact: <sip:12134237681@10.0.9.50:12000;transport=udp>
  306.    User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
  307.    Accept: application/sdp
  308.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  309.    Supported: timer, path, replaces
  310.    Allow-Events: talk, hold, conference, refer
  311.    Content-Type: application/sdp
  312.    Content-Disposition: session
  313.    Content-Length: 220
  314.    P-Asserted-Identity: "12134237681" <sip:12134237681@office.nga911.com>
  315.    
  316.    v=0
  317.    o=FreeSWITCH 1515654208 1515654209 IN IP4 34.214.12.24
  318.    s=FreeSWITCH
  319.    c=IN IP4 34.214.12.24
  320.    t=0 0
  321.    m=audio 18352 RTP/AVP 9 101
  322.    a=rtpmap:9 G722/8000
  323.    a=rtpmap:101 telephone-event/8000
  324.    a=fmtp:101 0-16
  325.    a=ptime:20
  326.    ------------------------------------------------------------------------
  327. 2018-01-11 12:09:20.115447 [ERR] mod_sndfile.c:204 Error Opening File [/usr/share/freeswitch/sounds/en/us/callie/error.wav] [System error : No such file or directory.]
  328. 2018-01-11 12:09:20.115447 [DEBUG] sofia.c:7084 Channel sofia/external-kamailio/12013992990@sip.telnyx.com entering state [early][183]
  329. 2018-01-11 12:09:20.115447 [DEBUG] mod_python.c:286 Finished calling python script
  330. 2018-01-11 12:09:20.115447 [NOTICE] switch_core_state_machine.c:385 sofia/external-kamailio/12013992990@sip.telnyx.com has executed the last dialplan instruction, hanging up.
  331. 2018-01-11 12:09:20.115447 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external-kamailio/12013992990@sip.telnyx.com [CS_EXECUTE] [NORMAL_CLEARING]
  332. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:650 (sofia/external-kamailio/12013992990@sip.telnyx.com) State EXECUTE going to sleep
  333. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_HANGUP (Cur 1 Tot 356)
  334. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:850 (sofia/external-kamailio/12013992990@sip.telnyx.com) Callstate Change EARLY -> HANGUP
  335. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:852 (sofia/external-kamailio/12013992990@sip.telnyx.com) State HANGUP
  336. 2018-01-11 12:09:20.115447 [DEBUG] mod_sofia.c:438 Channel sofia/external-kamailio/12013992990@sip.telnyx.com hanging up, cause: NORMAL_CLEARING
  337. 2018-01-11 12:09:20.115447 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
  338. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:60 sofia/external-kamailio/12013992990@sip.telnyx.com Standard HANGUP, cause: NORMAL_CLEARING
  339. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:852 (sofia/external-kamailio/12013992990@sip.telnyx.com) State HANGUP going to sleep
  340. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:619 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_HANGUP -> CS_REPORTING
  341. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_REPORTING (Cur 1 Tot 356)
  342. send 910 bytes to udp/[10.0.9.55]:5060 at 12:09:20.121884:
  343.    ------------------------------------------------------------------------
  344.    SIP/2.0 480 Temporarily Unavailable
  345.    Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
  346.    Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
  347.    v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
  348.    Max-Forwards: 44
  349.    f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
  350.    To: <sip:12134237681@office.nga911.com:15080>;tag=jHa17jcp7XrtH
  351.    i:17fab07d-716b-1236-7a88-02420a0f0c04
  352.    CSeq:117500215 INVITE
  353.    User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
  354.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  355.    Supported: timer, path, replaces
  356.    Allow-Events: talk, hold, conference, refer
  357.    Reason: Q.850;cause=16;text="NORMAL_CLEARING"
  358.    Content-Length: 0
  359.    P-Asserted-Identity: "12134237681" <sip:12134237681@office.nga911.com>
  360.    
  361.    ------------------------------------------------------------------------
  362. 2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:938 (sofia/external-kamailio/12013992990@sip.telnyx.com) State REPORTING
  363. recv 359 bytes from udp/[10.0.9.55]:5060 at 12:09:20.122573:
  364.    ------------------------------------------------------------------------
  365.    ACK sip:12134237681@office.nga911.com:15080 SIP/2.0
  366.    Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
  367.    Max-Forwards:44
  368.    f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
  369.    To: <sip:12134237681@office.nga911.com:15080>;tag=jHa17jcp7XrtH
  370.    i:17fab07d-716b-1236-7a88-02420a0f0c04
  371.    CSeq:117500215 ACK
  372.    l: 0
  373.    
  374.    ------------------------------------------------------------------------
  375. 2018-01-11 12:09:20.375470 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
  376. 2018-01-11 12:09:20.375470 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
  377. 2018-01-11 12:09:22.725466 [NOTICE] sofia_reg.c:448 Registering kazoo
  378. send 822 bytes to udp/[52.42.195.203]:5060 at 12:09:22.745610:
  379.    ------------------------------------------------------------------------
  380.    REGISTER sip:node1.nga911.com;transport=udp SIP/2.0
  381.    Via: SIP/2.0/UDP 52.24.72.57:5080;rport;branch=z9hG4bK86raX05cQ8gae
  382.    Max-Forwards: 70
  383.    From: <sip:queries1@node1.nga911.com>;tag=8XQ4Za3H2tD8g
  384.    To: <sip:queries1@node1.nga911.com>
  385.    Call-ID: 1268c844-60be-4a27-9325-bb3155eec8af
  386.    CSeq: 117500202 REGISTER
  387.    Contact: <sip:gw+kazoo@52.24.72.57:5080;transport=udp;gw=kazoo>
  388.    Expires: 30
  389.    User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
  390.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  391.    Supported: timer, path, replaces
  392.    Authorization: Digest username="queries1", realm="node1.nga911.com", nonce="WldU3FpXU7Ca5zf6SMinI2t36d3oUXlW", algorithm=MD5, uri="sip:node1.nga911.com;transport=udp", response="21e4c96c435809ed68656ef92732a1c7"
  393.    Content-Length: 0
  394.    
  395.    ------------------------------------------------------------------------
  396. recv 440 bytes from udp/[52.42.195.203]:5060 at 12:09:22.767369:
  397.    ------------------------------------------------------------------------
  398.    SIP/2.0 200 OK
  399.    Via: SIP/2.0/UDP 52.24.72.57:5080;rport=5080;branch=z9hG4bK86raX05cQ8gae;received=34.214.12.24
  400.    From: <sip:queries1@node1.nga911.com>;tag=8XQ4Za3H2tD8g
  401.    To: <sip:queries1@node1.nga911.com>;tag=bdded40c8142006f90af49be63d6cf32-6b23
  402.    Call-ID: 1268c844-60be-4a27-9325-bb3155eec8af
  403.    CSeq: 117500202 REGISTER
  404.    Contact: <sip:gw+kazoo@52.24.72.57:5080;transport=udp;gw=kazoo>;expires=300
  405.    Supported: outbound
  406.    Content-Length: 0
  407.    
  408.    ------------------------------------------------------------------------
  409. 2018-01-11 12:09:22.765513 [DEBUG] sofia_reg.c:2435 Changing expire time to 300 by request of proxy sip:node1.nga911.com
  410. 2018-01-11 12:09:22.845469 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
  411. 2018-01-11 12:09:22.845469 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
  412. 2018-01-11 12:09:25.065472 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
  413. 2018-01-11 12:09:25.065472 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
  414. 2018-01-11 12:09:27.355470 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
  415. 2018-01-11 12:09:27.355470 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
  416. 2018-01-11 12:09:27.355470 [ERR] mod_xml_cdr.c:418 Unable to post to web server, writing to file
  417. 2018-01-11 12:09:27.355470 [DEBUG] switch_core_state_machine.c:174 sofia/external-kamailio/12013992990@sip.telnyx.com Standard REPORTING, cause: NORMAL_CLEARING
  418. 2018-01-11 12:09:27.355470 [DEBUG] switch_core_state_machine.c:938 (sofia/external-kamailio/12013992990@sip.telnyx.com) State REPORTING going to sleep
  419. 2018-01-11 12:09:27.355470 [DEBUG] switch_core_state_machine.c:610 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_REPORTING -> CS_DESTROY
  420. 2018-01-11 12:09:27.355470 [DEBUG] switch_core_session.c:1665 Session 356 (sofia/external-kamailio/12013992990@sip.telnyx.com) Locked, Waiting on external entities
  421. recv 326 bytes from udp/[10.0.9.54]:5060 at 12:09:28.413832:
  422.    ------------------------------------------------------------------------
  423.    OPTIONS sip:10.0.9.50:12000 SIP/2.0
  424.    Via: SIP/2.0/UDP 10.0.9.54;branch=z9hG4bKae87.00980432000000000000000000000000.0
  425.    To: <sip:10.0.9.50:12000>
  426.    From: <sip:sipcheck@proxy2a-pre.kazoo>;tag=dd842359c3d1f52b828bb146259eb8e4-8608
  427.    CSeq: 10 OPTIONS
  428.    Call-ID: 60ec4ccf27887dd6-105@10.0.9.54
  429.    Max-Forwards: 70
  430.