Type /help <enter> to see a list of commands
[This app Best viewed at 160x60 or more..]
+OK log level [7]
2019-07-04 16:04:55.647066 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [4779206277@pbx3.inexlocal.com] from ip 192.168.1.13
2019-07-04 16:05:05.007055 [NOTICE] switch_channel.c:1104 New Channel sofia/default/8889687188@pbx3.inexlocal.com [62dee30a-9e47-11e9-94fc-2d0e45e4becc]
2019-07-04 16:05:05.007055 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_NEW (Cur 1 Tot 303)
2019-07-04 16:05:05.007055 [DEBUG] sofia.c:9873 sofia/default/8889687188@pbx3.inexlocal.com receiving invite from 192.168.1.151:5062 version: 1.6.20 64bit
2019-07-04 16:05:05.007055 [DEBUG] sofia.c:10044 IP 192.168.1.151 Rejected by acl "default". Falling back to Digest auth.
2019-07-04 16:05:05.007055 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [919724268060@pbx3.inexlocal.com] from ip 192.168.1.151
2019-07-04 16:05:05.007055 [DEBUG] switch_core_state_machine.c:603 (sofia/default/8889687188@pbx3.inexlocal.com) State NEW
2019-07-04 16:05:05.007055 [DEBUG] sofia.c:2334 detaching session 62dee30a-9e47-11e9-94fc-2d0e45e4becc
2019-07-04 16:05:05.067062 [DEBUG] sofia.c:2442 Re-attaching to session 62dee30a-9e47-11e9-94fc-2d0e45e4becc
2019-07-04 16:05:05.067062 [DEBUG] sofia.c:9873 sofia/default/8889687188@pbx3.inexlocal.com receiving invite from 192.168.1.151:5062 version: 1.6.20 64bit
2019-07-04 16:05:05.067062 [DEBUG] sofia.c:10044 IP 192.168.1.151 Rejected by acl "default". Falling back to Digest auth.
2019-07-04 16:05:05.087284 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [received][100]
2019-07-04 16:05:05.087284 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=8889687188 8001 8000 IN IP4 192.168.1.151
s=SIP Call
c=IN IP4 192.168.1.151
t=0 0
m=audio 5036 RTP/AVP 0 8 4 18 9 97 2 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/8889687188@pbx3.inexlocal.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-07-04 16:05:05.087284 [DEBUG] switch_core_codec.c:111 sofia/default/8889687188@pbx3.inexlocal.com Original read codec set to PCMU:0
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4767 sofia/default/8889687188@pbx3.inexlocal.com Set 2833 dtmf send payload to 101 recv payload to 101
2019-07-04 16:05:05.087284 [DEBUG] sofia.c:7507 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_NEW -> CS_INIT
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_INIT (Cur 1 Tot 303)
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:627 (sofia/default/8889687188@pbx3.inexlocal.com) State INIT
2019-07-04 16:05:05.087284 [DEBUG] mod_sofia.c:90 sofia/default/8889687188@pbx3.inexlocal.com SOFIA INIT
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:40 sofia/default/8889687188@pbx3.inexlocal.com Standard INIT
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:48 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_INIT -> CS_ROUTING
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:627 (sofia/default/8889687188@pbx3.inexlocal.com) State INIT going to sleep
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_ROUTING (Cur 1 Tot 303)
2019-07-04 16:05:05.087284 [DEBUG] switch_channel.c:2249 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change DOWN -> RINGING
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:643 (sofia/default/8889687188@pbx3.inexlocal.com) State ROUTING
2019-07-04 16:05:05.087284 [DEBUG] mod_sofia.c:143 sofia/default/8889687188@pbx3.inexlocal.com SOFIA ROUTING
2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:236 sofia/default/8889687188@pbx3.inexlocal.com Standard ROUTING
2019-07-04 16:05:05.087284 [INFO] mod_dialplan_xml.c:637 Processing 8889687188 <8889687188>->919724268060 in context default
2019-07-04 16:05:05.087284 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f6b8805e880 Connected.
2019-07-04 16:05:05.087284 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2019-07-04 16:05:05.087284 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] blind_flag: 0
2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 919724268060
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '919724268060' limit 1
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '919724268060' AND status=0 limit 1
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Functions] [GET_queue_INFO] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = '919724268060' and status=0 LIMIT 1
2019-07-04 16:05:05.127070 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FAXER] in custom Caller ID
2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number : 8889687188 / 8889687188
2019-07-04 16:05:05.127070 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="919724268060" LIMIT 1
2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : inbound
2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 8889687188]
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "8889687188" AND deleted = 0 limit 1
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [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 ="919724268060" AND A.accountid = '415' limit 1
2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 919724268060
2019-07-04 16:05:05.127070 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="919724268060" LIMIT 1
2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] New Call direction : inbound
2019-07-04 16:05:05.127070 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:05.127070 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="919724268060" AND (accountid = 0 OR status = 1) LIMIT 1
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :415
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE (patterns = '^919724268060.*' OR patterns = '^91972426806.*' OR patterns = '^9197242680.*' OR patterns = '^919724268.*' OR patterns = '^91972426.*' OR patterns = '^9197242.*' OR patterns = '^919724.*' OR patterns = '^91972.*' OR patterns = '^9197.*' OR patterns = '^919.*' OR patterns = '^91.*' OR patterns = '^9.*' OR patterns ='--') AND accountid = 415 ORDER BY LENGTH(PKGPTR.patterns) DESC
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '919724268060' OR number = '91972426806' OR number = '9197242680' OR number = '919724268' OR number = '91972426' OR number = '9197242' OR number = '919724' OR number = '91972' OR number = '9197' OR number = '919' OR number = '91' OR number = '9' OR number ='--') OR (number = '919724268060*' OR number = '91972426806*' OR number = '9197242680*' OR number = '919724268*' OR number = '91972426*' OR number = '9197242*' OR number = '919724*' OR number = '91972*' OR number = '9197*' OR number = '919*' OR number = '91*' OR number = '9*' OR number ='--') OR (number = '8889687188' OR number = '888968718' OR number = '88896871' OR number = '8889687' OR number = '888968' OR number = '88896' OR number = '8889' OR number = '888' OR number = '88' OR number = '8' OR number ='--') OR (number = '8889687188*' OR number = '888968718*' OR number = '88896871*' OR number = '8889687*' OR number = '888968*' OR number = '88896*' OR number = '8889*' OR number = '888*' OR number = '88*' OR number = '8*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] Call Barring Status : -1
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '919724268060' OR routing_prefix = '91972426806' OR routing_prefix = '9197242680' OR routing_prefix = '919724268' OR routing_prefix = '91972426' OR routing_prefix = '9197242' OR routing_prefix = '919724' OR routing_prefix = '91972' OR routing_prefix = '9197' OR routing_prefix = '919' OR routing_prefix = '91' OR routing_prefix = '9' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 415
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 8889687188
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 4839.9
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 1 [0:prepaid,1:postpaid]
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 4
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] CID Pool : 0
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :inbound
2019-07-04 16:05:05.147031 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="919724268060" LIMIT 1
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: inbound
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 13095
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 1.50000
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : test Gandhinagar
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
2019-07-04 16:05:05.147031 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] INB_FREE:TRUE
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] free_inbound:0
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 415 AND status=0 LIMIT 1
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE id = "415" AND deleted = 0 limit 1
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :outbound
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^919724268060.*' OR pattern = '^91972426806.*' OR pattern = '^9197242680.*' OR pattern = '^919724268.*' OR pattern = '^91972426.*' OR pattern = '^9197242.*' OR pattern = '^919724.*' OR pattern = '^91972.*' OR pattern = '^9197.*' OR pattern = '^919.*' OR pattern = '^91.*' OR pattern = '^9.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=415) ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: outbound
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 11
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.60000
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : Ahmedabad-Urban
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Trunk ID:
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Routing type:
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
2019-07-04 16:05:05.147031 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML:415
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Userinfo XML:415
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML : 415
2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] maxlength::::::::: 100
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_0
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [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="4779206277" AND domains.domain="pbx3.inexlocal.com" limit 1
2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] [GET_ROUTING_INFO] Query :SELECT * from sip_device_routing WHERE sip_device_id = 460 limit 1
2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer_attended' limit 1
2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer' limit 1
2019-07-04 16:05:05.167246 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] user_domain beforepbx3.inexlocal.com
2019-07-04 16:05:05.167246 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] pickup_group_permission pickup_str
2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [NOTIFY] START:
2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [NOTIFY] Query :SELECT callkit_token,mobile_type FROM dialer_device_info WHERE username='4779206277'
2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [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="4779206277" AND domains.domain="pbx3.inexlocal.com" limit 1
2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] [GET_ROUTING_INFO] Query :SELECT * from sip_device_routing WHERE sip_device_id = 460 limit 1
2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [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="919724268060">
<condition field="destination_number" expression="919724268060">
<action application="set" data="effective_destination_number=919724268060"/>
<action application="set" data="bridge_pre_execute_bleg_app=sched_hangup"/>
<action application="set" data="bridge_pre_execute_bleg_data=+6000 normal_clearing"/>
<action application="set" data="callstart=2019-07-04 10:35:05"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="set" data="continue_on_fail=TRUE"/>
<action application="set" data="account_id=415"/>
<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:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415"/>
<action application="set" data="origination_rates=ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415"/>
<action application="set" data="original_caller_id_name=8889687188"/>
<action application="set" data="original_caller_id_number=8889687188"/>
<action application="set" data="effective_caller_id_name=8889687188"/>
<action application="set" data="effective_caller_id_number=8889687188"/>
<action application="set" data="receiver_accid=415"/>
<action application="export" data="presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID"/>
<action application="export" data="call_type=0"/>
<action application="set" data="calltype=DID-LOCAL"/>
<action application="db" data="insert/pickup_any_group_${callgroup}/4779206277/${uuid}"/>
<action application="set" data="dialed_extension=transfer_call"/>
<action application="export" data="dialed_extension=transfer_call"/>
<action application="bind_meta_app" data="95 b s execute_extension::transfer_call_95 XML default"/>
<action application="bind_meta_app" data="94 b s execute_extension::transfer_call_94 XML default"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="export" data="did_user_domain=pbx3.inexlocal.com"/>
<action application="ring_ready"/>
<action application="sleep" data="5000"/>
<action application="bridge" data="{sip_invite_params=user=LOCAL,sip_from_uri=4779206277@${domain_name}}[leg_timeout=30]user/4779206277@${domain_name}"/>
<action application="set" data="on_busy_flag=1"/>
<action application="set" data="on_busy_destination=0"/>
<action application="set" data="no_answer_flag=1"/>
<action application="set" data="no_answer_destination=0"/>
<action application="set" data="not_register_flag=1"/>
<action application="set" data="not_register_destination=0"/>
<action application="set" data="opensips_flag=1"/>
<action application="set" data="variable_sip_to_host=pbx3.inexlocal.com"/>
<action application="set" data="opensips_domain=127.0.0.1"/>
<action application="set" data="leg_timeout=60"/>
<action application="set" data="userinfo_id=415"/>
<action application="set" data="sip_destination_number=4779206277"/>
<action application="set" data="destination_number=919724268060"/>
<action application="set" data="did_number=919724268060"/>
<action application="lua" data="astpp/lib/pbx/astpp-sipdevice-routing.lua"/>
<condition field="${cond(${user_data 4779206277@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
<action application="answer"/>
<action application="export" data="voicemail_alternate_greet_id=919724268060"/>
<action application="voicemail" data="default $${domain_name} 4779206277"/>
<anti-action application="hangup" data="${originate_disposition}"/>
</condition>
</condition>
</extension>
</context>
</section>
</document>
2019-07-04 16:05:05.167246 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f6b8805e880 released.
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com parsing [default->919724268060] continue=false
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Regex (PASS) [919724268060] destination_number(919724268060) =~ /919724268060/ break=on-false
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_destination_number=919724268060)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_app=sched_hangup)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(callstart=2019-07-04 10:35:05)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(continue_on_fail=TRUE)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(account_id=415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(parent_id=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(entity_id=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_processed=internal)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_direction=inbound)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(accountname=default)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(filename1=astpp.pbx.lua)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(origination_rates_did=ID:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(origination_rates=ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_name=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_number=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_name=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_number=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(receiver_accid=415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(call_type=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(calltype=DID-LOCAL)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action db(insert/pickup_any_group_${callgroup}/4779206277/${uuid})
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(dialed_extension=transfer_call)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(dialed_extension=transfer_call)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(did_user_domain=pbx3.inexlocal.com)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action ring_ready()
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action sleep(5000)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bridge({sip_invite_params=user=LOCAL,sip_from_uri=4779206277@${domain_name}}[leg_timeout=30]user/4779206277@${domain_name})
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_destination=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_destination=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_destination=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(variable_sip_to_host=pbx3.inexlocal.com)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_domain=127.0.0.1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(leg_timeout=60)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(userinfo_id=415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(sip_destination_number=4779206277)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(destination_number=919724268060)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(did_number=919724268060)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action lua(astpp/lib/pbx/astpp-sipdevice-routing.lua)
|--- Dialplan: Processing recursive conditions level:1 [919724268060_recur_1] require-nested=TRUE
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Regex (PASS) [919724268060_recur_1] ${cond(${user_data 4779206277@${domain_name} param vm-enabled} == true ? YES : NO)}(YES) =~ /^YES$/ break=on-false
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action answer()
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(voicemail_alternate_greet_id=919724268060)
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action voicemail(default $${domain_name} 4779206277)
2019-07-04 16:05:05.187074 [DEBUG] switch_core_state_machine.c:286 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_ROUTING -> CS_EXECUTE
2019-07-04 16:05:05.187074 [DEBUG] switch_core_state_machine.c:643 (sofia/default/8889687188@pbx3.inexlocal.com) State ROUTING going to sleep
2019-07-04 16:05:05.187074 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_EXECUTE (Cur 1 Tot 303)
2019-07-04 16:05:05.187074 [DEBUG] switch_core_state_machine.c:650 (sofia/default/8889687188@pbx3.inexlocal.com) State EXECUTE
2019-07-04 16:05:05.187074 [DEBUG] mod_sofia.c:198 sofia/default/8889687188@pbx3.inexlocal.com SOFIA EXECUTE
2019-07-04 16:05:05.187074 [DEBUG] switch_core_state_machine.c:328 sofia/default/8889687188@pbx3.inexlocal.com Standard EXECUTE
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_destination_number=919724268060)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_destination_number]=[919724268060]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_app=sched_hangup)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [bridge_pre_execute_bleg_app]=[sched_hangup]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [bridge_pre_execute_bleg_data]=[+6000 normal_clearing]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(callstart=2019-07-04 10:35:05)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [callstart]=[2019-07-04 10:35:05]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(continue_on_fail=TRUE)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [continue_on_fail]=[TRUE]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(account_id=415)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [account_id]=[415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(parent_id=0)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [parent_id]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(entity_id=0)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [entity_id]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_processed=internal)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_processed]=[internal]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_direction=inbound)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_direction]=[inbound]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(accountname=default)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [accountname]=[default]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(filename1=astpp.pbx.lua)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [filename1]=[astpp.pbx.lua]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(origination_rates_did=ID:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [origination_rates_did]=[ID:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(origination_rates=ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [origination_rates]=[ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_name=8889687188)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_name]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_number=8889687188)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_number]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_name=8889687188)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_name]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_number=8889687188)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_number]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(receiver_accid=415)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [receiver_accid]=[415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
2019-07-04 16:05:05.187074 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [presence_data]=[x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(call_type=0)
2019-07-04 16:05:05.187074 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_type]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(calltype=DID-LOCAL)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [calltype]=[DID-LOCAL]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com db(insert/pickup_any_group_/4779206277/62dee30a-9e47-11e9-94fc-2d0e45e4becc)
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(dialed_extension=transfer_call)
2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [dialed_extension]=[transfer_call]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(dialed_extension=transfer_call)
2019-07-04 16:05:05.207036 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[transfer_call]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
2019-07-04 16:05:05.207036 [ERR] switch_ivr_async.c:4146 Invalid key 95
2019-07-04 16:05:05.207036 [ERR] mod_dptools.c:786 Bind Error!
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
2019-07-04 16:05:05.207036 [ERR] switch_ivr_async.c:4146 Invalid key 94
2019-07-04 16:05:05.207036 [ERR] mod_dptools.c:786 Bind Error!
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
2019-07-04 16:05:05.207036 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(did_user_domain=pbx3.inexlocal.com)
2019-07-04 16:05:05.207036 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [did_user_domain]=[pbx3.inexlocal.com]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com ring_ready()
2019-07-04 16:05:05.207036 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/default/8889687188@pbx3.inexlocal.com!
2019-07-04 16:05:05.207036 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [early][180]
2019-07-04 16:05:05.207036 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com sleep(5000)
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bridge({sip_invite_params=user=LOCAL,sip_from_uri=4779206277@pbx3.inexlocal.com}[leg_timeout=30]user/4779206277@pbx3.inexlocal.com)
2019-07-04 16:05:10.347021 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [presence_data]=[x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID] to event
2019-07-04 16:05:10.347021 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [call_type]=[0] to event
2019-07-04 16:05:10.347021 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [dialed_extension]=[transfer_call] to event
2019-07-04 16:05:10.347021 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [did_user_domain]=[pbx3.inexlocal.com] to event
2019-07-04 16:05:10.347021 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2019-07-04 16:05:10.347021 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
2019-07-04 16:05:10.627063 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [presence_data]=[x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID] to event
2019-07-04 16:05:10.627063 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [call_type]=[0] to event
2019-07-04 16:05:10.627063 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [dialed_extension]=[transfer_call] to event
2019-07-04 16:05:10.627063 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [did_user_domain]=[pbx3.inexlocal.com] to event
2019-07-04 16:05:10.627063 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2019-07-04 16:05:10.627063 [NOTICE] switch_channel.c:1104 New Channel sofia/default/4779206277@192.168.1.13:52632 [6638483e-9e47-11e9-9529-2d0e45e4becc]
2019-07-04 16:05:10.627063 [DEBUG] mod_sofia.c:4819 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_NEW -> CS_INIT
2019-07-04 16:05:10.627063 [DEBUG] switch_ivr_originate.c:2963 sofia/default/4779206277@192.168.1.13:52632 Setting leg timeout to 30
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_INIT (Cur 2 Tot 304)
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:627 (sofia/default/4779206277@192.168.1.13:52632) State INIT
2019-07-04 16:05:10.627063 [DEBUG] mod_sofia.c:90 sofia/default/4779206277@192.168.1.13:52632 SOFIA INIT
2019-07-04 16:05:10.627063 [DEBUG] sofia_glue.c:1295 sofia/default/4779206277@192.168.1.13:52632 sending invite version: 1.6.20 64bit
Local SDP:
v=0
o=FreeSWITCH 1562210176 1562210177 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 26334 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
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:40 sofia/default/4779206277@192.168.1.13:52632 Standard INIT
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:48 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_INIT -> CS_ROUTING
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:627 (sofia/default/4779206277@192.168.1.13:52632) State INIT going to sleep
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_ROUTING (Cur 2 Tot 304)
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:643 (sofia/default/4779206277@192.168.1.13:52632) State ROUTING
2019-07-04 16:05:10.627063 [DEBUG] mod_sofia.c:143 sofia/default/4779206277@192.168.1.13:52632 SOFIA ROUTING
2019-07-04 16:05:10.627063 [DEBUG] switch_ivr_originate.c:67 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:643 (sofia/default/4779206277@192.168.1.13:52632) State ROUTING going to sleep
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 304)
2019-07-04 16:05:10.627063 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [calling][0]
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:662 (sofia/default/4779206277@192.168.1.13:52632) State CONSUME_MEDIA
2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:662 (sofia/default/4779206277@192.168.1.13:52632) State CONSUME_MEDIA going to sleep
2019-07-04 16:05:10.727027 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [proceeding][180]
2019-07-04 16:05:10.727027 [NOTICE] sofia.c:7192 Ring-Ready sofia/default/4779206277@192.168.1.13:52632!
2019-07-04 16:05:10.727027 [DEBUG] switch_channel.c:3346 (sofia/default/4779206277@192.168.1.13:52632) Callstate Change DOWN -> RINGING
2019-07-04 16:05:10.747027 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
2019-07-04 16:05:14.467024 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [terminated][487]
2019-07-04 16:05:14.467024 [NOTICE] sofia.c:8273 Hangup sofia/default/8889687188@pbx3.inexlocal.com [CS_EXECUTE] [ORIGINATOR_CANCEL]
2019-07-04 16:05:14.487037 [NOTICE] switch_ivr_originate.c:3612 Hangup sofia/default/4779206277@192.168.1.13:52632 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
2019-07-04 16:05:14.487037 [DEBUG] switch_ivr_originate.c:3837 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_HANGUP (Cur 2 Tot 304)
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:850 (sofia/default/4779206277@192.168.1.13:52632) Callstate Change RINGING -> HANGUP
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:852 (sofia/default/4779206277@192.168.1.13:52632) State HANGUP
2019-07-04 16:05:14.487037 [DEBUG] mod_sofia.c:432 sofia/default/4779206277@192.168.1.13:52632 Overriding SIP cause 487 with 487 from the other leg
2019-07-04 16:05:14.487037 [DEBUG] mod_sofia.c:438 Channel sofia/default/4779206277@192.168.1.13:52632 hanging up, cause: ORIGINATOR_CANCEL
2019-07-04 16:05:14.487037 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
2019-07-04 16:05:14.487037 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
2019-07-04 16:05:14.487037 [INFO] mod_dptools.c:3436 Originate Failed. Cause: ORIGINATOR_CANCEL
2019-07-04 16:05:14.487037 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/default/4779206277@192.168.1.13:52632
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:60 sofia/default/4779206277@192.168.1.13:52632 Standard HANGUP, cause: ORIGINATOR_CANCEL
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:852 (sofia/default/4779206277@192.168.1.13:52632) State HANGUP going to sleep
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:619 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_HANGUP -> CS_REPORTING
2019-07-04 16:05:14.487037 [DEBUG] switch_core_session.c:2815 sofia/default/8889687188@pbx3.inexlocal.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:650 (sofia/default/8889687188@pbx3.inexlocal.com) State EXECUTE going to sleep
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_HANGUP (Cur 2 Tot 304)
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_REPORTING (Cur 2 Tot 304)
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:850 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change RINGING -> HANGUP
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:938 (sofia/default/4779206277@192.168.1.13:52632) State REPORTING
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:852 (sofia/default/8889687188@pbx3.inexlocal.com) State HANGUP
2019-07-04 16:05:14.487037 [DEBUG] mod_sofia.c:438 Channel sofia/default/8889687188@pbx3.inexlocal.com hanging up, cause: ORIGINATOR_CANCEL
2019-07-04 16:05:14.487037 [INFO] mod_json_cdr.c:271 Process [6638483e-9e47-11e9-9529-2d0e45e4becc.cdr.json]
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:60 sofia/default/8889687188@pbx3.inexlocal.com Standard HANGUP, cause: ORIGINATOR_CANCEL
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:852 (sofia/default/8889687188@pbx3.inexlocal.com) State HANGUP going to sleep
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:619 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_HANGUP -> CS_REPORTING
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_REPORTING (Cur 2 Tot 304)
2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:938 (sofia/default/8889687188@pbx3.inexlocal.com) State REPORTING
2019-07-04 16:05:14.487037 [INFO] mod_json_cdr.c:271 Process [62dee30a-9e47-11e9-94fc-2d0e45e4becc.cdr.json]
2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:174 sofia/default/4779206277@192.168.1.13:52632 Standard REPORTING, cause: ORIGINATOR_CANCEL
2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:938 (sofia/default/4779206277@192.168.1.13:52632) State REPORTING going to sleep
2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:610 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_REPORTING -> CS_DESTROY
2019-07-04 16:05:14.506997 [DEBUG] switch_core_session.c:1665 Session 304 (sofia/default/4779206277@192.168.1.13:52632) Locked, Waiting on external entities
2019-07-04 16:05:14.506997 [NOTICE] switch_core_session.c:1683 Session 304 (sofia/default/4779206277@192.168.1.13:52632) Ended
2019-07-04 16:05:14.506997 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/4779206277@192.168.1.13:52632 [CS_DESTROY]
2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:741 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_DESTROY (Cur 1 Tot 304)
2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:751 (sofia/default/4779206277@192.168.1.13:52632) State DESTROY
2019-07-04 16:05:14.506997 [DEBUG] mod_sofia.c:343 sofia/default/4779206277@192.168.1.13:52632 SOFIA DESTROY
2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:181 sofia/default/4779206277@192.168.1.13:52632 Standard DESTROY
2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:751 (sofia/default/4779206277@192.168.1.13:52632) State DESTROY going to sleep
2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:174 sofia/default/8889687188@pbx3.inexlocal.com Standard REPORTING, cause: ORIGINATOR_CANCEL
2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:938 (sofia/default/8889687188@pbx3.inexlocal.com) State REPORTING going to sleep
2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:610 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_REPORTING -> CS_DESTROY
2019-07-04 16:05:14.726996 [DEBUG] switch_core_session.c:1665 Session 303 (sofia/default/8889687188@pbx3.inexlocal.com) Locked, Waiting on external entities
2019-07-04 16:05:14.726996 [NOTICE] switch_core_session.c:1683 Session 303 (sofia/default/8889687188@pbx3.inexlocal.com) Ended
2019-07-04 16:05:14.726996 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/8889687188@pbx3.inexlocal.com [CS_DESTROY]
2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:741 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_DESTROY (Cur 0 Tot 304)
2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:751 (sofia/default/8889687188@pbx3.inexlocal.com) State DESTROY
2019-07-04 16:05:14.726996 [DEBUG] mod_sofia.c:343 sofia/default/8889687188@pbx3.inexlocal.com SOFIA DESTROY
2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:181 sofia/default/8889687188@pbx3.inexlocal.com Standard DESTROY
2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:751 (sofia/default/8889687188@pbx3.inexlocal.com) State DESTROY going to sleep
2019-07-04 16:05:21.387057 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [7100815208@pbx3.inexlocal.com] from ip 192.168.1.43
2019-07-04 16:05:33.927025 [WARNING] sofia_reg.c:2906 Can't find user [4727985745@192.168.1.118] from 192.168.1.165
You must define a domain called '192.168.1.118' in your directory and add a user with the id="4727985745" attribute
and you must configure your device to use the proper domain in it's authentication credentials.
2019-07-04 16:05:33.927025 [WARNING] sofia_reg.c:1737 SIP auth failure (REGISTER) on sofia profile 'default' for [4727985745@192.168.1.118] from ip 192.168.1.165
2019-07-04 16:05:39.467047 [NOTICE] switch_channel.c:1104 New Channel sofia/default/8889687188@pbx3.inexlocal.com [7769e32e-9e47-11e9-9533-2d0e45e4becc]
2019-07-04 16:05:39.467047 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_NEW (Cur 1 Tot 305)
2019-07-04 16:05:39.467047 [DEBUG] sofia.c:9873 sofia/default/8889687188@pbx3.inexlocal.com receiving invite from 192.168.1.151:5062 version: 1.6.20 64bit
2019-07-04 16:05:39.467047 [DEBUG] sofia.c:10044 IP 192.168.1.151 Rejected by acl "default". Falling back to Digest auth.
2019-07-04 16:05:39.467047 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [919724268060@pbx3.inexlocal.com] from ip 192.168.1.151
2019-07-04 16:05:39.467047 [DEBUG] switch_core_state_machine.c:603 (sofia/default/8889687188@pbx3.inexlocal.com) State NEW
2019-07-04 16:05:39.467047 [DEBUG] sofia.c:2334 detaching session 7769e32e-9e47-11e9-9533-2d0e45e4becc
2019-07-04 16:05:39.527020 [DEBUG] sofia.c:2442 Re-attaching to session 7769e32e-9e47-11e9-9533-2d0e45e4becc
2019-07-04 16:05:39.527020 [DEBUG] sofia.c:9873 sofia/default/8889687188@pbx3.inexlocal.com receiving invite from 192.168.1.151:5062 version: 1.6.20 64bit
2019-07-04 16:05:39.527020 [DEBUG] sofia.c:10044 IP 192.168.1.151 Rejected by acl "default". Falling back to Digest auth.
2019-07-04 16:05:39.547044 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [received][100]
2019-07-04 16:05:39.547044 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=8889687188 8001 8000 IN IP4 192.168.1.151
s=SIP Call
c=IN IP4 192.168.1.151
t=0 0
m=audio 5038 RTP/AVP 0 8 4 18 9 97 2 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:9 G722/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:2 G726-32/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/8889687188@pbx3.inexlocal.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-07-04 16:05:39.547044 [DEBUG] switch_core_codec.c:111 sofia/default/8889687188@pbx3.inexlocal.com Original read codec set to PCMU:0
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4767 sofia/default/8889687188@pbx3.inexlocal.com Set 2833 dtmf send payload to 101 recv payload to 101
2019-07-04 16:05:39.547044 [DEBUG] sofia.c:7507 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_NEW -> CS_INIT
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_INIT (Cur 1 Tot 305)
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:627 (sofia/default/8889687188@pbx3.inexlocal.com) State INIT
2019-07-04 16:05:39.547044 [DEBUG] mod_sofia.c:90 sofia/default/8889687188@pbx3.inexlocal.com SOFIA INIT
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:40 sofia/default/8889687188@pbx3.inexlocal.com Standard INIT
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:48 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_INIT -> CS_ROUTING
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:627 (sofia/default/8889687188@pbx3.inexlocal.com) State INIT going to sleep
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_ROUTING (Cur 1 Tot 305)
2019-07-04 16:05:39.547044 [DEBUG] switch_channel.c:2249 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change DOWN -> RINGING
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:643 (sofia/default/8889687188@pbx3.inexlocal.com) State ROUTING
2019-07-04 16:05:39.547044 [DEBUG] mod_sofia.c:143 sofia/default/8889687188@pbx3.inexlocal.com SOFIA ROUTING
2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:236 sofia/default/8889687188@pbx3.inexlocal.com Standard ROUTING
2019-07-04 16:05:39.547044 [INFO] mod_dialplan_xml.c:637 Processing 8889687188 <8889687188>->919724268060 in context default
2019-07-04 16:05:39.547044 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f6b8805e880 Connected.
2019-07-04 16:05:39.547044 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2019-07-04 16:05:39.547044 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] blind_flag: 0
2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 919724268060
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '919724268060' limit 1
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '919724268060' AND status=0 limit 1
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Functions] [GET_queue_INFO] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = '919724268060' and status=0 LIMIT 1
2019-07-04 16:05:39.587050 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FAXER] in custom Caller ID
2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number : 8889687188 / 8889687188
2019-07-04 16:05:39.587050 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="919724268060" LIMIT 1
2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : inbound
2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 8889687188]
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "8889687188" AND deleted = 0 limit 1
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [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 ="919724268060" AND A.accountid = '415' limit 1
2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 919724268060
2019-07-04 16:05:39.587050 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="919724268060" LIMIT 1
2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] New Call direction : inbound
2019-07-04 16:05:39.587050 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:39.587050 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="919724268060" AND (accountid = 0 OR status = 1) LIMIT 1
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :415
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE (patterns = '^919724268060.*' OR patterns = '^91972426806.*' OR patterns = '^9197242680.*' OR patterns = '^919724268.*' OR patterns = '^91972426.*' OR patterns = '^9197242.*' OR patterns = '^919724.*' OR patterns = '^91972.*' OR patterns = '^9197.*' OR patterns = '^919.*' OR patterns = '^91.*' OR patterns = '^9.*' OR patterns ='--') AND accountid = 415 ORDER BY LENGTH(PKGPTR.patterns) DESC
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '919724268060' OR number = '91972426806' OR number = '9197242680' OR number = '919724268' OR number = '91972426' OR number = '9197242' OR number = '919724' OR number = '91972' OR number = '9197' OR number = '919' OR number = '91' OR number = '9' OR number ='--') OR (number = '919724268060*' OR number = '91972426806*' OR number = '9197242680*' OR number = '919724268*' OR number = '91972426*' OR number = '9197242*' OR number = '919724*' OR number = '91972*' OR number = '9197*' OR number = '919*' OR number = '91*' OR number = '9*' OR number ='--') OR (number = '8889687188' OR number = '888968718' OR number = '88896871' OR number = '8889687' OR number = '888968' OR number = '88896' OR number = '8889' OR number = '888' OR number = '88' OR number = '8' OR number ='--') OR (number = '8889687188*' OR number = '888968718*' OR number = '88896871*' OR number = '8889687*' OR number = '888968*' OR number = '88896*' OR number = '8889*' OR number = '888*' OR number = '88*' OR number = '8*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] Call Barring Status : -1
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '919724268060' OR routing_prefix = '91972426806' OR routing_prefix = '9197242680' OR routing_prefix = '919724268' OR routing_prefix = '91972426' OR routing_prefix = '9197242' OR routing_prefix = '919724' OR routing_prefix = '91972' OR routing_prefix = '9197' OR routing_prefix = '919' OR routing_prefix = '91' OR routing_prefix = '9' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 415
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 8889687188
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 4839.9
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 1 [0:prepaid,1:postpaid]
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 4
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] CID Pool : 0
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :inbound
2019-07-04 16:05:39.607189 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,in_caller_id_originate,out_caller_id_originate,number_originate FROM localization WHERE id = 5 AND status=0 limit 1
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,A.number as did_number,B.id as accountid,B.number as account_code,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout,A.status,A.country_id,A.call_type_vm_flag FROM dids AS A,accounts AS B WHERE B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="919724268060" LIMIT 1
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: inbound
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 13095
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 1.50000
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : test Gandhinagar
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
2019-07-04 16:05:39.607189 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] INB_FREE:TRUE
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] free_inbound:0
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 415 AND status=0 LIMIT 1
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE id = "415" AND deleted = 0 limit 1
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :outbound
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^919724268060.*' OR pattern = '^91972426806.*' OR pattern = '^9197242680.*' OR pattern = '^919724268.*' OR pattern = '^91972426.*' OR pattern = '^9197242.*' OR pattern = '^919724.*' OR pattern = '^91972.*' OR pattern = '^9197.*' OR pattern = '^919.*' OR pattern = '^91.*' OR pattern = '^9.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=415) ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: outbound
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 11
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.60000
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : Ahmedabad-Urban
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Trunk ID:
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Routing type:
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
2019-07-04 16:05:39.607189 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML:415
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Userinfo XML:415
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML : 415
2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] maxlength::::::::: 100
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_0
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [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="4779206277" AND domains.domain="pbx3.inexlocal.com" limit 1
2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] [GET_ROUTING_INFO] Query :SELECT * from sip_device_routing WHERE sip_device_id = 460 limit 1
2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer_attended' limit 1
2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer' limit 1
2019-07-04 16:05:39.627064 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] user_domain beforepbx3.inexlocal.com
2019-07-04 16:05:39.627064 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] pickup_group_permission pickup_str
2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [NOTIFY] START:
2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [NOTIFY] Query :SELECT callkit_token,mobile_type FROM dialer_device_info WHERE username='4779206277'
2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [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="4779206277" AND domains.domain="pbx3.inexlocal.com" limit 1
2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] [GET_ROUTING_INFO] Query :SELECT * from sip_device_routing WHERE sip_device_id = 460 limit 1
2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [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="919724268060">
<condition field="destination_number" expression="919724268060">
<action application="set" data="effective_destination_number=919724268060"/>
<action application="set" data="bridge_pre_execute_bleg_app=sched_hangup"/>
<action application="set" data="bridge_pre_execute_bleg_data=+6000 normal_clearing"/>
<action application="set" data="callstart=2019-07-04 10:35:39"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="set" data="continue_on_fail=TRUE"/>
<action application="set" data="account_id=415"/>
<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:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415"/>
<action application="set" data="origination_rates=ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415"/>
<action application="set" data="original_caller_id_name=8889687188"/>
<action application="set" data="original_caller_id_number=8889687188"/>
<action application="set" data="effective_caller_id_name=8889687188"/>
<action application="set" data="effective_caller_id_number=8889687188"/>
<action application="set" data="receiver_accid=415"/>
<action application="export" data="presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID"/>
<action application="export" data="call_type=0"/>
<action application="set" data="calltype=DID-LOCAL"/>
<action application="db" data="insert/pickup_any_group_${callgroup}/4779206277/${uuid}"/>
<action application="set" data="dialed_extension=transfer_call"/>
<action application="export" data="dialed_extension=transfer_call"/>
<action application="bind_meta_app" data="95 b s execute_extension::transfer_call_95 XML default"/>
<action application="bind_meta_app" data="94 b s execute_extension::transfer_call_94 XML default"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="export" data="did_user_domain=pbx3.inexlocal.com"/>
<action application="ring_ready"/>
<action application="sleep" data="5000"/>
<action application="bridge" data="{sip_invite_params=user=LOCAL,sip_from_uri=4779206277@${domain_name}}[leg_timeout=30]user/4779206277@${domain_name}"/>
<action application="set" data="on_busy_flag=1"/>
<action application="set" data="on_busy_destination=0"/>
<action application="set" data="no_answer_flag=1"/>
<action application="set" data="no_answer_destination=0"/>
<action application="set" data="not_register_flag=1"/>
<action application="set" data="not_register_destination=0"/>
<action application="set" data="opensips_flag=1"/>
<action application="set" data="variable_sip_to_host=pbx3.inexlocal.com"/>
<action application="set" data="opensips_domain=127.0.0.1"/>
<action application="set" data="leg_timeout=60"/>
<action application="set" data="userinfo_id=415"/>
<action application="set" data="sip_destination_number=4779206277"/>
<action application="set" data="destination_number=919724268060"/>
<action application="set" data="did_number=919724268060"/>
<action application="lua" data="astpp/lib/pbx/astpp-sipdevice-routing.lua"/>
<condition field="${cond(${user_data 4779206277@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
<action application="answer"/>
<action application="export" data="voicemail_alternate_greet_id=919724268060"/>
<action application="voicemail" data="default $${domain_name} 4779206277"/>
<anti-action application="hangup" data="${originate_disposition}"/>
</condition>
</condition>
</extension>
</context>
</section>
</document>
2019-07-04 16:05:39.627064 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f6b8805e880 released.
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com parsing [default->919724268060] continue=false
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Regex (PASS) [919724268060] destination_number(919724268060) =~ /919724268060/ break=on-false
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_destination_number=919724268060)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_app=sched_hangup)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(callstart=2019-07-04 10:35:39)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(continue_on_fail=TRUE)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(account_id=415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(parent_id=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(entity_id=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_processed=internal)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_direction=inbound)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(accountname=default)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(filename1=astpp.pbx.lua)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(origination_rates_did=ID:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(origination_rates=ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_name=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_number=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_name=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_number=8889687188)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(receiver_accid=415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(call_type=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(calltype=DID-LOCAL)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action db(insert/pickup_any_group_${callgroup}/4779206277/${uuid})
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(dialed_extension=transfer_call)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(dialed_extension=transfer_call)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(did_user_domain=pbx3.inexlocal.com)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action ring_ready()
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action sleep(5000)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bridge({sip_invite_params=user=LOCAL,sip_from_uri=4779206277@${domain_name}}[leg_timeout=30]user/4779206277@${domain_name})
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_destination=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_destination=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_destination=0)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_flag=1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(variable_sip_to_host=pbx3.inexlocal.com)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_domain=127.0.0.1)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(leg_timeout=60)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(userinfo_id=415)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(sip_destination_number=4779206277)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(destination_number=919724268060)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(did_number=919724268060)
Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action lua(astpp/lib/pbx/astpp-sipdevice-routing.lua)
|--- Dialplan: Processing recursive conditions level:1 [919724268060_recur_1] require-nested=TRUE
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Regex (PASS) [919724268060_recur_1] ${cond(${user_data 4779206277@${domain_name} param vm-enabled} == true ? YES : NO)}(YES) =~ /^YES$/ break=on-false
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action answer()
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(voicemail_alternate_greet_id=919724268060)
|--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action voicemail(default $${domain_name} 4779206277)
2019-07-04 16:05:39.667045 [DEBUG] switch_core_state_machine.c:286 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_ROUTING -> CS_EXECUTE
2019-07-04 16:05:39.667045 [DEBUG] switch_core_state_machine.c:643 (sofia/default/8889687188@pbx3.inexlocal.com) State ROUTING going to sleep
2019-07-04 16:05:39.667045 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8889687188@pbx3.inexlocal.com) Running State Change CS_EXECUTE (Cur 1 Tot 305)
2019-07-04 16:05:39.667045 [DEBUG] switch_core_state_machine.c:650 (sofia/default/8889687188@pbx3.inexlocal.com) State EXECUTE
2019-07-04 16:05:39.667045 [DEBUG] mod_sofia.c:198 sofia/default/8889687188@pbx3.inexlocal.com SOFIA EXECUTE
2019-07-04 16:05:39.667045 [DEBUG] switch_core_state_machine.c:328 sofia/default/8889687188@pbx3.inexlocal.com Standard EXECUTE
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_destination_number=919724268060)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_destination_number]=[919724268060]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_app=sched_hangup)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [bridge_pre_execute_bleg_app]=[sched_hangup]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [bridge_pre_execute_bleg_data]=[+6000 normal_clearing]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(callstart=2019-07-04 10:35:39)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [callstart]=[2019-07-04 10:35:39]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(continue_on_fail=TRUE)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [continue_on_fail]=[TRUE]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(account_id=415)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [account_id]=[415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(parent_id=0)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [parent_id]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(entity_id=0)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [entity_id]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_processed=internal)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_processed]=[internal]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_direction=inbound)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_direction]=[inbound]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(accountname=default)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [accountname]=[default]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(filename1=astpp.pbx.lua)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [filename1]=[astpp.pbx.lua]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(origination_rates_did=ID:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415)
2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [origination_rates_did]=[ID:13095|CODE:^919724268060.*|DESTINATION:test Gandhinagar|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:0|COST:1.50000|INC:1|INITIALBLOCK:1|RATEGROUP:0|MARKUP:0|CI:88|ACCID:415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(origination_rates=ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [origination_rates]=[ID:11|CODE:^91.*|DESTINATION:Ahmedabad-Urban|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:0.60000|INC:1|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:88|ACCID:415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_name=8889687188)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_name]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_number=8889687188)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_number]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_name=8889687188)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_name]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_number=8889687188)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_number]=[8889687188]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(receiver_accid=415)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [receiver_accid]=[415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
2019-07-04 16:05:39.686997 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [presence_data]=[x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(call_type=0)
2019-07-04 16:05:39.686997 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_type]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(calltype=DID-LOCAL)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [calltype]=[DID-LOCAL]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com db(insert/pickup_any_group_/4779206277/7769e32e-9e47-11e9-9533-2d0e45e4becc)
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(dialed_extension=transfer_call)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [dialed_extension]=[transfer_call]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(dialed_extension=transfer_call)
2019-07-04 16:05:39.686997 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[transfer_call]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
2019-07-04 16:05:39.686997 [ERR] switch_ivr_async.c:4146 Invalid key 95
2019-07-04 16:05:39.686997 [ERR] mod_dptools.c:786 Bind Error!
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
2019-07-04 16:05:39.686997 [ERR] switch_ivr_async.c:4146 Invalid key 94
2019-07-04 16:05:39.686997 [ERR] mod_dptools.c:786 Bind Error!
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(did_user_domain=pbx3.inexlocal.com)
2019-07-04 16:05:39.686997 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [did_user_domain]=[pbx3.inexlocal.com]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com ring_ready()
2019-07-04 16:05:39.686997 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/default/8889687188@pbx3.inexlocal.com!
2019-07-04 16:05:39.686997 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [early][180]
2019-07-04 16:05:39.686997 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com sleep(5000)
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bridge({sip_invite_params=user=LOCAL,sip_from_uri=4779206277@pbx3.inexlocal.com}[leg_timeout=30]user/4779206277@pbx3.inexlocal.com)
2019-07-04 16:05:44.727017 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [presence_data]=[x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID] to event
2019-07-04 16:05:44.727017 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [call_type]=[0] to event
2019-07-04 16:05:44.727017 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [dialed_extension]=[transfer_call] to event
2019-07-04 16:05:44.727017 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [did_user_domain]=[pbx3.inexlocal.com] to event
2019-07-04 16:05:44.727017 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2019-07-04 16:05:44.727017 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
2019-07-04 16:05:44.787026 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [presence_data]=[x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID] to event
2019-07-04 16:05:44.787026 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [call_type]=[0] to event
2019-07-04 16:05:44.787026 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [dialed_extension]=[transfer_call] to event
2019-07-04 16:05:44.787026 [DEBUG] switch_channel.c:1250 sofia/default/8889687188@pbx3.inexlocal.com EXPORTING[export_vars] [did_user_domain]=[pbx3.inexlocal.com] to event
2019-07-04 16:05:44.787026 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2019-07-04 16:05:44.787026 [NOTICE] switch_channel.c:1104 New Channel sofia/default/4779206277@192.168.1.13:52632 [7a959930-9e47-11e9-9560-2d0e45e4becc]
2019-07-04 16:05:44.787026 [DEBUG] mod_sofia.c:4819 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_NEW -> CS_INIT
2019-07-04 16:05:44.787026 [DEBUG] switch_ivr_originate.c:2963 sofia/default/4779206277@192.168.1.13:52632 Setting leg timeout to 30
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_INIT (Cur 2 Tot 306)
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:627 (sofia/default/4779206277@192.168.1.13:52632) State INIT
2019-07-04 16:05:44.787026 [DEBUG] mod_sofia.c:90 sofia/default/4779206277@192.168.1.13:52632 SOFIA INIT
2019-07-04 16:05:44.787026 [DEBUG] sofia_glue.c:1295 sofia/default/4779206277@192.168.1.13:52632 sending invite version: 1.6.20 64bit
Local SDP:
v=0
o=FreeSWITCH 1562215530 1562215531 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 21014 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
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:40 sofia/default/4779206277@192.168.1.13:52632 Standard INIT
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:48 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_INIT -> CS_ROUTING
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:627 (sofia/default/4779206277@192.168.1.13:52632) State INIT going to sleep
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_ROUTING (Cur 2 Tot 306)
2019-07-04 16:05:44.787026 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [calling][0]
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:643 (sofia/default/4779206277@192.168.1.13:52632) State ROUTING
2019-07-04 16:05:44.787026 [DEBUG] mod_sofia.c:143 sofia/default/4779206277@192.168.1.13:52632 SOFIA ROUTING
2019-07-04 16:05:44.787026 [DEBUG] switch_ivr_originate.c:67 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:643 (sofia/default/4779206277@192.168.1.13:52632) State ROUTING going to sleep
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 306)
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:662 (sofia/default/4779206277@192.168.1.13:52632) State CONSUME_MEDIA
2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:662 (sofia/default/4779206277@192.168.1.13:52632) State CONSUME_MEDIA going to sleep
2019-07-04 16:05:44.907006 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [proceeding][180]
2019-07-04 16:05:44.907006 [NOTICE] sofia.c:7192 Ring-Ready sofia/default/4779206277@192.168.1.13:52632!
2019-07-04 16:05:44.907006 [DEBUG] switch_channel.c:3346 (sofia/default/4779206277@192.168.1.13:52632) Callstate Change DOWN -> RINGING
2019-07-04 16:05:44.907006 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
2019-07-04 16:05:47.007062 [NOTICE] switch_channel.c:1104 New Channel sofia/default/7100815208@pbx3.inexlocal.com [7be92414-9e47-11e9-9564-2d0e45e4becc]
2019-07-04 16:05:47.007062 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7100815208@pbx3.inexlocal.com) Running State Change CS_NEW (Cur 3 Tot 307)
2019-07-04 16:05:47.007062 [DEBUG] sofia.c:9873 sofia/default/7100815208@pbx3.inexlocal.com receiving invite from 192.168.1.43:5060 version: 1.6.20 64bit
2019-07-04 16:05:47.007062 [DEBUG] sofia.c:10044 IP 192.168.1.43 Rejected by acl "default". Falling back to Digest auth.
2019-07-04 16:05:47.007062 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [*102@pbx3.inexlocal.com] from ip 192.168.1.43
2019-07-04 16:05:47.007062 [DEBUG] switch_core_state_machine.c:603 (sofia/default/7100815208@pbx3.inexlocal.com) State NEW
2019-07-04 16:05:47.007062 [DEBUG] sofia.c:2334 detaching session 7be92414-9e47-11e9-9564-2d0e45e4becc
2019-07-04 16:05:47.027166 [DEBUG] sofia.c:2442 Re-attaching to session 7be92414-9e47-11e9-9564-2d0e45e4becc
2019-07-04 16:05:47.046998 [DEBUG] sofia.c:9873 sofia/default/7100815208@pbx3.inexlocal.com receiving invite from 192.168.1.43:5060 version: 1.6.20 64bit
2019-07-04 16:05:47.046998 [DEBUG] sofia.c:10044 IP 192.168.1.43 Rejected by acl "default". Falling back to Digest auth.
2019-07-04 16:05:47.067041 [DEBUG] sofia.c:7084 Channel sofia/default/7100815208@pbx3.inexlocal.com entering state [received][100]
2019-07-04 16:05:47.067041 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=twinkle 971131215 462933206 IN IP4 192.168.1.43
s=-
c=IN IP4 192.168.1.43
t=0 0
m=audio 8000 RTP/AVP 98 97 8 0 3 101
a=rtpmap:98 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/7100815208@pbx3.inexlocal.com PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2019-07-04 16:05:47.067041 [DEBUG] switch_core_codec.c:111 sofia/default/7100815208@pbx3.inexlocal.com Original read codec set to PCMA:8
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4767 sofia/default/7100815208@pbx3.inexlocal.com Set 2833 dtmf send payload to 101 recv payload to 101
2019-07-04 16:05:47.067041 [DEBUG] sofia.c:7507 (sofia/default/7100815208@pbx3.inexlocal.com) State Change CS_NEW -> CS_INIT
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7100815208@pbx3.inexlocal.com) Running State Change CS_INIT (Cur 3 Tot 307)
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7100815208@pbx3.inexlocal.com) State INIT
2019-07-04 16:05:47.067041 [DEBUG] mod_sofia.c:90 sofia/default/7100815208@pbx3.inexlocal.com SOFIA INIT
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:40 sofia/default/7100815208@pbx3.inexlocal.com Standard INIT
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:48 (sofia/default/7100815208@pbx3.inexlocal.com) State Change CS_INIT -> CS_ROUTING
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7100815208@pbx3.inexlocal.com) State INIT going to sleep
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7100815208@pbx3.inexlocal.com) Running State Change CS_ROUTING (Cur 3 Tot 307)
2019-07-04 16:05:47.067041 [DEBUG] switch_channel.c:2249 (sofia/default/7100815208@pbx3.inexlocal.com) Callstate Change DOWN -> RINGING
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7100815208@pbx3.inexlocal.com) State ROUTING
2019-07-04 16:05:47.067041 [DEBUG] mod_sofia.c:143 sofia/default/7100815208@pbx3.inexlocal.com SOFIA ROUTING
2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:236 sofia/default/7100815208@pbx3.inexlocal.com Standard ROUTING
2019-07-04 16:05:47.067041 [INFO] mod_dialplan_xml.c:637 Processing 7100815208 <7100815208>->*102 in context default
2019-07-04 16:05:47.086992 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f6b8805e880 Connected.
2019-07-04 16:05:47.086992 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2019-07-04 16:05:47.086992 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] blind_flag: 0
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] TRAN user_domain: pbx3.inexlocal.com
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] hunt_destination_number: *102
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer_attended' limit 1
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer' limit 1
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code blind_value_two_digit*9
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code destination_number_two_digit*1
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code transfer_attended_two_digit*9
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : *102
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '*102' limit 1
2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code Action :::: call_pickup_same_group
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [FEATURE_CODE] sip_number :7100815208
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [get_sip_accountcode] Query :SELECT sip_devices.accountid from sip_devices,domains where sip_devices.accountid=domains.accountid and sip_devices.username = '7100815208' and domain = 'pbx3.inexlocal.com' limit 1
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [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="7100815208" AND domains.domain="pbx3.inexlocal.com" limit 1
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [FEATURE_CODE] sip_info id :459
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [FEATURE_CODE] feature_code_action :call_pickup_same_group
2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] [GET_ROUTING_INFO] Query :SELECT * from sip_device_routing WHERE sip_device_id = 459 limit 1
2019-07-04 16:05:47.129449 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_PICKUP_GROUP] Query :SELECT id,name from pickup_group where id IN (1,2,3,1,2,3) AND status = 0
2019-07-04 16:05:47.129449 [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="\*102">
<condition field="destination_number" expression="\*102">
<action application="export" data="bypass_media=true"/>
<action application="export" data="did_user_domain=pbx3.inexlocal.com"/>
<action application="play_and_get_digits" data="2 15 3 7000 # /usr/share/freeswitch/sounds/en/us/callie/astpp-pbx-extension-number.wav /invalid.wav foobar \d+"/>
<action application="pickup" data="SIP_device_${foobar}"/>
<action application="pickup" data="Allow-pick-up_${foobar}"/>
<action application="pickup" data="ABC_${foobar}"/>
</condition>
</extension>
</context>
</section>
</document>
2019-07-04 16:05:47.129449 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f6b8805e880 released.
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com parsing [default->\*102] continue=false
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Regex (PASS) [\*102] destination_number(*102) =~ /\*102/ break=on-false
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action export(bypass_media=true)
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action export(did_user_domain=pbx3.inexlocal.com)
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action play_and_get_digits(2 15 3 7000 # /usr/share/freeswitch/sounds/en/us/callie/astpp-pbx-extension-number.wav /invalid.wav foobar \d+)
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action pickup(SIP_device_${foobar})
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action pickup(Allow-pick-up_${foobar})
Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action pickup(ABC_${foobar})
2019-07-04 16:05:47.129449 [DEBUG] switch_core_state_machine.c:286 (sofia/default/7100815208@pbx3.inexlocal.com) State Change CS_ROUTING -> CS_EXECUTE
2019-07-04 16:05:47.129449 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7100815208@pbx3.inexlocal.com) State ROUTING going to sleep
2019-07-04 16:05:47.129449 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7100815208@pbx3.inexlocal.com) Running State Change CS_EXECUTE (Cur 3 Tot 307)
2019-07-04 16:05:47.129449 [DEBUG] switch_core_state_machine.c:650 (sofia/default/7100815208@pbx3.inexlocal.com) State EXECUTE
2019-07-04 16:05:47.129449 [DEBUG] mod_sofia.c:198 sofia/default/7100815208@pbx3.inexlocal.com SOFIA EXECUTE
2019-07-04 16:05:47.129449 [DEBUG] switch_core_state_machine.c:328 sofia/default/7100815208@pbx3.inexlocal.com Standard EXECUTE
EXECUTE sofia/default/7100815208@pbx3.inexlocal.com export(bypass_media=true)
2019-07-04 16:05:47.129449 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [bypass_media]=[true]
EXECUTE sofia/default/7100815208@pbx3.inexlocal.com export(did_user_domain=pbx3.inexlocal.com)
2019-07-04 16:05:47.129449 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [did_user_domain]=[pbx3.inexlocal.com]
2019-07-04 16:05:47.129449 [DEBUG] switch_core_session.c:2647 Application play_and_get_digits Requires media! pre_answering channel sofia/default/7100815208@pbx3.inexlocal.com
2019-07-04 16:05:47.129449 [INFO] switch_core_session.c:2649 Sending early media
2019-07-04 16:05:47.129449 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/7100815208@pbx3.inexlocal.com] 192.168.1.118 port 30396 -> 192.168.1.43 port 8000 codec: 8 ms: 20
2019-07-04 16:05:47.129449 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
2019-07-04 16:05:47.129449 [DEBUG] switch_core_media.c:7180 sofia/default/7100815208@pbx3.inexlocal.com Set 2833 dtmf send payload to 101
2019-07-04 16:05:47.129449 [DEBUG] switch_core_media.c:7187 sofia/default/7100815208@pbx3.inexlocal.com Set 2833 dtmf receive payload to 101
2019-07-04 16:05:47.129449 [DEBUG] switch_core_media.c:7210 sofia/default/7100815208@pbx3.inexlocal.com Set rtp dtmf delay to 40
2019-07-04 16:05:47.129449 [DEBUG] mod_sofia.c:2364 Ring SDP:
v=0
o=FreeSWITCH 1562206151 1562206152 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 30396 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
2019-07-04 16:05:47.129449 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/default/7100815208@pbx3.inexlocal.com!
2019-07-04 16:05:47.129449 [DEBUG] switch_channel.c:3474 (sofia/default/7100815208@pbx3.inexlocal.com) Callstate Change RINGING -> EARLY
EXECUTE sofia/default/7100815208@pbx3.inexlocal.com play_and_get_digits(2 15 3 7000 # /usr/share/freeswitch/sounds/en/us/callie/astpp-pbx-extension-number.wav /invalid.wav foobar \d+)
span style="color: goldenrod; font-weight: bold;"> 2019-07-04 16:05:47.129449 [DEBUG] switch_core_file.c:342 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pbx-extension-number.wav sample rate 22050 doesn't match requested rate 8000
2019-07-04 16:05:47.129449 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur.
2019-07-04 16:05:47.129449 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2019-07-04 16:05:47.129449 [DEBUG] sofia.c:7084 Channel sofia/default/7100815208@pbx3.inexlocal.com entering state [early][183]
2019-07-04 16:05:47.227061 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
2019-07-04 16:05:50.307057 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pbx-extension-number.wav
2019-07-04 16:05:57.327009 [ERR] mod_sndfile.c:204 Error Opening File [/invalid.wav] [System error : No such file or directory.]
2019-07-04 16:05:57.327009 [DEBUG] switch_core_file.c:342 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pbx-extension-number.wav sample rate 22050 doesn't match requested rate 8000
2019-07-04 16:05:57.327009 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur.
2019-07-04 16:05:57.327009 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2019-07-04 16:05:57.687039 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 7:800
2019-07-04 16:05:57.687039 [INFO] switch_channel.c:515 RECV DTMF 7:800
2019-07-04 16:05:57.687039 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pbx-extension-number.wav
2019-07-04 16:05:58.307049 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 1:800
2019-07-04 16:05:58.307049 [INFO] switch_channel.c:515 RECV DTMF 1:800
2019-07-04 16:05:59.407021 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 0:800
2019-07-04 16:05:59.407021 [INFO] switch_channel.c:515 RECV DTMF 0:800
2019-07-04 16:05:59.946994 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 0:800
2019-07-04 16:05:59.946994 [INFO] switch_channel.c:515 RECV DTMF 0:800
2019-07-04 16:06:03.107038 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 8:800
2019-07-04 16:06:03.107038 [INFO] switch_channel.c:515 RECV DTMF 8:800
2019-07-04 16:06:03.667023 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 1:800
2019-07-04 16:06:03.667023 [INFO] switch_channel.c:515 RECV DTMF 1:800
2019-07-04 16:06:04.247000 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 5:800
2019-07-04 16:06:04.247000 [INFO] switch_channel.c:515 RECV DTMF 5:800
2019-07-04 16:06:07.027006 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 2:800
2019-07-04 16:06:07.027006 [INFO] switch_channel.c:515 RECV DTMF 2:800
2019-07-04 16:06:07.787059 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 0:800
2019-07-04 16:06:07.787059 [INFO] switch_channel.c:515 RECV DTMF 0:800
2019-07-04 16:06:08.327010 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 8:800
2019-07-04 16:06:08.327010 [INFO] switch_channel.c:515 RECV DTMF 8:800
2019-07-04 16:06:08.946995 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF #:800
span style="color: green; font-weight: bold;"> 2019-07-04 16:06:08.946995 [INFO] switch_channel.c:515 RECV DTMF #:800
EXECUTE sofia/default/7100815208@pbx3.inexlocal.com pickup(SIP_device_7100815208)
EXECUTE sofia/default/7100815208@pbx3.inexlocal.com pickup(Allow-pick-up_7100815208)
EXECUTE sofia/default/7100815208@pbx3.inexlocal.com pickup(ABC_7100815208)
2019-07-04 16:06:08.946995 [NOTICE] switch_core_state_machine.c:385 sofia/default/7100815208@pbx3.inexlocal.com has executed the last dialplan instruction, hanging up.
2019-07-04 16:06:08.946995 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/default/7100815208@pbx3.inexlocal.com [CS_EXECUTE] [NORMAL_CLEARING]
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:650 (sofia/default/7100815208@pbx3.inexlocal.com) State EXECUTE going to sleep
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7100815208@pbx3.inexlocal.com) Running State Change CS_HANGUP (Cur 3 Tot 307)
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:850 (sofia/default/7100815208@pbx3.inexlocal.com) Callstate Change EARLY -> HANGUP
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:852 (sofia/default/7100815208@pbx3.inexlocal.com) State HANGUP
2019-07-04 16:06:08.946995 [DEBUG] mod_sofia.c:438 Channel sofia/default/7100815208@pbx3.inexlocal.com hanging up, cause: NORMAL_CLEARING
2019-07-04 16:06:08.946995 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:60 sofia/default/7100815208@pbx3.inexlocal.com Standard HANGUP, cause: NORMAL_CLEARING
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:852 (sofia/default/7100815208@pbx3.inexlocal.com) State HANGUP going to sleep
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:619 (sofia/default/7100815208@pbx3.inexlocal.com) State Change CS_HANGUP -> CS_REPORTING
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7100815208@pbx3.inexlocal.com) Running State Change CS_REPORTING (Cur 3 Tot 307)
2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:938 (sofia/default/7100815208@pbx3.inexlocal.com) State REPORTING
2019-07-04 16:06:08.946995 [INFO] mod_json_cdr.c:271 Process [7be92414-9e47-11e9-9564-2d0e45e4becc.cdr.json]
2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:174 sofia/default/7100815208@pbx3.inexlocal.com Standard REPORTING, cause: NORMAL_CLEARING
2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:938 (sofia/default/7100815208@pbx3.inexlocal.com) State REPORTING going to sleep
2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:610 (sofia/default/7100815208@pbx3.inexlocal.com) State Change CS_REPORTING -> CS_DESTROY
2019-07-04 16:06:08.967222 [DEBUG] switch_core_session.c:1665 Session 307 (sofia/default/7100815208@pbx3.inexlocal.com) Locked, Waiting on external entities
2019-07-04 16:06:08.967222 [NOTICE] switch_core_session.c:1683 Session 307 (sofia/default/7100815208@pbx3.inexlocal.com) Ended
2019-07-04 16:06:08.967222 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/7100815208@pbx3.inexlocal.com [CS_DESTROY]
2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:741 (sofia/default/7100815208@pbx3.inexlocal.com) Running State Change CS_DESTROY (Cur 2 Tot 307)
2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:751 (sofia/default/7100815208@pbx3.inexlocal.com) State DESTROY
2019-07-04 16:06:08.967222 [DEBUG] mod_sofia.c:343 sofia/default/7100815208@pbx3.inexlocal.com SOFIA DESTROY
2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:181 sofia/default/7100815208@pbx3.inexlocal.com Standard DESTROY
2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:751 (sofia/default/7100815208@pbx3.inexlocal.com) State DESTROY going to sleep
2019-07-04 16:06:14.007022 [NOTICE] switch_ivr_originate.c:3612 Hangup sofia/default/4779206277@192.168.1.13:52632 [CS_CONSUME_MEDIA] [NO_ANSWER]
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_HANGUP (Cur 2 Tot 307)
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:850 (sofia/default/4779206277@192.168.1.13:52632) Callstate Change RINGING -> HANGUP
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:852 (sofia/default/4779206277@192.168.1.13:52632) State HANGUP
2019-07-04 16:06:14.007022 [DEBUG] mod_sofia.c:438 Channel sofia/default/4779206277@192.168.1.13:52632 hanging up, cause: NO_ANSWER
2019-07-04 16:06:14.007022 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [NO_ANSWER]
2019-07-04 16:06:14.007022 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 19 [NO_ANSWER]
2019-07-04 16:06:14.007022 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NO_ANSWER
2019-07-04 16:06:14.007022 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/default/4779206277@192.168.1.13:52632
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:60 sofia/default/4779206277@192.168.1.13:52632 Standard HANGUP, cause: NO_ANSWER
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:852 (sofia/default/4779206277@192.168.1.13:52632) State HANGUP going to sleep
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:619 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_HANGUP -> CS_REPORTING
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(on_busy_flag=1)
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:584 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_REPORTING (Cur 2 Tot 307)
2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:938 (sofia/default/4779206277@192.168.1.13:52632) State REPORTING
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [on_busy_flag]=[1]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(on_busy_destination=0)
2019-07-04 16:06:14.007022 [INFO] mod_json_cdr.c:271 Process [7a959930-9e47-11e9-9560-2d0e45e4becc.cdr.json]
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [on_busy_destination]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(no_answer_flag=1)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [no_answer_flag]=[1]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(no_answer_destination=0)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [no_answer_destination]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(not_register_flag=1)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [not_register_flag]=[1]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(not_register_destination=0)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [not_register_destination]=[0]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(opensips_flag=1)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [opensips_flag]=[1]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(variable_sip_to_host=pbx3.inexlocal.com)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [variable_sip_to_host]=[pbx3.inexlocal.com]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(opensips_domain=127.0.0.1)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [opensips_domain]=[127.0.0.1]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(leg_timeout=60)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [leg_timeout]=[60]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(userinfo_id=415)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [userinfo_id]=[415]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(sip_destination_number=4779206277)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [sip_destination_number]=[4779206277]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(destination_number=919724268060)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [destination_number]=[919724268060]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(did_number=919724268060)
2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [did_number]=[919724268060]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com lua(astpp/lib/pbx/astpp-sipdevice-routing.lua)
2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:174 sofia/default/4779206277@192.168.1.13:52632 Standard REPORTING, cause: NO_ANSWER
2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:938 (sofia/default/4779206277@192.168.1.13:52632) State REPORTING going to sleep
2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:610 (sofia/default/4779206277@192.168.1.13:52632) State Change CS_REPORTING -> CS_DESTROY
2019-07-04 16:06:14.027016 [DEBUG] switch_core_session.c:1665 Session 306 (sofia/default/4779206277@192.168.1.13:52632) Locked, Waiting on external entities
2019-07-04 16:06:14.027016 [NOTICE] switch_cpp.cpp:1365 [Astpp_SIP-Devices] This is last dispositions NO_ANSWER This is SIP Number : 4779206277
2019-07-04 16:06:14.027016 [NOTICE] switch_core_session.c:1683 Session 306 (sofia/default/4779206277@192.168.1.13:52632) Ended
2019-07-04 16:06:14.027016 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/4779206277@192.168.1.13:52632 [CS_DESTROY]
2019-07-04 16:06:14.027016 [DEBUG] switch_cpp.cpp:1112 sofia/default/8889687188@pbx3.inexlocal.com destroy/unlink session from object
2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:741 (sofia/default/4779206277@192.168.1.13:52632) Running State Change CS_DESTROY (Cur 1 Tot 307)
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com answer()
2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:751 (sofia/default/4779206277@192.168.1.13:52632) State DESTROY
2019-07-04 16:06:14.027016 [DEBUG] mod_sofia.c:343 sofia/default/4779206277@192.168.1.13:52632 SOFIA DESTROY
2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:181 sofia/default/4779206277@192.168.1.13:52632 Standard DESTROY
2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:751 (sofia/default/4779206277@192.168.1.13:52632) State DESTROY going to sleep
2019-07-04 16:06:14.027016 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/8889687188@pbx3.inexlocal.com] 192.168.1.118 port 26652 -> 192.168.1.151 port 5038 codec: 0 ms: 20
2019-07-04 16:06:14.027016 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
2019-07-04 16:06:14.027016 [DEBUG] switch_core_media.c:7180 sofia/default/8889687188@pbx3.inexlocal.com Set 2833 dtmf send payload to 101
2019-07-04 16:06:14.027016 [DEBUG] switch_core_media.c:7187 sofia/default/8889687188@pbx3.inexlocal.com Set 2833 dtmf receive payload to 101
2019-07-04 16:06:14.027016 [DEBUG] switch_core_media.c:7210 sofia/default/8889687188@pbx3.inexlocal.com Set rtp dtmf delay to 40
2019-07-04 16:06:14.027016 [DEBUG] mod_sofia.c:850 Local SDP sofia/default/8889687188@pbx3.inexlocal.com:
v=0
o=FreeSWITCH 1562209922 1562209923 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 26652 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
2019-07-04 16:06:14.027016 [NOTICE] mod_dptools.c:1312 Channel [sofia/default/8889687188@pbx3.inexlocal.com] has been answered
2019-07-04 16:06:14.027016 [DEBUG] switch_channel.c:3773 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change RINGING -> ACTIVE
2019-07-04 16:06:14.027016 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [completed][200]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(voicemail_alternate_greet_id=919724268060)
2019-07-04 16:06:14.027016 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [voicemail_alternate_greet_id]=[919724268060]
EXECUTE sofia/default/8889687188@pbx3.inexlocal.com voicemail(default pbx3.inexlocal.com 4779206277)
2019-07-04 16:06:14.067068 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [ready][200]
2019-07-04 16:06:14.127017 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2019-07-04 16:06:14.147139 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-person.wav] (en:en)
2019-07-04 16:06:14.147139 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2019-07-04 16:06:14.327028 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
freeswitch@localhost.localdomain> ...