I have tested several scenarios and found out that it happens only in Call Center Queues and only if the call is inbound.
Scenarios:
A:
- An extension makes an outbound call
OR;
- An inbound call or a local call comes directly to an extension
OR;
- A local call comes to call center
THEN;
- The extension holds the call and takes it back.
- Sound is normal.
B:
- An inbound call comes to call center:
- The extension holds the call and takes it back.
- Sound is distorted. Neither of the legs could hear the other well.
And I found out that the problem is caused by codecs.
In the scenario A, I see logs like this:
Code:
8565fc3d-d8ec-426d-990a-c45b0eb88f50 2023-04-27 11:50:01.740690 96.37% [INFO] switch_rtp.c:7885 Auto Changing audio port from 10.1.3.142:11800 to XXX.XXX.XXX.XXX:11800
c1c3e262-5620-4d20-bf2c-5b5210da9be2 EXECUTE [depth=0] sofia/external/XXXXXXXX@sipgw5003.com playback(local_stream://default)
8565fc3d-d8ec-426d-990a-c45b0eb88f50 2023-04-27 11:50:04.480454 96.37% [INFO] switch_rtp.c:6432 RE-Activating Secure RTP RECV
8565fc3d-d8ec-426d-990a-c45b0eb88f50 2023-04-27 11:50:08.260469 96.30% [INFO] switch_rtp.c:8792 RE-Activating audio Secure RTP SEND
8565fc3d-d8ec-426d-990a-c45b0eb88f50 2023-04-27 11:50:08.260469 96.30% [WARNING] switch_core_media.c:3338 Changing current codec to PCMA (payload type 8).
8565fc3d-d8ec-426d-990a-c45b0eb88f50 2023-04-27 11:50:08.340461 96.30% [WARNING] switch_core_media.c:3338 Changing current codec to PCMU (payload type 0).
But in scenario B, I see logs like this:
Code:
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:12.560467 91.20% [INFO] switch_rtp.c:7885 Auto Changing audio port from 10.1.3.142:11796 to XXX.XXX.XXX.XXX:11796
5a2656dd-82a3-49a6-91ac-6ee0f866626a EXECUTE [depth=0] sofia/external/XXXXXXX@XXX.XXX.XXX.XXX playback(local_stream://default)
5a2656dd-82a3-49a6-91ac-6ee0f866626a 2023-04-27 11:48:15.620427 89.67% [NOTICE] switch_core_media.c:16203 Deactivating write resampler
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:15.680457 89.67% [INFO] switch_rtp.c:6432 RE-Activating Secure RTP RECV
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:20.860461 90.13% [INFO] switch_rtp.c:8792 RE-Activating audio Secure RTP SEND
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:20.880468 90.13% [WARNING] switch_core_media.c:3338 Changing current codec to G722 (payload type 9).
5a2656dd-82a3-49a6-91ac-6ee0f866626a 2023-04-27 11:48:20.940660 90.13% [NOTICE] switch_core_media.c:16176 Activating write resampler
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:20.940660 90.13% [NOTICE] switch_core_media.c:16176 Activating write resampler
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:21.100448 90.13% [WARNING] switch_core_media.c:3338 Changing current codec to PCMU (payload type 0).
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:21.140472 90.13% [NOTICE] switch_core_media.c:16176 Activating write resampler
Looks like one end is on codec G722 and the other end is on PCMU. I didn't know different ends could use different codecs. At first, I remembered that my provider supports only G711 (PCMA and PCMU) and thought that it could be the reason. (Nevertheless, actually the codecs are different in the working scenario too. One of the legs is PCMU and the other is PCMA.) But searching around, I learnt that different legs can perfectly use different codecs; and otherwise why would FreeSWITCH evet set different codecs for leg-A and leg-B in the first place? So I thought the call can and should still take place when the inbound caller hears the sound in G711 whilst the extension hears it in G722.
Well, turns out not. Why? I had the codec variables set to this:
Code:
global_codec_prefs = PCMU,PCMA,G722
outbound_codec_prefs = G7221@32000h,G7221@16000h,G722,PCMU,PCMA
In order to resolve this problem, I had to set outbound_codec_prefs to match exactly global_codec_prefs. Now the problem has gone away, leaving me with the questions above. Why can't two legs use different codecs? If not, why FreeSWITCH allows it and why there are two different variables if we alrady have to set them to exactly same value? I was expecting to switch to Opus, but turns out I can't manage to make an even more spread and widely supported G722 codec work; let alone Opus. (When I set codec prefs to OPUS,PCMU,PCMA,G722 and started Opus module, I lost all registrations except two and they kept failing registration, I had to revert it back to get back on operation.)
By the way two interesting notes:
1- I am calling the call center from my mobile phone and with scenario A, I see my mobile number is displayed in the log like "
XXXXXXXX@sipgw5003.com", I don't know where this domain comes from, it is not even a registered domain name? But in scenario B, you see the very same mobile phone number as: "XXXXXXX@PUBLIC_IP_ADRESS".
2- I see some other strange problems in scenario B in the log like:
Code:
c1c3e262-5620-4d20-bf2c-5b5210da9be2 EXECUTE [depth=0] sofia/external/905415607090@sipgw5003.com playback(/usr/share/freeswitch/sounds/{default_language}/{default_dialect}/{default_voice}/ivr/ivr-call_being_transferred.wav)
2023-04-27 11:49:51.360479 97.93% [WARNING] mod_sndfile.c:281 Error Opening File [/usr/share/freeswitch/sounds/{default_language}/{default_dialect}/{default_voice}/ivr/ivr-call_being_transferred.wav] [System error : No such file or directory.]
I am using a custom language and for it, I have created same directory structure with callie's. My `sound_prefix` variable is set to: `$${sounds_dir}/$${default_language}/$${default_dialect}/$${default_voice}` which I believe is default. Normally prompts work with this setting but as you can see in the log, on some conditions, "variable variables" are not resolved and it tries to literally fetch a file named like that instead of turning it into the value of the corresponding variables.
AND:
Code:
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 EXECUTE [depth=0] sofia/internal/1020@10.1.3.142:12439 record_session(/var/lib/freeswitch/recordings/pbx.example.com/archive/{strftime(%Y)}/{strftime(%b)}/{strftime(%d)}/{uuid}.{record_ext})
2023-04-27 11:48:12.400449 91.20% [ERR] switch_core_file.c:346 Invalid file format [{record_ext}] for [/var/lib/freeswitch/recordings/pbx.example.com/archive/{strftime(%Y)}/{strftime(%b)}/{strftime(%d)}/{uuid}.{record_ext}]!
81e428dc-ab0a-4428-a404-d1aed9cdc2c2 2023-04-27 11:48:12.400449 91.20% [ERR] switch_ivr_async.c:3135 Error opening /var/lib/freeswitch/recordings/pbx.example.com/archive/{strftime(%Y)}/{strftime(%b)}/{strftime(%d)}/{uuid}.{record_ext}
I believe these two bogus entries have something in common. (And I should say it actually had created a file exactly, literally like that: `/var/lib/freeswitch/recordings/pbx.example.com/archive/{strftime(%Y)}/{strftime(%b)}/{strftime(%d)}/{uuid}.{record_ext}`
