[hibernate-issues] [Hibernate-JIRA] Commented: (HHH-2588) Incorrect database updates with "generated" fields in record

Incorrect database updates with "generated" fields in record ------------------------------------------------------------ Key: HHH-2588 URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2588 Project: Hibernate3 Issue Type: Bug Components: core Affects Versions: 3.2.0.ga, 3.2.3 Environment: Tested with Hibernate 3.2.3 and 3.2.0GA, Oracle 10gR2, Linux, Java 5. Reporter: Frits Jalvingh Attachments: hhh-2588.patch, hhh2588-2.patch I have a single POJO (UserGroup) which is based on a superclass which defines a number of properties as @Generated(GenerationTime.INSERT); amongst others tcn and ros_id. These properties are defined as "not null" in the database, and are filled in by an insert database trigger. When I create a new instance and do this: -------------------- Transaction tr = getSession().beginTransaction(); UserGroup ug = new UserGroup(); ug.setType(UserGroupType.PLN); ug.setName(name); ug.setDescription(desc); getSession().save(ug); // persist() exhibits the same problem... ug.setGroupEmail(&quot;jaja(a)nono.com&quot;); tr.commit(); -------------------- I get a database exception: ORA-01407: cannot update ("TEST"."CRM_GROUPS"."ROS_ID") to NULL When I look at the persister's logging I see something very wrong happening: -------------------- DEBUG - commit DEBUG - automatically flushing session DEBUG - flushing session DEBUG - processing flush-time cascades DEBUG - dirty checking collections DEBUG - Flushing entities and processing referenced collections DEBUG - nl.itris.viewpoint.db.crm.UserGroup.groupEmail is dirty DEBUG - nl.itris.viewpoint.db.crm.UserGroup.memberMutable is dirty DEBUG - Updating entity: [nl.itris.viewpoint.db.crm.UserGroup#1150000159] DEBUG - nl.itris.viewpoint.db.crm.UserGroup.groupEmail is dirty DEBUG - nl.itris.viewpoint.db.crm.UserGroup.memberMutable is dirty DEBUG - Collection found: [nl.itris.viewpoint.db.crm.UserGroup.memberList#1150000159], was: [<unreferenced>] (initialized) DEBUG - Processing unreferenced collections DEBUG - Scheduling collection removes/(re)creates/updates DEBUG - Flushed: 1 insertions, 1 updates, 0 deletions to 1 objects DEBUG - Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections DEBUG - listing entities: DEBUG - nl.itris.viewpoint.db.crm.UserGroup{groupEmail=jal(a)etc.to, memberList=[], type=PLN, tcn=null, logTime=null, logModule=null, id=1150000159, organisationId=null, groupLeader=null, description=test2, memberMutable=null, logDate=null, name=test2, logUser=null} DEBUG - executing flush DEBUG - registering flush begin DEBUG - Inserting entity: [nl.itris.viewpoint.db.crm.UserGroup#1150000159] DEBUG - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) DEBUG - insert into CRM_GROUPS (CGP_DESCRIPTION, CGP_GROUPEMAIL, CST_ID, CGP_MEMBER_MUTABLE, CGP_NAME, CGP_TYPE, CGP_ID) values (?, ?, ?, ?, ?, ?, ?) DEBUG - preparing statement DEBUG - Dehydrating entity: [nl.itris.viewpoint.db.crm.UserGroup#1150000159] DEBUG - binding 'test2' to parameter: 1 DEBUG - binding null to parameter: 2 DEBUG - binding null to parameter: 3 DEBUG - binding 'test2' to parameter: 5 DEBUG - Binding 'PLN' to parameter: 6 DEBUG - binding '1150000159' to parameter: 7 DEBUG - Executing batch size: 1 DEBUG - success of batch update unknown: 0 DEBUG - about to close PreparedStatement (open PreparedStatements: 1, globally: 1) DEBUG - closing statement DEBUG - about to open PreparedStatement (open PreparedStatements: 0, globally: 0) DEBUG - select usergroup_.LOG_DATE as LOG2_74_, usergroup_.LOG_MODULE as LOG3_74_, usergroup_.LOG_TIME as LOG4_74_, usergroup_.LOG_USER as LOG5_74_, usergroup_.TCN as TCN74_, usergroup_.ROS_ID as ROS7_74_ from CRM_GROUPS usergroup_ where usergroup_.CGP_ID=? DEBUG - preparing statement DEBUG - binding '1150000159' to parameter: 1 DEBUG - about to open ResultSet (open ResultSets: 0, globally: 0) DEBUG - returning '2007-04-26 00:00:00' as column: LOG2_74_ DEBUG - returning null as column: LOG3_74_ DEBUG - returning '14:28:04' as column: LOG4_74_ DEBUG - returning 'VPC' as column: LOG5_74_ DEBUG - returning '310525020' as column: TCN74_ DEBUG - returning '1500' as column: ROS7_74_ DEBUG - about to close ResultSet (open ResultSets: 1, globally: 1) DEBUG - Updating entity: [nl.itris.viewpoint.db.crm.UserGroup#1150000159] DEBUG - about to open PreparedStatement (open PreparedStatements: 1, globally: 1) DEBUG - update CRM_GROUPS set TCN=?, ROS_ID=?, CGP_DESCRIPTION=?, CGP_GROUPEMAIL=?, CST_ID=?, CGP_MEMBER_MUTABLE=?, CGP_NAME=?, CGP_TYPE=? where CGP_ID=? DEBUG - preparing statement DEBUG - Dehydrating entity: [nl.itris.viewpoint.db.crm.UserGroup#1150000159] DEBUG - binding null to parameter: 1 DEBUG - binding null to parameter: 2 DEBUG - binding 'test2' to parameter: 3 DEBUG - binding &#39;jal(a)etc.to&#39; to parameter: 4 DEBUG - binding null to parameter: 5 DEBUG - binding 'test2' to parameter: 7 DEBUG - Binding 'PLN' to parameter: 8 DEBUG - binding '1150000159' to parameter: 9 DEBUG - Executing batch size: 1 DEBUG - about to close PreparedStatement (open PreparedStatements: 2, globally: 2) DEBUG - closing statement DEBUG - Could not execute JDBC batch update [update CRM_GROUPS set TCN=?, ROS_ID=?, CGP_DESCRIPTION=?, CGP_GROUPEMAIL=?, CST_ID=?, CGP_MEMBER_MUTABLE=?, CGP_NAME=?, CGP_TYPE=? where CGP_ID=?] to.etc.dbpool.BetterSQLException: java.sql.BatchUpdateException: ORA-01407: cannot update ("VIEWPOINT"."CRM_GROUPS"."ROS_ID") to NULL SQL: update CRM_GROUPS set TCN=?, ROS_ID=?, CGP_DESCRIPTION=?, CGP_GROUPEMAIL=?, CST_ID=?, CGP_MEMBER_MUTABLE=?, CGP_NAME=?, CGP_TYPE=? where CGP_ID=? Parameters: #1:[null] #2:[null] #3:java.lang.String:test2 #4:java.lang.String:jal@etc.to #5:[null] #6:java.lang.String:N #7:java.lang.String:test2 #8:java.lang.String:PLN #9:java.lang.Long:1150000159 at to.etc.dbpool.PreparedStatementProxy.wrap(PreparedStatementProxy.java:68) at to.etc.dbpool.StatementProxy.executeBatch(StatementProxy.java:176) at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48) at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:246) at org.hibernate.persister.entity.AbstractEntityPersister.processGeneratedProperties(AbstractEntityPersister.java:3691) at org.hibernate.persister.entity.AbstractEntityPersister.processUpdateGeneratedProperties(AbstractEntityPersister.java:3680) at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:124) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338) at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106) at nl.itris.moca.ajax.Planner.updatePlanGroup(Planner.java:1717) ---------------------------------- Hibernate starts by inserting the new record correctly, and then reselects the inserted record to retrieve the changed fields correctly. But after that it does an update of that record with stale data: it sets all of the generated fields it *has* read to null, and updates the groupEmail field which for some reason was not present in the insert!? It looks like multiple versions of the same records are maintained in some way?? The problem is triggered by the existence of the "save" call *followed by* another change to the record. But the same problem occurs when other things cause an intermediary update, for instance when trying to save the data in a collection parented by UserGroup. Because this problem also occurs when I add/change elements in the UserGroup's associated GroupMember one-to-many association I am effectively unable to store a group with it's members in one transaction! In addition I noticed that the persist() call seems to check defined constraints on the record at the time persist() is called instead of the time that it gets commited. This means it can only be called when the pojo is complete which looks odd to me? I sort of understand this for save() as that is required to return the primary key but I do not understand why this is needed for persist...