Hi I am currently using Hibernate version 2.0.3
Against an Oracle 9 database and a MS SQLServer 2000 DB.

I am having a heck of a time figuring out what the following message means.

Basically I am attempting to insert more than one record at a time into the SQLServer DB. The first record gets processed, but then I get this error, and the second record is never processed.

Here is my Mapping file for the Entity




and here is the debug log from hibernate...

[code]
log4j:WARN No appenders could be found for logger (org.springframework.beans.factory.xml.XmlBeanDefinitionReader).
log4j:WARN Please initialize the log4j system properly.
114735 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'ca.csi.cassynch.dao.CSICASDataSynchAuditDAO'
114735 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Bean with name 'ca.csi.cassynch.dao.CSICASDataSynchAuditDAO' is a factory bean
114735 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'ca.csi.cassynch.dao.CSICASDataSynchConflictDAO'
114735 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Bean with name 'ca.csi.cassynch.dao.CSICASDataSynchConflictDAO' is a factory bean
114735 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'ca.csi.cassynch.dao.CSIEntJournalDAO'
114735 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Bean with name 'ca.csi.cassynch.dao.CSIEntJournalDAO' is a factory bean
114782 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - run() - BEGIN
114782 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - startSynch() - BEGIN
114844 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
114907 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
114907 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
114907 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@16c5f50] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] to thread [main]
114922 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - loadAuditByJournalName(name=ca.csi.enterprise.model.entity.CSIStudent state=busy) - BEGIN
114922 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
114922 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@16c5f50] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] bound to thread [main]
114922 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
114922 [main] DEBUG net.sf.hibernate.impl.SessionImpl - find: from CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
114969 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - compiling query
115016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
115016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Dont need to execute flush
115016 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - HQL: from ca.csi.cassynch.entity.CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
115016 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - SQL: select csicasda0_.CAS_DATA_SYNCH_AUDIT_ID as CAS_DATA_SYNCH_AUDIT_ID, csicasda0_.version_stamp as version_2_, csicasda0_.journal_name as journal_3_, csicasda0_.state as state, csicasda0_.time_completed as time_com5_, csicasda0_.start_journal_record_timestamp as start_jo6_, csicasda0_.end_journal_record_timestamp as end_jour7_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
115032 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115032 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select csicasda0_.CAS_DATA_SYNCH_AUDIT_ID as CAS_DATA_SYNCH_AUDIT_ID, csicasda0_.version_stamp as version_2_, csicasda0_.journal_name as journal_3_, csicasda0_.state as state, csicasda0_.time_completed as time_com5_, csicasda0_.start_journal_record_timestamp as start_jo6_, csicasda0_.end_journal_record_timestamp as end_jour7_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
115032 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115047 [main] DEBUG net.sf.hibernate.type.StringType - binding 'busy' to parameter: 2
115047 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 1
115063 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
115063 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (0 rows)
115063 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115078 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115078 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 0
115078 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - loadAuditByJournalName() - END
115078 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
115078 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@16c5f50] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] from thread [main]
115078 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
115078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
115094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
115094 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
115094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
115094 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
115094 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@bfa709] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] to thread [main]
115094 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - getLatestRecordTimeStamp(getLatestRecordTimeStamp() - name=ca.csi.enterprise.model.entity.CSIStudent) - BEGIN
115094 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
115094 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@bfa709] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] bound to thread [main]
115094 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
115094 [main] DEBUG net.sf.hibernate.impl.SessionImpl - find: select max(audit.endRecordTimestamp) from CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
115094 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - compiling query
115125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
115125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Dont need to execute flush
115125 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - HQL: select max(audit.endRecordTimestamp) from ca.csi.cassynch.entity.CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
115125 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - SQL: select max(csicasda0_.end_journal_record_timestamp) as x0_0_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
115125 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115141 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select max(csicasda0_.end_journal_record_timestamp) as x0_0_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
115141 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115141 [main] DEBUG net.sf.hibernate.type.StringType - binding 'done' to parameter: 2
115141 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 1
115141 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
115157 [main] DEBUG net.sf.hibernate.loader.Loader - result row:
115157 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '22 March 2004 02:11:00' as column: x0_0_
115157 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (1 rows)
115157 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115157 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115157 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - getLatestRecordTimeStamp() - END
115157 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
115157 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115157 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115157 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115157 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115157 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
115157 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115172 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
115172 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
115172 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@bfa709] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] from thread [main]
115172 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
115188 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
115188 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
115188 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
115188 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
115188 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
115188 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
115188 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@12a585c] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] to thread [main]
115188 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - newAudit(newAudit() - name=ca.csi.enterprise.model.entity.CSIStudent) - BEGIN
115188 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
115188 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@12a585c] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] bound to thread [main]
115188 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
115188 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115203 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select data_synch_audit_id_seq.nextval from dual
115203 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115235 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
115235 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
115266 [main] DEBUG net.sf.hibernate.id.SequenceGenerator - Sequence identifier generated: 4881
115266 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115266 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [ca.csi.cassynch.entity.CSICASDataSynchAudit#4881]
115266 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-03-22 16:19:42.609
115282 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - newAudit() - END
115282 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
115282 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115282 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115297 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115297 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115297 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
115297 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115297 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
115297 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Inserting entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#4881
115297 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Version: 2004-03-22 16:19:42.609
115297 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115297 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: insert into enterprise.cas_data_synch_audit (version_stamp, journal_name, state, time_completed, start_journal_record_timestamp, end_journal_record_timestamp, CAS_DATA_SYNCH_AUDIT_ID) values (?, ?, ?, ?, ?, ?, ?)
115297 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115297 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Dehydrating entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#4881
115297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '22 March 2004 04:19:42' to parameter: 1
115297 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 2
115297 [main] DEBUG net.sf.hibernate.type.StringType - binding 'busy' to parameter: 3
115297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 4
115297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 5
115297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 6
115297 [main] DEBUG net.sf.hibernate.type.LongType - binding '4881' to parameter: 7
115313 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - Adding to batch
115313 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - Executing batch size: 1
115328 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115328 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
115344 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@12a585c] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] from thread [main]
115344 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
115344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
115344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
115344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
115344 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
115344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
115344 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
115344 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@14cee08] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] to thread [main]
115344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - updateAudit(audit=ca.csi.cassynch.entity.CSICASDataSynchAudit@831e35) - BEGIN
115344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
115344 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@14cee08] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] bound to thread [main]
115344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
115344 [main] DEBUG net.sf.hibernate.engine.Cascades - unsaved-value strategy NULL
115344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() previously saved instance with id: 4881
115344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - updating [ca.csi.cassynch.entity.CSICASDataSynchAudit#4881]
115344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - updateAudit() - END
115344 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Updating entity: [ca.csi.cassynch.entity.CSICASDataSynchAudit#4881]
115360 [main] DEBUG net.sf.hibernate.engine.Versioning - Incrementing: 2004-03-22 16:19:42.609 to 2004-03-22 16:19:42.703
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115360 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
115360 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Updating entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#4881
115360 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Existing version: 2004-03-22 16:19:42.609 -> New version: 2004-03-22 16:19:42.703
115360 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115375 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: update enterprise.cas_data_synch_audit set version_stamp=?, journal_name=?, state=?, time_completed=?, start_journal_record_timestamp=?, end_journal_record_timestamp=? where CAS_DATA_SYNCH_AUDIT_ID=? and version_stamp=?
115375 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115375 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Dehydrating entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#4881
115375 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '22 March 2004 04:19:42' to parameter: 1
115375 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 2
115375 [main] DEBUG net.sf.hibernate.type.StringType - binding 'busy' to parameter: 3
115375 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 4
115375 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '22 March 2004 02:11:00' to parameter: 5
115375 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '22 March 2004 04:19:42' to parameter: 6
115375 [main] DEBUG net.sf.hibernate.type.LongType - binding '4881' to parameter: 7
115375 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '22 March 2004 04:19:42' to parameter: 8
115407 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115407 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115422 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
115422 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@14cee08] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] from thread [main]
115422 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
115422 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
115422 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
115422 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
115422 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - setStartRecordTimestamp() - 2004-03-22 14:11:00.867
115422 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - setEndRecordTimestamp() - 2004-03-22 16:19:42.687
115422 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - startSynch() - END
115422 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - startSynch() - END
115422 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
115422 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
115422 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
115422 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@5cd7f9] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] to thread [main]
115422 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal(loadJournal()) - BEGIN
115422 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() Class = ca.csi.enterprise.model.entity.CSIStudent
115422 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() From = 2004-03-22 14:11:00.867
115438 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() To = 2004-03-22 16:19:42.687
115438 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@5cd7f9] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] bound to thread [main]
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - find: from CSIEntityLog as audit where audit.entityName=? and audit.versionStamp>? and audit.versionStamp<?
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - parameters: ca.csi.enterprise.model.entity.CSIStudent, 2004-03-22 14:11:00.867, 2004-03-22 16:19:42.687
115438 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - compiling query
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115438 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Dont need to execute flush
115438 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - HQL: from ca.csi.cassynch.entity.CSIEntityLog as audit where audit.entityName=? and audit.versionStamp>? and audit.versionStamp<?
115438 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - SQL: select csientit0_.ENTITY_LOG_ID as ENTITY_LOG_ID, csientit0_.version_stamp as version_2_, csientit0_.entity_name as entity_n4_, csientit0_.entity_id as entity_id, csientit0_.action as action from enterprise.entity_log csientit0_ where (csientit0_.entity_name=? )and(csientit0_.version_stamp>? )and(csientit0_.version_stamp<? )
115438 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115453 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select csientit0_.ENTITY_LOG_ID as ENTITY_LOG_ID, csientit0_.version_stamp as version_2_, csientit0_.entity_name as entity_n4_, csientit0_.entity_id as entity_id, csientit0_.action as action from enterprise.entity_log csientit0_ where (csientit0_.entity_name=? )and(csientit0_.version_stamp>? )and(csientit0_.version_stamp<? )
115469 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115469 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 1
115469 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '22 March 2004 02:11:00' to parameter: 2
115469 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '22 March 2004 04:19:42' to parameter: 3
115469 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
115485 [main] DEBUG net.sf.hibernate.type.LongType - returning '6962' as column: ENTITY_LOG_ID
115485 [main] DEBUG net.sf.hibernate.loader.Loader - result row: 6962
115485 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 6962
115485 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.cassynch.entity.CSIEntityLog#6962
115485 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '22 March 2004 04:01:54' as column: version_2_
115485 [main] DEBUG net.sf.hibernate.type.StringType - returning 'ca.csi.enterprise.model.entity.CSIStudent' as column: entity_n4_
115485 [main] DEBUG net.sf.hibernate.type.LongType - returning '8464' as column: entity_id
115485 [main] DEBUG net.sf.hibernate.type.StringType - returning 'I' as column: action
115485 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-22 16:01:54.791
115485 [main] DEBUG net.sf.hibernate.type.LongType - returning '6963' as column: ENTITY_LOG_ID
115485 [main] DEBUG net.sf.hibernate.loader.Loader - result row: 6963
115485 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 6963
115485 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.cassynch.entity.CSIEntityLog#6963
115485 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '22 March 2004 04:05:39' as column: version_2_
115500 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
115500 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
115500 [main] DEBUG net.sf.hibernate.type.StringType - returning 'ca.csi.enterprise.model.entity.CSIStudent' as column: entity_n4_
115500 [main] DEBUG net.sf.hibernate.type.LongType - returning '8465' as column: entity_id
115500 [main] DEBUG net.sf.hibernate.type.StringType - returning 'I' as column: action
115500 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-22 16:05:39.043
115500 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (2 rows)
115500 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115500 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115500 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 2
115500 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.cassynch.entity.CSIEntityLog#6962]
115500 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.cassynch.entity.CSIEntityLog#6962]
115500 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.cassynch.entity.CSIEntityLog#6963]
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.cassynch.entity.CSIEntityLog#6963]
115516 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() - Query returned 2 results
115516 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() - END
115516 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
115516 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@5cd7f9] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] from thread [main]
115516 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
115516 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
115516 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - run() - Records to process=2
115516 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - synch(Journals=2) - BEGIN
115532 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - insert() - BEGIN
115532 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
115532 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
115532 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
115532 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@eeb406] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] to thread [main]
115532 [main] DEBUG ca.csi.enterprise.model.dao.hibernate.CSIHibernateBaseDAO - loadByObjectID() Class = ca.csi.enterprise.model.entity.CSIStudent
115532 [main] DEBUG ca.csi.enterprise.model.dao.hibernate.CSIHibernateBaseDAO - loadByObjectID() ID= 8464
115532 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@eeb406] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] bound to thread [main]
115532 [main] DEBUG net.sf.hibernate.impl.SessionImpl - loading [ca.csi.enterprise.model.entity.CSIStudent#8464]
115532 [main] DEBUG net.sf.hibernate.impl.SessionImpl - attempting to resolve [ca.csi.enterprise.model.entity.CSIStudent#8464]
115532 [main] DEBUG net.sf.hibernate.impl.SessionImpl - object not resolved in any cache [ca.csi.enterprise.model.entity.CSIStudent#8464]
115532 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Materializing entity: ca.csi.enterprise.model.entity.CSIStudent#8464
115532 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115547 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select csiaddre1_.ADDRESS_ID as ADDRESS_ID0_, csiaddre1_.version_stamp as version_2_0_, csiaddre1_.line1 as line10_, csiaddre1_.line2 as line20_, csiaddre1_.line3 as line30_, csiaddre1_.city as city0_, csiaddre1_.province_state as province7_0_, csiaddre1_.post_code as post_code0_, csiaddre1_.iso_country_code as iso_coun9_0_, csiaddre1_.create_datetime as create_10_0_, csiaddre1_.create_ip_address as create_11_0_, csiaddre1_.last_update_ip_address as last_up12_0_, csiaddre2_.ADDRESS_ID as ADDRESS_ID1_, csiaddre2_.version_stamp as version_2_1_, csiaddre2_.line1 as line11_, csiaddre2_.line2 as line21_, csiaddre2_.line3 as line31_, csiaddre2_.city as city1_, csiaddre2_.province_state as province7_1_, csiaddre2_.post_code as post_code1_, csiaddre2_.iso_country_code as iso_coun9_1_, csiaddre2_.create_datetime as create_10_1_, csiaddre2_.create_ip_address as create_11_1_, csiaddre2_.last_update_ip_address as last_up12_1_, csiorgan3_.organization_id as organization_id2_, csiorgan3_.version_stamp as version_2_2_, csiorgan3_.create_datetime as create_d3_2_, csiorgan3_.create_ip_address as create_i4_2_, csiorgan3_.last_update_ip_address as last_upd5_2_, csiorgan3_.type as type2_, csiorgan3_.english_name as english_7_2_, csiorgan3_.french_name as french_n8_2_, csiorgan3_.parent_ID as parent_ID2_, csiorgan3_.confirmed as confirmed2_, csiorgan3_.ida_flag as ida_flag2_, csiorgan3_.corp_price_flag as corp_pr12_2_, csiorgan3_.csi_firm_id as csi_fir13_2_, csiorgan4_.organization_id as organization_id3_, csiorgan4_.version_stamp as version_2_3_, csiorgan4_.create_datetime as create_d3_3_, csiorgan4_.create_ip_address as create_i4_3_, csiorgan4_.last_update_ip_address as last_upd5_3_, csiorgan4_.type as type3_, csiorgan4_.english_name as english_7_3_, csiorgan4_.french_name as french_n8_3_, csiorgan4_.parent_ID as parent_ID3_, csiorgan4_.confirmed as confirmed3_, csiorgan4_.ida_flag as ida_flag3_, csiorgan4_.corp_price_flag as corp_pr12_3_, csiorgan4_.csi_firm_id as csi_fir13_3_, csiorgan5_.organization_id as organization_id4_, csiorgan5_.version_stamp as version_2_4_, csiorgan5_.create_datetime as create_d3_4_, csiorgan5_.create_ip_address as create_i4_4_, csiorgan5_.last_update_ip_address as last_upd5_4_, csiorgan5_.type as type4_, csiorgan5_.english_name as english_7_4_, csiorgan5_.french_name as french_n8_4_, csiorgan5_.parent_ID as parent_ID4_, csiorgan5_.confirmed as confirmed4_, csiorgan5_.ida_flag as ida_flag4_, csiorgan5_.corp_price_flag as corp_pr12_4_, csiorgan5_.csi_firm_id as csi_fir13_4_, csisurve6_.survey_id as survey_id5_, csisurve6_.version_stamp as version_2_5_, csisurve6_.create_datetime as create_d3_5_, csisurve6_.create_ip_address as create_i4_5_, csisurve6_.last_update_ip_address as last_upd5_5_, csisurve6_.field1 as field15_, csisurve6_.field2 as field25_, csisurve6_.field3 as field35_, csisurve6_.field4 as field45_, csisurve6_.field5 as field55_, csisurve6_.field6 as field65_, csistude0_.student_id as student_id6_, csistude0_.version_stamp as version_2_6_, csistude0_.csi_student_id as csi_stud3_6_, csistude0_.company_name as company_4_6_, csistude0_.job_title as job_title6_, csistude0_.first_name as first_name6_, csistude0_.initial_name as initial_7_6_, csistude0_.last_name as last_name6_, csistude0_.password as password6_, csistude0_.title as title6_, csistude0_.home_address_id as home_ad11_6_, csistude0_.business_address_id as busines12_6_, csistude0_.gender as gender6_, csistude0_.sin as sin6_, csistude0_.month_of_birth as month_o15_6_, csistude0_.year_of_birth as year_of16_6_, csistude0_.pref_mailing_addr_type_id as pref_ma17_6_, csistude0_.email_address as email_a18_6_, csistude0_.alternate_email_address as alterna19_6_, csistude0_.correspondence_method_code as corresp20_6_, csistude0_.mailing_list_ind as mailing21_6_, csistude0_.language_id as languag22_6_, csistude0_.password_question as passwor23_6_, csistude0_.password_question_answer as passwor24_6_, csistude0_.accept_privacy_option_ind as accept_25_6_, csistude0_.privacy_optn_update_datetime as privacy26_6_, csistude0_.employer_id as employe27_6_, csistude0_.school_id as school_id6_, csistude0_.association_id as associa29_6_, csistude0_.ethical_violation_ind as ethical30_6_, csistude0_.amount_owing as amount_31_6_, csistude0_.home_phone as home_phone6_, csistude0_.business_phone as busines33_6_, csistude0_.student_status_code as student34_6_, csistude0_.infocus_member_date as infocus35_6_, csistude0_.infocus_discount_applied as infocus36_6_, csistude0_.survey_id as survey_id6_, csistude0_.create_datetime as create_38_6_, csistude0_.create_ip_address as create_39_6_, csistude0_.last_update_ip_address as last_up40_6_ from enterprise.student csistude0_, enterprise.address csiaddre1_, enterprise.address csiaddre2_, enterprise.ORGANIZATION csiorgan3_, enterprise.ORGANIZATION csiorgan4_, enterprise.ORGANIZATION csiorgan5_, enterprise.survey csisurve6_ where csistude0_.student_id=? and csistude0_.home_address_id=csiaddre1_.ADDRESS_ID(+) and csistude0_.business_address_id=csiaddre2_.ADDRESS_ID(+) and csistude0_.employer_id=csiorgan3_.organization_id(+) and csistude0_.school_id=csiorgan4_.organization_id(+) and csistude0_.association_id=csiorgan5_.organization_id(+) and csistude0_.survey_id=csisurve6_.survey_id(+)
115547 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115547 [main] DEBUG net.sf.hibernate.type.LongType - binding '8464' to parameter: 1
115594 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
115594 [main] DEBUG net.sf.hibernate.type.LongType - returning '14691' as column: ADDRESS_ID0_
115594 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: ADDRESS_ID1_
115594 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: organization_id2_
115594 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: organization_id3_
115594 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: organization_id4_
115594 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: survey_id5_
115594 [main] DEBUG net.sf.hibernate.loader.Loader - result row: 14691, null, null, null, null, null, 8464
115594 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 14691
115594 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.enterprise.model.entity.CSIAddress#14691
115594 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '22 March 2004 04:01:54' as column: version_2_0_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning '123 Some Road' as column: line10_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: line20_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: line30_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning 'Mississauga' as column: city0_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning 'ON' as column: province7_0_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning 'L7Y 6R4' as column: post_code0_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning 'CA' as column: iso_coun9_0_
115610 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '31 December 1969 07:00:00' as column: create_10_0_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: create_11_0_
115610 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: last_up12_0_
115625 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-22 16:01:54.795
115625 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 8464
115625 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.enterprise.model.entity.CSIStudent#8464
115625 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '22 March 2004 04:01:54' as column: version_2_6_
115625 [main] DEBUG net.sf.hibernate.type.LongType - returning '605994' as column: csi_stud3_6_
115625 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: company_4_6_
115625 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: job_title6_
115625 [main] DEBUG net.sf.hibernate.type.StringType - returning 'Sean' as column: first_name6_
115625 [main] DEBUG net.sf.hibernate.type.StringType - returning 'J' as column: initial_7_6_
115625 [main] DEBUG net.sf.hibernate.type.StringType - returning 'Tiley_Mar228' as column: last_name6_
115625 [main] DEBUG net.sf.hibernate.type.StringType - returning '1234' as column: password6_
115641 [main] DEBUG net.sf.hibernate.type.StringType - returning 'Mr' as column: title6_
115641 [main] DEBUG net.sf.hibernate.type.LongType - returning '14691' as column: home_ad11_6_
115641 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: busines12_6_
115641 [main] DEBUG net.sf.hibernate.type.StringType - returning 'M' as column: gender6_
115641 [main] DEBUG net.sf.hibernate.type.StringType - returning '565 ' as column: sin6_
115641 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '0' as column: month_o15_6_
115641 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '0' as column: year_of16_6_
115641 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '1' as column: pref_ma17_6_
115641 [main] DEBUG net.sf.hibernate.type.StringType - returning 'stiley@csi.ca' as column: email_a18_6_
115641 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: alterna19_6_
115641 [main] DEBUG net.sf.hibernate.type.StringType - returning 'EM' as column: corresp20_6_
115641 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '2' as column: mailing21_6_
115641 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '1' as column: languag22_6_
115657 [main] DEBUG net.sf.hibernate.type.StringType - returning 'What is your favourite movie?' as column: passwor23_6_
115657 [main] DEBUG net.sf.hibernate.type.StringType - returning 'se' as column: passwor24_6_
115657 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '1' as column: accept_25_6_
115657 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '22 March 2004 04:01:53' as column: privacy26_6_
115657 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: employe27_6_
115657 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: school_id6_
115657 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: associa29_6_
115657 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '0' as column: ethical30_6_
115657 [main] DEBUG net.sf.hibernate.type.FloatType - returning '0.0' as column: amount_31_6_
115657 [main] DEBUG net.sf.hibernate.type.StringType - returning '7666673453' as column: home_phone6_
115657 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ext. ' as column: busines33_6_
115657 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: student34_6_
115657 [main] DEBUG net.sf.hibernate.type.TimestampType - returning null as column: infocus35_6_
115657 [main] DEBUG net.sf.hibernate.type.BooleanType - returning null as column: infocus36_6_
115657 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: survey_id6_
115657 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '31 December 1969 07:00:00' as column: create_38_6_
115657 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: create_39_6_
115657 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: last_up40_6_
115657 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-22 16:01:54.796
115672 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (1 rows)
115672 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115672 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115672 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 2
115672 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.enterprise.model.entity.CSIAddress#14691]
115672 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.enterprise.model.entity.CSIAddress#14691]
115672 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.enterprise.model.entity.CSIStudent#8464]
115672 [main] DEBUG net.sf.hibernate.impl.SessionImpl - loading [ca.csi.enterprise.model.entity.CSIAddress#14691]
115672 [main] DEBUG net.sf.hibernate.impl.SessionImpl - attempting to resolve [ca.csi.enterprise.model.entity.CSIAddress#14691]
115672 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolved object in session cache [ca.csi.enterprise.model.entity.CSIAddress#14691]
115688 [main] DEBUG net.sf.hibernate.impl.SessionImpl - initializing collection [ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments#8464]
115688 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115688 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select student_0_.student_course_enrollemnt_id as student_1___, student_0_.student_course_enrollemnt_id as student_course_enrollemnt_id, student_0_.version_stamp as version_2_, student_0_.course_id as course_id, student_0_.student_id as student_id, student_0_.enrollment_date as enrollme5_, student_0_.completion_date as completi6_, student_0_.withdrawn_date as withdraw7_, student_0_.terminated_date as terminat8_, student_0_.expiry_date as expiry_d9_, student_0_.substitute_date as substit10_, student_0_.CAS_ENROLMENT_NUMBER as CAS_ENR11_, student_0_.pass_mark as pass_mark, student_0_.overall_mark as overall13_, student_0_.create_datetime as create_14_, student_0_.create_ip_address as create_15_, student_0_.last_update_ip_address as last_up16_ from enterprise.student_course_enrolment student_0_ where student_0_.student_id=?
115688 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115703 [main] DEBUG net.sf.hibernate.type.LongType - binding '8464' to parameter: 1
115719 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
115719 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (0 rows)
115719 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115719 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115719 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 0
115719 [main] DEBUG net.sf.hibernate.impl.SessionImpl - initializing collection [ca.csi.enterprise.model.entity.CSIStudent.ircfs#8464]
115735 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
115735 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select student_0_.student_ircf_id as student_1___, csiircf1_.ircf_id as ircf_id0_, csiircf1_.version_stamp as version_2_0_, csiircf1_.create_datetime as create_d3_0_, csiircf1_.create_ip_address as create_i4_0_, csiircf1_.last_update_ip_address as last_upd5_0_, csiircf1_.organization as organiza6_0_, csiircf1_.version as version0_, csiorgan2_.organization_id as organization_id1_, csiorgan2_.version_stamp as version_2_1_, csiorgan2_.create_datetime as create_d3_1_, csiorgan2_.create_ip_address as create_i4_1_, csiorgan2_.last_update_ip_address as last_upd5_1_, csiorgan2_.type as type1_, csiorgan2_.english_name as english_7_1_, csiorgan2_.french_name as french_n8_1_, csiorgan2_.parent_ID as parent_ID1_, csiorgan2_.confirmed as confirmed1_, csiorgan2_.ida_flag as ida_flag1_, csiorgan2_.corp_price_flag as corp_pr12_1_, csiorgan2_.csi_firm_id as csi_fir13_1_, student_0_.student_ircf_id as student_ircf_id2_, student_0_.version_stamp as version_2_2_, student_0_.create_datetime as create_d3_2_, student_0_.create_ip_address as create_i4_2_, student_0_.last_update_ip_address as last_upd5_2_, student_0_.student_id as student_id2_, student_0_.ircf_id as ircf_id2_, student_0_.accepted as accepted2_, student_0_.field_1 as field_12_, student_0_.field_2 as field_22_, student_0_.field_3 as field_32_, student_0_.field_4 as field_42_, student_0_.field_5 as field_52_ from enterprise.student_ircf student_0_, enterprise.ircf csiircf1_, enterprise.ORGANIZATION csiorgan2_ where student_0_.student_id=? and student_0_.ircf_id=csiircf1_.ircf_id(+) and csiircf1_.organization=csiorgan2_.organization_id(+)
115735 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
115735 [main] DEBUG net.sf.hibernate.type.LongType - binding '8464' to parameter: 1
115750 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
115750 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (0 rows)
115750 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
115750 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
115750 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 0
115766 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.enterprise.model.entity.CSIStudent#8464]
115766 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
115766 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115766 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: ca.csi.enterprise.model.entity.CSIStudent
115766 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
115766 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
115766 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments
115766 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: ca.csi.enterprise.model.entity.CSIStudent.ircfs
115766 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: ca.csi.enterprise.model.entity.CSIStudent
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Collection found: [ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments#8464], was: [ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments#8464]
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Collection found: [ca.csi.enterprise.model.entity.CSIStudent.ircfs#8464], was: [ca.csi.enterprise.model.entity.CSIStudent.ircfs#8464]
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
115797 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@eeb406] for key [net.sf.hibernate.impl.SessionFactoryImpl@6f0962] from thread [main]
115797 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
115797 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
115797 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Converting Enterprise Phone Number = 7666673453
115797 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Converted Phone = 766-667-3453
115797 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Converted Phone =
115813 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Truncating Password Question
115813 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
115813 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
115813 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
115813 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@1404c51] for key [net.sf.hibernate.impl.SessionFactoryImpl@11563a2] to thread [main]
115813 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@1404c51] for key [net.sf.hibernate.impl.SessionFactoryImpl@11563a2] bound to thread [main]
115813 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [ca.csi.cassynch.entity.CSICASStudent#605994]
115813 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
115813 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
115813 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
115813 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
115813 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
115813 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
1

Hi Gavin,
thanks for the response.
I am in fact calling save or update as required.

In my case, the first record does get persisted, but then I get the error.

I have included a newer log here for more detail.

[code]

log4j:WARN No appenders could be found for logger (org.springframework.beans.factory.xml.XmlBeanDefinitionReader).
log4j:WARN Please initialize the log4j system properly.
45750 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'ca.csi.cassynch.dao.CSICASDataSynchAuditDAO'
45766 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Bean with name 'ca.csi.cassynch.dao.CSICASDataSynchAuditDAO' is a factory bean
45766 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'ca.csi.cassynch.dao.CSICASDataSynchConflictDAO'
45766 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Bean with name 'ca.csi.cassynch.dao.CSICASDataSynchConflictDAO' is a factory bean
45766 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Returning cached instance of singleton bean 'ca.csi.cassynch.dao.CSIEntJournalDAO'
45766 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Bean with name 'ca.csi.cassynch.dao.CSIEntJournalDAO' is a factory bean
45781 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - run() - BEGIN
45781 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - startSynch() - BEGIN
45828 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
45891 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
45891 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
45891 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@1a6b028] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] to thread [main]
45891 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - loadAuditByJournalName(name=ca.csi.enterprise.model.entity.CSIStudent state=busy) - BEGIN
45891 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
45891 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@1a6b028] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] bound to thread [main]
45891 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
45906 [main] DEBUG net.sf.hibernate.impl.SessionImpl - find: from CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
45938 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - compiling query
46000 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46000 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46000 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46000 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46000 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
46000 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46000 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Dont need to execute flush
46000 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - HQL: from ca.csi.cassynch.entity.CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
46000 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - SQL: select csicasda0_.CAS_DATA_SYNCH_AUDIT_ID as CAS_DATA_SYNCH_AUDIT_ID, csicasda0_.version_stamp as version_2_, csicasda0_.journal_name as journal_3_, csicasda0_.state as state, csicasda0_.time_completed as time_com5_, csicasda0_.start_journal_record_timestamp as start_jo6_, csicasda0_.end_journal_record_timestamp as end_jour7_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
46000 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
46000 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select csicasda0_.CAS_DATA_SYNCH_AUDIT_ID as CAS_DATA_SYNCH_AUDIT_ID, csicasda0_.version_stamp as version_2_, csicasda0_.journal_name as journal_3_, csicasda0_.state as state, csicasda0_.time_completed as time_com5_, csicasda0_.start_journal_record_timestamp as start_jo6_, csicasda0_.end_journal_record_timestamp as end_jour7_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
46000 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
46016 [main] DEBUG net.sf.hibernate.type.StringType - binding 'busy' to parameter: 2
46016 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 1
46031 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
46047 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (0 rows)
46047 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
46047 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
46047 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 0
46047 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - loadAuditByJournalName() - END
46047 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
46047 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@1a6b028] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] from thread [main]
46047 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
46047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
46063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
46063 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
46063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
46063 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
46063 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@1c2fff0] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] to thread [main]
46063 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - getLatestRecordTimeStamp(getLatestRecordTimeStamp() - name=ca.csi.enterprise.model.entity.CSIStudent) - BEGIN
46063 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
46063 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@1c2fff0] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] bound to thread [main]
46063 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
46063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - find: select max(audit.endRecordTimestamp) from CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
46063 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - compiling query
46078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
46078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46078 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Dont need to execute flush
46078 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - HQL: select max(audit.endRecordTimestamp) from ca.csi.cassynch.entity.CSICASDataSynchAudit as audit where audit.name = :NAME and audit.state = :STATE
46078 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - SQL: select max(csicasda0_.end_journal_record_timestamp) as x0_0_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
46078 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
46094 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select max(csicasda0_.end_journal_record_timestamp) as x0_0_ from enterprise.cas_data_synch_audit csicasda0_ where (csicasda0_.journal_name=? )and(csicasda0_.state=? )
46094 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
46094 [main] DEBUG net.sf.hibernate.type.StringType - binding 'done' to parameter: 2
46094 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 1
46109 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
46109 [main] DEBUG net.sf.hibernate.loader.Loader - result row:
46109 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
46109 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '23 March 2004 11:39:24' as column: x0_0_
46109 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (1 rows)
46109 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
46125 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
46125 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - getLatestRecordTimeStamp() - END
46125 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
46125 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@1c2fff0] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] from thread [main]
46125 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
46125 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
46125 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
46125 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
46125 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@346762] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] to thread [main]
46125 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - newAudit(newAudit() - name=ca.csi.enterprise.model.entity.CSIStudent) - BEGIN
46125 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
46125 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@346762] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] bound to thread [main]
46125 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
46141 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
46141 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select data_synch_audit_id_seq.nextval from dual
46141 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
46188 [main] DEBUG net.sf.hibernate.id.SequenceGenerator - Sequence identifier generated: 5712
46188 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
46188 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
46188 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [ca.csi.cassynch.entity.CSICASDataSynchAudit#5712]
46203 [main] DEBUG net.sf.hibernate.engine.Versioning - Seeding: 2004-03-23 12:56:38.265
46203 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - newAudit() - END
46203 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
46203 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46219 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46219 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46219 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46219 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
46219 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46219 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
46219 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Inserting entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#5712
46219 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Version: 2004-03-23 12:56:38.265
46219 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
46219 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: insert into enterprise.cas_data_synch_audit (version_stamp, journal_name, state, time_completed, start_journal_record_timestamp, end_journal_record_timestamp, CAS_DATA_SYNCH_AUDIT_ID) values (?, ?, ?, ?, ?, ?, ?)
46219 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
46219 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Dehydrating entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#5712
46219 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '23 March 2004 12:56:38' to parameter: 1
46219 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 2
46234 [main] DEBUG net.sf.hibernate.type.StringType - binding 'busy' to parameter: 3
46234 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 4
46234 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 5
46234 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 6
46234 [main] DEBUG net.sf.hibernate.type.LongType - binding '5712' to parameter: 7
46234 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - Adding to batch
46234 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - Executing batch size: 1
46266 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
46266 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
46266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
46266 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@346762] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] from thread [main]
46266 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
46266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
46266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
46266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
46266 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
46266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
46266 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
46266 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@dfbabd] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] to thread [main]
46266 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - updateAudit(audit=ca.csi.cassynch.entity.CSICASDataSynchAudit@1ac4f3e) - BEGIN
46266 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession(getHibernateSession()) - BEGIN
46266 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@dfbabd] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] bound to thread [main]
46266 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASJournalHibernateDAO - getHibernateSession() - END
46266 [main] DEBUG net.sf.hibernate.engine.Cascades - unsaved-value strategy NULL
46266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() previously saved instance with id: 5712
46266 [main] DEBUG net.sf.hibernate.impl.SessionImpl - updating [ca.csi.cassynch.entity.CSICASDataSynchAudit#5712]
46266 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASDataSynchAuditHibernateDAO - updateAudit() - END
46281 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Updating entity: [ca.csi.cassynch.entity.CSICASDataSynchAudit#5712]
46281 [main] DEBUG net.sf.hibernate.engine.Versioning - Incrementing: 2004-03-23 12:56:38.265 to 2004-03-23 12:56:38.343
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46281 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
46281 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Updating entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#5712
46281 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Existing version: 2004-03-23 12:56:38.265 -> New version: 2004-03-23 12:56:38.343
46281 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
46297 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: update enterprise.cas_data_synch_audit set version_stamp=?, journal_name=?, state=?, time_completed=?, start_journal_record_timestamp=?, end_journal_record_timestamp=? where CAS_DATA_SYNCH_AUDIT_ID=? and version_stamp=?
46297 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
46297 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Dehydrating entity: ca.csi.cassynch.entity.CSICASDataSynchAudit#5712
46297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '23 March 2004 12:56:38' to parameter: 1
46297 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 2
46297 [main] DEBUG net.sf.hibernate.type.StringType - binding 'busy' to parameter: 3
46297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding null to parameter: 4
46297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '23 March 2004 11:39:24' to parameter: 5
46297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '23 March 2004 12:56:38' to parameter: 6
46297 [main] DEBUG net.sf.hibernate.type.LongType - binding '5712' to parameter: 7
46297 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '23 March 2004 12:56:38' to parameter: 8
46328 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
46328 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
46328 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
46328 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@dfbabd] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] from thread [main]
46328 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
46328 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
46328 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
46328 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
46328 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - setStartRecordTimestamp() - 2004-03-23 11:39:24.815
46328 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - setEndRecordTimestamp() - 2004-03-23 12:56:38.328
46328 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - startSynch() - END
46328 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - startSynch() - END
46328 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
46328 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
46328 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
46344 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@551ee3] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] to thread [main]
46344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal(loadJournal()) - BEGIN
46344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() Class = ca.csi.enterprise.model.entity.CSIStudent
46344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() From = 2004-03-23 11:39:24.815
46344 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() To = 2004-03-23 12:56:38.328
46344 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@551ee3] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] bound to thread [main]
46344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - find: from CSIEntityLog as audit where audit.entityName=? and audit.versionStamp>? and audit.versionStamp<?
46344 [main] DEBUG net.sf.hibernate.impl.SessionImpl - parameters: ca.csi.enterprise.model.entity.CSIStudent, 2004-03-23 11:39:24.815, 2004-03-23 12:56:38.328
46344 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - compiling query
46344 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
46344 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
46344 [Finalizer] DEBUG net.sf.hibernate.impl.SessionImpl - running Session.finalize()
46359 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46359 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46359 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46359 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46359 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
46359 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46359 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Dont need to execute flush
46359 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - HQL: from ca.csi.cassynch.entity.CSIEntityLog as audit where audit.entityName=? and audit.versionStamp>? and audit.versionStamp<?
46359 [main] DEBUG net.sf.hibernate.hql.QueryTranslator - SQL: select csientit0_.ENTITY_LOG_ID as ENTITY_LOG_ID, csientit0_.version_stamp as version_2_, csientit0_.entity_name as entity_n4_, csientit0_.entity_id as entity_id, csientit0_.action as action from enterprise.entity_log csientit0_ where (csientit0_.entity_name=? )and(csientit0_.version_stamp>? )and(csientit0_.version_stamp<? )
46359 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
46375 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select csientit0_.ENTITY_LOG_ID as ENTITY_LOG_ID, csientit0_.version_stamp as version_2_, csientit0_.entity_name as entity_n4_, csientit0_.entity_id as entity_id, csientit0_.action as action from enterprise.entity_log csientit0_ where (csientit0_.entity_name=? )and(csientit0_.version_stamp>? )and(csientit0_.version_stamp<? )
46375 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
46375 [main] DEBUG net.sf.hibernate.type.StringType - binding 'ca.csi.enterprise.model.entity.CSIStudent' to parameter: 1
46375 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '23 March 2004 11:39:24' to parameter: 2
46375 [main] DEBUG net.sf.hibernate.type.TimestampType - binding '23 March 2004 12:56:38' to parameter: 3
46391 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
46391 [main] DEBUG net.sf.hibernate.type.LongType - returning '7003' as column: ENTITY_LOG_ID
46391 [main] DEBUG net.sf.hibernate.loader.Loader - result row: 7003
46391 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 7003
46391 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.cassynch.entity.CSIEntityLog#7003
46391 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '23 March 2004 12:42:10' as column: version_2_
46391 [main] DEBUG net.sf.hibernate.type.StringType - returning 'ca.csi.enterprise.model.entity.CSIStudent' as column: entity_n4_
46391 [main] DEBUG net.sf.hibernate.type.LongType - returning '8491' as column: entity_id
46391 [main] DEBUG net.sf.hibernate.type.StringType - returning 'I' as column: action
46391 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-23 12:42:10.084
46391 [main] DEBUG net.sf.hibernate.type.LongType - returning '7004' as column: ENTITY_LOG_ID
46391 [main] DEBUG net.sf.hibernate.loader.Loader - result row: 7004
46391 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 7004
46391 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.cassynch.entity.CSIEntityLog#7004
46391 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '23 March 2004 12:43:16' as column: version_2_
46391 [main] DEBUG net.sf.hibernate.type.StringType - returning 'ca.csi.enterprise.model.entity.CSIStudent' as column: entity_n4_
46391 [main] DEBUG net.sf.hibernate.type.LongType - returning '8492' as column: entity_id
46391 [main] DEBUG net.sf.hibernate.type.StringType - returning 'I' as column: action
46391 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-23 12:43:16.582
46406 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (2 rows)
46406 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
46406 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
46406 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 2
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.cassynch.entity.CSIEntityLog#7003]
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.cassynch.entity.CSIEntityLog#7003]
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.cassynch.entity.CSIEntityLog#7004]
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.cassynch.entity.CSIEntityLog#7004]
46406 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() - Query returned 2 results
46406 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSIEntJournalHibernateDAO - loadJournal() - END
46406 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
46406 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@551ee3] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] from thread [main]
46406 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
46406 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
46422 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
46422 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - run() - Records to process=2
46422 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - synch(Journals=2) - BEGIN
47844 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - insert() - BEGIN
47844 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
47844 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
47844 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
47844 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@166faac] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] to thread [main]
47844 [main] DEBUG ca.csi.enterprise.model.dao.hibernate.CSIHibernateBaseDAO - loadByObjectID() Class = ca.csi.enterprise.model.entity.CSIStudent
47844 [main] DEBUG ca.csi.enterprise.model.dao.hibernate.CSIHibernateBaseDAO - loadByObjectID() ID= 8491
47844 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@166faac] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] bound to thread [main]
47844 [main] DEBUG net.sf.hibernate.impl.SessionImpl - loading [ca.csi.enterprise.model.entity.CSIStudent#8491]
47844 [main] DEBUG net.sf.hibernate.impl.SessionImpl - attempting to resolve [ca.csi.enterprise.model.entity.CSIStudent#8491]
47844 [main] DEBUG net.sf.hibernate.impl.SessionImpl - object not resolved in any cache [ca.csi.enterprise.model.entity.CSIStudent#8491]
47859 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Materializing entity: ca.csi.enterprise.model.entity.CSIStudent#8491
47859 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
47859 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select csiaddre1_.ADDRESS_ID as ADDRESS_ID0_, csiaddre1_.version_stamp as version_2_0_, csiaddre1_.line1 as line10_, csiaddre1_.line2 as line20_, csiaddre1_.line3 as line30_, csiaddre1_.city as city0_, csiaddre1_.province_state as province7_0_, csiaddre1_.post_code as post_code0_, csiaddre1_.iso_country_code as iso_coun9_0_, csiaddre1_.create_datetime as create_10_0_, csiaddre1_.create_ip_address as create_11_0_, csiaddre1_.last_update_ip_address as last_up12_0_, csiaddre2_.ADDRESS_ID as ADDRESS_ID1_, csiaddre2_.version_stamp as version_2_1_, csiaddre2_.line1 as line11_, csiaddre2_.line2 as line21_, csiaddre2_.line3 as line31_, csiaddre2_.city as city1_, csiaddre2_.province_state as province7_1_, csiaddre2_.post_code as post_code1_, csiaddre2_.iso_country_code as iso_coun9_1_, csiaddre2_.create_datetime as create_10_1_, csiaddre2_.create_ip_address as create_11_1_, csiaddre2_.last_update_ip_address as last_up12_1_, csiorgan3_.organization_id as organization_id2_, csiorgan3_.version_stamp as version_2_2_, csiorgan3_.create_datetime as create_d3_2_, csiorgan3_.create_ip_address as create_i4_2_, csiorgan3_.last_update_ip_address as last_upd5_2_, csiorgan3_.type as type2_, csiorgan3_.english_name as english_7_2_, csiorgan3_.french_name as french_n8_2_, csiorgan3_.parent_ID as parent_ID2_, csiorgan3_.confirmed as confirmed2_, csiorgan3_.ida_flag as ida_flag2_, csiorgan3_.corp_price_flag as corp_pr12_2_, csiorgan3_.csi_firm_id as csi_fir13_2_, csiorgan4_.organization_id as organization_id3_, csiorgan4_.version_stamp as version_2_3_, csiorgan4_.create_datetime as create_d3_3_, csiorgan4_.create_ip_address as create_i4_3_, csiorgan4_.last_update_ip_address as last_upd5_3_, csiorgan4_.type as type3_, csiorgan4_.english_name as english_7_3_, csiorgan4_.french_name as french_n8_3_, csiorgan4_.parent_ID as parent_ID3_, csiorgan4_.confirmed as confirmed3_, csiorgan4_.ida_flag as ida_flag3_, csiorgan4_.corp_price_flag as corp_pr12_3_, csiorgan4_.csi_firm_id as csi_fir13_3_, csiorgan5_.organization_id as organization_id4_, csiorgan5_.version_stamp as version_2_4_, csiorgan5_.create_datetime as create_d3_4_, csiorgan5_.create_ip_address as create_i4_4_, csiorgan5_.last_update_ip_address as last_upd5_4_, csiorgan5_.type as type4_, csiorgan5_.english_name as english_7_4_, csiorgan5_.french_name as french_n8_4_, csiorgan5_.parent_ID as parent_ID4_, csiorgan5_.confirmed as confirmed4_, csiorgan5_.ida_flag as ida_flag4_, csiorgan5_.corp_price_flag as corp_pr12_4_, csiorgan5_.csi_firm_id as csi_fir13_4_, csisurve6_.survey_id as survey_id5_, csisurve6_.version_stamp as version_2_5_, csisurve6_.create_datetime as create_d3_5_, csisurve6_.create_ip_address as create_i4_5_, csisurve6_.last_update_ip_address as last_upd5_5_, csisurve6_.field1 as field15_, csisurve6_.field2 as field25_, csisurve6_.field3 as field35_, csisurve6_.field4 as field45_, csisurve6_.field5 as field55_, csisurve6_.field6 as field65_, csistude0_.student_id as student_id6_, csistude0_.version_stamp as version_2_6_, csistude0_.csi_student_id as csi_stud3_6_, csistude0_.company_name as company_4_6_, csistude0_.job_title as job_title6_, csistude0_.first_name as first_name6_, csistude0_.initial_name as initial_7_6_, csistude0_.last_name as last_name6_, csistude0_.password as password6_, csistude0_.title as title6_, csistude0_.home_address_id as home_ad11_6_, csistude0_.business_address_id as busines12_6_, csistude0_.gender as gender6_, csistude0_.sin as sin6_, csistude0_.month_of_birth as month_o15_6_, csistude0_.year_of_birth as year_of16_6_, csistude0_.pref_mailing_addr_type_id as pref_ma17_6_, csistude0_.email_address as email_a18_6_, csistude0_.alternate_email_address as alterna19_6_, csistude0_.correspondence_method_code as corresp20_6_, csistude0_.mailing_list_ind as mailing21_6_, csistude0_.language_id as languag22_6_, csistude0_.password_question as passwor23_6_, csistude0_.password_question_answer as passwor24_6_, csistude0_.accept_privacy_option_ind as accept_25_6_, csistude0_.privacy_optn_update_datetime as privacy26_6_, csistude0_.employer_id as employe27_6_, csistude0_.school_id as school_id6_, csistude0_.association_id as associa29_6_, csistude0_.ethical_violation_ind as ethical30_6_, csistude0_.amount_owing as amount_31_6_, csistude0_.home_phone as home_phone6_, csistude0_.business_phone as busines33_6_, csistude0_.student_status_code as student34_6_, csistude0_.infocus_member_date as infocus35_6_, csistude0_.infocus_discount_applied as infocus36_6_, csistude0_.survey_id as survey_id6_, csistude0_.create_datetime as create_38_6_, csistude0_.create_ip_address as create_39_6_, csistude0_.last_update_ip_address as last_up40_6_ from enterprise.student csistude0_, enterprise.address csiaddre1_, enterprise.address csiaddre2_, enterprise.ORGANIZATION csiorgan3_, enterprise.ORGANIZATION csiorgan4_, enterprise.ORGANIZATION csiorgan5_, enterprise.survey csisurve6_ where csistude0_.student_id=? and csistude0_.home_address_id=csiaddre1_.ADDRESS_ID(+) and csistude0_.business_address_id=csiaddre2_.ADDRESS_ID(+) and csistude0_.employer_id=csiorgan3_.organization_id(+) and csistude0_.school_id=csiorgan4_.organization_id(+) and csistude0_.association_id=csiorgan5_.organization_id(+) and csistude0_.survey_id=csisurve6_.survey_id(+)
47859 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
47859 [main] DEBUG net.sf.hibernate.type.LongType - binding '8491' to parameter: 1
47906 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
47906 [main] DEBUG net.sf.hibernate.type.LongType - returning '14725' as column: ADDRESS_ID0_
47906 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: ADDRESS_ID1_
47906 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: organization_id2_
47906 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: organization_id3_
47906 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: organization_id4_
47906 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: survey_id5_
47906 [main] DEBUG net.sf.hibernate.loader.Loader - result row: 14725, null, null, null, null, null, 8491
47906 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 14725
47906 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.enterprise.model.entity.CSIAddress#14725
47906 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '23 March 2004 12:42:10' as column: version_2_0_
47906 [main] DEBUG net.sf.hibernate.type.StringType - returning '5435 tert' as column: line10_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: line20_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: line30_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning 'ertewt' as column: city0_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning 'AB' as column: province7_0_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning 'y6y7y7' as column: post_code0_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning 'CA' as column: iso_coun9_0_
47922 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '31 December 1969 07:00:00' as column: create_10_0_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: create_11_0_
47922 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: last_up12_0_
47922 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-23 12:42:10.087
47922 [main] DEBUG net.sf.hibernate.loader.Loader - Initializing object from ResultSet: 8491
47922 [main] DEBUG net.sf.hibernate.loader.Loader - Hydrating entity: ca.csi.enterprise.model.entity.CSIStudent#8491
47938 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '23 March 2004 12:42:10' as column: version_2_6_
47938 [main] DEBUG net.sf.hibernate.type.LongType - returning '606021' as column: csi_stud3_6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: company_4_6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: job_title6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning 'sdfs' as column: first_name6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: initial_7_6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning 'sdf' as column: last_name6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning '1234' as column: password6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning 'Mr' as column: title6_
47938 [main] DEBUG net.sf.hibernate.type.LongType - returning '14725' as column: home_ad11_6_
47938 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: busines12_6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning 'M' as column: gender6_
47938 [main] DEBUG net.sf.hibernate.type.StringType - returning '345 ' as column: sin6_
47938 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '0' as column: month_o15_6_
47953 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '0' as column: year_of16_6_
47953 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '1' as column: pref_ma17_6_
47953 [main] DEBUG net.sf.hibernate.type.StringType - returning 'stiley@csi.ca' as column: email_a18_6_
47953 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: alterna19_6_
47953 [main] DEBUG net.sf.hibernate.type.StringType - returning 'EM' as column: corresp20_6_
47953 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '2' as column: mailing21_6_
47953 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '1' as column: languag22_6_
47953 [main] DEBUG net.sf.hibernate.type.StringType - returning 'What is your favourite movie?' as column: passwor23_6_
47953 [main] DEBUG net.sf.hibernate.type.StringType - returning 'sdfdsf sdfsdf' as column: passwor24_6_
47953 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '1' as column: accept_25_6_
47953 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '23 March 2004 12:42:08' as column: privacy26_6_
47953 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: employe27_6_
47953 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: school_id6_
47953 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: associa29_6_
47953 [main] DEBUG net.sf.hibernate.type.IntegerType - returning '0' as column: ethical30_6_
47953 [main] DEBUG net.sf.hibernate.type.FloatType - returning '0.0' as column: amount_31_6_
47969 [main] DEBUG net.sf.hibernate.type.StringType - returning '5665675675' as column: home_phone6_
47969 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ext. ' as column: busines33_6_
47969 [main] DEBUG net.sf.hibernate.type.StringType - returning null as column: student34_6_
47969 [main] DEBUG net.sf.hibernate.type.TimestampType - returning null as column: infocus35_6_
47969 [main] DEBUG net.sf.hibernate.type.BooleanType - returning null as column: infocus36_6_
47969 [main] DEBUG net.sf.hibernate.type.LongType - returning null as column: survey_id6_
47969 [main] DEBUG net.sf.hibernate.type.TimestampType - returning '31 December 1969 07:00:00' as column: create_38_6_
47969 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: create_39_6_
47969 [main] DEBUG net.sf.hibernate.type.StringType - returning ' ' as column: last_up40_6_
47969 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Version: 2004-03-23 12:42:10.088
47969 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (1 rows)
47969 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
47969 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
47969 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 2
47969 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.enterprise.model.entity.CSIAddress#14725]
47969 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.enterprise.model.entity.CSIAddress#14725]
47969 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolving associations for [ca.csi.enterprise.model.entity.CSIStudent#8491]
47969 [main] DEBUG net.sf.hibernate.impl.SessionImpl - loading [ca.csi.enterprise.model.entity.CSIAddress#14725]
47969 [main] DEBUG net.sf.hibernate.impl.SessionImpl - attempting to resolve [ca.csi.enterprise.model.entity.CSIAddress#14725]
47969 [main] DEBUG net.sf.hibernate.impl.SessionImpl - resolved object in session cache [ca.csi.enterprise.model.entity.CSIAddress#14725]
47984 [main] DEBUG net.sf.hibernate.impl.SessionImpl - initializing collection [ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments#8491]
47984 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
47984 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select student_0_.student_course_enrollemnt_id as student_1___, student_0_.student_course_enrollemnt_id as student_course_enrollemnt_id, student_0_.version_stamp as version_2_, student_0_.course_id as course_id, student_0_.student_id as student_id, student_0_.enrollment_date as enrollme5_, student_0_.completion_date as completi6_, student_0_.withdrawn_date as withdraw7_, student_0_.terminated_date as terminat8_, student_0_.expiry_date as expiry_d9_, student_0_.substitute_date as substit10_, student_0_.CAS_ENROLMENT_NUMBER as CAS_ENR11_, student_0_.pass_mark as pass_mark, student_0_.overall_mark as overall13_, student_0_.create_datetime as create_14_, student_0_.create_ip_address as create_15_, student_0_.last_update_ip_address as last_up16_ from enterprise.student_course_enrolment student_0_ where student_0_.student_id=?
47984 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
48000 [main] DEBUG net.sf.hibernate.type.LongType - binding '8491' to parameter: 1
48016 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
48016 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (0 rows)
48016 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
48016 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
48016 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 0
48016 [main] DEBUG net.sf.hibernate.impl.SessionImpl - initializing collection [ca.csi.enterprise.model.entity.CSIStudent.ircfs#8491]
48016 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
48016 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: select student_0_.student_ircf_id as student_1___, csiircf1_.ircf_id as ircf_id0_, csiircf1_.version_stamp as version_2_0_, csiircf1_.create_datetime as create_d3_0_, csiircf1_.create_ip_address as create_i4_0_, csiircf1_.last_update_ip_address as last_upd5_0_, csiircf1_.organization as organiza6_0_, csiircf1_.version as version0_, csiorgan2_.organization_id as organization_id1_, csiorgan2_.version_stamp as version_2_1_, csiorgan2_.create_datetime as create_d3_1_, csiorgan2_.create_ip_address as create_i4_1_, csiorgan2_.last_update_ip_address as last_upd5_1_, csiorgan2_.type as type1_, csiorgan2_.english_name as english_7_1_, csiorgan2_.french_name as french_n8_1_, csiorgan2_.parent_ID as parent_ID1_, csiorgan2_.confirmed as confirmed1_, csiorgan2_.ida_flag as ida_flag1_, csiorgan2_.corp_price_flag as corp_pr12_1_, csiorgan2_.csi_firm_id as csi_fir13_1_, student_0_.student_ircf_id as student_ircf_id2_, student_0_.version_stamp as version_2_2_, student_0_.create_datetime as create_d3_2_, student_0_.create_ip_address as create_i4_2_, student_0_.last_update_ip_address as last_upd5_2_, student_0_.student_id as student_id2_, student_0_.ircf_id as ircf_id2_, student_0_.accepted as accepted2_, student_0_.field_1 as field_12_, student_0_.field_2 as field_22_, student_0_.field_3 as field_32_, student_0_.field_4 as field_42_, student_0_.field_5 as field_52_ from enterprise.student_ircf student_0_, enterprise.ircf csiircf1_, enterprise.ORGANIZATION csiorgan2_ where student_0_.student_id=? and student_0_.ircf_id=csiircf1_.ircf_id(+) and csiircf1_.organization=csiorgan2_.organization_id(+)
48016 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
48016 [main] DEBUG net.sf.hibernate.type.LongType - binding '8491' to parameter: 1
48047 [main] DEBUG net.sf.hibernate.loader.Loader - processing result set
48047 [main] DEBUG net.sf.hibernate.loader.Loader - done processing result set (0 rows)
48047 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - done closing: 0 open PreparedStatements, 0 open ResultSets
48047 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - closing statement
48047 [main] DEBUG net.sf.hibernate.loader.Loader - total objects hydrated: 0
48047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - done materializing entity [ca.csi.enterprise.model.entity.CSIStudent#8491]
48047 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
48047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
48047 [main] DEBUG net.sf.hibernate.engine.Cascades - processing cascades for: ca.csi.enterprise.model.entity.CSIStudent
48047 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to saveOrUpdate()
48047 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saveOrUpdate() persistent instance
48047 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments
48063 [main] DEBUG net.sf.hibernate.engine.Cascades - cascading to collection: ca.csi.enterprise.model.entity.CSIStudent.ircfs
48063 [main] DEBUG net.sf.hibernate.engine.Cascades - done processing cascades for: ca.csi.enterprise.model.entity.CSIStudent
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Collection found: [ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments#8491], was: [ca.csi.enterprise.model.entity.CSIStudent.courseEnrolments#8491]
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Collection found: [ca.csi.enterprise.model.entity.CSIStudent.ircfs#8491], was: [ca.csi.enterprise.model.entity.CSIStudent.ircfs#8491]
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - post flush
48063 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Removed value [org.springframework.orm.hibernate.SessionHolder@166faac] for key [net.sf.hibernate.impl.SessionFactoryImpl@96b38e] from thread [main]
48063 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Closing Hibernate session
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - closing session
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - disconnecting session
48063 [main] DEBUG net.sf.hibernate.impl.SessionImpl - transaction completion
49016 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Converting Enterprise Phone Number = 5665675675
49016 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Converted Phone = 566-567-5675
49016 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Converted Phone =
49016 [main] DEBUG ca.csi.cassynch.business.CSIEntStudentSynch - Truncating Password Question
51438 [main] DEBUG ca.csi.cassynch.business.CSICASDataSynch - insertCASEntity() - BEGIN
51453 [main] DEBUG org.springframework.orm.hibernate.SessionFactoryUtils - Opening Hibernate session
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - opened session
51453 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Using new session for Hibernate interceptor
51453 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Bound value [org.springframework.orm.hibernate.SessionHolder@1fb06c9] for key [net.sf.hibernate.impl.SessionFactoryImpl@6bcf5d] to thread [main]
51453 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASBaseDAO - insertCasEntity() - BEGIN
51453 [main] DEBUG org.springframework.transaction.support.TransactionSynchronizationManager - Retrieved value [org.springframework.orm.hibernate.SessionHolder@1fb06c9] for key [net.sf.hibernate.impl.SessionFactoryImpl@6bcf5d] bound to thread [main]
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - saving [ca.csi.cassynch.entity.CSICASStudent#606021]
51453 [main] DEBUG ca.csi.cassynch.dao.hibernate.CSICASBaseDAO - insertCasEntity() - END
51453 [main] DEBUG org.springframework.orm.hibernate.HibernateInterceptor - Eagerly flushing Hibernate session
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - flushing session
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushing entities and processing referenced collections
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Processing unreferenced collections
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Scheduling collection removes/(re)creates/updates
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
51453 [main] DEBUG net.sf.hibernate.impl.SessionImpl - executing flush
51453 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Inserting entity: ca.csi.cassynch.entity.CSICASStudent#606021
51453 [main] DEBUG net.sf.hibernate.impl.BatcherImpl - about to open: 0 open PreparedStatements, 0 open ResultSets
51453 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - prepared statement get: insert into Student (FirstName, Initials, LastName, PIN, Title, Gender, SIN, Email, ContactPreference, OptIn, LangCorresp, VerificationQuestion, VerificationWord, PPAccepted, HomePhone, BusPhone, MailAddressType, MailAddr1, MailAddr2, MailAddr3, MailCity, MailProv, MailCtry, MailPostCode, studentID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
51453 [main] DEBUG net.sf.hibernate.impl.SessionFactoryImpl - preparing statement
51609 [main] DEBUG net.sf.hibernate.persister.EntityPersister - Dehydrating entity: ca.csi.cassynch.entity.CSICASStudent#606021
51609 [main] DEBUG net.sf.hibernate.type.StringType - binding 'sdfs' to parameter: 1
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding null to parameter: 2
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'sdf' to parameter: 3
51641 [main] DEBUG net.sf.hibernate.type.LongType - binding '1234' to parameter: 4
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'Mr' to parameter: 5
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'M' to parameter: 6
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding '345 ' to parameter: 7
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'stiley@csi.ca' to parameter: 8
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'E' to parameter: 9
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'N' to parameter: 10
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'E' to parameter: 11
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'What is your favour' to parameter: 12
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'sdfdsf sdfsdf' to parameter: 13
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding 'A' to parameter: 14
51641 [main] DEBUG net.sf.hibernate.type.StringType - binding '' to parameter: 15
51641 [main] DEBUG net.sf.hibernate.type.

cont'd