afterTransactionCompletion() warning

rich · **Joined:** Sat Dec 20, 2003 5:09 pm **Posts:** 38

I have quite a bit of a hibernate/tomcat/struts web application complete. So far, it *appears* as though it's working quite well. However, the server logs show many warnings that look like this:

11-01-04 14:08:46 [Finalizer] WARN net.sf.hibernate.impl.SessionImpl: afterTransactionCompletion() was never called

I've searched around on "afterTransactionCompletion()" and haven't found all that much. I'm assuming it has something to do with closing the session? To do that, I'm doing something like this:

Code:

protected static void closeHibernateSession()
       throws HibernateException
{
       Session s = (Session) session.get();
       session.set(null);

       if (s != null) s.close();
 } 

where session is:

Code:

protected static final ThreadLocal session = new ThreadLocal();

And used in code:

Code:

try
{
   Session     sess = getHibernateSession();
   Transaction tx   = sess.beginTransaction();

   sess.saveOrUpdate(hibernateBean);

   if(flush) { sess.flush(); }

   tx.commit();
}
catch(NamingException ne)
{
}
catch(HibernateException he)
{
}
finally
{
   try
   {
      closeHibernateSession();
   }
   catch (HibernateException he)
   {

    }
}

Is this something I should worry about?

Thanks ...

michael · **Posted:** Sun Jan 11, 2004 3:32 pm

Do you really have all those empty catch blocks in there? If yes, log the exception and see if you have some ignored exception somewhere.

rich · **Joined:** Sat Dec 20, 2003 5:09 pm **Posts:** 38

Hehe. The try - catch blocks aren't empty in my application. I just removed all the code there for clarity.

rich · **Joined:** Sat Dec 20, 2003 5:09 pm **Posts:** 38

Should of mentioned that I don't see anything out of the ordinary in my catch blocks. I'll try and catch the base Exception class and see if that shows anything.

rich · **Joined:** Sat Dec 20, 2003 5:09 pm **Posts:** 38

I just updated that code with catch blocks for plain old Exception. My logs don't show anything out of the ordinary. I also just noticed that this warning always appears first in the logs ...

12-01-04 10:08:29 [main] WARN net.sf.hibernate.impl.SessionFactoryObjectFactory: InitialContext did not implement EventContext

But after searching in the forums I see that this warning is probably benign.

I also put more debugging in the code that opens and closes the session:

Code:

    protected static Session getHibernateSession()
        throws NamingException, HibernateException
    {
       Session s = (Session) session.get();
       if (s == null)
       {
          if(_baseLog.isDebugEnabled())
          {
             _baseLog.debug("Acquiring new session factory");
          }

          SessionFactory sf = (SessionFactory) new 
               InitialContext().lookup("prospecting/hibernate/SessionFactory");
          s = sf.openSession();
          session.set(s);
       }
       else
       {
          if(_baseLog.isDebugEnabled())
          {
             _baseLog.debug("Session acquired from threadLocal");
          }
       }
       return s;
    }

and

Code:

    protected static void closeHibernateSession()
       throws HibernateException
    {
       if(_baseLog.isDebugEnabled())
       {
          _baseLog.debug("Closing session");
       }

       Session s = (Session) session.get();
       session.set(null);

       if (s != null)
       {
          s.close();
       }
       else
       {
          if(_baseLog.isDebugEnabled())
          {
             _baseLog.debug("S was null, not calling close()");
          }
       }
    }

And what I see is that the session is opened and closed, yet I still get the warnings?

12-01-04 10:54:50 [http8080-Processor25] DEBUG com.MyClass: Acquiring new session factory
12-01-04 10:54:51 [http8080-Processor25] DEBUG com.MyClass: Closing session
12-01-04 10:54:51 [http8080-Processor25] DEBUG com.MyClass: Acquiring new session factory
12-01-04 10:54:51 [http8080-Processor25] DEBUG com.MyClass: Closing session
12-01-04 10:54:51 [http8080-Processor25] DEBUG com.MyClass: Acquiring new session factory
12-01-04 10:54:51 [http8080-Processor25] DEBUG com.MyClass: Closing session
12-01-04 10:54:51 [Finalizer] WARN net.sf.hibernate.impl.SessionImpl: afterTransactionCompletion() was never called
12-01-04 10:54:51 [Finalizer] WARN net.sf.hibernate.impl.SessionImpl: afterTransactionCompletion() was never called
12-01-04 10:54:51 [Finalizer] WARN net.sf.hibernate.impl.SessionImpl: afterTransactionCompletion() was never called

Should I be calling afterTransactionCompletion() myself?

Funny thing is, after serveral test runs I see that there is not always a one-to-one relationship between opening and closing the session to the warning. Sometimes the session is closed and opened several times with no warnings at all. Maybe the two aren't related?

rich · **Joined:** Sat Dec 20, 2003 5:09 pm **Posts:** 38

Javadocs says that afterTransactionCompletion() is used to Notify the session that the transaction completed, so we no longer own the old locks.
Also, since this method is in the net.sf.hibernate.impl package I assume it is meant for Hibernate internals only and probably gets called as a side effect of commiting the transaction.

With that said, I'm theorizing my warning comes from some place in my code where I open a session, start a transaction, but then never close the transaction. Does that seem reasonable? Or is that thought processes way off base?

emmanuel · **Posted:** Tue Jan 20, 2004 1:41 pm

rich wrote:

I'm theorizing my warning comes from some place in my code where I open a session, start a transaction, but then never close the transaction. Does that seem reasonable? Or is that thought processes way off base?

You're right, you opened a Tx with hibernate API and don't close it the same way, something like that

rich · **Joined:** Sat Dec 20, 2003 5:09 pm **Posts:** 38

Thanks for the note.

Going to be tough to track down - I don't see how that could happen. Probably has something to do with my ignorance with the ThreadLocal class, which is holding the HIbernate session.

One other question. I have everything wrapped in Tx's, even simple selects. Should I be doing that? Or should I only wrapp insert/update/delete in Tx's?

emmanuel · **Posted:** Tue Jan 20, 2004 2:01 pm

It's fine. Gavin always yell on people considering simple select don't need tx :)

rich · **Joined:** Sat Dec 20, 2003 5:09 pm **Posts:** 38

emmanuel wrote:

It's fine. Gavin always yell on people considering simple select don't need tx :)

Hehe

Emmanuel, thanks a log for your guidance. I found the issue! Just like you said, there was on code snippet where I forgot to do a tx.commit().

Thanks again!

Rich