freeswitch@ip-172-31-40-49> 
2022-09-28 11:21:46.320647 92.00% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:21:46.520655 92.00% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:21:54.600730 97.43% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:21:54.800659 97.43% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:14.880659 88.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:15.080656 88.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:16.560680 87.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [123@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:16.580657 87.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [123@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:16.580657 87.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:16.580657 87.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:24.520678 85.73% [NOTICE] sofia_reg.c:459 Registering 8134791837
2022-09-28 11:22:24.780681 85.73% [ERR] sofia_reg.c:2677 8134791837 Failed Registration with status Forbidden [403]. failure #3
2022-09-28 11:22:25.520678 86.60% [WARNING] sofia_reg.c:516 8134791837 Failed Registration [403], setting retry to 90 seconds.
2022-09-28 11:22:32.420674 88.30% [NOTICE] switch_channel.c:1123 New Channel sofia/default/900090111312715161@13.127.15.161 [e5368728-bfab-47fb-ae5c-439ac7b7ab42]
2022-09-28 11:22:32.420674 88.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/900090111312715161@13.127.15.161) Running State Change CS_NEW (Cur 1 Tot 3383)
2022-09-28 11:22:32.420674 88.30% [INFO] sofia.c:10462 sofia/default/900090111312715161@13.127.15.161 receiving invite from 146.70.88.246:58539 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 1840783406-1731873435-674215418
2022-09-28 11:22:32.420674 88.30% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 146.70.88.246:0.
2022-09-28 11:22:32.420674 88.30% [DEBUG] sofia.c:2419 detaching session e5368728-bfab-47fb-ae5c-439ac7b7ab42
2022-09-28 11:22:32.420674 88.30% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [90009011972598112101@13.127.15.161] from ip 146.70.88.246
2022-09-28 11:22:32.420674 88.30% [DEBUG] switch_core_state_machine.c:600 (sofia/default/900090111312715161@13.127.15.161) State NEW
2022-09-28 11:22:42.440647 95.07% [WARNING] switch_core_state_machine.c:684 e5368728-bfab-47fb-ae5c-439ac7b7ab42 sofia/default/900090111312715161@13.127.15.161 Abandoned
2022-09-28 11:22:42.440647 95.07% [NOTICE] switch_core_state_machine.c:687 Hangup sofia/default/900090111312715161@13.127.15.161 [CS_NEW] [WRONG_CALL_STATE]
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/900090111312715161@13.127.15.161) Running State Change CS_HANGUP (Cur 1 Tot 3383)
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:844 (sofia/default/900090111312715161@13.127.15.161) Callstate Change DOWN -> HANGUP
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/900090111312715161@13.127.15.161) State HANGUP
2022-09-28 11:22:42.440647 95.07% [DEBUG] mod_sofia.c:468 Channel sofia/default/900090111312715161@13.127.15.161 hanging up, cause: WRONG_CALL_STATE
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:59 sofia/default/900090111312715161@13.127.15.161 Standard HANGUP, cause: WRONG_CALL_STATE
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/900090111312715161@13.127.15.161) State HANGUP going to sleep
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:616 (sofia/default/900090111312715161@13.127.15.161) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/900090111312715161@13.127.15.161) Running State Change CS_REPORTING (Cur 1 Tot 3383)
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/900090111312715161@13.127.15.161) State REPORTING
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:168 sofia/default/900090111312715161@13.127.15.161 Standard REPORTING, cause: WRONG_CALL_STATE
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/900090111312715161@13.127.15.161) State REPORTING going to sleep
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:607 (sofia/default/900090111312715161@13.127.15.161) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_session.c:1753 Session 3383 (sofia/default/900090111312715161@13.127.15.161) Locked, Waiting on external entities
2022-09-28 11:22:42.440647 95.07% [NOTICE] switch_core_session.c:1771 Session 3383 (sofia/default/900090111312715161@13.127.15.161) Ended
2022-09-28 11:22:42.440647 95.07% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/900090111312715161@13.127.15.161 [CS_DESTROY]
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:735 (sofia/default/900090111312715161@13.127.15.161) Running State Change CS_DESTROY (Cur 0 Tot 3383)
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/900090111312715161@13.127.15.161) State DESTROY
2022-09-28 11:22:42.440647 95.07% [DEBUG] mod_sofia.c:379 sofia/default/900090111312715161@13.127.15.161 SOFIA DESTROY
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:175 sofia/default/900090111312715161@13.127.15.161 Standard DESTROY
2022-09-28 11:22:42.440647 95.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/900090111312715161@13.127.15.161) State DESTROY going to sleep
2022-09-28 11:22:47.080658 94.60% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [123@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:22:47.100658 94.60% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:19.140650 76.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:19.300672 76.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:19.300672 76.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:19.480658 76.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:21.120669 76.37% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:21.160667 75.87% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [123@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:21.340650 75.87% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:21.360664 75.87% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [123@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:51.520648 82.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [123@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:51.540668 82.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [1911@13.127.15.161] from ip 103.240.35.46
2022-09-28 11:23:56.620658 81.03% [NOTICE] sofia_reg.c:459 Registering 8134791837
2022-09-28 11:23:56.900685 81.03% [ERR] sofia_reg.c:2677 8134791837 Failed Registration with status Forbidden [403]. failure #4
2022-09-28 11:23:57.620693 80.50% [WARNING] sofia_reg.c:516 8134791837 Failed Registration [403], setting retry to 120 seconds.
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-09-28 11:24:03.560650 74.87% [NOTICE] switch_channel.c:1123 New Channel sofia/default/1515121325@127.0.0.1:5060 [0229b1be-5386-4026-9dea-80e728cabde0]
2022-09-28 11:24:03.560650 74.87% [DEBUG] mod_sofia.c:5121 (sofia/default/1515121325@127.0.0.1:5060) State Change CS_NEW -> CS_INIT
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1515121325@127.0.0.1:5060) Running State Change CS_INIT (Cur 1 Tot 3384)
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1515121325@127.0.0.1:5060) State INIT
2022-09-28 11:24:03.560650 74.87% [DEBUG] mod_sofia.c:97 sofia/default/1515121325@127.0.0.1:5060 SOFIA INIT
2022-09-28 11:24:03.560650 74.87% [INFO] sofia_glue.c:1651 sofia/default/1515121325@127.0.0.1:5060 sending invite call-id: (null)
2022-09-28 11:24:03.560650 74.87% [DEBUG] sofia_glue.c:1654 sofia/default/1515121325@127.0.0.1:5060 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1664347185 1664347186 IN IP4 172.31.40.49
s=FreeSWITCH
c=IN IP4 172.31.40.49
t=0 0
m=audio 17058 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:40 sofia/default/1515121325@127.0.0.1:5060 Standard INIT
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:48 (sofia/default/1515121325@127.0.0.1:5060) State Change CS_INIT -> CS_ROUTING
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1515121325@127.0.0.1:5060) State INIT going to sleep
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1515121325@127.0.0.1:5060) Running State Change CS_ROUTING (Cur 1 Tot 3384)
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1515121325@127.0.0.1:5060) State ROUTING
2022-09-28 11:24:03.560650 74.87% [DEBUG] mod_sofia.c:158 sofia/default/1515121325@127.0.0.1:5060 SOFIA ROUTING
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_ivr_originate.c:67 (sofia/default/1515121325@127.0.0.1:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1515121325@127.0.0.1:5060) State ROUTING going to sleep
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1515121325@127.0.0.1:5060) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 3384)
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:659 (sofia/default/1515121325@127.0.0.1:5060) State CONSUME_MEDIA
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:659 (sofia/default/1515121325@127.0.0.1:5060) State CONSUME_MEDIA going to sleep
2022-09-28 11:24:03.560650 74.87% [DEBUG] sofia.c:7499 Channel sofia/default/1515121325@127.0.0.1:5060 entering state [calling][0]
2022-09-28 11:24:03.560650 74.87% [DEBUG] sofia.c:7499 Channel sofia/default/1515121325@127.0.0.1:5060 entering state [terminated][503]
2022-09-28 11:24:03.560650 74.87% [NOTICE] sofia.c:8738 Hangup sofia/default/1515121325@127.0.0.1:5060 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1515121325@127.0.0.1:5060) Running State Change CS_HANGUP (Cur 1 Tot 3384)
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1515121325@127.0.0.1:5060) Callstate Change DOWN -> HANGUP
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1515121325@127.0.0.1:5060) State HANGUP
2022-09-28 11:24:03.560650 74.87% [DEBUG] mod_sofia.c:468 Channel sofia/default/1515121325@127.0.0.1:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:59 sofia/default/1515121325@127.0.0.1:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1515121325@127.0.0.1:5060) State HANGUP going to sleep
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1515121325@127.0.0.1:5060) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1515121325@127.0.0.1:5060) Running State Change CS_REPORTING (Cur 1 Tot 3384)
2022-09-28 11:24:03.560650 74.87% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1515121325@127.0.0.1:5060) State REPORTING
2022-09-28 11:24:03.560650 74.87% [INFO] mod_json_cdr.c:271 Process [0229b1be-5386-4026-9dea-80e728cabde0.cdr.json]
2022-09-28 11:24:03.580658 74.87% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_state_machine.c:168 sofia/default/1515121325@127.0.0.1:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1515121325@127.0.0.1:5060) State REPORTING going to sleep
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1515121325@127.0.0.1:5060) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_session.c:1753 Session 3384 (sofia/default/1515121325@127.0.0.1:5060) Locked, Waiting on external entities
2022-09-28 11:24:04.160647 74.07% [NOTICE] switch_core_session.c:1771 Session 3384 (sofia/default/1515121325@127.0.0.1:5060) Ended
2022-09-28 11:24:04.160647 74.07% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/1515121325@127.0.0.1:5060 [CS_DESTROY]
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1515121325@127.0.0.1:5060) Running State Change CS_DESTROY (Cur 0 Tot 3384)
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1515121325@127.0.0.1:5060) State DESTROY
2022-09-28 11:24:04.160647 74.07% [DEBUG] mod_sofia.c:379 sofia/default/1515121325@127.0.0.1:5060 SOFIA DESTROY
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_state_machine.c:175 sofia/default/1515121325@127.0.0.1:5060 Standard DESTROY
2022-09-28 11:24:04.160647 74.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1515121325@127.0.0.1:5060) State DESTROY going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-09-28 11:24:05.600647 74.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/2536854752@127.0.0.1:5060 [df336261-d5ec-4a10-afbd-9815672f18d3]
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:5121 (sofia/default/2536854752@127.0.0.1:5060) State Change CS_NEW -> CS_INIT
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/2536854752@127.0.0.1:5060) Running State Change CS_INIT (Cur 1 Tot 3385)
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/2536854752@127.0.0.1:5060) State INIT
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:97 sofia/default/2536854752@127.0.0.1:5060 SOFIA INIT
2022-09-28 11:24:05.600647 74.03% [INFO] sofia_glue.c:1651 sofia/default/2536854752@127.0.0.1:5060 sending invite call-id: (null)
2022-09-28 11:24:05.600647 74.03% [DEBUG] sofia_glue.c:1654 sofia/default/2536854752@127.0.0.1:5060 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1664346827 1664346828 IN IP4 172.31.40.49
s=FreeSWITCH
c=IN IP4 172.31.40.49
t=0 0
m=audio 17418 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/2536854752@127.0.0.1:5060 Standard INIT
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/2536854752@127.0.0.1:5060) State Change CS_INIT -> CS_ROUTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/2536854752@127.0.0.1:5060) State INIT going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/2536854752@127.0.0.1:5060) Running State Change CS_ROUTING (Cur 1 Tot 3385)
2022-09-28 11:24:05.600647 74.03% [DEBUG] sofia.c:7499 Channel sofia/default/2536854752@127.0.0.1:5060 entering state [calling][0]
2022-09-28 11:24:05.600647 74.03% [DEBUG] sofia.c:7499 Channel sofia/default/2536854752@127.0.0.1:5060 entering state [terminated][503]
2022-09-28 11:24:05.600647 74.03% [NOTICE] sofia.c:8738 Hangup sofia/default/2536854752@127.0.0.1:5060 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/2536854752@127.0.0.1:5060) State ROUTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:158 sofia/default/2536854752@127.0.0.1:5060 SOFIA ROUTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/2536854752@127.0.0.1:5060) State ROUTING going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/2536854752@127.0.0.1:5060) Running State Change CS_HANGUP (Cur 1 Tot 3385)
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:844 (sofia/default/2536854752@127.0.0.1:5060) Callstate Change DOWN -> HANGUP
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/2536854752@127.0.0.1:5060) State HANGUP
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:468 Channel sofia/default/2536854752@127.0.0.1:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:59 sofia/default/2536854752@127.0.0.1:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/2536854752@127.0.0.1:5060) State HANGUP going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:616 (sofia/default/2536854752@127.0.0.1:5060) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/2536854752@127.0.0.1:5060) Running State Change CS_REPORTING (Cur 1 Tot 3385)
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/2536854752@127.0.0.1:5060) State REPORTING
2022-09-28 11:24:05.600647 74.03% [INFO] mod_json_cdr.c:271 Process [df336261-d5ec-4a10-afbd-9815672f18d3.cdr.json]
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:168 sofia/default/2536854752@127.0.0.1:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/2536854752@127.0.0.1:5060) State REPORTING going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:607 (sofia/default/2536854752@127.0.0.1:5060) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_session.c:1753 Session 3385 (sofia/default/2536854752@127.0.0.1:5060) Locked, Waiting on external entities
2022-09-28 11:24:05.600647 74.03% [NOTICE] switch_core_session.c:1771 Session 3385 (sofia/default/2536854752@127.0.0.1:5060) Ended
2022-09-28 11:24:05.600647 74.03% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/2536854752@127.0.0.1:5060 [CS_DESTROY]
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:735 (sofia/default/2536854752@127.0.0.1:5060) Running State Change CS_DESTROY (Cur 0 Tot 3385)
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/2536854752@127.0.0.1:5060) State DESTROY
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:379 sofia/default/2536854752@127.0.0.1:5060 SOFIA DESTROY
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:175 sofia/default/2536854752@127.0.0.1:5060 Standard DESTROY
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/2536854752@127.0.0.1:5060) State DESTROY going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-09-28 11:24:05.600647 74.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/1554856322@127.0.0.1:5060 [afa6c99c-ab20-4e4a-8580-b86d5f3f9cb9]
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:5121 (sofia/default/1554856322@127.0.0.1:5060) State Change CS_NEW -> CS_INIT
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1554856322@127.0.0.1:5060) Running State Change CS_INIT (Cur 1 Tot 3386)
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1554856322@127.0.0.1:5060) State INIT
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:97 sofia/default/1554856322@127.0.0.1:5060 SOFIA INIT
2022-09-28 11:24:05.600647 74.03% [INFO] sofia_glue.c:1651 sofia/default/1554856322@127.0.0.1:5060 sending invite call-id: (null)
2022-09-28 11:24:05.600647 74.03% [DEBUG] sofia_glue.c:1654 sofia/default/1554856322@127.0.0.1:5060 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1664346825 1664346826 IN IP4 172.31.40.49
s=FreeSWITCH
c=IN IP4 172.31.40.49
t=0 0
m=audio 17420 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/1554856322@127.0.0.1:5060 Standard INIT
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/1554856322@127.0.0.1:5060) State Change CS_INIT -> CS_ROUTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1554856322@127.0.0.1:5060) State INIT going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1554856322@127.0.0.1:5060) Running State Change CS_ROUTING (Cur 1 Tot 3386)
2022-09-28 11:24:05.600647 74.03% [DEBUG] sofia.c:7499 Channel sofia/default/1554856322@127.0.0.1:5060 entering state [calling][0]
2022-09-28 11:24:05.600647 74.03% [DEBUG] sofia.c:7499 Channel sofia/default/1554856322@127.0.0.1:5060 entering state [terminated][503]
2022-09-28 11:24:05.600647 74.03% [NOTICE] sofia.c:8738 Hangup sofia/default/1554856322@127.0.0.1:5060 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1554856322@127.0.0.1:5060) State ROUTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:158 sofia/default/1554856322@127.0.0.1:5060 SOFIA ROUTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1554856322@127.0.0.1:5060) State ROUTING going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1554856322@127.0.0.1:5060) Running State Change CS_HANGUP (Cur 1 Tot 3386)
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1554856322@127.0.0.1:5060) Callstate Change DOWN -> HANGUP
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1554856322@127.0.0.1:5060) State HANGUP
2022-09-28 11:24:05.600647 74.03% [DEBUG] mod_sofia.c:468 Channel sofia/default/1554856322@127.0.0.1:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:59 sofia/default/1554856322@127.0.0.1:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1554856322@127.0.0.1:5060) State HANGUP going to sleep
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1554856322@127.0.0.1:5060) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1554856322@127.0.0.1:5060) Running State Change CS_REPORTING (Cur 1 Tot 3386)
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1554856322@127.0.0.1:5060) State REPORTING
2022-09-28 11:24:05.600647 74.03% [INFO] mod_json_cdr.c:271 Process [afa6c99c-ab20-4e4a-8580-b86d5f3f9cb9.cdr.json]
2022-09-28 11:24:05.600647 74.03% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_state_machine.c:168 sofia/default/1554856322@127.0.0.1:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1554856322@127.0.0.1:5060) State REPORTING going to sleep
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1554856322@127.0.0.1:5060) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_session.c:1753 Session 3386 (sofia/default/1554856322@127.0.0.1:5060) Locked, Waiting on external entities
2022-09-28 11:24:05.620649 74.03% [NOTICE] switch_core_session.c:1771 Session 3386 (sofia/default/1554856322@127.0.0.1:5060) Ended
2022-09-28 11:24:05.620649 74.03% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/1554856322@127.0.0.1:5060 [CS_DESTROY]
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1554856322@127.0.0.1:5060) Running State Change CS_DESTROY (Cur 0 Tot 3386)
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1554856322@127.0.0.1:5060) State DESTROY
2022-09-28 11:24:05.620649 74.03% [DEBUG] mod_sofia.c:379 sofia/default/1554856322@127.0.0.1:5060 SOFIA DESTROY
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_state_machine.c:175 sofia/default/1554856322@127.0.0.1:5060 Standard DESTROY
2022-09-28 11:24:05.620649 74.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1554856322@127.0.0.1:5060) State DESTROY going to sleep
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-09-28 11:24:07.620648 72.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/1547964325@127.0.0.1:5060 [eeb03201-8baa-456c-8c23-5dbcff3457a4]
2022-09-28 11:24:07.620648 72.07% [DEBUG] mod_sofia.c:5121 (sofia/default/1547964325@127.0.0.1:5060) State Change CS_NEW -> CS_INIT
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1547964325@127.0.0.1:5060) Running State Change CS_INIT (Cur 1 Tot 3387)
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1547964325@127.0.0.1:5060) State INIT
2022-09-28 11:24:07.620648 72.07% [DEBUG] mod_sofia.c:97 sofia/default/1547964325@127.0.0.1:5060 SOFIA INIT
2022-09-28 11:24:07.620648 72.07% [INFO] sofia_glue.c:1651 sofia/default/1547964325@127.0.0.1:5060 sending invite call-id: (null)
2022-09-28 11:24:07.620648 72.07% [DEBUG] sofia_glue.c:1654 sofia/default/1547964325@127.0.0.1:5060 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1664341303 1664341304 IN IP4 172.31.40.49
s=FreeSWITCH
c=IN IP4 172.31.40.49
t=0 0
m=audio 22944 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/1547964325@127.0.0.1:5060 Standard INIT
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/1547964325@127.0.0.1:5060) State Change CS_INIT -> CS_ROUTING
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1547964325@127.0.0.1:5060) State INIT going to sleep
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1547964325@127.0.0.1:5060) Running State Change CS_ROUTING (Cur 1 Tot 3387)
2022-09-28 11:24:07.620648 72.07% [DEBUG] sofia.c:7499 Channel sofia/default/1547964325@127.0.0.1:5060 entering state [calling][0]
2022-09-28 11:24:07.620648 72.07% [DEBUG] sofia.c:7499 Channel sofia/default/1547964325@127.0.0.1:5060 entering state [terminated][503]
2022-09-28 11:24:07.620648 72.07% [NOTICE] sofia.c:8738 Hangup sofia/default/1547964325@127.0.0.1:5060 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1547964325@127.0.0.1:5060) State ROUTING
2022-09-28 11:24:07.620648 72.07% [DEBUG] mod_sofia.c:158 sofia/default/1547964325@127.0.0.1:5060 SOFIA ROUTING
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1547964325@127.0.0.1:5060) State ROUTING going to sleep
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1547964325@127.0.0.1:5060) Running State Change CS_HANGUP (Cur 1 Tot 3387)
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1547964325@127.0.0.1:5060) Callstate Change DOWN -> HANGUP
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1547964325@127.0.0.1:5060) State HANGUP
2022-09-28 11:24:07.620648 72.07% [DEBUG] mod_sofia.c:468 Channel sofia/default/1547964325@127.0.0.1:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:59 sofia/default/1547964325@127.0.0.1:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1547964325@127.0.0.1:5060) State HANGUP going to sleep
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1547964325@127.0.0.1:5060) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1547964325@127.0.0.1:5060) Running State Change CS_REPORTING (Cur 1 Tot 3387)
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1547964325@127.0.0.1:5060) State REPORTING
2022-09-28 11:24:07.620648 72.07% [INFO] mod_json_cdr.c:271 Process [eeb03201-8baa-456c-8c23-5dbcff3457a4.cdr.json]
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:07.620648 72.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-09-28 11:24:07.620648 72.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/1030303044@127.0.0.1:5060 [951ba294-ce81-4e4f-93bc-bf221f0ed6c5]
2022-09-28 11:24:07.620648 72.07% [DEBUG] mod_sofia.c:5121 (sofia/default/1030303044@127.0.0.1:5060) State Change CS_NEW -> CS_INIT
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1030303044@127.0.0.1:5060) Running State Change CS_INIT (Cur 2 Tot 3388)
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1030303044@127.0.0.1:5060) State INIT
2022-09-28 11:24:07.640719 72.07% [DEBUG] mod_sofia.c:97 sofia/default/1030303044@127.0.0.1:5060 SOFIA INIT
2022-09-28 11:24:07.640719 72.07% [INFO] sofia_glue.c:1651 sofia/default/1030303044@127.0.0.1:5060 sending invite call-id: (null)
2022-09-28 11:24:07.640719 72.07% [DEBUG] sofia_glue.c:1654 sofia/default/1030303044@127.0.0.1:5060 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1664345241 1664345242 IN IP4 172.31.40.49
s=FreeSWITCH
c=IN IP4 172.31.40.49
t=0 0
m=audio 19006 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/1030303044@127.0.0.1:5060 Standard INIT
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/1030303044@127.0.0.1:5060) State Change CS_INIT -> CS_ROUTING
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1030303044@127.0.0.1:5060) State INIT going to sleep
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1030303044@127.0.0.1:5060) Running State Change CS_ROUTING (Cur 2 Tot 3388)
2022-09-28 11:24:07.640719 72.07% [DEBUG] sofia.c:7499 Channel sofia/default/1030303044@127.0.0.1:5060 entering state [calling][0]
2022-09-28 11:24:07.640719 72.07% [DEBUG] sofia.c:7499 Channel sofia/default/1030303044@127.0.0.1:5060 entering state [terminated][503]
2022-09-28 11:24:07.640719 72.07% [NOTICE] sofia.c:8738 Hangup sofia/default/1030303044@127.0.0.1:5060 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1030303044@127.0.0.1:5060) State ROUTING
2022-09-28 11:24:07.640719 72.07% [DEBUG] mod_sofia.c:158 sofia/default/1030303044@127.0.0.1:5060 SOFIA ROUTING
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1030303044@127.0.0.1:5060) State ROUTING going to sleep
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1030303044@127.0.0.1:5060) Running State Change CS_HANGUP (Cur 2 Tot 3388)
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1030303044@127.0.0.1:5060) Callstate Change DOWN -> HANGUP
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1030303044@127.0.0.1:5060) State HANGUP
2022-09-28 11:24:07.640719 72.07% [DEBUG] mod_sofia.c:468 Channel sofia/default/1030303044@127.0.0.1:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:59 sofia/default/1030303044@127.0.0.1:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1030303044@127.0.0.1:5060) State HANGUP going to sleep
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1030303044@127.0.0.1:5060) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1030303044@127.0.0.1:5060) Running State Change CS_REPORTING (Cur 2 Tot 3388)
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1030303044@127.0.0.1:5060) State REPORTING
2022-09-28 11:24:07.640719 72.07% [INFO] mod_json_cdr.c:271 Process [951ba294-ce81-4e4f-93bc-bf221f0ed6c5.cdr.json]
2022-09-28 11:24:07.640719 72.07% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:168 sofia/default/1547964325@127.0.0.1:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1547964325@127.0.0.1:5060) State REPORTING going to sleep
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1547964325@127.0.0.1:5060) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_session.c:1753 Session 3387 (sofia/default/1547964325@127.0.0.1:5060) Locked, Waiting on external entities
2022-09-28 11:24:08.120649 72.07% [NOTICE] switch_core_session.c:1771 Session 3387 (sofia/default/1547964325@127.0.0.1:5060) Ended
2022-09-28 11:24:08.120649 72.07% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/1547964325@127.0.0.1:5060 [CS_DESTROY]
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1547964325@127.0.0.1:5060) Running State Change CS_DESTROY (Cur 1 Tot 3388)
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1547964325@127.0.0.1:5060) State DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] mod_sofia.c:379 sofia/default/1547964325@127.0.0.1:5060 SOFIA DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:175 sofia/default/1547964325@127.0.0.1:5060 Standard DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1547964325@127.0.0.1:5060) State DESTROY going to sleep
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:168 sofia/default/1030303044@127.0.0.1:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1030303044@127.0.0.1:5060) State REPORTING going to sleep
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1030303044@127.0.0.1:5060) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_session.c:1753 Session 3388 (sofia/default/1030303044@127.0.0.1:5060) Locked, Waiting on external entities
2022-09-28 11:24:08.120649 72.07% [NOTICE] switch_core_session.c:1771 Session 3388 (sofia/default/1030303044@127.0.0.1:5060) Ended
2022-09-28 11:24:08.120649 72.07% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/1030303044@127.0.0.1:5060 [CS_DESTROY]
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1030303044@127.0.0.1:5060) Running State Change CS_DESTROY (Cur 0 Tot 3388)
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1030303044@127.0.0.1:5060) State DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] mod_sofia.c:379 sofia/default/1030303044@127.0.0.1:5060 SOFIA DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:175 sofia/default/1030303044@127.0.0.1:5060 Standard DESTROY
2022-09-28 11:24:08.120649 72.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1030303044@127.0.0.1:5060) State DESTROY going to sleep
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-09-28 11:24:09.640658 70.93% [NOTICE] switch_channel.c:1123 New Channel sofia/default/1039999999@127.0.0.1:5060 [d5167806-ec44-45cd-a0a1-8c3cb46d0faf]
2022-09-28 11:24:09.640658 70.93% [DEBUG] mod_sofia.c:5121 (sofia/default/1039999999@127.0.0.1:5060) State Change CS_NEW -> CS_INIT
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1039999999@127.0.0.1:5060) Running State Change CS_INIT (Cur 1 Tot 3389)
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1039999999@127.0.0.1:5060) State INIT
2022-09-28 11:24:09.640658 70.93% [DEBUG] mod_sofia.c:97 sofia/default/1039999999@127.0.0.1:5060 SOFIA INIT
2022-09-28 11:24:09.640658 70.93% [INFO] sofia_glue.c:1651 sofia/default/1039999999@127.0.0.1:5060 sending invite call-id: (null)
2022-09-28 11:24:09.640658 70.93% [DEBUG] sofia_glue.c:1654 sofia/default/1039999999@127.0.0.1:5060 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1664339101 1664339102 IN IP4 172.31.40.49
s=FreeSWITCH
c=IN IP4 172.31.40.49
t=0 0
m=audio 25148 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/1039999999@127.0.0.1:5060 Standard INIT
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/1039999999@127.0.0.1:5060) State Change CS_INIT -> CS_ROUTING
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1039999999@127.0.0.1:5060) State INIT going to sleep
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1039999999@127.0.0.1:5060) Running State Change CS_ROUTING (Cur 1 Tot 3389)
2022-09-28 11:24:09.640658 70.93% [DEBUG] sofia.c:7499 Channel sofia/default/1039999999@127.0.0.1:5060 entering state [calling][0]
2022-09-28 11:24:09.640658 70.93% [DEBUG] sofia.c:7499 Channel sofia/default/1039999999@127.0.0.1:5060 entering state [terminated][503]
2022-09-28 11:24:09.640658 70.93% [NOTICE] sofia.c:8738 Hangup sofia/default/1039999999@127.0.0.1:5060 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1039999999@127.0.0.1:5060) State ROUTING
2022-09-28 11:24:09.640658 70.93% [DEBUG] mod_sofia.c:158 sofia/default/1039999999@127.0.0.1:5060 SOFIA ROUTING
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1039999999@127.0.0.1:5060) State ROUTING going to sleep
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1039999999@127.0.0.1:5060) Running State Change CS_HANGUP (Cur 1 Tot 3389)
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1039999999@127.0.0.1:5060) Callstate Change DOWN -> HANGUP
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1039999999@127.0.0.1:5060) State HANGUP
2022-09-28 11:24:09.640658 70.93% [DEBUG] mod_sofia.c:468 Channel sofia/default/1039999999@127.0.0.1:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:59 sofia/default/1039999999@127.0.0.1:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1039999999@127.0.0.1:5060) State HANGUP going to sleep
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1039999999@127.0.0.1:5060) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1039999999@127.0.0.1:5060) Running State Change CS_REPORTING (Cur 1 Tot 3389)
2022-09-28 11:24:09.640658 70.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1039999999@127.0.0.1:5060) State REPORTING
2022-09-28 11:24:09.640658 70.93% [INFO] mod_json_cdr.c:271 Process [d5167806-ec44-45cd-a0a1-8c3cb46d0faf.cdr.json]
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:168 sofia/default/1039999999@127.0.0.1:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1039999999@127.0.0.1:5060) State REPORTING going to sleep
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1039999999@127.0.0.1:5060) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_session.c:1753 Session 3389 (sofia/default/1039999999@127.0.0.1:5060) Locked, Waiting on external entities
2022-09-28 11:24:09.660640 70.93% [NOTICE] switch_core_session.c:1771 Session 3389 (sofia/default/1039999999@127.0.0.1:5060) Ended
2022-09-28 11:24:09.660640 70.93% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/1039999999@127.0.0.1:5060 [CS_DESTROY]
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1039999999@127.0.0.1:5060) Running State Change CS_DESTROY (Cur 0 Tot 3389)
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1039999999@127.0.0.1:5060) State DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] mod_sofia.c:379 sofia/default/1039999999@127.0.0.1:5060 SOFIA DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:175 sofia/default/1039999999@127.0.0.1:5060 Standard DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1039999999@127.0.0.1:5060) State DESTROY going to sleep
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-09-28 11:24:09.660640 70.93% [NOTICE] switch_channel.c:1123 New Channel sofia/default/1077777777@127.0.0.1:5060 [3f0c278e-d714-4727-9202-3b7bfa7fc250]
2022-09-28 11:24:09.660640 70.93% [DEBUG] mod_sofia.c:5121 (sofia/default/1077777777@127.0.0.1:5060) State Change CS_NEW -> CS_INIT
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1077777777@127.0.0.1:5060) Running State Change CS_INIT (Cur 1 Tot 3390)
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1077777777@127.0.0.1:5060) State INIT
2022-09-28 11:24:09.660640 70.93% [DEBUG] mod_sofia.c:97 sofia/default/1077777777@127.0.0.1:5060 SOFIA INIT
2022-09-28 11:24:09.660640 70.93% [INFO] sofia_glue.c:1651 sofia/default/1077777777@127.0.0.1:5060 sending invite call-id: (null)
2022-09-28 11:24:09.660640 70.93% [DEBUG] sofia_glue.c:1654 sofia/default/1077777777@127.0.0.1:5060 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1664338989 1664338990 IN IP4 172.31.40.49
s=FreeSWITCH
c=IN IP4 172.31.40.49
t=0 0
m=audio 25260 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/1077777777@127.0.0.1:5060 Standard INIT
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/1077777777@127.0.0.1:5060) State Change CS_INIT -> CS_ROUTING
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1077777777@127.0.0.1:5060) State INIT going to sleep
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1077777777@127.0.0.1:5060) Running State Change CS_ROUTING (Cur 1 Tot 3390)
2022-09-28 11:24:09.660640 70.93% [DEBUG] sofia.c:7499 Channel sofia/default/1077777777@127.0.0.1:5060 entering state [calling][0]
2022-09-28 11:24:09.660640 70.93% [DEBUG] sofia.c:7499 Channel sofia/default/1077777777@127.0.0.1:5060 entering state [terminated][503]
2022-09-28 11:24:09.660640 70.93% [NOTICE] sofia.c:8738 Hangup sofia/default/1077777777@127.0.0.1:5060 [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1077777777@127.0.0.1:5060) State ROUTING
2022-09-28 11:24:09.660640 70.93% [DEBUG] mod_sofia.c:158 sofia/default/1077777777@127.0.0.1:5060 SOFIA ROUTING
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1077777777@127.0.0.1:5060) State ROUTING going to sleep
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1077777777@127.0.0.1:5060) Running State Change CS_HANGUP (Cur 1 Tot 3390)
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1077777777@127.0.0.1:5060) Callstate Change DOWN -> HANGUP
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1077777777@127.0.0.1:5060) State HANGUP
2022-09-28 11:24:09.660640 70.93% [DEBUG] mod_sofia.c:468 Channel sofia/default/1077777777@127.0.0.1:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:59 sofia/default/1077777777@127.0.0.1:5060 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1077777777@127.0.0.1:5060) State HANGUP going to sleep
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1077777777@127.0.0.1:5060) State Change CS_HANGUP -> CS_REPORTING
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1077777777@127.0.0.1:5060) Running State Change CS_REPORTING (Cur 1 Tot 3390)
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1077777777@127.0.0.1:5060) State REPORTING
2022-09-28 11:24:09.660640 70.93% [INFO] mod_json_cdr.c:271 Process [3f0c278e-d714-4727-9202-3b7bfa7fc250.cdr.json]
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:168 sofia/default/1077777777@127.0.0.1:5060 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1077777777@127.0.0.1:5060) State REPORTING going to sleep
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1077777777@127.0.0.1:5060) State Change CS_REPORTING -> CS_DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_session.c:1753 Session 3390 (sofia/default/1077777777@127.0.0.1:5060) Locked, Waiting on external entities
2022-09-28 11:24:09.660640 70.93% [NOTICE] switch_core_session.c:1771 Session 3390 (sofia/default/1077777777@127.0.0.1:5060) Ended
2022-09-28 11:24:09.660640 70.93% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/1077777777@127.0.0.1:5060 [CS_DESTROY]
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1077777777@127.0.0.1:5060) Running State Change CS_DESTROY (Cur 0 Tot 3390)
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1077777777@127.0.0.1:5060) State DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] mod_sofia.c:379 sofia/default/1077777777@127.0.0.1:5060 SOFIA DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:175 sofia/default/1077777777@127.0.0.1:5060 Standard DESTROY
2022-09-28 11:24:09.660640 70.93% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1077777777@127.0.0.1:5060) State DESTROY going to sleep
2022-09-28 11:24:25.580677 75.23% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [4082586355@13.127.15.161] from ip 103.240.35.46
freeswitch@ip-172-31-40-49> /exit

You have new mail in /var/mail/root