2023-02-07 13:27:02.173785 98.10% [NOTICE] switch_channel.c:1123 New Channel sofia/default/436766007464@46.19.210.14 [27d40098-c915-4cc9-812b-97a120a401e9]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/436766007464@46.19.210.14) Running State Change CS_NEW (Cur 5 Tot 1858)
2023-02-07 13:27:02.173785 98.10% [INFO] sofia.c:10462 sofia/default/436766007464@46.19.210.14 receiving invite from 195.201.136.94:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 11-11-413020C1-63E251A6000276C9-0E22D700
2023-02-07 13:27:02.173785 98.10% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 195.201.136.94:0.
2023-02-07 13:27:02.173785 98.10% [DEBUG] sofia.c:10585 IP 195.201.136.94 Approved by acl "default[]". Access Granted.
2023-02-07 13:27:02.173785 98.10% [DEBUG] sofia.c:7499 Channel sofia/default/436766007464@46.19.210.14 entering state [received][100]
2023-02-07 13:27:02.173785 98.10% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=didww-sbc 2862399366 2862399367 IN IP4 46.19.210.39
s=didww-sbc
t=0 0
m=audio 47488 RTP/AVP 0 8 18 4 101
c=IN IP4 46.19.210.39
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=rtpmap:101 telephone-event/8000
a=ptime:20

2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/436766007464@46.19.210.14 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_codec.c:111 sofia/default/436766007464@46.19.210.14 Original read codec set to PCMU:0
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_media.c:5973 sofia/default/436766007464@46.19.210.14 Set 2833 dtmf send payload to 101 recv payload to 101
2023-02-07 13:27:02.173785 98.10% [DEBUG] sofia.c:7933 (sofia/default/436766007464@46.19.210.14) State Change CS_NEW -> CS_INIT
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:600 (sofia/default/436766007464@46.19.210.14) State NEW
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/436766007464@46.19.210.14) Running State Change CS_INIT (Cur 5 Tot 1858)
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/436766007464@46.19.210.14) State INIT
2023-02-07 13:27:02.173785 98.10% [DEBUG] mod_sofia.c:97 sofia/default/436766007464@46.19.210.14 SOFIA INIT
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:40 sofia/default/436766007464@46.19.210.14 Standard INIT
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:48 (sofia/default/436766007464@46.19.210.14) State Change CS_INIT -> CS_ROUTING
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/436766007464@46.19.210.14) State INIT going to sleep
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/436766007464@46.19.210.14) Running State Change CS_ROUTING (Cur 5 Tot 1858)
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_channel.c:2380 (sofia/default/436766007464@46.19.210.14) Callstate Change DOWN -> RINGING
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/436766007464@46.19.210.14) State ROUTING
2023-02-07 13:27:02.173785 98.10% [DEBUG] mod_sofia.c:158 sofia/default/436766007464@46.19.210.14 SOFIA ROUTING
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_core_state_machine.c:230 sofia/default/436766007464@46.19.210.14 Standard ROUTING
2023-02-07 13:27:02.173785 98.10% [INFO] mod_dialplan_xml.c:639 Processing 436766007464 <436766007464>->43720145500 in context default
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2023-02-07 13:27:02.173785 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-02-07 13:27:02.193781 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] blind_flag: 0
2023-02-07 13:27:02.193781 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '43720145500' limit 1
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '43720145500' AND status=0 limit 1
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE domain = '46.19.210.14' limit 1
2023-02-07 13:27:02.193781 98.10% [WARNING] switch_cpp.cpp:1465 [ASTPP] [FAXER] in custom Caller ID 
2023-02-07 13:27:02.193781 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Caller Id name / number  : 436766007464 / 436766007464
2023-02-07 13:27:02.193781 98.10% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="43720145500" LIMIT 1
2023-02-07 13:27:02.193781 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Call direction : inbound
2023-02-07 13:27:02.193781 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 714761424818]
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "714761424818" AND deleted = 0 limit 1
2023-02-07 13:27:02.193781 98.10% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="43720145500" LIMIT 1
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "862027868347" AND deleted = 0 limit 1
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [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 ="43720145500" AND A.accountid = '889' limit 1
2023-02-07 13:27:02.193781 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 43720145500
2023-02-07 13:27:02.193781 98.10% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.193781 98.10% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="43720145500" LIMIT 1
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] New Call direction : inbound
2023-02-07 13:27:02.213777 98.10% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="43720145500" AND (accountid = 0 OR status = 1) LIMIT 1
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :889
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [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 = '^43720145500.*' OR patterns = '^4372014550.*' OR patterns = '^437201455.*' OR patterns = '^43720145.*' OR patterns = '^4372014.*' OR patterns = '^437201.*' OR patterns = '^43720.*' OR patterns = '^4372.*' OR patterns = '^437.*' OR patterns = '^43.*' OR patterns = '^4.*' OR patterns ='--') AND accountid = 889 ORDER BY LENGTH(PKGPTR.patterns) DESC
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '43720145500' OR number = '4372014550' OR number = '437201455' OR number = '43720145' OR number = '4372014' OR number = '437201' OR number = '43720' OR number = '4372' OR number = '437' OR number = '43' OR number = '4' OR number ='--') OR (number = '43720145500*' OR number = '4372014550*' OR number = '437201455*' OR number = '43720145*' OR number = '4372014*' OR number = '437201*' OR number = '43720*' OR number = '4372*' OR number = '437*' OR number = '43*' OR number = '4*' OR number ='--') OR (number = '436766007464' OR number = '43676600746' OR number = '4367660074' OR number = '436766007' OR number = '43676600' OR number = '4367660' OR number = '436766' OR number = '43676' OR number = '4367' OR number = '436' OR number = '43' OR number = '4' OR number ='--') OR (number = '436766007464*' OR number = '43676600746*' OR number = '4367660074*' OR number = '436766007*' OR number = '43676600*' OR number = '4367660*' OR number = '436766*' OR number = '43676*' OR number = '4367*' OR number = '436*' OR number = '43*' OR number = '4*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Call Barring Status : -1
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '43720145500' OR routing_prefix = '4372014550' OR routing_prefix = '437201455' OR routing_prefix = '43720145' OR routing_prefix = '4372014' OR routing_prefix = '437201' OR routing_prefix = '43720' OR routing_prefix = '4372' OR routing_prefix = '437' OR routing_prefix = '43' OR routing_prefix = '4' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 889
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 862027868347
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 3992.04532
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 51
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] CID Pool : 0
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 51 AND status = 0
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :inbound
2023-02-07 13:27:02.213777 98.10% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....43720145500
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="43720145500" LIMIT 1
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction:::::: inbound
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 1973
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 0.00000
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : National Landline
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 13
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 889
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your3992.04532 balance Accountid 889 !!!
2023-02-07 13:27:02.213777 98.10% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 180
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Call Max length duration : 180 minutes
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] INB_FREE:TRUE
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] free_inbound:1
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 889 AND status= '0' LIMIT 1
2023-02-07 13:27:02.213777 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE id = "889" AND deleted = 0 limit 1
2023-02-07 13:27:02.213777 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] Actual CustomerInfo XML:889
2023-02-07 13:27:02.233778 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] Userinfo XML:889
2023-02-07 13:27:02.233778 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] Actual CustomerInfo XML : 889
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE accountid = 889 limit 1
2023-02-07 13:27:02.233778 98.10% [WARNING] switch_cpp.cpp:1465 [ASTPP] [user_domain] user_domainReshetcall812.newsip.israelnumber.com
2023-02-07 13:27:02.233778 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] maxlength::::::::: 180
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"000/00".....436766007464
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"000/00".....436766007464
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE accountid = 889 limit 1
2023-02-07 13:27:02.233778 98.10% [WARNING] switch_cpp.cpp:1465 [ASTPP] [user_domain] user_domainReshetcall812.newsip.israelnumber.com
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_2
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Generated XML:<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="43720145500">
<condition field="destination_number" expression="43720145500">
<action application="set" data="effective_destination_number=43720145500"/>
<action application="set" data="execute_on_answer=sched_hangup +10800 normal_clearing"/>
<action application="set" data="callstart=2023-02-07 13:27:02"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="set" data="continue_on_fail=TRUE"/>
<action application="set" data="account_id=889"/>
<action application="set" data="parent_id=0"/>
<action application="set" data="entity_id=0"/>
<action application="set" data="call_processed=internal"/>
<action application="set" data="call_direction=inbound"/>
<action application="set" data="accountname=default"/>
<action application="set" data="filename1=astpp.pbx.lua"/>
<action application="set" data="origination_rates_did=ID:1973|CODE:^43720145500.*|DESTINATION:National Landline|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:2|COST:0.00000|INC:60|INITIALBLOCK:60|RATEGROUP:0|MARKUP:0|CI:13|ACCID:889"/>
<action application="set" data="origination_rates=0"/>
<action application="set" data="original_caller_id_name=436766007464"/>
<action application="set" data="original_caller_id_number=436766007464"/>
<action application="set" data="effective_caller_id_name=436766007464"/>
<action application="set" data="effective_caller_id_number=436766007464"/>
<action application="set" data="receiver_accid=889"/>
<action application="export" data="domain_name=Reshetcall812.newsip.israelnumber.com"/>
<action application="export" data="sip_to_host=Reshetcall812.newsip.israelnumber.com"/>
<action application="export" data="presence_data=x|||Reshetcall(862027868347)|||^43720145500.* // National Landline // 0.00000||||||DID|||46.19.210.14"/>
<action application="export" data="call_type=2"/>
<action application="set" data="calltype=DIRECT-IP"/>
<action application="bridge" data="[leg_timeout=30]sofia/${sofia_profile_name}/43720145500@88.99.5.200;fs_path=sip:195.201.136.94:5060"/>
</condition>
</extension>
</context>
</section>
</document>
Dialplan: sofia/default/436766007464@46.19.210.14 parsing [default->43720145500] continue=false
Dialplan: sofia/default/436766007464@46.19.210.14 Regex (PASS) [43720145500] destination_number(43720145500) =~ /43720145500/ break=on-false
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(effective_destination_number=43720145500) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(execute_on_answer=sched_hangup +10800 normal_clearing) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(callstart=2023-02-07 13:27:02) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(hangup_after_bridge=true) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(continue_on_fail=TRUE) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(account_id=889) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(parent_id=0) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(entity_id=0) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(call_processed=internal) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(call_direction=inbound) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(accountname=default) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(filename1=astpp.pbx.lua) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(origination_rates_did=ID:1973|CODE:^43720145500.*|DESTINATION:National Landline|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:2|COST:0.00000|INC:60|INITIALBLOCK:60|RATEGROUP:0|MARKUP:0|CI:13|ACCID:889) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(origination_rates=0) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(original_caller_id_name=436766007464) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(original_caller_id_number=436766007464) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(effective_caller_id_name=436766007464) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(effective_caller_id_number=436766007464) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(receiver_accid=889) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action export(domain_name=Reshetcall812.newsip.israelnumber.com) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action export(sip_to_host=Reshetcall812.newsip.israelnumber.com) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action export(presence_data=x|||Reshetcall(862027868347)|||^43720145500.* // National Landline // 0.00000||||||DID|||46.19.210.14) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action export(call_type=2) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action set(calltype=DIRECT-IP) 
Dialplan: sofia/default/436766007464@46.19.210.14 Action bridge([leg_timeout=30]sofia/${sofia_profile_name}/43720145500@88.99.5.200;fs_path=sip:195.201.136.94:5060) 
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:281 (sofia/default/436766007464@46.19.210.14) State Change CS_ROUTING -> CS_EXECUTE
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/436766007464@46.19.210.14) State ROUTING going to sleep
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/436766007464@46.19.210.14) Running State Change CS_EXECUTE (Cur 5 Tot 1858)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:647 (sofia/default/436766007464@46.19.210.14) State EXECUTE
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_sofia.c:213 sofia/default/436766007464@46.19.210.14 SOFIA EXECUTE
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:323 sofia/default/436766007464@46.19.210.14 Standard EXECUTE
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(effective_destination_number=43720145500)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [effective_destination_number]=[43720145500]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(execute_on_answer=sched_hangup +10800 normal_clearing)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [execute_on_answer]=[sched_hangup +10800 normal_clearing]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(callstart=2023-02-07 13:27:02)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [callstart]=[2023-02-07 13:27:02]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(hangup_after_bridge=true)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(continue_on_fail=TRUE)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [continue_on_fail]=[TRUE]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(account_id=889)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [account_id]=[889]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(parent_id=0)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [parent_id]=[0]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(entity_id=0)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [entity_id]=[0]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(call_processed=internal)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [call_processed]=[internal]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(call_direction=inbound)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [call_direction]=[inbound]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(accountname=default)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [accountname]=[default]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(filename1=astpp.pbx.lua)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [filename1]=[astpp.pbx.lua]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(origination_rates_did=ID:1973|CODE:^43720145500.*|DESTINATION:National Landline|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:2|COST:0.00000|INC:60|INITIALBLOCK:60|RATEGROUP:0|MARKUP:0|CI:13|ACCID:889)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [origination_rates_did]=[ID:1973|CODE:^43720145500.*|DESTINATION:National Landline|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:2|COST:0.00000|INC:60|INITIALBLOCK:60|RATEGROUP:0|MARKUP:0|CI:13|ACCID:889]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(origination_rates=0)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [origination_rates]=[0]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(original_caller_id_name=436766007464)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [original_caller_id_name]=[436766007464]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(original_caller_id_number=436766007464)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [original_caller_id_number]=[436766007464]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(effective_caller_id_name=436766007464)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [effective_caller_id_name]=[436766007464]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(effective_caller_id_number=436766007464)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [effective_caller_id_number]=[436766007464]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(receiver_accid=889)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [receiver_accid]=[889]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 export(domain_name=Reshetcall812.newsip.israelnumber.com)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [domain_name]=[Reshetcall812.newsip.israelnumber.com]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 export(sip_to_host=Reshetcall812.newsip.israelnumber.com)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [sip_to_host]=[Reshetcall812.newsip.israelnumber.com]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 export(presence_data=x|||Reshetcall(862027868347)|||^43720145500.* // National Landline // 0.00000||||||DID|||46.19.210.14)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Reshetcall(862027868347)|||^43720145500.* // National Landline // 0.00000||||||DID|||46.19.210.14]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 export(call_type=2)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_type]=[2]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 set(calltype=DIRECT-IP)
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/436766007464@46.19.210.14 [calltype]=[DIRECT-IP]
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 bridge([leg_timeout=30]sofia/default/43720145500@88.99.5.200;fs_path=sip:195.201.136.94:5060)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1269 sofia/default/436766007464@46.19.210.14 EXPORTING[export_vars] [domain_name]=[Reshetcall812.newsip.israelnumber.com] to event
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1269 sofia/default/436766007464@46.19.210.14 EXPORTING[export_vars] [sip_to_host]=[Reshetcall812.newsip.israelnumber.com] to event
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1269 sofia/default/436766007464@46.19.210.14 EXPORTING[export_vars] [presence_data]=[x|||Reshetcall(862027868347)|||^43720145500.* // National Landline // 0.00000||||||DID|||46.19.210.14] to event
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_channel.c:1269 sofia/default/436766007464@46.19.210.14 EXPORTING[export_vars] [call_type]=[2] to event
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
2023-02-07 13:27:02.233778 98.10% [NOTICE] switch_channel.c:1123 New Channel sofia/default/43720145500@88.99.5.200 [85c52195-91fb-4883-863c-4ee9b032a311]
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_sofia.c:5121 (sofia/default/43720145500@88.99.5.200) State Change CS_NEW -> CS_INIT
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_ivr_originate.c:3151 sofia/default/43720145500@88.99.5.200 Setting leg timeout to 30
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/43720145500@88.99.5.200) Running State Change CS_INIT (Cur 6 Tot 1859)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/43720145500@88.99.5.200) State INIT
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_sofia.c:97 sofia/default/43720145500@88.99.5.200 SOFIA INIT
2023-02-07 13:27:02.233778 98.10% [DEBUG] sofia_glue.c:1620 sip:195.201.136.94:5060 Setting proxy route to sofia/default/43720145500@88.99.5.200
2023-02-07 13:27:02.233778 98.10% [INFO] sofia_glue.c:1651 sofia/default/43720145500@88.99.5.200 sending invite call-id: (null)
2023-02-07 13:27:02.233778 98.10% [DEBUG] sofia_glue.c:1654 sofia/default/43720145500@88.99.5.200 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1675747466 1675747467 IN IP4 195.201.136.88
s=FreeSWITCH
c=IN IP4 195.201.136.88
t=0 0
m=audio 28956 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:40 sofia/default/43720145500@88.99.5.200 Standard INIT
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:48 (sofia/default/43720145500@88.99.5.200) State Change CS_INIT -> CS_ROUTING
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/43720145500@88.99.5.200) State INIT going to sleep
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/43720145500@88.99.5.200) Running State Change CS_ROUTING (Cur 6 Tot 1859)
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/43720145500@88.99.5.200) State ROUTING
2023-02-07 13:27:02.233778 98.10% [DEBUG] mod_sofia.c:158 sofia/default/43720145500@88.99.5.200 SOFIA ROUTING
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_ivr_originate.c:67 (sofia/default/43720145500@88.99.5.200) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/43720145500@88.99.5.200) State ROUTING going to sleep
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/43720145500@88.99.5.200) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 1859)
2023-02-07 13:27:02.233778 98.10% [DEBUG] sofia.c:7499 Channel sofia/default/43720145500@88.99.5.200 entering state [calling][0]
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:659 (sofia/default/43720145500@88.99.5.200) State CONSUME_MEDIA
2023-02-07 13:27:02.233778 98.10% [DEBUG] switch_core_state_machine.c:659 (sofia/default/43720145500@88.99.5.200) State CONSUME_MEDIA going to sleep
2023-02-07 13:27:02.833788 98.00% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [101@195.201.136.88] from ip 128.90.116.22
2023-02-07 13:27:02.893795 98.00% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [201@195.201.136.88] from ip 128.90.104.131
2023-02-07 13:27:02.913794 98.00% [WARNING] sofia_reg.c:3223 Can't find user [201@195.201.136.88] from 128.90.104.131
You must define a domain called '195.201.136.88' in your directory and add a user with the id="201" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2023-02-07 13:27:02.913794 98.00% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [201@195.201.136.88] from ip 128.90.104.131
2023-02-07 13:27:03.013777 98.00% [WARNING] sofia_reg.c:3223 Can't find user [101@195.201.136.88] from 128.90.116.22
You must define a domain called '195.201.136.88' in your directory and add a user with the id="101" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2023-02-07 13:27:03.013777 98.00% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [101@195.201.136.88] from ip 128.90.116.22
2023-02-07 13:27:03.373785 98.00% [DEBUG] sofia.c:7499 Channel sofia/default/43720145500@88.99.5.200 entering state [completing][200]
2023-02-07 13:27:03.373785 98.00% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=FreeSWITCH 1675758043 1675758044 IN IP4 88.99.5.200
s=FreeSWITCH
c=IN IP4 88.99.5.200
t=0 0
m=audio 18380 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2023-02-07 13:27:03.373785 98.00% [DEBUG] sofia.c:7499 Channel sofia/default/43720145500@88.99.5.200 entering state [ready][200]
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/43720145500@88.99.5.200 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_codec.c:111 sofia/default/43720145500@88.99.5.200 Original read codec set to PCMU:0
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:5973 sofia/default/43720145500@88.99.5.200 Set 2833 dtmf send payload to 101 recv payload to 101
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/43720145500@88.99.5.200] 195.201.136.88 port 28956 -> 88.99.5.200 port 18380 codec: 0 ms: 20
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:9089 sofia/default/43720145500@88.99.5.200 Set 2833 dtmf send payload to 101
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:9096 sofia/default/43720145500@88.99.5.200 Set 2833 dtmf receive payload to 101
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_core_media.c:9119 sofia/default/43720145500@88.99.5.200 Set rtp dtmf delay to 40
2023-02-07 13:27:03.373785 98.00% [NOTICE] sofia.c:8683 Channel [sofia/default/43720145500@88.99.5.200] has been answered
2023-02-07 13:27:03.373785 98.00% [DEBUG] switch_channel.c:3950 (sofia/default/43720145500@88.99.5.200) Callstate Change DOWN -> ACTIVE
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/436766007464@46.19.210.14] 195.201.136.88 port 31978 -> 46.19.210.39 port 47488 codec: 0 ms: 20
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_core_media.c:9089 sofia/default/436766007464@46.19.210.14 Set 2833 dtmf send payload to 101
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_core_media.c:9096 sofia/default/436766007464@46.19.210.14 Set 2833 dtmf receive payload to 101
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_core_media.c:9119 sofia/default/436766007464@46.19.210.14 Set rtp dtmf delay to 40
2023-02-07 13:27:03.393781 98.00% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/436766007464@46.19.210.14:
v=0
o=FreeSWITCH 1675744445 1675744446 IN IP4 195.201.136.88
s=FreeSWITCH
c=IN IP4 195.201.136.88
t=0 0
m=audio 31978 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2023-02-07 13:27:03.393781 98.00% [NOTICE] switch_ivr_originate.c:3834 Channel [sofia/default/436766007464@46.19.210.14] has been answered
EXECUTE [depth=0] sofia/default/436766007464@46.19.210.14 sched_hangup(+10800 normal_clearing)
2023-02-07 13:27:03.393781 98.00% [DEBUG] sofia.c:7499 Channel sofia/default/436766007464@46.19.210.14 entering state [completed][200]
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_scheduler.c:263 Added task 53 switch_ivr_schedule_hangup (27d40098-c915-4cc9-812b-97a120a401e9) to run at 1675787223
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_channel.c:3950 (sofia/default/436766007464@46.19.210.14) Callstate Change RINGING -> ACTIVE
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/default/43720145500@88.99.5.200] Peer UUID: 85c52195-91fb-4883-863c-4ee9b032a311
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_ivr_bridge.c:1793 (sofia/default/43720145500@88.99.5.200) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_core_state_machine.c:581 (sofia/default/43720145500@88.99.5.200) Running State Change CS_EXCHANGE_MEDIA (Cur 6 Tot 1859)
2023-02-07 13:27:03.393781 98.00% [DEBUG] switch_core_state_machine.c:650 (sofia/default/43720145500@88.99.5.200) State EXCHANGE_MEDIA
2023-02-07 13:27:03.393781 98.00% [DEBUG] mod_sofia.c:671 SOFIA EXCHANGE_MEDIA
2023-02-07 13:27:03.433778 98.00% [DEBUG] sofia.c:7499 Channel sofia/default/436766007464@46.19.210.14 entering state [ready][200]
2023-02-07 13:27:03.433778 98.00% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
2023-02-07 13:27:03.513784 98.00% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
2023-02-07 13:27:19.873790 97.90% [NOTICE] sofia.c:1065 Hangup sofia/default/436766007464@46.19.210.14 [CS_EXECUTE] [NORMAL_CLEARING]
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/436766007464@46.19.210.14]
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_ivr_bridge.c:820 sofia/default/436766007464@46.19.210.14 ending bridge by request from write function
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/43720145500@88.99.5.200]
2023-02-07 13:27:19.873790 97.90% [NOTICE] switch_ivr_bridge.c:1029 Hangup sofia/default/43720145500@88.99.5.200 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:650 (sofia/default/43720145500@88.99.5.200) State EXCHANGE_MEDIA going to sleep
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/43720145500@88.99.5.200) Running State Change CS_HANGUP (Cur 6 Tot 1859)
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:844 (sofia/default/43720145500@88.99.5.200) Callstate Change ACTIVE -> HANGUP
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/43720145500@88.99.5.200) State HANGUP
2023-02-07 13:27:19.873790 97.90% [DEBUG] mod_sofia.c:462 sofia/default/43720145500@88.99.5.200 Overriding SIP cause 480 with 200 from the other leg
2023-02-07 13:27:19.873790 97.90% [DEBUG] mod_sofia.c:468 Channel sofia/default/43720145500@88.99.5.200 hanging up, cause: NORMAL_CLEARING
2023-02-07 13:27:19.873790 97.90% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/43720145500@88.99.5.200
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:59 sofia/default/43720145500@88.99.5.200 Standard HANGUP, cause: NORMAL_CLEARING
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/43720145500@88.99.5.200) State HANGUP going to sleep
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_ivr_bridge.c:1892 sofia/default/43720145500@88.99.5.200 skip receive message [UNBRIDGE] (channel is hungup already)
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_ivr_bridge.c:1895 sofia/default/436766007464@46.19.210.14 skip receive message [UNBRIDGE] (channel is hungup already)
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:616 (sofia/default/43720145500@88.99.5.200) State Change CS_HANGUP -> CS_REPORTING
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/43720145500@88.99.5.200) Running State Change CS_REPORTING (Cur 6 Tot 1859)
2023-02-07 13:27:19.873790 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/43720145500@88.99.5.200) State REPORTING
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_session.c:2983 sofia/default/436766007464@46.19.210.14 skip receive message [PHONE_EVENT] (channel is hungup already)
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:647 (sofia/default/436766007464@46.19.210.14) State EXECUTE going to sleep
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/436766007464@46.19.210.14) Running State Change CS_HANGUP (Cur 6 Tot 1859)
2023-02-07 13:27:19.893789 97.90% [INFO] mod_json_cdr.c:271 Process [85c52195-91fb-4883-863c-4ee9b032a311.cdr.json]
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:844 (sofia/default/436766007464@46.19.210.14) Callstate Change ACTIVE -> HANGUP
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/436766007464@46.19.210.14) State HANGUP
2023-02-07 13:27:19.893789 97.90% [DEBUG] mod_sofia.c:468 Channel sofia/default/436766007464@46.19.210.14 hanging up, cause: NORMAL_CLEARING
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:59 sofia/default/436766007464@46.19.210.14 Standard HANGUP, cause: NORMAL_CLEARING
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/436766007464@46.19.210.14) State HANGUP going to sleep
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:616 (sofia/default/436766007464@46.19.210.14) State Change CS_HANGUP -> CS_REPORTING
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/436766007464@46.19.210.14) Running State Change CS_REPORTING (Cur 6 Tot 1859)
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/436766007464@46.19.210.14) State REPORTING
2023-02-07 13:27:19.893789 97.90% [INFO] mod_json_cdr.c:271 Process [27d40098-c915-4cc9-812b-97a120a401e9.cdr.json]
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:168 sofia/default/43720145500@88.99.5.200 Standard REPORTING, cause: NORMAL_CLEARING
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/43720145500@88.99.5.200) State REPORTING going to sleep
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:607 (sofia/default/43720145500@88.99.5.200) State Change CS_REPORTING -> CS_DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_session.c:1753 Session 1859 (sofia/default/43720145500@88.99.5.200) Locked, Waiting on external entities
2023-02-07 13:27:19.893789 97.90% [NOTICE] switch_core_session.c:1771 Session 1859 (sofia/default/43720145500@88.99.5.200) Ended
2023-02-07 13:27:19.893789 97.90% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/43720145500@88.99.5.200 [CS_DESTROY]
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:735 (sofia/default/43720145500@88.99.5.200) Running State Change CS_DESTROY (Cur 5 Tot 1859)
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/43720145500@88.99.5.200) State DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] mod_sofia.c:379 sofia/default/43720145500@88.99.5.200 SOFIA DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:175 sofia/default/43720145500@88.99.5.200 Standard DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/43720145500@88.99.5.200) State DESTROY going to sleep
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:168 sofia/default/436766007464@46.19.210.14 Standard REPORTING, cause: NORMAL_CLEARING
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/436766007464@46.19.210.14) State REPORTING going to sleep
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:607 (sofia/default/436766007464@46.19.210.14) State Change CS_REPORTING -> CS_DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_session.c:1753 Session 1858 (sofia/default/436766007464@46.19.210.14) Locked, Waiting on external entities
2023-02-07 13:27:19.893789 97.90% [NOTICE] switch_core_session.c:1771 Session 1858 (sofia/default/436766007464@46.19.210.14) Ended
2023-02-07 13:27:19.893789 97.90% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/436766007464@46.19.210.14 [CS_DESTROY]
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:735 (sofia/default/436766007464@46.19.210.14) Running State Change CS_DESTROY (Cur 4 Tot 1859)
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/436766007464@46.19.210.14) State DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] mod_sofia.c:379 sofia/default/436766007464@46.19.210.14 SOFIA DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:175 sofia/default/436766007464@46.19.210.14 Standard DESTROY
2023-02-07 13:27:19.893789 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/436766007464@46.19.210.14) State DESTROY going to sleep
2023-02-07 13:27:19.913778 97.90% [DEBUG] switch_scheduler.c:147 Deleting task 53 switch_ivr_schedule_hangup (27d40098-c915-4cc9-812b-97a120a401e9)
2023-02-07 13:27:21.873806 97.83% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0546322423@212.150.158.100 [02641f90-b524-448f-8f56-9cbd99102e61]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_NEW (Cur 5 Tot 1860)
2023-02-07 13:27:21.873806 97.83% [INFO] sofia.c:10462 sofia/default/0546322423@212.150.158.100 receiving invite from 195.201.136.94:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 600cfe8911b3e2f63124df395d8dacdf@212.150.158.100
2023-02-07 13:27:21.873806 97.83% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 195.201.136.94:0.
2023-02-07 13:27:21.873806 97.83% [DEBUG] sofia.c:10585 IP 195.201.136.94 Approved by acl "default[]". Access Granted.
2023-02-07 13:27:21.873806 97.83% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [received][100]
2023-02-07 13:27:21.873806 97.83% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 7779 7779 IN IP4 212.150.158.100
s=session
c=IN IP4 212.150.158.100
b=CT:384
t=0 0
m=audio 13310 RTP/AVP 8 0 3 112 5 10 7 18 111 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:112 AAL2-G726-32/8000
a=rtpmap:5 DVI4/8000
a=rtpmap:10 L16/8000
a=rtpmap:7 LPC/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:111 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
m=video 17968 RTP/AVP 26 31 34 103 99
a=rtpmap:26 JPEG/90000
a=rtpmap:31 H261/90000
a=rtpmap:34 H263/90000
a=rtpmap:103 h263-1998/90000
a=rtpmap:99 H264/90000

2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [AAL2-G726-32:112:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [AAL2-G726-32:112:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [DVI4:5:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [DVI4:5:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [L16:10:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [L16:10:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [LPC:7:8000:20:2400:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [LPC:7:8000:20:2400:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:111:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:111:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/0546322423@212.150.158.100 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_codec.c:111 sofia/default/0546322423@212.150.158.100 Original read codec set to PCMA:8
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:5973 sofia/default/0546322423@212.150.158.100 Set 2833 dtmf send payload to 101 recv payload to 101
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:6301 No matches with FTMP, fallback to ignoring FMTP
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_media.c:6309 No matches with inherit_codec, fallback to ignoring PT
2023-02-07 13:27:21.873806 97.83% [DEBUG] sofia.c:7933 (sofia/default/0546322423@212.150.158.100) State Change CS_NEW -> CS_INIT
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:600 (sofia/default/0546322423@212.150.158.100) State NEW
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_INIT (Cur 5 Tot 1860)
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0546322423@212.150.158.100) State INIT
2023-02-07 13:27:21.873806 97.83% [DEBUG] mod_sofia.c:97 sofia/default/0546322423@212.150.158.100 SOFIA INIT
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:40 sofia/default/0546322423@212.150.158.100 Standard INIT
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0546322423@212.150.158.100) State Change CS_INIT -> CS_ROUTING
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0546322423@212.150.158.100) State INIT going to sleep
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_ROUTING (Cur 5 Tot 1860)
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_channel.c:2380 (sofia/default/0546322423@212.150.158.100) Callstate Change DOWN -> RINGING
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0546322423@212.150.158.100) State ROUTING
2023-02-07 13:27:21.873806 97.83% [DEBUG] mod_sofia.c:158 sofia/default/0546322423@212.150.158.100 SOFIA ROUTING
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_core_state_machine.c:230 sofia/default/0546322423@212.150.158.100 Standard ROUTING
2023-02-07 13:27:21.873806 97.83% [INFO] mod_dialplan_xml.c:639 Processing 0546322423 <0546322423>->0737004346 in context default
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2023-02-07 13:27:21.873806 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-02-07 13:27:21.893778 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] blind_flag: 0
2023-02-07 13:27:21.893778 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 0737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '0737004346' limit 1
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '0737004346' AND status=0 limit 1
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE domain = '212.150.158.100' limit 1
2023-02-07 13:27:21.893778 97.83% [WARNING] switch_cpp.cpp:1465 [ASTPP] [FAXER] in custom Caller ID 
2023-02-07 13:27:21.893778 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Caller Id name / number  : 0546322423 / 0546322423
2023-02-07 13:27:21.893778 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.893778 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] Before Localization CLI/DST : 0737004346
2023-02-07 13:27:21.893778 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] After Localization CLI/DST : 972737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="972737004346" LIMIT 1
2023-02-07 13:27:21.893778 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Call direction : inbound
2023-02-07 13:27:21.893778 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 170019686118]
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "170019686118" AND deleted = 0 limit 1
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [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 ="0737004346" AND A.accountid = '709' limit 1
2023-02-07 13:27:21.893778 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 0737004346
2023-02-07 13:27:21.893778 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:21.893778 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.913789 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] Before Localization CLI/DST : 0737004346
2023-02-07 13:27:21.913789 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] After Localization CLI/DST : 972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="972737004346" LIMIT 1
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] New Call direction : inbound
2023-02-07 13:27:21.913789 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....0737004346
2023-02-07 13:27:21.913789 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] Before Localization CLI/DST : 0737004346
2023-02-07 13:27:21.913789 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] After Localization CLI/DST : 972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="972737004346" AND (accountid = 0 OR status = 1) LIMIT 1
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :5203
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [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 = '^0737004346.*' OR patterns = '^073700434.*' OR patterns = '^07370043.*' OR patterns = '^0737004.*' OR patterns = '^073700.*' OR patterns = '^07370.*' OR patterns = '^0737.*' OR patterns = '^073.*' OR patterns = '^07.*' OR patterns = '^0.*' OR patterns ='--') AND accountid = 5203 ORDER BY LENGTH(PKGPTR.patterns) DESC
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '0737004346' OR number = '073700434' OR number = '07370043' OR number = '0737004' OR number = '073700' OR number = '07370' OR number = '0737' OR number = '073' OR number = '07' OR number = '0' OR number ='--') OR (number = '0737004346*' OR number = '073700434*' OR number = '07370043*' OR number = '0737004*' OR number = '073700*' OR number = '07370*' OR number = '0737*' OR number = '073*' OR number = '07*' OR number = '0*' OR number ='--') OR (number = '0546322423' OR number = '054632242' OR number = '05463224' OR number = '0546322' OR number = '054632' OR number = '05463' OR number = '0546' OR number = '054' OR number = '05' OR number = '0' OR number ='--') OR (number = '0546322423*' OR number = '054632242*' OR number = '05463224*' OR number = '0546322*' OR number = '054632*' OR number = '05463*' OR number = '0546*' OR number = '054*' OR number = '05*' OR number = '0*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Call Barring Status : -1
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '0737004346' OR routing_prefix = '073700434' OR routing_prefix = '07370043' OR routing_prefix = '0737004' OR routing_prefix = '073700' OR routing_prefix = '07370' OR routing_prefix = '0737' OR routing_prefix = '073' OR routing_prefix = '07' OR routing_prefix = '0' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 709
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 170019686118
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 8.92
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 23
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] CID Pool : 0
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 23 AND status = 0
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :inbound
2023-02-07 13:27:21.913789 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....972737004346
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="972737004346" LIMIT 1
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction:::::: inbound
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 17861
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 0.00000
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : 972737004346
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 93
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 709
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your8.92 balance Accountid 709 !!!
2023-02-07 13:27:21.913789 97.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 180
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] Call Max length duration : 180 minutes
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] INB_FREE:TRUE
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] free_inbound:1
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 709 AND status= '0' LIMIT 1
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE id = "5203" AND deleted = 0 limit 1
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] Actual CustomerInfo XML:709
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] Userinfo XML:709
2023-02-07 13:27:21.913789 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [userinfo] Actual CustomerInfo XML : 709
2023-02-07 13:27:21.913789 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE accountid = 5203 limit 1
2023-02-07 13:27:21.933790 97.83% [WARNING] switch_cpp.cpp:1465 [ASTPP] [user_domain] user_domainAmir4660.newsip.israelnumber.com
2023-02-07 13:27:21.933790 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] maxlength::::::::: 180
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"000/00".....0546322423
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"000/00".....0546322423
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE accountid = 5203 limit 1
2023-02-07 13:27:21.933790 97.83% [WARNING] switch_cpp.cpp:1465 [ASTPP] [user_domain] user_domainAmir4660.newsip.israelnumber.com
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_14
2023-02-07 13:27:21.933790 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [PBX] call_type : 14
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Generated XML:<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="972737004346">
<condition field="destination_number" expression="0737004346">
<action application="set" data="effective_destination_number=0737004346"/>
<action application="set" data="execute_on_answer=sched_hangup +10800 normal_clearing"/>
<action application="set" data="callstart=2023-02-07 13:27:21"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="set" data="continue_on_fail=TRUE"/>
<action application="set" data="account_id=709"/>
<action application="set" data="parent_id=0"/>
<action application="set" data="entity_id=0"/>
<action application="set" data="call_processed=internal"/>
<action application="set" data="call_direction=inbound"/>
<action application="set" data="accountname=default"/>
<action application="set" data="filename1=astpp.pbx.lua"/>
<action application="set" data="origination_rates_did=ID:17861|CODE:^972737004346.*|DESTINATION:972737004346|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:14|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:93|ACCID:5203"/>
<action application="set" data="origination_rates=0"/>
<action application="set" data="original_caller_id_name=0546322423"/>
<action application="set" data="original_caller_id_number=0546322423"/>
<action application="limit" data="db 5203 user_5203 2 !SWITCH_CONGESTION"/>
<action application="set" data="effective_caller_id_name=0546322423"/>
<action application="set" data="effective_caller_id_number=0546322423"/>
<action application="set" data="receiver_accid=5203"/>
<action application="export" data="domain_name=Amir4660.newsip.israelnumber.com"/>
<action application="export" data="sip_to_host=Amir4660.newsip.israelnumber.com"/>
<action application="limit" data="db 972737004346 did_972737004346 2 !SWITCH_CONGESTION"/>
<action application="export" data="presence_data=x|||prodtwo(170019686118)|||^972737004346.* // 972737004346 // 0.00000||||||DID|||212.150.158.100"/>
<action application="export" data="call_type=14"/>
<action application="set" data="did_calltype=14"/>
<action application="set" data="did_extensions=972737004346"/>
<action application="transfer" data="972737004346 XML default"/>
</condition>
</extension>
</context>
</section>
</document>
Dialplan: sofia/default/0546322423@212.150.158.100 parsing [default->972737004346] continue=false
Dialplan: sofia/default/0546322423@212.150.158.100 Regex (PASS) [972737004346] destination_number(0737004346) =~ /0737004346/ break=on-false
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(effective_destination_number=0737004346) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(execute_on_answer=sched_hangup +10800 normal_clearing) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(callstart=2023-02-07 13:27:21) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(hangup_after_bridge=true) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(continue_on_fail=TRUE) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(account_id=709) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(parent_id=0) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(entity_id=0) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(call_processed=internal) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(call_direction=inbound) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(accountname=default) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(filename1=astpp.pbx.lua) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(origination_rates_did=ID:17861|CODE:^972737004346.*|DESTINATION:972737004346|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:14|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:93|ACCID:5203) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(origination_rates=0) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(original_caller_id_name=0546322423) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(original_caller_id_number=0546322423) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action limit(db 5203 user_5203 2 !SWITCH_CONGESTION) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(effective_caller_id_name=0546322423) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(effective_caller_id_number=0546322423) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(receiver_accid=5203) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action export(domain_name=Amir4660.newsip.israelnumber.com) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action export(sip_to_host=Amir4660.newsip.israelnumber.com) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action limit(db 972737004346 did_972737004346 2 !SWITCH_CONGESTION) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action export(presence_data=x|||prodtwo(170019686118)|||^972737004346.* // 972737004346 // 0.00000||||||DID|||212.150.158.100) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action export(call_type=14) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(did_calltype=14) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action set(did_extensions=972737004346) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action transfer(972737004346 XML default) 
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0546322423@212.150.158.100) State Change CS_ROUTING -> CS_EXECUTE
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0546322423@212.150.158.100) State ROUTING going to sleep
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_EXECUTE (Cur 5 Tot 1860)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0546322423@212.150.158.100) State EXECUTE
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_sofia.c:213 sofia/default/0546322423@212.150.158.100 SOFIA EXECUTE
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:323 sofia/default/0546322423@212.150.158.100 Standard EXECUTE
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(effective_destination_number=0737004346)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [effective_destination_number]=[0737004346]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(execute_on_answer=sched_hangup +10800 normal_clearing)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [execute_on_answer]=[sched_hangup +10800 normal_clearing]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(callstart=2023-02-07 13:27:21)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [callstart]=[2023-02-07 13:27:21]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(hangup_after_bridge=true)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(continue_on_fail=TRUE)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [continue_on_fail]=[TRUE]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(account_id=709)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [account_id]=[709]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(parent_id=0)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [parent_id]=[0]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(entity_id=0)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [entity_id]=[0]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(call_processed=internal)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [call_processed]=[internal]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(call_direction=inbound)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [call_direction]=[inbound]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(accountname=default)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [accountname]=[default]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(filename1=astpp.pbx.lua)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [filename1]=[astpp.pbx.lua]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(origination_rates_did=ID:17861|CODE:^972737004346.*|DESTINATION:972737004346|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:14|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:93|ACCID:5203)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [origination_rates_did]=[ID:17861|CODE:^972737004346.*|DESTINATION:972737004346|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:14|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|CI:93|ACCID:5203]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(origination_rates=0)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [origination_rates]=[0]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(original_caller_id_name=0546322423)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [original_caller_id_name]=[0546322423]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(original_caller_id_number=0546322423)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [original_caller_id_number]=[0546322423]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 limit(db 5203 user_5203 2 !SWITCH_CONGESTION)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_limit.c:124 incr called: 5203_user_5203 max:2, interval:0
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_db.c:194 Usage for 5203_user_5203 is now 1/2
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(effective_caller_id_name=0546322423)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [effective_caller_id_name]=[0546322423]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(effective_caller_id_number=0546322423)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [effective_caller_id_number]=[0546322423]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(receiver_accid=5203)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [receiver_accid]=[5203]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(domain_name=Amir4660.newsip.israelnumber.com)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [domain_name]=[Amir4660.newsip.israelnumber.com]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(sip_to_host=Amir4660.newsip.israelnumber.com)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [sip_to_host]=[Amir4660.newsip.israelnumber.com]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 limit(db 972737004346 did_972737004346 2 !SWITCH_CONGESTION)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_limit.c:124 incr called: 972737004346_did_972737004346 max:2, interval:0
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_db.c:194 Usage for 972737004346_did_972737004346 is now 1/2
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(presence_data=x|||prodtwo(170019686118)|||^972737004346.* // 972737004346 // 0.00000||||||DID|||212.150.158.100)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||prodtwo(170019686118)|||^972737004346.* // 972737004346 // 0.00000||||||DID|||212.150.158.100]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(call_type=14)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_type]=[14]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(did_calltype=14)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [did_calltype]=[14]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(did_extensions=972737004346)
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [did_extensions]=[972737004346]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 transfer(972737004346 XML default)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_ivr.c:2289 (sofia/default/0546322423@212.150.158.100) State Change CS_EXECUTE -> CS_ROUTING
2023-02-07 13:27:21.933790 97.83% [NOTICE] switch_ivr.c:2296 Transfer sofia/default/0546322423@212.150.158.100 to XML[972737004346@default]
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0546322423@212.150.158.100) State EXECUTE going to sleep
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_ROUTING (Cur 5 Tot 1860)
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0546322423@212.150.158.100) State ROUTING
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_sofia.c:149 Call appears to be already acknowledged
2023-02-07 13:27:21.933790 97.83% [DEBUG] mod_sofia.c:158 sofia/default/0546322423@212.150.158.100 SOFIA ROUTING
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_core_state_machine.c:230 sofia/default/0546322423@212.150.158.100 Standard ROUTING
2023-02-07 13:27:21.933790 97.83% [INFO] mod_dialplan_xml.c:639 Processing 0546322423 <0546322423>->972737004346 in context default
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2023-02-07 13:27:21.933790 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-02-07 13:27:21.953782 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] blind_flag: 0
2023-02-07 13:27:21.953782 97.83% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 972737004346
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '972737004346' limit 1
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '972737004346' AND status=0 limit 1
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="972737004346">
<condition field="destination_number" expression="972737004346">
<action application="log" data="INFO ASTPP - Calling Card Call"/>
<action application="answer"/>
<action application="sleep" data="2000"/>
<action application="lua" data="astpp-callingcards.lua"/>
</condition>
</extension>
</context>
</section>
</document>
Dialplan: sofia/default/0546322423@212.150.158.100 parsing [default->972737004346] continue=false
Dialplan: sofia/default/0546322423@212.150.158.100 Regex (PASS) [972737004346] destination_number(972737004346) =~ /972737004346/ break=on-false
Dialplan: sofia/default/0546322423@212.150.158.100 Action log(INFO ASTPP - Calling Card Call) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action answer() 
Dialplan: sofia/default/0546322423@212.150.158.100 Action sleep(2000) 
Dialplan: sofia/default/0546322423@212.150.158.100 Action lua(astpp-callingcards.lua) 
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0546322423@212.150.158.100) State Change CS_ROUTING -> CS_EXECUTE
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0546322423@212.150.158.100) State ROUTING going to sleep
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_EXECUTE (Cur 5 Tot 1860)
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0546322423@212.150.158.100) State EXECUTE
2023-02-07 13:27:21.953782 97.83% [DEBUG] mod_sofia.c:213 sofia/default/0546322423@212.150.158.100 SOFIA EXECUTE
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_state_machine.c:323 sofia/default/0546322423@212.150.158.100 Standard EXECUTE
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 log(INFO ASTPP - Calling Card Call)
2023-02-07 13:27:21.953782 97.83% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 answer()
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0546322423@212.150.158.100] 195.201.136.88 port 22604 -> 212.150.158.100 port 13310 codec: 8 ms: 20
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_media.c:9089 sofia/default/0546322423@212.150.158.100 Set 2833 dtmf send payload to 101
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_media.c:9096 sofia/default/0546322423@212.150.158.100 Set 2833 dtmf receive payload to 101
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_core_media.c:9119 sofia/default/0546322423@212.150.158.100 Set rtp dtmf delay to 40
2023-02-07 13:27:21.953782 97.83% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/0546322423@212.150.158.100:
v=0
o=FreeSWITCH 1675753837 1675753838 IN IP4 195.201.136.88
s=FreeSWITCH
c=IN IP4 195.201.136.88
t=0 0
m=audio 22604 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
m=video 0 RTP/AVP 19

2023-02-07 13:27:21.953782 97.83% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/0546322423@212.150.158.100] has been answered
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 sched_hangup(+10800 normal_clearing)
2023-02-07 13:27:21.953782 97.83% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [completed][200]
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_scheduler.c:263 Added task 54 switch_ivr_schedule_hangup (02641f90-b524-448f-8f56-9cbd99102e61) to run at 1675787241
2023-02-07 13:27:21.953782 97.83% [DEBUG] switch_channel.c:3950 (sofia/default/0546322423@212.150.158.100) Callstate Change RINGING -> ACTIVE
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 sleep(2000)
2023-02-07 13:27:22.013779 97.83% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [ready][200]
2023-02-07 13:27:22.033778 97.83% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [received][100]
2023-02-07 13:27:22.033778 97.83% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 7779 7780 IN IP4 82.166.67.145
s=session
c=IN IP4 82.166.67.145
t=0 0
m=audio 9804 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20

2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:5973 sofia/default/0546322423@212.150.158.100 Set 2833 dtmf send payload to 101 recv payload to 101
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:8765 Audio params changed for sofia/default/0546322423@212.150.158.100 from 212.150.158.100:13310 to 82.166.67.145:9804
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0546322423@212.150.158.100] 195.201.136.88 port 22604 -> 82.166.67.145 port 9804 codec: 8 ms: 20
2023-02-07 13:27:22.033778 97.83% [DEBUG] switch_core_media.c:8806 AUDIO RTP CHANGING DEST TO: [82.166.67.145:9804]
2023-02-07 13:27:22.033778 97.83% [DEBUG] sofia.c:8454 Processing updated SDP
2023-02-07 13:27:22.053786 97.83% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [completed][200]
2023-02-07 13:27:22.093798 97.83% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [ready][200]
2023-02-07 13:27:22.213778 97.83% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 lua(astpp-callingcards.lua)
2023-02-07 13:27:23.973782 97.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2023-02-07 13:27:23.973782 97.73% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION 
2023-02-07 13:27:23.973782 97.73% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
2023-02-07 13:27:23.973782 97.73% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
2023-02-07 13:27:25.773783 97.67% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-welcome.wav
2023-02-07 13:27:25.773783 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [get_ani] Query :SELECT * FROM ani_map WHERE number = 0546322423
2023-02-07 13:27:25.773783 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE (number = "5203" OR id="5203") AND status=0 AND deleted=0 limit 1
2023-02-07 13:27:25.773783 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2033-01-09 13:46:06' , '%Y%m%d%H%i%s') AS expiry
2023-02-07 13:27:25.773783 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2023-02-07 13:27:25' , '%Y%m%d%H%i%s') AS expiry
2023-02-07 13:27:25.773783 97.67% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 389385276538]
2023-02-07 13:27:25.773783 97.67% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
2023-02-07 13:27:25.773783 97.67% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
2023-02-07 13:27:26.993802 97.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [102@195.201.136.88] from ip 45.254.254.147
2023-02-07 13:27:27.413804 97.67% [WARNING] sofia_reg.c:3223 Can't find user [102@195.201.136.88] from 45.254.254.147
You must define a domain called '195.201.136.88' in your directory and add a user with the id="102" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2023-02-07 13:27:27.413804 97.67% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [102@195.201.136.88] from ip 45.254.254.147
2023-02-07 13:27:29.473782 97.60% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
2023-02-07 13:27:29.833796 97.60% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [302@195.201.136.88] from ip 45.120.203.97
2023-02-07 13:27:30.293822 97.60% [WARNING] sofia_reg.c:3223 Can't find user [302@195.201.136.88] from 45.120.203.97
You must define a domain called '195.201.136.88' in your directory and add a user with the id="302" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2023-02-07 13:27:30.293822 97.60% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [302@195.201.136.88] from ip 45.120.203.97
2023-02-07 13:27:30.593779 97.57% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1800
2023-02-07 13:27:30.593779 97.57% [INFO] switch_channel.c:527 RECV DTMF 9:1800
2023-02-07 13:27:31.093801 97.57% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1800
2023-02-07 13:27:31.093801 97.57% [INFO] switch_channel.c:527 RECV DTMF 7:1800
2023-02-07 13:27:31.613780 97.53% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1760
2023-02-07 13:27:31.613780 97.53% [INFO] switch_channel.c:527 RECV DTMF 2:1760
2023-02-07 13:27:33.053785 97.60% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:1800
2023-02-07 13:27:33.053785 97.60% [INFO] switch_channel.c:527 RECV DTMF 3:1800
2023-02-07 13:27:33.533783 97.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:1760
2023-02-07 13:27:33.533783 97.63% [INFO] switch_channel.c:527 RECV DTMF 5:1760
2023-02-07 13:27:34.033780 97.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:1920
2023-02-07 13:27:34.033780 97.63% [INFO] switch_channel.c:527 RECV DTMF 5:1920
2023-02-07 13:27:34.553783 97.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:2000
2023-02-07 13:27:34.553783 97.67% [INFO] switch_channel.c:527 RECV DTMF 5:2000
2023-02-07 13:27:35.053774 97.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:1840
2023-02-07 13:27:35.053774 97.67% [INFO] switch_channel.c:527 RECV DTMF 5:1840
2023-02-07 13:27:35.553774 97.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:1800
2023-02-07 13:27:35.553774 97.67% [INFO] switch_channel.c:527 RECV DTMF 5:1800
2023-02-07 13:27:35.593776 97.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [302@195.201.136.88] from ip 45.254.246.243
2023-02-07 13:27:36.033787 97.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:1760
2023-02-07 13:27:36.033787 97.67% [INFO] switch_channel.c:527 RECV DTMF 5:1760
2023-02-07 13:27:36.093786 97.67% [WARNING] sofia_reg.c:3223 Can't find user [302@195.201.136.88] from 45.254.246.243
You must define a domain called '195.201.136.88' in your directory and add a user with the id="302" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2023-02-07 13:27:36.093786 97.67% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [302@195.201.136.88] from ip 45.254.246.243
2023-02-07 13:27:36.573785 97.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:2080
2023-02-07 13:27:36.573785 97.67% [INFO] switch_channel.c:527 RECV DTMF 5:2080
2023-02-07 13:27:37.053772 97.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [101@195.201.136.88] from ip 128.90.102.195
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1760
2023-02-07 13:27:37.073777 97.67% [INFO] switch_channel.c:527 RECV DTMF #:1760
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :97235555555
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '97235555555' OR number = '9723555555' OR number = '972355555' OR number = '97235555' OR number = '9723555' OR number = '972355' OR number = '97235' OR number = '9723' OR number = '972' OR number = '97' OR number = '9' OR number ='--') OR (number = '97235555555*' OR number = '9723555555*' OR number = '972355555*' OR number = '97235555*' OR number = '9723555*' OR number = '972355*' OR number = '97235*' OR number = '9723*' OR number = '972*' OR number = '97*' OR number = '9*' OR number ='--') OR (number = '0546322423' OR number = '054632242' OR number = '05463224' OR number = '0546322' OR number = '054632' OR number = '05463' OR number = '0546' OR number = '054' OR number = '05' OR number = '0' OR number ='--') OR (number = '0546322423*' OR number = '054632242*' OR number = '05463224*' OR number = '0546322*' OR number = '054632*' OR number = '05463*' OR number = '0546*' OR number = '054*' OR number = '05*' OR number = '0*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Call Barring Status : -1
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '97235555555' OR routing_prefix = '9723555555' OR routing_prefix = '972355555' OR routing_prefix = '97235555' OR routing_prefix = '9723555' OR routing_prefix = '972355' OR routing_prefix = '97235' OR routing_prefix = '9723' OR routing_prefix = '972' OR routing_prefix = '97' OR routing_prefix = '9' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 5203
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 389385276538
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 17.78002
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 137
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] CID Pool : 0
2023-02-07 13:27:37.073777 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 3 AND status=0 limit 1 
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"00/*,+/*".....97235555555
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"00/*,+/*".....97235555555
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^97235555555.*' OR blocked_patterns = '^9723555555.*' OR blocked_patterns = '^972355555.*' OR blocked_patterns = '^97235555.*' OR blocked_patterns = '^9723555.*' OR blocked_patterns = '^972355.*' OR blocked_patterns = '^97235.*' OR blocked_patterns = '^9723.*' OR blocked_patterns = '^972.*' OR blocked_patterns = '^97.*' OR blocked_patterns = '^9.*' OR blocked_patterns ='--') AND accountid = 5203 limit 1 
2023-02-07 13:27:37.073777 97.67% [DEBUG] switch_cpp.cpp:1465 [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 = '^97235555555.*' OR patterns = '^9723555555.*' OR patterns = '^972355555.*' OR patterns = '^97235555.*' OR patterns = '^9723555.*' OR patterns = '^972355.*' OR patterns = '^97235.*' OR patterns = '^9723.*' OR patterns = '^972.*' OR patterns = '^97.*' OR patterns = '^9.*' OR patterns ='--') AND accountid = 5203 ORDER BY LENGTH(PKGPTR.patterns) DESC
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 137 AND status = 0
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 137 AND status = 0
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^97235555555.*' OR pattern = '^9723555555.*' OR pattern = '^972355555.*' OR pattern = '^97235555.*' OR pattern = '^9723555.*' OR pattern = '^972355.*' OR pattern = '^97235.*' OR pattern = '^9723.*' OR pattern = '^972.*' OR pattern = '^97.*' OR pattern = '^9.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 137 OR accountid=5203)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction:::::: 
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 46448781
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 0.05125
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : IsraelOther
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 0
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 5203
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 0
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type: 
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
2023-02-07 13:27:37.093773 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your17.78002 balance Accountid 5203 !!!
2023-02-07 13:27:37.093773 97.67% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 180 mins!
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 limit(db 389385276538 db_389385276538 2)
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_limit.c:124 incr called: 389385276538_db_389385276538 max:2, interval:0
2023-02-07 13:27:37.093773 97.67% [DEBUG] mod_db.c:194 Usage for 389385276538_db_389385276538 is now 1/2
2023-02-07 13:27:37.093773 97.67% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 180 Minutes
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 180
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
2023-02-07 13:27:37.093773 97.67% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
2023-02-07 13:27:37.373782 97.67% [WARNING] sofia_reg.c:3223 Can't find user [101@195.201.136.88] from 128.90.102.195
You must define a domain called '195.201.136.88' in your directory and add a user with the id="101" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2023-02-07 13:27:37.373782 97.67% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [101@195.201.136.88] from ip 128.90.102.195
2023-02-07 13:27:38.273778 97.67% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 say(en number pronounced 180)
2023-02-07 13:27:38.273778 97.67% [WARNING] mod_sndfile.c:281 Error Opening File [/usr/share/freeswitch/sounds/en/us/callie/digits/1.wav] [System error : No such file or directory.]
2023-02-07 13:27:38.273778 97.67% [ERR] mod_dptools.c:5045 Can't open file /usr/share/freeswitch/sounds/en/us/callie/digits/1.wav
2023-02-07 13:27:38.273778 97.67% [WARNING] mod_sndfile.c:281 Error Opening File [/usr/share/freeswitch/sounds/en/us/callie/digits/hundred.wav] [System error : No such file or directory.]
2023-02-07 13:27:38.273778 97.67% [ERR] mod_dptools.c:5045 Can't open file /usr/share/freeswitch/sounds/en/us/callie/digits/hundred.wav
2023-02-07 13:27:38.273778 97.67% [WARNING] mod_sndfile.c:281 Error Opening File [/usr/share/freeswitch/sounds/en/us/callie/digits/80.wav] [System error : No such file or directory.]
2023-02-07 13:27:38.273778 97.67% [ERR] mod_dptools.c:5045 Can't open file /usr/share/freeswitch/sounds/en/us/callie/digits/80.wav
2023-02-07 13:27:38.273778 97.67% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
2023-02-07 13:27:38.273778 97.67% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES]123131 Query rate_carrier_id   :0
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES_TRUNKS] Query :SELECT GROUP_CONCAT(trunk_id) as ids FROM routing WHERE pricelist_id=137 ORDER by id asc
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_cpp.cpp:1465 [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 = '^97235555555.*' OR pattern = '^9723555555.*' OR pattern = '^972355555.*' OR pattern = '^97235555.*' OR pattern = '^9723555.*' OR pattern = '^972355.*' OR pattern = '^97235.*' OR pattern = '^9723.*' OR pattern = '^972.*' OR pattern = '^97.*' OR pattern = '^9.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (25,33) ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [HYBRID_ROUTING]LCR with Cost in 2nd stage
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 28031785
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^972.*
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : IsraelOther
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^972.*
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip : 0
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 25
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : tata3
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway : 
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 587
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : tata3
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 28239385
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^972.*
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : IsraelOther
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^972.*
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip : 0
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 33
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : tata3
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway : 
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 587
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : tata3
2023-02-07 13:27:38.893787 97.67% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
2023-02-07 13:27:38.893787 97.67% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Loss less routing flag ::> 1
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(call_processed=internal)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_processed]=[internal]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(callstart=2023-02-07 13:27:38)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [callstart]=[2023-02-07 13:27:38]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(originated_destination_number=97235555555)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [originated_destination_number]=[97235555555]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(effective_destination_number=97235555555)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_destination_number]=[97235555555]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(continue_on_fail=true)
2023-02-07 13:27:38.893787 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(hangup_after_bridge=true)
2023-02-07 13:27:38.893787 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(account_id=5203)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_id]=[5203]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(account_type=0)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_type]=[0]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(resellerid=0)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [resellerid]=[0]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(parent_id=0)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [parent_id]=[0]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(accountcode=389385276538)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [accountcode]=[389385276538]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(call_direction=outbound)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(calltype=CALLINGCARD)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [calltype]=[CALLINGCARD]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(origination_rates=ID:46448781|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.05125|INC:10|INITIALBLOCK:30|RATEGROUP:137|MARKUP:0|CI:0|ACCID:5203)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_rates]=[ID:46448781|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.05125|INC:10|INITIALBLOCK:30|RATEGROUP:137|MARKUP:0|CI:0|ACCID:5203]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(execute_on_answer=sched_hangup +10800)
2023-02-07 13:27:38.893787 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [execute_on_answer]=[sched_hangup +10800]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(process_cdr=true)
2023-02-07 13:27:38.893787 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [process_cdr]=[true]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 sched_hangup(+10800)
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_scheduler.c:263 Added task 55 switch_ivr_schedule_hangup (02641f90-b524-448f-8f56-9cbd99102e61) to run at 1675787258
2023-02-07 13:27:38.893787 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 5203 AND status != '1' LIMIT 1
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(original_caller_id_name=201501718238)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_name]=[201501718238]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(original_caller_id_number=201501718238)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_number]=[201501718238]
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 3 AND status=0 limit 1 
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(presence_data=x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC]
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 587) AND status=0 limit 1 
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(effective_caller_id_name=201501718238)
2023-02-07 13:27:38.913777 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [effective_caller_id_name]=[201501718238]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(effective_caller_id_number=201501718238)
2023-02-07 13:27:38.913777 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [effective_caller_id_number]=[201501718238]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(effective_caller_id_name=201501718238)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_caller_id_name]=[201501718238]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(effective_caller_id_number=201501718238)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_caller_id_number]=[201501718238]
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :0/0.....97235555555
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(termination_rates=ID:28031785|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02050|INC:1|TRUNK:25|PROVIDER:587)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:28031785|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02050|INC:1|TRUNK:25|PROVIDER:587]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(trunk_id=25)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[25]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(provider_id=587)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[587]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 bridge([leg_timeout=0]sofia/gateway/tata3/97235555555)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1954 (sofia/default/0546322423@212.150.158.100) Callstate Change ACTIVE -> RING_WAIT
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [domain_name]=[Amir4660.newsip.israelnumber.com] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [sip_to_host]=[Amir4660.newsip.israelnumber.com] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [presence_data]=[x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [call_type]=[14] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [call_processed]=[internal] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [callstart]=[2023-02-07 13:27:38] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [originated_destination_number]=[97235555555] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_destination_number]=[97235555555] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [account_id]=[5203] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [account_type]=[0] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [resellerid]=[0] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [parent_id]=[0] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [accountcode]=[389385276538] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [call_direction]=[outbound] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [origination_rates]=[ID:46448781|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.05125|INC:10|INITIALBLOCK:30|RATEGROUP:137|MARKUP:0|CI:0|ACCID:5203] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [original_caller_id_name]=[201501718238] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [original_caller_id_number]=[201501718238] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [presence_data]=[x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_caller_id_name]=[201501718238] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_caller_id_number]=[201501718238] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [termination_rates]=[ID:28031785|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02050|INC:1|TRUNK:25|PROVIDER:587] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [trunk_id]=[25] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [provider_id]=[587] to event
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
2023-02-07 13:27:38.913777 97.67% [NOTICE] switch_channel.c:1123 New Channel sofia/default/97235555555 [321b749b-dd3b-480e-bd59-c6e7ca1ddfb7]
2023-02-07 13:27:38.913777 97.67% [DEBUG] mod_sofia.c:5121 (sofia/default/97235555555) State Change CS_NEW -> CS_INIT
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_INIT (Cur 6 Tot 1861)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:624 (sofia/default/97235555555) State INIT
2023-02-07 13:27:38.913777 97.67% [DEBUG] mod_sofia.c:97 sofia/default/97235555555 SOFIA INIT
2023-02-07 13:27:38.913777 97.67% [INFO] sofia_glue.c:1651 sofia/default/97235555555 sending invite call-id: (null)
2023-02-07 13:27:38.913777 97.67% [DEBUG] sofia_glue.c:1654 sofia/default/97235555555 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1675744024 1675744025 IN IP4 195.201.136.88
s=FreeSWITCH
c=IN IP4 195.201.136.88
t=0 0
m=audio 32434 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:40 sofia/default/97235555555 Standard INIT
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:48 (sofia/default/97235555555) State Change CS_INIT -> CS_ROUTING
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:624 (sofia/default/97235555555) State INIT going to sleep
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_ROUTING (Cur 6 Tot 1861)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:640 (sofia/default/97235555555) State ROUTING
2023-02-07 13:27:38.913777 97.67% [DEBUG] mod_sofia.c:158 sofia/default/97235555555 SOFIA ROUTING
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_ivr_originate.c:67 (sofia/default/97235555555) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:640 (sofia/default/97235555555) State ROUTING going to sleep
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 1861)
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:659 (sofia/default/97235555555) State CONSUME_MEDIA
2023-02-07 13:27:38.913777 97.67% [DEBUG] switch_core_state_machine.c:659 (sofia/default/97235555555) State CONSUME_MEDIA going to sleep
2023-02-07 13:27:38.913777 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/97235555555 entering state [calling][0]
2023-02-07 13:27:39.033782 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/97235555555 entering state [terminated][500]
2023-02-07 13:27:39.033782 97.67% [NOTICE] sofia.c:8738 Hangup sofia/default/97235555555 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_HANGUP (Cur 6 Tot 1861)
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:844 (sofia/default/97235555555) Callstate Change DOWN -> HANGUP
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:846 (sofia/default/97235555555) State HANGUP
2023-02-07 13:27:39.033782 97.67% [DEBUG] mod_sofia.c:468 Channel sofia/default/97235555555 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:59 sofia/default/97235555555 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:846 (sofia/default/97235555555) State HANGUP going to sleep
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:616 (sofia/default/97235555555) State Change CS_HANGUP -> CS_REPORTING
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_REPORTING (Cur 6 Tot 1861)
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:932 (sofia/default/97235555555) State REPORTING
2023-02-07 13:27:39.033782 97.67% [INFO] mod_json_cdr.c:271 Process [321b749b-dd3b-480e-bd59-c6e7ca1ddfb7.cdr.json]
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:168 sofia/default/97235555555 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:932 (sofia/default/97235555555) State REPORTING going to sleep
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_state_machine.c:607 (sofia/default/97235555555) State Change CS_REPORTING -> CS_DESTROY
2023-02-07 13:27:39.033782 97.67% [DEBUG] switch_core_session.c:1753 Session 1861 (sofia/default/97235555555) Locked, Waiting on external entities
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2023-02-07 13:27:39.053780 97.67% [NOTICE] switch_core_session.c:1771 Session 1861 (sofia/default/97235555555) Ended
2023-02-07 13:27:39.053780 97.67% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/97235555555 [CS_DESTROY]
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:735 (sofia/default/97235555555) Running State Change CS_DESTROY (Cur 5 Tot 1861)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:745 (sofia/default/97235555555) State DESTROY
2023-02-07 13:27:39.053780 97.67% [DEBUG] mod_sofia.c:379 sofia/default/97235555555 SOFIA DESTROY
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:175 sofia/default/97235555555 Standard DESTROY
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:745 (sofia/default/97235555555) State DESTROY going to sleep
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:2178 (sofia/default/0546322423@212.150.158.100) Callstate Change RING_WAIT -> ACTIVE
2023-02-07 13:27:39.053780 97.67% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(presence_data=x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC]
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 587) AND status=0 limit 1 
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(effective_caller_id_name=201501718238)
2023-02-07 13:27:39.053780 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [effective_caller_id_name]=[201501718238]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 set(effective_caller_id_number=201501718238)
2023-02-07 13:27:39.053780 97.67% [DEBUG] mod_dptools.c:1685 SET sofia/default/0546322423@212.150.158.100 [effective_caller_id_number]=[201501718238]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(effective_caller_id_name=201501718238)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_caller_id_name]=[201501718238]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(effective_caller_id_number=201501718238)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_caller_id_number]=[201501718238]
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :0/0.....97235555555
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(termination_rates=ID:28239385|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02050|INC:1|TRUNK:33|PROVIDER:587)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:28239385|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02050|INC:1|TRUNK:33|PROVIDER:587]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(trunk_id=33)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[33]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 export(provider_id=587)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[587]
EXECUTE [depth=0] sofia/default/0546322423@212.150.158.100 bridge([leg_timeout=0]sofia/gateway/tata3/97235555555)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1954 (sofia/default/0546322423@212.150.158.100) Callstate Change ACTIVE -> RING_WAIT
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [domain_name]=[Amir4660.newsip.israelnumber.com] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [sip_to_host]=[Amir4660.newsip.israelnumber.com] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [presence_data]=[x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [call_type]=[14] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [call_processed]=[internal] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [callstart]=[2023-02-07 13:27:38] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [originated_destination_number]=[97235555555] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_destination_number]=[97235555555] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [account_id]=[5203] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [account_type]=[0] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [resellerid]=[0] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [parent_id]=[0] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [accountcode]=[389385276538] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [call_direction]=[outbound] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [origination_rates]=[ID:46448781|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.05125|INC:10|INITIALBLOCK:30|RATEGROUP:137|MARKUP:0|CI:0|ACCID:5203] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [original_caller_id_name]=[201501718238] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [original_caller_id_number]=[201501718238] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [presence_data]=[x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_caller_id_name]=[201501718238] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_caller_id_number]=[201501718238] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [termination_rates]=[ID:28239385|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02050|INC:1|TRUNK:33|PROVIDER:587] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [trunk_id]=[33] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [provider_id]=[587] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [presence_data]=[x|||Amir(389385276538)|||^972.* // IsraelOther // 0.05125|||tata3 // ^972.* // IsraelOther // 0.02050|||CC] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_caller_id_name]=[201501718238] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [effective_caller_id_number]=[201501718238] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [termination_rates]=[ID:28239385|CODE:^972.*|DESTINATION:IsraelOther|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.02050|INC:1|TRUNK:33|PROVIDER:587] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [trunk_id]=[33] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_channel.c:1269 sofia/default/0546322423@212.150.158.100 EXPORTING[export_vars] [provider_id]=[587] to event
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
2023-02-07 13:27:39.053780 97.67% [NOTICE] switch_channel.c:1123 New Channel sofia/default/97235555555 [f8b9ff8c-ceed-4956-8582-efb86100fd0d]
2023-02-07 13:27:39.053780 97.67% [DEBUG] mod_sofia.c:5121 (sofia/default/97235555555) State Change CS_NEW -> CS_INIT
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_INIT (Cur 6 Tot 1862)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:624 (sofia/default/97235555555) State INIT
2023-02-07 13:27:39.053780 97.67% [DEBUG] mod_sofia.c:97 sofia/default/97235555555 SOFIA INIT
2023-02-07 13:27:39.053780 97.67% [INFO] sofia_glue.c:1651 sofia/default/97235555555 sending invite call-id: (null)
2023-02-07 13:27:39.053780 97.67% [DEBUG] sofia_glue.c:1654 sofia/default/97235555555 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1675749733 1675749734 IN IP4 195.201.136.88
s=FreeSWITCH
c=IN IP4 195.201.136.88
t=0 0
m=audio 26726 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:40 sofia/default/97235555555 Standard INIT
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:48 (sofia/default/97235555555) State Change CS_INIT -> CS_ROUTING
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:624 (sofia/default/97235555555) State INIT going to sleep
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_ROUTING (Cur 6 Tot 1862)
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:640 (sofia/default/97235555555) State ROUTING
2023-02-07 13:27:39.053780 97.67% [DEBUG] mod_sofia.c:158 sofia/default/97235555555 SOFIA ROUTING
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_ivr_originate.c:67 (sofia/default/97235555555) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:640 (sofia/default/97235555555) State ROUTING going to sleep
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 1862)
2023-02-07 13:27:39.053780 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/97235555555 entering state [calling][0]
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:659 (sofia/default/97235555555) State CONSUME_MEDIA
2023-02-07 13:27:39.053780 97.67% [DEBUG] switch_core_state_machine.c:659 (sofia/default/97235555555) State CONSUME_MEDIA going to sleep
2023-02-07 13:27:39.193781 97.67% [DEBUG] sofia.c:7499 Channel sofia/default/97235555555 entering state [terminated][500]
2023-02-07 13:27:39.193781 97.67% [NOTICE] sofia.c:8738 Hangup sofia/default/97235555555 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_HANGUP (Cur 6 Tot 1862)
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:844 (sofia/default/97235555555) Callstate Change DOWN -> HANGUP
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:846 (sofia/default/97235555555) State HANGUP
2023-02-07 13:27:39.193781 97.67% [DEBUG] mod_sofia.c:468 Channel sofia/default/97235555555 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:59 sofia/default/97235555555 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:846 (sofia/default/97235555555) State HANGUP going to sleep
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:616 (sofia/default/97235555555) State Change CS_HANGUP -> CS_REPORTING
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/97235555555) Running State Change CS_REPORTING (Cur 6 Tot 1862)
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:932 (sofia/default/97235555555) State REPORTING
2023-02-07 13:27:39.193781 97.67% [INFO] mod_json_cdr.c:271 Process [f8b9ff8c-ceed-4956-8582-efb86100fd0d.cdr.json]
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_channel.c:2178 (sofia/default/0546322423@212.150.158.100) Callstate Change RING_WAIT -> ACTIVE
2023-02-07 13:27:39.193781 97.67% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:168 sofia/default/97235555555 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:932 (sofia/default/97235555555) State REPORTING going to sleep
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav sample rate 16000 doesn't match requested rate 8000
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:607 (sofia/default/97235555555) State Change CS_REPORTING -> CS_DESTROY
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_session.c:1753 Session 1862 (sofia/default/97235555555) Locked, Waiting on external entities
2023-02-07 13:27:39.193781 97.67% [NOTICE] switch_core_session.c:1771 Session 1862 (sofia/default/97235555555) Ended
2023-02-07 13:27:39.193781 97.67% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/97235555555 [CS_DESTROY]
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:735 (sofia/default/97235555555) Running State Change CS_DESTROY (Cur 5 Tot 1862)
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:745 (sofia/default/97235555555) State DESTROY
2023-02-07 13:27:39.193781 97.67% [DEBUG] mod_sofia.c:379 sofia/default/97235555555 SOFIA DESTROY
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:175 sofia/default/97235555555 Standard DESTROY
2023-02-07 13:27:39.193781 97.67% [DEBUG] switch_core_state_machine.c:745 (sofia/default/97235555555) State DESTROY going to sleep
2023-02-07 13:27:40.153782 97.60% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [302@195.201.136.88] from ip 128.90.173.184
2023-02-07 13:27:40.193774 97.60% [WARNING] sofia_reg.c:3223 Can't find user [302@195.201.136.88] from 128.90.173.184
You must define a domain called '195.201.136.88' in your directory and add a user with the id="302" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2023-02-07 13:27:40.193774 97.60% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [302@195.201.136.88] from ip 128.90.173.184
2023-02-07 13:27:41.793798 97.60% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [received][100]
2023-02-07 13:27:41.793798 97.60% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 7779 7781 IN IP4 212.150.158.100
s=session
c=IN IP4 212.150.158.100
t=0 0
m=audio 13310 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20

2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:5973 sofia/default/0546322423@212.150.158.100 Set 2833 dtmf send payload to 101 recv payload to 101
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:8765 Audio params changed for sofia/default/0546322423@212.150.158.100 from 82.166.67.145:9804 to 212.150.158.100:13310
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0546322423@212.150.158.100] 195.201.136.88 port 22604 -> 212.150.158.100 port 13310 codec: 8 ms: 20
2023-02-07 13:27:41.793798 97.60% [DEBUG] switch_core_media.c:8806 AUDIO RTP CHANGING DEST TO: [212.150.158.100:13310]
2023-02-07 13:27:41.793798 97.60% [DEBUG] sofia.c:8454 Processing updated SDP
2023-02-07 13:27:41.813804 97.60% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [completed][200]
2023-02-07 13:27:41.853795 97.60% [DEBUG] sofia.c:7499 Channel sofia/default/0546322423@212.150.158.100 entering state [ready][200]
2023-02-07 13:27:41.873794 97.60% [NOTICE] sofia.c:1065 Hangup sofia/default/0546322423@212.150.158.100 [CS_EXECUTE] [NORMAL_CLEARING]
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:0
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:1
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:2
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_cpp.cpp:1209 sofia/default/0546322423@212.150.158.100 destroy/unlink session from object
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_session.c:2983 sofia/default/0546322423@212.150.158.100 skip receive message [PHONE_EVENT] (channel is hungup already)
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0546322423@212.150.158.100) State EXECUTE going to sleep
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_HANGUP (Cur 5 Tot 1862)
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0546322423@212.150.158.100) Callstate Change ACTIVE -> HANGUP
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0546322423@212.150.158.100) State HANGUP
2023-02-07 13:27:41.873794 97.60% [DEBUG] mod_sofia.c:462 sofia/default/0546322423@212.150.158.100 Overriding SIP cause 480 with 500 from the other leg
2023-02-07 13:27:41.873794 97.60% [DEBUG] mod_sofia.c:468 Channel sofia/default/0546322423@212.150.158.100 hanging up, cause: NORMAL_CLEARING
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:59 sofia/default/0546322423@212.150.158.100 Standard HANGUP, cause: NORMAL_CLEARING
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0546322423@212.150.158.100) State HANGUP going to sleep
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0546322423@212.150.158.100) State Change CS_HANGUP -> CS_REPORTING
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0546322423@212.150.158.100) Running State Change CS_REPORTING (Cur 5 Tot 1862)
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0546322423@212.150.158.100) State REPORTING
2023-02-07 13:27:41.873794 97.60% [INFO] mod_json_cdr.c:271 Process [02641f90-b524-448f-8f56-9cbd99102e61.cdr.json]
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:168 sofia/default/0546322423@212.150.158.100 Standard REPORTING, cause: NORMAL_CLEARING
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0546322423@212.150.158.100) State REPORTING going to sleep
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0546322423@212.150.158.100) State Change CS_REPORTING -> CS_DESTROY
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_session.c:1753 Session 1860 (sofia/default/0546322423@212.150.158.100) Locked, Waiting on external entities
2023-02-07 13:27:41.873794 97.60% [NOTICE] switch_core_session.c:1771 Session 1860 (sofia/default/0546322423@212.150.158.100) Ended
2023-02-07 13:27:41.873794 97.60% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0546322423@212.150.158.100 [CS_DESTROY]
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0546322423@212.150.158.100) Running State Change CS_DESTROY (Cur 4 Tot 1862)
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0546322423@212.150.158.100) State DESTROY
2023-02-07 13:27:41.873794 97.60% [DEBUG] mod_sofia.c:379 sofia/default/0546322423@212.150.158.100 SOFIA DESTROY
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:175 sofia/default/0546322423@212.150.158.100 Standard DESTROY
2023-02-07 13:27:41.873794 97.60% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0546322423@212.150.158.100) State DESTROY going to sleep
2023-02-07 13:27:41.893777 97.60% [DEBUG] switch_scheduler.c:147 Deleting task 54 switch_ivr_schedule_hangup (02641f90-b524-448f-8f56-9cbd99102e61)
2023-02-07 13:27:41.893777 97.60% [DEBUG] switch_scheduler.c:147 Deleting task 55 switch_ivr_schedule_hangup (02641f90-b524-448f-8f56-9cbd99102e61)
2023-02-07 13:27:46.493782 97.50% [NOTICE] switch_channel.c:1123 New Channel sofia/default/+447903175491@avoxi.io [6f7e3567-38b4-46b1-b91c-ffeba236d499]
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/+447903175491@avoxi.io) Running State Change CS_NEW (Cur 5 Tot 1863)
2023-02-07 13:27:46.493782 97.50% [INFO] sofia.c:10462 sofia/default/+447903175491@avoxi.io receiving invite from 195.201.136.94:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: dac88e3d-8b52-43a2-a3b9-df8b9c19136f
2023-02-07 13:27:46.493782 97.50% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 195.201.136.94:0.
2023-02-07 13:27:46.493782 97.50% [DEBUG] sofia.c:10585 IP 195.201.136.94 Approved by acl "default[]". Access Granted.
2023-02-07 13:27:46.493782 97.50% [DEBUG] sofia.c:7499 Channel sofia/default/+447903175491@avoxi.io entering state [received][100]
2023-02-07 13:27:46.493782 97.50% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=- 1129890993 1129890993 IN IP4 34.75.227.126
s=Asterisk
c=IN IP4 34.75.227.126
t=0 0
m=audio 22704 RTP/AVP 101 0 8 18
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=maxptime:150
a=rtcp:22705
a=rtcp-mux
a=ptime:20

2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/+447903175491@avoxi.io PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_codec.c:111 sofia/default/+447903175491@avoxi.io Original read codec set to PCMU:0
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_media.c:5973 sofia/default/+447903175491@avoxi.io Set 2833 dtmf send payload to 101 recv payload to 101
2023-02-07 13:27:46.493782 97.50% [DEBUG] sofia.c:7933 (sofia/default/+447903175491@avoxi.io) State Change CS_NEW -> CS_INIT
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:600 (sofia/default/+447903175491@avoxi.io) State NEW
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/+447903175491@avoxi.io) Running State Change CS_INIT (Cur 5 Tot 1863)
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:624 (sofia/default/+447903175491@avoxi.io) State INIT
2023-02-07 13:27:46.493782 97.50% [DEBUG] mod_sofia.c:97 sofia/default/+447903175491@avoxi.io SOFIA INIT
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:40 sofia/default/+447903175491@avoxi.io Standard INIT
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:48 (sofia/default/+447903175491@avoxi.io) State Change CS_INIT -> CS_ROUTING
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:624 (sofia/default/+447903175491@avoxi.io) State INIT going to sleep
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/+447903175491@avoxi.io) Running State Change CS_ROUTING (Cur 5 Tot 1863)
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_channel.c:2380 (sofia/default/+447903175491@avoxi.io) Callstate Change DOWN -> RINGING
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:640 (sofia/default/+447903175491@avoxi.io) State ROUTING
2023-02-07 13:27:46.493782 97.50% [DEBUG] mod_sofia.c:158 sofia/default/+447903175491@avoxi.io SOFIA ROUTING
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_core_state_machine.c:230 sofia/default/+447903175491@avoxi.io Standard ROUTING
2023-02-07 13:27:46.493782 97.50% [INFO] mod_dialplan_xml.c:639 Processing +447903175491 <+447903175491>->442039877750 in context default
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2023-02-07 13:27:46.493782 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] blind_flag: 0
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '442039877750' limit 1
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '442039877750' AND status=0 limit 1
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET domains] Query :SELECT * FROM domains WHERE domain = 'avoxi.io' limit 1
2023-02-07 13:27:46.513775 97.50% [WARNING] switch_cpp.cpp:1465 [ASTPP] [FAXER] in custom Caller ID 
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Caller Id name / number  : +447903175491 / +447903175491
2023-02-07 13:27:46.513775 97.50% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="442039877750" LIMIT 1
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [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="442039877750"  AND domains.domain="newsip.israelnumber.com" limit 1
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Call direction : outbound
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 594905904039]
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "594905904039" AND deleted = 0 limit 1
2023-02-07 13:27:46.513775 97.50% [WARNING] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] [594905904039] Insufficent balance (-13.0735) to make calls..!!
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [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 ="442039877750" AND A.accountid = '855' limit 1
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 442039877750
2023-02-07 13:27:46.513775 97.50% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [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.buy_minutes,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 ="442039877750" LIMIT 1
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [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="442039877750"  AND domains.domain="newsip.israelnumber.com" limit 1
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] New Call direction : outbound
2023-02-07 13:27:46.513775 97.50% [NOTICE] switch_cpp.cpp:1465 [ASTPP] DID global translation id: 13
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 13 AND status=0 limit 1 
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :"+/*,03/9723,073/97273,09/9729,02/9722,04/9724,077/97277".....442039877750
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="442039877750" AND (accountid = 0 OR status = 1) LIMIT 1
2023-02-07 13:27:46.513775 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] New Call direction HEREE : outbound
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] post_cdrs:::0
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET RESELLERID] Query :SELECT reseller_id FROM accounts WHERE id = 855
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="442039877750">
<condition field="destination_number" expression="442039877750">
<action application="log" data="WARNING Accountcode . Dialed DID number (442039877750) routes not set!!"/>
<action application="set" data="original_caller_id_name=+447903175491"/>
<action application="set" data="original_caller_id_number=+447903175491"/>
<action application="set" data="error_cdr=1"/>
<action application="set" data="callstart=2023-02-07 13:27:46"/>
<action application="set" data="account_id=855"/>
<action application="set" data="parent_id=0"/>
<action application="set" data="call_direction=outbound"/>
<action application="set" data="sip_ignore_remote_cause=true"/>
<action application="set" data="call_processed=internal"/>
<action application="set" data="effective_destination_number=442039877750"/>
<action application="set" data="last_bridge_hangup_cause=NO_ROUTE_DESTINATION"/>
<action application="hangup" data="NO_ROUTE_DESTINATION"/>
</condition>
</extension>
</context>
</section>
</document>
Dialplan: sofia/default/+447903175491@avoxi.io parsing [default->442039877750] continue=false
Dialplan: sofia/default/+447903175491@avoxi.io Regex (PASS) [442039877750] destination_number(442039877750) =~ /442039877750/ break=on-false
Dialplan: sofia/default/+447903175491@avoxi.io Action log(WARNING Accountcode . Dialed DID number (442039877750) routes not set!!) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(original_caller_id_name=+447903175491) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(original_caller_id_number=+447903175491) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(error_cdr=1) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(callstart=2023-02-07 13:27:46) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(account_id=855) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(parent_id=0) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(call_direction=outbound) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(sip_ignore_remote_cause=true) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(call_processed=internal) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(effective_destination_number=442039877750) 
Dialplan: sofia/default/+447903175491@avoxi.io Action set(last_bridge_hangup_cause=NO_ROUTE_DESTINATION) 
Dialplan: sofia/default/+447903175491@avoxi.io Action hangup(NO_ROUTE_DESTINATION) 
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_core_state_machine.c:281 (sofia/default/+447903175491@avoxi.io) State Change CS_ROUTING -> CS_EXECUTE
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_core_state_machine.c:640 (sofia/default/+447903175491@avoxi.io) State ROUTING going to sleep
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/+447903175491@avoxi.io) Running State Change CS_EXECUTE (Cur 5 Tot 1863)
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_core_state_machine.c:647 (sofia/default/+447903175491@avoxi.io) State EXECUTE
2023-02-07 13:27:46.513775 97.50% [DEBUG] mod_sofia.c:213 sofia/default/+447903175491@avoxi.io SOFIA EXECUTE
2023-02-07 13:27:46.513775 97.50% [DEBUG] switch_core_state_machine.c:323 sofia/default/+447903175491@avoxi.io Standard EXECUTE
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io log(WARNING Accountcode . Dialed DID number (442039877750) routes not set!!)
2023-02-07 13:27:46.513775 97.50% [WARNING] mod_dptools.c:1879 Accountcode . Dialed DID number (442039877750) routes not set!!
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(original_caller_id_name=+447903175491)
2023-02-07 13:27:46.513775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [original_caller_id_name]=[+447903175491]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(original_caller_id_number=+447903175491)
2023-02-07 13:27:46.513775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [original_caller_id_number]=[+447903175491]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(error_cdr=1)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [error_cdr]=[1]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(callstart=2023-02-07 13:27:46)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [callstart]=[2023-02-07 13:27:46]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(account_id=855)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [account_id]=[855]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(parent_id=0)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [parent_id]=[0]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(call_direction=outbound)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [call_direction]=[outbound]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(sip_ignore_remote_cause=true)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [sip_ignore_remote_cause]=[true]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(call_processed=internal)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [call_processed]=[internal]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(effective_destination_number=442039877750)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [effective_destination_number]=[442039877750]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io set(last_bridge_hangup_cause=NO_ROUTE_DESTINATION)
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_dptools.c:1685 SET sofia/default/+447903175491@avoxi.io [last_bridge_hangup_cause]=[NO_ROUTE_DESTINATION]
EXECUTE [depth=0] sofia/default/+447903175491@avoxi.io hangup(NO_ROUTE_DESTINATION)
2023-02-07 13:27:46.533775 97.50% [NOTICE] mod_dptools.c:1387 Hangup sofia/default/+447903175491@avoxi.io [CS_EXECUTE] [NO_ROUTE_DESTINATION]
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_session.c:2983 sofia/default/+447903175491@avoxi.io skip receive message [PHONE_EVENT] (channel is hungup already)
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:647 (sofia/default/+447903175491@avoxi.io) State EXECUTE going to sleep
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/+447903175491@avoxi.io) Running State Change CS_HANGUP (Cur 5 Tot 1863)
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:844 (sofia/default/+447903175491@avoxi.io) Callstate Change RINGING -> HANGUP
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/+447903175491@avoxi.io) State HANGUP
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_sofia.c:468 Channel sofia/default/+447903175491@avoxi.io hanging up, cause: NO_ROUTE_DESTINATION
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:59 sofia/default/+447903175491@avoxi.io Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/+447903175491@avoxi.io) State HANGUP going to sleep
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:616 (sofia/default/+447903175491@avoxi.io) State Change CS_HANGUP -> CS_REPORTING
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/+447903175491@avoxi.io) Running State Change CS_REPORTING (Cur 5 Tot 1863)
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/+447903175491@avoxi.io) State REPORTING
2023-02-07 13:27:46.533775 97.50% [INFO] mod_json_cdr.c:271 Process [6f7e3567-38b4-46b1-b91c-ffeba236d499.cdr.json]
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:168 sofia/default/+447903175491@avoxi.io Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/+447903175491@avoxi.io) State REPORTING going to sleep
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:607 (sofia/default/+447903175491@avoxi.io) State Change CS_REPORTING -> CS_DESTROY
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_session.c:1753 Session 1863 (sofia/default/+447903175491@avoxi.io) Locked, Waiting on external entities
2023-02-07 13:27:46.533775 97.50% [NOTICE] switch_core_session.c:1771 Session 1863 (sofia/default/+447903175491@avoxi.io) Ended
2023-02-07 13:27:46.533775 97.50% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/+447903175491@avoxi.io [CS_DESTROY]
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:735 (sofia/default/+447903175491@avoxi.io) Running State Change CS_DESTROY (Cur 4 Tot 1863)
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/+447903175491@avoxi.io) State DESTROY
2023-02-07 13:27:46.533775 97.50% [DEBUG] mod_sofia.c:379 sofia/default/+447903175491@avoxi.io SOFIA DESTROY
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:175 sofia/default/+447903175491@avoxi.io Standard DESTROY
2023-02-07 13:27:46.533775 97.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/+447903175491@avoxi.io) State DESTROY going to sleep