Here is my problem and I very much hope that one of you will take the time to show me the error of my ways.
The basic case is this. The app has a Persona class which is a user. Each user can have multiple ContactLists and each ContactList has multiple Contacts. Each Contact has some data (like user defined nickname), but they also have a reference to the contacts owner (Persona 1) and the contacts target (Persona 2). The association between ContacList and Contact is bidirectional through the contact.contactList property.
The problem is that when I delete the target of a Contact (Persona 2), I get a "not-null property references a null or transient value" exception at commit time on the contact.targetContact property because that Persona has been deleted. This contact shouldn't violate any constraints as it should be getting deleted because a contact has a single owning contactlist and I am removing the contact from that contactlist as part of deleting the Persona. I have traced through the code and the hibernate logs and it seems that hibernate it trying to update the contact before it deletes it. This is a problem because I have called delete() for the Persona and the update tries to set the contact's targetContact to NULL. It seems almost as if hibernate does not yet know that the contact is going to be deleted, but that is not the case because the exception is thrown WHILE trying to delete the Contact. If I remove the Not-null property from the Contact targetContact propety, I can see that hibernate is trying to Update the contact with a null targetContact before trying to delete it. Here is a picture of the runtime object relationships that should help understand a little bit better.
Code:
P1 -> CL1 <-> C1 ->P1 (owner)
->P2 (target)
P2 -> CL2 -> (empty).
I am trying to delete P2.
Hibernate version: 3.1
Mapping documents:Persona ClassCode:
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >
<hibernate-mapping>
<class name="tcbn.domainmodel.impl.PersonaImpl" table="persona">
<id column="OID" name="id">
<generator class="native"></generator>
</id>
<map name="contactListMap" table="contact_list" lazy="true" cascade="all-delete-orphan">
<key column="persona_oid" not-null="true"/>
<map-key-many-to-many column="contact_list_type_oid" class="tcbn.domainmodel.impl.ContactListTypeImpl"/>
<one-to-many class="tcbn.domainmodel.impl.ContactListImpl"/>
</map>
</class>
</hibernate-mapping>
ContactList classCode:
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >
<hibernate-mapping>
<class name="tcbn.domainmodel.impl.ContactListImpl" table="contact_list">
<id column="OID" name="id">
<generator class="native"></generator>
</id>
<many-to-one name="contactListType"
class="tcbn.domainmodel.impl.ContactListTypeImpl" column="contact_list_type_oid"
cascade="none" not-null="true" insert="false" update="false">
</many-to-one>
<set name="contacts" table="contact" lazy="true" inverse="true" cascade="all-delete-orphan">
<key column="contact_list_oid"></key>
<one-to-many class="tcbn.domainmodel.impl.ContactImpl"></one-to-many>
</set>
</class>
</hibernate-mapping>
Contact ClassCode:
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >
<hibernate-mapping>
<class name="tcbn.domainmodel.impl.ContactImpl" table="contact" batch-size="10">
<id column="OID" name="id">
<generator class="native"></generator>
</id>
<many-to-one name="owner"
class="tcbn.domainmodel.impl.PersonaImpl" column="owner_oid"
cascade="none" not-null="true" index="contact_ownerOid_idx">
</many-to-one>
<many-to-one name="targetContact"
class="tcbn.domainmodel.impl.PersonaImpl" column="target_contact_oid"
cascade="none" not-null="true" index="contact_targetConteactOid_idx">
</many-to-one>
<many-to-one name="contactList"
class="tcbn.domainmodel.impl.ContactListImpl" column="contact_list_oid"
cascade="none" not-null="true" index="contact_contactListOid_idx">
</many-to-one>
</class>
</hibernate-mapping>
ContactListType class - this functions as an enumCode:
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 3.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd" >
<hibernate-mapping>
<class name="tcbn.domainmodel.impl.ContactListTypeImpl" table="contact_list_type">
<id column="OID" name="id">
<generator class="native"></generator>
</id>
<property name="name" column="name" type="string" unique="true" not-null="true"></property>
</class>
</hibernate-mapping>
Code between sessionFactory.openSession() and session.close():Unit test excerptCode:
public void testDeleteContactsTargetPersona() throws Exception {
{
Persona owner1 = personaFixture.getPersona("user", 0);
Persona target1 = personaFixture.getPersona("user", 1);
ContactList ownerBlocked1 = owner1.getContactList("blocked");
ContactDao contactDao = (ContactDao)springFixture.getBean("contactDao");
Contact contact1 = contactDao.create("contact11", target1, owner1);
ownerBlocked1.add( contact1 );
//commit
getSessionFixture().endSession();
getSessionFixture().startSession();
}
{
PersonaDao dao = (PersonaDao)springFixture.getBean("personaDao");
Persona target1 = personaFixture.getPersona("user", 1);
dao.delete(target1);
//commit
try{
getSessionFixture().endSession();
}catch( Exception e ){
e.printStackTrace();
}
PersonaDao excerptCode:
public void delete(Persona persona){
//getAllContactsToPersona = "from ContactImpl contact where contact.targetContact = ?"
Session s = getHibernateTemplate().getSessionFactory().getCurrentSession();
List<Contact> reverseContacts =
getHibernateTemplate().findByNamedQuery("getAllContactsToPersona", persona);
for( Contact contact : reverseContacts ){
contact.getContactList().remove(contact);
}
getHibernateTemplate().delete(persona);
}
ContactList remove methodCode:
public void remove(Contact contact){
contacts.remove(contact);
contact.setContactList(null);
}
Full stack trace of any exception that occurs:Code:
org.hibernate.PropertyValueException: not-null property references a null or transient value: tcbn.domainmodel.impl.ContactImpl.targetContact
at org.hibernate.engine.Nullability.checkNullability(Nullability.java:72)
at org.hibernate.event.def.DefaultDeleteEventListener.deleteEntity(DefaultDeleteEventListener.java:173)
at org.hibernate.event.def.DefaultDeleteEventListener.onDelete(DefaultDeleteEventListener.java:110)
at org.hibernate.impl.SessionImpl.fireDelete(SessionImpl.java:761)
at org.hibernate.impl.SessionImpl.delete(SessionImpl.java:753)
at org.hibernate.engine.Cascade.deleteOrphans(Cascade.java:351)
at org.hibernate.engine.Cascade.cascadeCollectionElements(Cascade.java:318)
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 tcbn.runtime.impl.DomainEntityRepository$FlushEventCallback.onFlush(DomainEntityRepository.java:165)
at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:985)
at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:333)
at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
at unit.fixtures.SessionFixture.endSession(SessionFixture.java:59)
at unit.tcbn.domainmodel.ContactDaoTest.testDeleteContactsTargetPersona(ContactDaoTest.java:625)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.junit.internal.runners.TestMethodRunner.executeMethodBody(TestMethodRunner.java:99)
at org.junit.internal.runners.TestMethodRunner.runUnprotected(TestMethodRunner.java:81)
at org.junit.internal.runners.BeforeAndAfterRunner.runProtected(BeforeAndAfterRunner.java:34)
at org.junit.internal.runners.TestMethodRunner.runMethod(TestMethodRunner.java:75)
at org.junit.internal.runners.TestMethodRunner.run(TestMethodRunner.java:45)
at org.junit.internal.runners.TestClassMethodsRunner.invokeTestMethod(TestClassMethodsRunner.java:71)
at org.junit.internal.runners.TestClassMethodsRunner.run(TestClassMethodsRunner.java:35)
Name and version of the database you are using:Oracle 10g
The generated SQL (show_sql=true):With the Not-null property on Contact.targetContact, I get the following exception. This is the primary problem.
Code:
Hibernate: select contactimp0_.OID as OID11_, contactimp0_.internal_version as internal2_11_, contactimp0_.last_modified as last3_11_, contactimp0_.entity_version as entity4_11_, contactimp0_.created_timestamp as created5_11_, contactimp0_.nickname as nickname11_, contactimp0_.owner_oid as owner7_11_, contactimp0_.target_contact_oid as target8_11_, contactimp0_.contact_list_oid as contact9_11_ from contact contactimp0_ where contactimp0_.target_contact_oid=?
Hibernate: select contactlis0_.OID as OID9_0_, contactlis0_.internal_version as internal2_9_0_, contactlis0_.last_modified as last3_9_0_, contactlis0_.entity_version as entity4_9_0_, contactlis0_.created_timestamp as created5_9_0_, contactlis0_.contact_list_type_oid as contact6_9_0_ from contact_list contactlis0_ where contactlis0_.OID=?
Hibernate: select contacts0_.contact_list_oid as contact9_1_, contacts0_.OID as OID1_, contacts0_.OID as OID11_0_, contacts0_.internal_version as internal2_11_0_, contacts0_.last_modified as last3_11_0_, contacts0_.entity_version as entity4_11_0_, contacts0_.created_timestamp as created5_11_0_, contacts0_.nickname as nickname11_0_, contacts0_.owner_oid as owner7_11_0_, contacts0_.target_contact_oid as target8_11_0_, contacts0_.contact_list_oid as contact9_11_0_ from contact contacts0_ where contacts0_.contact_list_oid=?
Hibernate: select personaimp0_.OID as OID4_0_, personaimp0_.internal_version as internal2_4_0_, personaimp0_.last_modified as last3_4_0_, personaimp0_.entity_version as entity4_4_0_, personaimp0_.created_timestamp as created5_4_0_, personaimp0_.user_name as user6_4_0_, personaimp0_.principal_id as principal7_4_0_, personaimp0_.member_level as member8_4_0_, personaimp0_.join_date as join9_4_0_, personaimp0_.last_login_date as last10_4_0_, personaimp0_.banned as banned4_0_, personaimp0_.persona_type_oid as persona12_4_0_, personaimp0_.profile_oid as profile13_4_0_ from persona personaimp0_ where personaimp0_.OID=?
Hibernate: select personatyp0_.OID as OID5_0_, personatyp0_.internal_version as internal2_5_0_, personatyp0_.entity_version as entity3_5_0_, personatyp0_.created_timestamp as created4_5_0_, personatyp0_.last_modified as last5_5_0_, personatyp0_.name as name5_0_ from persona_type personatyp0_ where personatyp0_.OID=?
Hibernate: select personaimp0_.OID as OID4_0_, personaimp0_.internal_version as internal2_4_0_, personaimp0_.last_modified as last3_4_0_, personaimp0_.entity_version as entity4_4_0_, personaimp0_.created_timestamp as created5_4_0_, personaimp0_.user_name as user6_4_0_, personaimp0_.principal_id as principal7_4_0_, personaimp0_.member_level as member8_4_0_, personaimp0_.join_date as join9_4_0_, personaimp0_.last_login_date as last10_4_0_, personaimp0_.banned as banned4_0_, personaimp0_.persona_type_oid as persona12_4_0_, personaimp0_.profile_oid as profile13_4_0_ from persona personaimp0_ where personaimp0_.OID=?
Hibernate: select contactlis0_.persona_oid as persona7_1_, contactlis0_.OID as OID1_, contactlis0_.contact_list_type_oid as contact6_1_, contactlis0_.OID as OID9_0_, contactlis0_.internal_version as internal2_9_0_, contactlis0_.last_modified as last3_9_0_, contactlis0_.entity_version as entity4_9_0_, contactlis0_.created_timestamp as created5_9_0_, contactlis0_.contact_list_type_oid as contact6_9_0_ from contact_list contactlis0_ where contactlis0_.persona_oid=?
Hibernate: select contactlis0_.OID as OID10_0_, contactlis0_.internal_version as internal2_10_0_, contactlis0_.entity_version as entity3_10_0_, contactlis0_.created_timestamp as created4_10_0_, contactlis0_.last_modified as last5_10_0_, contactlis0_.name as name10_0_ from contact_list_type contactlis0_ where contactlis0_.OID=?
Hibernate: select contactlis0_.OID as OID10_0_, contactlis0_.internal_version as internal2_10_0_, contactlis0_.entity_version as entity3_10_0_, contactlis0_.created_timestamp as created4_10_0_, contactlis0_.last_modified as last5_10_0_, contactlis0_.name as name10_0_ from contact_list_type contactlis0_ where contactlis0_.OID=?
Hibernate: select contacts0_.contact_list_oid as contact9_1_, contacts0_.OID as OID1_, contacts0_.OID as OID11_0_, contacts0_.internal_version as internal2_11_0_, contacts0_.last_modified as last3_11_0_, contacts0_.entity_version as entity4_11_0_, contacts0_.created_timestamp as created5_11_0_, contacts0_.nickname as nickname11_0_, contacts0_.owner_oid as owner7_11_0_, contacts0_.target_contact_oid as target8_11_0_, contacts0_.contact_list_oid as contact9_11_0_ from contact contacts0_ where contacts0_.contact_list_oid=?
Hibernate: select contacts0_.contact_list_oid as contact9_1_, contacts0_.OID as OID1_, contacts0_.OID as OID11_0_, contacts0_.internal_version as internal2_11_0_, contacts0_.last_modified as last3_11_0_, contacts0_.entity_version as entity4_11_0_, contacts0_.created_timestamp as created5_11_0_, contacts0_.nickname as nickname11_0_, contacts0_.owner_oid as owner7_11_0_, contacts0_.target_contact_oid as target8_11_0_, contacts0_.contact_list_oid as contact9_11_0_ from contact contacts0_ where contacts0_.contact_list_oid=?
Hibernate: select profileimp0_.OID as OID6_0_, profileimp0_.internal_version as internal2_6_0_, profileimp0_.last_modified as last3_6_0_, profileimp0_.entity_version as entity4_6_0_, profileimp0_.created_timestamp as created5_6_0_, profileimp0_.location as location6_0_, profileimp0_.motto as motto6_0_, profileimp0_.avatar as avatar6_0_, profileimp0_.comedic_persona as comedic9_6_0_, options1_.profile_oid as profile1_2_, options1_.value as value2_, options1_.name as name2_ from profile profileimp0_ left outer join preferences options1_ on profileimp0_.OID=options1_.profile_oid where profileimp0_.OID=?
Hibernate: select resourceli0_.profile_oid as profile8_1_, resourceli0_.OID as OID1_, resourceli0_.sequence_number as sequence9_1_, resourceli0_.OID as OID8_0_, resourceli0_.internal_version as internal2_8_0_, resourceli0_.entity_version as entity3_8_0_, resourceli0_.created_timestamp as created4_8_0_, resourceli0_.last_modified as last5_8_0_, resourceli0_.name as name8_0_, resourceli0_.uri as uri8_0_, resourceli0_.profile_oid as profile8_8_0_ from resource_link resourceli0_ where resourceli0_.profile_oid=?
Without the Not-Null property in Contact.targetContact, I get the following. I only did this test to see if more information was logged. SQL:
Code:
Hibernate: select contactimp0_.OID as OID11_, contactimp0_.internal_version as internal2_11_, contactimp0_.last_modified as last3_11_, contactimp0_.entity_version as entity4_11_, contactimp0_.created_timestamp as created5_11_, contactimp0_.nickname as nickname11_, contactimp0_.owner_oid as owner7_11_, contactimp0_.target_contact_oid as target8_11_, contactimp0_.contact_list_oid as contact9_11_ from contact contactimp0_ where contactimp0_.target_contact_oid=?
Hibernate: select contactlis0_.OID as OID9_0_, contactlis0_.internal_version as internal2_9_0_, contactlis0_.last_modified as last3_9_0_, contactlis0_.entity_version as entity4_9_0_, contactlis0_.created_timestamp as created5_9_0_, contactlis0_.contact_list_type_oid as contact6_9_0_ from contact_list contactlis0_ where contactlis0_.OID=?
Hibernate: select contacts0_.contact_list_oid as contact9_1_, contacts0_.OID as OID1_, contacts0_.OID as OID11_0_, contacts0_.internal_version as internal2_11_0_, contacts0_.last_modified as last3_11_0_, contacts0_.entity_version as entity4_11_0_, contacts0_.created_timestamp as created5_11_0_, contacts0_.nickname as nickname11_0_, contacts0_.owner_oid as owner7_11_0_, contacts0_.target_contact_oid as target8_11_0_, contacts0_.contact_list_oid as contact9_11_0_ from contact contacts0_ where contacts0_.contact_list_oid=?
Hibernate: select personaimp0_.OID as OID4_0_, personaimp0_.internal_version as internal2_4_0_, personaimp0_.last_modified as last3_4_0_, personaimp0_.entity_version as entity4_4_0_, personaimp0_.created_timestamp as created5_4_0_, personaimp0_.user_name as user6_4_0_, personaimp0_.principal_id as principal7_4_0_, personaimp0_.member_level as member8_4_0_, personaimp0_.join_date as join9_4_0_, personaimp0_.last_login_date as last10_4_0_, personaimp0_.banned as banned4_0_, personaimp0_.persona_type_oid as persona12_4_0_, personaimp0_.profile_oid as profile13_4_0_ from persona personaimp0_ where personaimp0_.OID=?
Hibernate: select personatyp0_.OID as OID5_0_, personatyp0_.internal_version as internal2_5_0_, personatyp0_.entity_version as entity3_5_0_, personatyp0_.created_timestamp as created4_5_0_, personatyp0_.last_modified as last5_5_0_, personatyp0_.name as name5_0_ from persona_type personatyp0_ where personatyp0_.OID=?
Hibernate: select personaimp0_.OID as OID4_0_, personaimp0_.internal_version as internal2_4_0_, personaimp0_.last_modified as last3_4_0_, personaimp0_.entity_version as entity4_4_0_, personaimp0_.created_timestamp as created5_4_0_, personaimp0_.user_name as user6_4_0_, personaimp0_.principal_id as principal7_4_0_, personaimp0_.member_level as member8_4_0_, personaimp0_.join_date as join9_4_0_, personaimp0_.last_login_date as last10_4_0_, personaimp0_.banned as banned4_0_, personaimp0_.persona_type_oid as persona12_4_0_, personaimp0_.profile_oid as profile13_4_0_ from persona personaimp0_ where personaimp0_.OID=?
Hibernate: select contactlis0_.persona_oid as persona7_1_, contactlis0_.OID as OID1_, contactlis0_.contact_list_type_oid as contact6_1_, contactlis0_.OID as OID9_0_, contactlis0_.internal_version as internal2_9_0_, contactlis0_.last_modified as last3_9_0_, contactlis0_.entity_version as entity4_9_0_, contactlis0_.created_timestamp as created5_9_0_, contactlis0_.contact_list_type_oid as contact6_9_0_ from contact_list contactlis0_ where contactlis0_.persona_oid=?
Hibernate: select contactlis0_.OID as OID10_0_, contactlis0_.internal_version as internal2_10_0_, contactlis0_.entity_version as entity3_10_0_, contactlis0_.created_timestamp as created4_10_0_, contactlis0_.last_modified as last5_10_0_, contactlis0_.name as name10_0_ from contact_list_type contactlis0_ where contactlis0_.OID=?
Hibernate: select contactlis0_.OID as OID10_0_, contactlis0_.internal_version as internal2_10_0_, contactlis0_.entity_version as entity3_10_0_, contactlis0_.created_timestamp as created4_10_0_, contactlis0_.last_modified as last5_10_0_, contactlis0_.name as name10_0_ from contact_list_type contactlis0_ where contactlis0_.OID=?
Hibernate: select contacts0_.contact_list_oid as contact9_1_, contacts0_.OID as OID1_, contacts0_.OID as OID11_0_, contacts0_.internal_version as internal2_11_0_, contacts0_.last_modified as last3_11_0_, contacts0_.entity_version as entity4_11_0_, contacts0_.created_timestamp as created5_11_0_, contacts0_.nickname as nickname11_0_, contacts0_.owner_oid as owner7_11_0_, contacts0_.target_contact_oid as target8_11_0_, contacts0_.contact_list_oid as contact9_11_0_ from contact contacts0_ where contacts0_.contact_list_oid=?
Hibernate: select contacts0_.contact_list_oid as contact9_1_, contacts0_.OID as OID1_, contacts0_.OID as OID11_0_, contacts0_.internal_version as internal2_11_0_, contacts0_.last_modified as last3_11_0_, contacts0_.entity_version as entity4_11_0_, contacts0_.created_timestamp as created5_11_0_, contacts0_.nickname as nickname11_0_, contacts0_.owner_oid as owner7_11_0_, contacts0_.target_contact_oid as target8_11_0_, contacts0_.contact_list_oid as contact9_11_0_ from contact contacts0_ where contacts0_.contact_list_oid=?
Hibernate: select profileimp0_.OID as OID6_0_, profileimp0_.internal_version as internal2_6_0_, profileimp0_.last_modified as last3_6_0_, profileimp0_.entity_version as entity4_6_0_, profileimp0_.created_timestamp as created5_6_0_, profileimp0_.location as location6_0_, profileimp0_.motto as motto6_0_, profileimp0_.avatar as avatar6_0_, profileimp0_.comedic_persona as comedic9_6_0_, options1_.profile_oid as profile1_2_, options1_.value as value2_, options1_.name as name2_ from profile profileimp0_ left outer join preferences options1_ on profileimp0_.OID=options1_.profile_oid where profileimp0_.OID=?
Hibernate: select resourceli0_.profile_oid as profile8_1_, resourceli0_.OID as OID1_, resourceli0_.sequence_number as sequence9_1_, resourceli0_.OID as OID8_0_, resourceli0_.internal_version as internal2_8_0_, resourceli0_.entity_version as entity3_8_0_, resourceli0_.created_timestamp as created4_8_0_, resourceli0_.last_modified as last5_8_0_, resourceli0_.name as name8_0_, resourceli0_.uri as uri8_0_, resourceli0_.profile_oid as profile8_8_0_ from resource_link resourceli0_ where resourceli0_.profile_oid=?
Hibernate: update contact set internal_version=?, last_modified=?, entity_version=?, created_timestamp=?, nickname=?, owner_oid=?, target_contact_oid=?, contact_list_oid=? where OID=? and internal_version=?
Code:
Hibernate: update contact_list set internal_version=?, last_modified=?, entity_version=?, created_timestamp=? where OID=? and internal_version=?
Hibernate: update contact set internal_version=?, last_modified=?, entity_version=?, created_timestamp=?, nickname=?, owner_oid=?, target_contact_oid=?, contact_list_oid=? where OID=? and internal_version=?
Debug level Hibernate log excerpt:
The full log keeps getting cut off when I submit, so here the last little bit.
10:36:09,179 DEBUG BooleanType:122 - returning 'false' as column: value2_
10:36:09,179 DEBUG StringType:122 - returning 'groupNotify' as column: name2_
10:36:09,179 DEBUG Loader:687 - result set row: 6
10:36:09,179 DEBUG Loader:1164 - result row: EntityKey[tcbn.domainmodel.impl.ProfileImpl#18]
10:36:09,179 DEBUG LongType:122 - returning '18' as column: profile1_2_
10:36:09,179 DEBUG Loader:972 - found row of collection: [tcbn.domainmodel.impl.ProfileImpl.options#18]
10:36:09,179 DEBUG CollectionLoadContext:112 - reading row
10:36:09,179 DEBUG BooleanType:122 - returning 'false' as column: value2_
10:36:09,189 DEBUG StringType:122 - returning 'uploadCommentNotify' as column: name2_
10:36:09,189 DEBUG Loader:687 - result set row: 7
10:36:09,189 DEBUG Loader:1164 - result row: EntityKey[tcbn.domainmodel.impl.ProfileImpl#18]
10:36:09,189 DEBUG LongType:122 - returning '18' as column: profile1_2_
10:36:09,189 DEBUG Loader:972 - found row of collection: [tcbn.domainmodel.impl.ProfileImpl.options#18]
10:36:09,189 DEBUG CollectionLoadContext:112 - reading row
10:36:09,189 DEBUG BooleanType:122 - returning 'false' as column: value2_
10:36:09,189 DEBUG StringType:122 - returning 'shareVideoNotify' as column: name2_
10:36:09,189 DEBUG Loader:709 - done processing result set (8 rows)
10:36:09,189 DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
10:36:09,189 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:36:09,189 DEBUG AbstractBatcher:470 - closing statement
10:36:09,189 DEBUG Loader:839 - total objects hydrated: 1
10:36:09,189 DEBUG TwoPhaseLoad:107 - resolving associations for [tcbn.domainmodel.impl.ProfileImpl#18]
10:36:09,189 DEBUG CollectionLoadContext:132 - returning loading collection:[tcbn.domainmodel.impl.ProfileImpl.options#18]
10:36:09,199 DEBUG CollectionLoadContext:141 - creating collection wrapper:[tcbn.domainmodel.impl.ProfileImpl.resourceLinks#18]
10:36:09,199 DEBUG TwoPhaseLoad:206 - done materializing entity [tcbn.domainmodel.impl.ProfileImpl#18]
10:36:09,199 DEBUG CollectionLoadContext:262 - 1 collections were found in result set for role: tcbn.domainmodel.impl.ProfileImpl.options
10:36:09,199 DEBUG CollectionLoadContext:206 - collection fully initialized: [tcbn.domainmodel.impl.ProfileImpl.options#18]
10:36:09,199 DEBUG CollectionLoadContext:272 - 1 collections initialized for role: tcbn.domainmodel.impl.ProfileImpl.options
10:36:09,199 DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
10:36:09,199 DEBUG Loader:1808 - done entity load
10:36:09,199 DEBUG DefaultDeleteEventListener:90 - deleting a persistent instance
10:36:09,199 DEBUG DefaultDeleteEventListener:127 - deleting [tcbn.domainmodel.impl.ProfileImpl#18]
10:36:09,199 DEBUG SessionImpl:1272 - setting cache mode to: GET
10:36:09,199 DEBUG Cascade:237 - processing cascade ACTION_DELETE for: tcbn.domainmodel.impl.ProfileImpl
10:36:09,209 DEBUG Cascade:285 - cascade ACTION_DELETE for collection: tcbn.domainmodel.impl.ProfileImpl.resourceLinks
10:36:09,209 DEBUG DefaultInitializeCollectionEventListener:41 - initializing collection [tcbn.domainmodel.impl.ProfileImpl.resourceLinks#18]
10:36:09,209 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
10:36:09,209 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
10:36:09,209 DEBUG Loader:1911 - loading collection: [tcbn.domainmodel.impl.ProfileImpl.resourceLinks#18]
10:36:09,209 DEBUG AbstractBatcher:311 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:36:09,209 DEBUG SQL:346 - select resourceli0_.profile_oid as profile8_1_, resourceli0_.OID as OID1_, resourceli0_.sequence_number as sequence9_1_, resourceli0_.OID as OID8_0_, resourceli0_.internal_version as internal2_8_0_, resourceli0_.entity_version as entity3_8_0_, resourceli0_.created_timestamp as created4_8_0_, resourceli0_.last_modified as last5_8_0_, resourceli0_.name as name8_0_, resourceli0_.uri as uri8_0_, resourceli0_.profile_oid as profile8_8_0_ from resource_link resourceli0_ where resourceli0_.profile_oid=?
10:36:09,209 DEBUG AbstractBatcher:424 - preparing statement
10:36:09,219 DEBUG LongType:80 - binding '18' to parameter: 1
10:36:09,229 DEBUG AbstractBatcher:327 - about to open ResultSet (open ResultSets: 0, globally: 0)
10:36:09,229 DEBUG Loader:1040 - result set contains (possibly empty) collection: [tcbn.domainmodel.impl.ProfileImpl.resourceLinks#18]
10:36:09,229 DEBUG CollectionLoadContext:84 - uninitialized collection: initializing
10:36:09,229 DEBUG Loader:682 - processing result set
10:36:09,229 DEBUG Loader:709 - done processing result set (0 rows)
10:36:09,239 DEBUG AbstractBatcher:334 - about to close ResultSet (open ResultSets: 1, globally: 1)
10:36:09,239 DEBUG AbstractBatcher:319 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:36:09,239 DEBUG AbstractBatcher:470 - closing statement
10:36:09,239 DEBUG Loader:839 - total objects hydrated: 0
10:36:09,239 DEBUG CollectionLoadContext:262 - 1 collections were found in result set for role: tcbn.domainmodel.impl.ProfileImpl.resourceLinks
10:36:09,239 DEBUG CollectionLoadContext:206 - collection fully initialized: [tcbn.domainmodel.impl.ProfileImpl.resourceLinks#18]
10:36:09,239 DEBUG CollectionLoadContext:272 - 1 collections initialized for role: tcbn.domainmodel.impl.ProfileImpl.resourceLinks
10:36:09,239 DEBUG StatefulPersistenceContext:748 - initializing non-lazy collections
10:36:09,239 DEBUG Loader:1935 - done loading collection
10:36:09,239 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
10:36:09,239 DEBUG Cascade:300 - done cascade ACTION_DELETE for collection: tcbn.domainmodel.impl.ProfileImpl.resourceLinks
10:36:09,239 DEBUG Cascade:311 - deleting orphans for collection: tcbn.domainmodel.impl.ProfileImpl.resourceLinks
10:36:09,239 DEBUG Cascade:321 - done deleting orphans for collection: tcbn.domainmodel.impl.ProfileImpl.resourceLinks
10:36:09,239 DEBUG Cascade:259 - done processing cascade ACTION_DELETE for: tcbn.domainmodel.impl.ProfileImpl
10:36:09,239 DEBUG SessionImpl:1272 - setting cache mode to: GET
10:36:09,249 DEBUG SessionImpl:1272 - setting cache mode to: GET
10:36:09,249 DEBUG Cascade:237 - processing cascade ACTION_DELETE for: tcbn.domainmodel.impl.ProfileImpl
10:36:09,249 DEBUG Cascade:259 - done processing cascade ACTION_DELETE for: tcbn.domainmodel.impl.ProfileImpl
10:36:09,249 DEBUG SessionImpl:1272 - setting cache mode to: GET
10:36:09,249 DEBUG Cascade:259 - done processing cascade ACTION_DELETE for: tcbn.domainmodel.impl.PersonaImpl
10:36:09,249 DEBUG SessionImpl:1272 - setting cache mode to: NORMAL
10:36:09,249 DEBUG HibernateTemplate:382 - Not closing pre-bound Hibernate Session after HibernateTemplate
10:37:21,152 DEBUG DefaultListableBeanFactory:189 - Returning cached instance of singleton bean 'sessionFactory'
10:37:21,162 DEBUG DefaultListableBeanFactory:818 - Bean with name 'sessionFactory' is a factory bean
10:37:21,162 DEBUG TransactionSynchronizationManager:185 - Removed value [org.springframework.orm.hibernate3.SessionHolder@fc5408] for key [org.hibernate.impl.SessionFactoryImpl@1987298] from thread [main]
10:37:21,172 DEBUG JDBCTransaction:54 - begin
10:37:21,172 DEBUG JDBCTransaction:59 - current autocommit status: false
10:37:21,172 DEBUG JDBCContext:194 - after transaction begin
10:37:21,172 DEBUG JDBCTransaction:103 - commit
10:37:21,182 DEBUG SessionImpl:332 - automatically flushing session
10:37:21,182 DEBUG AbstractFlushingEventListener:58 - flushing session
10:37:21,182 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
10:37:21,192 DEBUG Cascade:237 - processing cascade ACTION_SAVE_UPDATE for: tcbn.domainmodel.impl.ContactListImpl
10:37:21,192 DEBUG Cascade:285 - cascade ACTION_SAVE_UPDATE for collection: tcbn.domainmodel.impl.ContactListImpl.contacts
10:37:21,202 DEBUG Cascade:300 - done cascade ACTION_SAVE_UPDATE for collection: tcbn.domainmodel.impl.ContactListImpl.contacts
10:37:21,202 DEBUG Cascade:311 - deleting orphans for collection: tcbn.domainmodel.impl.ContactListImpl.contacts
10:37:21,202 DEBUG Cascade:349 - deleting orphaned entity instance: tcbn.domainmodel.impl.ContactImpl
10:37:21,212 DEBUG DefaultDeleteEventListener:90 - deleting a persistent instance
10:37:21,212 DEBUG DefaultDeleteEventListener:127 - deleting [tcbn.domainmodel.impl.ContactImpl#26]
10:37:21,222 DEBUG SessionImpl:1272 - setting cache mode to: GET
10:37:21,222 DEBUG SessionImpl:1272 - setting cache mode to: NORMAL