From Prashant Kumar, 2 Years ago, written in FreeSWITCH.
- go back
Embed
Viewing differences between and Directed Call Pickup Same group
  1. Type /help <enter> to see a list of commands
  2.  
  3.  
  4.  
  5.  
  6. [This app Best viewed at 160x60 or more..]
  7. +OK log level  [7]
  8. 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
  9. 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]
  10. 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)
  11. 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
  12. 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.
  13. 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
  14. 2019-07-04 16:05:05.007055 [DEBUG] switch_core_state_machine.c:603 (sofia/default/8889687188@pbx3.inexlocal.com) State NEW
  15. 2019-07-04 16:05:05.007055 [DEBUG] sofia.c:2334 detaching session 62dee30a-9e47-11e9-94fc-2d0e45e4becc
  16. 2019-07-04 16:05:05.067062 [DEBUG] sofia.c:2442 Re-attaching to session 62dee30a-9e47-11e9-94fc-2d0e45e4becc
  17. 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
  18. 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.
  19. 2019-07-04 16:05:05.087284 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [received][100]
  20. 2019-07-04 16:05:05.087284 [DEBUG] sofia.c:7094 Remote SDP:
  21. v=0
  22. o=8889687188 8001 8000 IN IP4 192.168.1.151
  23. s=SIP Call
  24. c=IN IP4 192.168.1.151
  25. t=0 0
  26. m=audio 5036 RTP/AVP 0 8 4 18 9 97 2 101
  27. a=rtpmap:0 PCMU/8000
  28. a=rtpmap:8 PCMA/8000
  29. a=rtpmap:4 G723/8000
  30. a=rtpmap:18 G729/8000
  31. a=fmtp:18 annexb=no
  32. a=rtpmap:9 G722/8000
  33. a=rtpmap:97 iLBC/8000
  34. a=fmtp:97 mode=30
  35. a=rtpmap:2 G726-32/8000
  36. a=rtpmap:101 telephone-event/8000
  37. a=fmtp:101 0-15
  38. a=ptime:20
  39.  
  40. 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]
  41. 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]
  42. 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
  43. 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]
  44. 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
  45. 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]
  46. 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]
  47. 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]
  48. 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]
  49. 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]
  50. 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]
  51. 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]
  52. 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]
  53. 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]
  54. 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]
  55. 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]
  56. 2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  57. 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
  58. 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
  59. 2019-07-04 16:05:05.087284 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  60. 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
  61. 2019-07-04 16:05:05.087284 [DEBUG] sofia.c:7507 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_NEW -> CS_INIT
  62. 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)
  63. 2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:627 (sofia/default/8889687188@pbx3.inexlocal.com) State INIT
  64. 2019-07-04 16:05:05.087284 [DEBUG] mod_sofia.c:90 sofia/default/8889687188@pbx3.inexlocal.com SOFIA INIT
  65. 2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:40 sofia/default/8889687188@pbx3.inexlocal.com Standard INIT
  66. 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
  67. 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
  68. 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)
  69. 2019-07-04 16:05:05.087284 [DEBUG] switch_channel.c:2249 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change DOWN -> RINGING
  70. 2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:643 (sofia/default/8889687188@pbx3.inexlocal.com) State ROUTING
  71. 2019-07-04 16:05:05.087284 [DEBUG] mod_sofia.c:143 sofia/default/8889687188@pbx3.inexlocal.com SOFIA ROUTING
  72. 2019-07-04 16:05:05.087284 [DEBUG] switch_core_state_machine.c:236 sofia/default/8889687188@pbx3.inexlocal.com Standard ROUTING
  73. 2019-07-04 16:05:05.087284 [INFO] mod_dialplan_xml.c:637 Processing 8889687188 <8889687188>->919724268060 in context default
  74. 2019-07-04 16:05:05.087284 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f6b8805e880 Connected.
  75. 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')
  76. 2019-07-04 16:05:05.087284 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  77. 2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] blind_flag: 0
  78. 2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 919724268060
  79. 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
  80. 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
  81. 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
  82. 2019-07-04 16:05:05.127070 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FAXER] in custom Caller ID
  83. 2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number  : 8889687188 / 8889687188
  84. 2019-07-04 16:05:05.127070 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  85. 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
  86. 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
  87. 2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : inbound
  88. 2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 8889687188]
  89. 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
  90. 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
  91. 2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 919724268060
  92. 2019-07-04 16:05:05.127070 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  93. 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
  94. 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
  95. 2019-07-04 16:05:05.127070 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] New Call direction : inbound
  96. 2019-07-04 16:05:05.127070 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  97. 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
  98. 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
  99. 2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
  100. 2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :415
  101. 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
  102. 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
  103. 2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] Call Barring Status : -1
  104. 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
  105. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
  106. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 415
  107. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 8889687188
  108. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 4839.9
  109. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 1 [0:prepaid,1:postpaid]
  110. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 4
  111. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] CID Pool : 0
  112. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
  113. 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
  114. 2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :inbound
  115. 2019-07-04 16:05:05.147031 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  116. 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
  117. 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
  118. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: inbound
  119. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
  120. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 13095
  121. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
  122. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
  123. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 1.50000
  124. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : test Gandhinagar
  125. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
  126. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
  127. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
  128. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
  129. 2019-07-04 16:05:05.147031 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
  130. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes
  131. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] INB_FREE:TRUE
  132. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] free_inbound:0
  133. 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
  134. 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
  135. 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
  136. 2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :outbound
  137. 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
  138. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: outbound
  139. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
  140. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 11
  141. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
  142. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
  143. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.60000
  144. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : Ahmedabad-Urban
  145. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
  146. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
  147. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Trunk ID:
  148. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] Routing type:
  149. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
  150. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
  151. 2019-07-04 16:05:05.147031 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
  152. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML:415
  153. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Userinfo XML:415
  154. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML : 415
  155. 2019-07-04 16:05:05.147031 [INFO] switch_cpp.cpp:1365 [ASTPP] maxlength::::::::: 100
  156. 2019-07-04 16:05:05.147031 [DEBUG] switch_cpp.cpp:1365 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_0
  157. 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
  158. 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
  159. 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
  160. 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
  161. 2019-07-04 16:05:05.167246 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] user_domain beforepbx3.inexlocal.com
  162. 2019-07-04 16:05:05.167246 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] pickup_group_permission pickup_str
  163. 2019-07-04 16:05:05.167246 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [NOTIFY] START:
  164. 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'
  165. 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
  166. 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
  167. 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"?>
  168. <document type="freeswitch/xml">
  169. <section name="dialplan" description="ASTPP Dialplan">
  170. <context name="default">
  171. <extension name="919724268060">
  172. <condition field="destination_number" expression="919724268060">
  173. <action application="set" data="effective_destination_number=919724268060"/>
  174. <action application="set" data="bridge_pre_execute_bleg_app=sched_hangup"/>
  175. <action application="set" data="bridge_pre_execute_bleg_data=+6000 normal_clearing"/>
  176. <action application="set" data="callstart=2019-07-04 10:35:05"/>
  177. <action application="set" data="hangup_after_bridge=true"/>
  178. <action application="set" data="continue_on_fail=TRUE"/>
  179. <action application="set" data="account_id=415"/>
  180. <action application="set" data="parent_id=0"/>
  181. <action application="set" data="entity_id=0"/>
  182. <action application="set" data="call_processed=internal"/>
  183. <action application="set" data="call_direction=inbound"/>
  184. <action application="set" data="accountname=default"/>
  185. <action application="set" data="filename1=astpp.pbx.lua"/>
  186. <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"/>
  187. <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"/>
  188. <action application="set" data="original_caller_id_name=8889687188"/>
  189. <action application="set" data="original_caller_id_number=8889687188"/>
  190. <action application="set" data="effective_caller_id_name=8889687188"/>
  191. <action application="set" data="effective_caller_id_number=8889687188"/>
  192. <action application="set" data="receiver_accid=415"/>
  193. <action application="export" data="presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID"/>
  194. <action application="export" data="call_type=0"/>
  195. <action application="set" data="calltype=DID-LOCAL"/>
  196. <action application="db" data="insert/pickup_any_group_${callgroup}/4779206277/${uuid}"/>
  197. <action application="set" data="dialed_extension=transfer_call"/>
  198. <action application="export" data="dialed_extension=transfer_call"/>
  199. <action application="bind_meta_app" data="95 b s execute_extension::transfer_call_95 XML default"/>
  200. <action application="bind_meta_app" data="94 b s execute_extension::transfer_call_94 XML default"/>
  201. <action application="set" data="hangup_after_bridge=true"/>
  202. <action application="export" data="did_user_domain=pbx3.inexlocal.com"/>
  203. <action application="ring_ready"/>
  204. <action application="sleep" data="5000"/>
  205. <action application="bridge" data="{sip_invite_params=user=LOCAL,sip_from_uri=4779206277@${domain_name}}[leg_timeout=30]user/4779206277@${domain_name}"/>
  206. <action application="set" data="on_busy_flag=1"/>
  207. <action application="set" data="on_busy_destination=0"/>
  208. <action application="set" data="no_answer_flag=1"/>
  209. <action application="set" data="no_answer_destination=0"/>
  210. <action application="set" data="not_register_flag=1"/>
  211. <action application="set" data="not_register_destination=0"/>
  212. <action application="set" data="opensips_flag=1"/>
  213. <action application="set" data="variable_sip_to_host=pbx3.inexlocal.com"/>
  214. <action application="set" data="opensips_domain=127.0.0.1"/>
  215. <action application="set" data="leg_timeout=60"/>
  216. <action application="set" data="userinfo_id=415"/>
  217. <action application="set" data="sip_destination_number=4779206277"/>
  218. <action application="set" data="destination_number=919724268060"/>
  219. <action application="set" data="did_number=919724268060"/>
  220. <action application="lua" data="astpp/lib/pbx/astpp-sipdevice-routing.lua"/>
  221. <condition field="${cond(${user_data 4779206277@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
  222. <action application="answer"/>
  223. <action application="export" data="voicemail_alternate_greet_id=919724268060"/>
  224. <action application="voicemail" data="default $${domain_name} 4779206277"/>
  225. <anti-action application="hangup" data="${originate_disposition}"/>
  226. </condition>
  227. </condition>
  228. </extension>
  229. </context>
  230. </section>
  231. </document>
  232. 2019-07-04 16:05:05.167246 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f6b8805e880 released.
  233. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com parsing [default->919724268060] continue=false
  234. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Regex (PASS) [919724268060] destination_number(919724268060) =~ /919724268060/ break=on-false
  235. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_destination_number=919724268060)
  236. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_app=sched_hangup)
  237. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  238. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(callstart=2019-07-04 10:35:05)
  239. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
  240. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(continue_on_fail=TRUE)
  241. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(account_id=415)
  242. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(parent_id=0)
  243. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(entity_id=0)
  244. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_processed=internal)
  245. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_direction=inbound)
  246. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(accountname=default)
  247. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(filename1=astpp.pbx.lua)
  248. 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)
  249. 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)
  250. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_name=8889687188)
  251. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_number=8889687188)
  252. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_name=8889687188)
  253. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_number=8889687188)
  254. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(receiver_accid=415)
  255. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
  256. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(call_type=0)
  257. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(calltype=DID-LOCAL)
  258. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action db(insert/pickup_any_group_${callgroup}/4779206277/${uuid})
  259. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(dialed_extension=transfer_call)
  260. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(dialed_extension=transfer_call)
  261. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
  262. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
  263. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
  264. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(did_user_domain=pbx3.inexlocal.com)
  265. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action ring_ready()
  266. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action sleep(5000)
  267. 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})
  268. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_flag=1)
  269. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_destination=0)
  270. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_flag=1)
  271. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_destination=0)
  272. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_flag=1)
  273. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_destination=0)
  274. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_flag=1)
  275. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(variable_sip_to_host=pbx3.inexlocal.com)
  276. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_domain=127.0.0.1)
  277. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(leg_timeout=60)
  278. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(userinfo_id=415)
  279. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(sip_destination_number=4779206277)
  280. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(destination_number=919724268060)
  281. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(did_number=919724268060)
  282. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action lua(astpp/lib/pbx/astpp-sipdevice-routing.lua)
  283. |--- Dialplan: Processing recursive conditions level:1 [919724268060_recur_1] require-nested=TRUE
  284. |--- 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
  285. |--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action answer()
  286. |--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(voicemail_alternate_greet_id=919724268060)
  287. |--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action voicemail(default $${domain_name} 4779206277)
  288. 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
  289. 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
  290. 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)
  291. 2019-07-04 16:05:05.187074 [DEBUG] switch_core_state_machine.c:650 (sofia/default/8889687188@pbx3.inexlocal.com) State EXECUTE
  292. 2019-07-04 16:05:05.187074 [DEBUG] mod_sofia.c:198 sofia/default/8889687188@pbx3.inexlocal.com SOFIA EXECUTE
  293. 2019-07-04 16:05:05.187074 [DEBUG] switch_core_state_machine.c:328 sofia/default/8889687188@pbx3.inexlocal.com Standard EXECUTE
  294. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_destination_number=919724268060)
  295. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_destination_number]=[919724268060]
  296. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_app=sched_hangup)
  297. 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]
  298. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  299. 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]
  300. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(callstart=2019-07-04 10:35:05)
  301. 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]
  302. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
  303. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
  304. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(continue_on_fail=TRUE)
  305. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [continue_on_fail]=[TRUE]
  306. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(account_id=415)
  307. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [account_id]=[415]
  308. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(parent_id=0)
  309. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [parent_id]=[0]
  310. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(entity_id=0)
  311. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [entity_id]=[0]
  312. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_processed=internal)
  313. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_processed]=[internal]
  314. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_direction=inbound)
  315. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_direction]=[inbound]
  316. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(accountname=default)
  317. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [accountname]=[default]
  318. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(filename1=astpp.pbx.lua)
  319. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [filename1]=[astpp.pbx.lua]
  320. 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)
  321. 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]
  322. 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)
  323. 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]
  324. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_name=8889687188)
  325. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_name]=[8889687188]
  326. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_number=8889687188)
  327. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_number]=[8889687188]
  328. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_name=8889687188)
  329. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_name]=[8889687188]
  330. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_number=8889687188)
  331. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_number]=[8889687188]
  332. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(receiver_accid=415)
  333. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [receiver_accid]=[415]
  334. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
  335. 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]
  336. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(call_type=0)
  337. 2019-07-04 16:05:05.187074 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_type]=[0]
  338. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(calltype=DID-LOCAL)
  339. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [calltype]=[DID-LOCAL]
  340. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com db(insert/pickup_any_group_/4779206277/62dee30a-9e47-11e9-94fc-2d0e45e4becc)
  341. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(dialed_extension=transfer_call)
  342. 2019-07-04 16:05:05.187074 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [dialed_extension]=[transfer_call]
  343. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(dialed_extension=transfer_call)
  344. 2019-07-04 16:05:05.207036 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[transfer_call]
  345. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
  346. 2019-07-04 16:05:05.207036 [ERR] switch_ivr_async.c:4146 Invalid key 95
  347. 2019-07-04 16:05:05.207036 [ERR] mod_dptools.c:786 Bind Error!
  348. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
  349. 2019-07-04 16:05:05.207036 [ERR] switch_ivr_async.c:4146 Invalid key 94
  350. 2019-07-04 16:05:05.207036 [ERR] mod_dptools.c:786 Bind Error!
  351. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
  352. 2019-07-04 16:05:05.207036 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
  353. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(did_user_domain=pbx3.inexlocal.com)
  354. 2019-07-04 16:05:05.207036 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [did_user_domain]=[pbx3.inexlocal.com]
  355. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com ring_ready()
  356. 2019-07-04 16:05:05.207036 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/default/8889687188@pbx3.inexlocal.com!
  357. 2019-07-04 16:05:05.207036 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [early][180]
  358. 2019-07-04 16:05:05.207036 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
  359. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com sleep(5000)
  360. 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)
  361. 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
  362. 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
  363. 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
  364. 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
  365. 2019-07-04 16:05:10.347021 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  366. 2019-07-04 16:05:10.347021 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
  367. 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
  368. 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
  369. 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
  370. 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
  371. 2019-07-04 16:05:10.627063 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  372. 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]
  373. 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
  374. 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
  375. 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)
  376. 2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:627 (sofia/default/4779206277@192.168.1.13:52632) State INIT
  377. 2019-07-04 16:05:10.627063 [DEBUG] mod_sofia.c:90 sofia/default/4779206277@192.168.1.13:52632 SOFIA INIT
  378. 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
  379. Local SDP:
  380. v=0
  381. o=FreeSWITCH 1562210176 1562210177 IN IP4 192.168.1.118
  382. s=FreeSWITCH
  383. c=IN IP4 192.168.1.118
  384. t=0 0
  385. m=audio 26334 RTP/AVP 0 101
  386. a=rtpmap:0 PCMU/8000
  387. a=rtpmap:101 telephone-event/8000
  388. a=fmtp:101 0-16
  389. a=ptime:20
  390. a=sendrecv
  391.  
  392. 2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:40 sofia/default/4779206277@192.168.1.13:52632 Standard INIT
  393. 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
  394. 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
  395. 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)
  396. 2019-07-04 16:05:10.627063 [DEBUG] switch_core_state_machine.c:643 (sofia/default/4779206277@192.168.1.13:52632) State ROUTING
  397. 2019-07-04 16:05:10.627063 [DEBUG] mod_sofia.c:143 sofia/default/4779206277@192.168.1.13:52632 SOFIA ROUTING
  398. 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
  399. 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
  400. 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)
  401. 2019-07-04 16:05:10.627063 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [calling][0]
  402. 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
  403. 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
  404. 2019-07-04 16:05:10.727027 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [proceeding][180]
  405. 2019-07-04 16:05:10.727027 [NOTICE] sofia.c:7192 Ring-Ready sofia/default/4779206277@192.168.1.13:52632!
  406. 2019-07-04 16:05:10.727027 [DEBUG] switch_channel.c:3346 (sofia/default/4779206277@192.168.1.13:52632) Callstate Change DOWN -> RINGING
  407. 2019-07-04 16:05:10.747027 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
  408. 2019-07-04 16:05:14.467024 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [terminated][487]
  409. 2019-07-04 16:05:14.467024 [NOTICE] sofia.c:8273 Hangup sofia/default/8889687188@pbx3.inexlocal.com [CS_EXECUTE] [ORIGINATOR_CANCEL]
  410. 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]
  411. 2019-07-04 16:05:14.487037 [DEBUG] switch_ivr_originate.c:3837 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
  412. 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)
  413. 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
  414. 2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:852 (sofia/default/4779206277@192.168.1.13:52632) State HANGUP
  415. 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
  416. 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
  417. 2019-07-04 16:05:14.487037 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL]
  418. 2019-07-04 16:05:14.487037 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL]
  419. 2019-07-04 16:05:14.487037 [INFO] mod_dptools.c:3436 Originate Failed.  Cause: ORIGINATOR_CANCEL
  420. 2019-07-04 16:05:14.487037 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/default/4779206277@192.168.1.13:52632
  421. 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
  422. 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
  423. 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
  424. 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)
  425. 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
  426. 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)
  427. 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)
  428. 2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:850 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change RINGING -> HANGUP
  429. 2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:938 (sofia/default/4779206277@192.168.1.13:52632) State REPORTING
  430. 2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:852 (sofia/default/8889687188@pbx3.inexlocal.com) State HANGUP
  431. 2019-07-04 16:05:14.487037 [DEBUG] mod_sofia.c:438 Channel sofia/default/8889687188@pbx3.inexlocal.com hanging up, cause: ORIGINATOR_CANCEL
  432. 2019-07-04 16:05:14.487037 [INFO] mod_json_cdr.c:271 Process [6638483e-9e47-11e9-9529-2d0e45e4becc.cdr.json]
  433. 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
  434. 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
  435. 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
  436. 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)
  437. 2019-07-04 16:05:14.487037 [DEBUG] switch_core_state_machine.c:938 (sofia/default/8889687188@pbx3.inexlocal.com) State REPORTING
  438. 2019-07-04 16:05:14.487037 [INFO] mod_json_cdr.c:271 Process [62dee30a-9e47-11e9-94fc-2d0e45e4becc.cdr.json]
  439. 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
  440. 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
  441. 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
  442. 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
  443. 2019-07-04 16:05:14.506997 [NOTICE] switch_core_session.c:1683 Session 304 (sofia/default/4779206277@192.168.1.13:52632) Ended
  444. 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]
  445. 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)
  446. 2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:751 (sofia/default/4779206277@192.168.1.13:52632) State DESTROY
  447. 2019-07-04 16:05:14.506997 [DEBUG] mod_sofia.c:343 sofia/default/4779206277@192.168.1.13:52632 SOFIA DESTROY
  448. 2019-07-04 16:05:14.506997 [DEBUG] switch_core_state_machine.c:181 sofia/default/4779206277@192.168.1.13:52632 Standard DESTROY
  449. 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
  450. 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
  451. 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
  452. 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
  453. 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
  454. 2019-07-04 16:05:14.726996 [NOTICE] switch_core_session.c:1683 Session 303 (sofia/default/8889687188@pbx3.inexlocal.com) Ended
  455. 2019-07-04 16:05:14.726996 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/8889687188@pbx3.inexlocal.com [CS_DESTROY]
  456. 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)
  457. 2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:751 (sofia/default/8889687188@pbx3.inexlocal.com) State DESTROY
  458. 2019-07-04 16:05:14.726996 [DEBUG] mod_sofia.c:343 sofia/default/8889687188@pbx3.inexlocal.com SOFIA DESTROY
  459. 2019-07-04 16:05:14.726996 [DEBUG] switch_core_state_machine.c:181 sofia/default/8889687188@pbx3.inexlocal.com Standard DESTROY
  460. 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
  461. 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
  462. 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
  463. You must define a domain called '192.168.1.118' in your directory and add a user with the id="4727985745" attribute
  464. and you must configure your device to use the proper domain in it's authentication credentials.
  465. 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
  466. 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]
  467. 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)
  468. 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
  469. 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.
  470. 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
  471. 2019-07-04 16:05:39.467047 [DEBUG] switch_core_state_machine.c:603 (sofia/default/8889687188@pbx3.inexlocal.com) State NEW
  472. 2019-07-04 16:05:39.467047 [DEBUG] sofia.c:2334 detaching session 7769e32e-9e47-11e9-9533-2d0e45e4becc
  473. 2019-07-04 16:05:39.527020 [DEBUG] sofia.c:2442 Re-attaching to session 7769e32e-9e47-11e9-9533-2d0e45e4becc
  474. 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
  475. 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.
  476. 2019-07-04 16:05:39.547044 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [received][100]
  477. 2019-07-04 16:05:39.547044 [DEBUG] sofia.c:7094 Remote SDP:
  478. v=0
  479. o=8889687188 8001 8000 IN IP4 192.168.1.151
  480. s=SIP Call
  481. c=IN IP4 192.168.1.151
  482. t=0 0
  483. m=audio 5038 RTP/AVP 0 8 4 18 9 97 2 101
  484. a=rtpmap:0 PCMU/8000
  485. a=rtpmap:8 PCMA/8000
  486. a=rtpmap:4 G723/8000
  487. a=rtpmap:18 G729/8000
  488. a=fmtp:18 annexb=no
  489. a=rtpmap:9 G722/8000
  490. a=rtpmap:97 iLBC/8000
  491. a=fmtp:97 mode=30
  492. a=rtpmap:2 G726-32/8000
  493. a=rtpmap:101 telephone-event/8000
  494. a=fmtp:101 0-15
  495. a=ptime:20
  496.  
  497. 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]
  498. 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]
  499. 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
  500. 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]
  501. 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
  502. 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]
  503. 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]
  504. 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]
  505. 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]
  506. 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]
  507. 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]
  508. 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]
  509. 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]
  510. 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]
  511. 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]
  512. 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]
  513. 2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  514. 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
  515. 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
  516. 2019-07-04 16:05:39.547044 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  517. 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
  518. 2019-07-04 16:05:39.547044 [DEBUG] sofia.c:7507 (sofia/default/8889687188@pbx3.inexlocal.com) State Change CS_NEW -> CS_INIT
  519. 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)
  520. 2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:627 (sofia/default/8889687188@pbx3.inexlocal.com) State INIT
  521. 2019-07-04 16:05:39.547044 [DEBUG] mod_sofia.c:90 sofia/default/8889687188@pbx3.inexlocal.com SOFIA INIT
  522. 2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:40 sofia/default/8889687188@pbx3.inexlocal.com Standard INIT
  523. 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
  524. 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
  525. 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)
  526. 2019-07-04 16:05:39.547044 [DEBUG] switch_channel.c:2249 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change DOWN -> RINGING
  527. 2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:643 (sofia/default/8889687188@pbx3.inexlocal.com) State ROUTING
  528. 2019-07-04 16:05:39.547044 [DEBUG] mod_sofia.c:143 sofia/default/8889687188@pbx3.inexlocal.com SOFIA ROUTING
  529. 2019-07-04 16:05:39.547044 [DEBUG] switch_core_state_machine.c:236 sofia/default/8889687188@pbx3.inexlocal.com Standard ROUTING
  530. 2019-07-04 16:05:39.547044 [INFO] mod_dialplan_xml.c:637 Processing 8889687188 <8889687188>->919724268060 in context default
  531. 2019-07-04 16:05:39.547044 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f6b8805e880 Connected.
  532. 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')
  533. 2019-07-04 16:05:39.547044 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  534. 2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] blind_flag: 0
  535. 2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 919724268060
  536. 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
  537. 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
  538. 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
  539. 2019-07-04 16:05:39.587050 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FAXER] in custom Caller ID
  540. 2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number  : 8889687188 / 8889687188
  541. 2019-07-04 16:05:39.587050 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  542. 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
  543. 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
  544. 2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : inbound
  545. 2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 8889687188]
  546. 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
  547. 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
  548. 2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 919724268060
  549. 2019-07-04 16:05:39.587050 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  550. 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
  551. 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
  552. 2019-07-04 16:05:39.587050 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] New Call direction : inbound
  553. 2019-07-04 16:05:39.587050 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  554. 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
  555. 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
  556. 2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] call_direction :inbound
  557. 2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] DID_ACCOUNTID :415
  558. 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
  559. 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
  560. 2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] Call Barring Status : -1
  561. 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
  562. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
  563. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 415
  564. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 8889687188
  565. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 4839.9
  566. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 1 [0:prepaid,1:postpaid]
  567. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 4
  568. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] CID Pool : 0
  569. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
  570. 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
  571. 2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :inbound
  572. 2019-07-04 16:05:39.607189 [NOTICE] switch_cpp.cpp:1365 [ASTPP] HARSH2: 5
  573. 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
  574. 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
  575. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: inbound
  576. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
  577. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 13095
  578. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
  579. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
  580. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 1.50000
  581. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : test Gandhinagar
  582. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
  583. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
  584. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
  585. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
  586. 2019-07-04 16:05:39.607189 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
  587. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes
  588. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] INB_FREE:TRUE
  589. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] free_inbound:0
  590. 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
  591. 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
  592. 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
  593. 2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] call_direction :outbound
  594. 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
  595. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] call_direction:::::: outbound
  596. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information ===================
  597. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 11
  598. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000
  599. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0
  600. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.60000
  601. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : Ahmedabad-Urban
  602. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Country Id : 88
  603. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 415
  604. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Trunk ID:
  605. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] Routing type:
  606. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================
  607. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Your4839.9 balance Accountid 415 !!!
  608. 2019-07-04 16:05:39.607189 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Limiting call to config max length 100 mins!
  609. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML:415
  610. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Userinfo XML:415
  611. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML : 415
  612. 2019-07-04 16:05:39.607189 [INFO] switch_cpp.cpp:1365 [ASTPP] maxlength::::::::: 100
  613. 2019-07-04 16:05:39.607189 [DEBUG] switch_cpp.cpp:1365 [ASTPP] custom_function_name:::::::::::::::::::::::::custom_inbound_0
  614. 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
  615. 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
  616. 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
  617. 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
  618. 2019-07-04 16:05:39.627064 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] user_domain beforepbx3.inexlocal.com
  619. 2019-07-04 16:05:39.627064 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] pickup_group_permission pickup_str
  620. 2019-07-04 16:05:39.627064 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [NOTIFY] START:
  621. 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'
  622. 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
  623. 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
  624. 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"?>
  625. <document type="freeswitch/xml">
  626. <section name="dialplan" description="ASTPP Dialplan">
  627. <context name="default">
  628. <extension name="919724268060">
  629. <condition field="destination_number" expression="919724268060">
  630. <action application="set" data="effective_destination_number=919724268060"/>
  631. <action application="set" data="bridge_pre_execute_bleg_app=sched_hangup"/>
  632. <action application="set" data="bridge_pre_execute_bleg_data=+6000 normal_clearing"/>
  633. <action application="set" data="callstart=2019-07-04 10:35:39"/>
  634. <action application="set" data="hangup_after_bridge=true"/>
  635. <action application="set" data="continue_on_fail=TRUE"/>
  636. <action application="set" data="account_id=415"/>
  637. <action application="set" data="parent_id=0"/>
  638. <action application="set" data="entity_id=0"/>
  639. <action application="set" data="call_processed=internal"/>
  640. <action application="set" data="call_direction=inbound"/>
  641. <action application="set" data="accountname=default"/>
  642. <action application="set" data="filename1=astpp.pbx.lua"/>
  643. <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"/>
  644. <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"/>
  645. <action application="set" data="original_caller_id_name=8889687188"/>
  646. <action application="set" data="original_caller_id_number=8889687188"/>
  647. <action application="set" data="effective_caller_id_name=8889687188"/>
  648. <action application="set" data="effective_caller_id_number=8889687188"/>
  649. <action application="set" data="receiver_accid=415"/>
  650. <action application="export" data="presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID"/>
  651. <action application="export" data="call_type=0"/>
  652. <action application="set" data="calltype=DID-LOCAL"/>
  653. <action application="db" data="insert/pickup_any_group_${callgroup}/4779206277/${uuid}"/>
  654. <action application="set" data="dialed_extension=transfer_call"/>
  655. <action application="export" data="dialed_extension=transfer_call"/>
  656. <action application="bind_meta_app" data="95 b s execute_extension::transfer_call_95 XML default"/>
  657. <action application="bind_meta_app" data="94 b s execute_extension::transfer_call_94 XML default"/>
  658. <action application="set" data="hangup_after_bridge=true"/>
  659. <action application="export" data="did_user_domain=pbx3.inexlocal.com"/>
  660. <action application="ring_ready"/>
  661. <action application="sleep" data="5000"/>
  662. <action application="bridge" data="{sip_invite_params=user=LOCAL,sip_from_uri=4779206277@${domain_name}}[leg_timeout=30]user/4779206277@${domain_name}"/>
  663. <action application="set" data="on_busy_flag=1"/>
  664. <action application="set" data="on_busy_destination=0"/>
  665. <action application="set" data="no_answer_flag=1"/>
  666. <action application="set" data="no_answer_destination=0"/>
  667. <action application="set" data="not_register_flag=1"/>
  668. <action application="set" data="not_register_destination=0"/>
  669. <action application="set" data="opensips_flag=1"/>
  670. <action application="set" data="variable_sip_to_host=pbx3.inexlocal.com"/>
  671. <action application="set" data="opensips_domain=127.0.0.1"/>
  672. <action application="set" data="leg_timeout=60"/>
  673. <action application="set" data="userinfo_id=415"/>
  674. <action application="set" data="sip_destination_number=4779206277"/>
  675. <action application="set" data="destination_number=919724268060"/>
  676. <action application="set" data="did_number=919724268060"/>
  677. <action application="lua" data="astpp/lib/pbx/astpp-sipdevice-routing.lua"/>
  678. <condition field="${cond(${user_data 4779206277@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
  679. <action application="answer"/>
  680. <action application="export" data="voicemail_alternate_greet_id=919724268060"/>
  681. <action application="voicemail" data="default $${domain_name} 4779206277"/>
  682. <anti-action application="hangup" data="${originate_disposition}"/>
  683. </condition>
  684. </condition>
  685. </extension>
  686. </context>
  687. </section>
  688. </document>
  689. 2019-07-04 16:05:39.627064 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f6b8805e880 released.
  690. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com parsing [default->919724268060] continue=false
  691. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Regex (PASS) [919724268060] destination_number(919724268060) =~ /919724268060/ break=on-false
  692. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_destination_number=919724268060)
  693. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_app=sched_hangup)
  694. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  695. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(callstart=2019-07-04 10:35:39)
  696. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
  697. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(continue_on_fail=TRUE)
  698. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(account_id=415)
  699. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(parent_id=0)
  700. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(entity_id=0)
  701. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_processed=internal)
  702. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(call_direction=inbound)
  703. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(accountname=default)
  704. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(filename1=astpp.pbx.lua)
  705. 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)
  706. 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)
  707. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_name=8889687188)
  708. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(original_caller_id_number=8889687188)
  709. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_name=8889687188)
  710. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(effective_caller_id_number=8889687188)
  711. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(receiver_accid=415)
  712. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
  713. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(call_type=0)
  714. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(calltype=DID-LOCAL)
  715. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action db(insert/pickup_any_group_${callgroup}/4779206277/${uuid})
  716. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(dialed_extension=transfer_call)
  717. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(dialed_extension=transfer_call)
  718. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
  719. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
  720. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(hangup_after_bridge=true)
  721. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(did_user_domain=pbx3.inexlocal.com)
  722. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action ring_ready()
  723. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action sleep(5000)
  724. 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})
  725. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_flag=1)
  726. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(on_busy_destination=0)
  727. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_flag=1)
  728. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(no_answer_destination=0)
  729. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_flag=1)
  730. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(not_register_destination=0)
  731. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_flag=1)
  732. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(variable_sip_to_host=pbx3.inexlocal.com)
  733. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(opensips_domain=127.0.0.1)
  734. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(leg_timeout=60)
  735. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(userinfo_id=415)
  736. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(sip_destination_number=4779206277)
  737. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(destination_number=919724268060)
  738. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action set(did_number=919724268060)
  739. Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action lua(astpp/lib/pbx/astpp-sipdevice-routing.lua)
  740. |--- Dialplan: Processing recursive conditions level:1 [919724268060_recur_1] require-nested=TRUE
  741. |--- 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
  742. |--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action answer()
  743. |--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action export(voicemail_alternate_greet_id=919724268060)
  744. |--- Dialplan: sofia/default/8889687188@pbx3.inexlocal.com Action voicemail(default $${domain_name} 4779206277)
  745. 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
  746. 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
  747. 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)
  748. 2019-07-04 16:05:39.667045 [DEBUG] switch_core_state_machine.c:650 (sofia/default/8889687188@pbx3.inexlocal.com) State EXECUTE
  749. 2019-07-04 16:05:39.667045 [DEBUG] mod_sofia.c:198 sofia/default/8889687188@pbx3.inexlocal.com SOFIA EXECUTE
  750. 2019-07-04 16:05:39.667045 [DEBUG] switch_core_state_machine.c:328 sofia/default/8889687188@pbx3.inexlocal.com Standard EXECUTE
  751. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_destination_number=919724268060)
  752. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_destination_number]=[919724268060]
  753. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_app=sched_hangup)
  754. 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]
  755. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(bridge_pre_execute_bleg_data=+6000 normal_clearing)
  756. 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]
  757. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(callstart=2019-07-04 10:35:39)
  758. 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]
  759. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
  760. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
  761. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(continue_on_fail=TRUE)
  762. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [continue_on_fail]=[TRUE]
  763. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(account_id=415)
  764. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [account_id]=[415]
  765. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(parent_id=0)
  766. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [parent_id]=[0]
  767. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(entity_id=0)
  768. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [entity_id]=[0]
  769. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_processed=internal)
  770. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_processed]=[internal]
  771. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(call_direction=inbound)
  772. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [call_direction]=[inbound]
  773. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(accountname=default)
  774. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [accountname]=[default]
  775. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(filename1=astpp.pbx.lua)
  776. 2019-07-04 16:05:39.667045 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [filename1]=[astpp.pbx.lua]
  777. 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)
  778. 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]
  779. 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)
  780. 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]
  781. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_name=8889687188)
  782. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_name]=[8889687188]
  783. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(original_caller_id_number=8889687188)
  784. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [original_caller_id_number]=[8889687188]
  785. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_name=8889687188)
  786. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_name]=[8889687188]
  787. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(effective_caller_id_number=8889687188)
  788. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [effective_caller_id_number]=[8889687188]
  789. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(receiver_accid=415)
  790. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [receiver_accid]=[415]
  791. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(presence_data=x|||PBX(8889687188)|||^919724268060.* // test Gandhinagar // 1.50000||||||DID)
  792. 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]
  793. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(call_type=0)
  794. 2019-07-04 16:05:39.686997 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_type]=[0]
  795. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(calltype=DID-LOCAL)
  796. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [calltype]=[DID-LOCAL]
  797. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com db(insert/pickup_any_group_/4779206277/7769e32e-9e47-11e9-9533-2d0e45e4becc)
  798. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(dialed_extension=transfer_call)
  799. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [dialed_extension]=[transfer_call]
  800. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(dialed_extension=transfer_call)
  801. 2019-07-04 16:05:39.686997 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[transfer_call]
  802. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(95 b s execute_extension::transfer_call_95 XML default)
  803. 2019-07-04 16:05:39.686997 [ERR] switch_ivr_async.c:4146 Invalid key 95
  804. 2019-07-04 16:05:39.686997 [ERR] mod_dptools.c:786 Bind Error!
  805. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com bind_meta_app(94 b s execute_extension::transfer_call_94 XML default)
  806. 2019-07-04 16:05:39.686997 [ERR] switch_ivr_async.c:4146 Invalid key 94
  807. 2019-07-04 16:05:39.686997 [ERR] mod_dptools.c:786 Bind Error!
  808. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(hangup_after_bridge=true)
  809. 2019-07-04 16:05:39.686997 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [hangup_after_bridge]=[true]
  810. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(did_user_domain=pbx3.inexlocal.com)
  811. 2019-07-04 16:05:39.686997 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [did_user_domain]=[pbx3.inexlocal.com]
  812. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com ring_ready()
  813. 2019-07-04 16:05:39.686997 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/default/8889687188@pbx3.inexlocal.com!
  814. 2019-07-04 16:05:39.686997 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [early][180]
  815. 2019-07-04 16:05:39.686997 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
  816. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com sleep(5000)
  817. 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)
  818. 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
  819. 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
  820. 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
  821. 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
  822. 2019-07-04 16:05:44.727017 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  823. 2019-07-04 16:05:44.727017 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
  824. 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
  825. 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
  826. 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
  827. 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
  828. 2019-07-04 16:05:44.787026 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  829. 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]
  830. 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
  831. 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
  832. 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)
  833. 2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:627 (sofia/default/4779206277@192.168.1.13:52632) State INIT
  834. 2019-07-04 16:05:44.787026 [DEBUG] mod_sofia.c:90 sofia/default/4779206277@192.168.1.13:52632 SOFIA INIT
  835. 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
  836. Local SDP:
  837. v=0
  838. o=FreeSWITCH 1562215530 1562215531 IN IP4 192.168.1.118
  839. s=FreeSWITCH
  840. c=IN IP4 192.168.1.118
  841. t=0 0
  842. m=audio 21014 RTP/AVP 0 101
  843. a=rtpmap:0 PCMU/8000
  844. a=rtpmap:101 telephone-event/8000
  845. a=fmtp:101 0-16
  846. a=ptime:20
  847. a=sendrecv
  848.  
  849. 2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:40 sofia/default/4779206277@192.168.1.13:52632 Standard INIT
  850. 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
  851. 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
  852. 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)
  853. 2019-07-04 16:05:44.787026 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [calling][0]
  854. 2019-07-04 16:05:44.787026 [DEBUG] switch_core_state_machine.c:643 (sofia/default/4779206277@192.168.1.13:52632) State ROUTING
  855. 2019-07-04 16:05:44.787026 [DEBUG] mod_sofia.c:143 sofia/default/4779206277@192.168.1.13:52632 SOFIA ROUTING
  856. 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
  857. 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
  858. 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)
  859. 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
  860. 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
  861. 2019-07-04 16:05:44.907006 [DEBUG] sofia.c:7084 Channel sofia/default/4779206277@192.168.1.13:52632 entering state [proceeding][180]
  862. 2019-07-04 16:05:44.907006 [NOTICE] sofia.c:7192 Ring-Ready sofia/default/4779206277@192.168.1.13:52632!
  863. 2019-07-04 16:05:44.907006 [DEBUG] switch_channel.c:3346 (sofia/default/4779206277@192.168.1.13:52632) Callstate Change DOWN -> RINGING
  864. 2019-07-04 16:05:44.907006 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/8889687188@pbx3.inexlocal.com!
  865. 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]
  866. 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)
  867. 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
  868. 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.
  869. 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
  870. 2019-07-04 16:05:47.007062 [DEBUG] switch_core_state_machine.c:603 (sofia/default/7100815208@pbx3.inexlocal.com) State NEW
  871. 2019-07-04 16:05:47.007062 [DEBUG] sofia.c:2334 detaching session 7be92414-9e47-11e9-9564-2d0e45e4becc
  872. 2019-07-04 16:05:47.027166 [DEBUG] sofia.c:2442 Re-attaching to session 7be92414-9e47-11e9-9564-2d0e45e4becc
  873. 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
  874. 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.
  875. 2019-07-04 16:05:47.067041 [DEBUG] sofia.c:7084 Channel sofia/default/7100815208@pbx3.inexlocal.com entering state [received][100]
  876. 2019-07-04 16:05:47.067041 [DEBUG] sofia.c:7094 Remote SDP:
  877. v=0
  878. o=twinkle 971131215 462933206 IN IP4 192.168.1.43
  879. s=-
  880. c=IN IP4 192.168.1.43
  881. t=0 0
  882. m=audio 8000 RTP/AVP 98 97 8 0 3 101
  883. a=rtpmap:98 speex/16000
  884. a=rtpmap:97 speex/8000
  885. a=rtpmap:8 PCMA/8000
  886. a=rtpmap:0 PCMU/8000
  887. a=rtpmap:3 GSM/8000
  888. a=rtpmap:101 telephone-event/8000
  889. a=fmtp:101 0-15
  890. a=ptime:20
  891.  
  892. 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]
  893. 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]
  894. 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]
  895. 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]
  896. 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]
  897. 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
  898. 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]
  899. 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]
  900. 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]
  901. 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
  902. 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]
  903. 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]
  904. 2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  905. 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
  906. 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
  907. 2019-07-04 16:05:47.067041 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  908. 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
  909. 2019-07-04 16:05:47.067041 [DEBUG] sofia.c:7507 (sofia/default/7100815208@pbx3.inexlocal.com) State Change CS_NEW -> CS_INIT
  910. 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)
  911. 2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7100815208@pbx3.inexlocal.com) State INIT
  912. 2019-07-04 16:05:47.067041 [DEBUG] mod_sofia.c:90 sofia/default/7100815208@pbx3.inexlocal.com SOFIA INIT
  913. 2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:40 sofia/default/7100815208@pbx3.inexlocal.com Standard INIT
  914. 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
  915. 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
  916. 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)
  917. 2019-07-04 16:05:47.067041 [DEBUG] switch_channel.c:2249 (sofia/default/7100815208@pbx3.inexlocal.com) Callstate Change DOWN -> RINGING
  918. 2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7100815208@pbx3.inexlocal.com) State ROUTING
  919. 2019-07-04 16:05:47.067041 [DEBUG] mod_sofia.c:143 sofia/default/7100815208@pbx3.inexlocal.com SOFIA ROUTING
  920. 2019-07-04 16:05:47.067041 [DEBUG] switch_core_state_machine.c:236 sofia/default/7100815208@pbx3.inexlocal.com Standard ROUTING
  921. 2019-07-04 16:05:47.067041 [INFO] mod_dialplan_xml.c:637 Processing 7100815208 <7100815208>->*102 in context default
  922. 2019-07-04 16:05:47.086992 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f6b8805e880 Connected.
  923. 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')
  924. 2019-07-04 16:05:47.086992 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  925. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] blind_flag: 0
  926. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] TRAN user_domain: pbx3.inexlocal.com
  927. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] hunt_destination_number: *102
  928. 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
  929. 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
  930. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code blind_value_two_digit*9
  931. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code destination_number_two_digit*1
  932. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code transfer_attended_two_digit*9
  933. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : *102
  934. 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
  935. 2019-07-04 16:05:47.107022 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Feature Code Action :::: call_pickup_same_group
  936. 2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [FEATURE_CODE] sip_number :7100815208
  937. 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
  938. 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
  939. 2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [FEATURE_CODE] sip_info id :459
  940. 2019-07-04 16:05:47.107022 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [FEATURE_CODE] feature_code_action :call_pickup_same_group
  941. 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
  942. 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
  943. 2019-07-04 16:05:47.129449 [DEBUG] switch_cpp.cpp:1365 [ASTPP] Generated XML:
  944. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  945. <document type="freeswitch/xml">
  946. <section name="dialplan" description="ASTPP Dialplan">
  947. <context name="default">
  948. <extension name="\*102">
  949. <condition field="destination_number" expression="\*102">
  950. <action application="export" data="bypass_media=true"/>
  951. <action application="export" data="did_user_domain=pbx3.inexlocal.com"/>
  952. <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+"/>
  953. <action application="pickup" data="SIP_device_${foobar}"/>
  954. <action application="pickup" data="Allow-pick-up_${foobar}"/>
  955. <action application="pickup" data="ABC_${foobar}"/>
  956. </condition>
  957. </extension>
  958. </context>
  959. </section>
  960. </document>
  961. 2019-07-04 16:05:47.129449 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f6b8805e880 released.
  962. Dialplan: sofia/default/7100815208@pbx3.inexlocal.com parsing [default->\*102] continue=false
  963. Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Regex (PASS) [\*102] destination_number(*102) =~ /\*102/ break=on-false
  964. Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action export(bypass_media=true)
  965. Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action export(did_user_domain=pbx3.inexlocal.com)
  966. 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+)
  967. Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action pickup(SIP_device_${foobar})
  968. Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action pickup(Allow-pick-up_${foobar})
  969. Dialplan: sofia/default/7100815208@pbx3.inexlocal.com Action pickup(ABC_${foobar})
  970. 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
  971. 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
  972. 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)
  973. 2019-07-04 16:05:47.129449 [DEBUG] switch_core_state_machine.c:650 (sofia/default/7100815208@pbx3.inexlocal.com) State EXECUTE
  974. 2019-07-04 16:05:47.129449 [DEBUG] mod_sofia.c:198 sofia/default/7100815208@pbx3.inexlocal.com SOFIA EXECUTE
  975. 2019-07-04 16:05:47.129449 [DEBUG] switch_core_state_machine.c:328 sofia/default/7100815208@pbx3.inexlocal.com Standard EXECUTE
  976. EXECUTE sofia/default/7100815208@pbx3.inexlocal.com export(bypass_media=true)
  977. 2019-07-04 16:05:47.129449 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [bypass_media]=[true]
  978. EXECUTE sofia/default/7100815208@pbx3.inexlocal.com export(did_user_domain=pbx3.inexlocal.com)
  979. 2019-07-04 16:05:47.129449 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [did_user_domain]=[pbx3.inexlocal.com]
  980. 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
  981. 2019-07-04 16:05:47.129449 [INFO] switch_core_session.c:2649 Sending early media
  982. 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
  983. 2019-07-04 16:05:47.129449 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
  984. 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
  985. 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
  986. 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
  987. 2019-07-04 16:05:47.129449 [DEBUG] mod_sofia.c:2364 Ring SDP:
  988. v=0
  989. o=FreeSWITCH 1562206151 1562206152 IN IP4 192.168.1.118
  990. s=FreeSWITCH
  991. c=IN IP4 192.168.1.118
  992. t=0 0
  993. m=audio 30396 RTP/AVP 8 101
  994. a=rtpmap:8 PCMA/8000
  995. a=rtpmap:101 telephone-event/8000
  996. a=fmtp:101 0-16
  997. a=ptime:20
  998. a=sendrecv
  999.  
  1000. 2019-07-04 16:05:47.129449 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/default/7100815208@pbx3.inexlocal.com!
  1001. 2019-07-04 16:05:47.129449 [DEBUG] switch_channel.c:3474 (sofia/default/7100815208@pbx3.inexlocal.com) Callstate Change RINGING -> EARLY
  1002. 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+)
  1003. 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
  1004. 2019-07-04 16:05:47.129449 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur.
  1005. 2019-07-04 16:05:47.129449 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
  1006. 2019-07-04 16:05:47.129449 [DEBUG] sofia.c:7084 Channel sofia/default/7100815208@pbx3.inexlocal.com entering state [early][183]
  1007. 2019-07-04 16:05:47.227061 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  1008. 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
  1009. 2019-07-04 16:05:57.327009 [ERR] mod_sndfile.c:204 Error Opening File [/invalid.wav] [System error : No such file or directory.]
  1010. 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
  1011. 2019-07-04 16:05:57.327009 [WARNING] switch_core_file.c:360 File has 2 channels, muxing to 1 channel will occur.
  1012. 2019-07-04 16:05:57.327009 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
  1013. 2019-07-04 16:05:57.687039 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 7:800
  1014. 2019-07-04 16:05:57.687039 [INFO] switch_channel.c:515 RECV DTMF 7:800
  1015. 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
  1016. 2019-07-04 16:05:58.307049 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 1:800
  1017. 2019-07-04 16:05:58.307049 [INFO] switch_channel.c:515 RECV DTMF 1:800
  1018. 2019-07-04 16:05:59.407021 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 0:800
  1019. 2019-07-04 16:05:59.407021 [INFO] switch_channel.c:515 RECV DTMF 0:800
  1020. 2019-07-04 16:05:59.946994 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 0:800
  1021. 2019-07-04 16:05:59.946994 [INFO] switch_channel.c:515 RECV DTMF 0:800
  1022. 2019-07-04 16:06:03.107038 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 8:800
  1023. 2019-07-04 16:06:03.107038 [INFO] switch_channel.c:515 RECV DTMF 8:800
  1024. 2019-07-04 16:06:03.667023 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 1:800
  1025. 2019-07-04 16:06:03.667023 [INFO] switch_channel.c:515 RECV DTMF 1:800
  1026. 2019-07-04 16:06:04.247000 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 5:800
  1027. 2019-07-04 16:06:04.247000 [INFO] switch_channel.c:515 RECV DTMF 5:800
  1028. 2019-07-04 16:06:07.027006 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 2:800
  1029. 2019-07-04 16:06:07.027006 [INFO] switch_channel.c:515 RECV DTMF 2:800
  1030. 2019-07-04 16:06:07.787059 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 0:800
  1031. 2019-07-04 16:06:07.787059 [INFO] switch_channel.c:515 RECV DTMF 0:800
  1032. 2019-07-04 16:06:08.327010 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 8:800
  1033. 2019-07-04 16:06:08.327010 [INFO] switch_channel.c:515 RECV DTMF 8:800
  1034. 2019-07-04 16:06:08.946995 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF #:800
  1035. span style="color: green; font-weight: bold;"> 2019-07-04 16:06:08.946995 [INFO] switch_channel.c:515 RECV DTMF #:800
  1036. EXECUTE sofia/default/7100815208@pbx3.inexlocal.com pickup(SIP_device_7100815208)
  1037. EXECUTE sofia/default/7100815208@pbx3.inexlocal.com pickup(Allow-pick-up_7100815208)
  1038. EXECUTE sofia/default/7100815208@pbx3.inexlocal.com pickup(ABC_7100815208)
  1039. 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.
  1040. 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]
  1041. 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
  1042. 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)
  1043. 2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:850 (sofia/default/7100815208@pbx3.inexlocal.com) Callstate Change EARLY -> HANGUP
  1044. 2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:852 (sofia/default/7100815208@pbx3.inexlocal.com) State HANGUP
  1045. 2019-07-04 16:06:08.946995 [DEBUG] mod_sofia.c:438 Channel sofia/default/7100815208@pbx3.inexlocal.com hanging up, cause: NORMAL_CLEARING
  1046. 2019-07-04 16:06:08.946995 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
  1047. 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
  1048. 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
  1049. 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
  1050. 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)
  1051. 2019-07-04 16:06:08.946995 [DEBUG] switch_core_state_machine.c:938 (sofia/default/7100815208@pbx3.inexlocal.com) State REPORTING
  1052. 2019-07-04 16:06:08.946995 [INFO] mod_json_cdr.c:271 Process [7be92414-9e47-11e9-9564-2d0e45e4becc.cdr.json]
  1053. 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
  1054. 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
  1055. 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
  1056. 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
  1057. 2019-07-04 16:06:08.967222 [NOTICE] switch_core_session.c:1683 Session 307 (sofia/default/7100815208@pbx3.inexlocal.com) Ended
  1058. 2019-07-04 16:06:08.967222 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/7100815208@pbx3.inexlocal.com [CS_DESTROY]
  1059. 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)
  1060. 2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:751 (sofia/default/7100815208@pbx3.inexlocal.com) State DESTROY
  1061. 2019-07-04 16:06:08.967222 [DEBUG] mod_sofia.c:343 sofia/default/7100815208@pbx3.inexlocal.com SOFIA DESTROY
  1062. 2019-07-04 16:06:08.967222 [DEBUG] switch_core_state_machine.c:181 sofia/default/7100815208@pbx3.inexlocal.com Standard DESTROY
  1063. 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
  1064. 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]
  1065. 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)
  1066. 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
  1067. 2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:852 (sofia/default/4779206277@192.168.1.13:52632) State HANGUP
  1068. 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
  1069. 2019-07-04 16:06:14.007022 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [NO_ANSWER]
  1070. 2019-07-04 16:06:14.007022 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 19 [NO_ANSWER]
  1071. 2019-07-04 16:06:14.007022 [INFO] mod_dptools.c:3436 Originate Failed.  Cause: NO_ANSWER
  1072. 2019-07-04 16:06:14.007022 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/default/4779206277@192.168.1.13:52632
  1073. 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
  1074. 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
  1075. 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
  1076. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(on_busy_flag=1)
  1077. 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)
  1078. 2019-07-04 16:06:14.007022 [DEBUG] switch_core_state_machine.c:938 (sofia/default/4779206277@192.168.1.13:52632) State REPORTING
  1079. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [on_busy_flag]=[1]
  1080. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(on_busy_destination=0)
  1081. 2019-07-04 16:06:14.007022 [INFO] mod_json_cdr.c:271 Process [7a959930-9e47-11e9-9560-2d0e45e4becc.cdr.json]
  1082. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [on_busy_destination]=[0]
  1083. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(no_answer_flag=1)
  1084. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [no_answer_flag]=[1]
  1085. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(no_answer_destination=0)
  1086. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [no_answer_destination]=[0]
  1087. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(not_register_flag=1)
  1088. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [not_register_flag]=[1]
  1089. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(not_register_destination=0)
  1090. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [not_register_destination]=[0]
  1091. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(opensips_flag=1)
  1092. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [opensips_flag]=[1]
  1093. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(variable_sip_to_host=pbx3.inexlocal.com)
  1094. 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]
  1095. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(opensips_domain=127.0.0.1)
  1096. 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]
  1097. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(leg_timeout=60)
  1098. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [leg_timeout]=[60]
  1099. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(userinfo_id=415)
  1100. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [userinfo_id]=[415]
  1101. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(sip_destination_number=4779206277)
  1102. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [sip_destination_number]=[4779206277]
  1103. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(destination_number=919724268060)
  1104. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [destination_number]=[919724268060]
  1105. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com set(did_number=919724268060)
  1106. 2019-07-04 16:06:14.007022 [DEBUG] mod_dptools.c:1548 SET sofia/default/8889687188@pbx3.inexlocal.com [did_number]=[919724268060]
  1107. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com lua(astpp/lib/pbx/astpp-sipdevice-routing.lua)
  1108. 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
  1109. 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
  1110. 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
  1111. 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
  1112. 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
  1113. 2019-07-04 16:06:14.027016 [NOTICE] switch_core_session.c:1683 Session 306 (sofia/default/4779206277@192.168.1.13:52632) Ended
  1114. 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]
  1115. 2019-07-04 16:06:14.027016 [DEBUG] switch_cpp.cpp:1112 sofia/default/8889687188@pbx3.inexlocal.com destroy/unlink session from object
  1116. 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)
  1117. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com answer()
  1118. 2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:751 (sofia/default/4779206277@192.168.1.13:52632) State DESTROY
  1119. 2019-07-04 16:06:14.027016 [DEBUG] mod_sofia.c:343 sofia/default/4779206277@192.168.1.13:52632 SOFIA DESTROY
  1120. 2019-07-04 16:06:14.027016 [DEBUG] switch_core_state_machine.c:181 sofia/default/4779206277@192.168.1.13:52632 Standard DESTROY
  1121. 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
  1122. 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
  1123. 2019-07-04 16:06:14.027016 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
  1124. 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
  1125. 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
  1126. 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
  1127. 2019-07-04 16:06:14.027016 [DEBUG] mod_sofia.c:850 Local SDP sofia/default/8889687188@pbx3.inexlocal.com:
  1128. v=0
  1129. o=FreeSWITCH 1562209922 1562209923 IN IP4 192.168.1.118
  1130. s=FreeSWITCH
  1131. c=IN IP4 192.168.1.118
  1132. t=0 0
  1133. m=audio 26652 RTP/AVP 0 101
  1134. a=rtpmap:0 PCMU/8000
  1135. a=rtpmap:101 telephone-event/8000
  1136. a=fmtp:101 0-16
  1137. a=ptime:20
  1138. a=sendrecv
  1139.  
  1140. 2019-07-04 16:06:14.027016 [NOTICE] mod_dptools.c:1312 Channel [sofia/default/8889687188@pbx3.inexlocal.com] has been answered
  1141. 2019-07-04 16:06:14.027016 [DEBUG] switch_channel.c:3773 (sofia/default/8889687188@pbx3.inexlocal.com) Callstate Change RINGING -> ACTIVE
  1142. 2019-07-04 16:06:14.027016 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [completed][200]
  1143. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com export(voicemail_alternate_greet_id=919724268060)
  1144. 2019-07-04 16:06:14.027016 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [voicemail_alternate_greet_id]=[919724268060]
  1145. EXECUTE sofia/default/8889687188@pbx3.inexlocal.com voicemail(default pbx3.inexlocal.com 4779206277)
  1146. 2019-07-04 16:06:14.067068 [DEBUG] sofia.c:7084 Channel sofia/default/8889687188@pbx3.inexlocal.com entering state [ready][200]
  1147. 2019-07-04 16:06:14.127017 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
  1148. 2019-07-04 16:06:14.147139 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-person.wav] (en:en)
  1149. 2019-07-04 16:06:14.147139 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
  1150. 2019-07-04 16:06:14.327028 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
  1151. freeswitch@localhost.localdomain> ...
  1152.  
  1153.