This is the first time I've had this problem. Essentially, I'm saving an object for the first time [com.declivis.pos.Media] and then updating another object (com.declivis.pos.StockKeepingUnit) with with newly saved Media object. This has worked for me in the past (Id change was transparent) although in that case I wasn't persisting the actual object, just its id.

At every point a hibernate exception is caught, I get the exception listed below. The first transaction completes properly, but all subsequent attempts to get or save any useful data appear to fail. Certainly the last call to update does not complete.

Any ideas?

TIA

Hibernate version:
3.0.5
Code between sessionFactory.openSession() and session.close():
Session ds = null;
Transaction tx = null;
try {
ds = GlobalData.sessionFactory.openSession();
try {
tx = ds.beginTransaction();
ds.save(media);
tx.commit();
} catch (HibernateException he) {
log.warn("1) " + he.toString());
if (tx != null)
tx.rollback();
}
log.debug(media.toString());
StockKeepingUnit sku = null;
try {
sku = (StockKeepingUnit) ds.get(StockKeepingUnit.class, skuId);
ds.flush();
} catch (HibernateException he) {
log.warn("2) " + he.toString());
}
if (sku != null) {
sku.setMedia(media);
try {
tx = ds.beginTransaction();
ds.update(sku);
tx.commit();
} catch (HibernateException he) {
log.warn("3) " + he.toString());
if (tx != null)
tx.rollback();
}
}
} finally {
if (ds != null)
ds.close();
}
Full stack trace of any exception that occurs:
org.hibernate.HibernateException: identifier of an instance of com.declivis.pos.Media altered from 1 to 1
Name and version of the database you are using:
MySQL 4.1.somthing
Debug level Hibernate log excerpt:
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: opened session at timestamp: 4589158527254528
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: begin
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Looking for UserTransaction under: java:comp/UserTransaction
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Obtained UserTransaction
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Began a new JTA transaction
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: successfully registered Synchronization
Jul 03 10:13:51 org.hibernate.event.def.DefaultSaveOrUpdateEventListener[DEBUG]: saving transient instance
Jul 03 10:13:51 org.hibernate.event.def.AbstractSaveEventListener[DEBUG]: generated identifier: , using strategy: org.hibernate.id.IdentityGenerator
Jul 03 10:13:51 org.hibernate.event.def.AbstractSaveEventListener[DEBUG]: saving [com.declivis.pos.Media#<null>]
Jul 03 10:13:51 org.hibernate.event.def.AbstractSaveEventListener[DEBUG]: executing insertions
Jul 03 10:13:51 org.hibernate.cache.UpdateTimestampsCache[DEBUG]: Pre-invalidating space [media]
Jul 03 10:13:51 org.hibernate.persister.entity.BasicEntityPersister[DEBUG]: Inserting entity: com.declivis.pos.Media (native id)
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
Jul 03 10:13:51 org.hibernate.jdbc.ConnectionManager[DEBUG]: opening JDBC connection
Jul 03 10:13:51 org.hibernate.SQL[DEBUG]: insert into media (filename, filesize_m, filesize_h, fileheight_l, filewidth_l, fileheight_m, filewidth_m, fileheight_h, filewidth_h, description, created_date, modified_date) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: preparing statement
Jul 03 10:13:51 org.hibernate.persister.entity.BasicEntityPersister[DEBUG]: Dehydrating entity: [com.declivis.pos.Media#<null>]
Jul 03 10:13:51 org.hibernate.id.IdentifierGeneratorFactory[DEBUG]: Natively generated identity: 1
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: closing statement
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: commit
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: automatically flushing session
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: flushing session
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: processing flush-time cascades
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: dirty checking collections
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: Flushing entities and processing referenced collections
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: rollback
Jul 03 10:13:51 org.hibernate.transaction.CacheSynchronization[DEBUG]: transaction before completion callback
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: before transaction completion
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: before transaction completion
Jul 03 10:13:51 org.hibernate.transaction.CacheSynchronization[DEBUG]: transaction after completion callback, status: 4
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: after transaction completion
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: after transaction completion
Jul 03 10:13:51 org.hibernate.cache.UpdateTimestampsCache[DEBUG]: Invalidating space [media], timestamp: 4589158528249856
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Rolled back JTA UserTransaction
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: loading entity: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: attempting to resolve: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.cache.ReadWriteCache[DEBUG]: Cache lookup: com.declivis.pos.StockKeepingUnit#1
Jul 03 10:13:51 org.hibernate.cache.EhCache[DEBUG]: key: com.declivis.pos.StockKeepingUnit#1
Jul 03 10:13:51 org.hibernate.cache.EhCache[DEBUG]: Element for com.declivis.pos.StockKeepingUnit#1 is null
Jul 03 10:13:51 org.hibernate.cache.ReadWriteCache[DEBUG]: Cache miss: com.declivis.pos.StockKeepingUnit#1
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: object not resolved in any cache: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.persister.entity.BasicEntityPersister[DEBUG]: Materializing entity: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: loading entity: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
Jul 03 10:13:51 org.hibernate.SQL[DEBUG]: select stockkeepi0_.id as id0_, stockkeepi0_.category as category19_0_, stockkeepi0_.sku as sku19_0_, stockkeepi0_.upc as upc19_0_, stockkeepi0_.origin as origin19_0_, stockkeepi0_.description as descript6_19_0_, stockkeepi0_.long_desc as long7_19_0_, stockkeepi0_.weight as weight19_0_, stockkeepi0_.lENGTH as lENGTH19_0_, stockkeepi0_.width as width19_0_, stockkeepi0_.height as height19_0_, stockkeepi0_.media_id as media12_19_0_, stockkeepi0_.cost as cost19_0_, stockkeepi0_.retail as retail19_0_, stockkeepi0_.properties as properties19_0_, stockkeepi0_.active as active19_0_, stockkeepi0_.ONHAND as ONHAND19_0_, stockkeepi0_.jit as jit19_0_ from skus stockkeepi0_ where stockkeepi0_.id=?
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: preparing statement
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: about to open ResultSet (open ResultSets: 0, globally: 0)
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: processing result set
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: result set row: 0
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: result row: EntityKey[com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: Initializing object from ResultSet: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.persister.entity.BasicEntityPersister[DEBUG]: Hydrating entity: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: done processing result set (1 rows)
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: about to close ResultSet (open ResultSets: 1, globally: 1)
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
Jul 03 10:13:51 org.hibernate.jdbc.AbstractBatcher[DEBUG]: closing statement
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: total objects hydrated: 1
Jul 03 10:13:51 org.hibernate.engine.TwoPhaseLoad[DEBUG]: resolving associations for [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: loading entity: [com.declivis.pos.SKUCategory#2]
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: creating new proxy for entity
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: loading entity: [com.declivis.pos.OriginAddress#1]
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: creating new proxy for entity
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: loading entity: [com.declivis.pos.Media#0]
Jul 03 10:13:51 org.hibernate.event.def.DefaultLoadEventListener[DEBUG]: creating new proxy for entity
Jul 03 10:13:51 org.hibernate.engine.TwoPhaseLoad[DEBUG]: adding entity to second-level cache: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.cache.ReadWriteCache[DEBUG]: Caching: com.declivis.pos.StockKeepingUnit#1
Jul 03 10:13:51 org.hibernate.cache.EhCache[DEBUG]: key: com.declivis.pos.StockKeepingUnit#1
Jul 03 10:13:51 org.hibernate.cache.EhCache[DEBUG]: Element for com.declivis.pos.StockKeepingUnit#1 is null
Jul 03 10:13:51 org.hibernate.cache.ReadWriteCache[DEBUG]: Cached: com.declivis.pos.StockKeepingUnit#1
Jul 03 10:13:51 org.hibernate.engine.TwoPhaseLoad[DEBUG]: done materializing entity [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.engine.PersistenceContext[DEBUG]: initializing non-lazy collections
Jul 03 10:13:51 org.hibernate.loader.Loader[DEBUG]: done entity load
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: after autocommit
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: after transaction completion
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: flushing session
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: processing flush-time cascades
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: dirty checking collections
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: Flushing entities and processing referenced collections
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: begin
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Looking for UserTransaction under: java:comp/UserTransaction
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Obtained UserTransaction
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Began a new JTA transaction
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: successfully registered Synchronization
Jul 03 10:13:51 org.hibernate.event.def.DefaultSaveOrUpdateEventListener[DEBUG]: ignoring persistent instance
Jul 03 10:13:51 org.hibernate.event.def.DefaultSaveOrUpdateEventListener[DEBUG]: object already associated with session: [com.declivis.pos.StockKeepingUnit#1]
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: commit
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: automatically flushing session
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: flushing session
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: processing flush-time cascades
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: dirty checking collections
Jul 03 10:13:51 org.hibernate.event.def.AbstractFlushingEventListener[DEBUG]: Flushing entities and processing referenced collections
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: rollback
Jul 03 10:13:51 org.hibernate.transaction.CacheSynchronization[DEBUG]: transaction before completion callback
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: before transaction completion
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: before transaction completion
Jul 03 10:13:51 org.hibernate.transaction.CacheSynchronization[DEBUG]: transaction after completion callback, status: 4
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: after transaction completion
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: after transaction completion
Jul 03 10:13:51 org.hibernate.transaction.JTATransaction[DEBUG]: Rolled back JTA UserTransaction
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: closing session
Jul 03 10:13:51 org.hibernate.jdbc.ConnectionManager[DEBUG]: closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
Jul 03 10:13:51 org.hibernate.jdbc.JDBCContext[DEBUG]: after transaction completion
Jul 03 10:13:51 org.hibernate.impl.SessionImpl[DEBUG]: after transaction completion
Jul 03 10:14:14 org.hibernate.jdbc.ConnectionManager[DEBUG]: running Session.finalize()