Jul 12 2010

Two Applications Compared At The JVM Level - Startling Stuff

Posted by Mike Brunt at 11:37 AM

 

This posting has two important messages, in my opinion.  Load test all applications and code to least 150% of the expect before deploying to production and before deploying anything to production make sure that the JVM has been tuned, the "out of the box" settings after a ColdFusion install are not good enough.

What I am showing here are Garbage Collection logging results from two different clients, because I want to illustrate the immense differences we encounter with different clients and environments.  The first example is from a client using two of the prominent CFC based frameworks...

{Heap before GC invocations=40639 (full 193):

 PSYoungGen      total 125120K, used 102464K [0x5bbf0000, 0x64c60000, 0x64c60000)

 eden space 102464K, 100% used [0x5bbf0000,0x62000000,0x62000000)

 from space 22656K, 0% used [0x63640000,0x63640000,0x64c60000)

  to   space 22720K, 0% used [0x62000000,0x62000000,0x63630000)

 PSOldGen        total 1183296K, used 1183291K [0x13860000, 0x5bbf0000, 0x5bbf0000)

  object space 1183296K, 99% used [0x13860000,0x5bbeefb8,0x5bbf0000)

 PSPermGen       total 196608K, used 97179K [0x03860000, 0x0f860000, 0x13860000)

  object space 196608K, 49% used [0x03860000,0x09746d20,0x0f860000)

15339.053: [Full GC [PSYoungGen: 102464K->26228K(125120K)] [PSOldGen: 1183291K->1183291K(1183296K)] 1285755K->1209520K(1308416K) [PSPermGen: 97179K->97179K(196608K)], 3.1595979 secs] [Times: user=3.16 sys=0.00, real=3.16 secs] 

In this case the server has been running for 15,339 seconds and in that time there have been 40,639 garbage collections and 193 Full GC's.  Full GC's are challenging because all other processes stop during a Full GC, so we do not want too many.  This snapshot is taken when the server is dying, mainly because we are out of Old Generation space because that is where all objects end up.  Despite, 193 Full GC's some lasting for seconds the objects in the Old Generation cannot be collected because they still have references to them from the application I could even say Application Scope.  In this dying phase of the server, Full GC's are also occurring every few seconds, In essence, the garbage collector is frantically trying to do a good job.

 

Here is example two, from a different client and this time using no well known CFC based frameworks.

{Heap before GC invocations=3989 (full 62): 

PSYoungGen total 702528K, used 649818K [0x000000011c9f0000, 0x000000014b4e0000, 0x000000014b7f0000) 

 eden space 646464K, 100% used [0x000000011c9f0000,0x0000000144140000,0x0000000144140000) 

 from space 56064K, 5% used [0x0000000147e20000,0x0000000148166860,0x000000014b4e0000) 

 to space 59200K, 0% used [0x0000000144140000,0x0000000144140000,0x0000000147b10000) 

PSOldGen total 1152000K, used 699717K [0x000000008fff0000, 0x00000000d64f0000, 0x000000011c9f0000) 

 object space 1152000K, 60% used [0x000000008fff0000,0x00000000bab41478,0x00000000d64f0000) 

PSPermGen total 196608K, used 121178K [0x000000007fff0000, 0x000000008bff0000, 0x000000008fff0000) 

 object space 196608K, 61% used [0x000000007fff0000,0x0000000087646b98,0x000000008bff0000) 

198572.058: [GC [PSYoungGen: 649818K->11108K(705664K)] 1349535K->711718K(1857664K), 0.0431385 secs]

The difference is quite marked. In 198,572 seconds there have been 3,989 garbage collections of which 62 were Full GC's. 

Back to my original point, had our first client here been able to fully test the framework and applications they would not have ended up with the issues they have and what makes it worse is their ColdFusion application is totally enmeshed in the framework and cannot easily be gotten out of there.

Here are our simple methods to ensure that clients always deploy efficient and scalable ColdFusion applications.


 

Comments

Joshua Cyr

Joshua Cyr wrote on 07/12/10 11:57 AM

Can you clarify a bit more about what in the frameworks (if really related to the framework) was causing the additional full GC? Was it due to so much being loaded in the app scope from the framework, or the client code? What did they do to resolve?
Aaron Longnion

Aaron Longnion wrote on 07/12/10 12:10 PM

Hi Mike,

This is some nice, juicy stuff. But can you tell us the CF versions, 64bit?, and what JVM version number?

And did you notice if any of the slowness was tied to database or I/O slowness? I ask because many times I end up finding out that JVM memory problems are a *symptom* of a deeper problem, usually related to that queries or dB indexes need to be tuned, or sometimes I/O issues on network shares or NAS configurations...

- Aaron
Aaron Greenlee

Aaron Greenlee wrote on 07/12/10 2:07 PM

Mike,

This post, and your last one, are teasing us too much. Can you share a little more about the Frameworks you are talking about?

If you do not want to say in public, please, email me.

Thanks.

Aaron
Mike Brunt

Mike Brunt wrote on 07/12/10 6:53 PM

@Joshua, these are both new projects and are ongoing. When I find these sorts of situations and I have many times, I am loathe to broadcast the issue simply because those who have worked hard to create sophisticated frameworks deserve consideration for that. The biggest problem, typically is that inadequate load-testing was done prior to launching the framework and when there are multiple frameworks they have typically never been load tested in concert with close attention paid to the garbage collection in the JVM.
Mike Brunt

Mike Brunt wrote on 07/12/10 6:58 PM

Aaron L both were ColdFusion 8 standard 32 bit on Windows. Your question about external dependencies is an important one and we have not gotten that far, yet. We have not gotten that far because it is key to tune the JVM first, it is the engine room. In the case of the high number of GC's issue we tried two different JVM versions and three different garbage collectors, with little to no improvement and always the same manifestation, the old generation filling up. I agree with what you cite as being possible causes also.
Mike Brunt

Mike Brunt wrote on 07/12/10 7:19 PM

@Aaron G I just sent you the details, as mentioned above I do not want to denigrate hours and hours of unpaid work by others. The key to all of this is realistic load testing before deploying to production.
Jason Dean

Jason Dean wrote on 07/12/10 8:48 PM

Mike,

You keep saying that the key is to do realistic load testing, but that doesn't answer the ultimate question of "what can we do about it". To ME, the key is knowing what I should do to avoid these problems.

Realistic load testing will tell us if there is a problem, and it may even tell us where the problem is, but does it tell us how to fix it? Can this type of problem be fixed without rewriting the application without a CFC-based framework?

It seems to me that the thing that you really don't want to say out loud is that for the sake of performance and scalability, that we should not be using these CFC heavy frameworks. As you said "... and what makes it worse is their ColdFusion application is totally enmeshed in the framework and cannot easily be gotten out of there". This indicates to me that you feel the solution to the problem of performance is to remve the framework.

Am I speculating too much?

I know you don't want to criticize somebodies hard work, and I respect that. But if you know something we don't, do you feel obligated to tell us? Is there a solution to writing performant and scalable applications using CFC-based frameworks?
David Boyer

David Boyer wrote on 07/13/10 7:57 AM

@Mike,

Is there an easy way to pull out those Garbage collection counts you reference, using ColdFusion? It'd be nice to know if there's a simple way to keep an eye on this sort of thing.
Mike Brunt

Mike Brunt wrote on 07/17/10 10:40 PM

@Jason sorry to be late in responding. If we adequately load test after enabling metrics logging and garbage collection logging and monitoring and making corrections from that, then the possible issues levied by these frameworks would be observed. I do feel uncomfortable, for a client, when an application is consumed inside a framework when I have often observed significant performance penalties.
Mike Brunt

Mike Brunt wrote on 07/17/10 10:43 PM

@David, here are arguments which when added to the jvm.config file will enabled GC logging...-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -verbose:gc -Xloggc:cfwhispererGC.log
CFWHISPERER

CFWHISPERER wrote on 08/11/10 11:59 PM

If you need assistance with JVM issues.
Mark Ireland

Mark Ireland wrote on 08/23/10 3:08 AM

Why dont people just watch the Performance Monitor?
Mike Brunt

Mike Brunt wrote on 09/04/10 1:05 PM

@Mark you make a good point, we certainly use it a good deal to look for network or hard-drive I/O issues but in all the years I have been troubleshooting or testing ColdFusion applications I have not found the performance monitor to be sufficient in itself.
David Boyer

David Boyer wrote on 09/16/10 1:16 AM

I thought it might be worth pointing out that it's possible for ColdFusion to expose some very useful statistics via Java.

http://download.oracle.com/javase/6/docs/api/java/lang/management/ManagementFactory.html#getGarbageCollectorMXBeans()

Gives you access to the garbage collection statistics including the number of times they're been run, before/after memory, duration, start/end times, memory pools they manage...

Although it's not as detailed as looking at the log itself, it can provide an easy way to see what's going on right at that moment and could prove useful.

It's what my CfTracker project uses to source it's Garbage Collection information.
superdry sale

superdry sale wrote on 11/18/11 6:08 PM

Every superdry sale fans convinced superdry will be next huge designer. The colors of superdry uk are just amazing because they are universally flattering! It is a great alternative for people who are tired of buying out the entire superdry outlet line and are finished shopping at Our Superdry uk sale store.
rak toko swalayan murah

rak toko swalayan murah wrote on 06/17/12 10:10 AM

This posting is very cool and interesting post.This is a great inspiring article.I am very much pleased with your good work.You put really very helpful information in this site.

http://www.rakminimarket.com

therefore, I would like to thank you for the efforts you have made in writing this article.
f50 chaussure de foot

f50 chaussure de foot wrote on 10/28/13 5:28 AM

great blog,thanks for your revealing so competent write-up.
chaussure de foot nike

chaussure de foot nike wrote on 11/20/13 4:09 AM

thank you for this great I definitely loved every little bit of it.
sparxxrx

sparxxrx wrote on 10/16/14 8:56 AM

We offer natural penis enlargement to boost your erection. Don’t settle for anything less than perfection when it comes to your male enhancement needs.
www.fentonfinance.net

www.fentonfinance.net wrote on 11/02/14 12:56 AM

Accounts Receivable Financing- "Don't Worry, Be Happy" explores the issues of notification vs non-notification accounts receivable financing.
www.newbusinessintroductions.net

www.newbusinessintroductions.net wrote on 11/02/14 12:56 AM

Building a network of business contacts takes time and patience. One great way to expand your network is to add "introductions" to your regular routine.
www.ivbusiness.net

www.ivbusiness.net wrote on 11/02/14 12:56 AM

Is it time to sell? Selling your business is a major decision! You have devoted your time, money, and energy to building, running, and operating your business. It may well represent your life's work
www.health-matrix.org

www.health-matrix.org wrote on 11/19/14 7:02 AM

Although the Dwelling vote so that you can repeal heath care treatment reform is definitely symbolic exclusively (supplied the Democratic Senate and White colored House), this is the necessary initially step creating committee by way of committee action covering the coming many months on individually distinct provisions of heath care treatment.
www.breakfast4health.org

www.breakfast4health.org wrote on 11/19/14 7:02 AM

When you are someone who seem to thinks not eating breakfast just might help you lose excess fat, you're not by yourself. I perceive this out of my clients often; many think skipping morning meal is very best way to cut fat laden calories and shed extra pounds quicker.
www.waterloohealthcare.org

www.waterloohealthcare.org wrote on 11/19/14 7:02 AM

Responding to your teeth really should be a no-brainer. Why in that case do dental consultants make a great deal of money each and every year in highly-priced dental types of procedures?
www.scorespro.com

www.scorespro.com wrote on 01/26/15 11:42 PM

The actual Bundesliga promises lots of action this season, with 4 teams effective at competing for that prize. Germany's powerful showing in the 2006 Globe Cup helped enhance the league within the eyes of numerous spectators, and it has become much more competitive consequently.
clothing manufacturer

clothing manufacturer wrote on 07/04/15 4:20 AM

Mike,

This post, and your last one, are teasing us too much. Can you share a little more about the Frameworks you are talking about?

If you do not want to say in public, please, email me.

Thanks.

Aaron