Asp Forum - Ruby memory usage

Pete Hodgson

5/7/2009 6:01:00 PM

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-profiling-....
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
--
Posted via http://www.ruby-....

22 Answers

Christopher Dicely

5/7/2009 7:02:00 PM

On Thu, May 7, 2009 at 11:01 AM, Pete Hodgson <ruby-forum@thepete.net> wrot=
e:
> 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-profiling-....
> 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
> =C2=A0 23724: String
> =C2=A0 =C2=A01121: Hash
> =C2=A0 =C2=A0 776: Class
> =C2=A0 =C2=A0 738: Regexp
> =C2=A0 =C2=A0 578: Array
> =C2=A0 =C2=A0 474: StatsBucket(id: integer, organization_id: integer,
> se_account_id: integer, date: date)
> =C2=A0 =C2=A0 474: TZInfo::TimezoneTransitionInfo
> =C2=A0 =C2=A0 374: Proc
> =C2=A0 =C2=A0 236: Module
> =C2=A0 =C2=A0 154: Bignum
> =C2=A0 =C2=A0 152: UnboundMethod
> =C2=A0 =C2=A0 134: Range
> =C2=A0 =C2=A0 =C2=A062: Rational
> =C2=A0 =C2=A0 =C2=A057: Float
> =C2=A0 =C2=A0 =C2=A034: Gem::Version
> =C2=A0 =C2=A0 =C2=A028: ActiveRecord::ConnectionAdapters::MysqlColumn
> =C2=A0 =C2=A0 =C2=A027: Time
> =C2=A0 =C2=A0 =C2=A022: Gem::Version::Requirement
> =C2=A0 =C2=A0 =C2=A017: Mutex
> =C2=A0 =C2=A0 =C2=A016: Gem::Specification
>
>
> ----------Thu May 07 10:45:48 -0700 2009----------
> Top 20
> =C2=A0 23848: String
> =C2=A0 =C2=A0 834: Class
> =C2=A0 =C2=A0 790: Bignum
> =C2=A0 =C2=A0 783: Array
> =C2=A0 =C2=A0 738: Regexp
> =C2=A0 =C2=A0 506: Hash
> =C2=A0 =C2=A0 474: TZInfo::TimezoneTransitionInfo
> =C2=A0 =C2=A0 376: Proc
> =C2=A0 =C2=A0 236: Module
> =C2=A0 =C2=A0 159: StatsBucket(id: integer, organization_id: integer,
> se_account_id: integer, date: date)
> =C2=A0 =C2=A0 152: UnboundMethod
> =C2=A0 =C2=A0 134: Range
> =C2=A0 =C2=A0 129: Rational
> =C2=A0 =C2=A0 107: Float
> =C2=A0 =C2=A0 104: MatchData
> =C2=A0 =C2=A0 =C2=A054: Thread
> =C2=A0 =C2=A0 =C2=A046: Timeout::Error
> =C2=A0 =C2=A0 =C2=A045: Time
> =C2=A0 =C2=A0 =C2=A034: Gem::Version
> =C2=A0 =C2=A0 =C2=A032: 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?

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.

Pete Hodgson

5/7/2009 10:20:00 PM

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!
--
Posted via http://www.ruby-....

Xeno Campanoli

5/7/2009 11:12:00 PM

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

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

--
"I told the Republicans that when they stopped lying about me I'd stop
telling the truth about them" -- Harry Truman.

Bill Kelly

5/7/2009 11:32:00 PM

From: "Pete Hodgson" <ruby-forum@thepete.net>
>
> Christopher Dicely wrote:
>> 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!

Also, what's your ruby -v ?

Some versions of 1.8.6 have leaked memory, for instance.

Regards,

Bill

Tony Arcieri

5/8/2009 3:58:00 AM

[Note: parts of this message were removed to make it a legal post.]

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.

--
Tony Arcieri
medioh.com

Robert Klemme

5/8/2009 9:12:00 AM

2009/5/8 Tony Arcieri <tony@medioh.com>:
> On Thu, May 7, 2009 at 12:01 PM, Pete Hodgson <ruby-forum@thepete.net>wro=
te:
>
>> 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. =A0MRI h=
as a
> tendency towards unbounded heap growth over time, especially in long-runn=
ing
> 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=3D"."*1024;t=3D"";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

--=20
remember.guy do |as, often| as.you_can - without end
http://blog.rubybestprac...

Roger Pack

5/8/2009 12:27:00 PM

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
--
Posted via http://www.ruby-....

Joel VanderWerf

5/8/2009 4:24:00 PM

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.

--
vjoel : Joel VanderWerf : path berkeley edu : 510 665 3407

Robert Klemme

5/8/2009 4:30:00 PM

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

--
remember.guy do |as, often| as.you_can - without end
http://blog.rubybestprac...

Roger Pack

5/8/2009 5:04:00 PM

>> 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
--
Posted via http://www.ruby-....

comp.lang.ruby

Ruby memory usage

Pete Hodgson

Christopher Dicely

Pete Hodgson

Xeno Campanoli

Bill Kelly

Tony Arcieri

Robert Klemme

Roger Pack

Joel VanderWerf

Robert Klemme

Roger Pack

x Login to ForumsZone