1) 2018-07-12 12:53:45.689120 [DEBUG] switch_channel.c:2249 (sofia/default/1489873901@192.168.1.201) Callstate Change DOWN -> RINGING 2018-07-12 12:53:45.689120 [DEBUG] switch_core_state_machine.c:643 (sofia/default/1489873901@192.168.1.201) State ROUTING 2018-07-12 12:53:45.689120 [DEBUG] mod_sofia.c:154 sofia/default/1489873901@192.168.1.201 SOFIA ROUTING 2018-07-12 12:53:45.689120 [DEBUG] switch_core_state_machine.c:236 sofia/default/1489873901@192.168.1.201 Standard ROUTING 2018-07-12 12:53:45.689120 [INFO] mod_dialplan_xml.c:637 Processing 1489873901 <1489873901>->12127773456 in context default 2018-07-12 12:53:45.989074 [DEBUG] freeswitch_lua.cpp:372 DBH handle 0x7f49ec053030 Connected. 2018-07-12 12:53:45.989074 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard') 2018-07-12 12:53:45.989074 [INFO] switch_cpp.cpp:1376 [ASTPP] [Dialplan] Dialed number : 12127773456 2018-07-12 12:53:46.009069 [INFO] switch_cpp.cpp:1376 [ASTPP] [Dialplan] Caller Id name / number : 1489873901 / 1489873901 2018-07-12 12:53:46.009069 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,B.did_cid_translation as did_cid_translation,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout FROM dids AS A,accounts AS B WHERE A.status=0 AND B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="12127773456" LIMIT 1 2018-07-12 12:53:46.009069 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT 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 WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="12127773456" limit 1 2018-07-12 12:53:46.009069 [INFO] switch_cpp.cpp:1376 [ASTPP] [Dialplan] Call direction : outbound 2018-07-12 12:53:46.009069 [NOTICE] switch_cpp.cpp:1376 [ASTPP] [Accountcode : 1489873901] 2018-07-12 12:53:46.009069 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "1489873901" OR id="1489873901") AND status=0 AND deleted=0 AND (expiry >= '2018-07-12 07:23:46' OR expiry = '0000-00-00 00:00:00') limit 1 2018-07-12 12:53:46.029079 [WARNING] switch_cpp.cpp:1376 [ASTPP] [DOAUTHORIZATION] [1489873901] Insufficent balance (0) to make calls..!! 2018-07-12 12:53:46.029079 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT * FROM packages as P inner join package_patterns as PKGPTR on P.id = PKGPTR.package_id WHERE (patterns ='^12127773456.*' OR patterns ='^1212777345.*' OR patterns ='^121277734.*' OR patterns ='^12127773.*' OR patterns ='^1212777.*' OR patterns ='^121277.*' OR patterns ='^12127.*' OR patterns ='^1212.*' OR patterns ='^121.*' OR patterns ='^12.*' OR patterns ='^1.*' OR patterns ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1 2018-07-12 12:53:46.029079 [INFO] switch_cpp.cpp:1376 [ASTPP] Pack Type : 0 Call Direction : outbound [0:outbound,1:inbound,2:both] 2018-07-12 12:53:46.029079 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [GET_COUNTER_INFO] Query :SELECT seconds FROM counters WHERE accountid = 15 AND package_id = 1 AND status=1 LIMIT 1 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] Remaining Sec : 50000 2018-07-12 12:53:46.069113 [NOTICE] switch_cpp.cpp:1376 [ASTPP] Actual Balance : 0 2018-07-12 12:53:46.069113 [NOTICE] switch_cpp.cpp:1376 [ASTPP] Allocating static balance for package calls, Balance : 100, Credit limit : 200 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] =============== Account Information =================== 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] User id : 15 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] Account code : 1489873901 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] Balance : 100 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] Type : 0 [0:prepaid,1:postpaid] 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] Ratecard id : 1 2018-07-12 12:53:46.069113 [INFO] switch_cpp.cpp:1376 [ASTPP] ======================================================== 2018-07-12 12:53:46.069113 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0 2018-07-12 12:53:46.069113 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern ='^12127773456.*' OR pattern ='^1212777345.*' OR pattern ='^121277734.*' OR pattern ='^12127773.*' OR pattern ='^1212777.*' OR pattern ='^121277.*' OR pattern ='^12127.*' OR pattern ='^1212.*' OR pattern ='^121.*' OR pattern ='^12.*' OR pattern ='^1.*' OR pattern ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(pattern) DESC,cost DESC LIMIT 1 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] [FIND_MAXLENGTH] LIMITING CALL TO CONFIG MAX LENGTH 24!!! 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] =============== Rates Information =================== 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] ID : 1 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Code : ^1.* 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Destination : USA 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Connectcost : 1.00000 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Includedseconds : 10 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Cost : 0.20000 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Initial Increment : 1 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Increment : 1 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Accid : 15 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] ================================================================ 2018-07-12 12:53:46.089107 [INFO] switch_cpp.cpp:1376 [ASTPP] Call Max length duration : 833.41666666667 minutes 2018-07-12 12:53:46.089107 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [GET_CARRIER_RATES_TRUNKS] Query :SELECT GROUP_CONCAT(trunk_id) as ids FROM routing WHERE pricelist_id=1 2018-07-12 12:53:46.089107 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TK.cid_translation,TR.init_inc,TK.status,TK.dialed_modify,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 ='^12127773456.*' OR pattern ='^1212777345.*' OR pattern ='^121277734.*' OR pattern ='^12127773.*' OR pattern ='^1212777.*' OR pattern ='^121277.*' OR pattern ='^12127.*' OR pattern ='^1212.*' OR pattern ='^121.*' OR pattern ='^12.*' OR pattern ='^1.*' OR pattern ='--') AND TR.status = 0 AND TR.trunk_id IN (1) ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] =============== Termination Rates Information =================== 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] ID : 1 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Code : ^1.* 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Destination : USA 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Connectcost : 0.00000 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Free Seconds : 0 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Prefix : ^1.* 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Strip : 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Prepend : 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Carrier id : 1 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] carrier_name : YourProvider 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] dialplan_variable : 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Failover gateway : 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Vendor id : 12 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Number Translation : 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] Max channels : 0 2018-07-12 12:53:46.189098 [INFO] switch_cpp.cpp:1376 [ASTPP] ========================END OF TERMINATION RATES======================= 2018-07-12 12:53:46.189098 [DEBUG] switch_cpp.cpp:1376 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 15 AND status=0 LIMIT 1 2018-07-12 12:53:46.229087 [WARNING] switch_cpp.cpp:1376 [ASTPP] [FSXMLOUTBOUND] Caller ID Translation Starts 2018-07-12 12:53:46.229087 [WARNING] switch_cpp.cpp:1376 [ASTPP] [FSXMLOUTBOUND] Caller ID Translation Ends 2018-07-12 12:53:46.229087 [DEBUG] switch_cpp.cpp:1376 [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="12127773456"> <condition field="destination_number" expression="12127773456"> <action application="set" data="effective_destination_number=12127773456"/> <action application="sched_hangup" data="+50005 normal_clearing"/> <action application="set" data="callstart=2018-07-12 07:23:46"/> <action application="set" data="hangup_after_bridge=true"/> <action application="set" data="continue_on_fail=!USER_BUSY"/> <action application="set" data="account_id=15"/> <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=outbound"/> <action application="set" data="accountname=default"/> <action application="export" data="t38_passthru=true"/> <action application="set" data="fax_enable_t38=true"/> <action application="set" data="fax_enable_t38_request=true"/> <action application="set" data="origination_rates=ID:1|CODE:^1.*|DESTINATION:USA|CONNECTIONCOST:1.00000|INCLUDEDSECONDS:10|COST:0.20000|INC:1|INITIALBLOCK:1|RATEGROUP:1|MARKUP:0|ACCID:15"/> <action application="set" data="original_caller_id_name=1489873901"/> <action application="set" data="original_caller_id_number=1489873901"/> <action application="set" data="effective_caller_id_name=1489873901"/> <action application="set" data="effective_caller_id_number=1489873901"/> <action application="set" data="calltype=STANDARD"/> <action application="set" data="termination_rates=ID:1|CODE:^1.*|DESTINATION:USA|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.10000|INC:60|INITIALBLOCK:30|TRUNK:1|PROVIDER:12"/> <action application="set" data="trunk_id=1"/> <action application="set" data="provider_id=12"/> <action application="bridge" data="[leg_timeout=30,absolute_codec_string=^^:PCMA:G729:PCMA]sofia/gateway/YourProvider/12127773456"/> </condition> </extension> </context> </section> </document> 2018-07-12 12:53:46.229087 [DEBUG] freeswitch_lua.cpp:401 DBH handle 0x7f49ec053030 released.