Hibernate StackOverflowError: bidirectional many-to-many

[Brian Kuhn]

I have two objects to persist; Account and Role. Account has a String username, a String password and a Set of Roles. Role has a String name, and a Set of Accounts. Hibernate creates a join table called accountroles to manage the Sets' many-to-many relationship. Everything works fine; Hibernate generates the correct SQL as far as I can tell. I inserted intermediate commits at each step just to make sure. On the last commit, I get a java.lang.StackOverflowError. I assume this has something to do with the bidirectional nature of the relationship. I must be getting an infinite loop of recursion or something. Any idea what I did wrong?

Thanks!

Hibernate version:
version 3.0.2 , 27.04.2005

Config file:

hibernate.cfg.xml (no hibernate.properties)
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE hibernate-configuration PUBLIC
    "-//Hibernate/Hibernate Configuration DTD//EN"
    "http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd">
 
<hibernate-configuration>
 
    <session-factory>
       
        <property name="show_sql">true</property>
       
        <property name="dialect">org.hibernate.dialect.HSQLDialect</property>
        <property name="connection.driver_class">org.hsqldb.jdbcDriver</property>
        <property name="connection.url">jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb</property>
        <property name="connection.username">sa</property>
        <property name="connection.password"></property>
       
        <property name="c3p0.min_size">5</property>
        <property name="c3p0.max_size">20</property>       
        <property name="c3p0.timeout">300</property>
        <property name="c3p0.max_statements">50</property>
        <property name="c3p0.idle_test_period">3000</property>
 
        <mapping resource="Account.hbm.xml"/>
        <mapping resource="Role.hbm.xml"/>
 
    </session-factory>
 
</hibernate-configuration>

Mapping documents:
Account.hbm.xml

<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE hibernate-mapping PUBLIC
    "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
    "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">         
 
<hibernate-mapping
    package="com.briankuhn.demo.hibernate.simple">
 
    <class name="Account">
        <id name="id">
            <generator class="hilo"/>
        </id>
        <property name="username" not-null="true"/>
        <property name="password" not-null="true"/>
        <set name="roles" table="accountroles">
            <key column="account_id"/>
            <many-to-many column="role_id" class="Role"/>
        </set>
    </class>
 
</hibernate-mapping>

Role.hbm.xml

<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE hibernate-mapping PUBLIC
      "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
      "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">
 
<hibernate-mapping
    package="com.briankuhn.demo.hibernate.simple">
 
    <class name="Role">
        <id name="id">
            <generator class="hilo"/>
        </id>
        <property name="name" not-null="true"/>
        <set name="accounts" table="accountroles" inverse="true">
            <key column="role_id"/>
            <many-to-many column="account_id" class="Account"/>
        </set>
    </class>
 
</hibernate-mapping>

Code between sessionFactory.openSession() and session.close():

       Session session = sessionFactory.openSession();
        Transaction transaction = null;   
        try {
            transaction = session.beginTransaction();   
           
            Account account = new Account();
            account.setUsername("briankuhn");
            account.setPassword("hibernate");
            session.persist(account);
            transaction.commit();   //Works fine...
           
            Role userRole = new Role();
            userRole.setName("user");
            session.persist(userRole);
            transaction.commit();   //Works fine...
           
            Role adminRole = new Role();
            adminRole.setName("admin");
            session.persist(adminRole);
            transaction.commit();  //Works fine...
           
            Set accounts = new HashSet();
            accounts.add(account);
            userRole.setAccounts(accounts);
            adminRole.setAccounts(accounts);
           
            Set roles = new HashSet();
            roles.add(userRole);
            roles.add(adminRole);           
            account.setRoles(roles);
           
            transaction.commit();  //StackOverflowError here
        }
        catch (Throwable t) {
            t.printStackTrace();
            if (transaction != null) {
                transaction.rollback();
            }   
        }
        finally {
            session.close();
        }

Schema-export.sql:

alter table accountroles drop constraint FK421758B09D5D27B4;
alter table accountroles drop constraint FK421758B0672A82A0;
drop table Account if exists;
drop table Role if exists;
drop table accountroles if exists;
drop table hibernate_unique_key if exists;
create table Account (
   id bigint not null,
   username varchar(255) not null,
   password varchar(255) not null,
   primary key (id)
);
create table Role (
   id bigint not null,
   name varchar(255) not null,
   primary key (id)
);
create table accountroles (
   account_id bigint not null,
   role_id bigint not null,
   primary key (account_id, role_id)
);
alter table accountroles add constraint FK421758B09D5D27B4 foreign key (role_id) references Role;
alter table accountroles add constraint FK421758B0672A82A0 foreign key (account_id) references Account;
create table hibernate_unique_key (
    next_hi integer
);
insert into hibernate_unique_key values ( 0 );

Full stack trace of any exception that occurs:
java.lang.StackOverflowError (that's it)


Name and version of the database you are using:
hsqldb_1_7_3_3


The generated SQL (show_sql=true):

Hibernate: insert into Account (username, password, id) values (?, ?, ?)
Hibernate: insert into Role (name, id) values (?, ?)
Hibernate: insert into Role (name, id) values (?, ?)
Hibernate: insert into accountroles (account_id, role_id) values (?, ?)
Hibernate: insert into accountroles (account_id, role_id) values (?, ?)

Debug level Hibernate log excerpt:

[java] 22:33:52,164 INFO Environment:464 - Hibernate 3.0.2
[java] 22:33:52,174 INFO Environment:477 - hibernate.properties not found
[java] 22:33:52,184 INFO Environment:510 - using CGLIB reflection optimizer
[java] 22:33:52,184 INFO Environment:540 - using JDK 1.4 java.sql.Timestamp handling
[java] 22:33:52,254 INFO Configuration:1160 - configuring from resource: /hibernate.cfg.xml
[java] 22:33:52,254 INFO Configuration:1131 - Configuration resource: /hibernate.cfg.xml
[java] 22:33:52,534 DEBUG DTDEntityResolver:42 - trying to locate <a href="http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd" target="_blank" rel="nofollow">http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd</a> in classpath under org/hibernate/
[java] 22:33:52,534 DEBUG DTDEntityResolver:53 - found <a href="http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd" target="_blank" rel="nofollow">http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd</a> in classpath
[java] 22:33:52,584 DEBUG Configuration:1117 - show_sql=true
[java] 22:33:52,584 DEBUG Configuration:1117 - dialect=org.hibernate.dialect.HSQLDialect
[java] 22:33:52,584 DEBUG Configuration:1117 - connection.driver_class=org.hsqldb.jdbcDriver
[java] 22:33:52,584 DEBUG Configuration:1117 - connection.url=jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb
[java] 22:33:52,584 DEBUG Configuration:1117 - connection.username=sa
[java] 22:33:52,584 DEBUG Configuration:1117 - connection.password=
[java] 22:33:52,584 DEBUG Configuration:1117 - c3p0.min_size=5
[java] 22:33:52,584 DEBUG Configuration:1117 - c3p0.max_size=20
[java] 22:33:52,584 DEBUG Configuration:1117 - c3p0.timeout=300
[java] 22:33:52,594 DEBUG Configuration:1117 - c3p0.max_statements=50
[java] 22:33:52,594 DEBUG Configuration:1117 - c3p0.idle_test_period=3000
[java] 22:33:52,594 DEBUG Configuration:1312 - null<-org.dom4j.tree.DefaultAttribute@4fce71 [Attribute: name resource value "Account.hbm.xml"]
[java] 22:33:52,594 INFO Configuration:441 - Mapping resource: Account.hbm.xml
[java] 22:33:52,604 DEBUG DTDEntityResolver:42 - trying to locate <a href="http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" target="_blank" rel="nofollow">http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd</a> in classpath under org/hibernate/
[java] 22:33:52,604 DEBUG DTDEntityResolver:53 - found <a href="http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" target="_blank" rel="nofollow">http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd</a> in classpath
[java] 22:33:52,725 INFO HbmBinder:258 - Mapping class: com.briankuhn.demo.hibernate.simple.Account -> Account
[java] 22:33:52,745 DEBUG HbmBinder:1089 - Mapped property: id -> id
[java] 22:33:52,755 DEBUG HbmBinder:1089 - Mapped property: username -> username
[java] 22:33:52,755 DEBUG HbmBinder:1089 - Mapped property: password -> password
[java] 22:33:52,765 INFO HbmBinder:1202 - Mapping collection: com.briankuhn.demo.hibernate.simple.Account.roles -> accountroles
[java] 22:33:52,765 DEBUG HbmBinder:1089 - Mapped property: roles
[java] 22:33:52,765 DEBUG Configuration:1312 - null<-org.dom4j.tree.DefaultAttribute@13adc56 [Attribute: name resource value "Role.hbm.xml"]
[java] 22:33:52,765 INFO Configuration:441 - Mapping resource: Role.hbm.xml
[java] 22:33:52,765 DEBUG DTDEntityResolver:42 - trying to locate <a href="http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" target="_blank" rel="nofollow">http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd</a> in classpath under org/hibernate/
[java] 22:33:52,775 DEBUG DTDEntityResolver:53 - found <a href="http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" target="_blank" rel="nofollow">http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd</a> in classpath
[java] 22:33:52,805 INFO HbmBinder:258 - Mapping class: com.briankuhn.demo.hibernate.simple.Role -> Role
[java] 22:33:52,815 DEBUG HbmBinder:1089 - Mapped property: id -> id
[java] 22:33:52,815 DEBUG HbmBinder:1089 - Mapped property: name -> name
[java] 22:33:52,815 INFO HbmBinder:1202 - Mapping collection: com.briankuhn.demo.hibernate.simple.Role.accounts -> accountroles
[java] 22:33:52,815 DEBUG HbmBinder:1089 - Mapped property: accounts
[java] 22:33:52,815 INFO Configuration:1272 - Configured SessionFactory: null
[java] 22:33:52,815 DEBUG Configuration:1273 - properties: {java.vendor=Sun Microsystems Inc., show_sql=true, hibernate.connection.url=jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb, c3p0.min_size=5, os.name=Windows XP, sun.boot.class.path=C:\j2sdk1.4.2_05\jre\lib\rt.jar;C:\j2sdk1.4.2_05\jre\lib\i18n.jar;C:\j2sdk1.4.2_05\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2_05\jre\lib\jsse.jar;C:\j2sdk1.4.2_05\jre\lib\jce.jar;C:\j2sdk1.4.2_05\jre\lib\charsets.jar;C:\j2sdk1.4.2_05\jre\classes, hibernate.c3p0.max_size=20, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., c3p0.max_size=20, java.runtime.version=1.4.2_05-b04, hibernate.c3p0.min_size=5, user.name=brian, connection.driver_class=org.hsqldb.jdbcDriver, hibernate.c3p0.timeout=300,user.language=en, sun.boot.library.path=C:\j2sdk1.4.2_05\jre\bin, dialect=org.hibernate.dialect.HSQLDialect, java.version=1.4.2_05, user.timezone=America/Los_Angeles, sun.arch.data.model=32, java.endorsed.dirs=C:\j2sdk1.4.2_05\jre\lib\endorsed, sun.cpu.isalist=pentium i486 i386, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=US, connection.url=jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb, java.home=C:\j2sdk1.4.2_05\jre, java.vm.info=mixed mode, os.version=5.1, c3p0.idle_test_period=3000, path.separator=;, connection.password=, java.vm.version=1.4.2_05-b04, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, user.home=C:\Documents and Settings\brian, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\j2sdk1.4.2_05\jre\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Java\jdk1.5.0_01\bin;C:\Program Files\ATI Technologies\ATI Control Panel;C:\Program Files\Common Files\Adaptec Shared\System;C:\Program Files\UltraEdit;C:\Program Files\Java\jdk1.5.0_01\bin;C:\j2sdk1.4.2_05\bin;c:\ant\bin;"C:\Documents and Settings\brian\My Documents\bin", java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\bin;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\antlr-2.7.5H3.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\asm-attrs.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\asm.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\c3p0-0.8.5.2.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\cglib-2.1.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\commons-collections-2.1.1.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\commons-logging-1.0.4.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\dom4j-1.6.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\ehcache-1.1.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\hibernate3.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\hsqldb.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\jta.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\log4j-1.2.8.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\xerces-2.6.2.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\xml-apis.jar, c3p0.timeout=300, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 2, java.io.tmpdir=C:\DOCUME~1\brian\LOCALS~1\Temp\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\j2sdk1.4.2_05\jre\lib\ext, user.dir=C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo, hibernate.c3p0.idle_test_period=3000, line.separator=
[java] , java.vm.name=Java HotSpot(TM) Client VM, file.encoding=Cp1252, java.specification.version=1.4, c3p0.max_statements=50, hibernate.show_sql=true, hibernate.c3p0.max_statements=50}
[java] 22:33:52,815 DEBUG Configuration:1048 - Preparing to build session factory with filters : {}
[java] 22:33:52,825 INFO Configuration:852 - processing extends queue
[java] 22:33:52,825 INFO Configuration:856 - processing collection mappings
[java] 22:33:52,825 DEBUG HbmBinder:2390 - Second pass for collection: com.briankuhn.demo.hibernate.simple.Account.roles
[java] 22:33:52,895 DEBUG HbmBinder:2406 - Mapped collection key: account_id, element: role_id
[java] 22:33:52,895 DEBUG HbmBinder:2390 - Second pass for collection: com.briankuhn.demo.hibernate.simple.Role.accounts
[java] 22:33:52,895 DEBUG HbmBinder:2406 - Mapped collection key: role_id, element: account_id
[java] 22:33:52,895 INFO Configuration:865 - processing association property references
[java] 22:33:52,895 INFO Configuration:894 - processing foreign key constraints
[java] 22:33:52,895 DEBUG Configuration:941 - resolving reference to class: com.briankuhn.demo.hibernate.simple.Role
[java] 22:33:52,895 DEBUG Configuration:941 - resolving reference to class: com.briankuhn.demo.hibernate.simple.Account
[java] 22:33:52,905 INFO C3P0ConnectionProvider:50 - C3P0 using driver: org.hsqldb.jdbcDriver at URL: jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb
[java] 22:33:52,905 INFO C3P0ConnectionProvider:51 - Connection properties: {user=sa, password=****}
[java] 22:33:52,905 INFO C3P0ConnectionProvider:54 - autocommit mode: false
[java] Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@12d96f2 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@1dd3812 [ acquireIncrement -> 1, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxIdleTime -> 300, maxPoolSize -> 20, maxStatements -> 50, maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@1833eca [ description -> null, driverClass ->null, factoryClassLocation -> null, jdbcUrl -> jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb, properties -> {user=******, password=******} ] , preferredTestQuery -> null, propertyCycle -> 300, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies -> false ] , factoryClassLocation -> null, numHelperThreads -> 3, poolOwnerIdentityToken -> 12d96f2 ]
[java] 22:33:53,376 INFO SettingsFactory:71 - RDBMS: HSQL Database Engine, version: 1.7.1
[java] 22:33:53,376 INFO SettingsFactory:72 - JDBC driver: HSQL Database Engine Driver, version: 1.7.1
[java] 22:33:53,396 INFO Dialect:92 - Using dialect: org.hibernate.dialect.HSQLDialect
[java] 22:33:53,396 INFO SettingsFactory:130 - Scrollable result sets: enabled
[java] 22:33:53,396 DEBUG SettingsFactory:134 - Wrap result sets: disabled
[java] 22:33:53,396 INFO SettingsFactory:138 - JDBC3 getGeneratedKeys(): disabled
[java] 22:33:53,396 INFO SettingsFactory:150 - Aggressive release : disabled
[java] 22:33:53,396 INFO SettingsFactory:166 - Default batch fetch size: 1
[java] 22:33:53,396 INFO SettingsFactory:170 - Generate SQL with comments: disabled
[java] 22:33:53,396 INFO SettingsFactory:174 - Order SQL updates by primary key: disabled
[java] 22:33:53,396 INFO SettingsFactory:312 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
[java] 22:33:53,406 INFO ASTQueryTranslatorFactory:21 - Using ASTQueryTranslatorFactory
[java] 22:33:53,406 INFO SettingsFactory:182 - Query language substitutions: {}
[java] 22:33:53,406 INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions)
[java] 22:33:53,416 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
[java] 22:33:53,416 INFO SettingsFactory:191 - Automatic flush during beforeCompletion(): disabled
[java] 22:33:53,416 INFO SettingsFactory:195 - Automatic session close at end of transaction: disabled
[java] 22:33:53,416 INFO SettingsFactory:201 - Second-level cache: enabled
[java] 22:33:53,416 INFO SettingsFactory:205 - Query cache: disabled
[java] 22:33:53,426 INFO SettingsFactory:299 - Cache provider: org.hibernate.cache.EhCacheProvider
[java] 22:33:53,426 INFO SettingsFactory:220 - Optimize cache for minimal puts: disabled
[java] 22:33:53,426 INFO SettingsFactory:229 - Structured second-level cache entries: enabled
[java] 22:33:53,436 DEBUG SQLExceptionConverterFactory:52 - Using dialect defined converter
[java] 22:33:53,436 INFO SettingsFactory:249 - Echoing all SQL to stdout
[java] 22:33:53,436 INFO SettingsFactory:253 - Statistics: disabled
[java] 22:33:53,436 INFO SettingsFactory:257 - Deleted entity synthetic identifier rollback: disabled
[java] 22:33:53,446 INFO SettingsFactory:271 - Default entity-mode: pojo
[java] 22:33:53,596 INFO SessionFactoryImpl:148 - building session factory
[java] 22:33:53,596 DEBUG SessionFactoryImpl:157 - Session factory constructed with filter configurations : {}
[java] 22:33:53,596 DEBUG SessionFactoryImpl:160 - instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=true, hibernate.connection.url=jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb, c3p0.min_size=5, os.name=Windows XP, sun.boot.class.path=C:\j2sdk1.4.2_05\jre\lib\rt.jar;C:\j2sdk1.4.2_05\jre\lib\i18n.jar;C:\j2sdk1.4.2_05\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2_05\jre\lib\jsse.jar;C:\j2sdk1.4.2_05\jre\lib\jce.jar;C:\j2sdk1.4.2_05\jre\lib\charsets.jar;C:\j2sdk1.4.2_05\jre\classes, hibernate.c3p0.max_size=20, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., c3p0.max_size=20, java.runtime.version=1.4.2_05-b04, hibernate.c3p0.min_size=5, user.name=brian, connection.driver_class=org.hsqldb.jdbcDriver, hibernate.c3p0.timeout=300, user.language=en, sun.boot.library.path=C:\j2sdk1.4.2_05\jre\bin, dialect=org.hibernate.dialect.HSQLDialect, java.version=1.4.2_05, user.timezone=America/Los_Angeles, sun.arch.data.model=32, java.endorsed.dirs=C:\j2sdk1.4.2_05\jre\lib\endorsed, sun.cpu.isalist=pentium i486 i386, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=US, connection.url=jdbc:hsqldb:/C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo/data/hsqldb, java.home=C:\j2sdk1.4.2_05\jre, java.vm.info=mixed mode, os.version=5.1, c3p0.idle_test_period=3000, path.separator=;, connection.password=, java.vm.version=1.4.2_05-b04, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, user.home=C:\Documents and Settings\brian, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\j2sdk1.4.2_05\jre\bin;.;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\Java\jdk1.5.0_01\bin;C:\Program Files\ATI Technologies\ATI Control Panel;C:\Program Files\Common Files\Adaptec Shared\System;C:\Program Files\UltraEdit;C:\Program Files\Java\jdk1.5.0_01\bin;C:\j2sdk1.4.2_05\bin;c:\ant\bin;"C:\Documents and Settings\brian\My Documents\bin", java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\bin;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\antlr-2.7.5H3.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\asm-attrs.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\asm.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\c3p0-0.8.5.2.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\cglib-2.1.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\commons-collections-2.1.1.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\commons-logging-1.0.4.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\dom4j-1.6.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\ehcache-1.1.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\hibernate3.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\hsqldb.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\jta.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\log4j-1.2.8.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\xerces-2.6.2.jar;C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo\lib\xml-apis.jar, c3p0.timeout=300, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 2, java.io.tmpdir=C:\DOCUME~1\brian\LOCALS~1\Temp\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\j2sdk1.4.2_05\jre\lib\ext, user.dir=C:\Documents and Settings\brian\Desktop\Simple Hibernate Demo, hibernate.c3p0.idle_test_period=3000, line.separator=
[java] , java.vm.name=Java HotSpot(TM) Client VM, file.encoding=Cp1252, java.specification.version=1.4, c3p0.max_statements=50, hibernate.show_sql=true, hibernate.c3p0.max_statements=50}
[java] 22:33:53,606 DEBUG CacheManager:191 - Creating new CacheManager with default config
[java] 22:33:53,606 DEBUG CacheManager:164 - Configuring ehcache from classpath.
[java] 22:33:53,616 WARN Configurator:126 - No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/C:/Documents%20and%20Settings/brian/Desktop/Simple%20Hibernate%20Demo/lib/ehcache-1.1.jar!/ehcache-failsafe.xml
[java] 22:33:53,626 DEBUG Configuration$DiskStore:185 - Disk Store Path: C:\DOCUME~1\brian\LOCALS~1\Temp\
[java] 22:33:53,946 DEBUG BasicEntityPersister:2210 - Static SQL for entity: com.briankuhn.demo.hibernate.simple.Account
[java] 22:33:53,946 DEBUG BasicEntityPersister:2212 - Version select: select id from Account where id =?
[java] 22:33:53,946 DEBUG BasicEntityPersister:2213 - Snapshot select: select account_.id, account_.username as username0_, account_.password as password0_ from Account account_ where account_.id=?
[java] 22:33:53,946 DEBUG BasicEntityPersister:2215 - Insert 0: insert into Account (username, password, id) values (?, ?, ?)
[java] 22:33:53,956 DEBUG BasicEntityPersister:2216 - Update 0: update Account set username=?, password=? where id=?
[java] 22:33:53,956 DEBUG BasicEntityPersister:2217 - Delete 0: delete from Account where id=?
[java] 22:33:53,986 DEBUG BasicEntityPersister:2210 - Static SQL for entity: com.briankuhn.demo.hibernate.simple.Role
[java] 22:33:53,986 DEBUG BasicEntityPersister:2212 - Version select: select id from Role where id =?
[java] 22:33:53,986 DEBUG BasicEntityPersister:2213 - Snapshot select: select role_.id, role_.name as name2_ from Role role_ where role_.id=?
[java] 22:33:53,986 DEBUG BasicEntityPersister:2215 - Insert 0: insert into Role (name, id) values (?, ?)
[java] 22:33:53,986 DEBUG BasicEntityPersister:2216 - Update 0: update Role set name=? where id=?
[java] 22:33:53,986 DEBUG BasicEntityPersister:2217 - Delete 0: delete from Role where id=?
[java] 22:33:53,996 DEBUG AbstractCollectionPersister:474 - Static SQL for collection: com.briankuhn.demo.hibernate.simple.Role.accounts
[java] 22:33:53,996 DEBUG AbstractCollectionPersister:475 - Row insert: insert into accountroles (role_id, account_id) values (?, ?)
[java] 22:33:53,996 DEBUG AbstractCollectionPersister:476 - Row update: update accountroles set account_id=? where role_id=? and account_id=?
[java] 22:33:53,996 DEBUG AbstractCollectionPersister:477 - Row delete: delete from accountroles where role_id=? and account_id=?
[java] 22:33:53,996 DEBUG AbstractCollectionPersister:478 - One-shot delete: delete from accountroles where role_id=?
[java] 22:33:54,006 DEBUG AbstractCollectionPersister:474 - Static SQL for collection: com.briankuhn.demo.hibernate.simple.Account.roles
[java] 22:33:54,006 DEBUG AbstractCollectionPersister:475 - Row insert: insert into accountroles (account_id, role_id) values (?, ?)
[java] 22:33:54,006 DEBUG AbstractCollectionPersister:476 - Row update: update accountroles set role_id=? where account_id=? and role_id=?
[java] 22:33:54,006 DEBUG AbstractCollectionPersister:477 - Row delete: delete from accountroles where account_id=? and role_id=?
[java] 22:33:54,006 DEBUG AbstractCollectionPersister:478 - One-shot delete: delete from accountroles where account_id=?
[java] 22:33:54,026 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Account: select account0_.id as id0_, account0_.username as username0_0_, account0_.password as password0_0_ from Account account0_ where account0_.id=
[java] 22:33:54,026 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Account: select account0_.id as id0_, account0_.username as username0_0_, account0_.password as password0_0_ from Account account0_ where account0_.id=?
[java] 22:33:54,026 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Account: select account0_.id as id0_, account0_.username as username0_0_, account0_.password as password0_0_ from Account account0_ where account0_.id=?
[java] 22:33:54,036 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Account: select account0_.id as id0_, account0_.username as username0_0_, account0_.password as password0_0_ from Account account0_ where account0_.id=?
[java] 22:33:54,036 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Role: select role0_.id as id0_, role0_.name as name2_0_ from Role role0_ where role0_.id=?
[java] 22:33:54,036 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Role: select role0_.id as id0_, role0_.name as name2_0_ from Role role0_ where role0_.id=?
[java] 22:33:54,036 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Role: select role0_.id as id0_, role0_.name as name2_0_ from Role role0_ where role0_.id=?
[java] 22:33:54,036 DEBUG EntityLoader:120 - Static select for entity com.briankuhn.demo.hibernate.simple.Role: select role0_.id as id0_, role0_.name as name2_0_ from Role role0_ where role0_.id=? [java] 22:33:54,047 DEBUG CollectionLoader:74 - Static select for collection com.briankuhn.demo.hibernate.simple.Role.accounts: select accounts0_.role_id as role2___, accounts0_.account_id as account1___, account1_.id as id0_, account1_.username as username0_0_, account1_.password as password0_0_ from accountroles accounts0_ inner join Account account1_ on accounts0_.account_id=account1_.id where accounts0_.role_id=?
[java] 22:33:54,047 DEBUG CollectionLoader:74 - Static select for collection com.briankuhn.demo.hibernate.simple.Account.roles: select roles0_.account_id as account1___, roles0_.role_id as role2___, role1_.id as id0_, role1_.name as name2_0_ from accountroles roles0_ inner join Role role1_ on roles0_.role_id=role1_.id where roles0_.account_id=?
[java] 22:33:54,047 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
[java] 22:33:54,057 DEBUG SessionFactoryObjectFactory:76 - registered: 402881e503cf65030103cf6505ff0000 (unnamed)
[java] 22:33:54,057 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
[java] 22:33:54,057 DEBUG SessionFactoryImpl:257 - instantiated session factory
[java] 22:33:54,057 INFO SessionFactoryImpl:374 - Checking 0 named queries
[java] 22:33:54,087 DEBUG SessionImpl:237 - opened session at timestamp: 4570628235497472
[java] 22:33:54,087 DEBUG JDBCTransaction:46 - begin
[java] 22:33:54,097 DEBUG AbstractBatcher:422 - opening JDBC connection
[java] 22:33:54,097 DEBUG JDBCTransaction:50 - current autocommit status: false
[java] 22:33:54,097 DEBUG AbstractSaveEventListener:409 - transient instance of: com.briankuhn.demo.hibernate.simple.Account
[java] 22:33:54,097 DEBUG DefaultPersistEventListener:117 - saving transient instance
[java] 22:33:54,107 DEBUG AbstractBatcher:422 - opening JDBC connection
[java] 22:33:54,107 DEBUG SQL:130 - select next_hi from hibernate_unique_key
[java] 22:33:54,157 DEBUG SQL:151 - update hibernate_unique_key set next_hi = ? where next_hi = ?
[java] 22:33:54,157 DEBUG AbstractBatcher:437 - closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
[java] 22:33:54,167 DEBUG TableHiLoGenerator:64 - new hi value: 0
[java] 22:33:54,167 DEBUG AbstractSaveEventListener:89 - generated identifier: 1, using strategy: org.hibernate.id.TableHiLoGenerator
[java] 22:33:54,167 DEBUG AbstractSaveEventListener:132 - saving [com.briankuhn.demo.hibernate.simple.Account#1]
[java] 22:33:54,187 DEBUG JDBCTransaction:83 - commit
[java] 22:33:54,187 DEBUG SessionImpl:308 - automatically flushing session
[java] 22:33:54,187 DEBUG AbstractFlushingEventListener:52 - flushing session
[java] 22:33:54,187 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
[java] 22:33:54,187 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
[java] 22:33:54,187 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
[java] 22:33:54,197 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
[java] 22:33:54,197 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
[java] 22:33:54,197 DEBUG AbstractFlushingEventListener:79 - Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
[java] 22:33:54,197 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[java] 22:33:54,197 DEBUG Printer:83 - listing entities:
[java] 22:33:54,197 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Account{password=hibernate, username=briankuhn, roles=null, id=1}
[java] 22:33:54,197 DEBUG AbstractFlushingEventListener:267 - executing flush
[java] 22:33:54,197 DEBUG BasicEntityPersister:1815 - Inserting entity: [com.briankuhn.demo.hibernate.simple.Account#1]
[java] 22:33:54,197 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[java] 22:33:54,197 DEBUG SQL:311 - insert into Account (username, password, id) values (?, ?, ?)
[java] Hibernate: insert into Account (username, password, id) values (?, ?, ?)
[java] 22:33:54,197 DEBUG AbstractBatcher:365 - preparing statement
[java] 22:33:54,207 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.briankuhn.demo.hibernate.simple.Account#1]
[java] 22:33:54,207 DEBUG StringType:59 - binding 'briankuhn' to parameter: 1
[java] 22:33:54,207 DEBUG StringType:59 - binding 'hibernate' to parameter: 2
[java] 22:33:54,207 DEBUG LongType:59 - binding '1' to parameter: 3
[java] 22:33:54,207 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[java] 22:33:54,207 DEBUG AbstractBatcher:403 - closing statement
[java] 22:33:54,207 DEBUG AbstractFlushingEventListener:294 - post flush
[java] 22:33:54,207 DEBUG JDBCContext:216 - before transaction completion
[java] 22:33:54,207 DEBUG SessionImpl:353 - before transaction completion
[java] 22:33:54,207 DEBUG JDBCTransaction:96 - committed JDBC Connection
[java] 22:33:54,207 DEBUG JDBCContext:221 - after transaction completion
[java] 22:33:54,207 DEBUG SessionImpl:369 - after transaction completion
[java] 22:33:54,207 DEBUG AbstractSaveEventListener:409 - transient instance of: com.briankuhn.demo.hibernate.simple.Role
[java] 22:33:54,217 DEBUG DefaultPersistEventListener:117 - saving transient instance
[java] 22:33:54,217 DEBUG AbstractBatcher:422 - opening JDBC connection
[java] 22:33:54,217 DEBUG SQL:130 - select next_hi from hibernate_unique_key
[java] 22:33:54,217 DEBUG SQL:151 - update hibernate_unique_key set next_hi = ? where next_hi = ?
[java] 22:33:54,217 DEBUG AbstractBatcher:437 - closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
[java] 22:33:54,227 DEBUG TableHiLoGenerator:64 - new hi value: 1
[java] 22:33:54,227 DEBUG AbstractSaveEventListener:89 - generated identifier: 32768, using strategy: org.hibernate.id.TableHiLoGenerator
[java] 22:33:54,227 DEBUG AbstractSaveEventListener:132 - saving [com.briankuhn.demo.hibernate.simple.Role#32768]
[java] 22:33:54,227 DEBUG JDBCTransaction:83 - commit
[java] 22:33:54,227 DEBUG SessionImpl:308 - automatically flushing session
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:52 - flushing session
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:79 - Flushed: 1 insertions, 0 updates, 0 deletions to 2 objects
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[java] 22:33:54,227 DEBUG Printer:83 - listing entities:
[java] 22:33:54,227 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Account{password=hibernate, username=briankuhn, roles=null, id=1}
[java] 22:33:54,227 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Role{accounts=null, name=user, id=32768}
[java] 22:33:54,227 DEBUG AbstractFlushingEventListener:267 - executing flush
[java] 22:33:54,227 DEBUG BasicEntityPersister:1815 - Inserting entity: [com.briankuhn.demo.hibernate.simple.Role#32768]
[java] 22:33:54,227 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[java] 22:33:54,237 DEBUG SQL:311 - insert into Role (name, id) values (?, ?)
[java] Hibernate: insert into Role (name, id) values (?, ?)
[java] 22:33:54,237 DEBUG AbstractBatcher:365 - preparing statement
[java] 22:33:54,237 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.briankuhn.demo.hibernate.simple.Role#32768]
[java] 22:33:54,237 DEBUG StringType:59 - binding 'user' to parameter: 1
[java] 22:33:54,237 DEBUG LongType:59 - binding '32768' to parameter: 2
[java] 22:33:54,237 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[java] 22:33:54,237 DEBUG AbstractBatcher:403 - closing statement
[java] 22:33:54,237 DEBUG AbstractFlushingEventListener:294 - post flush
[java] 22:33:54,237 DEBUG JDBCContext:216 - before transaction completion
[java] 22:33:54,237 DEBUG SessionImpl:353 - before transaction completion
[java] 22:33:54,237 DEBUG JDBCTransaction:96 - committed JDBC Connection
[java] 22:33:54,237 DEBUG JDBCContext:221 - after transaction completion
[java] 22:33:54,237 DEBUG SessionImpl:369 - after transaction completion
[java] 22:33:54,237 DEBUG AbstractSaveEventListener:409 - transient instance of: com.briankuhn.demo.hibernate.simple.Role
[java] 22:33:54,247 DEBUG DefaultPersistEventListener:117 - saving transient instance
[java] 22:33:54,247 DEBUG AbstractSaveEventListener:89 - generated identifier: 32769, using strategy: org.hibernate.id.TableHiLoGenerator
[java] 22:33:54,247 DEBUG AbstractSaveEventListener:132 - saving [com.briankuhn.demo.hibernate.simple.Role#32769]
[java] 22:33:54,247 DEBUG JDBCTransaction:83 - commit
[java] 22:33:54,247 DEBUG SessionImpl:308 - automatically flushing session
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:52 - flushing session
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:79 - Flushed: 1 insertions, 0 updates, 0 deletions to 3 objects
[java] 22:33:54,247 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[java] 22:33:54,247 DEBUG Printer:83 - listing entities:
[java] 22:33:54,247 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Account{password=hibernate, username=briankuhn, roles=null, id=1}
[java] 22:33:54,247 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Role{accounts=null, name=admin, id=32769}
[java] 22:33:54,247 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Role{accounts=null, name=user, id=32768}
[java] 22:33:54,257 DEBUG AbstractFlushingEventListener:267 - executing flush
[java] 22:33:54,257 DEBUG BasicEntityPersister:1815 - Inserting entity: [com.briankuhn.demo.hibernate.simple.Role#32769]
[java] 22:33:54,257 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[java] 22:33:54,257 DEBUG SQL:311 - insert into Role (name, id) values (?, ?)
[java] Hibernate: insert into Role (name, id) values (?, ?)
[java] 22:33:54,257 DEBUG AbstractBatcher:365 - preparing statement
[java] 22:33:54,257 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.briankuhn.demo.hibernate.simple.Role#32769]
[java] 22:33:54,257 DEBUG StringType:59 - binding 'admin' to parameter: 1
[java] 22:33:54,257 DEBUG LongType:59 - binding '32769' to parameter: 2
[java] 22:33:54,257 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[java] 22:33:54,257 DEBUG AbstractBatcher:403 - closing statement
[java] 22:33:54,257 DEBUG AbstractFlushingEventListener:294 - post flush
[java] 22:33:54,257 DEBUG JDBCContext:216 - before transaction completion
[java] 22:33:54,257 DEBUG SessionImpl:353 - before transaction completion
[java] 22:33:54,257 DEBUG JDBCTransaction:96 - committed JDBC Connection
[java] 22:33:54,267 DEBUG JDBCContext:221 - after transaction completion
[java] 22:33:54,267 DEBUG SessionImpl:369 - after transaction completion
[java] 22:33:54,267 DEBUG JDBCTransaction:83 - commit
[java] 22:33:54,267 DEBUG SessionImpl:308 - automatically flushing session
[java] 22:33:54,267 DEBUG AbstractFlushingEventListener:52 - flushing session
[java] 22:33:54,267 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
[java] 22:33:54,267 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
[java] 22:33:54,267 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
[java] 22:33:54,277 DEBUG WrapVisitor:86 - Wrapped collection in role: com.briankuhn.demo.hibernate.simple.Account.roles
[java] 22:33:54,277 DEBUG Collections:140 - Collection found: [com.briankuhn.demo.hibernate.simple.Account.roles#1], was: [<unreferenced>] (initialized)
[java] 22:33:54,277 DEBUG WrapVisitor:86 - Wrapped collection in role: com.briankuhn.demo.hibernate.simple.Role.accounts
[java] 22:33:54,277 DEBUG Collections:140 - Collection found: [com.briankuhn.demo.hibernate.simple.Role.accounts#32768], was: [<unreferenced>] (initialized)
[java] 22:33:54,277 DEBUG WrapVisitor:86 - Wrapped collection in role: com.briankuhn.demo.hibernate.simple.Role.accounts
[java] 22:33:54,277 DEBUG Collections:140 - Collection found: [com.briankuhn.demo.hibernate.simple.Role.accounts#32769], was: [<unreferenced>] (initialized)
[java] 22:33:54,277 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
[java] 22:33:54,277 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
[java] 22:33:54,287 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
[java] 22:33:54,287 DEBUG AbstractFlushingEventListener:85 - Flushed: 3 (re)creations, 0 updates, 0 removals to 3 collections
[java] 22:33:54,287 DEBUG Printer:83 - listing entities:
[java] 22:33:54,287 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Account{password=hibernate, username=briankuhn, roles=[com.briankuhn.demo.hibernate.simple.Role#32768, com.briankuhn.demo.hibernate.simple.Role#32769], id=1}
[java] 22:33:54,287 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Role{accounts=[com.briankuhn.demo.hibernate.simple.Account#1], name=admin, id=32769}
[java] 22:33:54,287 DEBUG Printer:90 - com.briankuhn.demo.hibernate.simple.Role{accounts=[com.briankuhn.demo.hibernate.simple.Account#1], name=user, id=32768}
[java] 22:33:54,287 DEBUG AbstractFlushingEventListener:267 - executing flush
[java] 22:33:54,287 DEBUG AbstractCollectionPersister:852 - Inserting collection: [com.briankuhn.demo.hibernate.simple.Account.roles#1]
[java] 22:33:54,287 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[java] 22:33:54,287 DEBUG SQL:311 - insert into accountroles (account_id, role_id) values (?, ?)
[java] Hibernate: insert into accountroles (account_id, role_id) values (?, ?)
[java] 22:33:54,297 DEBUG AbstractBatcher:365 - preparing statement
[java] 22:33:54,297 DEBUG LongType:59 - binding '1' to parameter: 1
[java] 22:33:54,297 DEBUG LongType:59 - binding '32768' to parameter: 2
[java] 22:33:54,297 DEBUG AbstractBatcher:152 - reusing prepared statement
[java] 22:33:54,297 DEBUG SQL:311 - insert into accountroles (account_id, role_id) values (?, ?)
[java] Hibernate: insert into accountroles (account_id, role_id) values (?, ?)
[java] 22:33:54,297 DEBUG LongType:59 - binding '1' to parameter: 1
[java] 22:33:54,297 DEBUG LongType:59 - binding '32769' to parameter: 2
[java] 22:33:54,297 DEBUG AbstractCollectionPersister:895 - done inserting collection: 2 rows inserted
[java] 22:33:54,297 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[java] 22:33:54,297 DEBUG AbstractBatcher:403 - closing statement
[java] 22:33:54,297 DEBUG AbstractFlushingEventListener:294 - post flush
[java] java.lang.StackOverflowError
[java] 22:33:54,317 DEBUG JDBCTransaction:124 - rollback
[java] 22:33:54,317 DEBUG JDBCContext:216 - before transaction completion
[java] 22:33:54,317 DEBUG SessionImpl:353 - before transaction completion
[java] 22:33:54,317 DEBUG JDBCTransaction:135 - rolled back JDBC Connection
[java] 22:33:54,317 DEBUG JDBCContext:221 - after transaction completion
[java] 22:33:54,317 DEBUG SessionImpl:369 - after transaction completion
[java] 22:33:54,317 DEBUG SessionImpl:254 - closing session
[java] 22:33:54,317 DEBUG AbstractBatcher:437 - closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
[java] 22:33:54,317 DEBUG JDBCContext:221 - after transaction completion
[java] 22:33:54,317 DEBUG SessionImpl:369 - after transaction completion
[java] 22:33:54,317 INFO SessionFactoryImpl:756 - closing 

[Brian Kuhn]

I almost forgot to mention, the above code uses the same instance of HashSet for userRole and adminRole.

The following code gave me the exact same result:

Set userAccounts = new HashSet();
userAccounts.add(account);
userRole.setAccounts(userAccounts);
 
Set adminAccounts = new HashSet();
adminAccounts.add(account);
adminRole.setAccounts(adminAccounts); 

I also tried out this project with MySQL 3.0.16 and had the same problem.

In case anyone wants to try this out, I've published the project at:
SimpleHibernateDemo.zip

[Brian Kuhn]

I don't know why my last reply shows up blank, but I also wanted to mention:

The above code uses the same instance of HashSet for userRole and adminRole. I also tried this:

Set userAccounts = new HashSet();
userAccounts.add(account);
userRole.setAccounts(userAccounts);
 
Set adminAccounts = new HashSet();
adminAccounts.add(account);
adminRole.setAccounts(adminAccounts);

but I got the same problem. I also tried out this project with MySQL 3.0.16. Same issue. In case anyone wants to try this out, I've published the project at:

http://java.briankuhn.com/SimpleHibernateDemo.zip

[Brian Kuhn]

I don't know why my last 2 replies show up blank, but I still want to mention:

The above code uses the same instance of HashSet for userRole and adminRole. I also tried this:

Set userAccounts = new HashSet();
userAccounts.add(account);
userRole.setAccounts(userAccounts);
 
Set adminAccounts = new HashSet();
adminAccounts.add(account);
adminRole.setAccounts(adminAccounts);

but I got the same problem. I also tried out this project with MySQL 3.0.16. Same issue. In case anyone wants to try this out, I've published the project at:

http://java.briankuhn.com/SimpleHibernateDemo.zip