From sahil, 3 Years ago, written in FreeSWITCH.
- view diff
Embed
  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.