2024-07-31 12:30:49.467969 97.70% [NOTICE] switch_channel.c:1123 New Channel sofia/external/bbbuser@44.222.41.176:5060 [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:581 (sofia/external/bbbuser@44.222.41.176:5060) Running State Change CS_NEW (Cur 2 Tot 19)
2024-07-31 12:30:49.467969 97.70% [INFO] sofia.c:10453 sofia/external/bbbuser@44.222.41.176:5060 receiving invite from 103.254.35.50:41041 version: 1.10.9-release  64bit call-id: zedD05_CBVtzC7nwYwfT9A..
2024-07-31 12:30:49.467969 97.70% [DEBUG] sofia.c:7487 Channel sofia/external/bbbuser@44.222.41.176:5060 entering state [received][100]
2024-07-31 12:30:49.467969 97.70% [DEBUG] sofia.c:7497 Remote SDP:
v=0
o=Z 0 32010277 IN IP4 103.254.35.50
s=Z
c=IN IP4 103.254.35.50
t=0 0
m=audio 51941 RTP/AVP 106 9 98 101 0 8 3
a=rtpmap:106 opus/48000/2
a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1
a=rtpmap:98 telephone-event/48000
a=fmtp:98 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp-mux

2024-07-31 12:30:49.467969 97.70% [DEBUG] sofia.c:7900 (sofia/external/bbbuser@44.222.41.176:5060) State Change CS_NEW -> CS_INIT
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:600 (sofia/external/bbbuser@44.222.41.176:5060) State NEW
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:581 (sofia/external/bbbuser@44.222.41.176:5060) Running State Change CS_INIT (Cur 2 Tot 19)
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:624 (sofia/external/bbbuser@44.222.41.176:5060) State INIT
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:97 sofia/external/bbbuser@44.222.41.176:5060 SOFIA INIT
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:40 sofia/external/bbbuser@44.222.41.176:5060 Standard INIT
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:48 (sofia/external/bbbuser@44.222.41.176:5060) State Change CS_INIT -> CS_ROUTING
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:624 (sofia/external/bbbuser@44.222.41.176:5060) State INIT going to sleep
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:581 (sofia/external/bbbuser@44.222.41.176:5060) Running State Change CS_ROUTING (Cur 2 Tot 19)
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_channel.c:2380 (sofia/external/bbbuser@44.222.41.176:5060) Callstate Change DOWN -> RINGING
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:640 (sofia/external/bbbuser@44.222.41.176:5060) State ROUTING
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:158 sofia/external/bbbuser@44.222.41.176:5060 SOFIA ROUTING
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:230 sofia/external/bbbuser@44.222.41.176:5060 Standard ROUTING
2024-07-31 12:30:49.467969 97.70% [INFO] mod_dialplan_xml.c:639 Processing bbbuser <bbbuser>->5612755500 in context public
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->unloop] continue=false
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->outside_call] continue=true
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Absolute Condition [outside_call]
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action set(outside_call=true) 
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->bbb_dialin authorised and arrived from other server] continue=false
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Regex (FAIL) [bbb_dialin authorised and arrived from other server] destination_number(5612755500) =~ /^\*321(.*)$/ break=on-false
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->bbb_dialin auth checking] continue=false
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Regex (PASS) [bbb_dialin auth checking] destination_number(5612755500) =~ /^(\+1|\+91)?(\d{10,12})$/ break=on-false
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action info() 
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action log(INFO bbb_dialin checking for Auth) 
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action lua(/opt/freeswitch/scripts/bbb_conference_auth.lua 5612755500 ${sip_from_host}) 
Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action transfer(${pin} XML server_check) 
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:281 (sofia/external/bbbuser@44.222.41.176:5060) State Change CS_ROUTING -> CS_EXECUTE
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:640 (sofia/external/bbbuser@44.222.41.176:5060) State ROUTING going to sleep
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:581 (sofia/external/bbbuser@44.222.41.176:5060) Running State Change CS_EXECUTE (Cur 2 Tot 19)
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:647 (sofia/external/bbbuser@44.222.41.176:5060) State EXECUTE
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:213 sofia/external/bbbuser@44.222.41.176:5060 SOFIA EXECUTE
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_state_machine.c:323 sofia/external/bbbuser@44.222.41.176:5060 Standard EXECUTE
EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 set(outside_call=true)
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_dptools.c:1673 SET sofia/external/bbbuser@44.222.41.176:5060 [outside_call]=[true]
EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 export(RFC2822_DATE=Wed, 31 Jul 2024 12:30:49 +0000)
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 31 Jul 2024 12:30:49 +0000]
EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 info()
2024-07-31 12:30:49.467969 97.70% [INFO] mod_dptools.c:1886 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-Call-State: [RINGING]
Channel-State-Number: [4]
Channel-Name: [sofia/external/bbbuser@44.222.41.176:5060]
Unique-ID: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Call-UUID: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
Answer-State: [ringing]
Caller-Direction: [inbound]
Caller-Logical-Direction: [inbound]
Caller-Username: [bbbuser]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [bbbuser]
Caller-Caller-ID-Number: [bbbuser]
Caller-Orig-Caller-ID-Name: [bbbuser]
Caller-Orig-Caller-ID-Number: [bbbuser]
Caller-Network-Addr: [103.254.35.50]
Caller-ANI: [bbbuser]
Caller-Destination-Number: [5612755500]
Caller-Unique-ID: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
Caller-Source: [mod_sofia]
Caller-Context: [public]
Caller-Channel-Name: [sofia/external/bbbuser@44.222.41.176:5060]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1722429049467969]
Caller-Channel-Created-Time: [1722429049467969]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Channel-Resurrect-Time: [0]
Caller-Channel-Bridged-Time: [0]
Caller-Channel-Last-Hold: [0]
Caller-Channel-Hold-Accum: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
variable_session_id: [19]
variable_sip_from_params: [transport=TCP]
variable_sip_from_user: [bbbuser]
variable_sip_from_port: [5060]
variable_sip_from_uri: [bbbuser@44.222.41.176:5060]
variable_sip_from_host: [44.222.41.176]
variable_video_media_flow: [disabled]
variable_audio_media_flow: [disabled]
variable_text_media_flow: [disabled]
variable_channel_name: [sofia/external/bbbuser@44.222.41.176:5060]
variable_sip_call_id: [zedD05_CBVtzC7nwYwfT9A..]
variable_sip_local_network_addr: [44.222.41.176]
variable_sip_network_ip: [103.254.35.50]
variable_sip_network_port: [41041]
variable_sip_invite_stamp: [1722429049467969]
variable_sip_received_ip: [103.254.35.50]
variable_sip_received_port: [41041]
variable_sip_via_protocol: [tcp]
variable_sip_from_user_stripped: [bbbuser]
variable_sip_from_tag: [cc199b10]
variable_sofia_profile_name: [external]
variable_sofia_profile_url: [sip:mod_sofia@44.222.41.176:5060]
variable_recovery_profile_name: [external]
variable_sip_full_via: [SIP/2.0/TCP 10.212.135.50:56027;branch=z9hG4bK-524287-1---b5f9082309d929c9;rport=41041;received=103.254.35.50]
variable_sip_recover_via: [SIP/2.0/TCP 10.212.135.50:56027;branch=z9hG4bK-524287-1---b5f9082309d929c9;rport=41041;received=103.254.35.50]
variable_sip_full_from: [<sip:bbbuser@44.222.41.176:5060;transport=TCP>;tag=cc199b10]
variable_sip_full_to: [<sip:5612755500@44.222.41.176:5060>]
variable_sip_allow: [INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE]
variable_sip_req_params: [transport=TCP]
variable_sip_req_user: [5612755500]
variable_sip_req_port: [5060]
variable_sip_req_uri: [5612755500@44.222.41.176:5060]
variable_sip_req_host: [44.222.41.176]
variable_sip_to_user: [5612755500]
variable_sip_to_port: [5060]
variable_sip_to_uri: [5612755500@44.222.41.176:5060]
variable_sip_to_host: [44.222.41.176]
variable_sip_contact_params: [transport=TCP]
variable_sip_contact_user: [bbbuser]
variable_sip_contact_port: [41041]
variable_sip_contact_uri: [bbbuser@103.254.35.50:41041]
variable_sip_contact_host: [103.254.35.50]
variable_rtp_use_codec_string: [OPUS,speex@16000h@20i,speex@8000h@20i,G722,PCMU,PCMA]
variable_sip_user_agent: [Z 5.6.2 v2.10.20.2]
variable_sip_via_host: [10.212.135.50]
variable_sip_via_port: [56027]
variable_sip_via_rport: [41041]
variable_max_forwards: [70]
variable_switch_r_sdp: [v=0
o=Z 0 32010277 IN IP4 103.254.35.50
s=Z
c=IN IP4 103.254.35.50
t=0 0
m=audio 51941 RTP/AVP 106 9 98 101 0 8 3
a=rtpmap:106 opus/48000/2
a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1
a=rtpmap:98 telephone-event/48000
a=fmtp:98 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp-mux
]
variable_ep_codec_string: [mod_opus.opus@48000h@20i@2c,mod_spandsp.G722@8000h@20i@64000b,CORE_PCM_MODULE.PCMU@8000h@20i@64000b,CORE_PCM_MODULE.PCMA@8000h@20i@64000b]
variable_endpoint_disposition: [DELAYED NEGOTIATION]
variable_DP_MATCH: [5612755500]
variable_call_uuid: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
variable_outside_call: [true]
variable_RFC2822_DATE: [Wed, 31 Jul 2024 12:30:49 +0000]
variable_export_vars: [RFC2822_DATE]
variable_current_application: [info]


EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 log(INFO bbb_dialin checking for Auth)
2024-07-31 12:30:49.467969 97.70% [INFO] mod_dptools.c:1867 bbb_dialin checking for Auth
EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 lua(/opt/freeswitch/scripts/bbb_conference_auth.lua 5612755500 44.222.41.176)
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [opus:106:48000:20:0:1]/[SPEEX:99:16000:20:42200:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [opus:106:48000:20:0:1]/[SPEEX:99:8000:20:24600:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [opus:106:48000:20:0:1]/[G722:9:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [G722:9:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [G722:9:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5451 Set telephone-event payload to 98@48000
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:16000:20:42200:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[SPEEX:99:8000:20:24600:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [GSM:3:8000:20:13200:1]/[SPEEX:99:16000:20:42200:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [GSM:3:8000:20:13200:1]/[SPEEX:99:8000:20:24600:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5535 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_opus.c:614 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [64000bps]
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_opus.c:630 Opus encoder: set audio bandwidth to [FULLBAND] based on maxplaybackrate value found in SDP or local config [48000Hz]
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_opus.c:614 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [64000bps]
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_opus.c:630 Opus encoder: set audio bandwidth to [FULLBAND] based on maxplaybackrate value found in SDP or local config [48000Hz]
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:3750 Set Codec sofia/external/bbbuser@44.222.41.176:5060 opus/48000 20 ms 960 samples 0 bits 1 channels
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_codec.c:111 sofia/external/bbbuser@44.222.41.176:5060 Original read codec set to opus:116
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5800 Set telephone-event payload to 98@48000
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5858 sofia/external/bbbuser@44.222.41.176:5060 Set 2833 dtmf send payload to 98 recv payload to 98
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/external/bbbuser@44.222.41.176:5060] 172.31.27.212 port 18580 -> 103.254.35.50 port 51941 codec: 106 ms: 20
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_rtp.c:4389 Starting timer [soft] 960 bytes per 20ms
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:8879 Activating RTCP PORT 51941
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_rtp.c:4720 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 51941
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:8971 sofia/external/bbbuser@44.222.41.176:5060 Set 2833 dtmf send payload to 98
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:8978 sofia/external/bbbuser@44.222.41.176:5060 Set 2833 dtmf receive payload to 98
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:9001 sofia/external/bbbuser@44.222.41.176:5060 Set rtp dtmf delay to 40
2024-07-31 12:30:49.467969 97.70% [NOTICE] sofia_media.c:90 Pre-Answer sofia/external/bbbuser@44.222.41.176:5060!
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_channel.c:3566 (sofia/external/bbbuser@44.222.41.176:5060) Callstate Change RINGING -> EARLY
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/external/bbbuser@44.222.41.176:5060.
2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:913 Local SDP sofia/external/bbbuser@44.222.41.176:5060:
v=0
o=FreeSWITCH 1722410469 1722410470 IN IP4 44.222.41.176
s=FreeSWITCH
c=IN IP4 44.222.41.176
t=0 0
m=audio 18580 RTP/AVP 106 98
a=rtpmap:106 opus/48000/2
a=fmtp:106 useinbandfec=1; maxaveragebitrate=64000; maxplaybackrate=48000; sprop-maxcapturerate=48000; minptime=20
a=rtpmap:98 telephone-event/48000
a=fmtp:98 0-15
a=ptime:20
a=sendrecv
a=rtcp-mux
a=rtcp:18580 IN IP4 44.222.41.176

2024-07-31 12:30:49.467969 97.70% [NOTICE] switch_cpp.cpp:703 Channel [sofia/external/bbbuser@44.222.41.176:5060] has been answered
2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_channel.c:3893 (sofia/external/bbbuser@44.222.41.176:5060) Callstate Change EARLY -> ACTIVE
2024-07-31 12:30:49.467969 97.70% [DEBUG] sofia.c:7487 Channel sofia/external/bbbuser@44.222.41.176:5060 entering state [completed][200]
2024-07-31 12:30:49.467969 97.70% [NOTICE] switch_cpp.cpp:1465 tenant id query = {"did_status" : "1", "did_number" : "5612755500"}
2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 tenant id query result = 196
2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 tenant id query result = 153
2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 ACL CHECK STR : acl 44.222.41.176 196
2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 Not allowed to Enter rejected by acl
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:751 Hangup sofia/external/bbbuser@44.222.41.176:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_cpp.cpp:1209 sofia/external/bbbuser@44.222.41.176:5060 destroy/unlink session from object
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_session.c:2973 sofia/external/bbbuser@44.222.41.176:5060 skip receive message [PHONE_EVENT] (channel is hungup already)
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:647 (sofia/external/bbbuser@44.222.41.176:5060) State EXECUTE going to sleep
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:581 (sofia/external/bbbuser@44.222.41.176:5060) Running State Change CS_HANGUP (Cur 2 Tot 19)
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:844 (sofia/external/bbbuser@44.222.41.176:5060) Callstate Change ACTIVE -> HANGUP
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:846 (sofia/external/bbbuser@44.222.41.176:5060) State HANGUP
2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_sofia.c:468 Channel sofia/external/bbbuser@44.222.41.176:5060 hanging up, cause: NORMAL_CLEARING
2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/external/bbbuser@44.222.41.176:5060
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:59 sofia/external/bbbuser@44.222.41.176:5060 Standard HANGUP, cause: NORMAL_CLEARING
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:846 (sofia/external/bbbuser@44.222.41.176:5060) State HANGUP going to sleep
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:616 (sofia/external/bbbuser@44.222.41.176:5060) State Change CS_HANGUP -> CS_REPORTING
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:581 (sofia/external/bbbuser@44.222.41.176:5060) Running State Change CS_REPORTING (Cur 2 Tot 19)
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:932 (sofia/external/bbbuser@44.222.41.176:5060) State REPORTING
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:168 sofia/external/bbbuser@44.222.41.176:5060 Standard REPORTING, cause: NORMAL_CLEARING
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:932 (sofia/external/bbbuser@44.222.41.176:5060) State REPORTING going to sleep
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:607 (sofia/external/bbbuser@44.222.41.176:5060) State Change CS_REPORTING -> CS_DESTROY
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_session.c:1743 Session 19 (sofia/external/bbbuser@44.222.41.176:5060) Locked, Waiting on external entities
2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_core_session.c:1761 Session 19 (sofia/external/bbbuser@44.222.41.176:5060) Ended
2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_core_session.c:1765 Close Channel sofia/external/bbbuser@44.222.41.176:5060 [CS_DESTROY]
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:735 (sofia/external/bbbuser@44.222.41.176:5060) Running State Change CS_DESTROY (Cur 1 Tot 19)
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:745 (sofia/external/bbbuser@44.222.41.176:5060) State DESTROY
2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_sofia.c:379 sofia/external/bbbuser@44.222.41.176:5060 SOFIA DESTROY
2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:175 sofia/external/bbbuser@44.222.41.176:5060 Standard DESTROY
2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_core_state_machine.c:745 (sofia/external/bbbuser@44.222.41.176:5060) State DESTROY going to sleep