Phone number not found / WARNING Accountcode XXXXXX. Dialed number (XXXXXXX) origination rates not found!!"/>

833 views
Skip to first unread message

Thiwanka

unread,
May 28, 2015, 3:44:00 AM5/28/15
to as...@googlegroups.com
Hello,

I have installed ASTPP using automate script, created a SIP profile with a Gateway and was able to successfully register.  When i try to make a test call to a external number it says Phone number not found, i have barely idea about how dialplans work on freeswitch, did some changes with dialplans but didn't help, below what i found on ASTPP logs

Something i noticed: WARNING Accountcode 8919667053. Dialed number (0112781725) origination rates not found!!"/>



[2015-05-28 13:08:06] hostname freeswitch.techseized.lk
[2015-05-28 13:08:06] section directory
[2015-05-28 13:08:06] tag_name domain
[2015-05-28 13:08:06] key_name name
[2015-05-28 13:08:06] key_value 172.20.0.46
[2015-05-28 13:08:06] Event-Name REQUEST_PARAMS
[2015-05-28 13:08:06] Core-UUID ad1e3b58-050a-11e5-9f29-c34fb654b0f3
[2015-05-28 13:08:06] FreeSWITCH-Hostname freeswitch.techseized.lk
[2015-05-28 13:08:06] FreeSWITCH-Switchname freeswitch.techseized.lk
[2015-05-28 13:08:06] FreeSWITCH-IPv4 172.20.0.46
[2015-05-28 13:08:06] FreeSWITCH-IPv6 ::1
[2015-05-28 13:08:06] Event-Date-Local 2015-05-28 13:08:06
[2015-05-28 13:08:06] Event-Date-GMT Thu, 28 May 2015 07:38:06 GMT
[2015-05-28 13:08:06] Event-Date-Timestamp 1432798686101167
[2015-05-28 13:08:06] Event-Calling-File sofia_reg.c
[2015-05-28 13:08:06] Event-Calling-Function sofia_reg_parse_auth
[2015-05-28 13:08:06] Event-Calling-Line-Number 2741
[2015-05-28 13:08:06] Event-Sequence 581
[2015-05-28 13:08:06] action sip_auth
[2015-05-28 13:08:06] sip_profile internal
[2015-05-28 13:08:06] sip_user_agent Bria Professional release 2.4 stamp 49381
[2015-05-28 13:08:06] sip_auth_username 8919667053
[2015-05-28 13:08:06] sip_auth_realm 172.20.0.46
[2015-05-28 13:08:06] sip_auth_nonce 7ab19cc6-050c-11e5-9f58-c34fb654b0f3
[2015-05-28 13:08:06] sip_auth_uri sip:01127...@172.20.0.46
[2015-05-28 13:08:06] sip_contact_user 8919667053
[2015-05-28 13:08:06] sip_contact_host 172.20.2.1
[2015-05-28 13:08:06] sip_to_user 0112781725
[2015-05-28 13:08:06] sip_to_host 172.20.0.46
[2015-05-28 13:08:06] sip_via_protocol udp
[2015-05-28 13:08:06] sip_from_user 8919667053
[2015-05-28 13:08:06] sip_from_host 172.20.0.46
[2015-05-28 13:08:06] sip_call_id ZjU1ZjNlNGQxYTAyMjRiOTg3OGUzOWNhYmJjMmVhYzE.
[2015-05-28 13:08:06] sip_request_user 0112781725
[2015-05-28 13:08:06] sip_request_host 172.20.0.46
[2015-05-28 13:08:06] sip_auth_qop auth
[2015-05-28 13:08:06] sip_auth_cnonce 9972fc5b775c4e7d9a9fbd33deaa5b46
[2015-05-28 13:08:06] sip_auth_nc 00000001
[2015-05-28 13:08:06] sip_auth_response 3cdc15f9a86373bb888e57c0f3bc3d74
[2015-05-28 13:08:06] sip_auth_method INVITE
[2015-05-28 13:08:06] client_port 51978
[2015-05-28 13:08:06] key id
[2015-05-28 13:08:06] user 8919667053
[2015-05-28 13:08:06] domain 172.20.0.46
[2015-05-28 13:08:06] ip 172.20.2.1
[2015-05-28 13:08:06] SELECT username,dir_params,dir_vars,number as accountcode,accountid FROM sip_devices,accounts WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND username='8919667053'
[2015-05-28 13:08:06] Content-Type: text/plain; charset=ISO-8859-1

<?xml version="1.0"?>
<document type="freeswitch/xml">
<section name="Directory" description="Directory">
<domain name="172.20.0.46">
<user id="8919667053">
<params>
<param name="password" value="123456"/>
<param name="allow-empty-password" value="false"/>
<param name="domain_name" value="172.20.0.46"/>
<param name="dial-string" value="{sip_invite_domain=${domain_name},presence_id=${dialed_user}@${domain_name}}${sofia_contact(*/${dialed_user}@${domain_name})}"/>
</params>
<variables>
<variable name="effective_caller_id_name" value="8919667053"/>
<variable name="effective_caller_id_number" value="8919667053"/>
<variable name="accountcode" value="8919667053"/>
<variable name="account_id" value="4"/>
</variables>
</user>
</domain>
</section>
</document>

[2015-05-28 13:08:06] hostname freeswitch.techseized.lk
[2015-05-28 13:08:06] section dialplan
[2015-05-28 13:08:06] tag_name
[2015-05-28 13:08:06] key_name
[2015-05-28 13:08:06] key_value
[2015-05-28 13:08:06] Event-Name REQUEST_PARAMS
[2015-05-28 13:08:06] Core-UUID ad1e3b58-050a-11e5-9f29-c34fb654b0f3
[2015-05-28 13:08:06] FreeSWITCH-Hostname freeswitch.techseized.lk
[2015-05-28 13:08:06] FreeSWITCH-Switchname freeswitch.techseized.lk
[2015-05-28 13:08:06] FreeSWITCH-IPv4 172.20.0.46
[2015-05-28 13:08:06] FreeSWITCH-IPv6 ::1
[2015-05-28 13:08:06] Event-Date-Local 2015-05-28 13:08:06
[2015-05-28 13:08:06] Event-Date-GMT Thu, 28 May 2015 07:38:06 GMT
[2015-05-28 13:08:06] Event-Date-Timestamp 1432798686181142
[2015-05-28 13:08:06] Event-Calling-File mod_dialplan_xml.c
[2015-05-28 13:08:06] Event-Calling-Function dialplan_xml_locate
[2015-05-28 13:08:06] Event-Calling-Line-Number 606
[2015-05-28 13:08:06] Event-Sequence 587
[2015-05-28 13:08:06] Channel-State CS_ROUTING
[2015-05-28 13:08:06] Channel-Call-State RINGING
[2015-05-28 13:08:06] Channel-State-Number 2
[2015-05-28 13:08:06] Channel-Name sofia/internal/89196...@172.20.0.46
[2015-05-28 13:08:06] Unique-ID 7ab18f6a-050c-11e5-9f57-c34fb654b0f3
[2015-05-28 13:08:06] Call-Direction inbound
[2015-05-28 13:08:06] Presence-Call-Direction inbound
[2015-05-28 13:08:06] Channel-HIT-Dialplan true
[2015-05-28 13:08:06] Channel-Presence-ID 89196...@172.20.0.46
[2015-05-28 13:08:06] Channel-Call-UUID 7ab18f6a-050c-11e5-9f57-c34fb654b0f3
[2015-05-28 13:08:06] Answer-State ringing
[2015-05-28 13:08:06] Caller-Direction inbound
[2015-05-28 13:08:06] Caller-Logical-Direction inbound
[2015-05-28 13:08:06] Caller-Username 8919667053
[2015-05-28 13:08:06] Caller-Dialplan XML
[2015-05-28 13:08:06] Caller-Caller-ID-Name 8919667053
[2015-05-28 13:08:06] Caller-Caller-ID-Number 8919667053
[2015-05-28 13:08:06] Caller-Orig-Caller-ID-Name 8919667053
[2015-05-28 13:08:06] Caller-Orig-Caller-ID-Number 8919667053
[2015-05-28 13:08:06] Caller-Network-Addr 172.20.2.1
[2015-05-28 13:08:06] Caller-ANI 8919667053
[2015-05-28 13:08:06] Caller-Destination-Number 0112781725
[2015-05-28 13:08:06] Caller-Unique-ID 7ab18f6a-050c-11e5-9f57-c34fb654b0f3
[2015-05-28 13:08:06] Caller-Source mod_sofia
[2015-05-28 13:08:06] Caller-Context public
[2015-05-28 13:08:06] Caller-Channel-Name sofia/internal/89196...@172.20.0.46
[2015-05-28 13:08:06] Caller-Profile-Index 1
[2015-05-28 13:08:06] Caller-Profile-Created-Time 1432798686161151
[2015-05-28 13:08:06] Caller-Channel-Created-Time 1432798686161151
[2015-05-28 13:08:06] Caller-Channel-Answered-Time 0
[2015-05-28 13:08:06] Caller-Channel-Progress-Time 0
[2015-05-28 13:08:06] Caller-Channel-Progress-Media-Time 0
[2015-05-28 13:08:06] Caller-Channel-Hangup-Time 0
[2015-05-28 13:08:06] Caller-Channel-Transfer-Time 0
[2015-05-28 13:08:06] Caller-Channel-Resurrect-Time 0
[2015-05-28 13:08:06] Caller-Channel-Bridged-Time 0
[2015-05-28 13:08:06] Caller-Channel-Last-Hold 0
[2015-05-28 13:08:06] Caller-Channel-Hold-Accum 0
[2015-05-28 13:08:06] Caller-Screen-Bit true
[2015-05-28 13:08:06] Caller-Privacy-Hide-Name false
[2015-05-28 13:08:06] Caller-Privacy-Hide-Number false
[2015-05-28 13:08:06] variable_direction inbound
[2015-05-28 13:08:06] variable_uuid 7ab18f6a-050c-11e5-9f57-c34fb654b0f3
[2015-05-28 13:08:06] variable_session_id 3
[2015-05-28 13:08:06] variable_sip_from_user 8919667053
[2015-05-28 13:08:06] variable_sip_from_uri 89196...@172.20.0.46
[2015-05-28 13:08:06] variable_sip_from_host 172.20.0.46
[2015-05-28 13:08:06] variable_channel_name sofia/internal/89196...@172.20.0.46
[2015-05-28 13:08:06] variable_sip_call_id ZjU1ZjNlNGQxYTAyMjRiOTg3OGUzOWNhYmJjMmVhYzE.
[2015-05-28 13:08:06] variable_ep_codec_string PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b
[2015-05-28 13:08:06] variable_sip_local_network_addr 172.20.0.46
[2015-05-28 13:08:06] variable_sip_network_ip 172.20.2.1
[2015-05-28 13:08:06] variable_sip_network_port 51978
[2015-05-28 13:08:06] variable_sip_received_ip 172.20.2.1
[2015-05-28 13:08:06] variable_sip_received_port 51978
[2015-05-28 13:08:06] variable_sip_via_protocol udp
[2015-05-28 13:08:06] variable_sip_authorized true
[2015-05-28 13:08:06] variable_Event-Name REQUEST_PARAMS
[2015-05-28 13:08:06] variable_Core-UUID ad1e3b58-050a-11e5-9f29-c34fb654b0f3
[2015-05-28 13:08:06] variable_FreeSWITCH-Hostname freeswitch.techseized.lk
[2015-05-28 13:08:06] variable_FreeSWITCH-Switchname freeswitch.techseized.lk
[2015-05-28 13:08:06] variable_FreeSWITCH-IPv4 172.20.0.46
[2015-05-28 13:08:06] variable_FreeSWITCH-IPv6 ::1
[2015-05-28 13:08:06] variable_Event-Date-Local 2015-05-28 13:08:06
[2015-05-28 13:08:06] variable_Event-Date-GMT Thu, 28 May 2015 07:38:06 GMT
[2015-05-28 13:08:06] variable_Event-Date-Timestamp 1432798686101167
[2015-05-28 13:08:06] variable_Event-Calling-File sofia.c
[2015-05-28 13:08:06] variable_Event-Calling-Function sofia_handle_sip_i_invite
[2015-05-28 13:08:06] variable_Event-Calling-Line-Number 9056
[2015-05-28 13:08:06] variable_Event-Sequence 580
[2015-05-28 13:08:06] variable_sip_number_alias 8919667053
[2015-05-28 13:08:06] variable_sip_auth_username 8919667053
[2015-05-28 13:08:06] variable_sip_auth_realm 172.20.0.46
[2015-05-28 13:08:06] variable_number_alias 8919667053
[2015-05-28 13:08:06] variable_requested_domain_name 172.20.0.46
[2015-05-28 13:08:06] variable_effective_caller_id_name 8919667053
[2015-05-28 13:08:06] variable_effective_caller_id_number 8919667053
[2015-05-28 13:08:06] variable_accountcode 8919667053
[2015-05-28 13:08:06] variable_account_id 4
[2015-05-28 13:08:06] variable_user_name 8919667053
[2015-05-28 13:08:06] variable_domain_name 172.20.0.46
[2015-05-28 13:08:06] variable_sip_from_user_stripped 8919667053
[2015-05-28 13:08:06] variable_sip_from_tag df0f3b74
[2015-05-28 13:08:06] variable_sofia_profile_name internal
[2015-05-28 13:08:06] variable_recovery_profile_name internal
[2015-05-28 13:08:06] variable_sip_full_via SIP/2.0/UDP 172.20.2.1:51978;branch=z9hG4bK-d8754z-a5076a5a1b7dba33-1---d8754z-;rport=51978
[2015-05-28 13:08:06] variable_sip_full_from <sip:89196...@172.20.0.46>;tag=df0f3b74
[2015-05-28 13:08:06] variable_sip_full_to <sip:01127...@172.20.0.46>
[2015-05-28 13:08:06] variable_sip_req_user 0112781725
[2015-05-28 13:08:06] variable_sip_req_uri 01127...@172.20.0.46
[2015-05-28 13:08:06] variable_sip_req_host 172.20.0.46
[2015-05-28 13:08:06] variable_sip_to_user 0112781725
[2015-05-28 13:08:06] variable_sip_to_uri 01127...@172.20.0.46
[2015-05-28 13:08:06] variable_sip_to_host 172.20.0.46
[2015-05-28 13:08:06] variable_sip_contact_user 8919667053
[2015-05-28 13:08:06] variable_sip_contact_port 51978
[2015-05-28 13:08:06] variable_sip_contact_uri 89196...@172.20.2.1:51978
[2015-05-28 13:08:06] variable_sip_contact_host 172.20.2.1
[2015-05-28 13:08:06] variable_rtp_use_codec_string OPUS,G722,PCMU,PCMA,GSM
[2015-05-28 13:08:06] variable_sip_user_agent Bria Professional release 2.4 stamp 49381
[2015-05-28 13:08:06] variable_sip_via_host 172.20.2.1
[2015-05-28 13:08:06] variable_sip_via_port 51978
[2015-05-28 13:08:06] variable_sip_via_rport 51978
[2015-05-28 13:08:06] variable_max_forwards 70
[2015-05-28 13:08:06] variable_presence_id 89196...@172.20.0.46
[2015-05-28 13:08:06] variable_switch_r_sdp v=0
o=- 9 2 IN IP4 172.20.2.1
s=CounterPath Bria Professional
c=IN IP4 172.20.2.1
t=0 0
m=audio 22428 RTP/AVP 107 119 100 106 0 98 8 18 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:98 iLBC/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : yQOgQClX Far56kPK 172.20.2.1 22428
a=x-rtp-session-id:8E76191DEB184329BD3881A64F8593B6

[2015-05-28 13:08:06] variable_endpoint_disposition DELAYED NEGOTIATION
[2015-05-28 13:08:06] variable_call_uuid 7ab18f6a-050c-11e5-9f57-c34fb654b0f3
[2015-05-28 13:08:06] Hunt-Direction inbound
[2015-05-28 13:08:06] Hunt-Logical-Direction inbound
[2015-05-28 13:08:06] Hunt-Username 8919667053
[2015-05-28 13:08:06] Hunt-Dialplan XML
[2015-05-28 13:08:06] Hunt-Caller-ID-Name 8919667053
[2015-05-28 13:08:06] Hunt-Caller-ID-Number 8919667053
[2015-05-28 13:08:06] Hunt-Orig-Caller-ID-Name 8919667053
[2015-05-28 13:08:06] Hunt-Orig-Caller-ID-Number 8919667053
[2015-05-28 13:08:06] Hunt-Network-Addr 172.20.2.1
[2015-05-28 13:08:06] Hunt-ANI 8919667053
[2015-05-28 13:08:06] Hunt-Destination-Number 0112781725
[2015-05-28 13:08:06] Hunt-Unique-ID 7ab18f6a-050c-11e5-9f57-c34fb654b0f3
[2015-05-28 13:08:06] Hunt-Source mod_sofia
[2015-05-28 13:08:06] Hunt-Context public
[2015-05-28 13:08:06] Hunt-Channel-Name sofia/internal/89196...@172.20.0.46
[2015-05-28 13:08:06] Hunt-Profile-Index 1
[2015-05-28 13:08:06] Hunt-Profile-Created-Time 1432798686161151
[2015-05-28 13:08:06] Hunt-Channel-Created-Time 1432798686161151
[2015-05-28 13:08:06] Hunt-Channel-Answered-Time 0
[2015-05-28 13:08:06] Hunt-Channel-Progress-Time 0
[2015-05-28 13:08:06] Hunt-Channel-Progress-Media-Time 0
[2015-05-28 13:08:06] Hunt-Channel-Hangup-Time 0
[2015-05-28 13:08:06] Hunt-Channel-Transfer-Time 0
[2015-05-28 13:08:06] Hunt-Channel-Resurrect-Time 0
[2015-05-28 13:08:06] Hunt-Channel-Bridged-Time 0
[2015-05-28 13:08:06] Hunt-Channel-Last-Hold 0
[2015-05-28 13:08:06] Hunt-Channel-Hold-Accum 0
[2015-05-28 13:08:06] Hunt-Screen-Bit true
[2015-05-28 13:08:06] Hunt-Privacy-Hide-Name false
[2015-05-28 13:08:06] Hunt-Privacy-Hide-Number false
[2015-05-28 13:08:06] DID SQL : SELECT B.id,B.id,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 FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number = '0112781725'
[2015-05-28 13:08:06] Get Account SQL : SELECT * FROM accounts WHERE number = '8919667053' AND status = 0 AND deleted=0
[2015-05-28 13:08:06] [Customer info] : [Account code: 8919667053, Rategroup Id: 2, Called number: 0112781725]
[2015-05-28 13:08:06] Block Prefixes SQL : SELECT * from block_patterns WHERE ((blocked_patterns='^0112781725.*' OR blocked_patterns='^011278172.*' OR blocked_patterns='^01127817.*' OR blocked_patterns='^0112781.*' OR blocked_patterns='^011278.*' OR blocked_patterns='^01127.*' OR blocked_patterns='^0112.*' OR blocked_patterns='^011.*' OR blocked_patterns='^01.*' OR blocked_patterns='^0.*' OR blocked_patterns='^defaultprefix.*')) AND accountid = 4 limit 1
[2015-05-28 13:08:06] Rate group SQL : select * from pricelists WHERE id = 2 AND status = 0
[2015-05-28 13:08:06] Origination Rates SQL : SELECT * FROM routes WHERE ((pattern='^0112781725.*' OR pattern='^011278172.*' OR pattern='^01127817.*' OR pattern='^0112781.*' OR pattern='^011278.*' OR pattern='^01127.*' OR pattern='^0112.*' OR pattern='^011.*' OR pattern='^01.*' OR pattern='^0.*' OR pattern='^defaultprefix.*')) AND status = 0 AND pricelist_id = 2 ORDER BY LENGTH(pattern) DESC,cost DESC LIMIT 1
[2015-05-28 13:08:06] Content-Type: text/plain; charset=ISO-8859-1

<?xml version="1.0"?>
<document type="freeswitch/xml">
<section name="dialplan" description="Dialplan">
<context name="public">
<extension name=\"0112781725">
<condition field="destination_number" expression=\"0112781725">
<action application="set" data="callstart=2015-05-28 07:38:06"/>
<action application="set" data="call_processed=internal"/>
<action application="set" data="originated_destination_number=0112781725"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="log" data="WARNING Accountcode 8919667053. Dialed number (0112781725) origination rates not found!!"/>
<action application="playback" data="/usr/local/freeswitch/sounds/en/us/callie/astpp-badphone.wav"/>
<action application="set" data="process_cdr=false"/>
<action application="hangup" data="CALL_REJECTED"/>
</condition>
</extension>
</context>
</section>
</document>

vps4hire

unread,
May 28, 2015, 4:08:33 AM5/28/15
to as...@googlegroups.com
The number you are dialing does not have a corresponding origination rate. you are dialing  0112781725  can you match that number to any of the rates you are using??
[2015-05-28 13:08:06] sip_auth_uri sip:011...@172.20.0.46
[2015-05-28 13:08:06] variable_sip_full_from <sip:891...@172.20.0.46>;tag=df0f3b74
[2015-05-28 13:08:06] variable_sip_full_to <sip:011...@172.20.0.46>

Thiwanka

unread,
May 28, 2015, 4:16:32 AM5/28/15
to as...@googlegroups.com
Below is my sample origination rates, can you guide me little bit more


Thiwanka

unread,
May 28, 2015, 4:17:22 AM5/28/15
to as...@googlegroups.com

vps4hire

unread,
May 28, 2015, 4:31:44 AM5/28/15
to as...@googlegroups.com
You have 2 rates which are 1 and 94. so if you dial 011XXXXXX  that number does not match any of the rates. You can only dial 1XXXXXX  or 94XXXXXXX

Thiwanka

unread,
May 28, 2015, 5:54:20 AM5/28/15
to as...@googlegroups.com
Perfect everything works, now i can route calls through my gateway. Many Thanks Mr.vps4hire,   Highly appreciate for making me understand how these rates works.

megasystema

unread,
Oct 19, 2017, 11:47:38 AM10/19/17
to ASTPP
Hi I have the same issue install ASTPP with the script, and calls are not going our or incoming or using DID I can see on the log the origination rate not found I double check everything reload everything and still the same issue. below is the call log, I double check, origination rate is higher than termination rate, the gateway is connected, trunk assigned to rate groupe and termination rates.

2017-10-19 15:19:06.097044 [NOTICE] switch_channel.c:1104 New Channel sofia/megasystema/53815...@45.33.19.191 [d8cd86ea-b4e0-11e7-b7ff-91a805700b08]
2017-10-19 15:19:06.097044 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/53815...@45.33.19.191) Running State Change CS_NEW (Cur 1 Tot 1)
2017-10-19 15:19:06.097044 [DEBUG] sofia.c:9873 sofia/megasystema/53815...@45.33.19.191 receiving invite from 67.85.92.59:52761 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2017-10-19 15:19:06.097044 [DEBUG] sofia.c:10044 IP 67.85.92.59 Rejected by acl "default". Falling back to Digest auth.
2017-10-19 15:19:06.097044 [DEBUG] sofia.c:2334 detaching session d8cd86ea-b4e0-11e7-b7ff-91a805700b08
2017-10-19 15:19:06.097044 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'megasystema' for [17186...@45.33.19.191] from ip 67.85.92.59
2017-10-19 15:19:06.097044 [DEBUG] switch_core_state_machine.c:603 (sofia/megasystema/53815...@45.33.19.191) State NEW
2017-10-19 15:19:06.437046 [DEBUG] sofia.c:2442 Re-attaching to session d8cd86ea-b4e0-11e7-b7ff-91a805700b08
2017-10-19 15:19:06.457033 [DEBUG] sofia.c:9873 sofia/megasystema/53815...@45.33.19.191 receiving invite from 67.85.92.59:52761 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2017-10-19 15:19:06.457033 [DEBUG] sofia.c:10044 IP 67.85.92.59 Rejected by acl "default". Falling back to Digest auth.
2017-10-19 15:19:06.477033 [DEBUG] sofia.c:7084 Channel sofia/megasystema/53815...@45.33.19.191 entering state [received][100]
2017-10-19 15:19:06.477033 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=Z 0 0 IN IP4 67.85.92.59
s=Z
c=IN IP4 67.85.92.59
t=0 0
m=audio 8000 RTP/AVP 106 9 3 111 0 8 97 110 112 98 101 100 99 102
a=rtpmap:106 opus/48000/2
a=fmtp:106 minptime=20; cbr=1; maxaveragebitrate=40000; useinbandfec=1
a=rtpmap:111 speex/16000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=20
a=rtpmap:110 speex/8000
a=rtpmap:112 speex/32000
a=rtpmap:98 telephone-event/48000
a=fmtp:98 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:100 telephone-event/16000
a=fmtp:100 0-16
a=rtpmap:99 telephone-event/32000
a=fmtp:99 0-16
a=rtpmap:102 G726-32/8000

2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:106:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:106:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:106:48000:20:0:2]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:111:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:111:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:111:16000:20:0:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:30:0:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:110:8000:20:0:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:112:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:112:32000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:112:32000:20:0:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 98@48000
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:102:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:102:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:102:8000:20:0:1]/[G729:18:8000:20:8000:1]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:3061 Set Codec sofia/megasystema/53815...@45.33.19.191 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-10-19 15:19:06.477033 [DEBUG] switch_core_codec.c:111 sofia/megasystema/53815...@45.33.19.191 Original read codec set to PCMU:0
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4767 sofia/megasystema/53815...@45.33.19.191 Set 2833 dtmf send payload to 101 recv payload to 101
2017-10-19 15:19:06.477033 [DEBUG] sofia.c:7507 (sofia/megasystema/53815...@45.33.19.191) State Change CS_NEW -> CS_INIT
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/53815...@45.33.19.191) Running State Change CS_INIT (Cur 1 Tot 1)
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:627 (sofia/megasystema/53815...@45.33.19.191) State INIT
2017-10-19 15:19:06.477033 [DEBUG] mod_sofia.c:90 sofia/megasystema/53815...@45.33.19.191 SOFIA INIT
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:40 sofia/megasystema/53815...@45.33.19.191 Standard INIT
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:48 (sofia/megasystema/53815...@45.33.19.191) State Change CS_INIT -> CS_ROUTING
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:627 (sofia/megasystema/53815...@45.33.19.191) State INIT going to sleep
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/53815...@45.33.19.191) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-10-19 15:19:06.477033 [DEBUG] switch_channel.c:2249 (sofia/megasystema/53815...@45.33.19.191) Callstate Change DOWN -> RINGING
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:643 (sofia/megasystema/53815...@45.33.19.191) State ROUTING
2017-10-19 15:19:06.477033 [DEBUG] mod_sofia.c:143 sofia/megasystema/53815...@45.33.19.191 SOFIA ROUTING
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:236 sofia/megasystema/53815...@45.33.19.191 Standard ROUTING
2017-10-19 15:19:06.477033 [INFO] mod_dialplan_xml.c:637 Processing 5381516526 <5381516526>->17186173500 in context default
2017-10-19 15:19:06.497031 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fc1a0070520 Connected.
2017-10-19 15:19:06.497031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2017-10-19 15:19:06.497031 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17186173500
2017-10-19 15:19:06.497031 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number  : 5381516526 / 5381516526
2017-10-19 15:19:06.497031 [DEBUG] switch_cpp.cpp:1365 [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 ="17186173500" LIMIT 1
2017-10-19 15:19:06.517035 [DEBUG] switch_cpp.cpp:1365 [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="17186173500" limit 1
2017-10-19 15:19:06.517035 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : outbound
2017-10-19 15:19:06.517035 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 5617957161]
2017-10-19 15:19:06.517035 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "5617957161" OR id="5617957161") AND status=0 AND deleted=0 AND (expiry >= '2017-10-19 15:19:06' OR expiry = '0000-00-00 00:00:00') limit 1
2017-10-19 15:19:06.637470 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns ='^17186173500.*' OR blocked_patterns ='^1718617350.*' OR blocked_patterns ='^171861735.*' OR blocked_patterns ='^17186173.*' OR blocked_patterns ='^1718617.*' OR blocked_patterns ='^171861.*' OR blocked_patterns ='^17186.*' OR blocked_patterns ='^1718.*' OR blocked_patterns ='^171.*' OR blocked_patterns ='^17.*' OR blocked_patterns ='^1.*' OR blocked_patterns ='--') AND accountid = 4 limit 1
2017-10-19 15:19:06.637470 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT * FROM packages  as P inner join package_patterns as PKGPTR on P.id = PKGPTR.package_id WHERE (patterns ='^17186173500.*' OR patterns ='^1718617350.*' OR patterns ='^171861735.*' OR patterns ='^17186173.*' OR patterns ='^1718617.*' OR patterns ='^171861.*' OR patterns ='^17186.*' OR patterns ='^1718.*' OR patterns ='^171.*' OR patterns ='^17.*' OR patterns ='^1.*' OR patterns ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 4
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 5617957161
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 50000
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 1
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
2017-10-19 15:19:06.637470 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
2017-10-19 15:19:06.637470 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Rate group not found or Inactive!!!
2017-10-19 15:19:06.637470 [DEBUG] switch_cpp.cpp:1365 [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="17186173500">
<condition field="destination_number" expression="17186173500">
<action application="log" data="WARNING Accountcode 5617957161. Dialed number (17186173500)  origination rates not found!!"/>
<action application="set" data="original_caller_id_name=5381516526"/>
<action application="set" data="original_caller_id_number=5381516526"/>
<action application="set" data="error_cdr=1"/>
<action application="set" data="callstart=2017-10-19 15:19:06"/>
<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=17186173500"/>
<action application="set" data="last_bridge_hangup_cause=ORIGNATION_RATE_NOT_FOUND"/>
<action application="hangup" data="ORIGNATION_RATE_NOT_FOUND"/>
</condition>
</extension>
</context>
</section>
</document>
2017-10-19 15:19:06.637470 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fc1a0070520 released.
Dialplan: sofia/megasystema/53815...@45.33.19.191 parsing [default->17186173500] continue=false
Dialplan: sofia/megasystema/53815...@45.33.19.191 Regex (PASS) [17186173500] destination_number(17186173500) =~ /17186173500/ break=on-false
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action log(WARNING Accountcode 5617957161. Dialed number (17186173500)  origination rates not found!!)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(original_caller_id_name=5381516526)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(original_caller_id_number=5381516526)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(error_cdr=1)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(callstart=2017-10-19 15:19:06)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(account_id=4)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(call_direction=outbound)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(sip_ignore_remote_cause=true)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(call_processed=internal)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(effective_destination_number=17186173500)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action set(last_bridge_hangup_cause=ORIGNATION_RATE_NOT_FOUND)
Dialplan: sofia/megasystema/53815...@45.33.19.191 Action hangup(ORIGNATION_RATE_NOT_FOUND)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:286 (sofia/megasystema/53815...@45.33.19.191) State Change CS_ROUTING -> CS_EXECUTE
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:643 (sofia/megasystema/53815...@45.33.19.191) State ROUTING going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/53815...@45.33.19.191) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:650 (sofia/megasystema/53815...@45.33.19.191) State EXECUTE
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:198 sofia/megasystema/53815...@45.33.19.191 SOFIA EXECUTE
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:328 sofia/megasystema/53815...@45.33.19.191 Standard EXECUTE
EXECUTE sofia/megasystema/53815...@45.33.19.191 log(WARNING Accountcode 5617957161. Dialed number (17186173500)  origination rates not found!!)
2017-10-19 15:19:06.637470 [WARNING] mod_dptools.c:1742 Accountcode 5617957161. Dialed number (17186173500)  origination rates not found!!
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(original_caller_id_name=5381516526)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [original_caller_id_name]=[5381516526]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(original_caller_id_number=5381516526)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [original_caller_id_number]=[5381516526]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(error_cdr=1)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [error_cdr]=[1]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(callstart=2017-10-19 15:19:06)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [callstart]=[2017-10-19 15:19:06]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(account_id=4)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [account_id]=[4]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(call_direction=outbound)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [call_direction]=[outbound]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(sip_ignore_remote_cause=true)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [sip_ignore_remote_cause]=[true]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(call_processed=internal)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [call_processed]=[internal]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(effective_destination_number=17186173500)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [effective_destination_number]=[17186173500]
EXECUTE sofia/megasystema/53815...@45.33.19.191 set(last_bridge_hangup_cause=ORIGNATION_RATE_NOT_FOUND)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/53815...@45.33.19.191 [last_bridge_hangup_cause]=[ORIGNATION_RATE_NOT_FOUND]
EXECUTE sofia/megasystema/53815...@45.33.19.191 hangup(ORIGNATION_RATE_NOT_FOUND)
2017-10-19 15:19:06.637470 [NOTICE] mod_dptools.c:1286 Hangup sofia/megasystema/53815...@45.33.19.191 [CS_EXECUTE] [NORMAL_CLEARING]
2017-10-19 15:19:06.637470 [DEBUG] switch_core_session.c:2815 sofia/megasystema/53815...@45.33.19.191 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:650 (sofia/megasystema/53815...@45.33.19.191) State EXECUTE going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/53815...@45.33.19.191) Running State Change CS_HANGUP (Cur 1 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:850 (sofia/megasystema/53815...@45.33.19.191) Callstate Change RINGING -> HANGUP
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:852 (sofia/megasystema/53815...@45.33.19.191) State HANGUP
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:438 Channel sofia/megasystema/53815...@45.33.19.191 hanging up, cause: NORMAL_CLEARING
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:60 sofia/megasystema/53815...@45.33.19.191 Standard HANGUP, cause: NORMAL_CLEARING
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:852 (sofia/megasystema/53815...@45.33.19.191) State HANGUP going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:619 (sofia/megasystema/53815...@45.33.19.191) State Change CS_HANGUP -> CS_REPORTING
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/53815...@45.33.19.191) Running State Change CS_REPORTING (Cur 1 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:938 (sofia/megasystema/53815...@45.33.19.191) State REPORTING
2017-10-19 15:19:06.637470 [INFO] mod_json_cdr.c:271 Process [d8cd86ea-b4e0-11e7-b7ff-91a805700b08.cdr.json]
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:174 sofia/megasystema/53815...@45.33.19.191 Standard REPORTING, cause: NORMAL_CLEARING
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:938 (sofia/megasystema/53815...@45.33.19.191) State REPORTING going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:610 (sofia/megasystema/53815...@45.33.19.191) State Change CS_REPORTING -> CS_DESTROY
2017-10-19 15:19:06.637470 [DEBUG] switch_core_session.c:1665 Session 1 (sofia/megasystema/53815...@45.33.19.191) Locked, Waiting on external entities
2017-10-19 15:19:06.637470 [NOTICE] switch_core_session.c:1683 Session 1 (sofia/megasystema/53815...@45.33.19.191) Ended
2017-10-19 15:19:06.637470 [NOTICE] switch_core_session.c:1687 Close Channel sofia/megasystema/53815...@45.33.19.191 [CS_DESTROY]
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:741 (sofia/megasystema/53815...@45.33.19.191) Running State Change CS_DESTROY (Cur 0 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:751 (sofia/megasystema/53815...@45.33.19.191) State DESTROY
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:343 sofia/megasystema/53815...@45.33.19.191 SOFIA DESTROY
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:181 sofia/megasystema/53815...@45.33.19.191 Standard DESTROY
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:751 (sofia/megasystema/53815...@45.33.19.191) State DESTROY going to sleep



Devang Nathwani

unread,
Oct 20, 2017, 2:22:37 AM10/20/17
to as...@googlegroups.com
Hi,

 =============== Account Information ===================
2017-10-19 15:19:06.637470 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 1
 ========================================================
2017-10-19 15:19:06.637470 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
2017-10-19 15:19:06.637470 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Rate group not found or Inactive!!!

Please check the rategroup status for id =1.

On Thu, Oct 19, 2017 at 9:17 PM, megasystema <pop...@gmail.com> wrote:
Hi I have the same issue install ASTPP with the script, and calls are not going our or incoming or using DID I can see on the log the origination rate not found I double check everything reload everything and still the same issue. below is the call log, I double check, origination rate is higher than termination rate, the gateway is connected, trunk assigned to rate groupe and termination rates.

2017-10-19 15:19:06.097044 [NOTICE] switch_channel.c:1104 New Channel sofia/megasystema/5381516526@45.33.19.191 [d8cd86ea-b4e0-11e7-b7ff-91a805700b08]
2017-10-19 15:19:06.097044 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/5381516526@45.33.19.191) Running State Change CS_NEW (Cur 1 Tot 1)
2017-10-19 15:19:06.097044 [DEBUG] sofia.c:9873 sofia/megasystema/5381516526@45.33.19.191 receiving invite from 67.85.92.59:52761 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2017-10-19 15:19:06.097044 [DEBUG] sofia.c:10044 IP 67.85.92.59 Rejected by acl "default". Falling back to Digest auth.
2017-10-19 15:19:06.097044 [DEBUG] sofia.c:2334 detaching session d8cd86ea-b4e0-11e7-b7ff-91a805700b08
2017-10-19 15:19:06.097044 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'megasystema' for [17186...@45.33.19.191] from ip 67.85.92.59
2017-10-19 15:19:06.097044 [DEBUG] switch_core_state_machine.c:603 (sofia/megasystema/5381516526@45.33.19.191) State NEW
2017-10-19 15:19:06.437046 [DEBUG] sofia.c:2442 Re-attaching to session d8cd86ea-b4e0-11e7-b7ff-91a805700b08
2017-10-19 15:19:06.457033 [DEBUG] sofia.c:9873 sofia/megasystema/5381516526@45.33.19.191 receiving invite from 67.85.92.59:52761 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2017-10-19 15:19:06.457033 [DEBUG] sofia.c:10044 IP 67.85.92.59 Rejected by acl "default". Falling back to Digest auth.
2017-10-19 15:19:06.477033 [DEBUG] sofia.c:7084 Channel sofia/megasystema/5381516526@45.33.19.191 entering state [received][100]
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:3061 Set Codec sofia/megasystema/5381516526@45.33.19.191 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-10-19 15:19:06.477033 [DEBUG] switch_core_codec.c:111 sofia/megasystema/5381516526@45.33.19.191 Original read codec set to PCMU:0
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2017-10-19 15:19:06.477033 [DEBUG] switch_core_media.c:4767 sofia/megasystema/5381516526@45.33.19.191 Set 2833 dtmf send payload to 101 recv payload to 101
2017-10-19 15:19:06.477033 [DEBUG] sofia.c:7507 (sofia/megasystema/5381516526@45.33.19.191) State Change CS_NEW -> CS_INIT
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/5381516526@45.33.19.191) Running State Change CS_INIT (Cur 1 Tot 1)
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:627 (sofia/megasystema/5381516526@45.33.19.191) State INIT
2017-10-19 15:19:06.477033 [DEBUG] mod_sofia.c:90 sofia/megasystema/5381516526@45.33.19.191 SOFIA INIT
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:40 sofia/megasystema/5381516526@45.33.19.191 Standard INIT
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:48 (sofia/megasystema/5381516526@45.33.19.191) State Change CS_INIT -> CS_ROUTING
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:627 (sofia/megasystema/5381516526@45.33.19.191) State INIT going to sleep
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/5381516526@45.33.19.191) Running State Change CS_ROUTING (Cur 1 Tot 1)
2017-10-19 15:19:06.477033 [DEBUG] switch_channel.c:2249 (sofia/megasystema/5381516526@45.33.19.191) Callstate Change DOWN -> RINGING
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:643 (sofia/megasystema/5381516526@45.33.19.191) State ROUTING
2017-10-19 15:19:06.477033 [DEBUG] mod_sofia.c:143 sofia/megasystema/5381516526@45.33.19.191 SOFIA ROUTING
2017-10-19 15:19:06.477033 [DEBUG] switch_core_state_machine.c:236 sofia/megasystema/5381516526@45.33.19.191 Standard ROUTING
Dialplan: sofia/megasystema/5381516526@45.33.19.191 parsing [default->17186173500] continue=false
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Regex (PASS) [17186173500] destination_number(17186173500) =~ /17186173500/ break=on-false
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action log(WARNING Accountcode 5617957161. Dialed number (17186173500)  origination rates not found!!)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(original_caller_id_name=5381516526)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(original_caller_id_number=5381516526)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(error_cdr=1)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(callstart=2017-10-19 15:19:06)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(account_id=4)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(call_direction=outbound)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(sip_ignore_remote_cause=true)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(call_processed=internal)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(effective_destination_number=17186173500)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action set(last_bridge_hangup_cause=ORIGNATION_RATE_NOT_FOUND)
Dialplan: sofia/megasystema/5381516526@45.33.19.191 Action hangup(ORIGNATION_RATE_NOT_FOUND)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:286 (sofia/megasystema/5381516526@45.33.19.191) State Change CS_ROUTING -> CS_EXECUTE
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:643 (sofia/megasystema/5381516526@45.33.19.191) State ROUTING going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/5381516526@45.33.19.191) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:650 (sofia/megasystema/5381516526@45.33.19.191) State EXECUTE
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:198 sofia/megasystema/5381516526@45.33.19.191 SOFIA EXECUTE
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:328 sofia/megasystema/5381516526@45.33.19.191 Standard EXECUTE
EXECUTE sofia/megasystema/5381516526@45.33.19.191 log(WARNING Accountcode 5617957161. Dialed number (17186173500)  origination rates not found!!)
2017-10-19 15:19:06.637470 [WARNING] mod_dptools.c:1742 Accountcode 5617957161. Dialed number (17186173500)  origination rates not found!!
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(original_caller_id_name=5381516526)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [original_caller_id_name]=[5381516526]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(original_caller_id_number=5381516526)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [original_caller_id_number]=[5381516526]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(error_cdr=1)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [error_cdr]=[1]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(callstart=2017-10-19 15:19:06)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [callstart]=[2017-10-19 15:19:06]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(account_id=4)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [account_id]=[4]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(call_direction=outbound)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [call_direction]=[outbound]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(sip_ignore_remote_cause=true)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [sip_ignore_remote_cause]=[true]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(call_processed=internal)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [call_processed]=[internal]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(effective_destination_number=17186173500)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [effective_destination_number]=[17186173500]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 set(last_bridge_hangup_cause=ORIGNATION_RATE_NOT_FOUND)
2017-10-19 15:19:06.637470 [DEBUG] mod_dptools.c:1548 SET sofia/megasystema/5381516526@45.33.19.191 [last_bridge_hangup_cause]=[ORIGNATION_RATE_NOT_FOUND]
EXECUTE sofia/megasystema/5381516526@45.33.19.191 hangup(ORIGNATION_RATE_NOT_FOUND)
2017-10-19 15:19:06.637470 [NOTICE] mod_dptools.c:1286 Hangup sofia/megasystema/5381516526@45.33.19.191 [CS_EXECUTE] [NORMAL_CLEARING]
2017-10-19 15:19:06.637470 [DEBUG] switch_core_session.c:2815 sofia/megasystema/5381516526@45.33.19.191 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:650 (sofia/megasystema/5381516526@45.33.19.191) State EXECUTE going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/5381516526@45.33.19.191) Running State Change CS_HANGUP (Cur 1 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:850 (sofia/megasystema/5381516526@45.33.19.191) Callstate Change RINGING -> HANGUP
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:852 (sofia/megasystema/5381516526@45.33.19.191) State HANGUP
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:438 Channel sofia/megasystema/5381516526@45.33.19.191 hanging up, cause: NORMAL_CLEARING
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:60 sofia/megasystema/5381516526@45.33.19.191 Standard HANGUP, cause: NORMAL_CLEARING
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:852 (sofia/megasystema/5381516526@45.33.19.191) State HANGUP going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:619 (sofia/megasystema/5381516526@45.33.19.191) State Change CS_HANGUP -> CS_REPORTING
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:584 (sofia/megasystema/5381516526@45.33.19.191) Running State Change CS_REPORTING (Cur 1 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:938 (sofia/megasystema/5381516526@45.33.19.191) State REPORTING
2017-10-19 15:19:06.637470 [INFO] mod_json_cdr.c:271 Process [d8cd86ea-b4e0-11e7-b7ff-91a805700b08.cdr.json]
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:174 sofia/megasystema/5381516526@45.33.19.191 Standard REPORTING, cause: NORMAL_CLEARING
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:938 (sofia/megasystema/5381516526@45.33.19.191) State REPORTING going to sleep
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:610 (sofia/megasystema/5381516526@45.33.19.191) State Change CS_REPORTING -> CS_DESTROY
2017-10-19 15:19:06.637470 [DEBUG] switch_core_session.c:1665 Session 1 (sofia/megasystema/5381516526@45.33.19.191) Locked, Waiting on external entities
2017-10-19 15:19:06.637470 [NOTICE] switch_core_session.c:1683 Session 1 (sofia/megasystema/5381516526@45.33.19.191) Ended
2017-10-19 15:19:06.637470 [NOTICE] switch_core_session.c:1687 Close Channel sofia/megasystema/5381516526@45.33.19.191 [CS_DESTROY]
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:741 (sofia/megasystema/5381516526@45.33.19.191) Running State Change CS_DESTROY (Cur 0 Tot 1)
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:751 (sofia/megasystema/5381516526@45.33.19.191) State DESTROY
2017-10-19 15:19:06.637470 [DEBUG] mod_sofia.c:343 sofia/megasystema/5381516526@45.33.19.191 SOFIA DESTROY
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:181 sofia/megasystema/5381516526@45.33.19.191 Standard DESTROY
2017-10-19 15:19:06.637470 [DEBUG] switch_core_state_machine.c:751 (sofia/megasystema/5381516526@45.33.19.191) State DESTROY going to sleep



--
=====================================================================
Documentation : https://astppdoc.atlassian.net/
Please contact at sa...@inextrix.com for commercial support.
---
You received this message because you are subscribed to the Google Groups "ASTPP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to astpp+unsubscribe@googlegroups.com.
To post to this group, send email to as...@googlegroups.com.
Visit this group at https://groups.google.com/group/astpp.
To view this discussion on the web visit https://groups.google.com/d/msgid/astpp/ac9a8dea-9e36-4cba-b9e8-620d93dc340a%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.



--
Thanks,
Devang Nathwani

Disclaimer:
The information contained in this communication is confidential and may be legally privileged. It is intended solely for the use of the individual or entity to whom it is addressed and others authorized to receive it. If you are not the intended recipient you are hereby notified that any disclosure, copying, distribution or taking action in reliance of the contents of this information is strictly prohibited and may be unlawful. Please notify the sender immediately and destroy all copies of this message and any attachments contained in it.
Reply all
Reply to author
Forward
0 new messages