-->
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.

View unanswered posts | View active topics


Board index » Hibernate & Java Persistence » Hibernate Users

All times are UTC - 5 hours [ DST ]


Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 2 posts ] 
  Previous topic | Next topic 
Author Message
jesse_sweetland
 Post subject: NPE in AbstractPersistentCollection$1.hasNext( )
PostPosted: Thu Jan 12, 2006 10:36 am 
Regular
Regular

Joined: Mon Jul 26, 2004 2:28 pm
Posts: 86
Location: Pensacola, Florida
I ran into an NPE when reattaching a detached parent object with an uninitialized list proxy and then adding a child to that list. The problem seems to come from the getListIndex method. It accesses the _children collection to calculate the list index, and in doing so causes an NPE in the AbstractPersistentCollection queue iterator. If I initialize the unitialized list proxy prior to calling transaction.commit( ), then the error goes away. I'm not sure if this is a bug or just esoteric usage, but here is a simple test case that will duplicate the problem.

- Jesse


Need help with Hibernate? Read this first:
http://www.hibernate.org/ForumMailingli ... AskForHelp

Hibernate version: 3.1

SQL
Code:
create table parent (id number(10) primary key, version number(10));
create table child (id number(10) primary key, version number(10), parent number(10) references parent (id), list_index number(10));

insert into parent values (1,0);
insert into child values (1,0,1,0);
insert into child values (2,0,1,1);


Mapping documents:

Hibernate.cfg.xml
Code:
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE hibernate-configuration PUBLIC
    "-//Hibernate/Hibernate Configuration DTD 3.0//EN"
    "http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd">

<hibernate-configuration>
    <session-factory>
        <property name="connection.driver_class">oracle.jdbc.driver.OracleDriver</property>
        <property name="connection.url">jdbc:oracle:thin:@localhost:1521:jesse</property>
        <property name="connection.username">playground_owner</property>
        <property name="connection.password">playground_owner</property>

        <property name="c3p0.acquire_increment">1</property>
        <property name="c3p0.idle_test_period">100</property>
        <property name="c3p0.max_size">100</property>
        <property name="c3p0.max_statements">0</property>
        <property name="c3p0.min_size">10</property>
        <property name="c3p0.timeout">100</property>
       
        <property name="dialect">org.hibernate.dialect.Oracle9Dialect</property>
        <property name="show_sql">true</property>

        <mapping resource="playground/Parent.hbm.xml"/>
        <mapping resource="playground/Child.hbm.xml"/>
    </session-factory>
</hibernate-configuration>


Parent.hbm.xml
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
        "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
        "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping package="playground">
    <class name="Parent" table="parent">
        <id name="id" column="id" type="int" unsaved-value="-1">
            <generator class="native">
                <param name="sequence">id_seq</param>
            </generator>
        </id>

        <version name="version" column="version" unsaved-value="negative"/>
       
        <list name="children" cascade="save-update" inverse="true" lazy="true">
            <key column="parent"/>
            <index column="list_index" type="integer"/>
            <one-to-many class="Child"/>
        </list>
    </class>
</hibernate-mapping>


Child.hbm.xml
Code:
<?xml version="1.0"?>
<!DOCTYPE hibernate-mapping PUBLIC
        "-//Hibernate/Hibernate Mapping DTD 3.0//EN"
        "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd">

<hibernate-mapping package="playground">
    <class name="Child" table="child">
        <id name="id" column="id" type="int" unsaved-value="-1">
            <generator class="native">
                <param name="sequence">id_seq</param>
            </generator>
        </id>

        <version name="version" column="version" unsaved-value="negative"/>
       
        <many-to-one name="parent" column="parent" class="Parent" fetch="join" lazy="false"/>
        <property name="listIndex" column="list_index" type="int"/>
    </class>
</hibernate-mapping>


Code between sessionFactory.openSession() and session.close():
Code:
package playground;

import org.hibernate.*;
import org.hibernate.cfg.*;

/**
*
* @author JESSE_SWEETLAND
*/
public class Test
{
    private static final Configuration _config;
    private static final SessionFactory _sessionFactory;
   
    static
    {
        try
        {
            _config = new Configuration( );
            _config.configure( );
            _sessionFactory = _config.buildSessionFactory( );
        }
        catch( Throwable t )
        {
            t.printStackTrace( );
            throw new ExceptionInInitializerError( t );
        }
    }
   
    public static void main( String[] arguments )
    {
        try
        {
            Session s1 = _sessionFactory.openSession( );
            Transaction t1 = s1.beginTransaction( );
            Parent p1 = (Parent)s1.load( Parent.class, new Integer( 1 ) );
            t1.commit( );
            s1.close( );
           
            Session s2 = _sessionFactory.openSession( );
            Transaction t2 = s2.beginTransaction( );
            s2.lock( p1, LockMode.NONE );
            p1.addChild( new Child( ) );
            t2.commit( );
            s2.close( );
        }
        catch( Throwable t )
        {
            t.printStackTrace( );
        }
    }
}


Full stack trace of any exception that occurs:
Code:
java.lang.NullPointerException
        at org.hibernate.collection.AbstractPersistentCollection$1.hasNext(AbstractPersistentCollection.java:494)
        at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:289)
        at org.hibernate.engine.Cascade.cascadeCollection(Cascade.java:185)
        at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:160)
        at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:108)
        at org.hibernate.engine.Cascade.cascade(Cascade.java:248)
        at org.hibernate.event.def.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:130)
        at org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:121)
        at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:65)
        at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
        at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:980)
        at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:353)
        at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
        at playground.Test.main(Test.java:54)


Name and version of the database you are using: Oracle 10g

The generated SQL (show_sql=true):
Code:
select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=?
select id_seq.nextval from dual
select children0_.parent as parent1_, children0_.id as id1_, children0_.list_index as list4_1_, children0_.id as id1_0_, children0_.version as version1_0_, children0_.parent as parent1_0_, children0_.list_index as list4_1_0_ from child children0_ where children0_.parent=?


Debug level Hibernate log excerpt:
[code]
org.hibernate.cfg.Environment: 01/12/06 08:28:38: main: INFO: Hibernate 3.1
org.hibernate.cfg.Environment: 01/12/06 08:28:38: main: INFO: hibernate.properties not found
org.hibernate.cfg.Environment: 01/12/06 08:28:38: main: INFO: using CGLIB reflection optimizer
org.hibernate.cfg.Environment: 01/12/06 08:28:38: main: INFO: using JDK 1.4 java.sql.Timestamp handling
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: INFO: configuring from resource: /hibernate.cfg.xml
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: INFO: Configuration resource: /hibernate.cfg.xml
org.hibernate.util.DTDEntityResolver: 01/12/06 08:28:38: main: DEBUG: trying to locate http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd in classpath under org/hibernate/
org.hibernate.util.DTDEntityResolver: 01/12/06 08:28:38: main: DEBUG: found http://hibernate.sourceforge.net/hibernate-configuration-3.0.dtd in classpath
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: connection.driver_class=oracle.jdbc.driver.OracleDriver
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: connection.url=jdbc:oracle:thin:@localhost:1521:jesse
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: connection.username=playground_owner
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: connection.password=playground_owner
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: c3p0.acquire_increment=1
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: c3p0.idle_test_period=100
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: c3p0.max_size=100
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: c3p0.max_statements=0
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: c3p0.min_size=10
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: c3p0.timeout=100
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: dialect=org.hibernate.dialect.Oracle9Dialect
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: show_sql=true
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: DEBUG: null<-org.dom4j.tree.DefaultAttribute@1e59128 [Attribute: name resource value "playground/Parent.hbm.xml"]
org.hibernate.cfg.Configuration: 01/12/06 08:28:38: main: INFO: Reading mappings from resource: playground/Parent.hbm.xml
org.hibernate.util.DTDEntityResolver: 01/12/06 08:28:38: main: DEBUG: trying to locate http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd in classpath under org/hibernate/
org.hibernate.util.DTDEntityResolver: 01/12/06 08:28:38: main: DEBUG: found http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd in classpath
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: INFO: Mapping class: playground.Parent -> parent
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: DEBUG: Mapped property: id -> id
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: DEBUG: Mapped property: version -> version
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: DEBUG: Mapped property: children
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: DEBUG: null<-org.dom4j.tree.DefaultAttribute@281d4b [Attribute: name resource value "playground/Child.hbm.xml"]
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: INFO: Reading mappings from resource: playground/Child.hbm.xml
org.hibernate.util.DTDEntityResolver: 01/12/06 08:28:39: main: DEBUG: trying to locate http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd in classpath under org/hibernate/
org.hibernate.util.DTDEntityResolver: 01/12/06 08:28:39: main: DEBUG: found http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd in classpath
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: INFO: Mapping class: playground.Child -> child
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: DEBUG: Mapped property: id -> id
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: DEBUG: Mapped property: version -> version
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: DEBUG: Mapped property: parent -> parent
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: DEBUG: Mapped property: listIndex -> list_index
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: INFO: Configured SessionFactory: null
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: DEBUG: properties: {show_sql=true, java.vendor=Sun Microsystems Inc., hibernate.connection.url=jdbc:oracle:thin:@localhost:1521:jesse, c3p0.min_size=10, os.name=Windows XP, sun.boot.class.path=C:\j2sdk1.4.2\jre\lib\rt.jar;C:\j2sdk1.4.2\jre\lib\i18n.jar;C:\j2sdk1.4.2\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2\jre\lib\jsse.jar;C:\j2sdk1.4.2\jre\lib\jce.jar;C:\j2sdk1.4.2\jre\lib\charsets.jar;C:\j2sdk1.4.2\jre\classes, hibernate.c3p0.max_size=100, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., c3p0.max_size=100, java.runtime.version=1.4.2-b28, hibernate.c3p0.min_size=10, c3p0.acquire_increment=1, user.name=JESSE_SWEETLAND, connection.driver_class=oracle.jdbc.driver.OracleDriver, hibernate.c3p0.timeout=100, user.language=en, sun.boot.library.path=C:\j2sdk1.4.2\jre\bin, dialect=org.hibernate.dialect.Oracle9Dialect, java.version=1.4.2, user.timezone=America/Chicago, sun.arch.data.model=32, java.endorsed.dirs=C:\j2sdk1.4.2\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:oracle:thin:@localhost:1521:jesse, java.home=C:\j2sdk1.4.2\jre, java.vm.info=mixed mode, os.version=5.1, path.separator=;, c3p0.idle_test_period=100, connection.password=playground_owner, java.vm.version=1.4.2-b28, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=playground_owner, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=playground_owner, user.home=C:\Documents and Settings\JESSE_SWEETLAND, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\j2sdk1.4.2\jre\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\oracle\product\10.1.0\db_1\bin;C:\oracle\product\10.1.0\db_1\jre\1.4.2\bin\client;C:\oracle\product\10.1.0\db_1\jre\1.4.2\bin;C:\Program Files\PVCS\vm\win32\bin;C:\Program Files\PVCS\vm\common\bin\win32;J:\PVCS\vm8003w\PROGRA~1\Merant\vm\win32\bin;J:\PVCS\vm8003w\PROGRA~1\Merant\vm\common\bin\win32;C:\j2sdk1.4.2\bin;c:\Oracle_9\bin;C:\ORANT\bin;C:\Program Files\Oracle\jre\1.3.1\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\PROGRA~1\GRADKE~1\DBSIGN~1\lib;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\system32\nls;C:\WINDOWS\system32\nls\ENGLISH;C:\DE3270;C:\Program Files\NetManage\Windows;c:\orawin\bin;C:\ORANT\jdk\bin;C:\Program Files\apache-ant-1.6.5\bin;Z:.;C:\ORAWIN\BIN;, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=oracle.jdbc.driver.OracleDriver, connection.username=playground_owner, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.Oracle9Dialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-antlr-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-junit-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-launcher-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-swing-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\antlr-2.7.6rc1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\asm-attrs.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\asm.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\c3p0-0.9.0.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\cglib-2.1.3.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\cleanimports.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\commons-collections-2.1.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\commons-logging-1.0.4.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\concurrent-1.3.2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\connector.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\dom4j-1.6.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ehcache-1.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jaas.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jacc-1_0-fr.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jaxen-1.1-beta-7.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-cache.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-common.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-jmx.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-system.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jdbc2_0-stdext.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jgroups-2.2.7.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jta.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\junit-3.8.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\log4j-1.2.11.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\oscache-2.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\proxool-0.8.3.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\swarmcache-1.0rc2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\syndiag2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\versioncheck.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\xerces-2.6.2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\xml-apis.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\hibernate3.jar;C:\oracle\product\10.1.0\db_1\jdbc\lib\ojdbc14_g.jar;C:\Documents and Settings\JESSE_SWEETLAND\Playground\build\classes, c3p0.timeout=100, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 1, java.io.tmpdir=C:\WINDOWS\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\jre\lib\ext, user.dir=C:\Documents and Settings\JESSE_SWEETLAND\Playground, hibernate.c3p0.idle_test_period=100, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, hibernate.c3p0.acquire_increment=1, file.encoding=Cp1252, java.specification.version=1.4, c3p0.max_statements=0, hibernate.show_sql=true, hibernate.c3p0.max_statements=0}
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: DEBUG: Preparing to build session factory with filters : {}
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: INFO: processing extends queue
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: INFO: processing collection mappings
org.hibernate.cfg.CollectionSecondPass: 01/12/06 08:28:39: main: DEBUG: Second pass for collection: playground.Parent.children
org.hibernate.cfg.HbmBinder: 01/12/06 08:28:39: main: INFO: Mapping collection: playground.Parent.children -> child
org.hibernate.cfg.CollectionSecondPass: 01/12/06 08:28:39: main: DEBUG: Mapped collection key: parent, index: list_index, one-to-many: playground.Child
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: INFO: processing association property references
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: INFO: processing foreign key constraints
org.hibernate.cfg.Configuration: 01/12/06 08:28:39: main: DEBUG: resolving reference to class: playground.Parent
org.hibernate.connection.C3P0ConnectionProvider: 01/12/06 08:28:39: main: INFO: C3P0 using driver: oracle.jdbc.driver.OracleDriver at URL: jdbc:oracle:thin:@localhost:1521:jesse
org.hibernate.connection.C3P0ConnectionProvider: 01/12/06 08:28:39: main: INFO: Connection properties: {user=playground_owner, password=****}
org.hibernate.connection.C3P0ConnectionProvider: 01/12/06 08:28:39: main: INFO: autocommit mode: false
com.mchange.v2.log.MLog: 01/12/06 08:28:39: main: INFO: MLog clients using log4j logging.
com.mchange.v2.c3p0.C3P0Registry: 01/12/06 08:28:39: main: INFO: Initializing c3p0-0.9.0 [built 11-July-2005 00:43:29 -0400; debug? true; trace: 10]
com.mchange.v2.c3p0.PoolBackedDataSource: 01/12/06 08:28:39: main: INFO: Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@476128 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@125fefa [ 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, identityToken -> 125fefa, idleConnectionTestPeriod -> 100, initialPoolSize -> 10, maxIdleTime -> 100, maxPoolSize -> 100, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 10, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@f0c85e [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> f0c85e, jdbcUrl -> jdbc:oracle:thin:@localhost:1521:jesse, properties -> {user=******, password=******} ], preferredTestQuery -> null, propertyCycle -> 300, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, usesTraditionalReflectiveProxies -> false ], factoryClassLocation -> null, identityToken -> 476128, numHelperThreads -> 3 ]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:39: main: DEBUG: awaitAvailable(): [unknown]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:39: main: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 0, unused: 0, excluded: 0]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:40: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 1, unused: 1, excluded: 0]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:40: main: DEBUG: resource age is okay: com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53 ---> age: 0 max: 100000 [com.mchange.v2.resourcepool.BasicResourcePool@1b5998f]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:40: main: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 1, unused: 0, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:40: main: INFO: RDBMS: Oracle, version: Personal Oracle Database 10g Release 10.1.0.2.0 - Production
With the Partitioning, OLAP and Data Mining options
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:40: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 2, unused: 1, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:40: main: INFO: JDBC driver: Oracle JDBC driver, version: 10.1.0.2.0
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:40: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 3, unused: 2, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:40: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 4, unused: 3, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:40: main: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 4, unused: 3, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.dialect.Dialect: 01/12/06 08:28:40: main: INFO: Using dialect: org.hibernate.dialect.Oracle9Dialect
org.hibernate.transaction.TransactionFactoryFactory: 01/12/06 08:28:41: main: INFO: Using default transaction strategy (direct JDBC transactions)
org.hibernate.transaction.TransactionManagerLookupFactory: 01/12/06 08:28:41: main: INFO: No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Automatic flush during beforeCompletion(): disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Automatic session close at end of transaction: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: JDBC batch size: 15
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: JDBC batch updates for versioned data: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Scrollable result sets: enabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: DEBUG: Wrap result sets: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: JDBC3 getGeneratedKeys(): disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Connection release mode: auto
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Default batch fetch size: 1
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Generate SQL with comments: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Order SQL updates by primary key: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
org.hibernate.hql.ast.ASTQueryTranslatorFactory: 01/12/06 08:28:41: main: INFO: Using ASTQueryTranslatorFactory
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Query language substitutions: {}
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Second-level cache: enabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Query cache: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Cache provider: org.hibernate.cache.EhCacheProvider
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Optimize cache for minimal puts: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Structured second-level cache entries: disabled
org.hibernate.exception.SQLExceptionConverterFactory: 01/12/06 08:28:41: main: DEBUG: Using dialect defined converter
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Echoing all SQL to stdout
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Statistics: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Deleted entity synthetic identifier rollback: disabled
org.hibernate.cfg.SettingsFactory: 01/12/06 08:28:41: main: INFO: Default entity-mode: pojo
org.hibernate.impl.SessionFactoryImpl: 01/12/06 08:28:41: main: INFO: building session factory
org.hibernate.impl.SessionFactoryImpl: 01/12/06 08:28:41: main: DEBUG: Session factory constructed with filter configurations : {}
org.hibernate.impl.SessionFactoryImpl: 01/12/06 08:28:41: main: DEBUG: instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=true, hibernate.connection.url=jdbc:oracle:thin:@localhost:1521:jesse, c3p0.min_size=10, os.name=Windows XP, sun.boot.class.path=C:\j2sdk1.4.2\jre\lib\rt.jar;C:\j2sdk1.4.2\jre\lib\i18n.jar;C:\j2sdk1.4.2\jre\lib\sunrsasign.jar;C:\j2sdk1.4.2\jre\lib\jsse.jar;C:\j2sdk1.4.2\jre\lib\jce.jar;C:\j2sdk1.4.2\jre\lib\charsets.jar;C:\j2sdk1.4.2\jre\classes, hibernate.c3p0.max_size=100, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., c3p0.max_size=100, java.runtime.version=1.4.2-b28, hibernate.c3p0.min_size=10, c3p0.acquire_increment=1, user.name=JESSE_SWEETLAND, connection.driver_class=oracle.jdbc.driver.OracleDriver, hibernate.c3p0.timeout=100, user.language=en, sun.boot.library.path=C:\j2sdk1.4.2\jre\bin, dialect=org.hibernate.dialect.Oracle9Dialect, java.version=1.4.2, user.timezone=America/Chicago, sun.arch.data.model=32, java.endorsed.dirs=C:\j2sdk1.4.2\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:oracle:thin:@localhost:1521:jesse, java.home=C:\j2sdk1.4.2\jre, java.vm.info=mixed mode, os.version=5.1, path.separator=;, c3p0.idle_test_period=100, connection.password=playground_owner, java.vm.version=1.4.2-b28, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=playground_owner, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=playground_owner, user.home=C:\Documents and Settings\JESSE_SWEETLAND, java.specification.vendor=Sun Microsystems Inc., java.library.path=C:\j2sdk1.4.2\jre\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\oracle\product\10.1.0\db_1\bin;C:\oracle\product\10.1.0\db_1\jre\1.4.2\bin\client;C:\oracle\product\10.1.0\db_1\jre\1.4.2\bin;C:\Program Files\PVCS\vm\win32\bin;C:\Program Files\PVCS\vm\common\bin\win32;J:\PVCS\vm8003w\PROGRA~1\Merant\vm\win32\bin;J:\PVCS\vm8003w\PROGRA~1\Merant\vm\common\bin\win32;C:\j2sdk1.4.2\bin;c:\Oracle_9\bin;C:\ORANT\bin;C:\Program Files\Oracle\jre\1.3.1\bin;C:\Program Files\Oracle\jre\1.1.8\bin;C:\PROGRA~1\GRADKE~1\DBSIGN~1\lib;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\system32\nls;C:\WINDOWS\system32\nls\ENGLISH;C:\DE3270;C:\Program Files\NetManage\Windows;c:\orawin\bin;C:\ORANT\jdk\bin;C:\Program Files\apache-ant-1.6.5\bin;Z:.;C:\ORAWIN\BIN;, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=oracle.jdbc.driver.OracleDriver, connection.username=playground_owner, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.Oracle9Dialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-antlr-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-junit-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-launcher-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ant-swing-1.6.5.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\antlr-2.7.6rc1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\asm-attrs.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\asm.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\c3p0-0.9.0.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\cglib-2.1.3.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\cleanimports.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\commons-collections-2.1.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\commons-logging-1.0.4.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\concurrent-1.3.2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\connector.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\dom4j-1.6.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\ehcache-1.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jaas.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jacc-1_0-fr.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jaxen-1.1-beta-7.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-cache.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-common.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-jmx.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jboss-system.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jdbc2_0-stdext.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jgroups-2.2.7.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\jta.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\junit-3.8.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\log4j-1.2.11.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\oscache-2.1.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\proxool-0.8.3.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\swarmcache-1.0rc2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\syndiag2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\versioncheck.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\xerces-2.6.2.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\lib\xml-apis.jar;C:\Documents and Settings\JESSE_SWEETLAND\My Documents\Libraries\Source\hibernate-3.1\hibernate3.jar;C:\oracle\product\10.1.0\db_1\jdbc\lib\ojdbc14_g.jar;C:\Documents and Settings\JESSE_SWEETLAND\Playground\build\classes, c3p0.timeout=100, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, sun.cpu.endian=little, sun.os.patch.level=Service Pack 1, java.io.tmpdir=C:\WINDOWS\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\jre\lib\ext, user.dir=C:\Documents and Settings\JESSE_SWEETLAND\Playground, hibernate.c3p0.idle_test_period=100, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, hibernate.c3p0.acquire_increment=1, file.encoding=Cp1252, java.specification.version=1.4, c3p0.max_statements=0, hibernate.c3p0.max_statements=0, hibernate.show_sql=true}
net.sf.ehcache.CacheManager: 01/12/06 08:28:41: main: DEBUG: Creating new CacheManager with default config
net.sf.ehcache.CacheManager: 01/12/06 08:28:41: main: DEBUG: Configuring ehcache from classpath.
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:41: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 5, unused: 5, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
net.sf.ehcache.config.Configurator: 01/12/06 08:28:41: main: WARN: No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/C:/Documents%20and%20Settings/JESSE_SWEETLAND/My%20Documents/Libraries/Source/hibernate-3.1/lib/ehcache-1.1.jar!/ehcache-failsafe.xml
net.sf.ehcache.config.Configuration$DiskStore: 01/12/06 08:28:41: main: DEBUG: Disk Store Path: C:\WINDOWS\TEMP\
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:41: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 6, unused: 6, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:41: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 7, unused: 7, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.util.ReflectHelper: 01/12/06 08:28:41: main: DEBUG: reflection optimizer disabled for: playground.Child, BulkBeanException: Property is private (property setVersion)
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:41: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 8, unused: 8, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Static SQL for entity: playground.Child
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Version select: select version from child where id =?
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Snapshot select: select child_.id, child_.version as version1_, child_.parent as parent1_, child_.list_index as list4_1_ from child child_ where child_.id=?
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Insert 0: insert into child (version, parent, list_index, id) values (?, ?, ?, ?)
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Update 0: update child set version=?, parent=?, list_index=? where id=? and version=?
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Delete 0: delete from child where id=? and version=?
org.hibernate.util.ReflectHelper: 01/12/06 08:28:41: main: DEBUG: reflection optimizer disabled for: playground.Parent, BulkBeanException: Property is private (property setVersion)
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Static SQL for entity: playground.Parent
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Version select: select version from parent where id =?
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Snapshot select: select parent_.id, parent_.version as version0_ from parent parent_ where parent_.id=?
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Insert 0: insert into parent (version, id) values (?, ?)
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Update 0: update parent set version=? where id=? and version=?
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:41: main: DEBUG: Delete 0: delete from parent where id=? and version=?
org.hibernate.persister.collection.AbstractCollectionPersister: 01/12/06 08:28:41: main: DEBUG: Static SQL for collection: playground.Parent.children
org.hibernate.persister.collection.AbstractCollectionPersister: 01/12/06 08:28:41: main: DEBUG: Row insert: update child set parent=?, list_index=? where id=?
org.hibernate.persister.collection.AbstractCollectionPersister: 01/12/06 08:28:41: main: DEBUG: Row delete: update child set parent=null, list_index=null where parent=? and id=?
org.hibernate.persister.collection.AbstractCollectionPersister: 01/12/06 08:28:41: main: DEBUG: One-shot delete: update child set parent=null, list_index=null where parent=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Child: select child0_.id as id1_1_, child0_.version as version1_1_, child0_.parent as parent1_1_, child0_.list_index as list4_1_1_, parent1_.id as id0_0_, parent1_.version as version0_0_ from child child0_ left outer join parent parent1_ on child0_.parent=parent1_.id where child0_.id=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Child: select child0_.id as id1_1_, child0_.version as version1_1_, child0_.parent as parent1_1_, child0_.list_index as list4_1_1_, parent1_.id as id0_0_, parent1_.version as version0_0_ from child child0_ left outer join parent parent1_ on child0_.parent=parent1_.id where child0_.id=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Child: select child0_.id as id1_0_, child0_.version as version1_0_, child0_.parent as parent1_0_, child0_.list_index as list4_1_0_ from child child0_ where child0_.id=? for update
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Child: select child0_.id as id1_0_, child0_.version as version1_0_, child0_.parent as parent1_0_, child0_.list_index as list4_1_0_ from child child0_ where child0_.id=? for update nowait
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for action ACTION_MERGE on entity playground.Child: select child0_.id as id1_0_, child0_.version as version1_0_, child0_.parent as parent1_0_, child0_.list_index as list4_1_0_ from child child0_ where child0_.id=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for action ACTION_REFRESH on entity playground.Child: select child0_.id as id1_0_, child0_.version as version1_0_, child0_.parent as parent1_0_, child0_.list_index as list4_1_0_ from child child0_ where child0_.id=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Parent: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Parent: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Parent: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=? for update
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for entity playground.Parent: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=? for update nowait
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for action ACTION_MERGE on entity playground.Parent: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=?
org.hibernate.loader.entity.EntityLoader: 01/12/06 08:28:41: main: DEBUG: Static select for action ACTION_REFRESH on entity playground.Parent: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=?
org.hibernate.loader.collection.OneToManyLoader: 01/12/06 08:28:41: main: DEBUG: Static select for one-to-many playground.Parent.children: select children0_.parent as parent1_, children0_.id as id1_, children0_.list_index as list4_1_, children0_.id as id1_0_, children0_.version as version1_0_, children0_.parent as parent1_0_, children0_.list_index as list4_1_0_ from child children0_ where children0_.parent=?
org.hibernate.impl.SessionFactoryObjectFactory: 01/12/06 08:28:41: main: DEBUG: initializing class SessionFactoryObjectFactory
org.hibernate.impl.SessionFactoryObjectFactory: 01/12/06 08:28:41: main: DEBUG: registered: 4ca2d19008bf04ad0108bf04b0e70000 (unnamed)
org.hibernate.impl.SessionFactoryObjectFactory: 01/12/06 08:28:41: main: INFO: Not binding factory to JNDI, no JNDI name configured
org.hibernate.impl.SessionFactoryImpl: 01/12/06 08:28:41: main: DEBUG: instantiated session factory
org.hibernate.impl.SessionFactoryImpl: 01/12/06 08:28:41: main: INFO: Checking 0 named HQL queries
org.hibernate.impl.SessionFactoryImpl: 01/12/06 08:28:41: main: INFO: Checking 0 named SQL queries
org.hibernate.impl.SessionImpl: 01/12/06 08:28:41: main: DEBUG: opened session at timestamp: 4657463795081216
org.hibernate.transaction.JDBCTransaction: 01/12/06 08:28:41: main: DEBUG: begin
org.hibernate.jdbc.ConnectionManager: 01/12/06 08:28:41: main: DEBUG: opening JDBC connection
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:41: main: DEBUG: resource age is okay: com.mchange.v2.c3p0.impl.NewPooledConnection@19eda2c ---> age: 1407 max: 100000 [com.mchange.v2.resourcepool.BasicResourcePool@1b5998f]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:41: main: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 8, unused: 7, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.transaction.JDBCTransaction: 01/12/06 08:28:41: main: DEBUG: current autocommit status: false
org.hibernate.jdbc.JDBCContext: 01/12/06 08:28:41: main: DEBUG: after transaction begin
org.hibernate.event.def.DefaultLoadEventListener: 01/12/06 08:28:41: main: DEBUG: loading entity: [playground.Parent#1]
org.hibernate.event.def.DefaultLoadEventListener: 01/12/06 08:28:41: main: DEBUG: creating new proxy for entity
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:41: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 9, unused: 8, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.transaction.JDBCTransaction: 01/12/06 08:28:42: main: DEBUG: commit
org.hibernate.impl.SessionImpl: 01/12/06 08:28:42: main: DEBUG: automatically flushing session
org.hibernate.jdbc.JDBCContext: 01/12/06 08:28:42: main: DEBUG: before transaction completion
org.hibernate.impl.SessionImpl: 01/12/06 08:28:42: main: DEBUG: before transaction completion
org.hibernate.transaction.JDBCTransaction: 01/12/06 08:28:42: main: DEBUG: committed JDBC Connection
org.hibernate.jdbc.JDBCContext: 01/12/06 08:28:42: main: DEBUG: after transaction completion
org.hibernate.jdbc.ConnectionManager: 01/12/06 08:28:42: main: DEBUG: aggressively releasing JDBC connection
org.hibernate.jdbc.ConnectionManager: 01/12/06 08:28:42: main: DEBUG: closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:42: main: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 9, unused: 8, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.impl.SessionImpl: 01/12/06 08:28:42: main: DEBUG: after transaction completion
org.hibernate.impl.SessionImpl: 01/12/06 08:28:42: main: DEBUG: closing session
org.hibernate.jdbc.ConnectionManager: 01/12/06 08:28:42: main: DEBUG: connection already null in cleanup : no action
org.hibernate.impl.SessionImpl: 01/12/06 08:28:42: main: DEBUG: opened session at timestamp: 4657463795851264
org.hibernate.transaction.JDBCTransaction: 01/12/06 08:28:42: main: DEBUG: begin
org.hibernate.jdbc.ConnectionManager: 01/12/06 08:28:42: main: DEBUG: opening JDBC connection
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:42: main: DEBUG: resource age is okay: com.mchange.v2.c3p0.impl.NewPooledConnection@1cef4f7 ---> age: 1250 max: 100000 [com.mchange.v2.resourcepool.BasicResourcePool@1b5998f]
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:42: main: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 9, unused: 8, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.transaction.JDBCTransaction: 01/12/06 08:28:42: main: DEBUG: current autocommit status: false
org.hibernate.jdbc.JDBCContext: 01/12/06 08:28:42: main: DEBUG: after transaction begin
org.hibernate.impl.SessionImpl: 01/12/06 08:28:42: main: DEBUG: initializing proxy: [playground.Parent#1]
org.hibernate.event.def.DefaultLoadEventListener: 01/12/06 08:28:42: main: DEBUG: attempting to resolve: [playground.Parent#1]
org.hibernate.event.def.DefaultLoadEventListener: 01/12/06 08:28:42: main: DEBUG: object not resolved in any cache: [playground.Parent#1]
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:42: main: DEBUG: Fetching entity: [playground.Parent#1]
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: loading entity: [playground.Parent#1]
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
org.hibernate.SQL: 01/12/06 08:28:42: main: DEBUG: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=?
Hibernate: select parent0_.id as id0_0_, parent0_.version as version0_0_ from parent parent0_ where parent0_.id=?
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: preparing statement
org.hibernate.type.IntegerType: 01/12/06 08:28:42: main: DEBUG: binding '1' to parameter: 1
com.mchange.v2.resourcepool.BasicResourcePool: 01/12/06 08:28:42: com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0: DEBUG: trace com.mchange.v2.resourcepool.BasicResourcePool@1b5998f [managed: 10, unused: 9, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@13c0b53)
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: about to open ResultSet (open ResultSets: 0, globally: 0)
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: processing result set
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: result set row: 0
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: result row: EntityKey[playground.Parent#1]
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: Initializing object from ResultSet: [playground.Parent#1]
org.hibernate.persister.entity.AbstractEntityPersister: 01/12/06 08:28:42: main: DEBUG: Hydrating entity: [playground.Parent#1]
org.hibernate.type.IntegerType: 01/12/06 08:28:42: main: DEBUG: returning '6' as column: version0_0_
org.hibernate.engine.TwoPhaseLoad: 01/12/06 08:28:42: main: DEBUG: Version: 6
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: done processing result set (1 rows)
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: about to close ResultSet (open ResultSets: 1, globally: 1)
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: closing statement
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: total objects hydrated: 1
org.hibernate.engine.TwoPhaseLoad: 01/12/06 08:28:42: main: DEBUG: resolving associations for [playground.Parent#1]
org.hibernate.engine.CollectionLoadContext: 01/12/06 08:28:42: main: DEBUG: creating collection wrapper:[playground.Parent.children#1]
org.hibernate.engine.TwoPhaseLoad: 01/12/06 08:28:42: main: DEBUG: done materializing entity [playground.Parent#1]
org.hibernate.engine.StatefulPersistenceContext: 01/12/06 08:28:42: main: DEBUG: initializing non-lazy collections
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: done entity load
org.hibernate.transaction.JDBCTransaction: 01/12/06 08:28:42: main: DEBUG: commit
org.hibernate.impl.SessionImpl: 01/12/06 08:28:42: main: DEBUG: automatically flushing session
org.hibernate.event.def.AbstractFlushingEventListener: 01/12/06 08:28:42: main: DEBUG: flushing session
org.hibernate.event.def.AbstractFlushingEventListener: 01/12/06 08:28:42: main: DEBUG: processing flush-time cascades
org.hibernate.engine.Cascade: 01/12/06 08:28:42: main: DEBUG: processing cascade ACTION_SAVE_UPDATE for: playground.Parent
org.hibernate.engine.Cascade: 01/12/06 08:28:42: main: DEBUG: cascade ACTION_SAVE_UPDATE for collection: playground.Parent.children
org.hibernate.engine.CascadingAction: 01/12/06 08:28:42: main: DEBUG: cascading to saveOrUpdate: playground.Child
org.hibernate.engine.VersionValue: 01/12/06 08:28:42: main: DEBUG: version unsaved-value strategy NEGATIVE
org.hibernate.event.def.AbstractSaveEventListener: 01/12/06 08:28:42: main: DEBUG: transient instance of: playground.Child
org.hibernate.event.def.DefaultSaveOrUpdateEventListener: 01/12/06 08:28:42: main: DEBUG: saving transient instance
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
org.hibernate.SQL: 01/12/06 08:28:42: main: DEBUG: select id_seq.nextval from dual
Hibernate: select id_seq.nextval from dual
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: preparing statement
org.hibernate.id.SequenceGenerator: 01/12/06 08:28:42: main: DEBUG: Sequence identifier generated: 11
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: closing statement
org.hibernate.event.def.AbstractSaveEventListener: 01/12/06 08:28:42: main: DEBUG: generated identifier: 11, using strategy: org.hibernate.id.SequenceGenerator
org.hibernate.event.def.AbstractSaveEventListener: 01/12/06 08:28:42: main: DEBUG: saving [playground.Child#11]
org.hibernate.event.def.DefaultInitializeCollectionEventListener: 01/12/06 08:28:42: main: DEBUG: initializing collection [playground.Parent.children#1]
org.hibernate.event.def.DefaultInitializeCollectionEventListener: 01/12/06 08:28:42: main: DEBUG: checking second-level cache
org.hibernate.event.def.DefaultInitializeCollectionEventListener: 01/12/06 08:28:42: main: DEBUG: collection not cached
org.hibernate.loader.Loader: 01/12/06 08:28:42: main: DEBUG: loading collection: [playground.Parent.children#1]
org.hibernate.jdbc.AbstractBatcher: 01/12/06 08:28:42: main: DEBUG: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
org.hibernate.SQL: 01/12/06 08:28:42: main: DEBUG: select children0_.parent as parent1_, children0_.id as id1_, children0_.list_index as list4_1_, children0_.id as id1_0_, children0_.version as version1_0_, children0_.parent as parent1_0_, children0_.list_index as list4_1_0_ from child children0_ where children0_.parent=?
Hibernate: select
Top
 Profile  
 
cdombroski
 Post subject: Was a solution to this found?
PostPosted: Thu Jul 31, 2008 7:17 pm 
Newbie

Joined: Thu Jul 31, 2008 6:28 pm
Posts: 2
I seem to be running into this same problem and was wondering if any solution was found. Hope all of this information is useful to figuring this out.
Versions:
Spring: 2.5.5
Hibernate: 3.2
Glassfish: V2 UR2
PostgreSQL: 8.3.3

It looks like in AbstractPersistentCollection, operationQueue is emptied/nulled between when queuedAdditionIterator is called and hasNext() is called on the returned iterator. Specifically, the lines of interest are between 486 and 504 with the NPE coming from the hasNext function on line 494.

AbstractPersistentCollection: 486-504
Code:
486:    public final Iterator queuedAdditionIterator() {
487:      if ( hasQueuedOperations() ) {
488:         return new Iterator() {
489:            int i = 0;
490:            public Object next() {
491:               return ( (DelayedOperation) operationQueue.get(i++) ).getAddedInstance();
492:            }
493:            public boolean hasNext() {
494:               return i<operationQueue.size();
495:            }
496:            public void remove() {
497:               throw new UnsupportedOperationException();
498:            }
499:         };
500:      }
501:      else {
502:         return EmptyIterator.INSTANCE;
503:      }
504:   }


The code being run:
CreateListController:
Code:
   @Override
   @Transactional
   protected ModelAndView onSubmit(HttpServletRequest request,
         HttpServletResponse response, Object command, BindException errors)
         throws Exception {
      NewListModel list = (NewListModel) command;
      User user = userDao.getUserById((Long) request.getSession().
            getAttribute("userID"));
      WishList newList = new WishList();
      newList.setDescription(list.getDescription());
      newList.setName(list.getName());
      user.addList(newList);
      userDao.updateUser(user);
      return new ModelAndView(getSuccessView());
   }


HibernateUserDao:
Code:
   @Transactional(readOnly = true)
   public final User getUserById(final long id) {
      return (User) getHibernateTemplate().load(User.class, id);
   }

   public void updateUser(User user) {
      getHibernateTemplate().update(user);
   }

Entities:
User.java
Code:
@Entity(name = "users")
//@Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
public class User implements Serializable {

   @Transient
   private final Log logger = LogFactory.getLog(getClass());
   @Id
   @GeneratedValue(generator = "hibid")
   @GenericGenerator(name = "hibid", strategy = "native", parameters = {
      @Parameter(name = "sequence", value = "user_sequence"),
      @Parameter(name = "table", value = "user_hilo"),
      @Parameter(name = "column", value = "next_hi")
   })
   private Long id;
   @NaturalId
   private String username;
   @OneToMany(mappedBy = "owner", cascade = {
      javax.persistence.CascadeType.MERGE,
      javax.persistence.CascadeType.PERSIST
   })
   @Cascade({CascadeType.SAVE_UPDATE, CascadeType.DELETE_ORPHAN})
   @IndexColumn(name = "index")
   //@Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
   private List<WishList> wishlists = new LinkedList<WishList>();
   private String password;
   private String email;
   private String firstName;
   private String lastName;
   private static final long serialVersionUID = 1;


WishList.java
Code:
@Entity
@Table(uniqueConstraints = @UniqueConstraint(columnNames = {"owner", "index"}))
//@Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
public class WishList implements Serializable {

   @Id
   @GeneratedValue(generator = "hibid")
   @GenericGenerator(name = "hibid", strategy = "native", parameters = {
      @Parameter(name = "sequence", value = "wishlist_sequence"),
      @Parameter(name = "table", value = "wishlist_hilo"),
      @Parameter(name = "column", value = "next_hi")
   })
   private Long id;
   @ManyToOne(optional = false)
   private User owner;
   private String name;
   @Lob
   private String description;
   private boolean viewable;
   @OneToMany(mappedBy = "wishList", cascade = {
      javax.persistence.CascadeType.MERGE,
      javax.persistence.CascadeType.PERSIST
   })
   @IndexColumn(name = "index")
   @Cascade({CascadeType.SAVE_UPDATE, CascadeType.DELETE_ORPHAN})
   //@Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
   private List<WishItem> items = new LinkedList<WishItem>();
   @AccessType("property")
   private int index;
   private static final long serialVersionUID = 1;


WishItem.java
Code:
@Entity
@Table(uniqueConstraints = @UniqueConstraint(
columnNames = {"index", "wish_list"}))
//@Cache(usage = CacheConcurrencyStrategy.READ_WRITE)
public class WishItem implements Serializable {

   @Id
   @GeneratedValue(generator = "hibid")
   @GenericGenerator(name = "hibid", strategy = "native", parameters = {
      @Parameter(name = "sequence", value = "wishitem_sequence"),
      @Parameter(name = "table", value = "wishitem_hilo"),
      @Parameter(name = "column", value = "next_hi")
   })
   private Long id;
   @ManyToOne(optional = false)
   private WishList wishList;
   @Lob
   private String url;
   @Lob
   private String description;
   @AccessType("property")
   private int index;
   private String name;
   private int desiredQuantity;
   private int obtainedQuantity;
   private static final long serialVersionUID = 1;



Debug log:
This has the spring stuff thrown in along with the hibernate information. Hopefully it's of use rather than an annoyance since I'm using the spring transaction and session management facilities.
Code:
DEBUG - Publishing event in context [org.springframework.web.context.support.XmlWebApplicationContext@1609812]: ServletRequestHandledEvent: url=[/WishList/createList.form]; client=[127.0.0.1]; method=[GET]; servlet=[wishlist]; session=[b2f22f76032950b37e755ef96e1b]; user=[null]; time=[407ms]; status=[OK]
DEBUG - Publishing event in context [org.springframework.web.context.support.XmlWebApplicationContext@1e3d24a]: ServletRequestHandledEvent: url=[/WishList/createList.form]; client=[127.0.0.1]; method=[GET]; servlet=[wishlist]; session=[b2f22f76032950b37e755ef96e1b]; user=[null]; time=[407ms]; status=[OK]
DEBUG - DispatcherServlet with name 'wishlist' received request for [/WishList/createList.form]
DEBUG - Bound request context to thread: org.apache.coyote.tomcat5.CoyoteRequestFacade@1b0ed81
DEBUG - Testing handler map [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping@1832ae6] in DispatcherServlet with name 'wishlist'
DEBUG - Looking up handler for [/createList.form]
DEBUG - Opening single Hibernate Session in OpenSessionInViewInterceptor
DEBUG - Opening Hibernate Session
DEBUG - opened session at timestamp: 12175444419
DEBUG - setting flush mode to: NEVER
DEBUG - Bound value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] to thread [httpSSLWorkerThread-8080-1]
DEBUG - Testing handler adapter [org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter@184a7d6]
DEBUG - Testing handler adapter [org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter@896098]
DEBUG - Creating new command of class [org.icanttype.wishlist.web.NewListModel]
DEBUG - Invoking validator [org.icanttype.wishlist.web.NewListValidator@6fcd32]
DEBUG - Validator found no errors
DEBUG - No errors -> processing submit
DEBUG - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] bound to thread [httpSSLWorkerThread-8080-1]
DEBUG - Found thread-bound Session [org.hibernate.impl.SessionImpl@89e41] for Hibernate transaction
DEBUG - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@1cdc393]
DEBUG - Creating new transaction with name [org.icanttype.wishlist.repository.UserDao.getUserById]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly
DEBUG - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@89e41]
DEBUG - opening JDBC connection
DEBUG - Setting JDBC Connection [com.sun.gjc.spi.jdbc40.ConnectionHolder40@1e2ecec] read-only
DEBUG - begin
DEBUG - current autocommit status: true
DEBUG - disabling autocommit
DEBUG - after transaction begin
DEBUG - Exposing Hibernate transaction as JDBC transaction [com.sun.gjc.spi.jdbc40.ConnectionHolder40@1e2ecec]
DEBUG - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@1308c5c] for key [com.sun.gjc.spi.jdbc40.DataSource40@c58432] to thread [httpSSLWorkerThread-8080-1]
DEBUG - Initializing transaction synchronization
DEBUG - Getting transaction for [org.icanttype.wishlist.repository.UserDao.getUserById]
DEBUG - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] bound to thread [httpSSLWorkerThread-8080-1]
DEBUG - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] bound to thread [httpSSLWorkerThread-8080-1]
DEBUG - Found thread-bound Session for HibernateTemplate
DEBUG - loading entity: [org.icanttype.wishlist.domain.User#1]
DEBUG - creating new proxy for entity
DEBUG - Not closing pre-bound Hibernate Session after HibernateTemplate
DEBUG - Completing transaction for [org.icanttype.wishlist.repository.UserDao.getUserById]
DEBUG - Triggering beforeCommit synchronization
DEBUG - Triggering beforeCompletion synchronization
DEBUG - Initiating transaction commit
DEBUG - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@89e41]
DEBUG - commit
DEBUG - before transaction completion
DEBUG - before transaction completion
DEBUG - re-enabling autocommit
DEBUG - committed JDBC Connection
DEBUG - after transaction completion
DEBUG - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
DEBUG - after transaction completion
DEBUG - Triggering afterCommit synchronization
DEBUG - Triggering afterCompletion synchronization
DEBUG - Clearing transaction synchronization
DEBUG - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@1308c5c] for key [com.sun.gjc.spi.jdbc40.DataSource40@c58432] from thread [httpSSLWorkerThread-8080-1]
DEBUG - Resetting read-only flag of JDBC Connection [com.sun.gjc.spi.jdbc40.ConnectionHolder40@1e2ecec]
DEBUG - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@89e41] after transaction
DEBUG - disconnecting session
DEBUG - performing cleanup
DEBUG - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG - after transaction completion
DEBUG - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
DEBUG - after transaction completion
DEBUG - initializing proxy: [org.icanttype.wishlist.domain.User#1]
DEBUG - attempting to resolve: [org.icanttype.wishlist.domain.User#1]
DEBUG - object not resolved in any cache: [org.icanttype.wishlist.domain.User#1]
DEBUG - Fetching entity: [org.icanttype.wishlist.domain.User#1]
DEBUG - loading entity: [org.icanttype.wishlist.domain.User#1]
DEBUG - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG - opening JDBC connection
DEBUG -
    select
        user0_.id as id0_0_,
        user0_.email as email0_0_,
        user0_.first_name as first3_0_0_,
        user0_.last_name as last4_0_0_,
        user0_.password as password0_0_,
        user0_.username as username0_0_
    from
        users user0_
    where
        user0_.id=?
DEBUG - preparing statement
DEBUG - binding '1' to parameter: 1
DEBUG - about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG - processing result set
DEBUG - result set row: 0
DEBUG - result row: EntityKey[org.icanttype.wishlist.domain.User#1]
DEBUG - Initializing object from ResultSet: [org.icanttype.wishlist.domain.User#1]
DEBUG - Hydrating entity: [org.icanttype.wishlist.domain.User#1]
DEBUG - returning 'XXX' as column: email0_0_
DEBUG - returning 'XXX' as column: first3_0_0_
DEBUG - returning 'XXX' as column: last4_0_0_
DEBUG - returning 'XXX' as column: password0_0_
DEBUG - returning 'XXX' as column: username0_0_
DEBUG - done processing result set (1 rows)
DEBUG - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG - closing statement
DEBUG - total objects hydrated: 1
DEBUG - resolving associations for [org.icanttype.wishlist.domain.User#1]
DEBUG - creating collection wrapper:[org.icanttype.wishlist.domain.User.wishlists#1]
DEBUG - done materializing entity [org.icanttype.wishlist.domain.User#1]
DEBUG - initializing non-lazy collections
DEBUG - done entity load
DEBUG - Adding transactional method [updateUser] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT]
DEBUG - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] bound to thread [httpSSLWorkerThread-8080-1]
DEBUG - Found thread-bound Session [org.hibernate.impl.SessionImpl@89e41] for Hibernate transaction
DEBUG - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@174009b]
DEBUG - Creating new transaction with name [org.icanttype.wishlist.repository.UserDao.updateUser]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
DEBUG - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@89e41]
DEBUG - setting flush mode to: AUTO
DEBUG - begin
DEBUG - current autocommit status: true
DEBUG - disabling autocommit
DEBUG - after transaction begin
DEBUG - Exposing Hibernate transaction as JDBC transaction [com.sun.gjc.spi.jdbc40.ConnectionHolder40@d3d145]
DEBUG - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@502d56] for key [com.sun.gjc.spi.jdbc40.DataSource40@c58432] to thread [httpSSLWorkerThread-8080-1]
DEBUG - Initializing transaction synchronization
DEBUG - Getting transaction for [org.icanttype.wishlist.repository.UserDao.updateUser]
DEBUG - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] bound to thread [httpSSLWorkerThread-8080-1]
DEBUG - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] bound to thread [httpSSLWorkerThread-8080-1]
DEBUG - Found thread-bound Session for HibernateTemplate
DEBUG - ignoring persistent instance
DEBUG - object already associated with session: [org.icanttype.wishlist.domain.User#1]
DEBUG - Not closing pre-bound Hibernate Session after HibernateTemplate
DEBUG - Completing transaction for [org.icanttype.wishlist.repository.UserDao.updateUser]
DEBUG - Triggering beforeCommit synchronization
DEBUG - Triggering beforeCompletion synchronization
DEBUG - Initiating transaction commit
DEBUG - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@89e41]
DEBUG - commit
DEBUG - automatically flushing session
DEBUG - flushing session
DEBUG - processing flush-time cascades
DEBUG - processing cascade ACTION_SAVE_UPDATE for: org.icanttype.wishlist.domain.User
DEBUG - cascade ACTION_SAVE_UPDATE for collection: org.icanttype.wishlist.domain.User.wishlists
DEBUG - cascading to saveOrUpdate: org.icanttype.wishlist.domain.WishList
DEBUG - transient instance of: org.icanttype.wishlist.domain.WishList
DEBUG - saving transient instance
DEBUG - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG -
    select
        nextval ('wishlist_sequence')
DEBUG - preparing statement
DEBUG - Sequence identifier generated: 6
DEBUG - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG - closing statement
DEBUG - generated identifier: 6, using strategy: org.hibernate.id.SequenceGenerator
DEBUG - saving [org.icanttype.wishlist.domain.WishList#6]
DEBUG - processing cascade ACTION_SAVE_UPDATE for: org.icanttype.wishlist.domain.WishList
DEBUG - done processing cascade ACTION_SAVE_UPDATE for: org.icanttype.wishlist.domain.WishList
DEBUG - initializing collection [org.icanttype.wishlist.domain.User.wishlists#1]
DEBUG - checking second-level cache
DEBUG - collection not cached
DEBUG - loading collection: [org.icanttype.wishlist.domain.User.wishlists#1]
DEBUG - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
DEBUG -
    select
        wishlists0_.owner as owner1_,
        wishlists0_.id as id1_,
        wishlists0_.index as index1_,
        wishlists0_.id as id1_0_,
        wishlists0_.description as descript2_1_0_,
        wishlists0_.index as index1_0_,
        wishlists0_.name as name1_0_,
        wishlists0_.owner as owner1_0_,
        wishlists0_.viewable as viewable1_0_
    from
        wish_list wishlists0_
    where
        wishlists0_.owner=?
DEBUG - preparing statement
DEBUG - binding '1' to parameter: 1
DEBUG - about to open ResultSet (open ResultSets: 0, globally: 0)
DEBUG - result set contains (possibly empty) collection: [org.icanttype.wishlist.domain.User.wishlists#1]
DEBUG - constructing collection load context for result set [org.postgresql.jdbc3.Jdbc3ResultSet@1ccfec]
DEBUG - starting attempt to find loading collection [[org.icanttype.wishlist.domain.User.wishlists#1]]
DEBUG - collection not yet initialized; initializing
DEBUG - processing result set
DEBUG - done processing result set (0 rows)
DEBUG - about to close ResultSet (open ResultSets: 1, globally: 1)
DEBUG - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
DEBUG - closing statement
DEBUG - total objects hydrated: 0
DEBUG - attempting to locate loading collection entry [CollectionKey[org.icanttype.wishlist.domain.User.wishlists#1]] in any result-set context
DEBUG - collection [CollectionKey[org.icanttype.wishlist.domain.User.wishlists#1]] located in load context
DEBUG - removing collection load entry [org.hibernate.engine.loading.LoadingCollectionEntry<rs=org.postgresql.jdbc3.Jdbc3ResultSet@1ccfec, coll=[org.icanttype.wishlist.domain.User.wishlists#1]>@1969e65]
DEBUG - 1 collections were found in result set for role: org.icanttype.wishlist.domain.User.wishlists
DEBUG - ending loading collection [org.hibernate.engine.loading.LoadingCollectionEntry<rs=org.postgresql.jdbc3.Jdbc3ResultSet@1ccfec, coll=[org.icanttype.wishlist.domain.User.wishlists#1]>@1969e65]
DEBUG - collection fully initialized: [org.icanttype.wishlist.domain.User.wishlists#1]
DEBUG - 1 collections initialized for role: org.icanttype.wishlist.domain.User.wishlists
DEBUG - initializing non-lazy collections
DEBUG - done loading collection
DEBUG - collection initialized
DEBUG - Wrapped collection in role: org.icanttype.wishlist.domain.WishList.items
DEBUG - processing cascade ACTION_SAVE_UPDATE for: org.icanttype.wishlist.domain.WishList
DEBUG - cascade ACTION_SAVE_UPDATE for collection: org.icanttype.wishlist.domain.WishList.items
DEBUG - done cascade ACTION_SAVE_UPDATE for collection: org.icanttype.wishlist.domain.WishList.items
DEBUG - deleting orphans for collection: org.icanttype.wishlist.domain.WishList.items
DEBUG - done deleting orphans for collection: org.icanttype.wishlist.domain.WishList.items
DEBUG - done processing cascade ACTION_SAVE_UPDATE for: org.icanttype.wishlist.domain.WishList
DEBUG - Initiating transaction rollback after commit exception
java.lang.NullPointerException
        at org.hibernate.collection.AbstractPersistentCollection$1.hasNext(AbstractPersistentCollection.java:494)
        at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:295)
        at org.hibernate.engine.Cascade.cascadeCollection(Cascade.java:242)
        at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:219)
        at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169)
        at org.hibernate.engine.Cascade.cascade(Cascade.java:130)
        at org.hibernate.event.def.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:131)
        at org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:122)
        at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:65)
        at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
        at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
        at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
        at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
        at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:655)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:709)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:678)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy32.updateUser(Unknown Source)
        at org.icanttype.wishlist.web.CreateListController.onSubmit(CreateListController.java:33)
        at org.springframework.web.servlet.mvc.SimpleFormController.processFormSubmission(SimpleFormController.java:267)
        at org.springframework.web.servlet.mvc.AbstractFormController.handleRequestInternal(AbstractFormController.java:265)
        at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
        at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
        at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:511)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
        at org.apache.catalina.core.ApplicationFilterChain.servletService(ApplicationFilterChain.java:411)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:290)
        at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:271)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:202)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:94)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:206)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:150)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
        at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:272)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.invokeAdapter(DefaultProcessorTask.java:637)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.doProcess(DefaultProcessorTask.java:568)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.process(DefaultProcessorTask.java:813)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.executeProcessorTask(DefaultReadTask.java:341)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:263)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:214)
        at com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:265)
        at com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread.run(SSLWorkerThread.java:106)
DEBUG - Rolling back Hibernate transaction on Session [org.hibernate.impl.SessionImpl@89e41]
DEBUG - rollback
DEBUG - re-enabling autocommit
DEBUG - rolled back JDBC Connection
DEBUG - after transaction completion
DEBUG - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
DEBUG - after transaction completion
DEBUG - Triggering afterCompletion synchronization
DEBUG - Clearing transaction synchronization
DEBUG - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@502d56] for key [com.sun.gjc.spi.jdbc40.DataSource40@c58432] from thread [httpSSLWorkerThread-8080-1]
DEBUG - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@89e41] after transaction
DEBUG - setting flush mode to: NEVER
DEBUG - disconnecting session
DEBUG - performing cleanup
DEBUG - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
DEBUG - after transaction completion
DEBUG - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
DEBUG - after transaction completion
DEBUG - Removed value [org.springframework.orm.hibernate3.SessionHolder@b8c068] for key [org.hibernate.impl.SessionFactoryImpl@9e49c0] from thread [httpSSLWorkerThread-8080-1]
DEBUG - Closing single Hibernate Session in OpenSessionInViewInterceptor
DEBUG - Closing Hibernate Session
DEBUG - closing session
DEBUG - connection already null in cleanup : no action
DEBUG - Cleared thread-bound request context: org.apache.coyote.tomcat5.CoyoteRequestFacade@1b0ed81
DEBUG - Could not complete request
java.lang.NullPointerException
        at org.hibernate.collection.AbstractPersistentCollection$1.hasNext(AbstractPersistentCollection.java:494)
        at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:295)
        at org.hibernate.engine.Cascade.cascadeCollection(Cascade.java:242)
        at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:219)
        at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169)
        at org.hibernate.engine.Cascade.cascade(Cascade.java:130)
        at org.hibernate.event.def.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:131)
        at org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:122)
        at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:65)
        at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
        at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
        at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
        at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
        at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:655)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:709)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:678)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy32.updateUser(Unknown Source)
        at org.icanttype.wishlist.web.CreateListController.onSubmit(CreateListController.java:33)
        at org.springframework.web.servlet.mvc.SimpleFormController.processFormSubmission(SimpleFormController.java:267)
        at org.springframework.web.servlet.mvc.AbstractFormController.handleRequestInternal(AbstractFormController.java:265)
        at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
        at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
        at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:511)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
        at org.apache.catalina.core.ApplicationFilterChain.servletService(ApplicationFilterChain.java:411)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:290)
        at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:271)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:202)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:94)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:206)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:150)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
        at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:272)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.invokeAdapter(DefaultProcessorTask.java:637)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.doProcess(DefaultProcessorTask.java:568)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.process(DefaultProcessorTask.java:813)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.executeProcessorTask(DefaultReadTask.java:341)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:263)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:214)
        at com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:265)
        at com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread.run(SSLWorkerThread.java:106)
DEBUG - Publishing event in context [org.springframework.web.context.support.XmlWebApplicationContext@1609812]: ServletRequestHandledEvent: url=[/WishList/createList.form]; client=[127.0.0.1]; method=[POST]; servlet=[wishlist]; session=[b2f22f76032950b37e755ef96e1b]; user=[null]; time=[124ms]; status=[failed: java.lang.NullPointerException]
DEBUG - Publishing event in context [org.springframework.web.context.support.XmlWebApplicationContext@1e3d24a]: ServletRequestHandledEvent: url=[/WishList/createList.form]; client=[127.0.0.1]; method=[POST]; servlet=[wishlist]; session=[b2f22f76032950b37e755ef96e1b]; user=[null]; time=[124ms]; status=[failed: java.lang.NullPointerException]
StandardWrapperValve[wishlist]: PWC1406: Servlet.service() for servlet wishlist threw exception
java.lang.NullPointerException
        at org.hibernate.collection.AbstractPersistentCollection$1.hasNext(AbstractPersistentCollection.java:494)
        at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:295)
        at org.hibernate.engine.Cascade.cascadeCollection(Cascade.java:242)
        at org.hibernate.engine.Cascade.cascadeAssociation(Cascade.java:219)
        at org.hibernate.engine.Cascade.cascadeProperty(Cascade.java:169)
        at org.hibernate.engine.Cascade.cascade(Cascade.java:130)
        at org.hibernate.event.def.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:131)
        at org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:122)
        at org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:65)
        at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:26)
        at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
        at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338)
        at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
        at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:655)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:709)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:678)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy32.updateUser(Unknown Source)
        at org.icanttype.wishlist.web.CreateListController.onSubmit(CreateListController.java:33)
        at org.springframework.web.servlet.mvc.SimpleFormController.processFormSubmission(SimpleFormController.java:267)
        at org.springframework.web.servlet.mvc.AbstractFormController.handleRequestInternal(AbstractFormController.java:265)
        at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
        at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
        at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:511)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:738)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)
        at org.apache.catalina.core.ApplicationFilterChain.servletService(ApplicationFilterChain.java:411)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:290)
        at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:271)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:202)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:94)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:206)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:150)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
        at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
        at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571)
        at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080)
        at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:272)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.invokeAdapter(DefaultProcessorTask.java:637)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.doProcess(DefaultProcessorTask.java:568)
        at com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.process(DefaultProcessorTask.java:813)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.executeProcessorTask(DefaultReadTask.java:341)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:263)
        at com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:214)
        at com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:265)
        at com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread.run(SSLWorkerThread.java:106)
Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  Page 1 of 1
  [ 2 posts ] 

Board index » Hibernate & Java Persistence » Hibernate Users

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.