LucidDB / luciddb

DEFUNCT: See README
https://github.com/LucidDB/luciddb
Apache License 2.0
52 stars 24 forks source link

[FRG-166] RmiJDBC makes excessive explicit calls to garbage collection, gc(), killing performance. #706

Closed dynamobi-build closed 12 years ago

dynamobi-build commented 12 years ago

[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: <mailto:sympa@objectweb.org?subject=help>
List-Subscribe: <mailto:sympa@objectweb.org?subject=subscribe%20rmijdbc>
List-Unsubscribe: <mailto:sympa@objectweb.org?subject=unsubscribe%20rmijdbc>
List-Post: <mailto:rmijdbc@objectweb.org>
List-Owner: <mailto: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.

dynamobi-build commented 12 years ago

[author="johnk", created="Tue, 4 Jul 2006 16:10:41 -0500 (GMT-05:00)"] Fixed by change 7112.