-->
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: incorrect use of IndexColumn with base != 0
PostPosted: Sun Apr 20, 2008 11:58 am 
Newbie

Joined: Tue Aug 15, 2006 5:49 am
Posts: 4
Hibernate version: 3.2.6.ga

Mapping documents:

Code:
@Entity
public class E1 {
   @Id
   @GeneratedValue
   private int id;

   @OneToMany(fetch = FetchType.LAZY, cascade = { CascadeType.ALL })
   @JoinColumn(name = "e1", nullable = false, insertable = true, updatable = false)
   @IndexColumn(name = "e1i", base = 1, nullable = false)
   @Cascade( { org.hibernate.annotations.CascadeType.ALL, org.hibernate.annotations.CascadeType.DELETE_ORPHAN })
   private List<E2> e2s = new ArrayList<E2>();

   public int getId() {
      return id;
   }

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

   public List<E2> getE2s() {
      return e2s;
   }

   public void setE2s(List<E2> e2s) {
      this.e2s = e2s;
   }

}

@Entity
@Table(uniqueConstraints = { @UniqueConstraint(columnNames = { "e1", "e1i" }) })
public class E2 {
   @Id
   @GeneratedValue
   private int id;

   @ManyToOne(optional = false, fetch = FetchType.LAZY)
   @JoinColumn(name = "e1", nullable = false, insertable = false, updatable = false)
   private E1 e1;

   public int getId() {
      return id;
   }

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

   public E1 getE1() {
      return e1;
   }

   public void setE1(E1 e1) {
      this.e1 = e1;
   }

}

Code between sessionFactory.openSession() and session.close():
Code:
      Session session = sessionFactory.openSession();
      Transaction transaction = session.beginTransaction();
      E1 e1 = new E1();
      e1.getE2s().add(new E2());
      session.save(e1);
      transaction.commit();
      session.close();
      session = sessionFactory.openSession();
      transaction = session.beginTransaction();
      e1 = (E1) session.get(E1.class, 1);
      e1.getE2s().add(new E2());
      session.update(e1);
      transaction.commit();
      session.close();

Full stack trace of any exception that occurs:
Code:
java.lang.ArrayIndexOutOfBoundsException: -1
   at java.util.ArrayList.set(ArrayList.java:339)
   at org.hibernate.collection.PersistentList.readFrom(PersistentList.java:386)
   at org.hibernate.loader.Loader.readCollectionElement(Loader.java:1008)
   at org.hibernate.loader.Loader.readCollectionElements(Loader.java:646)
   at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:591)
   at org.hibernate.loader.Loader.doQuery(Loader.java:701)
   at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
   at org.hibernate.loader.Loader.loadCollection(Loader.java:1994)
   at org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:36)
   at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:565)
   at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:63)
   at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1716)
   at org.hibernate.collection.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:344)
   at org.hibernate.collection.AbstractPersistentCollection.write(AbstractPersistentCollection.java:183)
   at org.hibernate.collection.PersistentList.add(PersistentList.java:140)
   at own.test.Run.run(Run.java:44)
   at own.test.Run.main(Run.java:17)

Name and version of the database you are using:
MySQL 5.0 or HSQL embedded

Debug level Hibernate log excerpt:

Code:
17:54:24,432 INFO  [Version] Hibernate Annotations 3.3.0.GA
17:54:24,448 INFO  [Environment] Hibernate 3.2.6
17:54:24,453 INFO  [Environment] hibernate.properties not found
17:54:24,457 INFO  [Environment] Bytecode provider name : cglib
17:54:24,463 INFO  [Environment] using JDK 1.4 java.sql.Timestamp handling
17:54:24,566 INFO  [Configuration] configuring from resource: /hibernate-hsql.cfg.xml
17:54:24,567 INFO  [Configuration] Configuration resource: /hibernate-hsql.cfg.xml
17:54:24,624 DEBUG [DTDEntityResolver] trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd]
17:54:24,625 DEBUG [DTDEntityResolver] recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
17:54:24,626 DEBUG [DTDEntityResolver] located [http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd] in classpath
17:54:24,663 DEBUG [Configuration] connection.url=jdbc:hsqldb:mem:testdb
17:54:24,664 DEBUG [Configuration] connection.driver_class=org.hsqldb.jdbcDriver
17:54:24,664 DEBUG [Configuration] connection.username=sa
17:54:24,664 DEBUG [Configuration] connection.password=
17:54:24,664 DEBUG [Configuration] connection.pool_size=12
17:54:24,664 DEBUG [Configuration] show_sql=true
17:54:24,664 DEBUG [Configuration] format_sql=true
17:54:24,664 DEBUG [Configuration] indent_sql=true
17:54:24,664 DEBUG [Configuration] hibernate.hbm2ddl.auto=create-drop
17:54:24,664 DEBUG [Configuration] hibernate.dialect=org.hibernate.dialect.HSQLDialect
17:54:24,670 DEBUG [Configuration] hibernate.cache.use_query_cache=false
17:54:24,670 DEBUG [Configuration] hibernate.cache.use_second_level_cache=false
17:54:24,670 INFO  [Configuration] Configured SessionFactory: null
17:54:24,671 DEBUG [Configuration] properties: {java.vendor=Apple Computer, Inc., show_sql=true, sun.java.launcher=SUN_STANDARD, hibernate.connection.url=jdbc:hsqldb:mem:testdb, sun.management.compiler=HotSpot Client Compiler, os.name=Mac OS X, sun.boot.class.path=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/classes.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/ui.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/laf.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/sunrsasign.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/jsse.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/jce.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/charsets.jar, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_13-b05-241, user.name=frank, awt.nativeDoubleBuffering=true, connection.driver_class=org.hsqldb.jdbcDriver, user.language=de, sun.boot.library.path=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Libraries, java.version=1.5.0_13, user.timezone=Europe/Berlin, sun.arch.data.model=32, java.endorsed.dirs=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home/lib/endorsed, sun.cpu.isalist=, sun.jnu.encoding=MacRoman, file.encoding.pkg=sun.io, file.separator=/, java.specification.name=Java Platform API Specification, hibernate.format_sql=true, java.class.version=49.0, user.country=DE, connection.url=jdbc:hsqldb:mem:testdb, java.home=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home, java.vm.info=mixed mode, hibernate.indent_sql=true, os.version=10.4.11, path.separator=:, connection.password=, java.vm.version=1.5.0_13-121, hibernate.connection.password=, java.awt.printerjob=apple.awt.CPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=apple.awt.CToolkit, hibernate.connection.username=sa, user.home=/Users/frank, java.specification.vendor=Sun Microsystems Inc., hibernate.hbm2ddl.auto=create-drop, java.library.path=.:/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java, java.vendor.url=http://apple.com/, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, connection.username=sa, java.vm.vendor="Apple Computer, Inc.", gopherProxySet=false, hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=/Users/frank/codebaseTest/hibernatetest/target/classes:/Users/frank/.m2/repository/antlr/antlr/2.7.6/antlr-2.7.6.jar:/Users/frank/.m2/repository/asm/asm-attrs/1.5.3/asm-attrs-1.5.3.jar:/Users/frank/.m2/repository/asm/asm/1.5.3/asm-1.5.3.jar:/Users/frank/.m2/repository/cglib/cglib/2.1_3/cglib-2.1_3.jar:/Users/frank/.m2/repository/commons-collections/commons-collections/2.1.1/commons-collections-2.1.1.jar:/Users/frank/.m2/repository/commons-logging/commons-logging/1.0.4/commons-logging-1.0.4.jar:/Users/frank/.m2/repository/dom4j/dom4j/1.6.1/dom4j-1.6.1.jar:/Users/frank/.m2/repository/findbugs/annotations/1.0.0/annotations-1.0.0.jar:/Users/frank/.m2/repository/hsqldb/hsqldb/1.8.0.7/hsqldb-1.8.0.7.jar:/Users/frank/.m2/repository/javax/persistence/persistence-api/1.0/persistence-api-1.0.jar:/Users/frank/.m2/repository/javax/transaction/jta/1.0.1B/jta-1.0.1B.jar:/Users/frank/.m2/repository/log4j/log4j/1.2.13/log4j-1.2.13.jar:/Users/frank/.m2/repository/mysql/mysql-connector-java/5.0.5/mysql-connector-java-5.0.5.jar:/Users/frank/.m2/repository/net/sf/ehcache/ehcache/1.2.3/ehcache-1.2.3.jar:/Users/frank/.m2/repository/org/hibernate/hibernate-annotations/3.3.0.ga/hibernate-annotations-3.3.0.ga.jar:/Users/frank/.m2/repository/org/hibernate/hibernate-commons-annotations/3.3.0.ga/hibernate-commons-annotations-3.3.0.ga.jar:/Users/frank/.m2/repository/org/hibernate/hibernate/3.2.6.ga/hibernate-3.2.6.ga.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/.compatibility/14compatibility.jar, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, hibernate.cache.use_query_cache=false, sun.cpu.endian=little, sun.os.patch.level=unknown, connection.pool_size=12, java.io.tmpdir=/tmp, java.vendor.url.bug=http://developer.apple.com/java/, os.arch=i386, java.awt.graphicsenv=apple.awt.CGraphicsEnvironment, java.ext.dirs=/Library/Java/Extensions:/System/Library/Java/Extensions:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home/lib/ext, mrj.version=1040.1.5.0_13-241, user.dir=/Users/frank/codebaseTest/hibernatetest, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, hibernate.cache.use_second_level_cache=false, file.encoding=UTF-8, format_sql=true, indent_sql=true, java.specification.version=1.5, hibernate.show_sql=true, hibernate.connection.pool_size=12}
17:54:24,679 DEBUG [AnnotationConfiguration] Validator not present in classpath, ignoring event listener registration
17:54:24,680 DEBUG [AnnotationConfiguration] Search not present in classpath, ignoring event listener registration
17:54:24,680 DEBUG [Configuration] Preparing to build session factory with filters : {}
17:54:24,680 DEBUG [AnnotationConfiguration] Execute first pass mapping processing
17:54:24,782 DEBUG [AnnotationConfiguration] Process hbm files
17:54:24,782 DEBUG [AnnotationConfiguration] Process annotated classes
17:54:24,787 INFO  [AnnotationBinder] Binding entity from annotated class: own.test.entities.E1
17:54:24,810 DEBUG [Ejb3Column] Binding column DTYPE unique false
17:54:24,832 DEBUG [EntityBinder] Import with entity name=E1
17:54:24,846 INFO  [EntityBinder] Bind entity own.test.entities.E1 on table E1
17:54:24,856 DEBUG [AnnotationBinder] Processing own.test.entities.E1 property annotation
17:54:24,878 DEBUG [AnnotationBinder] Processing own.test.entities.E1 field annotation
17:54:24,924 DEBUG [AnnotationBinder] Processing annotations of own.test.entities.E1.id
17:54:24,927 DEBUG [Ejb3Column] Binding column id unique false
17:54:24,927 DEBUG [AnnotationBinder] id is an id
17:54:24,930 DEBUG [SimpleValueBinder] building SimpleValue for id
17:54:24,933 DEBUG [PropertyBinder] Building property id
17:54:24,936 DEBUG [PropertyBinder] Cascading id with null
17:54:24,936 DEBUG [AnnotationBinder] Bind @Id on id
17:54:24,937 DEBUG [AnnotationBinder] Processing annotations of own.test.entities.E1.e2s
17:54:24,940 DEBUG [Ejb3Column] Binding column e1 unique false
17:54:24,940 DEBUG [Ejb3Column] Binding column e2s unique false
17:54:24,941 DEBUG [Ejb3Column] Binding column e1i unique false
17:54:24,968 DEBUG [Ejb3Column] Binding column element unique false
17:54:24,970 DEBUG [Ejb3Column] Binding column mapkey unique false
17:54:24,970 DEBUG [Ejb3Column] Binding column null unique false
17:54:24,972 DEBUG [Ejb3Column] Binding column null unique false
17:54:24,972 DEBUG [Ejb3Column] Binding column null unique false
17:54:24,975 DEBUG [CollectionBinder] Collection role: own.test.entities.E1.e2s
17:54:24,984 DEBUG [PropertyBinder] Building property e2s
17:54:24,984 DEBUG [PropertyBinder] Cascading e2s with all,delete-orphan
17:54:24,985 INFO  [AnnotationBinder] Binding entity from annotated class: own.test.entities.E2
17:54:24,986 DEBUG [Ejb3Column] Binding column DTYPE unique false
17:54:24,986 DEBUG [EntityBinder] Import with entity name=E2
17:54:24,986 INFO  [EntityBinder] Bind entity own.test.entities.E2 on table E2
17:54:24,986 DEBUG [AnnotationBinder] Processing own.test.entities.E2 property annotation
17:54:24,986 DEBUG [AnnotationBinder] Processing own.test.entities.E2 field annotation
17:54:24,993 DEBUG [AnnotationBinder] Processing annotations of own.test.entities.E2.id
17:54:24,994 DEBUG [Ejb3Column] Binding column id unique false
17:54:24,994 DEBUG [AnnotationBinder] id is an id
17:54:24,994 DEBUG [SimpleValueBinder] building SimpleValue for id
17:54:24,994 DEBUG [PropertyBinder] Building property id
17:54:24,994 DEBUG [PropertyBinder] Cascading id with null
17:54:24,994 DEBUG [AnnotationBinder] Bind @Id on id
17:54:24,994 DEBUG [AnnotationBinder] Processing annotations of own.test.entities.E2.e1
17:54:24,994 DEBUG [Ejb3Column] Binding column e1 unique false
17:54:24,994 DEBUG [Ejb3Column] Binding column e1 unique false
17:54:24,996 DEBUG [PropertyBinder] Building property e1
17:54:24,996 DEBUG [PropertyBinder] Cascading e1 with none
17:54:24,996 DEBUG [AnnotationConfiguration] processing manytoone fk mappings
17:54:25,085 DEBUG [Configuration] processing extends queue
17:54:25,085 DEBUG [Configuration] processing collection mappings
17:54:25,085 DEBUG [CollectionSecondPass] Second pass for collection: own.test.entities.E1.e2s
17:54:25,085 DEBUG [CollectionBinder] Binding a OneToMany: own.test.entities.E1.e2s through a foreign key
17:54:25,087 INFO  [CollectionBinder] Mapping collection: own.test.entities.E1.e2s -> E2
17:54:25,089 DEBUG [SimpleValueBinder] building SimpleValue for null
17:54:25,090 DEBUG [CollectionSecondPass] Mapped collection key: e1, index: e1i, one-to-many: own.test.entities.E2
17:54:25,090 DEBUG [Configuration] processing native query and ResultSetMapping mappings
17:54:25,090 DEBUG [Configuration] processing association property references
17:54:25,090 DEBUG [Configuration] processing foreign key constraints
17:54:25,090 DEBUG [Configuration] resolving reference to class: own.test.entities.E1
17:54:25,093 INFO  [AnnotationConfiguration] Hibernate Validator not found: ignoring
17:54:25,106 INFO  [DriverManagerConnectionProvider] Using Hibernate built-in connection pool (not for production use!)
17:54:25,106 INFO  [DriverManagerConnectionProvider] Hibernate connection pool size: 12
17:54:25,106 INFO  [DriverManagerConnectionProvider] autocommit mode: false
17:54:25,109 INFO  [DriverManagerConnectionProvider] using driver: org.hsqldb.jdbcDriver at URL: jdbc:hsqldb:mem:testdb
17:54:25,109 INFO  [DriverManagerConnectionProvider] connection properties: {user=sa, password=}
17:54:25,109 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
17:54:25,109 DEBUG [DriverManagerConnectionProvider] opening new JDBC connection
17:54:25,341 DEBUG [DriverManagerConnectionProvider] created connection to: jdbc:hsqldb:mem:testdb, Isolation Level: 2
17:54:25,372 INFO  [SettingsFactory] RDBMS: HSQL Database Engine, version: 1.8.0
17:54:25,372 INFO  [SettingsFactory] JDBC driver: HSQL Database Engine Driver, version: 1.8.0
17:54:25,373 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
17:54:25,401 INFO  [Dialect] Using dialect: org.hibernate.dialect.HSQLDialect
17:54:25,409 INFO  [TransactionFactoryFactory] Using default transaction strategy (direct JDBC transactions)
17:54:25,412 INFO  [TransactionManagerLookupFactory] No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
17:54:25,412 INFO  [SettingsFactory] Automatic flush during beforeCompletion(): disabled
17:54:25,412 INFO  [SettingsFactory] Automatic session close at end of transaction: disabled
17:54:25,412 INFO  [SettingsFactory] JDBC batch size: 15
17:54:25,413 INFO  [SettingsFactory] JDBC batch updates for versioned data: disabled
17:54:25,413 INFO  [SettingsFactory] Scrollable result sets: enabled
17:54:25,414 DEBUG [SettingsFactory] Wrap result sets: disabled
17:54:25,414 INFO  [SettingsFactory] JDBC3 getGeneratedKeys(): disabled
17:54:25,414 INFO  [SettingsFactory] Connection release mode: auto
17:54:25,414 INFO  [SettingsFactory] Default batch fetch size: 1
17:54:25,414 INFO  [SettingsFactory] Generate SQL with comments: disabled
17:54:25,414 INFO  [SettingsFactory] Order SQL updates by primary key: disabled
17:54:25,415 INFO  [SettingsFactory] Order SQL inserts for batching: disabled
17:54:25,415 INFO  [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
17:54:25,417 INFO  [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
17:54:25,417 INFO  [SettingsFactory] Query language substitutions: {}
17:54:25,417 INFO  [SettingsFactory] JPA-QL strict compliance: disabled
17:54:25,417 INFO  [SettingsFactory] Second-level cache: disabled
17:54:25,417 INFO  [SettingsFactory] Query cache: disabled
17:54:25,417 INFO  [SettingsFactory] Optimize cache for minimal puts: disabled
17:54:25,417 INFO  [SettingsFactory] Structured second-level cache entries: disabled
17:54:25,418 DEBUG [SQLExceptionConverterFactory] Using dialect defined converter
17:54:25,424 INFO  [SettingsFactory] Echoing all SQL to stdout
17:54:25,424 INFO  [SettingsFactory] Statistics: disabled
17:54:25,424 INFO  [SettingsFactory] Deleted entity synthetic identifier rollback: disabled
17:54:25,425 INFO  [SettingsFactory] Default entity-mode: pojo
17:54:25,425 INFO  [SettingsFactory] Named query checking : enabled
17:54:25,476 INFO  [SessionFactoryImpl] building session factory
17:54:25,477 DEBUG [SessionFactoryImpl] Session factory constructed with filter configurations : {}
17:54:25,480 DEBUG [SessionFactoryImpl] instantiating session factory with properties: {java.vendor=Apple Computer, Inc., show_sql=true, sun.java.launcher=SUN_STANDARD, hibernate.connection.url=jdbc:hsqldb:mem:testdb, sun.management.compiler=HotSpot Client Compiler, os.name=Mac OS X, sun.boot.class.path=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/classes.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/ui.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/laf.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/sunrsasign.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/jsse.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/jce.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/charsets.jar, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_13-b05-241, user.name=frank, awt.nativeDoubleBuffering=true, connection.driver_class=org.hsqldb.jdbcDriver, user.language=de, sun.boot.library.path=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Libraries, java.version=1.5.0_13, user.timezone=Europe/Berlin, sun.arch.data.model=32, java.endorsed.dirs=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home/lib/endorsed, sun.cpu.isalist=, sun.jnu.encoding=MacRoman, file.encoding.pkg=sun.io, file.separator=/, java.specification.name=Java Platform API Specification, hibernate.format_sql=true, java.class.version=49.0, user.country=DE, connection.url=jdbc:hsqldb:mem:testdb, java.home=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home, java.vm.info=mixed mode, hibernate.indent_sql=true, os.version=10.4.11, path.separator=:, connection.password=, java.vm.version=1.5.0_13-121, hibernate.connection.password=, java.awt.printerjob=apple.awt.CPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=apple.awt.CToolkit, hibernate.connection.username=sa, user.home=/Users/frank, java.specification.vendor=Sun Microsystems Inc., hibernate.hbm2ddl.auto=create-drop, java.library.path=.:/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java, java.vendor.url=http://apple.com/, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, connection.username=sa, java.vm.vendor="Apple Computer, Inc.", gopherProxySet=false, hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=/Users/frank/codebaseTest/hibernatetest/target/classes:/Users/frank/.m2/repository/antlr/antlr/2.7.6/antlr-2.7.6.jar:/Users/frank/.m2/repository/asm/asm-attrs/1.5.3/asm-attrs-1.5.3.jar:/Users/frank/.m2/repository/asm/asm/1.5.3/asm-1.5.3.jar:/Users/frank/.m2/repository/cglib/cglib/2.1_3/cglib-2.1_3.jar:/Users/frank/.m2/repository/commons-collections/commons-collections/2.1.1/commons-collections-2.1.1.jar:/Users/frank/.m2/repository/commons-logging/commons-logging/1.0.4/commons-logging-1.0.4.jar:/Users/frank/.m2/repository/dom4j/dom4j/1.6.1/dom4j-1.6.1.jar:/Users/frank/.m2/repository/findbugs/annotations/1.0.0/annotations-1.0.0.jar:/Users/frank/.m2/repository/hsqldb/hsqldb/1.8.0.7/hsqldb-1.8.0.7.jar:/Users/frank/.m2/repository/javax/persistence/persistence-api/1.0/persistence-api-1.0.jar:/Users/frank/.m2/repository/javax/transaction/jta/1.0.1B/jta-1.0.1B.jar:/Users/frank/.m2/repository/log4j/log4j/1.2.13/log4j-1.2.13.jar:/Users/frank/.m2/repository/mysql/mysql-connector-java/5.0.5/mysql-connector-java-5.0.5.jar:/Users/frank/.m2/repository/net/sf/ehcache/ehcache/1.2.3/ehcache-1.2.3.jar:/Users/frank/.m2/repository/org/hibernate/hibernate-annotations/3.3.0.ga/hibernate-annotations-3.3.0.ga.jar:/Users/frank/.m2/repository/org/hibernate/hibernate-commons-annotations/3.3.0.ga/hibernate-commons-annotations-3.3.0.ga.jar:/Users/frank/.m2/repository/org/hibernate/hibernate/3.2.6.ga/hibernate-3.2.6.ga.jar:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Classes/.compatibility/14compatibility.jar, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=unknown, hibernate.cache.use_query_cache=false, connection.pool_size=12, java.io.tmpdir=/tmp, java.vendor.url.bug=http://developer.apple.com/java/, os.arch=i386, java.awt.graphicsenv=apple.awt.CGraphicsEnvironment, java.ext.dirs=/Library/Java/Extensions:/System/Library/Java/Extensions:/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home/lib/ext, mrj.version=1040.1.5.0_13-241, user.dir=/Users/frank/codebaseTest/hibernatetest, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, hibernate.cache.use_second_level_cache=false, file.encoding=UTF-8, format_sql=true, indent_sql=true, java.specification.version=1.5, hibernate.connection.pool_size=12, hibernate.show_sql=true}
17:54:25,793 DEBUG [AbstractEntityPersister] Static SQL for entity: own.test.entities.E2
17:54:25,793 DEBUG [AbstractEntityPersister]  Version select: select id from E2 where id =?
17:54:25,793 DEBUG [AbstractEntityPersister]  Snapshot select: select e2x_.id from E2 e2x_ where e2x_.id=?
17:54:25,793 DEBUG [AbstractEntityPersister]  Insert 0: insert into E2 (e1, e1i, id) values (?, ?, ?)
17:54:25,793 DEBUG [AbstractEntityPersister]  Update 0: null
17:54:25,794 DEBUG [AbstractEntityPersister]  Delete 0: delete from E2 where id=?
17:54:25,794 DEBUG [AbstractEntityPersister]  Identity insert: insert into E2 (id, e1, e1i) values (null, ?, ?)
17:54:25,804 DEBUG [AbstractEntityPersister] Static SQL for entity: own.test.entities.E1
17:54:25,805 DEBUG [AbstractEntityPersister]  Version select: select id from E1 where id =?
17:54:25,805 DEBUG [AbstractEntityPersister]  Snapshot select: select e1x_.id from E1 e1x_ where e1x_.id=?
17:54:25,805 DEBUG [AbstractEntityPersister]  Insert 0: insert into E1 (id) values (?)
17:54:25,805 DEBUG [AbstractEntityPersister]  Update 0: null
17:54:25,805 DEBUG [AbstractEntityPersister]  Delete 0: delete from E1 where id=?
17:54:25,805 DEBUG [AbstractEntityPersister]  Identity insert: insert into E1 (id) values (null)
17:54:25,815 DEBUG [AbstractCollectionPersister] Static SQL for collection: own.test.entities.E1.e2s
17:54:25,815 DEBUG [AbstractCollectionPersister]  Row insert: update E2 set e1=?, e1i=? where id=?
17:54:25,815 DEBUG [AbstractCollectionPersister]  Row delete: update E2 set e1=null, e1i=null where e1=? and id=?
17:54:25,815 DEBUG [AbstractCollectionPersister]  One-shot delete: update E2 set e1=null, e1i=null where e1=?
17:54:25,844 DEBUG [EntityLoader] Static select for entity own.test.entities.E2: select e2x0_.id as id1_0_, e2x0_.e1 as e2_1_0_ from E2 e2x0_ where e2x0_.id=?
17:54:25,844 DEBUG [EntityLoader] Static select for entity own.test.entities.E2: select e2x0_.id as id1_0_, e2x0_.e1 as e2_1_0_ from E2 e2x0_ where e2x0_.id=?
17:54:25,844 DEBUG [EntityLoader] Static select for entity own.test.entities.E2: select e2x0_.id as id1_0_, e2x0_.e1 as e2_1_0_ from E2 e2x0_ where e2x0_.id=?
17:54:25,845 DEBUG [EntityLoader] Static select for entity own.test.entities.E2: select e2x0_.id as id1_0_, e2x0_.e1 as e2_1_0_ from E2 e2x0_ where e2x0_.id=?
17:54:25,845 DEBUG [EntityLoader] Static select for entity own.test.entities.E2: select e2x0_.id as id1_0_, e2x0_.e1 as e2_1_0_ from E2 e2x0_ where e2x0_.id=?
17:54:25,859 DEBUG [EntityLoader] Static select for action ACTION_MERGE on entity own.test.entities.E2: select e2x0_.id as id1_0_, e2x0_.e1 as e2_1_0_ from E2 e2x0_ where e2x0_.id=?
17:54:25,859 DEBUG [EntityLoader] Static select for action ACTION_REFRESH on entity own.test.entities.E2: select e2x0_.id as id1_0_, e2x0_.e1 as e2_1_0_ from E2 e2x0_ where e2x0_.id=?
17:54:25,859 DEBUG [EntityLoader] Static select for entity own.test.entities.E1: select e1x0_.id as id0_0_ from E1 e1x0_ where e1x0_.id=?
17:54:25,860 DEBUG [EntityLoader] Static select for entity own.test.entities.E1: select e1x0_.id as id0_0_ from E1 e1x0_ where e1x0_.id=?
17:54:25,860 DEBUG [EntityLoader] Static select for entity own.test.entities.E1: select e1x0_.id as id0_0_ from E1 e1x0_ where e1x0_.id=?
17:54:25,860 DEBUG [EntityLoader] Static select for entity own.test.entities.E1: select e1x0_.id as id0_0_ from E1 e1x0_ where e1x0_.id=?
17:54:25,860 DEBUG [EntityLoader] Static select for entity own.test.entities.E1: select e1x0_.id as id0_0_ from E1 e1x0_ where e1x0_.id=?
17:54:25,867 DEBUG [EntityLoader] Static select for action ACTION_MERGE on entity own.test.entities.E1: select e1x0_.id as id0_1_, e2s1_.e1 as e2_3_, e2s1_.id as id3_, e2s1_.e1i as e3_3_, e2s1_.id as id1_0_, e2s1_.e1 as e2_1_0_ from E1 e1x0_ left outer join E2 e2s1_ on e1x0_.id=e2s1_.e1 where e1x0_.id=?
17:54:25,868 DEBUG [EntityLoader] Static select for action ACTION_REFRESH on entity own.test.entities.E1: select e1x0_.id as id0_1_, e2s1_.e1 as e2_3_, e2s1_.id as id3_, e2s1_.e1i as e3_3_, e2s1_.id as id1_0_, e2s1_.e1 as e2_1_0_ from E1 e1x0_ left outer join E2 e2s1_ on e1x0_.id=e2s1_.e1 where e1x0_.id=?
17:54:25,873 DEBUG [OneToManyLoader] Static select for one-to-many own.test.entities.E1.e2s: select e2s0_.e1 as e2_1_, e2s0_.id as id1_, e2s0_.e1i as e3_1_, e2s0_.id as id1_0_, e2s0_.e1 as e2_1_0_ from E2 e2s0_ where e2s0_.e1=?
17:54:25,876 DEBUG [SessionFactoryObjectFactory] initializing class SessionFactoryObjectFactory
17:54:25,877 DEBUG [SessionFactoryObjectFactory] registered: 4028e48b196c8b1901196c8b1ad10000 (unnamed)
17:54:25,877 INFO  [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
17:54:25,877 DEBUG [SessionFactoryImpl] instantiated session factory
17:54:25,882 DEBUG [AnnotationConfiguration] Execute first pass mapping processing
17:54:25,882 DEBUG [AnnotationConfiguration] Process hbm files
17:54:25,882 DEBUG [AnnotationConfiguration] Process annotated classes
17:54:25,882 DEBUG [AnnotationConfiguration] processing manytoone fk mappings
17:54:25,882 DEBUG [Configuration] processing extends queue
17:54:25,883 DEBUG [Configuration] processing collection mappings
17:54:25,883 DEBUG [Configuration] processing native query and ResultSetMapping mappings
17:54:25,883 DEBUG [Configuration] processing association property references
17:54:25,883 DEBUG [Configuration] processing foreign key constraints
17:54:25,883 DEBUG [Configuration] resolving reference to class: own.test.entities.E1
17:54:25,883 INFO  [AnnotationConfiguration] Hibernate Validator not found: ignoring
17:54:25,884 DEBUG [AnnotationConfiguration] Execute first pass mapping processing
17:54:25,884 DEBUG [AnnotationConfiguration] Process hbm files
17:54:25,884 DEBUG [AnnotationConfiguration] Process annotated classes
17:54:25,884 DEBUG [AnnotationConfiguration] processing manytoone fk mappings
17:54:25,884 DEBUG [Configuration] processing extends queue
17:54:25,884 DEBUG [Configuration] processing collection mappings
17:54:25,884 DEBUG [Configuration] processing native query and ResultSetMapping mappings
17:54:25,884 DEBUG [Configuration] processing association property references
17:54:25,884 DEBUG [Configuration] processing foreign key constraints
17:54:25,884 DEBUG [Configuration] resolving reference to class: own.test.entities.E1
17:54:25,885 INFO  [AnnotationConfiguration] Hibernate Validator not found: ignoring
17:54:25,886 INFO  [SchemaExport] Running hbm2ddl schema export
17:54:25,886 DEBUG [SchemaExport] import file not found: /import.sql
17:54:25,886 INFO  [SchemaExport] exporting generated schema to database
17:54:25,886 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
17:54:25,886 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
17:54:25,887 DEBUG [SchemaExport]
    alter table E2
        drop constraint FK88DC594F851
17:54:25,890 DEBUG [SchemaExport] Unsuccessful: alter table E2 drop constraint FK88DC594F851
17:54:25,890 DEBUG [SchemaExport] Table not found: E2 in statement [alter table E2]
17:54:25,890 DEBUG [SchemaExport]
    drop table E1 if exists
17:54:25,891 DEBUG [SchemaExport]
    drop table E2 if exists
17:54:25,891 DEBUG [SchemaExport]
    create table E1 (
        id integer generated by default as identity (start with 1),
        primary key (id)
    )
17:54:25,895 DEBUG [SchemaExport]
    create table E2 (
        id integer generated by default as identity (start with 1),
        e1 integer not null,
        e1i integer not null,
        primary key (id),
        unique (e1, e1i)
    )
17:54:25,907 DEBUG [SchemaExport]
    alter table E2
        add constraint FK88DC594F851
        foreign key (e1)
        references E1
17:54:25,907 INFO  [SchemaExport] schema export complete
17:54:25,909 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
17:54:25,909 DEBUG [AnnotationConfiguration] Execute first pass mapping processing
17:54:25,909 DEBUG [AnnotationConfiguration] Process hbm files
17:54:25,909 DEBUG [AnnotationConfiguration] Process annotated classes
17:54:25,909 DEBUG [AnnotationConfiguration] processing manytoone fk mappings
17:54:25,909 DEBUG [Configuration] processing extends queue
17:54:25,910 DEBUG [Configuration] processing collection mappings
17:54:25,910 DEBUG [Configuration] processing native query and ResultSetMapping mappings
17:54:25,910 DEBUG [Configuration] processing association property references
17:54:25,910 DEBUG [Configuration] processing foreign key constraints
17:54:25,910 DEBUG [Configuration] resolving reference to class: own.test.entities.E1
17:54:25,910 INFO  [AnnotationConfiguration] Hibernate Validator not found: ignoring
17:54:25,911 DEBUG [AnnotationConfiguration] Execute first pass mapping processing
17:54:25,911 DEBUG [AnnotationConfiguration] Process hbm files
17:54:25,911 DEBUG [AnnotationConfiguration] Process annotated classes
17:54:25,911 DEBUG [AnnotationConfiguration] processing manytoone fk mappings
17:54:25,911 DEBUG [Configuration] processing extends queue
17:54:25,911 DEBUG [Configuration] processing collection mappings
17:54:25,911 DEBUG [Configuration] processing native query and ResultSetMapping mappings
17:54:25,911 DEBUG [Configuration] processing association property references
17:54:25,911 DEBUG [Configuration] processing foreign key constraints
17:54:25,911 DEBUG [Configuration] resolving reference to class: own.test.entities.E1
17:54:25,912 INFO  [AnnotationConfiguration] Hibernate Validator not found: ignoring
17:54:25,912 DEBUG [SessionFactoryImpl] Checking 0 named HQL queries
17:54:25,912 DEBUG [SessionFactoryImpl] Checking 0 named SQL queries
17:54:25,962 DEBUG [SessionImpl] opened session at timestamp: 12087068659
17:54:25,964 DEBUG [JDBCTransaction] begin
17:54:25,964 DEBUG [ConnectionManager] opening JDBC connection
17:54:25,964 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
17:54:25,964 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
17:54:25,964 DEBUG [JDBCTransaction] current autocommit status: false
17:54:25,964 DEBUG [JDBCContext] after transaction begin
17:54:25,967 DEBUG [DefaultSaveOrUpdateEventListener] saving transient instance
17:54:25,968 DEBUG [AbstractSaveEventListener] saving [own.test.entities.E1#<null>]
17:54:25,968 DEBUG [AbstractSaveEventListener] executing insertions
17:54:25,977 DEBUG [Cascade] processing cascade ACTION_SAVE_UPDATE for: own.test.entities.E1
17:54:25,977 DEBUG [Cascade] done processing cascade ACTION_SAVE_UPDATE for: own.test.entities.E1
17:54:25,987 DEBUG [WrapVisitor] Wrapped collection in role: own.test.entities.E1.e2s
17:54:25,993 DEBUG [AbstractSaveEventListener] executing identity-insert immediately
17:54:25,993 DEBUG [AbstractEntityPersister] Inserting entity: own.test.entities.E1 (native id)
17:54:25,994 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:54:25,997 DEBUG [SQL]
    insert
    into
        E1
        (id)
    values
        (null)
Hibernate:
    insert
    into
        E1
        (id)
    values
        (null)
17:54:25,997 DEBUG [AbstractBatcher] preparing statement
17:54:26,003 DEBUG [AbstractEntityPersister] Dehydrating entity: [own.test.entities.E1#<null>]
17:54:26,009 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:54:26,009 DEBUG [AbstractBatcher] closing statement
17:54:26,009 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:54:26,009 DEBUG [SQL]
    call identity()
Hibernate:
    call identity()
17:54:26,009 DEBUG [AbstractBatcher] preparing statement
17:54:26,010 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 1
17:54:26,010 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:54:26,010 DEBUG [AbstractBatcher] closing statement
17:54:26,017 DEBUG [Cascade] processing cascade ACTION_SAVE_UPDATE for: own.test.entities.E1
17:54:26,017 DEBUG [Cascade] cascade ACTION_SAVE_UPDATE for collection: own.test.entities.E1.e2s
17:54:26,019 DEBUG [CascadingAction] cascading to saveOrUpdate: own.test.entities.E2
17:54:26,023 DEBUG [IdentifierValue] id unsaved-value: 0
17:54:26,023 DEBUG [AbstractSaveEventListener] transient instance of: own.test.entities.E2
17:54:26,024 DEBUG [DefaultSaveOrUpdateEventListener] saving transient instance
17:54:26,024 DEBUG [AbstractSaveEventListener] saving [own.test.entities.E2#<null>]
17:54:26,024 DEBUG [AbstractSaveEventListener] executing insertions
17:54:26,025 DEBUG [AbstractSaveEventListener] executing identity-insert immediately
17:54:26,025 DEBUG [AbstractEntityPersister] Inserting entity: own.test.entities.E2 (native id)
17:54:26,025 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:54:26,025 DEBUG [SQL]
    insert
    into
        E2
        (id, e1, e1i)
    values
        (null, ?, ?)
Hibernate:
    insert
    into
        E2
        (id, e1, e1i)
    values
        (null, ?, ?)
17:54:26,025 DEBUG [AbstractBatcher] preparing statement
17:54:26,026 DEBUG [AbstractEntityPersister] Dehydrating entity: [own.test.entities.E2#<null>]
17:54:26,026 DEBUG [IntegerType] binding '1' to parameter: 1
17:54:26,026 DEBUG [IntegerType] binding '0' to parameter: 2
17:54:26,026 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:54:26,026 DEBUG [AbstractBatcher] closing statement
17:54:26,026 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:54:26,027 DEBUG [SQL]
    call identity()
Hibernate:
    call identity()
17:54:26,027 DEBUG [AbstractBatcher] preparing statement
17:54:26,027 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 1
17:54:26,027 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:54:26,027 DEBUG [AbstractBatcher] closing statement
17:54:26,027 DEBUG [Cascade] done cascade ACTION_SAVE_UPDATE for collection: own.test.entities.E1.e2s
17:54:26,027 DEBUG [Cascade] deleting orphans for collection: own.test.entities.E1.e2s
17:54:26,029 DEBUG [Cascade] done deleting orphans for collection: own.test.entities.E1.e2s
17:54:26,029 DEBUG [Cascade] done processing cascade ACTION_SAVE_UPDATE for: own.test.entities.E1
17:54:26,029 DEBUG [JDBCTransaction] commit
17:54:26,029 DEBUG [SessionImpl] automatically flushing session
17:54:26,029 DEBUG [AbstractFlushingEventListener] flushing session
17:54:26,030 DEBUG [AbstractFlushingEventListener] processing flush-time cascades
17:54:26,030 DEBUG [Cascade] processing cascade ACTION_SAVE_UPDATE for: own.test.entities.E1
17:54:26,030 DEBUG [Cascade] cascade ACTION_SAVE_UPDATE for collection: own.test.entities.E1.e2s
17:54:26,030 DEBUG [CascadingAction] cascading to saveOrUpdate: own.test.entities.E2
17:54:26,030 DEBUG [AbstractSaveEventListener] persistent instance of: own.test.entities.E2
17:54:26,030 DEBUG [DefaultSaveOrUpdateEventListener] ignoring persistent instance
17:54:26,030 DEBUG [DefaultSaveOrUpdateEventListener] object already associated with session: [own.test.entities.E2#1]
17:54:26,030 DEBUG [Cascade] done cascade ACTION_SAVE_UPDATE for collection: own.test.entities.E1.e2s
17:54:26,030 DEBUG [Cascade] deleting orphans for collection: own.test.entities.E1.e2s
17:54:26,030 DEBUG [Cascade] done deleting orphans for collection: own.test.entities.E1.e2s
17:54:26,030 DEBUG [Cascade] done processing cascade ACTION_SAVE_UPDATE for: own.test.entities.E1
17:54:26,030 DEBUG [AbstractFlushingEventListener] dirty checking collections
17:54:26,031 DEBUG [AbstractFlushingEventListener] Flushing entities and processing referenced collections
17:54:26,035 DEBUG [Collections] Collection found: [own.test.entities.E1.e2s#1], was: [<unreferenced>] (initialized)
17:54:26,035 DEBUG [AbstractFlushingEventListener] Processing unreferenced collections
17:54:26,036 DEBUG [AbstractFlushingEventListener] Scheduling collection removes/(re)creates/updates
17:54:26,038 DEBUG [AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 2 objects
17:54:26,038 DEBUG [AbstractFlushingEventListener] Flushed: 1 (re)creations, 0 updates, 0 removals to 1 collections
17:54:26,039 DEBUG [Printer] listing entities:
17:54:26,039 DEBUG [Printer] own.test.entities.E2{e1=null, id=1}
17:54:26,039 DEBUG [Printer] own.test.entities.E1{e2s=[own.test.entities.E2#1], id=1}
17:54:26,039 DEBUG [AbstractFlushingEventListener] executing flush
17:54:26,039 DEBUG [ConnectionManager] registering flush begin
17:54:26,040 DEBUG [ConnectionManager] registering flush end
17:54:26,040 DEBUG [AbstractFlushingEventListener] post flush
17:54:26,041 DEBUG [JDBCContext] before transaction completion
17:54:26,041 DEBUG [SessionImpl] before transaction completion
17:54:26,041 DEBUG [JDBCTransaction] committed JDBC Connection
17:54:26,041 DEBUG [JDBCContext] after transaction completion
17:54:26,041 DEBUG [ConnectionManager] aggressively releasing JDBC connection
17:54:26,041 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17:54:26,041 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
17:54:26,041 DEBUG [SessionImpl] after transaction completion
17:54:26,041 DEBUG [SessionImpl] closing session
17:54:26,041 DEBUG [ConnectionManager] connection already null in cleanup : no action
17:54:26,043 DEBUG [SessionImpl] opened session at timestamp: 12087068660
17:54:26,043 DEBUG [JDBCTransaction] begin
17:54:26,043 DEBUG [ConnectionManager] opening JDBC connection
17:54:26,043 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
17:54:26,043 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
17:54:26,043 DEBUG [JDBCTransaction] current autocommit status: false
17:54:26,043 DEBUG [JDBCContext] after transaction begin
17:54:26,044 DEBUG [DefaultLoadEventListener] loading entity: [own.test.entities.E1#1]
17:54:26,044 DEBUG [DefaultLoadEventListener] attempting to resolve: [own.test.entities.E1#1]
17:54:26,045 DEBUG [DefaultLoadEventListener] object not resolved in any cache: [own.test.entities.E1#1]
17:54:26,045 DEBUG [AbstractEntityPersister] Fetching entity: [own.test.entities.E1#1]
17:54:26,045 DEBUG [Loader] loading entity: [own.test.entities.E1#1]
17:54:26,048 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:54:26,048 DEBUG [SQL]
    select
        e1x0_.id as id0_0_
    from
        E1 e1x0_
    where
        e1x0_.id=?
Hibernate:
    select
        e1x0_.id as id0_0_
    from
        E1 e1x0_
    where
        e1x0_.id=?
17:54:26,048 DEBUG [AbstractBatcher] preparing statement
17:54:26,053 DEBUG [IntegerType] binding '1' to parameter: 1
17:54:26,054 DEBUG [AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
17:54:26,054 DEBUG [Loader] processing result set
17:54:26,054 DEBUG [Loader] result set row: 0
17:54:26,055 DEBUG [Loader] result row: EntityKey[own.test.entities.E1#1]
17:54:26,055 DEBUG [Loader] Initializing object from ResultSet: [own.test.entities.E1#1]
17:54:26,061 DEBUG [AbstractEntityPersister] Hydrating entity: [own.test.entities.E1#1]
17:54:26,061 DEBUG [Loader] done processing result set (1 rows)
17:54:26,061 DEBUG [AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
17:54:26,062 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:54:26,062 DEBUG [AbstractBatcher] closing statement
17:54:26,064 DEBUG [Loader] total objects hydrated: 1
17:54:26,064 DEBUG [TwoPhaseLoad] resolving associations for [own.test.entities.E1#1]
17:54:26,066 DEBUG [LoadContexts] creating collection wrapper:[own.test.entities.E1.e2s#1]
17:54:26,066 DEBUG [TwoPhaseLoad] done materializing entity [own.test.entities.E1#1]
17:54:26,066 DEBUG [StatefulPersistenceContext] initializing non-lazy collections
17:54:26,066 DEBUG [Loader] done entity load
17:54:26,068 DEBUG [DefaultInitializeCollectionEventListener] initializing collection [own.test.entities.E1.e2s#1]
17:54:26,069 DEBUG [DefaultInitializeCollectionEventListener] checking second-level cache
17:54:26,069 DEBUG [DefaultInitializeCollectionEventListener] collection not cached
17:54:26,069 DEBUG [Loader] loading collection: [own.test.entities.E1.e2s#1]
17:54:26,069 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:54:26,071 DEBUG [SQL]
    select
        e2s0_.e1 as e2_1_,
        e2s0_.id as id1_,
        e2s0_.e1i as e3_1_,
        e2s0_.id as id1_0_,
        e2s0_.e1 as e2_1_0_
    from
        E2 e2s0_
    where
        e2s0_.e1=?
Hibernate:
    select
        e2s0_.e1 as e2_1_,
        e2s0_.id as id1_,
        e2s0_.e1i as e3_1_,
        e2s0_.id as id1_0_,
        e2s0_.e1 as e2_1_0_
    from
        E2 e2s0_
    where
        e2s0_.e1=?
17:54:26,073 DEBUG [AbstractBatcher] preparing statement
17:54:26,074 DEBUG [IntegerType] binding '1' to parameter: 1
17:54:26,074 DEBUG [AbstractBatcher] about to open ResultSet (open ResultSets: 0, globally: 0)
17:54:26,074 DEBUG [Loader] result set contains (possibly empty) collection: [own.test.entities.E1.e2s#1]
17:54:26,075 DEBUG [LoadContexts] constructing collection load context for result set [org.hsqldb.jdbc.jdbcResultSet@1da1f8]
17:54:26,078 DEBUG [CollectionLoadContext] starting attempt to find loading collection [[own.test.entities.E1.e2s#1]]
17:54:26,078 DEBUG [CollectionLoadContext] collection not yet initialized; initializing
17:54:26,079 DEBUG [Loader] processing result set
17:54:26,079 DEBUG [Loader] result set row: 0
17:54:26,079 DEBUG [IntegerType] returning '1' as column: id1_0_
17:54:26,080 DEBUG [Loader] result row: EntityKey[own.test.entities.E2#1]
17:54:26,080 DEBUG [Loader] Initializing object from ResultSet: [own.test.entities.E2#1]
17:54:26,080 DEBUG [AbstractEntityPersister] Hydrating entity: [own.test.entities.E2#1]
17:54:26,080 DEBUG [IntegerType] returning '1' as column: e2_1_0_
17:54:26,081 DEBUG [IntegerType] returning '1' as column: e2_1_
17:54:26,081 DEBUG [Loader] found row of collection: [own.test.entities.E1.e2s#1]
17:54:26,081 DEBUG [CollectionLoadContext] starting attempt to find loading collection [[own.test.entities.E1.e2s#1]]
17:54:26,083 DEBUG [LoadContexts] attempting to locate loading collection entry [CollectionKey[own.test.entities.E1.e2s#1]] in any result-set context
17:54:26,083 DEBUG [LoadContexts] collection [CollectionKey[own.test.entities.E1.e2s#1]] located in load context
17:54:26,083 DEBUG [CollectionLoadContext] found loading collection bound to current result set processing; reading row
17:54:26,083 DEBUG [IntegerType] returning '1' as column: id1_
17:54:26,083 DEBUG [DefaultLoadEventListener] loading entity: [own.test.entities.E2#1]
17:54:26,083 DEBUG [DefaultLoadEventListener] attempting to resolve: [own.test.entities.E2#1]
17:54:26,084 DEBUG [DefaultLoadEventListener] resolved object in session cache: [own.test.entities.E2#1]
17:54:26,084 DEBUG [IntegerType] returning '0' as column: e3_1_
17:54:26,084 DEBUG [AbstractBatcher] about to close ResultSet (open ResultSets: 1, globally: 1)
17:54:26,084 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:54:26,084 DEBUG [AbstractBatcher] closing statement
java.lang.ArrayIndexOutOfBoundsException: -1
   at java.util.ArrayList.set(ArrayList.java:339)
   at org.hibernate.collection.PersistentList.readFrom(PersistentList.java:386)
   at org.hibernate.loader.Loader.readCollectionElement(Loader.java:1008)
   at org.hibernate.loader.Loader.readCollectionElements(Loader.java:646)
   at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:591)
   at org.hibernate.loader.Loader.doQuery(Loader.java:701)
   at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
   at org.hibernate.loader.Loader.loadCollection(Loader.java:1994)
   at org.hibernate.loader.collection.CollectionLoader.initialize(CollectionLoader.java:36)
   at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:565)
   at org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:63)
   at org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1716)
   at org.hibernate.collection.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:344)
   at org.hibernate.collection.AbstractPersistentCollection.write(AbstractPersistentCollection.java:183)
   at org.hibernate.collection.PersistentList.add(PersistentList.java:140)
   at own.test.Run.run(Run.java:44)
   at own.test.Run.main(Run.java:17)


If someone want to play with it, I provide a ready to use maven2-example under: it-blogger.com/examples/hibernate.zip

I would post it on JIRA, but I'm not sure if it is a hibernate core or hibernate annotations problem.

The problem occurs on both databases and if you switch the base-value to zero, no exception will throw.


Top
 Profile  
 
 Post subject:
PostPosted: Sun Apr 20, 2008 12:00 pm 
Newbie

Joined: Tue Aug 15, 2006 5:49 am
Posts: 4
To direct download the example:
http://www.it-blogger.com/examples/hibernate.zip


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.