From ft, 3 Years ago, written in Plain Text.
- go back
Embed
Viewing differences between and reinvitebreak
  1. freeswitch@test>
  2. freeswitch@test>
  3. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  4. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  5. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f9668011390 from (udp/192.168.1.166:5080) has 4 bytes, veclen = 1
  6. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): bad msg 0x7f9668011390 (4 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  7. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  8. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  9. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f96680285d0 from (udp/192.168.1.166:5080) has 766 bytes, veclen = 1
  10. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f96680285d0 (766 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  11. nta.c:2951 agent_recv_request() nta: received INVITE sip:0000@192.168.1.166:5080;transport=UDP SIP/2.0 (CSeq 1) (load: 0 rps)
  12. nta.c:3319 agent_aliases() nta: canonizing sip:0000@192.168.1.166:5080 with contact
  13. nta.c:3156 agent_recv_request() nta: INVITE (1) going to a default leg
  14. nta.c:1362 set_timeout() nta: timer set to 200 ms
  15. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  16. nua_stack.c:935 nh_create() nua: nh_create: entering
  17. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  18. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  19. soa.c:280 soa_clone() soa_clone(static::0x7f9668001b90, 0x7f9668001390, 0x7f9668001fb0) called
  20. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
  21. nta.c:4488 nta_leg_tcreate() nta_leg_tcreate(0x7f966800eca0)
  22. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f9668012dd0) called
  23. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f9668012dd0, (nil), 0x7f9668012832, 188) called
  24. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f9668001fb0): adding session usage
  25. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_invite 100 Trying
  26. nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: init -> received, received offer
  27. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f9668012dd0, [0x7f9696768610], [0x7f9696768618], [(nil)]) called
  28. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 100 Trying
  29. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  30. nua.c:341 nua_handle_bind() nua: nua_handle_bind: entering
  31. 2021-12-15 13:16:06.306094 93.63% [NOTICE] switch_channel.c:1123 New Channel sofia/external/1234@192.168.1.166:5080 [28a9abce-1577-436d-a925-168503e5c82c]
  32. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  33. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  34. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  35. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  36. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  37. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  38. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  39. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  40. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  41. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  42. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  43. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  44. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  45. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_NEW (Cur 1 Tot 9)
  46. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  47. 2021-12-15 13:16:06.306094 93.63% [INFO] sofia.c:10462 sofia/external/1234@192.168.1.166:5080 receiving invite from 192.168.1.166:44068 version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit call-id: YqPqtGVJcra2S-9IwR-khw..
  48. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  49. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  50. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  51. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  52. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  53. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  54. 2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [received][100]
  55. 2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7509 Remote SDP:
  56. v=0
  57. o=Z 1639574166265 1 IN IP4 192.168.1.166
  58. s=Z
  59. c=IN IP4 192.168.1.166
  60. t=0 0
  61. m=audio 8000 RTP/AVP 106
  62. a=rtpmap:106 opus/48000/2
  63. a=fmtp:106 minptime=20; useinbandfec=1
  64.  
  65. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  66. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  67. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:1]
  68. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
  69. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  70. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  71. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_opus.c:619 Opus encoder: set bitrate to local settings [72000bps]
  72. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_opus.c:619 Opus encoder: set bitrate to local settings [72000bps]
  73. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:3872 Set Codec sofia/external/1234@192.168.1.166:5080 opus/48000 20 ms 960 samples 0 bits 1 channels
  74. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_codec.c:111 sofia/external/1234@192.168.1.166:5080 Original read codec set to opus:116
  75. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5982 No 2833 in SDP.  Disable 2833 dtmf and switch to INFO
  76. 2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7933 (sofia/external/1234@192.168.1.166:5080) State Change CS_NEW -> CS_INIT
  77. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  78. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  79. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  80. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  81. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  82. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:600 (sofia/external/1234@192.168.1.166:5080) State NEW
  83. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  84. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  85. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_INIT (Cur 1 Tot 9)
  86. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/1234@192.168.1.166:5080) State INIT
  87. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:97 sofia/external/1234@192.168.1.166:5080 SOFIA INIT
  88. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:40 sofia/external/1234@192.168.1.166:5080 Standard INIT
  89. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:48 (sofia/external/1234@192.168.1.166:5080) State Change CS_INIT -> CS_ROUTING
  90. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/1234@192.168.1.166:5080) State INIT going to sleep
  91. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_ROUTING (Cur 1 Tot 9)
  92. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_channel.c:2380 (sofia/external/1234@192.168.1.166:5080) Callstate Change DOWN -> RINGING
  93. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/1234@192.168.1.166:5080) State ROUTING
  94. nua.c:878 nua_respond() nua: nua_respond: entering
  95. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_respond
  96. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:158 sofia/external/1234@192.168.1.166:5080 SOFIA ROUTING
  97. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:230 sofia/external/1234@192.168.1.166:5080 Standard ROUTING
  98. 2021-12-15 13:16:06.306094 93.63% [INFO] mod_dialplan_xml.c:639 Processing 1234 <1234>->0000 in context public
  99. nua_stack.c:603 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_respond 100 Trying
  100. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  101. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
  102. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
  103. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
  104. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
  105. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 367 bytes of 367 to udp/192.168.1.166:44068
  106. tport.c:3521 tport_send_msg() tport_vsend returned 367
  107. Dialplan: sofia/external/1234@192.168.1.166:5080 parsing [public->ex0] continue=false
  108. nta.c:6868 incoming_reply() nta: sent 100 Trying for INVITE (1)
  109. Dialplan: sofia/external/1234@192.168.1.166:5080 Regex (PASS) [ex0] destination_number(0000) =~ /0000/ break=on-false
  110. Dialplan: sofia/external/1234@192.168.1.166:5080 Action info()
  111. Dialplan: sofia/external/1234@192.168.1.166:5080 Action set(hangup_after_bridge=true)
  112. Dialplan: sofia/external/1234@192.168.1.166:5080 Action export(nolocal:absolute_codec_string=PCMA)
  113. Dialplan: sofia/external/1234@192.168.1.166:5080 Action bridge(sofia/external/7777@192.168.1.166:5090)
  114. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:281 (sofia/external/1234@192.168.1.166:5080) State Change CS_ROUTING -> CS_EXECUTE
  115. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/1234@192.168.1.166:5080) State ROUTING going to sleep
  116. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_EXECUTE (Cur 1 Tot 9)
  117. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:647 (sofia/external/1234@192.168.1.166:5080) State EXECUTE
  118. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:213 sofia/external/1234@192.168.1.166:5080 SOFIA EXECUTE
  119. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:323 sofia/external/1234@192.168.1.166:5080 Standard EXECUTE
  120. EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 info()
  121. 2021-12-15 13:16:06.306094 93.63% [INFO] mod_dptools.c:1898 CHANNEL_DATA:
  122. Channel-State: [CS_EXECUTE]
  123. Channel-Call-State: [RINGING]
  124. Channel-State-Number: [4]
  125. Channel-Name: [sofia/external/1234@192.168.1.166:5080]
  126. Unique-ID: [28a9abce-1577-436d-a925-168503e5c82c]
  127. Call-Direction: [inbound]
  128. Presence-Call-Direction: [inbound]
  129. Channel-HIT-Dialplan: [true]
  130. Channel-Call-UUID: [28a9abce-1577-436d-a925-168503e5c82c]
  131. Answer-State: [ringing]
  132. Channel-Read-Codec-Name: [opus]
  133. Channel-Read-Codec-Rate: [48000]
  134. Channel-Read-Codec-Bit-Rate: [0]
  135. Channel-Write-Codec-Name: [opus]
  136. Channel-Write-Codec-Rate: [48000]
  137. Channel-Write-Codec-Bit-Rate: [0]
  138. Caller-Direction: [inbound]
  139. Caller-Logical-Direction: [inbound]
  140. Caller-Username: [1234]
  141. Caller-Dialplan: [XML]
  142. Caller-Caller-ID-Name: [1234]
  143. Caller-Caller-ID-Number: [1234]
  144. Caller-Orig-Caller-ID-Name: [1234]
  145. Caller-Orig-Caller-ID-Number: [1234]
  146. Caller-Network-Addr: [192.168.1.166]
  147. Caller-ANI: [1234]
  148. Caller-Destination-Number: [0000]
  149. Caller-Unique-ID: [28a9abce-1577-436d-a925-168503e5c82c]
  150. Caller-Source: [mod_sofia]
  151. Caller-Context: [public]
  152. Caller-Channel-Name: [sofia/external/1234@192.168.1.166:5080]
  153. Caller-Profile-Index: [1]
  154. Caller-Profile-Created-Time: [1639574166306094]
  155. Caller-Channel-Created-Time: [1639574166306094]
  156. Caller-Channel-Answered-Time: [0]
  157. Caller-Channel-Progress-Time: [0]
  158. Caller-Channel-Progress-Media-Time: [0]
  159. Caller-Channel-Hangup-Time: [0]
  160. Caller-Channel-Transfer-Time: [0]
  161. Caller-Channel-Resurrect-Time: [0]
  162. Caller-Channel-Bridged-Time: [0]
  163. Caller-Channel-Last-Hold: [0]
  164. Caller-Channel-Hold-Accum: [0]
  165. Caller-Screen-Bit: [true]
  166. Caller-Privacy-Hide-Name: [false]
  167. Caller-Privacy-Hide-Number: [false]
  168. variable_direction: [inbound]
  169. variable_uuid: [28a9abce-1577-436d-a925-168503e5c82c]
  170. variable_session_id: [9]
  171. variable_sip_from_params: [transport=UDP]
  172. variable_sip_from_user: [1234]
  173. variable_sip_from_port: [5080]
  174. variable_sip_from_uri: [1234@192.168.1.166:5080]
  175. variable_sip_from_host: [192.168.1.166]
  176. variable_video_media_flow: [disabled]
  177. variable_text_media_flow: [disabled]
  178. variable_channel_name: [sofia/external/1234@192.168.1.166:5080]
  179. variable_sip_call_id: [YqPqtGVJcra2S-9IwR-khw..]
  180. variable_sip_local_network_addr: [192.168.1.166]
  181. variable_sip_network_ip: [192.168.1.166]
  182. variable_sip_network_port: [44068]
  183. variable_sip_invite_stamp: [1639574166306094]
  184. variable_sip_received_ip: [192.168.1.166]
  185. variable_sip_received_port: [44068]
  186. variable_sip_via_protocol: [udp]
  187. variable_sip_from_user_stripped: [1234]
  188. variable_sip_from_tag: [1cc66e3d]
  189. variable_sofia_profile_name: [external]
  190. variable_sofia_profile_url: [sip:mod_sofia@192.168.1.166:5080]
  191. variable_recovery_profile_name: [external]
  192. variable_sip_full_via: [SIP/2.0/UDP 192.168.1.166:44068;branch=z9hG4bK-524287-1---54f2af585e8554e1;rport=44068]
  193. variable_sip_full_from: [<sip:1234@192.168.1.166:5080;transport=UDP>;tag=1cc66e3d]
  194. variable_sip_full_to: [<sip:0000@192.168.1.166:5080>]
  195. variable_sip_allow: [INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE]
  196. variable_sip_req_params: [transport=UDP]
  197. variable_sip_req_user: [0000]
  198. variable_sip_req_port: [5080]
  199. variable_sip_req_uri: [0000@192.168.1.166:5080]
  200. variable_sip_req_host: [192.168.1.166]
  201. variable_sip_to_user: [0000]
  202. variable_sip_to_port: [5080]
  203. variable_sip_to_uri: [0000@192.168.1.166:5080]
  204. variable_sip_to_host: [192.168.1.166]
  205. variable_sip_contact_params: [transport=UDP]
  206. variable_sip_contact_user: [1234]
  207. variable_sip_contact_port: [44068]
  208. variable_sip_contact_uri: [1234@192.168.1.166:44068]
  209. variable_sip_contact_host: [192.168.1.166]
  210. variable_sip_user_agent: [Z 5.4.12 v2.10.13.2-mod]
  211. variable_sip_via_host: [192.168.1.166]
  212. variable_sip_via_port: [44068]
  213. variable_sip_via_rport: [44068]
  214. variable_max_forwards: [70]
  215. variable_switch_r_sdp: [v=0
  216. o=Z 1639574166265 1 IN IP4 192.168.1.166
  217. s=Z
  218. c=IN IP4 192.168.1.166
  219. t=0 0
  220. m=audio 8000 RTP/AVP 106
  221. a=rtpmap:106 opus/48000/2
  222. a=fmtp:106 minptime=20; useinbandfec=1
  223. ]
  224. variable_ep_codec_string: [mod_opus.opus@48000h@20i@2c]
  225. variable_rtp_use_codec_string: [OPUS,PCMU,PCMA,VP8,VP9]
  226. variable_remote_video_media_flow: [inactive]
  227. variable_remote_text_media_flow: [inactive]
  228. variable_remote_audio_media_flow: [sendrecv]
  229. variable_audio_media_flow: [sendrecv]
  230. variable_remote_media_ip: [192.168.1.166]
  231. variable_remote_media_port: [8000]
  232. variable_rtp_audio_recv_pt: [106]
  233. variable_rtp_use_codec_name: [opus]
  234. variable_rtp_use_codec_fmtp: [minptime=20; useinbandfec=1]
  235. variable_rtp_use_codec_rate: [48000]
  236. variable_rtp_use_codec_ptime: [20]
  237. variable_rtp_use_codec_channels: [1]
  238. variable_rtp_last_audio_codec_string: [opus@48000h@20i@1c]
  239. variable_read_codec: [opus]
  240. variable_original_read_codec: [opus]
  241. variable_read_rate: [48000]
  242. variable_original_read_rate: [48000]
  243. variable_write_codec: [opus]
  244. variable_write_rate: [48000]
  245. variable_dtmf_type: [info]
  246. variable_endpoint_disposition: [RECEIVED]
  247. variable_call_uuid: [28a9abce-1577-436d-a925-168503e5c82c]
  248. variable_current_application: [info]
  249.  
  250.  
  251. EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 set(hangup_after_bridge=true)
  252. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_dptools.c:1685 SET sofia/external/1234@192.168.1.166:5080 [hangup_after_bridge]=[true]
  253. EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 export(nolocal:absolute_codec_string=PCMA)
  254. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[PCMA]
  255. EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 bridge(sofia/external/7777@192.168.1.166:5090)
  256. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_channel.c:1269 sofia/external/1234@192.168.1.166:5080 EXPORTING[export_vars] [absolute_codec_string]=[PCMA] to event
  257. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  258. 2021-12-15 13:16:06.306094 93.63% [NOTICE] switch_channel.c:1123 New Channel sofia/external/7777@192.168.1.166:5090 [1f6e2bc8-89bb-4089-881d-575b56c6f0b3]
  259. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:5121 (sofia/external/7777@192.168.1.166:5090) State Change CS_NEW -> CS_INIT
  260. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_INIT (Cur 2 Tot 10)
  261. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/7777@192.168.1.166:5090) State INIT
  262. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:97 sofia/external/7777@192.168.1.166:5090 SOFIA INIT
  263. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
  264. nua.c:341 nua_handle_bind() nua: nua_handle_bind: entering
  265. 2021-12-15 13:16:06.306094 93.63% [INFO] sofia_glue.c:1651 sofia/external/7777@192.168.1.166:5090 sending invite call-id: (null)
  266. 2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia_glue.c:1654 sofia/external/7777@192.168.1.166:5090 sending invite version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit
  267. Local SDP:
  268. v=0
  269. o=FreeSWITCH 1639544422 1639544423 IN IP4 192.168.1.166
  270. s=FreeSWITCH
  271. c=IN IP4 192.168.1.166
  272. t=0 0
  273. m=audio 29744 RTP/AVP 8 101 13
  274. a=rtpmap:8 PCMA/8000
  275. a=rtpmap:101 telephone-event/8000
  276. a=fmtp:101 0-15
  277. a=rtpmap:13 CN/8000
  278. a=ptime:20
  279. a=sendrecv
  280.  
  281. nua.c:632 nua_invite() nua: nua_invite: entering
  282. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_invite
  283. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:40 sofia/external/7777@192.168.1.166:5090 Standard INIT
  284. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:48 (sofia/external/7777@192.168.1.166:5090) State Change CS_INIT -> CS_ROUTING
  285. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/7777@192.168.1.166:5090) State INIT going to sleep
  286. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_invite
  287. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  288. soa.c:280 soa_clone() soa_clone(static::0x7f9668001b90, 0x7f9668001390, 0x7f96340037a0) called
  289. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
  290. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
  291. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f9668024df0, (nil), 0x7f963401445c, -1) called
  292. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f9668024df0, (nil), 0x7f963401445c, -1) called
  293. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f96340037a0): adding session usage
  294. nta.c:4488 nta_leg_tcreate() nta_leg_tcreate(0x7f9668018240)
  295. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_ROUTING (Cur 2 Tot 10)
  296. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f9668024df0) called
  297. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f9668024df0, 0) called
  298. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f9668024df0, soa_generate_offer): called
  299. soa_static.c:1189 offer_answer_step() soa_static(0x7f9668024df0, soa_generate_offer): generating local description
  300. soa_static.c:1217 offer_answer_step() soa_static(0x7f9668024df0, soa_generate_offer): upgrade with local description
  301. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f96967667e0, (nil), ""): called
  302. soa_static.c:1446 offer_answer_step() soa_static(0x7f9668024df0, soa_generate_offer): storing local description
  303. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668024df0, [(nil)], [0x7f9696768960], [0x7f969676895c]) called
  304. nta.c:2707 nta_tpn_by_url() nta: selecting scheme sip
  305. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/7777@192.168.1.166:5090) State ROUTING
  306. 2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:158 sofia/external/7777@192.168.1.166:5090 SOFIA ROUTING
  307. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_ivr_originate.c:67 (sofia/external/7777@192.168.1.166:5090) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  308. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = */192.168.1.166:5090
  309. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/7777@192.168.1.166:5090) State ROUTING going to sleep
  310. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:5090
  311. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 10)
  312. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name */192.168.1.166:5090
  313. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:659 (sofia/external/7777@192.168.1.166:5090) State CONSUME_MEDIA
  314. 2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:659 (sofia/external/7777@192.168.1.166:5090) State CONSUME_MEDIA going to sleep
  315. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 1049 bytes of 1049 to udp/192.168.1.166:5090
  316. tport.c:3521 tport_send_msg() tport_vsend returned 1049
  317. nta.c:8390 outgoing_send() nta: sent INVITE (45233291) to */192.168.1.166:5090
  318. tport.c:4189 tport_pend() tport_pend(0x7f96680062f0): pending 0x7f96680289e0 for udp/192.168.1.166:5080 (already 0)
  319. nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: init -> calling, sent offer
  320. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668024df0, [0x7f9696768940], [0x7f9696768948], [(nil)]) called
  321. nua_stack.c:299 nua_stack_event() nua(0x7f96340037a0): event i_state INVITE sent
  322. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  323. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  324. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  325. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  326. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  327. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  328. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  329. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  330. 2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [calling][0]
  331. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  332. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  333. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  334. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  335. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  336. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  337. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  338. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  339. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  340. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801e970 from (udp/192.168.1.166:5080) has 253 bytes, veclen = 1
  341. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801e970 (253 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  342. nta.c:3370 agent_recv_response() nta: received 100 Trying for INVITE (45233291)
  343. nta.c:3437 agent_recv_response() nta: 100 Trying is going to a transaction
  344. nta.c:9684 outgoing_estimate_delay() nta_outgoing: RTT is 10.244 ms
  345. tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f96680289e0 by 0x7f9668027ad0 with 0x7f966801e970 (preliminary)
  346. nta.c:1301 agent_timer() nta: timer not set
  347. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  348. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  349. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801e970 from (udp/192.168.1.166:5080) has 346 bytes, veclen = 1
  350. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801e970 (346 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  351. nta.c:3370 agent_recv_response() nta: received 180 Ringing for INVITE (45233291)
  352. nta.c:3437 agent_recv_response() nta: 180 Ringing is going to a transaction
  353. tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f96680289e0 by 0x7f9668027ad0 with 0x7f966801e970 (preliminary)
  354. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event r_invite 180 Ringing
  355. nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: calling -> proceeding
  356. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 180 Ringing
  357. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  358. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  359. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  360. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  361. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  362. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  363. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  364. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  365. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  366. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  367. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  368. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  369. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  370. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  371. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  372. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  373. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  374. 2021-12-15 13:16:06.566002 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [proceeding][180]
  375. 2021-12-15 13:16:06.566002 93.63% [NOTICE] sofia.c:7610 Ring-Ready sofia/external/7777@192.168.1.166:5090!
  376. 2021-12-15 13:16:06.566002 93.63% [DEBUG] switch_channel.c:3494 (sofia/external/7777@192.168.1.166:5090) Callstate Change DOWN -> RINGING
  377. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  378. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  379. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  380. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  381. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  382. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  383. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  384. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  385. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  386. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  387. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  388. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  389. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  390. nua.c:878 nua_respond() nua: nua_respond: entering
  391. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_respond
  392. 2021-12-15 13:16:06.586006 93.63% [NOTICE] mod_sofia.c:2515 Ring-Ready sofia/external/1234@192.168.1.166:5080!
  393. 2021-12-15 13:16:06.586006 93.63% [NOTICE] switch_ivr_originate.c:565 Ring Ready sofia/external/1234@192.168.1.166:5080!
  394. nua_stack.c:603 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_respond 180 Ringing
  395. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  396. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
  397. nua_session.c:2318 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  398. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
  399. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
  400. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
  401. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 729 bytes of 729 to udp/192.168.1.166:44068
  402. tport.c:3521 tport_send_msg() tport_vsend returned 729
  403. nta.c:6868 incoming_reply() nta: sent 180 Ringing for INVITE (1)
  404. nta.c:1362 set_timeout() nta: timer set to 60000 ms
  405. nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: received -> early
  406. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 180 Ringing
  407. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  408. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  409. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  410. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  411. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  412. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  413. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  414. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  415. 2021-12-15 13:16:06.606012 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [early][180]
  416. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  417. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  418. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  419. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  420. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  421. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  422. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  423. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  424. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  425. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f9668011370 from (udp/192.168.1.166:5080) has 752 bytes, veclen = 1
  426. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f9668011370 (752 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  427. nta.c:3370 agent_recv_response() nta: received 200 Ok for INVITE (45233291)
  428. nta.c:3437 agent_recv_response() nta: 200 Ok is going to a transaction
  429. tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f96680289e0 by 0x7f9668027ad0 with 0x7f9668011370
  430. nta.c:1360 set_timeout() nta: timer shortened to 32000 ms
  431. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f9668024df0, (nil), 0x7f9634000b2f, 145) called
  432. soa.c:1595 soa_process_answer() soa_process_answer(static::0x7f9668024df0) called
  433. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f9668024df0, soa_process_answer): called
  434. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f9668010050, 0x7f966801a0b0, ""): called
  435. soa_static.c:1304 offer_answer_step() soa_static(0x7f9668024df0, soa_process_answer): upgrade codecs with remote description
  436. soa.c:1730 soa_activate() soa_activate(static::0x7f9668024df0, (nil)) called
  437. nua_session.c:986 nua_session_client_response() nua(0x7f96340037a0): INVITE: processed SDP answer in 200 Ok (200)
  438. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event r_invite 200 Ok
  439. nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: proceeding -> completing, received answer
  440. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f9668024df0, [0x7f9696768320], [0x7f9696768328], [(nil)]) called
  441. soa.c:616 soa_get_params() soa_get_params(static::0x7f9668024df0, ...) called
  442. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 200 Ok
  443. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  444. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  445. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  446. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  447. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  448. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  449. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  450. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  451. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  452. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  453. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  454. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  455. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  456. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  457. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  458. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  459. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  460. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  461. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  462. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  463. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  464. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  465. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  466. 2021-12-15 13:16:08.106041 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [completing][200]
  467. 2021-12-15 13:16:08.106041 92.23% [DEBUG] sofia.c:7509 Remote SDP:
  468. v=0
  469. o=9999 450 2195 IN IP4 192.168.1.166
  470. s=Talk
  471. c=IN IP4 192.168.1.166
  472. t=0 0
  473. m=audio 7078 RTP/AVP 8 101
  474. a=rtpmap:101 telephone-event/8000
  475.  
  476. nua.c:638 nua_ack() nua: nua_ack: entering
  477. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_ack
  478. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  479. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  480. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  481. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  482. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_ack
  483. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  484. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  485. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
  486. soa.c:1730 soa_activate() soa_activate(static::0x7f9668024df0, (nil)) called
  487. nta.c:2707 nta_tpn_by_url() nta: selecting scheme sip
  488. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = udp/192.168.1.166:5090
  489. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:5090
  490. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name udp/192.168.1.166:5090
  491. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 381 bytes of 381 to udp/192.168.1.166:5090
  492. tport.c:3521 tport_send_msg() tport_vsend returned 381
  493. nta.c:8390 outgoing_send() nta: sent ACK (45233291) to udp/192.168.1.166:5090
  494. nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: completing -> ready
  495. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 200 ACK sent
  496. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_active 200 Call active
  497. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  498. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  499. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  500. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  501. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  502. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  503. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  504. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  505. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  506. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  507. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  508. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  509. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  510. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  511. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  512. 2021-12-15 13:16:08.106041 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [ready][200]
  513. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  514. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  515. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  516. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  517. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5568 Set telephone-event payload to 101@8000
  518. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:3872 Set Codec sofia/external/7777@192.168.1.166:5090 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  519. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_codec.c:111 sofia/external/7777@192.168.1.166:5090 Original read codec set to PCMA:8
  520. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5917 Set telephone-event payload to 101@8000
  521. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5975 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf send payload to 101 recv payload to 101
  522. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:8779 AUDIO RTP [sofia/external/7777@192.168.1.166:5090] 192.168.1.166 port 29744 -> 192.168.1.166 port 7078 codec: 8 ms: 20
  523. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_rtp.c:4641 Not using a timer
  524. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9091 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf send payload to 101
  525. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9098 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf receive payload to 101
  526. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9121 sofia/external/7777@192.168.1.166:5090 Set rtp dtmf delay to 40
  527. 2021-12-15 13:16:08.106041 92.23% [NOTICE] sofia.c:8683 Channel [sofia/external/7777@192.168.1.166:5090] has been answered
  528. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_channel.c:3950 (sofia/external/7777@192.168.1.166:5090) Callstate Change RINGING -> ACTIVE
  529. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  530. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  531. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  532. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  533. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  534. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  535. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  536. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  537. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  538. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  539. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  540. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  541. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  542. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  543. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  544. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:8779 AUDIO RTP [sofia/external/1234@192.168.1.166:5080] 192.168.1.166 port 22076 -> 192.168.1.166 port 8000 codec: 106 ms: 20
  545. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_rtp.c:4641 Not using a timer
  546. 2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9121 sofia/external/1234@192.168.1.166:5080 Set rtp dtmf delay to 40
  547. 2021-12-15 13:16:08.106041 92.23% [DEBUG] mod_sofia.c:913 Local SDP sofia/external/1234@192.168.1.166:5080:
  548. v=0
  549. o=FreeSWITCH 1639552092 1639552093 IN IP4 192.168.1.166
  550. s=FreeSWITCH
  551. c=IN IP4 192.168.1.166
  552. t=0 0
  553. m=audio 22076 RTP/AVP 106
  554. a=rtpmap:106 opus/48000/2
  555. a=fmtp:106 useinbandfec=1; minptime=20
  556. a=ptime:20
  557. a=sendrecv
  558.  
  559. nua.c:878 nua_respond() nua: nua_respond: entering
  560. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_respond
  561. nua_stack.c:603 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_respond 200 OK
  562. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  563. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
  564. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f9668012dd0, (nil), 0x7f963000f8db, -1) called
  565. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f9668012dd0, (nil), 0x7f963000f8db, -1) called
  566. nua_session.c:2318 nua_invite_server_respond() nua: nua_invite_server_respond: entering
  567. soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f9668012dd0) called
  568. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f9668012dd0, soa_generate_answer): called
  569. soa_static.c:1189 offer_answer_step() soa_static(0x7f9668012dd0, soa_generate_answer): generating local description
  570. soa_static.c:1230 offer_answer_step() soa_static(0x7f9668012dd0, soa_generate_answer): upgrade with remote description
  571. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f9696766800, 0x7f966801cf80, ""): called
  572. soa_static.c:1446 offer_answer_step() soa_static(0x7f9668012dd0, soa_generate_answer): storing local description
  573. soa.c:1730 soa_activate() soa_activate(static::0x7f9668012dd0, (nil)) called
  574. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668012dd0, [(nil)], [0x7f9696768980], [0x7f969676897c]) called
  575. 2021-12-15 13:16:08.106041 92.23% [NOTICE] switch_ivr_originate.c:3834 Channel [sofia/external/1234@192.168.1.166:5080] has been answered
  576. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
  577. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
  578. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
  579. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 975 bytes of 975 to udp/192.168.1.166:44068
  580. tport.c:3521 tport_send_msg() tport_vsend returned 975
  581. nta.c:6868 incoming_reply() nta: sent 200 OK for INVITE (1)
  582. nta.c:1360 set_timeout() nta: timer shortened to 500 ms
  583. nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: early -> completed, sent answer
  584. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668012dd0, [0x7f9696768a50], [0x7f9696768a58], [(nil)]) called
  585. soa.c:616 soa_get_params() soa_get_params(static::0x7f9668012dd0, ...) called
  586. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 200 OK
  587. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  588. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  589. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  590. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  591. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  592. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  593. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  594. 2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_channel.c:3950 (sofia/external/1234@192.168.1.166:5080) Callstate Change RINGING -> ACTIVE
  595. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  596. 2021-12-15 13:16:08.126068 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [completed][200]
  597. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  598. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  599. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  600. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  601. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  602. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  603. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  604. 2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/external/7777@192.168.1.166:5090] Peer UUID: 1f6e2bc8-89bb-4089-881d-575b56c6f0b3
  605. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  606. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  607. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801ddd0 from (udp/192.168.1.166:5080) has 438 bytes, veclen = 1
  608. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801ddd0 (438 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  609. nta.c:2951 agent_recv_request() nta: received ACK sip:0000@192.168.1.166:5080;transport=udp SIP/2.0 (CSeq 1) (load: 0 rps)
  610. nta.c:3090 agent_recv_request() nta: ACK (1) is going to INVITE (1)
  611. nua_session.c:2567 process_ack_or_cancel() nua: process_ack_or_cancel: entering
  612. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f9668012dd0) called
  613. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_ack 200 OK
  614. nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: completed -> ready
  615. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 200 OK
  616. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_active 200 Call active
  617. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  618. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  619. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  620. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  621. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  622. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  623. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  624. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  625. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  626. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  627. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  628. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  629. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  630. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  631. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  632. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  633. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  634. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  635. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  636. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  637. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  638. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  639. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  640. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  641. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  642. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  643. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  644. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  645. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  646. 2021-12-15 13:16:08.126068 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [ready][200]
  647. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  648. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  649. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  650. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  651. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  652. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  653. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  654. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  655. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  656. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  657. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  658. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  659. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  660. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  661. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  662. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  663. 2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_ivr_bridge.c:1793 (sofia/external/7777@192.168.1.166:5090) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  664. 2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 10)
  665. 2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_core_state_machine.c:650 (sofia/external/7777@192.168.1.166:5090) State EXCHANGE_MEDIA
  666. 2021-12-15 13:16:08.126068 92.23% [DEBUG] mod_sofia.c:671 SOFIA EXCHANGE_MEDIA
  667. 2021-12-15 13:16:08.165988 92.23% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  668. 2021-12-15 13:16:08.165988 92.23% [NOTICE] switch_core_media.c:16153 Activating write resampler
  669. 2021-12-15 13:16:08.226073 92.23% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  670. 2021-12-15 13:16:08.226073 92.23% [NOTICE] switch_core_media.c:16153 Activating write resampler
  671. nta.c:1308 agent_timer() nta: timer set next to 4501 ms
  672. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  673. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  674. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801e440 from (udp/192.168.1.166:5080) has 917 bytes, veclen = 1
  675. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801e440 (917 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  676. nta.c:2951 agent_recv_request() nta: received INVITE sip:mod_sofia@192.168.1.166:5080 SIP/2.0 (CSeq 111) (load: 0 rps)
  677. nta.c:3319 agent_aliases() nta: canonizing sip:mod_sofia@192.168.1.166:5080 with contact
  678. nta.c:3131 agent_recv_request() nta: INVITE (111) going to existing leg
  679. nta.c:1360 set_timeout() nta: timer shortened to 200 ms
  680. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  681. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f9668024df0) called
  682. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f9668024df0, (nil), 0x7f966802548d, 280) called
  683. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_invite 100 Trying
  684. nua_session.c:4146 signal_call_state_change() nua(0x7f96340037a0): ready call updated: received received offer
  685. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f9668024df0, [0x7f9696768610], [0x7f9696768618], [(nil)]) called
  686. nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 100 Trying
  687. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  688. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  689. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  690. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  691. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  692. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  693. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  694. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  695. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  696. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  697. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  698. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  699. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  700. nua.c:878 nua_respond() nua: nua_respond: entering
  701. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_respond
  702. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  703. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  704. nua_stack.c:603 nua_stack_signal() nua(0x7f96340037a0): recv signal r_respond 100 Trying
  705. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  706. soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
  707. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:5090
  708. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:5090
  709. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:5090
  710. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 361 bytes of 361 to udp/192.168.1.166:5090
  711. tport.c:3521 tport_send_msg() tport_vsend returned 361
  712. nta.c:6868 incoming_reply() nta: sent 100 Trying for INVITE (111)
  713. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  714. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  715. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  716. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  717. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  718. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  719. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  720. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  721. 2021-12-15 13:16:11.046069 91.53% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [received][100]
  722. 2021-12-15 13:16:11.046069 91.53% [DEBUG] sofia.c:7509 Remote SDP:
  723. v=0
  724. o=9999 450 2196 IN IP4 192.168.1.166
  725. s=Talk
  726. c=IN IP4 192.168.1.166
  727. t=0 0
  728. a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
  729. m=audio 7078 RTP/AVP 8 101
  730. a=rtpmap:101 telephone-event/8000
  731. a=sendonly
  732. a=rtcp-fb:* trr-int 5000
  733. a=rtcp-fb:* ccm tmmbr
  734.  
  735. 2021-12-15 13:16:11.046069 91.53% [DEBUG] switch_channel.c:1975 (sofia/external/7777@192.168.1.166:5090) Callstate Change ACTIVE -> HELD
  736. 2021-12-15 13:16:11.166080 91.53% [DEBUG] switch_ivr.c:632 sofia/external/1234@192.168.1.166:5080 Command Execute [depth=0] playback(local_stream://moh)
  737. EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 playback(local_stream://moh)
  738. 2021-12-15 13:16:11.166080 91.53% [ERR] switch_core_file.c:346 Invalid file format [local_stream] for [moh]!
  739. nta.c:1308 agent_timer() nta: timer set next to 1864 ms
  740. 2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  741. 2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  742. 2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5568 Set telephone-event payload to 101@8000
  743. 2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5917 Set telephone-event payload to 101@8000
  744. 2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5975 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf send payload to 101 recv payload to 101
  745. 2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:8761 Audio params are unchanged for sofia/external/7777@192.168.1.166:5090.
  746. 2021-12-15 13:16:11.306024 91.53% [DEBUG] sofia.c:8454 Processing updated SDP
  747. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  748. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
  749. nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
  750. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  751. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  752. nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
  753. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  754. 2021-12-15 13:16:11.326016 91.53% [INFO] sofia_glue.c:1651 sofia/external/1234@192.168.1.166:5080 sending invite call-id: (null)
  755. 2021-12-15 13:16:11.326016 91.53% [DEBUG] sofia_glue.c:1654 sofia/external/1234@192.168.1.166:5080 sending invite version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit
  756. Local SDP:
  757. v=0
  758. o=FreeSWITCH 1639552092 1639552095 IN IP4 192.168.1.166
  759. s=FreeSWITCH
  760. c=IN IP4 192.168.1.166
  761. t=0 0
  762. m=audio 22076 RTP/AVP 8
  763. a=rtpmap:8 PCMA/8000
  764. a=ptime:20
  765. a=sendonly
  766.  
  767. nua.c:632 nua_invite() nua: nua_invite: entering
  768. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_invite
  769. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_invite
  770. nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
  771. soa.c:356 soa_destroy() soa_destroy(static::0x7f9668012dd0) called
  772. nta.c:2707 nta_tpn_by_url() nta: selecting scheme sip
  773. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
  774. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
  775. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
  776. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 856 bytes of 856 to udp/192.168.1.166:44068
  777. tport.c:3521 tport_send_msg() tport_vsend returned 856
  778. nta.c:8390 outgoing_send() nta: sent INVITE (45233293) to UDP/192.168.1.166:44068
  779. tport.c:4189 tport_pend() tport_pend(0x7f96680062f0): pending 0x7f966801f4a0 for udp/192.168.1.166:5080 (already 0)
  780. nta.c:1360 set_timeout() nta: timer shortened to 1000 ms
  781. nua_session.c:4146 signal_call_state_change() nua(0x7f9668001fb0): ready call updated: calling sent offer
  782. nua_stack.c:299 nua_stack_event() nua(0x7f9668001fb0): event i_state INVITE sent
  783. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  784. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  785. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  786. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  787. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  788. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  789. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  790. tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
  791. tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
  792. tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966802a390 from (udp/192.168.1.166:5080) has 345 bytes, veclen = 1
  793. tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966802a390 (345 bytes) from udp/192.168.1.166:5080/sip next=(nil)
  794. nta.c:3370 agent_recv_response() nta: received 415 Unsupported Media Type for INVITE (45233293)
  795. nta.c:3437 agent_recv_response() nta: 415 Unsupported Media Type is going to a transaction
  796. nta.c:9684 outgoing_estimate_delay() nta_outgoing: RTT is 0.385 ms
  797. tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f966801f4a0 by 0x7f9668022d40 with 0x7f966802a390
  798. tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
  799. tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
  800. tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
  801. tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 338 bytes of 338 to udp/192.168.1.166:44068
  802. tport.c:3521 tport_send_msg() tport_vsend returned 338
  803. nta.c:8390 outgoing_send() nta: sent ACK (45233293) to UDP/192.168.1.166:44068
  804. nta.c:8816 outgoing_free() nta: outgoing_free(0x7f96680256f0)
  805. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event r_invite 415 Unsupported Media Type
  806. nua_session.c:4146 signal_call_state_change() nua(0x7f9668001fb0): ready call updated: init
  807. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 415 Unsupported Media Type
  808. nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_active 415 Call active
  809. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  810. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  811. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  812. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  813. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  814. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  815. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  816. 2021-12-15 13:16:11.326016 91.53% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [calling][0]
  817. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  818. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  819. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  820. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  821. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  822. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  823. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  824. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  825. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  826. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  827. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  828. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  829. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  830. nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
  831. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  832. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  833. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  834. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  835. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  836. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  837. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  838. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  839. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  840. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  841. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  842. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  843. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  844. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  845. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  846. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  847. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  848. 2021-12-15 13:16:11.326016 91.53% [DEBUG] sofia.c:7492 Channel sofia/external/1234@192.168.1.166:5080 skipping state [ready][415]
  849. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  850. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  851. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  852. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  853. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  854. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  855. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  856. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  857. nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
  858. nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
  859. nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
  860. nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
  861. nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
  862. nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
  863. nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
  864. nta.c:1308 agent_timer() nta: timer set next to 788 ms
  865. nta.c:7211 _nta_incoming_timer() nta: timer I fired, terminate 200 response
  866. nta.c:5896 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f96967689d0)
  867. nta.c:7265 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/2 free
  868. nta.c:1308 agent_timer() nta: timer set next to 26983 ms
  869.