[Home]

Summary:ASTERISK-13721: memory leak in "strings.c"
Reporter:pj (pj)Labels:
Date Opened:2009-03-10 05:59:43Date Closed:2011-07-26 15:09:25
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_skinny
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 20090310__debug_14636__2.diff.txt
( 1) 20090310__debug_14636.diff.txt
( 2) 20090313__debug_bug14636.diff.txt
( 3) 20090316__bug14636.diff.txt
( 4) 20090319__debug_bug14636.diff.txt
( 5) memory.zip
( 6) memory2.zip
( 7) memory3.zip
( 8) memory4.zip
( 9) memory5.zip
(10) memory6.zip
(11) memory7.zip
Description:memory allocations for strings.c continuously growing,
after 4 days uptime and small amout of call processed,
my asterisk eats 120MB of RAM.

mmlog is empty

*CLI> core show calls uptime
0 active calls
320 calls processed
System uptime: 4 days, 15 hours, 32 minutes, 58 seconds



****** ADDITIONAL INFORMATION ******

asterisk  6165  1.7 12.9 118684 16080 pts/2    Sl   Mar05 115:22  \_ asterisk -vvv -c
Comments:By: Tilghman Lesher (tilghman) 2009-03-10 13:06:09

Please re-run your memory statistics, with this patch applied.  This will show where the actual memory leak is occurring.  strings.c is merely a set of utility functions for managing memory.
By: pj (pj) 2009-03-10 14:40:06

What should I see different with your patch applied? I have apply this patch and strings.c isn't at all in 'memory show summary' output.
uploading new output from asterisk with patch applied - memory2.zip
By: Tilghman Lesher (tilghman) 2009-03-10 18:44:31

Yep, it moves the tracking of the memory allocations to the module which actually made the allocation request.  Here is yet a further patch, which should start showing which modules are actually requesting the memory used.
By: Digium Subversion (svnbot) 2009-03-10 19:30:00

Repository: asterisk
Revision: 181028

U   trunk/include/asterisk/astobj2.h
U   trunk/include/asterisk/hashtab.h
U   trunk/include/asterisk/heap.h
U   trunk/include/asterisk/strings.h
U   trunk/main/astobj2.c
U   trunk/main/hashtab.c
U   trunk/main/heap.c
U   trunk/main/strings.c

------------------------------------------------------------------------
r181028 | tilghman | 2009-03-10 19:29:59 -0500 (Tue, 10 Mar 2009) | 3 lines

Add MALLOC_DEBUG to various utility APIs, so that memory leaks can be tracked back to their source.
(related to issue ASTERISK-13721)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=181028
By: Digium Subversion (svnbot) 2009-03-10 19:30:56

Repository: asterisk
Revision: 181030

_U  branches/1.6.1/

------------------------------------------------------------------------
r181030 | tilghman | 2009-03-10 19:30:55 -0500 (Tue, 10 Mar 2009) | 13 lines

Blocked revisions 181027-181028 via svnmerge

........
 r181027 | tilghman | 2009-03-10 19:28:28 -0500 (Tue, 10 Mar 2009) | 2 lines
 
 Spacing changes only
........
 r181028 | tilghman | 2009-03-10 19:29:59 -0500 (Tue, 10 Mar 2009) | 3 lines
 
 Add MALLOC_DEBUG to various utility APIs, so that memory leaks can be tracked back to their source.
 (related to issue ASTERISK-13721)
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=181030
By: pj (pj) 2009-03-11 09:03:08

I have tried fresh svn (revision that should contain your patch), but asterisk always segfault during startup. This is preliminary notice, I will try next during off-hours more thoroughly.
By: Tilghman Lesher (tilghman) 2009-03-11 12:06:06

Update again.  Apparently, astobj2.h debugging invokes a glibc bug in stdio, when called during a bootup sequence.
By: Tilghman Lesher (tilghman) 2009-03-13 11:24:05

Ping.  Any further testing?
By: pj (pj) 2009-03-13 14:10:42

memory3.zip contains memory statistic taken:
1) after asterisk start
2) after:
174 calls processed
System uptime: 1 day, 12 hours, 9 minutes, 23 seconds
By: Tilghman Lesher (tilghman) 2009-03-13 15:09:28

Okay, yet another debugging patch has been uploaded...
By: pj (pj) 2009-03-16 15:29:23

another memory statistic uploaded, memory4.zip, it's from:
Asterisk SVN-trunk-r182071 + 20090313__debug_bug14636.diff.txt

92 calls processed
System uptime: 2 days, 23 hours, 46 minutes
By: Tilghman Lesher (tilghman) 2009-03-16 17:31:45

Patch just uploaded should fix that leak.  Note that the last debug patch will probably also get committed, just in case more memory leaks show up in the future, but it may also be helpful in case this patch doesn't fix all of the potential leaks.
By: pj (pj) 2009-03-18 05:47:01

memory5.zip uploaded, it seems, that some modules still continually eating more and more memory (especially chan_sip, astobj2, pbx...)

0 active calls
70 calls processed
System uptime: 1 day, 1 hour, 58 minutes, 29 seconds

Asterisk SVN-trunk-r182450
+20090313__debug_bug14636.diff.txt
+20090316__bug14636.diff.txt
By: Tilghman Lesher (tilghman) 2009-03-18 12:28:24

To find the issue related to the astobj2 leak, please apply the debug patch from issue ASTERISK-13758
By: pj (pj) 2009-03-18 14:13:36

OK, I will try apply also patch from ASTERISK-1452680 and you will still working on another last discovered leaks?
By: pj (pj) 2009-03-18 14:25:53

it failed to apply debug patch from issue ASTERISK-137580,
tried patching asterisk svn trunk rev.182959

patching file include/asterisk/astobj2.h
Hunk #1 FAILED at 162.
Hunk #2 FAILED at 373.
Hunk #3 FAILED at 413.
3 out of 3 hunks FAILED -- saving rejects to file include/asterisk/astobj2.h.rej
patching file main/astobj2.c
Hunk #1 FAILED at 245.
Hunk #2 succeeded at 315 (offset 58 lines).
Hunk #3 FAILED at 398.
Hunk #4 FAILED at 453.
Hunk ASTERISK-1 succeeded at 519 (offset 107 lines).
3 out of 5 hunks FAILED -- saving rejects to file main/astobj2.c.rej
By: Tilghman Lesher (tilghman) 2009-03-19 10:02:36

Sorry about that.  astobj2 contains other debugging in trunk that made the patch unable to apply.  Here is a patch for trunk.
By: pj (pj) 2009-03-23 11:07:56

another set of memory statistics - memory6.zip,
you can compare what was allocated after asterisk start and after:
0 active calls
196 calls processed
System uptime: 4 days, 9 minutes, 55 seconds

after start, asterisk process eats about 22MB of RAM, now it's 58MB

Asterisk SVN-trunk-r183057
+ 20090319__debug_bug14636.diff.txt
+ 20090316__bug14636.diff.txt


By: pj (pj) 2009-03-23 11:18:07

I would also know, what all patches should I appply to discover this leaking, because last I applied only your last patch, but it seems, that it contain only debuging for astobj2 module, so should I still apply all your previous patches?
By: Tilghman Lesher (tilghman) 2009-03-23 11:25:32

I really don't think there's that much difficulty with the current statistics.  What I can consider memory leaks are all solved.  This ballooning of 22MB to 58MB is illusory, I believe, as most of the memory within that space is actually unallocated.  It was used while you were processing calls, but memory is never released back to the kernel, once allocated (until the process ends).  However, the memory is unlikely to increase beyond that 58MB, unless you throw a larger quantity of calls than you previously had at the system.
By: pj (pj) 2009-03-23 12:04:42

do you think, that "memory is never released back to the kernel" is correct? please keep in mind, that I never had more than three concurrent calls, so I don't know, why asterisk should eats more and more of ram and not reuse memory, that allocated before.
But anyway, please keep this bugreport open for some time, I will report back if I find something strange.
By: pj (pj) 2009-03-27 15:05:23

another statistics - memory7.zip
after about 400 calls processed, my asterisk eats almost 100MB of RAM, so I have really suspicion, that asterisk has still memory leak, because this huge memory consuption doesn't happened before.

0 active calls
393 calls processed
System uptime: 3 days, 21 hours, 50 minutes, 27 seconds

root     29900  0.0  0.0   3984    88 pts/2    S    Mar23   0:00 /bin/sh /etc/init.d/asterisk start
asterisk 29905  2.4 12.2  98048 15276 pts/2    Sl   Mar23 140:26  \_ asterisk -vvv -c
By: Tilghman Lesher (tilghman) 2009-03-28 11:39:09

What is the output of the following command:  cat /proc/`pidof asterisk`/status
By: pj (pj) 2009-03-28 14:42:27

Name:   asterisk
State:  S (sleeping)
Tgid:   29905
Pid:    29905
PPid:   29900
TracerPid:      0
Uid:    75      75      75      75
Gid:    75      75      75      75
FDSize: 256
Groups:
VmPeak:    98292 kB
VmSize:    98288 kB
VmLck:         0 kB
VmHWM:     15436 kB
VmRSS:      7196 kB
VmData:    86020 kB
VmStk:        88 kB
VmExe:      1688 kB
VmLib:      9496 kB
VmPTE:       108 kB
Threads:        17
SigQ:   0/1023
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000000001004
SigCgt: 0000000181414003
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000
CapBnd: ffffffffffffffff
voluntary_ctxt_switches:        12676
nonvoluntary_ctxt_switches:     1968
By: Tilghman Lesher (tilghman) 2009-04-03 15:47:02

At this point, I'm stumped.  Every memory access by the Asterisk code, other than that by the debugger itself, should be going through the MALLOC_DEBUG routines.  That it isn't suggests one of several possibilities:

1) The MALLOC_DEBUG routines are leaking (unlikely).
2) You have additional modules that were not compiled with MALLOC_DEBUG (for example, the addons) that are leaking.
3) One or more of the runtime libraries is itself leaking memory.

You can test the first one by shutting off MALLOC_DEBUG and see if it still leaks memory.  If it still does, then MALLOC_DEBUG is not the culprit.  I'm not sure what else we can do, though.
By: pj (pj) 2009-04-04 15:54:41

I'm using vanilla asterisk, ie. without addons modules, so I will try fresh trunk soon and compare results again, eventually I will try to compile without MALLOC_DEBUG enabled.
By: pj (pj) 2009-04-29 13:36:05

I tried Asterisk SVN-trunk-r190797 and seems, that it still leaking, next my try will be to compile without MALLOC_DEBUG enabled.
By: pj (pj) 2009-05-04 09:03:48

Asterisk SVN-trunk-r191136 compiled without MALLOC_DEBUG, still leaking:

0 active channels
0 active calls
107 calls processed

cat /proc/<pid>/status

VmPeak:    73460 kB
VmSize:    73456 kB
VmLck:         0 kB
VmHWM:     14760 kB
VmRSS:     14748 kB
VmData:    61580 kB
VmStk:        96 kB
VmExe:      1620 kB
VmLib:      9348 kB
VmPTE:        84 kB
Threads:        17
By: pj (pj) 2009-05-04 09:32:41

I wrote some hint in bugreport ASTERISK-12960 msg104091
By: Damien Wedhorn (wedhorn) 2009-05-04 16:16:19

pj, it's quite feasible that skinny is leaking some memory, especially considering your reset issues. indicate2 shouldn't be causing leaks, although it may stop a core dump which could allow a memory leak to exist ;)

Looking through your mem usage, it seems weird that you don't have more skinny sessions. Can you confirm you have 5 lines configured and 5 devices for configured for skinny. Also, it seems you only actually have one physical device, although it only shows up occasionally (3608 bytes allocated in        accept_thread at line  6428 of chan_skinny.c).

It's quite possible various stuff gets orphaned when your skinny device resets (and you seem to have a lot of those). Not sure I can be of much help, i've a gut feeling that not all the alloc's are recorded for some reason (either that or your skinny device spends more time disconnected than connected).
By: pj (pj) 2009-05-05 03:17:12

Right, I have only five skinny devices, almost all are 7920, only one to three are connected in one time, they are connected over wan.
Is quite curious, that skinny connections are reset so frequently and phone reregisters so often, because users connection should be stable (dsl).
By: pj (pj) 2009-05-12 13:48:33

today I haven't any skinny phones registered and memory consumption is exactly same as yesterday, so it seems, that chan_skinny is actually source of this leak, and especially the code, that handles phone unregistration. It seems, that memory leak occurs, when network connection between phone and asterisk brokes and phone periodically registers again (probably chan_skinny doesn't unfrees memory allocations from previous registration).
I think this issue can be easily moved into chan_skinny category.
Asterisk SVN-trunk-r191136
By: Leif Madsen (lmadsen) 2009-05-12 16:19:40

Reassigned to mvanbaak, hoping he can take a look at this in the near(ish) future.
By: Michiel van Baak (mvanbaak) 2009-05-13 01:52:26

I'm not sure it's caused by re-registration.
We load the skinny devices and lines in memory on module load, and a registration only sets some device/line struct members and does not really allocate new memory. (skinny_register on line 1812 in trunk as of now)

But, I'm not sure as I did not look much further into this issue at the moment.
We'll have to spend some more time on this one.
By: Michiel van Baak (mvanbaak) 2009-05-13 03:23:10

this does not mean it's not related to the device resets.
It probably has something to do with the sessions.

Will investigate later.
By: Russell Bryant (russell) 2011-07-26 15:09:00.294-0500

Per the Asterisk maintenance timeline page at http://www.asterisk.org/asterisk-versions maintenance (bug) support for the 1.4 and 1.6.x branches has ended. For continued maintenance support please move to the 1.8 branch which is a long term support (LTS) branch. For more information about branch support, please see https://wiki.asterisk.org/wiki/display/AST/Asterisk+Versions

If this is still an issue, please open a new issue so it can be re-triaged appropriately. Thanks!