2022-05-17 10:49:27.369197 [NOTICE] sofia.c:1089 Hangup sofia/default/31611143910@185.249.40.254 [CS_EXECUTE] [NORMAL_CLEARING] 2022-05-17 10:49:27.369197 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/31611143910@185.249.40.254] 2022-05-17 10:49:27.369197 [DEBUG] switch_ivr_bridge.c:820 sofia/default/31611143910@185.249.40.254 ending bridge by request from write function 2022-05-17 10:49:27.369197 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/101@45.129.144.123] 2022-05-17 10:49:27.369197 [NOTICE] switch_ivr_bridge.c:1029 Hangup sofia/default/101@45.129.144.123 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:654 (sofia/default/101@45.129.144.123) State EXCHANGE_MEDIA going to sleep 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:585 (sofia/default/101@45.129.144.123) Running State Change CS_HANGUP (Cur 10 Tot 23773) 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:848 (sofia/default/101@45.129.144.123) Callstate Change ACTIVE -> HANGUP 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:850 (sofia/default/101@45.129.144.123) State HANGUP 2022-05-17 10:49:27.369197 [DEBUG] mod_sofia.c:447 sofia/default/101@45.129.144.123 Overriding SIP cause 480 with 200 from the other leg 2022-05-17 10:49:27.369197 [DEBUG] mod_sofia.c:453 Channel sofia/default/101@45.129.144.123 hanging up, cause: NORMAL_CLEARING 2022-05-17 10:49:27.369197 [DEBUG] switch_ivr_bridge.c:1892 sofia/default/101@45.129.144.123 skip receive message [UNBRIDGE] (channel is hungup already) 2022-05-17 10:49:27.369197 [DEBUG] switch_ivr_bridge.c:1895 sofia/default/31611143910@185.249.40.254 skip receive message [UNBRIDGE] (channel is hungup already) 2022-05-17 10:49:27.369197 [DEBUG] switch_core_session.c:2905 sofia/default/31611143910@185.249.40.254 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:651 (sofia/default/31611143910@185.249.40.254) State EXECUTE going to sleep 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31611143910@185.249.40.254) Running State Change CS_HANGUP (Cur 10 Tot 23773) 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:848 (sofia/default/31611143910@185.249.40.254) Callstate Change ACTIVE -> HANGUP 2022-05-17 10:49:27.369197 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31611143910@185.249.40.254) State HANGUP 2022-05-17 10:49:27.369197 [DEBUG] mod_sofia.c:453 Channel sofia/default/31611143910@185.249.40.254 hanging up, cause: NORMAL_CLEARING 2022-05-17 10:49:27.369197 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/default/101@45.129.144.123 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:60 sofia/default/101@45.129.144.123 Standard HANGUP, cause: NORMAL_CLEARING 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:850 (sofia/default/101@45.129.144.123) State HANGUP going to sleep 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:620 (sofia/default/101@45.129.144.123) State Change CS_HANGUP -> CS_REPORTING 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:585 (sofia/default/101@45.129.144.123) Running State Change CS_REPORTING (Cur 10 Tot 23773) 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:936 (sofia/default/101@45.129.144.123) State REPORTING 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:60 sofia/default/31611143910@185.249.40.254 Standard HANGUP, cause: NORMAL_CLEARING 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31611143910@185.249.40.254) State HANGUP going to sleep 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:620 (sofia/default/31611143910@185.249.40.254) State Change CS_HANGUP -> CS_REPORTING 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31611143910@185.249.40.254) Running State Change CS_REPORTING (Cur 10 Tot 23773) 2022-05-17 10:49:27.389230 [INFO] mod_json_cdr.c:271 Process [3a4e37a6-da1d-4e60-b8c1-4bfce3fd1e5e.cdr.json] 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31611143910@185.249.40.254) State REPORTING 2022-05-17 10:49:27.389230 [INFO] mod_json_cdr.c:271 Process [b4414704-724e-408c-a359-427f6120c8f6.cdr.json] 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:174 sofia/default/101@45.129.144.123 Standard REPORTING, cause: NORMAL_CLEARING 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:936 (sofia/default/101@45.129.144.123) State REPORTING going to sleep 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:611 (sofia/default/101@45.129.144.123) State Change CS_REPORTING -> CS_DESTROY 2022-05-17 10:49:27.389230 [DEBUG] switch_core_session.c:1726 Session 23768 (sofia/default/101@45.129.144.123) Locked, Waiting on external entities 2022-05-17 10:49:27.389230 [NOTICE] switch_core_session.c:1744 Session 23768 (sofia/default/101@45.129.144.123) Ended 2022-05-17 10:49:27.389230 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/101@45.129.144.123 [CS_DESTROY] 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:739 (sofia/default/101@45.129.144.123) Running State Change CS_DESTROY (Cur 9 Tot 23773) 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:749 (sofia/default/101@45.129.144.123) State DESTROY 2022-05-17 10:49:27.389230 [DEBUG] mod_sofia.c:364 sofia/default/101@45.129.144.123 SOFIA DESTROY 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:181 sofia/default/101@45.129.144.123 Standard DESTROY 2022-05-17 10:49:27.389230 [DEBUG] switch_core_state_machine.c:749 (sofia/default/101@45.129.144.123) State DESTROY going to sleep 2022-05-17 10:49:27.409190 [DEBUG] switch_core_state_machine.c:174 sofia/default/31611143910@185.249.40.254 Standard REPORTING, cause: NORMAL_CLEARING 2022-05-17 10:49:27.409190 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31611143910@185.249.40.254) State REPORTING going to sleep 2022-05-17 10:49:27.409190 [DEBUG] switch_core_state_machine.c:611 (sofia/default/31611143910@185.249.40.254) State Change CS_REPORTING -> CS_DESTROY 2022-05-17 10:49:27.409190 [DEBUG] switch_core_session.c:1726 Session 23767 (sofia/default/31611143910@185.249.40.254) Locked, Waiting on external entities 2022-05-17 10:49:27.409190 [NOTICE] switch_core_session.c:1744 Session 23767 (sofia/default/31611143910@185.249.40.254) Ended 2022-05-17 10:49:27.409190 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/31611143910@185.249.40.254 [CS_DESTROY] 2022-05-17 10:49:27.409190 [DEBUG] switch_core_state_machine.c:739 (sofia/default/31611143910@185.249.40.254) Running State Change CS_DESTROY (Cur 8 Tot 23773) 2022-05-17 10:49:27.409190 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31611143910@185.249.40.254) State DESTROY 2022-05-17 10:49:27.409190 [DEBUG] mod_sofia.c:364 sofia/default/31611143910@185.249.40.254 SOFIA DESTROY 2022-05-17 10:49:27.409190 [DEBUG] switch_core_state_machine.c:181 sofia/default/31611143910@185.249.40.254 Standard DESTROY 2022-05-17 10:49:27.409190 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31611143910@185.249.40.254) State DESTROY going to sleep 2022-05-17 10:49:27.609231 [DEBUG] switch_scheduler.c:147 Deleting task 7120 switch_ivr_schedule_hangup (3a4e37a6-da1d-4e60-b8c1-4bfce3fd1e5e) freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> 2022-05-17 10:49:47.129191 [DEBUG] mod_hash.c:234 Freeing limit item: CPS_262908_CPS_user_262908 2022-05-17 10:49:47.129191 [DEBUG] mod_hash.c:234 Freeing limit item: CPS_134271_CPS_user_134271 freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> freeswitch@multitenant-1> 2022-05-17 10:49:54.469194 [DEBUG] sofia.c:7326 Channel sofia/default/31652033157@185.249.40.132 entering state [terminated][487] 2022-05-17 10:49:54.469194 [NOTICE] sofia.c:8559 Hangup sofia/default/31652033157@185.249.40.132 [CS_EXECUTE] [ORIGINATOR_CANCEL] 2022-05-17 10:49:54.469194 [DEBUG] switch_ivr_bridge.c:826 sofia/default/31652033157@185.249.40.132 ending bridge by request from read function 2022-05-17 10:49:54.469194 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/31652033157@185.249.40.132] 2022-05-17 10:49:54.489201 [DEBUG] switch_ivr_bridge.c:820 sofia/default/31652033157@185.249.40.132 ending bridge by request from write function 2022-05-17 10:49:54.489201 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/31854832191@134271.yoursipcloud.com:5060] 2022-05-17 10:49:54.489201 [NOTICE] switch_ivr_bridge.c:1025 Hangup sofia/default/31854832191@134271.yoursipcloud.com:5060 [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL] 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:654 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State EXCHANGE_MEDIA going to sleep 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31854832191@134271.yoursipcloud.com:5060) Running State Change CS_HANGUP (Cur 8 Tot 23773) 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:848 (sofia/default/31854832191@134271.yoursipcloud.com:5060) Callstate Change EARLY -> HANGUP 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State HANGUP 2022-05-17 10:49:54.489201 [DEBUG] mod_sofia.c:447 sofia/default/31854832191@134271.yoursipcloud.com:5060 Overriding SIP cause 487 with 487 from the other leg 2022-05-17 10:49:54.489201 [DEBUG] mod_sofia.c:453 Channel sofia/default/31854832191@134271.yoursipcloud.com:5060 hanging up, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.489201 [DEBUG] switch_ivr_bridge.c:1892 sofia/default/31854832191@134271.yoursipcloud.com:5060 skip receive message [UNBRIDGE] (channel is hungup already) 2022-05-17 10:49:54.489201 [DEBUG] switch_ivr_bridge.c:1895 sofia/default/31652033157@185.249.40.132 skip receive message [UNBRIDGE] (channel is hungup already) 2022-05-17 10:49:54.489201 [DEBUG] switch_core_session.c:2905 sofia/default/31652033157@185.249.40.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:651 (sofia/default/31652033157@185.249.40.132) State EXECUTE going to sleep 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31652033157@185.249.40.132) Running State Change CS_HANGUP (Cur 8 Tot 23773) 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:848 (sofia/default/31652033157@185.249.40.132) Callstate Change EARLY -> HANGUP 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31652033157@185.249.40.132) State HANGUP 2022-05-17 10:49:54.489201 [DEBUG] mod_sofia.c:453 Channel sofia/default/31652033157@185.249.40.132 hanging up, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.489201 [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/default/31854832191@134271.yoursipcloud.com:5060 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:60 sofia/default/31854832191@134271.yoursipcloud.com:5060 Standard HANGUP, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State HANGUP going to sleep 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:620 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State Change CS_HANGUP -> CS_REPORTING 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31854832191@134271.yoursipcloud.com:5060) Running State Change CS_REPORTING (Cur 8 Tot 23773) 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State REPORTING 2022-05-17 10:49:54.489201 [INFO] mod_json_cdr.c:271 Process [eb952e75-9ed5-4498-b095-0526d0c8569b.cdr.json] 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:60 sofia/default/31652033157@185.249.40.132 Standard HANGUP, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31652033157@185.249.40.132) State HANGUP going to sleep 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:620 (sofia/default/31652033157@185.249.40.132) State Change CS_HANGUP -> CS_REPORTING 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31652033157@185.249.40.132) Running State Change CS_REPORTING (Cur 8 Tot 23773) 2022-05-17 10:49:54.489201 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31652033157@185.249.40.132) State REPORTING 2022-05-17 10:49:54.489201 [INFO] mod_json_cdr.c:271 Process [a14193ad-936d-43c0-9d03-f27ead3f8853.cdr.json] 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:174 sofia/default/31854832191@134271.yoursipcloud.com:5060 Standard REPORTING, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State REPORTING going to sleep 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:611 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State Change CS_REPORTING -> CS_DESTROY 2022-05-17 10:49:54.509204 [DEBUG] switch_core_session.c:1726 Session 23771 (sofia/default/31854832191@134271.yoursipcloud.com:5060) Locked, Waiting on external entities 2022-05-17 10:49:54.509204 [NOTICE] switch_core_session.c:1744 Session 23771 (sofia/default/31854832191@134271.yoursipcloud.com:5060) Ended 2022-05-17 10:49:54.509204 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/31854832191@134271.yoursipcloud.com:5060 [CS_DESTROY] 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:739 (sofia/default/31854832191@134271.yoursipcloud.com:5060) Running State Change CS_DESTROY (Cur 7 Tot 23773) 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State DESTROY 2022-05-17 10:49:54.509204 [DEBUG] mod_sofia.c:364 sofia/default/31854832191@134271.yoursipcloud.com:5060 SOFIA DESTROY 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:181 sofia/default/31854832191@134271.yoursipcloud.com:5060 Standard DESTROY 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31854832191@134271.yoursipcloud.com:5060) State DESTROY going to sleep 2022-05-17 10:49:54.509204 [DEBUG] sofia.c:7326 Channel sofia/default/31652033157@185.249.40.236 entering state [terminated][487] 2022-05-17 10:49:54.509204 [NOTICE] sofia.c:8559 Hangup sofia/default/31652033157@185.249.40.236 [CS_EXECUTE] [ORIGINATOR_CANCEL] 2022-05-17 10:49:54.509204 [DEBUG] mod_hash.c:296 Usage for CPS_160_CPS_user_160 is now 0 2022-05-17 10:49:54.509204 [DEBUG] switch_ivr_bridge.c:826 sofia/default/31652033157@185.249.40.236 ending bridge by request from read function 2022-05-17 10:49:54.509204 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/31652033157@185.249.40.236] 2022-05-17 10:49:54.509204 [DEBUG] switch_ivr_bridge.c:820 sofia/default/31652033157@185.249.40.236 ending bridge by request from write function 2022-05-17 10:49:54.509204 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/default/31854832191] 2022-05-17 10:49:54.509204 [NOTICE] switch_ivr_bridge.c:1025 Hangup sofia/default/31854832191 [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL] 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:654 (sofia/default/31854832191) State EXCHANGE_MEDIA going to sleep 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31854832191) Running State Change CS_HANGUP (Cur 7 Tot 23773) 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:848 (sofia/default/31854832191) Callstate Change EARLY -> HANGUP 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31854832191) State HANGUP 2022-05-17 10:49:54.509204 [DEBUG] mod_sofia.c:447 sofia/default/31854832191 Overriding SIP cause 487 with 487 from the other leg 2022-05-17 10:49:54.509204 [DEBUG] mod_sofia.c:453 Channel sofia/default/31854832191 hanging up, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.509204 [DEBUG] switch_ivr_bridge.c:1892 sofia/default/31854832191 skip receive message [UNBRIDGE] (channel is hungup already) 2022-05-17 10:49:54.509204 [DEBUG] switch_ivr_bridge.c:1895 sofia/default/31652033157@185.249.40.236 skip receive message [UNBRIDGE] (channel is hungup already) 2022-05-17 10:49:54.509204 [DEBUG] switch_core_session.c:2905 sofia/default/31652033157@185.249.40.236 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:651 (sofia/default/31652033157@185.249.40.236) State EXECUTE going to sleep 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31652033157@185.249.40.236) Running State Change CS_HANGUP (Cur 7 Tot 23773) 2022-05-17 10:49:54.509204 [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/default/31854832191 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:60 sofia/default/31854832191 Standard HANGUP, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31854832191) State HANGUP going to sleep 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:620 (sofia/default/31854832191) State Change CS_HANGUP -> CS_REPORTING 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31854832191) Running State Change CS_REPORTING (Cur 7 Tot 23773) 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31854832191) State REPORTING 2022-05-17 10:49:54.509204 [DEBUG] switch_core_state_machine.c:848 (sofia/default/31652033157@185.249.40.236) Callstate Change EARLY -> HANGUP 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31652033157@185.249.40.236) State HANGUP 2022-05-17 10:49:54.529185 [DEBUG] mod_sofia.c:453 Channel sofia/default/31652033157@185.249.40.236 hanging up, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.529185 [INFO] mod_json_cdr.c:271 Process [14074e49-f09d-41cc-8acd-9815b32a5cc6.cdr.json] 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:60 sofia/default/31652033157@185.249.40.236 Standard HANGUP, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:850 (sofia/default/31652033157@185.249.40.236) State HANGUP going to sleep 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:620 (sofia/default/31652033157@185.249.40.236) State Change CS_HANGUP -> CS_REPORTING 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31652033157@185.249.40.236) Running State Change CS_REPORTING (Cur 7 Tot 23773) 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31652033157@185.249.40.236) State REPORTING 2022-05-17 10:49:54.529185 [INFO] mod_json_cdr.c:271 Process [b6aeed30-a71e-4f99-8ce8-c321ed3a0c70.cdr.json] 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:174 sofia/default/31652033157@185.249.40.132 Standard REPORTING, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31652033157@185.249.40.132) State REPORTING going to sleep 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:611 (sofia/default/31652033157@185.249.40.132) State Change CS_REPORTING -> CS_DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_session.c:1726 Session 23770 (sofia/default/31652033157@185.249.40.132) Locked, Waiting on external entities 2022-05-17 10:49:54.529185 [NOTICE] switch_core_session.c:1744 Session 23770 (sofia/default/31652033157@185.249.40.132) Ended 2022-05-17 10:49:54.529185 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/31652033157@185.249.40.132 [CS_DESTROY] 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:739 (sofia/default/31652033157@185.249.40.132) Running State Change CS_DESTROY (Cur 6 Tot 23773) 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31652033157@185.249.40.132) State DESTROY 2022-05-17 10:49:54.529185 [DEBUG] mod_sofia.c:364 sofia/default/31652033157@185.249.40.132 SOFIA DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:181 sofia/default/31652033157@185.249.40.132 Standard DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31652033157@185.249.40.132) State DESTROY going to sleep 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:174 sofia/default/31854832191 Standard REPORTING, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31854832191) State REPORTING going to sleep 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:611 (sofia/default/31854832191) State Change CS_REPORTING -> CS_DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_session.c:1726 Session 23773 (sofia/default/31854832191) Locked, Waiting on external entities 2022-05-17 10:49:54.529185 [NOTICE] switch_core_session.c:1744 Session 23773 (sofia/default/31854832191) Ended 2022-05-17 10:49:54.529185 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/31854832191 [CS_DESTROY] 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:739 (sofia/default/31854832191) Running State Change CS_DESTROY (Cur 5 Tot 23773) 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31854832191) State DESTROY 2022-05-17 10:49:54.529185 [DEBUG] mod_sofia.c:364 sofia/default/31854832191 SOFIA DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:181 sofia/default/31854832191 Standard DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31854832191) State DESTROY going to sleep 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:174 sofia/default/31652033157@185.249.40.236 Standard REPORTING, cause: ORIGINATOR_CANCEL 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:936 (sofia/default/31652033157@185.249.40.236) State REPORTING going to sleep 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:611 (sofia/default/31652033157@185.249.40.236) State Change CS_REPORTING -> CS_DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_session.c:1726 Session 23772 (sofia/default/31652033157@185.249.40.236) Locked, Waiting on external entities 2022-05-17 10:49:54.529185 [NOTICE] switch_core_session.c:1744 Session 23772 (sofia/default/31652033157@185.249.40.236) Ended 2022-05-17 10:49:54.529185 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/31652033157@185.249.40.236 [CS_DESTROY] 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:739 (sofia/default/31652033157@185.249.40.236) Running State Change CS_DESTROY (Cur 4 Tot 23773) 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31652033157@185.249.40.236) State DESTROY 2022-05-17 10:49:54.529185 [DEBUG] mod_sofia.c:364 sofia/default/31652033157@185.249.40.236 SOFIA DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:181 sofia/default/31652033157@185.249.40.236 Standard DESTROY 2022-05-17 10:49:54.529185 [DEBUG] switch_core_state_machine.c:749 (sofia/default/31652033157@185.249.40.236) State DESTROY going to sleep 2022-05-17 10:49:54.629199 [DEBUG] switch_scheduler.c:147 Deleting task 7121 switch_ivr_schedule_hangup (14074e49-f09d-41cc-8acd-9815b32a5cc6) 2022-05-17 10:49:54.629199 [DEBUG] switch_scheduler.c:147 Deleting task 7122 switch_ivr_schedule_hangup (eb952e75-9ed5-4498-b095-0526d0c8569b) 2022-05-17 10:49:55.189234 [NOTICE] switch_channel.c:1118 New Channel sofia/default/3123999999@vellinga135.yoursipcloud.com [edaeb3aa-824e-48a4-bbd0-15b73208809c] 2022-05-17 10:49:55.189234 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3123999999@vellinga135.yoursipcloud.com) Running State Change CS_NEW (Cur 5 Tot 23774) 2022-05-17 10:49:55.189234 [DEBUG] sofia.c:10280 sofia/default/3123999999@vellinga135.yoursipcloud.com receiving invite from 51.89.5.107:5060 version: 1.10.5 -release-17-25569c1631 64bit 2022-05-17 10:49:55.189234 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 51.89.5.107:0. 2022-05-17 10:49:55.189234 [WARNING] sofia_reg.c:1794 SIP auth challenge (INVITE) on sofia profile 'default' for [31302780000@vellinga135.yoursipcloud.com] from ip 51.89.5.107 2022-05-17 10:49:55.189234 [DEBUG] switch_core_state_machine.c:604 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State NEW 2022-05-17 10:49:55.189234 [DEBUG] sofia.c:2434 detaching session edaeb3aa-824e-48a4-bbd0-15b73208809c 2022-05-17 10:49:55.229197 [DEBUG] sofia.c:2544 Re-attaching to session edaeb3aa-824e-48a4-bbd0-15b73208809c 2022-05-17 10:49:55.249201 [DEBUG] sofia.c:10280 sofia/default/3123999999@vellinga135.yoursipcloud.com receiving invite from 51.89.5.107:5060 version: 1.10.5 -release-17-25569c1631 64bit 2022-05-17 10:49:55.249201 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 51.89.5.107:0. 2022-05-17 10:49:55.269195 [DEBUG] sofia.c:7326 Channel sofia/default/3123999999@vellinga135.yoursipcloud.com entering state [received][100] 2022-05-17 10:49:55.269195 [DEBUG] sofia.c:7336 Remote SDP: v=0 o=3cxPS 32003351252041728 4333136452255745 IN IP4 51.89.5.107 s=3cxPS Audio call c=IN IP4 51.89.5.107 t=0 0 m=audio 9420 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:3839 Set Codec sofia/default/3123999999@vellinga135.yoursipcloud.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2022-05-17 10:49:55.269195 [DEBUG] switch_core_codec.c:111 sofia/default/3123999999@vellinga135.yoursipcloud.com Original read codec set to PCMU:0 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000 2022-05-17 10:49:55.269195 [DEBUG] switch_core_media.c:5911 sofia/default/3123999999@vellinga135.yoursipcloud.com Set 2833 dtmf send payload to 101 recv payload to 101 2022-05-17 10:49:55.269195 [DEBUG] sofia.c:7760 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State Change CS_NEW -> CS_INIT 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3123999999@vellinga135.yoursipcloud.com) Running State Change CS_INIT (Cur 5 Tot 23774) 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:628 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State INIT 2022-05-17 10:49:55.269195 [DEBUG] mod_sofia.c:93 sofia/default/3123999999@vellinga135.yoursipcloud.com SOFIA INIT 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:40 sofia/default/3123999999@vellinga135.yoursipcloud.com Standard INIT 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:48 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State Change CS_INIT -> CS_ROUTING 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:628 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State INIT going to sleep 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3123999999@vellinga135.yoursipcloud.com) Running State Change CS_ROUTING (Cur 5 Tot 23774) 2022-05-17 10:49:55.269195 [DEBUG] switch_channel.c:2332 (sofia/default/3123999999@vellinga135.yoursipcloud.com) Callstate Change DOWN -> RINGING 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:644 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State ROUTING 2022-05-17 10:49:55.269195 [DEBUG] mod_sofia.c:154 sofia/default/3123999999@vellinga135.yoursipcloud.com SOFIA ROUTING 2022-05-17 10:49:55.269195 [DEBUG] switch_core_state_machine.c:236 sofia/default/3123999999@vellinga135.yoursipcloud.com Standard ROUTING 2022-05-17 10:49:55.269195 [INFO] mod_dialplan_xml.c:637 Processing 3123999999 <3123999999>->31302780000 in context default 2022-05-17 10:49:55.269195 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes') 2022-05-17 10:49:55.269195 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons 2022-05-17 10:49:55.269195 [NOTICE] switch_cpp.cpp:1447 [ASTPP] [xml_handler] Params: Event-Name: REQUEST_PARAMS Core-UUID: 1570752e-33b2-4fd5-ae87-2429c1fe8547 FreeSWITCH-Hostname: multitenant-1 FreeSWITCH-Switchname: multitenant-1 FreeSWITCH-IPv4: 185.249.40.236 FreeSWITCH-IPv6: %3A%3A1 Event-Date-Local: 2022-05-17%2010%3A49%3A55 Event-Date-GMT: Tue,%2017%20May%202022%2008%3A49%3A55%20GMT Event-Date-Timestamp: 1652777395269195 Event-Calling-File: mod_dialplan_xml.c Event-Calling-Function: dialplan_xml_locate Event-Calling-Line-Number: 608 Event-Sequence: 1800506 Channel-State: CS_ROUTING Channel-Call-State: RINGING Channel-State-Number: 2 Channel-Name: sofia/default/3123999999%40vellinga135.yoursipcloud.com Unique-ID: edaeb3aa-824e-48a4-bbd0-15b73208809c Call-Direction: inbound Presence-Call-Direction: inbound Channel-HIT-Dialplan: true Channel-Presence-ID: 3123999999%40vellinga135.yoursipcloud.com Channel-Call-UUID: edaeb3aa-824e-48a4-bbd0-15b73208809c Answer-State: ringing Channel-Read-Codec-Name: PCMU Channel-Read-Codec-Rate: 8000 Channel-Read-Codec-Bit-Rate: 64000 Channel-Write-Codec-Name: PCMU Channel-Write-Codec-Rate: 8000 Channel-Write-Codec-Bit-Rate: 64000 Caller-Direction: inbound Caller-Logical-Direction: inbound Caller-Username: 3123999999 Caller-Dialplan: XML Caller-Caller-ID-Name: 3123999999 Caller-Caller-ID-Number: 3123999999 Caller-Orig-Caller-ID-Name: 3123999999 Caller-Orig-Caller-ID-Number: 3123999999 Caller-Network-Addr: 51.89.5.107 Caller-ANI: 3123999999 Caller-Destination-Number: 31302780000 Caller-Unique-ID: edaeb3aa-824e-48a4-bbd0-15b73208809c Caller-Source: mod_sofia Caller-Context: default Caller-Channel-Name: sofia/default/3123999999%40vellinga135.yoursipcloud.com Caller-Profile-Index: 1 Caller-Profile-Created-Time: 1652777395269195 Caller-Channel-Created-Time: 1652777395269195 Caller-Channel-Answered-Time: 0 Caller-Channel-Progress-Time: 0 Caller-Channel-Progress-Media-Time: 0 Caller-Channel-Hangup-Time: 0 Caller-Channel-Transfer-Time: 0 Caller-Channel-Resurrect-Time: 0 Caller-Channel-Bridged-Time: 0 Caller-Channel-Last-Hold: 0 Caller-Channel-Hold-Accum: 0 Caller-Screen-Bit: true Caller-Privacy-Hide-Name: false Caller-Privacy-Hide-Number: false variable_direction: inbound variable_uuid: edaeb3aa-824e-48a4-bbd0-15b73208809c variable_session_id: 23774 variable_sip_from_user: 3123999999 variable_sip_from_uri: 3123999999%40vellinga135.yoursipcloud.com variable_sip_from_host: vellinga135.yoursipcloud.com variable_video_media_flow: disabled variable_text_media_flow: disabled variable_channel_name: sofia/default/3123999999%40vellinga135.yoursipcloud.com variable_sip_call_id: LQ0H69avEcCb9MYn6QtYzA.. variable_sip_local_network_addr: 185.249.40.236 variable_sip_network_ip: 51.89.5.107 variable_sip_network_port: 5060 variable_sip_invite_stamp: 1652777395249201 variable_sip_received_ip: 51.89.5.107 variable_sip_received_port: 5060 variable_sip_via_protocol: udp variable_sip_authorized: true variable_Event-Name: REQUEST_PARAMS variable_Core-UUID: 1570752e-33b2-4fd5-ae87-2429c1fe8547 variable_FreeSWITCH-Hostname: multitenant-1 variable_FreeSWITCH-Switchname: multitenant-1 variable_FreeSWITCH-IPv4: 185.249.40.236 variable_FreeSWITCH-IPv6: %3A%3A1 variable_Event-Date-Local: 2022-05-17%2010%3A49%3A55 variable_Event-Date-GMT: Tue,%2017%20May%202022%2008%3A49%3A55%20GMT variable_Event-Date-Timestamp: 1652777395249201 variable_Event-Calling-File: sofia.c variable_Event-Calling-Function: sofia_handle_sip_i_invite variable_Event-Calling-Line-Number: 10542 variable_Event-Sequence: 1800497 variable_sip_number_alias: 504618 variable_sip_auth_username: 504618 variable_sip_auth_realm: vellinga135.yoursipcloud.com variable_number_alias: 504618 variable_requested_user_name: 504618 variable_requested_domain_name: vellinga135.yoursipcloud.com variable_effective_caller_id_number: 31235258411 variable_sipcall: true variable_sip_user: 504618 variable_accountcode: 504618 variable_user_name: 504618 variable_domain_name: vellinga135.yoursipcloud.com variable_sip_from_user_stripped: 3123999999 variable_sip_from_tag: e1402922 variable_sofia_profile_name: default variable_sofia_profile_url: sip%3Amod_sofia%40185.249.40.236%3A5060 variable_recovery_profile_name: default variable_sip_Remote-Party-ID: %223123999999%22%20%3Csip%3A3123999999%40vellinga135.yoursipcloud.com%3E%3Bparty%3Dcalling variable_sip_cid_type: rpid variable_sip_full_via: SIP/2.0/UDP%2051.89.5.107%3A5060%3Bbranch%3Dz9hG4bK-524287-1---ff441d18f8858f4e%3Brport%3D5060 variable_sip_from_display: 3123999999 variable_sip_full_from: %223123999999%22%20%3Csip%3A3123999999%40vellinga135.yoursipcloud.com%3E%3Btag%3De1402922 variable_sip_full_to: %3Csip%3A31302780000%40vellinga135.yoursipcloud.com%3E variable_sip_allow: INVITE,%20ACK,%20CANCEL,%20OPTIONS,%20BYE,%20REGISTER,%20SUBSCRIBE,%20NOTIFY,%20REFER,%20INFO,%20MESSAGE,%20UPDATE variable_sip_req_user: 31302780000 variable_sip_req_uri: 31302780000%40vellinga135.yoursipcloud.com variable_sip_req_host: vellinga135.yoursipcloud.com variable_sip_to_user: 31302780000 variable_sip_to_uri: 31302780000%40vellinga135.yoursipcloud.com variable_sip_to_host: vellinga135.yoursipcloud.com variable_sip_contact_user: 3123999999 variable_sip_contact_port: 5060 variable_sip_contact_uri: 3123999999%4051.89.5.107%3A5060 variable_sip_contact_host: 51.89.5.107 variable_sip_user_agent: 3CXPhoneSystem%2018.0.3.461%20(461) variable_sip_via_host: 51.89.5.107 variable_sip_via_port: 5060 variable_sip_via_rport: 5060 variable_max_forwards: 70 variable_presence_id: 3123999999%40vellinga135.yoursipcloud.com variable_switch_r_sdp: v%3D0%0D%0Ao%3D3cxPS%2032003351252041728%204333136452255745%20IN%20IP4%2051.89.5.107%0D%0As%3D3cxPS%20Audio%20call%0D%0Ac%3DIN%20IP4%2051.89.5.107%0D%0At%3D0%200%0D%0Am%3Daudio%209420%20RTP/AVP%200%208%2018%20101%0D%0Aa%3Drtpmap%3A0%20PCMU/8000%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A18%20G729/8000%0D%0Aa%3Dfmtp%3A18%20annexb%3Dno%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0A variable_ep_codec_string: CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b,CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b variable_rtp_use_codec_string: PCMA,PCMU variable_remote_video_media_flow: inactive variable_remote_text_media_flow: inactive variable_remote_audio_media_flow: sendrecv variable_audio_media_flow: sendrecv variable_remote_media_ip: 51.89.5.107 variable_remote_media_port: 9420 variable_rtp_audio_recv_pt: 0 variable_rtp_use_codec_name: PCMU variable_rtp_use_codec_rate: 8000 variable_rtp_use_codec_ptime: 20 variable_rtp_use_codec_channels: 1 variable_rtp_last_audio_codec_string: PCMU%408000h%4020i%401c variable_read_codec: PCMU variable_original_read_codec: PCMU variable_read_rate: 8000 variable_original_read_rate: 8000 variable_write_codec: PCMU variable_write_rate: 8000 variable_dtmf_type: rfc2833 variable_endpoint_disposition: RECEIVED variable_call_uuid: edaeb3aa-824e-48a4-bbd0-15b73208809c Hunt-Direction: inbound Hunt-Logical-Direction: inbound Hunt-Username: 3123999999 Hunt-Dialplan: XML Hunt-Caller-ID-Name: 3123999999 Hunt-Caller-ID-Number: 3123999999 Hunt-Orig-Caller-ID-Name: 3123999999 Hunt-Orig-Caller-ID-Number: 3123999999 Hunt-Network-Addr: 51.89.5.107 Hunt-ANI: 3123999999 Hunt-Destination-Number: 31302780000 Hunt-Unique-ID: edaeb3aa-824e-48a4-bbd0-15b73208809c Hunt-Source: mod_sofia Hunt-Context: default Hunt-Channel-Name: sofia/default/3123999999%40vellinga135.yoursipcloud.com Hunt-Profile-Index: 1 Hunt-Profile-Created-Time: 1652777395269195 Hunt-Channel-Created-Time: 1652777395269195 Hunt-Channel-Answered-Time: 0 Hunt-Channel-Progress-Time: 0 Hunt-Channel-Progress-Media-Time: 0 Hunt-Channel-Hangup-Time: 0 Hunt-Channel-Transfer-Time: 0 Hunt-Channel-Resurrect-Time: 0 Hunt-Channel-Bridged-Time: 0 Hunt-Channel-Last-Hold: 0 Hunt-Channel-Hold-Accum: 0 Hunt-Screen-Bit: true Hunt-Privacy-Hide-Name: false Hunt-Privacy-Hide-Number: false 2022-05-17 10:49:55.269195 [INFO] switch_cpp.cpp:1447 [ASTPP] [xml_REQUEST] key_value: 2022-05-17 10:49:55.269195 [INFO] switch_cpp.cpp:1447 [ASTPP] [xml_REQUEST] section: dialplan 2022-05-17 10:49:55.269195 [INFO] switch_cpp.cpp:1447 [ASTPP] [xml_REQUEST] tag_name: 2022-05-17 10:49:55.269195 [INFO] switch_cpp.cpp:1447 [ASTPP] [xml_REQUEST] key_name: 2022-05-17 10:49:55.269195 [INFO] switch_cpp.cpp:1447 [ASTPP] [feature_code_call_transfer] Blind Call Flag: 0 2022-05-17 10:49:55.269195 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Dialed number : 31302780000 2022-05-17 10:49:55.269195 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '31302780000' limit 1 2022-05-17 10:49:55.269195 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '31302780000' AND status=0 limit 1 2022-05-17 10:49:55.269195 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Functions] [Fifo Condition Check] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = '31302780000' and status=0 LIMIT 1 2022-05-17 10:49:55.269195 [WARNING] switch_cpp.cpp:1447 [ASTPP] [FAXER] Custom Caller ID 2022-05-17 10:49:55.269195 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Caller Id name / number : / 31235258411 2022-05-17 10:49:55.269195 [DEBUG] switch_cpp.cpp:1447 [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 ="31302780000" LIMIT 1 2022-05-17 10:49:55.269195 [DEBUG] switch_cpp.cpp:1447 [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="31302780000" AND domains.domain="vellinga135.yoursipcloud.com" limit 1 2022-05-17 10:49:55.289196 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Call direction : outbound 2022-05-17 10:49:55.289196 [INFO] switch_cpp.cpp:1447 [ASTPP] [Accountcode : 504618] 2022-05-17 10:49:55.289196 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE number = "504618" AND deleted = 0 limit 1 2022-05-17 10:49:55.289196 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^31302780000.*' OR blocked_patterns = '^3130278000.*' OR blocked_patterns = '^313027800.*' OR blocked_patterns = '^31302780.*' OR blocked_patterns = '^3130278.*' OR blocked_patterns = '^313027.*' OR blocked_patterns = '^31302.*' OR blocked_patterns = '^3130.*' OR blocked_patterns = '^313.*' OR blocked_patterns = '^31.*' OR blocked_patterns = '^3.*' OR blocked_patterns ='--') AND accountid = 196 limit 1 2022-05-17 10:49:55.289196 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [IS_CHECK_DID] Query :SELECT * FROM dids WHERE number ="31302780000" AND (accountid = 0 OR status = 1) LIMIT 1 2022-05-17 10:49:55.289196 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id,P.product_id as product_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE P.is_terminated = 0 AND (patterns = '^31302780000.*' OR patterns = '^3130278000.*' OR patterns = '^313027800.*' OR patterns = '^31302780.*' OR patterns = '^3130278.*' OR patterns = '^313027.*' OR patterns = '^31302.*' OR patterns = '^3130.*' OR patterns = '^313.*' OR patterns = '^31.*' OR patterns = '^3.*' OR patterns ='--') AND accountid = 196 ORDER BY LENGTH(PKGPTR.patterns) DESC 2022-05-17 10:49:55.289196 [DEBUG] switch_cpp.cpp:1447 [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 ="31302780000" AND A.accountid = '196' limit 1 2022-05-17 10:49:55.289196 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] SPEED DIAL NUMBER : 31302780000 2022-05-17 10:49:55.289196 [DEBUG] switch_cpp.cpp:1447 [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 ="31302780000" LIMIT 1 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [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="31302780000" AND domains.domain="vellinga135.yoursipcloud.com" limit 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] New Call Direction : outbound 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type FROM call_barring WHERE ((number = '31302780000' OR number = '3130278000' OR number = '313027800' OR number = '31302780' OR number = '3130278' OR number = '313027' OR number = '31302' OR number = '3130' OR number = '313' OR number = '31' OR number = '3' OR number ='--') OR (number = '31302780000*' OR number = '3130278000*' OR number = '313027800*' OR number = '31302780*' OR number = '3130278*' OR number = '313027*' OR number = '31302*' OR number = '3130*' OR number = '313*' OR number = '31*' OR number = '3*' OR number ='--') OR (number = '31235258411' OR number = '3123525841' OR number = '312352584' OR number = '31235258' OR number = '3123525' OR number = '312352' OR number = '31235' OR number = '3123' OR number = '312' OR number = '31' OR number = '3' OR number ='--') OR (number = '31235258411*' OR number = '3123525841*' OR number = '312352584*' OR number = '31235258*' OR number = '3123525*' OR number = '312352*' OR number = '31235*' OR number = '3123*' OR number = '312*' OR number = '31*' OR number = '3*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Call Barring Status : -1 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '31302780000' OR routing_prefix = '3130278000' OR routing_prefix = '313027800' OR routing_prefix = '31302780' OR routing_prefix = '3130278' OR routing_prefix = '313027' OR routing_prefix = '31302' OR routing_prefix = '3130' OR routing_prefix = '313' OR routing_prefix = '31' OR routing_prefix = '3' OR routing_prefix ='--') AND status = 0 and reseller_id = 189 limit 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Account Information =================== 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] User id : 196 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Account code : 504618 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Balance : 53.4258 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Type : 1 [0:prepaid,1:postpaid] 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Ratecard id : 24 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] CID Pool : 0 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ======================================================== 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 24 AND status = 0 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] call_direction :outbound 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 24 AND status = 0 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^31302780000.*' OR pattern = '^3130278000.*' OR pattern = '^313027800.*' OR pattern = '^31302780.*' OR pattern = '^3130278.*' OR pattern = '^313027.*' OR pattern = '^31302.*' OR pattern = '^3130.*' OR pattern = '^313.*' OR pattern = '^31.*' OR pattern = '^3.*' OR pattern ='--') AND status = 0 AND effective_date <= UTC_TIMESTAMP() AND (pricelist_id = 24 OR accountid=196) ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC,effective_date DESC LIMIT 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Call Direction : outbound 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Rates Information =================== 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ID : 1597622 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Connectcost : 0.04900 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Includedseconds : 0 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Cost : 0.01890 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Comment : 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Country Id : 0 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Accid : 196 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Trunk ID: 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Routing type: 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ================================================================ 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Your53.4258 balance Accountid 196 !!! 2022-05-17 10:49:55.309203 [NOTICE] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Limiting Call To Config Max Length 100 mins! 2022-05-17 10:49:55.309203 [NOTICE] switch_cpp.cpp:1447 [ASTPP] FINDING LIMIT FOR RESELLER: 189 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE id = "189" AND deleted = 0 limit 1 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^31302780000.*' OR blocked_patterns = '^3130278000.*' OR blocked_patterns = '^313027800.*' OR blocked_patterns = '^31302780.*' OR blocked_patterns = '^3130278.*' OR blocked_patterns = '^313027.*' OR blocked_patterns = '^31302.*' OR blocked_patterns = '^3130.*' OR blocked_patterns = '^313.*' OR blocked_patterns = '^31.*' OR blocked_patterns = '^3.*' OR blocked_patterns ='--') AND accountid = 189 limit 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Reseller Information =================== 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] User id : 189 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Account code : 510514 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Balance : 239.6057 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Type : 1 [0:prepaid,1:postpaid] 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Ratecard id : 44 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 44 AND status = 0 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] call_direction :outbound 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 44 AND status = 0 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^31302780000.*' OR pattern = '^3130278000.*' OR pattern = '^313027800.*' OR pattern = '^31302780.*' OR pattern = '^3130278.*' OR pattern = '^313027.*' OR pattern = '^31302.*' OR pattern = '^3130.*' OR pattern = '^313.*' OR pattern = '^31.*' OR pattern = '^3.*' OR pattern ='--') AND status = 0 AND effective_date <= UTC_TIMESTAMP() AND (pricelist_id = 44 OR accountid=189) ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC,effective_date DESC LIMIT 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Call Direction : outbound 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Rates Information =================== 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ID : 2846757 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Connectcost : 0.00000 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Includedseconds : 0 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Cost : 0.00210 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Comment : Netherlands fixed 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Country Id : 0 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Accid : 189 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Trunk ID: 4 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Routing type: 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ================================================================ 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Your239.6057 balance Accountid 189 !!! 2022-05-17 10:49:55.309203 [NOTICE] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Limiting Call To Config Max Length 100 mins! 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Reseller xml_user_rates : ID:1597622|CODE:^31.*|DESTINATION:|CONNECTIONCOST:0.04900|INCLUDEDSECONDS:0|CT:|COST:0.01890|INC:1|INITIALBLOCK:1|RATEGROUP:24|MARKUP:0|CI:0|ACCID:196||ID:2846757|CODE:^3130.*|DESTINATION:Netherlands fixed|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.00210|INC:1|INITIALBLOCK:1|RATEGROUP:44|MARKUP:0|CI:0|ACCID:189 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ======================================================== 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Lossless Routing Status : 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Call Max Length Duration : 100 minutes 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] [DIALPLAN] User Rate ID : 1597622 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_CARRIER_RATES] Query Rate Carrier Id :4 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^31302780000.*' OR pattern = '^3130278000.*' OR pattern = '^313027800.*' OR pattern = '^31302780.*' OR pattern = '^3130278.*' OR pattern = '^313027.*' OR pattern = '^31302.*' OR pattern = '^3130.*' OR pattern = '^313.*' OR pattern = '^31.*' OR pattern = '^3.*' OR pattern ='--') AND TR.status = 0 AND TR.trunk_id IN (4) AND TR.effective_date <= UTC_TIMESTAMP() ORDER by FIELD(TR.trunk_id,4),LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC,TR.effective_date DESC 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Termination Rates Information =================== 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ID : 114164 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Code : ^3130.* 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Destination : Netherlands fixed 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Connectcost : 0.00000 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Free Seconds : 0 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Prefix : ^3130.* 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Strip : 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Prepend : 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Carrier id : 4 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] carrier_name : SBC1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] dialplan_variable : 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Failover gateway : SBC2 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Vendor id : 231 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Max channels : 0 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Trunk Name : SBCs 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] ========================END OF TERMINATION RATES======================= 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 196 AND status=0 LIMIT 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] Maxlength : 100 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] [XML] Customer Recording Flag : 1 2022-05-17 10:49:55.309203 [INFO] switch_cpp.cpp:1447 [ASTPP] [PBX] Call Direction : outbound 2022-05-17 10:49:55.309203 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 44 AND status = 0 2022-05-17 10:49:55.329192 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate,dst_base_cid FROM localization WHERE id=(SELECT localization_id from accounts where id = 231) AND status=0 limit 1 2022-05-17 10:49:55.329192 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate,dst_base_cid FROM localization WHERE id=(SELECT localization_id from trunks where id = 4) AND status=0 limit 1 2022-05-17 10:49:55.329192 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_LOCALIZATION] Query :"0/31".....31302780000 2022-05-17 10:49:55.329192 [DEBUG] switch_cpp.cpp:1447 [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 ="31302780000" LIMIT 1 2022-05-17 10:49:55.329192 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Generated XML:
Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com parsing [default->31302780000] continue=false Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Regex (PASS) [31302780000] destination_number(31302780000) =~ /31302780000/ break=on-false Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(effective_destination_number=31302780000) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(bridge_pre_execute_bleg_app=sched_hangup) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(bridge_pre_execute_bleg_data=+6000 normal_clearing) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(callstart=2022-05-17 08:49:55) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(hangup_after_bridge=true) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(continue_on_fail=TRUE) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(account_id=196) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(parent_id=189) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(entity_id=0) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(call_processed=internal) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(call_direction=outbound) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(accountname=default) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(filename1=astpp.pbx.lua) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(origination_rates=ID:1597622|CODE:^31.*|DESTINATION:|CONNECTIONCOST:0.04900|INCLUDEDSECONDS:0|CT:|COST:0.01890|INC:1|INITIALBLOCK:1|RATEGROUP:24|MARKUP:0|CI:0|ACCID:196||ID:2846757|CODE:^3130.*|DESTINATION:Netherlands fixed|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.00210|INC:1|INITIALBLOCK:1|RATEGROUP:44|MARKUP:0|CI:0|ACCID:189) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(original_caller_id_number=31235258411) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action limit(db 504618 user_504618 10 ) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action limit(db 510514 user_510514 20 ) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action limit(hash CPS_510514 CPS_user_510514 1/1 ) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(effective_caller_id_number=31235258411) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(calltype=STANDARD) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(termination_rates=ID:114164|CODE:^3130.*|DESTINATION:Netherlands fixed|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00077|INC:1|INITIALBLOCK:1|TRUNK:4|PROVIDER:231) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(trunk_id=4) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(provider_id=231) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(rate_flag=0) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(force_trunk_flag=1597622) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action export(presence_data=trunk_id=4) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action set(intcall=0) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action export(presence_id=31302780000) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action export(presence_data=x//189|||vellinga(504618)|||^31.* // // 0.01890 |||SBCs // ^3130.* // Netherlands fixed // 0.00077 // trunk_id=4|||STD|||51.89.5.107|||0.00210 // ^3130.* // Netherlands fixed) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action bridge([leg_timeout=0,absolute_codec_string=^^:PCMA]sofia/gateway/SBC1/31302780000) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action bridge([leg_timeout=0,absolute_codec_string=^^:PCMA]sofia/gateway/SBC2/31302780000) Dialplan: sofia/default/3123999999@vellinga135.yoursipcloud.com Action bridge([leg_timeout=0,absolute_codec_string=^^:PCMA]sofia/gateway/MOR/31302780000) 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:287 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State Change CS_ROUTING -> CS_EXECUTE 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:644 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State ROUTING going to sleep 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3123999999@vellinga135.yoursipcloud.com) Running State Change CS_EXECUTE (Cur 5 Tot 23774) 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:651 (sofia/default/3123999999@vellinga135.yoursipcloud.com) State EXECUTE 2022-05-17 10:49:55.329192 [DEBUG] mod_sofia.c:209 sofia/default/3123999999@vellinga135.yoursipcloud.com SOFIA EXECUTE 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:329 sofia/default/3123999999@vellinga135.yoursipcloud.com Standard EXECUTE EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(effective_destination_number=31302780000) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [effective_destination_number]=[31302780000] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(bridge_pre_execute_bleg_app=sched_hangup) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [bridge_pre_execute_bleg_app]=[sched_hangup] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(bridge_pre_execute_bleg_data=+6000 normal_clearing) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [bridge_pre_execute_bleg_data]=[+6000 normal_clearing] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(callstart=2022-05-17 08:49:55) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [callstart]=[2022-05-17 08:49:55] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(hangup_after_bridge=true) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [hangup_after_bridge]=[true] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(continue_on_fail=TRUE) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [continue_on_fail]=[TRUE] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(account_id=196) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [account_id]=[196] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(parent_id=189) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [parent_id]=[189] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(entity_id=0) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [entity_id]=[0] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(call_processed=internal) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [call_processed]=[internal] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(call_direction=outbound) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [call_direction]=[outbound] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(accountname=default) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [accountname]=[default] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(filename1=astpp.pbx.lua) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [filename1]=[astpp.pbx.lua] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(origination_rates=ID:1597622|CODE:^31.*|DESTINATION:|CONNECTIONCOST:0.04900|INCLUDEDSECONDS:0|CT:|COST:0.01890|INC:1|INITIALBLOCK:1|RATEGROUP:24|MARKUP:0|CI:0|ACCID:196||ID:2846757|CODE:^3130.*|DESTINATION:Netherlands fixed|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.00210|INC:1|INITIALBLOCK:1|RATEGROUP:44|MARKUP:0|CI:0|ACCID:189) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [origination_rates]=[ID:1597622|CODE:^31.*|DESTINATION:|CONNECTIONCOST:0.04900|INCLUDEDSECONDS:0|CT:|COST:0.01890|INC:1|INITIALBLOCK:1|RATEGROUP:24|MARKUP:0|CI:0|ACCID:196||ID:2846757|CODE:^3130.*|DESTINATION:Netherlands fixed|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:0.00210|INC:1|INITIALBLOCK:1|RATEGROUP:44|MARKUP:0|CI:0|ACCID:189] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(original_caller_id_number=31235258411) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [original_caller_id_number]=[31235258411] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com limit(db 504618 user_504618 10 ) 2022-05-17 10:49:55.329192 [DEBUG] switch_limit.c:124 incr called: 504618_user_504618 max:10, interval:0 2022-05-17 10:49:55.329192 [DEBUG] mod_db.c:194 Usage for 504618_user_504618 is now 2/10 EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com limit(db 510514 user_510514 20 ) 2022-05-17 10:49:55.329192 [DEBUG] switch_limit.c:124 incr called: 510514_user_510514 max:20, interval:0 2022-05-17 10:49:55.329192 [DEBUG] mod_db.c:194 Usage for 510514_user_510514 is now 3/20 EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com limit(hash CPS_510514 CPS_user_510514 1/1 ) 2022-05-17 10:49:55.329192 [DEBUG] switch_limit.c:124 incr called: CPS_510514_CPS_user_510514 max:1, interval:1 2022-05-17 10:49:55.329192 [DEBUG] mod_hash.c:198 Usage for CPS_510514_CPS_user_510514 is now 1/1 for the last 1 seconds EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(effective_caller_id_number=31235258411) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [effective_caller_id_number]=[31235258411] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(calltype=STANDARD) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [calltype]=[STANDARD] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(termination_rates=ID:114164|CODE:^3130.*|DESTINATION:Netherlands fixed|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00077|INC:1|INITIALBLOCK:1|TRUNK:4|PROVIDER:231) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [termination_rates]=[ID:114164|CODE:^3130.*|DESTINATION:Netherlands fixed|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00077|INC:1|INITIALBLOCK:1|TRUNK:4|PROVIDER:231] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(trunk_id=4) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [trunk_id]=[4] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(provider_id=231) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [provider_id]=[231] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(rate_flag=0) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [rate_flag]=[0] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(force_trunk_flag=1597622) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [force_trunk_flag]=[1597622] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com export(presence_data=trunk_id=4) 2022-05-17 10:49:55.329192 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [presence_data]=[trunk_id=4] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com set(intcall=0) 2022-05-17 10:49:55.329192 [DEBUG] mod_dptools.c:1672 SET sofia/default/3123999999@vellinga135.yoursipcloud.com [intcall]=[0] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com export(presence_id=31302780000) 2022-05-17 10:49:55.329192 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [presence_id]=[31302780000] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com export(presence_data=x//189|||vellinga(504618)|||^31.* // // 0.01890 |||SBCs // ^3130.* // Netherlands fixed // 0.00077 // trunk_id=4|||STD|||51.89.5.107|||0.00210 // ^3130.* // Netherlands fixed) 2022-05-17 10:49:55.329192 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [presence_data]=[x//189|||vellinga(504618)|||^31.* // // 0.01890 |||SBCs // ^3130.* // Netherlands fixed // 0.00077 // trunk_id=4|||STD|||51.89.5.107|||0.00210 // ^3130.* // Netherlands fixed] EXECUTE [depth=0] sofia/default/3123999999@vellinga135.yoursipcloud.com bridge([leg_timeout=0,absolute_codec_string=^^:PCMA]sofia/gateway/SBC1/31302780000) 2022-05-17 10:49:55.329192 [DEBUG] switch_channel.c:1264 sofia/default/3123999999@vellinga135.yoursipcloud.com EXPORTING[export_vars] [presence_data]=[x//189|||vellinga(504618)|||^31.* // // 0.01890 |||SBCs // ^3130.* // Netherlands fixed // 0.00077 // trunk_id=4|||STD|||51.89.5.107|||0.00210 // ^3130.* // Netherlands fixed] to event 2022-05-17 10:49:55.329192 [DEBUG] switch_channel.c:1264 sofia/default/3123999999@vellinga135.yoursipcloud.com EXPORTING[export_vars] [presence_id]=[31302780000] to event 2022-05-17 10:49:55.329192 [DEBUG] switch_channel.c:1264 sofia/default/3123999999@vellinga135.yoursipcloud.com EXPORTING[export_vars] [presence_data]=[x//189|||vellinga(504618)|||^31.* // // 0.01890 |||SBCs // ^3130.* // Netherlands fixed // 0.00077 // trunk_id=4|||STD|||51.89.5.107|||0.00210 // ^3130.* // Netherlands fixed] to event 2022-05-17 10:49:55.329192 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables 2022-05-17 10:49:55.329192 [DEBUG] switch_ivr_originate.c:2804 Parsing session specific variables 2022-05-17 10:49:55.329192 [NOTICE] switch_channel.c:1118 New Channel sofia/default/31302780000 [f0801030-9791-4908-93dc-1585b84497f5] 2022-05-17 10:49:55.329192 [DEBUG] mod_sofia.c:5089 (sofia/default/31302780000) State Change CS_NEW -> CS_INIT 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31302780000) Running State Change CS_INIT (Cur 6 Tot 23775) 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:628 (sofia/default/31302780000) State INIT 2022-05-17 10:49:55.329192 [DEBUG] mod_sofia.c:93 sofia/default/31302780000 SOFIA INIT 2022-05-17 10:49:55.329192 [DEBUG] sofia_glue.c:1618 sofia/default/31302780000 sending invite version: 1.10.5 -release-17-25569c1631 64bit Local SDP: v=0 o=FreeSWITCH 1652748725 1652748726 IN IP4 185.249.40.236 s=FreeSWITCH c=IN IP4 185.249.40.236 t=0 0 m=audio 28670 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:40 sofia/default/31302780000 Standard INIT 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:48 (sofia/default/31302780000) State Change CS_INIT -> CS_ROUTING 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:628 (sofia/default/31302780000) State INIT going to sleep 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31302780000) Running State Change CS_ROUTING (Cur 6 Tot 23775) 2022-05-17 10:49:55.329192 [DEBUG] sofia.c:7326 Channel sofia/default/31302780000 entering state [calling][0] 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:644 (sofia/default/31302780000) State ROUTING 2022-05-17 10:49:55.329192 [DEBUG] mod_sofia.c:154 sofia/default/31302780000 SOFIA ROUTING 2022-05-17 10:49:55.329192 [DEBUG] switch_ivr_originate.c:67 (sofia/default/31302780000) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:644 (sofia/default/31302780000) State ROUTING going to sleep 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31302780000) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 23775) 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:663 (sofia/default/31302780000) State CONSUME_MEDIA 2022-05-17 10:49:55.329192 [DEBUG] switch_core_state_machine.c:663 (sofia/default/31302780000) State CONSUME_MEDIA going to sleep 2022-05-17 10:49:56.709233 [DEBUG] sofia.c:7326 Channel sofia/default/31302780000 entering state [proceeding][183] 2022-05-17 10:49:56.709233 [DEBUG] sofia.c:7336 Remote SDP: v=0 o=- 3476782421 1 IN IP4 185.249.40.253 s=- c=IN IP4 185.249.40.253 t=0 0 m=audio 12888 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=silenceSupp:off - - - - a=ptime:20 2022-05-17 10:49:56.709233 [NOTICE] sofia.c:7339 Pre-Answer sofia/default/31302780000! 2022-05-17 10:49:56.709233 [DEBUG] switch_channel.c:3565 (sofia/default/31302780000) Callstate Change DOWN -> EARLY 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:3839 Set Codec sofia/default/31302780000 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2022-05-17 10:49:56.709233 [DEBUG] switch_core_codec.c:111 sofia/default/31302780000 Original read codec set to PCMA:8 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:5911 sofia/default/31302780000 Set 2833 dtmf send payload to 101 recv payload to 101 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/default/31302780000] 185.249.40.236 port 28670 -> 185.249.40.253 port 12888 codec: 8 ms: 20 2022-05-17 10:49:56.709233 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:8977 sofia/default/31302780000 Set 2833 dtmf send payload to 101 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:8984 sofia/default/31302780000 Set 2833 dtmf receive payload to 101 2022-05-17 10:49:56.709233 [DEBUG] switch_core_media.c:9007 sofia/default/31302780000 Set rtp dtmf delay to 40 2022-05-17 10:49:56.729193 [INFO] switch_ivr_originate.c:3801 Sending early media 2022-05-17 10:49:56.729193 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/default/3123999999@vellinga135.yoursipcloud.com] 185.249.40.236 port 17896 -> 51.89.5.107 port 9420 codec: 0 ms: 20 2022-05-17 10:49:56.729193 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms 2022-05-17 10:49:56.729193 [DEBUG] switch_core_media.c:8977 sofia/default/3123999999@vellinga135.yoursipcloud.com Set 2833 dtmf send payload to 101 2022-05-17 10:49:56.729193 [DEBUG] switch_core_media.c:8984 sofia/default/3123999999@vellinga135.yoursipcloud.com Set 2833 dtmf receive payload to 101 2022-05-17 10:49:56.729193 [DEBUG] switch_core_media.c:9007 sofia/default/3123999999@vellinga135.yoursipcloud.com Set rtp dtmf delay to 40 2022-05-17 10:49:56.729193 [DEBUG] mod_sofia.c:2593 Ring SDP: v=0 o=FreeSWITCH 1652759500 1652759501 IN IP4 185.249.40.236 s=FreeSWITCH c=IN IP4 185.249.40.236 t=0 0 m=audio 17896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2022-05-17 10:49:56.729193 [NOTICE] mod_sofia.c:2596 Pre-Answer sofia/default/3123999999@vellinga135.yoursipcloud.com! 2022-05-17 10:49:56.729193 [DEBUG] switch_channel.c:3565 (sofia/default/3123999999@vellinga135.yoursipcloud.com) Callstate Change RINGING -> EARLY 2022-05-17 10:49:56.729193 [DEBUG] switch_ivr_originate.c:3852 Originate Resulted in Success: [sofia/default/31302780000] 2022-05-17 10:49:56.729193 [DEBUG] sofia.c:7326 Channel sofia/default/3123999999@vellinga135.yoursipcloud.com entering state [early][183] 2022-05-17 10:49:56.729193 [DEBUG] switch_ivr_bridge.c:1793 (sofia/default/31302780000) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2022-05-17 10:49:56.729193 [DEBUG] switch_core_state_machine.c:585 (sofia/default/31302780000) Running State Change CS_EXCHANGE_MEDIA (Cur 6 Tot 23775) 2022-05-17 10:49:56.729193 [DEBUG] switch_core_state_machine.c:654 (sofia/default/31302780000) State EXCHANGE_MEDIA 2022-05-17 10:49:56.729193 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA 2022-05-17 10:49:56.809193 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed. 2022-05-17 10:49:56.809193 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed. 2022-05-17 10:49:56.909224 [DEBUG] switch_ivr_bridge.c:655 sofia/default/31302780000 Bridge execute app sched_hangup(+6000 normal_clearing) 2022-05-17 10:49:56.929233 [DEBUG] switch_ivr.c:632 sofia/default/31302780000 Command Execute [depth=0] sched_hangup(+6000 normal_clearing) EXECUTE [depth=0] sofia/default/31302780000 sched_hangup(+6000 normal_clearing) 2022-05-17 10:49:56.929233 [DEBUG] switch_scheduler.c:252 Added task 7123 switch_ivr_schedule_hangup (f0801030-9791-4908-93dc-1585b84497f5) to run at 1652783396 2022-05-17 10:49:57.629205 [DEBUG] sofia.c:7326 Channel sofia/default/31302780000 entering state [completing][200] 2022-05-17 10:49:57.629205 [DEBUG] sofia.c:7333 Duplicate SDP v=0 o=- 3476782421 1 IN IP4 185.249.40.253 s=- c=IN IP4 185.249.40.253 t=0 0 m=audio 12888 RTP/AVP 8 101 a=rtpmap:101 telephone-event/8000 a=silenceSupp:off - - - - a=ptime:20 2022-05-17 10:49:57.649235 [DEBUG] sofia.c:7326 Channel sofia/default/31302780000 entering state [ready][200] 2022-05-17 10:49:57.649235 [NOTICE] sofia.c:8445 Channel [sofia/default/31302780000] has been answered 2022-05-17 10:49:57.649235 [DEBUG] switch_channel.c:3865 (sofia/default/31302780000) Callstate Change EARLY -> ACTIVE 2022-05-17 10:49:57.669230 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/default/3123999999@vellinga135.yoursipcloud.com. 2022-05-17 10:49:57.669230 [DEBUG] mod_sofia.c:898 Local SDP sofia/default/3123999999@vellinga135.yoursipcloud.com: v=0 o=FreeSWITCH 1652759500 1652759502 IN IP4 185.249.40.236 s=FreeSWITCH c=IN IP4 185.249.40.236 t=0 0 m=audio 17896 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2022-05-17 10:49:57.669230 [NOTICE] switch_ivr_bridge.c:731 Channel [sofia/default/3123999999@vellinga135.yoursipcloud.com] has been answered 2022-05-17 10:49:57.669230 [DEBUG] switch_channel.c:3865 (sofia/default/3123999999@vellinga135.yoursipcloud.com) Callstate Change EARLY -> ACTIVE 2022-05-17 10:49:57.669230 [DEBUG] sofia.c:7326 Channel sofia/default/3123999999@vellinga135.yoursipcloud.com entering state [completed][200] 2022-05-17 10:49:57.689232 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed. 2022-05-17 10:49:57.729201 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed. 2022-05-17 10:49:57.749199 [DEBUG] sofia.c:7326 Channel sofia/default/3123999999@vellinga135.yoursipcloud.com entering state [ready][200]