I had tried to send this yesterday, if you get it more than once, apologies.
 
Kind Regards - Mike Brunt
CTO and Lead Architect - Webapper Services LLC
Tel 562.243.6255
Web Site: http://www.webapper.com
Blog: http://www.webapper.net
Tools: http://www.seefusion.com
 


From: Mike Brunt - Webapper Services, LLC [mailto:[EMAIL PROTECTED]
Sent: Sunday, May 28, 2006 1:05 PM
To: '[email protected]'
Subject: RE: Reactor Performance was RE: [Reactor For CF] Been out of touch, but trying to get back

Just a quick update on what I have observed since we made the tweak to the jvm.config file on Doug's server.  Doug restarted a little while ago but I don't think it was due to low memory in the instance.  Here is the memory situation just before the restart:
 
Total Memory=512768 Free=215700
 
At this point the instance had been up and running from  05/25 21:47:47 to 05/28 14:16:57, around 2 days 17 hours and the free memory never got dangerously low during that time, in the logs I saw. Disabling those Explicit Full GC's had a beneficial impact.  I feel there are still improvements to be made but I know Doug is also looking at code-level issue at present so will hold off further recommendations at present.
 
In essence, we did two different things, the first group were related to monitoring or logging.  We enabled Verbose Garbage Collection logging using these commands in the jvm.config file:
 
-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -verbose:gc -Xloggc:reactorgc.log (the last bit -Xloggc:reactorgc.log gives the log a name).  This information goes into the jrun4 or runtime bin directory, by default.  As a note point, this is not too verbose so the log does not get too big, however it should eventually be disabled.  This logging helped us identify that too many Full GC's were occurring.
 
We also enabled JRun Metrics Logging which shows us the memory status at a point in time along with thread usage details.  We set this to report every 60 seconds by adding this to the jrun.xml file for this instance:
 
<service class="coldfusion.server.jrun4.metrics.MetricsServiceAdapter" name="MetricsService">
    <attribute name="bindToJNDI">true</attribute>
</service>
    <attribute name="metricsEnabled">true</attribute>
    <attribute name="metricsLogFrequency">60</attribute>
    <attribute name="metricsFormat">Web threads (busy/total/listen/idle/delay/handled):
{jrpp.busyTh}/{jrpp.totalTh}/{jrpp.listenTh}/{jrpp.idleTh}/{jrpp.delayRq}/{jrpp.handledRq}
Sessions: {sessions} Total Memory={totalMemory} Free={freeMemory}</attribute>
 
(note, on stand-alone-server installs of CFMX you do not need the jrpp. as in jrpp.busyTh).
 
The most useful piece that I used was SeeFusion which enables us to observe memory and thread behavior in real-time by looking at requests as they literally run.  We also wrapped the JDBC driver with SeeFusion which enabled us to monitor database calls, SQL passed and query times.
 
Moving on the second group of things we did.  As a result of looking at this monitor and log data, we observed to many Full GC's taking place and an difficulty for JRun-CFMX to get up and running "comfortably".  As a result, we made these changes to the jvm.config file:
 
Added these arguments (I have these on separate lines here for clarity but they should be added to the arguments string with a single space between each):
 
-Xms512m (this sets the memory available to the jvm at start at 512MB which saves the effort of the jvm acquiring it)
 
-XX:PermSize=128m (this does the same thing as above for the permanent memory space which is what the jvm uses for its own operation). 
 
Note the start settings here must always be either equal to or less that the maximum setting, they cannot be set to higher.  Also note, if you only have a single jvm.config file in a single jvm whatever you set in that file will apply to all instances.  So if you have 5 JRun/CFMX instances they will each take the start amount of memory when they start up. 
 
-XX:+DisableExplicitGC (this stops all explicitly called Full Garbage Collections)  this does not stop all Full GC's only those called explicitly by something.
 
These settings certainly improved memory availability to the instance used for Doug's blog I am still seeing frequent filling up of the New Space in the jvm so I think we should try some more jvm argument tweaks but as I say, I think Doug is working on some code level stuff so it is prudent to observe what effect this has, first.
 
By the way, I would like to blog this on the Webapper blog, is that alright with you Doug?
 
Kind Regards - Mike Brunt
CTO and Lead Architect - Webapper Services LLC
Tel 562.243.6255
Web Site: http://www.webapper.com
Blog: http://www.webapper.net
Tools: http://www.seefusion.com
 


From: [EMAIL PROTECTED] [mailto:[EMAIL PROTECTED] On Behalf Of Jeff Lester
Sent: Friday, May 26, 2006 6:58 PM
To: [email protected]
Subject: Re: Reactor Performance was RE: [Reactor For CF] Been out of touch, but trying to get back

Mike,

No I'm not running the blog application. I am running an in-house portal for our employees and a webpage for our business. Both are running on the same server in the same instance so I can't compare mine with a multi-instanced installation that Doug is using however I feel that since I am running different apps with no problems:

Is it a possibility that Dougs Blog application may be missing some var's somewhere, if I remember correctly I did hear something about how not using var on your cfc function variables can cause a high memory usage...

I'm using var on all my function variables, so is it a possibility is all I'm saying. Is anyone else who is experiencing this problem not using the Blog and if so, are you declaring var's properly?

Just my 2c.

~Jeff Lester

On 5/27/06, Dan Wilson <[EMAIL PROTECTED]> wrote:
Thanks to both of you for the lessons, as appropriate and mult-faceted as they happen to be.  I appreciate the info as well as the pointers to more information.

I am going to research GC more as this has been enlightening.  If anybody else wants a summation of what I find, shoot me an email off list.

Thanks


Dan Wilson










On 5/26/06, Mike Brunt - Webapper Services, LLC < [EMAIL PROTECTED]> wrote:
Dan there are basically two flavors of Garbage Collection (GC) in the JVM.  The ongoing GC's (not Full) are going on all the time and are typically miliseconds in duration.  For instance on Doug's server there were 2,569 GC's in a 12.8 hour period, 56 of which were Full GC's.
 
Full GC's in this case were what the JVM decided was necessary.  When I first looked and prior to adding the disable explicit GC's there were 786 Full GC's in just over 8 hours.  Because they were being called explicitly probably, by RMI.
 
Full GC's are at best a necessary evil because literally everything stops so they need to be minimzed to run when needed and should always reclaim some memory, if they do not they should not be running.  And yes your assumption is correct in a Full GC all objects are inspaected, as Sean rightly says in his last excellent post, this is a very dense subject.
 
One last thing I will emphasize here for now.  In all CFMX installations the JVM is as close to a beating heart as CF gets (this is true of all J2EE - JavaEE applications and servers).
 
Kind Regards - Mike Brunt
CTO and Lead Architect - Webapper Services LLC
Tel 562.243.6255
 


From: [EMAIL PROTECTED] [mailto:[EMAIL PROTECTED]] On Behalf Of Dan Wilson
Sent: Friday, May 26, 2006 12:02 PM

To: [email protected]
Subject: Re: Reactor Performance was RE: [Reactor For CF] Been out of touch, but trying to get back

So to the layperson, Explicit Garbage collection would infer a complete review of all objects held in memory and a complete review of all currently held references. ( sounds like VACUUM FULL in PostgreSQL, Expensive and Important. )

Thinking out loud, I remember an object caching mechanism in CF. If the frequency of GCs before the change was sub-optimally high, and disabling explicit Garbage collection at the JVM layer improved the memory management situation, was there an impact to any of the default, standard, behaviour of ColdFusion server?

When I re-read the original summation, it sounded like disabling Explicit Garbage collection was something you recommended to all your clients.  Does this pertain to just Reactor users, or any CFserver user?

If this is not the right time, place, or questions for this list, please let me know.

I remain highly interested in this issue and would like to say thanks for the transparent manner in which this is being handled.

Dan Wilson





On 5/26/06, Mike Brunt - Webapper Services, LLC <[EMAIL PROTECTED]> wrote:
As a quick explanation about garbage collection, objects are inspected to see if there are any references to them if there are not they are garbage collected and the memory is freed up.  So if the references to any objects are not being released effectively in an application they will hang around.  That is a vey basic explanation of why objects are not collected and memory is not freed up. 
 
I think there is another thought point here, Jeff Lester mentioned he does NOT have similar issues (correct me if I am wrong Jeff) does Jeff also use the Blog Application?
 
Kind Regards - Mike Brunt
CTO and Lead Architect - Webapper Services LLC
Tel 562.243.6255
 


From: [EMAIL PROTECTED] [mailto: [EMAIL PROTECTED]] On Behalf Of Doug Hughes
Sent: Friday, May 26, 2006 8:32 AM

To: [email protected]
Subject: RE: Reactor Performance was RE: [Reactor For CF] Been out of touch, but trying to get back

Mike – As always:  Awesome.  I've been using a tool called Jprobe to watch what variables CF creates when using my blog.  I can essentially run one use case and see what's around when I'm done.  Based on this, I'm beginning to suspect that this is in the OO queries…. I think that some of the various objects (join, field, order, etc) used by the queries are not released when the query is added back into the resource pool.  I'm not sure, however, how this could create such a leak.  OO queries are where I'll be focusing a lot of my time this weekend with reactor dev.  Maybe I'll track it down?  We'll see.

 

Doug

 


From: [EMAIL PROTECTED] [mailto: [EMAIL PROTECTED]] On Behalf Of Mike Brunt - Webapper Services, LLC
Sent: Friday, May 26, 2006 11:05 AM
To: [email protected]
Subject: RE: Reactor Performance was RE: [Reactor For CF] Been out of touch, but trying to get back

 

Just a quick update on what I found this morning.  Doug last restarted his CFMX instance here 05/25 21:47:47, the first Full GC ocurred 5.4 hours later (which is early morning?) and as with the previous behavior did reclaim a good amount of memory (around 220MB).  However, in the total time the system has been up there have been 56 Full GC's and as before the most recent ones reclaim virtually no memory.

 

As of 10 minutes ago there was 220MB of available memory which is reasonable.  I will be sending Doug some other suggestions as tweaks to the JVM arguments in a little while to see if we can control those Full GC's more effectively.  I will also have some observations about the New and Old memory segments.

 

Kind Regards - Mike Brunt

CTO and Lead Architect - Webapper Services LLC

Tel 562.243.6255

Web Site: http://www.webapper.com

Blog: http://www.webapper.net

Tools: http://www.seefusion.com

 

 


From: [EMAIL PROTECTED] [mailto: [EMAIL PROTECTED]] On Behalf Of Brian Kotek
Sent: Thursday, May 25, 2006 2:44 PM
To: [email protected]
Subject: Re: Reactor Performance was RE: [Reactor For CF] Been out of touch, but trying to get back

Mike I'm afraid I can't add to the technical discussion becuase the innards of the JVM are way over my head. But I am learning a lot from hearing this back and forth and I wanted to thank you for stepping up and helping Doug work through this.

Thanks,

Brian

On 5/25/06, Mike Brunt - Webapper Services, LLC < [EMAIL PROTECTED]> wrote:

I thought I would add a bit to the subject line so that we know this is
about the performance review we are carrying out for Reactor at Doug's
place.  If you recall yesterday we observed the following as far as Full
Garbage Collections (Full GC's) on Doug's instance running Reactor:

"In 8.9 hours of uptime there were 786 Full GC's, that is one every 41
seconds the latest ones are taking 3.8 seconds"

Doug applied a change to the jvm.config file to disable Explicit Full GC's.
Explicit Full GC's are Full GC's called either by an application, a command
or a process such as RMI (Remote Method Invocation). After the change
applied by Doug there is a very noticeable change.

In the 4.08 hours since Doug started the instance with Explicit Full GC's
disabled there have been 19 Full GC's.  We can be fairly certain that these
Full GC's are being activated by the JVM itself.  19 is much better however
there is still evidence of them not being very effective, eventually and we
will watch that.  Here are some details:

The first Full GC occurred after 3.02 hours of uptime and was efficient (as
a comparison before these changes the first Full GC occurred at 0.012
seconds after restart and continued unabated).  This ([Full GC
515767K->256620K) tells us that before the Full GC 516MB of Ram was being
used by the JVM and after that reduced to 257MB.  At 3.6 hours after the
restart the Full GC's although still running are not reclaiming much if any
RAM.  So we have made some progress by disabling Explicit Full GC's and we
recommend that our clients do that unless there is a compelling not to do so
that they are aware of.

Doug, do you have any idea what your traffic level is like on this instance?

Kind Regards - Mike Brunt
CTO and Lead Architect - Webapper Services LLC
Tel 562.243.6255
Web Site: http://www.webapper.com
Blog: http://www.webapper.net
Tools: http://www.seefusion.com


-- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/

-- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/ -- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/
-- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/



--
"Go for it, its later than you think" -- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/
-- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/



--
"Go for it, its later than you think" -- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/

-- Reactor for ColdFusion Mailing List -- [email protected] -- Archives at http://www.mail-archive.com/reactor%40doughughes.net/

-- Reactor for ColdFusion Mailing List -- [email protected]
-- Archives at http://www.mail-archive.com/reactor%40doughughes.net/

Reply via email to