1. span style="color: cornflowerblue; font-weight: bold;"> 2021-03-16 11:11:08.614396 [NOTICE] switch_channel.c:1118 New Channel sofia/default/07943550553@213.166.3.69 [f84572be-63d0-4cde-950f-0aa2076f2fc6]
2. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_NEW (Cur 1 Tot 116859)
3. 2021-03-16 11:11:08.614396 [DEBUG] sofia.c:10280 sofia/default/07943550553@213.166.3.69 receiving invite from 87.238.72.129:5060 version: 1.10.5 -release-17-25569c1631 64bit
4. 2021-03-16 11:11:08.614396 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 87.238.72.129:0.
5. 2021-03-16 11:11:08.614396 [DEBUG] sofia.c:10403 IP 87.238.72.129 Approved by acl "default[]". Access Granted.
6. 2021-03-16 11:11:08.614396 [DEBUG] sofia.c:7326 Channel sofia/default/07943550553@213.166.3.69 entering state [received][100]
7. 2021-03-16 11:11:08.614396 [DEBUG] sofia.c:7336 Remote SDP:
8. v=0
9. o=MSSMGC 28676985 0 IN IP4 213.166.3.162
10. s=Cisco SDP 0
11. c=IN IP4 213.166.3.162
12. t=0 0
13. m=audio 16918 RTP/AVP 8 0 3 18 4 101 100
14. a=rtpmap:101 telephone-event/8000
15. a=fmtp:101 0-15
16. a=rtpmap:100 X-NSE/8000
17. a=fmtp:100 200-202
18. a=X-sqn:0
19. a=X-cap: 1 audio RTP/AVP 100
20. a=X-cpar: a=rtpmap:100 X-NSE/8000
21. a=X-cpar: a=fmtp:100 200-202
22. a=X-cap: 2 image udptl t38
23.  
24. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
25. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
26. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
27. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
28. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
29. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
30. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
31. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
32. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
33. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
34. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G729:18:8000:20:8000:1]
35. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
36. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
37. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
38. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
39. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMA:8:8000:20:64000:1]
40. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMU:0:8000:20:64000:1]
41. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G723:4:8000:30:6300:1]/[G729:18:8000:20:8000:1]
42. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
43. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [X-NSE:100:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
44. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [X-NSE:100:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
45. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [X-NSE:100:8000:20:0:1]/[G729:18:8000:20:8000:1]
46. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:3839 Set Codec sofia/default/07943550553@213.166.3.69 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
47. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_codec.c:111 sofia/default/07943550553@213.166.3.69 Original read codec set to PCMA:8
48. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
49. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_media.c:5911 sofia/default/07943550553@213.166.3.69 Set 2833 dtmf send payload to 101 recv payload to 101
50. 2021-03-16 11:11:08.614396 [DEBUG] sofia.c:7760 (sofia/default/07943550553@213.166.3.69) State Change CS_NEW -> CS_INIT
51. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:604 (sofia/default/07943550553@213.166.3.69) State NEW
52. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_INIT (Cur 1 Tot 116859)
53. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:628 (sofia/default/07943550553@213.166.3.69) State INIT
54. 2021-03-16 11:11:08.614396 [DEBUG] mod_sofia.c:93 sofia/default/07943550553@213.166.3.69 SOFIA INIT
55. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:40 sofia/default/07943550553@213.166.3.69 Standard INIT
56. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:48 (sofia/default/07943550553@213.166.3.69) State Change CS_INIT -> CS_ROUTING
57. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:628 (sofia/default/07943550553@213.166.3.69) State INIT going to sleep
58. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_ROUTING (Cur 1 Tot 116859)
59. 2021-03-16 11:11:08.614396 [DEBUG] switch_channel.c:2332 (sofia/default/07943550553@213.166.3.69) Callstate Change DOWN -> RINGING
60. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:644 (sofia/default/07943550553@213.166.3.69) State ROUTING
61. 2021-03-16 11:11:08.614396 [DEBUG] mod_sofia.c:154 sofia/default/07943550553@213.166.3.69 SOFIA ROUTING
62. 2021-03-16 11:11:08.614396 [DEBUG] switch_core_state_machine.c:236 sofia/default/07943550553@213.166.3.69 Standard ROUTING
63. 2021-03-16 11:11:08.614396 [INFO] mod_dialplan_xml.c:637 Processing 07943550553 <07943550553>->01582513838 in context default
64. 2021-03-16 11:11:08.614396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
65. 2021-03-16 11:11:08.634392 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
66. 2021-03-16 11:11:08.634392 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] blind_flag: 0
67. 2021-03-16 11:11:08.634392 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Dialed number : 01582513838
68. 2021-03-16 11:11:08.634392 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '01582513838' limit 1
69. 2021-03-16 11:11:08.634392 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '01582513838' AND status=0 limit 1
70. 2021-03-16 11:11:08.654390 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Functions] [GET_queue_INFO] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = '01582513838' and status=0 LIMIT 1
71. 2021-03-16 11:11:08.654390 [WARNING] switch_cpp.cpp:1447 [ASTPP] [FAXER] in custom Caller ID
72. 2021-03-16 11:11:08.654390 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Caller Id name / number  : 07943550553 / 07943550553
73. 2021-03-16 11:11:08.654390 [DEBUG] switch_cpp.cpp:1447 [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 ="01582513838" LIMIT 1
74. 2021-03-16 11:11:08.654390 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Call direction : inbound
75. 2021-03-16 11:11:08.654390 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [IPAUTHENTICATION] Query :SELECT ip_map.*, (SELECT number FROM accounts where id=accountid AND status=0 AND deleted=0) AS account_code FROM ip_map WHERE INET_ATON("87.238.72.129") BETWEEN(INET_ATON(SUBSTRING_INDEX(`ip`, '/', 1)) & 0xffffffff ^((0x1 <<(32 -  SUBSTRING_INDEX(`ip`, '/', -1))) -1 )) AND(INET_ATON(SUBSTRING_INDEX(`ip`, '/', 1)) |((0x100000000 >> SUBSTRING_INDEX(`ip`,'/', -1)) -1))  AND "01582513838"  LIKE CONCAT(prefix,'%') ORDER BY LENGTH(prefix) DESC LIMIT 1
76. 2021-03-16 11:11:08.654390 [INFO] switch_cpp.cpp:1447 [ASTPP] [Accountcode : 3673942894]
77. 2021-03-16 11:11:08.654390 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "3673942894" AND deleted = 0 limit 1
78. freeswitch@ip-172-31-7-52>
79. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_SPEEDDIAL] Query :SELECT A.number FROM speed_dial as A,accounts as B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.speed_num ="01582513838" AND A.accountid = '3' limit 1
80. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 01582513838
81. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [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 ="01582513838" LIMIT 1
82. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] New Call direction : inbound
83. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="01582513838" AND (accountid = 0 OR status = 1) LIMIT 1
84. 2021-03-16 11:11:08.974384 [NOTICE] switch_cpp.cpp:1447 [ASTPP] Localization Id: 1
85. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate,dst_base_cid FROM localization WHERE id = 1 AND status=0 limit 1
86. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
87. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :76
88. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id,P.product_id as product_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE (patterns = '^01582513838.*' OR patterns = '^0158251383.*' OR patterns = '^015825138.*' OR patterns = '^01582513.*' OR patterns = '^0158251.*' OR patterns = '^015825.*' OR patterns = '^01582.*' OR patterns = '^0158.*' OR patterns = '^015.*' OR patterns = '^01.*' OR patterns = '^0.*' OR patterns ='--') AND accountid = 76 ORDER BY LENGTH(PKGPTR.patterns) DESC
89. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '01582513838' OR number = '0158251383' OR number = '015825138' OR number = '01582513' OR number = '0158251' OR number = '015825' OR number = '01582' OR number = '0158' OR number = '015' OR number = '01' OR number = '0' OR number ='--') OR (number = '01582513838*' OR number = '0158251383*' OR number = '015825138*' OR number = '01582513*' OR number = '0158251*' OR number = '015825*' OR number = '01582*' OR number = '0158*' OR number = '015*' OR number = '01*' OR number = '0*' OR number ='--') OR (number = '07943550553' OR number = '0794355055' OR number = '079435505' OR number = '07943550' OR number = '0794355' OR number = '079435' OR number = '07943' OR number = '0794' OR number = '079' OR number = '07' OR number = '0' OR number ='--') OR (number = '07943550553*' OR number = '0794355055*' OR number = '079435505*' OR number = '07943550*' OR number = '0794355*' OR number = '079435*' OR number = '07943*' OR number = '0794*' OR number = '079*' OR number = '07*' OR number = '0*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
90. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Call Barring Status : -1
91. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '01582513838' OR routing_prefix = '0158251383' OR routing_prefix = '015825138' OR routing_prefix = '01582513' OR routing_prefix = '0158251' OR routing_prefix = '015825' OR routing_prefix = '01582' OR routing_prefix = '0158' OR routing_prefix = '015' OR routing_prefix = '01' OR routing_prefix = '0' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
92. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Account Information ===================
93. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] User id : 3
94. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Account code : 3673942894
95. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Balance : 10000
96. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
97. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Ratecard id : 3
98. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] CID Pool : 0
99. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] ========================================================
100. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 3 AND status = 0
101. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] call_direction :inbound
102. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [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 ="01582513838" LIMIT 1
103. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] call_direction:::::: inbound
104. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Rates Information ===================
105. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] ID : 16
106. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Connectcost : 0.00000
107. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Includedseconds : 0
108. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Cost : 0.00000
109. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] comment : Luton Bedfordshire
110. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Country Id : 200
111. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Accid : 3
112. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] ================================================================
113. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Your10000 balance Accountid 3 !!!
114. 2021-03-16 11:11:08.974384 [NOTICE] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100
115. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] Call Max length duration : 100 minutes
116. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] [userinfo] INB_FREE:TRUE
117. 2021-03-16 11:11:08.974384 [INFO] switch_cpp.cpp:1447 [ASTPP] [userinfo] free_inbound:1
118. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 3 AND status=0 LIMIT 1
119. 2021-03-16 11:11:08.974384 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE id = "76" AND deleted = 0 limit 1
120. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] [userinfo] Actual CustomerInfo XML:3
121. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] [userinfo] Userinfo XML:3
122. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] [userinfo] Actual CustomerInfo XML : 3
123. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE accountid = 76 limit 1
124. 2021-03-16 11:11:09.014383 [WARNING] switch_cpp.cpp:1447 [ASTPP] [user_domain] user_domainKamal58.appcaption.com
125. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] maxlength::::::::: 100
126. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] [PBX] call_direction : inbound
127. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan1] pbx did-loca adding custome header1
128. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :"44/0".....07943550553
129. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :"44/0".....07943550553
130. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE accountid = 76 limit 1
131. 2021-03-16 11:11:09.014383 [WARNING] switch_cpp.cpp:1447 [ASTPP] [user_domain] user_domainKamal58.appcaption.com
132. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_10
133. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] custom_function_name::::::::::1343:::::::::::::::16
134. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] [PBX] call_type : 10
135. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] [PBX] call_type : IVR
136. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Functions] [GET_IVR_INFO] Query :SELECT * from pbx_ivr_specification WHERE id = 1 and status=0 LIMIT 1
137. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Functions] [GET_RING_GROUP_INFO] Query :SELECT file_name from pbx_recording WHERE id = '${au-ring}' LIMIT 1
138. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== calleridname=calleridname calleridname==================NEW_BUSSINESS_SALES=========
139. 2021-03-16 11:11:09.014383 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== calleridnumber=calleridnumber calleridnumber==================54895=========
140. 2021-03-16 11:11:09.014383 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Generated XML:<?xml version="1.0" encoding="UTF-8" standalone="no"?>
141. <document type="freeswitch/xml">
142. <section name="dialplan" description="ASTPP Dialplan">
143. <context name="default">
144. <extension name="01582513838">
145. <condition field="destination_number" expression="01582513838">
146. <action application="set" data="effective_destination_number=01582513838"/>
147. <action application="set" data="bridge_pre_execute_bleg_app=sched_hangup"/>
148. <action application="set" data="bridge_pre_execute_bleg_data=+6000 normal_clearing"/>
149. <action application="set" data="callstart=2021-03-16 11:11:09"/>
150. <action application="set" data="hangup_after_bridge=true"/>
151. <action application="set" data="continue_on_fail=TRUE"/>
152. <action application="set" data="account_id=3"/>
153. <action application="set" data="parent_id=0"/>
154. <action application="set" data="entity_id=3"/>
155. <action application="set" data="call_processed=internal"/>
156. <action application="set" data="call_direction=inbound"/>
157. <action application="set" data="accountname=Magrathea_IP_1"/>
158. <action application="set" data="filename1=astpp.pbx.lua"/>
159. <action application="set" data="origination_rates_did=ID:16|CODE:^01582513838.*|DESTINATION:Luton Bedfordshire|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:10|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:200|ACCID:76"/>
160. <action application="set" data="origination_rates=0"/>
161. <action application="set" data="original_caller_id_name=07943550553"/>
162. <action application="set" data="original_caller_id_number=07943550553"/>
163. <action application="limit" data="db 76 user_76 2 !SWITCH_CONGESTION"/>
164. <action application="set" data="effective_caller_id_name=07943550553"/>
165. <action application="set" data="effective_caller_id_number=07943550553"/>
166. <action application="set" data="receiver_accid=76"/>
167. <action application="limit" data="db 01582513838 did_01582513838 2 !SWITCH_CONGESTION"/>
168. <action application="export" data="presence_data=x|||Magrathea(3673942894)|||^01582513838.* // Luton Bedfordshire // 0.00000||||||DID"/>
169. <action application="export" data="call_type=10"/>
170. <action application="set" data="did_calltype=10"/>
171. <action application="set" data="did_extensions=1"/>
172. <action application="export" data="is_recording=1"/>
173. <action application="export" data="media_bug_answer_req=true"/>
174. <action application="export" data="RECORD_STEREO=true"/>
175. <action application="export" data="record_sample_rate=8000"/>
176. <action application="export" data="execute_on_answer=record_session $${recordings_dir}/${uuid}.wav"/>
177. <action application="set" data="ringback=${au-ring}"/>
178. <action application="set" data="effective_caller_id_name=NEW_BUSSINESS_SALES#07943550553"/>
179. <action application="set" data="effective_caller_id_number=54895#07943550553"/>
180. <action application="set" data="module_name=pbx"/>
181.     <action application="answer"/>
182. <action application="ivr" data="TEST_IVR0"/>
183. </condition>
184. </extension>
185. </context>
186. </section>
187. </document>
188. Dialplan: sofia/default/07943550553@213.166.3.69 parsing [default->01582513838] continue=false
189. Dialplan: sofia/default/07943550553@213.166.3.69 Regex (PASS) [01582513838] destination_number(01582513838) =~ /01582513838/ break=on-false
190. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_destination_number=01582513838)
191. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(bridge_pre_execute_bleg_app=sched_hangup)
192. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
193. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(callstart=2021-03-16 11:11:09)
194. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(hangup_after_bridge=true)
195. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(continue_on_fail=TRUE)
196. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(account_id=3)
197. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(parent_id=0)
198. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(entity_id=3)
199. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(call_processed=internal)
200. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(call_direction=inbound)
201. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(accountname=Magrathea_IP_1)
202. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(filename1=astpp.pbx.lua)
203. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(origination_rates_did=ID:16|CODE:^01582513838.*|DESTINATION:Luton Bedfordshire|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:10|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:200|ACCID:76)
204. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(origination_rates=0)
205. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(original_caller_id_name=07943550553)
206. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(original_caller_id_number=07943550553)
207. Dialplan: sofia/default/07943550553@213.166.3.69 Action limit(db 76 user_76 2 !SWITCH_CONGESTION)
208. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_caller_id_name=07943550553)
209. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_caller_id_number=07943550553)
210. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(receiver_accid=76)
211. Dialplan: sofia/default/07943550553@213.166.3.69 Action limit(db 01582513838 did_01582513838 2 !SWITCH_CONGESTION)
212. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(presence_data=x|||Magrathea(3673942894)|||^01582513838.* // Luton Bedfordshire // 0.00000||||||DID)
213. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(call_type=10)
214. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(did_calltype=10)
215. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(did_extensions=1)
216. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(is_recording=1)
217. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(media_bug_answer_req=true)
218. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(RECORD_STEREO=true)
219. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(record_sample_rate=8000)
220. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(execute_on_answer=record_session $${recordings_dir}/${uuid}.wav)
221. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(ringback=${au-ring})
222. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_caller_id_name=NEW_BUSSINESS_SALES#07943550553)
223. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_caller_id_number=54895#07943550553)
224. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(module_name=pbx)
225. Dialplan: sofia/default/07943550553@213.166.3.69 Action answer()
226. Dialplan: sofia/default/07943550553@213.166.3.69 Action ivr(TEST_IVR0)
227. 2021-03-16 11:11:09.014383 [DEBUG] switch_core_state_machine.c:287 (sofia/default/07943550553@213.166.3.69) State Change CS_ROUTING -> CS_EXECUTE
228. 2021-03-16 11:11:09.014383 [DEBUG] switch_core_state_machine.c:644 (sofia/default/07943550553@213.166.3.69) State ROUTING going to sleep
229. 2021-03-16 11:11:09.014383 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_EXECUTE (Cur 1 Tot 116859)
230. 2021-03-16 11:11:09.014383 [DEBUG] switch_core_state_machine.c:651 (sofia/default/07943550553@213.166.3.69) State EXECUTE
231. 2021-03-16 11:11:09.034425 [DEBUG] mod_sofia.c:209 sofia/default/07943550553@213.166.3.69 SOFIA EXECUTE
232. 2021-03-16 11:11:09.034425 [DEBUG] switch_core_state_machine.c:329 sofia/default/07943550553@213.166.3.69 Standard EXECUTE
233. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_destination_number=01582513838)
234. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_destination_number]=[01582513838]
235. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(bridge_pre_execute_bleg_app=sched_hangup)
236. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [bridge_pre_execute_bleg_app]=[sched_hangup]
237. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
238. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [bridge_pre_execute_bleg_data]=[+6000 normal_clearing]
239. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(callstart=2021-03-16 11:11:09)
240. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [callstart]=[2021-03-16 11:11:09]
241. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(hangup_after_bridge=true)
242. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [hangup_after_bridge]=[true]
243. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(continue_on_fail=TRUE)
244. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [continue_on_fail]=[TRUE]
245. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(account_id=3)
246. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [account_id]=[3]
247. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(parent_id=0)
248. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [parent_id]=[0]
249. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(entity_id=3)
250. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [entity_id]=[3]
251. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(call_processed=internal)
252. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [call_processed]=[internal]
253. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(call_direction=inbound)
254. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [call_direction]=[inbound]
255. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(accountname=Magrathea_IP_1)
256. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [accountname]=[Magrathea_IP_1]
257. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(filename1=astpp.pbx.lua)
258. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [filename1]=[astpp.pbx.lua]
259. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(origination_rates_did=ID:16|CODE:^01582513838.*|DESTINATION:Luton Bedfordshire|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:10|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:200|ACCID:76)
260. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [origination_rates_did]=[ID:16|CODE:^01582513838.*|DESTINATION:Luton Bedfordshire|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:10|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:200|ACCID:76]
261. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(origination_rates=0)
262. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [origination_rates]=[0]
263. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(original_caller_id_name=07943550553)
264. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [original_caller_id_name]=[07943550553]
265. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(original_caller_id_number=07943550553)
266. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [original_caller_id_number]=[07943550553]
267. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 limit(db 76 user_76 2 !SWITCH_CONGESTION)
268. 2021-03-16 11:11:09.034425 [DEBUG] switch_limit.c:124 incr called: 76_user_76 max:2, interval:0
269. 2021-03-16 11:11:09.034425 [DEBUG] mod_db.c:194 Usage for 76_user_76 is now 1/2
270. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_caller_id_name=07943550553)
271. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_caller_id_name]=[07943550553]
272. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_caller_id_number=07943550553)
273. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_caller_id_number]=[07943550553]
274. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(receiver_accid=76)
275. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [receiver_accid]=[76]
276. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 limit(db 01582513838 did_01582513838 2 !SWITCH_CONGESTION)
277. 2021-03-16 11:11:09.034425 [DEBUG] switch_limit.c:124 incr called: 01582513838_did_01582513838 max:2, interval:0
278. 2021-03-16 11:11:09.034425 [DEBUG] mod_db.c:194 Usage for 01582513838_did_01582513838 is now 1/2
279. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(presence_data=x|||Magrathea(3673942894)|||^01582513838.* // Luton Bedfordshire // 0.00000||||||DID)
280. 2021-03-16 11:11:09.034425 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [presence_data]=[x|||Magrathea(3673942894)|||^01582513838.* // Luton Bedfordshire // 0.00000||||||DID]
281. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(call_type=10)
282. 2021-03-16 11:11:09.034425 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_type]=[10]
283. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(did_calltype=10)
284. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [did_calltype]=[10]
285. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(did_extensions=1)
286. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [did_extensions]=[1]
287. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(is_recording=1)
288. 2021-03-16 11:11:09.034425 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [is_recording]=[1]
289. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(media_bug_answer_req=true)
290. 2021-03-16 11:11:09.034425 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [media_bug_answer_req]=[true]
291. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(RECORD_STEREO=true)
292. 2021-03-16 11:11:09.034425 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [RECORD_STEREO]=[true]
293. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(record_sample_rate=8000)
294. 2021-03-16 11:11:09.034425 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [record_sample_rate]=[8000]
295. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(execute_on_answer=record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav)
296. 2021-03-16 11:11:09.034425 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [execute_on_answer]=[record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav]
297. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(ringback=%(400,200,383,417);%(400,2000,383,417))
298. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [ringback]=[%(400,200,383,417);%(400,2000,383,417)]
299. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_caller_id_name=NEW_BUSSINESS_SALES#07943550553)
300. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_caller_id_name]=[NEW_BUSSINESS_SALES#07943550553]
301. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_caller_id_number=54895#07943550553)
302. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_caller_id_number]=[54895#07943550553]
303. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(module_name=pbx)
304. 2021-03-16 11:11:09.034425 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [module_name]=[pbx]
305. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 answer()
306. 2021-03-16 11:11:09.034425 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/default/07943550553@213.166.3.69] 172.31.7.52 port 19604 -> 213.166.3.162 port 16918 codec: 8 ms: 20
307. 2021-03-16 11:11:09.034425 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
308. 2021-03-16 11:11:09.034425 [DEBUG] switch_core_media.c:8977 sofia/default/07943550553@213.166.3.69 Set 2833 dtmf send payload to 101
309. 2021-03-16 11:11:09.034425 [DEBUG] switch_core_media.c:8984 sofia/default/07943550553@213.166.3.69 Set 2833 dtmf receive payload to 101
310. 2021-03-16 11:11:09.034425 [DEBUG] switch_core_media.c:9007 sofia/default/07943550553@213.166.3.69 Set rtp dtmf delay to 40
311. 2021-03-16 11:11:09.034425 [DEBUG] mod_sofia.c:898 Local SDP sofia/default/07943550553@213.166.3.69:
312. v=0
313. o=FreeSWITCH 1615873465 1615873466 IN IP4 35.176.176.116
314. s=FreeSWITCH
315. c=IN IP4 35.176.176.116
316. t=0 0
317. m=audio 19604 RTP/AVP 8 101
318. a=rtpmap:8 PCMA/8000
319. a=rtpmap:101 telephone-event/8000
320. a=fmtp:101 0-16
321. a=ptime:20
322. a=sendrecv
323.  
324. 2021-03-16 11:11:09.034425 [NOTICE] mod_dptools.c:1406 Channel [sofia/default/07943550553@213.166.3.69] has been answered
325. 2021-03-16 11:11:09.034425 [DEBUG] sofia.c:7326 Channel sofia/default/07943550553@213.166.3.69 entering state [completed][200]
326. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 record_session(/var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav)
327. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_async.c:1351 Record session sample rate: 8000 -> 8000
328. 2021-03-16 11:11:09.054393 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to sofia/default/07943550553@213.166.3.69
329. 2021-03-16 11:11:09.054393 [DEBUG] sofia.c:7326 Channel sofia/default/07943550553@213.166.3.69 entering state [ready][200]
330. 2021-03-16 11:11:09.054393 [DEBUG] switch_channel.c:3865 (sofia/default/07943550553@213.166.3.69) Callstate Change RINGING -> ACTIVE
331. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 ivr(TEST_IVR0)
332. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:746 switch_ivr_menu_stack_xml_add binding 'menu-exit'
333. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:746 switch_ivr_menu_stack_xml_add binding 'menu-sub'
334. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:746 switch_ivr_menu_stack_xml_add binding 'menu-exec-app'
335. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:746 switch_ivr_menu_stack_xml_add binding 'menu-play-sound'
336. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:746 switch_ivr_menu_stack_xml_add binding 'menu-back'
337. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:746 switch_ivr_menu_stack_xml_add binding 'menu-top'
338. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:883 building menu 'TEST_IVR0'
339. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:968 binding menu action 'menu-exec-app' to '1'
340. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:968 binding menu action 'menu-exec-app' to '/^(\d{2,20})$/'
341. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_menu.c:486 Executing IVR menu TEST_IVR0
342. 2021-03-16 11:11:09.054393 [WARNING] switch_core_file.c:424 File has 2 channels, muxing to 1 channel will occur.
343. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
344. 2021-03-16 11:11:09.054393 [DEBUG] switch_ivr_async.c:1640 No silence detection configured; assuming start of speech
345. 2021-03-16 11:11:09.114390 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
346. 2021-03-16 11:11:09.114390 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMA:8
347. 2021-03-16 11:11:12.154402 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 1:2184
348. 2021-03-16 11:11:12.154402 [INFO] switch_channel.c:522 RECV DTMF 1:2184
349. 2021-03-16 11:11:12.154402 [DEBUG] switch_ivr_play_say.c:1933 done playing file /var/www/html/astpp/upload/pbx/WelcomeGreeting_080321104213.wav
350. 2021-03-16 11:11:12.154402 [DEBUG] switch_ivr_menu.c:378 waiting for 19/20 digits t/o 2000
351. 2021-03-16 11:11:14.174393 [DEBUG] switch_ivr_menu.c:425 digits '1'
352. 2021-03-16 11:11:14.174393 [DEBUG] switch_ivr_menu.c:580 IVR action on menu 'TEST_IVR0' matched '1' param 'transfer 5285082368 XML ${domain_name}'
353. 2021-03-16 11:11:14.174393 [DEBUG] switch_ivr_menu.c:584 switch_ivr_menu_execute todo=[2]
354. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 transfer(5285082368 XML 172.31.7.52)
355. 2021-03-16 11:11:14.174393 [DEBUG] switch_ivr.c:2243 (sofia/default/07943550553@213.166.3.69) State Change CS_EXECUTE -> CS_ROUTING
356. 2021-03-16 11:11:14.174393 [NOTICE] switch_ivr.c:2250 Transfer sofia/default/07943550553@213.166.3.69 to XML[5285082368@172.31.7.52]
357. 2021-03-16 11:11:14.174393 [DEBUG] switch_ivr_menu.c:562 action regex [1] [/^(\d{2,20})$/] [0]
358. 2021-03-16 11:11:14.174393 [DEBUG] switch_ivr_menu.c:676 exit-sound '(null)'
359. 2021-03-16 11:11:14.174393 [DEBUG] switch_core_state_machine.c:651 (sofia/default/07943550553@213.166.3.69) State EXECUTE going to sleep
360. 2021-03-16 11:11:14.174393 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_ROUTING (Cur 1 Tot 116859)
361. 2021-03-16 11:11:14.174393 [DEBUG] switch_channel.c:2332 (sofia/default/07943550553@213.166.3.69) Callstate Change ACTIVE -> RINGING
362. 2021-03-16 11:11:14.174393 [DEBUG] switch_core_state_machine.c:644 (sofia/default/07943550553@213.166.3.69) State ROUTING
363. 2021-03-16 11:11:14.174393 [DEBUG] mod_sofia.c:154 sofia/default/07943550553@213.166.3.69 SOFIA ROUTING
364. 2021-03-16 11:11:14.174393 [DEBUG] switch_core_state_machine.c:236 sofia/default/07943550553@213.166.3.69 Standard ROUTING
365. 2021-03-16 11:11:14.174393 [INFO] mod_dialplan_xml.c:637 Processing 07943550553 <07943550553>->5285082368 in context 172.31.7.52
366. 2021-03-16 11:11:14.174393 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
367. 2021-03-16 11:11:14.194391 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
368. 2021-03-16 11:11:14.194391 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] blind_flag: 0
369. 2021-03-16 11:11:14.194391 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Dialed number : 5285082368
370. 2021-03-16 11:11:14.194391 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '5285082368' limit 1
371. 2021-03-16 11:11:14.194391 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '5285082368' AND status=0 limit 1
372. 2021-03-16 11:11:14.194391 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Functions] [GET_queue_INFO] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = '5285082368' and status=0 LIMIT 1
373. 2021-03-16 11:11:14.194391 [WARNING] switch_cpp.cpp:1447 [ASTPP] [FAXER] in custom Caller ID
374. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Caller Id name / number  : NEW_BUSSINESS_SALES#07943550553 / 54895#07943550553
375. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [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 ="5285082368" LIMIT 1
376. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation FROM sip_devices as sip_devices,accounts as  accounts ,domains WHERE accounts.id=domains.accountid AND accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="5285082368"  AND domains.domain="sip.e.e164.org.uk" limit 1
377. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Call direction : outbound
378. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [IPAUTHENTICATION] Query :SELECT ip_map.*, (SELECT number FROM accounts where id=accountid AND status=0 AND deleted=0) AS account_code FROM ip_map WHERE INET_ATON("87.238.72.129") BETWEEN(INET_ATON(SUBSTRING_INDEX(`ip`, '/', 1)) & 0xffffffff ^((0x1 <<(32 -  SUBSTRING_INDEX(`ip`, '/', -1))) -1 )) AND(INET_ATON(SUBSTRING_INDEX(`ip`, '/', 1)) |((0x100000000 >> SUBSTRING_INDEX(`ip`,'/', -1)) -1))  AND "5285082368"  LIKE CONCAT(prefix,'%') ORDER BY LENGTH(prefix) DESC LIMIT 1
379. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] [Accountcode : 3673942894]
380. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "3673942894" AND deleted = 0 limit 1
381. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^5285082368.*' OR blocked_patterns = '^528508236.*' OR blocked_patterns = '^52850823.*' OR blocked_patterns = '^5285082.*' OR blocked_patterns = '^528508.*' OR blocked_patterns = '^52850.*' OR blocked_patterns = '^5285.*' OR blocked_patterns = '^528.*' OR blocked_patterns = '^52.*' OR blocked_patterns = '^5.*' OR blocked_patterns ='--') AND accountid = 3 limit 1
382. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_SPEEDDIAL] Query :SELECT A.number FROM speed_dial as A,accounts as B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.speed_num ="5285082368" AND A.accountid = '3' limit 1
383. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 5285082368
384. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [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 ="5285082368" LIMIT 1
385. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation FROM sip_devices as sip_devices,accounts as  accounts ,domains WHERE accounts.id=domains.accountid AND accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="5285082368"  AND domains.domain="sip.e.e164.org.uk" limit 1
386. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] New Call direction : outbound
387. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="5285082368" AND (accountid = 0 OR status = 1) LIMIT 1
388. 2021-03-16 11:11:14.214396 [NOTICE] switch_cpp.cpp:1447 [ASTPP] Localization Id: 1
389. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate,dst_base_cid FROM localization WHERE id = 1 AND status=0 limit 1
390. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :"0/44".....5285082368
391. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id,P.product_id as product_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE (patterns = '^5285082368.*' OR patterns = '^528508236.*' OR patterns = '^52850823.*' OR patterns = '^5285082.*' OR patterns = '^528508.*' OR patterns = '^52850.*' OR patterns = '^5285.*' OR patterns = '^528.*' OR patterns = '^52.*' OR patterns = '^5.*' OR patterns ='--') AND accountid = 3 ORDER BY LENGTH(PKGPTR.patterns) DESC
392. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '5285082368' OR number = '528508236' OR number = '52850823' OR number = '5285082' OR number = '528508' OR number = '52850' OR number = '5285' OR number = '528' OR number = '52' OR number = '5' OR number ='--') OR (number = '5285082368*' OR number = '528508236*' OR number = '52850823*' OR number = '5285082*' OR number = '528508*' OR number = '52850*' OR number = '5285*' OR number = '528*' OR number = '52*' OR number = '5*' OR number ='--') OR (number = '54895#07943550553' OR number = '54895#0794355055' OR number = '54895#079435505' OR number = '54895#07943550' OR number = '54895#0794355' OR number = '54895#079435' OR number = '54895#07943' OR number = '54895#0794' OR number = '54895#079' OR number = '54895#07' OR number = '54895#0' OR number = '54895#' OR number = '54895' OR number = '5489' OR number = '548' OR number = '54' OR number = '5' OR number ='--') OR (number = '54895#07943550553*' OR number = '54895#0794355055*' OR number = '54895#079435505*' OR number = '54895#07943550*' OR number = '54895#0794355*' OR number = '54895#079435*' OR number = '54895#07943*' OR number = '54895#0794*' OR number = '54895#079*' OR number = '54895#07*' OR number = '54895#0*' OR number = '54895#*' OR number = '54895*' OR number = '5489*' OR number = '548*' OR number = '54*' OR number = '5*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
393. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Call Barring Status : -1
394. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '5285082368' OR routing_prefix = '528508236' OR routing_prefix = '52850823' OR routing_prefix = '5285082' OR routing_prefix = '528508' OR routing_prefix = '52850' OR routing_prefix = '5285' OR routing_prefix = '528' OR routing_prefix = '52' OR routing_prefix = '5' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
395. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Account Information ===================
396. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] User id : 3
397. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Account code : 3673942894
398. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Balance : 13.24
399. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
400. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Ratecard id : 3
401. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] CID Pool : 0
402. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] ========================================================
403. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 3 AND status = 0
404. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] call_direction :outbound
405. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 3 AND status = 0
406. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^5285082368.*' OR pattern = '^528508236.*' OR pattern = '^52850823.*' OR pattern = '^5285082.*' OR pattern = '^528508.*' OR pattern = '^52850.*' OR pattern = '^5285.*' OR pattern = '^528.*' OR pattern = '^52.*' OR pattern = '^5.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 3 OR accountid=3)  ORDER BY accountid DESC,cost ASC LIMIT 1
407. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] call_direction:::::: outbound
408. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Rates Information ===================
409. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] ID : 55536
410. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Connectcost : 0.00000
411. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Includedseconds : 0
412. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Cost : 0.03290
413. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] comment : Mexico
414. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Country Id : 0
415. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Accid : 3
416. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Trunk ID: 0
417. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Routing type:
418. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] ================================================================
419. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Your13.24 balance Accountid 3 !!!
420. 2021-03-16 11:11:14.214396 [NOTICE] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
421. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] Call Max length duration : 100 minutes
422. 2021-03-16 11:11:14.214396 [INFO] switch_cpp.cpp:1447 [ASTPP] [DIALPLAN] User Rate ID : 55536
423. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_CARRIER_RATES]123131 Query rate_carrier_id  :0
424. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_CARRIER_RATES_TRUNKS] Query :SELECT GROUP_CONCAT(trunk_id) as ids FROM routing WHERE pricelist_id=3 ORDER by id asc
425. 2021-03-16 11:11:14.214396 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^5285082368.*' OR pattern = '^528508236.*' OR pattern = '^52850823.*' OR pattern = '^5285082.*' OR pattern = '^528508.*' OR pattern = '^52850.*' OR pattern = '^5285.*' OR pattern = '^528.*' OR pattern = '^52.*' OR pattern = '^5.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (4,5) ORDER by TR.cost ASC,TR.precedence ASC, TK.precedence
426. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Termination Rates Information ===================
427. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] ID : 55538
428. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Code : ^52.*
429. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Destination : Mexico
430. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Connectcost : 0.00000
431. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Free Seconds : 0
432. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Prefix : ^52.*
433. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Strip :
434. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Prepend :
435. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Carrier id : 4
436. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] carrier_name : Magrathea_Gateway
437. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] dialplan_variable :
438. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Failover gateway : NSN_Gateway
439. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Vendor id : 3
440. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Max channels : 0
441. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] Trunk Name : Trunk_M1
442. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] ========================END OF TERMINATION RATES=======================
443. 2021-03-16 11:11:14.234392 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 3 AND status=0 LIMIT 1
444. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] maxlength::::::::: 100
445. 2021-03-16 11:11:14.234392 [INFO] switch_cpp.cpp:1447 [ASTPP] [PBX] call_direction : outbound
446. 2021-03-16 11:11:14.234392 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 3 AND status = 0
447. 2021-03-16 11:11:14.234392 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate,dst_base_cid FROM localization WHERE id=(SELECT localization_id from accounts where id = 3) AND status=0 limit 1
448. 2021-03-16 11:11:14.234392 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Generated XML:
449. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
450. <document type="freeswitch/xml">
451. <section name="dialplan" description="ASTPP Dialplan">
452. <context name="172.31.7.52">
453. <extension name="5285082368">
454. <condition field="destination_number" expression="5285082368">
455. <action application="set" data="effective_destination_number=5285082368"/>
456. <action application="set" data="bridge_pre_execute_bleg_app=sched_hangup"/>
457. <action application="set" data="bridge_pre_execute_bleg_data=+6000 normal_clearing"/>
458. <action application="set" data="callstart=2021-03-16 11:11:14"/>
459. <action application="set" data="hangup_after_bridge=true"/>
460. <action application="set" data="continue_on_fail=TRUE"/>
461. <action application="set" data="account_id=3"/>
462. <action application="set" data="parent_id=0"/>
463. <action application="set" data="entity_id=3"/>
464. <action application="set" data="call_processed=internal"/>
465. <action application="set" data="call_direction=outbound"/>
466. <action application="set" data="accountname=Magrathea_IP_1"/>
467. <action application="set" data="filename1=astpp.pbx.lua"/>
468. <action application="set" data="origination_rates=ID:55536|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.03290|INC:60|INITIALBLOCK:60|RATEGROUP:3|MARKUP:0|CI:0|ACCID:3"/>
469. <action application="set" data="original_caller_id_name=NEW_BUSSINESS_SALES#07943550553"/>
470. <action application="set" data="original_caller_id_number=54895#07943550553"/>
471.  
472. <action application="export" data="is_recording=1"/>
473. <action application="export" data="media_bug_answer_req=true"/>
474. <action application="export" data="RECORD_STEREO=true"/>
475. <action application="export" data="record_sample_rate=8000"/>
476. <action application="export" data="execute_on_answer=record_session $${recordings_dir}/${uuid}.wav"/>
477. <action application="set" data="effective_caller_id_name=NEW_BUSSINESS_SALES#07943550553"/>
478. <action application="set" data="effective_caller_id_number=54895#07943550553"/>
479. <action application="set" data="calltype=STANDARD"/>
480. <action application="set" data="termination_rates=ID:55538|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00940|INC:1|INITIALBLOCK:60|TRUNK:4|PROVIDER:3"/>
481. <action application="set" data="trunk_id=4"/>
482. <action application="set" data="provider_id=3"/>
483. <action application="set" data="rate_flag=1"/>
484. <action application="set" data="force_trunk_flag=55536"/>
485. <action application="export" data="presence_data=trunk_id=4"/>
486. <action application="set" data="intcall=0"/>
487. <action application="export" data="presence_data=x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129"/>
488. <action application="bridge" data="[leg_timeout=0,absolute_codec_string=^^:PCMA:PCMU:G729]sofia/gateway/Magrathea_Gateway/5285082368"/>
489. <action application="bridge" data="[leg_timeout=0,absolute_codec_string=^^:PCMA:PCMU:G729]sofia/gateway/NSN_Gateway/5285082368"/>
490. </condition>
491. </extension>
492. </context>
493. </section>
494. </document>
495. Dialplan: sofia/default/07943550553@213.166.3.69 parsing [172.31.7.52->5285082368] continue=false
496. Dialplan: sofia/default/07943550553@213.166.3.69 Regex (PASS) [5285082368] destination_number(5285082368) =~ /5285082368/ break=on-false
497. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_destination_number=5285082368)
498. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(bridge_pre_execute_bleg_app=sched_hangup)
499. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
500. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(callstart=2021-03-16 11:11:14)
501. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(hangup_after_bridge=true)
502. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(continue_on_fail=TRUE)
503. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(account_id=3)
504. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(parent_id=0)
505. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(entity_id=3)
506. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(call_processed=internal)
507. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(call_direction=outbound)
508. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(accountname=Magrathea_IP_1)
509. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(filename1=astpp.pbx.lua)
510. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(origination_rates=ID:55536|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.03290|INC:60|INITIALBLOCK:60|RATEGROUP:3|MARKUP:0|CI:0|ACCID:3)
511. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(original_caller_id_name=NEW_BUSSINESS_SALES#07943550553)
512. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(original_caller_id_number=54895#07943550553)
513. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(is_recording=1)
514. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(media_bug_answer_req=true)
515. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(RECORD_STEREO=true)
516. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(record_sample_rate=8000)
517. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(execute_on_answer=record_session $${recordings_dir}/${uuid}.wav)
518. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_caller_id_name=NEW_BUSSINESS_SALES#07943550553)
519. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(effective_caller_id_number=54895#07943550553)
520. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(calltype=STANDARD)
521. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(termination_rates=ID:55538|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00940|INC:1|INITIALBLOCK:60|TRUNK:4|PROVIDER:3)
522. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(trunk_id=4)
523. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(provider_id=3)
524. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(rate_flag=1)
525. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(force_trunk_flag=55536)
526. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(presence_data=trunk_id=4)
527. Dialplan: sofia/default/07943550553@213.166.3.69 Action set(intcall=0)
528. Dialplan: sofia/default/07943550553@213.166.3.69 Action export(presence_data=x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129)
529. Dialplan: sofia/default/07943550553@213.166.3.69 Action bridge([leg_timeout=0,absolute_codec_string=^^:PCMA:PCMU:G729]sofia/gateway/Magrathea_Gateway/5285082368)
530. Dialplan: sofia/default/07943550553@213.166.3.69 Action bridge([leg_timeout=0,absolute_codec_string=^^:PCMA:PCMU:G729]sofia/gateway/NSN_Gateway/5285082368)
531. 2021-03-16 11:11:14.234392 [DEBUG] switch_core_state_machine.c:287 (sofia/default/07943550553@213.166.3.69) State Change CS_ROUTING -> CS_EXECUTE
532. 2021-03-16 11:11:14.234392 [DEBUG] switch_core_state_machine.c:644 (sofia/default/07943550553@213.166.3.69) State ROUTING going to sleep
533. 2021-03-16 11:11:14.234392 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_EXECUTE (Cur 1 Tot 116859)
534. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:2334 (sofia/default/07943550553@213.166.3.69) Callstate Change RINGING -> ACTIVE
535. 2021-03-16 11:11:14.234392 [DEBUG] switch_core_state_machine.c:651 (sofia/default/07943550553@213.166.3.69) State EXECUTE
536. 2021-03-16 11:11:14.234392 [DEBUG] mod_sofia.c:209 sofia/default/07943550553@213.166.3.69 SOFIA EXECUTE
537. 2021-03-16 11:11:14.234392 [DEBUG] switch_core_state_machine.c:329 sofia/default/07943550553@213.166.3.69 Standard EXECUTE
538. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_destination_number=5285082368)
539. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_destination_number]=[5285082368]
540. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(bridge_pre_execute_bleg_app=sched_hangup)
541. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [bridge_pre_execute_bleg_app]=[sched_hangup]
542. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
543. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [bridge_pre_execute_bleg_data]=[+6000 normal_clearing]
544. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(callstart=2021-03-16 11:11:14)
545. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [callstart]=[2021-03-16 11:11:14]
546. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(hangup_after_bridge=true)
547. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [hangup_after_bridge]=[true]
548. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(continue_on_fail=TRUE)
549. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [continue_on_fail]=[TRUE]
550. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(account_id=3)
551. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [account_id]=[3]
552. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(parent_id=0)
553. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [parent_id]=[0]
554. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(entity_id=3)
555. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [entity_id]=[3]
556. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(call_processed=internal)
557. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [call_processed]=[internal]
558. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(call_direction=outbound)
559. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [call_direction]=[outbound]
560. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(accountname=Magrathea_IP_1)
561. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [accountname]=[Magrathea_IP_1]
562. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(filename1=astpp.pbx.lua)
563. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [filename1]=[astpp.pbx.lua]
564. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(origination_rates=ID:55536|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.03290|INC:60|INITIALBLOCK:60|RATEGROUP:3|MARKUP:0|CI:0|ACCID:3)
565. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [origination_rates]=[ID:55536|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.03290|INC:60|INITIALBLOCK:60|RATEGROUP:3|MARKUP:0|CI:0|ACCID:3]
566. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(original_caller_id_name=NEW_BUSSINESS_SALES#07943550553)
567. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [original_caller_id_name]=[NEW_BUSSINESS_SALES#07943550553]
568. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(original_caller_id_number=54895#07943550553)
569. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [original_caller_id_number]=[54895#07943550553]
570. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(is_recording=1)
571. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [is_recording]=[1]
572. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(media_bug_answer_req=true)
573. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [media_bug_answer_req]=[true]
574. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(RECORD_STEREO=true)
575. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [RECORD_STEREO]=[true]
576. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(record_sample_rate=8000)
577. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [record_sample_rate]=[8000]
578. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(execute_on_answer=record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav)
579. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [execute_on_answer]=[record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav]
580. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_caller_id_name=NEW_BUSSINESS_SALES#07943550553)
581. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_caller_id_name]=[NEW_BUSSINESS_SALES#07943550553]
582. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(effective_caller_id_number=54895#07943550553)
583. span style="color: goldenrod; font-weight: bold;"> 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [effective_caller_id_number]=[54895#07943550553]
584. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(calltype=STANDARD)
585. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [calltype]=[STANDARD]
586. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(termination_rates=ID:55538|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00940|INC:1|INITIALBLOCK:60|TRUNK:4|PROVIDER:3)
587. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [termination_rates]=[ID:55538|CODE:^52.*|DESTINATION:Mexico|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00940|INC:1|INITIALBLOCK:60|TRUNK:4|PROVIDER:3]
588. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(trunk_id=4)
589. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [trunk_id]=[4]
590. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(provider_id=3)
591. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [provider_id]=[3]
592. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(rate_flag=1)
593. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [rate_flag]=[1]
594. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(force_trunk_flag=55536)
595. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [force_trunk_flag]=[55536]
596. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(presence_data=trunk_id=4)
597. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [presence_data]=[trunk_id=4]
598. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 set(intcall=0)
599. 2021-03-16 11:11:14.234392 [DEBUG] mod_dptools.c:1672 SET sofia/default/07943550553@213.166.3.69 [intcall]=[0]
600. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 export(presence_data=x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129)
601. 2021-03-16 11:11:14.234392 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [presence_data]=[x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129]
602. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 bridge([leg_timeout=0,absolute_codec_string=^^:PCMA:PCMU:G729]sofia/gateway/Magrathea_Gateway/5285082368)
603. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1906 (sofia/default/07943550553@213.166.3.69) Callstate Change ACTIVE -> RING_WAIT
604. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [presence_data]=[x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129] to event
605. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [call_type]=[10] to event
606. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [is_recording]=[1] to event
607. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [media_bug_answer_req]=[true] to event
608. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [RECORD_STEREO]=[true] to event
609. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [record_sample_rate]=[8000] to event
610. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [execute_on_answer]=[record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav] to event
611. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [is_recording]=[1] to event
612. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [media_bug_answer_req]=[true] to event
613. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [RECORD_STEREO]=[true] to event
614. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [record_sample_rate]=[8000] to event
615. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [execute_on_answer]=[record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav] to event
616. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [presence_data]=[x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129] to event
617. 2021-03-16 11:11:14.254400 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [presence_data]=[x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129] to event
618. 2021-03-16 11:11:14.254400 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
619. 2021-03-16 11:11:14.254400 [DEBUG] switch_ivr_originate.c:2804 Parsing session specific variables
620. 2021-03-16 11:11:14.254400 [NOTICE] switch_channel.c:1118 New Channel sofia/default/5285082368 [68a595d2-fc15-4b00-8bac-3715aba31ac8]
621. 2021-03-16 11:11:14.254400 [DEBUG] mod_sofia.c:5089 (sofia/default/5285082368) State Change CS_NEW -> CS_INIT
622. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_INIT (Cur 2 Tot 116860)
623. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:628 (sofia/default/5285082368) State INIT
624. 2021-03-16 11:11:14.254400 [DEBUG] mod_sofia.c:93 sofia/default/5285082368 SOFIA INIT
625. 2021-03-16 11:11:14.254400 [DEBUG] sofia_glue.c:1618 sofia/default/5285082368 sending invite version: 1.10.5 -release-17-25569c1631 64bit
626. Local SDP:
627. v=0
628. o=FreeSWITCH 1615876372 1615876373 IN IP4 35.176.176.116
629. s=FreeSWITCH
630. c=IN IP4 35.176.176.116
631. t=0 0
632. m=audio 16702 RTP/AVP 8 0 18 101
633. a=rtpmap:8 PCMA/8000
634. a=rtpmap:0 PCMU/8000
635. a=rtpmap:18 G729/8000
636. a=fmtp:18 annexb=no
637. a=rtpmap:101 telephone-event/8000
638. a=fmtp:101 0-16
639. a=ptime:20
640. a=sendrecv
641.  
642. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:40 sofia/default/5285082368 Standard INIT
643. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:48 (sofia/default/5285082368) State Change CS_INIT -> CS_ROUTING
644. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:628 (sofia/default/5285082368) State INIT going to sleep
645. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_ROUTING (Cur 2 Tot 116860)
646. 2021-03-16 11:11:14.254400 [DEBUG] sofia.c:7326 Channel sofia/default/5285082368 entering state [calling][0]
647. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:644 (sofia/default/5285082368) State ROUTING
648. 2021-03-16 11:11:14.254400 [DEBUG] mod_sofia.c:154 sofia/default/5285082368 SOFIA ROUTING
649. 2021-03-16 11:11:14.254400 [DEBUG] switch_ivr_originate.c:67 (sofia/default/5285082368) State Change CS_ROUTING -> CS_CONSUME_MEDIA
650. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:644 (sofia/default/5285082368) State ROUTING going to sleep
651. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 116860)
652. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:663 (sofia/default/5285082368) State CONSUME_MEDIA
653. 2021-03-16 11:11:14.254400 [DEBUG] switch_core_state_machine.c:663 (sofia/default/5285082368) State CONSUME_MEDIA going to sleep
654. 2021-03-16 11:11:15.734387 [DEBUG] sofia.c:6501 Remote Reason: 28
655. 2021-03-16 11:11:15.734387 [DEBUG] sofia.c:7326 Channel sofia/default/5285082368 entering state [terminated][484]
656. 2021-03-16 11:11:15.734387 [NOTICE] sofia.c:8559 Hangup sofia/default/5285082368 [CS_CONSUME_MEDIA] [INVALID_NUMBER_FORMAT]
657. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_HANGUP (Cur 2 Tot 116860)
658. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:848 (sofia/default/5285082368) Callstate Change DOWN -> HANGUP
659. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:850 (sofia/default/5285082368) State HANGUP
660. 2021-03-16 11:11:15.734387 [DEBUG] mod_sofia.c:453 Channel sofia/default/5285082368 hanging up, cause: INVALID_NUMBER_FORMAT
661. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:60 sofia/default/5285082368 Standard HANGUP, cause: INVALID_NUMBER_FORMAT
662. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:850 (sofia/default/5285082368) State HANGUP going to sleep
663. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:620 (sofia/default/5285082368) State Change CS_HANGUP -> CS_REPORTING
664. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_REPORTING (Cur 2 Tot 116860)
665. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:936 (sofia/default/5285082368) State REPORTING
666. 2021-03-16 11:11:15.734387 [INFO] mod_json_cdr.c:271 Process [68a595d2-fc15-4b00-8bac-3715aba31ac8.cdr.json]
667. 2021-03-16 11:11:15.734387 [DEBUG] switch_ivr_originate.c:3995 Originate Resulted in Error Cause: 28 [INVALID_NUMBER_FORMAT]
668. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:2130 (sofia/default/07943550553@213.166.3.69) Callstate Change RING_WAIT -> ACTIVE
669. 2021-03-16 11:11:15.734387 [INFO] mod_dptools.c:3631 Originate Failed.  Cause: INVALID_NUMBER_FORMAT
670. EXECUTE [depth=0] sofia/default/07943550553@213.166.3.69 bridge([leg_timeout=0,absolute_codec_string=^^:PCMA:PCMU:G729]sofia/gateway/NSN_Gateway/5285082368)
671. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1906 (sofia/default/07943550553@213.166.3.69) Callstate Change ACTIVE -> RING_WAIT
672. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [presence_data]=[x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129] to event
673. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [call_type]=[10] to event
674. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [is_recording]=[1] to event
675. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [media_bug_answer_req]=[true] to event
676. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [RECORD_STEREO]=[true] to event
677. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [record_sample_rate]=[8000] to event
678. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [execute_on_answer]=[record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav] to event
679. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [is_recording]=[1] to event
680. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [media_bug_answer_req]=[true] to event
681. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [RECORD_STEREO]=[true] to event
682. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [record_sample_rate]=[8000] to event
683. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [execute_on_answer]=[record_session /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav] to event
684. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [presence_data]=[x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129] to event
685. 2021-03-16 11:11:15.734387 [DEBUG] switch_channel.c:1264 sofia/default/07943550553@213.166.3.69 EXPORTING[export_vars] [presence_data]=[x|||Magrathea(3673942894)|||^52.* // Mexico // 0.03290 // trunk_id=0|||Trunk_M1 // ^52.* // Mexico // 0.00940 // trunk_id=4|||STD|||87.238.72.129] to event
686. 2021-03-16 11:11:15.734387 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
687. 2021-03-16 11:11:15.734387 [DEBUG] switch_ivr_originate.c:2804 Parsing session specific variables
688. 2021-03-16 11:11:15.734387 [NOTICE] switch_channel.c:1118 New Channel sofia/default/5285082368 [ae7b3b94-7ef3-4aaa-852f-4a19f5701f39]
689. 2021-03-16 11:11:15.734387 [DEBUG] mod_sofia.c:5089 (sofia/default/5285082368) State Change CS_NEW -> CS_INIT
690. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_INIT (Cur 3 Tot 116861)
691. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:628 (sofia/default/5285082368) State INIT
692. 2021-03-16 11:11:15.734387 [DEBUG] mod_sofia.c:93 sofia/default/5285082368 SOFIA INIT
693. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:174 sofia/default/5285082368 Standard REPORTING, cause: INVALID_NUMBER_FORMAT
694. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:936 (sofia/default/5285082368) State REPORTING going to sleep
695. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:611 (sofia/default/5285082368) State Change CS_REPORTING -> CS_DESTROY
696. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_session.c:1726 Session 116860 (sofia/default/5285082368) Locked, Waiting on external entities
697. 2021-03-16 11:11:15.734387 [NOTICE] switch_core_session.c:1744 Session 116860 (sofia/default/5285082368) Ended
698. 2021-03-16 11:11:15.734387 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/5285082368 [CS_DESTROY]
699. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:739 (sofia/default/5285082368) Running State Change CS_DESTROY (Cur 2 Tot 116861)
700. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:749 (sofia/default/5285082368) State DESTROY
701. 2021-03-16 11:11:15.734387 [DEBUG] mod_sofia.c:364 sofia/default/5285082368 SOFIA DESTROY
702. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:181 sofia/default/5285082368 Standard DESTROY
703. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:749 (sofia/default/5285082368) State DESTROY going to sleep
704. 2021-03-16 11:11:15.734387 [DEBUG] sofia_glue.c:1618 sofia/default/5285082368 sending invite version: 1.10.5 -release-17-25569c1631 64bit
705. Local SDP:
706. v=0
707. o=FreeSWITCH 1615875975 1615875976 IN IP4 35.176.176.116
708. s=FreeSWITCH
709. c=IN IP4 35.176.176.116
710. t=0 0
711. m=audio 17100 RTP/AVP 8 0 18 101
712. a=rtpmap:8 PCMA/8000
713. a=rtpmap:0 PCMU/8000
714. a=rtpmap:18 G729/8000
715. a=fmtp:18 annexb=no
716. a=rtpmap:101 telephone-event/8000
717. a=fmtp:101 0-16
718. a=ptime:20
719. a=sendrecv
720.  
721. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:40 sofia/default/5285082368 Standard INIT
722. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:48 (sofia/default/5285082368) State Change CS_INIT -> CS_ROUTING
723. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:628 (sofia/default/5285082368) State INIT going to sleep
724. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_ROUTING (Cur 2 Tot 116861)
725. 2021-03-16 11:11:15.734387 [DEBUG] sofia.c:7326 Channel sofia/default/5285082368 entering state [calling][0]
726. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:644 (sofia/default/5285082368) State ROUTING
727. 2021-03-16 11:11:15.734387 [DEBUG] mod_sofia.c:154 sofia/default/5285082368 SOFIA ROUTING
728. 2021-03-16 11:11:15.734387 [DEBUG] switch_ivr_originate.c:67 (sofia/default/5285082368) State Change CS_ROUTING -> CS_CONSUME_MEDIA
729. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:644 (sofia/default/5285082368) State ROUTING going to sleep
730. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 116861)
731. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:663 (sofia/default/5285082368) State CONSUME_MEDIA
732. 2021-03-16 11:11:15.734387 [DEBUG] switch_core_state_machine.c:663 (sofia/default/5285082368) State CONSUME_MEDIA going to sleep
733. 2021-03-16 11:11:15.774401 [DEBUG] sofia.c:7326 Channel sofia/default/5285082368 entering state [terminated][404]
734. 2021-03-16 11:11:15.774401 [NOTICE] sofia.c:8559 Hangup sofia/default/5285082368 [CS_CONSUME_MEDIA] [UNALLOCATED_NUMBER]
735. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_HANGUP (Cur 2 Tot 116861)
736. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:848 (sofia/default/5285082368) Callstate Change DOWN -> HANGUP
737. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:850 (sofia/default/5285082368) State HANGUP
738. 2021-03-16 11:11:15.774401 [DEBUG] mod_sofia.c:453 Channel sofia/default/5285082368 hanging up, cause: UNALLOCATED_NUMBER
739. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:60 sofia/default/5285082368 Standard HANGUP, cause: UNALLOCATED_NUMBER
740. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:850 (sofia/default/5285082368) State HANGUP going to sleep
741. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:620 (sofia/default/5285082368) State Change CS_HANGUP -> CS_REPORTING
742. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:585 (sofia/default/5285082368) Running State Change CS_REPORTING (Cur 2 Tot 116861)
743. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:936 (sofia/default/5285082368) State REPORTING
744. 2021-03-16 11:11:15.774401 [INFO] mod_json_cdr.c:271 Process [ae7b3b94-7ef3-4aaa-852f-4a19f5701f39.cdr.json]
745. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:174 sofia/default/5285082368 Standard REPORTING, cause: UNALLOCATED_NUMBER
746. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:936 (sofia/default/5285082368) State REPORTING going to sleep
747. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:611 (sofia/default/5285082368) State Change CS_REPORTING -> CS_DESTROY
748. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_session.c:1726 Session 116861 (sofia/default/5285082368) Locked, Waiting on external entities
749. 2021-03-16 11:11:15.774401 [DEBUG] switch_ivr_originate.c:3995 Originate Resulted in Error Cause: 1 [UNALLOCATED_NUMBER]
750. 2021-03-16 11:11:15.774401 [NOTICE] switch_core_session.c:1744 Session 116861 (sofia/default/5285082368) Ended
751. 2021-03-16 11:11:15.774401 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/5285082368 [CS_DESTROY]
752. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:739 (sofia/default/5285082368) Running State Change CS_DESTROY (Cur 1 Tot 116861)
753. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:749 (sofia/default/5285082368) State DESTROY
754. 2021-03-16 11:11:15.774401 [DEBUG] mod_sofia.c:364 sofia/default/5285082368 SOFIA DESTROY
755. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:181 sofia/default/5285082368 Standard DESTROY
756. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:749 (sofia/default/5285082368) State DESTROY going to sleep
757. 2021-03-16 11:11:15.774401 [DEBUG] switch_channel.c:2130 (sofia/default/07943550553@213.166.3.69) Callstate Change RING_WAIT -> ACTIVE
758. 2021-03-16 11:11:15.774401 [INFO] mod_dptools.c:3631 Originate Failed.  Cause: UNALLOCATED_NUMBER
759. 2021-03-16 11:11:15.774401 [NOTICE] switch_core_state_machine.c:386 sofia/default/07943550553@213.166.3.69 has executed the last dialplan instruction, hanging up.
760. 2021-03-16 11:11:15.774401 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/default/07943550553@213.166.3.69 [CS_EXECUTE] [NORMAL_CLEARING]
761. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:651 (sofia/default/07943550553@213.166.3.69) State EXECUTE going to sleep
762. 2021-03-16 11:11:15.774401 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_HANGUP (Cur 1 Tot 116861)
763. 2021-03-16 11:11:15.774401 [DEBUG] switch_ivr_async.c:1445 Stop recording file /var/lib/freeswitch/recordings/f84572be-63d0-4cde-950f-0aa2076f2fc6.wav
764. 2021-03-16 11:11:15.794390 [DEBUG] switch_ivr_async.c:1520 Channel is hung up
765. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_media_bug.c:1295 Removing BUG from sofia/default/07943550553@213.166.3.69
766. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_state_machine.c:848 (sofia/default/07943550553@213.166.3.69) Callstate Change ACTIVE -> HANGUP
767. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_state_machine.c:850 (sofia/default/07943550553@213.166.3.69) State HANGUP
768. 2021-03-16 11:11:15.794390 [DEBUG] mod_sofia.c:447 sofia/default/07943550553@213.166.3.69 Overriding SIP cause 480 with 404 from the other leg
769. 2021-03-16 11:11:15.794390 [DEBUG] mod_sofia.c:453 Channel sofia/default/07943550553@213.166.3.69 hanging up, cause: NORMAL_CLEARING
770. 2021-03-16 11:11:15.794390 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/default/07943550553@213.166.3.69
771. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_state_machine.c:60 sofia/default/07943550553@213.166.3.69 Standard HANGUP, cause: NORMAL_CLEARING
772. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_state_machine.c:850 (sofia/default/07943550553@213.166.3.69) State HANGUP going to sleep
773. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_state_machine.c:620 (sofia/default/07943550553@213.166.3.69) State Change CS_HANGUP -> CS_REPORTING
774. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_state_machine.c:585 (sofia/default/07943550553@213.166.3.69) Running State Change CS_REPORTING (Cur 1 Tot 116861)
775. 2021-03-16 11:11:15.794390 [DEBUG] switch_core_state_machine.c:936 (sofia/default/07943550553@213.166.3.69) State REPORTING
776. 2021-03-16 11:11:15.794390 [INFO] mod_json_cdr.c:271 Process [f84572be-63d0-4cde-950f-0aa2076f2fc6.cdr.json]
777. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_state_machine.c:174 sofia/default/07943550553@213.166.3.69 Standard REPORTING, cause: NORMAL_CLEARING
778. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_state_machine.c:936 (sofia/default/07943550553@213.166.3.69) State REPORTING going to sleep
779. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_state_machine.c:611 (sofia/default/07943550553@213.166.3.69) State Change CS_REPORTING -> CS_DESTROY
780. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_session.c:1726 Session 116859 (sofia/default/07943550553@213.166.3.69) Locked, Waiting on external entities
781. 2021-03-16 11:11:15.834397 [NOTICE] switch_core_session.c:1744 Session 116859 (sofia/default/07943550553@213.166.3.69) Ended
782. 2021-03-16 11:11:15.834397 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/07943550553@213.166.3.69 [CS_DESTROY]
783. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_state_machine.c:739 (sofia/default/07943550553@213.166.3.69) Running State Change CS_DESTROY (Cur 0 Tot 116861)
784. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_state_machine.c:749 (sofia/default/07943550553@213.166.3.69) State DESTROY
785. 2021-03-16 11:11:15.834397 [DEBUG] mod_sofia.c:364 sofia/default/07943550553@213.166.3.69 SOFIA DESTROY
786. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_state_machine.c:181 sofia/default/07943550553@213.166.3.69 Standard DESTROY
787. 2021-03-16 11:11:15.834397 [DEBUG] switch_core_state_machine.c:749 (sofia/default/07943550553@213.166.3.69) State DESTROY going to sleep
788.