| Summary: | ASTERISK-15862: [patch] Memory Leak in app_queue | ||||
| Reporter: | Wolfgang Liegel (wliegel) | Labels: | |||
| Date Opened: | 2010-03-23 07:12:46 | Date Closed: | 2010-05-21 16:57:28 | ||
| Priority: | Major | Regression? | No | ||
| Status: | Closed/Complete | Components: | Applications/app_queue | ||
| Versions: | Frequency of Occurrence | ||||
| Related Issues: |
| ||||
| Environment: | Attachments: | ( 0) 17081v2.patch ( 1) queue_mem_allocations.txt ( 2) queue_mem_check_output.txt ( 3) queue_mem_check.sh ( 4) valgrind.txt | |||
| Description: | Hello, on a system with lots of realtime queues I have a problem with very high memory consumption in app_queue. According to "memory show summary", there is a high number of allocations in /usr/src/asterisk-1.6.0.26/include/asterisk/strings.h:390 (>5.000.000 allocations per Day) as well as high memory consumption in app_queue.c:1449 in only a few allocations (>1GB in 778 allocations). This issue is simply reproducible by typing "queue show" several times in the cli and watch the allocation summary. The more (realtime?)queues are configured the faster grows the memory consumption after each "queue show" command. ****** ADDITIONAL INFORMATION ****** This issue seems to be in all 1.6 Versions. I also checked this issue with 1.6.0.3, 1.6.0.7, 1.6.0.25 and 1.6.1.18. | ||||
| Comments: | By: Leif Madsen (lmadsen) 2010-03-23 09:35:19 I'm not too sure what to ask for here, but it may be requested that you provide some valgrind output while this is happening. You can check the doc/valgrind.txt file in your Asterisk source for more information. By: Wolfgang Liegel (wliegel) 2010-03-29 06:45:18 I uploaded the requested valgrind.txt file with options --leak-check=full -v --log-fd=9 During operation no output was written to this file. I entered about 5000 times "queue show" and shut down the asterisk process. You can see in the summary section, that there are are a lot of allocations left during asterisk shutdown. By: Leif Madsen (lmadsen) 2010-03-31 10:36:01 OK thanks for gathering that information. It will be attended to as soon as time and resources become available for a developer to move this forward. By: Mark Michelson (mmichelson) 2010-05-04 16:10:53 Well, I certainly am seeing memory usage increase as I run the "queue show summary" command more. I'll let you know when I have a patch for this. By: Mark Michelson (mmichelson) 2010-05-04 16:42:28 I have uploaded 17081.diff to this issue. I found that there were several calls to ast_str_create whenever I would execute the "queue show" CLI command. This was because when realtime queues are loaded, we start by placing all configurable values at their default using a function called init_queue. init_queue had a bug where rather than simply resetting the ast_str buffer that was already allocated, it would reallocate the data, thus causing the previously allocated data to leak. As you pointed out, if you have a lot or realtime queues, the number of allocations can climb FAST. You also mentioned that you were seeing allocations at line 1449 of app_queue. The first time that I ran "queue show" I noticed the number of allocations jump up here. This is because when you run "queue show" all realtime queues are loaded at the time so that information can be printed about them. However, each subsequent call to "queue show" will not result in more allocations for realtime queues that were found previously. Please let me know if the patch appears to fix things for you. By: Wolfgang Liegel (wliegel) 2010-05-05 17:02:39 I set up a test environment with 40 realtime queues patched with your changes. Your patch seems to fix the string allocations problem. The string allocations didn't increase within 2100 "queue show" commands. But there's still an increasing amount of allocations in app_queue.c at line 1449 (line 1454 after patching app_queue.c). I uploaded a simple script which you can use to check the allocations at app_queue.c queue_mem_check_output.txt contains the ouput of this script. In queue_mem_allocations.txt you can see the memory allocations after 2100 times running "queue show". By: Mark Michelson (mmichelson) 2010-05-06 15:13:46 Okay, I believe I have this figured out, and let's just say it's a bit on the bizarre side. First off, this technically isn't a memory leak, but an abuse of a handy facility in Asterisk. Asterisk has an API for string fields. Essentially, if a structure has a lot of strings within it, we allocate a single block of memory to house these strings. In the interest of simplicity, if a string must be resized to be larger than it previously was, then we just move the string to the next section of the memory block that is available. If there is not a space large enough, then we allocate a new block of memory that is twice the size of the previous block. On the other hand, if a string is shortened, we simply leave it where it currently is. The API is simple and is designed for cases where a string will be set once and changed maybe once or twice during the lifetime of the structure. There is an issue that occurs if we constantly are resizing the same string. So let's say we initialize the string with a length of 10. Now, later, we resize it to size 5. Since the string is now smaller, it can stay where it is. Now, here's the bad part. If we once again try to set the string's size to 10, the API sees that the string has a length of 5 and then moves the string to the next available section in the memory block. Now, consider that this operation gets repeated often. Eventually, there's no place to put the 10 byte string, so a new block gets allocated at twice the original block's size. Now consider that this happens 2100 times in a row... At first when I ran your script, I was not seeing the same result you were. Then I changed all my realtime queues to have their "queue_thankyou" string set to "beep." Doing this caused me to see the issue. The reason is that every time "queue show" is used at the CLI, all realtime queues are loaded. When this happens, we initialize all queue components to their defaults. So the queue_thankyou option is initialized to "queue-thankyou." Then, after that, all values specified in the realtime backend are overridden, so the queue_thankyou sound gets changed to "beep." Now the next time that "queue show" is run, the queue_thankyou sound is changed to "queue-thankyou" and then back to "beep" again. So now that I can reproduce the problem, I just need to actually write a fix. Likely what I will do is just change queues to not use string fields since they are not a good fit for queues. By: Mark Michelson (mmichelson) 2010-05-06 15:14:32 I'm not sure why Mantis decided to post my note twice. Don't try to comb through and look for differences; they're identical :) By: Mark Michelson (mmichelson) 2010-05-06 16:30:43 I added a new file, 17081v2.patch, to this issue. It contains both the first patch that I uploaded as well as the string field change I outlined in my last note. Please give this a try and let me know if it helps out. I ran your script with my queues and encountered no new allocations as the script went on. I will be deleting the original patch I uploaded since its contents are included in the new patch. By: Wolfgang Liegel (wliegel) 2010-05-09 15:54:56 Thanks for the patch. In my test environment it works great. None of the allocations are increasing anymore. I'll test your patch on a system with real users for a few days. By: Leif Madsen (lmadsen) 2010-05-10 11:06:42 Duplicate note deleted ;) By: Digium Subversion (svnbot) 2010-05-21 16:57:24 Repository: asterisk Revision: 265172 U branches/1.6.2/apps/app_queue.c ------------------------------------------------------------------------ r265172 | mmichelson | 2010-05-21 16:57:24 -0500 (Fri, 21 May 2010) | 53 lines Fix memory hogging behavior of app_queue. From reviewboard: This review request is for the patch on issue 17081. A user reported that he saw increasing numbers of allocations stemming from app_queue.c when he would run the "queue show" CLI command. The user reported that he was using approximately 40 realtime queues and as he ran the CLI command more and more, the memory usage would shoot up. As it turns out, there was a memory leak and a separate usage of memory that, while not really a leak, was very irresponsible. Both memory problems can be attributed to the function init_queue(). When the "queue show" command is run, all realtime queues have the init_queue() function called on the in-memory queue. The idea is to place the queue in its default state and then overwrite options specified in the realtime backend as we read them. The first problem, the memory leak, had to do with the fact that the string field for the name of the first periodic announcement file was being re-created every time init_queue was called. This patch corrects the behavior by only calling ast_str_create if the memory has not already been allocated. The other problem is a bit more complicated. The majority of the strings in the call_queue structure were changed to use the ast_string_fields API for 1.6.0 and beyond. init_queue resets all string fields on the queue to their default values. Then, later in the realtime queue loading process, these string fields are set to their configured values. For those unfamiliar with string fields, frequent resizing of a string like this is not what the string fields API is designed for. The result of this constant resizing is that as the queue gets loaded, eventually space for the string runs out and so a new memory pool, at twice the size of the previously allocated one, is created for the string fields. The reporter of issue 17081 wrote a script that ran the "queue show" CLI command 2100 times. By the end, each of his 40 queues was taking about a megabyte of memory apiece just for their string fields. My fix for this problem is to revert the call_queue structure from using string fields. In my patch here, I have moved the queue back to using fixed-sized buffers. I ran the script provided by the reporter of 17081 and determined that I no longer saw the steadily-increasing memory usage that I had seen before applying the patch. (closes issue ASTERISK-15862) Reported by: wliegel Patches: 17081v2.patch uploaded by mmichelson (license 60) Tested by: wliegel, mmichelson Review: https://reviewboard.asterisk.org/r/651/ ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=265172 | ||||