[Home]

Summary:ASTERISK-29302: res_ari: Format cache FRACK when invoking operations
Reporter:Igor Yeroshev (Igor_Ye)Labels:
Date Opened:2021-02-19 02:34:41.000-0600Date Closed:
Priority:MinorRegression?
Status:Open/NewComponents:Resources/res_ari
Versions:18.1.0 18.1.1 18.2.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:RHEL8Attachments:( 0) 24.02.2021.7z
( 1) extensions.conf
( 2) messages.7z
Description:Hello!
We try to implement auto dialer with Asterisk ARI Interface.
When we start calling after several calls we receive Errors
[Feb 17 10:35:03] ERROR[749178] format_cache.c: FRACK!, Failed assertion bad magic number 0x0 for object 0x11a8ff8 (0)
[Feb 17 10:35:03] ERROR[749178] : Got 13 backtrace records
Problem occurs on 18.1.0, 18.1.1, 18.2.0 versions.

After this errors asterisk was restarted.
We make this POST requests to make a call.
1. POST /ari/bridges?type=mixing (x2)
2. POST /ari/channels/create
3. POST /ari/channels/variable (x5)
4. POST /ari/channels/externalMedia
5. POST /ari/channels/snoop
6. POST /ari/bridges/addChannel (x3) 7
7. POST /ari/channels/dial
8. POST /ari/bridges/record
9. POST /ari/bridges/play (cycle)
10. DELETE /ari/channels
11. DELETE /ari/bridges (x2)
Full log in attach.
We can reproduce this problem.
Comments:By: Asterisk Team (asteriskteam) 2021-02-19 02:34:43.651-0600

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.

Please note that by submitting data, code, or documentation to Sangoma through JIRA, you accept the Terms of Use present at [https://www.asterisk.org/terms-of-use/|https://www.asterisk.org/terms-of-use/].
By: Joshua C. Colp (jcolp) 2021-02-19 04:02:11.915-0600

Can you please provide precise ARI routes that are invoked including arguments and configuration for reproducing this issue?
By: Igor Yeroshev (Igor_Ye) 2021-02-19 06:13:16.545-0600

1. POST http://10.34.190.55:8088/ari/bridges?type=mixing
       Create first bridge for customer channel
2. POST http://10.34.190.55:8088/ari/bridges?type=mixing
       Create second bridge for ExternalMedia Channel
3. POST http://10.34.190.55:8088/ari/channels/create?endpoint=Local%2F87012457124%40cce&app=ari-satan&channelId=out-87012457124-503297
       Create channel for customer
4. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=callId&value=20212171035287086706070
5. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=phoneNumber&value=87012457124
6. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=treeName&value=SoftCollectionTodayNotification
7. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=contractId&value=1-AXYVJID
8. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=companyId&value=101548
       Set up variables to customer channel

9. POST http://10.34.190.55:8088/ari/channels/externalMedia?app=ari-satan&external_host=172.23.34.19%3A16384&encapsulation=rtp&transport=udp&connection_type=client&format=slin&direction=both
       Create channel for ExternalMedia
10. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/snoop?spy=in&whisper=out&app=ari-satan
       Create Snoop channel for customer channel

11. POST http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac/addChannel?channel=out-87012457124-503297
       Add customer channel for first bridge
12. POST http://10.34.190.55:8088/ari/bridges/7c53e8ec-9ed6-47f9-b685-280e0b86b2aa/addChannel?channel=1613536503.585
13. POST http://10.34.190.55:8088/ari/bridges/7c53e8ec-9ed6-47f9-b685-280e0b86b2aa/addChannel?channel=1613733756.323
Add ExternalMedia channel and Snoop channel for second bridge

14. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/dial
Make Dial for customer channel
15. POST http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac/record?name=20212171035287086706070&format=wav&ifExists=fail&terminateOn=none
Enable recording for customer bridge
16. POST http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac/play?media=sound%3A%2Fdata%2Fdm%2Fh5sXN9UNx0V3ft56qKtn2mDHQtNJUH6e
Playing some prompts in customer bridge depending on customer says

17. DELETE http://10.34.190.55:8088/ari/channels/1613536503.585
18. DELETE http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac
19. DELETE http://10.34.190.55:8088/ari/bridges/7c53e8ec-9ed6-47f9-b685-280e0b86b2aa
Clear all channels and bridges after we detect that customer Hangup the call

We use ExternalMedia to to get the voice of the client on our ASR platform.
For this we use second bridge and Snoop on the customer channel.
We can make 10-15 calls and they comleat successfully but suddenly we recve FRACK Error and after some time (1or 2 minutes) asterisk restarts.
We can't understand why it happens.
Also I have add to attachments extensions.conf file.
If you need additional information such as configuration files of asterisk or something else we are ready to provide this.
Thank you.
By: Joshua C. Colp (jcolp) 2021-02-19 06:24:36.583-0600

Did this suddenly start happening when you started using functionality, or is this usage completely new? (I'm trying to determine if there's something specific or not)
By: Igor Yeroshev (Igor_Ye) 2021-02-21 01:30:06.115-0600

It's our new development. When we was make a tests it's looked like all is fine. But when we start to make more calls we got this error. We can get this error after first call or after 10 or 20 calls.
By: Joshua C. Colp (jcolp) 2021-02-22 03:39:22.468-0600

Is it possible for you to reduce usage of specific parts in an effort to isolate the specific issue? For example, not using external media or snoop temporarily. If the issue doesn't occur then it's due to that functionality or an interaction with it.
By: Igor Yeroshev (Igor_Ye) 2021-02-24 02:56:47.963-0600

Hello,
Today we was  try to disable the second bridge and snoop for customer channel
But result the same.
We have started to get error after second call.
New log for this I have attached.
By: Joshua C. Colp (jcolp) 2021-02-24 03:46:54.440-0600

What does this put the API calls down to?
By: Igor Yeroshev (Igor_Ye) 2021-02-24 04:33:11.972-0600

Sorry, I didn't quite understand your question
In logs I see that the first FRACK error appears after this request
[Feb 24 11:01:46] DEBUG[917072] http.c: HTTP Request URI is /ari/channels/create?endpoint=Local/87066661337@cce&app=ari-satan&channelId=out-87066661337-906409
It is a request to craeate a channel for first call.
After that we can put this call to bridge, start recording, and play promts for this call.
After first call we had restart our application and make the second call.
In logs I see that second call start calling too.
Because Dial is executed, but I don't see this call on our next device "cusp"
[Feb 24 11:13:13] VERBOSE[917940][C-00000032] pbx.c: Executing [87066661337@cce:9] Dial("Local/87066661337@cce-0000006f;2", "PJSIP/87066661337@cusp,32") in new stack
After 5 seconds in 11:13:18 Asterisk was restarted
So, I can say that API calls works after we recieve first error.
By: Joshua C. Colp (jcolp) 2021-02-24 04:39:51.193-0600

Previously you gave a list of the POST and DELETE requests with values, I was referring to what that looks like when you are still experiencing the issue - what exactly did you remove?
By: Igor Yeroshev (Igor_Ye) 2021-02-24 04:54:03.990-0600

We remoove this requests
2. POST http://10.34.190.55:8088/ari/bridges?type=mixing
10. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/snoop?spy=in&whisper=out&app=ari-satan

This 2 requests which add snoop channel and external media channel to the second bridge, we replaced with one request to add externall media channel to bridge with customer channel
12. POST http://10.34.190.55:8088/ari/bridges/7c53e8ec-9ed6-47f9-b685-280e0b86b2aa/addChannel?channel=1613536503.585
13. POST http://10.34.190.55:8088/ari/bridges/7c53e8ec-9ed6-47f9-b685-280e0b86b2aa/addChannel?channel=1613733756.323

For now it look like this list
1. POST http://10.34.190.55:8088/ari/bridges?type=mixing
Create first bridge for customer channel
2. POST http://10.34.190.55:8088/ari/channels/create?endpoint=Local%2F87012457124%40cce&app=ari-satan&channelId=out-87012457124-503297
Create channel for customer
3. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=callId&value=20212171035287086706070
4. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=phoneNumber&value=87012457124
5. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=treeName&value=SoftCollectionTodayNotification
6. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=contractId&value=1-AXYVJID
7. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/variable?variable=companyId&value=101548
Set up variables to customer channel

8. POST http://10.34.190.55:8088/ari/channels/externalMedia?app=ari-satan&external_host=172.23.34.19%3A16384&encapsulation=rtp&transport=udp&connection_type=client&format=slin&direction=both
Create channel for ExternalMedia

9. POST http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac/addChannel?channel=out-87012457124-503297
Add customer channel for first bridge
10. POST http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac/addChannel?channel=1613733756.323
Add ExternalMedia channel for first bridge

11. POST http://10.34.190.55:8088/ari/channels/out-87012457124-503297/dial
Make Dial for customer channel
12. POST http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac/record?name=20212171035287086706070&format=wav&ifExists=fail&terminateOn=none
Enable recording for customer bridge
13. POST http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac/play?media=sound%3A%2Fdata%2Fdm%2Fh5sXN9UNx0V3ft56qKtn2mDHQtNJUH6e
Playing some prompts in customer bridge depending on customer says

14. DELETE http://10.34.190.55:8088/ari/channels/1613536503.585
15. DELETE http://10.34.190.55:8088/ari/bridges/6419fddc-ede2-4d4d-85f2-ce09e6b46cac

By: Igor Yeroshev (Igor_Ye) 2021-03-01 00:51:24.576-0600

Hello!
Can you advise what else we can do in this situation?
What this errors with FRACK messege means?
By: Joshua C. Colp (jcolp) 2021-03-01 03:33:50.505-0600

The FRACK means that something was freed and then was used, which is problematic. As to why - until someone digs deeply into this, I don't know.
By: Sanat Aliyev (alvsnt) 2021-03-09 23:20:47.524-0600

Hi Joshua
It seems like error was caused by 8. POST http://10.34.190.55:8088/ari/channels/externalMedia?app=ari-satan&external_host=172.23.34.19%3A16384&encapsulation=rtp&transport=udp&connection_type=client&format=slin&direction=both request
We changed format parameter from slin to ulaw and crashes disappeared
Maybe it would help somewhere somehow