Forum: Ruby Ruby memory usage

8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-07 20:01
Hi Folks,

I'm trying to figure out a memory usage issue with some long running
ruby processes and was wondering if anyone can help me out.

The background is that I have a set of long running ruby processes which
are communicating with a larger system using an activeMQ server via
STOMP. These processes are running for weeks at a time, most of the time
just sitting there waiting for an incoming message.

My team has noticed that these processes memory usage gradually grows
over time. As a concrete example one of my processes starts life using
around ~20MB of virtual memory, and 20 hours later is sitting at 382MB
of virtual memory, 115MB resident.

My first step in trying to figure this out was to use a slightly tweaked
version of the memory profiler described here:
http://scottstuff.net/blog/2006/08/17/memory-leak-....
Essentially I'm just taking a snapshot of ObjectSpace every 10 seconds
and dumping a top 20 count of how many instances there are of a class.
Here are two snapshots, one take a few minutes after the process starts,
and one ~20 hours later:

----------Wed May 06 14:03:33 -0700 2009----------
Top 20
   23724: String
    1121: Hash
     776: Class
     738: Regexp
     578: Array
     474: StatsBucket(id: integer, organization_id: integer,
se_account_id: integer, date: date)
     474: TZInfo::TimezoneTransitionInfo
     374: Proc
     236: Module
     154: Bignum
     152: UnboundMethod
     134: Range
      62: Rational
      57: Float
      34: Gem::Version
      28: ActiveRecord::ConnectionAdapters::MysqlColumn
      27: Time
      22: Gem::Version::Requirement
      17: Mutex
      16: Gem::Specification


----------Thu May 07 10:45:48 -0700 2009----------
Top 20
   23848: String
     834: Class
     790: Bignum
     783: Array
     738: Regexp
     506: Hash
     474: TZInfo::TimezoneTransitionInfo
     376: Proc
     236: Module
     159: StatsBucket(id: integer, organization_id: integer,
se_account_id: integer, date: date)
     152: UnboundMethod
     134: Range
     129: Rational
     107: Float
     104: MatchData
      54: Thread
      46: Timeout::Error
      45: Time
      34: Gem::Version
      32: ActiveRecord::ConnectionAdapters::MysqlColumn



As you can see there's not that much of a change in the ObjectSpace, and
yet the memory usage of this same process has blown up from 20MB to over
300MB of virtual memory.

Can anyone give me any clues on what's going on here? Or any pointers as
to what else I can in terms of measurements and instrumentation to get a
better insight as to what's going here?

Any help greatly appreciated!

Cheers,
Pete
D7463bd611f227cfb2ef4da4a978a203?d=identicon&s=25 Christopher Dicely (Guest)
on 2009-05-07 21:04
(Received via mailing list)
On Thu, May 7, 2009 at 11:01 AM, Pete Hodgson <ruby-forum@thepete.net>
wrote:
> My team has noticed that these processes memory usage gradually grows
> and one ~20 hours later:
>     474: TZInfo::TimezoneTransitionInfo
>      22: Gem::Version::Requirement
>     738: Regexp
>     104: MatchData
> 300MB of virtual memory.
>
> Can anyone give me any clues on what's going on here? Or any pointers as
> to what else I can in terms of measurements and instrumentation to get a
> better insight as to what's going here?

The first thing that jumps to mind is that the 54 instance of Thread
in the later listing may be a sign of the problem; unless you really
should have that many Threads hanging around, you may be doing
something that is preventing used Thread objects from being garbage
collected. If you are, for instance, launching a new thread when you
get a message and they are hanging around after they aren't needed,
that could explain the expanding memory usage.
8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-08 00:19
Christopher Dicely wrote:
> On Thu, May 7, 2009 at 11:01 AM, Pete Hodgson <ruby-forum@thepete.net>
> wrote:
>> My team has noticed that these processes memory usage gradually grows
>> and one ~20 hours later:
>>     474: TZInfo::TimezoneTransitionInfo
>>      22: Gem::Version::Requirement
>>     738: Regexp
>>     104: MatchData
>> 300MB of virtual memory.
>>
>> Can anyone give me any clues on what's going on here? Or any pointers as
>> to what else I can in terms of measurements and instrumentation to get a
>> better insight as to what's going here?
>
> The first thing that jumps to mind is that the 54 instance of Thread
> in the later listing may be a sign of the problem; unless you really
> should have that many Threads hanging around, you may be doing
> something that is preventing used Thread objects from being garbage
> collected. If you are, for instance, launching a new thread when you
> get a message and they are hanging around after they aren't needed,
> that could explain the expanding memory usage.

Hmm, you're right that is strange. I can't think of anywhere where I am
spawning threads after initial start up, so I'll look into that more and
see where that leads. Thanks Christopher!
8e44b211865cd5915f2f883fd960b56d?d=identicon&s=25 Xeno Campanoli (Guest)
on 2009-05-08 01:12
(Received via mailing list)
Pete Hodgson wrote:
> Christopher Dicely wrote:
>> On Thu, May 7, 2009 at 11:01 AM, Pete Hodgson <ruby-forum@thepete.net>
>> wrote:
>>> My team has noticed that these processes memory usage gradually grows

For what it's worth, I have a pretty complex web app with multiple
dimensional
arrays referencing nested classes and it runs really slow when we have
less than
  a gig of memory, which never really made sense to us for the level of
stuff it
was doing.  I may just need to spend a lot more time cleaning up my
code, but
seems to me Ruby can eat a bit more memory than one might expect it
should.

xc
4feed660d3728526797edeb4f0467384?d=identicon&s=25 Bill Kelly (Guest)
on 2009-05-08 01:33
(Received via mailing list)
From: "Pete Hodgson" <ruby-forum@thepete.net>
> Hmm, you're right that is strange. I can't think of anywhere where I am
> spawning threads after initial start up, so I'll look into that more and
> see where that leads. Thanks Christopher!

Also, what's your ruby -v ?

Some versions of 1.8.6 have leaked memory, for instance.


Regards,

Bill
2f55791ab9018b4d01fb741fab21843d?d=identicon&s=25 Tony Arcieri (Guest)
on 2009-05-08 05:59
(Received via mailing list)
On Thu, May 7, 2009 at 12:01 PM, Pete Hodgson
<ruby-forum@thepete.net>wrote:

> My team has noticed that these processes memory usage gradually grows
> over time. As a concrete example one of my processes starts life using
> around ~20MB of virtual memory, and 20 hours later is sitting at 382MB
> of virtual memory, 115MB resident.
>

One thing to keep in mind is that MRI's garbage collector never returns
memory to the system, and doesn't do a very good job in general.  MRI
has a
tendency towards unbounded heap growth over time, especially in
long-running
processes.

You might try JRuby if you don't have too many dependencies on C
extensions.  It uses the advanced garbage collection available in the
JVM.
E0d864d9677f3c1482a20152b7cac0e2?d=identicon&s=25 Robert Klemme (Guest)
on 2009-05-08 11:12
(Received via mailing list)
2009/5/8 Tony Arcieri <tony@medioh.com>:
> tendency towards unbounded heap growth over time, especially in long-running
> processes.

I believe this has changed with 1.9.1 - at least memory usage seems to
not grow as much as with 1.8.*.

Btw, you can easily construct a memory leak, which cannot necessarily
be detected by counting objects:

ruby19 -e 's="."*1024;t="";loop do t << s end'

I.e., you can grow any String which is not frozen to arbitrary lengths.

Btw, Pete, you might get more insight into your application if you
dump deltas of object counts.  IIRC we had a sample here in the group
but I cannot find it at the moment.

Kind regards

robert
Bec38d63650c8912b6ba9b557fb953b9?d=identicon&s=25 Roger Pack (rogerdpack)
on 2009-05-08 14:27
Pete Hodgson wrote:
> Hi Folks,
>
> I'm trying to figure out a memory usage issue with some long running
> ruby processes and was wondering if anyone can help me out.

If it's poor GC you could try out the MBARI patches.  I had a rails app
that grew by 8MB /request *every request* until I switched to MBARI--now
it works like a charm.  Good luck!
-=r
47b1910084592eb77a032bc7d8d1a84e?d=identicon&s=25 Joel VanderWerf (Guest)
on 2009-05-08 18:24
(Received via mailing list)
Robert Klemme wrote:
> Btw, you can easily construct a memory leak, which cannot necessarily
> be detected by counting objects:
>
> ruby19 -e 's="."*1024;t="";loop do t << s end'
>
> I.e., you can grow any String which is not frozen to arbitrary lengths.

That not really a leak, though, since t is referenced...

Not that this situation isn't a potential problem, but we should make
sure everyone understands that the blame for it rests squarely on the
programmer and not on ruby's GC.
E0d864d9677f3c1482a20152b7cac0e2?d=identicon&s=25 Robert Klemme (Guest)
on 2009-05-08 18:31
(Received via mailing list)
On 08.05.2009 18:24, Joel VanderWerf wrote:
> Robert Klemme wrote:
>> Btw, you can easily construct a memory leak, which cannot necessarily
>> be detected by counting objects:
>>
>> ruby19 -e 's="."*1024;t="";loop do t << s end'
>>
>> I.e., you can grow any String which is not frozen to arbitrary lengths.
>
> That not really a leak, though, since t is referenced...

Well, AFAIK the definition of "memory leak" in GC languages is that of
objects kept longer than needed.  So if someone creates a program which
simply appends text to a String over and over again where creating new
short strings would be sufficient he has created a memory leak IMHO.

My main point though was to demonstrate that memory usage and object
count do not necessarily correlate.

> Not that this situation isn't a potential problem, but we should make
> sure everyone understands that the blame for it rests squarely on the
> programmer and not on ruby's GC.

Yep!

Kind regards

  robert
Bec38d63650c8912b6ba9b557fb953b9?d=identicon&s=25 Roger Pack (rogerdpack)
on 2009-05-08 19:04
>> ruby19 -e 's="."*1024;t="";loop do t << s end'
>>
>> I.e., you can grow any String which is not frozen to arbitrary lengths.
>
> That not really a leak, though, since t is referenced...
>
> Not that this situation isn't a potential problem, but we should make
> sure everyone understands that the blame for it rests squarely on the
> programmer and not on ruby's GC.

In this particular case the problem definitely lies with the programmer.
However, in some other instances ruby's GC really does stink (but
hopefully the MBARI patches overcome its deficiencies, and also Ruby 1.9
should have fewer problems since its threads use distinct thread memory
spaces so can't share ghost references).
Cheers!
-=r
8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-08 22:49
Thanks so much for all the input folks, it's really really appreciated.

ruby -v gives:
ruby 1.8.6 (2008-06-20 patchlevel 230) [i386-linux]


I did some additional tweaks to the memory profiler, and it now dumps a
yaml document with object space details every 10 seconds. I did some
analysis on discovered that:

- Virtual memory grows in a straight line serially over time
- Resident memory grows up to a point, then start fluctuating. I'm
presuming that's the kernel starting to reclaim resident memory from the
process as it starts to run out of physical memory.
- Object counts stay almost entirely flat over time.

At this point I wonder whether the issue is with the MRI GC, as Tony
mentioned. I'm a little leary of upgrading to 1.9 just in order to fix
this, but I might give it a try just to see what the memory usage over
time looks like compared to 1.8.6.
8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-08 23:33
Pete Hodgson wrote:
>
> Thanks so much for all the input folks, it's really really appreciated.
>
> ruby -v gives:
> ruby 1.8.6 (2008-06-20 patchlevel 230) [i386-linux]
>
>
> I did some additional tweaks to the memory profiler, and it now dumps a
> yaml document with object space details every 10 seconds. I did some
> analysis on discovered that:
>
> - Virtual memory grows in a straight line serially over time
> - Resident memory grows up to a point, then start fluctuating. I'm
> presuming that's the kernel starting to reclaim resident memory from the
> process as it starts to run out of physical memory.
> - Object counts stay almost entirely flat over time.
>
> At this point I wonder whether the issue is with the MRI GC, as Tony
> mentioned. I'm a little leary of upgrading to 1.9 just in order to fix
> this, but I might give it a try just to see what the memory usage over
> time looks like compared to 1.8.6.

I charted out memory usage over time and object space usage over time to
illustrate what I'm seeing:

http://dl.getdropbox.com/u/796485/mercury_mem_usage.jpg
http://dl.getdropbox.com/u/796485/mercury_object_counts.jpg
7838393e522d4b6daf208ee3c30ff2e9?d=identicon&s=25 Fleck Jean-Julien (Guest)
on 2009-05-08 23:56
(Received via mailing list)
Hello,

>
> I charted out memory usage over time and object space usage over time to
> illustrate what I'm seeing:
>
> http://dl.getdropbox.com/u/796485/mercury_mem_usage.jpg
> http://dl.getdropbox.com/u/796485/mercury_object_counts.jpg

Which type of object is the red curve (between 500 and 1000) that
makes one jump up when memory start raising and begins to behave
erraticaly approximately at the same time resident memory does ?

Cheers,

JJ
2f55791ab9018b4d01fb741fab21843d?d=identicon&s=25 Tony Arcieri (Guest)
on 2009-05-09 00:05
(Received via mailing list)
On Fri, May 8, 2009 at 2:49 PM, Pete Hodgson <ruby-forum@thepete.net>
wrote:

>
> Thanks so much for all the input folks, it's really really appreciated.
>
> ruby -v gives:
> ruby 1.8.6 (2008-06-20 patchlevel 230) [i386-linux]
>
>
> I did some additional tweaks to the memory profiler, and it now dumps a
> yaml document with object space details every 10 seconds.


I think memory profiling using ObjectSpace is fundamentally flawed (a
few
years ago I wrote an ObjectSpace-powered memory profiler and had many
issues
with it)

You might check out bleak_house instead:

http://blog.evanweaver.com/files/doc/fauna/bleak_h...


> At this point I wonder whether the issue is with the MRI GC, as Tony
> mentioned. I'm a little leary of upgrading to 1.9 just in order to fix
> this, but I might give it a try just to see what the memory usage over
> time looks like compared to 1.8.6.
>

With JRuby you can have 1.8 compatibility plus your selection of all the
pluggable garbage collectors available in the JVM.
8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-09 00:46
Fleck Jean-Julien wrote:
> Hello,
>
>>
>> I charted out memory usage over time and object space usage over time to
>> illustrate what I'm seeing:
>>
>> http://dl.getdropbox.com/u/796485/mercury_mem_usage.jpg
>> http://dl.getdropbox.com/u/796485/mercury_object_counts.jpg
>
> Which type of object is the red curve (between 500 and 1000) that
> makes one jump up when memory start raising and begins to behave
> erraticaly approximately at the same time resident memory does ?
>
> Cheers,
>
> JJ

instances of Array. Not sure why it starts behaving like that at the
same time residential memory does.
8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-09 00:49
Tony Arcieri wrote:
> On Fri, May 8, 2009 at 2:49 PM, Pete Hodgson <ruby-forum@thepete.net>
> wrote:
>
>>
>> Thanks so much for all the input folks, it's really really appreciated.
>>
>> ruby -v gives:
>> ruby 1.8.6 (2008-06-20 patchlevel 230) [i386-linux]
>>
>>
>> I did some additional tweaks to the memory profiler, and it now dumps a
>> yaml document with object space details every 10 seconds.
>
>
> I think memory profiling using ObjectSpace is fundamentally flawed (a
> few
> years ago I wrote an ObjectSpace-powered memory profiler and had many
> issues
> with it)
>
> You might check out bleak_house instead:
>
> http://blog.evanweaver.com/files/doc/fauna/bleak_h...
>

I'm thinking that is probably gonna have to be the next step. I had a
bad experience trying to set it up in the past and now am a bit gun shy,
but I'm running out of options here...

>
>> At this point I wonder whether the issue is with the MRI GC, as Tony
>> mentioned. I'm a little leary of upgrading to 1.9 just in order to fix
>> this, but I might give it a try just to see what the memory usage over
>> time looks like compared to 1.8.6.
>>
>
> With JRuby you can have 1.8 compatibility plus your selection of all the
> pluggable garbage collectors available in the JVM.


Thanks, I'll give JRuby a run on a VM and see how it performs. I'm
guessing that bleak_house and JRuby don't play together?
4feed660d3728526797edeb4f0467384?d=identicon&s=25 Bill Kelly (Guest)
on 2009-05-09 01:52
(Received via mailing list)
From: "Pete Hodgson" <ruby-forum@thepete.net>
>
> ruby -v gives:
> ruby 1.8.6 (2008-06-20 patchlevel 230) [i386-linux]

patchlevel 230 was one of the bad ones.  It leaks like a sieve.

See [ruby-core] thread:

[Ruby 1.8 - Bug #216] Memory leaks in 1.8.6p230 and p238
http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...

It affected a whole range of patchlevels:
http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...


Also, a leak of similar severity was introduced later on, starting
in p296 lasting at least through p355:

[ruby-core:22582] Re: [Bug #1223] Memory leak reintroduced in 1.8.6
branch?
http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...

I'd recommend trying the recent official 1.8.6 release, p368
http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...

I have not personally tried p368 on my long-running servers, as
I had already found a stable version, p279.  So I have not had a
need to upgrade the version.  I can say that p279 is very stable
in its memory profile.  I'm guessing the official p368 release
probably is too.


Hope this helps,

Bill
F1d6cc2b735bfd82c8773172da2aeab9?d=identicon&s=25 Nobuyoshi Nakada (nobu)
on 2009-05-09 02:21
(Received via mailing list)
Hi,

At Fri, 8 May 2009 12:57:52 +0900,
Tony Arcieri wrote in [ruby-talk:336091]:
> One thing to keep in mind is that MRI's garbage collector never returns
> memory to the system, and doesn't do a very good job in general.  MRI has a
> tendency towards unbounded heap growth over time, especially in long-running
> processes.

You know only pretty old versions.
Bec38d63650c8912b6ba9b557fb953b9?d=identicon&s=25 Roger Pack (rogerdpack)
on 2009-05-09 04:31
>> With JRuby you can have 1.8 compatibility plus your selection of all the
>> pluggable garbage collectors available in the JVM.
>
>
> Thanks, I'll give JRuby a run on a VM and see how it performs. I'm
> guessing that bleak_house and JRuby don't play together?

bleak house is a patched mri to provide quick access to its internals.
As an alternative to 1.9 you could try mbari patches, which are patched
versions of 1.8.7 and 1.8.6
GL!
-=r
8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-09 23:20
Bill Kelly wrote:
> From: "Pete Hodgson" <ruby-forum@thepete.net>
>>
>> ruby -v gives:
>> ruby 1.8.6 (2008-06-20 patchlevel 230) [i386-linux]
>
> patchlevel 230 was one of the bad ones.  It leaks like a sieve.
>
> See [ruby-core] thread:
>
> [Ruby 1.8 - Bug #216] Memory leaks in 1.8.6p230 and p238
> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>
> It affected a whole range of patchlevels:
> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>
>
> Also, a leak of similar severity was introduced later on, starting
> in p296 lasting at least through p355:
>
> [ruby-core:22582] Re: [Bug #1223] Memory leak reintroduced in 1.8.6
> branch?
> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>
> I'd recommend trying the recent official 1.8.6 release, p368
> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>
> I have not personally tried p368 on my long-running servers, as
> I had already found a stable version, p279.  So I have not had a
> need to upgrade the version.  I can say that p279 is very stable
> in its memory profile.  I'm guessing the official p368 release
> probably is too.
>
>
> Hope this helps,
>
> Bill


Great info Bill, thanks so much. I'll try building 1.8.6-p368 and see if
the same component exhibits different behaviour running under that
build.

Assuming that helps, does anyone have any pointers on putting a
non-standard ruby rpm onto a centOS box? My company use centos in
production and I'm betting that my Ops guys will want an rpm, official
or otherwise.
8903a75dedc9892d0702dfe027c95011?d=identicon&s=25 Pete Hodgson (moredip)
on 2009-05-11 05:28
Pete Hodgson wrote:
> Bill Kelly wrote:
>> From: "Pete Hodgson" <ruby-forum@thepete.net>
>>>
>>> ruby -v gives:
>>> ruby 1.8.6 (2008-06-20 patchlevel 230) [i386-linux]
>>
>> patchlevel 230 was one of the bad ones.  It leaks like a sieve.
>>
>> See [ruby-core] thread:
>>
>> [Ruby 1.8 - Bug #216] Memory leaks in 1.8.6p230 and p238
>> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>>
>> It affected a whole range of patchlevels:
>> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>>
>>
>> Also, a leak of similar severity was introduced later on, starting
>> in p296 lasting at least through p355:
>>
>> [ruby-core:22582] Re: [Bug #1223] Memory leak reintroduced in 1.8.6
>> branch?
>> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>>
>> I'd recommend trying the recent official 1.8.6 release, p368
>> http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/...
>>
>> I have not personally tried p368 on my long-running servers, as
>> I had already found a stable version, p279.  So I have not had a
>> need to upgrade the version.  I can say that p279 is very stable
>> in its memory profile.  I'm guessing the official p368 release
>> probably is too.
>>
>>
>> Hope this helps,
>>
>> Bill
>
>
> Great info Bill, thanks so much. I'll try building 1.8.6-p368 and see if
> the same component exhibits different behaviour running under that
> build.
>
> Assuming that helps, does anyone have any pointers on putting a
> non-standard ruby rpm onto a centOS box? My company use centos in
> production and I'm betting that my Ops guys will want an rpm, official
> or otherwise.


I've ran the same component side by side on both p230 and p368 for a few
hours. The p368 component is holding steady at around 19MB, while the
p230 component is up to 83MB resident, 98MB virtual. Looks like the
culprit was indeed a leaky interpreter.

Bill, thanks so much for pointing me in such a fruitful direction.

I guess my solution will be to upgrade our production machines to the
new p368 build.

Cheers,
Pete
4feed660d3728526797edeb4f0467384?d=identicon&s=25 Bill Kelly (Guest)
on 2009-05-11 05:37
(Received via mailing list)
From: "Pete Hodgson" <ruby-forum@thepete.net>
>
> Assuming that helps, does anyone have any pointers on putting a
> non-standard ruby rpm onto a centOS box? My company use centos in
> production and I'm betting that my Ops guys will want an rpm, official
> or otherwise.

I've not tried it, but checkinstall is supposedly able to capture
whatever
"make install" would do, and then "create a Slackware, RPM or Debian
compatible package and install it using your distribution's standard
package administration utilities."

http://checkinstall.izto.org/docs.php


Hope this helps,

Bill
Please log in before posting. Registration is free and takes only a minute.
Existing account

NEW: Do you have a Google/GoogleMail, Yahoo or Facebook account? No registration required!
Log in with Google account | Log in with Yahoo account | Log in with Facebook account
No account? Register here.