freeswitch icon indicating copy to clipboard operation
freeswitch copied to clipboard

The speed of the right channel of the recording wav file is very fast sometimes

Open wangduanduan opened this issue 3 years ago • 3 comments

Describe the bug

Call quality is ok, but recording wav file has a strange problem。

we have many recoding wav files, The speed of the right channel of the sound file is too fast to listen clearly sometime, but the left channel of sound file is listen normarly always.

the two call leg both use pcma codes。

To Reproduce

Steps to reproduce the behavior:

  1. one sip ua call fs
  2. then fs bridge other sip phone
  3. call connected, and recodring_session
  4. drop call, and listen the wav file

Expected behavior the right channel of recording file has number speed

Package version or git hash

  • Version [e.g. 1.10.7]

Trace logs Provide freeswitch logs w/ DEBUG and UUID logging enabled

wangduanduan avatar Dec 30 '21 11:12 wangduanduan

and when i change the fs to 1.4.26, recording file speed problem solved。

i don't know why 1.10.7 has the recording problem.

wangduanduan avatar Dec 30 '21 11:12 wangduanduan

DEBUG logs ? pcap traces ? we need to see at least what codecs are used.

dragos-oancea avatar Dec 30 '21 13:12 dragos-oancea

We have the same problem on 'FS 1.10.9' when using late codec negotiation, it only occurs to certain numbers. We can workaround the problem by generating ring back (or disabling late codec negotiation).

It seems to be caused by SIP\SDP update messages after the call has been answered and recording started, FreeSWITCH decides it needs to change the codec then changes it back again so there's ultimately no codec change. The call itself is fine, but there's a rate mismatch with the audio in the recording, one leg is fine and the other is sped up.

This is where it occurs.

2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] sofia.c:8507 Processing updated SDP
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:8622 Audio params are unchanged for sofia/internal/222@mydomain:6000.
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.205754 96.83% [DEBUG] switch_core_media.c:3637 Changing Codec from PCMA@20ms@8000hz to G722@20ms@8000hz
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.205754 96.83% [DEBUG] switch_rtp.c:7511 Correct audio ip/port confirmed.
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.245754 96.83% [DEBUG] switch_core_media.c:3739 Set Codec sofia/internal/222@mydomain:6000 G722/8000 20 ms 160 samples 64000 bits 1 channels
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.245754 96.83% [DEBUG] switch_core_codec.c:123 sofia/internal/222@mydomain:6000 Original read codec replaced with G722:9
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.245754 96.83% [NOTICE] switch_core_media.c:15975 Activating write resampler
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.265754 96.83% [DEBUG] switch_core_media.c:3183 alternate payload received (received 8, expecting 9)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.265754 96.83% [WARNING] switch_core_media.c:3194 Changing current codec to PCMA (payload type 8).
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.265754 96.83% [NOTICE] switch_core_media.c:15975 Activating write resampler
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.285755 96.83% [DEBUG] switch_core_media.c:3637 Changing Codec from G722@20ms@16000hz to PCMA@20ms@8000hz
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.325754 96.83% [DEBUG] switch_core_media.c:3739 Set Codec sofia/internal/222@mydomain:6000 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.325754 96.83% [DEBUG] switch_core_codec.c:123 sofia/internal/222@mydomain:6000 Original read codec replaced with PCMA:8

Here's the SIP trace. image

Here are the logs.

2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.845755 96.80% [NOTICE] switch_channel.c:1123 New Channel sofia/internal/222@mydomain:6000 [2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.845755 96.80% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/222@mydomain:6000) Running State Change CS_NEW (Cur 105 Tot 40263)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.845755 96.80% [INFO] sofia.c:10448 sofia/internal/222@mydomain:6000 receiving invite from x.x.x.103:6000 version: 1.10.9-release git a615e85 2023-02-03 20:07:30Z 64bit call-id: e0a1efc0ef9e309be78a7885f2bbb433
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] sofia.c:7487 Channel sofia/internal/222@mydomain:6000 entering state [received][100]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] sofia.c:7497 Remote SDP:
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba v=0
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba o=- 1711374318 1711374318 IN IP4 x.x.x.128
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba s=Polycom IP Phone
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba c=IN IP4 x.x.x.128
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba t=0 0
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=sendrecv
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba m=audio 2242 RTP/AVP 9 102 0 8 18 127
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:9 G722/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:102 G7221/16000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=fmtp:102 bitrate=32000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:0 PCMU/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:8 PCMA/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:18 G729/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=fmtp:18 annexb=no
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:127 telephone-event/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] sofia.c:7900 (sofia/internal/222@mydomain:6000) State Change CS_NEW -> CS_INIT
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/222@mydomain:6000) State NEW
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/222@mydomain:6000) Running State Change CS_INIT (Cur 105 Tot 40263)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/222@mydomain:6000) State INIT
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] mod_sofia.c:97 sofia/internal/222@mydomain:6000 SOFIA INIT
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:40 sofia/internal/222@mydomain:6000 Standard INIT
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/222@mydomain:6000) State Change CS_INIT -> CS_ROUTING
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/222@mydomain:6000) State INIT going to sleep
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/222@mydomain:6000) Running State Change CS_ROUTING (Cur 105 Tot 40263)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_channel.c:2380 (sofia/internal/222@mydomain:6000) Callstate Change DOWN -> RINGING
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/222@mydomain:6000) State ROUTING
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] mod_sofia.c:158 sofia/internal/222@mydomain:6000 SOFIA ROUTING
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.865757 96.80% [DEBUG] switch_core_state_machine.c:230 sofia/internal/222@mydomain:6000 Standard ROUTING
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba Dialplan: sofia/internal/222@mydomain:6000 Action set(suppress_cng=true) INLINE
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba EXECUTE [depth=0] sofia/internal/222@mydomain:6000 set(suppress_cng=true)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.885754 96.80% [DEBUG] mod_dptools.c:1673 SET sofia/internal/222@mydomain:6000 [suppress_cng]=[true]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.905756 96.80% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/222@mydomain:6000) State Change CS_ROUTING -> CS_EXECUTE
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.905756 96.80% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/222@mydomain:6000) State ROUTING going to sleep
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.905756 96.80% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/222@mydomain:6000) Running State Change CS_EXECUTE (Cur 105 Tot 40263)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.905756 96.80% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/222@mydomain:6000) State EXECUTE
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.905756 96.80% [DEBUG] mod_sofia.c:213 sofia/internal/222@mydomain:6000 SOFIA EXECUTE
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:17.905756 96.80% [DEBUG] switch_core_state_machine.c:323 sofia/internal/222@mydomain:6000 Standard EXECUTE
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:18.005752 96.80% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable(RECORD_APPEND, true)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:18.005752 96.80% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable(RECORD_MIN_SEC, 0)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:18.005752 96.80% [DEBUG] switch_cpp.cpp:1209 sofia/internal/222@mydomain:6000 destroy/unlink session from object
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba EXECUTE [depth=0] sofia/internal/222@mydomain:6000 export(nolocal:execute_on_answer=lua app.lua call_recording start)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:18.005752 96.80% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) (REMOTE ONLY) [execute_on_answer]=[lua app.lua call_recording start]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:19.205752 96.80% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable(hangup_after_bridge, true)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba EXECUTE [depth=0] sofia/internal/222@mydomain:6000 export(media_timeout_audio=300000)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:19.205752 96.80% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [media_timeout_audio]=[300000]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba EXECUTE [depth=0] sofia/internal/222@mydomain:6000 export(media_hold_timeout_audio=1800000)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:19.205752 96.80% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [media_hold_timeout_audio]=[1800000]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba EXECUTE [depth=0] sofia/internal/222@mydomain:6000 set(call_timeout=120)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:19.205752 96.80% [DEBUG] mod_dptools.c:1673 SET sofia/internal/222@mydomain:6000 [call_timeout]=[120]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:19.205752 96.80% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable(sip_cid_type, pid)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba EXECUTE [depth=0] sofia/internal/222@mydomain:6000 export(nolocal:execute_on_answer=lua app.lua call_recording start)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) (REMOTE ONLY) [execute_on_answer]=[lua app.lua call_recording start]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba EXECUTE [depth=0] sofia/internal/222@mydomain:6000 bridge({fail_on_single_reject=^^:CALL_REJECTED:NORMAL_CLEARING:USER_BUSY:UNALLOCATED_NUMBER,origination_privacy=none,absolute_codec_string=^^:mod_spandsp.G722@8000h@20i@64000b:CORE_PCM_MODULE.PCMA@8000h@20i@64000b}sofia/external/+443445570006@pstn_gateway:5000|sofia/external/[email protected]:5000)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_ivr_originate.c:2291 Parsing global variables
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [NOTICE] switch_channel.c:1123 New Channel sofia/external/%2B443445570006@pstn_gateway:5000 [d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa]
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] mod_sofia.c:5117 (sofia/external/%2B443445570006@pstn_gateway:5000) State Change CS_NEW -> CS_INIT
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:581 (sofia/external/%2B443445570006@pstn_gateway:5000) Running State Change CS_INIT (Cur 106 Tot 40264)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:624 (sofia/external/%2B443445570006@pstn_gateway:5000) State INIT
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] mod_sofia.c:97 sofia/external/%2B443445570006@pstn_gateway:5000 SOFIA INIT
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [INFO] sofia_glue.c:1668 sofia/external/%2B443445570006@pstn_gateway:5000 sending invite call-id: (null)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] sofia_glue.c:1671 sofia/external/%2B443445570006@pstn_gateway:5000 sending invite version: 1.10.9-release git a615e85 2023-02-03 20:07:30Z 64bit
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa Local SDP:
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa v=0
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa o=FreeSWITCH 1711350595 1711350596 IN IP4 x.x.x.112
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa s=FreeSWITCH
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa c=IN IP4 x.x.x.112
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa t=0 0
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa m=audio 23724 RTP/AVP 9 8 101 13
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=rtpmap:9 G722/8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=rtpmap:8 PCMA/8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=rtpmap:101 telephone-event/8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=fmtp:101 0-15
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=rtpmap:13 CN/8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=ptime:20
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=sendrecv
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:40 sofia/external/%2B443445570006@pstn_gateway:5000 Standard INIT
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:48 (sofia/external/%2B443445570006@pstn_gateway:5000) State Change CS_INIT -> CS_ROUTING
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:624 (sofia/external/%2B443445570006@pstn_gateway:5000) State INIT going to sleep
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:581 (sofia/external/%2B443445570006@pstn_gateway:5000) Running State Change CS_ROUTING (Cur 106 Tot 40264)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] sofia.c:7487 Channel sofia/external/%2B443445570006@pstn_gateway:5000 entering state [calling][0]
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:640 (sofia/external/%2B443445570006@pstn_gateway:5000) State ROUTING
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] mod_sofia.c:158 sofia/external/%2B443445570006@pstn_gateway:5000 SOFIA ROUTING
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_ivr_originate.c:67 (sofia/external/%2B443445570006@pstn_gateway:5000) State Change CS_ROUTING -> CS_CONSUME_MEDIA
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:640 (sofia/external/%2B443445570006@pstn_gateway:5000) State ROUTING going to sleep
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:581 (sofia/external/%2B443445570006@pstn_gateway:5000) Running State Change CS_CONSUME_MEDIA (Cur 106 Tot 40264)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:659 (sofia/external/%2B443445570006@pstn_gateway:5000) State CONSUME_MEDIA
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:19.225753 96.80% [DEBUG] switch_core_state_machine.c:659 (sofia/external/%2B443445570006@pstn_gateway:5000) State CONSUME_MEDIA going to sleep
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] sofia.c:7487 Channel sofia/external/%2B443445570006@pstn_gateway:5000 entering state [completing][200]
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] sofia.c:7497 Remote SDP:
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa v=0
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa o=FreeSWITCH 1711342242 1711342243 IN IP4 x.x.x.66
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa s=FreeSWITCH
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa c=IN IP4 x.x.x.66
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa t=0 0
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa m=audio 32078 RTP/AVP 8 101
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=rtpmap:8 PCMA/8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=rtpmap:101 telephone-event/8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=fmtp:101 0-15
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa a=ptime:20
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] sofia.c:7487 Channel sofia/external/%2B443445570006@pstn_gateway:5000 entering state [ready][200]
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:5571 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:5432 Set telephone-event payload to 101@8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:3739 Set Codec sofia/external/%2B443445570006@pstn_gateway:5000 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_codec.c:111 sofia/external/%2B443445570006@pstn_gateway:5000 Original read codec set to PCMA:8
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:5781 Set telephone-event payload to 101@8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:5839 sofia/external/%2B443445570006@pstn_gateway:5000 Set 2833 dtmf send payload to 101 recv payload to 101
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:8640 AUDIO RTP [sofia/external/%2B443445570006@pstn_gateway:5000] x.x.x.112 port 23724 -> x.x.x.66 port 32078 codec: 8 ms: 20
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_rtp.c:4377 Starting timer [soft] 160 bytes per 20ms
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:8952 sofia/external/%2B443445570006@pstn_gateway:5000 Set 2833 dtmf send payload to 101
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:8959 sofia/external/%2B443445570006@pstn_gateway:5000 Set 2833 dtmf receive payload to 101
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [DEBUG] switch_core_media.c:8982 sofia/external/%2B443445570006@pstn_gateway:5000 Set rtp dtmf delay to 40
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.045754 96.83% [NOTICE] sofia.c:8669 Channel [sofia/external/%2B443445570006@pstn_gateway:5000] has been answered
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa EXECUTE [depth=1] sofia/external/%2B443445570006@pstn_gateway:5000 lua(app.lua call_recording start)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_ivr_originate.c:448 Setting codec string on sofia/internal/222@mydomain:6000 to PCMA@8000h@20i
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G7221:102:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5571 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5432 Set telephone-event payload to 127@8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:3739 Set Codec sofia/internal/222@mydomain:6000 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_codec.c:111 sofia/internal/222@mydomain:6000 Original read codec set to PCMA:8
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5781 Set telephone-event payload to 127@8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:5839 sofia/internal/222@mydomain:6000 Set 2833 dtmf send payload to 127 recv payload to 127
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:8640 AUDIO RTP [sofia/internal/222@mydomain:6000] x.x.x.103 port 17128 -> x.x.x.128 port 2242 codec: 8 ms: 20
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_rtp.c:4377 Starting timer [soft] 160 bytes per 20ms
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:8952 sofia/internal/222@mydomain:6000 Set 2833 dtmf send payload to 127
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:8959 sofia/internal/222@mydomain:6000 Set 2833 dtmf receive payload to 127
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:8982 sofia/internal/222@mydomain:6000 Set rtp dtmf delay to 40
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [NOTICE] sofia_media.c:90 Pre-Answer sofia/internal/222@mydomain:6000!
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_channel.c:3566 (sofia/internal/222@mydomain:6000) Callstate Change RINGING -> EARLY
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_core_media.c:8622 Audio params are unchanged for sofia/internal/222@mydomain:6000.
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] mod_sofia.c:913 Local SDP sofia/internal/222@mydomain:6000:
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba v=0
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba o=FreeSWITCH 1711357192 1711357193 IN IP4 x.x.x.103
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba s=FreeSWITCH
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba c=IN IP4 x.x.x.103
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba t=0 0
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba m=audio 17128 RTP/AVP 8 127
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:8 PCMA/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:127 telephone-event/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=fmtp:127 0-15
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=ptime:20
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=sendrecv
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [NOTICE] switch_ivr_originate.c:3844 Channel [sofia/internal/222@mydomain:6000] has been answered
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_channel.c:3893 (sofia/internal/222@mydomain:6000) Callstate Change EARLY -> ACTIVE
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] sofia.c:7487 Channel sofia/internal/222@mydomain:6000 entering state [completed][200]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.065754 96.83% [DEBUG] switch_ivr_originate.c:3902 Originate Resulted in Success: [sofia/external/%2B443445570006@pstn_gateway:5000] Peer UUID: d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.125754 96.83% [DEBUG] switch_rtp.c:7511 Correct audio ip/port confirmed.
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable(RECORD_APPEND, true)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] switch_cpp.cpp:773 CoreSession::setVariable(RECORD_MIN_SEC, 0)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] switch_cpp.cpp:1209 sofia/external/%2B443445570006@pstn_gateway:5000 destroy/unlink session from object
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] switch_channel.c:3893 (sofia/external/%2B443445570006@pstn_gateway:5000) Callstate Change DOWN -> ACTIVE
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.145754 96.83% [DEBUG] sofia.c:7487 Channel sofia/internal/222@mydomain:6000 entering state [ready][200]
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] switch_ivr_bridge.c:1791 (sofia/external/%2B443445570006@pstn_gateway:5000) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] switch_core_state_machine.c:581 (sofia/external/%2B443445570006@pstn_gateway:5000) Running State Change CS_EXCHANGE_MEDIA (Cur 106 Tot 40264)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] switch_core_state_machine.c:650 (sofia/external/%2B443445570006@pstn_gateway:5000) State EXCHANGE_MEDIA
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.145754 96.83% [DEBUG] mod_sofia.c:671 SOFIA EXCHANGE_MEDIA
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.165754 96.83% [DEBUG] sofia.c:7487 Channel sofia/internal/222@mydomain:6000 entering state [calling][0]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] sofia.c:7487 Channel sofia/internal/222@mydomain:6000 entering state [ready][200]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] sofia.c:7494 Duplicate SDP
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba v=0
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba o=- 1711374318 1711374318 IN IP4 x.x.x.128
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba s=Polycom IP Phone
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba c=IN IP4 x.x.x.128
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba t=0 0
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=sendrecv
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba m=audio 2242 RTP/AVP 9 102 0 8 18 127
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:9 G722/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:102 G7221/16000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=fmtp:102 bitrate=32000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:0 PCMU/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:8 PCMA/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:18 G729/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=fmtp:18 annexb=no
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba a=rtpmap:127 telephone-event/8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5571 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G7221:102:16000:20:0:1]/[G722:9:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G7221:102:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5571 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5516 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5432 Set telephone-event payload to 127@8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5781 Set telephone-event payload to 127@8000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:5839 sofia/internal/222@mydomain:6000 Set 2833 dtmf send payload to 127 recv payload to 127
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] sofia.c:8507 Processing updated SDP
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.185754 96.83% [DEBUG] switch_core_media.c:8622 Audio params are unchanged for sofia/internal/222@mydomain:6000.
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.205754 96.83% [DEBUG] switch_core_media.c:3637 Changing Codec from PCMA@20ms@8000hz to G722@20ms@8000hz
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.205754 96.83% [DEBUG] switch_rtp.c:7511 Correct audio ip/port confirmed.
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.245754 96.83% [DEBUG] switch_core_media.c:3739 Set Codec sofia/internal/222@mydomain:6000 G722/8000 20 ms 160 samples 64000 bits 1 channels
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.245754 96.83% [DEBUG] switch_core_codec.c:123 sofia/internal/222@mydomain:6000 Original read codec replaced with G722:9
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.245754 96.83% [NOTICE] switch_core_media.c:15975 Activating write resampler
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.265754 96.83% [DEBUG] switch_core_media.c:3183 alternate payload received (received 8, expecting 9)
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.265754 96.83% [WARNING] switch_core_media.c:3194 Changing current codec to PCMA (payload type 8).
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.265754 96.83% [NOTICE] switch_core_media.c:15975 Activating write resampler
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.285755 96.83% [DEBUG] switch_core_media.c:3637 Changing Codec from G722@20ms@16000hz to PCMA@20ms@8000hz
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.325754 96.83% [DEBUG] switch_core_media.c:3739 Set Codec sofia/internal/222@mydomain:6000 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.325754 96.83% [DEBUG] switch_core_codec.c:123 sofia/internal/222@mydomain:6000 Original read codec replaced with PCMA:8
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.345754 96.83% [DEBUG] switch_ivr_bridge.c:654 sofia/external/%2B443445570006@pstn_gateway:5000 Bridge execute app limit(hash mydomain_bleg 222 6 !OUTGOING_CALL_BARRED)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.365754 96.83% [DEBUG] switch_ivr.c:632 sofia/external/%2B443445570006@pstn_gateway:5000 Command Execute [depth=0] limit(hash mydomain_bleg 222 6 !OUTGOING_CALL_BARRED)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa EXECUTE [depth=0] sofia/external/%2B443445570006@pstn_gateway:5000 limit(hash mydomain_bleg 222 6 !OUTGOING_CALL_BARRED)
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.365754 96.83% [DEBUG] switch_limit.c:124 incr called: mydomain_bleg_222 max:6, interval:0
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:20.365754 96.83% [DEBUG] mod_hash.c:193 Usage for mydomain_bleg_222 is now 1/6
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:20.465755 96.83% [INFO] switch_rtp.c:7471 Auto Changing audio port from x.x.x.128:2242 to 213.121.166.18:23100
2024-03-25 14:45:21.145751 96.77% [NOTICE] switch_cpp.cpp:1465 uuid_record d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa start /usr/local/freeswitch/recordings/mydomain/archive/2024/Mar/25/d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa.mp3 
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:21.165751 96.77% [DEBUG] switch_ivr_async.c:1503 Record session sample rate: 8000 -> 8000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:21.165751 96.77% [DEBUG] switch_core_media_bug.c:976 Attaching BUG to sofia/external/%2B443445570006@pstn_gateway:5000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:21.165751 96.77% [DEBUG] switch_ivr_async.c:1777 No silence detection configured; assuming start of speech
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:21.205752 96.77% [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMA:8
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:38.165754 96.77% [DEBUG] switch_rtp.c:7756 RTP RECV DTMF 1:640
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:38.165754 96.77% [DEBUG] mod_dptools.c:131 sofia/internal/222@mydomain:6000 Digit NOT match binding [1]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:38.165754 96.77% [INFO] switch_channel.c:527 RECV DTMF 1:2000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:38.165754 96.77% [DEBUG] switch_channel.c:623 sofia/internal/222@mydomain:6000 Queue dtmf
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba digit=1 ms=250 samples=2000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.165754 96.77% [DEBUG] switch_rtp.c:5430 Send start packet for [1] ts=1605173893 dur=160/160/2000 seq=1789 lw=1605173893
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.185750 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=320/320/2000 seq=1790 lw=1605174053
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.205754 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=480/480/2000 seq=1791 lw=1605174213
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.225754 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=640/640/2000 seq=1792 lw=1605174373
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.245756 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=800/800/2000 seq=1793 lw=1605174533
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.265756 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=960/960/2000 seq=1794 lw=1605174693
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.285750 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=1120/1120/2000 seq=1795 lw=1605174853
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.305755 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=1280/1280/2000 seq=1796 lw=1605175013
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.325755 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=1440/1440/2000 seq=1797 lw=1605175173
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.345755 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=1600/1600/2000 seq=1798 lw=1605175333
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.365755 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=1760/1760/2000 seq=1799 lw=1605175493
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.385750 96.77% [DEBUG] switch_rtp.c:5329 Send middle packet for [1] ts=1605173893 dur=1920/1920/2000 seq=1800 lw=1605175653
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.405754 96.77% [DEBUG] switch_rtp.c:5329 Send end packet for [1] ts=1605173893 dur=2080/2080/2000 seq=1801 lw=1605175653
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.405754 96.77% [DEBUG] switch_rtp.c:5329 Send end packet for [1] ts=1605173893 dur=2080/2080/2000 seq=1802 lw=1605175653
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.405754 96.77% [DEBUG] switch_rtp.c:5329 Send end packet for [1] ts=1605173893 dur=2080/2080/2000 seq=1803 lw=1605175653
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:38.405754 96.77% [DEBUG] switch_rtp.c:5277 Queue digit delay of 40ms
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:55.985755 96.67% [DEBUG] switch_rtp.c:7756 RTP RECV DTMF 6:640
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:55.985755 96.67% [DEBUG] mod_dptools.c:131 sofia/internal/222@mydomain:6000 Digit NOT match binding [6]
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:55.985755 96.67% [INFO] switch_channel.c:527 RECV DTMF 6:2000
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba 2024-03-25 14:45:55.985755 96.67% [DEBUG] switch_channel.c:623 sofia/internal/222@mydomain:6000 Queue dtmf
2e4f6c17-0e6f-4a4b-90ea-6817e42f07ba digit=6 ms=250 samples=2000
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:55.985755 96.67% [DEBUG] switch_rtp.c:5430 Send start packet for [6] ts=1605316453 dur=160/160/2000 seq=2683 lw=1605316453
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.005755 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=320/320/2000 seq=2684 lw=1605316613
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.025755 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=480/480/2000 seq=2685 lw=1605316773
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.045755 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=640/640/2000 seq=2686 lw=1605316933
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.065755 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=800/800/2000 seq=2687 lw=1605317093
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.085754 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=960/960/2000 seq=2688 lw=1605317253
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.105754 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=1120/1120/2000 seq=2689 lw=1605317413
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.125756 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=1280/1280/2000 seq=2690 lw=1605317573
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.145751 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=1440/1440/2000 seq=2691 lw=1605317733
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.165751 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=1600/1600/2000 seq=2692 lw=1605317893
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.185752 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=1760/1760/2000 seq=2693 lw=1605318053
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.205752 96.67% [DEBUG] switch_rtp.c:5329 Send middle packet for [6] ts=1605316453 dur=1920/1920/2000 seq=2694 lw=1605318213
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.225751 96.67% [DEBUG] switch_rtp.c:5329 Send end packet for [6] ts=1605316453 dur=2080/2080/2000 seq=2695 lw=1605318213
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.225751 96.67% [DEBUG] switch_rtp.c:5329 Send end packet for [6] ts=1605316453 dur=2080/2080/2000 seq=2696 lw=1605318213
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.225751 96.67% [DEBUG] switch_rtp.c:5329 Send end packet for [6] ts=1605316453 dur=2080/2080/2000 seq=2697 lw=1605318213
d43cd3b9-f6d9-4b1d-b93e-ef73e32ba8aa 2024-03-25 14:45:56.225751 96.67% [DEBUG] switch_rtp.c:5277 Queue digit delay of 40ms

shaunjstokes avatar Mar 26 '24 10:03 shaunjstokes