Issues when saving call recording

[abuzooz]

Hi All

 

We are running kazoo version 4.3-126, we have the following call recording setting for our users to  get the recording to be uploaded to an external storage, as below.

 

Everything works just fine, however, sometimes, we encounter an issue  that the recording is not being uploaded and we notice that freeswitch in this case has the following error in its logs, any idea what is wrong here? the strange thing is, it is working many times and only having an issue randomly, I would say it fails 2 times out of 5.

2020-10-23 21:08:58.814190 92.10% [ERR] kazoo_commands.c:395 Received HTTP error 0 trying to save /tmp/3cbfd6241913cda2317d50cda2a90938.mp3 to http://d0f0148eb2da5499:7586908d6b54a522@ecallmgr2.xxxxx.com:24517/store/g2gEbQAAADdhY2NvdW50JTJGYmElMkY0NyUyRjc0ODQyZTU4NDBiMjljNWY2YWIxNzg0YWQxNzEtMjAyMDEwbQAAACcyMDIwMTAtZGY2N2Y4NjgyMjRiYTlkZWMzMDcxM2UzOTVhNjhhNDRtAAAAJDNjYmZkNjI0MTkxM2NkYTIzMTdkNTBjZGEyYTkwOTM4Lm1wM2wAAAACaAJkAAhkb2NfdHlwZW0AAAAOY2FsbF9yZWNvcmRpbmdoAmQADXBsYW5fb3ZlcnJpZGV0AAAAA2QAC2F0dF9oYW5kbGVyaAJkAAtrel9hdHRfaHR0cHQAAAAEZAAKZmllbGRfbGlzdGwAAAATbQAAAA9jYWxsX3JlY29yZGluZ19oAmQABWZpZWxkbQAAAAdjYWxsX2lkbQAAAAUuLm1wM20AAAAGP2Zyb209aAJkAAVmaWVsZG0AAAAEZnJvbW0AAAAEJnRvPWgCZAAFZmllbGRtAAAAAnRvbQAAABAmY2FsbGVyX2lkX25hbWU9aAJkAAVmaWVsZG0AAAAOY2FsbGVyX2lkX25hbWVtAAAAEiZjYWxsZXJfaWRfbnVtYmVyPWgCZAAFZmllbGRtAAAAEGNhbGxlcl9pZF9udW1iZXJtAAAACSZjYWxsX2lkPWgCZAAFZmllbGRtAAAAB2NhbGxfaWRtAAAACCZjZHJfaWQ9aAJkAAVmaWVsZG0AAAAGY2RyX2lkbQAAABAmaW50ZXJhY3Rpb25faWQ9aAJkAAVmaWVsZG0AAAAOaW50ZXJhY3Rpb25faWRtAAAADCZhY2NvdW50X2lkPW0AAAAgYmE0Nzc0ODQyZTU4NDBiMjljNWY2YWIxNzg0YWQxNzFqZAAPZmllbGRfc2VwYXJhdG9ybQAAAABkAAN1cmxtAAAAMWh0dHBzOi8vZHctcmVjb3JkaW5ncy5zMy11cy13ZXN0LTEuYW1hem9uYXdzLmNvbS9kAAR2ZXJibQAAAANwdXRkABBhdHRfcG9zdF9oYW5kbGVyZAAIZXh0ZXJuYWxkAAlhdHRfcHJveHlkAAR0cnVlag%3D%3D/3cbfd6241913cda2317d50cda2a90938.mp3

Edited October 23, 2020 by abuzooz (see edit history)

[mc_]

You'll need to check the KAZOO logs for that mp3 filename to see what kz_att_* logs might have to say.

[abuzooz]

well, basically I have 2 ecallmgr separate servers in my Kazoo cluster, working fine with no issues.

After checking the logs, I can see similar error in only one of the ecallmgr nodes, error message is identical to the one provided above which was showing on freeswitch server.

2020-10-23 21:08:58.814190 92.10% [ERR] kazoo_commands.c:395 Received HTTP error 0 trying to save /tmp/3cbfd6241913cda2317d50cda2a90938.mp3 to http://d0f0148eb2da5499:7586908d6b54a522@ecallmgr2.xxxxx.com:24517/store/g2gEbQAAADdhY2NvdW50JTJGYmElMkY0NyUyRjc0ODQyZTU4NDBiMjljNWY2YWIxNzg0YWQxNzEtMjAyMDEwbQAAACcyMDIwMTAtZGY2N2Y4NjgyMjRiYTlkZWMzMDcxM2UzOTVhNjhhNDRtAAAAJDNjYmZkNjI0MTkxM2NkYTIzMTdkNTBjZGEyYTkwOTM4Lm1wM2wAAAACaAJkAAhkb2NfdHlwZW0AAAAOY2FsbF9yZWNvcmRpbmdoAmQADXBsYW5fb3ZlcnJpZGV0AAAAA2QAC2F0dF9oYW5kbGVyaAJkAAtrel9hdHRfaHR0cHQAAAAEZAAKZmllbGRfbGlzdGwAAAATbQAAAA9jYWxsX3JlY29yZGluZ19oAmQABWZpZWxkbQAAAAdjYWxsX2lkbQAAAAUuLm1wM20AAAAGP2Zyb209aAJkAAVmaWVsZG0AAAAEZnJvbW0AAAAEJnRvPWgCZAAFZmllbGRtAAAAAnRvbQAAABAmY2FsbGVyX2lkX25hbWU9aAJkAAVmaWVsZG0AAAAOY2FsbGVyX2lkX25hbWVtAAAAEiZjYWxsZXJfaWRfbnVtYmVyPWgCZAAFZmllbGRtAAAAEGNhbGxlcl9pZF9udW1iZXJtAAAACSZjYWxsX2lkPWgCZAAFZmllbGRtAAAAB2NhbGxfaWRtAAAACCZjZHJfaWQ9aAJkAAVmaWVsZG0AAAAGY2RyX2lkbQAAABAmaW50ZXJhY3Rpb25faWQ9aAJkAAVmaWVsZG0AAAAOaW50ZXJhY3Rpb25faWRtAAAADCZhY2NvdW50X2lkPW0AAAAgYmE0Nzc0ODQyZTU4NDBiMjljNWY2YWIxNzg0YWQxNzFqZAAPZmllbGRfc2VwYXJhdG9ybQAAAABkAAN1cmxtAAAAMWh0dHBzOi8vZHctcmVjb3JkaW5ncy5zMy11cy13ZXN0LTEuYW1hem9uYXdzLmNvbS9kAAR2ZXJibQAAAANwdXRkABBhdHRfcG9zdF9oYW5kbGVyZAAIZXh0ZXJuYWxkAAlhdHRfcHJveHlkAAR0cnVlag%3D%3D/3cbfd6241913cda2317d50cda2a90938.mp3

Is it related to authentication issues between freeswtich and ecallmanager2 maybe? I think that freeswitches are able to store recording files normally when they communicate with ecallmanager1 but when dealing with ecallmanager2 it gives this error.

What would be the issue in this case? how can I troubleshoot further?

[mc_]

In this case, the app `media_mgr` is setting up that URL to feed to FreeSWITCH for getting the recording off FreeSWITCH. Once received from FreeSWITCH, media_mgr will attempt to store the media to the configured backend.

So check any nodes where media_mgr is running (ensuring log level is debug) and you should see kz_att_* logs related to the attempt to upload the file to the storage backend.

[abuzooz]

Thank you @mc_ for the advise.

 

I enabled debug mode on Kazoo apps server and on ecallmanager servers, below are the logs I received when freeswitch throw the error for saving a recording file:

On EcallManager Server

First I received this error

Oct 27 17:24:48 ecallmgr2 2600hz[872]: |2235b4fc-931c-1239-808a-96000047b665|ecallmgr_call_control:1162(<0.20860.45>) sending execution error: [{<<"Msg-ID">>,<<"92c9f70a822734147e2fc87b6d21432e">>},{<<"Error-Message">>,<<"Could not execute dialplan action: bridge">>},{<<"Request">>,{[{<<"Export-Bridge-Variables">>,[<<"hold_music">>]},{<<"Timeout">>,20},{<<"Ignore-Forward">>,<<"false">>},{<<"Dial-Endpoint-Method">>,<<"simultaneous">>},{<<"Endpoints">>,[{[{<<"Endpoint-Actions">>,{[{<<"Execute-On-Answer">>,{[{<<"Record-Endpoint">>,{[{<<"Application-Name">>,<<"record_call">>},{<<"Record-Action">>,<<"start">>},{<<"Follow-Transfer">>,false},{<<"Time-Limit">>,3600},{<<"Media-Name">>,<<"67174e29afa55a3477a75518c0cc0516.mp3">>},{<<"Media-Recording-ID">>,<<"202010-291af209ed763ebffa284d3e6e2567bc">>},{<<"Media-Recording-Origin">>,<<"offnet">>},{<<"Media-Recording-Endpoint-ID">>,<<"ed4421e3c7d6d66f303279edce5cd322">>},{<<"Record-Min-Sec">>,<<"1">>},{<<"Media-Recorder">>,<<"kz_media_recording">>},{<<"Call-ID">>,<<"2235b4fc-931c-1239-808a-96000047b665">>},{<<"Msg-ID">>,<<"d746eea51d32d3d336333d33447b6a81">>},{<<"Server-ID">>,<<>>},{<<"Event-Category">>,<<"call">>},{<<"Event-Name">>,<<"command">>},{<<"App-Name">>,<<"kazoo_endpoint">>},{<<"App-Version">>,<<"4.3.120">>},{<<"Node">>,<<"kazoo_apps@kz-webhook.deskwaves.com">>}]}}]}}]}},{<<"To-Username">>,<<"yazan">>},{<<"To-User">>,<<"yazan">>},{<<"To-Realm">>,<<"atlantic.deskwaves.com">>},{<<"To-DID">>,<<"+972559664237">>},{<<"Presence-ID">>,<<"10080@atlantic.deskwaves.com">>},{<<"Privacy-Method">>,<<"kazoo">>},{<<"Outbound-Callee-ID-Number">>,<<"+972559664237">>},{<<"Outbound-Callee-ID-Name">>,<<"yazan inaimss">>},{<<"Ignore-Completed-Elsewhere">>,false},{<<"Endpoint-Timeout">>,<<"20">>},{<<"Custom-SIP-Headers">>,{[{<<"X-KAZOO-INVITE-FORMAT">>,<<"contact">>},{<<"X-KAZOO-AOR">>,<<"sip:yazan@atlantic.deskwaves.com">>}]}},{<<"Custom-Channel-Vars">>,{[{<<"SIP-Invite-Domain">>,<<"atlantic.deskwaves.com">>},{<<"Media-Encryption-Enforce-Security">>,false},{<<"Account-ID">>,<<"ba4774842e5840b29c5f6ab1784ad171">>},{<<"Owner-ID">>,<<"2399970e0db1a68698fd21ea0ec1999c">>},{<<"Authorizing-Type">>,<<"device">>},{<<"Authorizing-ID">>,<<"ed4421e3c7d6d66f303279edce5cd322">>}]}},{<<"Codecs">>,[<<"OPUS">>]},{<<"Callee-ID-Number">>,<<"+972559664237">>},{<<"Callee-ID-Name">>,<<"yazan inaimss">>},{<<"Invite-Format">>,<<"contact">>}]}]},{<<"Call-ID">>,<<"2235b4fc-931c-1239-808a-96000047b665">>},{<<"Application-Name">>,<<"bridge">>},{<<"Server-ID">>,<<"kazoo_apps@kz-webhook.deskwaves.com-cf_exe-<0.7347.234>-8f29a565">>},{<<"Node">>,<<"kazoo_apps@kz-webhook.deskwaves.com">>},{<<"Msg-ID">>,<<"92c9f70a822734147e2fc87b6d21432e">>},{<<"Event-Name">>,<<"command">>},{<<"Event-Category">>,<<"call">>},{<<"App-Version">>,<<"4.0.0">>},{<<"App-Name">>,<<"callflow">>}]}},{<<"Call-ID">>,<<"2235b4fc-931c-1239-808a-96000047b665">>},{<<"Custom-Channel-Vars">>,undefined},{<<"Server-ID">>,<<>>},{<<"Event-Category">>,<<"error">>},{<<"Event-Name">>,<<"dialplan">>},{<<"App-Name">>,<<"ecallmgr">>},{<<"App-Version">>,<<"4.0.0">>},{<<"Node">>,<<"ecallmgr@ecallmgr2.deskwaves.com">>},{<<"Disposition">>,<<"SUCCESS">>},{<<"Hangup-Cause">>,<<"NORMAL_CLEARING">>},{<<"Hangup-Code">>,<<"sip:200">>}]

 

Then I received this error on ecallmger when freeswitch throw error for saving the recording file

Oct 27 17:33:57 ecallmgr2 2600hz[872]: |89984f4d-04c2-457a-8224-0fc33ee9e5eb|kz_media_file:75(<0.22029.45>) building proxy URI: {<<"account%2Fba%2F47%2F74842e5840b29c5f6ab1784ad171-202010">>,<<"202010-d155b1aa71750e81de832d9cf2f6863b">>,<<"0d9845c26c117d17a911961435c9b1a5.mp3">>,[{rev,<<"1-35255159d3f4cfa13e14d8c0578e0c0b">>},{stream_type,<<"store">>},{doc_type,<<"call_recording">>},{plan_override,#{att_handler => {kz_att_http,#{field_list => [<<"call_recording_">>,{field,<<"call_id">>},<<"..mp3">>,<<"?from=">>,{field,<<"from">>},<<"&to=">>,{field,<<"to">>},<<"&caller_id_name=">>,{field,<<"caller_id_name">>},<<"&caller_id_number=">>,{field,<<"caller_id_number">>},<<"&call_id=">>,{field,<<"call_id">>},<<"&cdr_id=">>,{field,<<"cdr_id">>},<<"&interaction_id=">>,{field,<<"interaction_id">>},<<"&account_id=">>,<<"ba4774842e5840b29c5f6ab1784ad171">>],field_separator => <<>>,url => <<"https://dw-recordings.s3-us-west-1.amazonaws.com/">>,verb => <<"put">>}},att_post_handler => external,att_proxy => true}}]}
 

On Kazoo Apps server

This is the error shown in KazooApps server when freeswitch throw the error for saving the recording file

Oct 27 17:31:25 kz-webhook 2600hz[862]: |ebee3a7b9f867d2a8eb962652259bdd4|kzs_attachments:144(<0.10111.234>) using handler kz_att_http to store account%2Fba%2F47%2F74842e5840b29c5f6ab1784ad171-202010/202010-528e2fd62354fac43107aa0a034cdf1f/4952ca1fb10a41ee56243daa4f56b4f3.mp3
Oct 27 17:31:25 kz-webhook 2600hz[862]: |ebee3a7b9f867d2a8eb962652259bdd4|kz_att_http:49(<0.10111.234>) storing via put to https://dw-recordings.s3-us-west-1.amazonaws.com/call_recording_17c1dbd3-66dc-4b47-8c8b-1361ff211ba8..mp3?from=972599796989%40atlantic.deskwaves.com&to=10080%40atlantic.deskwaves.com&caller_id_name=972599796989&caller_id_number=972599796989&call_id=17c1dbd3-66dc-4b47-8c8b-1361ff211ba8&cdr_id=202010-17c1dbd3-66dc-4b47-8c8b-1361ff211ba8&interaction_id=63771039078-833e2b68&account_id=ba4774842e5840b29c5f6ab1784ad171

Edited October 27, 2020 by abuzooz (see edit history)

[mc_]

Yup so grep that kz_att_http PID '0.10111.234' to see more info.

But it looks like you're using the HTTP handler to put your recordings in AWS; perhaps you've misconfigured the storage plan to use http instead of s3?

[abuzooz]

@mc_ I am not getting kz_att_ for the faulty recordings, only for the one who succeeded, the only error I get is on ecallmgr server as below .

 

It is worth to mention that this used to work just fine before upgrading kazoo to version 4.3-126 and I am not using Kazoo storage configuration, I only set URL in recording settings and point it to my S3 bucket

 

2020-10-27 18:54:46.254175 93.10% [ERR] kazoo_commands.c:395 Received HTTP error 0 trying to save /tmp/de304538f3bc261e17ce7bd4fab50294.mp3 to http://d0f0148eb2da5499:7586908d6b54a522@ecallmgr.deskwaves.com:24517/store/g2gEbQAAADdhY2NvdW50JTJGYmElMkY0NyUyRjc0ODQyZTU4NDBiMjljNWY2YWIxNzg0YWQxNzEtMjAyMDEwbQAAACcyMDIwMTAtOTdjMjYyOTllYzRlNjkxN2ZlMjJiYjgwNGY1ZWYyYWFtAAAAJGRlMzA0NTM4ZjNiYzI2MWUxN2NlN2JkNGZhYjUwMjk0Lm1wM2wAAAACaAJkAAhkb2NfdHlwZW0AAAAOY2FsbF9yZWNvcmRpbmdoAmQADXBsYW5fb3ZlcnJpZGV0AAAAA2QAC2F0dF9oYW5kbGVyaAJkAAtrel9hdHRfaHR0cHQAAAAEZAAKZmllbGRfbGlzdGwAAAATbQAAAA9jYWxsX3JlY29yZGluZ19oAmQABWZpZWxkbQAAAAdjYWxsX2lkbQAAAAUuLm1wM20AAAAGP2Zyb209aAJkAAVmaWVsZG0AAAAEZnJvbW0AAAAEJnRvPWgCZAAFZmllbGRtAAAAAnRvbQAAABAmY2FsbGVyX2lkX25hbWU9aAJkAAVmaWVsZG0AAAAOY2FsbGVyX2lkX25hbWVtAAAAEiZjYWxsZXJfaWRfbnVtYmVyPWgCZAAFZmllbGRtAAAAEGNhbGxlcl9pZF9udW1iZXJtAAAACSZjYWxsX2lkPWgCZAAFZmllbGRtAAAAB2NhbGxfaWRtAAAACCZjZHJfaWQ9aAJkAAVmaWVsZG0AAAAGY2RyX2lkbQAAABAmaW50ZXJhY3Rpb25faWQ9aAJkAAVmaWVsZG0AAAAOaW50ZXJhY3Rpb25faWRtAAAADCZhY2NvdW50X2lkPW0AAAAgYmE0Nzc0ODQyZTU4NDBiMjljNWY2YWIxNzg0YWQxNzFqZAAPZmllbGRfc2VwYXJhdG9ybQAAAABkAAN1cmxtAAAAMWh0dHBzOi8vZHctcmVjb3JkaW5ncy5zMy11cy13ZXN0LTEuYW1hem9uYXdzLmNvbS9kAAR2ZXJibQAAAANwdXRkABBhdHRfcG9zdF9oYW5kbGVyZAAIZXh0ZXJuYWxkAAlhdHRfcHJveHlkAAR0cnVlag%3D%3D/de304538f3bc261e17ce7bd4fab50294.mp3
 

[abuzooz]

well, it seems that having couple of kazooApps servers and ecallmgr in the same cluster is not a good idea, this is what was causing the problem, when I turned off ecallmgr2 and kazooApps2 severs and left the cluster with 1 for each, everything worked fine!

Is it not recommended to have multiple kazooApps & ecallmgr in the same cluster?

[mc_]

Multiple instances of each app are definitely encouraged and supported!

Unfortunately I cannot think of why multiple instances might affect saving media. Would require more investigation for sure.

The basic idea is, when KAZOO is ready to store the recording, it builds a URL to a media_mgr instance for FreeSWITCH to stream the recording off the server to the media_mgr server. Once received, the process in media_mgr will 'save' the recording which should use your storage plan's config to save to the configured backend.

Hopefully you can use the mp3 filename to key in on logs on nodes running ecallmgr and media_mgr.

[tomas_]

Hi!

I've just set up a new cluster with Kazoo 4.3 and encountered this issue also. I noticed that the /tmp folder of Freeswitch server was filling up with a lot of call recordings (mp3 files), and found the "Received HTTP error 0 trying to save" error in Freeswitch logs. Also "Error Storing File" in Kazoo console log.
Also the recordings isn't found when trying to get them from recordings API.

It started when adding another Kazoo / Ecallmgr server, before that there was no issue at all. And it's only when Freeswitch tries to save the media to the new, second Kazoo / Ecallmgr server, it works perfect to the first one.

Somehow I noticed the "proxy_store_acls" setting in system_config/media (Bigcouch /_utils/document.html?system_config/media), and when adding the IP addresses for both Freeswitch servers there it seems that the problem is gone!
Needs some more testing to be sure, but all it seems like every recording is saved properly.

I haven't seen this in any docs or guides anywhere.

Br - Tomas

 

[RuhNet]

@tomas_ Was one of the FS IP addresses already there and not the other, or just the default 127.0.0.0/24 entry only?

[tomas_]

It was just the default:

[RuhNet]

And both Freeswitch servers were already previously added to both ecallmgr nodes? 
 

(Just trying to be clear on the scenario so I can avoid issues.)  :-)

Edited June 19, 2023 by RuhNet (see edit history)

[tomas_]

Yes, I'm quite sure I added both FS servers before making the change in System Config CouchDB

[RuhNet]

Ok yes that's very interesting. I'll have to add this to my notes.

[abuzooz]

On 4/2/2023 at 12:06 AM, tomas_ said:

Hi!

I've just set up a new cluster with Kazoo 4.3 and encountered this issue also. I noticed that the /tmp folder of Freeswitch server was filling up with a lot of call recordings (mp3 files), and found the "Received HTTP error 0 trying to save" error in Freeswitch logs. Also "Error Storing File" in Kazoo console log.
Also the recordings isn't found when trying to get them from recordings API.

It started when adding another Kazoo / Ecallmgr server, before that there was no issue at all. And it's only when Freeswitch tries to save the media to the new, second Kazoo / Ecallmgr server, it works perfect to the first one.

Somehow I noticed the "proxy_store_acls" setting in system_config/media (Bigcouch /_utils/document.html?system_config/media), and when adding the IP addresses for both Freeswitch servers there it seems that the problem is gone!
Needs some more testing to be sure, but all it seems like every recording is saved properly.

I haven't seen this in any docs or guides anywhere.

Br - Tomas

 

Well, we built a script to handle the stuck recordings under /tmp, will definitely give this a try! But how did you figure it out? 

 

Thanks mate