Help! define_method leaking procs...

[Jamis Buck]

A plea for help, here... The rails core team is hacking like mad this
weekend at RubyConf, and my assignment has been to track down and fix
the memory leak in development mode. Here's what is known about this
leak:

1. It only occurs in development mode (production mode does not
exhibit the leak)
2. It only occurs under FastCGI (running under WEBrick does not
exhibit the leak)
3. The leak is due to an accumulation of Proc objects used with
define_method, primarily in ActiveRecord (the define_method's in
question are used to create the dynamic "has_one", "belongs_to",
"has_many", and "habtm" accessors). The leak may also be due to
define_method's used in ActionMailer, as well.

The problem seems strangely nondeterministic. Although it is easily
reproducible, fixing it has been like a nightmare game of whack-a-
mole. I'll add a few lines of code somewhere to test a solution, and
the problem will go away, but moving those lines elsewhere in the
framework (even a line or two up or down) brings the problem back.
And what "fixes" one application's leak may have no effect at all on
another application. There _must_ be a sane solution, however,
because I have verified multiple times (in multiple applications)
that there are no leaks when running the same application under WEBrick.

The leak seems to be on the order of 10 procs per request, per
declared ActiveRecord association. (Basecamp, as an example, leaks
about 200 procs per request in development mode. A minimal app I
wrote to reproduce the problem, with two AR subclasses with one
association each, leaks 20 procs per request.)

I won't spam the lists with additional details, but if anyone is
feeling particularly noble (and brave), please contact me off list
and I'll give you as much information about this as you can handle.
(You'll need to have edge rails and fastcgi working, either with
lighttpd or apache. I can provide you with a sample app to play with,
which requires sqlite.)

- Jamis

 

[Ryan Davis]

A plea for help, here... The rails core team is hacking like mad
this weekend at RubyConf, and my assignment has been to track down
and fix the memory leak in development mode. Here's what is known
about this leak:

1. It only occurs in development mode (production mode does not
exhibit the leak)
2. It only occurs under FastCGI (running under WEBrick does not
exhibit the leak)
3. The leak is due to an accumulation of Proc objects used with
define_method, primarily in ActiveRecord (the define_method's in
question are used to create the dynamic "has_one", "belongs_to",
"has_many", and "habtm" accessors). The leak may also be due to
define_method's used in ActionMailer, as well.

Someone on IRC made this claim a while ago so I looked into it. Doing
tens of thousands of define_methods certainly increased the memory
footprint, but explicit calls to GC.start every 100 calls or so kept
it to a bare minimum. I don't think it is a real leak, but I could be
wrong. I can talk to you about it in more depth if you grab me later
today or tomorrow.

 

[Yukihiro Matsumoto]

Hi,

In message "Re: Help! define_method leaking procs..."

|Someone on IRC made this claim a while ago so I looked into it. Doing
|tens of thousands of define_methods certainly increased the memory
|footprint, but explicit calls to GC.start every 100 calls or so kept
|it to a bare minimum. I don't think it is a real leak, but I could be
|wrong. I can talk to you about it in more depth if you grab me later
|today or tomorrow.

Since define_method creates reference to the block (a closure) which
holds reference to the variables in the external scope. So that if
it's not a real memory leak, isolating define_method with block by a
separate method may help, e.g. changing

define_methodfoo){...}

to

def def_something(name)
define_method(name){...}
end
...
def_somethingfoo)

matz.

 

[Eric Mahurin]

=20
On Oct 15, 2005, at 11:36 AM, Jamis Buck wrote:
=20
=20
Someone on IRC made this claim a while ago so I looked into
it. Doing =20
tens of thousands of define_methods certainly increased the
memory =20
footprint, but explicit calls to GC.start every 100 calls or
so kept =20
it to a bare minimum. I don't think it is a real leak, but I
could be =20
wrong. I can talk to you about it in more depth if you grab
me later =20
today or tomorrow.

Take a look at this thread:

http://groups.google.com/group/comp.lang.ruby/browse_thread/thread/3ad495=
07f2086e22/ac92a1373161035e?q=3Dmahurin&rnum=3D4#ac92a1373161035e

I demonstrated some example code with a memory leak with
lambdas.



=09
__________________________________=20
Yahoo! Music Unlimited=20
Access over 1 million songs. Try it free.
http://music.yahoo.com/unlimited/

 

[ES]

Take a look at this thread:

http://groups.google.com/group/comp...1373161035e?q=mahurin&rnum=4#ac92a1373161035e

I demonstrated some example code with a memory leak with
lambdas.

I still do not think this is a memory leak. It is, perhaps, memory
that the implementer may not realize will be consumed but its
whereabouts are known and it is accessible.

E

 

[Eric Mahurin]

http://groups.google.com/group/comp.lang.ruby/browse_thread/thread/3ad495=
07f2086e22/ac92a1373161035e?q=3Dmahurin&rnum=3D4#ac92a1373161035e
=20
I still do not think this is a memory leak. It is, perhaps,
memory
that the implementer may not realize will be consumed but its
whereabouts are known and it is accessible.
=20
E

So you definition of "memory leak" says that it is not a memory
leak if the unused memory can still be freed by the program.=20
With the example I gave, you could still free the memory using
the Proc#binding with eval to assign the unused variables to
nil. But, here is a slightly modified example where (using
#define_method) where you lose this access:

n=3D2**13;(1..n).each{|i|
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 172028 kB

As far as I know, you can't access any of thoses a's after you
get out of the each loop. I call that a memory leak by any
definition.

Here is the fixed version:

ruby -e '
n=3D2**13;(1..n).each{|i|
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=3Dnil};GC=
start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 11504 kB



=09
__________________________________=20
Yahoo! Music Unlimited=20
Access over 1 million songs. Try it free.
http://music.yahoo.com/unlimited/

 

[Yohanes Santoso]

n=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 172028 kB

ruby -e '
n=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=nil};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 11504 kB

Stop right there. I want to remind people that you can't use VmSize as
a leak indicator. In some OS, VmSize is an always increasing
number. Memory allocated in a process is not returned to the OS until
the process dies.

Here is a C program that free() every malloc(), yet still have
outrageous VmSize;

ysantoso@jenny:/tmp$ gcc -W -Wall ./leak.c -o leak && ./leak immed && ./leak not_immed
Freeing immediately
----BEFORE----
malloc count = 0
free count = 0
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 364 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
unwinding
----AFTER-----
malloc count = 8193
free count = 8193
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 440 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Not freeing immediately
----BEFORE----
malloc count = 0
free count = 0
VmSize: 1568 kB
VmLck: 0 kB
VmRSS: 364 kB
VmData: 156 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
unwinding
freeing 8192 elements
----AFTER-----
malloc count = 8193
free count = 8192
VmSize: 206360 kB
VmLck: 0 kB
VmRSS: 205280 kB
VmData: 204948 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 216 kB
ysantoso@jenny:/tmp$ cat ./leak.c
#include <stdio.h>
#include <stdlib.h>
#include <string.h>

int malloc_count = 0;
int free_count = 0;

void *
counting_malloc(size_t size)
{
malloc_count++;
return malloc(size);
}

void
counting_free(void *ptr)
{
free_count++;
if (ptr == NULL) {
fprintf(stderr, "Warning: free-ing NULL pointer\n");
}
free(ptr);
}

void
display_vminfo()
{
FILE *status = fopen("/proc/self/status", "r");
char line[132];
while (fgets(line, 132, status)) {
if (strstr(line, "Vm") == line) {
printf(line);
}
}
fclose(status);
}

/* allocs about 200M of mem. if free_immed_p, then memory allocated is free()ed immediately */
void
leak_test(int free_immed_p)
{
int i, j;
char **array = NULL;
int max_array_idx = -1;
int max_array_size = 8192;
int element_size = 25*1024;
array = counting_malloc(max_array_size * sizeof(char*));
if (!array) {
fprintf(stderr, "Unable to malloc\n");
goto die;
}
for (i=0; i < max_array_size; i++) {
char *element = counting_malloc(element_size);
if (!element) {
fprintf(stderr, "Unable to malloc\n");
goto die;
}
/* walk through the allocated mem to negate any lazy allocation schema */
for (j=0; j < element_size; j++) {
element[j] = '\0';
}
array = element;
max_array_idx = i;
if (free_immed_p) {
counting_free(element);
}
}
die:
fprintf(stderr, "unwinding\n");
if (array) {
if (!free_immed_p) {
fprintf(stderr, "freeing %d elements\n", max_array_idx + 1);
for (i=0; i < max_array_idx; i++) {
counting_free(array);
}
}
counting_free(array);
}
}



void
usage()
{
fprintf(stderr, "Don't understand argument. immed or not_immed\n");
}

int
main(int argc, char **argv)
{
int free_immed_p;
if (argc != 2) {
usage();
return 1;
}
if (strcmp("immed", argv[1]) == 0) {
printf("Freeing immediately\n");
free_immed_p = 1;
} else if (strcmp("not_immed", argv[1]) == 0) {
printf("Not freeing immediately\n");
free_immed_p = 0;
} else {
usage();
return 1;
}
printf("----BEFORE----\n");
printf("malloc count = %d\n", malloc_count);
printf("free count = %d\n", free_count);
display_vminfo();
printf("Executing leak test\n");
leak_test(free_immed_p);
printf("----AFTER-----\n");
printf("malloc count = %d\n", malloc_count);
printf("free count = %d\n", free_count);
display_vminfo();
return 0;
}

Here is the fixed version:

You can't say this if you only have VmSize.


YS.

 

[Yohanes Santoso]

Stop right there. I want to remind people that you can't use VmSize as
a leak indicator. In some OS, VmSize is an always increasing
number. Memory allocated in a process is not returned to the OS until
the process dies.

Here is a C program that free() every malloc(), yet still have
outrageous VmSize;

Sorry, I posted the wrong version. Here is the correct one:

ysantoso@jenny:/tmp$ gcc -W -Wall ./leak.c -o leak && ./leak immed && ./leak not_immed
Freeing immediately
----BEFORE----
malloc count = 0
free count = 0
VmSize: 1568 kB
VmLck: 0 kB
VmRSS: 360 kB
VmData: 156 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
Allocating hole
unwinding
----AFTER-----
malloc count = 8193
free count = 8193
VmSize: 1568 kB
VmLck: 0 kB
VmRSS: 440 kB
VmData: 156 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Freeing hole
Not freeing immediately
----BEFORE----
malloc count = 0
free count = 0
VmSize: 1568 kB
VmLck: 0 kB
VmRSS: 364 kB
VmData: 156 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
Allocating hole
unwinding
freeing 8192 elements
----AFTER-----
malloc count = 8193
free count = 8193
VmSize: 206360 kB
VmLck: 0 kB
VmRSS: 205284 kB
VmData: 204948 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 216 kB
Freeing hole
ysantoso@jenny:/tmp$ cat ./leak.c
#include <stdio.h>
#include <stdlib.h>
#include <string.h>

int malloc_count = 0;
int free_count = 0;
char *hole;

void *
counting_malloc(size_t size)
{
malloc_count++;
return malloc(size);
}

void
counting_free(void *ptr)
{
free_count++;
if (ptr == NULL) {
fprintf(stderr, "Warning: free-ing NULL pointer\n");
}
free(ptr);
}

void
display_vminfo()
{
FILE *status = fopen("/proc/self/status", "r");
char line[132];
while (fgets(line, 132, status)) {
if (strstr(line, "Vm") == line) {
printf(line);
}
}
fclose(status);
}

/* allocs about 200M of mem. if free_immed_p, then memory allocated is free()ed immediately */
void
leak_test(int free_immed_p)
{
int i, j;
char **array = NULL;
int max_array_idx = -1;
int max_array_size = 8192;
int element_size = 25*1024;
array = counting_malloc(max_array_size * sizeof(char*));
if (!array) {
fprintf(stderr, "Unable to malloc\n");
goto die;
}
for (i=0; i < max_array_size; i++) {
char *element = counting_malloc(element_size);
if (!element) {
fprintf(stderr, "Unable to malloc\n");
goto die;
}
/* walk through the allocated mem to negate any lazy allocation schema */
for (j=0; j < element_size; j++) {
element[j] = '\0';
}
array = element;
max_array_idx = i;
if (free_immed_p) {
counting_free(element);
}
}
if (!hole) {
fprintf(stderr, "Allocating hole\n");
hole = malloc(1);
if (!hole) {
fprintf(stderr, "Unable to make hole\n");
goto die;
}
hole[0] = '\0';
}
die:
fprintf(stderr, "unwinding\n");
if (array) {
if (!free_immed_p) {
fprintf(stderr, "freeing %d elements\n", max_array_idx + 1);
for (i=0; i < max_array_idx+1; i++) {
counting_free(array);
}
}
counting_free(array);
}
}



void
usage()
{
fprintf(stderr, "Don't understand argument. immed or not_immed\n");
}

int
main(int argc, char **argv)
{
int free_immed_p;
hole = NULL;
if (argc != 2) {
usage();
goto die;
}
if (strcmp("immed", argv[1]) == 0) {
printf("Freeing immediately\n");
free_immed_p = 1;
} else if (strcmp("not_immed", argv[1]) == 0) {
printf("Not freeing immediately\n");
free_immed_p = 0;
} else {
usage();
goto die;
}
printf("----BEFORE----\n");
printf("malloc count = %d\n", malloc_count);
printf("free count = %d\n", free_count);
display_vminfo();
printf("Executing leak test\n");
leak_test(free_immed_p);
printf("----AFTER-----\n");
printf("malloc count = %d\n", malloc_count);
printf("free count = %d\n", free_count);
display_vminfo();
die:
if (hole) {
fprintf(stderr, "Freeing hole\n");
free(hole);
}
return 0;
}
ysantoso@jenny:/tmp$

 

[Wilson Bilkovich]

Has anyone tried throwing DTrace at this problem? I don't have any
Solaris access here at RubyConf, and I don't use FCGI, or I'd give it
a go.

n=3D2**13;(1..n).each{|i|
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start= ;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 172028 kB

ruby -e '
n=3D2**13;(1..n).each{|i|
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=3Dnil};= GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 11504 kB

Stop right there. I want to remind people that you can't use VmSize as
a leak indicator. In some OS, VmSize is an always increasing
number. Memory allocated in a process is not returned to the OS until
the process dies.

Here is a C program that free() every malloc(), yet still have
outrageous VmSize;

ysantoso@jenny:/tmp$ gcc -W -Wall ./leak.c -o leak && ./leak immed && ./l= eak not_immed
Freeing immediately
----BEFORE----
malloc count =3D 0
free count =3D 0
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 364 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
unwinding
----AFTER-----
malloc count =3D 8193
free count =3D 8193
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 440 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Not freeing immediately
----BEFORE----
malloc count =3D 0
free count =3D 0
VmSize: 1568 kB
VmLck: 0 kB
VmRSS: 364 kB
VmData: 156 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
unwinding
freeing 8192 elements
----AFTER-----
malloc count =3D 8193
free count =3D 8192
VmSize: 206360 kB
VmLck: 0 kB
VmRSS: 205280 kB
VmData: 204948 kB
VmStk: 84 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 216 kB
ysantoso@jenny:/tmp$ cat ./leak.c
#include <stdio.h>
#include <stdlib.h>
#include <string.h>

int malloc_count =3D 0;
int free_count =3D 0;

void *
counting_malloc(size_t size)
{
malloc_count++;
return malloc(size);
}

void
counting_free(void *ptr)
{
free_count++;
if (ptr =3D=3D NULL) {
fprintf(stderr, "Warning: free-ing NULL pointer\n");
}
free(ptr);
}

void
display_vminfo()
{
FILE *status =3D fopen("/proc/self/status", "r");
char line[132];
while (fgets(line, 132, status)) {
if (strstr(line, "Vm") =3D=3D line) {
printf(line);
}
}
fclose(status);
}

/* allocs about 200M of mem. if free_immed_p, then memory allocated is fr= ee()ed immediately */
void
leak_test(int free_immed_p)
{
int i, j;
char **array =3D NULL;
int max_array_idx =3D -1;
int max_array_size =3D 8192;
int element_size =3D 25*1024;
array =3D counting_malloc(max_array_size * sizeof(char*));
if (!array) {
fprintf(stderr, "Unable to malloc\n");
goto die;
}
for (i=3D0; i < max_array_size; i++) {
char *element =3D counting_malloc(element_size);
if (!element) {
fprintf(stderr, "Unable to malloc\n");
goto die;
}
/* walk through the allocated mem to negate any lazy allocation schem= a */
for (j=3D0; j < element_size; j++) {
element[j] =3D '\0';
}
array =3D element;
max_array_idx =3D i;
if (free_immed_p) {
counting_free(element);
}
}
die:
fprintf(stderr, "unwinding\n");
if (array) {
if (!free_immed_p) {
fprintf(stderr, "freeing %d elements\n", max_array_idx + 1);
for (i=3D0; i < max_array_idx; i++) {
counting_free(array);
}
}
counting_free(array);
}
}



void
usage()
{
fprintf(stderr, "Don't understand argument. immed or not_immed\n");
}

int
main(int argc, char **argv)
{
int free_immed_p;
if (argc !=3D 2) {
usage();
return 1;
}
if (strcmp("immed", argv[1]) =3D=3D 0) {
printf("Freeing immediately\n");
free_immed_p =3D 1;
} else if (strcmp("not_immed", argv[1]) =3D=3D 0) {
printf("Not freeing immediately\n");
free_immed_p =3D 0;
} else {
usage();
return 1;
}
printf("----BEFORE----\n");
printf("malloc count =3D %d\n", malloc_count);
printf("free count =3D %d\n", free_count);
display_vminfo();
printf("Executing leak test\n");
leak_test(free_immed_p);
printf("----AFTER-----\n");
printf("malloc count =3D %d\n", malloc_count);
printf("free count =3D %d\n", free_count);
display_vminfo();
return 0;
}

Here is the fixed version:

You can't say this if you only have VmSize.


YS.

 

[Eric Mahurin]

a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=3Dnil};GC=
start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
=20
Stop right there. I want to remind people that you can't use
VmSize as
a leak indicator. In some OS, VmSize is an always increasing
number. Memory allocated in a process is not returned to the
OS until
the process dies.

OK. Pick another way to measure memory. top shows the same
memory as above for me. Or make n=3D2**15. This brings my
machine (768MB) to its knees:

ruby -e 'n=3D2**15;(1..n).each{|i|
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'

I'd estimate it would use about 3GB. And if you put an a=3Dnil
after the define_method, you get this:

ruby -e 'n=3D2**15;(1..n).each{|i|
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=3Dnil};GC=
start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 31032 kB



=09
=09
__________________________________=20
Yahoo! Mail - PC Magazine Editors' Choice 2005=20
http://mail.yahoo.com

 

[Yohanes Santoso]

OK. Pick another way to measure memory. top shows the same
memory as above for me. Or make n=2**15. This brings my
machine (768MB) to its knees:

ruby -e 'n=2**15;(1..n).each{|i|
a=(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'

I'd estimate it would use about 3GB. And if you put an a=nil
after the define_method, you get this:

ruby -e 'n=2**15;(1..n).each{|i|
a=(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=nil};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 31032 kB

That is still not a valid way to detect leak as that still depends on
VmSize value. Ruby could be freeing every allocation and the Vmsize
would still grow.

I posted two versions because the first version was
1. has an off-by-1 error,
2. does not show that the order of free() matters.

Try this diff where the hole is freed in different order. There is no
memory leak this time. The same number of allocations and frees, but
it has no memory leak!

Cheers,
YS.


--- leak.c 2005-10-16 00:18:34.000000000 -0400
+++ noleak.c 2005-10-16 00:40:36.000000000 -0400
@@ -74,6 +74,11 @@
goto die;
}
hole[0] = '\0';
+ if (hole) {
+ fprintf(stderr, "Freeing hole\n");
+ free(hole);
+ hole=NULL;
+ }
}
die:
fprintf(stderr, "unwinding\n");
Freeing immediately
----BEFORE----
malloc count = 0
free count = 0
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 364 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
Allocating hole
Freeing hole
unwinding
----AFTER-----
malloc count = 8193
free count = 8193
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 440 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Not freeing immediately
----BEFORE----
malloc count = 0
free count = 0
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 364 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB
Executing leak test
Allocating hole
Freeing hole
unwinding
freeing 8192 elements
----AFTER-----
malloc count = 8193
free count = 8193
VmSize: 1572 kB
VmLck: 0 kB
VmRSS: 512 kB
VmData: 156 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 1280 kB
VmPTE: 16 kB

 

[Eric Mahurin]

a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=3Dnil};GC=
start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i};a=3Dnil};GC=
start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
=20
=20
That is still not a valid way to detect leak as that still
depends on
VmSize value. Ruby could be freeing every allocation and the
Vmsize
would still grow.=20

But it is not. Have you tried this example? On my 768MB
machine, top shows it filling my physical memory and then the
the CPU drops to about 3% because it starts swapping and my
machine becomes very unresponsive. I'd say that's a good
indication that top is reporting the right thing.

You could consider this case a bug in ruby or a bug in the
simple test case above. It doesn't matter where the fault
lies, it still shows a memory leak. The point is you better be
careful with closures (block/lambda) because they carry all the
variables in scope in Proc#binding in the current
implementation. Personally, I would like to see something done
about this in ruby, but at minimum people need to be aware of
this memory issue (as ruby stands now).



=09
=09
__________________________________=20
Yahoo! Mail - PC Magazine Editors' Choice 2005=20
http://mail.yahoo.com

 

[Ara.T.Howard]

But it is not. Have you tried this example? On my 768MB machine, top shows
it filling my physical memory and then the the CPU drops to about 3% because
it starts swapping and my machine becomes very unresponsive. I'd say that's
a good indication that top is reporting the right thing.

You could consider this case a bug in ruby or a bug in the simple test case
above. It doesn't matter where the fault lies, it still shows a memory
leak. The point is you better be careful with closures (block/lambda)
because they carry all the variables in scope in Proc#binding in the current
implementation. Personally, I would like to see something done about this
in ruby, but at minimum people need to be aware of this memory issue (as
ruby stands now).

this is quite suspect:

[ahoward@localhost ~]$ for i in $(seq 0 18);do
printf "$i => ";
ruby -e' class << self; (2**ARGV.shift.to_i).times{|n| s = '42' * n; define_method("f#{ n }"){ 42 }}; end; GC::start; p IO::read("/proc/#{ $$ }/status").grep(/VmSize/) ' $i;
done

0 => ["VmSize:\t 2840 kB\n"]
1 => ["VmSize:\t 2840 kB\n"]
2 => ["VmSize:\t 2840 kB\n"]
3 => ["VmSize:\t 2840 kB\n"]
4 => ["VmSize:\t 2844 kB\n"]
5 => ["VmSize:\t 2840 kB\n"]
6 => ["VmSize:\t 2840 kB\n"]
7 => ["VmSize:\t 2844 kB\n"]
8 => ["VmSize:\t 2976 kB\n"]
9 => ["VmSize:\t 3456 kB\n"]
10 => ["VmSize:\t 3720 kB\n"]
11 => ["VmSize:\t 4380 kB\n"]
12 => ["VmSize:\t 6072 kB\n"]
13 => ["VmSize:\t 9456 kB\n"]
14 => ["VmSize:\t 15996 kB\n"]
15 => ["VmSize:\t 28704 kB\n"]
16 => ["VmSize:\t 53352 kB\n"]
17 => ["VmSize:\t 101220 kB\n"]
18 => ["VmSize:\t 194404 kB\n"]


note the progression is linear until 13 (note irony) and then climbs
exponentially - doubling each time.

-a
--
===============================================================================
| email :: ara [dot] t [dot] howard [at] noaa [dot] gov
| phone :: 303.497.6469
| anything that contradicts experience and logic should be abandoned.
| -- h.h. the 14th dalai lama
===============================================================================

 

[Ara.T.Howard]

this is quite suspect:

[ahoward@localhost ~]$ for i in $(seq 0 18);do
printf "$i => ";
ruby -e' class << self; (2**ARGV.shift.to_i).times{|n| s = '42' * n;
define_method("f#{ n }"){ 42 }}; end; GC::start; p IO::read("/proc/#{ $$
}/status").grep(/VmSize/) ' $i;
done

0 => ["VmSize:\t 2840 kB\n"]
1 => ["VmSize:\t 2840 kB\n"]
2 => ["VmSize:\t 2840 kB\n"]
3 => ["VmSize:\t 2840 kB\n"]
4 => ["VmSize:\t 2844 kB\n"]
5 => ["VmSize:\t 2840 kB\n"]
6 => ["VmSize:\t 2840 kB\n"]
7 => ["VmSize:\t 2844 kB\n"]
8 => ["VmSize:\t 2976 kB\n"]
9 => ["VmSize:\t 3456 kB\n"]
10 => ["VmSize:\t 3720 kB\n"]
11 => ["VmSize:\t 4380 kB\n"]
12 => ["VmSize:\t 6072 kB\n"]
13 => ["VmSize:\t 9456 kB\n"]
14 => ["VmSize:\t 15996 kB\n"]
15 => ["VmSize:\t 28704 kB\n"]
16 => ["VmSize:\t 53352 kB\n"]
17 => ["VmSize:\t 101220 kB\n"]
18 => ["VmSize:\t 194404 kB\n"]


note the progression is linear until 13 (note irony) and then climbs
exponentially - doubling each time.

and even wrapping in a method doesn't seem to help

[ahoward@localhost ~]$ ruby a.rb 15
1 => VmSize: 2844 kB
2 => VmSize: 2848 kB
4 => VmSize: 2848 kB
8 => VmSize: 2848 kB
16 => VmSize: 2848 kB
32 => VmSize: 2848 kB
64 => VmSize: 2976 kB
128 => VmSize: 3108 kB
256 => VmSize: 3724 kB
512 => VmSize: 4648 kB
1024 => VmSize: 5572 kB
2048 => VmSize: 9904 kB
4096 => VmSize: 13104 kB
8192 => VmSize: 27016 kB
16384 => VmSize: 46676 kB


[ahoward@localhost ~]$ cat a.rb
class Object
def gen_method
klass = Class === self ? self : self.class
class << klass
define_method("f#{ rand(2 ** 42) }"){ 42 }
end
end
end

limit = Integer ARGV.shift

limit.times do |l|
n = 2 ** l

n.times{|i| s = '42' * i and gen_method}

GC::start

printf "% 8d => %s", n, IO::read("/proc/#{ $$ }/status").grep(/VmSize/)
end

still exponential after a threshold...

-a
--
===============================================================================
| email :: ara [dot] t [dot] howard [at] noaa [dot] gov
| phone :: 303.497.6469
| anything that contradicts experience and logic should be abandoned.
| -- h.h. the 14th dalai lama
===============================================================================

 

[Yohanes Santoso]

But it is not.

Be careful, 1. there is no evidence yet that ruby is not freeing every
allocation, and 2. I am not saying there is no memory leak caused by
define_method.

What I have been saying is, you can't use VmSize as an indicator of
memory leak. I have shown examples where the order of free() can
affect VmSize.

Here is an alternative scenario that would have resulted in what you
are seeing: ruby could have free()-ed all its allocations properly
when you call GC.start, but may free() them in different order on each
test case which result in you seeing different VmSize values.

Probably that is not what happens; Probably there really is a genuine
memory leak; But you can't determine which scenario is happening from
VmSize value.

Have you tried this example? On my 768MB machine, top shows it
filling my physical memory and then the the CPU drops to about 3%
because it starts swapping and my machine becomes very unresponsive.
I'd say that's a good indication that top is reporting the right
thing.

This only shows whether the free-ing is done immediately or not. Thus,
why my example program focuses in the immediateness of freeing.

You could consider this case a bug in ruby or a bug in the
simple test case above. It doesn't matter where the fault
lies, it still shows a memory leak.

Memory leak is tricky to show since it requires one to prove that
there is an allocation that is not free-ed by the time the process
ends.

However, there are evidences (search the archive for GC problems) that
the GC is too conservative (read: lazy) and stupid in some
cases. Sometimes, you need to drop the clue book on its head, like
doing a=nil. Without the a=nil, the number of objects is not decreased
by much after GC.

The point is you better be careful with closures (block/lambda)

Yes, be careful as the GC is a lazy bum.

In any case, here is another 'fixed' version.

ysantoso@jenny:/tmp$ ruby -e 'n=2**13;for i in (1..n) do
a=(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i} end;GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'

VmSize: 11268 kB



YS.

 

[Yohanes Santoso]

still exponential after a threshold...

I think that's because the symbol table grows exponentially.

YS.

 

[Randy Kramer]

I'm really not trying to start a flamewar. Some of the statements made in=
=20
this thread seem completely contrary to what I thought I knew, and=20
counter-intuitive as well. =20

Am I completely mixed up?

Memory leak is tricky to show since it requires one to prove that
there is an allocation that is not free-ed by the time the process
ends.

I didn't/don't think so. Unused memory allocations that are not freed whil=
e=20
the process is running seem to be the very definition of a memory leak:

Result of Googling [define:"memory leak"]:
=3D
Definitions of "memory leak" on the Web:

Making malloc calls without the corresponding calls to free. The result is=
=20
that the amount of heap memory used continues to increase as the process=20
runs.
techpubs.sgi.com/library/tpl/cgi-bin/getdoc.cgi

The effect of a program that maintains references to objects that are no=20
longer required and therefore need to be reclaimed by garbage collection=20
routines.
publib.boulder.ibm.com/infocenter/adiehelp/topic/com.ibm.wsinted.glossary.d=
oc/topics/glossary.html

A programming term describing the losing of memory. This happens when the=20
program allocates some memory but fails to return it to the system. Excessi=
ve=20
memory leaks can lead to program failure after a sufficiently long period o=
f=20
time.
www.fieldpine.com/help/en/user/glossary/m.htm

Memory leaks are often thought of as failures to release unused memory by a=
=20
computer program. Strictly speaking, it is just unneccesary memory=20
consumption. A memory leak occurs when the program loses the ability to fre=
e=20
the memory. A memory leak diminishes the performance of the computer, as it=
=20
becomes unable to use all its available memory.=20
en.wikipedia.org/wiki/Memory_leak
=3D

I'd call it a memory leak even if the allocation is freed when the process=
=20
ends. Consider processes that (should) run continuously.

=46rom an earlier post:

Stop right there. I want to remind people that you can't use VmSize as
a leak indicator.=20

That may be true (I really don't know)--but:
* if increasing VmSize corresponds to a slowdown in my machine, I'd call=
it=20
a pretty good "indicator"
* what can you use as a better indicator

In some OS, VmSize is an always increasing=20
number.=20

Out of curiosity (and the intent to try to avoid such), which OS? Or maybe=
I=20
better clarify your statement--are you saying that in some OS, VmSize does=
=20
not decrease even if a program is stopped?

Memory allocated in a process is not returned to the OS until=20
the process dies.

Again, seems like the very defintion of a memory leak. =20

It is true that if the memory allocated to a process is returned to the OS=
=20
when the process dies, that gives you a workaround for the memory leak, but=
=20
it is still a memory leak. =20

I can remember some programs that I ran in Windows that I had to occasional=
ly=20
stop and restart for just this reason. I'm beginning to think that some=20
"well known" programs in Linux behave in a similar way. (I shouldn't reall=
y=20
name names yet, as I haven't quite proved it to my own satisfaction, but I =
do=20
occasionally close kmail and epihany and get back a lot of memory (and make=
=20
my system run a lot better.)

Aside: I did note your other comments from a later post:

Be careful, 1. there is no evidence yet that ruby is not freeing every
allocation, and 2. I am not saying there is no memory leak caused by
define_method.

What I have been saying is, you can't use VmSize as an indicator of
memory leak. I have shown examples where the order of free() can
affect VmSize.

regards,
Randy Kramer

 

[Eric Mahurin]

=20
Be careful, 1. there is no evidence yet that ruby is not
freeing every
allocation, and 2. I am not saying there is no memory leak
caused by
define_method.
=20
What I have been saying is, you can't use VmSize as an
indicator of
memory leak. I have shown examples where the order of free()
can
affect VmSize.
=20
Here is an alternative scenario that would have resulted in
what you
are seeing: ruby could have free()-ed all its allocations
properly
when you call GC.start, but may free() them in different
order on each
test case which result in you seeing different VmSize values.
=20
Probably that is not what happens; Probably there really is a
genuine
memory leak; But you can't determine which scenario is
happening from
VmSize value.
=20
=20
This only shows whether the free-ing is done immediately or
not. Thus,
why my example program focuses in the immediateness of
freeing.
=20
=20
Memory leak is tricky to show since it requires one to prove
that
there is an allocation that is not free-ed by the time the
process
ends.

Just because a process frees all its memory before it
terminates doesn't mean there isn't a leak. That doesn't help
too much if you run out of memory before the process is done.=20
I've seen 2 definitions: a) when a program isn't freeing memory
that isn't used anymore, b) when a program loses all references
to memory that isn't being freed. From the ruby script level
for this example, by both of these definitions it is a memory
leak. From ruby itself, ruby probably still has references to
the memory, so (b) may not call it a "memory leak". To me (a)
is the right definition because it describes symtoms not the
mechanism. If any program keeps growing in memory and it
shouldn't, I'd say it has a memory leak. It doesn't matter how
it comes about and whether or not the program could free the
memory if it was fixed, it is still "leaking" memory.

However, there are evidences (search the archive for GC
problems) that
the GC is too conservative (read: lazy) and stupid in some
cases. Sometimes, you need to drop the clue book on its head,
like
doing a=3Dnil. Without the a=3Dnil, the number of objects is not
decreased
by much after GC.
=20
(block/lambda)
=20
Yes, be careful as the GC is a lazy bum.

If you want to assign blame to ruby, the problem is not GC.=20
The problem is that closures hold strong references to all
variables in the scope whether or not they are used. One of my
solutions was to make references (in Proc#binding) to currently
unused variables (by the closure) "weak", so that they wouldn't
prevent GC.

In any case, here is another 'fixed' version.=20
=20
ysantoso@jenny:/tmp$ ruby -e 'n=3D2**13;for i in (1..n) do
a=3D(1..i).to_a;self.class.senddefine_method,:"f#{i}"){i*i}
end;GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
=20
VmSize: 11268 kB

This is because the "for" loop (which uses #each) doesn't
create the same type of block/lambda that the normal block
(after a method call) does. In the above example, "a" is in
the outer scope. With using #each and a block directly, "a" is
a local to each interation that it is yielded - it is a
different variable on each iteration. The "for" loop you
showed actually doesn't even work the same because all of the
defined f* methods will use the same "i" because "i" is not
local for each iteration for "for" but it is for #each using a
normal block.



__________________________________________________
Do You Yahoo!?
Tired of spam? Yahoo! Mail has the best spam protection around=20
http://mail.yahoo.com=20

 

[ts]

E> to memory that isn't being freed. From the ruby script level
E> for this example, by both of these definitions it is a memory
E> leak. From ruby itself, ruby probably still has references to
E> the memory, so (b) may not call it a "memory leak". To me (a)
E> is the right definition because it describes symtoms not the
E> mechanism. If any program keeps growing in memory and it
E> shouldn't, I'd say it has a memory leak. It doesn't matter how
E> it comes about and whether or not the program could free the
E> memory if it was fixed, it is still "leaking" memory.

No please.

You are writing stupid program, don't expect that ruby correct what you
write. ruby is a programming language, first learn it before trying to
blame it.



Guy Decoux

 

[Eric Mahurin]

On Sun, 16 Oct 2005, Ara.T.Howard wrote:
=20

this is quite suspect:

[ahoward@localhost ~]$ for i in $(seq 0 18);do
printf "$i =3D> ";
ruby -e' class << self; (2**ARGV.shift.to_i).times{|n| s =3D '42' * n;=20
define_method("f#{ n }"){ 42 }}; end; GC::start; p IO::read("/proc/#{ $$=20
}/status").grep(/VmSize/) ' $i;
done

0 =3D> ["VmSize:\t 2840 kB\n"]
1 =3D> ["VmSize:\t 2840 kB\n"]
2 =3D> ["VmSize:\t 2840 kB\n"]
3 =3D> ["VmSize:\t 2840 kB\n"]
4 =3D> ["VmSize:\t 2844 kB\n"]
5 =3D> ["VmSize:\t 2840 kB\n"]
6 =3D> ["VmSize:\t 2840 kB\n"]
7 =3D> ["VmSize:\t 2844 kB\n"]
8 =3D> ["VmSize:\t 2976 kB\n"]
9 =3D> ["VmSize:\t 3456 kB\n"]
10 =3D> ["VmSize:\t 3720 kB\n"]
11 =3D> ["VmSize:\t 4380 kB\n"]
12 =3D> ["VmSize:\t 6072 kB\n"]
13 =3D> ["VmSize:\t 9456 kB\n"]
14 =3D> ["VmSize:\t 15996 kB\n"]
15 =3D> ["VmSize:\t 28704 kB\n"]
16 =3D> ["VmSize:\t 53352 kB\n"]
17 =3D> ["VmSize:\t 101220 kB\n"]
18 =3D> ["VmSize:\t 194404 kB\n"]


note the progression is linear until 13 (note irony) and then climbs
exponentially - doubling each time.

=20
and even wrapping in a method doesn't seem to help
=20
[ahoward@localhost ~]$ ruby a.rb 15
1 =3D> VmSize: 2844 kB
2 =3D> VmSize: 2848 kB
4 =3D> VmSize: 2848 kB
8 =3D> VmSize: 2848 kB
16 =3D> VmSize: 2848 kB
32 =3D> VmSize: 2848 kB
64 =3D> VmSize: 2976 kB
128 =3D> VmSize: 3108 kB
256 =3D> VmSize: 3724 kB
512 =3D> VmSize: 4648 kB
1024 =3D> VmSize: 5572 kB
2048 =3D> VmSize: 9904 kB
4096 =3D> VmSize: 13104 kB
8192 =3D> VmSize: 27016 kB
16384 =3D> VmSize: 46676 kB
=20
=20
[ahoward@localhost ~]$ cat a.rb
class Object
def gen_method
klass =3D Class =3D=3D=3D self ? self : self.class
class << klass
define_method("f#{ rand(2 ** 42) }"){ 42 }
end
end
end
=20
limit =3D Integer ARGV.shift
=20
limit.times do |l|
n =3D 2 ** l
=20
n.times{|i| s =3D '42' * i and gen_method}
=20
GC::start
=20
printf "% 8d =3D> %s", n, IO::read("/proc/#{ $$
}/status").grep(/VmSize/)
end
=20
still exponential after a threshold...

The other leaking examples were technically quadratic (O(n**2))
were they should have been O(n). The above one is also O(n).=20
Take on the "s =3D '42' * i and" and you'll see the same memory
usage. I don't see an issue in the above example. It's just
that the memory usage was so small for anything below n=3D1024,
that it probably didn't have to grow much beyond what ruby had
allocated to it when it started up.



=09
__________________________________=20
Yahoo! Music Unlimited=20
Access over 1 million songs. Try it free.
http://music.yahoo.com/unlimited/