dynamobi/dynamobi — Issue #706: [FRG-166] RmiJDBC makes excessive explicit calls to garbage collection, gc(), killing performance.
Author: dynamobi-build
Created: 2011-12-30 03:44:19+00:00
State: open
Labels: FRG

[reporter="johnk", created="Tue, 4 Jul 2006 16:08:49 -0500 (GMT-05:00)"]
Copying from dtbug 655:

No response to post on mailing list:

-----Original Message-----

From: John Kalucki [mailto:dt-farrago@kalucki.com]

Sent: Friday, June 16, 2006 2:47 PM

To: farrago-dev@eigenbase.org

Subject: RMIJDBC & Forced Garbage Collection

RMIJDBC calls Runtime.getRuntime().gc() from 18 places on the server.

These are from unreferenced() (RMI), finalize() (Java) and close()

(JDBC) methods of various objects on the server side.

There are no other mainline calls to .gc() in Farrago, or in our

red-zone project.

These hints to garbage collect are often taken by Java5 (..._06). Whe

there is any sort of concurrent query volume, the server does repeated

fruitless major garbage collections. Performance is greatly affected,

and concurrent query latency is miserable. Java threads are generally

unserviced for 200-6000 milliseconds during these gc() storms. Tweaking

GC to reduce stop-the-world pauses does not reduce the impact of the CPU

utilization in any meaningful way.

To make matters even worse, the JVM eventually freezes for 15 to 45

seconds, consumes a bunch of system cpu time, and the responsiveness of

all applications on even a beefy box is slowed. (My guess is that

eventually one of the heap resizes causes the JVM to *really* reorganize

the heap, perhaps ticking a JVM bug)

Disabling code-driven garbage collection at the JVM level with

-XX:+DisableExplicitGC or removing these gc() calls from

thirdparty/RmiJdbc/src/org/objectweb/rmijdbc restores sanity. The JVM

and server perform as one would expect. I have not seen any bad side

effects in my poking around.

Does anyone know what RMIJDBC is trying to do by forcing garbage

collection so often? Is it working around some ancient JVM bug? Is it

attempting to be very tidy and remove RMI references and keep memory

usage very low, at great expense elsewhere?

Similar message posted to RMIJDBC group:

From - Fri Jun 16 17:09:37 2006

X-Mozilla-Status: 0001

X-Mozilla-Status2: 00000000

Return-Path: <rmijdbc-owner@objectweb.org>

Received: from mars.objectweb.org (mars.objectweb.org [194.199.16.17])

by gromit.kalucki.com (8.13.1/8.13.1) with ESMTP id k5H0BWpj031376

for <dtrmijdbc@kalucki.com>; Fri, 16 Jun 2006 17:11:32 -0700

Received: from sympa by mars.objectweb.org with local (Exim 3.36 #1 (Debian))

id 1FrOLU-0001hd-00; Sat, 17 Jun 2006 02:07:24 +0200

Received: from sympa by mars.objectweb.org with local (Exim 3.36 #1 (Debian))

id 1FrOLN-0001hP-00

for <rmijdbc@objectweb.org>; Sat, 17 Jun 2006 02:07:17 +0200

To: rmijdbc@objectweb.org

From: dtrmijdbc@kalucki.com

In-Reply-To:

Message-ID: <sympa.1150502426.15101.532@objectweb.org>

MIME-Version: 1.0

Date: Sat, 17 Jun 2006 02:07:17 +0200

X-Loop: rmijdbc@objectweb.org

X-Sequence: 249

Errors-to: rmijdbc-owner@objectweb.org

Precedence: list

X-no-archive: yes

List-Id:

List-Help: sympa@objectweb.org?subject=help>

List-Subscribe: sympa@objectweb.org?subject=subscribe%20rmijdbc>

List-Unsubscribe: sympa@objectweb.org?subject=unsubscribe%20rmijdbc>

List-Post: rmijdbc@objectweb.org>

List-Owner: rmijdbc-request@objectweb.org>

List-Archive: <http://www.objectweb.org/wws/arc/rmijdbc>

Subject: [rmijdbc] Explicit Garbage Collection calls: Runtime.getRuntime.gc()

in server side

Content-type: multipart/mixed; boundary="----------=_1150502844-15151-79"

Status: O

X-UID: 13037

Content-Length: 1742

X-Keywords:

There are 18 calls to gc() in org.objectweb.rmijdbc. These are from

unreferenced() (RMI), finalize() (Java) and close() (JDBC) methods of various

objects on the server side.

Does anyone recall why these explicit calls to gc() were placed in the code?

What are the downsides to removing these gc() calls?

The upside of removing them is great:

These hints to garbage collect are often taken by Java5. When there is any sort

of concurrent query volume, the server does repeated fruitless major garbage

collections. Performance is greatly affected, and concurrent query latency is

miserable. Java server threads are generally unserviced for 200-6000

milliseconds during these gc() storms. Tweaking GC to reduce stop-the-world

pauses does not reduce the impact of the CPU utilization in any meaningful way.

Disabling code-driven garbage collection at the JVM level with

-XX:+DisableExplicitGC or removing these gc() calls from

RmiJdbc/src/org/objectweb/rmijdbc restores sanity. The server performs as one

would expect. I have not seen any bad side effects in my initial poking around.

-- You receive this message as a subscriber of the rmijdbc@objectweb.org

mailing list. To unsubscribe: mailto:rmijdbc-unsubscribe@objectweb.org For

general help: mailto:sympa@objectweb.org?subject=help ObjectWeb mailing lists

service home page: http://www.objectweb.org/wws

------- Comment #1 From John Kalucki 2006-07-04 16:10 [reply] -------

On 6/27/06, Pierre-Yves Gibello - ExperLog, removed some, but not all of the

gc() calls from their source code:

I have committed the following modification in the CVS (source code) last week

:

removed all explicit calls to gc(), except in the unreferenced() methods.

Particularly, there was a call to gc() in the close() method of connections,

that might be called very frequently.

Regards,

Pierre-Yves Gibello - ExperLog

I asked why not remove all calls on 6/29/06:

John Kalucki wrote:

> Thank you!

>

> Is there a reason for retaining the explicit gc() calls in the unreferenced() methods?

>

I'm not sure with recent JDKs... this was added a long time ago, and as far as

I remember it was related to users that created more RMI objects than what was

deleted by the RMI DGC (at least at some moments in their application

lifecycle).

This caused random "OutOfMemory" errors, and the error got less frequent when I

added gc() calls because the average amount of memory used was smaller (well, I

admit I really added MANY calls to gc() ... but then I haven't heard any more

of that error for years !)

Possibly, the recent versions of java have eliminated this problem (eg. if they

more frequently run the gc, or if it is more optimized - and also because

people have more memory on their PCs now), but in fact I don't know, as this

can only be tested under very specific conditions and heavy load.

Regards,

Pierre-Yves Gibello - ExperLog

--------------------------

Still, I'm removing all calls from our private branch of RMIJDBC. My testing seems to show

no ill-effects so far.