1. 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]
2. 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)
3. 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..
4. 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]
5. 2024-07-31 12:30:49.467969 97.70% [DEBUG] sofia.c:7497 Remote SDP:
6. v=0
7. o=Z 0 32010277 IN IP4 103.254.35.50
8. s=Z
9. c=IN IP4 103.254.35.50
10. t=0 0
11. m=audio 51941 RTP/AVP 106 9 98 101 0 8 3
12. a=rtpmap:106 opus/48000/2
13. a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1
14. a=rtpmap:98 telephone-event/48000
15. a=fmtp:98 0-16
16. a=rtpmap:101 telephone-event/8000
17. a=fmtp:101 0-16
18. a=rtcp-mux
19.  
20. 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
21. 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
22. 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)
23. 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
24. 2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:97 sofia/external/bbbuser@44.222.41.176:5060 SOFIA INIT
25. 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
26. 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
27. 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
28. 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)
29. 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
30. 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
31. 2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:158 sofia/external/bbbuser@44.222.41.176:5060 SOFIA ROUTING
32. 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
33. 2024-07-31 12:30:49.467969 97.70% [INFO] mod_dialplan_xml.c:639 Processing bbbuser <bbbuser>->5612755500 in context public
34. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->unloop] continue=false
35. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
36. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
37. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->outside_call] continue=true
38. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Absolute Condition [outside_call]
39. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action set(outside_call=true)
40. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
41. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->bbb_dialin authorised and arrived from other server] continue=false
42. 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
43. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 parsing [public->bbb_dialin auth checking] continue=false
44. 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
45. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action info()
46. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action log(INFO bbb_dialin checking for Auth)
47. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action lua(/opt/freeswitch/scripts/bbb_conference_auth.lua 5612755500 ${sip_from_host})
48. Dialplan: sofia/external/bbbuser@44.222.41.176:5060 Action transfer(${pin} XML server_check)
49. 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
50. 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
51. 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)
52. 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
53. 2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:213 sofia/external/bbbuser@44.222.41.176:5060 SOFIA EXECUTE
54. 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
55. EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 set(outside_call=true)
56. 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]
57. EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 export(RFC2822_DATE=Wed, 31 Jul 2024 12:30:49 +0000)
58. 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]
59. EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 info()
60. 2024-07-31 12:30:49.467969 97.70% [INFO] mod_dptools.c:1886 CHANNEL_DATA:
61. Channel-State: [CS_EXECUTE]
62. Channel-Call-State: [RINGING]
63. Channel-State-Number: [4]
64. Channel-Name: [sofia/external/bbbuser@44.222.41.176:5060]
65. Unique-ID: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
66. Call-Direction: [inbound]
67. Presence-Call-Direction: [inbound]
68. Channel-HIT-Dialplan: [true]
69. Channel-Call-UUID: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
70. Answer-State: [ringing]
71. Caller-Direction: [inbound]
72. Caller-Logical-Direction: [inbound]
73. Caller-Username: [bbbuser]
74. Caller-Dialplan: [XML]
75. Caller-Caller-ID-Name: [bbbuser]
76. Caller-Caller-ID-Number: [bbbuser]
77. Caller-Orig-Caller-ID-Name: [bbbuser]
78. Caller-Orig-Caller-ID-Number: [bbbuser]
79. Caller-Network-Addr: [103.254.35.50]
80. Caller-ANI: [bbbuser]
81. Caller-Destination-Number: [5612755500]
82. Caller-Unique-ID: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
83. Caller-Source: [mod_sofia]
84. Caller-Context: [public]
85. Caller-Channel-Name: [sofia/external/bbbuser@44.222.41.176:5060]
86. Caller-Profile-Index: [1]
87. Caller-Profile-Created-Time: [1722429049467969]
88. Caller-Channel-Created-Time: [1722429049467969]
89. Caller-Channel-Answered-Time: [0]
90. Caller-Channel-Progress-Time: [0]
91. Caller-Channel-Progress-Media-Time: [0]
92. Caller-Channel-Hangup-Time: [0]
93. Caller-Channel-Transfer-Time: [0]
94. Caller-Channel-Resurrect-Time: [0]
95. Caller-Channel-Bridged-Time: [0]
96. Caller-Channel-Last-Hold: [0]
97. Caller-Channel-Hold-Accum: [0]
98. Caller-Screen-Bit: [true]
99. Caller-Privacy-Hide-Name: [false]
100. Caller-Privacy-Hide-Number: [false]
101. variable_direction: [inbound]
102. variable_uuid: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
103. variable_session_id: [19]
104. variable_sip_from_params: [transport=TCP]
105. variable_sip_from_user: [bbbuser]
106. variable_sip_from_port: [5060]
107. variable_sip_from_uri: [bbbuser@44.222.41.176:5060]
108. variable_sip_from_host: [44.222.41.176]
109. variable_video_media_flow: [disabled]
110. variable_audio_media_flow: [disabled]
111. variable_text_media_flow: [disabled]
112. variable_channel_name: [sofia/external/bbbuser@44.222.41.176:5060]
113. variable_sip_call_id: [zedD05_CBVtzC7nwYwfT9A..]
114. variable_sip_local_network_addr: [44.222.41.176]
115. variable_sip_network_ip: [103.254.35.50]
116. variable_sip_network_port: [41041]
117. variable_sip_invite_stamp: [1722429049467969]
118. variable_sip_received_ip: [103.254.35.50]
119. variable_sip_received_port: [41041]
120. variable_sip_via_protocol: [tcp]
121. variable_sip_from_user_stripped: [bbbuser]
122. variable_sip_from_tag: [cc199b10]
123. variable_sofia_profile_name: [external]
124. variable_sofia_profile_url: [sip:mod_sofia@44.222.41.176:5060]
125. variable_recovery_profile_name: [external]
126. 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]
127. 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]
128. variable_sip_full_from: [<sip:bbbuser@44.222.41.176:5060;transport=TCP>;tag=cc199b10]
129. variable_sip_full_to: [<sip:5612755500@44.222.41.176:5060>]
130. variable_sip_allow: [INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE]
131. variable_sip_req_params: [transport=TCP]
132. variable_sip_req_user: [5612755500]
133. variable_sip_req_port: [5060]
134. variable_sip_req_uri: [5612755500@44.222.41.176:5060]
135. variable_sip_req_host: [44.222.41.176]
136. variable_sip_to_user: [5612755500]
137. variable_sip_to_port: [5060]
138. variable_sip_to_uri: [5612755500@44.222.41.176:5060]
139. variable_sip_to_host: [44.222.41.176]
140. variable_sip_contact_params: [transport=TCP]
141. variable_sip_contact_user: [bbbuser]
142. variable_sip_contact_port: [41041]
143. variable_sip_contact_uri: [bbbuser@103.254.35.50:41041]
144. variable_sip_contact_host: [103.254.35.50]
145. variable_rtp_use_codec_string: [OPUS,speex@16000h@20i,speex@8000h@20i,G722,PCMU,PCMA]
146. variable_sip_user_agent: [Z 5.6.2 v2.10.20.2]
147. variable_sip_via_host: [10.212.135.50]
148. variable_sip_via_port: [56027]
149. variable_sip_via_rport: [41041]
150. variable_max_forwards: [70]
151. variable_switch_r_sdp: [v=0
152. o=Z 0 32010277 IN IP4 103.254.35.50
153. s=Z
154. c=IN IP4 103.254.35.50
155. t=0 0
156. m=audio 51941 RTP/AVP 106 9 98 101 0 8 3
157. a=rtpmap:106 opus/48000/2
158. a=fmtp:106 sprop-maxcapturerate=16000; minptime=20; useinbandfec=1
159. a=rtpmap:98 telephone-event/48000
160. a=fmtp:98 0-16
161. a=rtpmap:101 telephone-event/8000
162. a=fmtp:101 0-16
163. a=rtcp-mux
164. ]
165. 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]
166. variable_endpoint_disposition: [DELAYED NEGOTIATION]
167. variable_DP_MATCH: [5612755500]
168. variable_call_uuid: [93d15e80-4f0c-4e46-8f26-7460eeec55ad]
169. variable_outside_call: [true]
170. variable_RFC2822_DATE: [Wed, 31 Jul 2024 12:30:49 +0000]
171. variable_export_vars: [RFC2822_DATE]
172. variable_current_application: [info]
173.  
174.  
175. EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 log(INFO bbb_dialin checking for Auth)
176. 2024-07-31 12:30:49.467969 97.70% [INFO] mod_dptools.c:1867 bbb_dialin checking for Auth
177. EXECUTE [depth=0] sofia/external/bbbuser@44.222.41.176:5060 lua(/opt/freeswitch/scripts/bbb_conference_auth.lua 5612755500 44.222.41.176)
178. 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]
179. 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
180. 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]
181. 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]
182. 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]
183. 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]
184. 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]
185. 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]
186. 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]
187. 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]
188. 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]
189. 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
190. 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]
191. 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]
192. 2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5451 Set telephone-event payload to 98@48000
193. 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]
194. 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]
195. 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]
196. 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]
197. 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]
198. 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
199. 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]
200. 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]
201. 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]
202. 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]
203. 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]
204. 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]
205. 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]
206. 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
207. 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]
208. 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]
209. 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]
210. 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]
211. 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]
212. 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]
213. 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]
214. 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]
215. 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]
216. 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]
217. 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
218. 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
219. 2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:5800 Set telephone-event payload to 98@48000
220. 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
221. 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
222. 2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_rtp.c:4389 Starting timer [soft] 960 bytes per 20ms
223. 2024-07-31 12:30:49.467969 97.70% [DEBUG] switch_core_media.c:8879 Activating RTCP PORT 51941
224. 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
225. 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
226. 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
227. 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
228. 2024-07-31 12:30:49.467969 97.70% [NOTICE] sofia_media.c:90 Pre-Answer sofia/external/bbbuser@44.222.41.176:5060!
229. 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
230. 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.
231. 2024-07-31 12:30:49.467969 97.70% [DEBUG] mod_sofia.c:913 Local SDP sofia/external/bbbuser@44.222.41.176:5060:
232. v=0
233. o=FreeSWITCH 1722410469 1722410470 IN IP4 44.222.41.176
234. s=FreeSWITCH
235. c=IN IP4 44.222.41.176
236. t=0 0
237. m=audio 18580 RTP/AVP 106 98
238. a=rtpmap:106 opus/48000/2
239. a=fmtp:106 useinbandfec=1; maxaveragebitrate=64000; maxplaybackrate=48000; sprop-maxcapturerate=48000; minptime=20
240. a=rtpmap:98 telephone-event/48000
241. a=fmtp:98 0-15
242. a=ptime:20
243. a=sendrecv
244. a=rtcp-mux
245. a=rtcp:18580 IN IP4 44.222.41.176
246.  
247. 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
248. 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
249. 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]
250. 2024-07-31 12:30:49.467969 97.70% [NOTICE] switch_cpp.cpp:1465 tenant id query = {"did_status" : "1", "did_number" : "5612755500"}
251. 2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 tenant id query result = 196
252. 2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 tenant id query result = 153
253. 2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 ACL CHECK STR : acl 44.222.41.176 196
254. 2024-07-31 12:30:49.487933 97.70% [NOTICE] switch_cpp.cpp:1465 Not allowed to Enter rejected by acl
255. 2024-07-31 12:30:49.487933 97.70% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
256. 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]
257. 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
258. 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)
259. 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
260. 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)
261. 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
262. 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
263. 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
264. 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
265. 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
266. 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
267. 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
268. 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)
269. 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
270. 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
271. 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
272. 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
273. 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
274. 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
275. 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]
276. 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)
277. 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
278. 2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_sofia.c:379 sofia/external/bbbuser@44.222.41.176:5060 SOFIA DESTROY
279. 2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
280. 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]
281. 2024-07-31 12:30:49.487933 97.70% [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
282. 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]
283. 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
284. 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