-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 25 posts ]  Go to page 1, 2  Next
Author Message
 Post subject: Long gc pause problems
PostPosted: Tue Oct 25, 2005 9:29 am 
Newbie

Joined: Sat Oct 22, 2005 9:26 pm
Posts: 11
Hello all,

We have been using Hibernate successfully but with one problem, we have long gc pauses using the 1.5 concurrent collector. We previously had really long pauses with Hibernate 2.1.7, and had traced it down to the SessionImpl overriding finalize(). We looked at the 3.0.5 source and realized that SessionImpl had removed the finalize() modifier, which was great, so we upgraded. (I had read Gavin's blog on the topic)

However, we had missed two important details ...

1) org.hibernate.jdbc.ConnectionManager also overrides finalize()
2) Our JDBC driver vendor overrides finalize() in their statements

Now in our scenario, there is a 1:1 mapping between SessionImpl and ConnectionManager for various reasons, which kind of negates the advantage of taking finalize out of SessionImpl. We can help this situation out by using our Sessions for multiple database updates ... we're in the process of getting better about this. We also may be able to influence our database vendor to take the finalize() out of their driver, we need both to really fix our pausing with Sun's VM.

However, it remains that the ConnectionManager overrides finalize(), even in 3.1 rc2. Is there any way that the override can be taken out ? Any other suggestions besides being more frugal with our SessionImpl's ?

Regards,
John.

Hibernate version:3.05
DatabaseVendor: Solid Embedded Database (http://www.solidtech.com/)
Java Version: 1.5.0_04 (Sun)
O/S: Linux Redhat 2.6.9

ps. This shows up in the concurrent collector in long pauses as WeakReference processing if you want to see the effect. Finalizers create weak references, which is the bit the garbage collector complains about.


Top
 Profile  
 
 Post subject: Re: Long gc pause problems
PostPosted: Tue Oct 25, 2005 10:07 am 
Expert
Expert

Joined: Fri Aug 19, 2005 2:11 pm
Posts: 628
Location: Cincinnati
jadams3 wrote:
Is there any way that the override can be taken out ? Any other suggestions besides being more frugal with our SessionImpl's ?


delete it or change it in the source code and rebuild the hibernate.jar file.

Or if you don't want to change the source code, extend whatever ConnectionManager extends, copy the source of that class, and take out the finalize in your new version :)

_________________
Chris

If you were at work doing this voluntarily, imagine what you'd want to see to answer a question.


Top
 Profile  
 
 Post subject:
PostPosted: Tue Oct 25, 2005 10:24 am 
CGLIB Developer
CGLIB Developer

Joined: Thu Aug 28, 2003 1:44 pm
Posts: 1217
Location: Vilnius, Lithuania
Yes, it is a good idea to change hibernate code and to test it, if you will find it more performant and post test results to jira then I am sure "finalize" will be removed.


Top
 Profile  
 
 Post subject: Re: Long gc pause problems
PostPosted: Tue Oct 25, 2005 10:29 am 
Newbie

Joined: Sat Oct 22, 2005 9:26 pm
Posts: 11
kochcp wrote:
delete it or change it in the source code and rebuild the hibernate.jar file.

Or if you don't want to change the source code, extend whatever ConnectionManager extends, copy the source of that class, and take out the finalize in your new version :)


Sorry, that may have not been clear. I have no problem with changing/patching the source code myself. I've patched it for 'fun' and I know that it at least partially solves my pausing problem. I haven't actually shipped with a patched version of open source code before, so I have some license reading to do before I go down that road.

What I'm trying to do is influence the source code to change. Overriding finalize() is, I believe, a questionable thing to do for many reasons, in my case this impacts real time performance fairly significantly. I understand it's a safety measure for database connection closure, but once shipped this shouldn't happen, and it impacts the performance of all hibernate users who use the code the right way.

That is unless I'm clearly doing something wrong, but looking through the source code so far the only thing I think I'm doing wrong is using SessionImpl's a bit gratuitously. I can fix that, but I'm still going to have a problem with pausing.

John.


Top
 Profile  
 
 Post subject:
PostPosted: Tue Oct 25, 2005 10:45 am 
Hibernate Team
Hibernate Team

Joined: Tue Aug 26, 2003 6:10 am
Posts: 8615
Location: Neuchatel, Switzerland (Danish)
as baliukas states.

if you can show significant performance improvements by just removing finalize() then show the numbers and we will look into it.

_________________
Max
Don't forget to rate


Top
 Profile  
 
 Post subject:
PostPosted: Tue Oct 25, 2005 11:19 am 
Newbie

Joined: Sat Oct 22, 2005 9:26 pm
Posts: 11
max wrote:
as baliukas states.

if you can show significant performance improvements by just removing finalize() then show the numbers and we will look into it.


Sigh. Ok ... if I can get some time in the next few days, I'll try to come up with a small program to demonstrate. I don't mind doing the legwork to support it, but I do believe there is ample evidence via the web that finalize() is bad, e.g. it's just the right thing to do.

I have created a JIRA issue as requested in the earlier case, and I'll cross post results there once I've gatherded some evidence.

In the meantime, here are some links that may support the reason ...

From Sun's page on tuning GC
http://java.sun.com/docs/hotspot/gc5.0/gc_tuning_5.html
Sun wrote:
Some applications interact with garbage collection by using finalization and weak/soft/phantom references. These features can create performance artifacts at the Java programming language level. An example of this is relying on finalization to close file descriptors, which makes an external resource (descriptors) dependent on garbage collection promptness. Relying on garbage collection to manage resources other than memory is almost always a bad idea.

(this one is actually about C# I believe, but the comments are on Garbage Collectors) ...
http://www.sidhe.org/~dan/blog/archives/000388.html


Top
 Profile  
 
 Post subject:
PostPosted: Tue Oct 25, 2005 2:52 pm 
Hibernate Team
Hibernate Team

Joined: Tue Aug 26, 2003 6:10 am
Posts: 8615
Location: Neuchatel, Switzerland (Danish)
yes we know finalize() is bad (as per gavins blog), and the question is wether the safeguard is worth the price.

until now it has been worthwhile ensuring connections are getting closed...

_________________
Max
Don't forget to rate


Top
 Profile  
 
 Post subject:
PostPosted: Wed Oct 26, 2005 3:35 am 
CGLIB Developer
CGLIB Developer

Joined: Thu Aug 28, 2003 1:44 pm
Posts: 1217
Location: Vilnius, Lithuania
If this a problem then it must be better to drop "finalize" from proxies first. Check it, I do not remember we use filter for this method or not.


Top
 Profile  
 
 Post subject:
PostPosted: Wed Oct 26, 2005 5:44 am 
Hibernate Team
Hibernate Team

Joined: Tue Aug 26, 2003 6:10 am
Posts: 8615
Location: Neuchatel, Switzerland (Danish)
we dont have finalize on proxies afaik ?

and if users *does* have finalize we should still let it pass through correct?

_________________
Max
Don't forget to rate


Top
 Profile  
 
 Post subject:
PostPosted: Wed Oct 26, 2005 9:17 am 
CGLIB Developer
CGLIB Developer

Joined: Thu Aug 28, 2003 1:44 pm
Posts: 1217
Location: Vilnius, Lithuania
CGLIB owerrides all owerridable methods including "finalize" by default, this method doe's nothing (it is ignored by lazy initializer) but it must be more proxies than sessions or prepared statements to finalize for GC. It is possible to avoid this finalization using "callback filter" :

Code:
    Enhancer e = new Enhancer();

        e.setCallbackTypes(new Class[]{
            MethodInterceptor.class,
            NoOp.class,
        });

        e.setCallbackFilter(


         new CallbackFilter(){

             int accept(Method m){
               //return callback index in CallbackTypes array
                if(isFinalize(m))
                  return 1; //NoOp code generator
                 else return 0;
             
              }

           }

       );


Top
 Profile  
 
 Post subject:
PostPosted: Wed Oct 26, 2005 9:42 am 
Hibernate Team
Hibernate Team

Joined: Tue Aug 26, 2003 6:10 am
Posts: 8615
Location: Neuchatel, Switzerland (Danish)
hmm - are you saying that every proxy will be reigstrered with the finalizer even though the underlying object does not implement finalizer ?

_________________
Max
Don't forget to rate


Top
 Profile  
 
 Post subject:
PostPosted: Wed Oct 26, 2005 10:03 am 
Hibernate Team
Hibernate Team

Joined: Tue Aug 26, 2003 12:50 pm
Posts: 5130
Location: Melbourne, Australia
Oooooohhh that would be VERY bad!

If CGLIB overrides the finalize() method, that will certainly cause major slowness reclaiming memory, since objects which redefine finalize() require two full gc cycles instead of one. And Hibernate instantiates a lot of proxies.

If this is the case, we absolutely must fix this.


Top
 Profile  
 
 Post subject: Micro-Benchmark
PostPosted: Wed Oct 26, 2005 10:12 am 
Newbie

Joined: Sat Oct 22, 2005 9:26 pm
Posts: 11
max wrote:
yes we know finalize() is bad (as per gavins blog), and the question is wether the safeguard is worth the price.

until now it has been worthwhile ensuring connections are getting closed...


One comment before I post a benchmark ... I would be happy if someone could provide a "SafeConnectionManager" vs. an "Unsafe" one via properties or something. If I can pick and choose that would be fine, and you guys could keep the safety built into the loads.

Anyways ....

I just want to use the standard disclaimer about how micro benchmarks are bad. I know they are, and that was the source of my original reluctance to do this, but it seems the onus is on me to prove the problem exists. I'm surrpised that the Hibernate team doesn't have a suite of benchmarks that would support this, but in any case.

I wrote something that did simple writes only to an HSQL database, based on the cats example from the quickstart. I constrained the heap to get some fast GC results, and am using the concurrent mark and sweep collector. Some maybe relevant stats on my pc ...

- Java 1.5.0_Update 5
- HSQL - v1.7.3
- Windows 2000, Pentium 1.8, 1 Gb RAM

Run with finalizer:
D:\temp\hibernate>java -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -verbose:gc -Xloggc:hibernategc.log -Xmx48m -cp .;.\lib\hibernate3.jar;.\
lib\antlr-2.7.5H3.jar;.\lib\asm.jar;.\lib\cglib-2.1.jar;.\lib\commons-collections-2.1.1.jar;.\lib\commons-logging-1.0.4.jar;.\lib\dom4j-1.6.
jar;.\lib\ehcache-1.1.jar;.\lib\hsqldb.jar;.\lib\jta.jar PauseTest 60000
Starting test.
Time to complete test: 58656ms.
Longest weak reference impact in log: 0.0989011 secs

Run without finalizer:
D:\temp\hibernate>java -XX:+UseConcMarkSweepGC -verbose:gc -Xloggc:hibernategc.log -Xmx48m -cp .;.\patch\NoFinalizeConnectionManager.jar;.\l
ib\hibernate3.jar;.\lib\antlr-2.7.5H3.jar;.\lib\asm.jar;.\lib\cglib-2.1.jar;.\lib\commons-collections-2.1.1.jar;.\lib\commons-logging-1.0.4.
jar;.\lib\dom4j-1.6.jar;.\lib\ehcache-1.1.jar;.\lib\hsqldb.jar;.\lib\jta.jar PauseTest 60000
Starting test.
Time to complete test: 41111ms.
Longest weak reference impact in log: *None*

Why is this ?... I believe the concurrent collector never needs to go to the long collection, which helps the throughput as much as it does. Here is the code, if I'm doing something wrong can someone please point it out to me ? I ran this run a couple of times to try and generate a long pause, and I just couldn't do it.

Is that what you guys needed ?

Code:
import org.hibernate.*;
import org.hibernate.cfg.Configuration;

import java.util.logging.*;


/**
* A simple test class to demonstrate pause times in hibernate due
* to finalizers.  Based on the simple cats example in the quickstart
* guide using Hypersonic as a database.<p>
*/

public class PauseTest {

    /**
     *Empty Constructor.<p>
     */
    public PauseTest(){
   Level newLevel =Level.SEVERE; // We still want to log errors
        Logger tmpLogger = java.util.logging.Logger.getLogger("org.hibernate");
        tmpLogger.setLevel(newLevel);
    }

    /**
     * Create the session factory for this test.<p>
     *
     */
    public SessionFactory getSessionFactory(){
   Configuration configuration = new Configuration()
       .setProperty("hibernate.hbm2ddl.auto","update")
       .setProperty("hibernate.dialect", "org.hibernate.dialect.HSQLDialect")
       .setProperty("hibernate.connection.driver_class", "org.hsqldb.jdbcDriver")
       .setProperty("hibernate.connection.url","jdbc:hsqldb:mem:test")
       .setProperty("hibernate.connection.username", "sa")
       .setProperty("hibernate.connection.pool_size", "1")
       .setProperty("hibernate.cache.provider_class", "org.hibernate.cache.HashtableCacheProvider")
       .setProperty("hibernate.show_sql", "false")
       .addClass(Cat.class);

   return configuration.buildSessionFactory();
    }

    /**
     * Starts the test routine.<p>
     * @param n The number of iterations.
     */
    public void start(int n) throws Exception {

   SessionFactory factory = getSessionFactory();
   Session session = null;

   for (int i=0 ;i<n; i++) {
       try {      
      session = factory.openSession();
      Cat princess = new Cat();
      princess.setName("Princess"+i);
      princess.setSex('F');
      princess.setWeight(7.4f);
      session.save(princess);
      session.flush();
      session.connection().commit();
       } catch (HibernateException he) {
      he.printStackTrace();
       }
       finally {
      session.close();
       }
   }
    }

    /**
     * Start the pause test.<p>
     *
     */
    public static void main(String[] args) throws Exception{

   long timeStamp = System.currentTimeMillis();
   PauseTest aTest = new PauseTest();
   System.out.println("Starting test.");
   if (args[0] !=null){
       aTest.start(Integer.parseInt(args[0]));
   }else {
       aTest.start(200);
   }
   long delta = System.currentTimeMillis() - timeStamp;
   System.out.println("Time to complete test: "+delta+" ms.");
    }

}



Top
 Profile  
 
 Post subject:
PostPosted: Wed Oct 26, 2005 10:15 am 
CGLIB Developer
CGLIB Developer

Joined: Thu Aug 28, 2003 1:44 pm
Posts: 1217
Location: Vilnius, Lithuania
OK, I will send a patch tomorrow.


Top
 Profile  
 
 Post subject:
PostPosted: Wed Oct 26, 2005 10:25 am 
Hibernate Team
Hibernate Team

Joined: Tue Aug 26, 2003 12:50 pm
Posts: 5130
Location: Melbourne, Australia
We do of course already have such benchmarks:

http://blog.hibernate.org/cgi-bin/blosx ... 7#finalize


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 25 posts ]  Go to page 1, 2  Next

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.