java
Reply
 
Thread Tools Search this Thread Display Modes
  #1  
Old 26-01-2009, 06:43
kjkoster kjkoster is offline
Forum Operator
 
Join Date: Jul 2008
Posts: 1,117
Default Calling System.gc() is a bad idea

Dear All,

Pate's slow load time case is a really interesting one. I have to say I was dumbstruck about the performance issues he was reporting, especially when he started telling me about his configuration. I thought he must have been feeding me measurements and configuration parameters from two different systems. It just did not make any sense.

Let's review, since Pate and I chatted on IRC quite a bit and you guys probably missed that. From Pate's report on Java-monitor, it was clear that his system was swamped in stop-the-world garbage collects. When I asked a bit more, Pate told me on IRC that his memory configuration was "-Xms512M -Xmx4096M -XX:MaxPermSize=1024M". Well, that's nice and sane for a large production system.

To my confusion he then told me that Java-monitor reported that only 20% of the heap memory was in use. I was unable to fit that into the picture, because Sun's JVM's do not use the stop-the-world garbage collectors until their old generations have filled up to well over 70% of their capacity. And yet, here was a JVM doing stop-the-world garbage collects at 20% heap memory capacity. Bizarre.

On top of this, he reported some really, really strange performance figures for test JSP's he as running. Putting a "hello world" JSP in an empty web app on the same server would be served in a few milliseconds, as expected. Putting that very same JSP into their own application's web app would give response times of several hundreds of milliseconds. Pate noted that there were some servlet filters that would match the JSP, so that explained what Java code was responsible for the slowdown.

As it turns out, the answer was really simple: the application was doing it to itself. An enterprising developer had decided to put in a call to System.gc(), the call in Java to suggest that the JVM do a garbage collect.

This call does not look so bad in itself. He'd placed it after pruning a large buffer, so he may have thought that that would be a good time to give the JVM a chance to take out the trash. What the developer did not realize was that System.gc() triggers a stop-the-world garbage collect cycle.

Now why is that so bad? It's only a few milliseconds overhead on each HTTP request, right? What harm can 100 ms do when there is lots of XML marshalling also going on? Well, the devil is in the fact that these 100 ms are not imposed on the current thread alone. Since you've just caused a stop-the-world garbage collect, all processing threads have to wait for 100 ms. What's worse, they all call System.gc() too. So each thread gets (number-of-threads * 100 ms) of GC overhead.

As if that was not enough: the number of threads that are in the process of handling an HTTP request grows larger and larger as requests are not processed quickly enough. More requests processing means more requests arriving and starting and calling System.gc(), thus causing yet more delays.

I feel sorry for Pate for having to work weekends to resolve this, but I am glad that he did. I learned a few very valuable lessons this week. I owe him a beer for that.

Kees Jan

PS. Here is some reading material on tuning garbage collection.
Reply With Quote
  #2  
Old 26-01-2009, 10:12
Kees de Kooter Kees de Kooter is offline
Moderator
 
Join Date: Jul 2008
Location: Rotterdam
Posts: 197
Default

Always run FindBugs when you inherit someone else's code!

Quote:
Dm: Explicit garbage collection; extremely dubious except in benchmarking code (DM_GC)

Code explicitly invokes garbage collection. Except for specific use in benchmarking, this is very dubious.

In the past, situations where people have explicitly invoked the garbage collector in routines such as close or finalize methods has led to huge performance black holes. Garbage collection can be expensive. Any situation that forces hundreds or thousands of garbage collections will bring the machine to a crawl.
__________________
Kees
moderator Tomcat Administration forum
Reply With Quote
  #3  
Old 26-01-2009, 10:38
kjkoster kjkoster is offline
Forum Operator
 
Join Date: Jul 2008
Posts: 1,117
Default

Drat, I was going to do a post on findbugs later this week. You stole my thunder.

But yeah, findbugs is excellent.

Kees Jan
Reply With Quote
  #4  
Old 18-02-2009, 17:26
Barry Barry is offline
Moderator
 
Join Date: Jul 2008
Posts: 106
Default

-XX:-DisableExplicitGC Disable calls to System.gc(), JVM still performs garbage collection when necessary.

This should prevent applications from doing this
Reply With Quote
  #5  
Old 18-02-2009, 20:10
kjkoster kjkoster is offline
Forum Operator
 
Join Date: Jul 2008
Posts: 1,117
Default

Dear Barry,

Excellent find! Just one nit to pick. In order to actually disable the explicit GC's you have to specify -XX:+DisableExplicitGC and not -XX:-DisableExplicitGC.

I tested this using jconsole. If you use the plus sign (+DisableExplicitGC) pressing the "Perform GC" button has no effect. If you use the minus sign (-DisableExplicitGC), the stop-the-world GC still runs on command.

Kees Jan
Reply With Quote
  #6  
Old 18-02-2009, 20:52
Barry Barry is offline
Moderator
 
Join Date: Jul 2008
Posts: 106
Default

Quote:
Originally Posted by kjkoster View Post
Dear Barry,

Excellent find! Just one nit to pick. In order to actually disable the explicit GC's you have to specify -XX:+DisableExplicitGC and not -XX:-DisableExplicitGC.

I tested this using jconsole. If you use the plus sign (+DisableExplicitGC) pressing the "Perform GC" button has no effect. If you use the minus sign (-DisableExplicitGC), the stop-the-world GC still runs on command.

Kees Jan
You might want to tell Sun...
Quote:
-XX:-DisableExplicitGC Disable calls to System.gc(), JVM still performs garbage collection when necessary.
Reply With Quote
  #7  
Old 18-02-2009, 21:17
kjkoster kjkoster is offline
Forum Operator
 
Join Date: Jul 2008
Posts: 1,117
Default

Dear Barry,

No big deal. Nobody would go into production with something like this without testing it thoroughly to see if it works or not, would they?

*crickets*

... would they?

Kees Jan
Reply With Quote
  #8  
Old 20-02-2009, 11:35
Barry Barry is offline
Moderator
 
Join Date: Jul 2008
Posts: 106
Default

You would be surprised

http://blogs.sun.com/alexismp/entry/..._killed_no_log

Apparently people also put System.exit in their webapps somehow
It's a findbugs rule though, so my first suggestion is using findbugs on anything
Reply With Quote
Reply

Thread Tools Search this Thread
Search this Thread:

Advanced Search
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off

Forum Jump