[ASTPPCOM-96] unable to make call - Termination Rate not found! Created: 31/Aug/16  Updated: 01/Apr/21  Resolved: 01/Apr/21

Status: Done
Project: ASTPP Community
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Task
Reporter: deve1608 Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

2016-08-31 18:17:32.220087 [DEBUG] sofia.c:9543 IP XX:XX:XX:XX Rejected by acl "default". Falling back to Digest auth.
2016-08-31 18:17:32.260081 [DEBUG] sofia.c:6858 Channel sofia/default/7724558832@XX:XX:XX:XX entering state [received][100]
2016-08-31 18:17:32.260081 [DEBUG] sofia.c:6868 Remote SDP:
v=0
o=- 4 2 IN IP4 XXXXXXXXXX
s=CounterPath X-Lite 3.0
c=IN IP4 XXXXXXXXXX
t=0 0
m=audio 44230 RTP/AVP 107 119 0 98 8 3 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 3 : 85v3XCWk Bd4ZW4Cc 192.168.247.1 44230
a=alt:2 2 : jeUGOIc3 Q2Gk2GNW 192.168.12.1 44230
a=alt:3 1 : FJKlyDwo hc+8oK3d 192.168.1.6 44230

2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [BV32:107:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [BV32:107:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMA:8:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMU:0:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4410 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4355 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4271 Set telephone-event payload to 101@8000
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:3090 Set Codec sofia/default/7724558832@XX:XX:XX:XX PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2016-08-31 18:17:32.260081 [DEBUG] switch_core_codec.c:111 sofia/default/7724558832@XX:XX:XX:XX Original read codec set to PCMU:0
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4623 Set telephone-event payload to 101@8000
2016-08-31 18:17:32.260081 [DEBUG] switch_core_media.c:4681 sofia/default/7724558832@XX:XX:XX:XX Set 2833 dtmf send payload to 101 recv payload to 101
2016-08-31 18:17:32.260081 [DEBUG] sofia.c:7248 (sofia/default/7724558832@XX:XX:XX:XX) State Change CS_NEW -> CS_INIT
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:543 (sofia/default/7724558832@XX:XX:XX:XX) Running State Change CS_INIT
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:586 (sofia/default/7724558832@XX:XX:XX:XX) State INIT
2016-08-31 18:17:32.260081 [DEBUG] mod_sofia.c:89 sofia/default/7724558832@XX:XX:XX:XX SOFIA INIT
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:40 sofia/default/7724558832@XX:XX:XX:XX Standard INIT
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:48 (sofia/default/7724558832@XX:XX:XX:XX) State Change CS_INIT -> CS_ROUTING
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:586 (sofia/default/7724558832@XX:XX:XX:XX) State INIT going to sleep
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:543 (sofia/default/7724558832@XX:XX:XX:XX) Running State Change CS_ROUTING
2016-08-31 18:17:32.260081 [DEBUG] switch_channel.c:2249 (sofia/default/7724558832@XX:XX:XX:XX) Callstate Change DOWN -> RINGING
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:602 (sofia/default/7724558832@XX:XX:XX:XX) State ROUTING
2016-08-31 18:17:32.260081 [DEBUG] mod_sofia.c:142 sofia/default/7724558832@XX:XX:XX:XX SOFIA ROUTING
2016-08-31 18:17:32.260081 [DEBUG] switch_core_state_machine.c:236 sofia/default/7724558832@XX:XX:XX:XX Standard ROUTING
2016-08-31 18:17:32.260081 [INFO] mod_dialplan_xml.c:637 Processing 7724558832 <7724558832>->91XXXXXXXXXX in context default
2016-08-31 18:17:32.280047 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f62fc0ec750 Connected.
2016-08-31 18:17:32.280047 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2016-08-31 18:17:32.280047 [INFO] switch_cpp.cpp:1360 [ASTPP] [Dialplan] Dialed number : 91XXXXXXXXXX
2016-08-31 18:17:32.280047 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="91XXXXXXXXXX" LIMIT 1
2016-08-31 18:17:32.300049 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.username as username,number as accountcode,sip_devices.accountid as accountid FROM sip_devices as sip_devices,accounts as accounts WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND username="91XXXXXXXXXX" limit 1
2016-08-31 18:17:32.300049 [INFO] switch_cpp.cpp:1360 [ASTPP] [Dialplan] Call direction : outbound
2016-08-31 18:17:32.300049 [NOTICE] switch_cpp.cpp:1360 [ASTPP] [Accountcode : 7724558832]
2016-08-31 18:17:32.300049 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "7724558832" OR id="7724558832") AND status=0 AND deleted=0 AND (expiry >= '2016-08-31 18:17:32' OR expiry = '0000-00-00 00:00:00') limit 1
2016-08-31 18:17:32.340041 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns ='^91XXXXXXXXXX.' OR blocked_patterns ='^91XXXXXXXXXX19.' OR blocked_patterns ='^91XXXXXXXXXX1.' OR blocked_patterns ='^91XXXXXXXXXX.' OR blocked_patterns ='^91XXXX20.' OR blocked_patterns ='^91XXXX2.' OR blocked_patterns ='^91XXXX.' OR blocked_patterns ='^91971.' OR blocked_patterns ='^9197.' OR blocked_patterns ='^919.' OR blocked_patterns ='^91.' OR blocked_patterns ='^9.' OR blocked_patterns ='--') AND accountid = 4 limit 1
2016-08-31 18:17:32.340041 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT * FROM packages as P inner join package_patterns as PKGPTR on P.id = PKGPTR.package_id WHERE (patterns ='^91XXXXXXXXXX.' OR patterns ='^91XXXXXXXXXX19.' OR patterns ='^91XXXXXXXXXX1.' OR patterns ='^91XXXXXXXXXX.' OR patterns ='^91XXXX20.' OR patterns ='^91XXXX2.' OR patterns ='^91XXXX.' OR patterns ='^91971.' OR patterns ='^9197.' OR patterns ='^919.' OR patterns ='^91.' OR patterns ='^9.' OR patterns ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] =============== Account Information ===================
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] User id : 4
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Account code : 7724558832
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Balance : 5
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Ratecard id : 1
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] ========================================================
2016-08-31 18:17:32.340041 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
2016-08-31 18:17:32.340041 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern ='^91XXXXXXXXXX.' OR pattern ='^91XXXXXXXXXX19.' OR pattern ='^91XXXXXXXXXX1.' OR pattern ='^91XXXXXXXXXX.' OR pattern ='^91XXXX20.' OR pattern ='^91XXXX2.' OR pattern ='^91XXXX.' OR pattern ='^91971.' OR pattern ='^9197.' OR pattern ='^919.' OR pattern ='^91.' OR pattern ='^9.' OR pattern ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(pattern) DESC,cost DESC LIMIT 1
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] =============== Rates Information ===================
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] ID : 2
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Connectcost : 0.00000
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Includedseconds : 0
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Cost : 0.40000
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] comment : India
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Accid : 4
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] ================================================================
2016-08-31 18:17:32.340041 [INFO] switch_cpp.cpp:1360 [ASTPP] Call Max length duration : 12.5 minutes
2016-08-31 18:17:32.340041 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [GET_CARRIER_RATES_TRUNKS] Query :SELECT GROUP_CONCAT(trunk_id) as ids FROM routing WHERE pricelist_id=1
2016-08-31 18:17:32.340041 [DEBUG] switch_cpp.cpp:1360 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.dialed_modify,TK.maxchannels,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 ='^91XXXXXXXXXX.' OR pattern ='^91XXXXXXXXXX19.' OR pattern ='^91XXXXXXXXXX1.' OR pattern ='^91XXXXXXXXXX.' OR pattern ='^91XXXX20.' OR pattern ='^91XXXX2.' OR pattern ='^91XXXX.' OR pattern ='^91971.' OR pattern ='^9197.' OR pattern ='^919.' OR pattern ='^91.' OR pattern ='^9.' OR pattern ='--') AND TR.status = 0 AND TR.trunk_id IN (0) ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
2016-08-31 18:17:32.340041 [NOTICE] switch_cpp.cpp:1360 [ASTPP] [Dialplan] No termination rates found...!!!
2016-08-31 18:17:32.340041 [DEBUG] switch_cpp.cpp:1360 [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="91XXXXXXXXXX">
<condition field="destination_number" expression="91XXXXXXXXXX">
<action application="log" data="WARNING Accountcode 7724558832. Dialed number (91XXXXXXXXXX) termination rates not found!!"/>
<action application="playback" data="/usr/local/freeswitch/sounds/en/us/callie/astpp-badphone.wav"/>
<action application="set" data="error_cdr=1"/>
<action application="set" data="callstart=2016-08-31 18:17:32"/>
<action application="set" data="account_id=4"/>
<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=91XXXXXXXXXX"/>
<action application="set" data="last_bridge_hangup_cause=TERMINATION_RATE_NOT_FOUND"/>
<action application="hangup" data="TERMINATION_RATE_NOT_FOUND"/>
</condition>
</extension>
</context>
</section>
</document>
2016-08-31 18:17:32.340041 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f62fc0ec750 released.
Dialplan: sofia/default/7724558832@XX:XX:XX:XX parsing [default->91XXXXXXXXXX] continue=false
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Regex (PASS) [91XXXXXXXXXX] destination_number(91XXXXXXXXXX) =~ /91XXXXXXXXXX/ break=on-false
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action log(WARNING Accountcode 7724558832. Dialed number (91XXXXXXXXXX) termination rates not found!!)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action playback(/usr/local/freeswitch/sounds/en/us/callie/astpp-badphone.wav)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(error_cdr=1)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(callstart=2016-08-31 18:17:32)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(account_id=4)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(call_direction=outbound)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(sip_ignore_remote_cause=true)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(call_processed=internal)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(effective_destination_number=91XXXXXXXXXX)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action set(last_bridge_hangup_cause=TERMINATION_RATE_NOT_FOUND)
Dialplan: sofia/default/7724558832@XX:XX:XX:XX Action hangup(TERMINATION_RATE_NOT_FOUND)
2016-08-31 18:17:32.340041 [DEBUG] switch_core_state_machine.c:286 (sofia/default/7724558832@XX:XX:XX:XX) State Change CS_ROUTING -> CS_EXECUTE
2016-08-31 18:17:32.340041 [DEBUG] switch_core_state_machine.c:602 (sofia/default/7724558832@XX:XX:XX:XX) State ROUTING going to sleep
2016-08-31 18:17:32.340041 [DEBUG] switch_core_state_machine.c:543 (sofia/default/7724558832@XX:XX:XX:XX) Running State Change CS_EXECUTE
2016-08-31 18:17:32.340041 [DEBUG] switch_core_state_machine.c:609 (sofia/default/7724558832@XX:XX:XX:XX) State EXECUTE
2016-08-31 18:17:32.340041 [DEBUG] mod_sofia.c:197 sofia/default/7724558832@XX:XX:XX:XX SOFIA EXECUTE
2016-08-31 18:17:32.340041 [DEBUG] switch_core_state_machine.c:328 sofia/default/7724558832@XX:XX:XX:XX Standard EXECUTE
EXECUTE sofia/default/7724558832@XX:XX:XX:XX log(WARNING Accountcode 7724558832. Dialed number (91XXXXXXXXXX) termination rates not found!!)
2016-08-31 18:17:32.340041 [WARNING] mod_dptools.c:1713 Accountcode 7724558832. Dialed number (91XXXXXXXXXX) termination rates not found!!
2016-08-31 18:17:32.340041 [DEBUG] switch_core_session.c:2628 Application playback Requires media! pre_answering channel sofia/default/7724558832@XX:XX:XX:XX
2016-08-31 18:17:32.340041 [INFO] switch_core_session.c:2630 Sending early media
2016-08-31 18:17:32.340041 [DEBUG] switch_core_media.c:6464 AUDIO RTP [sofia/default/7724558832@XX:XX:XX:XX] XX:XX:XX:XX port 16412 -> XXXXXXXXXX port 44230 codec: 0 ms: 20
2016-08-31 18:17:32.340041 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 160 bytes per 20ms
2016-08-31 18:17:32.340041 [DEBUG] switch_core_media.c:6763 sofia/default/7724558832@XX:XX:XX:XX Set 2833 dtmf send payload to 101
2016-08-31 18:17:32.340041 [DEBUG] switch_core_media.c:6770 sofia/default/7724558832@XX:XX:XX:XX Set 2833 dtmf receive payload to 101
2016-08-31 18:17:32.340041 [DEBUG] switch_core_media.c:6793 sofia/default/7724558832@XX:XX:XX:XX Set rtp dtmf delay to 40
2016-08-31 18:17:32.340041 [DEBUG] mod_sofia.c:2367 Ring SDP:
v=0
o=FreeSWITCH 1472651040 1472651041 IN IP4 XX:XX:XX:XX
s=FreeSWITCH
c=IN IP4 XX:XX:XX:XX
t=0 0
m=audio 16412 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2016-08-31 18:17:32.340041 [NOTICE] mod_sofia.c:2370 Pre-Answer sofia/default/7724558832@XX:XX:XX:XX!
2016-08-31 18:17:32.340041 [DEBUG] switch_channel.c:3471 (sofia/default/7724558832@XX:XX:XX:XX) Callstate Change RINGING -> EARLY
2016-08-31 18:17:32.340041 [DEBUG] sofia.c:6858 Channel sofia/default/7724558832@XX:XX:XX:XX entering state [early][183]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX playback(/usr/local/freeswitch/sounds/en/us/callie/astpp-badphone.wav)
2016-08-31 18:17:32.340041 [DEBUG] switch_core_file.c:330 File /usr/local/freeswitch/sounds/en/us/callie/astpp-badphone.wav sample rate 16000 doesn't match requested rate 8000
2016-08-31 18:17:32.340041 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
2016-08-31 18:17:32.580167 [DEBUG] switch_rtp.c:6707 Correct audio ip/port confirmed.
2016-08-31 18:17:33.780100 [DEBUG] switch_ivr_play_say.c:1910 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-badphone.wav
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(error_cdr=1)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [error_cdr]=[1]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(callstart=2016-08-31 18:17:32)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [callstart]=[2016-08-31 18:17:32]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(account_id=4)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [account_id]=[4]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(call_direction=outbound)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [call_direction]=[outbound]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(sip_ignore_remote_cause=true)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [sip_ignore_remote_cause]=[true]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(call_processed=internal)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [call_processed]=[internal]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(effective_destination_number=91XXXXXXXXXX)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [effective_destination_number]=[91XXXXXXXXXX]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX set(last_bridge_hangup_cause=TERMINATION_RATE_NOT_FOUND)
2016-08-31 18:17:33.780100 [DEBUG] mod_dptools.c:1519 SET sofia/default/7724558832@XX:XX:XX:XX [last_bridge_hangup_cause]=[TERMINATION_RATE_NOT_FOUND]
EXECUTE sofia/default/7724558832@XX:XX:XX:XX hangup(TERMINATION_RATE_NOT_FOUND)
2016-08-31 18:17:33.780100 [NOTICE] mod_dptools.c:1283 Hangup sofia/default/7724558832@XX:XX:XX:XX [CS_EXECUTE] [NORMAL_CLEARING]
2016-08-31 18:17:33.780100 [DEBUG] switch_core_session.c:2796 sofia/default/7724558832@XX:XX:XX:XX skip receive message [PHONE_EVENT|channel is hungup already]
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:609 (sofia/default/7724558832@XX:XX:XX:XX) State EXECUTE going to sleep
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:543 (sofia/default/7724558832@XX:XX:XX:XX) Running State Change CS_HANGUP
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:809 (sofia/default/7724558832@XX:XX:XX:XX) Callstate Change EARLY -> HANGUP
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:811 (sofia/default/7724558832@XX:XX:XX:XX) State HANGUP
2016-08-31 18:17:33.780100 [DEBUG] mod_sofia.c:437 Channel sofia/default/7724558832@XX:XX:XX:XX hanging up, cause: NORMAL_CLEARING
2016-08-31 18:17:33.780100 [DEBUG] mod_sofia.c:574 Responding to INVITE with: 480
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:60 sofia/default/7724558832@XX:XX:XX:XX Standard HANGUP, cause: NORMAL_CLEARING
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:811 (sofia/default/7724558832@XX:XX:XX:XX) State HANGUP going to sleep
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:578 (sofia/default/7724558832@XX:XX:XX:XX) State Change CS_HANGUP -> CS_REPORTING
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:543 (sofia/default/7724558832@XX:XX:XX:XX) Running State Change CS_REPORTING
2016-08-31 18:17:33.780100 [DEBUG] switch_core_state_machine.c:897 (sofia/default/7724558832@XX:XX:XX:XX) State REPORTING
2016-08-31 18:17:33.780100 [INFO] mod_json_cdr.c:271 Process [2ef6be90-6fa7-11e6-b836-f96d931a8344.cdr.json]
2016-08-31 18:17:33.820054 [DEBUG] switch_core_state_machine.c:174 sofia/default/7724558832@XX:XX:XX:XX Standard REPORTING, cause: NORMAL_CLEARING
2016-08-31 18:17:33.820054 [DEBUG] switch_core_state_machine.c:897 (sofia/default/7724558832@XX:XX:XX:XX) State REPORTING going to sleep
2016-08-31 18:17:33.820054 [DEBUG] switch_core_state_machine.c:569 (sofia/default/7724558832@XX:XX:XX:XX) State Change CS_REPORTING -> CS_DESTROY
2016-08-31 18:17:33.820054 [DEBUG] switch_core_session.c:1646 Session 2 (sofia/default/7724558832@XX:XX:XX:XX) Locked, Waiting on external entities
2016-08-31 18:17:33.820054 [NOTICE] switch_core_session.c:1664 Session 2 (sofia/default/7724558832@XX:XX:XX:XX) Ended
2016-08-31 18:17:33.820054 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/7724558832@XX:XX:XX:XX [CS_DESTROY]
2016-08-31 18:17:33.820054 [DEBUG] switch_core_state_machine.c:700 (sofia/default/7724558832@XX:XX:XX:XX) Running State Change CS_DESTROY
2016-08-31 18:17:33.820054 [DEBUG] switch_core_state_machine.c:710 (sofia/default/7724558832@XX:XX:XX:XX) State DESTROY
2016-08-31 18:17:33.820054 [DEBUG] mod_sofia.c:342 sofia/default/7724558832@XX:XX:XX:XX SOFIA DESTROY
2016-08-31 18:17:33.820054 [DEBUG] switch_core_state_machine.c:181 sofia/default/7724558832@XX:XX:XX:XX Standard DESTROY
2016-08-31 18:17:33.820054 [DEBUG] switch_core_state_machine.c:710 (sofia/default/7724558832@XX:XX:XX:XX) State DESTROY going to sleep

 Comments   
Comment by dev-astpp [ 01/Sep/16 ]

Its not a issue I guess.

Please check that trunk (vox_trunk) should be selected in rategroup or not?

If not then select it and call again it should be work

Comment by landman16 [ 07/Sep/16 ]

Have you created the rate group and orginating rate as well (remember, just incase it passed you the termination rate (cost to you) must be lower than the orgination rate (selling rate to customer) as this will stop the call from entering whats known as a NORMAL_CLEARING status. If you have done this let me know and i will go to the next thing to help you out.

Regards

Generated at Sat Feb 10 07:14:07 CET 2024 using Jira 8.13.3#813003-sha1:22ebedbb75c99b147c66f14e031dd8a2d214753a.