From: Tal Yalon <tal.yalon@...>
Date: 2011-02-09T16:58:52+09:00
Subject: Re: Memory leak in 1.9.2-p330?

--0016363b8d8ccc377e049bd4d518
Content-Type: text/plain; charset=ISO-8859-1

Okay,

I ran your code on 1.8.7 (2010-08-16 patchlevel 302) [i686-darwin10.5.0],
and it did not crash, although interestingly enough it did produce the same
leak that I've experienced on 1.9.2-p302!

BTW on my 1.9.2-p302 it didn't ran fine - it didn't crash, but leaked -
exactly which version of 1.9 were you using?

Now, to get things even more interesting, I took your code (that leaked on
both ruby versions I have) and moved the "max_items = [ max_items,
queue.size ].max" line to be before the if() condition. This corrects a
potential bug where max_items would be calculated every second, missing
theoretical spikes in the queue size. Below is the modified code.

Running that code for a few minutes on both versions did _not_ produce any
leak whatsoever... So this is very strange indeed. Can you verify that it
works for you too?

#!/usr/bin/env ruby

time_to_print = Time.now

i = max_rss = max_items = 0

queue = []

while true
 start = Time.now
 interval = 2 # seconds

 queue << start

 while !queue.empty? && (Time.now - queue.first) > interval
  queue.shift
 end

 # MOVED max_items CALC TO HERE
 max_items = [ max_items, queue.size ].max
 if Time.now - time_to_print >= 0
  rss = `ps -o rss= -p #{Process.pid}`.to_i
  max_rss = [ max_rss, rss].max
  puts "#{start.to_i} iters=#{i} queue_size=#{queue.size} rss=#{rss} max
queue_size=#{max_items} rss=#{max_rss}"
  time_to_print = Time.now + 1
 end

 i += 1
end


On Tue, Feb 8, 2011 at 7:57 PM, Adam Prescott <mentionuse@gmail.com> wrote:

> On Tue, Feb 8, 2011 at 3:07 PM, Tal Yalon <tal.yalon@gmail.com> wrote:
>
> > Hi all,
> >
> > Before I go and submit a bug report, I would appreciate a fresh pair of
> > eyes
> > hopefully finding a bug in the code and not in Ruby :)
> >
> > The code pushes elements to a "time window" queue of 2 seconds. Although
> I
> > see that the maximum queue size stabilizes after a very short time
> (couple
> > of seconds), the process's max RSS size starts to grow after a while 2
> > minutes.
> > Interestingly enough, the max RSS size stays fixed when running with
> 1.8.7.
> > All tests were done on Ruby compiled using rvm.
> >
> > Printing the process's RSS and max RSS size was done to observe the leak
> in
> > action, This code also leaks when removing the lines that execute ps and
> > print it.
> >
> > Any idea will be welcomed.
> >
> > Thanks,
> > Tal
> >
> > #!/usr/bin/env ruby
> >
> > before = Time.now.to_i
> > i = 0
> > max_rss = 0
> > max_items = 0
> >
> > queue = []
> > while true
> >  now = Time.now.to_i
> >  windows_start_time = now - 2
> >  queue << now
> >  while not queue.empty? and queue[0] < windows_start_time
> >    queue.shift
> >  end
> >
> >  if now - before >= 1
> >    max_items = [ max_items, queue.size ].max
> >    rss = `ps -o rss= -p #{Process.pid}`.to_i
> >    max_rss = [ max_rss, rss].max
> >    print("#{now} iters=#{i} queue_size=#{queue.size} rss=#{rss}, max:
> > queue_size=#{max_items}, rss=#{max_rss}\n")
> >    before = now
> >  end
> >  i += 1
> > end
> >
>
> This is the error I was getting running your code:
>
> /tmp/orig:8: [BUG] Segmentation fault
> ruby 1.8.7 (2009-06-12 patchlevel 174) [universal-darwin10.0]
>
> Abort trap
>
> In 1.9 it was running fine, as you said.
>
> I was having some trouble reading your code so I did some tidying to get
> this:
>
>
>
> time_to_print = Time.now
>
> i = max_rss = max_items = 0
>
> queue = []
>
> while true
>  start = Time.now
>  interval = 2 # seconds
>
>  queue << start
>
>  while !queue.empty? && (Time.now - queue.first) > interval
>   queue.shift
>  end
>
>  if Time.now - time_to_print >= 0
>    max_items = [ max_items, queue.size ].max
>   rss = `ps -o rss= -p #{Process.pid}`.to_i
>   max_rss = [ max_rss, rss].max
>    puts "#{start.to_i} iters=#{i} queue_size=#{queue.size} rss=#{rss} max
> queue_size=#{max_items} rss=#{max_rss}"
>    time_to_print = Time.now + 1
>  end
>
>  i += 1
> end
>
>
> The inner conditional chunk uses a Time.now in the comparison against
> time_to_print, whereas before it hooked into now and before. It's also
> using
> Time instances and not working off just integers.
>
> However, this code now works fine on 1.8.7 and 1.9, for me.
>
> Maybe this could highlight whatever is causing the bug in 1.8.7 in the
> original code? Personally, I'm just more confused as to what might be
> causing it!
>

--0016363b8d8ccc377e049bd4d518--