From Bernie negative, 1 Year ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: green; font-weight: bold;"> 2023-06-23 08:47:12.507039 [INFO] mod_dialplan_xml.c:637 Processing Tinku <443300431567>->12345 in context default
  2. 2023-06-23 08:47:12.547038 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  3. 2023-06-23 08:47:12.547038 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  4. 2023-06-23 08:47:12.547038 [NOTICE] switch_cpp.cpp:1443 [ASTPP] [xml_handler] Params:
  5. Event-Name: REQUEST_PARAMS
  6. Core-UUID: 62a0f6fb-b129-416d-93be-60f18bfa3c46
  7. FreeSWITCH-Hostname: astpp4qemert2.hivelocity.net
  8. FreeSWITCH-Switchname: astpp4qemert2.hivelocity.net
  9. FreeSWITCH-IPv4: 199.167.144.231
  10. FreeSWITCH-IPv6: %3A%3A1
  11. Event-Date-Local: 2023-06-23%2008%3A47%3A12
  12. Event-Date-GMT: Fri,%2023%20Jun%202023%2008%3A47%3A12%20GMT
  13. Event-Date-Timestamp: 1687510032507039
  14. Event-Calling-File: mod_dialplan_xml.c
  15. Event-Calling-Function: dialplan_xml_locate
  16. Event-Calling-Line-Number: 608
  17. Event-Sequence: 433680118
  18. Channel-State: CS_ROUTING
  19. Channel-Call-State: RINGING
  20. Channel-State-Number: 2
  21. Channel-Name: sofia/default/443300431567%4065.109.0.34
  22. Unique-ID: 2332b2cd-a2e3-49a5-bf31-f4bf2d6733c1
  23. Call-Direction: inbound
  24. Presence-Call-Direction: inbound
  25. Channel-HIT-Dialplan: true
  26. Channel-Presence-ID: 443300431567%4065.109.0.34
  27. Channel-Call-UUID: 2332b2cd-a2e3-49a5-bf31-f4bf2d6733c1
  28. Answer-State: ringing
  29. Channel-Read-Codec-Name: PCMA
  30. Channel-Read-Codec-Rate: 8000
  31. Channel-Read-Codec-Bit-Rate: 64000
  32. Channel-Write-Codec-Name: PCMA
  33. Channel-Write-Codec-Rate: 8000
  34. Channel-Write-Codec-Bit-Rate: 64000
  35. Caller-Direction: inbound
  36. Caller-Logical-Direction: inbound
  37. Caller-Username: 443300431567
  38. Caller-Dialplan: XML
  39. Caller-Caller-ID-Name: Tinku
  40. Caller-Caller-ID-Number: 443300431567
  41. Caller-Orig-Caller-ID-Name: Tinku
  42. Caller-Orig-Caller-ID-Number: 443300431567
  43. Caller-Network-Addr: 199.167.144.226
  44. Caller-ANI: 443300431567
  45. Caller-Destination-Number: 12345
  46. Caller-Unique-ID: 2332b2cd-a2e3-49a5-bf31-f4bf2d6733c1
  47. Caller-Source: mod_sofia
  48. Caller-Context: default
  49. Caller-Channel-Name: sofia/default/443300431567%4065.109.0.34
  50. Caller-Profile-Index: 1
  51. Caller-Profile-Created-Time: 1687510032507039
  52. Caller-Channel-Created-Time: 1687510032507039
  53. Caller-Channel-Answered-Time: 0
  54. Caller-Channel-Progress-Time: 0
  55. Caller-Channel-Progress-Media-Time: 0
  56. Caller-Channel-Hangup-Time: 0
  57. Caller-Channel-Transfer-Time: 0
  58. Caller-Channel-Resurrect-Time: 0
  59. Caller-Channel-Bridged-Time: 0
  60. Caller-Channel-Last-Hold: 0
  61. Caller-Channel-Hold-Accum: 0
  62. Caller-Screen-Bit: true
  63. Caller-Privacy-Hide-Name: false
  64. Caller-Privacy-Hide-Number: false
  65. variable_direction: inbound
  66. variable_uuid: 2332b2cd-a2e3-49a5-bf31-f4bf2d6733c1
  67. variable_session_id: 8604573
  68. variable_sip_from_user: 443300431567
  69. variable_sip_from_uri: 443300431567%4065.109.0.34
  70. variable_sip_from_host: 65.109.0.34
  71. variable_video_media_flow: disabled
  72. variable_text_media_flow: disabled
  73. variable_channel_name: sofia/default/443300431567%4065.109.0.34
  74. variable_sip_call_id: 63423b21-8c45-123c-dbb2-9600017f4e11
  75. variable_sip_local_network_addr: 199.167.144.231
  76. variable_sip_network_ip: 199.167.144.226
  77. variable_sip_network_port: 5060
  78. variable_sip_invite_stamp: 1687510032507039
  79. variable_sip_received_ip: 199.167.144.226
  80. variable_sip_received_port: 5060
  81. variable_sip_via_protocol: udp
  82. variable_sip_authorized: true
  83. variable_sip_acl_authed_by: default
  84. variable_sip_from_user_stripped: 443300431567
  85. variable_sip_from_tag: y8696t65Be6rr
  86. variable_sofia_profile_name: default
  87. variable_sofia_profile_url: sip%3Amod_sofia%40199.167.144.231%3A7777
  88. variable_recovery_profile_name: default
  89. variable_sip_invite_route_uri: %3Csip%3A199.167.144.226%3Blr%3Bdid%3Dfe1.f2a6a3e6%3E
  90. variable_sip_invite_record_route: %3Csip%3A199.167.144.226%3Blr%3Bdid%3Dfe1.f2a6a3e6%3E
  91. variable_sip_full_via: SIP/2.0/UDP%20199.167.144.226%3A5060%3Bbranch%3Dz9hG4bKc8ee.9e61eb26.0,SIP/2.0/UDP%2065.109.0.34%3Breceived%3D65.109.0.34%3Brport%3D5060%3Bbranch%3Dz9hG4bKvUvKjmD0gNDZN
  92. variable_sip_from_display: Tinku
  93. variable_sip_full_from: %22Tinku%22%20%3Csip%3A443300431567%4065.109.0.34%3E%3Btag%3Dy8696t65Be6rr
  94. variable_sip_full_to: %3Csip%3A12345%40199.167.144.226%3E
  95. variable_sip_allow: INVITE,%20ACK,%20BYE,%20CANCEL,%20OPTIONS,%20MESSAGE,%20INFO,%20UPDATE,%20REGISTER,%20REFER,%20NOTIFY,%20PUBLISH,%20SUBSCRIBE
  96. variable_sip_req_user: 12345
  97. variable_sip_req_uri: 12345%40199.167.144.226
  98. variable_sip_req_host: 199.167.144.226
  99. variable_sip_to_user: 12345
  100. variable_sip_to_uri: 12345%40199.167.144.226
  101. variable_sip_to_host: 199.167.144.226
  102. variable_sip_contact_params: transport%3Dudp%3Bgw%3DBernie_gateway
  103. variable_sip_contact_user: admin
  104. variable_sip_contact_port: 5060
  105. variable_sip_contact_uri: admin%4065.109.0.34%3A5060
  106. variable_sip_contact_host: 65.109.0.34
  107. variable_sip_user_agent: ASTPP
  108. variable_sip_via_host: 199.167.144.226
  109. variable_sip_via_port: 5060
  110. variable_max_forwards: 30
  111. variable_presence_id: 443300431567%4065.109.0.34
  112. variable_sip_h_X-ASTPP-Stir-Verification: Not%20Verified
  113. variable_sip_h_X-AUTH-IP: 65.109.0.34
  114. variable_sip_h_P-Accountcode: 152631
  115. variable_sip_h_P-effective_caller_id_name: 443300431567
  116. variable_sip_h_P-effective_caller_id_number: 443300431567
  117. variable_switch_r_sdp: v%3D0%0D%0Ao%3DFreeSWITCH%201687478422%201687478423%20IN%20IP4%2065.109.0.34%0D%0As%3DFreeSWITCH%0D%0Ac%3DIN%20IP4%2065.109.0.34%0D%0At%3D0%200%0D%0Am%3Daudio%2031610%20RTP/AVP%208%20101%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-15%0D%0Aa%3Dptime%3A20%0D%0A
  118. variable_ep_codec_string: CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b
  119. variable_rtp_use_codec_string: PCMA,PCMU,G729
  120. variable_remote_video_media_flow: inactive
  121. variable_remote_text_media_flow: inactive
  122. variable_remote_audio_media_flow: sendrecv
  123. variable_audio_media_flow: sendrecv
  124. variable_remote_media_ip: 65.109.0.34
  125. variable_remote_media_port: 31610
  126. variable_rtp_audio_recv_pt: 8
  127. variable_rtp_use_codec_name: PCMA
  128. variable_rtp_use_codec_rate: 8000
  129. variable_rtp_use_codec_ptime: 20
  130. variable_rtp_use_codec_channels: 1
  131. variable_rtp_last_audio_codec_string: PCMA%408000h%4020i%401c
  132. variable_read_codec: PCMA
  133. variable_original_read_codec: PCMA
  134. variable_read_rate: 8000
  135. variable_original_read_rate: 8000
  136. variable_write_codec: PCMA
  137. variable_write_rate: 8000
  138. variable_dtmf_type: rfc2833
  139. variable_endpoint_disposition: RECEIVED
  140. variable_call_uuid: 2332b2cd-a2e3-49a5-bf31-f4bf2d6733c1
  141. Hunt-Direction: inbound
  142. Hunt-Logical-Direction: inbound
  143. Hunt-Username: 443300431567
  144. Hunt-Dialplan: XML
  145. Hunt-Caller-ID-Name: Tinku
  146. Hunt-Caller-ID-Number: 443300431567
  147. Hunt-Orig-Caller-ID-Name: Tinku
  148. Hunt-Orig-Caller-ID-Number: 443300431567
  149. Hunt-Network-Addr: 199.167.144.226
  150. Hunt-ANI: 443300431567
  151. Hunt-Destination-Number: 12345
  152. Hunt-Unique-ID: 2332b2cd-a2e3-49a5-bf31-f4bf2d6733c1
  153. Hunt-Source: mod_sofia
  154. Hunt-Context: default
  155. Hunt-Channel-Name: sofia/default/443300431567%4065.109.0.34
  156. Hunt-Profile-Index: 1
  157. Hunt-Profile-Created-Time: 1687510032507039
  158. Hunt-Channel-Created-Time: 1687510032507039
  159. Hunt-Channel-Answered-Time: 0
  160. Hunt-Channel-Progress-Time: 0
  161. Hunt-Channel-Progress-Media-Time: 0
  162. Hunt-Channel-Hangup-Time: 0
  163. Hunt-Channel-Transfer-Time: 0
  164. Hunt-Channel-Resurrect-Time: 0
  165. Hunt-Channel-Bridged-Time: 0
  166. Hunt-Channel-Last-Hold: 0
  167. Hunt-Channel-Hold-Accum: 0
  168. Hunt-Screen-Bit: true
  169. Hunt-Privacy-Hide-Name: false
  170. Hunt-Privacy-Hide-Number: false
  171.  
  172.  
  173. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [xml_REQUEST] key_name:
  174. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [xml_REQUEST] key_value:
  175. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [xml_REQUEST] tag_name:
  176. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [xml_REQUEST] section: dialplan
  177. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [Dialplan] start time : 2023-06-23 08:47:12
  178. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [Dialplan] Dialed number : 12345
  179. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [Dialplan] =======line2 :
  180. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [Dialplan] =======line3 :
  181. 2023-06-23 08:47:12.547038 [INFO] switch_cpp.cpp:1443 [ASTPP] [Dialplan] Caller Id name / number  : 443300431567 / 443300431567
  182. 2023-06-23 08:47:12.547038 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="12345" LIMIT 1
  183. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [Dialplan] Call direction : inbound
  184. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [Accountcode : 152631]
  185. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "152631" AND deleted = 0 limit 1
  186. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [ash3] Query :SELECT * FROM accounts WHERE number = "152631" AND deleted = 0 limit 1
  187. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="12345" AND (accountid = 0 OR status = 1) LIMIT 1
  188. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
  189. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :6945
  190. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] Call performance report start
  191. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [calculate_call_count22222] Query :insert into write_cc_cps(accountid,callednum,start_time) values('6945','12345','2023-06-23 08:47:12')
  192. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] Call performance report end
  193. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] =============== Account Information ===================
  194. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] User id : 6945
  195. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Account code : 152631
  196. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Balance : 1
  197. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  198. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Ratecard id : 1
  199. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] CID Pool : 0
  200. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] ========================================================
  201. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [calculate_call_count22222] Query :insert into write_cc_cps(accountid,callednum,start_time) values('6945','12345','2023-06-23 08:47:12')
  202. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
  203. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [GET_RATES] call_direction :inbound
  204. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="12345" LIMIT 1
  205. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] call_direction:::::: inbound
  206. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] =============== Rates Information ===================
  207. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] ID : 939
  208. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Connectcost : 0.00000
  209. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Includedseconds : 0
  210. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Cost : 1.00000
  211. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] comment : 12345
  212. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Country Id : 85
  213. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Accid : 6945
  214. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] ================================================================
  215. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [FIND_MAXLENGTH] Your1 balance Accountid 6945 !!!
  216. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] Call Max length duration : 1 minutes
  217. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [userinfo] INB_FREE:TRUE
  218. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [userinfo] free_inbound:1
  219. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 6945 AND status=0 LIMIT 1
  220. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE id = "6945" AND deleted = 0 limit 1
  221. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [ash3] Query :SELECT * FROM accounts WHERE id = "6945" AND deleted = 0 limit 1
  222. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [userinfo] Actual CustomerInfo XML:6945
  223. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [userinfo] Userinfo XML:6945
  224. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] [userinfo] Actual CustomerInfo XML : 6945
  225. 2023-06-23 08:47:12.567022 [INFO] switch_cpp.cpp:1443 [ASTPP] maxlength::::::::: 1
  226. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_0
  227. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [NOTIFY] START:
  228. 2023-06-23 08:47:12.567022 [DEBUG] switch_cpp.cpp:1443 [ASTPP] [Dialplan] Generated XML:<?xml version="1.0" encoding="UTF-8" standalone="no"?>
  229. <document type="freeswitch/xml">
  230. <section name="dialplan" description="ASTPP Dialplan">
  231. <context name="default">
  232. <extension name="12345">
  233. <condition field="destination_number" expression="12345">
  234. <action application="set" data="effective_destination_number=12345"/>
  235. <action application="set" data="bridge_pre_execute_bleg_app=sched_hangup"/>
  236. <action application="set" data="bridge_pre_execute_bleg_data=+60 normal_clearing"/>
  237. <action application="set" data="callstart=2023-06-23 08:47:12"/>
  238. <action application="set" data="hangup_after_bridge=true"/>
  239. <action application="set" data="continue_on_fail=TRUE"/>
  240. <action application="set" data="account_id=6945"/>
  241. <action application="set" data="parent_id=0"/>
  242. <action application="set" data="entity_id=0"/>
  243. <action application="set" data="call_processed=internal"/>
  244. <action application="set" data="call_direction=inbound"/>
  245. <action application="set" data="accountname=default"/>
  246. <action application="set" data="origination_rates_did=ID:939|CODE:^12345.*|DESTINATION:12345|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:85|ACCID:6945"/>
  247. <action application="set" data="origination_rates=0"/>
  248. <action application="set" data="original_caller_id_name=443300431567"/>
  249. <action application="set" data="original_caller_id_number=443300431567"/>
  250. <action application="set" data="effective_caller_id_name=443300431567"/>
  251. <action application="set" data="effective_caller_id_number=443300431567"/>
  252. <action application="set" data="receiver_accid=6945"/>
  253. <action application="export" data="presence_data=x|||Tushar(152631)|||^12345.* // 12345 // 1.00000||||||DID"/>
  254. <action application="export" data="call_type=0"/>
  255. <action application="set" data="calltype=DID-LOCAL"/>
  256. <action application="bridge" data="{sip_invite_params=user=LOCAL,sip_from_uri=152631@${domain_name}}[leg_timeout=0]sofia/${sofia_profile_name}/152631@199.167.144.226"/>
  257. <condition field="${cond(${user_data 152631@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
  258. <action application="answer"/>
  259. <action application="export" data="voicemail_alternate_greet_id=12345"/>
  260. <action application="voicemail" data="default $${domain_name} 152631"/>
  261. <anti-action application="hangup" data="${originate_disposition}"/>
  262. </condition>
  263. <action application="set" data="did_id=939"/>
  264. <action application="set" data="destination_number=12345"/>
  265. <action application="set" data="leg_timeout=0"/>
  266. <action application="set" data="call_type_vm_flag=1"/>
  267. <action application="set" data="is_local_extension=1"/>
  268. <action application="lua" data="did_call_forwarding.lua"/>
  269. </condition>
  270. </extension>
  271. </context>
  272. </section>
  273. </document>
  274. Dialplan: sofia/default/443300431567@65.109.0.34 parsing [default->12345] continue=false
  275. Dialplan: sofia/default/443300431567@65.109.0.34 Regex (PASS) [12345] destination_number(12345) =~ /12345/ break=on-false
  276. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(effective_destination_number=12345)
  277. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(bridge_pre_execute_bleg_app=sched_hangup)
  278. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(bridge_pre_execute_bleg_data=+60 normal_clearing)
  279. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(callstart=2023-06-23 08:47:12)
  280. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(hangup_after_bridge=true)
  281. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(continue_on_fail=TRUE)
  282. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(account_id=6945)
  283. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(parent_id=0)
  284. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(entity_id=0)
  285. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(call_processed=internal)
  286. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(call_direction=inbound)
  287. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(accountname=default)
  288. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(origination_rates_did=ID:939|CODE:^12345.*|DESTINATION:12345|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:85|ACCID:6945)
  289. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(origination_rates=0)
  290. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(original_caller_id_name=443300431567)
  291. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(original_caller_id_number=443300431567)
  292. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(effective_caller_id_name=443300431567)
  293. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(effective_caller_id_number=443300431567)
  294. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(receiver_accid=6945)
  295. Dialplan: sofia/default/443300431567@65.109.0.34 Action export(presence_data=x|||Tushar(152631)|||^12345.* // 12345 // 1.00000||||||DID)
  296. Dialplan: sofia/default/443300431567@65.109.0.34 Action export(call_type=0)
  297. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(calltype=DID-LOCAL)
  298. Dialplan: sofia/default/443300431567@65.109.0.34 Action bridge({sip_invite_params=user=LOCAL,sip_from_uri=152631@${domain_name}}[leg_timeout=0]sofia/${sofia_profile_name}/152631@199.167.144.226)
  299. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(did_id=939)
  300. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(destination_number=12345)
  301. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(leg_timeout=0)
  302. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(call_type_vm_flag=1)
  303. Dialplan: sofia/default/443300431567@65.109.0.34 Action set(is_local_extension=1)
  304. Dialplan: sofia/default/443300431567@65.109.0.34 Action lua(did_call_forwarding.lua)
  305. |--- Dialplan: Processing recursive conditions level:1 [12345_recur_1] require-nested=TRUE
  306. |--- Dialplan: sofia/default/443300431567@65.109.0.34 Regex (PASS) [12345_recur_1] ${cond(${user_data 152631@${domain_name} param vm-enabled} == true ? YES : NO)}(YES) =~ /^YES$/ break=on-false
  307. |--- Dialplan: sofia/default/443300431567@65.109.0.34 Action answer()
  308. |--- Dialplan: sofia/default/443300431567@65.109.0.34 Action export(voicemail_alternate_greet_id=12345)
  309. |--- Dialplan: sofia/default/443300431567@65.109.0.34 Action voicemail(default $${domain_name} 152631)
  310. 2023-06-23 08:47:12.587024 [DEBUG] switch_core_state_machine.c:287 (sofia/default/443300431567@65.109.0.34) State Change CS_ROUTING -> CS_EXECUTE
  311. 2023-06-23 08:47:12.587024 [DEBUG] switch_core_state_machine.c:644 (sofia/default/443300431567@65.109.0.34) State ROUTING going to sleep
  312. 2023-06-23 08:47:12.587024 [DEBUG] switch_core_state_machine.c:585 (sofia/default/443300431567@65.109.0.34) Running State Change CS_EXECUTE (Cur 1 Tot 8604573)
  313. 2023-06-23 08:47:12.587024 [DEBUG] switch_core_state_machine.c:651 (sofia/default/443300431567@65.109.0.34) State EXECUTE
  314. 2023-06-23 08:47:12.587024 [DEBUG] mod_sofia.c:209 sofia/default/443300431567@65.109.0.34 SOFIA EXECUTE
  315. 2023-06-23 08:47:12.587024 [DEBUG] switch_core_state_machine.c:329 sofia/default/443300431567@65.109.0.34 Standard EXECUTE
  316. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(effective_destination_number=12345)
  317. 2023-06-23 08:47:12.587024 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [effective_destination_number]=[12345]
  318. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(bridge_pre_execute_bleg_app=sched_hangup)
  319. 2023-06-23 08:47:12.587024 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [bridge_pre_execute_bleg_app]=[sched_hangup]
  320. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(bridge_pre_execute_bleg_data=+60 normal_clearing)
  321. 2023-06-23 08:47:12.587024 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [bridge_pre_execute_bleg_data]=[+60 normal_clearing]
  322. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(callstart=2023-06-23 08:47:12)
  323. 2023-06-23 08:47:12.587024 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [callstart]=[2023-06-23 08:47:12]
  324. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(hangup_after_bridge=true)
  325. 2023-06-23 08:47:12.587024 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [hangup_after_bridge]=[true]
  326. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(continue_on_fail=TRUE)
  327. 2023-06-23 08:47:12.587024 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [continue_on_fail]=[TRUE]
  328. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(account_id=6945)
  329. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [account_id]=[6945]
  330. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(parent_id=0)
  331. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [parent_id]=[0]
  332. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(entity_id=0)
  333. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [entity_id]=[0]
  334. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(call_processed=internal)
  335. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [call_processed]=[internal]
  336. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(call_direction=inbound)
  337. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [call_direction]=[inbound]
  338. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(accountname=default)
  339. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [accountname]=[default]
  340. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(origination_rates_did=ID:939|CODE:^12345.*|DESTINATION:12345|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:85|ACCID:6945)
  341. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [origination_rates_did]=[ID:939|CODE:^12345.*|DESTINATION:12345|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:85|ACCID:6945]
  342. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(origination_rates=0)
  343. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [origination_rates]=[0]
  344. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(original_caller_id_name=443300431567)
  345. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [original_caller_id_name]=[443300431567]
  346. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(original_caller_id_number=443300431567)
  347. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [original_caller_id_number]=[443300431567]
  348. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(effective_caller_id_name=443300431567)
  349. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [effective_caller_id_name]=[443300431567]
  350. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(effective_caller_id_number=443300431567)
  351. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [effective_caller_id_number]=[443300431567]
  352. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(receiver_accid=6945)
  353. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [receiver_accid]=[6945]
  354. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 export(presence_data=x|||Tushar(152631)|||^12345.* // 12345 // 1.00000||||||DID)
  355. 2023-06-23 08:47:12.607020 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [presence_data]=[x|||Tushar(152631)|||^12345.* // 12345 // 1.00000||||||DID]
  356. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 export(call_type=0)
  357. 2023-06-23 08:47:12.607020 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_type]=[0]
  358. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 set(calltype=DID-LOCAL)
  359. 2023-06-23 08:47:12.607020 [DEBUG] mod_dptools.c:1672 SET sofia/default/443300431567@65.109.0.34 [calltype]=[DID-LOCAL]
  360. EXECUTE [depth=0] sofia/default/443300431567@65.109.0.34 bridge({sip_invite_params=user=LOCAL,sip_from_uri=152631@199.167.144.231}[leg_timeout=0]sofia/default/152631@199.167.144.226)
  361. 2023-06-23 08:47:12.607020 [DEBUG] switch_channel.c:1264 sofia/default/443300431567@65.109.0.34 EXPORTING[export_vars] [presence_data]=[x|||Tushar(152631)|||^12345.* // 12345 // 1.00000||||||DID] to event
  362. 2023-06-23 08:47:12.607020 [DEBUG] switch_channel.c:1264 sofia/default/443300431567@65.109.0.34 EXPORTING[export_vars] [call_type]=[0] to event
  363. 2023-06-23 08:47:12.607020 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
  364. 2023-06-23 08:47:12.607020 [DEBUG] switch_ivr_originate.c:2760 Parsing session specific variables
  365. 2023-06-23 08:47:12.607020 [NOTICE] switch_channel.c:1118 New Channel sofia/default/152631@199.167.144.226 [6f91ce6f-e104-4db0-971f-d19abc7d6bf1]
  366. 2023-06-23 08:47:12.607020 [DEBUG] mod_sofia.c:5089 (sofia/default/152631@199.167.144.226) State Change CS_NEW -> CS_INIT
  367. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:585 (sofia/default/152631@199.167.144.226) Running State Change CS_INIT (Cur 2 Tot 8604574)
  368. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:628 (sofia/default/152631@199.167.144.226) State INIT
  369. 2023-06-23 08:47:12.607020 [DEBUG] mod_sofia.c:93 sofia/default/152631@199.167.144.226 SOFIA INIT
  370. 2023-06-23 08:47:12.607020 [DEBUG] sofia_glue.c:1618 sofia/default/152631@199.167.144.226 sending invite version: 1.10.2 -release 64bit
  371. Local SDP:
  372. v=0
  373. o=FreeSWITCH 1687471070 1687471071 IN IP4 199.167.144.231
  374. s=FreeSWITCH
  375. c=IN IP4 199.167.144.231
  376. t=0 0
  377. m=audio 38962 RTP/AVP 8 101
  378. a=rtpmap:8 PCMA/8000
  379. a=rtpmap:101 telephone-event/8000
  380. a=fmtp:101 0-16
  381. a=ptime:20
  382. a=sendrecv
  383.  
  384. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:40 sofia/default/152631@199.167.144.226 Standard INIT
  385. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:48 (sofia/default/152631@199.167.144.226) State Change CS_INIT -> CS_ROUTING
  386. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:628 (sofia/default/152631@199.167.144.226) State INIT going to sleep
  387. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:585 (sofia/default/152631@199.167.144.226) Running State Change CS_ROUTING (Cur 2 Tot 8604574)
  388. 2023-06-23 08:47:12.607020 [DEBUG] sofia.c:7301 Channel sofia/default/152631@199.167.144.226 entering state [calling][0]
  389. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:644 (sofia/default/152631@199.167.144.226) State ROUTING
  390. 2023-06-23 08:47:12.607020 [DEBUG] mod_sofia.c:154 sofia/default/152631@199.167.144.226 SOFIA ROUTING
  391. 2023-06-23 08:47:12.607020 [DEBUG] switch_ivr_originate.c:67 (sofia/default/152631@199.167.144.226) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  392. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:644 (sofia/default/152631@199.167.144.226) State ROUTING going to sleep
  393. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:585 (sofia/default/152631@199.167.144.226) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 8604574)
  394. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:663 (sofia/default/152631@199.167.144.226) State CONSUME_MEDIA
  395. 2023-06-23 08:47:12.607020 [DEBUG] switch_core_state_machine.c:663 (sofia/default/152631@199.167.144.226) State CONSUME_MEDIA going to sleep
  396. 2023-06-23 08:47:13.767022 [DEBUG] sofia.c:7301 Channel sofia/default/152631@199.167.144.226 entering state [proceeding][180]
  397. 2023-06-23 08:47:13.767022 [NOTICE] sofia.c:7412 Ring-Ready sofia/default/152631@199.167.144.226!
  398. 2023-06-23 08:47:13.767022 [DEBUG] switch_channel.c:3437 (sofia/default/152631@199.167.144.226) Callstate Change DOWN -> RINGING
  399. 2023-06-23 08:47:13.767022 [NOTICE] mod_sofia.c:2498 Ring-Ready sofia/default/443300431567@65.109.0.34!
  400. 2023-06-23 08:47:13.767022 [DEBUG] sofia.c:7301 Channel sofia/default/443300431567@65.109.0.34 entering state [early][180]
  401. 2023-06-23 08:47:13.767022 [NOTICE] switch_ivr_originate.c:553 Ring Ready sofia/default/443300431567@65.109.0.34!
  402. 2023-06-23 08:47:21.887069 [DEBUG] sofia.c:7301 Channel sofia/default/152631@199.167.144.226 entering state [completing][200]
  403. 2023-06-23 08:47:21.887069 [DEBUG] sofia.c:7311 Remote SDP:
  404. v=0
  405. o=Z 0 3 IN IP4 103.240.35.46
  406. s=Z
  407. c=IN IP4 103.240.35.46
  408. t=0 0
  409. m=audio 1088 RTP/AVP 8 3 110 0 98 101
  410. a=rtpmap:110 speex/8000
  411. a=rtpmap:98 iLBC/8000
  412. a=fmtp:98 mode=20
  413. a=rtpmap:101 telephone-event/8000
  414. a=fmtp:101 0-15
  415.  
  416. 2023-06-23 08:47:21.887069 [DEBUG] sofia.c:7301 Channel sofia/default/152631@199.167.144.226 entering state [ready][200]
  417. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  418. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  419. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  420. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  421. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  422. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  423. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
  424. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:3837 Set Codec sofia/default/152631@199.167.144.226 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  425. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_codec.c:111 sofia/default/152631@199.167.144.226 Original read codec set to PCMA:8
  426. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
  427. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:5909 sofia/default/152631@199.167.144.226 Set 2833 dtmf send payload to 101 recv payload to 101
  428. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/default/152631@199.167.144.226] 199.167.144.231 port 38962 -> 103.240.35.46 port 1088 codec: 8 ms: 20
  429. 2023-06-23 08:47:21.887069 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
  430. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:8973 sofia/default/152631@199.167.144.226 Set 2833 dtmf send payload to 101
  431. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:8980 sofia/default/152631@199.167.144.226 Set 2833 dtmf receive payload to 101
  432. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:9003 sofia/default/152631@199.167.144.226 Set rtp dtmf delay to 40
  433. 2023-06-23 08:47:21.887069 [NOTICE] sofia.c:8479 Channel [sofia/default/152631@199.167.144.226] has been answered
  434. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/default/443300431567@65.109.0.34] 199.167.144.231 port 20726 -> 65.109.0.34 port 31610 codec: 8 ms: 20
  435. 2023-06-23 08:47:21.887069 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
  436. 2023-06-23 08:47:21.887069 [DEBUG] switch_channel.c:3865 (sofia/default/152631@199.167.144.226) Callstate Change RINGING -> ACTIVE
  437. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:8973 sofia/default/443300431567@65.109.0.34 Set 2833 dtmf send payload to 101
  438. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:8980 sofia/default/443300431567@65.109.0.34 Set 2833 dtmf receive payload to 101
  439. 2023-06-23 08:47:21.887069 [DEBUG] switch_core_media.c:9003 sofia/default/443300431567@65.109.0.34 Set rtp dtmf delay to 40
  440. 2023-06-23 08:47:21.887069 [DEBUG] mod_sofia.c:898 Local SDP sofia/default/443300431567@65.109.0.34:
  441. v=0
  442. o=FreeSWITCH 1687489315 1687489316 IN IP4 199.167.144.231
  443. s=FreeSWITCH
  444. c=IN IP4 199.167.144.231
  445. t=0 0
  446. m=audio 20726 RTP/AVP 8 101
  447. a=rtpmap:8 PCMA/8000
  448. a=rtpmap:101 telephone-event/8000
  449. a=fmtp:101 0-16
  450. a=ptime:20
  451. a=sendrecv
  452.  
  453. 2023-06-23 08:47:21.887069 [NOTICE] switch_ivr_originate.c:3751 Channel [sofia/default/443300431567@65.109.0.34] has been answered
  454. 2023-06-23 08:47:21.907023 [DEBUG] switch_channel.c:3865 (sofia/default/443300431567@65.109.0.34) Callstate Change RINGING -> ACTIVE
  455. 2023-06-23 08:47:21.907023 [DEBUG] sofia.c:7301 Channel sofia/default/443300431567@65.109.0.34 entering state [completed][200]
  456. 2023-06-23 08:47:21.907023 [DEBUG] switch_ivr_originate.c:3809 Originate Resulted in Success: [sofia/default/152631@199.167.144.226]
  457. 2023-06-23 08:47:21.907023 [DEBUG] switch_ivr_bridge.c:1796 (sofia/default/152631@199.167.144.226) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  458. 2023-06-23 08:47:21.907023 [DEBUG] switch_core_state_machine.c:585 (sofia/default/152631@199.167.144.226) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 8604574)
  459. 2023-06-23 08:47:21.907023 [DEBUG] switch_core_state_machine.c:654 (sofia/default/152631@199.167.144.226) State EXCHANGE_MEDIA
  460. 2023-06-23 08:47:21.907023 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA
  461. 2023-06-23 08:47:21.947051 [DEBUG] switch_rtp.c:7720 Correct audio ip/port confirmed.
  462. 2023-06-23 08:47:22.027051 [DEBUG] sofia.c:7301 Channel sofia/default/443300431567@65.109.0.34 entering state [ready][200]
  463. 2023-06-23 08:47:22.087022 [DEBUG] switch_ivr_bridge.c:658 sofia/default/152631@199.167.144.226 Bridge execute app sched_hangup(+60 normal_clearing)
  464. 2023-06-23 08:47:22.107051 [DEBUG] switch_ivr.c:632 sofia/default/152631@199.167.144.226 Command Execute [depth=0] sched_hangup(+60 normal_clearing)
  465. EXECUTE [depth=0] sofia/default/152631@199.167.144.226 sched_hangup(+60 normal_clearing)
  466. 2023-06-23 08:47:22.107051 [DEBUG] switch_scheduler.c:252 Added task 3071977 switch_ivr_schedule_hangup (6f91ce6f-e104-4db0-971f-d19abc7d6bf1) to run at 1687510102
  467. 2023-06-23 08:47:22.427052 [DEBUG] switch_rtp.c:7720 Correct audio ip/port confirmed.
  468. 2023-06-23 08:48:22.127054 [NOTICE] switch_ivr_async.c:5190 Hangup sofia/default/152631@199.167.144.226 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  469. 2023-06-23 08:48:22.127054 [DEBUG] switch_scheduler.c:147 Deleting task 3071977 switch_ivr_schedule_hangup (6f91ce6f-e104-4db0-971f-d19abc7d6bf1)
  470. 2023-06-23 08:48:22.127054 [DEBUG] switch_ivr_bridge.c:823 sofia/default/152631@199.167.144.226 ending bridge by request from write function
  471. 2023-06-23 08:48:22.127054 [DEBUG] switch_ivr_bridge.c:915 BRIDGE THREAD DONE [sofia/default/443300431567@65.109.0.34]
  472. 2023-06-23 08:48:22.127054 [DEBUG] switch_ivr_bridge.c:1895 sofia/default/152631@199.167.144.226 skip receive message [UNBRIDGE] (channel is hungup already)
  473. 2023-06-23 08:48:22.127054 [NOTICE] switch_ivr_bridge.c:1947 Hangup sofia/default/443300431567@65.109.0.34 [CS_EXECUTE] [NORMAL_CLEARING]
  474. 2023-06-23 08:48:22.127054 [DEBUG] switch_core_session.c:2905 sofia/default/443300431567@65.109.0.34 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  475. 2023-06-23 08:48:22.127054 [DEBUG] switch_core_state_machine.c:651 (sofia/default/443300431567@65.109.0.34) State EXECUTE going to sleep
  476. 2023-06-23 08:48:22.127054 [DEBUG] switch_core_state_machine.c:585 (sofia/default/443300431567@65.109.0.34) Running State Change CS_HANGUP (Cur 2 Tot 8604574)
  477. 2023-06-23 08:48:22.127054 [DEBUG] switch_core_state_machine.c:848 (sofia/default/443300431567@65.109.0.34) Callstate Change ACTIVE -> HANGUP
  478. 2023-06-23 08:48:22.127054 [DEBUG] switch_core_state_machine.c:850 (sofia/default/443300431567@65.109.0.34) State HANGUP
  479. 2023-06-23 08:48:22.127054 [DEBUG] mod_sofia.c:453 Channel sofia/default/443300431567@65.109.0.34 hanging up, cause: NORMAL_CLEARING
  480. 2023-06-23 08:48:22.147021 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/default/443300431567@65.109.0.34
  481. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:60 sofia/default/443300431567@65.109.0.34 Standard HANGUP, cause: NORMAL_CLEARING
  482. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:850 (sofia/default/443300431567@65.109.0.34) State HANGUP going to sleep
  483. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:620 (sofia/default/443300431567@65.109.0.34) State Change CS_HANGUP -> CS_REPORTING
  484. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:585 (sofia/default/443300431567@65.109.0.34) Running State Change CS_REPORTING (Cur 2 Tot 8604574)
  485. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:936 (sofia/default/443300431567@65.109.0.34) State REPORTING
  486. 2023-06-23 08:48:22.147021 [INFO] mod_json_cdr.c:271 Process [2332b2cd-a2e3-49a5-bf31-f4bf2d6733c1.cdr.json]
  487. 2023-06-23 08:48:22.147021 [DEBUG] switch_ivr_bridge.c:829 sofia/default/152631@199.167.144.226 ending bridge by request from read function
  488. 2023-06-23 08:48:22.147021 [DEBUG] switch_ivr_bridge.c:915 BRIDGE THREAD DONE [sofia/default/152631@199.167.144.226]
  489. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:654 (sofia/default/152631@199.167.144.226) State EXCHANGE_MEDIA going to sleep
  490. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:585 (sofia/default/152631@199.167.144.226) Running State Change CS_HANGUP (Cur 2 Tot 8604574)
  491. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:848 (sofia/default/152631@199.167.144.226) Callstate Change ACTIVE -> HANGUP
  492. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:850 (sofia/default/152631@199.167.144.226) State HANGUP
  493. 2023-06-23 08:48:22.147021 [DEBUG] mod_sofia.c:453 Channel sofia/default/152631@199.167.144.226 hanging up, cause: NORMAL_CLEARING
  494. 2023-06-23 08:48:22.147021 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/default/152631@199.167.144.226
  495. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:60 sofia/default/152631@199.167.144.226 Standard HANGUP, cause: NORMAL_CLEARING
  496. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:850 (sofia/default/152631@199.167.144.226) State HANGUP going to sleep
  497. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:620 (sofia/default/152631@199.167.144.226) State Change CS_HANGUP -> CS_REPORTING
  498. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:585 (sofia/default/152631@199.167.144.226) Running State Change CS_REPORTING (Cur 2 Tot 8604574)
  499. 2023-06-23 08:48:22.147021 [DEBUG] switch_core_state_machine.c:936 (sofia/default/152631@199.167.144.226) State REPORTING
  500. 2023-06-23 08:48:22.147021 [INFO] mod_json_cdr.c:271 Process [6f91ce6f-e104-4db0-971f-d19abc7d6bf1.cdr.json]
  501. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:174 sofia/default/443300431567@65.109.0.34 Standard REPORTING, cause: NORMAL_CLEARING
  502. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:936 (sofia/default/443300431567@65.109.0.34) State REPORTING going to sleep
  503. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:611 (sofia/default/443300431567@65.109.0.34) State Change CS_REPORTING -> CS_DESTROY
  504. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_session.c:1726 Session 8604573 (sofia/default/443300431567@65.109.0.34) Locked, Waiting on external entities
  505. 2023-06-23 08:48:22.167023 [NOTICE] switch_core_session.c:1744 Session 8604573 (sofia/default/443300431567@65.109.0.34) Ended
  506. 2023-06-23 08:48:22.167023 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/443300431567@65.109.0.34 [CS_DESTROY]
  507. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:739 (sofia/default/443300431567@65.109.0.34) Running State Change CS_DESTROY (Cur 1 Tot 8604574)
  508. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:174 sofia/default/152631@199.167.144.226 Standard REPORTING, cause: NORMAL_CLEARING
  509. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:936 (sofia/default/152631@199.167.144.226) State REPORTING going to sleep
  510. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:749 (sofia/default/443300431567@65.109.0.34) State DESTROY
  511. 2023-06-23 08:48:22.167023 [DEBUG] mod_sofia.c:364 sofia/default/443300431567@65.109.0.34 SOFIA DESTROY
  512. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:181 sofia/default/443300431567@65.109.0.34 Standard DESTROY
  513. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:749 (sofia/default/443300431567@65.109.0.34) State DESTROY going to sleep
  514. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:611 (sofia/default/152631@199.167.144.226) State Change CS_REPORTING -> CS_DESTROY
  515. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_session.c:1726 Session 8604574 (sofia/default/152631@199.167.144.226) Locked, Waiting on external entities
  516. 2023-06-23 08:48:22.167023 [NOTICE] switch_core_session.c:1744 Session 8604574 (sofia/default/152631@199.167.144.226) Ended
  517. 2023-06-23 08:48:22.167023 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/152631@199.167.144.226 [CS_DESTROY]
  518. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:739 (sofia/default/152631@199.167.144.226) Running State Change CS_DESTROY (Cur 0 Tot 8604574)
  519. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:749 (sofia/default/152631@199.167.144.226) State DESTROY
  520. 2023-06-23 08:48:22.167023 [DEBUG] mod_sofia.c:364 sofia/default/152631@199.167.144.226 SOFIA DESTROY
  521. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:181 sofia/default/152631@199.167.144.226 Standard DESTROY
  522. 2023-06-23 08:48:22.167023 [DEBUG] switch_core_state_machine.c:749 (sofia/default/152631@199.167.144.226) State DESTROY going to sleep