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 Thu, 11 Sep 2003 14:38:51 GMT
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.CompositeCacheAttributes
> > jcs.default.cacheattributes.MaxObjects=2000
> >
>
jcs.default.cacheattributes.MemoryCacheName=org.apache.jcs.engine.memory.lru
> > .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.IndexedDiskCacheFacto
> > ry
> >
>
jcs.auxiliary.DC.attributes=org.apache.jcs.auxiliary.disk.indexed.IndexedDis
> > kCacheAttributes
> > jcs.auxiliary.DC.attributes.DiskPath=jcscache
> > 
> > jcs.region.testCache=DC
> >
>
jcs.region.testCache.cacheattributes=org.apache.jcs.engine.CompositeCacheAtt
> > ributes
> > jcs.region.testCache.cacheattributes.MaxObjects=50
> >
>
jcs.region.testCache.cacheattributes.MemoryCacheName=org.apache.jcs.engine.m
> > emory.lru.LRUMemoryCache
> > jcs.region.testCache.cacheattributes.UseMemoryShrinker=true
> >
>
jcs.region.testCache.cacheattributes.ShrinkerIntervalSeconds=60
> >
>
jcs.region.testCache.elementattributes=org.apache.jcs.engine.ElementAttribut
> > 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


Mime
View raw message