-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 6 posts ] 
Author Message
 Post subject: foreign key not populated when using a <bag>
PostPosted: Sun Apr 30, 2006 1:37 pm 
Newbie

Joined: Tue Jan 11, 2005 6:02 pm
Posts: 13
Location: Seattle
I have a one-to-many (A Consumer has one/many PostalAddress) mapped via a <bag>,
and I cannot determine why Hibernate is not generating SQL
that contains the foreign key column on the "many" side. The insert for
the child PostalAddress does not contain an entry for the Consumer key.
Thanks for any help! I have been racking my head on this for hours; seems like a very simple problem.

--Michael

Hibernate version:
3.1.3
Mapping documents:
<hibernate-mapping package="com.real.ecs.account.domain">
<class name="Consumer" table="/*ecs*/myreal.consumers">
<id name="id" type="long" column="id">
<generator class="sequence">
<param name="sequence">consumers_seq</param>
</generator>
</id>
<property name="master" column="master"/>
<property name="handle" column="handle"/>
<property name="ci" column="ci_value"/>
<property name="createTime" column="create_dt" update="false"/>
<property name="updateTime" column="update_dt"/>
<bag name="addresses"
inverse="true"
cascade="save-update">
<key column="consumer_id"/>
<one-to-many class="PostalAddress"/>
</bag>
</class>
</hibernate-mapping>
<hibernate-mapping package="com.real.ecs.account.domain">
<class name="PostalAddress" table="/*ecs*/myreal.consumer_addresses">
<id name="id" type="long" column="id">
<generator class="sequence">
<param name="sequence">consumer_addresses_seq</param>
</generator>
</id>
<property name="firstName" column="first_name"/>
<property name="lastName" column="last_name"/>
<property name="addressLine1" column="address_line_1"/>
<property name="addressLine2" column="address_line_2"/>
<property name="addressLine3" column="address_line_3"/>
<property name="addressLine4" column="address_line_4"/>
<property name="city" column="city_name"/>
<property name="postalCode" column="postal_code"/>
<property name="state" column="state_province"/>
<property name="phoneNumber" column="phone"/>
<property name="countryCode" column="country_code"/>
<property name="status" column="status"/>
<property name="createTime" column="create_dt" update="false"/>
<property name="updateTime" column="update_dt" insert="true"/>
<many-to-one name="consumer" column="consumer_id" insert="false" update="false"/>
</class>
</hibernate-mapping>


Code between sessionFactory.openSession() and session.close():
PostalAddress billingAddress = getAddress(billingAddressRequest);
consumer.getAddresses().add(billingAddress);
session.save(Consumer.class, consumer);

Full stack trace of any exception that occurs:
[junit] 10:08:44.869 [main] ERROR org.hibernate.event.def.AbstractFlushingEventListener - Could not synchronize database state with session
[junit] org.hibernate.exception.ConstraintViolationException: Could not execute JDBC batch update
[junit] at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:71)
[junit] at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
[junit] at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:202)
[junit] at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:91)
[junit] at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:86)
[junit] at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:171)
[junit] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2048)
[junit] at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2427)
[junit] at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:51)
[junit] at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248)
[junit] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232)
[junit] at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:139)
[junit] at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:297)
[junit] at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
[junit] at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:985)
[junit] at org.springframework.orm.hibernate3.HibernateAccessor.flushIfNecessary(HibernateAccessor.java:394)
[junit] at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:367)
[junit] at org.springframework.orm.hibernate3.HibernateTemplate.save(HibernateTemplate.java:614)
[junit] at com.real.ecs.account.dao.AccountDao.createConsumer(AccountDao.java:68)
[junit] at com.real.ecs.account.service.AccountService.createConsumerAccount(AccountService.java:78)
[junit] at com.real.test.ecs.account.TestCreateConsumerAccount.testCreateConsumerAccount(TestCreateConsumerAccount.java:35)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:585)
[junit] at junit.framework.TestCase.runTest(TestCase.java:154)
[junit] at junit.framework.TestCase.runBare(TestCase.java:127)
[junit] at junit.framework.TestResult$1.protect(TestResult.java:106)
[junit] at junit.framework.TestResult.runProtected(TestResult.java:124)
[junit] at junit.framework.TestResult.run(TestResult.java:109)
[junit] at junit.framework.TestCase.run(TestCase.java:118)
[junit] at junit.framework.TestSuite.runTest(TestSuite.java:208)
[junit] at junit.framework.TestSuite.run(TestSuite.java:203)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:297)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.executeInVM(JUnitTask.java:1072)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.execute(JUnitTask.java:682)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.executeOrQueue(JUnitTask.java:1434)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.execute(JUnitTask.java:632)
[junit] at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:275)
[junit] at org.apache.tools.ant.Task.perform(Task.java:364)
[junit] at org.apache.tools.ant.Target.execute(Target.java:341)
[junit] at org.apache.tools.ant.Target.performTasks(Target.java:369)
[junit] at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1216)
[junit] at org.apache.tools.ant.Project.executeTarget(Project.java:1185)
[junit] at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(DefaultExecutor.java:40)
[junit] at org.apache.tools.ant.Project.executeTargets(Project.java:1068)
[junit] at org.apache.tools.ant.Main.runBuild(Main.java:668)
[junit] at org.apache.tools.ant.Main.startAnt(Main.java:187)
[junit] at org.apache.tools.ant.launch.Launcher.run(Launcher.java:246)
[junit] at org.apache.tools.ant.launch.Launcher.main(Launcher.java:67)
[junit] Caused by: java.sql.BatchUpdateException: ORA-02290: check constraint (MYREAL.SYS_C009082) violated

[junit] at oracle.jdbc.driver.DatabaseError.throwBatchUpdateException(DatabaseError.java:343)
[junit] at oracle.jdbc.driver.OraclePreparedStatement.executeBatch(OraclePreparedStatement.java:10656)
[junit] at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
[junit] at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:195)
[junit] ... 47 more
[junit] Tests run: 1, Failures: 0, Errors: 1, Time elapsed: 9.47 sec




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


The generated SQL (show_sql=true):
[junit] 10:08:44.543 [main] DEBUG org.hibernate.SQL - select consumers_seq.nextval from dual
[junit] 10:08:44.607 [main] DEBUG org.hibernate.SQL - select consumer_addresses_seq.nextval from dual
[junit] 10:08:44.673 [main] DEBUG org.hibernate.SQL - insert into /*ecs*/myreal.consumers (master, handle, ci_value, create_dt, update_dt, id) values (?, ?, ?, ?, ?, ?)
[junit] 10:08:44.820 [main] DEBUG org.hibernate.SQL - insert into /*ecs*/myreal.consumer_addresses (first_name, last_name, address_line_1, address_line_2, address_line_3, city_name, postal_code, state_province, country_code, status, create_dt, update_dt, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
[junit] 10:08:44.865 [main] WARN org.hibernate.util.JDBCExceptionReporter - SQL Error: 2290, SQLState: 23000
[junit] 10:08:44.865 [main] ERROR org.hibernate.util.JDBCExceptionReporter - ORA-02290: check constraint (MYREAL.SYS_C009082) violated
(THIS IS THE NOT NULL CONSTRAINT ON consumer_id)


Debug level Hibernate log excerpt:

12:34:52.042 [main] INFO org.hibernate.cfg.Environment - Hibernate 3.1.3
12:34:52.060 [main] INFO org.hibernate.cfg.Environment - hibernate.properties not found
12:34:52.064 [main] INFO org.hibernate.cfg.Environment - using CGLIB reflection optimizer
12:34:52.064 [main] INFO org.hibernate.cfg.Environment - using JDK 1.4 java.sql.Timestamp handling
12:34:52.358 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:52.359 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:52.364 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:52.625 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.ecs.account.domain.PostalAddress -> /*ecs*/myreal.consumer_addresses
12:34:52.660 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
12:34:52.732 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: firstName -> first_name
12:34:52.733 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: lastName -> last_name
12:34:52.734 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine1 -> address_line_1
12:34:52.734 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine2 -> address_line_2
12:34:52.735 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine3 -> address_line_3
12:34:52.736 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine4 -> address_line_4
12:34:52.743 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: city -> city_name
12:34:52.743 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: postalCode -> postal_code
12:34:52.745 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: state -> state_province
12:34:52.746 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: phoneNumber -> phone
12:34:52.747 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: countryCode -> country_code
12:34:52.747 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: status -> status
12:34:52.748 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: createTime -> create_dt
12:34:52.750 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: updateTime -> update_dt
12:34:52.945 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: consumer -> consumer_id
12:34:52.948 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:52.948 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:52.952 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:53.015 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.ecs.account.domain.Consumer -> /*ecs*/myreal.consumers
12:34:53.016 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
12:34:53.017 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: master -> master
12:34:53.018 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: handle -> handle
12:34:53.018 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: ci -> ci_value
12:34:53.018 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: createTime -> create_dt
12:34:53.019 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: updateTime -> update_dt
12:34:53.032 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addresses
12:34:53.034 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:53.034 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:53.036 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:53.086 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.ecs.account.domain.PaymentType -> /*ecs*/ecomm.payment_subtype
12:34:53.089 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: paymentTypeCode -> pmttyp_code
12:34:53.090 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: paymentSubTypeCode -> pmtsubtyp_code
12:34:53.090 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: paymentTypeKey -> pmttyp_code, pmtsubtyp_code
12:34:53.091 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: description -> description
12:34:53.092 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: createTime -> create_date
12:34:53.092 [main] DEBUG org.hibernate.cfg.Configuration - Preparing to build session factory with filters : {}
12:34:53.092 [main] DEBUG org.hibernate.cfg.Configuration - processing extends queue
12:34:53.093 [main] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
12:34:53.095 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Second pass for collection: com.real.ecs.account.domain.Consumer.addresses
12:34:53.095 [main] INFO org.hibernate.cfg.HbmBinder - Mapping collection: com.real.ecs.account.domain.Consumer.addresses -> /*ecs*/myreal.consumer_addresses
12:34:53.096 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Mapped collection key: consumer_id, one-to-many: com.real.ecs.account.domain.PostalAddress
12:34:53.231 [main] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
12:34:53.231 [main] DEBUG org.hibernate.cfg.Configuration - processing association property references
12:34:53.232 [main] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
12:34:53.232 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.ecs.account.domain.Consumer
12:34:53.465 [main] INFO org.hibernate.connection.ConnectionProviderFactory - Initializing connection provider: org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider
12:34:53.467 [main] INFO org.hibernate.cfg.SettingsFactory - RDBMS: Oracle, version: Oracle Database 10g Enterprise Edition Release 10.1.0.4.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options
12:34:53.467 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC driver: Oracle JDBC driver, version: 10.2.0.1.0
12:34:53.527 [main] INFO org.hibernate.dialect.Dialect - Using dialect: org.hibernate.dialect.Oracle9Dialect
12:34:53.550 [main] INFO org.hibernate.transaction.TransactionFactoryFactory - Using default transaction strategy (direct JDBC transactions)
12:34:53.557 [main] INFO org.hibernate.transaction.TransactionManagerLookupFactory - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
12:34:53.557 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic flush during beforeCompletion(): disabled
12:34:53.558 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic session close at end of transaction: disabled
12:34:53.558 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch size: 15
12:34:53.558 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch updates for versioned data: disabled
12:34:53.561 [main] INFO org.hibernate.cfg.SettingsFactory - Scrollable result sets: enabled
12:34:53.561 [main] DEBUG org.hibernate.cfg.SettingsFactory - Wrap result sets: disabled
12:34:53.561 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC3 getGeneratedKeys(): enabled
12:34:53.562 [main] INFO org.hibernate.cfg.SettingsFactory - Connection release mode: on_close
12:34:53.562 [main] INFO org.hibernate.cfg.SettingsFactory - Default batch fetch size: 1
12:34:53.569 [main] INFO org.hibernate.cfg.SettingsFactory - Generate SQL with comments: disabled
12:34:53.569 [main] INFO org.hibernate.cfg.SettingsFactory - Order SQL updates by primary key: disabled
12:34:53.569 [main] INFO org.hibernate.cfg.SettingsFactory - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
12:34:53.582 [main] INFO org.hibernate.hql.ast.ASTQueryTranslatorFactory - Using ASTQueryTranslatorFactory
12:34:53.583 [main] INFO org.hibernate.cfg.SettingsFactory - Query language substitutions: {true=1, false=0}
12:34:53.584 [main] INFO org.hibernate.cfg.SettingsFactory - Second-level cache: enabled
12:34:53.584 [main] INFO org.hibernate.cfg.SettingsFactory - Query cache: disabled
12:34:53.584 [main] INFO org.hibernate.cfg.SettingsFactory - Cache provider: org.hibernate.cache.EhCacheProvider
12:34:53.596 [main] INFO org.hibernate.cfg.SettingsFactory - Optimize cache for minimal puts: disabled
12:34:53.597 [main] INFO org.hibernate.cfg.SettingsFactory - Structured second-level cache entries: disabled
12:34:53.601 [main] DEBUG org.hibernate.exception.SQLExceptionConverterFactory - Using dialect defined converter
12:34:53.642 [main] INFO org.hibernate.cfg.SettingsFactory - Statistics: disabled
12:34:53.643 [main] INFO org.hibernate.cfg.SettingsFactory - Deleted entity synthetic identifier rollback: disabled
12:34:53.644 [main] INFO org.hibernate.cfg.SettingsFactory - Default entity-mode: pojo
12:34:53.758 [main] INFO org.hibernate.impl.SessionFactoryImpl - building session factory
12:34:53.759 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Session factory constructed with filter configurations : {}
12:34:53.760 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, hibernate.cache.provider_class=org.hibernate.cache.EhCacheProvider, sun.boot.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386, java.vm.version=1.5.0_05-b05, ant.library.dir=/usr/local/ant/lib, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=:, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=unknown, java.vm.specification.name=Java Virtual Machine Specification, user.dir=/usr/home/mmoores/rnwk/zylom/shared/ecs/test, java.runtime.version=1.5.0_05-b05, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.endorsed.dirs=/usr/local/jdk1.5.0_05/jre/lib/endorsed, os.arch=i386, java.io.tmpdir=/tmp, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., os.name=Linux, hibernate.cache.use_second_level_cache=true, ant.home=/usr/local/ant, sun.jnu.encoding=UTF-8, java.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386/client:/usr/local/jdk1.5.0_05/jre/lib/i386:/usr/local/jdk1.5.0_05/jre/../lib/i386, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, ecommerce.configuration=/usr/home/mmoores/rnwk/zylom/shared/ecs/test/config/rnce/config.properties, os.version=2.6.13-1532_FC4moores, user.home=/home/mmoores, user.timezone=America/New_York, hibernate.connection.release_mode=on_close, java.awt.printerjob=sun.print.PSPrinterJob, java.specification.version=1.5, file.encoding=UTF-8, java.class.path=/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-jai.jar:/usr/local/ant/lib/ant-vaj.jar:/usr/local/ant/lib/ant-apache-oro.jar:/usr/local/ant/lib/ant-jsch.jar:/usr/local/ant/lib/ant-starteam.jar:/usr/local/ant/lib/xercesImpl.jar:/usr/local/ant/lib/junit.jar:/usr/local/ant/lib/xml-apis.jar:/usr/local/ant/lib/ant-apache-bcel.jar:/usr/local/ant/lib/ant-xslp.jar:/usr/local/ant/lib/ant-netrexx.jar:/usr/local/ant/lib/ant-nodeps.jar:/usr/local/ant/lib/ant-apache-regexp.jar:/usr/local/ant/lib/ant-icontract.jar:/usr/local/ant/lib/ant-weblogic.jar:/usr/local/ant/lib/ant-jmf.jar:/usr/local/ant/lib/ant-commons-net.jar:/usr/local/ant/lib/ant-junit.jar:/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-xalan1.jar:/usr/local/ant/lib/ant-swing.jar:/usr/local/ant/lib/ant-commons-logging.jar:/usr/local/ant/lib/ant-trax.jar:/usr/local/ant/lib/ant-javamail.jar:/usr/local/ant/lib/ant-apache-resolver.jar:/usr/local/ant/lib/ant-apache-log4j.jar:/usr/local/ant/lib/ant-antlr.jar:/usr/local/ant/lib/ant.jar:/usr/local/ant/lib/ant-contrib.jar:/usr/local/ant/lib/ant-jdepend.jar:/usr/local/ant/lib/ant-apache-bsf.jar:/usr/local/ant/lib/ant-stylebook.jar:/usr/local/jdk1.5.0_05/lib/tools.jar, user.name=mmoores, hibernate.show_sql=false, hibernate.query.substitutions=true=1 false=0, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=/usr/local/jdk1.5.0_05/jre, hibernate.dialect=org.hibernate.dialect.Oracle9Dialect, java.specification.vendor=Sun Microsystems Inc., user.language=en, java.vm.info=mixed mode, sharing, hibernate.cglib.use_reflection_optimizer=true, java.version=1.5.0_05, java.ext.dirs=/usr/local/jdk1.5.0_05/jre/lib/ext, sun.boot.class.path=/usr/local/jdk1.5.0_05/jre/lib/rt.jar:/usr/local/jdk1.5.0_05/jre/lib/i18n.jar:/usr/local/jdk1.5.0_05/jre/lib/sunrsasign.jar:/usr/local/jdk1.5.0_05/jre/lib/jsse.jar:/usr/local/jdk1.5.0_05/jre/lib/jce.jar:/usr/local/jdk1.5.0_05/jre/lib/charsets.jar:/usr/local/jdk1.5.0_05/jre/classes, java.vendor=Sun Microsystems Inc., file.separator=/, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, hibernate.connection.provider_class=org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.isalist=}
12:34:53.840 [main] WARN net.sf.ehcache.config.Configurator - No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/usr/home/mmoores/rnwk/zylom/3rdparty/spring-framework/spring-framework-1.2.7/lib/ehcache/ehcache-1.1.jar!/ehcache-failsafe.xml
12:34:54.264 [main] DEBUG org.hibernate.util.ReflectHelper - reflection optimizer disabled for: com.real.ecs.account.domain.Consumer, BulkBeanException: Property is private (property setCreateTime)
12:34:54.346 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.ecs.account.domain.Consumer
12:34:54.347 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select id from /*ecs*/myreal.consumers where id =?
12:34:54.348 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select consumer_.id, consumer_.master as master1_, consumer_.handle as handle1_, consumer_.ci_value as ci4_1_, consumer_.update_dt as update6_1_ from /*ecs*/myreal.consumers consumer_ where consumer_.id=?
12:34:54.348 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into /*ecs*/myreal.consumers (master, handle, ci_value, create_dt, update_dt, id) values (?, ?, ?, ?, ?, ?)
12:34:54.348 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update /*ecs*/myreal.consumers set master=?, handle=?, ci_value=?, update_dt=? where id=?
12:34:54.349 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from /*ecs*/myreal.consumers where id=?
12:34:54.438 [main] DEBUG org.hibernate.util.ReflectHelper - reflection optimizer disabled for: com.real.ecs.account.domain.PostalAddress, BulkBeanException: Property is private (property setCreateTime)
12:34:54.445 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.ecs.account.domain.PostalAddress
12:34:54.446 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select id from /*ecs*/myreal.consumer_addresses where id =?
12:34:54.448 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select postaladdr_.id, postaladdr_.first_name as first2_0_, postaladdr_.last_name as last3_0_, postaladdr_.address_line_1 as address4_0_, postaladdr_.address_line_2 as address5_0_, postaladdr_.address_line_3 as address6_0_, postaladdr_.address_line_4 as address7_0_, postaladdr_.city_name as city8_0_, postaladdr_.postal_code as postal9_0_, postaladdr_.state_province as state10_0_, postaladdr_.phone as phone0_, postaladdr_.country_code as country12_0_, postaladdr_.status as status0_, postaladdr_.update_dt as update15_0_ from /*ecs*/myreal.consumer_addresses postaladdr_ where postaladdr_.id=?
12:34:54.449 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into /*ecs*/myreal.consumer_addresses (first_name, last_name, address_line_1, address_line_2, address_line_3, address_line_4, city_name, postal_code, state_province, phone, country_code, status, create_dt, update_dt, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
12:34:54.450 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update /*ecs*/myreal.consumer_addresses set first_name=?, last_name=?, address_line_1=?, address_line_2=?, address_line_3=?, address_line_4=?, city_name=?, postal_code=?, state_province=?, phone=?, country_code=?, status=?, update_dt=? where id=?
12:34:54.450 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from /*ecs*/myreal.consumer_addresses where id=?
12:34:54.501 [main] DEBUG org.hibernate.util.ReflectHelper - reflection optimizer disabled for: com.real.ecs.account.domain.PaymentType, BulkBeanException: Property is private (property setCreateTime)
12:34:54.504 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.ecs.account.domain.PaymentType
12:34:54.504 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select pmttyp_code, pmtsubtyp_code from /*ecs*/ecomm.payment_subtype where pmttyp_code =? and pmtsubtyp_code =?
12:34:54.504 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select paymenttyp_.pmttyp_code, paymenttyp_.pmtsubtyp_code, paymenttyp_.description as descript3_2_, paymenttyp_.create_date as create4_2_ from /*ecs*/ecomm.payment_subtype paymenttyp_ where paymenttyp_.pmttyp_code=? and paymenttyp_.pmtsubtyp_code=?
12:34:54.505 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into /*ecs*/ecomm.payment_subtype (description, create_date, pmttyp_code, pmtsubtyp_code) values (?, ?, ?, ?)
12:34:54.505 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update /*ecs*/ecomm.payment_subtype set description=?, create_date=? where pmttyp_code=? and pmtsubtyp_code=?
12:34:54.505 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from /*ecs*/ecomm.payment_subtype where pmttyp_code=? and pmtsubtyp_code=?
12:34:54.558 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - Static SQL for collection: com.real.ecs.account.domain.Consumer.addresses
12:34:54.558 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - Row insert: update /*ecs*/myreal.consumer_addresses set consumer_id=? where id=?
12:34:54.559 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - Row delete: update /*ecs*/myreal.consumer_addresses set consumer_id=null where consumer_id=? and id=?
12:34:54.559 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - One-shot delete: update /*ecs*/myreal.consumer_addresses set consumer_id=null where consumer_id=?
12:34:54.654 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
12:34:54.655 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
12:34:54.656 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=? for update
12:34:54.657 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=? for update nowait
12:34:54.842 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
12:34:54.843 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
12:34:54.844 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
12:34:54.847 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
12:34:54.851 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=? for update
12:34:54.853 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=? for update nowait
12:34:54.855 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
12:34:54.856 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
12:34:54.863 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
12:34:54.865 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
12:34:54.868 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=? for update
12:34:54.869 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=? for update nowait
12:34:54.870 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
12:34:54.871 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
12:34:54.930 [main] DEBUG org.hibernate.loader.collection.OneToManyLoader - Static select for one-to-many com.real.ecs.account.domain.Consumer.addresses: select addresses0_.consumer_id as consumer16_1_, addresses0_.id as id1_, addresses0_.id as id0_0_, addresses0_.first_name as first2_0_0_, addresses0_.last_name as last3_0_0_, addresses0_.address_line_1 as address4_0_0_, addresses0_.address_line_2 as address5_0_0_, addresses0_.address_line_3 as address6_0_0_, addresses0_.address_line_4 as address7_0_0_, addresses0_.city_name as city8_0_0_, addresses0_.postal_code as postal9_0_0_, addresses0_.state_province as state10_0_0_, addresses0_.phone as phone0_0_, addresses0_.country_code as country12_0_0_, addresses0_.status as status0_0_, addresses0_.create_dt as create14_0_0_, addresses0_.update_dt as update15_0_0_, addresses0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses addresses0_ where addresses0_.consumer_id=?
12:34:54.937 [main] DEBUG org.hibernate.impl.SessionFactoryObjectFactory - initializing class SessionFactoryObjectFactory
12:34:54.946 [main] DEBUG org.hibernate.impl.SessionFactoryObjectFactory - registered: ff8080810aeba70a010aeba70f540000 (unnamed)
12:34:54.947 [main] INFO org.hibernate.impl.SessionFactoryObjectFactory - Not binding factory to JNDI, no JNDI name configured
12:34:54.947 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - instantiated session factory
12:34:54.948 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Checking 0 named HQL queries
12:34:54.948 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Checking 0 named SQL queries
12:34:55.691 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:55.691 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:55.693 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:55.708 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.test.ecs.domain.Product -> product
12:34:55.710 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
12:34:55.711 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: marketName -> market_name
12:34:55.711 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: description -> description
12:34:55.714 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:55.714 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:55.716 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:55.737 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.test.ecs.domain.PurchaseOrder -> purchase_order
12:34:55.743 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
12:34:55.745 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: status -> status
12:34:55.745 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: subTotal -> subTotal
12:34:55.745 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: tax -> tax
12:34:55.748 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: total -> total
12:34:55.748 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: shippingTotal -> shipping_total
12:34:55.749 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: shippingTax -> shipping_tax
12:34:55.749 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: languageCode -> language_code
12:34:55.749 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: currencyCode -> currency_code
12:34:55.750 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: originCode -> origin_code
12:34:55.750 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: partnerCode -> partner_code
12:34:55.750 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: clickPath -> clickpath
12:34:55.750 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: offerPage -> offer_page
12:34:55.751 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: referringSource -> referring_source
12:34:55.751 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: localSource -> local_source
12:34:55.751 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: createTime -> create_date
12:34:55.752 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: updateTime -> update_date
12:34:55.752 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: items
12:34:55.752 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: payments
12:34:55.753 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: billingAddress -> bill_custaddr_id
12:34:55.753 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: shippingAddress -> ship_custaddr_id
12:34:55.758 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:55.758 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:55.760 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:55.798 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.test.ecs.domain.PurchaseOrderItem -> purchase_order_item
12:34:55.809 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: productId -> prd_id
12:34:55.809 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: orderId -> po_id
12:34:55.809 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> prd_id, po_id
12:34:55.812 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: price -> price
12:34:55.812 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: quantity -> quantity
12:34:55.812 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: product -> prd_id
12:34:55.813 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: order -> po_id
12:34:55.815 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:55.816 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:55.817 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:55.841 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.test.ecs.domain.ConsumerAddress -> myreal.consumer_addresses
12:34:55.842 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
12:34:55.843 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: consumerId -> consumer_id
12:34:55.843 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: FirstName -> first_name
12:34:55.844 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: LastName -> last_name
12:34:55.855 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine1 -> address_line_1
12:34:55.855 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine2 -> address_line_2
12:34:55.859 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine3 -> address_line_3
12:34:55.861 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine4 -> address_line_4
12:34:55.865 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: cityName -> city_name
12:34:55.865 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: postalCode -> postal_code
12:34:55.866 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: stateProvince -> state_province
12:34:55.866 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: phone -> phone
12:34:55.866 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: countryCode -> country_code
12:34:55.869 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:55.869 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:55.871 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:55.889 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.test.ecs.domain.ConsumerContainerSet -> myreal.consumer_container_sets
12:34:55.890 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: consumerId -> consumer_id
12:34:55.890 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: containerSetCode -> container_set_code
12:34:55.891 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: containerSetVersion -> container_set_version
12:34:55.891 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> consumer_id, container_set_code, container_set_version
12:34:55.899 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container1 -> container_1
12:34:55.900 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container2 -> container_2
12:34:55.900 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container3 -> container_3
12:34:55.900 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container4 -> container_4
12:34:55.921 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container5 -> container_5
12:34:55.921 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container6 -> container_6
12:34:55.924 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container7 -> container_7
12:34:55.925 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container8 -> container_8
12:34:55.925 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container9 -> container_9
12:34:55.925 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container10 -> container_10
12:34:55.926 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container11 -> container_11
12:34:55.926 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container12 -> container_12
12:34:55.926 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container13 -> container_13
12:34:55.926 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container14 -> container_14
12:34:55.927 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container15 -> container_15
12:34:55.927 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: container16 -> container_16
12:34:55.927 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: consumer -> consumer_id
12:34:55.940 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:55.940 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:55.944 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:55.958 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.test.ecs.domain.DConsumer -> myreal.consumers
12:34:55.959 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
12:34:55.959 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: master -> master
12:34:55.959 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: handle -> handle
12:34:55.987 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
12:34:55.987 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
12:34:55.992 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
12:34:56.007 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.test.ecs.domain.PaymentTx -> payment_tx
12:34:56.151 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
12:34:56.152 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: order -> po_id
12:34:56.153 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: txType -> tx_type
12:34:56.153 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: amount -> amount
12:34:56.153 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: currencyCode -> currency_code
12:34:56.154 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: status -> status
12:34:56.154 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: ppStatus -> pp_status
12:34:56.154 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: ptStatus -> pt_status
12:34:56.154 [main] DEBUG org.hibernate.cfg.Configuration - Preparing to build session factory with filters : {}
12:34:56.155 [main] DEBUG org.hibernate.cfg.Configuration - processing extends queue
12:34:56.155 [main] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
12:34:56.157 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Second pass for collection: com.real.test.ecs.domain.PurchaseOrder.items
12:34:56.159 [main] INFO org.hibernate.cfg.HbmBinder - Mapping collection: com.real.test.ecs.domain.PurchaseOrder.items -> purchase_order_item
12:34:56.159 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Mapped collection key: po_id, one-to-many: com.real.test.ecs.domain.PurchaseOrderItem
12:34:56.161 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Second pass for collection: com.real.test.ecs.domain.PurchaseOrder.payments
12:34:56.161 [main] INFO org.hibernate.cfg.HbmBinder - Mapping collection: com.real.test.ecs.domain.PurchaseOrder.payments -> payment_tx
12:34:56.161 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Mapped collection key: po_id, one-to-many: com.real.test.ecs.domain.PaymentTx
12:34:56.162 [main] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
12:34:56.162 [main] DEBUG org.hibernate.cfg.Configuration - processing association property references
12:34:56.162 [main] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
12:34:56.164 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.test.ecs.domain.DConsumer
12:34:56.164 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.test.ecs.domain.PurchaseOrder
12:34:56.165 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.test.ecs.domain.ConsumerAddress
12:34:56.165 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.test.ecs.domain.ConsumerAddress
12:34:56.165 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.test.ecs.domain.Product
12:34:56.165 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.test.ecs.domain.PurchaseOrder
12:34:56.204 [main] INFO org.hibernate.connection.ConnectionProviderFactory - Initializing connection provider: org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider
12:34:56.206 [main] INFO org.hibernate.cfg.SettingsFactory - RDBMS: Oracle, version: Oracle Database 10g Enterprise Edition Release 10.1.0.4.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options
12:34:56.209 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC driver: Oracle JDBC driver, version: 10.2.0.1.0
12:34:56.210 [main] INFO org.hibernate.dialect.Dialect - Using dialect: org.hibernate.dialect.Oracle9Dialect
12:34:56.210 [main] INFO org.hibernate.transaction.TransactionFactoryFactory - Using default transaction strategy (direct JDBC transactions)
12:34:56.210 [main] INFO org.hibernate.transaction.TransactionManagerLookupFactory - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
12:34:56.211 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic flush during beforeCompletion(): disabled
12:34:56.212 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic session close at end of transaction: disabled
12:34:56.212 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch size: 15
12:34:56.212 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch updates for versioned data: disabled
12:34:56.213 [main] INFO org.hibernate.cfg.SettingsFactory - Scrollable result sets: enabled
12:34:56.213 [main] DEBUG org.hibernate.cfg.SettingsFactory - Wrap result sets: disabled
12:34:56.213 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC3 getGeneratedKeys(): enabled
12:34:56.213 [main] INFO org.hibernate.cfg.SettingsFactory - Connection release mode: on_close
12:34:56.213 [main] INFO org.hibernate.cfg.SettingsFactory - Default batch fetch size: 1
12:34:56.213 [main] INFO org.hibernate.cfg.SettingsFactory - Generate SQL with comments: disabled
12:34:56.214 [main] INFO org.hibernate.cfg.SettingsFactory - Order SQL updates by primary key: disabled
12:34:56.214 [main] INFO org.hibernate.cfg.SettingsFactory - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
12:34:56.214 [main] INFO org.hibernate.hql.ast.ASTQueryTranslatorFactory - Using ASTQueryTranslatorFactory
12:34:56.214 [main] INFO org.hibernate.cfg.SettingsFactory - Query language substitutions: {true=1, false=0}
12:34:56.214 [main] INFO org.hibernate.cfg.SettingsFactory - Second-level cache: enabled
12:34:56.215 [main] INFO org.hibernate.cfg.SettingsFactory - Query cache: disabled
12:34:56.215 [main] INFO org.hibernate.cfg.SettingsFactory - Cache provider: org.hibernate.cache.EhCacheProvider
12:34:56.215 [main] INFO org.hibernate.cfg.SettingsFactory - Optimize cache for minimal puts: disabled
12:34:56.219 [main] INFO org.hibernate.cfg.SettingsFactory - Structured second-level cache entries: disabled
12:34:56.220 [main] DEBUG org.hibernate.exception.SQLExceptionConverterFactory - Using dialect defined converter
12:34:56.220 [main] INFO org.hibernate.cfg.SettingsFactory - Statistics: disabled
12:34:56.220 [main] INFO org.hibernate.cfg.SettingsFactory - Deleted entity synthetic identifier rollback: disabled
12:34:56.220 [main] INFO org.hibernate.cfg.SettingsFactory - Default entity-mode: pojo
12:34:56.251 [main] INFO org.hibernate.impl.SessionFactoryImpl - building session factory
12:34:56.251 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Session factory constructed with filter configurations : {}
12:34:56.254 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386, java.vm.version=1.5.0_05-b05, ant.library.dir=/usr/local/ant/lib, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=:, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=unknown, java.vm.specification.name=Java Virtual Machine Specification, user.dir=/usr/home/mmoores/rnwk/zylom/shared/ecs/test, java.runtime.version=1.5.0_05-b05, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.endorsed.dirs=/usr/local/jdk1.5.0_05/jre/lib/endorsed, os.arch=i386, java.io.tmpdir=/tmp, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., os.name=Linux, ant.home=/usr/local/ant, sun.jnu.encoding=UTF-8, java.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386/client:/usr/local/jdk1.5.0_05/jre/lib/i386:/usr/local/jdk1.5.0_05/jre/../lib/i386, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, ecommerce.configuration=/usr/home/mmoores/rnwk/zylom/shared/ecs/test/config/rnce/config.properties, os.version=2.6.13-1532_FC4moores, user.home=/home/mmoores, user.timezone=America/New_York, hibernate.connection.release_mode=on_close, java.awt.printerjob=sun.print.PSPrinterJob, file.encoding=UTF-8, java.specification.version=1.5, java.class.path=/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-jai.jar:/usr/local/ant/lib/ant-vaj.jar:/usr/local/ant/lib/ant-apache-oro.jar:/usr/local/ant/lib/ant-jsch.jar:/usr/local/ant/lib/ant-starteam.jar:/usr/local/ant/lib/xercesImpl.jar:/usr/local/ant/lib/junit.jar:/usr/local/ant/lib/xml-apis.jar:/usr/local/ant/lib/ant-apache-bcel.jar:/usr/local/ant/lib/ant-xslp.jar:/usr/local/ant/lib/ant-netrexx.jar:/usr/local/ant/lib/ant-nodeps.jar:/usr/local/ant/lib/ant-apache-regexp.jar:/usr/local/ant/lib/ant-icontract.jar:/usr/local/ant/lib/ant-weblogic.jar:/usr/local/ant/lib/ant-jmf.jar:/usr/local/ant/lib/ant-commons-net.jar:/usr/local/ant/lib/ant-junit.jar:/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-xalan1.jar:/usr/local/ant/lib/ant-swing.jar:/usr/local/ant/lib/ant-commons-logging.jar:/usr/local/ant/lib/ant-trax.jar:/usr/local/ant/lib/ant-javamail.jar:/usr/local/ant/lib/ant-apache-resolver.jar:/usr/local/ant/lib/ant-apache-log4j.jar:/usr/local/ant/lib/ant-antlr.jar:/usr/local/ant/lib/ant.jar:/usr/local/ant/lib/ant-contrib.jar:/usr/local/ant/lib/ant-jdepend.jar:/usr/local/ant/lib/ant-apache-bsf.jar:/usr/local/ant/lib/ant-stylebook.jar:/usr/local/jdk1.5.0_05/lib/tools.jar, user.name=mmoores, hibernate.show_sql=false, hibernate.query.substitutions=true=1 false=0, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=/usr/local/jdk1.5.0_05/jre, hibernate.dialect=org.hibernate.dialect.Oracle9Dialect, java.specification.vendor=Sun Microsystems Inc., user.language=en, java.vm.info=mixed mode, sharing, hibernate.cglib.use_reflection_optimizer=true, java.version=1.5.0_05, java.ext.dirs=/usr/local/jdk1.5.0_05/jre/lib/ext, sun.boot.class.path=/usr/local/jdk1.5.0_05/jre/lib/rt.jar:/usr/local/jdk1.5.0_05/jre/lib/i18n.jar:/usr/local/jdk1.5.0_05/jre/lib/sunrsasign.jar:/usr/local/jdk1.5.0_05/jre/lib/jsse.jar:/usr/local/jdk1.5.0_05/jre/lib/jce.jar:/usr/local/jdk1.5.0_05/jre/lib/charsets.jar:/usr/local/jdk1.5.0_05/jre/classes, java.vendor=Sun Microsystems Inc., file.separator=/, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, hibernate.connection.provider_class=org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.isalist=}
12:34:56.281 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.test.ecs.domain.DConsumer
12:34:56.282 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select id from myreal.consumers where id =?
12:34:56.282 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select dconsumer_.id, dconsumer_.master as master11_, dconsumer_.handle as handle11_ from myreal.consumers dconsumer_ where dconsumer_.id=?
12:34:56.285 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into myreal.consumers (master, handle, id) values (?, ?, ?)
12:34:56.287 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update myreal.consumers set master=?, handle=? where id=?
12:34:56.288 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from myreal.consumers where id=?
12:34:56.330 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.test.ecs.domain.PurchaseOrderItem
12:34:56.330 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select prd_id, po_id from purchase_order_item where prd_id =? and po_id =?
12:34:56.330 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select purchaseor_.prd_id, purchaseor_.po_id, purchaseor_.price as price8_, purchaseor_.quantity as quantity8_ from purchase_order_item purchaseor_ where purchaseor_.prd_id=? and purchaseor_.po_id=?
12:34:56.330 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into purchase_order_item (price, quantity, prd_id, po_id) values (?, ?, ?, ?)
12:34:56.343 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update purchase_order_item set price=?, quantity=? where prd_id=? and po_id=?
12:34:56.343 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from purchase_order_item where prd_id=? and po_id=?
12:34:56.430 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.tes


Top
 Profile  
 
 Post subject: (Correct DEBUG log for issue)
PostPosted: Sun Apr 30, 2006 6:48 pm 
Newbie

Joined: Tue Jan 11, 2005 6:02 pm
Posts: 13
Location: Seattle
17:48:25.923 [main] INFO org.hibernate.cfg.Environment - Hibernate 3.1.3
17:48:25.940 [main] INFO org.hibernate.cfg.Environment - hibernate.properties not found
17:48:25.945 [main] INFO org.hibernate.cfg.Environment - using CGLIB reflection optimizer
17:48:25.946 [main] INFO org.hibernate.cfg.Environment - using JDK 1.4 java.sql.Timestamp handling
17:48:26.240 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
17:48:26.241 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
17:48:26.243 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
17:48:26.505 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.ecs.account.domain.PostalAddress -> /*ecs*/myreal.consumer_addresses
17:48:26.539 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
17:48:26.618 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: firstName -> first_name
17:48:26.619 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: lastName -> last_name
17:48:26.619 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine1 -> address_line_1
17:48:26.620 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine2 -> address_line_2
17:48:26.620 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine3 -> address_line_3
17:48:26.622 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addressLine4 -> address_line_4
17:48:26.624 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: city -> city_name
17:48:26.624 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: postalCode -> postal_code
17:48:26.626 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: state -> state_province
17:48:26.627 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: phoneNumber -> phone
17:48:26.628 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: countryCode -> country_code
17:48:26.628 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: status -> status
17:48:26.629 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: createTime -> create_dt
17:48:26.631 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: updateTime -> update_dt
17:48:26.833 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: consumer -> consumer_id
17:48:26.835 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
17:48:26.835 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
17:48:26.837 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
17:48:27.023 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.ecs.account.domain.Consumer -> /*ecs*/myreal.consumers
17:48:27.024 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: id -> id
17:48:27.025 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: master -> master
17:48:27.026 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: handle -> handle
17:48:27.026 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: ci -> ci_value
17:48:27.026 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: createTime -> create_dt
17:48:27.027 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: updateTime -> update_dt
17:48:27.039 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: addresses
17:48:27.042 [main] DEBUG org.hibernate.util.DTDEntityResolver - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
17:48:27.042 [main] DEBUG org.hibernate.util.DTDEntityResolver - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
17:48:27.047 [main] DEBUG org.hibernate.util.DTDEntityResolver - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
17:48:27.095 [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: com.real.ecs.account.domain.PaymentType -> /*ecs*/ecomm.payment_subtype
17:48:27.098 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: paymentTypeCode -> pmttyp_code
17:48:27.099 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: paymentSubTypeCode -> pmtsubtyp_code
17:48:27.099 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: paymentTypeKey -> pmttyp_code, pmtsubtyp_code
17:48:27.100 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: description -> description
17:48:27.101 [main] DEBUG org.hibernate.cfg.HbmBinder - Mapped property: createTime -> create_date
17:48:27.106 [main] DEBUG org.hibernate.cfg.Configuration - Preparing to build session factory with filters : {}
17:48:27.106 [main] DEBUG org.hibernate.cfg.Configuration - processing extends queue
17:48:27.106 [main] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
17:48:27.108 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Second pass for collection: com.real.ecs.account.domain.Consumer.addresses
17:48:27.109 [main] INFO org.hibernate.cfg.HbmBinder - Mapping collection: com.real.ecs.account.domain.Consumer.addresses -> /*ecs*/myreal.consumer_addresses
17:48:27.110 [main] DEBUG org.hibernate.cfg.CollectionSecondPass - Mapped collection key: consumer_id, one-to-many: com.real.ecs.account.domain.PostalAddress
17:48:27.110 [main] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
17:48:27.110 [main] DEBUG org.hibernate.cfg.Configuration - processing association property references
17:48:27.111 [main] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
17:48:27.111 [main] DEBUG org.hibernate.cfg.Configuration - resolving reference to class: com.real.ecs.account.domain.Consumer
17:48:27.342 [main] INFO org.hibernate.connection.ConnectionProviderFactory - Initializing connection provider: org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider
17:48:27.344 [main] INFO org.hibernate.cfg.SettingsFactory - RDBMS: Oracle, version: Oracle Database 10g Enterprise Edition Release 10.1.0.4.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options
17:48:27.345 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC driver: Oracle JDBC driver, version: 10.2.0.1.0
17:48:27.432 [main] INFO org.hibernate.dialect.Dialect - Using dialect: org.hibernate.dialect.Oracle9Dialect
17:48:27.472 [main] INFO org.hibernate.transaction.TransactionFactoryFactory - Using default transaction strategy (direct JDBC transactions)
17:48:27.480 [main] INFO org.hibernate.transaction.TransactionManagerLookupFactory - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
17:48:27.481 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic flush during beforeCompletion(): disabled
17:48:27.482 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic session close at end of transaction: disabled
17:48:27.482 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch size: 15
17:48:27.483 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch updates for versioned data: disabled
17:48:27.488 [main] INFO org.hibernate.cfg.SettingsFactory - Scrollable result sets: enabled
17:48:27.489 [main] DEBUG org.hibernate.cfg.SettingsFactory - Wrap result sets: disabled
17:48:27.490 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC3 getGeneratedKeys(): enabled
17:48:27.490 [main] INFO org.hibernate.cfg.SettingsFactory - Connection release mode: on_close
17:48:27.491 [main] INFO org.hibernate.cfg.SettingsFactory - Default batch fetch size: 1
17:48:27.491 [main] INFO org.hibernate.cfg.SettingsFactory - Generate SQL with comments: disabled
17:48:27.492 [main] INFO org.hibernate.cfg.SettingsFactory - Order SQL updates by primary key: disabled
17:48:27.493 [main] INFO org.hibernate.cfg.SettingsFactory - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
17:48:27.504 [main] INFO org.hibernate.hql.ast.ASTQueryTranslatorFactory - Using ASTQueryTranslatorFactory
17:48:27.527 [main] INFO org.hibernate.cfg.SettingsFactory - Query language substitutions: {true=1, false=0}
17:48:27.528 [main] INFO org.hibernate.cfg.SettingsFactory - Second-level cache: enabled
17:48:27.528 [main] INFO org.hibernate.cfg.SettingsFactory - Query cache: disabled
17:48:27.529 [main] INFO org.hibernate.cfg.SettingsFactory - Cache provider: org.hibernate.cache.EhCacheProvider
17:48:27.538 [main] INFO org.hibernate.cfg.SettingsFactory - Optimize cache for minimal puts: disabled
17:48:27.539 [main] INFO org.hibernate.cfg.SettingsFactory - Structured second-level cache entries: disabled
17:48:27.546 [main] DEBUG org.hibernate.exception.SQLExceptionConverterFactory - Using dialect defined converter
17:48:27.584 [main] INFO org.hibernate.cfg.SettingsFactory - Statistics: disabled
17:48:27.585 [main] INFO org.hibernate.cfg.SettingsFactory - Deleted entity synthetic identifier rollback: disabled
17:48:27.585 [main] INFO org.hibernate.cfg.SettingsFactory - Default entity-mode: pojo
17:48:27.696 [main] INFO org.hibernate.impl.SessionFactoryImpl - building session factory
17:48:27.697 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Session factory constructed with filter configurations : {}
17:48:27.701 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, hibernate.cache.provider_class=org.hibernate.cache.EhCacheProvider, sun.boot.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386, java.vm.version=1.5.0_05-b05, ant.library.dir=/usr/local/ant/lib, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=:, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=unknown, java.vm.specification.name=Java Virtual Machine Specification, user.dir=/usr/home/mmoores/rnwk/zylom/shared/ecs/test, java.runtime.version=1.5.0_05-b05, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.endorsed.dirs=/usr/local/jdk1.5.0_05/jre/lib/endorsed, os.arch=i386, java.io.tmpdir=/tmp, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., os.name=Linux, hibernate.cache.use_second_level_cache=true, ant.home=/usr/local/ant, sun.jnu.encoding=UTF-8, java.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386/client:/usr/local/jdk1.5.0_05/jre/lib/i386:/usr/local/jdk1.5.0_05/jre/../lib/i386, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, ecommerce.configuration=/usr/home/mmoores/rnwk/zylom/shared/ecs/test/config/rnce/config.properties, os.version=2.6.13-1532_FC4moores, user.home=/home/mmoores, user.timezone=America/New_York, hibernate.connection.release_mode=on_close, java.awt.printerjob=sun.print.PSPrinterJob, java.specification.version=1.5, file.encoding=UTF-8, java.class.path=/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-jai.jar:/usr/local/ant/lib/ant-vaj.jar:/usr/local/ant/lib/ant-apache-oro.jar:/usr/local/ant/lib/ant-jsch.jar:/usr/local/ant/lib/ant-starteam.jar:/usr/local/ant/lib/xercesImpl.jar:/usr/local/ant/lib/junit.jar:/usr/local/ant/lib/xml-apis.jar:/usr/local/ant/lib/ant-apache-bcel.jar:/usr/local/ant/lib/ant-xslp.jar:/usr/local/ant/lib/ant-netrexx.jar:/usr/local/ant/lib/ant-nodeps.jar:/usr/local/ant/lib/ant-apache-regexp.jar:/usr/local/ant/lib/ant-icontract.jar:/usr/local/ant/lib/ant-weblogic.jar:/usr/local/ant/lib/ant-jmf.jar:/usr/local/ant/lib/ant-commons-net.jar:/usr/local/ant/lib/ant-junit.jar:/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-xalan1.jar:/usr/local/ant/lib/ant-swing.jar:/usr/local/ant/lib/ant-commons-logging.jar:/usr/local/ant/lib/ant-trax.jar:/usr/local/ant/lib/ant-javamail.jar:/usr/local/ant/lib/ant-apache-resolver.jar:/usr/local/ant/lib/ant-apache-log4j.jar:/usr/local/ant/lib/ant-antlr.jar:/usr/local/ant/lib/ant.jar:/usr/local/ant/lib/ant-contrib.jar:/usr/local/ant/lib/ant-jdepend.jar:/usr/local/ant/lib/ant-apache-bsf.jar:/usr/local/ant/lib/ant-stylebook.jar:/usr/local/jdk1.5.0_05/lib/tools.jar, user.name=mmoores, hibernate.show_sql=false, hibernate.query.substitutions=true=1 false=0, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=/usr/local/jdk1.5.0_05/jre, hibernate.dialect=org.hibernate.dialect.Oracle9Dialect, java.specification.vendor=Sun Microsystems Inc., user.language=en, java.vm.info=mixed mode, sharing, hibernate.cglib.use_reflection_optimizer=true, java.version=1.5.0_05, java.ext.dirs=/usr/local/jdk1.5.0_05/jre/lib/ext, sun.boot.class.path=/usr/local/jdk1.5.0_05/jre/lib/rt.jar:/usr/local/jdk1.5.0_05/jre/lib/i18n.jar:/usr/local/jdk1.5.0_05/jre/lib/sunrsasign.jar:/usr/local/jdk1.5.0_05/jre/lib/jsse.jar:/usr/local/jdk1.5.0_05/jre/lib/jce.jar:/usr/local/jdk1.5.0_05/jre/lib/charsets.jar:/usr/local/jdk1.5.0_05/jre/classes, java.vendor=Sun Microsystems Inc., file.separator=/, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, hibernate.connection.provider_class=org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.isalist=}
17:48:27.779 [main] WARN net.sf.ehcache.config.Configurator - No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/usr/home/mmoores/rnwk/zylom/3rdparty/spring-framework/spring-framework-1.2.7/lib/ehcache/ehcache-1.1.jar!/ehcache-failsafe.xml
17:48:28.198 [main] DEBUG org.hibernate.util.ReflectHelper - reflection optimizer disabled for: com.real.ecs.account.domain.Consumer, BulkBeanException: Property is private (property setCreateTime)
17:48:28.282 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.ecs.account.domain.Consumer
17:48:28.283 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select id from /*ecs*/myreal.consumers where id =?
17:48:28.283 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select consumer_.id, consumer_.master as master1_, consumer_.handle as handle1_, consumer_.ci_value as ci4_1_, consumer_.update_dt as update6_1_ from /*ecs*/myreal.consumers consumer_ where consumer_.id=?
17:48:28.284 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into /*ecs*/myreal.consumers (master, handle, ci_value, create_dt, update_dt, id) values (?, ?, ?, ?, ?, ?)
17:48:28.285 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update /*ecs*/myreal.consumers set master=?, handle=?, ci_value=?, update_dt=? where id=?
17:48:28.286 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from /*ecs*/myreal.consumers where id=?
17:48:28.376 [main] DEBUG org.hibernate.util.ReflectHelper - reflection optimizer disabled for: com.real.ecs.account.domain.PostalAddress, BulkBeanException: Property is private (property setCreateTime)
17:48:28.380 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.ecs.account.domain.PostalAddress
17:48:28.382 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select id from /*ecs*/myreal.consumer_addresses where id =?
17:48:28.382 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select postaladdr_.id, postaladdr_.first_name as first2_0_, postaladdr_.last_name as last3_0_, postaladdr_.address_line_1 as address4_0_, postaladdr_.address_line_2 as address5_0_, postaladdr_.address_line_3 as address6_0_, postaladdr_.address_line_4 as address7_0_, postaladdr_.city_name as city8_0_, postaladdr_.postal_code as postal9_0_, postaladdr_.state_province as state10_0_, postaladdr_.phone as phone0_, postaladdr_.country_code as country12_0_, postaladdr_.status as status0_, postaladdr_.update_dt as update15_0_ from /*ecs*/myreal.consumer_addresses postaladdr_ where postaladdr_.id=?
17:48:28.384 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into /*ecs*/myreal.consumer_addresses (first_name, last_name, address_line_1, address_line_2, address_line_3, address_line_4, city_name, postal_code, state_province, phone, country_code, status, create_dt, update_dt, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
17:48:28.385 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update /*ecs*/myreal.consumer_addresses set first_name=?, last_name=?, address_line_1=?, address_line_2=?, address_line_3=?, address_line_4=?, city_name=?, postal_code=?, state_province=?, phone=?, country_code=?, status=?, update_dt=? where id=?
17:48:28.386 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from /*ecs*/myreal.consumer_addresses where id=?
17:48:28.437 [main] DEBUG org.hibernate.util.ReflectHelper - reflection optimizer disabled for: com.real.ecs.account.domain.PaymentType, BulkBeanException: Property is private (property setCreateTime)
17:48:28.440 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Static SQL for entity: com.real.ecs.account.domain.PaymentType
17:48:28.440 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Version select: select pmttyp_code, pmtsubtyp_code from /*ecs*/ecomm.payment_subtype where pmttyp_code =? and pmtsubtyp_code =?
17:48:28.441 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Snapshot select: select paymenttyp_.pmttyp_code, paymenttyp_.pmtsubtyp_code, paymenttyp_.description as descript3_2_, paymenttyp_.create_date as create4_2_ from /*ecs*/ecomm.payment_subtype paymenttyp_ where paymenttyp_.pmttyp_code=? and paymenttyp_.pmtsubtyp_code=?
17:48:28.442 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Insert 0: insert into /*ecs*/ecomm.payment_subtype (description, create_date, pmttyp_code, pmtsubtyp_code) values (?, ?, ?, ?)
17:48:28.443 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Update 0: update /*ecs*/ecomm.payment_subtype set description=?, create_date=? where pmttyp_code=? and pmtsubtyp_code=?
17:48:28.443 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Delete 0: delete from /*ecs*/ecomm.payment_subtype where pmttyp_code=? and pmtsubtyp_code=?
17:48:28.616 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - Static SQL for collection: com.real.ecs.account.domain.Consumer.addresses
17:48:28.618 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - Row insert: update /*ecs*/myreal.consumer_addresses set consumer_id=? where id=?
17:48:28.618 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - Row delete: update /*ecs*/myreal.consumer_addresses set consumer_id=null where consumer_id=? and id=?
17:48:28.619 [main] DEBUG org.hibernate.persister.collection.AbstractCollectionPersister - One-shot delete: update /*ecs*/myreal.consumer_addresses set consumer_id=null where consumer_id=?
17:48:28.711 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
17:48:28.713 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
17:48:28.714 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=? for update
17:48:28.715 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=? for update nowait
17:48:28.777 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
17:48:28.779 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity com.real.ecs.account.domain.Consumer: select consumer0_.id as id1_0_, consumer0_.master as master1_0_, consumer0_.handle as handle1_0_, consumer0_.ci_value as ci4_1_0_, consumer0_.create_dt as create5_1_0_, consumer0_.update_dt as update6_1_0_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.id=?
17:48:28.780 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
17:48:28.784 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
17:48:28.786 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=? for update
17:48:28.788 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=? for update nowait
17:48:28.790 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
17:48:28.794 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity com.real.ecs.account.domain.PostalAddress: select postaladdr0_.id as id0_0_, postaladdr0_.first_name as first2_0_0_, postaladdr0_.last_name as last3_0_0_, postaladdr0_.address_line_1 as address4_0_0_, postaladdr0_.address_line_2 as address5_0_0_, postaladdr0_.address_line_3 as address6_0_0_, postaladdr0_.address_line_4 as address7_0_0_, postaladdr0_.city_name as city8_0_0_, postaladdr0_.postal_code as postal9_0_0_, postaladdr0_.state_province as state10_0_0_, postaladdr0_.phone as phone0_0_, postaladdr0_.country_code as country12_0_0_, postaladdr0_.status as status0_0_, postaladdr0_.create_dt as create14_0_0_, postaladdr0_.update_dt as update15_0_0_, postaladdr0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses postaladdr0_ where postaladdr0_.id=?
17:48:28.798 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
17:48:28.802 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
17:48:28.804 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=? for update
17:48:28.805 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=? for update nowait
17:48:28.806 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_MERGE on entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
17:48:28.808 [main] DEBUG org.hibernate.loader.entity.EntityLoader - Static select for action ACTION_REFRESH on entity com.real.ecs.account.domain.PaymentType: select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
17:48:28.866 [main] DEBUG org.hibernate.loader.collection.OneToManyLoader - Static select for one-to-many com.real.ecs.account.domain.Consumer.addresses: select addresses0_.consumer_id as consumer16_1_, addresses0_.id as id1_, addresses0_.id as id0_0_, addresses0_.first_name as first2_0_0_, addresses0_.last_name as last3_0_0_, addresses0_.address_line_1 as address4_0_0_, addresses0_.address_line_2 as address5_0_0_, addresses0_.address_line_3 as address6_0_0_, addresses0_.address_line_4 as address7_0_0_, addresses0_.city_name as city8_0_0_, addresses0_.postal_code as postal9_0_0_, addresses0_.state_province as state10_0_0_, addresses0_.phone as phone0_0_, addresses0_.country_code as country12_0_0_, addresses0_.status as status0_0_, addresses0_.create_dt as create14_0_0_, addresses0_.update_dt as update15_0_0_, addresses0_.consumer_id as consumer16_0_0_ from /*ecs*/myreal.consumer_addresses addresses0_ where addresses0_.consumer_id=?
17:48:28.873 [main] DEBUG org.hibernate.impl.SessionFactoryObjectFactory - initializing class SessionFactoryObjectFactory
17:48:28.882 [main] DEBUG org.hibernate.impl.SessionFactoryObjectFactory - registered: ff8080810aecc61e010aecc623440000 (unnamed)
17:48:28.883 [main] INFO org.hibernate.impl.SessionFactoryObjectFactory - Not binding factory to JNDI, no JNDI name configured
17:48:28.883 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - instantiated session factory
17:48:28.884 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Checking 0 named HQL queries
17:48:28.884 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Checking 0 named SQL queries
17:48:29.603 [main] DEBUG org.hibernate.cfg.Configuration - Preparing to build session factory with filters : {}
17:48:29.603 [main] DEBUG org.hibernate.cfg.Configuration - processing extends queue
17:48:29.603 [main] DEBUG org.hibernate.cfg.Configuration - processing collection mappings
17:48:29.604 [main] DEBUG org.hibernate.cfg.Configuration - processing native query and ResultSetMapping mappings
17:48:29.604 [main] DEBUG org.hibernate.cfg.Configuration - processing association property references
17:48:29.604 [main] DEBUG org.hibernate.cfg.Configuration - processing foreign key constraints
17:48:29.604 [main] INFO org.hibernate.connection.ConnectionProviderFactory - Initializing connection provider: org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider
17:48:29.606 [main] INFO org.hibernate.cfg.SettingsFactory - RDBMS: Oracle, version: Oracle Database 10g Enterprise Edition Release 10.1.0.4.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options
17:48:29.606 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC driver: Oracle JDBC driver, version: 10.2.0.1.0
17:48:29.606 [main] INFO org.hibernate.dialect.Dialect - Using dialect: org.hibernate.dialect.Oracle9Dialect
17:48:29.609 [main] INFO org.hibernate.transaction.TransactionFactoryFactory - Using default transaction strategy (direct JDBC transactions)
17:48:29.609 [main] INFO org.hibernate.transaction.TransactionManagerLookupFactory - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
17:48:29.610 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic flush during beforeCompletion(): disabled
17:48:29.610 [main] INFO org.hibernate.cfg.SettingsFactory - Automatic session close at end of transaction: disabled
17:48:29.613 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch size: 15
17:48:29.613 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch updates for versioned data: disabled
17:48:29.613 [main] INFO org.hibernate.cfg.SettingsFactory - Scrollable result sets: enabled
17:48:29.614 [main] DEBUG org.hibernate.cfg.SettingsFactory - Wrap result sets: disabled
17:48:29.614 [main] INFO org.hibernate.cfg.SettingsFactory - JDBC3 getGeneratedKeys(): enabled
17:48:29.614 [main] INFO org.hibernate.cfg.SettingsFactory - Connection release mode: on_close
17:48:29.614 [main] INFO org.hibernate.cfg.SettingsFactory - Default batch fetch size: 1
17:48:29.615 [main] INFO org.hibernate.cfg.SettingsFactory - Generate SQL with comments: disabled
17:48:29.615 [main] INFO org.hibernate.cfg.SettingsFactory - Order SQL updates by primary key: disabled
17:48:29.615 [main] INFO org.hibernate.cfg.SettingsFactory - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
17:48:29.615 [main] INFO org.hibernate.hql.ast.ASTQueryTranslatorFactory - Using ASTQueryTranslatorFactory
17:48:29.615 [main] INFO org.hibernate.cfg.SettingsFactory - Query language substitutions: {true=1, false=0}
17:48:29.616 [main] INFO org.hibernate.cfg.SettingsFactory - Second-level cache: enabled
17:48:29.616 [main] INFO org.hibernate.cfg.SettingsFactory - Query cache: disabled
17:48:29.616 [main] INFO org.hibernate.cfg.SettingsFactory - Cache provider: org.hibernate.cache.EhCacheProvider
17:48:29.616 [main] INFO org.hibernate.cfg.SettingsFactory - Optimize cache for minimal puts: disabled
17:48:29.617 [main] INFO org.hibernate.cfg.SettingsFactory - Structured second-level cache entries: disabled
17:48:29.617 [main] DEBUG org.hibernate.exception.SQLExceptionConverterFactory - Using dialect defined converter
17:48:29.617 [main] INFO org.hibernate.cfg.SettingsFactory - Statistics: disabled
17:48:29.617 [main] INFO org.hibernate.cfg.SettingsFactory - Deleted entity synthetic identifier rollback: disabled
17:48:29.617 [main] INFO org.hibernate.cfg.SettingsFactory - Default entity-mode: pojo
17:48:29.629 [main] INFO org.hibernate.impl.SessionFactoryImpl - building session factory
17:48:29.629 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Session factory constructed with filter configurations : {}
17:48:29.630 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - instantiating session factory with properties: {java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386, java.vm.version=1.5.0_05-b05, ant.library.dir=/usr/local/ant/lib, java.vm.vendor=Sun Microsystems Inc., java.vendor.url=http://java.sun.com/, path.separator=:, java.vm.name=Java HotSpot(TM) Client VM, file.encoding.pkg=sun.io, user.country=US, sun.os.patch.level=unknown, java.vm.specification.name=Java Virtual Machine Specification, user.dir=/usr/home/mmoores/rnwk/zylom/shared/ecs/test, java.runtime.version=1.5.0_05-b05, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.endorsed.dirs=/usr/local/jdk1.5.0_05/jre/lib/endorsed, os.arch=i386, java.io.tmpdir=/tmp, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., os.name=Linux, ant.home=/usr/local/ant, sun.jnu.encoding=UTF-8, java.library.path=/usr/local/jdk1.5.0_05/jre/lib/i386/client:/usr/local/jdk1.5.0_05/jre/lib/i386:/usr/local/jdk1.5.0_05/jre/../lib/i386, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, ecommerce.configuration=/usr/home/mmoores/rnwk/zylom/shared/ecs/test/config/rnce/config.properties, os.version=2.6.13-1532_FC4moores, user.home=/home/mmoores, user.timezone=America/New_York, hibernate.connection.release_mode=on_close, java.awt.printerjob=sun.print.PSPrinterJob, file.encoding=UTF-8, java.specification.version=1.5, java.class.path=/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-jai.jar:/usr/local/ant/lib/ant-vaj.jar:/usr/local/ant/lib/ant-apache-oro.jar:/usr/local/ant/lib/ant-jsch.jar:/usr/local/ant/lib/ant-starteam.jar:/usr/local/ant/lib/xercesImpl.jar:/usr/local/ant/lib/junit.jar:/usr/local/ant/lib/xml-apis.jar:/usr/local/ant/lib/ant-apache-bcel.jar:/usr/local/ant/lib/ant-xslp.jar:/usr/local/ant/lib/ant-netrexx.jar:/usr/local/ant/lib/ant-nodeps.jar:/usr/local/ant/lib/ant-apache-regexp.jar:/usr/local/ant/lib/ant-icontract.jar:/usr/local/ant/lib/ant-weblogic.jar:/usr/local/ant/lib/ant-jmf.jar:/usr/local/ant/lib/ant-commons-net.jar:/usr/local/ant/lib/ant-junit.jar:/usr/local/ant/lib/ant-launcher.jar:/usr/local/ant/lib/ant-xalan1.jar:/usr/local/ant/lib/ant-swing.jar:/usr/local/ant/lib/ant-commons-logging.jar:/usr/local/ant/lib/ant-trax.jar:/usr/local/ant/lib/ant-javamail.jar:/usr/local/ant/lib/ant-apache-resolver.jar:/usr/local/ant/lib/ant-apache-log4j.jar:/usr/local/ant/lib/ant-antlr.jar:/usr/local/ant/lib/ant.jar:/usr/local/ant/lib/ant-contrib.jar:/usr/local/ant/lib/ant-jdepend.jar:/usr/local/ant/lib/ant-apache-bsf.jar:/usr/local/ant/lib/ant-stylebook.jar:/usr/local/jdk1.5.0_05/lib/tools.jar, user.name=mmoores, hibernate.show_sql=false, hibernate.query.substitutions=true=1 false=0, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=/usr/local/jdk1.5.0_05/jre, hibernate.dialect=org.hibernate.dialect.Oracle9Dialect, java.specification.vendor=Sun Microsystems Inc., user.language=en, java.vm.info=mixed mode, sharing, hibernate.cglib.use_reflection_optimizer=true, java.version=1.5.0_05, java.ext.dirs=/usr/local/jdk1.5.0_05/jre/lib/ext, sun.boot.class.path=/usr/local/jdk1.5.0_05/jre/lib/rt.jar:/usr/local/jdk1.5.0_05/jre/lib/i18n.jar:/usr/local/jdk1.5.0_05/jre/lib/sunrsasign.jar:/usr/local/jdk1.5.0_05/jre/lib/jsse.jar:/usr/local/jdk1.5.0_05/jre/lib/jce.jar:/usr/local/jdk1.5.0_05/jre/lib/charsets.jar:/usr/local/jdk1.5.0_05/jre/classes, java.vendor=Sun Microsystems Inc., file.separator=/, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, hibernate.connection.provider_class=org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.isalist=}
17:48:29.636 [main] DEBUG org.hibernate.impl.SessionFactoryObjectFactory - registered: ff8080810aecc61e010aecc626440001 (unnamed)
17:48:29.637 [main] INFO org.hibernate.impl.SessionFactoryObjectFactory - Not binding factory to JNDI, no JNDI name configured
17:48:29.637 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - instantiated session factory
17:48:29.637 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Checking 0 named HQL queries
17:48:29.638 [main] DEBUG org.hibernate.impl.SessionFactoryImpl - Checking 0 named SQL queries
17:48:30.461 [main] WARN org.apache.axis.utils.JavaUtils - Unable to find required classes (javax.activation.DataHandler and javax.mail.internet.MimeMultipart). Attachment support is disabled.
17:48:32.146 [main] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 4695792484524032
17:48:32.155 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.155 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - attempting to resolve: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.160 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - object not resolved in any cache: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.161 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Fetching entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.161 [main] DEBUG org.hibernate.loader.Loader - loading entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.171 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:48:32.181 [main] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
17:48:32.182 [main] DEBUG org.hibernate.SQL - select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
17:48:32.182 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
17:48:32.487 [main] DEBUG org.hibernate.type.StringType - binding 'CC' to parameter: 1
17:48:32.488 [main] DEBUG org.hibernate.type.StringType - binding 'VI' to parameter: 2
17:48:32.560 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
17:48:32.561 [main] DEBUG org.hibernate.loader.Loader - processing result set
17:48:32.561 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
17:48:32.562 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.563 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.580 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.581 [main] DEBUG org.hibernate.type.StringType - returning 'Visa / Delta' as column: descript3_2_0_
17:48:32.584 [main] DEBUG org.hibernate.type.CalendarType - returning '2001-04-13 14:48:59' as column: create4_2_0_
17:48:32.595 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
17:48:32.596 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
17:48:32.596 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:48:32.596 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
17:48:32.603 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 1
17:48:32.603 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.620 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:32.621 [main] DEBUG org.hibernate.engine.StatefulPersistenceContext - initializing non-lazy collections
17:48:32.621 [main] DEBUG org.hibernate.loader.Loader - done entity load
17:48:32.625 [main] DEBUG org.hibernate.jdbc.JDBCContext - after autocommit
17:48:32.637 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
17:48:32.638 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
17:48:32.638 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - flushing session
17:48:32.640 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - processing flush-time cascades
17:48:32.652 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - dirty checking collections
17:48:32.652 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushing entities and processing referenced collections
17:48:32.664 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Processing unreferenced collections
17:48:32.666 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Scheduling collection removes/(re)creates/updates
17:48:32.666 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
17:48:32.667 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
17:48:32.670 [main] DEBUG org.hibernate.pretty.Printer - listing entities:
17:48:32.671 [main] DEBUG org.hibernate.pretty.Printer - com.real.ecs.account.domain.PaymentType{paymentTypeKey=component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}, description=Visa / Delta, createTime=2001-04-13 14:48:59}
17:48:32.671 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - executing flush
17:48:32.674 [main] DEBUG org.hibernate.jdbc.ConnectionManager - registering flush begin
17:48:32.674 [main] DEBUG org.hibernate.jdbc.ConnectionManager - registering flush end
17:48:32.674 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - post flush
17:48:32.675 [main] DEBUG org.hibernate.impl.SessionImpl - closing session
17:48:32.675 [main] DEBUG org.hibernate.jdbc.ConnectionManager - performing cleanup
17:48:32.675 [main] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17:48:32.679 [main] DEBUG org.hibernate.jdbc.JDBCContext - after transaction completion
17:48:32.679 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
17:48:32.679 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
17:48:32.688 [main] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 4695792487170048
17:48:32.696 [main] DEBUG org.hibernate.engine.query.QueryPlanCache - unable to locate HQL query plan in cache; generating (from Consumer where master = ? and handle = ?)
17:48:32.861 [main] DEBUG org.hibernate.hql.ast.QueryTranslatorImpl - parse() - HQL: from com.real.ecs.account.domain.Consumer where master = ? and handle = ?
17:48:32.903 [main] DEBUG org.hibernate.hql.ast.AST - --- HQL AST ---
\-[QUERY] 'query'
+-[SELECT_FROM] 'SELECT_FROM'
| \-[FROM] 'from'
| \-[RANGE] 'RANGE'
| \-[DOT] '.'
| +-[DOT] '.'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[DOT] '.'
| | | | | +-[IDENT] 'com'
| | | | | \-[IDENT] 'real'
| | | | \-[IDENT] 'ecs'
| | | \-[IDENT] 'account'
| | \-[IDENT] 'domain'
| \-[IDENT] 'Consumer'
\-[WHERE] 'where'
\-[AND] 'and'
+-[EQ] '='
| +-[IDENT] 'master'
| \-[PARAM] '?'
\-[EQ] '='
+-[IDENT] 'handle'
\-[PARAM] '?'

17:48:32.912 [main] DEBUG org.hibernate.hql.ast.ErrorCounter - throwQueryException() : no errors
17:48:33.036 [main] DEBUG org.hibernate.hql.antlr.HqlSqlBaseWalker - select << begin [level=1, statement=select]
17:48:33.098 [main] DEBUG org.hibernate.hql.ast.tree.FromElement - FromClause{level=1} : com.real.ecs.account.domain.Consumer (no alias) -> consumer0_
17:48:33.113 [main] DEBUG org.hibernate.hql.ast.HqlSqlWalker - attempting to resolve property [master] as a non-qualified ref
17:48:33.113 [main] DEBUG org.hibernate.hql.ast.tree.FromReferenceNode - Resolved : {synthetic-alias} -> {synthetic-alias}
17:48:33.114 [main] DEBUG org.hibernate.hql.ast.tree.DotNode - getDataType() : master -> org.hibernate.type.StringType@178aae1
17:48:33.115 [main] DEBUG org.hibernate.hql.ast.tree.FromReferenceNode - Resolved : {synthetic-alias}.master -> consumer0_.master
17:48:33.123 [main] DEBUG org.hibernate.hql.ast.HqlSqlWalker - attempting to resolve property [handle] as a non-qualified ref
17:48:33.124 [main] DEBUG org.hibernate.hql.ast.tree.FromReferenceNode - Resolved : {synthetic-alias} -> {synthetic-alias}
17:48:33.124 [main] DEBUG org.hibernate.hql.ast.tree.DotNode - getDataType() : handle -> org.hibernate.type.StringType@178aae1
17:48:33.124 [main] DEBUG org.hibernate.hql.ast.tree.FromReferenceNode - Resolved : {synthetic-alias}.handle -> consumer0_.handle
17:48:33.125 [main] DEBUG org.hibernate.hql.antlr.HqlSqlBaseWalker - select : finishing up [level=1, statement=select]
17:48:33.128 [main] DEBUG org.hibernate.hql.ast.HqlSqlWalker - processQuery() : ( SELECT ( FromClause{level=1} /*ecs*/myreal.consumers consumer0_ ) ( where ( and ( = ( consumer0_.master {synthetic-alias} master ) ? ) ( = ( consumer0_.handle {synthetic-alias} handle ) ? ) ) ) )
17:48:33.165 [main] DEBUG org.hibernate.hql.ast.HqlSqlWalker - Derived SELECT clause created.
17:48:33.200 [main] DEBUG org.hibernate.hql.ast.util.JoinProcessor - Using FROM fragment [/*ecs*/myreal.consumers consumer0_]
17:48:33.200 [main] DEBUG org.hibernate.hql.antlr.HqlSqlBaseWalker - select >> end [level=1, statement=select]
17:48:33.204 [main] DEBUG org.hibernate.hql.ast.AST - --- SQL AST ---
\-[SELECT] QueryNode: 'SELECT' querySpaces (/*ecs*/myreal.consumers)
+-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
| +-[SELECT_EXPR] SelectExpressionImpl: 'consumer0_.id as id1_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=/*ecs*/myreal.consumers,tableAlias=consumer0_,origin=null,colums={,className=com.real.ecs.account.domain.Consumer}}}
| \-[SQL_TOKEN] SqlFragment: 'consumer0_.master as master1_, consumer0_.handle as handle1_, consumer0_.ci_value as ci4_1_, consumer0_.create_dt as create5_1_, consumer0_.update_dt as update6_1_'
+-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[], fromElementByTableAlias=[consumer0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: '/*ecs*/myreal.consumers consumer0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=null,role=null,tableName=/*ecs*/myreal.consumers,tableAlias=consumer0_,origin=null,colums={,className=com.real.ecs.account.domain.Consumer}}
\-[WHERE] SqlNode: 'where'
\-[AND] SqlNode: 'and'
+-[EQ] BinaryLogicOperatorNode: '='
| +-[DOT] DotNode: 'consumer0_.master' {propertyName=master,dereferenceType=4,propertyPath=master,path={synthetic-alias}.master,tableAlias=consumer0_,className=com.real.ecs.account.domain.Consumer,classAlias=null}
| | +-[IDENT] IdentNode: '{synthetic-alias}' {originalText={synthetic-alias}}
| | \-[IDENT] IdentNode: 'master' {originalText=master}
| \-[PARAM] ParameterNode: '?' {ordinal=0, expectedType=org.hibernate.type.StringType@178aae1}
\-[EQ] BinaryLogicOperatorNode: '='
+-[DOT] DotNode: 'consumer0_.handle' {propertyName=handle,dereferenceType=4,propertyPath=handle,path={synthetic-alias}.handle,tableAlias=consumer0_,className=com.real.ecs.account.domain.Consumer,classAlias=null}
| +-[IDENT] IdentNode: '{synthetic-alias}' {originalText={synthetic-alias}}
| \-[IDENT] IdentNode: 'handle' {originalText=handle}
\-[PARAM] ParameterNode: '?' {ordinal=1, expectedType=org.hibernate.type.StringType@178aae1}

17:48:33.212 [main] DEBUG org.hibernate.hql.ast.ErrorCounter - throwQueryException() : no errors
17:48:33.260 [main] DEBUG org.hibernate.hql.ast.QueryTranslatorImpl - HQL: from com.real.ecs.account.domain.Consumer where master = ? and handle = ?
17:48:33.260 [main] DEBUG org.hibernate.hql.ast.QueryTranslatorImpl - SQL: select consumer0_.id as id1_, consumer0_.master as master1_, consumer0_.handle as handle1_, consumer0_.ci_value as ci4_1_, consumer0_.create_dt as create5_1_, consumer0_.update_dt as update6_1_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.master=? and consumer0_.handle=?
17:48:33.260 [main] DEBUG org.hibernate.hql.ast.ErrorCounter - throwQueryException() : no errors
17:48:33.304 [main] DEBUG org.hibernate.engine.query.HQLQueryPlan - HQL param location recognition took 6 mills (from Consumer where master = ? and handle = ?)
17:48:33.317 [main] DEBUG org.hibernate.engine.query.QueryPlanCache - located HQL query plan in cache (from Consumer where master = ? and handle = ?)
17:48:33.340 [main] DEBUG org.hibernate.engine.query.HQLQueryPlan - find: from Consumer where master = ? and handle = ?
17:48:33.340 [main] DEBUG org.hibernate.engine.QueryParameters - parameters: [rn.uds, 12AEAEDF422D0034E043C0A8AC180034]
17:48:33.341 [main] DEBUG org.hibernate.engine.QueryParameters - named parameters: {}
17:48:33.341 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:48:33.341 [main] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
17:48:33.341 [main] DEBUG org.hibernate.SQL - select consumer0_.id as id1_, consumer0_.master as master1_, consumer0_.handle as handle1_, consumer0_.ci_value as ci4_1_, consumer0_.create_dt as create5_1_, consumer0_.update_dt as update6_1_ from /*ecs*/myreal.consumers consumer0_ where consumer0_.master=? and consumer0_.handle=?
17:48:33.342 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
17:48:33.342 [main] DEBUG org.hibernate.type.StringType - binding 'rn.uds' to parameter: 1
17:48:33.343 [main] DEBUG org.hibernate.type.StringType - binding '12AEAEDF422D0034E043C0A8AC180034' to parameter: 2
17:48:33.434 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
17:48:33.434 [main] DEBUG org.hibernate.loader.Loader - processing result set
17:48:33.434 [main] DEBUG org.hibernate.loader.Loader - done processing result set (0 rows)
17:48:33.434 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
17:48:33.436 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:48:33.436 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
17:48:33.436 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 0
17:48:33.436 [main] DEBUG org.hibernate.engine.StatefulPersistenceContext - initializing non-lazy collections
17:48:33.436 [main] DEBUG org.hibernate.jdbc.JDBCContext - after autocommit
17:48:33.437 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
17:48:33.437 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
17:48:33.437 [main] DEBUG org.hibernate.impl.SessionImpl - closing session
17:48:33.437 [main] DEBUG org.hibernate.jdbc.ConnectionManager - performing cleanup
17:48:33.437 [main] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17:48:33.440 [main] DEBUG org.hibernate.jdbc.JDBCContext - after transaction completion
17:48:33.440 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
17:48:33.440 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
17:48:33.442 [main] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 4695792490258432
17:48:33.444 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - loading entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.445 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - attempting to resolve: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.445 [main] DEBUG org.hibernate.event.def.DefaultLoadEventListener - object not resolved in any cache: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.445 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Fetching entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.445 [main] DEBUG org.hibernate.loader.Loader - loading entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.445 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:48:33.446 [main] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
17:48:33.446 [main] DEBUG org.hibernate.SQL - select paymenttyp0_.pmttyp_code as pmttyp1_2_0_, paymenttyp0_.pmtsubtyp_code as pmtsubtyp2_2_0_, paymenttyp0_.description as descript3_2_0_, paymenttyp0_.create_date as create4_2_0_ from /*ecs*/ecomm.payment_subtype paymenttyp0_ where paymenttyp0_.pmttyp_code=? and paymenttyp0_.pmtsubtyp_code=?
17:48:33.446 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - preparing statement
17:48:33.446 [main] DEBUG org.hibernate.type.StringType - binding 'CC' to parameter: 1
17:48:33.446 [main] DEBUG org.hibernate.type.StringType - binding 'VI' to parameter: 2
17:48:33.477 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open ResultSet (open ResultSets: 0, globally: 0)
17:48:33.478 [main] DEBUG org.hibernate.loader.Loader - processing result set
17:48:33.478 [main] DEBUG org.hibernate.loader.Loader - result set row: 0
17:48:33.478 [main] DEBUG org.hibernate.loader.Loader - result row: EntityKey[com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.478 [main] DEBUG org.hibernate.loader.Loader - Initializing object from ResultSet: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.479 [main] DEBUG org.hibernate.persister.entity.AbstractEntityPersister - Hydrating entity: [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.479 [main] DEBUG org.hibernate.type.StringType - returning 'Visa / Delta' as column: descript3_2_0_
17:48:33.479 [main] DEBUG org.hibernate.type.CalendarType - returning '2001-04-13 14:48:59' as column: create4_2_0_
17:48:33.487 [main] DEBUG org.hibernate.loader.Loader - done processing result set (1 rows)
17:48:33.487 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close ResultSet (open ResultSets: 1, globally: 1)
17:48:33.489 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
17:48:33.489 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - closing statement
17:48:33.489 [main] DEBUG org.hibernate.loader.Loader - total objects hydrated: 1
17:48:33.489 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - resolving associations for [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.490 [main] DEBUG org.hibernate.engine.TwoPhaseLoad - done materializing entity [com.real.ecs.account.domain.PaymentType#component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}]
17:48:33.490 [main] DEBUG org.hibernate.engine.StatefulPersistenceContext - initializing non-lazy collections
17:48:33.490 [main] DEBUG org.hibernate.loader.Loader - done entity load
17:48:33.490 [main] DEBUG org.hibernate.jdbc.JDBCContext - after autocommit
17:48:33.490 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
17:48:33.491 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
17:48:33.491 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - flushing session
17:48:33.491 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - processing flush-time cascades
17:48:33.491 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - dirty checking collections
17:48:33.491 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushing entities and processing referenced collections
17:48:33.492 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Processing unreferenced collections
17:48:33.492 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Scheduling collection removes/(re)creates/updates
17:48:33.492 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
17:48:33.492 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
17:48:33.492 [main] DEBUG org.hibernate.pretty.Printer - listing entities:
17:48:33.498 [main] DEBUG org.hibernate.pretty.Printer - com.real.ecs.account.domain.PaymentType{paymentTypeKey=component[paymentTypeCode,paymentSubTypeCode]{paymentSubTypeCode=VI, paymentTypeCode=CC}, description=Visa / Delta, createTime=2001-04-13 14:48:59}
17:48:33.498 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - executing flush
17:48:33.498 [main] DEBUG org.hibernate.jdbc.ConnectionManager - registering flush begin
17:48:33.499 [main] DEBUG org.hibernate.jdbc.ConnectionManager - registering flush end
17:48:33.500 [main] DEBUG org.hibernate.event.def.AbstractFlushingEventListener - post flush
17:48:33.501 [main] DEBUG org.hibernate.impl.SessionImpl - closing session
17:48:33.501 [main] DEBUG org.hibernate.jdbc.ConnectionManager - performing cleanup
17:48:33.501 [main] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
17:48:33.502 [main] DEBUG org.hibernate.jdbc.JDBCContext - after transaction completion
17:48:33.502 [main] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
17:48:33.502 [main] DEBUG org.hibernate.impl.SessionImpl - after transaction completion
17:48:33.887 [main] DEBUG org.hibernate.impl.SessionImpl - opened session at timestamp: 4695792492081152
17:48:33.894 [main] DEBUG org.hibernate.event.def.DefaultSaveOrUpdateEventListener - saving transient instance
17:48:33.895 [main] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
17:48:33.895 [main] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
17:48:33


Top
 Profile  
 
 Post subject: URL to DEBUG output
PostPosted: Sun Apr 30, 2006 6:58 pm 
Newbie

Joined: Tue Jan 11, 2005 6:02 pm
Posts: 13
Location: Seattle
Here is the debug output:
http://216.254.17.193/hibernate.log


Top
 Profile  
 
 Post subject:
PostPosted: Sun Apr 30, 2006 7:26 pm 
Newbie

Joined: Tue Nov 15, 2005 4:21 am
Posts: 11
Are you sure you want insert="false" update="false" in the <many-to-one>?


Top
 Profile  
 
 Post subject:
PostPosted: Mon May 01, 2006 1:03 am 
Newbie

Joined: Tue Jan 11, 2005 6:02 pm
Posts: 13
Location: Seattle
Using 'insert="false" update="false"' in the <many-to-one> does not make any difference
because my code is driving the insert from the one-to-many.
So even if i change it to insert="true" the code still fails.


Top
 Profile  
 
 Post subject:
PostPosted: Mon May 01, 2006 1:20 am 
Newbie

Joined: Tue Jan 11, 2005 6:02 pm
Posts: 13
Location: Seattle
i think i have figured this one out.
i understand now how to use the key attributes for "not-null" and the inverse="true".
thanks,
--Michael


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 6 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.