Help! define_method leaking procs

ruby-talk
1

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
2

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.

···

On Oct 15, 2005, at 11:36 AM, Jamis Buck wrote:

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.

3

Have you thought about a ruby leak detector?

You could monitor object allocation with define_finalizer and a wrapped new.
Sort of like replacing new/delete in C++

4

Hi,

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_method(:foo){...}

to

  def def_something(name)
    define_method(name){...}
  end
  ...
  def_something(:foo)

              matz.

···

In message "Re: Help! define_method leaking procs..." on Sun, 16 Oct 2005 05:01:58 +0900, Ryan Davis <ryand-ruby@zenspider.com> writes:

5

Take a look at this thread:

http://groups.google.com/group/comp.lang.ruby/browse_thread/thread/3ad49507f2086e22/ac92a1373161035e?q=mahurin&rnum=4#ac92a1373161035e

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

···

--- Ryan Davis <ryand-ruby@zenspider.com> wrote:

On Oct 15, 2005, at 11:36 AM, Jamis Buck wrote:

> 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.

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

6

We have identified and fixed the leak, and all is well now. Thanks, everyone, for your suggestions.

If you're curious, the problem was fixed by calling undef_method on all the dynamically added methods before doing remove_const on the class. We also went through each class and removed all instance_variables from the class. Doing this seems to have allowed the Proc objects to be garbage collected.

- Jamis

···

On Oct 16, 2005, at 6:57 PM, Lyndon Samson wrote:

Have you thought about a ruby leak detector?

You could monitor object allocation with define_finalizer and a wrapped new.
Sort of like replacing new/delete in C++

7

Eric Mahurin wrote:

···

--- Ryan Davis <ryand-ruby@zenspider.com> wrote:

On Oct 15, 2005, at 11:36 AM, Jamis Buck wrote:

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.

Take a look at this thread:

http://groups.google.com/group/comp.lang.ruby/browse_thread/thread/3ad49507f2086e22/ac92a1373161035e?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

8

Would you mind showing us a snippet of code that demonstrates
the problem? Maybe there is some circular references?

···

--- Jamis Buck <jamis@37signals.com> wrote:

On Oct 16, 2005, at 6:57 PM, Lyndon Samson wrote:
We have identified and fixed the leak, and all is well now.
Thanks,
everyone, for your suggestions.

If you're curious, the problem was fixed by calling
undef_method on
all the dynamically added methods before doing remove_const
on the
class. We also went through each class and removed all
instance_variables from the class. Doing this seems to have
allowed
the Proc objects to be garbage collected.

__________________________________
Yahoo! Mail - PC Magazine Editors' Choice 2005

9

Eric Mahurin wrote:
>
>
>>
>>
>>>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.
>
>
>
> Take a look at this thread:
>
>

http://groups.google.com/group/comp.lang.ruby/browse_thread/thread/3ad49507f2086e22/ac92a1373161035e?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

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.
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=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.send(:define_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=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.send(:define_method,:"f#{i}"){i*i};a=nil};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 11504 kB

···

--- ES <ruby-ml@magical-cat.org> wrote:

> --- Ryan Davis <ryand-ruby@zenspider.com> wrote:
>>On Oct 15, 2005, at 11:36 AM, Jamis Buck wrote:

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

10

Well... here's a small script that duplicates the problem, but it requires that it be run from the root directory of a Rails application that has a model class called Dummy. And Dummy must have an association to some other model class.

   require './config/environment'

   module ObjectSpace
     def self.count(mod=Object)
       count = 0
       ObjectSpace.each_object(mod) { count += 1 }
       count
     end
   end

   20.times do
     GC.start

     Dummy.find(1)
     Dependencies.clear
     ActiveRecord::Base.reset_subclasses
     Dependencies.remove_subclasses_for(ActiveRecord::Base)

     procs = ObjectSpace.count(Proc)

     puts "procs: #{procs}"
   end

The set it up for this, you could do:

   * gem install rails
   * rails memleak
   * cd memleak
   * script/generate model Dummy
   * script/generate model Thing
   * edit Dummy so that it has_one :thing
   * edit config/database.yml to point to a database
   * add a dummies table
   * insert a record into the dummies table
   * run the script given above

Running against Rails 0.13.1, you should see the number of procs grow with each request. Running against the beta gems, you'll see the number remain constant.

- Jamis

···

On Oct 17, 2005, at 11:07 AM, Eric Mahurin wrote:

--- Jamis Buck <jamis@37signals.com> wrote:

On Oct 16, 2005, at 6:57 PM, Lyndon Samson wrote:
We have identified and fixed the leak, and all is well now.
Thanks,
everyone, for your suggestions.

If you're curious, the problem was fixed by calling
undef_method on
all the dynamically added methods before doing remove_const
on the
class. We also went through each class and removed all
instance_variables from the class. Doing this seems to have
allowed
the Proc objects to be garbage collected.

Would you mind showing us a snippet of code that demonstrates
the problem? Maybe there is some circular references?

11

Eric Mahurin <eric_mahurin@yahoo.com> writes:

n=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.send(:define_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.send(:define_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[i] = 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[i]);
      }
    }
    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.

12

Eric Mahurin wrote:

Eric Mahurin wrote:

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.

Take a look at this thread:

http://groups.google.com/group/comp.lang.ruby/browse_thread/thread/3ad49507f2086e22/ac92a1373161035e?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

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.

Yes. As far as I knew, this was the only sensible definition.
If there is a problem, it is not a memory leak (as most or all
C programmers understand the term anyway); changing the term might
yield a more successful debate.

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=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.send(:define_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=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.send(:define_method,:"f#{i}"){i*i};a=nil};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 11504 kB

E

···

--- ES <ruby-ml@magical-cat.org> wrote:

--- Ryan Davis <ryand-ruby@zenspider.com> wrote:

On Oct 15, 2005, at 11:36 AM, Jamis Buck wrote:

13

Yohanes Santoso <ysantoso-rubytalk@dessyku.is-a-geek.org> writes:

Eric Mahurin <eric_mahurin@yahoo.com> writes:

n=2**13;(1..n).each{|i|
a=(1..i).to_a;self.class.send(:define_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.send(:define_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;

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[i] = 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[i]);
      }
    }
    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$

14

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.

···

On 10/15/05, Yohanes Santoso <ysantoso-rubytalk@dessyku.is-a-geek.org> wrote:

Eric Mahurin <eric_mahurin@yahoo.com> writes:

> n=2**13;(1..n).each{|i|
> a=(1..i).to_a;self.class.send(:define_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.send(:define_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[i] = 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[i]);
      }
    }
    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.

15

--- Yohanes Santoso <ysantoso-rubytalk@dessyku.is-a-geek.org>
wrote:

Eric Mahurin <eric_mahurin@yahoo.com> writes:

> n=2**13;(1..n).each{|i|
>

a=(1..i).to_a;self.class.send(:define_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.send(:define_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.

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.send(:define_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.send(:define_method,:"f#{i}"){i*i};a=nil};GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'
VmSize: 31032 kB

···

__________________________________
Yahoo! Mail - PC Magazine Editors' Choice 2005

16

> So your definition of "memory leak" says that it is not a
memory
> leak if the unused memory can still be freed by the
program.

Yes. As far as I knew, this was the only sensible definition.
If there is a problem, it is not a memory leak (as most or
all
C programmers understand the term anyway); changing the term
might
yield a more successful debate.

Try a google on "memory leak". The first several defintions
you'll find are more general and not limited to languages that
don't have automatic GC. Just because you have a perfect
language with perfect GC doesn't mean you can't write a program
that "leaks" memory - over time uses more and more memory when
it doesn't need it. I think the language/GC/libs should try to
plug as many holes as possible, but you still won't be able to
prevent all memory leak bugs of programs written in the
language.

> 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=2**13;(1..n).each{|i|
>

a=(1..i).to_a;self.class.send(:define_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=2**13;(1..n).each{|i|
>

a=(1..i).to_a;self.class.send(:define_method,:"f#{i}"){i*i};a=nil};GC.start;

>

IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'

···

--- ES <ruby-ml@magical-cat.org> wrote:

> VmSize: 11504 kB

__________________________________
Start your day with Yahoo! - Make it your home page!
http://www.yahoo.com/r/hs

17

Eric Mahurin <eric_mahurin@yahoo.com> writes:

--- Yohanes Santoso <ysantoso-rubytalk@dessyku.is-a-geek.org>
wrote:

Eric Mahurin <eric_mahurin@yahoo.com> writes:

> n=2**13;(1..n).each{|i|
>

a=(1..i).to_a;self.class.send(:define_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.send(:define_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.

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.send(:define_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.send(:define_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

18

--- Yohanes Santoso <ysantoso-rubytalk@dessyku.is-a-geek.org>
wrote:

Eric Mahurin <eric_mahurin@yahoo.com> writes:

> --- Yohanes Santoso
<ysantoso-rubytalk@dessyku.is-a-geek.org>
> wrote:
>
>> Eric Mahurin <eric_mahurin@yahoo.com> writes:
>>
>> > n=2**13;(1..n).each{|i|
>> >
>>
>

a=(1..i).to_a;self.class.send(:define_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.send(:define_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.
>
> 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.send(:define_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.send(:define_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.

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).

···

__________________________________
Yahoo! Mail - PC Magazine Editors' Choice 2005

19

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

···

On Sun, 16 Oct 2005, Eric Mahurin wrote:

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).

--

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

===============================================================================

20

Eric Mahurin <eric_mahurin@yahoo.com> writes:

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.

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.send(:define_method,:"f#{i}"){i*i} end;GC.start;
IO.readlines("/proc/#{Process.pid}/status").grep(/VmSize/).display'

VmSize: 11268 kB

YS.