Need help with Hibernate? Read this first:
http://www.hibernate.org/ForumMailingli ... AskForHelp

Hibernate version:
3.1.2
Mapping documents:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
"http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >

<hibernate-mapping default-lazy="false">

<class name="net.canal.admin.persistence.Template" table="TEMPLATES">
<id name="id" type="long" column="TEMPLATE_ID" unsaved-value="0">
<generator class="identity"/>
</id>

<!-- base class attributes -->
<property name="name" type="string" not-null="true" column="NAME"/>
<property name="description" type="string" column="DESCR"/>
<property name="isDeleted" type="boolean" column="ISDELETED"/>
<property name="createTime" type="calendar" column="CREATE_TIME"/>
<property name="modifyTime" type="calendar" column="MODIFY_TIME"/>

<property name="folderDefinition" type="binary" length="65535"/>

<many-to-one name="category" not-null="true" column="TEMPLATECAT_ID" class="net.canal.admin.persistence.TemplateCategory"/>
<many-to-one name="org" class="net.canal.admin.persistence.Org" column="ORG_ID" cascade="none" not-null="true"/>
<property name="shared" type="boolean" column="SHARED"/>

<set name="attributeGroups" table="TEMPLATE_ATTRIBUTEGROUP" cascade="all-delete-orphan" lazy="false" order-by="SEQUENCE asc">
<key column="TEMPLATE_ID"/>
<one-to-many class="net.canal.admin.persistence.TemplateAttributeGroup"/>
</set>

</class>

</hibernate-mapping>

Full stack trace of any exception that occurs:
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - commit
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - automatically flushing session
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - flushing session
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - processing flush-time cascades
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - processing cascade ACTION_SAVE_UPDATE for: net.canal.admin.persistence.Template
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - cascade ACTION_SAVE_UPDATE for collection: net.canal.admin.persistence.Template.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done cascade ACTION_SAVE_UPDATE for collection: net.canal.admin.persistence.Template.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - deleting orphans for collection: net.canal.admin.persistence.Template.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done deleting orphans for collection: net.canal.admin.persistence.Template.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done processing cascade ACTION_SAVE_UPDATE for: net.canal.admin.persistence.Template
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - processing cascade ACTION_SAVE_UPDATE for: net.canal.admin.persistence.Org
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - cascade ACTION_SAVE_UPDATE for collection: net.canal.admin.persistence.Org.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done cascade ACTION_SAVE_UPDATE for collection: net.canal.admin.persistence.Org.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - deleting orphans for collection: net.canal.admin.persistence.Org.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done deleting orphans for collection: net.canal.admin.persistence.Org.attributeGroups
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - cascade ACTION_SAVE_UPDATE for collection: net.canal.admin.persistence.Org.applications
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done cascade ACTION_SAVE_UPDATE for collection: net.canal.admin.persistence.Org.applications
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - deleting orphans for collection: net.canal.admin.persistence.Org.applications
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done deleting orphans for collection: net.canal.admin.persistence.Org.applications
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Cascade - done processing cascade ACTION_SAVE_UPDATE for: net.canal.admin.persistence.Org
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - dirty checking collections
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushing entities and processing referenced collections
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - net.canal.admin.persistence.Template.description is dirty
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.DefaultFlushEntityEventListener - Updating entity: [net.canal.admin.persistence.Template#5]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Collections - Collection found: [net.canal.admin.persistence.Template.attributeGroups#5], was: [net.canal.admin.persistence.Template.attributeGroups#5] (initialized)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Collections - Collection found: [net.canal.admin.persistence.Org.attributeGroups#1], was: [net.canal.admin.persistence.Org.attributeGroups#1] (uninitialized)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.Collections - Collection found: [net.canal.admin.persistence.Org.applications#1], was: [net.canal.admin.persistence.Org.applications#1] (uninitialized)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Processing unreferenced collections
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Scheduling collection removes/(re)creates/updates
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 insertions, 1 updates, 0 deletions to 3 objects
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 3 collections
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.pretty.Printer - listing entities:
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.pretty.Printer - net.canal.admin.persistence.Org{attributeGroups=<uninitialized>, description=null, createTime=null, applications=<uninitialized>, modifyTime=null, isDeleted=null, name=Canal.net, id=1}
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.pretty.Printer - net.canal.admin.persistence.Template{attributeGroups=[], org=net.canal.admin.persistence.Org#1, category=net.canal.admin.persistence.TemplateCategory#5, folderDefinition=null, description=, shared=false, createTime=null, modifyTime=null, isDeleted=null, name=Root Permission, id=5}
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.pretty.Printer - net.canal.admin.persistence.TemplateCategory{description=null, createTime=null, modifyTime=null, isDeleted=null, name=Permission, id=5}
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - executing flush
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Updating entity: [net.canal.admin.persistence.Template#5]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.SQL - update TEMPLATES set NAME=?, DESCR=?, ISDELETED=?, CREATE_TIME=?, MODIFY_TIME=?, folderDefinition=?, TEMPLATECAT_ID=?, ORG_ID=?, SHARED=? where TEMPLATE_ID=?
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Dehydrating entity: [net.canal.admin.persistence.Template#5]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - binding 'Root Permission' to parameter: 1
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - binding '' to parameter: 2
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BooleanType - binding null to parameter: 3
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - binding null to parameter: 4
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - binding null to parameter: 5
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BinaryType - binding null to parameter: 6
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - binding '5' to parameter: 7
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - binding '1' to parameter: 8
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BooleanType - binding 'false' to parameter: 9
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - binding '5' to parameter: 10
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - Adding to batch
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - Executing batch size: 1
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - post flush
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.JDBCContext - before transaction completion
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - before transaction completion
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - re-enabling autocommit
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - committed JDBC Connection
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.JDBCContext - after transaction completion
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - setting flush mode to: NEVER
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - begin
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - current autocommit status: true
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - disabling autocommit
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.JDBCContext - after transaction begin
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.query.QueryPlanCache - located HQL query plan in cache (from TemplateCategory templateCategory order by templateCategory.id asc)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.query.QueryPlanCache - located HQL query plan in cache (from TemplateCategory templateCategory order by templateCategory.id asc)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.query.HQLQueryPlan - find: from TemplateCategory templateCategory order by templateCategory.id asc
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.QueryParameters - named parameters: {}
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.hql.classic.QueryTranslatorImpl - HQL: from net.canal.admin.persistence.TemplateCategory templateCategory order by templateCategory.id asc
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.hql.classic.QueryTranslatorImpl - SQL: select templateca0_.TEMPLATECAT_ID as TEMPLATE1_25_, templateca0_.NAME as NAME25_, templateca0_.DESCR as DESCR25_, templateca0_.ISDELETED as ISDELETED25_, templateca0_.CREATE_TIME as CREATE5_25_, templateca0_.MODIFY_TIME as MODIFY6_25_ from TEMPLATE_CATEGORIES templateca0_ order by templateca0_.TEMPLATECAT_ID asc
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.SQL - select templateca0_.TEMPLATECAT_ID as TEMPLATE1_25_, templateca0_.NAME as NAME25_, templateca0_.DESCR as DESCR25_, templateca0_.ISDELETED as ISDELETED25_, templateca0_.CREATE_TIME as CREATE5_25_, templateca0_.MODIFY_TIME as MODIFY6_25_ from TEMPLATE_CATEGORIES templateca0_ order by templateca0_.TEMPLATECAT_ID asc
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - processing result set
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result set row: 0
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - returning '1' as column: TEMPLATE1_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result row: EntityKey[net.canal.admin.persistence.TemplateCategory#1]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [net.canal.admin.persistence.TemplateCategory#1]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [net.canal.admin.persistence.TemplateCategory#1]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning 'Organization' as column: NAME25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning null as column: DESCR25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BooleanType - returning null as column: ISDELETED25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: CREATE5_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: MODIFY6_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result set row: 1
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - returning '2' as column: TEMPLATE1_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result row: EntityKey[net.canal.admin.persistence.TemplateCategory#2]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [net.canal.admin.persistence.TemplateCategory#2]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [net.canal.admin.persistence.TemplateCategory#2]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning 'Department' as column: NAME25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning null as column: DESCR25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BooleanType - returning null as column: ISDELETED25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: CREATE5_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: MODIFY6_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result set row: 2
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - returning '3' as column: TEMPLATE1_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result row: EntityKey[net.canal.admin.persistence.TemplateCategory#3]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [net.canal.admin.persistence.TemplateCategory#3]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [net.canal.admin.persistence.TemplateCategory#3]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning 'Program' as column: NAME25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning null as column: DESCR25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BooleanType - returning null as column: ISDELETED25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: CREATE5_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: MODIFY6_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result set row: 3
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - returning '4' as column: TEMPLATE1_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result row: EntityKey[net.canal.admin.persistence.TemplateCategory#4]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [net.canal.admin.persistence.TemplateCategory#4]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [net.canal.admin.persistence.TemplateCategory#4]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning 'User' as column: NAME25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning null as column: DESCR25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BooleanType - returning null as column: ISDELETED25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: CREATE5_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: MODIFY6_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result set row: 4
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - returning '5' as column: TEMPLATE1_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result row: EntityKey[net.canal.admin.persistence.TemplateCategory#5]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result set row: 5
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.LongType - returning '6' as column: TEMPLATE1_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - result row: EntityKey[net.canal.admin.persistence.TemplateCategory#6]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [net.canal.admin.persistence.TemplateCategory#6]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [net.canal.admin.persistence.TemplateCategory#6]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning 'Form' as column: NAME25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.StringType - returning null as column: DESCR25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.BooleanType - returning null as column: ISDELETED25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: CREATE5_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.type.CalendarType - returning null as column: MODIFY6_25_
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - done processing result set (6 rows)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.loader.Loader - total objects hydrated: 5
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [net.canal.admin.persistence.TemplateCategory#1]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [net.canal.admin.persistence.TemplateCategory#1]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [net.canal.admin.persistence.TemplateCategory#2]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [net.canal.admin.persistence.TemplateCategory#2]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [net.canal.admin.persistence.TemplateCategory#3]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [net.canal.admin.persistence.TemplateCategory#3]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [net.canal.admin.persistence.TemplateCategory#4]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [net.canal.admin.persistence.TemplateCategory#4]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [net.canal.admin.persistence.TemplateCategory#6]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [net.canal.admin.persistence.TemplateCategory#6]
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.engine.StatefulPersistenceContext - initializing non-lazy collections
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - commit
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.JDBCContext - before transaction completion
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - before transaction completion
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - re-enabling autocommit
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.transaction.JDBCTransaction - committed JDBC Connection
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.JDBCContext - after transaction completion
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
24.04.06 09:36:27 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
24.04.06 09:36:28 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - closing session
24.04.06 09:36:28 [http-8080-Processor25] DEBUG org.hibernate.jdbc.ConnectionManager - performing cleanup
24.04.06 09:36:28 [http-8080-Processor25] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
24.04.06 09:36:28 [http-8080-Processor25] DEBUG org.hibernate.jdbc.JDBCContext - after transaction completion
24.04.06 09:36:28 [http-8080-Processor25] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
24.04.06 09:36:28 [http-8080-Processor25] DEBUG org.hibernate.impl.SessionImpl - after transaction completion

Name and version of the database you are using:
mySQL 5.0

~~~~~~~~~~~~~~~~~~
The problem is after updating one Template, another Template in the table is somehow touched (the Org ID becomes a very big negative number - it is 0x800000000000001).
Totally lost, have no idea how this was happened !

thanks in advance for looking at this problem !
lixin

Hibernate tends to keep its spurious-modification code dormant until after you've deployed your code to mission-critical sites, so unless you noticed this in a nuclear reactor control application, chances are it's something you did that caused the problem.

;)

Is the mysteriously-modified Template in memory at the time? Do any of your mutator methods have side effects? Are you setting fake values into properties for testing purposes? Anything like this can cause strange values to be written to the database. Remember, once an object has been loaded by hibernate, any changes made to it will be persisted the name time the session is flushed.

Another possibility is that you've got odd casting/conversion going on. If you try to cram a 64 bit number into a 32-bit field, oddness like this happens. The fact that this is a negative 64-bit number raises this as a possibility, seeing as most int fields are handled as 32-bit numbers.

Your trace isn't helpful. At no point are any huge negative numbers mentioned in it, and you haven't included the SQL. Try creating the trace again, except this time, turn show_sql on, and find the output that writes the strange value to the DB.

this is indeed strange.

after turning on show_sql, i only find one update statement:

Hibernate: update TEMPLATES set NAME=?, DESCR=?, ISDELETED=?, CREATE_TIME=?, MODIFY_TIME=?, folderDefinition=?, TEMPLATECAT_ID=?, ORG_ID=?, SHARED=? where TEMPLATE_ID=?

does not find other errors though.

the flow in my application is something like this (with Struts and Spring Framework):

a page to list templates;

select one for updating;
// id passed to Struts action, which in turns calls (Spring):
TemplateManager manager = getBean ("templateManager");
Template template = manager.getTemplateById (id);
// id then kept in session scope ActionForm

click 'update' button:
// get id from ActionForm and get the template again:
TemplateManager manager = getBean ("templateManager");
Template template = manager.getTemplateById (id);
// update modified fields
template.setXXX, .....
// save template
manager.saveTemplate (template);

in saveTemplate:
if (template.getId() != null)
getHibernateTemplate().update (template);

that's all. I do this flow for other objects. So far so good. Only this template gives me headache.

still no clue.

thanks for reading !

In that case it's most likely something to do with types and casting. Check the type of the database column, the property mapping, and the type of the java primitive/class to ensure that they all match up. If you're using a user type, check the nullSafeSet and nullSafeGet methods.

still have no idea.

looks like all properties are using the correct type.

the strange thing is that the object that is being updated is correctly updated but another record in the same table is affected.

how this could happen ? show_sql does not show any other update statement.

any way to trace this ?

one more discovery:
if i indeed modify some properties of the object, then it is ok;
if i just fetch the object, do not modify anything, then save it, the problem then happens.

Sounds like proxying may be a factor. When you modify some properties, that causes the object to be fully inflated, so hashCode etc. will work properly. If you don't modify anything, and don't access any member methods, then internal member variables will not be initialized. If those internal members are used for something important, like hashCode, then you'll get errors.

If you access a member via its accesssor (any mapped member except the id), does it all work correctly? If it does, then it's likely that you're referring to mapped members before they're being initialized.

Look in all your mapped class implementations (Template.java, etc.) looking for uses of member variables. Replace any direct uses of member variables with the appropriate accessors/mutators (get/set methods). Only the get/set methods are allowed access a member variable directly, all other methods must use those getters and setters. This applies to hashCode and equals even more than to other methods.

Iam using a generic base class :

public class BaseObject implements Serializable {

public String toString() {
return ToStringBuilder.reflectionToString(this,
ToStringStyle.MULTI_LINE_STYLE);
}

public boolean equals(Object o) {
return EqualsBuilder.reflectionEquals(this, o);
}

public int hashCode(Object o) {
return HashCodeBuilder.reflectionHashCode(this);
}

}

will this cause the problem ?

You'll have to change those implementations. The apache *Builder.reflection*() methods all use reflection to get at the private fields: they don't use the get methods. Hibernate proxies the get methods, meaning that if the private fields are accessed before your object has been deproxied, those fields will report the default values instead of the real values. As a result, every object will have the same hash code, they will all appear to be equal, and toString() will return the same string for all objects. Clearly, not a desirable situation.

You can continue to use the *Builder classes, you just have to use the append methods, couple with your classes' get methods (not field names).

I see. thanks !

I guess there is no better way but have to write the three mthods for each class. That's tedious though.

Yep, a little bit tedious, but you can still use the HashCodeBuilder, EqualsBuilder and ToStringBuilder classes, just not those reflection methods.

Also, don't forget that the end result will be both more accurate and faster. Not only is reflection slow, but you're also using non-business-key fields that you shouldn't be. If you load an object that has a set member (parent.getChildren()), and the hashCode method in the Child class is wrong, then when you update a child, you'll have problems. The hashCode used to put the child into the set won't be the same as the hashCode it'll have when it's being saved. By eliminating all non business key fields from the hashCode and equals methods, you'll be preventing problems caused by this, and reducing the amount of work that has to be done to calculate the hashCode or whatever.