Hibernate 3 unable to update or delete

[fmaredia]

We migrating from Hibernate 2 to Hibernate 3. We upgraded JBoss to version 4.02. Our old version with Jboss 4.0.1 with Hibernate 2 worked fine with no errors. When we migrated everything works fine, except that we can not update or delete. It makes no sense! There is no error produced either.

Hibernate-service.xml is as Follows:

<server>
 <mbean code="org.jboss.hibernate.jmx.Hibernate" name="jboss.har:service=Hibernate">
 <attribute name="DatasourceName">java:/MySqlDS</attribute>
 <attribute name="Dialect">org.hibernate.dialect.MySQLDialect</attribute>
 <attribute name="SessionFactoryName">java:/hibernate/HibernateFactory</attribute>
 <attribute name="CacheProviderClass">org.hibernate.cache.TreeCacheProvider</attribute>
 <attribute name="ShowSqlEnabled">false</attribute>
 </mbean>
</server>

[biteme]

I'm having the same problem. Being a clueless newbie to JBoss/Hibernate, I'm poking around trying to find a debug mode that would produce some output about the state of things.

[garbett]

Similar problem on my configuration. I set ShowSqlEnabled to true and no SQL is being generated. I suspect something in the transaction management.

[garbett]

I turned on debuging by editing the conf/log4j.xml file. I changed this:

 <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
 <param name="Target" value="System.out"/>
 <param name="Threshold" value="INFO"/>

To this:

 <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
 <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
 <param name="Target" value="System.out"/>
 <param name="Threshold" value="DEBUG"/>

Now there is volumes of output to look at. The

16:20:42,301 INFO [STDOUT] class org.centerstone.admin.TupleSaveAction::execute()
16:20:42,302 INFO [STDOUT] HibernateUtil::getSession()
16:20:42,302 INFO [STDOUT] HibernateUtil::getSessionFactory()
16:20:42,302 DEBUG [SessionFactoryObjectFactory] JNDI lookup: hibernate/AdminSessionFactory
16:20:42,302 DEBUG [SessionFactoryObjectFactory] lookup: uid=8a828acf03d2c6bd0103d2c6c15e0000
16:20:42,302 DEBUG [JDBCContext] successfully registered Synchronization
16:20:42,302 DEBUG [SessionImpl] opened session at timestamp: 4570860922068992
16:20:42,302 INFO [STDOUT] HibernateUtil::beginTransaction()
16:20:42,303 INFO [STDOUT] HibernateUtil::getSession()
16:20:42,303 DEBUG [JTATransaction] begin
16:20:42,303 DEBUG [JTATransaction] Looking for UserTransaction under: UserTransaction
16:20:42,303 DEBUG [JTATransaction] Obtained UserTransaction
16:20:42,303 INFO [STDOUT] updateTuple(saveOrUpdate) org.centerstone.admin.Tuple@4486de[tupleId=1,domain=Test,subDomain=Cartoon,label=Flintstones,value=1]
16:20:42,303 DEBUG [Cascades] id unsaved-value: null
16:20:42,303 DEBUG [AbstractReassociateEventListener] reassociating transient instance: [org.centerstone.admin.Tuple#1]
16:20:42,303 DEBUG [AbstractSaveEventListener] persistent instance of: org.centerstone.admin.Tuple
16:20:42,303 DEBUG [DefaultSaveOrUpdateEventListener] ignoring persistent instance
16:20:42,303 DEBUG [DefaultSaveOrUpdateEventListener] object already associated with session: [org.centerstone.admin.Tuple#1]
16:20:42,304 INFO [STDOUT] updateTuple(saveOrUpdate) org.centerstone.admin.Tuple@f27cdc[tupleId=2,domain=Test,subDomain=Cartoon,label=Ren and Stimpy,value=2]
16:20:42,304 DEBUG [Cascades] id unsaved-value: null
16:20:42,304 DEBUG [AbstractReassociateEventListener] reassociating transient instance: [org.centerstone.admin.Tuple#2]
16:20:42,304 DEBUG [AbstractSaveEventListener] persistent instance of: org.centerstone.admin.Tuple
16:20:42,304 DEBUG [DefaultSaveOrUpdateEventListener] ignoring persistent instance
16:20:42,304 DEBUG [DefaultSaveOrUpdateEventListener] object already associated with session: [org.centerstone.admin.Tuple#2]
16:20:42,304 INFO [STDOUT] HibernateUtil::commitTransaction()
16:20:42,304 INFO [STDOUT] HibernateUtil::commitTransaction() actual call
16:20:42,304 DEBUG [JTATransaction] commit
16:20:42,304 INFO [STDOUT] HibernateUtil::closeSession()
16:20:42,304 DEBUG [SessionImpl] closing session
16:20:42,304 DEBUG [CacheSynchronization] transaction before completion callback
16:20:42,304 DEBUG [CacheSynchronization] automatically flushing session
16:20:42,304 DEBUG [SessionImpl] automatically flushing session
16:20:42,304 DEBUG [JDBCContext] before transaction completion
16:20:42,305 DEBUG [SessionImpl] before transaction completion

Note the 'ignoring persistent instance'. What would cause this?

[garbett]

I got rid of the 'ignoring persistent instance' by removing a lock call and just calling saveOrUpdate. However the same problem still remains.

[sebersole]

The message 'ignoring persistent instance' simply means that Hibernate encountered an entity instance during save/update (or cascade) that is already in a persistent state (i.e., associated with the session).

For example:

MyEntity myEntity = ( MyEntity ) session.load( MyEntity.class, id );
session.saveOrUpdate( myEntity );

will give you this message because the instance represented by myEntity is already associated with the session.

This is not a problem.

The real problem is that for some reason that entity is not (apparently) being caught up in the flush processing.

I'd need to see a *simple* test case reproducing this. Create a Hibernate JIRA bug report and attach the test:

http://opensource.atlassian.com/projects/hibernate

[sebersole]

Do you think your Tuple#1 and Tuple#2 are really in detached or persistent state when this processing occurs?

[garbett]

As I mentioned above, I fixed the ignore by getting rid of a extra lock call. I'm working on a simple reproducible test case.

[jukvaa]

Hi,

Just in case it would help, here's another debug log of what I think is the same problem (JBoss 4.0.2, Hibernate3). It's getting the identifier from sequence, but for some reason, no insert statement is made.

(In this case I'm trying to save a new instance of Paper class from stateless session bean)

2005-05-13 16:36:57,875 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] JNDI lookup: hibernate/HibernateFactory
2005-05-13 16:36:57,875 DEBUG [org.hibernate.impl.SessionFactoryObjectFactory] lookup: uid=42e4e57203d644650103d64491890000
2005-05-13 16:36:57,890 DEBUG [org.hibernate.jdbc.JDBCContext] successfully registered Synchronization
2005-05-13 16:36:57,890 DEBUG [org.hibernate.impl.SessionImpl] opened session at timestamp: 4571100847616000
2005-05-13 16:36:57,906 DEBUG [org.hibernate.transaction.JTATransaction] begin
2005-05-13 16:36:57,906 DEBUG [org.hibernate.transaction.JTATransaction] Looking for UserTransaction under: UserTransaction
2005-05-13 16:36:57,906 DEBUG [org.hibernate.transaction.JTATransaction] Obtained UserTransaction
2005-05-13 16:36:57,921 DEBUG [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] saving transient instance
2005-05-13 16:36:57,921 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2005-05-13 16:36:57,921 DEBUG [org.hibernate.jdbc.AbstractBatcher] opening JDBC connection
2005-05-13 16:36:57,921 DEBUG [org.hibernate.SQL] select nextval ('papers_paper_id_seq')
2005-05-13 16:36:57,921 DEBUG [org.hibernate.jdbc.AbstractBatcher] preparing statement
2005-05-13 16:36:57,921 DEBUG [org.hibernate.id.SequenceGenerator] Sequence identifier generated: 5
2005-05-13 16:36:57,921 DEBUG [org.hibernate.jdbc.AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2005-05-13 16:36:57,921 DEBUG [org.hibernate.jdbc.AbstractBatcher] closing statement
2005-05-13 16:36:57,921 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] generated identifier: 5, using strategy: org.hibernate.id.SequenceGenerator
2005-05-13 16:36:57,921 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] saving [fi.flowman.system.model.Paper#5]
2005-05-13 16:36:57,937 DEBUG [org.hibernate.engine.Cascades] id unsaved-value: null
2005-05-13 16:36:57,968 DEBUG [org.hibernate.jdbc.JDBCContext] running Session.finalize()
2005-05-13 16:36:58,015 DEBUG [org.hibernate.transaction.JTATransaction] commit
2005-05-13 16:36:58,015 DEBUG [org.hibernate.impl.SessionImpl] closing session
2005-05-13 16:36:58,015 DEBUG [org.hibernate.jdbc.AbstractBatcher] closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
2005-05-13 16:36:58,015 DEBUG [org.hibernate.transaction.CacheSynchronization] transaction before completion callback
2005-05-13 16:36:58,015 DEBUG [org.hibernate.transaction.CacheSynchronization] automatically flushing session
2005-05-13 16:36:58,015 DEBUG [org.hibernate.impl.SessionImpl] automatically flushing session
2005-05-13 16:36:58,015 DEBUG [org.hibernate.jdbc.JDBCContext] before transaction completion
2005-05-13 16:36:58,015 DEBUG [org.hibernate.impl.SessionImpl] before transaction completion
2005-05-13 16:36:58,015 DEBUG [org.hibernate.transaction.CacheSynchronization] transaction after completion callback, status: 3
2005-05-13 16:36:58,015 DEBUG [org.hibernate.jdbc.JDBCContext] after transaction completion
2005-05-13 16:36:58,015 DEBUG [org.hibernate.impl.SessionImpl] after transaction completion
2005-05-13 16:37:01,718 DEBUG [org.hibernate.jdbc.JDBCContext] running Session.finalize()

[garbett]

How did you turn on this level of debugging? I added the following to my log4j.xml and got no output in the log file. There must be another variable somewhere.

<category name="org.hibernate">
 <priority value="DEBUG"/>
</category>

[fmaredia]

I think I have figured out the problem but need some help, PLEASE. It seems that whenever I am using the SessionFactory that is retreived from JNDI I cannot update or delete (I know it sounds wierd). However when I create a new SessionFactory without retrieving from JNDI everything works fine and no problem. The only reason we do not want to create a SessionFactory on our own is that we wanted the Application Server (JBoss) to be reponsible for managing the session and what not. Has anyone faced anything like this?

We are using JBoss 4.0.2 and Hibernate 3.0.3.

Please someone tell me there is something I can do. I am going crazy because it makes no sense why I can save but not update or delete to the database

[garbett]

I changed my test code over to create a SessionFactory and it bombs with "You cannot commit during a managed transaction!". I remove the commit and voila no data is commited. Wait, that's not what I want.

[fmaredia]

I think there is a serious problem!!! Whom do I notify of this problem and how.
Server Configuration:

JBoss 4.0.2
EJB 3 Preview 5
Hibernate 3.0.3
Hibernate mappings, code, DAO all mapped in a HAR file

Data saved, updated, deleted at the EJB layer.

Example

@MethodPermissions({"Sales"})
 @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
 public void newsimpleupdate() {
 try {
 Session session = HibernateUtil.getSession();
 Transaction tx = session.beginTransaction();

 Types mytype = new Types(17);
 mytype.setId(17);
 mytype.setDescription("my new test");
 mytype.setType("Test5");

 session.update(mytype);

 tx.commit();
 HibernateUtil.closeSession();

 System.out.println("Updated Type to " + mytype.getType());
 }
 catch (Exception e) {log.error(e.getMessage()); }
 }

Using Session Factory from JBoss results in commit failure in methods of update and delete. Save works fine!

[garbett]

I submitted and example case and bug report at http://opensource.atlassian.com/projects/hibernate/browse/HHH-490

[starksm64]

http://jira.jboss.com/jira/browse/EJBTHREE