Hibernate version: 3.2.5.ga
Hibernate annotation version: 3.3.0.ga
Name and version of the database you are using: Postgresql 8.2
Hello.
I'm in a situation where Hibernate has a particular behaviour, and TopLink has a different one.
My whole project can be found here:
http://dspace-sandbox.googlecode.com/svn/prototypes/hibernate-prototype/trunk/dspace-api/src/main/java/org/dspace/ (look in /content and in /core).
I have two entities, Item and Bundle, they extend the class DSpaceObject. There's a OneToMany relationship between them, Item has a list of Bundle objects and a method called createBundle(). I use Property Access with only JPA standard annotations (no org.hibernate imports). Here's a snippet of the relevant code (I omit setter methods too):
Code:
@MappedSuperclass
public abstract class DSpaceObject {
protected int id;
@Id
@GeneratedValue(strategy=GenerationType.SEQUENCE)
public int getId() {
return id;
}
}
Code:
@Entity
public class Item extends DSpaceObject {
private List<Bundle> bundles;
public Item() {
this.bundles = new ArrayList<Bundle>();
}
@OneToMany(cascade = { CascadeType.ALL }, mappedBy = "item")
public List<Bundle> getBundles() {
return bundles;
}
public Bundle createBundle() {
Bundle bundle = BundleFactory.getInstance(context);
bundle.setItem(this);
getBundles().add(bundle);
return bundle;
}
}
Code:
@Entity
public class Bundle extends DSpaceObject {
private Item item;
@ManyToOne
public Item getItem() {
return item;
}
}
I use a class called ApplicationService, that uses javax.persistence.EntityManager to perform CRUD operations for Item and Bundle (and much more..). I paste the important part:
Code:
public class ApplicationService {
private EntityManagerFactory emf = Persistence.createEntityManagerFactory(persistentUnit);
private EntityManager em;
public <T> T get(Class<T> clazz, int id) {
setupTransaction();
T result = em.find(clazz, id);
return result;
}
public <T> void update(Class<T> clazz, T object) {
setupTransaction();
em.merge(object);
}
public void commit() {
EntityTransaction tr = em.getTransaction();
try {
tr.commit();
} finally {}
}
public void complete() {
EntityTransaction tr = em.getTransaction();
try {
tr.commit();
}
finally {
em.close();
}
}
private void setupTransaction(String method) {
if(em==null || !em.isOpen()) {
em = emf.createEntityManager();
}
if(em.getTransaction()==null || !em.getTransaction().isActive()) {
EntityTransaction tr = em.getTransaction();
tr.begin();
}
}
}
Now, the problem: I tried to run this test
Code:
ApplicationService applicationService = new ApplicationService();
Item item = applicationService.get(Item.class, 50);
Bundle bundle = item.createBundle();
bundle.setName("bundle");
applicationService.update(Item.class, item);
applicationService.complete();
Using Cascade, I expected to have a new bundle persisted on the DB, with a reference to the item. Actually, two bundles are persisted! I find two new lines on the table, referring to the same item_id.
Looking at the debugging messages of hibernate, i found that one id for the bundle is generated when em.merge is called, and then another one when tr.commit is called: two ids generated, two bundles persisted.
Another thing I noticed: I have this problem only when hibernate is in LAZY, if I set EAGER only one bundle is persisted.
The weird thing is: I tried also to use Toplink instead of Hibernate, this problem does not exist! only one bundle is persisted!
I paste the long console-output of the test:
Code:
...
-------------------------- Get --------------------------
Get: Creato un nuovo EntityManager
2008-01-25 09:47:02,711 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ trace com.mchange.v2.resourcepool.BasicResourcePool@cf710e [managed: 2, unused: 1, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@18aab40)
2008-01-25 09:47:02,711 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ decremented pending_acquires: 3
2008-01-25 09:47:02,712 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ trace com.mchange.v2.resourcepool.BasicResourcePool@cf710e [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@18aab40)
2008-01-25 09:47:02,718 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ decremented pending_acquires: 2
2008-01-25 09:47:02,729 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0
2008-01-25 09:47:02,729 DEBUG com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool @ com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager@1d98a.acquireResource() returning.
2008-01-25 09:47:02,729 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ trace com.mchange.v2.resourcepool.BasicResourcePool@cf710e [managed: 4, unused: 3, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@18aab40)
2008-01-25 09:47:02,729 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ decremented pending_acquires: 1
2008-01-25 09:47:02,729 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 0; checked out: 0; num connections: 0; num keys: 0
2008-01-25 09:47:02,792 DEBUG org.hibernate.impl.SessionImpl @ opened session at timestamp: 12012508226
2008-01-25 09:47:02,794 DEBUG org.hibernate.transaction.JDBCTransaction @ begin
2008-01-25 09:47:02,795 DEBUG org.hibernate.jdbc.ConnectionManager @ opening JDBC connection
2008-01-25 09:47:02,795 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ trace com.mchange.v2.resourcepool.BasicResourcePool@cf710e [managed: 4, unused: 3, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@18aab40)
2008-01-25 09:47:02,795 DEBUG org.hibernate.transaction.JDBCTransaction @ current autocommit status: true
2008-01-25 09:47:02,795 DEBUG org.hibernate.transaction.JDBCTransaction @ disabling autocommit
2008-01-25 09:47:02,796 DEBUG org.hibernate.jdbc.JDBCContext @ after transaction begin
Get: Creata una nuova transazione
2008-01-25 09:47:02,810 DEBUG org.hibernate.event.def.DefaultLoadEventListener @ loading entity: [org.dspace.content.Item#50]
2008-01-25 09:47:02,810 DEBUG org.hibernate.event.def.DefaultLoadEventListener @ attempting to resolve: [org.dspace.content.Item#50]
2008-01-25 09:47:02,810 DEBUG org.hibernate.event.def.DefaultLoadEventListener @ object not resolved in any cache: [org.dspace.content.Item#50]
2008-01-25 09:47:02,811 DEBUG org.hibernate.persister.entity.AbstractEntityPersister @ Fetching entity: [org.dspace.content.Item#50]
2008-01-25 09:47:02,811 DEBUG org.hibernate.loader.Loader @ loading entity: [org.dspace.content.Item#50]
2008-01-25 09:47:02,815 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-01-25 09:47:02,816 DEBUG org.hibernate.SQL @ select item0_.id as id5_10_, item0_.in_archive as in2_5_10_, item0_.last_modified as last3_5_10_, item0_.owning_collection_id as owning6_5_10_, item0_.submitter_id as submitter5_5_10_, item0_.withdrawn as withdrawn5_10_, collection1_.id as id3_0_, collection1_.administrators_id as administ4_3_0_, collection1_.license as license3_0_, collection1_.logo_id as logo5_3_0_, collection1_.submitters_id as submitters3_3_0_, collection1_.templateItem_id as template6_3_0_, group2_.id as id12_1_, group2_.name as name12_1_, bitstream3_.id as id7_2_, bitstream3_.bitstream_format_id as bitstream14_7_2_, bitstream3_.bundle_id as bundle13_7_2_, bitstream3_.checksum as checksum7_2_, bitstream3_.checksum_algorithm as checksum3_7_2_, bitstream3_.deleted as deleted7_2_, bitstream3_.description as descript5_7_2_, bitstream3_.internal_id as internal6_7_2_, bitstream3_.name as name7_2_, bitstream3_.sequence_id as sequence8_7_2_, bitstream3_.size_bytes as size9_7_2_, bitstream3_.source as source7_2_, bitstream3_.store_number as store11_7_2_, bitstream3_.user_format_description as user12_7_2_, bitstreamf4_.id as id13_3_, bitstreamf4_.mimetype as mimetype13_3_, bitstreamf4_.description as descript3_13_3_, bitstreamf4_.internal as internal13_3_, bitstreamf4_.short_description as short5_13_3_, bitstreamf4_.support_level as support6_13_3_, bundle5_.id as id6_4_, bundle5_.item_id as item3_6_4_, bundle5_.name as name6_4_, bundle5_.primary_bitstream_id as primary4_6_4_, item6_.id as id5_5_, item6_.in_archive as in2_5_5_, item6_.last_modified as last3_5_5_, item6_.owning_collection_id as owning6_5_5_, item6_.submitter_id as submitter5_5_5_, item6_.withdrawn as withdrawn5_5_, eperson7_.id as id11_6_, eperson7_.email as email11_6_, eperson7_.can_log_in as can3_11_6_, eperson7_.fistname as fistname11_6_, eperson7_.language as language11_6_, eperson7_.lastname as lastname11_6_, eperson7_.netid as netid11_6_, eperson7_.require_certificate as require8_11_6_, eperson7_.self_registered as self9_11_6_, bitstream8_.id as id7_7_, bitstream8_.bitstream_format_id as bitstream14_7_7_, bitstream8_.bundle_id as bundle13_7_7_, bitstream8_.checksum as checksum7_7_, bitstream8_.checksum_algorithm as checksum3_7_7_, bitstream8_.deleted as deleted7_7_, bitstream8_.description as descript5_7_7_, bitstream8_.internal_id as internal6_7_7_, bitstream8_.name as name7_7_, bitstream8_.sequence_id as sequence8_7_7_, bitstream8_.size_bytes as size9_7_7_, bitstream8_.source as source7_7_, bitstream8_.store_number as store11_7_7_, bitstream8_.user_format_description as user12_7_7_, group9_.id as id12_8_, group9_.name as name12_8_, item10_.id as id5_9_, item10_.in_archive as in2_5_9_, item10_.last_modified as last3_5_9_, item10_.owning_collection_id as owning6_5_9_, item10_.submitter_id as submitter5_5_9_, item10_.withdrawn as withdrawn5_9_ from Item item0_ left outer join Collection collection1_ on item0_.owning_collection_id=collection1_.id left outer join epersongroup group2_ on collection1_.administrators_id=group2_.id left outer join Bitstream bitstream3_ on collection1_.logo_id=bitstream3_.id left outer join bitstreamformatregistry bitstreamf4_ on bitstream3_.bitstream_format_id=bitstreamf4_.id left outer join Bundle bundle5_ on bitstream3_.bundle_id=bundle5_.id left outer join Item item6_ on bundle5_.item_id=item6_.id left outer join EPerson eperson7_ on item6_.submitter_id=eperson7_.id left outer join Bitstream bitstream8_ on bundle5_.primary_bitstream_id=bitstream8_.id left outer join epersongroup group9_ on collection1_.submitters_id=group9_.id left outer join Item item10_ on collection1_.templateItem_id=item10_.id where item0_.id=?
Hibernate: select item0_.id as id5_10_, item0_.in_archive as in2_5_10_, item0_.last_modified as last3_5_10_, item0_.owning_collection_id as owning6_5_10_, item0_.submitter_id as submitter5_5_10_, item0_.withdrawn as withdrawn5_10_, collection1_.id as id3_0_, collection1_.administrators_id as administ4_3_0_, collection1_.license as license3_0_, collection1_.logo_id as logo5_3_0_, collection1_.submitters_id as submitters3_3_0_, collection1_.templateItem_id as template6_3_0_, group2_.id as id12_1_, group2_.name as name12_1_, bitstream3_.id as id7_2_, bitstream3_.bitstream_format_id as bitstream14_7_2_, bitstream3_.bundle_id as bundle13_7_2_, bitstream3_.checksum as checksum7_2_, bitstream3_.checksum_algorithm as checksum3_7_2_, bitstream3_.deleted as deleted7_2_, bitstream3_.description as descript5_7_2_, bitstream3_.internal_id as internal6_7_2_, bitstream3_.name as name7_2_, bitstream3_.sequence_id as sequence8_7_2_, bitstream3_.size_bytes as size9_7_2_, bitstream3_.source as source7_2_, bitstream3_.store_number as store11_7_2_, bitstream3_.user_format_description as user12_7_2_, bitstreamf4_.id as id13_3_, bitstreamf4_.mimetype as mimetype13_3_, bitstreamf4_.description as descript3_13_3_, bitstreamf4_.internal as internal13_3_, bitstreamf4_.short_description as short5_13_3_, bitstreamf4_.support_level as support6_13_3_, bundle5_.id as id6_4_, bundle5_.item_id as item3_6_4_, bundle5_.name as name6_4_, bundle5_.primary_bitstream_id as primary4_6_4_, item6_.id as id5_5_, item6_.in_archive as in2_5_5_, item6_.last_modified as last3_5_5_, item6_.owning_collection_id as owning6_5_5_, item6_.submitter_id as submitter5_5_5_, item6_.withdrawn as withdrawn5_5_, eperson7_.id as id11_6_, eperson7_.email as email11_6_, eperson7_.can_log_in as can3_11_6_, eperson7_.fistname as fistname11_6_, eperson7_.language as language11_6_, eperson7_.lastname as lastname11_6_, eperson7_.netid as netid11_6_, eperson7_.require_certificate as require8_11_6_, eperson7_.self_registered as self9_11_6_, bitstream8_.id as id7_7_, bitstream8_.bitstream_format_id as bitstream14_7_7_, bitstream8_.bundle_id as bundle13_7_7_, bitstream8_.checksum as checksum7_7_, bitstream8_.checksum_algorithm as checksum3_7_7_, bitstream8_.deleted as deleted7_7_, bitstream8_.description as descript5_7_7_, bitstream8_.internal_id as internal6_7_7_, bitstream8_.name as name7_7_, bitstream8_.sequence_id as sequence8_7_7_, bitstream8_.size_bytes as size9_7_7_, bitstream8_.source as source7_7_, bitstream8_.store_number as store11_7_7_, bitstream8_.user_format_description as user12_7_7_, group9_.id as id12_8_, group9_.name as name12_8_, item10_.id as id5_9_, item10_.in_archive as in2_5_9_, item10_.last_modified as last3_5_9_, item10_.owning_collection_id as owning6_5_9_, item10_.submitter_id as submitter5_5_9_, item10_.withdrawn as withdrawn5_9_ from Item item0_ left outer join Collection collection1_ on item0_.owning_collection_id=collection1_.id left outer join epersongroup group2_ on collection1_.administrators_id=group2_.id left outer join Bitstream bitstream3_ on collection1_.logo_id=bitstream3_.id left outer join bitstreamformatregistry bitstreamf4_ on bitstream3_.bitstream_format_id=bitstreamf4_.id left outer join Bundle bundle5_ on bitstream3_.bundle_id=bundle5_.id left outer join Item item6_ on bundle5_.item_id=item6_.id left outer join EPerson eperson7_ on item6_.submitter_id=eperson7_.id left outer join Bitstream bitstream8_ on bundle5_.primary_bitstream_id=bitstream8_.id left outer join epersongroup group9_ on collection1_.submitters_id=group9_.id left outer join Item item10_ on collection1_.templateItem_id=item10_.id where item0_.id=?
2008-01-25 09:47:02,817 DEBUG org.hibernate.jdbc.AbstractBatcher @ preparing statement
2008-01-25 09:47:02,859 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ cxnStmtMgr.statementSet( org.postgresql.jdbc3.Jdbc3Connection@502819 ).size(): 1
2008-01-25 09:47:02,859 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 1; checked out: 1; num connections: 1; num keys: 1
2008-01-25 09:47:02,866 DEBUG org.hibernate.type.IntegerType @ binding '50' to parameter: 1
2008-01-25 09:47:02,879 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 1; checked out: 1; num connections: 1; num keys: 1
2008-01-25 09:47:02,879 DEBUG com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool @ com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager@1d98a.acquireResource() returning.
2008-01-25 09:47:02,880 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ trace com.mchange.v2.resourcepool.BasicResourcePool@cf710e [managed: 5, unused: 4, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@18aab40)
2008-01-25 09:47:02,883 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ decremented pending_acquires: 0
2008-01-25 09:47:03,953 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to open ResultSet (open ResultSets: 0, globally: 0)
2008-01-25 09:47:03,954 DEBUG org.hibernate.loader.Loader @ processing result set
2008-01-25 09:47:03,955 DEBUG org.hibernate.loader.Loader @ result set row: 0
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id3_0_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id12_1_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id7_2_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id13_3_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id6_4_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id5_5_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id11_6_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id7_7_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id12_8_
2008-01-25 09:47:03,955 DEBUG org.hibernate.type.IntegerType @ returning null as column: id5_9_
2008-01-25 09:47:03,955 DEBUG org.hibernate.loader.Loader @ result row: null, null, null, null, null, null, null, null, null, null, EntityKey[org.dspace.content.Item#50]
2008-01-25 09:47:03,956 DEBUG org.hibernate.loader.Loader @ Initializing object from ResultSet: [org.dspace.content.Item#50]
2008-01-25 09:47:03,963 DEBUG org.hibernate.persister.entity.AbstractEntityPersister @ Hydrating entity: [org.dspace.content.Item#50]
2008-01-25 09:47:03,963 DEBUG org.hibernate.type.BooleanType @ returning 'false' as column: in2_5_10_
2008-01-25 09:47:03,968 DEBUG org.hibernate.type.DateType @ returning '24 gennaio 2008' as column: last3_5_10_
2008-01-25 09:47:03,968 DEBUG org.hibernate.type.IntegerType @ returning null as column: owning6_5_10_
2008-01-25 09:47:03,968 DEBUG org.hibernate.type.IntegerType @ returning null as column: submitter5_5_10_
2008-01-25 09:47:03,968 DEBUG org.hibernate.type.BooleanType @ returning 'false' as column: withdrawn5_10_
2008-01-25 09:47:03,970 DEBUG org.hibernate.loader.Loader @ done processing result set (1 rows)
2008-01-25 09:47:03,970 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to close ResultSet (open ResultSets: 1, globally: 1)
2008-01-25 09:47:03,970 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-01-25 09:47:03,970 DEBUG org.hibernate.jdbc.AbstractBatcher @ closing statement
2008-01-25 09:47:03,970 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 1; checked out: 0; num connections: 1; num keys: 1
2008-01-25 09:47:03,972 DEBUG org.hibernate.loader.Loader @ total objects hydrated: 1
2008-01-25 09:47:03,973 DEBUG org.hibernate.engine.TwoPhaseLoad @ resolving associations for [org.dspace.content.Item#50]
2008-01-25 09:47:03,984 DEBUG org.hibernate.engine.loading.LoadContexts @ creating collection wrapper:[org.dspace.content.Item.bundles#50]
2008-01-25 09:47:03,994 DEBUG org.hibernate.engine.loading.LoadContexts @ creating collection wrapper:[org.dspace.content.Item.collections#50]
2008-01-25 09:47:03,994 DEBUG org.hibernate.engine.loading.LoadContexts @ creating collection wrapper:[org.dspace.content.Item.metadata#50]
2008-01-25 09:47:03,995 DEBUG org.hibernate.engine.TwoPhaseLoad @ done materializing entity [org.dspace.content.Item#50]
2008-01-25 09:47:03,995 DEBUG org.hibernate.engine.StatefulPersistenceContext @ initializing non-lazy collections
2008-01-25 09:47:03,995 DEBUG org.hibernate.loader.Loader @ done entity load
-------------------------- Update --------------------------
2008-01-25 09:47:04,001 DEBUG org.hibernate.event.def.AbstractSaveEventListener @ persistent instance of: org.dspace.content.Item
2008-01-25 09:47:04,002 DEBUG org.hibernate.event.def.DefaultMergeEventListener @ ignoring persistent instance
2008-01-25 09:47:04,016 DEBUG org.hibernate.engine.Cascade @ processing cascade ACTION_MERGE for: org.dspace.content.Item
2008-01-25 09:47:04,017 DEBUG org.hibernate.engine.Cascade @ cascade ACTION_MERGE for collection: org.dspace.content.Item.bundles
2008-01-25 09:47:04,019 DEBUG org.hibernate.engine.CascadingAction @ cascading to merge: org.dspace.content.Bundle
2008-01-25 09:47:04,021 DEBUG org.hibernate.engine.IdentifierValue @ id unsaved-value: 0
2008-01-25 09:47:04,022 DEBUG org.hibernate.event.def.AbstractSaveEventListener @ transient instance of: org.dspace.content.Bundle
2008-01-25 09:47:04,022 DEBUG org.hibernate.event.def.DefaultMergeEventListener @ merging transient instance
2008-01-25 09:47:04,022 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-01-25 09:47:04,022 DEBUG org.hibernate.SQL @ select nextval ('hibernate_sequence')
Hibernate: select nextval ('hibernate_sequence')
2008-01-25 09:47:04,023 DEBUG org.hibernate.jdbc.AbstractBatcher @ preparing statement
2008-01-25 09:47:04,023 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ cxnStmtMgr.statementSet( org.postgresql.jdbc3.Jdbc3Connection@502819 ).size(): 2
2008-01-25 09:47:04,023 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 2; checked out: 1; num connections: 1; num keys: 2
2008-01-25 09:47:04,269 DEBUG org.hibernate.id.SequenceGenerator @ Sequence identifier generated: 14
2008-01-25 09:47:04,269 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-01-25 09:47:04,269 DEBUG org.hibernate.jdbc.AbstractBatcher @ closing statement
2008-01-25 09:47:04,269 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 2; checked out: 0; num connections: 1; num keys: 2
2008-01-25 09:47:04,269 DEBUG org.hibernate.id.SequenceHiLoGenerator @ new hi value: 14
2008-01-25 09:47:04,269 DEBUG org.hibernate.event.def.AbstractSaveEventListener @ generated identifier: 140, using strategy: org.hibernate.id.SequenceHiLoGenerator
2008-01-25 09:47:04,269 DEBUG org.hibernate.event.def.AbstractSaveEventListener @ saving [org.dspace.content.Bundle#140]
2008-01-25 09:47:04,287 DEBUG org.hibernate.engine.Cascade @ done cascade ACTION_MERGE for collection: org.dspace.content.Item.bundles
2008-01-25 09:47:04,287 DEBUG org.hibernate.engine.Cascade @ done processing cascade ACTION_MERGE for: org.dspace.content.Item
-------------------------- Complete --------------------------
2008-01-25 09:47:04,287 DEBUG org.hibernate.transaction.JDBCTransaction @ commit
2008-01-25 09:47:04,287 DEBUG org.hibernate.impl.SessionImpl @ automatically flushing session
2008-01-25 09:47:04,287 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ flushing session
2008-01-25 09:47:04,288 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ processing flush-time cascades
2008-01-25 09:47:04,288 DEBUG org.hibernate.engine.Cascade @ processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Item
2008-01-25 09:47:04,288 DEBUG org.hibernate.engine.Cascade @ cascade ACTION_PERSIST_ON_FLUSH for collection: org.dspace.content.Item.bundles
2008-01-25 09:47:04,289 DEBUG org.hibernate.engine.CascadingAction @ cascading to persistOnFlush: org.dspace.content.Bundle
2008-01-25 09:47:04,289 DEBUG org.hibernate.engine.IdentifierValue @ id unsaved-value: 0
2008-01-25 09:47:04,289 DEBUG org.hibernate.event.def.AbstractSaveEventListener @ transient instance of: org.dspace.content.Bundle
2008-01-25 09:47:04,289 DEBUG org.hibernate.event.def.DefaultPersistEventListener @ saving transient instance
2008-01-25 09:47:04,289 DEBUG org.hibernate.event.def.AbstractSaveEventListener @ generated identifier: 141, using strategy: org.hibernate.id.SequenceHiLoGenerator
2008-01-25 09:47:04,289 DEBUG org.hibernate.event.def.AbstractSaveEventListener @ saving [org.dspace.content.Bundle#141]
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Bundle
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ done processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Bundle
2008-01-25 09:47:04,290 DEBUG org.hibernate.event.def.WrapVisitor @ Wrapped collection in role: org.dspace.content.Bundle.bitstreams
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Bundle
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ done processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Bundle
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ done cascade ACTION_PERSIST_ON_FLUSH for collection: org.dspace.content.Item.bundles
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ done processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Item
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Bundle
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.Cascade @ done processing cascade ACTION_PERSIST_ON_FLUSH for: org.dspace.content.Bundle
2008-01-25 09:47:04,290 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ dirty checking collections
2008-01-25 09:47:04,290 DEBUG org.hibernate.engine.CollectionEntry @ Collection dirty: [org.dspace.content.Item.bundles#50]
2008-01-25 09:47:04,290 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ Flushing entities and processing referenced collections
2008-01-25 09:47:04,297 DEBUG org.hibernate.engine.Collections @ Collection found: [org.dspace.content.Item.bundles#50], was: [org.dspace.content.Item.bundles#50] (uninitialized)
2008-01-25 09:47:04,297 DEBUG org.hibernate.engine.Collections @ Collection found: [org.dspace.content.Item.collections#50], was: [org.dspace.content.Item.collections#50] (uninitialized)
2008-01-25 09:47:04,298 DEBUG org.hibernate.engine.Collections @ Collection found: [org.dspace.content.Item.metadata#50], was: [org.dspace.content.Item.metadata#50] (uninitialized)
2008-01-25 09:47:04,298 DEBUG org.hibernate.event.def.WrapVisitor @ Wrapped collection in role: org.dspace.content.Bundle.bitstreams
2008-01-25 09:47:04,298 DEBUG org.hibernate.engine.Collections @ Collection found: [org.dspace.content.Bundle.bitstreams#140], was: [<unreferenced>] (initialized)
2008-01-25 09:47:04,298 DEBUG org.hibernate.engine.Collections @ Collection found: [org.dspace.content.Bundle.bitstreams#141], was: [<unreferenced>] (initialized)
2008-01-25 09:47:04,298 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ Processing unreferenced collections
2008-01-25 09:47:04,298 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ Scheduling collection removes/(re)creates/updates
2008-01-25 09:47:04,302 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ Flushed: 2 insertions, 0 updates, 0 deletions to 3 objects
2008-01-25 09:47:04,302 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ Flushed: 2 (re)creations, 1 updates, 0 removals to 5 collections
2008-01-25 09:47:04,303 DEBUG org.hibernate.pretty.Printer @ listing entities:
2008-01-25 09:47:04,304 DEBUG org.hibernate.pretty.Printer @ org.dspace.content.Bundle{item=org.dspace.content.Item#50, primaryBitstream=null, bitstreams=[], name=BBB, id=140}
2008-01-25 09:47:04,305 DEBUG org.hibernate.pretty.Printer @ org.dspace.content.Item{owningCollection=null, withdrawn=false, collections=<uninitialized>, submitter=null, metadata=<uninitialized>, archived=false, lastModified=24 gennaio 2008, bundles=<uninitialized>, id=50}
2008-01-25 09:47:04,305 DEBUG org.hibernate.pretty.Printer @ org.dspace.content.Bundle{item=org.dspace.content.Item#50, primaryBitstream=null, bitstreams=[], name=BBB, id=141}
2008-01-25 09:47:04,305 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ executing flush
2008-01-25 09:47:04,305 DEBUG org.hibernate.jdbc.ConnectionManager @ registering flush begin
2008-01-25 09:47:04,306 DEBUG org.hibernate.persister.entity.AbstractEntityPersister @ Inserting entity: [org.dspace.content.Bundle#140]
2008-01-25 09:47:04,314 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-01-25 09:47:04,314 DEBUG org.hibernate.SQL @ insert into Bundle (item_id, name, primary_bitstream_id, id) values (?, ?, ?, ?)
Hibernate: insert into Bundle (item_id, name, primary_bitstream_id, id) values (?, ?, ?, ?)
2008-01-25 09:47:04,314 DEBUG org.hibernate.jdbc.AbstractBatcher @ preparing statement
2008-01-25 09:47:04,315 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ cxnStmtMgr.statementSet( org.postgresql.jdbc3.Jdbc3Connection@502819 ).size(): 3
2008-01-25 09:47:04,315 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 3; checked out: 1; num connections: 1; num keys: 3
2008-01-25 09:47:04,315 DEBUG org.hibernate.persister.entity.AbstractEntityPersister @ Dehydrating entity: [org.dspace.content.Bundle#140]
2008-01-25 09:47:04,315 DEBUG org.hibernate.type.IntegerType @ binding '50' to parameter: 1
2008-01-25 09:47:04,315 DEBUG org.hibernate.type.StringType @ binding 'BBB' to parameter: 2
2008-01-25 09:47:04,315 DEBUG org.hibernate.type.IntegerType @ binding null to parameter: 3
2008-01-25 09:47:04,315 DEBUG org.hibernate.type.IntegerType @ binding '140' to parameter: 4
2008-01-25 09:47:04,317 DEBUG org.hibernate.persister.entity.AbstractEntityPersister @ Inserting entity: [org.dspace.content.Bundle#141]
2008-01-25 09:47:04,317 DEBUG org.hibernate.jdbc.AbstractBatcher @ reusing prepared statement
2008-01-25 09:47:04,317 DEBUG org.hibernate.SQL @ insert into Bundle (item_id, name, primary_bitstream_id, id) values (?, ?, ?, ?)
Hibernate: insert into Bundle (item_id, name, primary_bitstream_id, id) values (?, ?, ?, ?)
2008-01-25 09:47:04,317 DEBUG org.hibernate.persister.entity.AbstractEntityPersister @ Dehydrating entity: [org.dspace.content.Bundle#141]
2008-01-25 09:47:04,317 DEBUG org.hibernate.type.IntegerType @ binding '50' to parameter: 1
2008-01-25 09:47:04,317 DEBUG org.hibernate.type.StringType @ binding 'BBB' to parameter: 2
2008-01-25 09:47:04,317 DEBUG org.hibernate.type.IntegerType @ binding null to parameter: 3
2008-01-25 09:47:04,317 DEBUG org.hibernate.type.IntegerType @ binding '141' to parameter: 4
2008-01-25 09:47:04,317 DEBUG org.hibernate.jdbc.AbstractBatcher @ Executing batch size: 2
2008-01-25 09:47:04,525 DEBUG org.hibernate.jdbc.AbstractBatcher @ about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-01-25 09:47:04,525 DEBUG org.hibernate.jdbc.AbstractBatcher @ closing statement
2008-01-25 09:47:04,525 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 3; checked out: 0; num connections: 1; num keys: 3
2008-01-25 09:47:04,526 DEBUG org.hibernate.jdbc.ConnectionManager @ registering flush end
2008-01-25 09:47:04,526 DEBUG org.hibernate.event.def.AbstractFlushingEventListener @ post flush
2008-01-25 09:47:04,526 DEBUG org.hibernate.jdbc.JDBCContext @ before transaction completion
2008-01-25 09:47:04,526 DEBUG org.hibernate.impl.SessionImpl @ before transaction completion
2008-01-25 09:47:04,573 DEBUG org.hibernate.transaction.JDBCTransaction @ re-enabling autocommit
2008-01-25 09:47:04,573 DEBUG org.hibernate.transaction.JDBCTransaction @ committed JDBC Connection
2008-01-25 09:47:04,573 DEBUG org.hibernate.jdbc.JDBCContext @ after transaction completion
2008-01-25 09:47:04,573 DEBUG org.hibernate.jdbc.ConnectionManager @ aggressively releasing JDBC connection
2008-01-25 09:47:04,573 DEBUG org.hibernate.jdbc.ConnectionManager @ releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-01-25 09:47:04,576 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 3; checked out: 0; num connections: 1; num keys: 3
2008-01-25 09:47:04,576 DEBUG com.mchange.v2.resourcepool.BasicResourcePool @ trace com.mchange.v2.resourcepool.BasicResourcePool@cf710e [managed: 5, unused: 4, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@18aab40)
2008-01-25 09:47:04,576 DEBUG org.hibernate.impl.SessionImpl @ after transaction completion
Complete: Chiusa una transazione
2008-01-25 09:47:04,576 DEBUG org.hibernate.impl.SessionImpl @ closing session
2008-01-25 09:47:04,576 DEBUG org.hibernate.jdbc.ConnectionManager @ connection already null in cleanup : no action
Complete: Chiuso un EntityManager
2008-01-25 09:47:04,580 DEBUG com.mchange.v2.c3p0.stmt.GooGooStatementCache @ checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 3; checked out: 0; num connections: 1; num keys: 3
I hope to receive some suggestions, please help!
Thanks,
Daniele