-->
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
  [ 3 posts ] 
  Previous topic | Next topic 
Author Message
ertnutler
 Post subject: cascade confusion
PostPosted: Tue Oct 18, 2005 6:44 am 
Newbie

Joined: Wed Mar 23, 2005 9:33 am
Posts: 11
Hey, all. Just a quick clarification before I bother anyone with my source. I have an object at the head of a graph (Customer), with cascade set to save-update on its one-to-many (ShippingProfile) and many-to-one (BillingAddress). The code to create and update this graph is _exactly_ the same:

1. check the HTTP Session for an instance of the Customer, if it's not there, create an instance, overwrite its fields with the values from the current HTTP Request. do the same for the constituent objects.

2. call saveOrUpdate(customer).

As expected, Hibernate works wonderfully during the create sequence: all my relationships are flushed to the DB; transaction commits. Glorious.

However, when I try to execute the same code against the same (now detached) object graph, Hibernate flushes the updates to the Customer object (the one at the head of the graph), but ignores the (now dirty) associations. In the debug output, I see "ignoring persistent instance" for the dirty constituent objects that I'd like Hibernate to update and flush.

Am I missing something here? My understanding is that Hibernate will detect the changes to the associated objects and issue updates for them as well. The only thing that I can think of is that Hibernate is actively ignoring these object because they already exists in the session (by virtue of being attached to the Customer instance). According to section 11.7 of the 3.x reference, "saveOrUpdate() does the following: if the object is already persistent in this session, do nothing".

Do I need to evict the constituents to make this work? Any suggestions? This seems like a rather common usage for detached objects, so I'm sure I've botched something. Thanks in advance for any help...
Top
 Profile  
 
jw3525
 Post subject:
PostPosted: Thu Oct 20, 2005 10:01 pm 
Regular
Regular

Joined: Sat Aug 28, 2004 4:15 pm
Posts: 61
That is definitely a very common transitive persistence scenario.

You should post your mappings.

_________________
Joe W

Top
 Profile  
 
ertnutler
 Post subject:
PostPosted: Fri Oct 21, 2005 8:57 am 
Newbie

Joined: Wed Mar 23, 2005 9:33 am
Posts: 11
okay, i wrote a test case that simulates the behavior. i've pasted that below along with my mappings and debug level output.

you'll notice that hibernate cascades the save-update, but it always outputs "ignoring persistent instance...object already associated with session".

i'm pulling my hair out here. somebody please tell me i'm doing something stupid.

mySQL 4.1.11
windows xp
jdk 1.5.03
hibernate 3.0.3

Code:
public void testFlush() throws Exception {
      System.out.println("==> begin test <==");
      Customer cust = new Customer();
      cust.setFirstName("first");
      cust.setLastName("last");
      cust.setEmail("email");
      cust.setCompany("company");
      cust.setPhone("phone");
      cust.setAlternatePhone("altphone");

      Address billAddress = new Address();
      billAddress.setAddress1("address1");
      billAddress.setAddress2("address2");
      billAddress.setCity("city");
      billAddress.setState("VA");
      billAddress.setZip("99999");

      cust.setBillingAddress(billAddress);

      ShippingProfile profile = new ShippingProfile();
      profile.setFirstName("shipFirst");
      profile.setLastName("shipLast");
      profile.setEmail("shipEmail");
      profile.setCompany("shipCompany");
      profile.setPhone("shipPhone");
      profile.setAlternatePhone("shipAlternatePhone");

      Address shipAddress = new Address();
      shipAddress.setAddress1("address1");
      shipAddress.setAddress2("address2");
      shipAddress.setCity("city");
      shipAddress.setState("VA");
      shipAddress.setZip("20155");

      profile.setAddress(shipAddress);
      cust.addShippingProfile(profile);

      Session sess = getSession();
      System.out.println("session hash: " + sess.hashCode());
      Transaction tx = sess.beginTransaction();
      sess.saveOrUpdate(cust);
      sess.flush();
      tx.commit();
      sess.close();

      cust.setFirstName("ert");
      cust.setLastName("nutler");
      cust.getBillingAddress().setAddress1("123 nutler way");

      Set s = cust.getShippingProfiles();
      ShippingProfile sp = (ShippingProfile)s.iterator().next();
      sp.setFirstName("ernie");
      sp.getAddress().setCity("shiptocity");

      System.out.println("");
      System.out.println("==> opening second session <==");
      System.out.println("");

      sess = getSession();
      System.out.println("session hash: " + sess.hashCode());
      tx = sess.beginTransaction();
      sess.saveOrUpdate(cust);
      sess.flush();
      tx.commit();
      sess.close();
}

<?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="com.threeg.commerce.model">

   <class
      name="Customer"
      table="customer"
      >

      <id
         name="id"
         type="java.lang.Long"
         column="customer_id"
         >
         <generator class="native"/>
      </id>

      <version name="version" column="version" access="field"/>

      <property
         name="firstName"
         type="java.lang.String"
         column="first_name"
         not-null="true"
         length="50"
         >
      </property>
      <property
         name="middleInitial"
         type="java.lang.String"
         column="middle_initial"
         length="1"
         >
      </property>
      <property
         name="lastName"
         type="java.lang.String"
         column="last_name"
         not-null="true"
         length="50"
         >
      </property>
      <property
         name="company"
         type="java.lang.String"
         column="company_name"
         length="50"
         >
      </property>
      <property
         name="email"
         type="java.lang.String"
         column="email_address"
         length="50"
         >
      </property>
      <property
         name="password"
         type="java.lang.String"
         column="passwd"
         length="100"
         >
      </property>
      <property
         name="phone"
         type="java.lang.String"
         column="primary_phone"
         length="15"
         >
      </property>
      <property
         name="alternatePhone"
         type="java.lang.String"
         column="secondary_phone"
         length="15"
         >
      </property>
      <property
         name="fax"
         type="java.lang.String"
         column="fax"
         length="15"
         >
      </property>
      <property
         name="createdOn"
         type="java.sql.Timestamp"
         column="created_on"
         not-null="true"
         length="19"
         >
      </property>
      <property
         name="lastUpdate"
         type="java.sql.Timestamp"
         column="last_update"
         length="19"
         >
      </property>

      <!-- Associations -->

      <many-to-one
         name="billingAddress"
         class="Address"
         cascade="all"
         unique="true"
         not-null="true"
         >
         <column name="billing_address_id"/>
      </many-to-one>

      <!-- uni-directional one-to-many association to ShippingProfile -->
      <set
         name="shippingProfiles"
         lazy="true"
         inverse="false"
         cascade="all"
         >
         <key column="customer_id" not-null="true" />
         <one-to-many class="ShippingProfile" />
      </set>

      <!-- bi-directional one-to-many association to CustomerOrder -->
      <set
         name="orders"
         lazy="true"
         inverse="false"
         cascade="save-update"
         >
         <key column="customer_id"/>
         <one-to-many class="CustomerOrder"/>
      </set>

   </class>
</hibernate-mapping>

<?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="com.threeg.commerce.model">

   <class
      name="ShippingProfile"
      table="shipping_profile"
      >

      <id
         name="id"
         type="java.lang.Long"
         column="shipping_profile_id"
         >
         <generator class="native"/>
      </id>

      <version name="version" column="version" access="field"/>

      <property
         name="firstName"
         type="java.lang.String"
         column="first_name"
         not-null="true"
         length="50"
         />
      <property
         name="lastName"
         type="java.lang.String"
         column="last_name"
         not-null="true"
         length="50"
         />
      <property
         name="phone"
         type="java.lang.String"
         column="phone"
         not-null="true"
         length="15"
         />
      <property
         name="alternatePhone"
         type="java.lang.String"
         column="secondary_phone"
         length="15"
         />
      <property
         name="fax"
         type="java.lang.String"
         column="fax"
         length="15"
         />
      <property
         name="email"
         type="java.lang.String"
         column="email"
         length="10"
         />
      <property
         name="createdOn"
         type="java.sql.Timestamp"
         column="created_on"
         not-null="true"
         length="19"
         />
      <property
         name="lastUpdate"
         type="java.sql.Timestamp"
         column="last_update"
         length="19"
         />

      <!-- Associations -->

      <!-- bi-directional many-to-one association to Address -->
      <many-to-one
         name="address"
         class="Address"
         cascade="save-update"
         unique="true"
         not-null="true"
         >
         <column name="address_id"/>
      </many-to-one>

   </class>
</hibernate-mapping>

<?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="com.threeg.commerce.model">

   <class
      name="Address"
      table="address"
      >
      <id
         name="id"
         type="java.lang.Long"
         column="address_id"
         >
         <generator class="native"/>
      </id>

      <version name="version" column="version" access="field"/>

      <property
         name="addressType"
         type="com.threeg.commerce.persistence.customtype.AddressTypeCodeCustom"
         column="address_type"
         not-null="true"
         length="1"
         />
      <property
         name="address1"
         type="java.lang.String"
         column="address_1"
         not-null="true"
         length="100"
         />
      <property
         name="address2"
         type="java.lang.String"
         column="address_2"
         length="100"
         />
      <property
         name="city"
         type="java.lang.String"
         column="city"
         not-null="true"
         length="100"
         />
      <property
         name="state"
         type="java.lang.String"
         column="state"
         not-null="true"
         length="2"
         />
      <property
         name="zip"
         type="java.lang.String"
         column="postal_code"
         not-null="true"
         length="50"
         />
      <property
         name="createdOn"
         type="java.sql.Timestamp"
         column="created_on"
         not-null="true"
         length="19"
         />
      <property
         name="lastUpdate"
         type="java.sql.Timestamp"
         column="last_update"
         length="19"
         />

   </class>
</hibernate-mapping>


==> begin test <==
08:52:44,145 DEBUG SessionImpl:248 - opened session at timestamp: 4628066976215040
session hash: 17103907
08:52:44,145 DEBUG JDBCTransaction:46 - begin
08:52:44,145 DEBUG AbstractBatcher:422 - opening JDBC connection
08:52:44,145 DEBUG JDBCTransaction:50 - current autocommit status: true
08:52:44,145 DEBUG JDBCTransaction:52 - disabling autocommit
08:52:44,175 DEBUG AbstractSaveEventListener:409 - transient instance of: com.threeg.commerce.model.Customer
08:52:44,185 DEBUG DefaultSaveOrUpdateEventListener:159 - saving transient instance
08:52:44,185 DEBUG AbstractSaveEventListener:89 - generated identifier: , using strategy: org.hibernate.id.IdentityGenerator
08:52:44,185 DEBUG AbstractSaveEventListener:132 - saving [com.threeg.commerce.model.Customer#<null>]
08:52:44,185 DEBUG AbstractSaveEventListener:194 - executing insertions
08:52:44,195 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,195 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,195 DEBUG AbstractSaveEventListener:409 - transient instance of: com.threeg.commerce.model.Address
08:52:44,195 DEBUG DefaultSaveOrUpdateEventListener:159 - saving transient instance
08:52:44,195 DEBUG AbstractSaveEventListener:89 - generated identifier: , using strategy: org.hibernate.id.IdentityGenerator
08:52:44,195 DEBUG AbstractSaveEventListener:132 - saving [com.threeg.commerce.model.Address#<null>]
08:52:44,205 DEBUG AbstractSaveEventListener:194 - executing insertions
08:52:44,205 DEBUG Versioning:56 - using initial version: 0
08:52:44,215 DEBUG BasicEntityPersister:1722 - Inserting entity: com.threeg.commerce.model.Address (native id)
08:52:44,215 DEBUG BasicEntityPersister:1723 - Version: 0
08:52:44,215 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,215 DEBUG SQL:311 - insert into address (version, address_type, address_1, address_2, city, state, postal_code, created_on, last_update) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
08:52:44,225 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,255 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.threeg.commerce.model.Address#<null>]
08:52:44,275 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 158
08:52:44,275 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,285 DEBUG AbstractBatcher:403 - closing statement
08:52:44,285 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,285 DEBUG Versioning:56 - using initial version: 0
08:52:44,285 DEBUG BasicEntityPersister:1722 - Inserting entity: com.threeg.commerce.model.Customer (native id)
08:52:44,285 DEBUG BasicEntityPersister:1723 - Version: 0
08:52:44,285 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,295 DEBUG SQL:311 - insert into customer (version, first_name, middle_initial, last_name, company_name, email_address, passwd, primary_phone, secondary_phone, fax, created_on, last_update, billing_address_id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
08:52:44,295 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,295 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.threeg.commerce.model.Customer#<null>]
08:52:44,295 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 91
08:52:44,295 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,295 DEBUG AbstractBatcher:403 - closing statement
08:52:44,295 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,295 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,305 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.ShippingProfile
08:52:44,305 DEBUG AbstractSaveEventListener:409 - transient instance of: com.threeg.commerce.model.ShippingProfile
08:52:44,305 DEBUG DefaultSaveOrUpdateEventListener:159 - saving transient instance
08:52:44,305 DEBUG AbstractSaveEventListener:89 - generated identifier: , using strategy: org.hibernate.id.IdentityGenerator
08:52:44,305 DEBUG AbstractSaveEventListener:132 - saving [com.threeg.commerce.model.ShippingProfile#<null>]
08:52:44,305 DEBUG AbstractSaveEventListener:194 - executing insertions
08:52:44,305 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,315 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,315 DEBUG AbstractSaveEventListener:409 - transient instance of: com.threeg.commerce.model.Address
08:52:44,315 DEBUG DefaultSaveOrUpdateEventListener:159 - saving transient instance
08:52:44,315 DEBUG AbstractSaveEventListener:89 - generated identifier: , using strategy: org.hibernate.id.IdentityGenerator
08:52:44,315 DEBUG AbstractSaveEventListener:132 - saving [com.threeg.commerce.model.Address#<null>]
08:52:44,315 DEBUG AbstractSaveEventListener:194 - executing insertions
08:52:44,325 DEBUG Versioning:56 - using initial version: 0
08:52:44,325 DEBUG BasicEntityPersister:1722 - Inserting entity: com.threeg.commerce.model.Address (native id)
08:52:44,325 DEBUG BasicEntityPersister:1723 - Version: 0
08:52:44,325 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,325 DEBUG SQL:311 - insert into address (version, address_type, address_1, address_2, city, state, postal_code, created_on, last_update) values (?, ?, ?, ?, ?, ?, ?, ?, ?)
08:52:44,325 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,325 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.threeg.commerce.model.Address#<null>]
08:52:44,335 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 159
08:52:44,335 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,335 DEBUG AbstractBatcher:403 - closing statement
08:52:44,335 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,335 DEBUG Versioning:56 - using initial version: 0
08:52:44,335 DEBUG BasicEntityPersister:1722 - Inserting entity: com.threeg.commerce.model.ShippingProfile (native id)
08:52:44,345 DEBUG BasicEntityPersister:1723 - Version: 0
08:52:44,345 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,345 DEBUG SQL:311 - insert into shipping_profile (version, first_name, last_name, phone, secondary_phone, fax, email, created_on, last_update, address_id, customer_id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
08:52:44,345 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,345 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.threeg.commerce.model.ShippingProfile#<null>]
08:52:44,355 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 70
08:52:44,355 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,355 DEBUG AbstractBatcher:403 - closing statement
08:52:44,355 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,355 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,355 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,355 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,355 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,355 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,355 DEBUG AbstractFlushingEventListener:52 - flushing session
08:52:44,365 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
08:52:44,365 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,365 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,365 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.Address
08:52:44,365 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,365 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.Address#158]
08:52:44,365 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,365 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.ShippingProfile
08:52:44,365 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.ShippingProfile
08:52:44,365 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,365 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,375 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,375 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,375 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,375 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,375 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,375 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,416 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.Address
08:52:44,416 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,416 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.Address#159]
08:52:44,416 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,426 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
08:52:44,426 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
08:52:44,446 DEBUG WrapVisitor:86 - Wrapped collection in role: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,446 DEBUG WrapVisitor:86 - Wrapped collection in role: com.threeg.commerce.model.Customer.orders
08:52:44,446 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.shippingProfiles#91], was: [<unreferenced>] (initialized)
08:52:44,446 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.orders#91], was: [<unreferenced>] (initialized)
08:52:44,446 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
08:52:44,446 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
08:52:44,456 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 0 updates, 0 deletions to 4 objects
08:52:44,456 DEBUG AbstractFlushingEventListener:85 - Flushed: 2 (re)creations, 0 updates, 0 removals to 2 collections
08:52:44,456 DEBUG Printer:83 - listing entities:

08:52:44,466 DEBUG Printer:90 - com.threeg.commerce.model.ShippingProfile{phone=shipPhone, address=com.threeg.commerce.model.Address#159, email=shipEmail, lastUpdate=null, createdOn=2005-10-21 08:52:44, fax=null, alternatePhone=shipAlternatePhone, firstName=shipFirst, id=70, lastName=shipLast, version=0}
08:52:44,466 DEBUG Printer:90 - com.threeg.commerce.model.Address{address2=address2, state=VA, addressType=com.threeg.commerce.typecode.AddressTypeCode: code: C; label: Customer; description: Customer, zip=20155, address1=address1, lastUpdate=null, createdOn=2005-10-21 08:52:44, city=city, id=159, version=0}
08:52:44,466 DEBUG Printer:90 - com.threeg.commerce.model.Address{address2=address2, state=VA, addressType=com.threeg.commerce.typecode.AddressTypeCode: code: C; label: Customer; description: Customer, zip=99999, address1=address1, lastUpdate=null, createdOn=2005-10-21 08:52:44, city=city, id=158, version=0}
08:52:44,466 DEBUG Printer:90 - com.threeg.commerce.model.Customer{password=null, phone=phone, orders=[], middleInitial=null, alternatePhone=altphone, fax=null, id=91, firstName=first, version=0, lastName=last, company=company, shippingProfiles=[com.threeg.commerce.model.ShippingProfile#70], billingAddress=com.threeg.commerce.model.Address#158, email=email, lastUpdate=null, createdOn=2005-10-21 08:52:44}
08:52:44,496 DEBUG AbstractFlushingEventListener:267 - executing flush
08:52:44,496 DEBUG AbstractCollectionPersister:852 - Inserting collection: [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,496 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,496 DEBUG SQL:311 - update shipping_profile set customer_id=? where shipping_profile_id=?
08:52:44,496 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,496 DEBUG AbstractBatcher:27 - Adding to batch
08:52:44,506 DEBUG AbstractCollectionPersister:895 - done inserting collection: 1 rows inserted
08:52:44,506 DEBUG AbstractCollectionPersister:852 - Inserting collection: [com.threeg.commerce.model.Customer.orders#91]
08:52:44,506 DEBUG AbstractCollectionPersister:904 - collection was empty
08:52:44,506 DEBUG AbstractBatcher:54 - Executing batch size: 1
08:52:44,506 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,506 DEBUG AbstractBatcher:403 - closing statement
08:52:44,506 DEBUG AbstractFlushingEventListener:294 - post flush
08:52:44,506 DEBUG JDBCTransaction:83 - commit
08:52:44,516 DEBUG SessionImpl:319 - automatically flushing session
08:52:44,516 DEBUG AbstractFlushingEventListener:52 - flushing session
08:52:44,516 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
08:52:44,516 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,516 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,516 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.Address
08:52:44,516 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,516 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.Address#158]
08:52:44,516 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,516 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.ShippingProfile
08:52:44,516 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.ShippingProfile
08:52:44,526 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,526 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,526 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,526 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,526 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,526 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,526 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,526 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,526 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.Address
08:52:44,526 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,526 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.Address#159]
08:52:44,526 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,536 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
08:52:44,536 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
08:52:44,536 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.shippingProfiles#91], was: [com.threeg.commerce.model.Customer.shippingProfiles#91] (initialized)
08:52:44,536 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.orders#91], was: [com.threeg.commerce.model.Customer.orders#91] (initialized)
08:52:44,536 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
08:52:44,536 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
08:52:44,536 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 0 updates, 0 deletions to 4 objects
08:52:44,536 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
08:52:44,536 DEBUG Printer:83 - listing entities:

08:52:44,536 DEBUG Printer:90 - com.threeg.commerce.model.ShippingProfile{phone=shipPhone, address=com.threeg.commerce.model.Address#159, email=shipEmail, lastUpdate=null, createdOn=2005-10-21 08:52:44, fax=null, alternatePhone=shipAlternatePhone, firstName=shipFirst, id=70, lastName=shipLast, version=0}
08:52:44,546 DEBUG Printer:90 - com.threeg.commerce.model.Address{address2=address2, state=VA, addressType=com.threeg.commerce.typecode.AddressTypeCode: code: C; label: Customer; description: Customer, zip=20155, address1=address1, lastUpdate=null, createdOn=2005-10-21 08:52:44, city=city, id=159, version=0}
08:52:44,546 DEBUG Printer:90 - com.threeg.commerce.model.Address{address2=address2, state=VA, addressType=com.threeg.commerce.typecode.AddressTypeCode: code: C; label: Customer; description: Customer, zip=99999, address1=address1, lastUpdate=null, createdOn=2005-10-21 08:52:44, city=city, id=158, version=0}
08:52:44,546 DEBUG Printer:90 - com.threeg.commerce.model.Customer{password=null, phone=phone, orders=[], middleInitial=null, alternatePhone=altphone, fax=null, id=91, firstName=first, version=0, lastName=last, company=company, shippingProfiles=[com.threeg.commerce.model.ShippingProfile#70], billingAddress=com.threeg.commerce.model.Address#158, email=email, lastUpdate=null, createdOn=2005-10-21 08:52:44}
08:52:44,546 DEBUG AbstractFlushingEventListener:267 - executing flush
08:52:44,546 DEBUG AbstractFlushingEventListener:294 - post flush
08:52:44,546 DEBUG JDBCContext:238 - before transaction completion
08:52:44,546 DEBUG SessionImpl:368 - before transaction completion
08:52:44,626 DEBUG JDBCTransaction:173 - re-enabling autocommit
08:52:44,636 DEBUG JDBCTransaction:96 - committed JDBC Connection
08:52:44,636 DEBUG JDBCContext:243 - after transaction completion
08:52:44,636 DEBUG AbstractBatcher:437 - closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
08:52:44,646 DEBUG SessionImpl:399 - after transaction completion
08:52:44,646 DEBUG SessionImpl:265 - closing session

==> opening second session <==

08:52:44,646 DEBUG SessionImpl:248 - opened session at timestamp: 4628066978390016
session hash: 9899022
08:52:44,646 DEBUG JDBCTransaction:46 - begin
08:52:44,646 DEBUG AbstractBatcher:422 - opening JDBC connection
08:52:44,646 DEBUG JDBCTransaction:50 - current autocommit status: true
08:52:44,646 DEBUG JDBCTransaction:52 - disabling autocommit
08:52:44,646 DEBUG Cascades:665 - version unsaved-value strategy UNDEFINED
08:52:44,646 DEBUG Cascades:526 - id unsaved-value: null
08:52:44,656 DEBUG AbstractSaveEventListener:413 - detached instance of: com.threeg.commerce.model.Customer
08:52:44,656 DEBUG DefaultMergeEventListener:168 - merging detached instance
08:52:44,656 DEBUG DefaultLoadEventListener:143 - loading entity: [com.threeg.commerce.model.Customer#91]
08:52:44,656 DEBUG DefaultLoadEventListener:289 - attempting to resolve: [com.threeg.commerce.model.Customer#91]
08:52:44,656 DEBUG DefaultLoadEventListener:325 - object not resolved in any cache: [com.threeg.commerce.model.Customer#91]
08:52:44,656 DEBUG BasicEntityPersister:2457 - Materializing entity: [com.threeg.commerce.model.Customer#91]
08:52:44,656 DEBUG Loader:1307 - loading entity: [com.threeg.commerce.model.Customer#91]
08:52:44,666 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,666 DEBUG SQL:311 - select customer0_.customer_id as customer1_0_, customer0_.version as version17_0_, customer0_.first_name as first3_17_0_, customer0_.middle_initial as middle4_17_0_, customer0_.last_name as last5_17_0_, customer0_.company_name as company6_17_0_, customer0_.email_address as email7_17_0_, customer0_.passwd as passwd17_0_, customer0_.primary_phone as primary9_17_0_, customer0_.secondary_phone as secondary10_17_0_, customer0_.fax as fax17_0_, customer0_.created_on as created12_17_0_, customer0_.last_update as last13_17_0_, customer0_.billing_address_id as billing14_17_0_ from customer customer0_ where customer0_.customer_id=?
08:52:44,666 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,676 DEBUG AbstractBatcher:293 - about to open ResultSet (open ResultSets: 0, globally: 0)
08:52:44,676 DEBUG Loader:388 - processing result set
08:52:44,676 DEBUG Loader:393 - result set row: 0

08:52:44,676 DEBUG Loader:795 - result row: EntityKey[com.threeg.commerce.model.Customer#91]
08:52:44,676 DEBUG Loader:945 - Initializing object from ResultSet: [com.threeg.commerce.model.Customer#91]
08:52:44,696 DEBUG BasicEntityPersister:1641 - Hydrating entity: [com.threeg.commerce.model.Customer#91]
08:52:44,696 DEBUG TwoPhaseLoad:67 - Version: 0
08:52:44,696 DEBUG Loader:412 - done processing result set (1 rows)
08:52:44,696 DEBUG AbstractBatcher:300 - about to close ResultSet (open ResultSets: 1, globally: 1)

08:52:44,696 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,696 DEBUG AbstractBatcher:403 - closing statement
08:52:44,696 DEBUG Loader:508 - total objects hydrated: 1
08:52:44,706 DEBUG TwoPhaseLoad:96 - resolving associations for [com.threeg.commerce.model.Customer#91]
08:52:44,716 DEBUG DefaultLoadEventListener:143 - loading entity: [com.threeg.commerce.model.Address#158]
08:52:44,716 DEBUG DefaultLoadEventListener:216 - creating new proxy for entity
08:52:44,726 DEBUG CollectionLoadContext:134 - creating collection wrapper:[com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,726 DEBUG CollectionLoadContext:134 - creating collection wrapper:[com.threeg.commerce.model.Customer.orders#91]
08:52:44,726 DEBUG TwoPhaseLoad:167 - done materializing entity [com.threeg.commerce.model.Customer#91]
08:52:44,726 DEBUG PersistenceContext:789 - initializing non-lazy collections
08:52:44,726 DEBUG Loader:1335 - done entity load

08:52:44,726 DEBUG Cascades:836 - processing cascade ACTION_MERGE for: com.threeg.commerce.model.Customer
08:52:44,726 DEBUG Cascades:175 - cascading to merge: com.threeg.commerce.model.Address
08:52:44,726 DEBUG Cascades:665 - version unsaved-value strategy UNDEFINED
08:52:44,726 DEBUG Cascades:526 - id unsaved-value: null
08:52:44,736 DEBUG AbstractSaveEventListener:413 - detached instance of: com.threeg.commerce.model.Address
08:52:44,736 DEBUG DefaultMergeEventListener:168 - merging detached instance
08:52:44,736 DEBUG DefaultLoadEventListener:143 - loading entity: [com.threeg.commerce.model.Address#158]
08:52:44,736 DEBUG DefaultLoadEventListener:186 - entity proxy found in session cache
08:52:44,736 DEBUG DefaultLoadEventListener:289 - attempting to resolve: [com.threeg.commerce.model.Address#158]
08:52:44,736 DEBUG DefaultLoadEventListener:325 - object not resolved in any cache: [com.threeg.commerce.model.Address#158]
08:52:44,736 DEBUG BasicEntityPersister:2457 - Materializing entity: [com.threeg.commerce.model.Address#158]
08:52:44,736 DEBUG Loader:1307 - loading entity: [com.threeg.commerce.model.Address#158]
08:52:44,736 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,746 DEBUG SQL:311 - select address0_.address_id as address1_0_, address0_.version as version16_0_, address0_.address_type as address3_16_0_, address0_.address_1 as address4_16_0_, address0_.address_2 as address5_16_0_, address0_.city as city16_0_, address0_.state as state16_0_, address0_.postal_code as postal8_16_0_, address0_.created_on as created9_16_0_, address0_.last_update as last10_16_0_ from address address0_ where address0_.address_id=?
08:52:44,746 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,746 DEBUG AbstractBatcher:293 - about to open ResultSet (open ResultSets: 0, globally: 0)
08:52:44,746 DEBUG Loader:388 - processing result set
08:52:44,746 DEBUG Loader:393 - result set row: 0

08:52:44,746 DEBUG Loader:795 - result row: EntityKey[com.threeg.commerce.model.Address#158]
08:52:44,746 DEBUG Loader:945 - Initializing object from ResultSet: [com.threeg.commerce.model.Address#158]
08:52:44,756 DEBUG BasicEntityPersister:1641 - Hydrating entity: [com.threeg.commerce.model.Address#158]
08:52:44,756 DEBUG TwoPhaseLoad:67 - Version: 0
08:52:44,756 DEBUG Loader:412 - done processing result set (1 rows)
08:52:44,756 DEBUG AbstractBatcher:300 - about to close ResultSet (open ResultSets: 1, globally: 1)

08:52:44,756 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,756 DEBUG AbstractBatcher:403 - closing statement
08:52:44,756 DEBUG Loader:508 - total objects hydrated: 1
08:52:44,756 DEBUG TwoPhaseLoad:96 - resolving associations for [com.threeg.commerce.model.Address#158]
08:52:44,756 DEBUG TwoPhaseLoad:167 - done materializing entity [com.threeg.commerce.model.Address#158]
08:52:44,756 DEBUG PersistenceContext:789 - initializing non-lazy collections
08:52:44,766 DEBUG Loader:1335 - done entity load

08:52:44,766 DEBUG Cascades:890 - cascade ACTION_MERGE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,766 DEBUG Cascades:175 - cascading to merge: com.threeg.commerce.model.ShippingProfile
08:52:44,766 DEBUG Cascades:665 - version unsaved-value strategy UNDEFINED
08:52:44,766 DEBUG Cascades:526 - id unsaved-value: null
08:52:44,766 DEBUG AbstractSaveEventListener:413 - detached instance of: com.threeg.commerce.model.ShippingProfile
08:52:44,766 DEBUG DefaultMergeEventListener:168 - merging detached instance
08:52:44,766 DEBUG DefaultLoadEventListener:143 - loading entity: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,766 DEBUG DefaultLoadEventListener:289 - attempting to resolve: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,766 DEBUG DefaultLoadEventListener:325 - object not resolved in any cache: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,766 DEBUG BasicEntityPersister:2457 - Materializing entity: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,776 DEBUG Loader:1307 - loading entity: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,776 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,776 DEBUG SQL:311 - select shippingpr0_.shipping_profile_id as shipping1_0_, shippingpr0_.version as version29_0_, shippingpr0_.first_name as first3_29_0_, shippingpr0_.last_name as last4_29_0_, shippingpr0_.phone as phone29_0_, shippingpr0_.secondary_phone as secondary6_29_0_, shippingpr0_.fax as fax29_0_, shippingpr0_.email as email29_0_, shippingpr0_.created_on as created9_29_0_, shippingpr0_.last_update as last10_29_0_, shippingpr0_.address_id as address11_29_0_ from shipping_profile shippingpr0_ where shippingpr0_.shipping_profile_id=?
08:52:44,776 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,786 DEBUG AbstractBatcher:293 - about to open ResultSet (open ResultSets: 0, globally: 0)
08:52:44,786 DEBUG Loader:388 - processing result set
08:52:44,786 DEBUG Loader:393 - result set row: 0

08:52:44,786 DEBUG Loader:795 - result row: EntityKey[com.threeg.commerce.model.ShippingProfile#70]

08:52:44,786 DEBUG Loader:945 - Initializing object from ResultSet: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,796 DEBUG BasicEntityPersister:1641 - Hydrating entity: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,796 DEBUG TwoPhaseLoad:67 - Version: 0
08:52:44,796 DEBUG Loader:412 - done processing result set (1 rows)
08:52:44,796 DEBUG AbstractBatcher:300 - about to close ResultSet (open ResultSets: 1, globally: 1)

08:52:44,796 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,796 DEBUG AbstractBatcher:403 - closing statement
08:52:44,796 DEBUG Loader:508 - total objects hydrated: 1
08:52:44,796 DEBUG TwoPhaseLoad:96 - resolving associations for [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,796 DEBUG DefaultLoadEventListener:143 - loading entity: [com.threeg.commerce.model.Address#159]
08:52:44,796 DEBUG DefaultLoadEventListener:216 - creating new proxy for entity
08:52:44,806 DEBUG TwoPhaseLoad:167 - done materializing entity [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,806 DEBUG PersistenceContext:789 - initializing non-lazy collections
08:52:44,806 DEBUG Loader:1335 - done entity load

08:52:44,806 DEBUG Cascades:836 - processing cascade ACTION_MERGE for: com.threeg.commerce.model.ShippingProfile
08:52:44,806 DEBUG Cascades:861 - done processing cascade ACTION_MERGE for: com.threeg.commerce.model.ShippingProfile
08:52:44,806 DEBUG Cascades:665 - version unsaved-value strategy UNDEFINED
08:52:44,806 DEBUG Cascades:526 - id unsaved-value: null
08:52:44,806 DEBUG DefaultLoadEventListener:143 - loading entity: [com.threeg.commerce.model.Address#159]
08:52:44,806 DEBUG DefaultLoadEventListener:186 - entity proxy found in session cache
08:52:44,806 DEBUG Cascades:908 - done cascade ACTION_MERGE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,806 DEBUG Cascades:861 - done processing cascade ACTION_MERGE for: com.threeg.commerce.model.Customer
08:52:44,816 DEBUG DefaultInitializeCollectionEventListener:42 - initializing collection [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,816 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
08:52:44,816 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
08:52:44,816 DEBUG Loader:1393 - loading collection: [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,816 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,816 DEBUG SQL:311 - select shippingpr0_.customer_id as customer12___, shippingpr0_.shipping_profile_id as shipping1___, shippingpr0_.shipping_profile_id as shipping1_0_, shippingpr0_.version as version29_0_, shippingpr0_.first_name as first3_29_0_, shippingpr0_.last_name as last4_29_0_, shippingpr0_.phone as phone29_0_, shippingpr0_.secondary_phone as secondary6_29_0_, shippingpr0_.fax as fax29_0_, shippingpr0_.email as email29_0_, shippingpr0_.created_on as created9_29_0_, shippingpr0_.last_update as last10_29_0_, shippingpr0_.address_id as address11_29_0_ from shipping_profile shippingpr0_ where shippingpr0_.customer_id=?
08:52:44,816 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,816 DEBUG AbstractBatcher:293 - about to open ResultSet (open ResultSets: 0, globally: 0)
08:52:44,816 DEBUG Loader:686 - result set contains (possibly empty) collection: [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,816 DEBUG CollectionLoadContext:78 - uninitialized collection: initializing
08:52:44,826 DEBUG Loader:388 - processing result set
08:52:44,826 DEBUG Loader:393 - result set row: 0

08:52:44,826 DEBUG Loader:795 - result row: EntityKey[com.threeg.commerce.model.ShippingProfile#70]

08:52:44,826 DEBUG Loader:627 - found row of collection: [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,826 DEBUG CollectionLoadContext:105 - reading row
08:52:44,826 DEBUG DefaultLoadEventListener:143 - loading entity: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,826 DEBUG DefaultLoadEventListener:289 - attempting to resolve: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,826 DEBUG DefaultLoadEventListener:298 - resolved object in session cache: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,826 DEBUG Loader:412 - done processing result set (1 rows)
08:52:44,856 DEBUG AbstractBatcher:300 - about to close ResultSet (open ResultSets: 1, globally: 1)

08:52:44,856 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,856 DEBUG AbstractBatcher:403 - closing statement
08:52:44,856 DEBUG Loader:508 - total objects hydrated: 0
08:52:44,866 DEBUG CollectionLoadContext:248 - 1 collections were found in result set
08:52:44,866 DEBUG CollectionLoadContext:193 - collection fully initialized: [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,866 DEBUG CollectionLoadContext:256 - 1 collections initialized
08:52:44,866 DEBUG PersistenceContext:789 - initializing non-lazy collections
08:52:44,866 DEBUG Loader:1417 - done loading collection
08:52:44,866 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
08:52:44,866 DEBUG DefaultInitializeCollectionEventListener:42 - initializing collection [com.threeg.commerce.model.Customer.orders#91]
08:52:44,866 DEBUG DefaultInitializeCollectionEventListener:47 - checking second-level cache
08:52:44,866 DEBUG DefaultInitializeCollectionEventListener:59 - collection not cached
08:52:44,866 DEBUG Loader:1393 - loading collection: [com.threeg.commerce.model.Customer.orders#91]

08:52:44,866 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,876 DEBUG SQL:311 - select orders0_.customer_id as customer13___, orders0_.customer_order_id as customer1___, orders0_.customer_order_id as customer1_0_, orders0_.version as version18_0_, orders0_.customer_discount as customer3_18_0_, orders0_.tax as tax18_0_, orders0_.subtotal as subtotal18_0_, orders0_.shipping_cost as shipping6_18_0_, orders0_.txnResponse as txnRespo7_18_0_, orders0_.authorization_code as authoriz8_18_0_, orders0_.confirmation_code as confirma9_18_0_, orders0_.created_on as created10_18_0_, orders0_.last_update as last11_18_0_, orders0_.shipping_profile_id as shipping12_18_0_, orders0_.customer_id as customer13_18_0_ from customer_order orders0_ where orders0_.customer_id=?
08:52:44,876 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,876 DEBUG AbstractBatcher:293 - about to open ResultSet (open ResultSets: 0, globally: 0)
08:52:44,876 DEBUG Loader:686 - result set contains (possibly empty) collection: [com.threeg.commerce.model.Customer.orders#91]
08:52:44,876 DEBUG CollectionLoadContext:78 - uninitialized collection: initializing
08:52:44,876 DEBUG Loader:388 - processing result set
08:52:44,876 DEBUG Loader:412 - done processing result set (0 rows)
08:52:44,886 DEBUG AbstractBatcher:300 - about to close ResultSet (open ResultSets: 1, globally: 1)

08:52:44,886 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,886 DEBUG AbstractBatcher:403 - closing statement
08:52:44,886 DEBUG Loader:508 - total objects hydrated: 0
08:52:44,886 DEBUG CollectionLoadContext:248 - 1 collections were found in result set
08:52:44,886 DEBUG CollectionLoadContext:193 - collection fully initialized: [com.threeg.commerce.model.Customer.orders#91]
08:52:44,896 DEBUG CollectionLoadContext:256 - 1 collections initialized
08:52:44,896 DEBUG PersistenceContext:789 - initializing non-lazy collections
08:52:44,896 DEBUG Loader:1417 - done loading collection
08:52:44,896 DEBUG DefaultInitializeCollectionEventListener:61 - collection initialized
08:52:44,896 DEBUG AbstractFlushingEventListener:52 - flushing session
08:52:44,896 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
08:52:44,896 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,896 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,896 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.Address
08:52:44,896 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,906 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.Address#158]
08:52:44,906 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,906 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.ShippingProfile
08:52:44,906 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.ShippingProfile
08:52:44,906 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,906 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,906 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,906 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,906 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,916 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,916 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,916 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,916 DEBUG DefaultSaveOrUpdateEventListener:58 - reassociated uninitialized proxy
08:52:44,926 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,936 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
08:52:44,936 DEBUG CollectionEntry:115 - Collection dirty: [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,936 DEBUG CollectionEntry:115 - Collection dirty: [com.threeg.commerce.model.Customer.orders#91]
08:52:44,936 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
08:52:44,936 DEBUG DefaultFlushEntityEventListener:121 - Updating entity: [com.threeg.commerce.model.Customer#91]
08:52:44,936 DEBUG Versioning:26 - Incrementing: 0 to 1
08:52:44,936 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.shippingProfiles#91], was: [com.threeg.commerce.model.Customer.shippingProfiles#91] (initialized)
08:52:44,936 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.orders#91], was: [com.threeg.commerce.model.Customer.orders#91] (initialized)
08:52:44,936 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
08:52:44,946 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
08:52:44,946 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 1 updates, 0 deletions to 3 objects
08:52:44,946 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 2 updates, 0 removals to 2 collections
08:52:44,946 DEBUG Printer:83 - listing entities:

08:52:44,946 DEBUG Printer:90 - com.threeg.commerce.model.ShippingProfile{phone=shipPhone, address=com.threeg.commerce.model.Address#159, email=shipEmail, lastUpdate=null, createdOn=2005-10-21 08:52:44, fax=null, alternatePhone=shipAlternatePhone, firstName=ernie, id=70, lastName=shipLast, version=0}
08:52:44,946 DEBUG Printer:90 - com.threeg.commerce.model.Address{address2=address2, state=VA, addressType=com.threeg.commerce.typecode.AddressTypeCode: code: C; label: Customer; description: Customer, zip=99999, address1=123 nutler way, lastUpdate=null, createdOn=2005-10-21 08:52:44, city=city, id=158, version=0}
08:52:44,956 DEBUG Printer:90 - com.threeg.commerce.model.Customer{password=null, phone=phone, orders=[], middleInitial=null, alternatePhone=altphone, fax=null, id=91, firstName=ert, version=1, lastName=nutler, company=company, shippingProfiles=[com.threeg.commerce.model.ShippingProfile#70], billingAddress=com.threeg.commerce.model.Address#158, email=email, lastUpdate=2005-10-21 08:52:44, createdOn=2005-10-21 08:52:44}
08:52:44,956 DEBUG AbstractFlushingEventListener:267 - executing flush
08:52:44,956 DEBUG BasicEntityPersister:1930 - Updating entity: [com.threeg.commerce.model.Customer#91]
08:52:44,956 DEBUG BasicEntityPersister:1931 - Existing version: 0 -> New version: 1
08:52:44,956 DEBUG AbstractBatcher:277 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
08:52:44,956 DEBUG SQL:311 - update customer set version=?, first_name=?, middle_initial=?, last_name=?, company_name=?, email_address=?, passwd=?, primary_phone=?, secondary_phone=?, fax=?, created_on=?, last_update=?, billing_address_id=? where customer_id=? and version=?
08:52:44,956 DEBUG AbstractBatcher:365 - preparing statement
08:52:44,966 DEBUG BasicEntityPersister:1602 - Dehydrating entity: [com.threeg.commerce.model.Customer#91]
08:52:44,966 DEBUG AbstractBatcher:285 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
08:52:44,966 DEBUG AbstractBatcher:403 - closing statement
08:52:44,966 DEBUG AbstractCollectionPersister:1008 - Inserting rows of collection: [com.threeg.commerce.model.Customer.shippingProfiles#91]
08:52:44,966 DEBUG AbstractCollectionPersister:1052 - done inserting rows: 0 inserted
08:52:44,966 DEBUG AbstractFlushingEventListener:294 - post flush
08:52:44,966 DEBUG JDBCTransaction:83 - commit
08:52:44,966 DEBUG SessionImpl:319 - automatically flushing session
08:52:44,966 DEBUG AbstractFlushingEventListener:52 - flushing session
08:52:44,966 DEBUG AbstractFlushingEventListener:102 - processing flush-time cascades
08:52:44,966 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,976 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,976 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.Address
08:52:44,976 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,976 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.Address#158]
08:52:44,976 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,976 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.ShippingProfile
08:52:44,976 DEBUG AbstractSaveEventListener:393 - persistent instance of: com.threeg.commerce.model.ShippingProfile
08:52:44,976 DEBUG DefaultSaveOrUpdateEventListener:103 - ignoring persistent instance
08:52:44,976 DEBUG DefaultSaveOrUpdateEventListener:140 - object already associated with session: [com.threeg.commerce.model.ShippingProfile#70]
08:52:44,986 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.shippingProfiles
08:52:44,986 DEBUG Cascades:890 - cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,986 DEBUG Cascades:908 - done cascade ACTION_SAVE_UPDATE for collection: com.threeg.commerce.model.Customer.orders
08:52:44,986 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.Customer
08:52:44,986 DEBUG Cascades:836 - processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,986 DEBUG Cascades:153 - cascading to saveOrUpdate: com.threeg.commerce.model.Address
08:52:44,986 DEBUG DefaultSaveOrUpdateEventListener:58 - reassociated uninitialized proxy
08:52:44,986 DEBUG Cascades:861 - done processing cascade ACTION_SAVE_UPDATE for: com.threeg.commerce.model.ShippingProfile
08:52:44,996 DEBUG AbstractFlushingEventListener:150 - dirty checking collections
08:52:44,996 DEBUG AbstractFlushingEventListener:167 - Flushing entities and processing referenced collections
08:52:44,996 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.shippingProfiles#91], was: [com.threeg.commerce.model.Customer.shippingProfiles#91] (initialized)
08:52:44,996 DEBUG Collections:140 - Collection found: [com.threeg.commerce.model.Customer.orders#91], was: [com.threeg.commerce.model.Customer.orders#91] (initialized)
08:52:44,996 DEBUG AbstractFlushingEventListener:203 - Processing unreferenced collections
08:52:44,996 DEBUG AbstractFlushingEventListener:217 - Scheduling collection removes/(re)creates/updates
08:52:44,996 DEBUG AbstractFlushingEventListener:79 - Flushed: 0 insertions, 0 updates, 0 deletions to 3 objects
08:52:44,996 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 (re)creations, 0 updates, 0 removals to 2 collections
08:52:44,996 DEBUG Printer:83 - listing entities:

08:52:44,996 DEBUG Printer:90 - com.threeg.commerce.model.ShippingProfile{phone=shipPhone, address=com.threeg.commerce.model.Address#159, email=shipEmail, lastUpdate=null, createdOn=2005-10-21 08:52:44, fax=null, alternatePhone=shipAlternatePhone, firstName=ernie, id=70, lastName=shipLast, version=0}
08:52:45,006 DEBUG Printer:90 - com.threeg.commerce.model.Address{address2=address2, state=VA, addressType=com.threeg.commerce.typecode.AddressTypeCode: code: C; label: Customer; description: Customer, zip=99999, address1=123 nutler way, lastUpdate=null, createdOn=2005-10-21 08:52:44, city=city, id=158, version=0}
08:52:45,006 DEBUG Printer:90 - com.threeg.commerce.model.Customer{password=null, phone=phone, orders=[], middleInitial=null, alternatePhone=altphone, fax=null, id=91, firstName=ert, version=1, lastName=nutler, company=company, shippingProfiles=[com.threeg.commerce.model.ShippingProfile#70], billingAddress=com.threeg.commerce.model.Address#158, email=email, lastUpdate=2005-10-21 08:52:44, createdOn=2005-10-21 08:52:44}
08:52:45,006 DEBUG AbstractFlushingEventListener:267 - executing flush
08:52:45,006 DEBUG AbstractFlushingEventListener:294 - post flush
08:52:45,006 DEBUG JDBCContext:238 - before transaction completion
08:52:45,006 DEBUG SessionImpl:368 - before transaction completion
08:52:45,066 DEBUG JDBCTransaction:173 - re-enabling autocommit
08:52:45,077 DEBUG JDBCTransaction:96 - committed JDBC Connection
08:52:45,077 DEBUG JDBCContext:243 - after transaction completion
08:52:45,077 DEBUG AbstractBatcher:437 - closing JDBC connection (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)
08:52:45,077 DEBUG SessionImpl:399 - after transaction completion
08:52:45,077 DEBUG SessionImpl:265 - closing session
Process terminated with exit code 0
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
  [ 3 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.