2023-04-13 14:05:32.029086 97.90% [INFO] mod_dialplan_xml.c:639 Processing V4131405250000483084 <17813312611>->17814929087 in context default
2023-04-13 14:05:32.029086 97.90% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:32.029086 97.90% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:32.029086 97.90% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:32.029086 97.90% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:32.029086 97.90% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/17813312611@168.235.110.123 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/17813312611@168.235.110.123) State ROUTING going to sleep
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/17813312611@168.235.110.123) Running State Change CS_HANGUP (Cur 1 Tot 15363)
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:844 (sofia/default/17813312611@168.235.110.123) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/17813312611@168.235.110.123) State HANGUP
2023-04-13 14:05:32.029086 97.90% [DEBUG] mod_sofia.c:468 Channel sofia/default/17813312611@168.235.110.123 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.029086 97.90% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:59 sofia/default/17813312611@168.235.110.123 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/17813312611@168.235.110.123) State HANGUP going to sleep
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:616 (sofia/default/17813312611@168.235.110.123) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/17813312611@168.235.110.123) Running State Change CS_REPORTING (Cur 1 Tot 15363)
2023-04-13 14:05:32.029086 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/17813312611@168.235.110.123) State REPORTING
2023-04-13 14:05:32.029086 97.90% [INFO] mod_json_cdr.c:271 Process [00a2d511-da63-4700-8872-1aac70c3dbf1.cdr.json]
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_state_machine.c:168 sofia/default/17813312611@168.235.110.123 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/17813312611@168.235.110.123) State REPORTING going to sleep
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_state_machine.c:607 (sofia/default/17813312611@168.235.110.123) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_session.c:1753 Session 15363 (sofia/default/17813312611@168.235.110.123) Locked, Waiting on external entities
2023-04-13 14:05:32.069024 97.90% [NOTICE] switch_core_session.c:1771 Session 15363 (sofia/default/17813312611@168.235.110.123) Ended
2023-04-13 14:05:32.069024 97.90% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/17813312611@168.235.110.123 [CS_DESTROY]
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_state_machine.c:735 (sofia/default/17813312611@168.235.110.123) Running State Change CS_DESTROY (Cur 0 Tot 15363)
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/17813312611@168.235.110.123) State DESTROY
2023-04-13 14:05:32.069024 97.90% [DEBUG] mod_sofia.c:379 sofia/default/17813312611@168.235.110.123 SOFIA DESTROY
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_state_machine.c:175 sofia/default/17813312611@168.235.110.123 Standard DESTROY
2023-04-13 14:05:32.069024 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/17813312611@168.235.110.123) State DESTROY going to sleep
2023-04-13 14:05:32.209034 97.90% [NOTICE] switch_channel.c:1123 New Channel sofia/default/14233101014@168.235.110.123 [01df6d71-ba9f-4874-b3e3-a7a12ce601c0]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/14233101014@168.235.110.123) Running State Change CS_NEW (Cur 1 Tot 15364)
2023-04-13 14:05:32.209034 97.90% [INFO] sofia.c:10462 sofia/default/14233101014@168.235.110.123 receiving invite from 199.167.144.226:5060 version: 1.10.7 -release 64bit call-id: 1ad81dc8014ba92c45b2cfeb2532407b@168.235.110.123:5060
2023-04-13 14:05:32.209034 97.90% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 199.167.144.226:0.
2023-04-13 14:05:32.209034 97.90% [DEBUG] sofia.c:10585 IP 199.167.144.226 Approved by acl "default[]". Access Granted.
2023-04-13 14:05:32.209034 97.90% [DEBUG] sofia.c:7499 Channel sofia/default/14233101014@168.235.110.123 entering state [received][100]
2023-04-13 14:05:32.209034 97.90% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 1552548836 1552548836 IN IP4 168.235.110.123
s=Asterisk PBX 11.25.1-vici
c=IN IP4 168.235.110.123
t=0 0
m=audio 17626 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
a=fmtp:101 0-16
a=ptime:20

2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/14233101014@168.235.110.123 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_codec.c:111 sofia/default/14233101014@168.235.110.123 Original read codec set to PCMU:0
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_media.c:5973 sofia/default/14233101014@168.235.110.123 Set 2833 dtmf send payload to 101 recv payload to 101
2023-04-13 14:05:32.209034 97.90% [DEBUG] sofia.c:7933 (sofia/default/14233101014@168.235.110.123) State Change CS_NEW -> CS_INIT
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:600 (sofia/default/14233101014@168.235.110.123) State NEW
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/14233101014@168.235.110.123) Running State Change CS_INIT (Cur 1 Tot 15364)
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/14233101014@168.235.110.123) State INIT
2023-04-13 14:05:32.209034 97.90% [DEBUG] mod_sofia.c:97 sofia/default/14233101014@168.235.110.123 SOFIA INIT
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:40 sofia/default/14233101014@168.235.110.123 Standard INIT
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:48 (sofia/default/14233101014@168.235.110.123) State Change CS_INIT -> CS_ROUTING
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/14233101014@168.235.110.123) State INIT going to sleep
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/14233101014@168.235.110.123) Running State Change CS_ROUTING (Cur 1 Tot 15364)
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_channel.c:2380 (sofia/default/14233101014@168.235.110.123) Callstate Change DOWN -> RINGING
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/14233101014@168.235.110.123) State ROUTING
2023-04-13 14:05:32.209034 97.90% [DEBUG] mod_sofia.c:158 sofia/default/14233101014@168.235.110.123 SOFIA ROUTING
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:230 sofia/default/14233101014@168.235.110.123 Standard ROUTING
2023-04-13 14:05:32.209034 97.90% [INFO] mod_dialplan_xml.c:639 Processing V4131405250000490174 <14233101014>->14233550926 in context default
2023-04-13 14:05:32.209034 97.90% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:32.209034 97.90% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:32.209034 97.90% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:32.209034 97.90% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:32.209034 97.90% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/14233101014@168.235.110.123 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/14233101014@168.235.110.123) State ROUTING going to sleep
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/14233101014@168.235.110.123) Running State Change CS_HANGUP (Cur 1 Tot 15364)
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:844 (sofia/default/14233101014@168.235.110.123) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/14233101014@168.235.110.123) State HANGUP
2023-04-13 14:05:32.209034 97.90% [DEBUG] mod_sofia.c:468 Channel sofia/default/14233101014@168.235.110.123 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.209034 97.90% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:59 sofia/default/14233101014@168.235.110.123 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/14233101014@168.235.110.123) State HANGUP going to sleep
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:616 (sofia/default/14233101014@168.235.110.123) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/14233101014@168.235.110.123) Running State Change CS_REPORTING (Cur 1 Tot 15364)
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/14233101014@168.235.110.123) State REPORTING
2023-04-13 14:05:32.209034 97.90% [INFO] mod_json_cdr.c:271 Process [01df6d71-ba9f-4874-b3e3-a7a12ce601c0.cdr.json]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:168 sofia/default/14233101014@168.235.110.123 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/14233101014@168.235.110.123) State REPORTING going to sleep
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:607 (sofia/default/14233101014@168.235.110.123) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_session.c:1753 Session 15364 (sofia/default/14233101014@168.235.110.123) Locked, Waiting on external entities
2023-04-13 14:05:32.209034 97.90% [NOTICE] switch_core_session.c:1771 Session 15364 (sofia/default/14233101014@168.235.110.123) Ended
2023-04-13 14:05:32.209034 97.90% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/14233101014@168.235.110.123 [CS_DESTROY]
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:735 (sofia/default/14233101014@168.235.110.123) Running State Change CS_DESTROY (Cur 0 Tot 15364)
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/14233101014@168.235.110.123) State DESTROY
2023-04-13 14:05:32.209034 97.90% [DEBUG] mod_sofia.c:379 sofia/default/14233101014@168.235.110.123 SOFIA DESTROY
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:175 sofia/default/14233101014@168.235.110.123 Standard DESTROY
2023-04-13 14:05:32.209034 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/14233101014@168.235.110.123) State DESTROY going to sleep
2023-04-13 14:05:32.889066 97.90% [NOTICE] switch_channel.c:1123 New Channel sofia/default/19049701843@168.235.110.123 [e2490474-1a75-4ac0-87f7-12fa26227cf3]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/19049701843@168.235.110.123) Running State Change CS_NEW (Cur 1 Tot 15365)
2023-04-13 14:05:32.889066 97.90% [INFO] sofia.c:10462 sofia/default/19049701843@168.235.110.123 receiving invite from 199.167.144.226:5060 version: 1.10.7 -release 64bit call-id: 37ec331f0a762d113e1c29417e4537c7@168.235.110.123:5060
2023-04-13 14:05:32.889066 97.90% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 199.167.144.226:0.
2023-04-13 14:05:32.889066 97.90% [DEBUG] sofia.c:10585 IP 199.167.144.226 Approved by acl "default[]". Access Granted.
2023-04-13 14:05:32.889066 97.90% [DEBUG] sofia.c:7499 Channel sofia/default/19049701843@168.235.110.123 entering state [received][100]
2023-04-13 14:05:32.889066 97.90% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 613615751 613615751 IN IP4 168.235.110.123
s=Asterisk PBX 11.25.1-vici
c=IN IP4 168.235.110.123
t=0 0
m=audio 16004 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
a=fmtp:101 0-16
a=ptime:20

2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/19049701843@168.235.110.123 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_codec.c:111 sofia/default/19049701843@168.235.110.123 Original read codec set to PCMU:0
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_media.c:5973 sofia/default/19049701843@168.235.110.123 Set 2833 dtmf send payload to 101 recv payload to 101
2023-04-13 14:05:32.889066 97.90% [DEBUG] sofia.c:7933 (sofia/default/19049701843@168.235.110.123) State Change CS_NEW -> CS_INIT
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:600 (sofia/default/19049701843@168.235.110.123) State NEW
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/19049701843@168.235.110.123) Running State Change CS_INIT (Cur 1 Tot 15365)
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/19049701843@168.235.110.123) State INIT
2023-04-13 14:05:32.889066 97.90% [DEBUG] mod_sofia.c:97 sofia/default/19049701843@168.235.110.123 SOFIA INIT
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:40 sofia/default/19049701843@168.235.110.123 Standard INIT
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:48 (sofia/default/19049701843@168.235.110.123) State Change CS_INIT -> CS_ROUTING
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/19049701843@168.235.110.123) State INIT going to sleep
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/19049701843@168.235.110.123) Running State Change CS_ROUTING (Cur 1 Tot 15365)
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_channel.c:2380 (sofia/default/19049701843@168.235.110.123) Callstate Change DOWN -> RINGING
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/19049701843@168.235.110.123) State ROUTING
2023-04-13 14:05:32.889066 97.90% [DEBUG] mod_sofia.c:158 sofia/default/19049701843@168.235.110.123 SOFIA ROUTING
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:230 sofia/default/19049701843@168.235.110.123 Standard ROUTING
2023-04-13 14:05:32.889066 97.90% [INFO] mod_dialplan_xml.c:639 Processing V4131405250000456724 <19049701843>->19042377510 in context default
2023-04-13 14:05:32.889066 97.90% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:32.889066 97.90% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:32.889066 97.90% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:32.889066 97.90% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:32.889066 97.90% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/19049701843@168.235.110.123 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/19049701843@168.235.110.123) State ROUTING going to sleep
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/19049701843@168.235.110.123) Running State Change CS_HANGUP (Cur 1 Tot 15365)
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:844 (sofia/default/19049701843@168.235.110.123) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/19049701843@168.235.110.123) State HANGUP
2023-04-13 14:05:32.889066 97.90% [DEBUG] mod_sofia.c:468 Channel sofia/default/19049701843@168.235.110.123 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.889066 97.90% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:59 sofia/default/19049701843@168.235.110.123 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/19049701843@168.235.110.123) State HANGUP going to sleep
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:616 (sofia/default/19049701843@168.235.110.123) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/19049701843@168.235.110.123) Running State Change CS_REPORTING (Cur 1 Tot 15365)
2023-04-13 14:05:32.889066 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/19049701843@168.235.110.123) State REPORTING
2023-04-13 14:05:32.889066 97.90% [INFO] mod_json_cdr.c:271 Process [e2490474-1a75-4ac0-87f7-12fa26227cf3.cdr.json]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:168 sofia/default/19049701843@168.235.110.123 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/19049701843@168.235.110.123) State REPORTING going to sleep
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:607 (sofia/default/19049701843@168.235.110.123) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_session.c:1753 Session 15365 (sofia/default/19049701843@168.235.110.123) Locked, Waiting on external entities
2023-04-13 14:05:32.909048 97.90% [NOTICE] switch_core_session.c:1771 Session 15365 (sofia/default/19049701843@168.235.110.123) Ended
2023-04-13 14:05:32.909048 97.90% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/19049701843@168.235.110.123 [CS_DESTROY]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:735 (sofia/default/19049701843@168.235.110.123) Running State Change CS_DESTROY (Cur 0 Tot 15365)
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/19049701843@168.235.110.123) State DESTROY
2023-04-13 14:05:32.909048 97.90% [DEBUG] mod_sofia.c:379 sofia/default/19049701843@168.235.110.123 SOFIA DESTROY
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:175 sofia/default/19049701843@168.235.110.123 Standard DESTROY
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/19049701843@168.235.110.123) State DESTROY going to sleep
2023-04-13 14:05:32.909048 97.90% [NOTICE] switch_channel.c:1123 New Channel sofia/default/16306968030@192.158.239.154 [36572fb3-3c66-426e-bd4e-e91a22809b35]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16306968030@192.158.239.154) Running State Change CS_NEW (Cur 1 Tot 15366)
2023-04-13 14:05:32.909048 97.90% [INFO] sofia.c:10462 sofia/default/16306968030@192.158.239.154 receiving invite from 199.167.144.226:5060 version: 1.10.7 -release 64bit call-id: 3a4c153a6c6a1d824c976201491bee02@192.158.239.154:5060
2023-04-13 14:05:32.909048 97.90% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 199.167.144.226:0.
2023-04-13 14:05:32.909048 97.90% [DEBUG] sofia.c:10585 IP 199.167.144.226 Approved by acl "default[]". Access Granted.
2023-04-13 14:05:32.909048 97.90% [DEBUG] sofia.c:7499 Channel sofia/default/16306968030@192.158.239.154 entering state [received][100]
2023-04-13 14:05:32.909048 97.90% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 1859827084 1859827084 IN IP4 192.158.239.154
s=Asterisk PBX 13.29.2-vici
c=IN IP4 192.158.239.154
t=0 0
m=audio 11188 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
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150

2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/16306968030@192.158.239.154 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_codec.c:111 sofia/default/16306968030@192.158.239.154 Original read codec set to PCMU:0
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_media.c:5973 sofia/default/16306968030@192.158.239.154 Set 2833 dtmf send payload to 101 recv payload to 101
2023-04-13 14:05:32.909048 97.90% [DEBUG] sofia.c:7933 (sofia/default/16306968030@192.158.239.154) State Change CS_NEW -> CS_INIT
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:600 (sofia/default/16306968030@192.158.239.154) State NEW
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16306968030@192.158.239.154) Running State Change CS_INIT (Cur 1 Tot 15366)
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/16306968030@192.158.239.154) State INIT
2023-04-13 14:05:32.909048 97.90% [DEBUG] mod_sofia.c:97 sofia/default/16306968030@192.158.239.154 SOFIA INIT
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:40 sofia/default/16306968030@192.158.239.154 Standard INIT
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:48 (sofia/default/16306968030@192.158.239.154) State Change CS_INIT -> CS_ROUTING
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/16306968030@192.158.239.154) State INIT going to sleep
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16306968030@192.158.239.154) Running State Change CS_ROUTING (Cur 1 Tot 15366)
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_channel.c:2380 (sofia/default/16306968030@192.158.239.154) Callstate Change DOWN -> RINGING
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/16306968030@192.158.239.154) State ROUTING
2023-04-13 14:05:32.909048 97.90% [DEBUG] mod_sofia.c:158 sofia/default/16306968030@192.158.239.154 SOFIA ROUTING
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:230 sofia/default/16306968030@192.158.239.154 Standard ROUTING
2023-04-13 14:05:32.909048 97.90% [INFO] mod_dialplan_xml.c:639 Processing V4131405250003798137 <16306968030>->14859345516302001033 in context default
2023-04-13 14:05:32.909048 97.90% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:32.909048 97.90% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:32.909048 97.90% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:32.909048 97.90% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:32.909048 97.90% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/16306968030@192.158.239.154 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/16306968030@192.158.239.154) State ROUTING going to sleep
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16306968030@192.158.239.154) Running State Change CS_HANGUP (Cur 1 Tot 15366)
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:844 (sofia/default/16306968030@192.158.239.154) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:32.909048 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/16306968030@192.158.239.154) State HANGUP
2023-04-13 14:05:32.909048 97.90% [DEBUG] mod_sofia.c:468 Channel sofia/default/16306968030@192.158.239.154 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.949001 97.90% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:59 sofia/default/16306968030@192.158.239.154 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/16306968030@192.158.239.154) State HANGUP going to sleep
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:616 (sofia/default/16306968030@192.158.239.154) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16306968030@192.158.239.154) Running State Change CS_REPORTING (Cur 1 Tot 15366)
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/16306968030@192.158.239.154) State REPORTING
2023-04-13 14:05:32.949001 97.90% [INFO] mod_json_cdr.c:271 Process [36572fb3-3c66-426e-bd4e-e91a22809b35.cdr.json]
2023-04-13 14:05:32.949001 97.90% [NOTICE] switch_channel.c:1123 New Channel sofia/default/17879392883@149.28.206.5 [120d4ff5-9fe2-4f76-849d-501f40414ac2]
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/17879392883@149.28.206.5) Running State Change CS_NEW (Cur 2 Tot 15367)
2023-04-13 14:05:32.949001 97.90% [INFO] sofia.c:10462 sofia/default/17879392883@149.28.206.5 receiving invite from 199.167.144.226:5060 version: 1.10.7 -release 64bit call-id: 384da5543416569e542f63610d07d088@149.28.206.5:5060
2023-04-13 14:05:32.949001 97.90% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 199.167.144.226:0.
2023-04-13 14:05:32.949001 97.90% [DEBUG] sofia.c:10585 IP 199.167.144.226 Approved by acl "default[]". Access Granted.
2023-04-13 14:05:32.949001 97.90% [DEBUG] sofia.c:7499 Channel sofia/default/17879392883@149.28.206.5 entering state [received][100]
2023-04-13 14:05:32.949001 97.90% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 1824995045 1824995045 IN IP4 149.28.206.5
s=Asterisk PBX 13.27.1-vici
c=IN IP4 149.28.206.5
t=0 0
m=audio 10220 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150

2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/17879392883@149.28.206.5 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_codec.c:111 sofia/default/17879392883@149.28.206.5 Original read codec set to PCMU:0
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_media.c:5973 sofia/default/17879392883@149.28.206.5 Set 2833 dtmf send payload to 101 recv payload to 101
2023-04-13 14:05:32.949001 97.90% [DEBUG] sofia.c:7933 (sofia/default/17879392883@149.28.206.5) State Change CS_NEW -> CS_INIT
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:600 (sofia/default/17879392883@149.28.206.5) State NEW
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/17879392883@149.28.206.5) Running State Change CS_INIT (Cur 2 Tot 15367)
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/17879392883@149.28.206.5) State INIT
2023-04-13 14:05:32.949001 97.90% [DEBUG] mod_sofia.c:97 sofia/default/17879392883@149.28.206.5 SOFIA INIT
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:40 sofia/default/17879392883@149.28.206.5 Standard INIT
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:48 (sofia/default/17879392883@149.28.206.5) State Change CS_INIT -> CS_ROUTING
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/17879392883@149.28.206.5) State INIT going to sleep
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/17879392883@149.28.206.5) Running State Change CS_ROUTING (Cur 2 Tot 15367)
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_channel.c:2380 (sofia/default/17879392883@149.28.206.5) Callstate Change DOWN -> RINGING
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/17879392883@149.28.206.5) State ROUTING
2023-04-13 14:05:32.949001 97.90% [DEBUG] mod_sofia.c:158 sofia/default/17879392883@149.28.206.5 SOFIA ROUTING
2023-04-13 14:05:32.949001 97.90% [DEBUG] switch_core_state_machine.c:230 sofia/default/17879392883@149.28.206.5 Standard ROUTING
2023-04-13 14:05:32.949001 97.90% [INFO] mod_dialplan_xml.c:639 Processing V4131405310014682707 <17879392883>->17878071346 in context default
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:168 sofia/default/16306968030@192.158.239.154 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/16306968030@192.158.239.154) State REPORTING going to sleep
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:607 (sofia/default/16306968030@192.158.239.154) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_session.c:1753 Session 15366 (sofia/default/16306968030@192.158.239.154) Locked, Waiting on external entities
2023-04-13 14:05:32.969066 97.93% [NOTICE] switch_core_session.c:1771 Session 15366 (sofia/default/16306968030@192.158.239.154) Ended
2023-04-13 14:05:32.969066 97.93% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/16306968030@192.158.239.154 [CS_DESTROY]
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:735 (sofia/default/16306968030@192.158.239.154) Running State Change CS_DESTROY (Cur 1 Tot 15367)
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/16306968030@192.158.239.154) State DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] mod_sofia.c:379 sofia/default/16306968030@192.158.239.154 SOFIA DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:175 sofia/default/16306968030@192.158.239.154 Standard DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/16306968030@192.158.239.154) State DESTROY going to sleep
2023-04-13 14:05:32.969066 97.93% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:32.969066 97.93% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:32.969066 97.93% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:32.969066 97.93% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:32.969066 97.93% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/17879392883@149.28.206.5 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/17879392883@149.28.206.5) State ROUTING going to sleep
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/17879392883@149.28.206.5) Running State Change CS_HANGUP (Cur 1 Tot 15367)
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:844 (sofia/default/17879392883@149.28.206.5) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/17879392883@149.28.206.5) State HANGUP
2023-04-13 14:05:32.969066 97.93% [DEBUG] mod_sofia.c:468 Channel sofia/default/17879392883@149.28.206.5 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.969066 97.93% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:59 sofia/default/17879392883@149.28.206.5 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/17879392883@149.28.206.5) State HANGUP going to sleep
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:616 (sofia/default/17879392883@149.28.206.5) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/17879392883@149.28.206.5) Running State Change CS_REPORTING (Cur 1 Tot 15367)
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/17879392883@149.28.206.5) State REPORTING
2023-04-13 14:05:32.969066 97.93% [INFO] mod_json_cdr.c:271 Process [120d4ff5-9fe2-4f76-849d-501f40414ac2.cdr.json]
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:168 sofia/default/17879392883@149.28.206.5 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/17879392883@149.28.206.5) State REPORTING going to sleep
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:607 (sofia/default/17879392883@149.28.206.5) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_session.c:1753 Session 15367 (sofia/default/17879392883@149.28.206.5) Locked, Waiting on external entities
2023-04-13 14:05:32.969066 97.93% [NOTICE] switch_core_session.c:1771 Session 15367 (sofia/default/17879392883@149.28.206.5) Ended
2023-04-13 14:05:32.969066 97.93% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/17879392883@149.28.206.5 [CS_DESTROY]
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:735 (sofia/default/17879392883@149.28.206.5) Running State Change CS_DESTROY (Cur 0 Tot 15367)
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/17879392883@149.28.206.5) State DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] mod_sofia.c:379 sofia/default/17879392883@149.28.206.5 SOFIA DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:175 sofia/default/17879392883@149.28.206.5 Standard DESTROY
2023-04-13 14:05:32.969066 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/17879392883@149.28.206.5) State DESTROY going to sleep
2023-04-13 14:05:33.189058 97.93% [NOTICE] switch_channel.c:1123 New Channel sofia/default/6993237845@148.255.23.75 [045d6068-7a5e-47a2-9f50-7ecaa7a06aa3]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/6993237845@148.255.23.75) Running State Change CS_NEW (Cur 1 Tot 15368)
2023-04-13 14:05:33.189058 97.93% [INFO] sofia.c:10462 sofia/default/6993237845@148.255.23.75 receiving invite from 199.167.144.226:5060 version: 1.10.7 -release 64bit call-id: 6f39d118364f208f1944926b0fcaf936@148.255.23.75:5060
2023-04-13 14:05:33.189058 97.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 199.167.144.226:0.
2023-04-13 14:05:33.189058 97.93% [DEBUG] sofia.c:10585 IP 199.167.144.226 Approved by acl "default[]". Access Granted.
2023-04-13 14:05:33.189058 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/6993237845@148.255.23.75 entering state [received][100]
2023-04-13 14:05:33.189058 97.93% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 898251950 898251950 IN IP4 190.80.168.75
s=Asterisk PBX 13.38.3-vici
c=IN IP4 190.80.168.75
t=0 0
m=audio 17228 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150

2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/6993237845@148.255.23.75 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_codec.c:111 sofia/default/6993237845@148.255.23.75 Original read codec set to PCMU:0
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_media.c:5973 sofia/default/6993237845@148.255.23.75 Set 2833 dtmf send payload to 101 recv payload to 101
2023-04-13 14:05:33.189058 97.93% [DEBUG] sofia.c:7933 (sofia/default/6993237845@148.255.23.75) State Change CS_NEW -> CS_INIT
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:600 (sofia/default/6993237845@148.255.23.75) State NEW
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/6993237845@148.255.23.75) Running State Change CS_INIT (Cur 1 Tot 15368)
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/6993237845@148.255.23.75) State INIT
2023-04-13 14:05:33.189058 97.93% [DEBUG] mod_sofia.c:97 sofia/default/6993237845@148.255.23.75 SOFIA INIT
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/6993237845@148.255.23.75 Standard INIT
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/6993237845@148.255.23.75) State Change CS_INIT -> CS_ROUTING
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/6993237845@148.255.23.75) State INIT going to sleep
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/6993237845@148.255.23.75) Running State Change CS_ROUTING (Cur 1 Tot 15368)
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_channel.c:2380 (sofia/default/6993237845@148.255.23.75) Callstate Change DOWN -> RINGING
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/6993237845@148.255.23.75) State ROUTING
2023-04-13 14:05:33.189058 97.93% [DEBUG] mod_sofia.c:158 sofia/default/6993237845@148.255.23.75 SOFIA ROUTING
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:230 sofia/default/6993237845@148.255.23.75 Standard ROUTING
2023-04-13 14:05:33.189058 97.93% [INFO] mod_dialplan_xml.c:639 Processing V4121447320000102126 <9167259011>->51983497690 in context default
2023-04-13 14:05:33.189058 97.93% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:33.189058 97.93% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:33.189058 97.93% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:33.189058 97.93% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:33.189058 97.93% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/6993237845@148.255.23.75 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/6993237845@148.255.23.75) State ROUTING going to sleep
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/6993237845@148.255.23.75) Running State Change CS_HANGUP (Cur 1 Tot 15368)
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:844 (sofia/default/6993237845@148.255.23.75) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/6993237845@148.255.23.75) State HANGUP
2023-04-13 14:05:33.189058 97.93% [DEBUG] mod_sofia.c:468 Channel sofia/default/6993237845@148.255.23.75 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.189058 97.93% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:59 sofia/default/6993237845@148.255.23.75 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/6993237845@148.255.23.75) State HANGUP going to sleep
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:616 (sofia/default/6993237845@148.255.23.75) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/6993237845@148.255.23.75) Running State Change CS_REPORTING (Cur 1 Tot 15368)
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/6993237845@148.255.23.75) State REPORTING
2023-04-13 14:05:33.189058 97.93% [INFO] mod_json_cdr.c:271 Process [045d6068-7a5e-47a2-9f50-7ecaa7a06aa3.cdr.json]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:168 sofia/default/6993237845@148.255.23.75 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/6993237845@148.255.23.75) State REPORTING going to sleep
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:607 (sofia/default/6993237845@148.255.23.75) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_session.c:1753 Session 15368 (sofia/default/6993237845@148.255.23.75) Locked, Waiting on external entities
2023-04-13 14:05:33.189058 97.93% [NOTICE] switch_core_session.c:1771 Session 15368 (sofia/default/6993237845@148.255.23.75) Ended
2023-04-13 14:05:33.189058 97.93% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/6993237845@148.255.23.75 [CS_DESTROY]
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:735 (sofia/default/6993237845@148.255.23.75) Running State Change CS_DESTROY (Cur 0 Tot 15368)
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/6993237845@148.255.23.75) State DESTROY
2023-04-13 14:05:33.189058 97.93% [DEBUG] mod_sofia.c:379 sofia/default/6993237845@148.255.23.75 SOFIA DESTROY
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:175 sofia/default/6993237845@148.255.23.75 Standard DESTROY
2023-04-13 14:05:33.189058 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/6993237845@148.255.23.75) State DESTROY going to sleep
2023-04-13 14:05:33.228997 97.93% [NOTICE] switch_channel.c:1123 New Channel sofia/default/15616358450@168.235.110.123 [6b0bdab1-ee1f-417f-abd7-30d469113458]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/15616358450@168.235.110.123) Running State Change CS_NEW (Cur 1 Tot 15369)
2023-04-13 14:05:33.228997 97.93% [INFO] sofia.c:10462 sofia/default/15616358450@168.235.110.123 receiving invite from 199.167.144.226:5060 version: 1.10.7 -release 64bit call-id: 42b0528f58d8984e47c9f9c12855d804@168.235.110.123:5060
2023-04-13 14:05:33.228997 97.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 199.167.144.226:0.
2023-04-13 14:05:33.228997 97.93% [DEBUG] sofia.c:10585 IP 199.167.144.226 Approved by acl "default[]". Access Granted.
2023-04-13 14:05:33.228997 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/15616358450@168.235.110.123 entering state [received][100]
2023-04-13 14:05:33.228997 97.93% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 2105228367 2105228367 IN IP4 168.235.110.123
s=Asterisk PBX 11.25.1-vici
c=IN IP4 168.235.110.123
t=0 0
m=audio 16686 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
a=fmtp:101 0-16
a=ptime:20

2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/15616358450@168.235.110.123 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_codec.c:111 sofia/default/15616358450@168.235.110.123 Original read codec set to PCMU:0
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_media.c:5973 sofia/default/15616358450@168.235.110.123 Set 2833 dtmf send payload to 101 recv payload to 101
2023-04-13 14:05:33.228997 97.93% [DEBUG] sofia.c:7933 (sofia/default/15616358450@168.235.110.123) State Change CS_NEW -> CS_INIT
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:600 (sofia/default/15616358450@168.235.110.123) State NEW
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/15616358450@168.235.110.123) Running State Change CS_INIT (Cur 1 Tot 15369)
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/15616358450@168.235.110.123) State INIT
2023-04-13 14:05:33.228997 97.93% [DEBUG] mod_sofia.c:97 sofia/default/15616358450@168.235.110.123 SOFIA INIT
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/15616358450@168.235.110.123 Standard INIT
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/15616358450@168.235.110.123) State Change CS_INIT -> CS_ROUTING
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/15616358450@168.235.110.123) State INIT going to sleep
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/15616358450@168.235.110.123) Running State Change CS_ROUTING (Cur 1 Tot 15369)
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_channel.c:2380 (sofia/default/15616358450@168.235.110.123) Callstate Change DOWN -> RINGING
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/15616358450@168.235.110.123) State ROUTING
2023-04-13 14:05:33.228997 97.93% [DEBUG] mod_sofia.c:158 sofia/default/15616358450@168.235.110.123 SOFIA ROUTING
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_core_state_machine.c:230 sofia/default/15616358450@168.235.110.123 Standard ROUTING
2023-04-13 14:05:33.228997 97.93% [INFO] mod_dialplan_xml.c:639 Processing V4131405290000461810 <15616358450>->15616541645 in context default
2023-04-13 14:05:33.228997 97.93% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:33.228997 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:33.228997 97.93% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:33.228997 97.93% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:33.228997 97.93% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:33.228997 97.93% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/15616358450@168.235.110.123 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/15616358450@168.235.110.123) State ROUTING going to sleep
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/15616358450@168.235.110.123) Running State Change CS_HANGUP (Cur 1 Tot 15369)
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:844 (sofia/default/15616358450@168.235.110.123) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/15616358450@168.235.110.123) State HANGUP
2023-04-13 14:05:33.249024 97.93% [DEBUG] mod_sofia.c:468 Channel sofia/default/15616358450@168.235.110.123 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.249024 97.93% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:59 sofia/default/15616358450@168.235.110.123 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/15616358450@168.235.110.123) State HANGUP going to sleep
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:616 (sofia/default/15616358450@168.235.110.123) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/15616358450@168.235.110.123) Running State Change CS_REPORTING (Cur 1 Tot 15369)
2023-04-13 14:05:33.249024 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/15616358450@168.235.110.123) State REPORTING
2023-04-13 14:05:33.249024 97.93% [INFO] mod_json_cdr.c:271 Process [6b0bdab1-ee1f-417f-abd7-30d469113458.cdr.json]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:168 sofia/default/15616358450@168.235.110.123 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/15616358450@168.235.110.123) State REPORTING going to sleep
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:607 (sofia/default/15616358450@168.235.110.123) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_session.c:1753 Session 15369 (sofia/default/15616358450@168.235.110.123) Locked, Waiting on external entities
2023-04-13 14:05:33.269027 97.93% [NOTICE] switch_core_session.c:1771 Session 15369 (sofia/default/15616358450@168.235.110.123) Ended
2023-04-13 14:05:33.269027 97.93% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/15616358450@168.235.110.123 [CS_DESTROY]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:735 (sofia/default/15616358450@168.235.110.123) Running State Change CS_DESTROY (Cur 0 Tot 15369)
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/15616358450@168.235.110.123) State DESTROY
2023-04-13 14:05:33.269027 97.93% [DEBUG] mod_sofia.c:379 sofia/default/15616358450@168.235.110.123 SOFIA DESTROY
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:175 sofia/default/15616358450@168.235.110.123 Standard DESTROY
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/15616358450@168.235.110.123) State DESTROY going to sleep
2023-04-13 14:05:33.269027 97.93% [NOTICE] switch_channel.c:1123 New Channel sofia/default/16302669076@192.158.239.154 [90035199-11cd-48b1-9836-3f640f0be75c]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16302669076@192.158.239.154) Running State Change CS_NEW (Cur 1 Tot 15370)
2023-04-13 14:05:33.269027 97.93% [INFO] sofia.c:10462 sofia/default/16302669076@192.158.239.154 receiving invite from 199.167.144.226:5060 version: 1.10.7 -release 64bit call-id: 160984af26c1087d1637b3147a4b8f6c@192.158.239.154:5060
2023-04-13 14:05:33.269027 97.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 199.167.144.226:0.
2023-04-13 14:05:33.269027 97.93% [DEBUG] sofia.c:10585 IP 199.167.144.226 Approved by acl "default[]". Access Granted.
2023-04-13 14:05:33.269027 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/16302669076@192.158.239.154 entering state [received][100]
2023-04-13 14:05:33.269027 97.93% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=root 1240862897 1240862897 IN IP4 192.158.239.154
s=Asterisk PBX 13.29.2-vici
c=IN IP4 192.158.239.154
t=0 0
m=audio 17884 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
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150

2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/16302669076@192.158.239.154 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_codec.c:111 sofia/default/16302669076@192.158.239.154 Original read codec set to PCMU:0
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_media.c:5973 sofia/default/16302669076@192.158.239.154 Set 2833 dtmf send payload to 101 recv payload to 101
2023-04-13 14:05:33.269027 97.93% [DEBUG] sofia.c:7933 (sofia/default/16302669076@192.158.239.154) State Change CS_NEW -> CS_INIT
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:600 (sofia/default/16302669076@192.158.239.154) State NEW
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16302669076@192.158.239.154) Running State Change CS_INIT (Cur 1 Tot 15370)
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/16302669076@192.158.239.154) State INIT
2023-04-13 14:05:33.269027 97.93% [DEBUG] mod_sofia.c:97 sofia/default/16302669076@192.158.239.154 SOFIA INIT
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/16302669076@192.158.239.154 Standard INIT
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/16302669076@192.158.239.154) State Change CS_INIT -> CS_ROUTING
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/16302669076@192.158.239.154) State INIT going to sleep
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16302669076@192.158.239.154) Running State Change CS_ROUTING (Cur 1 Tot 15370)
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_channel.c:2380 (sofia/default/16302669076@192.158.239.154) Callstate Change DOWN -> RINGING
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/16302669076@192.158.239.154) State ROUTING
2023-04-13 14:05:33.269027 97.93% [DEBUG] mod_sofia.c:158 sofia/default/16302669076@192.158.239.154 SOFIA ROUTING
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_core_state_machine.c:230 sofia/default/16302669076@192.158.239.154 Standard ROUTING
2023-04-13 14:05:33.269027 97.93% [INFO] mod_dialplan_xml.c:639 Processing V4131405310003798145 <16302669076>->14859345516304530762 in context default
2023-04-13 14:05:33.269027 97.93% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2023-04-13 14:05:33.269027 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2023-04-13 14:05:33.288999 97.93% [ERR] switch_cpp.cpp:439 Trying to getHeader an invalid header!
2023-04-13 14:05:33.288999 97.93% [WARNING] mod_dialplan_xml.c:669 Context default not found
2023-04-13 14:05:33.288999 97.93% [INFO] switch_core_state_machine.c:306 No Route, Aborting
2023-04-13 14:05:33.288999 97.93% [NOTICE] switch_core_state_machine.c:307 Hangup sofia/default/16302669076@192.158.239.154 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/16302669076@192.158.239.154) State ROUTING going to sleep
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16302669076@192.158.239.154) Running State Change CS_HANGUP (Cur 1 Tot 15370)
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:844 (sofia/default/16302669076@192.158.239.154) Callstate Change RINGING -> HANGUP
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/16302669076@192.158.239.154) State HANGUP
2023-04-13 14:05:33.288999 97.93% [DEBUG] mod_sofia.c:468 Channel sofia/default/16302669076@192.158.239.154 hanging up, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.288999 97.93% [DEBUG] mod_sofia.c:613 Responding to INVITE with: 404
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:59 sofia/default/16302669076@192.158.239.154 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/16302669076@192.158.239.154) State HANGUP going to sleep
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:616 (sofia/default/16302669076@192.158.239.154) State Change CS_HANGUP -> CS_REPORTING
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/16302669076@192.158.239.154) Running State Change CS_REPORTING (Cur 1 Tot 15370)
2023-04-13 14:05:33.288999 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/16302669076@192.158.239.154) State REPORTING
2023-04-13 14:05:33.288999 97.93% [INFO] mod_json_cdr.c:271 Process [90035199-11cd-48b1-9836-3f640f0be75c.cdr.json]
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_state_machine.c:168 sofia/default/16302669076@192.158.239.154 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/16302669076@192.158.239.154) State REPORTING going to sleep
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_state_machine.c:607 (sofia/default/16302669076@192.158.239.154) State Change CS_REPORTING -> CS_DESTROY
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_session.c:1753 Session 15370 (sofia/default/16302669076@192.158.239.154) Locked, Waiting on external entities
2023-04-13 14:05:33.309027 97.93% [NOTICE] switch_core_session.c:1771 Session 15370 (sofia/default/16302669076@192.158.239.154) Ended
2023-04-13 14:05:33.309027 97.93% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/16302669076@192.158.239.154 [CS_DESTROY]
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_state_machine.c:735 (sofia/default/16302669076@192.158.239.154) Running State Change CS_DESTROY (Cur 0 Tot 15370)
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/16302669076@192.158.239.154) State DESTROY
2023-04-13 14:05:33.309027 97.93% [DEBUG] mod_sofia.c:379 sofia/default/16302669076@192.158.239.154 SOFIA DESTROY
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_state_machine.c:175 sofia/default/16302669076@192.158.239.154 Standard DESTROY
2023-04-13 14:05:33.309027 97.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/16302669076@192.158.239.154) State DESTROY going to sleep