[hibernate-issues] [Hibernate-JIRA] Created: (HHH-3349) SequenceStyleGenerator generates strange IDs for PostgreSQL database

Adam Wozniak (JIRA) noreply at atlassian.com
Tue Jun 17 14:27:34 EDT 2008


SequenceStyleGenerator generates strange IDs for PostgreSQL database
--------------------------------------------------------------------

                 Key: HHH-3349
                 URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-3349
             Project: Hibernate3
          Issue Type: Bug
    Affects Versions: 3.2.6
         Environment: hibernate-3.2.6.ga, hibernate-annotations-3.3.1.GA, hibernate-entitymanager-3.3.2.GA, hibernate-validator-3.0.0.GA, PostgreSQL 8.3.1 on Windows box. Sun Java 6 (Win32 on Vista 32 bits).
            Reporter: Adam Wozniak


Hello
I've got a standalone application using environment:
* PostgreSQL 8.3.1 (Win 32)
* hibernate-3.2.6.ga
* hibernate-annotations-3.3.1.GA
* hibernate-entitymanager-3.3.2.GA
* hibernate-validator-3.0.0.GA

I've got a PostgreSQL database sequence:
CREATE SEQUENCE t_seq
  INCREMENT 10
  MINVALUE 1
  MAXVALUE 999999999999999999
  START 11;

My entity:

@Entity
@Table(name = "T")
@org.hibernate.annotations.Entity(dynamicUpdate=true, dynamicInsert=true)
public class T
{
	private long   id;

	@Id
	@Column(unique = true, nullable = false, precision = 18, scale = 0)
	@GeneratedValue(generator = "t_generator")
    @GenericGenerator( name = "t_generator",
    strategy = "org.hibernate.id.enhanced.SequenceStyleGenerator",
    	parameters = {
    		  @Parameter(name = "sequence_name", value = "T_SEQ")
    		, @Parameter(name = "increment_size", value = "10")
    		, @Parameter(name = "optimizer", value = "pooled")
    	}
    )
	public long getId()
	{
		return id;
	}

	public void setId(long id)
	{
		this.id = id;
	}
}

And my test application to recreate this issue:
			for(int i = 0; i < 11; i++)
			{
				if(i == 0 || i == 10)
					System.out.println("Database hit to sequence will be performed.");

				T t = new T();
				em.persist(t);				
			}

Reading this Steve Ebersole description ( http://blog.hibernate.org/2082.lace#comments ) I would expect, that I will get the following IDs:
11
12
13
14
15
16
17
18
19
20
21

But Hibernate generates:
101
102
103
104
105
106
107
108
109
110
111

Is it something wrong with my code? Or this is a issue in Hibernate?
Note please, that on the same page ( http://blog.hibernate.org/2082.lace#comments ) other person claims that it doesn't work for his configuration based on PostgreSQL.

You will find my log4j output for my test application on the end of my email.

Regards,
Adam Wozniak

Piece of my log4j output:
2008-06-17 20:20:38,198 [main] DEBUG () SessionImpl: opened session at timestamp: 12137268381
2008-06-17 20:20:38,200 [main] DEBUG () JDBCTransaction: begin
2008-06-17 20:20:38,200 [main] DEBUG () ConnectionManager: opening JDBC connection
2008-06-17 20:20:38,200 [main] DEBUG () BasicResourcePool: trace com.mchange.v2.resourcepool.BasicResourcePool at 104a4b6 [managed: 1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection at b206e9)
2008-06-17 20:20:38,202 [main] DEBUG () JDBCTransaction: current autocommit status: true
2008-06-17 20:20:38,202 [main] DEBUG () JDBCTransaction: disabling autocommit
2008-06-17 20:20:38,202 [main] DEBUG () JDBCContext: after transaction begin
Database hit to sequence will be performed.
2008-06-17 20:20:39,467 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,469 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,469 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,472 [main] DEBUG () AbstractBatcher: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-06-17 20:20:39,479 [main] DEBUG () AbstractBatcher: 
    select
        nextval ('T_SEQ')
Hibernate: 
    select
        nextval ('T_SEQ')
2008-06-17 20:20:39,480 [main] DEBUG () AbstractBatcher: preparing statement
2008-06-17 20:20:39,489 [main] DEBUG () GooGooStatementCache: cxnStmtMgr.statementSet( org.postgresql.jdbc4.Jdbc4Connection at 1df3082 ).size(): 1
2008-06-17 20:20:39,489 [main] DEBUG () GooGooStatementCache: checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 1; checked out: 1; num connections: 1; num keys: 1
2008-06-17 20:20:39,506 [main] DEBUG () SequenceStructure$1: Sequence identifier generated: 11
2008-06-17 20:20:39,506 [main] DEBUG () AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-06-17 20:20:39,507 [main] DEBUG () AbstractBatcher: closing statement
2008-06-17 20:20:39,507 [main] DEBUG () GooGooStatementCache: checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 1; checked out: 0; num connections: 1; num keys: 1
2008-06-17 20:20:39,508 [main] DEBUG () AbstractSaveEventListener: generated identifier: 101, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,513 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#101]
2008-06-17 20:20:39,530 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,530 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,530 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,530 [main] DEBUG () AbstractSaveEventListener: generated identifier: 102, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,531 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#102]
2008-06-17 20:20:39,531 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,531 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,531 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,532 [main] DEBUG () AbstractSaveEventListener: generated identifier: 103, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,532 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#103]
2008-06-17 20:20:39,533 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,533 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,533 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,533 [main] DEBUG () AbstractSaveEventListener: generated identifier: 104, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,534 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#104]
2008-06-17 20:20:39,534 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,534 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,534 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,534 [main] DEBUG () AbstractSaveEventListener: generated identifier: 105, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,535 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#105]
2008-06-17 20:20:39,535 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,535 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,535 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,536 [main] DEBUG () AbstractSaveEventListener: generated identifier: 106, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,536 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#106]
2008-06-17 20:20:39,537 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,537 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,537 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,537 [main] DEBUG () AbstractSaveEventListener: generated identifier: 107, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,537 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#107]
2008-06-17 20:20:39,538 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,538 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,538 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,538 [main] DEBUG () AbstractSaveEventListener: generated identifier: 108, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,539 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#108]
2008-06-17 20:20:39,539 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,539 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,539 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,539 [main] DEBUG () AbstractSaveEventListener: generated identifier: 109, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,540 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#109]
2008-06-17 20:20:39,541 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:39,541 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:39,541 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:39,541 [main] DEBUG () AbstractSaveEventListener: generated identifier: 110, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:39,541 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#110]
Database hit to sequence will be performed.
2008-06-17 20:20:40,912 [main] DEBUG () IdentifierValue: id unsaved-value: 0
2008-06-17 20:20:40,912 [main] DEBUG () AbstractSaveEventListener: transient instance of: net.cellbell.model.T
2008-06-17 20:20:40,913 [main] DEBUG () DefaultPersistEventListener: saving transient instance
2008-06-17 20:20:40,913 [main] DEBUG () AbstractBatcher: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-06-17 20:20:40,913 [main] DEBUG () AbstractBatcher: 
    select
        nextval ('T_SEQ')
Hibernate: 
    select
        nextval ('T_SEQ')
2008-06-17 20:20:40,914 [main] DEBUG () AbstractBatcher: preparing statement
2008-06-17 20:20:40,914 [main] DEBUG () GooGooStatementCache: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache ----> CACHE HIT
2008-06-17 20:20:40,914 [main] DEBUG () GooGooStatementCache: checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 1; checked out: 1; num connections: 1; num keys: 1
2008-06-17 20:20:40,917 [main] DEBUG () SequenceStructure$1: Sequence identifier generated: 21
2008-06-17 20:20:40,917 [main] DEBUG () AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-06-17 20:20:40,917 [main] DEBUG () AbstractBatcher: closing statement
2008-06-17 20:20:40,917 [main] DEBUG () GooGooStatementCache: checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 1; checked out: 0; num connections: 1; num keys: 1
2008-06-17 20:20:40,918 [main] DEBUG () AbstractSaveEventListener: generated identifier: 111, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2008-06-17 20:20:40,918 [main] DEBUG () AbstractSaveEventListener: saving [net.cellbell.model.T#111]
2008-06-17 20:20:40,919 [main] DEBUG () JDBCTransaction: commit
2008-06-17 20:20:40,919 [main] DEBUG () SessionImpl: automatically flushing session
2008-06-17 20:20:40,922 [main] DEBUG () AbstractFlushingEventListener: flushing session
2008-06-17 20:20:40,923 [main] DEBUG () AbstractFlushingEventListener: processing flush-time cascades
2008-06-17 20:20:40,924 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,925 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,925 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,925 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,926 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,927 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,927 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,927 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,927 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,929 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,929 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,929 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,929 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,929 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,930 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,930 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,930 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,930 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,931 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,932 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,932 [main] DEBUG () Cascade: processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,932 [main] DEBUG () Cascade: done processing cascade ACTION_PERSIST_ON_FLUSH for: net.cellbell.model.T
2008-06-17 20:20:40,932 [main] DEBUG () AbstractFlushingEventListener: dirty checking collections
2008-06-17 20:20:40,933 [main] DEBUG () AbstractFlushingEventListener: Flushing entities and processing referenced collections
2008-06-17 20:20:40,939 [main] DEBUG () AbstractFlushingEventListener: Processing unreferenced collections
2008-06-17 20:20:40,939 [main] DEBUG () AbstractFlushingEventListener: Scheduling collection removes/(re)creates/updates
2008-06-17 20:20:40,940 [main] DEBUG () AbstractFlushingEventListener: Flushed: 11 insertions, 0 updates, 0 deletions to 11 objects
2008-06-17 20:20:40,940 [main] DEBUG () AbstractFlushingEventListener: Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
2008-06-17 20:20:40,942 [main] DEBUG () Printer: listing entities:
2008-06-17 20:20:40,942 [main] DEBUG () Printer: net.cellbell.model.T{id=105}
2008-06-17 20:20:40,943 [main] DEBUG () Printer: net.cellbell.model.T{id=104}
2008-06-17 20:20:40,943 [main] DEBUG () Printer: net.cellbell.model.T{id=107}
2008-06-17 20:20:40,943 [main] DEBUG () Printer: net.cellbell.model.T{id=106}
2008-06-17 20:20:40,945 [main] DEBUG () Printer: net.cellbell.model.T{id=101}
2008-06-17 20:20:40,945 [main] DEBUG () Printer: net.cellbell.model.T{id=103}
2008-06-17 20:20:40,945 [main] DEBUG () Printer: net.cellbell.model.T{id=102}
2008-06-17 20:20:40,945 [main] DEBUG () Printer: net.cellbell.model.T{id=109}
2008-06-17 20:20:40,945 [main] DEBUG () Printer: net.cellbell.model.T{id=108}
2008-06-17 20:20:40,946 [main] DEBUG () Printer: net.cellbell.model.T{id=111}
2008-06-17 20:20:40,946 [main] DEBUG () Printer: net.cellbell.model.T{id=110}
2008-06-17 20:20:40,946 [main] DEBUG () AbstractFlushingEventListener: executing flush
2008-06-17 20:20:40,947 [main] DEBUG () ConnectionManager: registering flush begin
2008-06-17 20:20:40,951 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#101]
2008-06-17 20:20:40,956 [main] DEBUG () AbstractBatcher: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2008-06-17 20:20:40,957 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,957 [main] DEBUG () AbstractBatcher: preparing statement
2008-06-17 20:20:40,957 [main] DEBUG () GooGooStatementCache: cxnStmtMgr.statementSet( org.postgresql.jdbc4.Jdbc4Connection at 1df3082 ).size(): 2
2008-06-17 20:20:40,959 [main] DEBUG () GooGooStatementCache: checkoutStatement: com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 2; checked out: 1; num connections: 1; num keys: 2
2008-06-17 20:20:40,959 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#101]
2008-06-17 20:20:40,960 [main] DEBUG () NullableType: binding '101' to parameter: 1
2008-06-17 20:20:40,964 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#102]
2008-06-17 20:20:40,965 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,965 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,965 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#102]
2008-06-17 20:20:40,967 [main] DEBUG () NullableType: binding '102' to parameter: 1
2008-06-17 20:20:40,967 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#103]
2008-06-17 20:20:40,967 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,968 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,968 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#103]
2008-06-17 20:20:40,970 [main] DEBUG () NullableType: binding '103' to parameter: 1
2008-06-17 20:20:40,970 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#104]
2008-06-17 20:20:40,970 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,970 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,971 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#104]
2008-06-17 20:20:40,971 [main] DEBUG () NullableType: binding '104' to parameter: 1
2008-06-17 20:20:40,971 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#105]
2008-06-17 20:20:40,972 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,972 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,972 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#105]
2008-06-17 20:20:40,973 [main] DEBUG () NullableType: binding '105' to parameter: 1
2008-06-17 20:20:40,973 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#106]
2008-06-17 20:20:40,973 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,975 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,976 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#106]
2008-06-17 20:20:40,977 [main] DEBUG () NullableType: binding '106' to parameter: 1
2008-06-17 20:20:40,977 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#107]
2008-06-17 20:20:40,977 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,978 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,979 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#107]
2008-06-17 20:20:40,979 [main] DEBUG () NullableType: binding '107' to parameter: 1
2008-06-17 20:20:40,979 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#108]
2008-06-17 20:20:40,980 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,980 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,980 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#108]
2008-06-17 20:20:40,981 [main] DEBUG () NullableType: binding '108' to parameter: 1
2008-06-17 20:20:40,981 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#109]
2008-06-17 20:20:40,982 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,982 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,982 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#109]
2008-06-17 20:20:40,983 [main] DEBUG () NullableType: binding '109' to parameter: 1
2008-06-17 20:20:40,983 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#110]
2008-06-17 20:20:40,983 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,983 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,984 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#110]
2008-06-17 20:20:40,984 [main] DEBUG () NullableType: binding '110' to parameter: 1
2008-06-17 20:20:40,984 [main] DEBUG () AbstractEntityPersister: Inserting entity: [net.cellbell.model.T#111]
2008-06-17 20:20:40,984 [main] DEBUG () AbstractBatcher: reusing prepared statement
2008-06-17 20:20:40,985 [main] DEBUG () AbstractBatcher: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
Hibernate: 
    /* insert net.cellbell.model.T
        */ insert 
        into
            T
            (id) 
        values
            (?)
2008-06-17 20:20:40,985 [main] DEBUG () AbstractEntityPersister: Dehydrating entity: [net.cellbell.model.T#111]
2008-06-17 20:20:40,986 [main] DEBUG () NullableType: binding '111' to parameter: 1
2008-06-17 20:20:40,986 [main] DEBUG () BatchingBatcher: Executing batch size: 11
2008-06-17 20:20:40,995 [main] DEBUG () AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2008-06-17 20:20:40,995 [main] DEBUG () AbstractBatcher: closing statement
2008-06-17 20:20:40,995 [main] DEBUG () GooGooStatementCache: checkinStatement(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 2; checked out: 0; num connections: 1; num keys: 2
2008-06-17 20:20:40,996 [main] DEBUG () ConnectionManager: registering flush end
2008-06-17 20:20:40,996 [main] DEBUG () AbstractFlushingEventListener: post flush
2008-06-17 20:20:40,996 [main] DEBUG () JDBCContext: before transaction completion
2008-06-17 20:20:40,996 [main] DEBUG () SessionImpl: before transaction completion
2008-06-17 20:20:41,044 [main] DEBUG () JDBCTransaction: re-enabling autocommit
2008-06-17 20:20:41,045 [main] DEBUG () JDBCTransaction: committed JDBC Connection
2008-06-17 20:20:41,045 [main] DEBUG () JDBCContext: after transaction completion
2008-06-17 20:20:41,045 [main] DEBUG () ConnectionManager: aggressively releasing JDBC connection
2008-06-17 20:20:41,045 [main] DEBUG () ConnectionManager: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2008-06-17 20:20:41,050 [main] DEBUG () GooGooStatementCache: checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 2; checked out: 0; num connections: 1; num keys: 2
2008-06-17 20:20:41,051 [main] DEBUG () BasicResourcePool: trace com.mchange.v2.resourcepool.BasicResourcePool at 104a4b6 [managed: 1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection at b206e9)
2008-06-17 20:20:41,051 [main] DEBUG () SessionImpl: after transaction completion
2008-06-17 20:20:41,051 [main] DEBUG () PersistenceUtil: Closing EntityManager: org.hibernate.ejb.EntityManagerImpl at 13c8540...
2008-06-17 20:20:41,052 [main] DEBUG () SessionImpl: closing session
2008-06-17 20:20:41,052 [main] DEBUG () ConnectionManager: connection already null in cleanup : no action
2008-06-17 20:20:41,051 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] DEBUG () GooGooStatementCache: checkinAll(): com.mchange.v2.c3p0.stmt.GlobalMaxOnlyStatementCache stats -- total size: 2; checked out: 0; num connections: 1; num keys: 2
2008-06-17 20:20:41,055 [main] DEBUG () PersistenceUtil: EntityManager: org.hibernate.ejb.EntityManagerImpl at 13c8540 closed.
2008-06-17 20:20:41,055 [main] INFO  () PersistenceUtil: Closing main EntityManagerFactory...
2008-06-17 20:20:41,056 [main] INFO  () SessionFactoryImpl: closing
2008-06-17 20:20:41,058 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] DEBUG () ThreadPoolAsynchronousRunner$PoolThread: Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1,5,main] interrupted. Shutting down.
2008-06-17 20:20:41,058 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] DEBUG () ThreadPoolAsynchronousRunner$PoolThread: Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2,5,main] interrupted. Shutting down.
2008-06-17 20:20:41,058 [main] DEBUG () ActiveManagementCoordinator: MBean: com.mchange.v2.c3p0:type=PooledDataSource[1hge11v7u163uw8e90ilzp|405f6] unregistered.
2008-06-17 20:20:41,059 [main] DEBUG () ActiveManagementCoordinator: C3P0Registry mbean unregistered.
2008-06-17 20:20:41,060 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] DEBUG () ThreadPoolAsynchronousRunner$PoolThread: Thread[com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0,5,main] interrupted. Shutting down.
2008-06-17 20:20:41,062 [main] DEBUG () AbstractPoolBackedDataSource: com.mchange.v2.c3p0.PoolBackedDataSource at 405f6 has been closed. 


-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://opensource.atlassian.com/projects/hibernate/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        



More information about the hibernate-issues mailing list