-->
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.  [ 13 posts ] 
Author Message
 Post subject: Problem with JTA, JOTM in standalone app
PostPosted: Thu Dec 29, 2005 12:50 am 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
Hibernate version:

3.0

Mapping documents:

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


<hibernate-mapping>
<class name="test.UserObject" table="USEROBJECT">
<id name="id" column="ID" type="long">
<generator class="native" />
</id>
<property name="name" column="NAME" type="string" />
</class>
</hibernate-mapping>

Hibernate Configuration

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

<hibernate-configuration>
<session-factory>
<property name="connection.username">prhodes</property>
<property name="connection.password">redacted</property>
<property name="connection.url">jdbc:db2://localhost:50000/HIBTEST</property>
<property name="connection.driver_class">com.ibm.db2.jcc.DB2Driver</property>
<property name="dialect">org.hibernate.dialect.DB2Dialect</property>
<property name="transaction.factory_class">org.hibernate.transaction.JTATransactionFactory</property>
<property name="transaction.manager_lookup_class">org.hibernate.transaction.JOTMTransactionManagerLookup</property>
<property name="current_session_context_class">jta</property>
<property name="jta.UserTransaction">java:comp/UserTransaction</property>

<mapping resource="test/UserObject.hbm.xml" />

</session-factory>


</hibernate-configuration>


Name and version of the database you are using:

DB/2 8.1.0

logging excerpt:

23:53:36,984 INFO [Environment] Hibernate 3.0.5
23:53:36,984 INFO [Environment] hibernate.properties not found
23:53:36,984 INFO [Environment] using CGLIB reflection optimizer
23:53:37,000 INFO [Environment] using JDK 1.4 java.sql.Timestamp handling
23:53:37,093 WARN [TestDriver] Welcome to TRANSACT!
23:53:37,109 INFO [jotm] JOTM started with a local transaction factory which is not bound.
23:53:37,109 INFO [jotm] CAROL initialization
23:53:37,125 DEBUG [ConfigurationRepository] Return empty properties, URL is null
23:53:37,125 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'cmi'.
23:53:37,140 DEBUG [ConfigurationRepository] Cmi is not available, don't configure it.
23:53:37,140 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'jeremie'.
23:53:37,140 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'iiop'.
23:53:37,140 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'jrmp'.
23:53:37,140 INFO [ConfigurationRepository] No protocols were defined for property 'carol.protocols', trying with default protocol = 'jrmp'.
23:53:37,375 DEBUG [jotm] default constructor
23:53:37,406 INFO [jta] JOTM 2.0.10
23:53:37,406 DEBUG [jta] TransactionFactory=org.objectweb.jotm.TransactionFactoryImpl@110003
23:53:37,406 DEBUG [jta] Batch constructor
23:53:37,406 DEBUG [jta] Clock constructor
23:53:37,421 DEBUG [recovery] TransactionRecoveryImpl constructor
23:53:37,421 DEBUG [recovery] JOTM Recovery is disabled
23:53:37,421 DEBUG [jotm] UserTransaction=org.objectweb.jotm.Current@290fbc
23:53:37,468 INFO [Configuration] configuring from file: hibernate.cfg.xml
23:53:37,578 DEBUG [DTDEntityResolver] trying to locate http://hibernate.sourceforge.net/hibern ... on-3.0.dtd in classpath under org/hibernate/
23:53:37,578 DEBUG [DTDEntityResolver] found http://hibernate.sourceforge.net/hibern ... on-3.0.dtd in classpath
23:53:37,625 DEBUG [Configuration] connection.username=prhodes
23:53:37,625 DEBUG [Configuration] connection.password=@dilbert
23:53:37,625 DEBUG [Configuration] connection.url=jdbc:db2://localhost:50000/HIBTEST
23:53:37,625 DEBUG [Configuration] connection.driver_class=com.ibm.db2.jcc.DB2Driver
23:53:37,625 DEBUG [Configuration] dialect=org.hibernate.dialect.DB2Dialect
23:53:37,625 DEBUG [Configuration] transaction.factory_class=org.hibernate.transaction.JTATransactionFactory
23:53:37,625 DEBUG [Configuration] transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup
23:53:37,625 DEBUG [Configuration] current_session_context_class=jta
23:53:37,625 DEBUG [Configuration] jta.UserTransaction=java:comp/UserTransaction
23:53:37,640 DEBUG [Configuration] null<-org.dom4j.tree.DefaultAttribute@2200d5 [Attribute: name resource value "test/UserObject.hbm.xml"]
23:53:37,640 INFO [Configuration] Mapping resource: test/UserObject.hbm.xml
23:53:37,640 DEBUG [DTDEntityResolver] trying to locate http://hibernate.sourceforge.net/hibern ... ng-3.0.dtd in classpath under org/hibernate/
23:53:37,640 DEBUG [DTDEntityResolver] found http://hibernate.sourceforge.net/hibern ... ng-3.0.dtd in classpath
23:53:37,812 INFO [HbmBinder] Mapping class: test.UserObject -> USEROBJECT
23:53:37,828 DEBUG [HbmBinder] Mapped property: id -> ID
23:53:37,843 DEBUG [HbmBinder] Mapped property: name -> NAME
23:53:37,843 INFO [Configuration] Configured SessionFactory: null
23:53:37,843 DEBUG [Configuration] properties: {hibernate.connection.password=@dilbert, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, sun.boot.library.path=d:\java\jdk1.5\jre\bin, java.vm.version=1.5.0-rc-b63, hibernate.connection.username=prhodes, 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=Service Pack 4, java.vm.specification.name=Java Virtual Machine Specification, user.dir=f:\learning\hibernate\TransactTest, java.runtime.version=1.5.0-rc-b63, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, hibernate.current_session_context_class=jta, java.endorsed.dirs=d:\java\jdk1.5\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\prhodes\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows 2000, jta.UserTransaction=java:comp/UserTransaction, sun.jnu.encoding=Cp1252, java.library.path=d:\java\jdk1.5\bin;.;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32\WBEM;d:\java\jdk1.5\bin;D:\java\apache-ant-1.6.1\bin;d:\java\jdk1.5\bin;d:\LANGUA~1\ada\bin;d:\program files\putty;S:\Program Files\IBM\WebSphere MQ\Java\lib;D:\languages\perl\bin\;d:\languages\ruby\bin;d:\program files\textpad4;S:\Program Files\IBM\WebSphere MQ\bin;S:\Program Files\IBM\WebSphere MQ\WEMPS\bin;d:\cygwin\bin;S:\PROGRA~1\IBM\SQLLIB\BIN;S:\PROGRA~1\IBM\SQLLIB\FUNCTION;S:\PROGRA~1\IBM\SQLLIB\SAMPLES\REPL;S:\oracle\ora92\bin;S:\Program Files\Oracle\jre\1.3.1\bin;S:\Program Files\Oracle\jre\1.1.8\bin;D:\Program Files\WinSCP3\;D:\Program Files\WinCvs1.3\CVSNT;C:\Program Files\Common Files\Roxio Shared\DLLShared\;C:\Program Files\Microsoft Visual Studio\Common\Tools\WinNT;C:\Program Files\Microsoft Visual Studio\Common\MSDev98\Bin;C:\Program Files\Microsoft Visual Studio\Common\Tools;D:\Program Files\Microsoft Visual Studio\VC98\bin;d:\languages\rexx, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, hibernate.transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, os.version=5.0, connection.password=@dilbert, user.home=C:\Documents and Settings\prhodes, user.timezone=America/New_York, connection.username=prhodes, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.5, transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, hibernate.connection.driver_class=com.ibm.db2.jcc.DB2Driver, user.name=prhodes, java.class.path=f:\learning\hibernate\TransactTest\bin;S:\Program Files\ibm\SQLLIB\java\db2jcc.jar;D:\java\hibernate-3.0\hibernate3.jar;D:\java\hibernate-3.0\lib\ant-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-antlr-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-junit-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-launcher-1.6.3.jar;D:\java\hibernate-3.0\lib\antlr-2.7.5H3.jar;D:\java\hibernate-3.0\lib\ant-swing-1.6.3.jar;D:\java\hibernate-3.0\lib\asm.jar;D:\java\hibernate-3.0\lib\asm-attrs.jar;D:\java\hibernate-3.0\lib\c3p0-0.8.5.2.jar;D:\java\hibernate-3.0\lib\cglib-2.1.jar;D:\java\hibernate-3.0\lib\cleanimports.jar;D:\java\hibernate-3.0\lib\commons-collections-2.1.1.jar;D:\java\hibernate-3.0\lib\commons-logging-1.0.4.jar;D:\java\hibernate-3.0\lib\concurrent-1.3.2.jar;D:\java\hibernate-3.0\lib\connector.jar;D:\java\hibernate-3.0\lib\dom4j-1.6.jar;D:\java\hibernate-3.0\lib\ehcache-1.1.jar;D:\java\hibernate-3.0\lib\jaas.jar;D:\java\hibernate-3.0\lib\jacc-1_0-fr.jar;D:\java\hibernate-3.0\lib\jaxen-1.1-beta-4.jar;D:\java\hibernate-3.0\lib\jboss-cache.jar;D:\java\hibernate-3.0\lib\jboss-common.jar;D:\java\hibernate-3.0\lib\jboss-jmx.jar;D:\java\hibernate-3.0\lib\jboss-system.jar;D:\java\hibernate-3.0\lib\jdbc2_0-stdext.jar;D:\java\hibernate-3.0\lib\jgroups-2.2.7.jar;D:\java\hibernate-3.0\lib\jta.jar;D:\java\hibernate-3.0\lib\junit-3.8.1.jar;D:\java\hibernate-3.0\lib\oscache-2.1.jar;D:\java\hibernate-3.0\lib\proxool-0.8.3.jar;D:\java\hibernate-3.0\lib\swarmcache-1.0rc2.jar;D:\java\hibernate-3.0\lib\versioncheck.jar;D:\java\hibernate-3.0\lib\xerces-2.6.2.jar;D:\java\hibernate-3.0\lib\xml-apis.jar;D:\java\hibernate-3.0\lib\log4j-1.2.9.jar;D:\java\spring-framework-1.2.5\dist\spring.jar;D:\java\jndi\fscontext\lib\fscontext.jar;D:\java\jndi\fscontext\lib\providerutil.jar;D:\java\jotm-2.0.10\lib\xapool.jar;D:\java\jotm-2.0.10\lib\commons-logging.jar;D:\java\jotm-2.0.10\lib\connector-1_5.jar;D:\java\jotm-2.0.10\lib\howl.jar;D:\java\jotm-2.0.10\lib\jotm.jar;D:\java\jotm-2.0.10\lib\jotm_iiop_stubs.jar;D:\java\jotm-2.0.10\lib\jotm_jrmp_stubs.jar;D:\java\jotm-2.0.10\lib\jts1_0.jar;D:\java\jotm-2.0.10\lib\log4j.jar;D:\java\jotm-2.0.10\lib\objectweb-datasource.jar;D:\java\jotm-2.0.10\lib\ow_carol.jar;D:\java\jotm-2.0.10\lib\commons-cli-1.0.jar, current_session_context_class=jta, java.vm.specification.version=1.0, java.home=d:\java\jdk1.5\jre, sun.arch.data.model=32, hibernate.dialect=org.hibernate.dialect.DB2Dialect, hibernate.connection.url=jdbc:db2://localhost:50000/HIBTEST, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.5.0-rc, java.ext.dirs=d:\java\jdk1.5\jre\lib\ext, sun.boot.class.path=d:\java\jdk1.5\jre\lib\rt.jar;d:\java\jdk1.5\jre\lib\i18n.jar;d:\java\jdk1.5\jre\lib\sunrsasign.jar;d:\java\jdk1.5\jre\lib\jsse.jar;d:\java\jdk1.5\jre\lib\jce.jar;d:\java\jdk1.5\jre\lib\charsets.jar;d:\java\jdk1.5\jre\classes, java.vendor=Sun Microsystems Inc., hibernate.jta.UserTransaction=java:comp/UserTransaction, connection.driver_class=com.ibm.db2.jcc.DB2Driver, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, hibernate.transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, sun.desktop=windows, connection.url=jdbc:db2://localhost:50000/HIBTEST, dialect=org.hibernate.dialect.DB2Dialect, sun.cpu.isalist=}
23:53:37,843 DEBUG [Configuration] Preparing to build session factory with filters : {}
23:53:37,843 INFO [Configuration] processing extends queue
23:53:37,843 INFO [Configuration] processing collection mappings
23:53:37,843 INFO [Configuration] processing association property references
23:53:37,843 INFO [Configuration] processing foreign key constraints
23:53:37,953 INFO [DriverManagerConnectionProvider] Using Hibernate built-in connection pool (not for production use!)
23:53:37,953 INFO [DriverManagerConnectionProvider] Hibernate connection pool size: 20
23:53:37,953 INFO [DriverManagerConnectionProvider] autocommit mode: false
23:53:37,968 INFO [DriverManagerConnectionProvider] using driver: com.ibm.db2.jcc.DB2Driver at URL: jdbc:db2://localhost:50000/HIBTEST
23:53:37,968 INFO [DriverManagerConnectionProvider] connection properties: {user=prhodes, password=@dilbert}
23:53:37,968 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
23:53:37,968 DEBUG [DriverManagerConnectionProvider] opening new JDBC connection
23:53:38,312 DEBUG [DriverManagerConnectionProvider] created connection to: jdbc:db2://localhost:50000/HIBTEST, Isolation Level: 2
23:53:38,312 DEBUG [SettingsFactory] could not get database version from JDBC metadata
23:53:38,312 INFO [SettingsFactory] RDBMS: DB2/NT, version: SQL08010
23:53:38,312 INFO [SettingsFactory] JDBC driver: IBM DB2 JDBC Universal Driver Architecture, version: 1.0.581
23:53:38,312 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
23:53:38,359 INFO [Dialect] Using dialect: org.hibernate.dialect.DB2Dialect
23:53:38,359 INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory
23:53:38,375 INFO [NamingHelper] JNDI InitialContext properties:{}
23:53:38,375 INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JOTMTransactionManagerLookup
23:53:38,375 INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup
23:53:38,375 INFO [SettingsFactory] Automatic flush during beforeCompletion(): disabled
23:53:38,375 INFO [SettingsFactory] Automatic session close at end of transaction: disabled
23:53:38,375 INFO [SettingsFactory] Scrollable result sets: enabled
23:53:38,375 DEBUG [SettingsFactory] Wrap result sets: disabled
23:53:38,375 INFO [SettingsFactory] JDBC3 getGeneratedKeys(): disabled
23:53:38,375 INFO [SettingsFactory] Connection release mode: null
23:53:38,375 INFO [SettingsFactory] Default batch fetch size: 1
23:53:38,375 INFO [SettingsFactory] Generate SQL with comments: disabled
23:53:38,375 INFO [SettingsFactory] Order SQL updates by primary key: disabled
23:53:38,375 INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
23:53:38,390 INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
23:53:38,390 INFO [SettingsFactory] Query language substitutions: {}
23:53:38,390 INFO [SettingsFactory] Second-level cache: enabled
23:53:38,390 INFO [SettingsFactory] Query cache: disabled
23:53:38,390 INFO [SettingsFactory] Cache provider: org.hibernate.cache.EhCacheProvider
23:53:38,390 INFO [SettingsFactory] Optimize cache for minimal puts: disabled
23:53:38,390 INFO [SettingsFactory] Structured second-level cache entries: disabled
23:53:38,390 DEBUG [SQLExceptionConverterFactory] Using dialect defined converter
23:53:38,406 INFO [SettingsFactory] Statistics: disabled
23:53:38,406 INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled
23:53:38,406 INFO [SettingsFactory] Default entity-mode: pojo
23:53:38,593 INFO [SessionFactoryImpl] building session factory
23:53:38,593 DEBUG [SessionFactoryImpl] Session factory constructed with filter configurations : {}
23:53:38,609 DEBUG [SessionFactoryImpl] instantiating session factory with properties: {hibernate.connection.password=@dilbert, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, sun.boot.library.path=d:\java\jdk1.5\jre\bin, java.vm.version=1.5.0-rc-b63, hibernate.connection.username=prhodes, 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=Service Pack 4, java.vm.specification.name=Java Virtual Machine Specification, user.dir=f:\learning\hibernate\TransactTest, java.runtime.version=1.5.0-rc-b63, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, hibernate.current_session_context_class=jta, java.endorsed.dirs=d:\java\jdk1.5\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\prhodes\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows 2000, jta.UserTransaction=java:comp/UserTransaction, sun.jnu.encoding=Cp1252, java.library.path=d:\java\jdk1.5\bin;.;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32\WBEM;d:\java\jdk1.5\bin;D:\java\apache-ant-1.6.1\bin;d:\java\jdk1.5\bin;d:\LANGUA~1\ada\bin;d:\program files\putty;S:\Program Files\IBM\WebSphere MQ\Java\lib;D:\languages\perl\bin\;d:\languages\ruby\bin;d:\program files\textpad4;S:\Program Files\IBM\WebSphere MQ\bin;S:\Program Files\IBM\WebSphere MQ\WEMPS\bin;d:\cygwin\bin;S:\PROGRA~1\IBM\SQLLIB\BIN;S:\PROGRA~1\IBM\SQLLIB\FUNCTION;S:\PROGRA~1\IBM\SQLLIB\SAMPLES\REPL;S:\oracle\ora92\bin;S:\Program Files\Oracle\jre\1.3.1\bin;S:\Program Files\Oracle\jre\1.1.8\bin;D:\Program Files\WinSCP3\;D:\Program Files\WinCvs1.3\CVSNT;C:\Program Files\Common Files\Roxio Shared\DLLShared\;C:\Program Files\Microsoft Visual Studio\Common\Tools\WinNT;C:\Program Files\Microsoft Visual Studio\Common\MSDev98\Bin;C:\Program Files\Microsoft Visual Studio\Common\Tools;D:\Program Files\Microsoft Visual Studio\VC98\bin;d:\languages\rexx, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, hibernate.transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, os.version=5.0, connection.password=@dilbert, user.home=C:\Documents and Settings\prhodes, user.timezone=America/New_York, connection.username=prhodes, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.5, transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, hibernate.connection.driver_class=com.ibm.db2.jcc.DB2Driver, user.name=prhodes, java.class.path=f:\learning\hibernate\TransactTest\bin;S:\Program Files\ibm\SQLLIB\java\db2jcc.jar;D:\java\hibernate-3.0\hibernate3.jar;D:\java\hibernate-3.0\lib\ant-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-antlr-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-junit-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-launcher-1.6.3.jar;D:\java\hibernate-3.0\lib\antlr-2.7.5H3.jar;D:\java\hibernate-3.0\lib\ant-swing-1.6.3.jar;D:\java\hibernate-3.0\lib\asm.jar;D:\java\hibernate-3.0\lib\asm-attrs.jar;D:\java\hibernate-3.0\lib\c3p0-0.8.5.2.jar;D:\java\hibernate-3.0\lib\cglib-2.1.jar;D:\java\hibernate-3.0\lib\cleanimports.jar;D:\java\hibernate-3.0\lib\commons-collections-2.1.1.jar;D:\java\hibernate-3.0\lib\commons-logging-1.0.4.jar;D:\java\hibernate-3.0\lib\concurrent-1.3.2.jar;D:\java\hibernate-3.0\lib\connector.jar;D:\java\hibernate-3.0\lib\dom4j-1.6.jar;D:\java\hibernate-3.0\lib\ehcache-1.1.jar;D:\java\hibernate-3.0\lib\jaas.jar;D:\java\hibernate-3.0\lib\jacc-1_0-fr.jar;D:\java\hibernate-3.0\lib\jaxen-1.1-beta-4.jar;D:\java\hibernate-3.0\lib\jboss-cache.jar;D:\java\hibernate-3.0\lib\jboss-common.jar;D:\java\hibernate-3.0\lib\jboss-jmx.jar;D:\java\hibernate-3.0\lib\jboss-system.jar;D:\java\hibernate-3.0\lib\jdbc2_0-stdext.jar;D:\java\hibernate-3.0\lib\jgroups-2.2.7.jar;D:\java\hibernate-3.0\lib\jta.jar;D:\java\hibernate-3.0\lib\junit-3.8.1.jar;D:\java\hibernate-3.0\lib\oscache-2.1.jar;D:\java\hibernate-3.0\lib\proxool-0.8.3.jar;D:\java\hibernate-3.0\lib\swarmcache-1.0rc2.jar;D:\java\hibernate-3.0\lib\versioncheck.jar;D:\java\hibernate-3.0\lib\xerces-2.6.2.jar;D:\java\hibernate-3.0\lib\xml-apis.jar;D:\java\hibernate-3.0\lib\log4j-1.2.9.jar;D:\java\spring-framework-1.2.5\dist\spring.jar;D:\java\jndi\fscontext\lib\fscontext.jar;D:\java\jndi\fscontext\lib\providerutil.jar;D:\java\jotm-2.0.10\lib\xapool.jar;D:\java\jotm-2.0.10\lib\commons-logging.jar;D:\java\jotm-2.0.10\lib\connector-1_5.jar;D:\java\jotm-2.0.10\lib\howl.jar;D:\java\jotm-2.0.10\lib\jotm.jar;D:\java\jotm-2.0.10\lib\jotm_iiop_stubs.jar;D:\java\jotm-2.0.10\lib\jotm_jrmp_stubs.jar;D:\java\jotm-2.0.10\lib\jts1_0.jar;D:\java\jotm-2.0.10\lib\log4j.jar;D:\java\jotm-2.0.10\lib\objectweb-datasource.jar;D:\java\jotm-2.0.10\lib\ow_carol.jar;D:\java\jotm-2.0.10\lib\commons-cli-1.0.jar, current_session_context_class=jta, java.vm.specification.version=1.0, java.home=d:\java\jdk1.5\jre, sun.arch.data.model=32, hibernate.dialect=org.hibernate.dialect.DB2Dialect, hibernate.connection.url=jdbc:db2://localhost:50000/HIBTEST, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.5.0-rc, java.ext.dirs=d:\java\jdk1.5\jre\lib\ext, sun.boot.class.path=d:\java\jdk1.5\jre\lib\rt.jar;d:\java\jdk1.5\jre\lib\i18n.jar;d:\java\jdk1.5\jre\lib\sunrsasign.jar;d:\java\jdk1.5\jre\lib\jsse.jar;d:\java\jdk1.5\jre\lib\jce.jar;d:\java\jdk1.5\jre\lib\charsets.jar;d:\java\jdk1.5\jre\classes, java.vendor=Sun Microsystems Inc., hibernate.jta.UserTransaction=java:comp/UserTransaction, connection.driver_class=com.ibm.db2.jcc.DB2Driver, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, hibernate.transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, sun.desktop=windows, connection.url=jdbc:db2://localhost:50000/HIBTEST, dialect=org.hibernate.dialect.DB2Dialect, sun.cpu.isalist=}
23:53:38,625 WARN [Configurator] No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/D:/java/hibernate-3.0/lib/ehcache-1.1.jar!/ehcache-failsafe.xml
23:53:39,093 DEBUG [BasicEntityPersister] Static SQL for entity: test.UserObject
23:53:39,093 DEBUG [BasicEntityPersister] Version select: select ID from USEROBJECT where ID =?
23:53:39,093 DEBUG [BasicEntityPersister] Snapshot select: select userobject_.ID, userobject_.NAME as NAME0_ from USEROBJECT userobject_ where userobject_.ID=?
23:53:39,093 DEBUG [BasicEntityPersister] Insert 0: insert into USEROBJECT (NAME, ID) values (?, ?)
23:53:39,093 DEBUG [BasicEntityPersister] Update 0: update USEROBJECT set NAME=? where ID=?
23:53:39,093 DEBUG [BasicEntityPersister] Delete 0: delete from USEROBJECT where ID=?
23:53:39,093 DEBUG [BasicEntityPersister] Identity insert: insert into USEROBJECT (NAME, ID) values (?, default)
23:53:39,125 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
23:53:39,125 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
23:53:39,125 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=? for update with rr
23:53:39,125 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=? for update with rr
23:53:39,125 DEBUG [SessionFactoryObjectFactory] initializing class SessionFactoryObjectFactory
23:53:39,140 DEBUG [SessionFactoryObjectFactory] registered: 4028825b0874dd2e010874dd30b50000 (unnamed)
23:53:39,140 INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
23:53:39,140 DEBUG [SessionFactoryImpl] instantiated session factory
23:53:39,140 DEBUG [SessionFactoryImpl] obtaining JTA TransactionManager
23:53:39,140 INFO [SessionFactoryImpl] Checking 0 named queries
23:53:39,140 DEBUG [jta] begin transaction
23:53:39,140 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
23:53:39,156 DEBUG [jta] xid= bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,156 DEBUG [jta] timeout= 60
23:53:39,156 DEBUG [jta] xid=bb14:38:0:016c8570f54bec9d27...c35001:, timeout=60
23:53:39,156 DEBUG [jta] tx=bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,156 DEBUG [jta] TransactionImpl.doAttach flag= TMJOIN
23:53:39,156 DEBUG [jta] number of enlisted= 0
23:53:39,156 DEBUG [jta] threadTx.set= java.lang.ThreadLocal@608760
23:53:39,156 DEBUG [jta] Associate tx to xid (xid=bb14:38:0:016c8570f54bec9d27...c35001:)
23:53:39,171 DEBUG [jta] TimerEvent.new(bb14:38:0:016c8570f54bec9d27...c35001:,60,null,false)
23:53:39,171 DEBUG [jta] set timer for tx (timer=org.objectweb.jotm.TimerEvent@17aece8, tx=bb14:38:0:016c8570f54bec9d27...c35001:)
23:53:39,187 DEBUG [jta] set date for tx (data=Wed Dec 28 23:53:39 EST 2005, tx=bb14:38:0:016c8570f54bec9d27...c35001:)
23:53:39,187 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
23:53:39,187 DEBUG [jta] Transaction ret= bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,187 DEBUG [jta] TransactionImpl.getStatus()
23:53:39,250 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
23:53:39,250 DEBUG [jta] Transaction ret= bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,250 DEBUG [jta] TransactionImpl.getStatus()
23:53:39,250 DEBUG [jta] TransactionImpl.registerSynchronization(Synchronization sync)
23:53:39,250 DEBUG [jta] make subcoordinator
23:53:39,265 DEBUG [jta] tx=bb14:38:0:016c8570f54bec9d27...c35001:, xid=bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,265 DEBUG [jta] synchro=org.hibernate.transaction.CacheSynchronization
23:53:39,265 DEBUG [jta] status=STATUS_ACTIVE
23:53:39,265 DEBUG [JDBCContext] successfully registered Synchronization
23:53:39,265 DEBUG [SessionImpl] opened session at timestamp: 4652367950655488
23:53:39,281 DEBUG [jta] TransactionImpl.registerSynchronization(Synchronization sync)
23:53:39,281 DEBUG [jta] synchro=org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@1c8efd1
23:53:39,281 DEBUG [jta] status=STATUS_ACTIVE
23:53:39,281 DEBUG [JTATransaction] begin
23:53:39,281 DEBUG [JTATransaction] Looking for UserTransaction under: java:comp/UserTransaction
23:53:39,281 DEBUG [JTATransaction] Obtained UserTransaction
23:53:39,281 DEBUG [jta] Current.getStatus()
23:53:39,281 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
23:53:39,281 DEBUG [jta] Transaction ret= bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,281 DEBUG [jta] TransactionImpl.getStatus()
23:53:39,281 DEBUG [jta] status=STATUS_ACTIVE
23:53:39,281 DEBUG [DefaultSaveOrUpdateEventListener] saving transient instance
23:53:39,296 DEBUG [AbstractSaveEventListener] saving [test.UserObject#<null>]
23:53:39,296 DEBUG [AbstractSaveEventListener] executing insertions
23:53:39,296 DEBUG [BasicEntityPersister] Inserting entity: test.UserObject (native id)
23:53:39,296 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
23:53:39,296 DEBUG [ConnectionManager] opening JDBC connection
23:53:39,312 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
23:53:39,312 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
23:53:39,312 DEBUG [SQL] insert into USEROBJECT (NAME, ID) values (?, default)
23:53:39,312 DEBUG [AbstractBatcher] preparing statement
23:53:39,359 DEBUG [BasicEntityPersister] Dehydrating entity: [test.UserObject#<null>]
23:53:39,359 DEBUG [StringType] binding 'PhillipRhodes' to parameter: 1
23:53:39,375 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
23:53:39,375 DEBUG [AbstractBatcher] closing statement
23:53:39,375 DEBUG [ConnectionManager] aggressively releasing JDBC connection
23:53:39,375 DEBUG [ConnectionManager] closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
23:53:39,375 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
23:53:39,375 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
23:53:39,375 DEBUG [ConnectionManager] opening JDBC connection
23:53:39,375 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
23:53:39,375 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
23:53:39,375 DEBUG [SQL] values identity_val_local()
23:53:39,375 DEBUG [AbstractBatcher] preparing statement
23:53:39,421 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 21
23:53:39,421 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
23:53:39,421 DEBUG [AbstractBatcher] closing statement
23:53:39,421 DEBUG [ConnectionManager] aggressively releasing JDBC connection
23:53:39,421 DEBUG [ConnectionManager] closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
23:53:39,421 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
23:53:39,437 DEBUG [JTATransaction] commit
23:53:39,437 DEBUG [SessionImpl] closing session
23:53:39,437 DEBUG [jta] commit transaction
23:53:39,437 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
23:53:39,437 DEBUG [jta] Transaction ret= bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,437 DEBUG [jta] tx=bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,437 DEBUG [jta] TransactionImpl.commit (tx= bb14:38:0:016c8570f54bec9d27...c35001:)
23:53:39,437 DEBUG [jta] status=STATUS_ACTIVE
23:53:39,437 DEBUG [jta] doBeforeCompletion committing= true
23:53:39,437 DEBUG [jta] unset timer for tx (timer=org.objectweb.jotm.TimerEvent@17aece8, tx=bb14:38:0:016c8570f54bec9d27...c35001:)
23:53:39,437 DEBUG [jta] TimerEvent(bb14:38:0:016c8570f54bec9d27...c35001:).unset
23:53:39,437 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
23:53:39,437 DEBUG [jta] Transaction ret= bb14:38:0:016c8570f54bec9d27...c35001:
23:53:39,437 DEBUG [jta] sychronization list size= 2
23:53:39,437 DEBUG [jta] Synchronization sync= org.hibernate.transaction.CacheSynchronization
23:53:39,437 DEBUG [CacheSynchronization] transaction before completion callback
23:53:39,437 DEBUG [jta] TransactionImpl.getStatus()
23:53:39,437 DEBUG [jta] status=STATUS_ACTIVE
23:53:39,437 DEBUG [CacheSynchronization] automatically flushing session
23:53:39,437 DEBUG [SessionImpl] automatically flushing session
23:53:39,437 DEBUG [JDBCContext] before transaction completion
23:53:39,437 DEBUG [SessionImpl] before transaction completion
23:53:39,437 DEBUG [jta] Synchronization sync= org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@1c8efd1
23:53:39,437 DEBUG [jta] TransactionImpl.doDetach flag= TMSUCCESS
23:53:39,437 DEBUG [jta] number of enlisted= 0
23:53:39,437 DEBUG [jta] status=STATUS_ACTIVE
23:53:39,437 DEBUG [jta] SubCoordinator.doPrepare()
23:53:39,437 DEBUG [jta] doAfterCompletion()
23:53:39,437 DEBUG [jta] sychronization list size= 2
23:53:39,437 DEBUG [jta] Synchronization sync= org.hibernate.transaction.CacheSynchronization
23:53:39,437 DEBUG [jta] sync.afterCompletion status= STATUS_COMMITTED
23:53:39,437 DEBUG [CacheSynchronization] transaction after completion callback, status: 3
23:53:39,437 DEBUG [JDBCContext] after transaction completion
23:53:39,437 DEBUG [SessionImpl] after transaction completion
23:53:39,437 DEBUG [jta] Synchronization sync= org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@1c8efd1
23:53:39,437 DEBUG [jta] sync.afterCompletion status= STATUS_COMMITTED
23:53:39,437 DEBUG [jta] threadTx.set = null
23:53:39,437 DEBUG [jta] remove tx from xid (xid=bb14:38:0:016c8570f54bec9d27...c35001:)
23:53:39,437 DEBUG [jta] SubCoordinator unexported [subcoord=org.objectweb.jotm.SubCoordinator@6397eb]
23:53:39,437 DEBUG [jta] threadTx.set= null
23:53:39,437 DEBUG [jta] reset timeout= 60
23:53:39,437 INFO [jotm] stop JOTM
23:53:39,437 DEBUG [jta] threadTx.set= null
23:53:39,437 DEBUG [jotm] TransactionFactory unexported
23:53:39,437 WARN [TestDriver] done




main code :

package test;

import java.io.File;
import javax.naming.InitialContext;
import javax.transaction.TransactionManager;
import javax.transaction.UserTransaction;
import org.apache.log4j.Logger;
import org.apache.log4j.xml.DOMConfigurator;
import org.hibernate.Session;
import org.hibernate.SessionFactory;
import org.hibernate.Transaction;
import org.hibernate.cfg.Configuration;
import org.objectweb.jotm.Jotm;
import org.objectweb.transaction.jta.TMService;

public class TestDriver
{
/**
* @param args
*/
public static void main( String[] args )
{

// BasicConfigurator.configure();
DOMConfigurator.configure( "log4j.xml" );
Configuration config = new Configuration();
Logger logger = Logger.getLogger( TestDriver.class );

logger.warn( "Welcome to TRANSACT!" );

try
{
/* startup JOTM */
TMService jotm = new Jotm(true, false);

/* and get a UserTransaction */
UserTransaction ut = jotm.getUserTransaction();

// setup JNDI
System.setProperty( "java.naming.factory.initial", "com.sun.jndi.fscontext.RefFSContextFactory" );
InitialContext jndi = new InitialContext();

// bind the userTransaction into JNDI
jndi.bind( "java:comp/UserTransaction", ut );

File file = new File( "./hibernate.cfg.xml" );
SessionFactory sf = config.configure( file ).buildSessionFactory();

// begin a new Transaction
ut.begin();

// and open the Hibernate session
Session session = sf.getCurrentSession();

// there's an existing transaction, hibernate will use it?
Transaction tx = session.beginTransaction();

// do something transactional using Hibernate
UserObject obj = new UserObject( "PhillipRhodes" );
session.save( obj );

// commit that action
tx.commit();

// close the hibernate session
session.close();

// do something else involving the transaction (send a JMS message, for example)
// TODO: add a separate transactional step here

// commit the transaction
ut.commit();

// stop the transaction manager
jotm.stop();

// goodbye...
logger.warn( "done" );
}
catch( Exception e )
{
e.printStackTrace();
}
}
}

code for a stupid little persistent class

package test;

public class UserObject
{
private Long id;
private String name;

public UserObject()
{
}

public UserObject( String name )
{
this.name = name;
}

public Long getId()
{
return id;
}

public void setId( Long id )
{
if( this.id == null )
{
this.id = id;
}
else
{
throw new RuntimeException( "attempt to modify immutable field \"id\" with value: " + this.id );
}
}

public void setName( String name )
{
this.name = name;
}

public String getName()
{
return name;
}
}


Hi all, sorry if this is more of a JOTM question than a Hibernate question,
but I'm a little confused. I've read what appear to be the relevant
sections of the references docs, as well as the community doc on
transactions, and I'm still missing something.

The problem is, using the above configuration and code, the transaction
somehow winds up never being finally committed. That is, when the
program ends, nothing has been written to the persistent store. OTOH, if I
comment out the jotm.stop() line, and check the database while the
program is still running, I can see the transaction in the database. It
appears that somehow JOTM is never finalizing the commit, and is
ultimately rolling it back when stopped (or just doing nothing, and the
underlying database is eventually doing the rollback, I'm not sure which).


Can somebody help clarify for me how this combination works? I thought
I was to create a new JTA transaction with ut.begin(), but that I still
needed to call session.beginTransaction(), with Hibernate picking up the
existing JTA transaction and using it..

In turn, I was expecting to need to call commit() on the Hibernate
transaction, to demarcate that that part of what might eventually be a
distributed transaction was done. And then finally, after doing any other
transactional steps, I thought to call ut.commit() (or ut.rollback() ) to finish
things up.

Obviously I'm missing something in my understanding however, as this
does not work. Worse, I've tried every imaginable (to me) permutation of
ways to begin and commit the transaction and can't find a way to make it
actually work, even by trial and error.

Also, FWIW, this is only a sample program I cooked up to experiment with
this very issue... it's not meant to reflect any real world use case, other
than my need to understand how this all works. I do eventually forsee a
need to combine a hibernate action with other transactional actions (such
as sending a JMS message), which is why I'm trying to figure this out.

Thanks in advance for any and all help.

-- phil


Top
 Profile  
 
 Post subject:
PostPosted: Thu Dec 29, 2005 1:05 am 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
I see this code sample from http://www.hibernate.org/42.html

Code:
try {
    factory.getCurrentSession().beginTransaction();

    // Do some work
    factory.getCurrentSession().load(...);
    factory.getCurrentSession().persist(...);

    factory.getCurrentSession().getTransaction().commit();
}
catch (RuntimeException e) {
    factory.getCurrentSession().getTransaction().rollback();
    throw e; // or display error message
}


which suggests that you do still use the session.beginTransaction() call
even when operating in a JTA environment. But it's vague on whether or
not you should have already called ut.begin() on the UserTransaction
object.

Also, this page references setting current_session_context_class to
"thread" but in the reference doc it seems to imply that you should set
that to "jta" when using JTA. I'm not sure if that is related to the problem
I'm seeing or not. FWIW, I tried it with it set to "thread" as well, and I
still see the same behavior.


Top
 Profile  
 
 Post subject:
PostPosted: Thu Dec 29, 2005 7:40 am 
Hibernate Team
Hibernate Team

Joined: Mon Aug 25, 2003 9:11 pm
Posts: 4592
Location: Switzerland
The page you quote is crystal clear. It says: "As recommended, you should hide the transaction system by using the Hibernate Transaction API. If you'd call the JTA UserTransaction yourself you'd bind your code to JTA."

So it's up to you what you would like to do. Obviously, if you use the Hibernate API you get automatic "thread" Session binding as a feature. Otherwise you need the "jta" model with binds Session to the transaction. This is explained in the next paragraph on the page (for CMT) and in the reference documentation.


Top
 Profile  
 
 Post subject:
PostPosted: Thu Dec 29, 2005 11:01 am 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
christian wrote:
The page you quote is crystal clear. It says: "As recommended, you should hide the transaction system by using the Hibernate Transaction API. If you'd call the JTA UserTransaction yourself you'd bind your code to JTA."


Well, I'm not sure I'd call it "crystal clear" but having that pointed out specifically does help. I think I was a little confused because I saw something which made reference to how session.beginTransaction()
would "join" an existing JTA transaction if there was one. I wasn't
quite sure what to expect if there wasn't one.

christian wrote:
So it's up to you what you would like to do. Obviously, if you use the Hibernate API you get automatic "thread" Session binding as a feature. Otherwise you need the "jta" model with binds Session to the transaction. This is explained in the next paragraph on the page (for CMT) and in the reference documentation.


so if I use "jta" model, I call begin() and commit() on the UserTransaction and if I use "thread" I use the Hibernate methods, is that it? And does that still apply if I'm going to have another transactional action occur in the same JTA transaction?

Given the example code above, it sounds like I (if I want to use JTA) should set the session binding model to "jta" and *only* call begin() and commit() on the UT. But I tried that and I still get the same behavior.. at the end the transaction still appears not to be committed. <sigh> Any more ideas on what I'm doing wrong?

Thanks for the help!


Top
 Profile  
 
 Post subject:
PostPosted: Thu Dec 29, 2005 11:04 am 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
updated code

Code:
         // begin a new Transaction
         ut.begin();
         
         // and open the Hibernate session
         Session session = sf.getCurrentSession();
         
         // there's an existing transaction, hibernate will use it?
         // Transaction tx = session.beginTransaction();
                  
         // do something transactional using Hibernate
         UserObject obj = new UserObject( "PhillipRhodes" );
         session.save( obj );
         
         // commit that action
         // tx.commit();

         // close the hibernate session
         session.close();
         
         // do something else involving the transaction (send a JMS message, for example)
         // TODO: add a separate transactional step here
         
         // commit the transaction
         ut.commit();

         // stop the transaction manager
         jotm.stop();
         


updated log output

10:11:26,375 INFO [Environment] Hibernate 3.0.5
10:11:26,375 INFO [Environment] hibernate.properties not found
10:11:26,375 INFO [Environment] using CGLIB reflection optimizer
10:11:26,375 INFO [Environment] using JDK 1.4 java.sql.Timestamp handling
10:11:26,484 WARN [TestDriver] Welcome to TRANSACT!
10:11:26,500 INFO [jotm] JOTM started with a local transaction factory which is not bound.
10:11:26,500 INFO [jotm] CAROL initialization
10:11:26,515 DEBUG [ConfigurationRepository] Return empty properties, URL is null
10:11:26,515 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'cmi'.
10:11:26,515 DEBUG [ConfigurationRepository] Cmi is not available, don't configure it.
10:11:26,515 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'jeremie'.
10:11:26,515 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'iiop'.
10:11:26,515 DEBUG [ConfigurationRepository] Build protocol object for protocol name found 'jrmp'.
10:11:26,515 INFO [ConfigurationRepository] No protocols were defined for property 'carol.protocols', trying with default protocol = 'jrmp'.
10:11:26,750 DEBUG [jotm] default constructor
10:11:26,781 INFO [jta] JOTM 2.0.10
10:11:26,781 DEBUG [jta] TransactionFactory=org.objectweb.jotm.TransactionFactoryImpl@110003
10:11:26,781 DEBUG [jta] Batch constructor
10:11:26,781 DEBUG [jta] Clock constructor
10:11:26,796 DEBUG [recovery] TransactionRecoveryImpl constructor
10:11:26,796 DEBUG [recovery] JOTM Recovery is disabled
10:11:26,796 DEBUG [jotm] UserTransaction=org.objectweb.jotm.Current@290fbc
10:11:26,828 INFO [Configuration] configuring from file: hibernate.cfg.xml
10:11:26,937 DEBUG [DTDEntityResolver] trying to locate http://hibernate.sourceforge.net/hibern ... on-3.0.dtd in classpath under org/hibernate/
10:11:26,937 DEBUG [DTDEntityResolver] found http://hibernate.sourceforge.net/hibern ... on-3.0.dtd in classpath
10:11:27,000 DEBUG [Configuration] connection.username=prhodes
10:11:27,000 DEBUG [Configuration] connection.password=@dilbert
10:11:27,000 DEBUG [Configuration] connection.url=jdbc:db2://localhost:50000/HIBTEST
10:11:27,000 DEBUG [Configuration] connection.driver_class=com.ibm.db2.jcc.DB2Driver
10:11:27,000 DEBUG [Configuration] dialect=org.hibernate.dialect.DB2Dialect
10:11:27,000 DEBUG [Configuration] transaction.factory_class=org.hibernate.transaction.JTATransactionFactory
10:11:27,000 DEBUG [Configuration] transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup
10:11:27,000 DEBUG [Configuration] current_session_context_class=jta
10:11:27,000 DEBUG [Configuration] jta.UserTransaction=java:comp/UserTransaction
10:11:27,000 DEBUG [Configuration] null<-org.dom4j.tree.DefaultAttribute@2200d5 [Attribute: name resource value "test/UserObject.hbm.xml"]
10:11:27,000 INFO [Configuration] Mapping resource: test/UserObject.hbm.xml
10:11:27,000 DEBUG [DTDEntityResolver] trying to locate http://hibernate.sourceforge.net/hibern ... ng-3.0.dtd in classpath under org/hibernate/
10:11:27,000 DEBUG [DTDEntityResolver] found http://hibernate.sourceforge.net/hibern ... ng-3.0.dtd in classpath
10:11:27,171 INFO [HbmBinder] Mapping class: test.UserObject -> USEROBJECT
10:11:27,171 DEBUG [HbmBinder] Mapped property: id -> ID
10:11:27,187 DEBUG [HbmBinder] Mapped property: name -> NAME
10:11:27,203 INFO [Configuration] Configured SessionFactory: null
10:11:27,203 DEBUG [Configuration] properties: {hibernate.connection.password=@dilbert, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, sun.boot.library.path=d:\java\jdk1.5\jre\bin, java.vm.version=1.5.0-rc-b63, hibernate.connection.username=prhodes, 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=Service Pack 4, java.vm.specification.name=Java Virtual Machine Specification, user.dir=f:\learning\hibernate\TransactTest, java.runtime.version=1.5.0-rc-b63, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, hibernate.current_session_context_class=jta, java.endorsed.dirs=d:\java\jdk1.5\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\prhodes\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows 2000, jta.UserTransaction=java:comp/UserTransaction, sun.jnu.encoding=Cp1252, java.library.path=d:\java\jdk1.5\bin;.;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32\WBEM;d:\java\jdk1.5\bin;D:\java\apache-ant-1.6.1\bin;d:\java\jdk1.5\bin;d:\LANGUA~1\ada\bin;d:\program files\putty;S:\Program Files\IBM\WebSphere MQ\Java\lib;D:\languages\perl\bin\;d:\languages\ruby\bin;d:\program files\textpad4;S:\Program Files\IBM\WebSphere MQ\bin;S:\Program Files\IBM\WebSphere MQ\WEMPS\bin;d:\cygwin\bin;S:\PROGRA~1\IBM\SQLLIB\BIN;S:\PROGRA~1\IBM\SQLLIB\FUNCTION;S:\PROGRA~1\IBM\SQLLIB\SAMPLES\REPL;S:\oracle\ora92\bin;S:\Program Files\Oracle\jre\1.3.1\bin;S:\Program Files\Oracle\jre\1.1.8\bin;D:\Program Files\WinSCP3\;D:\Program Files\WinCvs1.3\CVSNT;C:\Program Files\Common Files\Roxio Shared\DLLShared\;C:\Program Files\Microsoft Visual Studio\Common\Tools\WinNT;C:\Program Files\Microsoft Visual Studio\Common\MSDev98\Bin;C:\Program Files\Microsoft Visual Studio\Common\Tools;D:\Program Files\Microsoft Visual Studio\VC98\bin;d:\languages\rexx, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, hibernate.transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, os.version=5.0, connection.password=@dilbert, user.home=C:\Documents and Settings\prhodes, user.timezone=America/New_York, connection.username=prhodes, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.5, transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, hibernate.connection.driver_class=com.ibm.db2.jcc.DB2Driver, user.name=prhodes, java.class.path=f:\learning\hibernate\TransactTest\bin;S:\Program Files\ibm\SQLLIB\java\db2jcc.jar;D:\java\hibernate-3.0\hibernate3.jar;D:\java\hibernate-3.0\lib\ant-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-antlr-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-junit-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-launcher-1.6.3.jar;D:\java\hibernate-3.0\lib\antlr-2.7.5H3.jar;D:\java\hibernate-3.0\lib\ant-swing-1.6.3.jar;D:\java\hibernate-3.0\lib\asm.jar;D:\java\hibernate-3.0\lib\asm-attrs.jar;D:\java\hibernate-3.0\lib\c3p0-0.8.5.2.jar;D:\java\hibernate-3.0\lib\cglib-2.1.jar;D:\java\hibernate-3.0\lib\cleanimports.jar;D:\java\hibernate-3.0\lib\commons-collections-2.1.1.jar;D:\java\hibernate-3.0\lib\commons-logging-1.0.4.jar;D:\java\hibernate-3.0\lib\concurrent-1.3.2.jar;D:\java\hibernate-3.0\lib\connector.jar;D:\java\hibernate-3.0\lib\dom4j-1.6.jar;D:\java\hibernate-3.0\lib\ehcache-1.1.jar;D:\java\hibernate-3.0\lib\jaas.jar;D:\java\hibernate-3.0\lib\jacc-1_0-fr.jar;D:\java\hibernate-3.0\lib\jaxen-1.1-beta-4.jar;D:\java\hibernate-3.0\lib\jboss-cache.jar;D:\java\hibernate-3.0\lib\jboss-common.jar;D:\java\hibernate-3.0\lib\jboss-jmx.jar;D:\java\hibernate-3.0\lib\jboss-system.jar;D:\java\hibernate-3.0\lib\jdbc2_0-stdext.jar;D:\java\hibernate-3.0\lib\jgroups-2.2.7.jar;D:\java\hibernate-3.0\lib\jta.jar;D:\java\hibernate-3.0\lib\junit-3.8.1.jar;D:\java\hibernate-3.0\lib\oscache-2.1.jar;D:\java\hibernate-3.0\lib\proxool-0.8.3.jar;D:\java\hibernate-3.0\lib\swarmcache-1.0rc2.jar;D:\java\hibernate-3.0\lib\versioncheck.jar;D:\java\hibernate-3.0\lib\xerces-2.6.2.jar;D:\java\hibernate-3.0\lib\xml-apis.jar;D:\java\hibernate-3.0\lib\log4j-1.2.9.jar;D:\java\spring-framework-1.2.5\dist\spring.jar;D:\java\jndi\fscontext\lib\fscontext.jar;D:\java\jndi\fscontext\lib\providerutil.jar;D:\java\jotm-2.0.10\lib\xapool.jar;D:\java\jotm-2.0.10\lib\commons-logging.jar;D:\java\jotm-2.0.10\lib\connector-1_5.jar;D:\java\jotm-2.0.10\lib\howl.jar;D:\java\jotm-2.0.10\lib\jotm.jar;D:\java\jotm-2.0.10\lib\jotm_iiop_stubs.jar;D:\java\jotm-2.0.10\lib\jotm_jrmp_stubs.jar;D:\java\jotm-2.0.10\lib\jts1_0.jar;D:\java\jotm-2.0.10\lib\log4j.jar;D:\java\jotm-2.0.10\lib\objectweb-datasource.jar;D:\java\jotm-2.0.10\lib\ow_carol.jar;D:\java\jotm-2.0.10\lib\commons-cli-1.0.jar, current_session_context_class=jta, java.vm.specification.version=1.0, java.home=d:\java\jdk1.5\jre, sun.arch.data.model=32, hibernate.dialect=org.hibernate.dialect.DB2Dialect, hibernate.connection.url=jdbc:db2://localhost:50000/HIBTEST, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.5.0-rc, java.ext.dirs=d:\java\jdk1.5\jre\lib\ext, sun.boot.class.path=d:\java\jdk1.5\jre\lib\rt.jar;d:\java\jdk1.5\jre\lib\i18n.jar;d:\java\jdk1.5\jre\lib\sunrsasign.jar;d:\java\jdk1.5\jre\lib\jsse.jar;d:\java\jdk1.5\jre\lib\jce.jar;d:\java\jdk1.5\jre\lib\charsets.jar;d:\java\jdk1.5\jre\classes, java.vendor=Sun Microsystems Inc., hibernate.jta.UserTransaction=java:comp/UserTransaction, connection.driver_class=com.ibm.db2.jcc.DB2Driver, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, hibernate.transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, sun.desktop=windows, connection.url=jdbc:db2://localhost:50000/HIBTEST, dialect=org.hibernate.dialect.DB2Dialect, sun.cpu.isalist=}
10:11:27,203 DEBUG [Configuration] Preparing to build session factory with filters : {}
10:11:27,203 INFO [Configuration] processing extends queue
10:11:27,203 INFO [Configuration] processing collection mappings
10:11:27,203 INFO [Configuration] processing association property references
10:11:27,203 INFO [Configuration] processing foreign key constraints
10:11:27,312 INFO [DriverManagerConnectionProvider] Using Hibernate built-in connection pool (not for production use!)
10:11:27,312 INFO [DriverManagerConnectionProvider] Hibernate connection pool size: 20
10:11:27,312 INFO [DriverManagerConnectionProvider] autocommit mode: false
10:11:27,312 INFO [DriverManagerConnectionProvider] using driver: com.ibm.db2.jcc.DB2Driver at URL: jdbc:db2://localhost:50000/HIBTEST
10:11:27,328 INFO [DriverManagerConnectionProvider] connection properties: {user=prhodes, password=@dilbert}
10:11:27,328 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
10:11:27,328 DEBUG [DriverManagerConnectionProvider] opening new JDBC connection
10:11:27,656 DEBUG [DriverManagerConnectionProvider] created connection to: jdbc:db2://localhost:50000/HIBTEST, Isolation Level: 2
10:11:27,656 DEBUG [SettingsFactory] could not get database version from JDBC metadata
10:11:27,656 INFO [SettingsFactory] RDBMS: DB2/NT, version: SQL08010
10:11:27,656 INFO [SettingsFactory] JDBC driver: IBM DB2 JDBC Universal Driver Architecture, version: 1.0.581
10:11:27,656 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
10:11:27,703 INFO [Dialect] Using dialect: org.hibernate.dialect.DB2Dialect
10:11:27,703 INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory
10:11:27,718 INFO [NamingHelper] JNDI InitialContext properties:{}
10:11:27,718 INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JOTMTransactionManagerLookup
10:11:27,718 INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup
10:11:27,718 INFO [SettingsFactory] Automatic flush during beforeCompletion(): disabled
10:11:27,718 INFO [SettingsFactory] Automatic session close at end of transaction: disabled
10:11:27,718 INFO [SettingsFactory] Scrollable result sets: enabled
10:11:27,718 DEBUG [SettingsFactory] Wrap result sets: disabled
10:11:27,718 INFO [SettingsFactory] JDBC3 getGeneratedKeys(): disabled
10:11:27,718 INFO [SettingsFactory] Connection release mode: null
10:11:27,718 INFO [SettingsFactory] Default batch fetch size: 1
10:11:27,718 INFO [SettingsFactory] Generate SQL with comments: disabled
10:11:27,718 INFO [SettingsFactory] Order SQL updates by primary key: disabled
10:11:27,718 INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
10:11:27,734 INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
10:11:27,734 INFO [SettingsFactory] Query language substitutions: {}
10:11:27,734 INFO [SettingsFactory] Second-level cache: enabled
10:11:27,734 INFO [SettingsFactory] Query cache: disabled
10:11:27,734 INFO [SettingsFactory] Cache provider: org.hibernate.cache.EhCacheProvider
10:11:27,734 INFO [SettingsFactory] Optimize cache for minimal puts: disabled
10:11:27,734 INFO [SettingsFactory] Structured second-level cache entries: disabled
10:11:27,734 DEBUG [SQLExceptionConverterFactory] Using dialect defined converter
10:11:27,750 INFO [SettingsFactory] Statistics: disabled
10:11:27,750 INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled
10:11:27,750 INFO [SettingsFactory] Default entity-mode: pojo
10:11:27,953 INFO [SessionFactoryImpl] building session factory
10:11:27,953 DEBUG [SessionFactoryImpl] Session factory constructed with filter configurations : {}
10:11:27,953 DEBUG [SessionFactoryImpl] instantiating session factory with properties: {hibernate.connection.password=@dilbert, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, sun.boot.library.path=d:\java\jdk1.5\jre\bin, java.vm.version=1.5.0-rc-b63, hibernate.connection.username=prhodes, 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=Service Pack 4, java.vm.specification.name=Java Virtual Machine Specification, user.dir=f:\learning\hibernate\TransactTest, java.runtime.version=1.5.0-rc-b63, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, hibernate.current_session_context_class=jta, java.endorsed.dirs=d:\java\jdk1.5\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\DOCUME~1\prhodes\LOCALS~1\Temp\, line.separator=
, java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows 2000, jta.UserTransaction=java:comp/UserTransaction, sun.jnu.encoding=Cp1252, java.library.path=d:\java\jdk1.5\bin;.;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32;C:\WINNT;C:\WINNT\system32\WBEM;d:\java\jdk1.5\bin;D:\java\apache-ant-1.6.1\bin;d:\java\jdk1.5\bin;d:\LANGUA~1\ada\bin;d:\program files\putty;S:\Program Files\IBM\WebSphere MQ\Java\lib;D:\languages\perl\bin\;d:\languages\ruby\bin;d:\program files\textpad4;S:\Program Files\IBM\WebSphere MQ\bin;S:\Program Files\IBM\WebSphere MQ\WEMPS\bin;d:\cygwin\bin;S:\PROGRA~1\IBM\SQLLIB\BIN;S:\PROGRA~1\IBM\SQLLIB\FUNCTION;S:\PROGRA~1\IBM\SQLLIB\SAMPLES\REPL;S:\oracle\ora92\bin;S:\Program Files\Oracle\jre\1.3.1\bin;S:\Program Files\Oracle\jre\1.1.8\bin;D:\Program Files\WinSCP3\;D:\Program Files\WinCvs1.3\CVSNT;C:\Program Files\Common Files\Roxio Shared\DLLShared\;C:\Program Files\Microsoft Visual Studio\Common\Tools\WinNT;C:\Program Files\Microsoft Visual Studio\Common\MSDev98\Bin;C:\Program Files\Microsoft Visual Studio\Common\Tools;D:\Program Files\Microsoft Visual Studio\VC98\bin;d:\languages\rexx, java.specification.name=Java Platform API Specification, java.class.version=49.0, sun.management.compiler=HotSpot Client Compiler, hibernate.transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, os.version=5.0, connection.password=@dilbert, user.home=C:\Documents and Settings\prhodes, user.timezone=America/New_York, connection.username=prhodes, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.5, transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, hibernate.connection.driver_class=com.ibm.db2.jcc.DB2Driver, user.name=prhodes, java.class.path=f:\learning\hibernate\TransactTest\bin;S:\Program Files\ibm\SQLLIB\java\db2jcc.jar;D:\java\hibernate-3.0\hibernate3.jar;D:\java\hibernate-3.0\lib\ant-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-antlr-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-junit-1.6.3.jar;D:\java\hibernate-3.0\lib\ant-launcher-1.6.3.jar;D:\java\hibernate-3.0\lib\antlr-2.7.5H3.jar;D:\java\hibernate-3.0\lib\ant-swing-1.6.3.jar;D:\java\hibernate-3.0\lib\asm.jar;D:\java\hibernate-3.0\lib\asm-attrs.jar;D:\java\hibernate-3.0\lib\c3p0-0.8.5.2.jar;D:\java\hibernate-3.0\lib\cglib-2.1.jar;D:\java\hibernate-3.0\lib\cleanimports.jar;D:\java\hibernate-3.0\lib\commons-collections-2.1.1.jar;D:\java\hibernate-3.0\lib\commons-logging-1.0.4.jar;D:\java\hibernate-3.0\lib\concurrent-1.3.2.jar;D:\java\hibernate-3.0\lib\connector.jar;D:\java\hibernate-3.0\lib\dom4j-1.6.jar;D:\java\hibernate-3.0\lib\ehcache-1.1.jar;D:\java\hibernate-3.0\lib\jaas.jar;D:\java\hibernate-3.0\lib\jacc-1_0-fr.jar;D:\java\hibernate-3.0\lib\jaxen-1.1-beta-4.jar;D:\java\hibernate-3.0\lib\jboss-cache.jar;D:\java\hibernate-3.0\lib\jboss-common.jar;D:\java\hibernate-3.0\lib\jboss-jmx.jar;D:\java\hibernate-3.0\lib\jboss-system.jar;D:\java\hibernate-3.0\lib\jdbc2_0-stdext.jar;D:\java\hibernate-3.0\lib\jgroups-2.2.7.jar;D:\java\hibernate-3.0\lib\jta.jar;D:\java\hibernate-3.0\lib\junit-3.8.1.jar;D:\java\hibernate-3.0\lib\oscache-2.1.jar;D:\java\hibernate-3.0\lib\proxool-0.8.3.jar;D:\java\hibernate-3.0\lib\swarmcache-1.0rc2.jar;D:\java\hibernate-3.0\lib\versioncheck.jar;D:\java\hibernate-3.0\lib\xerces-2.6.2.jar;D:\java\hibernate-3.0\lib\xml-apis.jar;D:\java\hibernate-3.0\lib\log4j-1.2.9.jar;D:\java\spring-framework-1.2.5\dist\spring.jar;D:\java\jndi\fscontext\lib\fscontext.jar;D:\java\jndi\fscontext\lib\providerutil.jar;D:\java\jotm-2.0.10\lib\xapool.jar;D:\java\jotm-2.0.10\lib\commons-logging.jar;D:\java\jotm-2.0.10\lib\connector-1_5.jar;D:\java\jotm-2.0.10\lib\howl.jar;D:\java\jotm-2.0.10\lib\jotm.jar;D:\java\jotm-2.0.10\lib\jotm_iiop_stubs.jar;D:\java\jotm-2.0.10\lib\jotm_jrmp_stubs.jar;D:\java\jotm-2.0.10\lib\jts1_0.jar;D:\java\jotm-2.0.10\lib\log4j.jar;D:\java\jotm-2.0.10\lib\objectweb-datasource.jar;D:\java\jotm-2.0.10\lib\ow_carol.jar;D:\java\jotm-2.0.10\lib\commons-cli-1.0.jar, current_session_context_class=jta, java.vm.specification.version=1.0, java.home=d:\java\jdk1.5\jre, sun.arch.data.model=32, hibernate.dialect=org.hibernate.dialect.DB2Dialect, hibernate.connection.url=jdbc:db2://localhost:50000/HIBTEST, user.language=en, java.specification.vendor=Sun Microsystems Inc., awt.toolkit=sun.awt.windows.WToolkit, hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.5.0-rc, java.ext.dirs=d:\java\jdk1.5\jre\lib\ext, sun.boot.class.path=d:\java\jdk1.5\jre\lib\rt.jar;d:\java\jdk1.5\jre\lib\i18n.jar;d:\java\jdk1.5\jre\lib\sunrsasign.jar;d:\java\jdk1.5\jre\lib\jsse.jar;d:\java\jdk1.5\jre\lib\jce.jar;d:\java\jdk1.5\jre\lib\charsets.jar;d:\java\jdk1.5\jre\classes, java.vendor=Sun Microsystems Inc., hibernate.jta.UserTransaction=java:comp/UserTransaction, connection.driver_class=com.ibm.db2.jcc.DB2Driver, file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, hibernate.transaction.manager_lookup_class=org.hibernate.transaction.JOTMTransactionManagerLookup, sun.desktop=windows, connection.url=jdbc:db2://localhost:50000/HIBTEST, dialect=org.hibernate.dialect.DB2Dialect, sun.cpu.isalist=}
10:11:27,968 WARN [Configurator] No configuration found. Configuring ehcache from ehcache-failsafe.xml found in the classpath: jar:file:/D:/java/hibernate-3.0/lib/ehcache-1.1.jar!/ehcache-failsafe.xml
10:11:28,406 DEBUG [BasicEntityPersister] Static SQL for entity: test.UserObject
10:11:28,406 DEBUG [BasicEntityPersister] Version select: select ID from USEROBJECT where ID =?
10:11:28,406 DEBUG [BasicEntityPersister] Snapshot select: select userobject_.ID, userobject_.NAME as NAME0_ from USEROBJECT userobject_ where userobject_.ID=?
10:11:28,406 DEBUG [BasicEntityPersister] Insert 0: insert into USEROBJECT (NAME, ID) values (?, ?)
10:11:28,406 DEBUG [BasicEntityPersister] Update 0: update USEROBJECT set NAME=? where ID=?
10:11:28,406 DEBUG [BasicEntityPersister] Delete 0: delete from USEROBJECT where ID=?
10:11:28,406 DEBUG [BasicEntityPersister] Identity insert: insert into USEROBJECT (NAME, ID) values (?, default)
10:11:28,437 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
10:11:28,437 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
10:11:28,437 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=? for update with rr
10:11:28,437 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID0_, userobject0_.NAME as NAME0_0_ from USEROBJECT userobject0_ where userobject0_.ID=? for update with rr
10:11:28,437 DEBUG [SessionFactoryObjectFactory] initializing class SessionFactoryObjectFactory
10:11:28,437 DEBUG [SessionFactoryObjectFactory] registered: 4028825b087712d001087712d2b50000 (unnamed)
10:11:28,437 INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
10:11:28,437 DEBUG [SessionFactoryImpl] instantiated session factory
10:11:28,437 DEBUG [SessionFactoryImpl] obtaining JTA TransactionManager
10:11:28,453 INFO [SessionFactoryImpl] Checking 0 named queries
10:11:28,453 DEBUG [jta] begin transaction
10:11:28,453 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
10:11:28,468 DEBUG [jta] xid= bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,468 DEBUG [jta] timeout= 60
10:11:28,468 DEBUG [jta] xid=bb14:38:0:012218cdd9496249ae...4b1401:, timeout=60
10:11:28,468 DEBUG [jta] tx=bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,468 DEBUG [jta] TransactionImpl.doAttach flag= TMJOIN
10:11:28,468 DEBUG [jta] number of enlisted= 0
10:11:28,468 DEBUG [jta] threadTx.set= java.lang.ThreadLocal@608760
10:11:28,468 DEBUG [jta] Associate tx to xid (xid=bb14:38:0:012218cdd9496249ae...4b1401:)
10:11:28,468 DEBUG [jta] TimerEvent.new(bb14:38:0:012218cdd9496249ae...4b1401:,60,null,false)
10:11:28,468 DEBUG [jta] set timer for tx (timer=org.objectweb.jotm.TimerEvent@17aece8, tx=bb14:38:0:012218cdd9496249ae...4b1401:)
10:11:28,484 DEBUG [jta] set date for tx (data=Thu Dec 29 10:11:28 EST 2005, tx=bb14:38:0:012218cdd9496249ae...4b1401:)
10:11:28,484 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
10:11:28,484 DEBUG [jta] Transaction ret= bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,484 DEBUG [jta] TransactionImpl.getStatus()
10:11:28,546 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
10:11:28,546 DEBUG [jta] Transaction ret= bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,546 DEBUG [jta] TransactionImpl.getStatus()
10:11:28,546 DEBUG [jta] TransactionImpl.registerSynchronization(Synchronization sync)
10:11:28,546 DEBUG [jta] make subcoordinator
10:11:28,562 DEBUG [jta] tx=bb14:38:0:012218cdd9496249ae...4b1401:, xid=bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,562 DEBUG [jta] synchro=org.hibernate.transaction.CacheSynchronization
10:11:28,578 DEBUG [jta] status=STATUS_ACTIVE
10:11:28,578 DEBUG [JDBCContext] successfully registered Synchronization
10:11:28,578 DEBUG [SessionImpl] opened session at timestamp: 4652519786557440
10:11:28,578 DEBUG [jta] TransactionImpl.registerSynchronization(Synchronization sync)
10:11:28,578 DEBUG [jta] synchro=org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@1c8efd1
10:11:28,578 DEBUG [jta] status=STATUS_ACTIVE
10:11:28,578 DEBUG [DefaultSaveOrUpdateEventListener] saving transient instance
10:11:28,578 DEBUG [AbstractSaveEventListener] saving [test.UserObject#<null>]
10:11:28,578 DEBUG [AbstractSaveEventListener] executing insertions
10:11:28,609 DEBUG [BasicEntityPersister] Inserting entity: test.UserObject (native id)
10:11:28,609 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:11:28,609 DEBUG [ConnectionManager] opening JDBC connection
10:11:28,609 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
10:11:28,609 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
10:11:28,609 DEBUG [SQL] insert into USEROBJECT (NAME, ID) values (?, default)
10:11:28,609 DEBUG [AbstractBatcher] preparing statement
10:11:28,656 DEBUG [BasicEntityPersister] Dehydrating entity: [test.UserObject#<null>]
10:11:28,656 DEBUG [StringType] binding 'PhillipRhodes' to parameter: 1
10:11:28,671 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:11:28,671 DEBUG [AbstractBatcher] closing statement
10:11:28,671 DEBUG [ConnectionManager] aggressively releasing JDBC connection
10:11:28,671 DEBUG [ConnectionManager] closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
10:11:28,671 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
10:11:28,671 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
10:11:28,671 DEBUG [ConnectionManager] opening JDBC connection
10:11:28,671 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
10:11:28,671 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
10:11:28,671 DEBUG [SQL] values identity_val_local()
10:11:28,671 DEBUG [AbstractBatcher] preparing statement
10:11:28,718 DEBUG [IdentifierGeneratorFactory] Natively generated identity: 23
10:11:28,718 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
10:11:28,718 DEBUG [AbstractBatcher] closing statement
10:11:28,718 DEBUG [ConnectionManager] aggressively releasing JDBC connection
10:11:28,718 DEBUG [ConnectionManager] closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
10:11:28,718 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
10:11:28,734 DEBUG [SessionImpl] closing session
10:11:28,734 DEBUG [jta] commit transaction
10:11:28,734 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
10:11:28,734 DEBUG [jta] Transaction ret= bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,734 DEBUG [jta] tx=bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,734 DEBUG [jta] TransactionImpl.commit (tx= bb14:38:0:012218cdd9496249ae...4b1401:)
10:11:28,734 DEBUG [jta] status=STATUS_ACTIVE
10:11:28,734 DEBUG [jta] doBeforeCompletion committing= true
10:11:28,734 DEBUG [jta] unset timer for tx (timer=org.objectweb.jotm.TimerEvent@17aece8, tx=bb14:38:0:012218cdd9496249ae...4b1401:)
10:11:28,734 DEBUG [jta] TimerEvent(bb14:38:0:012218cdd9496249ae...4b1401:).unset
10:11:28,734 DEBUG [jta] threadTx.get= java.lang.ThreadLocal@608760
10:11:28,734 DEBUG [jta] Transaction ret= bb14:38:0:012218cdd9496249ae...4b1401:
10:11:28,734 DEBUG [jta] sychronization list size= 2
10:11:28,734 DEBUG [jta] Synchronization sync= org.hibernate.transaction.CacheSynchronization
10:11:28,734 DEBUG [CacheSynchronization] transaction before completion callback
10:11:28,734 DEBUG [jta] TransactionImpl.getStatus()
10:11:28,734 DEBUG [jta] status=STATUS_ACTIVE
10:11:28,734 DEBUG [CacheSynchronization] automatically flushing session
10:11:28,734 DEBUG [SessionImpl] automatically flushing session
10:11:28,734 DEBUG [JDBCContext] before transaction completion
10:11:28,734 DEBUG [SessionImpl] before transaction completion
10:11:28,734 DEBUG [jta] Synchronization sync= org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@1c8efd1
10:11:28,734 DEBUG [jta] TransactionImpl.doDetach flag= TMSUCCESS
10:11:28,734 DEBUG [jta] number of enlisted= 0
10:11:28,734 DEBUG [jta] status=STATUS_ACTIVE
10:11:28,734 DEBUG [jta] SubCoordinator.doPrepare()
10:11:28,734 DEBUG [jta] doAfterCompletion()
10:11:28,734 DEBUG [jta] sychronization list size= 2
10:11:28,734 DEBUG [jta] Synchronization sync= org.hibernate.transaction.CacheSynchronization
10:11:28,734 DEBUG [jta] sync.afterCompletion status= STATUS_COMMITTED
10:11:28,734 DEBUG [CacheSynchronization] transaction after completion callback, status: 3
10:11:28,734 DEBUG [JDBCContext] after transaction completion
10:11:28,734 DEBUG [SessionImpl] after transaction completion
10:11:28,734 DEBUG [jta] Synchronization sync= org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@1c8efd1
10:11:28,734 DEBUG [jta] sync.afterCompletion status= STATUS_COMMITTED
10:11:28,734 DEBUG [jta] threadTx.set = null
10:11:28,734 DEBUG [jta] remove tx from xid (xid=bb14:38:0:012218cdd9496249ae...4b1401:)
10:11:28,734 DEBUG [jta] SubCoordinator unexported [subcoord=org.objectweb.jotm.SubCoordinator@6397eb]
10:11:28,734 DEBUG [jta] threadTx.set= null
10:11:28,734 DEBUG [jta] reset timeout= 60
10:11:28,734 INFO [jotm] stop JOTM
10:11:28,734 DEBUG [jta] threadTx.set= null
10:11:28,734 DEBUG [jotm] TransactionFactory unexported
10:11:28,734 WARN [TestDriver] done


Top
 Profile  
 
 Post subject:
PostPosted: Thu Dec 29, 2005 11:22 pm 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
As a sanity check to make sure my problem wasn't database or driver specific, I have switched my configuration to use an Oracle 9i database instead of DB/2, but still see the same problem.

Also, I have modified my code so that I don't explicitly close the hibernate session, and instead rely on the automatic session close. From the logfile (see below) I see (what appears to be) Hibernate detecting the ut.close() call on the UserTransaction and the session being closed.

At this point, the session has been closed and flushed, and the transaction is commited, but yet it still acts like something is missing, as the final write to persist the data to the database isn't happening. Does anybody have any idea what I could be overlooking here? Would anybody think that my problem is likely to be something specific to JOTM? If so, I'll move over to their mailing list with this question.

Here's that logfile snippet, if it helps:

logfile snippet

22:20:35,968 DEBUG [SessionImpl] before transaction completion
22:20:35,968 DEBUG [jta] Synchronization sync= org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@e4245
22:20:35,968 DEBUG [jta] TransactionImpl.doDetach flag= TMSUCCESS
22:20:35,968 DEBUG [jta] number of enlisted= 0
22:20:35,968 DEBUG [jta] status=STATUS_ACTIVE
22:20:35,968 DEBUG [jta] SubCoordinator.doPrepare()
22:20:35,968 DEBUG [jta] doAfterCompletion()
22:20:35,968 DEBUG [jta] sychronization list size= 2
22:20:35,968 DEBUG [jta] Synchronization sync= org.hibernate.transaction.CacheSynchronization
22:20:35,984 DEBUG [jta] sync.afterCompletion status= STATUS_COMMITTED
22:20:35,984 DEBUG [CacheSynchronization] transaction after completion callback, status: 3
22:20:35,984 DEBUG [JDBCContext] after transaction completion
22:20:35,984 DEBUG [SessionImpl] after transaction completion
22:20:35,984 DEBUG [CacheSynchronization] automatically closing session
22:20:35,984 DEBUG [SessionImpl] automatically closing session
22:20:35,984 DEBUG [SessionImpl] closing session
22:20:35,984 DEBUG [jta] Synchronization sync= org.hibernate.impl.SessionFactoryImpl$CurrentSessionCleanupSynch@e4245
22:20:35,984 DEBUG [jta] sync.afterCompletion status= STATUS_COMMITTED
22:20:35,984 DEBUG [jta] threadTx.set = null
22:20:35,984 DEBUG [jta] remove tx from xid (xid=bb14:38:0:019f0bce2b5a9e3257...686401:)
22:20:35,984 DEBUG [jta] SubCoordinator unexported [subcoord=org.objectweb.jotm.SubCoordinator@827968]
22:20:35,984 DEBUG [jta] threadTx.set= null
22:20:35,984 DEBUG [jta] reset timeout= 60
22:20:35,984 INFO [jotm] stop JOTM
22:20:35,984 DEBUG [jta] threadTx.set= null
22:20:35,984 DEBUG [jotm] TransactionFactory unexported
22:20:35,984 WARN [TestDriver] done

The updated code

Code:
// begin a new Transaction
         ut.begin();
         
         // and open the Hibernate session
         Session session = sf.getCurrentSession();
         
               
         // do something transactional using Hibernate
         UserObject obj = new UserObject( "PhillipRhodes" );
         session.save( obj );
                  
      
         // do something else involving the transaction (send a JMS message, for example)
         // TODO: add a separate transactional step here
         
         
         // commit the transaction
         ut.commit();
      
         // stop the transaction manager
         jotm.stop();
         
         // goodbye...
         logger.warn( "done" );



Updated hibernate configuration

<hibernate-configuration>
<session-factory>
<property name="connection.username">scott</property>
<property name="connection.password">tiger</property>

<!--
<property name="connection.url">jdbc:db2://localhost:50000/HIBTEST</property>
<property name="connection.driver_class">com.ibm.db2.jcc.DB2Driver</property>
-->

<property name="connection.url">jdbc:oracle:thin:@//localhost:1521/oemrep</property>
<property name="connection.driver_class">oracle.jdbc.driver.OracleDriver</property>
<property name="dialect">org.hibernate.dialect.OracleDialect</property>

<property name="transaction.factory_class">org.hibernate.transaction.JTATransactionFactory</property>
<property name="transaction.manager_lookup_class">org.hibernate.transaction.JOTMTransactionManagerLookup</property>
<property name="current_session_context_class">jta</property>
<property name="jta.UserTransaction">java:comp/UserTransaction</property>

<mapping resource="test/UserObject.hbm.xml" />

</session-factory>


</hibernate-configuration>


Top
 Profile  
 
 Post subject:
PostPosted: Thu Dec 29, 2005 11:31 pm 
Hibernate Team
Hibernate Team

Joined: Tue Aug 26, 2003 12:50 pm
Posts: 5130
Location: Melbourne, Australia
Code:
[SettingsFactory] Automatic flush during beforeCompletion(): disabled



hibernate.transaction.flush_before_completion=true


Top
 Profile  
 
 Post subject:
PostPosted: Thu Dec 29, 2005 11:54 pm 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
Gavin:

Thanks for the help. I have added:


<property name="transaction.flush_before_completion">true</property>


to my hibernate.cfg.xml, and now I see this in the log


22:47:14,640 INFO [SettingsFactory] Automatic flush during beforeCompletion(): enabled


but I'm still not seeing anything written to the database when all is said and done.

Not sure if it's related or not, but I do see this in the earlier part of the log:


22:47:14,640 INFO [SettingsFactory] Automatic session close at end of transaction: disabled


But this part of the log seems to be saying that the transaction *is* being closed automatically:



22:47:15,937 DEBUG [CacheSynchronization] automatically closing session
22:47:15,937 DEBUG [SessionImpl] automatically closing session
22:47:15,937 DEBUG [SessionImpl] closing session


Is that what I should expect to see? And is there a property I should set to explicitly enable this:


22:47:14,640 INFO [SettingsFactory] Automatic session close at end of transaction: disabled


Also, if it matters, I've experimented with manually closing and / or flushing the Hibernate session before calling ut.commit(); and that doesn't seem to make any difference either.

Thanks again for the help. Sorry for being such a bother...


Top
 Profile  
 
 Post subject:
PostPosted: Fri Dec 30, 2005 12:42 am 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
Tomorrow, in order to try and narrow the problem down, I'll try running this code inside a servlet running under JBoss and use the JBoss transaction manager instead of JOTM. If it works, I'll know the problem is something JOTM specific. If it still doesn't work, er, well I'm not sure what that proves (if anything).

G'night all...


Top
 Profile  
 
 Post subject:
PostPosted: Fri Dec 30, 2005 2:54 pm 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
Ok, so I tried the same code in a servlet, relying
on JBoss' internal TM and I get the same result.
No object is persisted. So at least now I know the
problem isn't with JOTM, which means I'm probably
just doing something wrong. I'm a little stumped at
this point.. if anybody has any idea why this isn't
working, I'd love to hear your thoughts or suggestions.

Code, configs and logfile excerpt are below.


Code: New Servlet Version
Code:
package test;

import java.io.IOException;

import javax.naming.InitialContext;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import javax.transaction.UserTransaction;

import org.apache.log4j.Logger;
import org.apache.log4j.xml.DOMConfigurator;
import org.hibernate.Session;
import org.hibernate.SessionFactory;
import org.hibernate.cfg.Configuration;

public class TestDriverServlet extends HttpServlet
{

   @Override
   protected void doGet(HttpServletRequest arg0, HttpServletResponse arg1)
      throws ServletException, IOException
   {
      doWork();
   }
   
   /**
   * @param args
   */
   public static void doWork( )
   {
   
      // BasicConfigurator.configure();
      // DOMConfigurator.configure( "log4j.xml" );
      Configuration config = new Configuration();
      Logger logger = Logger.getLogger( TestDriverServlet.class );
      
      logger.fatal( "Welcome to TRANSACT!" );
      
      try
      {
         
         // File file = new File( "./hibernate.cfg.xml" );
         SessionFactory sf = config.configure().buildSessionFactory();
      
         InitialContext ctx = new InitialContext();
         
         UserTransaction ut = (UserTransaction)ctx.lookup( "java:comp/UserTransaction" );
         
         ut.begin();
         
         // and open the Hibernate session
         Session session = sf.getCurrentSession();
         
         logger.fatal( "saving object" );
         // do something transactional using Hibernate
         UserObject obj = new UserObject( "PhillipRhodes" );
         session.save( obj );
         
         
         // do something else involving the transaction (send a JMS message, for example)
         // TODO: add a separate transactional step here
         
         // commit the transaction
         logger.fatal( "committing transaction" );
         ut.commit();
         
         // goodbye...
         logger.fatal( "done" );
      }
      catch( Exception e )
      {
         e.printStackTrace();
      }
   }
}


hibernate.cfg.xml

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

<hibernate-configuration>

<session-factory>

<property name="connection.username">postgres</property>
<property name="connection.password"></property>
<property name="connection.url">jdbc:postgresql:test</property>
<property name="connection.driver_class">org.postgresql.Driver</property>
<property name="dialect">org.hibernate.dialect.PostgreSQLDialect</property>

<property name="transaction.factory_class">org.hibernate.transaction.JTATransactionFactory</property>
<property name="transaction.manager_lookup_class">org.hibernate.transaction.JBossTransactionManagerLookup</property>
<property name="current_session_context_class">jta</property>
<property name="transaction.flush_before_completion">true</property>
<property name="transaction.auto_close_session">true</property>
<property name="UserTransactionName">java:comp/UserTransaction</property>

<mapping resource="test/UserObject.hbm.xml" />

</session-factory>


</hibernate-configuration>

Logfile excerpt

13:44:47,493 FATAL [TestDriverServlet] Welcome to TRANSACT!
13:44:47,494 INFO [Configuration] configuring from resource: /hibernate.cfg.xml
13:44:47,494 INFO [Configuration] Configuration resource: /hibernate.cfg.xml
13:44:47,511 DEBUG [DTDEntityResolver] trying to locate http://hibernate.sourceforge.net/hibern ... on-3.0.dtd in classpath under org/hibernate/
13:44:47,511 DEBUG [DTDEntityResolver] found http://hibernate.sourceforge.net/hibern ... on-3.0.dtd in classpath
13:44:47,515 DEBUG [Configuration] connection.username=postgres
13:44:47,516 DEBUG [Configuration] connection.password=
13:44:47,516 DEBUG [Configuration] connection.url=jdbc:postgresql:test
13:44:47,516 DEBUG [Configuration] connection.driver_class=org.postgresql.Driver
13:44:47,516 DEBUG [Configuration] dialect=org.hibernate.dialect.PostgreSQLDialect
13:44:47,516 DEBUG [Configuration] transaction.factory_class=org.hibernate.transaction.JTATransactionFactory
13:44:47,516 DEBUG [Configuration] transaction.manager_lookup_class=org.hibernate.transaction.JBossTransactionManagerLookup
13:44:47,516 DEBUG [Configuration] current_session_context_class=jta
13:44:47,517 DEBUG [Configuration] transaction.flush_before_completion=true
13:44:47,517 DEBUG [Configuration] transaction.auto_close_session=true
13:44:47,517 DEBUG [Configuration] UserTransactionName=java:comp/UserTransaction
13:44:47,518 DEBUG [Configuration] null<-org.dom4j.tree.DefaultAttribute@4589eb [Attribute: name resource value "test/UserObject.hbm.xml"]
13:44:47,518 INFO [Configuration] Reading mappings from resource: test/UserObject.hbm.xml
13:44:47,519 DEBUG [DTDEntityResolver] trying to locate http://hibernate.sourceforge.net/hibern ... ng-3.0.dtd in classpath under org/hibernate/
13:44:47,520 DEBUG [DTDEntityResolver] found http://hibernate.sourceforge.net/hibern ... ng-3.0.dtd in classpath
13:44:47,564 INFO [HbmBinder] Mapping class: test.UserObject -> USEROBJECT
13:44:47,565 DEBUG [HbmBinder] Mapped property: id -> ID
13:44:47,565 DEBUG [HbmBinder] Mapped property: name -> NAME
13:44:47,565 INFO [Configuration] Configured SessionFactory: null
13:44:47,566 DEBUG [Configuration] properties: {java.vendor=Sun Microsystems Inc., catalina.base=/usr/local/jboss-4.0.3SP1/server/default, hibernate.connection.url=jdbc:postgresql:test, sun.management.compiler=HotSpot Server Compiler, catalina.useNaming=false, hibernate.transaction.flush_before_completion=true, os.name=Linux, sun.boot.class.path=/usr/local/jboss-4.0.3SP1/lib/endorsed/resolver.jar:/usr/local/jboss-4.0.3SP1/lib/endorsed/xml-apis.jar:/usr/local/jboss-4.0.3SP1/lib/endorsed/xalan.jar:/usr/local/jboss-4.0.3SP1/lib/endorsed/xercesImpl.jar:/opt/jdk1.5.0_06/jre/lib/rt.jar:/opt/jdk1.5.0_06/jre/lib/i18n.jar:/opt/jdk1.5.0_06/jre/lib/sunrsasign.jar:/opt/jdk1.5.0_06/jre/lib/jsse.jar:/opt/jdk1.5.0_06/jre/lib/jce.jar:/opt/jdk1.5.0_06/jre/lib/charsets.jar:/opt/jdk1.5.0_06/jre/classes, hibernate.current_session_context_class=jta, sun.desktop=gnome, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_06-b05, user.name=root, shared.loader=${catalina.base}/shared/classes,${catalina.base}/shared/lib/*.jar, jboss.bind.address=0.0.0.0, tomcat.util.buf.StringCache.byte.enabled=true, connection.driver_class=org.postgresql.Driver, transaction.auto_close_session=true, current_session_context_class=jta, jboss.home.dir=/usr/local/jboss-4.0.3SP1, user.language=en, java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, sun.boot.library.path=/opt/jdk1.5.0_06/jre/lib/i386, dialect=org.hibernate.dialect.PostgreSQLDialect, jboss.home.url=file:/usr/local/jboss-4.0.3SP1/, java.version=1.5.0_06, user.timezone=America/New_York, jboss.server.home.dir=/usr/local/jboss-4.0.3SP1/server/default, sun.arch.data.model=32, java.endorsed.dirs=/usr/local/jboss-4.0.3SP1/lib/endorsed, jboss.server.home.url=file:/usr/local/jboss-4.0.3SP1/server/default/, sun.cpu.isalist=, sun.jnu.encoding=UTF-8, file.encoding.pkg=sun.io, package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.,sun.beans., file.separator=/, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=49.0, jboss.server.config.url=file:/usr/local/jboss-4.0.3SP1/server/default/conf/, user.country=US, connection.url=jdbc:postgresql:test, java.home=/opt/jdk1.5.0_06/jre, java.vm.info=mixed mode, jboss.lib.url=file:/usr/local/jboss-4.0.3SP1/lib/, os.version=2.6.9-22.0.1.ELsmp, transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, hibernate.transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, path.separator=:, connection.password=, java.vm.version=1.5.0_06-b05, hibernate.connection.password=, java.protocol.handler.pkgs=org.jboss.net.protocol, java.awt.printerjob=sun.print.PSPrinterJob, sun.io.unicode.encoding=UnicodeLittle, hibernate.connection.username=postgres, package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper., transaction.manager_lookup_class=org.hibernate.transaction.JBossTransactionManagerLookup, jboss.server.temp.dir=/usr/local/jboss-4.0.3SP1/server/default/tmp, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces, user.home=/root, java.rmi.server.RMIClassLoaderSpi=org.jboss.system.JBossRMIClassLoader, java.specification.vendor=Sun Microsystems Inc., java.library.path=/opt/jdk1.5.0_06/jre/lib/i386/server:/opt/jdk1.5.0_06/jre/lib/i386:/opt/jdk1.5.0_06/jre/../lib/i386, java.vendor.url=http://java.sun.com/, program.name=run.sh, hibernate.connection.driver_class=org.postgresql.Driver, connection.username=postgres, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.PostgreSQLDialect, common.loader=${catalina.home}/common/classes,${catalina.home}/common/i18n/*.jar,${catalina.home}/common/endorsed/*.jar,${catalina.home}/common/lib/*.jar, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=/usr/local/jboss-4.0.3SP1/bin/run.jar:/opt/jdk1.5.0_06/lib/tools.jar, hibernate.transaction.auto_close_session=true, jbossmx.loader.repository.class=org.jboss.mx.loading.UnifiedLoaderRepository3, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, catalina.home=/usr/local/jboss-4.0.3SP1/server/default, sun.cpu.endian=little, sun.os.patch.level=unknown, jboss.server.lib.url=file:/usr/local/jboss-4.0.3SP1/server/default/lib/, java.rmi.server.codebase=http://dhcp55-193.rdu.redhat.com:8083/, java.io.tmpdir=/tmp, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, server.loader=${catalina.home}/server/classes,${catalina.home}/server/lib/*.jar, jboss.server.data.dir=/usr/local/jboss-4.0.3SP1/server/default/data, transaction.flush_before_completion=true, os.arch=i386, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.ext.dirs=/opt/jdk1.5.0_06/jre/lib/ext, user.dir=/root, line.separator=
, java.vm.name=Java HotSpot(TM) Server VM, jboss.server.base.dir=/usr/local/jboss-4.0.3SP1/server, jboss.server.base.url=file:/usr/local/jboss-4.0.3SP1/server/, javax.management.builder.initial=org.jboss.mx.server.MBeanServerBuilderImpl, file.encoding=UTF-8, UserTransactionName=java:comp/UserTransaction, hibernate.UserTransactionName=java:comp/UserTransaction, catalina.ext.dirs=/usr/local/jboss-4.0.3SP1/server/default/lib, hibernate.transaction.manager_lookup_class=org.hibernate.transaction.JBossTransactionManagerLookup, java.specification.version=1.5, jboss.server.name=default}
13:44:47,570 DEBUG [Configuration] Preparing to build session factory with filters : {}
13:44:47,570 INFO [Configuration] processing extends queue
13:44:47,571 INFO [Configuration] processing collection mappings
13:44:47,571 INFO [Configuration] processing association property references
13:44:47,571 INFO [Configuration] processing foreign key constraints
13:44:47,572 INFO [DriverManagerConnectionProvider] Using Hibernate built-in connection pool (not for production use!)
13:44:47,572 INFO [DriverManagerConnectionProvider] Hibernate connection pool size: 20
13:44:47,572 INFO [DriverManagerConnectionProvider] autocommit mode: false
13:44:47,572 INFO [DriverManagerConnectionProvider] using driver: org.postgresql.Driver at URL: jdbc:postgresql:test
13:44:47,572 INFO [DriverManagerConnectionProvider] connection properties: {user=postgres, password=}
13:44:47,572 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
13:44:47,572 DEBUG [DriverManagerConnectionProvider] opening new JDBC connection
13:44:47,591 DEBUG [DriverManagerConnectionProvider] created connection to: jdbc:postgresql:test, Isolation Level: 2
13:44:47,593 INFO [SettingsFactory] RDBMS: PostgreSQL, version: 7.4.8
13:44:47,595 INFO [SettingsFactory] JDBC driver: PostgreSQL Native Driver, version: PostgreSQL 8.2devel JDBC3 with SSL (build 500)
13:44:47,596 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
13:44:47,596 INFO [Dialect] Using dialect: org.hibernate.dialect.PostgreSQLDialect
13:44:47,597 INFO [TransactionFactoryFactory] Transaction strategy: org.hibernate.transaction.JTATransactionFactory
13:44:47,600 INFO [NamingHelper] JNDI InitialContext properties:{}
13:44:47,601 INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup
13:44:47,601 INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup
13:44:47,601 INFO [TransactionManagerLookupFactory] instantiating TransactionManagerLookup: org.hibernate.transaction.JBossTransactionManagerLookup
13:44:47,606 INFO [TransactionManagerLookupFactory] instantiated TransactionManagerLookup
13:44:47,606 INFO [SettingsFactory] Automatic flush during beforeCompletion(): enabled
13:44:47,606 INFO [SettingsFactory] Automatic session close at end of transaction: enabled
13:44:47,606 INFO [SettingsFactory] JDBC batch size: 15
13:44:47,606 INFO [SettingsFactory] JDBC batch updates for versioned data: disabled
13:44:47,606 INFO [SettingsFactory] Scrollable result sets: enabled
13:44:47,612 DEBUG [SettingsFactory] Wrap result sets: disabled
13:44:47,612 INFO [SettingsFactory] JDBC3 getGeneratedKeys(): disabled
13:44:47,613 INFO [SettingsFactory] Connection release mode: auto
13:44:47,613 INFO [SettingsFactory] Default batch fetch size: 1
13:44:47,613 INFO [SettingsFactory] Generate SQL with comments: disabled
13:44:47,613 INFO [SettingsFactory] Order SQL updates by primary key: disabled
13:44:47,613 INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
13:44:47,613 INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
13:44:47,613 INFO [SettingsFactory] Query language substitutions: {}
13:44:47,620 INFO [SettingsFactory] Second-level cache: enabled
13:44:47,620 INFO [SettingsFactory] Query cache: disabled
13:44:47,620 INFO [SettingsFactory] Cache provider: org.hibernate.cache.EhCacheProvider
13:44:47,620 INFO [SettingsFactory] Optimize cache for minimal puts: disabled
13:44:47,620 INFO [SettingsFactory] Structured second-level cache entries: disabled
13:44:47,621 DEBUG [SQLExceptionConverterFactory] Using dialect defined converter
13:44:47,621 INFO [SettingsFactory] Statistics: disabled
13:44:47,621 INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled
13:44:47,627 INFO [SettingsFactory] Default entity-mode: pojo
13:44:47,636 INFO [SessionFactoryImpl] building session factory
13:44:47,637 DEBUG [SessionFactoryImpl] Session factory constructed with filter configurations : {}
13:44:47,638 DEBUG [SessionFactoryImpl] instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., catalina.base=/usr/local/jboss-4.0.3SP1/server/default, hibernate.connection.url=jdbc:postgresql:test, sun.management.compiler=HotSpot Server Compiler, catalina.useNaming=false, hibernate.transaction.flush_before_completion=true, os.name=Linux, sun.boot.class.path=/usr/local/jboss-4.0.3SP1/lib/endorsed/resolver.jar:/usr/local/jboss-4.0.3SP1/lib/endorsed/xml-apis.jar:/usr/local/jboss-4.0.3SP1/lib/endorsed/xalan.jar:/usr/local/jboss-4.0.3SP1/lib/endorsed/xercesImpl.jar:/opt/jdk1.5.0_06/jre/lib/rt.jar:/opt/jdk1.5.0_06/jre/lib/i18n.jar:/opt/jdk1.5.0_06/jre/lib/sunrsasign.jar:/opt/jdk1.5.0_06/jre/lib/jsse.jar:/opt/jdk1.5.0_06/jre/lib/jce.jar:/opt/jdk1.5.0_06/jre/lib/charsets.jar:/opt/jdk1.5.0_06/jre/classes, hibernate.current_session_context_class=jta, sun.desktop=gnome, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.5.0_06-b05, user.name=root, shared.loader=${catalina.base}/shared/classes,${catalina.base}/shared/lib/*.jar, jboss.bind.address=0.0.0.0, tomcat.util.buf.StringCache.byte.enabled=true, connection.driver_class=org.postgresql.Driver, current_session_context_class=jta, transaction.auto_close_session=true, jboss.home.dir=/usr/local/jboss-4.0.3SP1, user.language=en, java.naming.factory.initial=org.jnp.interfaces.NamingContextFactory, sun.boot.library.path=/opt/jdk1.5.0_06/jre/lib/i386, dialect=org.hibernate.dialect.PostgreSQLDialect, jboss.home.url=file:/usr/local/jboss-4.0.3SP1/, java.version=1.5.0_06, user.timezone=America/New_York, jboss.server.home.dir=/usr/local/jboss-4.0.3SP1/server/default, sun.arch.data.model=32, java.endorsed.dirs=/usr/local/jboss-4.0.3SP1/lib/endorsed, jboss.server.home.url=file:/usr/local/jboss-4.0.3SP1/server/default/, sun.cpu.isalist=, sun.jnu.encoding=UTF-8, file.encoding.pkg=sun.io, package.access=sun.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper.,sun.beans., file.separator=/, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=49.0, jboss.server.config.url=file:/usr/local/jboss-4.0.3SP1/server/default/conf/, user.country=US, connection.url=jdbc:postgresql:test, java.home=/opt/jdk1.5.0_06/jre, java.vm.info=mixed mode, jboss.lib.url=file:/usr/local/jboss-4.0.3SP1/lib/, os.version=2.6.9-22.0.1.ELsmp, transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, hibernate.transaction.factory_class=org.hibernate.transaction.JTATransactionFactory, path.separator=:, connection.password=, java.vm.version=1.5.0_06-b05, hibernate.connection.password=, java.protocol.handler.pkgs=org.jboss.net.protocol, java.awt.printerjob=sun.print.PSPrinterJob, sun.io.unicode.encoding=UnicodeLittle, hibernate.connection.username=postgres, package.definition=sun.,java.,org.apache.catalina.,org.apache.coyote.,org.apache.tomcat.,org.apache.jasper., transaction.manager_lookup_class=org.hibernate.transaction.JBossTransactionManagerLookup, jboss.server.temp.dir=/usr/local/jboss-4.0.3SP1/server/default/tmp, java.naming.factory.url.pkgs=org.jboss.naming:org.jnp.interfaces, user.home=/root, java.rmi.server.RMIClassLoaderSpi=org.jboss.system.JBossRMIClassLoader, java.specification.vendor=Sun Microsystems Inc., java.library.path=/opt/jdk1.5.0_06/jre/lib/i386/server:/opt/jdk1.5.0_06/jre/lib/i386:/opt/jdk1.5.0_06/jre/../lib/i386, java.vendor.url=http://java.sun.com/, program.name=run.sh, hibernate.connection.driver_class=org.postgresql.Driver, connection.username=postgres, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=org.hibernate.dialect.PostgreSQLDialect, common.loader=${catalina.home}/common/classes,${catalina.home}/common/i18n/*.jar,${catalina.home}/common/endorsed/*.jar,${catalina.home}/common/lib/*.jar, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=/usr/local/jboss-4.0.3SP1/bin/run.jar:/opt/jdk1.5.0_06/lib/tools.jar, hibernate.transaction.auto_close_session=true, jbossmx.loader.repository.class=org.jboss.mx.loading.UnifiedLoaderRepository3, java.vm.specification.name=Java Virtual Machine Specification, catalina.home=/usr/local/jboss-4.0.3SP1/server/default, java.vm.specification.version=1.0, jboss.server.lib.url=file:/usr/local/jboss-4.0.3SP1/server/default/lib/, sun.os.patch.level=unknown, sun.cpu.endian=little, java.io.tmpdir=/tmp, java.rmi.server.codebase=http://dhcp55-193.rdu.redhat.com:8083/, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, server.loader=${catalina.home}/server/classes,${catalina.home}/server/lib/*.jar, jboss.server.data.dir=/usr/local/jboss-4.0.3SP1/server/default/data, transaction.flush_before_completion=true, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, os.arch=i386, java.ext.dirs=/opt/jdk1.5.0_06/jre/lib/ext, user.dir=/root, line.separator=
, java.vm.name=Java HotSpot(TM) Server VM, jboss.server.base.dir=/usr/local/jboss-4.0.3SP1/server, jboss.server.base.url=file:/usr/local/jboss-4.0.3SP1/server/, javax.management.builder.initial=org.jboss.mx.server.MBeanServerBuilderImpl, file.encoding=UTF-8, UserTransactionName=java:comp/UserTransaction, hibernate.UserTransactionName=java:comp/UserTransaction, catalina.ext.dirs=/usr/local/jboss-4.0.3SP1/server/default/lib, hibernate.transaction.manager_lookup_class=org.hibernate.transaction.JBossTransactionManagerLookup, java.specification.version=1.5, jboss.server.name=default}
13:44:47,648 DEBUG [CacheManager] Attempting to create an existing instance. Existing instance returned.
13:44:47,660 DEBUG [AbstractEntityPersister] Static SQL for entity: test.UserObject
13:44:47,660 DEBUG [AbstractEntityPersister] Version select: select ID from USEROBJECT where ID =?
13:44:47,660 DEBUG [AbstractEntityPersister] Snapshot select: select userobject_.ID, userobject_.NAME as NAME2_ from USEROBJECT userobject_ where userobject_.ID=?
13:44:47,661 DEBUG [AbstractEntityPersister] Insert 0: insert into USEROBJECT (NAME, ID) values (?, ?)
13:44:47,661 DEBUG [AbstractEntityPersister] Update 0: update USEROBJECT set NAME=? where ID=?
13:44:47,661 DEBUG [AbstractEntityPersister] Delete 0: delete from USEROBJECT where ID=?
13:44:47,661 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID2_0_, userobject0_.NAME as NAME2_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
13:44:47,661 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID2_0_, userobject0_.NAME as NAME2_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
13:44:47,662 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID2_0_, userobject0_.NAME as NAME2_0_ from USEROBJECT userobject0_ where userobject0_.ID=? for update
13:44:47,662 DEBUG [EntityLoader] Static select for entity test.UserObject: select userobject0_.ID as ID2_0_, userobject0_.NAME as NAME2_0_ from USEROBJECT userobject0_ where userobject0_.ID=? for update
13:44:47,662 DEBUG [EntityLoader] Static select for action ACTION_MERGE on entity test.UserObject: select userobject0_.ID as ID2_0_, userobject0_.NAME as NAME2_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
13:44:47,662 DEBUG [EntityLoader] Static select for action ACTION_REFRESH on entity test.UserObject: select userobject0_.ID as ID2_0_, userobject0_.NAME as NAME2_0_ from USEROBJECT userobject0_ where userobject0_.ID=?
13:44:47,662 DEBUG [SessionFactoryObjectFactory] registered: 2c90b741087cf8c201087cfc7bae0001 (unnamed)
13:44:47,662 INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
13:44:47,663 DEBUG [SessionFactoryImpl] instantiated session factory
13:44:47,663 DEBUG [SessionFactoryImpl] obtaining JTA TransactionManager
13:44:47,663 INFO [NamingHelper] JNDI InitialContext properties:{}
13:44:47,663 INFO [SessionFactoryImpl] Checking 0 named HQL queries
13:44:47,664 INFO [SessionFactoryImpl] Checking 0 named SQL queries
13:44:47,664 DEBUG [JDBCContext] successfully registered Synchronization
13:44:47,664 DEBUG [SessionImpl] opened session at timestamp: 4652926106271744
13:44:47,664 FATAL [TestDriverServlet] saving object
13:44:47,665 DEBUG [DefaultSaveOrUpdateEventListener] saving transient instance
13:44:47,665 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
13:44:47,665 DEBUG [ConnectionManager] opening JDBC connection
13:44:47,665 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
13:44:47,665 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
13:44:47,665 DEBUG [SQL] select nextval ('hibernate_sequence')
13:44:47,665 DEBUG [AbstractBatcher] preparing statement
13:44:47,676 DEBUG [SequenceGenerator] Sequence identifier generated: 7
13:44:47,676 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
13:44:47,676 DEBUG [AbstractBatcher] closing statement
13:44:47,677 DEBUG [ConnectionManager] aggressively releasing JDBC connection
13:44:47,677 DEBUG [ConnectionManager] closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
13:44:47,677 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
13:44:47,677 DEBUG [AbstractSaveEventListener] generated identifier: 7, using strategy: org.hibernate.id.SequenceGenerator
13:44:47,677 DEBUG [AbstractSaveEventListener] saving [test.UserObject#7]
13:44:47,680 FATAL [TestDriverServlet] committing transaction
13:44:47,680 DEBUG [CacheSynchronization] transaction before completion callback
13:44:47,680 DEBUG [CacheSynchronization] automatically flushing session
13:44:47,680 DEBUG [SessionImpl] automatically flushing session
13:44:47,680 DEBUG [AbstractFlushingEventListener] flushing session
13:44:47,680 DEBUG [AbstractFlushingEventListener] processing flush-time cascades
13:44:47,680 DEBUG [AbstractFlushingEventListener] dirty checking collections
13:44:47,680 DEBUG [AbstractFlushingEventListener] Flushing entities and processing referenced collections
13:44:47,681 DEBUG [AbstractFlushingEventListener] Processing unreferenced collections
13:44:47,683 DEBUG [AbstractFlushingEventListener] Scheduling collection removes/(re)creates/updates
13:44:47,683 DEBUG [AbstractFlushingEventListener] Flushed: 1 insertions, 0 updates, 0 deletions to 1 objects
13:44:47,683 DEBUG [AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
13:44:47,683 DEBUG [Printer] listing entities:
13:44:47,684 DEBUG [Printer] test.UserObject{name=PhillipRhodes, id=7}
13:44:47,685 DEBUG [AbstractFlushingEventListener] executing flush
13:44:47,685 DEBUG [AbstractEntityPersister] Inserting entity: [test.UserObject#7]
13:44:47,685 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
13:44:47,685 DEBUG [ConnectionManager] opening JDBC connection
13:44:47,686 DEBUG [DriverManagerConnectionProvider] total checked-out connections: 0
13:44:47,686 DEBUG [DriverManagerConnectionProvider] using pooled JDBC connection, pool size: 0
13:44:47,686 DEBUG [SQL] insert into USEROBJECT (NAME, ID) values (?, ?)
13:44:47,686 DEBUG [AbstractBatcher] preparing statement
13:44:47,686 DEBUG [AbstractEntityPersister] Dehydrating entity: [test.UserObject#7]
13:44:47,686 DEBUG [StringType] binding 'PhillipRhodes' to parameter: 1
13:44:47,687 DEBUG [LongType] binding '7' to parameter: 2
13:44:47,687 DEBUG [AbstractBatcher] Adding to batch
13:44:47,687 DEBUG [AbstractBatcher] Executing batch size: 1
13:44:47,688 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
13:44:47,689 DEBUG [AbstractBatcher] closing statement
13:44:47,689 DEBUG [ConnectionManager] aggressively releasing JDBC connection
13:44:47,689 DEBUG [ConnectionManager] closing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
13:44:47,689 DEBUG [DriverManagerConnectionProvider] returning connection to pool, pool size: 1
13:44:47,689 DEBUG [AbstractFlushingEventListener] post flush
13:44:47,689 DEBUG [JDBCContext] before transaction completion
13:44:47,689 DEBUG [SessionImpl] before transaction completion
13:44:47,689 DEBUG [CacheSynchronization] transaction after completion callback, status: 3
13:44:47,689 DEBUG [JDBCContext] after transaction completion
13:44:47,689 DEBUG [SessionImpl] after transaction completion
13:44:47,689 DEBUG [JDBCContext] no active transaction, could not register Synchronization
13:44:47,690 DEBUG [JDBCContext] no active transaction, could not register Synchronization
13:44:47,690 DEBUG [CacheSynchronization] automatically closing session
13:44:47,690 DEBUG [SessionImpl] automatically closing session
13:44:47,690 DEBUG [SessionImpl] closing session
13:44:47,690 DEBUG [ConnectionManager] connection already null in cleanup : no action
13:44:47,690 FATAL [TestDriverServlet] done


Top
 Profile  
 
 Post subject:
PostPosted: Fri Dec 30, 2005 2:58 pm 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
Oh, and in case it matters, the servlet test was run
using jboss-4.0.3SP1, Hibernate 3.1 and using PostgreSQL
all on RHEL 4.

The previous tests were all done on Windows 2000, using either DB/2 8.1.0 or Oracle 9i.

Somehow I doubt that any of that matters, but in the interest of completeness...


Top
 Profile  
 
 Post subject:
PostPosted: Fri Dec 30, 2005 5:38 pm 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
Think maybe - after much searching - I have found the answer in these threads:

http://forum.hibernate.org/viewtopic.php?t=924413&highlight=jta+committed

http://forum.hibernate.org/viewtopic.php?t=942801&highlight=jta+committed

http://forum.hibernate.org/viewtopic.php?t=931087&highlight=jta+committed


If I'm understanding this correctly, there is an extra step required to
create an XA aware datasource and enlist the datasource with the transaction manager. In my case, I'm not explicitly creating a datasource however, I'm just configuring Hibernate with the connection info.

So can anyone tell me, is there any way to configure hibernate to make the datasource suitable for JTA use and enlist it? Or does this scenario strictly demand that we manage creating the datasource and doing the enlistment before getting hibernate involved?

Thanks again for all the help, and sorry again for the noise. Maybe this thread will help others who might encounter this same problem in the future.


Top
 Profile  
 
 Post subject: Issue resolved (I think)!
PostPosted: Sat Dec 31, 2005 3:06 am 
Newbie

Joined: Sun Dec 25, 2005 7:27 pm
Posts: 13
Ok, I have this working now, although I'm not 100% sure I understand
exactly *why* it works. Basically I found that I did need to create a
DataSource and configure hibernate to use the dataSource (looked up
from JNDI) before it would work.

Since I'm in a non-managed environment, I had to explicitly create the
datasource and configure it, and then stick it in JNDI using that "file system
JNDI provider" that Sun provides... but the Hibernate config looks, AFAIK,
the same as it would if it were a managed environment. All Hibernate
knows is to go to JNDI to find the thing, and I don't suppose he cares how
it got there.

Anyway, for anybody who cares about this (now or in the future), this is
the code that actually works:

Code:
   public static void main( String[] args )
   {

      // BasicConfigurator.configure();
      DOMConfigurator.configure( "log4j.xml" );
      Configuration config = new Configuration();
      Logger logger = Logger.getLogger( TestDriver.class );
         
      logger.warn( "Welcome to TRANSACT!" );

      try
      {
      
         /* setup JNDI */
         System.setProperty( "java.naming.factory.initial", "com.sun.jndi.fscontext.RefFSContextFactory" );
         InitialContext jndiCtx = new InitialContext();
         
         // create a DataSource
         DB2DataSource db2DS = new DB2DataSource();
         db2DS.setUser( "prhodes" );
         db2DS.setPassword( "redacted" );
         db2DS.setServerName("localhost");
         db2DS.setPortNumber(50000);
         db2DS.setDatabaseName("HIBTEST");
         db2DS.setDriverType(4);
         
          jndiCtx.rebind( "db2DataSource", db2DS );
         
         /* startup JOTM */
         TMService jotm = new Jotm(true, false);

         // JOTM changes this for some strange reason, change it back to use our local provider
         System.setProperty( "java.naming.factory.initial", "com.sun.jndi.fscontext.RefFSContextFactory" );
         
         /* and get a UserTransaction */
         UserTransaction ut = jotm.getUserTransaction();

              /* get the Hibernate SessionFactory */
         File file = new File( "./hibernate.cfg.xml" );
         SessionFactory sf = config.configure( file ).buildSessionFactory();
         
         // begin a new Transaction
         ut.begin();
         
         // and open the Hibernate session
         Session session = sf.getCurrentSession();
         
         // do something transactional using Hibernate
         UserObject obj = new UserObject( "PhillipRhodes" );
         session.save( obj );
                  

         // do something else involving the transaction (send a JMS message, for example)
         // TODO: add a separate transactional step here
      
         // commit the transaction
         ut.commit();
         
         // stop the transaction manager
         jotm.stop();
         
         // goodbye...
         logger.warn( "done" );
      }
      catch( Exception e )
      {
         e.printStackTrace();
      }
   }


hibernate.cfg.xml

<hibernate-configuration>
<session-factory>

<property name="connection.datasource">db2DataSource</property>
<property name="dialect">org.hibernate.dialect.DB2Dialect</property>
<property name="transaction.flush_before_completion">true</property>
<property name="transaction.auto_close_session">true</property>
<property name="transaction.factory_class">org.hibernate.transaction.JTATransactionFactory</property>
<property name="transaction.manager_lookup_class">org.hibernate.transaction.JOTMTransactionManagerLookup</property>
<property name="current_session_context_class">jta</property>

<mapping resource="test/UserObject.hbm.xml" />

</session-factory>


</hibernate-configuration>


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 13 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.