freeswitch@BetaQA> 
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-10-10 11:24:03.743531 28.90% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [9a26ab61-7191-472d-bb43-b3b615719f12]
2022-10-10 11:24:03.743531 28.90% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 1 Tot 22250)
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
2022-10-10 11:24:03.743531 28.90% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
2022-10-10 11:24:03.743531 28.90% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
2022-10-10 11:24:03.743531 28.90% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1665383577 1665383578 IN IP4 142.132.184.134
s=FreeSWITCH
c=IN IP4 142.132.184.134
t=0 0
m=audio 17466 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-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 1 Tot 22250)
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
2022-10-10 11:24:03.743531 28.90% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 22250)
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
2022-10-10 11:24:03.743531 28.90% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
2022-10-10 11:24:03.743531 28.90% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
2022-10-10 11:24:08.423539 33.17% [NOTICE] sofia_reg.c:459 Registering 7986208696
2022-10-10 11:24:08.683565 33.17% [ERR] sofia_reg.c:2677 7986208696 Failed Registration with status Forbidden [403]. failure #5
2022-10-10 11:24:09.423554 34.07% [WARNING] sofia_reg.c:516 7986208696 Failed Registration [403], setting retry to 150 seconds.
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-10-10 11:24:10.443542 35.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [8e7d0da0-a490-47fb-943a-27e64199136b]
2022-10-10 11:24:10.443542 35.03% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 2 Tot 22251)
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
2022-10-10 11:24:10.443542 35.03% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
2022-10-10 11:24:10.443542 35.03% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
2022-10-10 11:24:10.443542 35.03% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1665376434 1665376435 IN IP4 142.132.184.134
s=FreeSWITCH
c=IN IP4 142.132.184.134
t=0 0
m=audio 24616 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-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 2 Tot 22251)
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
2022-10-10 11:24:10.443542 35.03% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 22251)
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
2022-10-10 11:24:10.443542 35.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
2022-10-10 11:24:10.443542 35.03% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
2022-10-10 11:24:11.403532 36.00% [ERR] sofia_reg.c:2677 6803528347 Failed Registration with status Request Timeout [408]. failure #4
2022-10-10 11:24:11.403532 36.00% [ERR] sofia_reg.c:2677 9814047798 Failed Registration with status Request Timeout [408]. failure #4
2022-10-10 11:24:11.423527 36.00% [WARNING] sofia_reg.c:516 6803528347 Failed Registration [408], setting retry to 120 seconds.
2022-10-10 11:24:11.423527 36.00% [WARNING] sofia_reg.c:516 9814047798 Failed Registration [408], setting retry to 120 seconds.
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-10-10 11:24:12.143527 37.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [79c2c4d2-92ef-4d38-9904-89727ac551d3]
2022-10-10 11:24:12.143527 37.07% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 3 Tot 22252)
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
2022-10-10 11:24:12.143527 37.07% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
2022-10-10 11:24:12.143527 37.07% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
2022-10-10 11:24:12.143527 37.07% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1665375516 1665375517 IN IP4 142.132.184.134
s=FreeSWITCH
c=IN IP4 142.132.184.134
t=0 0
m=audio 25536 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-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 3 Tot 22252)
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
2022-10-10 11:24:12.143527 37.07% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 22252)
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
2022-10-10 11:24:12.143527 37.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
2022-10-10 11:24:12.143527 37.07% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-10-10 11:24:13.823550 38.10% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [4ff12a14-ca02-4472-ae06-c069d4defc20]
2022-10-10 11:24:13.823550 38.10% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 4 Tot 22253)
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
2022-10-10 11:24:13.823550 38.10% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
2022-10-10 11:24:13.823550 38.10% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
2022-10-10 11:24:13.823550 38.10% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1665378547 1665378548 IN IP4 142.132.184.134
s=FreeSWITCH
c=IN IP4 142.132.184.134
t=0 0
m=audio 22506 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-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 4 Tot 22253)
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
2022-10-10 11:24:13.823550 38.10% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
2022-10-10 11:24:13.823550 38.10% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 22253)
2022-10-10 11:24:13.843541 38.10% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
2022-10-10 11:24:13.843541 38.10% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-10-10 11:24:15.523533 40.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [e1839fcd-f9ad-483b-bee1-33af86bc0726]
2022-10-10 11:24:15.523533 40.07% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 5 Tot 22254)
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
2022-10-10 11:24:15.523533 40.07% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
2022-10-10 11:24:15.523533 40.07% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
2022-10-10 11:24:15.523533 40.07% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1665381865 1665381866 IN IP4 142.132.184.134
s=FreeSWITCH
c=IN IP4 142.132.184.134
t=0 0
m=audio 19190 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-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 5 Tot 22254)
2022-10-10 11:24:15.523533 40.07% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
2022-10-10 11:24:15.523533 40.07% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 22254)
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
2022-10-10 11:24:15.523533 40.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-10-10 11:24:17.203531 42.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [87b19504-6457-4e07-a9e9-51c8f8c797b6]
2022-10-10 11:24:17.203531 42.03% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 6 Tot 22255)
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
2022-10-10 11:24:17.203531 42.03% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
2022-10-10 11:24:17.203531 42.03% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
2022-10-10 11:24:17.203531 42.03% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1665375815 1665375816 IN IP4 142.132.184.134
s=FreeSWITCH
c=IN IP4 142.132.184.134
t=0 0
m=audio 25242 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-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 6 Tot 22255)
2022-10-10 11:24:17.203531 42.03% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
2022-10-10 11:24:17.203531 42.03% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 22255)
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
2022-10-10 11:24:17.203531 42.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-10-10 11:24:18.903526 44.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/8485860527@142.132.184.134:5076 [73d15986-8d29-4c90-b63d-700de4b02a26]
2022-10-10 11:24:18.903526 44.07% [DEBUG] mod_sofia.c:5121 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_NEW -> CS_INIT
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_INIT (Cur 7 Tot 22256)
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT
2022-10-10 11:24:18.903526 44.07% [DEBUG] mod_sofia.c:97 sofia/default/8485860527@142.132.184.134:5076 SOFIA INIT
2022-10-10 11:24:18.903526 44.07% [INFO] sofia_glue.c:1651 sofia/default/8485860527@142.132.184.134:5076 sending invite call-id: (null)
2022-10-10 11:24:18.903526 44.07% [DEBUG] sofia_glue.c:1654 sofia/default/8485860527@142.132.184.134:5076 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1665373912 1665373913 IN IP4 142.132.184.134
s=FreeSWITCH
c=IN IP4 142.132.184.134
t=0 0
m=audio 27146 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-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/8485860527@142.132.184.134:5076 Standard INIT
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_INIT -> CS_ROUTING
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/8485860527@142.132.184.134:5076) State INIT going to sleep
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_ROUTING (Cur 7 Tot 22256)
2022-10-10 11:24:18.903526 44.07% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [calling][0]
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING
2022-10-10 11:24:18.903526 44.07% [DEBUG] mod_sofia.c:158 sofia/default/8485860527@142.132.184.134:5076 SOFIA ROUTING
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/8485860527@142.132.184.134:5076) State ROUTING going to sleep
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_CONSUME_MEDIA (Cur 7 Tot 22256)
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA
2022-10-10 11:24:18.903526 44.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/8485860527@142.132.184.134:5076) State CONSUME_MEDIA going to sleep
2022-10-10 11:24:35.743535 54.50% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
2022-10-10 11:24:35.743535 54.50% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 7 Tot 22256)
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
2022-10-10 11:24:35.743535 54.50% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 7 Tot 22256)
2022-10-10 11:24:35.743535 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
2022-10-10 11:24:35.743535 54.50% [INFO] mod_json_cdr.c:271 Process [9a26ab61-7191-472d-bb43-b3b615719f12.cdr.json]
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_session.c:1753 Session 22250 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
2022-10-10 11:24:35.763537 54.50% [NOTICE] switch_core_session.c:1771 Session 22250 (sofia/default/8485860527@142.132.184.134:5076) Ended
2022-10-10 11:24:35.763537 54.50% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 6 Tot 22256)
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
2022-10-10 11:24:35.763537 54.50% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
2022-10-10 11:24:35.763537 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
2022-10-10 11:24:42.443531 54.63% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
2022-10-10 11:24:42.443531 54.63% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 6 Tot 22256)
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
2022-10-10 11:24:42.443531 54.63% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 6 Tot 22256)
2022-10-10 11:24:42.443531 54.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
2022-10-10 11:24:42.443531 54.63% [INFO] mod_json_cdr.c:271 Process [8e7d0da0-a490-47fb-943a-27e64199136b.cdr.json]
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_session.c:1753 Session 22251 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:42.463532 54.63% [NOTICE] switch_core_session.c:1771 Session 22251 (sofia/default/8485860527@142.132.184.134:5076) Ended
2022-10-10 11:24:42.463532 54.63% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 5 Tot 22256)
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
2022-10-10 11:24:42.463532 54.63% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
2022-10-10 11:24:42.463532 54.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
2022-10-10 11:24:43.143535 54.57% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [900400@astppqa605.astppbilling.org] from ip 103.240.35.46
2022-10-10 11:24:44.143532 54.53% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
2022-10-10 11:24:44.143532 54.53% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 5 Tot 22256)
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
2022-10-10 11:24:44.143532 54.53% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 5 Tot 22256)
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
2022-10-10 11:24:44.143532 54.53% [INFO] mod_json_cdr.c:271 Process [79c2c4d2-92ef-4d38-9904-89727ac551d3.cdr.json]
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_session.c:1753 Session 22252 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
2022-10-10 11:24:44.143532 54.53% [NOTICE] switch_core_session.c:1771 Session 22252 (sofia/default/8485860527@142.132.184.134:5076) Ended
2022-10-10 11:24:44.143532 54.53% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 4 Tot 22256)
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
2022-10-10 11:24:44.143532 54.53% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
2022-10-10 11:24:44.143532 54.53% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
2022-10-10 11:24:45.843532 54.50% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
2022-10-10 11:24:45.843532 54.50% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 4 Tot 22256)
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
2022-10-10 11:24:45.843532 54.50% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 4 Tot 22256)
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
2022-10-10 11:24:45.843532 54.50% [INFO] mod_json_cdr.c:271 Process [4ff12a14-ca02-4472-ae06-c069d4defc20.cdr.json]
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_session.c:1753 Session 22253 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:45.843532 54.50% [NOTICE] switch_core_session.c:1771 Session 22253 (sofia/default/8485860527@142.132.184.134:5076) Ended
2022-10-10 11:24:45.843532 54.50% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 3 Tot 22256)
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
2022-10-10 11:24:45.843532 54.50% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
2022-10-10 11:24:45.843532 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
2022-10-10 11:24:47.523547 54.50% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
2022-10-10 11:24:47.523547 54.50% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 3 Tot 22256)
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
2022-10-10 11:24:47.523547 54.50% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 3 Tot 22256)
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
2022-10-10 11:24:47.523547 54.50% [INFO] mod_json_cdr.c:271 Process [e1839fcd-f9ad-483b-bee1-33af86bc0726.cdr.json]
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
2022-10-10 11:24:47.523547 54.50% [DEBUG] switch_core_session.c:1753 Session 22254 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:47.543533 54.50% [NOTICE] switch_core_session.c:1771 Session 22254 (sofia/default/8485860527@142.132.184.134:5076) Ended
2022-10-10 11:24:47.543533 54.50% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 2 Tot 22256)
2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
2022-10-10 11:24:47.543533 54.50% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
2022-10-10 11:24:47.543533 54.50% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
2022-10-10 11:24:49.203534 54.40% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
2022-10-10 11:24:49.203534 54.40% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 2 Tot 22256)
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
2022-10-10 11:24:49.203534 54.40% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 2 Tot 22256)
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
2022-10-10 11:24:49.203534 54.40% [INFO] mod_json_cdr.c:271 Process [87b19504-6457-4e07-a9e9-51c8f8c797b6.cdr.json]
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
2022-10-10 11:24:49.203534 54.40% [DEBUG] switch_core_session.c:1753 Session 22255 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:49.223524 54.40% [NOTICE] switch_core_session.c:1771 Session 22255 (sofia/default/8485860527@142.132.184.134:5076) Ended
2022-10-10 11:24:49.223524 54.40% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 1 Tot 22256)
2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
2022-10-10 11:24:49.223524 54.40% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
2022-10-10 11:24:49.223524 54.40% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
2022-10-10 11:24:50.903539 54.47% [DEBUG] sofia.c:7499 Channel sofia/default/8485860527@142.132.184.134:5076 entering state [terminated][408]
2022-10-10 11:24:50.903539 54.47% [NOTICE] sofia.c:8738 Hangup sofia/default/8485860527@142.132.184.134:5076 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_HANGUP (Cur 1 Tot 22256)
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:844 (sofia/default/8485860527@142.132.184.134:5076) Callstate Change DOWN -> HANGUP
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP
2022-10-10 11:24:50.903539 54.47% [DEBUG] mod_sofia.c:468 Channel sofia/default/8485860527@142.132.184.134:5076 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:59 sofia/default/8485860527@142.132.184.134:5076 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/8485860527@142.132.184.134:5076) State HANGUP going to sleep
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:616 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_HANGUP -> CS_REPORTING
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_REPORTING (Cur 1 Tot 22256)
2022-10-10 11:24:50.903539 54.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING
2022-10-10 11:24:50.923549 54.47% [INFO] mod_json_cdr.c:271 Process [73d15986-8d29-4c90-b63d-700de4b02a26.cdr.json]
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:168 sofia/default/8485860527@142.132.184.134:5076 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/8485860527@142.132.184.134:5076) State REPORTING going to sleep
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:607 (sofia/default/8485860527@142.132.184.134:5076) State Change CS_REPORTING -> CS_DESTROY
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_session.c:1753 Session 22256 (sofia/default/8485860527@142.132.184.134:5076) Locked, Waiting on external entities
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-10-10 11:24:50.923549 54.47% [NOTICE] switch_core_session.c:1771 Session 22256 (sofia/default/8485860527@142.132.184.134:5076) Ended
2022-10-10 11:24:50.923549 54.47% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/8485860527@142.132.184.134:5076 [CS_DESTROY]
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:735 (sofia/default/8485860527@142.132.184.134:5076) Running State Change CS_DESTROY (Cur 0 Tot 22256)
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY
2022-10-10 11:24:50.923549 54.47% [DEBUG] mod_sofia.c:379 sofia/default/8485860527@142.132.184.134:5076 SOFIA DESTROY
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:175 sofia/default/8485860527@142.132.184.134:5076 Standard DESTROY
2022-10-10 11:24:50.923549 54.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/8485860527@142.132.184.134:5076) State DESTROY going to sleep
2022-10-10 11:24:55.803535 55.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [4727985745@astppqa601.astppbilling.org] from ip 103.240.35.46