jakarta-jcs-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Daniel Rosenbaum <drosenb...@yahoo.com>
Subject RE: Memory test
Date Mon, 15 Sep 2003 21:07:58 GMT
I am using JDK 1.4.1

After some further testing I beleive I found the problem.  The
purgatory is not being emptied quickly enough.

To determine this, I modified AbstractDiskCache and added log
statements by the purgatory.remove() calls in the code to log
which key is being removed.  I also lessened that amount of
available memory to the jvm to arrive at an OutOfMemoryError
quicker.  These were the last of my results:

i=200000
i=201000
i=202000
i=203000
i=204000
removing from purg key = testkey751
removing from purg key = testkey752
removing from purg key = testkey753
i=205000
i=206000
java.lang.OutOfMemoryError

What you can see is that even when got to i=204000, only keys
751, 752 and 753 was being removed from the purgatory at that
time.  The cache event queue is not firing events nearly fast
enough to keep up with this loop.

When I added a 100 ms delay though into this loop after each put
the remove events show up more in sync with the current i and
memory seems to be stable. 

I suppose this is not too bad, since in real life it would be
rare that objects would be put into a cache as rapidly as they
were in my loop.  There would typically be a delay between
putting things into the cache.  So this test fails, but it
doesn't indicate that there would be a memory leak in a real
world application.

Another option is to modify the code to fire cache events more
often.  This may be good to satisfy this test but probably would
degrade performance in a real world app if the events get fired
too often.

hmmmm :-)

Daniel


--- Amy Wang <amy.wang@intersperse.com> wrote:
> what jvm you are using?
> 
> > -----Original Message-----
> > From: Daniel Rosenbaum [mailto:drosenbaum@yahoo.com]
> > Sent: Thursday, September 11, 2003 10:01 AM
> > To: Turbine JCS Users List
> > Subject: RE: Memory test
> > 
> > 
> > By the way I also removed the Thread.sleep(10) code and ran
> > without the indexed disk cache.  Memory was stable and
> within 10
> > minutes I already cached more than 150 million items.  I am
> sure
> > if I would have let it keep running it would have completed
> the
> > loop to 2 billion.  Go garbage collection is working by
> memory
> > only, but still not be indexed disk.
> > 
> > Daniel
> > 
> > --- Daniel Rosenbaum <drosenbaum@yahoo.com> wrote:
> > > Setting the memory shrinker to false had no effect, memory
> was
> > > still leaking.
> > > 
> > > When I switched off the aux disk cache though memory is
> very
> > > stable.  This seems to indicate a problem with the disk
> cache.
> > > 
> > > Daniel
> > > 
> > > --- Aaron Smuts <aasmuts@wisc.edu> wrote:
> > > > If turning off the memory shrinker doesn't work, try not
> > > using
> > > > a disk
> > > > cache at all.  
> > > > 
> > > > I want to isolate the issue.
> > > > 
> > > > Aaron
> > > > 
> > > > > -----Original Message-----
> > > > > From: Daniel Rosenbaum [mailto:drosenbaum@yahoo.com]
> > > > > Sent: Thursday, September 11, 2003 9:39 AM
> > > > > To: Turbine JCS Users List
> > > > > Subject: RE: Memory test
> > > > > 
> > > > > As a follow up, I let my test run for a while and
> after
> > > > about 5
> > > > > hours my JVM crashed with a
> java.lang.OutOfMemoryError,
> > > > after
> > > > > putting somewhere bewtween 3087000-3088000 items into
> the
> > > > cache.
> > > > >  My system has 512 megs of ram.  Following are the
> last
> > > few
> > > > > lines of my log:
> > > > > 
> > > > > Sep 10 21:00:35 2003: i=3086000
> > > > > Sep 10 21:00:35 2003: avail = 2757728
> > > > > Sep 10 21:00:35 2003: total = 524025856
> > > > > Sep 10 21:00:35 2003: [GC
> > > > > Sep 10 21:00:35 2003:  509217K->507306K(511744K)
> > > > > Sep 10 21:00:35 2003: , 0.0695549 secs]
> > > > > Sep 10 21:00:35 2003:
> > > > > Sep 10 21:00:36 2003: [GC
> > > > > Sep 10 21:00:36 2003:  509354K->507447K(511744K)
> > > > > Sep 10 21:00:36 2003: , 0.0713898 secs]
> > > > > Sep 10 21:00:36 2003:
> > > > > Sep 10 21:00:37 2003: [Full GC
> > > > > Sep 10 21:17:39 2003:  509495K->507573K(511744K)
> > > > > Sep 10 21:17:39 2003: , 1019.7951857 secs]
> > > > > Sep 10 21:17:39 2003:
> > > > > Sep 10 21:17:41 2003: i=3087000
> > > > > Sep 10 21:17:44 2003: avail = 3737904
> > > > > Sep 10 21:17:44 2003: total = 524025856
> > > > > Sep 10 21:17:45 2003: [Full GC
> > > > > Sep 10 21:30:07 2003:  511743K->509584K(511744K)
> > > > > Sep 10 21:30:07 2003: , 739.8379643 secs]
> > > > > Sep 10 21:30:07 2003:
> > > > > Sep 10 21:30:07 2003: [Full GC
> > > > > Sep 10 21:43:08 2003:  509584K->509584K(511744K)
> > > > > Sep 10 21:43:08 2003: , 798.5084294 secs]
> > > > > Sep 10 21:43:08 2003:
> > > > > Sep 10 21:43:09 2003: java.lang.OutOfMemoryError
> > > > > Sep 10 21:43:12 2003: 	<<no stack trace available>>
> > > > > 
> > > > > Notice especially the Full GCs, which took 739 and 798
> > > > seconds
> > > > > to complete.  You could see there was probably alot of
> > > > virtual
> > > > > memory swapping at that point, the system trying to
> stay
> > > > alive
> > > > > until it quit.
> > > > > 
> > > > > Seems there is a memory leak somewhere, doesn't it?
> > > > > 
> > > > > I wonder if it has anything to do with the
> > > IndexedDiskCache
> > > > file
> > > > > itself.  The documentation says "Depending on the key
> > > size,
> > > > > 500,000 disk entries will probably only require about
> 1 MB
> > > > of
> > > > > memory."  This has not been my experience though with
> my
> > > > test.
> > > > > According to the logs I posted before, 1000 elements
> > > between
> > > > > i=2000 and i=3000 required 4341272-3843352=497920, or
> an
> > > > average
> > > > > of 497.92 bytes per element. (I looked for a log entry
> in
> > > > which
> > > > > there was no GC between two log writings and the total
> > > > memory
> > > > > had the same number).  Later on, I had this:
> > > > > 
> > > > > Sep 10 18:49:52 2003: i=1531000
> > > > > Sep 10 18:49:52 2003: avail = 90172696
> > > > > Sep 10 18:49:52 2003: total = 382328832
> > > > > Sep 10 18:49:53 2003: [GC
> > > > > Sep 10 18:49:53 2003:  286864K->284953K(373368K)
> > > > > Sep 10 18:49:53 2003: , 0.0060882 secs]
> > > > > Sep 10 18:49:53 2003:
> > > > > Sep 10 18:49:54 2003: [GC
> > > > > Sep 10 18:49:54 2003:  287001K->285095K(373368K)
> > > > > Sep 10 18:49:54 2003: , 0.0062273 secs]
> > > > > Sep 10 18:49:54 2003:
> > > > > Sep 10 18:49:54 2003: i=1532000
> > > > > Sep 10 18:49:54 2003: avail = 89255520
> > > > > Sep 10 18:49:54 2003: total = 382328832
> > > > > 
> > > > > So between i=1531000 and i=1532000, there was
> > > > > 90172696-89255520=917176, or an average of 917.176
> bytes
> > > per
> > > > > item!  Grew almost 2x!  This is even with two GCs
> between
> > > > them.
> > > > > 
> > > > > The bottom line is, something is definately eating up
> > > > memory.
> > > > > 
> > > > > Daniel
> > > > > 
> > > > > 
> > > > > --- Daniel Rosenbaum <drosenbaum@yahoo.com> wrote:
> > > > > > Thanks Wayne and Amy for your help.
> > > > > >
> > > > > > Firstly with the -verbose:gc option, I modified my
> code
> > > as
> > > > > > follows:
> > > > > >
> > > > > > for(int i=0; i < 200000000; i++) {
> > > > > >   Vector vec = new Vector();
> > > > > >   testCache.put(key+i, vec);
> > > > > >   if (i%1000==0) {
> > > > > >     System.out.println("i=" + i);
> > > > > >     System.out.println("avail = " +
> > > > > > Runtime.getRuntime().freeMemory());
> > > > > >     System.out.println("total = " +
> > > > > > Runtime.getRuntime().totalMemory());
> > > > > >   }
> > > > > > }
> > > > > >
> > > > > > so info would be dumped out every 1000 elements. 
> > > Partial
> > > > > > results are:
> > > > > >
> > > > > > Sep 10 10:22:46 2003: i=0
> > > > > > Sep 10 10:22:46 2003: avail = 500208
> > > > > > Sep 10 10:22:46 2003: total = 7782400
> > > > > > Sep 10 10:22:46 2003: [GC
> > > > > > Sep 10 10:22:46 2003:  7431K->7237K(7856K)
> > > > > > Sep 10 10:22:46 2003: , 0.0086215 secs]
> > > > > > Sep 10 10:22:46 2003:
> > > > > > Sep 10 10:22:46 2003: i=1000
> > > > > > Sep 10 10:22:46 2003: avail = 443920
> > > > > > Sep 10 10:22:46 2003: total = 8044544
> > > > > > Sep 10 10:22:46 2003: [Full GC
> > > > > > Sep 10 10:22:47 2003:  7749K->5441K(9840K)
> > > > > > Sep 10 10:22:47 2003: , 0.1197119 secs]
> > > > > > Sep 10 10:22:47 2003:
> > > > > > Sep 10 10:22:47 2003: i=2000
> > > > > > Sep 10 10:22:47 2003: avail = 4341272
> > > > > > Sep 10 10:22:47 2003: total = 10076160
> > > > > > Sep 10 10:22:47 2003: i=3000
> > > > > > Sep 10 10:22:47 2003: avail = 3843352
> > > > > > Sep 10 10:22:47 2003: total = 10076160
> > > > > > Sep 10 10:22:47 2003: [GC
> > > > > > Sep 10 10:22:47 2003:  6145K->5949K(9840K)
> > > > > > Sep 10 10:22:47 2003: , 0.0081893 secs]
> > > > > > Sep 10 10:22:47 2003:
> > > > > > Sep 10 10:22:47 2003: i=4000
> > > > > > Sep 10 10:22:47 2003: avail = 3570144
> > > > > > Sep 10 10:22:47 2003: total = 10076160
> > > > > > Sep 10 10:22:47 2003: [GC
> > > > > > Sep 10 10:22:47 2003:  6653K->6451K(9840K)
> > > > > > Sep 10 10:22:47 2003: , 0.0078136 secs]
> > > > > > Sep 10 10:22:47 2003:
> > > > > > Sep 10 10:22:47 2003: i=5000
> > > > > > Sep 10 10:22:47 2003: avail = 3255256
> > > > > > Sep 10 10:22:47 2003: total = 10076160
> > > > > > Sep 10 10:22:47 2003: i=6000
> > > > > > Sep 10 10:22:47 2003: avail = 2781920
> > > > > > Sep 10 10:22:47 2003: total = 10076160
> > > > > > Sep 10 10:22:47 2003: [GC
> > > > > > Sep 10 10:22:47 2003:  7155K->6964K(9840K)
> > > > > > Sep 10 10:22:47 2003: , 0.0088930 secs]
> > > > > > Sep 10 10:22:47 2003:
> > > > > > Sep 10 10:22:47 2003: i=7000
> > > > > > Sep 10 10:22:47 2003: avail = 2503968
> > > > > > Sep 10 10:22:47 2003: total = 10076160
> > > > > > Sep 10 10:22:47 2003: [GC
> > > > > > Sep 10 10:22:47 2003:  7668K->7465K(9840K)
> > > > > > Sep 10 10:22:47 2003: , 0.0070875 secs]
> > > > > >
> > > > > > So we see that the GC messages are appearing.  Yet
> as
> > > you
> > > > > > could
> > > > > > see memory keeps going down.
> > > > > >
> > > > > > Afterward I put in a 10ms delay between puts:
> > > > > >
> > > > > > for(int i=0; i < 200000000; i++) {
> > > > > >   Vector vec = new Vector();
> > > > > >   testCache.put(key+i, vec);
> > > > > >   if (i%1000==0) {
> > > > > >     System.out.println("i=" + i);
> > > > > >     System.out.println("avail = " +
> > > > > > Runtime.getRuntime().freeMemory());
> > > > > >     System.out.println("total = " +
> > > > > > Runtime.getRuntime().totalMemory());
> > > > > >   }
> > > > > >   Thread.sleep(10);
> > > > > > }
> > > > > >
> > > > > > Now it is going much slower but memory is still
> > > noticably
> > > > > > still
> > > > > > going down.
> > > > > >
> > > > > > Any other ideas?
> > > > > >
> > > > > > Thanks,
> > > > > > Daniel
> > > > > >
> > > > > >
> > > > > >
> > > > > >
> > > > > >
> > > > > >
> > > > > > --- "Young, Wayne" <WYoung@metasolv.com> wrote:
> > > > > > > Do you know if garbage collections are happening?
> Try
> > > > > > running
> > > > > > > with the
> > > > > > > -verbose:gc option. It could be that the objects
> ARE
> > > > being
> > > > > > > dereferenced, but
> > > > > > > just aren't being collected before your loop ends.
> > > > > > >
> > > > > > > Wayne
> > > > > > >
> > > > > > > -----Original Message-----
> > > > > > > From: Daniel Rosenbaum
> [mailto:drosenbaum@yahoo.com]
> > > > > > > Sent: Tuesday, September 09, 2003 8:26 PM
> > > > > > > To: turbine-jcs-user@jakarta.apache.org
> > > > > > > Subject: Memory test
> > > > > > >
> > > > > > >
> > > > > > > Hi all,
> > > > > > >
> > > > > > > I am testing JCS to see how it handles memory. 
> The
> > > > > > following
> > > > > > > is
> > > > > > > a snippet of my code and config file:
> > > > > > >
> > > > > > > for(int i=0; i < 200000000; i++) {
> > > > > > >   Vector vec = new Vector();
> > > > > > >   testCache.put("testkey"+i, vec);
> > > > > > > }
> > > > > > >
> > > > > > > # DEFAULT CACHE REGION (memory cache)
> > > > > > > jcs.default=DC
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> jcs.default.cacheattributes=org.apache.jcs.engine.CompositeCac
> > heAttribut
> > > > es
> > > > > > > jcs.default.cacheattributes.MaxObjects=2000
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> jcs.default.cacheattributes.MemoryCacheName=org.apache.jcs.eng
> > ine.memory
> > > > .l
> > > > > ru
> > > > > > > .LRUMemoryCache
> > > > > > > jcs.default.cacheattributes.UseMemoryShrinker=true
> > > > > > >
> jcs.default.cacheattributes.ShrinkerIntervalSeconds=60
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
jcs.default.elementattributes=org.apache.jcs.engine.ElementAttributes
> > > > > > > jcs.default.elementattributes.IsEternal=false
> > > > > > > jcs.default.elementattributes.MaxLifeSeconds=43200
> > > > > > > jcs.default.elementattributes.IsSpool=true
> > > > > > > jcs.default.elementattributes.IsRemote=false
> > > > > > > jcs.default.elementattributes.IsLateral=false
> > > > > > >
> > > > > > > #Auxiliary CACHE (disk cache)
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> jcs.auxiliary.DC=org.apache.jcs.auxiliary.disk.indexed.Indexed
> > DiskCacheF
> > > > ac
> > > > > to
> > > > > > > ry
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> jcs.auxiliary.DC.attributes=org.apache.jcs.auxiliary.disk.inde
> > xed.Indexe
> > > > dD
> > > > > is
> > > > > > > kCacheAttributes
> > > > > > > jcs.auxiliary.DC.attributes.DiskPath=jcscache
> > > > > > >
> > > > > > > jcs.region.testCache=DC
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> jcs.region.testCache.cacheattributes=org.apache.jcs.engine.Com
> > positeCach
> > > > eA
> > > > > tt
> > > > > > > ributes
> > > > > > > jcs.region.testCache.cacheattributes.MaxObjects=50
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> jcs.region.testCache.cacheattributes.MemoryCacheName=org.apach
> > e.jcs.engi
> > > > ne
> > > > > .m
> > > > > > > emory.lru.LRUMemoryCache
> > > > > > >
> > > >
> jcs.region.testCache.cacheattributes.UseMemoryShrinker=true
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
jcs.region.testCache.cacheattributes.ShrinkerIntervalSeconds=60
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> jcs.region.testCache.elementattributes=org.apache.jcs.engine.E
> > lementAttr
> > > > ib
> > > > > ut
> > > > > > > es
> > > > > > >
> jcs.region.testCache.elementattributes.IsEternal=false
> > > > > > >
> > > >
> jcs.region.testCache.elementattributes.MaxLifeSeconds=43200
> > > > > > >
> jcs.region.testCache.elementattributes.IdleTime=43200
> > > > > > >
> jcs.region.testCache.elementattributes.IsSpool=true
> > > > > > >
> jcs.region.testCache.elementattributes.IsRemote=false
> > > > > > >
> jcs.region.testCache.elementattributes.IsLateral=false
> > > > > > >
> > > > > > > When I run this code the memory on my system goes
> down
> > > > very
> > > > > > > quickly.  I expected that after the first 50
> elements
> > > it
> > > > > > would
> > > > > > > start putting items on disk and removing them from
> > > > memory
> > > > > > but
> > > > > > > this does not seem to be happening.  I see the
> file on
> > > > disk
> > > > > > > getting increasingly bigger but memory still keeps
> > > > going,
> > > > > > > leading me to believe that the elements are not
> > > getting
> > > > > > > garbage
> > > > > > > collected or was never freed.  Am I doing
> something
> > > > > > > incorrectly?
> > > > > > >
> > > > > > > Thanks,
> > > > > > > Daniel
> > > > > > >
> > > > > > >
> > > > > > > __________________________________
> > > > > > > Do you Yahoo!?
> > > > > > > Yahoo! SiteBuilder - Free, easy-to-use web site
> design
> > > > > > > software
> > > > > > > http://sitebuilder.yahoo.com
> > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
---------------------------------------------------------------------
> > > > > > > To unsubscribe, e-mail:
> > > > > > > turbine-jcs-user-unsubscribe@jakarta.apache.org
> > > > > > > For additional commands, e-mail:
> > > > > > > turbine-jcs-user-help@jakarta.apache.org
> > > > > > >
> > > > > >
> > > > > >
> > > > > > __________________________________
> > > > > > Do you Yahoo!?
> > > > > > Yahoo! SiteBuilder - Free, easy-to-use web site
> design
> > > > > > software
> > > > > > http://sitebuilder.yahoo.com
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
---------------------------------------------------------------------
> > > > > > To unsubscribe, e-mail:
> > > > > > turbine-jcs-user-unsubscribe@jakarta.apache.org
> > > > > > For additional commands, e-mail:
> > > > > > turbine-jcs-user-help@jakarta.apache.org
> > > > > >
> > > > > 
> > > > > 
> > > > > __________________________________
> > > > > Do you Yahoo!?
> > > > > Yahoo! SiteBuilder - Free, easy-to-use web site design
> > > > software
> > > > > http://sitebuilder.yahoo.com
> > > > > 
> > > > >
> > > >
> > >
> >
>
---------------------------------------------------------------------
> > > > > To unsubscribe, e-mail:
> > > > turbine-jcs-user-unsubscribe@jakarta.apache.org
> > > > > For additional commands, e-mail:
> > > > turbine-jcs-user-help@jakarta.apache.org
> > > > 
> > > > 
> > > >
> > >
> >
>
---------------------------------------------------------------------
> > > > To unsubscribe, e-mail:
> > > > turbine-jcs-user-unsubscribe@jakarta.apache.org
> > > > For additional commands, e-mail:
> > > > turbine-jcs-user-help@jakarta.apache.org
> > > > 
> > > 
> > > 
> > > __________________________________
> > > Do you Yahoo!?
> > > Yahoo! SiteBuilder - Free, easy-to-use web site design
> > > software
> > > http://sitebuilder.yahoo.com
> > > 
> > >
> >
>
---------------------------------------------------------------------
> > > To unsubscribe, e-mail:
> > > turbine-jcs-user-unsubscribe@jakarta.apache.org
> > > For additional commands, e-mail:
> > > turbine-jcs-user-help@jakarta.apache.org
> > > 
> > 
> > 
> > __________________________________
> > Do you Yahoo!?
> > Yahoo! SiteBuilder - Free, easy-to-use web site design
> software
> > http://sitebuilder.yahoo.com
> > 
> >
>
---------------------------------------------------------------------
> > To unsubscribe, e-mail: 
> > turbine-jcs-user-unsubscribe@jakarta.apache.org
> > For additional commands, e-mail: 
> > turbine-jcs-user-help@jakarta.apache.org
> > 
> 
>
---------------------------------------------------------------------
> To unsubscribe, e-mail:
> turbine-jcs-user-unsubscribe@jakarta.apache.org
> For additional commands, e-mail:
> turbine-jcs-user-help@jakarta.apache.org
> 


__________________________________
Do you Yahoo!?
Yahoo! SiteBuilder - Free, easy-to-use web site design software
http://sitebuilder.yahoo.com

---------------------------------------------------------------------
To unsubscribe, e-mail: turbine-jcs-user-unsubscribe@jakarta.apache.org
For additional commands, e-mail: turbine-jcs-user-help@jakarta.apache.org


Mime
View raw message