-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 
Author Message
 Post subject: Problem using hibernate as jpa provider: double creation
PostPosted: Fri Jan 25, 2008 5:14 am 
Newbie

Joined: Thu Jan 24, 2008 12:01 pm
Posts: 2
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


Last edited by danielen on Fri Jan 25, 2008 5:29 am, edited 1 time in total.

Top
 Profile  
 
 Post subject:
PostPosted: Fri Jan 25, 2008 5:20 am 
Newbie

Joined: Thu Jan 24, 2008 12:01 pm
Posts: 2
I noticed that my message was too long, I apologize, I had to modify it omitting the first part of the output. Right now there's the output starting from when the applicationService.get method is called.


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.