Hi,
I suspect that the
replicate() method with replication mode
IGNORE does not actually check the previously unflushed entities in the session.
It seems to just check the db, which causes duplicates inserts for the same entity.
Is there a chance that this behavior might be a bug ?
Or have I missed something about the
ReplicationMode.IGNORE semantics ?
As usual, any help will be greatly appreciated.
Thanks,
Gregory
Need help with Hibernate? Read this first:
http://www.hibernate.org/ForumMailingli ... AskForHelp
Hibernate version: 3.0.5
Mapping documents:
Code:
<hibernate-mapping
>
<class
name="com.advestigo.mig279.model.Song"
table="SONG"
mutable="false"
>
<cache usage="read-only" />
<id
name="id"
column="SONG_ID"
type="java.lang.Long"
>
<generator class="assigned">
</generator>
</id>
<property
name="title"
type="string"
update="true"
insert="true"
length="50"
not-null="true"
/>
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():Code:
protected void setUp() throws Exception
{
super.setUp();
log.debug("setUp() called..");
log.debug("source session provider setup..");
this.sourceSessionProvider = new HibernateSessionProvider("source-hibernate.cfg.xml");
log.debug("target session provider setup..");
this.targetSessionProvider = new HibernateSessionProvider("target-hibernate.cfg.xml");
log.debug("populating source database with a few songs..");
Song aSong = new Song(new Long(1), "Waiting for my Man");
Song anotherSong = new Song(new Long(2),"Perfect day");
Transaction tx = this.sourceSessionProvider.currentSession().beginTransaction();
this.sourceSessionProvider.currentSession().save(aSong);
this.sourceSessionProvider.currentSession().save(anotherSong);
this.sourceSessionProvider.currentSession().flush();
tx.commit();
this.sourceSessionProvider.closeSession();
log.debug("source database populated");
}
protected void tearDown() throws Exception
{
super.tearDown();
log.debug("tearDown() called..");
this.sourceSessionProvider.closeSession();
this.targetSessionProvider.closeSession();
}
final public void testReplication()
{
log.debug("testReplication() called..");
Session targetSession = this.targetSessionProvider.currentSession();
Session sourceSession = this.sourceSessionProvider.currentSession();
//we don't start from scratch in the target session, that's part of the point
Transaction tx = targetSession.beginTransaction();
Song manuallySavedSong = new Song(new Long(2),"Perfect day");
targetSession.save(manuallySavedSong);
//now, begin replication from source database
Query selectQuery = sourceSession.createQuery("from Song");
selectQuery.setReadOnly(true);
List songs = selectQuery.list();
for (Iterator iter = songs.iterator(); iter.hasNext();)
{
Song song = (Song) iter.next();
sourceSession.evict(song);
targetSession.replicate(song, ReplicationMode.IGNORE);
}
//the following line fails, duplicate insert for Song#2
targetSession.flush();
tx.commit();
}
Name and version of the database you are using:PostgreSQL 8.0.4
Debug level Hibernate log excerpt:Code:
2006-01-05 17:34:17,133 DEBUG <main> [ReplicationTest] - setUp() called..
2006-01-05 17:34:17,133 DEBUG <main> [ReplicationTest] - source session provider setup..
2006-01-05 17:34:18,146 INFO <main> [TransactionFactoryFactory] - Using default transaction strategy (direct JDBC transactions)
2006-01-05 17:34:18,146 INFO <main> [TransactionManagerLookupFactory] - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
2006-01-05 17:34:18,286 INFO <main> [TransactionFactoryFactory] - Using default transaction strategy (direct JDBC transactions)
2006-01-05 17:34:18,286 INFO <main> [TransactionManagerLookupFactory] - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
2006-01-05 17:34:18,707 INFO <main> [SchemaExport] - Running hbm2ddl schema export
2006-01-05 17:34:18,707 INFO <main> [SchemaExport] - exporting generated schema to database
2006-01-05 17:34:18,801 DEBUG <main> [SchemaExport] - drop table demo.SONG
2006-01-05 17:34:18,816 DEBUG <main> [SchemaExport] - create table demo.SONG (
SONG_ID int8 not null,
title varchar(50) not null,
primary key (SONG_ID)
)
2006-01-05 17:34:18,926 INFO <main> [SchemaExport] - schema export complete
2006-01-05 17:34:18,957 DEBUG <main> [ReplicationTest] - target session provider setup..
2006-01-05 17:34:19,175 INFO <main> [TransactionFactoryFactory] - Using default transaction strategy (direct JDBC transactions)
2006-01-05 17:34:19,175 INFO <main> [TransactionManagerLookupFactory] - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
2006-01-05 17:34:19,284 INFO <main> [TransactionFactoryFactory] - Using default transaction strategy (direct JDBC transactions)
2006-01-05 17:34:19,284 INFO <main> [TransactionManagerLookupFactory] - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
2006-01-05 17:34:19,331 INFO <main> [SchemaExport] - Running hbm2ddl schema export
2006-01-05 17:34:19,331 INFO <main> [SchemaExport] - exporting generated schema to database
2006-01-05 17:34:19,409 DEBUG <main> [SchemaExport] - drop table demo2.SONG
2006-01-05 17:34:19,424 DEBUG <main> [SchemaExport] - create table demo2.SONG (
SONG_ID int8 not null,
title varchar(50) not null,
primary key (SONG_ID)
)
2006-01-05 17:34:19,565 INFO <main> [SchemaExport] - schema export complete
2006-01-05 17:34:19,565 DEBUG <main> [ReplicationTest] - populating source database with a few songs..
2006-01-05 17:34:19,565 DEBUG <main> [HibernateSessionProvider] - Getting the Hibernate session for this thread...
2006-01-05 17:34:19,565 DEBUG <main> [HibernateSessionProvider] - No session associated with this thread, opening a new one...
2006-01-05 17:34:19,596 DEBUG <main> [HibernateSessionProvider] - New session opened with cache mode NORMAL
2006-01-05 17:34:19,596 DEBUG <main> [JDBCTransaction] - begin
2006-01-05 17:34:19,596 DEBUG <main> [JDBCTransaction] - current autocommit status: false
2006-01-05 17:34:19,596 DEBUG <main> [HibernateSessionProvider] - Getting the Hibernate session for this thread...
2006-01-05 17:34:19,611 DEBUG <main> [HibernateSessionProvider] - Getting the Hibernate session for this thread...
2006-01-05 17:34:19,611 DEBUG <main> [HibernateSessionProvider] - Getting the Hibernate session for this thread...
2006-01-05 17:34:19,658 DEBUG <main> [JDBCTransaction] - commit
2006-01-05 17:34:19,658 DEBUG <main> [JDBCTransaction] - committed JDBC Connection
2006-01-05 17:34:19,658 DEBUG <main> [HibernateSessionProvider] - Closing the Hibernate session for this thread...
2006-01-05 17:34:19,658 DEBUG <main> [ReplicationTest] - source database populated
2006-01-05 17:34:19,658 DEBUG <main> [ReplicationTest] - testReplication() called..
2006-01-05 17:34:19,658 DEBUG <main> [HibernateSessionProvider] - Getting the Hibernate session for this thread...
2006-01-05 17:34:19,658 DEBUG <main> [HibernateSessionProvider] - No session associated with this thread, opening a new one...
2006-01-05 17:34:19,658 DEBUG <main> [HibernateSessionProvider] - New session opened with cache mode NORMAL
2006-01-05 17:34:19,658 DEBUG <main> [HibernateSessionProvider] - Getting the Hibernate session for this thread...
2006-01-05 17:34:19,658 DEBUG <main> [HibernateSessionProvider] - No session associated with this thread, opening a new one...
2006-01-05 17:34:19,658 DEBUG <main> [HibernateSessionProvider] - New session opened with cache mode NORMAL
2006-01-05 17:34:19,658 DEBUG <main> [JDBCTransaction] - begin
2006-01-05 17:34:19,658 DEBUG <main> [JDBCTransaction] - current autocommit status: false
2006-01-05 17:34:19,907 DEBUG <main> [TwoPhaseLoad] - resolving associations for [com.advestigo.mig279.model.Song#1]
2006-01-05 17:34:19,907 DEBUG <main> [TwoPhaseLoad] - done materializing entity [com.advestigo.mig279.model.Song#1]
2006-01-05 17:34:19,907 DEBUG <main> [TwoPhaseLoad] - resolving associations for [com.advestigo.mig279.model.Song#2]
2006-01-05 17:34:19,907 DEBUG <main> [TwoPhaseLoad] - done materializing entity [com.advestigo.mig279.model.Song#2]
2006-01-05 17:34:19,907 DEBUG <main> [PersistenceContext] - initializing non-lazy collections
Hibernate: select SONG_ID from demo2.SONG where SONG_ID =?
2006-01-05 17:34:19,907 DEBUG <main> [DefaultReplicateEventListener] - no existing row, replicating new instance [com.advestigo.mig279.model.Song#1]
Hibernate: select SONG_ID from demo2.SONG where SONG_ID =?
2006-01-05 17:34:19,907 DEBUG <main> [DefaultReplicateEventListener] - no existing row, replicating new instance [com.advestigo.mig279.model.Song#2]
Hibernate: insert into demo2.SONG (title, SONG_ID) values (?, ?)
Hibernate: insert into demo2.SONG (title, SONG_ID) values (?, ?)
Hibernate: insert into demo2.SONG (title, SONG_ID) values (?, ?)
2006-01-05 17:34:19,939 WARN <main> [JDBCExceptionReporter] - SQL Error: 0, SQLState: null
2006-01-05 17:34:19,939 ERROR <main> [JDBCExceptionReporter] - L'élément du batch 2 insert into demo2.SONG (title, SONG_ID) values (Perfect day, 2) a été annulé. Appeler getNextException pour en connaître la cause.
2006-01-05 17:34:19,939 WARN <main> [JDBCExceptionReporter] - SQL Error: 0, SQLState: 23505
2006-01-05 17:34:19,939 ERROR <main> [JDBCExceptionReporter] - ERROR: duplicate key violates unique constraint "song_pkey"
2006-01-05 17:34:19,970 ERROR <main> [AbstractFlushingEventListener] - Could not synchronize database state with session
org.hibernate.exception.ConstraintViolationException: Could not execute JDBC batch update
at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:63)
at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:181)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:226)
at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:136)
at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:274)
at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:730)
at com.advestigo.mig279.ReplicationTest.testReplication(ReplicationTest.java:93)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at junit.framework.TestCase.runTest(TestCase.java:154)
at junit.framework.TestCase.runBare(TestCase.java:127)
at junit.framework.TestResult$1.protect(TestResult.java:106)
at junit.framework.TestResult.runProtected(TestResult.java:124)
at junit.framework.TestResult.run(TestResult.java:109)
at junit.framework.TestCase.run(TestCase.java:118)
at junit.framework.TestSuite.runTest(TestSuite.java:208)
at junit.framework.TestSuite.run(TestSuite.java:203)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:478)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:344)
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
Caused by: java.sql.BatchUpdateException: L'élément du batch 2 insert into demo2.SONG (title, SONG_ID) values (Perfect day, 2) a été annulé. Appeler getNextException pour en connaître la cause.
at org.postgresql.jdbc2.AbstractJdbc2Statement$BatchResultHandler.handleError(AbstractJdbc2Statement.java:2423)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1268)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:345)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeBatch(AbstractJdbc2Statement.java:2485)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:57)
at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:174)
... 21 more
2006-01-05 17:34:19,985 DEBUG <main> [ReplicationTest] - tearDown() called..
2006-01-05 17:34:19,985 DEBUG <main> [HibernateSessionProvider] - Closing the Hibernate session for this thread...
2006-01-05 17:34:19,985 DEBUG <main> [HibernateSessionProvider] - Closing the Hibernate session for this thread...