I'm trying to use JOTM to provide JTA support for Hibernate (v22branch), but it's failing to commit the transaction. The debug log looks as it should do, there are no exceptions being thrown, but there's just a lack of data in the database.

Here's what I'm doing:



The code works fine using Hibernate's builti-in transactions. Any ideas?

Cheers,

Mark

Try integrating the TM into hibernate properly, by using JTATransactionFactory and using net.sf.hibernate.transaction.JOTMTransactionManagerLookup
as hibernate.transaction.manager_lookup_class

I have already got the JOTM JTA properties in my Hibernate configuration:



I changed my method of obtaining the transaction to go via the Hibernate Session, which seemed to help since Hibernate was now looking in JNDI for the UserTransaction. Since I'm running this code outside of any web/app server, I wrote a simple HashMap InitialContext implementation to store the UserTransaction in and for Hibernate to obtain it from. I also configured JOTM's CAROL to bypass RMI and thus use this JNDI context.

It now runs even more as expected, but it's still not commiting anything to the database. My code looks something like this now:



I'm not sure whether both the UserTransaction and the Hibernate Transaction require to be committed, but either way it doesn't complain nor work.

I have the complete debug logs for this code if that helps. Any more ideas please?

Cheers,

Mark

Well IMHO this should work .. have you enabled logging for JTATransaction? Post away with the debug log, probably somebody notices something. We don't have much experience yet with standalone JOTM, you are the first one I have heard of so far :)

Glad to be pushing the envelope..?! Here's the full log for a persisting one entity:

[code]18:22:43,562 INFO jotm:113 - JOTM started with a local transaction factory which is not bound.
18:22:43,609 INFO jotm:124 - CAROL initialization
18:22:43,640 DEBUG carol:106 - Carol file used is carol-defaults.properties in file:/C:/Documents%20and%20Settings/Mark/My%20Documents/projects/work/test/lib/jotm/carol.jar!/carol-defaults.properties
18:22:43,640 DEBUG carol:106 - Carol file used is carol.properties in /C:/Documents%20and%20Settings/Mark/My%20Documents/projects/work/test/target/classes/carol.properties
18:22:43,640 DEBUG carol:106 - Carol file used is jndi.properties in /C:/Documents%20and%20Settings/Mark/My%20Documents/projects/work/test/target/classes/jndi.properties
18:22:43,640 DEBUG carol:106 - map properties found in jndi.properties to CAROL ones
18:22:43,656 DEBUG carol:106 - rmi used=null
18:22:43,656 DEBUG carol:106 - initial properties = {java.naming.factory.initial=test.jndi.TestContextFactory}
18:22:43,671 DEBUG carol:106 - Carol use carol file to activate RMI: lmi
18:22:43,671 DEBUG carol:106 - --- Global Carol configuration: ---
18:22:43,671 DEBUG carol:106 - Multiple RMI is false
18:22:43,671 DEBUG carol:106 - carol.start.ns=false
18:22:43,671 DEBUG carol:106 - carol.start.rmi=true
18:22:43,671 DEBUG carol:106 - carol.start.jndi=false
18:22:43,671 DEBUG carol:106 - --- Carol RMI configuration ---
18:22:43,671 DEBUG carol:106 - Carol RMI lmi configuration:
18:22:43,671 DEBUG carol:106 - lmi is default
18:22:43,671 DEBUG carol:106 - carol.lmi.NameServiceClass=org.objectweb.carol.jndi.ns.LmiRegistry
18:22:43,671 DEBUG carol:106 - carol.lmi.PortableRemoteObjectClass=org.objectweb.carol.rmi.multi.LmiPRODelegate
18:22:43,671 DEBUG carol:106 - carol.lmi.context.factory=org.objectweb.carol.jndi.lmi.LmiInitialContextFactory
18:22:43,671 DEBUG carol:106 - carol.lmi.url=lmi://nohost:0
18:22:43,671 DEBUG carol:106 - --- Carol JVM configuration --- (without carol.jvm prefix)
18:22:43,687 DEBUG carol:106 - rmi.server.port=0
18:22:43,703 DEBUG rmi:163 - MultiPRODelegate.MultiPRODelegate()
18:22:43,703 DEBUG rmi:163 - MultiPRODelegate.initProtocols()
18:22:43,703 DEBUG carol:106 - ProtocolCurrent.ProtocolCurrent()
18:22:43,703 DEBUG carol:106 - Number of rmi:1
18:22:43,703 DEBUG carol:106 - Default:lmi
18:22:43,703 DEBUG rmi:163 - MultiPRODelegate.exportObject(TransactionFactoryImpl obj)
18:22:43,703 DEBUG export:171 - Export object org.objectweb.jotm.TransactionFactoryImpl
18:22:43,718 DEBUG jotm:66 - default constructor
18:22:43,734 DEBUG jta:159 - TransactionFactory=org.objectweb.jotm.TransactionFactoryImpl@4a63d8
18:22:43,734 DEBUG jotm:178 - UserTransaction=org.objectweb.jotm.Current@f99ff5
18:22:43,796 INFO Environment:462 - Hibernate 2.1.3
18:22:43,812 INFO Environment:491 - hibernate.properties not found
18:22:43,812 INFO Environment:519 - using CGLIB reflection optimizer
18:22:43,828 INFO Configuration:872 - configuring from resource: /hibernate.cfg.xml
18:22:43,828 INFO Configuration:844 - Configuration resource: /hibernate.cfg.xml
18:22:44,000 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd in classpath under net/sf/hibernate/
18:22:44,000 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd in classpath
18:22:44,062 DEBUG Configuration:830 - connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor
18:22:44,062 DEBUG Configuration:830 - connection.username=sa
18:22:44,062 DEBUG Configuration:830 - connection.password=test
18:22:44,062 DEBUG Configuration:830 - connection.driver_class=net.sourceforge.jtds.jdbc.Driver
18:22:44,062 DEBUG Configuration:830 - dialect=net.sf.hibernate.dialect.SQLServerDialect
18:22:44,062 DEBUG Configuration:830 - query.substitutions=true 1, false 0, yes 'Y', no 'N'
18:22:44,062 DEBUG Configuration:830 - show_sql=true
18:22:44,062 DEBUG Configuration:830 - dbcp.maxActive=100
18:22:44,062 DEBUG Configuration:830 - dbcp.whenExhaustedAction=1
18:22:44,062 DEBUG Configuration:830 - dbcp.maxWait=120000
18:22:44,078 DEBUG Configuration:830 - dbcp.maxIdle=10
18:22:44,078 DEBUG Configuration:830 - dbcp.ps.maxActive=100
18:22:44,078 DEBUG Configuration:830 - dbcp.ps.whenExhaustedAction=1
18:22:44,078 DEBUG Configuration:830 - dbcp.ps.maxWait=120000
18:22:44,078 DEBUG Configuration:830 - dbcp.ps.maxIdle=10
18:22:44,078 DEBUG Configuration:830 - transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory
18:22:44,078 DEBUG Configuration:830 - transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup
18:22:44,078 DEBUG Configuration:989 - null<-org.dom4j.tree.DefaultAttribute@fbb7cb [Attribute: name resource value "test/dao/hibernate/HibernateContent.hbm.xml"]
18:22:44,093 INFO Configuration:328 - Mapping resource: test/dao/hibernate/HibernateContent.hbm.xml
18:22:44,093 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
18:22:44,125 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
18:22:44,265 INFO Binder:229 - Mapping class: test.dao.hibernate.HibernateContent -> content
18:22:44,359 DEBUG Binder:475 - Mapped property: id -> id, type: long
18:22:44,375 DEBUG Binder:475 - Mapped property: name -> name, type: string
18:22:44,375 DEBUG Binder:475 - Mapped property: createDate -> create_date, type: timestamp
18:22:44,375 DEBUG Binder:475 - Mapped property: updateDate -> update_date, type: timestamp
18:22:44,390 DEBUG Binder:475 - Mapped property: folder -> folder, type: test.dao.hibernate.HibernateFolder
18:22:44,421 DEBUG Binder:475 - Mapped property: versions, type: java.util.Set
18:22:44,421 DEBUG Configuration:989 - null<-org.dom4j.tree.DefaultAttribute@39443f [Attribute: name resource value "test/dao/hibernate/HibernateFolder.hbm.xml"]
18:22:44,421 INFO Configuration:328 - Mapping resource: test/dao/hibernate/HibernateFolder.hbm.xml
18:22:44,421 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
18:22:44,421 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
18:22:44,468 INFO Binder:229 - Mapping class: test.dao.hibernate.HibernateFolder -> folder
18:22:44,484 DEBUG Binder:475 - Mapped property: id -> id, type: long
18:22:44,484 DEBUG Binder:475 - Mapped property: name -> name, type: string
18:22:44,484 DEBUG Binder:475 - Mapped property: parent -> parent, type: test.dao.hibernate.HibernateFolder
18:22:44,484 DEBUG Binder:475 - Mapped property: children, type: java.util.SortedSet
18:22:44,484 DEBUG Binder:475 - Mapped property: contents, type: java.util.SortedSet
18:22:44,484 DEBUG Configuration:989 - null<-org.dom4j.tree.DefaultAttribute@811c88 [Attribute: name resource value "test/dao/hibernate/HibernateVersion.hbm.xml"]
18:22:44,484 INFO Configuration:328 - Mapping resource: test/dao/hibernate/HibernateVersion.hbm.xml
18:22:44,500 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
18:22:44,500 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
18:22:44,531 INFO Binder:229 - Mapping class: test.dao.hibernate.HibernateVersion -> version
18:22:44,531 DEBUG Binder:475 - Mapped property: id -> id, type: long
18:22:44,531 DEBUG Binder:475 - Mapped property: number -> number, type: integer
18:22:44,531 INFO Configuration:1030 - Configured SessionFactory: null
18:22:44,531 DEBUG Configuration:1031 - properties: {java.vendor=Sun Microsystems Inc., show_sql=true, hibernate.connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, hibernate.dbcp.ps.maxWait=120000, os.name=Windows XP, sun.boot.class.path=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xalan.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xercesImpl.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xml-apis.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\rt.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\i18n.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\sunrsasign.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jsse.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jce.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\charsets.jar;C:\Program Files\j2sdk1.4.2_03\jre\classes, rmi.server.port=0, hibernate.dbcp.maxWait=120000, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.4.2_03-b02, user.name=Mark, hibernate.dbcp.ps.maxIdle=10, connection.driver_class=net.sourceforge.jtds.jdbc.Driver, hibernate.dbcp.maxActive=100, hibernate.dbcp.maxIdle=10, user.language=en, sun.boot.library.path=C:\Program Files\j2sdk1.4.2_03\jre\bin, dialect=net.sf.hibernate.dialect.SQLServerDialect, java.version=1.4.2_03, user.timezone=Europe/London, dbcp.ps.whenExhaustedAction=1, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed, sun.cpu.isalist=pentium i486 i386, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=GB, connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, java.home=C:\Program Files\j2sdk1.4.2_03\jre, hibernate.dbcp.whenExhaustedAction=1, java.vm.info=mixed mode, hibernate.dbcp.ps.whenExhaustedAction=1, os.version=5.1, transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, hibernate.transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, path.separator=;, connection.password=test, java.vm.version=1.4.2_03-b02, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=test, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup, dbcp.maxWait=120000, query.substitutions=true 1, false 0, yes 'Y', no 'N', dbcp.maxActive=100, user.home=C:\Documents and Settings\Mark, hibernate.query.substitutions=true 1, false 0, yes 'Y', no 'N', java.specification.vendor=Sun Microsystems Inc., hibernate.dbcp.ps.maxActive=100, java.library.path=C:\Program Files\j2sdk1.4.2_03\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\j2sdk1.4.2_03\bin;C:\Program Files\jikes-1.21\bin;C:\Program Files\Unrar;C:\Program Files\apache-ant-1.6.1\bin;C:\Program Files\Interact Commerce\SalesLogix\Common Files;C:\Program Files\Microsoft SQL Server\80\Tools\BINN;C:\Program Files\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\cygwin\bin;C:\Program Files\aspectj1.2\bin;C:\Program Files\Subversion\bin;C:\Documents and Settings\Mark\My Documents\apps\java\maven-1.0-rc2\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=net.sourceforge.jtds.jdbc.Driver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=net.sf.hibernate.dialect.SQLServerDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\Mark\My Documents\projects\work\test\target\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\target\test-classes;\test\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-collections-2.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\cglib-full-2.0.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-logging-1.0.3.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\log4j.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\dom4j-1.4.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\ehcache-0.7.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\hibernate2.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\jdbc2_0-stdext.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\odmg-3.0.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jdbc\postgres-jdbc.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\picocontainer\picocontainer-1.0-beta-5.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\jta.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\dbcp\commons-dbcp-1.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\carol.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\dbcp\commons-pool-1.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\commons-cli.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\connector-1_5.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm_iiop_stubs.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm_jrmp_stubs.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jts1_0.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\objectweb-datasource.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\xapool.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jdbc\jtds-0.8-rc1.jar, dbcp.maxIdle=10, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, javax.rmi.CORBA.PortableRemoteObjectClass=org.objectweb.carol.rmi.multi.MultiPRODelegate, sun.cpu.endian=little, sun.os.patch.level=Service Pack 1, java.io.tmpdir=C:\DOCUME~1\Mark\LOCALS~1\Temp\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Program Files\j2sdk1.4.2_03\jre\lib\ext, dbcp.ps.maxActive=100, user.dir=C:\Documents and Settings\Mark\My Documents\projects\work\test\target\classes, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, dbcp.ps.maxWait=120000, dbcp.whenExhaustedAction=1, file.encoding=Cp1252, hibernate.transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup, java.specification.version=1.4, dbcp.ps.maxIdle=10, hibernate.show_sql=true}
18:22:44,546 INFO Configuration:613 - processing one-to-many association mappings
18:22:44,546 DEBUG Binder:1340 - Second pass for collection: test.dao.hibernate.HibernateContent.versions
18:22:44,546 INFO Binder:1168 - Mapping collection: test.dao.hibernate.HibernateContent.versions -> version
18:22:44,546 DEBUG Binder:1355 - Mapped collection key: content, one-to-many: test.dao.hibernate.HibernateVersion
18:22:44,546 DEBUG Binder:1340 - Second pass for collection: test.dao.hibernate.HibernateFolder.children
18:22:44,546 INFO Binder:1168 - Mapping collection: test.dao.hibernate.HibernateFolder.children -> folder
18:22:44,546 DEBUG Binder:1355 - Mapped collection key: parent, one-to-many: test.dao.hibernate.HibernateFolder
18:22:44,546 DEBUG Binder:1340 - Second pass for collection: test.dao.hibernate.HibernateFolder.contents
18:22:44,546 INFO Binder:1168 - Mapping collection: test.dao.hibernate.HibernateFolder.contents -> content
18:22:44,546 DEBUG Binder:1355 - Mapped collection key: folder, one-to-many: test.dao.hibernate.HibernateContent
18:22:44,546 INFO Configuration:622 - processing one-to-one association property references
18:22:44,546 INFO Configuration:647 - processing foreign key constraints
18:22:44,546 DEBUG Configuration:657 - resolving reference to class: test.dao.hibernate.HibernateFolder
18:22:44,546 DEBUG Configuration:657 - resolving reference to class: test.dao.hibernate.HibernateFolder
18:22:44,546 DEBUG Configuration:657 - resolving reference to class: test.dao.hibernate.HibernateContent
18:22:44,656 INFO Dialect:82 - Using dialect: net.sf.hibernate.dialect.SQLServerDialect
18:22:44,656 INFO SettingsFactory:62 - Use outer join fetching: true
18:22:44,671 INFO DBCPConnectionProvider:56 - DBCP using driver: net.sourceforge.jtds.jdbc.Driver at URL: jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor
18:22:44,671 INFO DBCPConnectionProvider:57 - Connection properties: {user=sa, password=test}

18:22:44,687 INFO DBCPConnectionProvider:94 - DBCP prepared statement pooling enabled
18:22:44,703 INFO TransactionFactoryFactory:31 - Transaction strategy: net.sf.hibernate.transaction.JTATransactionFactory
18:22:44,703 INFO NamingHelper:26 - JNDI InitialContext properties:{}
18:22:44,718 INFO TransactionManagerLookupFactory:38 - instantiating TransactionManagerLookup: net.sf.hibernate.transaction.JOTMTransactionManagerLookup
18:22:44,718 INFO TransactionManagerLookupFactory:42 - instantiated TransactionManagerLookup
18:22:44,718 INFO TransactionManagerLookupFactory:38 - instantiating TransactionManagerLookup: net.sf.hibernate.transaction.JOTMTransactionManagerLookup
18:22:44,718 INFO TransactionManagerLookupFactory:42 - instantiated TransactionManagerLookup
18:22:44,937 INFO SettingsFactory:102 - Use scrollable result sets: true
18:22:44,937 INFO SettingsFactory:105 - Use JDBC3 getGeneratedKeys(): true
18:22:44,937 INFO SettingsFactory:108 - Optimize cache for minimal puts: false
18:22:44,937 INFO SettingsFactory:114 - echoing all SQL to stdout
18:22:44,937 INFO SettingsFactory:117 - Query language substitutions: {no='N', true=1, yes='Y', false=0}
18:22:44,937 INFO SettingsFactory:128 - cache provider: net.sf.ehcache.hibernate.Provider
18:22:44,953 INFO Configuration:1093 - instantiating and configuring caches
18:22:45,093 INFO SessionFactoryImpl:119 - building session factory
18:22:45,109 DEBUG SessionFactoryImpl:125 - instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=true, hibernate.connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, hibernate.dbcp.ps.maxWait=120000, os.name=Windows XP, sun.boot.class.path=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xalan.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xercesImpl.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xml-apis.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\rt.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\i18n.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\sunrsasign.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jsse.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jce.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\charsets.jar;C:\Program Files\j2sdk1.4.2_03\jre\classes, rmi.server.port=0, hibernate.dbcp.maxWait=120000, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.4.2_03-b02, user.name=Mark, hibernate.dbcp.ps.maxIdle=10, connection.driver_class=net.sourceforge.jtds.jdbc.Driver, hibernate.dbcp.maxActive=100, hibernate.dbcp.maxIdle=10, user.language=en, sun.boot.library.path=C:\Program Files\j2sdk1.4.2_03\jre\bin, dialect=net.sf.hibernate.dialect.SQLServerDialect, java.version=1.4.2_03, user.timezone=Europe/London, dbcp.ps.whenExhaustedAction=1, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed, sun.cpu.isalist=pentium i486 i386, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=GB, connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, java.home=C:\Program Files\j2sdk1.4.2_03\jre, hibernate.dbcp.whenExhaustedAction=1, java.vm.info=mixed mode, hibernate.dbcp.ps.whenExhaustedAction=1, os.version=5.1, transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, hibernate.transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, path.separator=;, connection.password=test, java.vm.version=1.4.2_03-b02, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=test, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup, dbcp.maxWait=120000, query.substitutions=true 1, false 0, yes 'Y', no 'N', dbcp.maxActive=100, user.home=C:\Documents and Settings\Mark, hibernate.query.substitutions=true 1, false 0, yes 'Y', no 'N', java.specification.vendor=Sun Microsystems Inc., hibernate.dbcp.ps.maxActive=100, java.library.path=C:\Program Files\j2sdk1.4.2_03\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\j2sdk1.4.2_03\bin;C:\Program Files\jikes-1.21\bin;C:\Program Files\Unrar;C:\Program Files\apache-ant-1.6.1\bin;C:\Program Files\Interact Commerce\SalesLogix\Common Files;C:\Program Files\Microsoft SQL Server\80\Tools\BINN;C:\Program Files\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\cygwin\bin;C:\Program Files\aspectj1.2\bin;C:\Program Files\Subversion\bin;C:\Documents and Settings\Mark\My Documents\apps\java\maven-1.0-rc2\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=net.sourceforge.jtds.jdbc.Driver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=net.sf.hibernate.dialect.SQLServerDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\Mark\My Documents\projects\work\test\target\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\target\test-classes;\test\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-collections-2.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\cglib-full-2.0.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-logging-1.0.3.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\log4j.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\dom4j-1.4.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\ehcache-0.7.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\hibernate2.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\jdbc2_0-stdext.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\odmg-3.0.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jdbc\postgres-jdbc.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\picocontainer\picocontainer-1.0-beta-5.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\jta.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\dbcp\commons-dbcp-1.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\carol.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\dbcp\commons-pool-1.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\commons-cli.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\connector-1_5.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm_iiop_stubs.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm_jrmp_stubs.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jts1_0.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\objectweb-datasource.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\xapool.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jdbc\jtds-0.8-rc1.jar, dbcp.maxIdle=10, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, javax.rmi.CORBA.PortableRemoteObjectClass=org.objectweb.carol.rmi.multi.MultiPRODelegate, sun.cpu.endian=little, sun.os.patch.level=Service Pack 1, java.io.tmpdir=C:\DOCUME~1\Mark\LOCALS~1\Temp\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Program Files\j2sdk1.4.2_03\jre\lib\ext, dbcp.ps.maxActive=100, user.dir=C:\Documents and Settings\Mark\My Documents\projects\work\test\target\classes, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, dbcp.ps.maxWait=120000, dbcp.whenExhaustedAction=1, file.encoding=Cp1252, hibernate.transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup, java.specification.version=1.4, dbcp.ps.maxIdle=10, hibernate.show_sql=true}
18:22:45,609 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
18:22:45,609 DEBUG SessionFactoryObjectFactory:76 - registered: 8a808081fcb2e2c600fcb2e2c8e90000 (unnamed)
18:22:45,609 INFO SessionFactoryObjectFactory:82 - no JNDI name configured
18:22:45,609 DEBUG SessionFactoryImpl:196 - instantiated session factory
18:22:45,609 DEBUG SessionFactoryImpl:203 - obtaining JTA TransactionManager
18:22:45,687 DEBUG SessionImpl:542 - opened session
18:22:45,687 DEBUG jta:194 - begin transaction
18:22:45,687 DEBUG jotm:111 - serverName=, ipAddr=0
18:22:45,687 DEBUG jotm:141 - new Xid (uuid= 3f2cb8b24dc01)
18:22:45,687 DEBUG jta:104 - xid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0, timeout=60
18:22:45,687 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,687 DEBUG jta:213 - tx=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,703 DEBUG jta:432 - flag=TMJOIN
18:22:45,703 DEBUG jta:433 - number of enlisted=0
18:22:45,703 DEBUG jta:1137 - Associate tx to xid (xid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0)
18:22:45,703 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,703 DEBUG jta:772 - set timer for tx (timer=org.objectweb.jotm.TimerEvent@1b273cc, tx=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0)
18:22:45,703 DEBUG JTATransaction:130 - Looking for UserTransaction under: java:comp/UserTransaction
18:22:45,703 DEBUG JTATransaction:142 - Obtained UserTransaction
18:22:45,703 DEBUG jta:523 - Current.getStatus()
18:22:45,703 DEBUG jta:474 - TransactionImpl.getStatus()
18:22:45,718 DEBUG jta:526 - TransactionImpl.registerSynchronization(Synchronization sync)
18:22:45,718 DEBUG jta:845 - make subcoordinator
18:22:45,718 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,718 DEBUG rmi:163 - MultiPRODelegate.exportObject(SubCoordinator obj)
18:22:45,718 DEBUG export:171 - Export object org.objectweb.jotm.SubCoordinator
18:22:45,718 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,718 DEBUG jta:200 - tx=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0, xid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,750 DEBUG jta:450 - synchro=net.sf.hibernate.engine.CacheSynchronization@15dd910
18:22:45,750 DEBUG jta:451 - status=STATUS_ACTIVE
18:22:45,750 INFO HibernateFolderServer:63 - Using session: net.sf.hibernate.impl.SessionImpl@18ce14a
18:22:45,765 DEBUG SessionImpl:1379 - saveOrUpdate() unsaved instance
18:22:45,765 DEBUG SessionImpl:818 - saving [test.dao.hibernate.HibernateFolder#<null>]
18:22:45,765 DEBUG SessionImpl:2298 - executing insertions
18:22:45,765 DEBUG Cascades:497 - processing cascades for: test.dao.hibernate.HibernateFolder
18:22:45,765 DEBUG Cascades:506 - done processing cascades for: test.dao.hibernate.HibernateFolder
18:22:45,781 DEBUG WrapVisitor:81 - Wrapped collection in role: test.dao.hibernate.HibernateFolder.children
18:22:45,781 DEBUG WrapVisitor:81 - Wrapped collection in role: test.dao.hibernate.HibernateFolder.contents
18:22:45,781 DEBUG EntityPersister:490 - Inserting entity: test.dao.hibernate.HibernateFolder (native id)
18:22:45,781 DEBUG BatcherImpl:196 - about to open: 0 open PreparedStatements, 0 open ResultSets
18:22:45,781 DEBUG SQL:237 - insert into folder (name, parent) values (?, ?)
18:22:45,796 DEBUG BatcherImpl:241 - preparing statement
18:22:45,812 DEBUG EntityPersister:388 - Dehydrating entity: [test.dao.hibernate.HibernateFolder#<null>]
18:22:45,812 DEBUG StringType:46 - binding 'New Folder' to parameter: 1
18:22:45,812 DEBUG LongType:41 - binding null to parameter: 2
18:22:45,828 DEBUG AbstractEntityPersister:1229 - Natively generated identity: 75
18:22:45,828 DEBUG BatcherImpl:203 - done closing: 0 open PreparedStatements, 0 open ResultSets
18:22:45,828 DEBUG BatcherImpl:261 - closing statement
18:22:45,828 DEBUG Cascades:497 - processing cascades for: test.dao.hibernate.HibernateFolder
18:22:45,828 DEBUG Cascades:506 - done processing cascades for: test.dao.hibernate.HibernateFolder
18:22:45,828 DEBUG SessionImpl:2235 - flushing session
18:22:45,828 DEBUG Cascades:497 - processing cascades for: test.dao.hibernate.HibernateFolder
18:22:45,828 DEBUG Cascades:506 - done processing cascades for: test.dao.hibernate.HibernateFolder
18:22:45,843 DEBUG SessionImpl:2428 - Flushing entities and processing referenced collections
18:22:45,843 DEBUG SessionImpl:2875 - Collection found: [test.dao.hibernate.HibernateFolder.children#75], was: [<unreferenced>]
18:22:45,843 DEBUG SessionImpl:2875 - Collection found: [test.dao.hibernate.HibernateFolder.contents#75], was: [<unreferenced>]
18:22:45,843 DEBUG SessionImpl:2771 - Processing unreferenced collections
18:22:45,843 DEBUG SessionImpl:2785 - Scheduling collection removes/(re)creates/updates
18:22:45,843 DEBUG SessionImpl:2259 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
18:22:45,843 DEBUG SessionImpl:2264 - Flushed: 2 (re)creations, 0 updates, 0 removals to 2 collections
18:22:45,843 DEBUG Printer:75 - listing entities:
18:22:45,875 DEBUG Printer:82 - test.dao.hibernate.HibernateFolder{contents=[], name=New Folder, children=[], parent=null, id=75}
18:22:45,875 DEBUG SessionImpl:2348 - executing flush
18:22:45,875 DEBUG SessionImpl:2815 - post flush
18:22:45,875 DEBUG SessionImpl:560 - closing session
18:22:45,875 DEBUG SessionImpl:3327 - disconnecting session
18:22:45,875 DEBUG JTATransaction:50 - commit
18:22:45,875 DEBUG SessionImpl:2235 - flushing session
18:22:45,875 DEBUG SessionImpl:2428 - Flushing entities and processing referenced collections
18:22:45,875 DEBUG SessionImpl:2771 - Processing unreferenced collections
18:22:45,875 DEBUG SessionImpl:2785 - Scheduling collection removes/(re)creates/updates
18:22:45,875 DEBUG SessionImpl:2259 - Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
18:22:45,875 DEBUG SessionImpl:2264 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
18:22:45,875 DEBUG SessionImpl:2348 - executing flush
18:22:45,875 DEBUG SessionImpl:2815 - post flush
18:22:45,890 DEBUG jta:426 - commit transaction
18:22:45,890 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,890 DEBUG jta:437 - tx=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,890 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,890 DEBUG jta:167 - commit transaction (tx=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0)
18:22:45,890 DEBUG jta:348 - status=STATUS_ACTIVE
18:22:45,890 DEBUG jta:415 - flag=TMSUCCESS
18:22:45,890 DEBUG jta:416 - number of enlisted=0
18:22:45,890 DEBUG jta:982 - committing=true
18:22:45,890 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,890 DEBUG jta:783 - unset timer for tx (timer=org.objectweb.jotm.TimerEvent@1b273cc, tx=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0)
18:22:45,890 DEBUG CacheSynchronization:24 - transaction before completion callback
18:22:45,890 DEBUG jta:382 - status=STATUS_ACTIVE
18:22:45,890 DEBUG jta:671 - SubCoordinator.doPrepare()
18:22:45,890 DEBUG jta:1142 - SubCoordinator.doAfterCompletion()
18:22:45,890 DEBUG CacheSynchronization:28 - transaction after completion callback, status: 3
18:22:45,890 DEBUG SessionImpl:572 - transaction completion
18:22:45,890 DEBUG jta:835 - myXid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0
18:22:45,890 DEBUG jta:1162 - remove tx from xid (xid=bb14111130336632636238623234646330315f305f 030336632636238623234646330315f305f 0)
18:22:45,906 DEBUG jta:1160 - SubCoordinator unexported [subcoord=org.objectweb.jotm.SubCoordinator@88df60]
18:22:45,906 DEBUG rmi:163 - MultiPRODelegate.unexportObject(SubCoordinator obj)
18:22:45,906 DEBUG export:171 - Unexport object org.objectweb.jotm.SubCoordinator
18:22:45,906 DEBUG export:171 - UnExported objects list:
Exported Objects:
1 instances of org.objectweb.jotm.TransactionFactoryImpl
1 instances of org.objectweb.jotm.SubCoordinator
Total number of exported objects=2
18:22:45,906 INFO jotm:185 - stop JOTM
18:22:45,906 DEBUG rmi:163 - MultiPRODelegate.unexportObject(TransactionFactoryImpl obj)
18:22:45,906 DEBUG export:171 - Unexport object org.objectweb.jotm.TransactionFactoryImpl
18:22:45,906 DEBUG export:171 - UnExported objects list:
Exported Objects:
1 instances of org.objectweb.jotm.TransactionFactoryImpl
Total number of exported objects=1
18:22:45,906 DEBUG jotm:206 - TransactionFactory unexported
18:23:57,968 INFO jotm:113 - JOTM started with a local transaction factory which is not bound.
18:23:58,000 INFO jotm:124 - CAROL initialization
18:23:58,031 DEBUG carol:106 - Carol file used is carol-defaults.properties in file:/C:/Documents%20and%20Settings/Mark/My%20Documents/projects/work/test/lib/jotm/carol.jar!/carol-defaults.properties
18:23:58,031 DEBUG carol:106 - Carol file used is carol.properties in /C:/Documents%20and%20Settings/Mark/My%20Documents/projects/work/test/target/classes/carol.properties
18:23:58,031 DEBUG carol:106 - Carol file used is jndi.properties in /C:/Documents%20and%20Settings/Mark/My%20Documents/projects/work/test/target/classes/jndi.properties
18:23:58,031 DEBUG carol:106 - map properties found in jndi.properties to CAROL ones
18:23:58,046 DEBUG carol:106 - rmi used=null
18:23:58,046 DEBUG carol:106 - initial properties = {java.naming.factory.initial=test.jndi.TestContextFactory}
18:23:58,046 DEBUG carol:106 - Carol use carol file to activate RMI: lmi
18:23:58,046 DEBUG carol:106 - --- Global Carol configuration: ---
18:23:58,046 DEBUG carol:106 - Multiple RMI is false
18:23:58,062 DEBUG carol:106 - carol.start.ns=false
18:23:58,062 DEBUG carol:106 - carol.start.rmi=true
18:23:58,062 DEBUG carol:106 - carol.start.jndi=false
18:23:58,062 DEBUG carol:106 - --- Carol RMI configuration ---
18:23:58,062 DEBUG carol:106 - Carol RMI lmi configuration:
18:23:58,062 DEBUG carol:106 - lmi is default
18:23:58,062 DEBUG carol:106 - carol.lmi.NameServiceClass=org.objectweb.carol.jndi.ns.LmiRegistry
18:23:58,062 DEBUG carol:106 - carol.lmi.PortableRemoteObjectClass=org.objectweb.carol.rmi.multi.LmiPRODelegate
18:23:58,062 DEBUG carol:106 - carol.lmi.context.factory=org.objectweb.carol.jndi.lmi.LmiInitialContextFactory
18:23:58,062 DEBUG carol:106 - carol.lmi.url=lmi://nohost:0
18:23:58,078 DEBUG carol:106 - --- Carol JVM configuration --- (without carol.jvm prefix)
18:23:58,078 DEBUG carol:106 - rmi.server.port=0
18:23:58,093 DEBUG rmi:163 - MultiPRODelegate.MultiPRODelegate()
18:23:58,093 DEBUG rmi:163 - MultiPRODelegate.initProtocols()
18:23:58,093 DEBUG carol:106 - ProtocolCurrent.ProtocolCurrent()
18:23:58,093 DEBUG carol:106 - Number of rmi:1
18:23:58,109 DEBUG carol:106 - Default:lmi
18:23:58,109 DEBUG rmi:163 - MultiPRODelegate.exportObject(TransactionFactoryImpl obj)
18:23:58,109 DEBUG export:171 - Export object org.objectweb.jotm.TransactionFactoryImpl
18:23:58,109 DEBUG jotm:66 - default constructor
18:23:58,156 DEBUG jta:159 - TransactionFactory=org.objectweb.jotm.TransactionFactoryImpl@4a63d8
18:23:58,156 DEBUG jotm:178 - UserTransaction=org.objectweb.jotm.Current@f99ff5
18:23:58,203 INFO Environment:462 - Hibernate 2.1.3
18:23:58,203 INFO Environment:491 - hibernate.properties not found
18:23:58,203 INFO Environment:519 - using CGLIB reflection optimizer
18:23:58,218 INFO Configuration:872 - configuring from resource: /hibernate.cfg.xml
18:23:58,218 INFO Configuration:844 - Configuration resource: /hibernate.cfg.xml
18:23:58,406 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd in classpath under net/sf/hibernate/
18:23:58,406 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd in classpath
18:23:58,468 DEBUG Configuration:830 - connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor
18:23:58,468 DEBUG Configuration:830 - connection.username=sa
18:23:58,468 DEBUG Configuration:830 - connection.password=test
18:23:58,468 DEBUG Configuration:830 - connection.driver_class=net.sourceforge.jtds.jdbc.Driver
18:23:58,484 DEBUG Configuration:830 - dialect=net.sf.hibernate.dialect.SQLServerDialect
18:23:58,484 DEBUG Configuration:830 - query.substitutions=true 1, false 0, yes 'Y', no 'N'
18:23:58,484 DEBUG Configuration:830 - show_sql=true
18:23:58,484 DEBUG Configuration:830 - dbcp.maxActive=100
18:23:58,484 DEBUG Configuration:830 - dbcp.whenExhaustedAction=1
18:23:58,484 DEBUG Configuration:830 - dbcp.maxWait=120000
18:23:58,484 DEBUG Configuration:830 - dbcp.maxIdle=10
18:23:58,484 DEBUG Configuration:830 - dbcp.ps.maxActive=100
18:23:58,484 DEBUG Configuration:830 - dbcp.ps.whenExhaustedAction=1
18:23:58,500 DEBUG Configuration:830 - dbcp.ps.maxWait=120000
18:23:58,500 DEBUG Configuration:830 - dbcp.ps.maxIdle=10
18:23:58,500 DEBUG Configuration:830 - transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory
18:23:58,500 DEBUG Configuration:830 - transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup
18:23:58,500 DEBUG Configuration:989 - null<-org.dom4j.tree.DefaultAttribute@fbb7cb [Attribute: name resource value "test/dao/hibernate/HibernateContent.hbm.xml"]
18:23:58,500 INFO Configuration:328 - Mapping resource: test/dao/hibernate/HibernateContent.hbm.xml
18:23:58,515 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
18:23:58,531 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
18:23:58,687 INFO Binder:229 - Mapping class: test.dao.hibernate.HibernateContent -> content
18:23:58,781 DEBUG Binder:475 - Mapped property: id -> id, type: long
18:23:58,796 DEBUG Binder:475 - Mapped property: name -> name, type: string
18:23:58,796 DEBUG Binder:475 - Mapped property: createDate -> create_date, type: timestamp
18:23:58,796 DEBUG Binder:475 - Mapped property: updateDate -> update_date, type: timestamp
18:23:58,828 DEBUG Binder:475 - Mapped property: folder -> folder, type: test.dao.hibernate.HibernateFolder
18:23:58,843 DEBUG Binder:475 - Mapped property: versions, type: java.util.Set
18:23:58,843 DEBUG Configuration:989 - null<-org.dom4j.tree.DefaultAttribute@39443f [Attribute: name resource value "test/dao/hibernate/HibernateFolder.hbm.xml"]
18:23:58,859 INFO Configuration:328 - Mapping resource: test/dao/hibernate/HibernateFolder.hbm.xml
18:23:58,859 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
18:23:58,859 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
18:23:58,890 INFO Binder:229 - Mapping class: test.dao.hibernate.HibernateFolder -> folder
18:23:58,906 DEBUG Binder:475 - Mapped property: id -> id, type: long
18:23:58,906 DEBUG Binder:475 - Mapped property: name -> name, type: string
18:23:58,906 DEBUG Binder:475 - Mapped property: parent -> parent, type: test.dao.hibernate.HibernateFolder
18:23:58,906 DEBUG Binder:475 - Mapped property: children, type: java.util.SortedSet
18:23:58,906 DEBUG Binder:475 - Mapped property: contents, type: java.util.SortedSet
18:23:58,906 DEBUG Configuration:989 - null<-org.dom4j.tree.DefaultAttribute@811c88 [Attribute: name resource value "test/dao/hibernate/HibernateVersion.hbm.xml"]
18:23:58,906 INFO Configuration:328 - Mapping resource: test/dao/hibernate/HibernateVersion.hbm.xml
18:23:58,937 DEBUG DTDEntityResolver:20 - trying to locate http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath under net/sf/hibernate/
18:23:58,953 DEBUG DTDEntityResolver:29 - found http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd in classpath
18:23:58,984 INFO Binder:229 - Mapping class: test.dao.hibernate.HibernateVersion -> version
18:23:58,984 DEBUG Binder:475 - Mapped property: id -> id, type: long
18:23:58,984 DEBUG Binder:475 - Mapped property: number -> number, type: integer
18:23:58,984 INFO Configuration:1030 - Configured SessionFactory: null
18:23:58,984 DEBUG Configuration:1031 - properties: {java.vendor=Sun Microsystems Inc., show_sql=true, hibernate.connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, hibernate.dbcp.ps.maxWait=120000, os.name=Windows XP, sun.boot.class.path=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xalan.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xercesImpl.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xml-apis.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\rt.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\i18n.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\sunrsasign.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jsse.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jce.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\charsets.jar;C:\Program Files\j2sdk1.4.2_03\jre\classes, rmi.server.port=0, hibernate.dbcp.maxWait=120000, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.4.2_03-b02, user.name=Mark, hibernate.dbcp.ps.maxIdle=10, connection.driver_class=net.sourceforge.jtds.jdbc.Driver, hibernate.dbcp.maxActive=100, hibernate.dbcp.maxIdle=10, user.language=en, sun.boot.library.path=C:\Program Files\j2sdk1.4.2_03\jre\bin, dialect=net.sf.hibernate.dialect.SQLServerDialect, java.version=1.4.2_03, user.timezone=Europe/London, dbcp.ps.whenExhaustedAction=1, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed, sun.cpu.isalist=pentium i486 i386, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=GB, connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, java.home=C:\Program Files\j2sdk1.4.2_03\jre, hibernate.dbcp.whenExhaustedAction=1, java.vm.info=mixed mode, hibernate.dbcp.ps.whenExhaustedAction=1, os.version=5.1, transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, hibernate.transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, path.separator=;, connection.password=test, java.vm.version=1.4.2_03-b02, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=test, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup, dbcp.maxWait=120000, query.substitutions=true 1, false 0, yes 'Y', no 'N', dbcp.maxActive=100, user.home=C:\Documents and Settings\Mark, hibernate.query.substitutions=true 1, false 0, yes 'Y', no 'N', java.specification.vendor=Sun Microsystems Inc., hibernate.dbcp.ps.maxActive=100, java.library.path=C:\Program Files\j2sdk1.4.2_03\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\j2sdk1.4.2_03\bin;C:\Program Files\jikes-1.21\bin;C:\Program Files\Unrar;C:\Program Files\apache-ant-1.6.1\bin;C:\Program Files\Interact Commerce\SalesLogix\Common Files;C:\Program Files\Microsoft SQL Server\80\Tools\BINN;C:\Program Files\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\cygwin\bin;C:\Program Files\aspectj1.2\bin;C:\Program Files\Subversion\bin;C:\Documents and Settings\Mark\My Documents\apps\java\maven-1.0-rc2\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=net.sourceforge.jtds.jdbc.Driver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=net.sf.hibernate.dialect.SQLServerDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\Mark\My Documents\projects\work\test\target\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\target\test-classes;\test\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-collections-2.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\cglib-full-2.0.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-logging-1.0.3.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\log4j.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\dom4j-1.4.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\ehcache-0.7.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\hibernate2.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\jdbc2_0-stdext.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\odmg-3.0.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jdbc\postgres-jdbc.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\picocontainer\picocontainer-1.0-beta-5.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\jta.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\dbcp\commons-dbcp-1.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\carol.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\dbcp\commons-pool-1.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\commons-cli.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\connector-1_5.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm_iiop_stubs.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm_jrmp_stubs.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jotm.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\jts1_0.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\objectweb-datasource.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jotm\xapool.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jdbc\jtds-0.8-rc1.jar, dbcp.maxIdle=10, java.vm.specification.name=Java Virtual Machine Specification, java.vm.specification.version=1.0, javax.rmi.CORBA.PortableRemoteObjectClass=org.objectweb.carol.rmi.multi.MultiPRODelegate, sun.cpu.endian=little, sun.os.patch.level=Service Pack 1, java.io.tmpdir=C:\DOCUME~1\Mark\LOCALS~1\Temp\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, os.arch=x86, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.ext.dirs=C:\Program Files\j2sdk1.4.2_03\jre\lib\ext, dbcp.ps.maxActive=100, user.dir=C:\Documents and Settings\Mark\My Documents\projects\work\test\target\classes, line.separator=
, java.vm.name=Java HotSpot(TM) Client VM, dbcp.ps.maxWait=120000, dbcp.whenExhaustedAction=1, file.encoding=Cp1252, hibernate.transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup, java.specification.version=1.4, dbcp.ps.maxIdle=10, hibernate.show_sql=true}
18:23:59,000 INFO Configuration:613 - processing one-to-many association mappings
18:23:59,000 DEBUG Binder:1340 - Second pass for collection: test.dao.hibernate.HibernateContent.versions
18:23:59,000 INFO Binder:1168 - Mapping collection: test.dao.hibernate.HibernateContent.versions -> version
18:23:59,000 DEBUG Binder:1355 - Mapped collection key: content, one-to-many: test.dao.hibernate.HibernateVersion
18:23:59,000 DEBUG Binder:1340 - Second pass for collection: test.dao.hibernate.HibernateFolder.children
18:23:59,000 INFO Binder:1168 - Mapping collection: test.dao.hibernate.HibernateFolder.children -> folder
18:23:59,000 DEBUG Binder:1355 - Mapped collection key: parent, one-to-many: test.dao.hibernate.HibernateFolder
18:23:59,000 DEBUG Binder:1340 - Second pass for collection: test.dao.hibernate.HibernateFolder.contents
18:23:59,000 INFO Binder:1168 - Mapping collection: test.dao.hibernate.HibernateFolder.contents -> content
18:23:59,015 DEBUG Binder:1355 - Mapped collection key: folder, one-to-many: test.dao.hibernate.HibernateContent
18:23:59,015 INFO Configuration:622 - processing one-to-one association property references
18:23:59,015 INFO Configuration:647 - processing foreign key constraints
18:23:59,015 DEBUG Configuration:657 - resolving reference to class: test.dao.hibernate.HibernateFolder
18:23:59,015 DEBUG Configuration:657 - resolving reference to class: test.dao.hibernate.HibernateFolder
18:23:59,015 DEBUG Configuration:657 - resolving reference to class: test.dao.hibernate.HibernateContent
18:23:59,125 INFO Dialect:82 - Using dialect: net.sf.hibernate.dialect.SQLServerDialect
18:23:59,125 INFO SettingsFactory:62 - Use outer join fetching: true
18:23:59,140 INFO DBCPConnectionProvider:56 - DBCP using driver: net.sourceforge.jtds.jdbc.Driver at URL: jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor
18:23:59,140 INFO DBCPConnectionProvider:57 - Connection properties: {user=sa, password=test}
18:23:59,171 INFO DBCPConnectionProvider:94 - DBCP prepared statement pooling enabled
18:23:59,187 INFO TransactionFactoryFactory:31 - Transaction strategy: net.sf.hibernate.transaction.JTATransactionFactory
18:23:59,187 INFO NamingHelper:26 - JNDI InitialContext properties:{}
18:23:59,203 INFO TransactionManagerLookupFactory:38 - instantiating TransactionManagerLookup: net.sf.hibernate.transaction.JOTMTransactionManagerLookup
18:23:59,203 INFO TransactionManagerLookupFactory:42 - instantiated TransactionManagerLookup
18:23:59,203 INFO TransactionManagerLookupFactory:38 - instantiating TransactionManagerLookup: net.sf.hibernate.transaction.JOTMTransactionManagerLookup
18:23:59,203 INFO TransactionManagerLookupFactory:42 - instantiated TransactionManagerLookup
18:23:59,421 INFO SettingsFactory:102 - Use scrollable result sets: true
18:23:59,421 INFO SettingsFactory:105 - Use JDBC3 getGeneratedKeys(): true
18:23:59,421 INFO SettingsFactory:108 - Optimize cache for minimal puts: false
18:23:59,421 INFO SettingsFactory:114 - echoing all SQL to stdout
18:23:59,421 INFO SettingsFactory:117 - Query language substitutions: {no='N', true=1, yes='Y', false=0}
18:23:59,421 INFO SettingsFactory:128 - cache provider: net.sf.ehcache.hibernate.Provider
18:23:59,437 INFO Configuration:1093 - instantiating and configuring caches
18:23:59,593 INFO SessionFactoryImpl:119 - building session factory
18:23:59,593 DEBUG SessionFactoryImpl:125 - instantiating session factory with properties: {java.vendor=Sun Microsystems Inc., show_sql=true, hibernate.connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, hibernate.dbcp.ps.maxWait=120000, os.name=Windows XP, sun.boot.class.path=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xalan.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xercesImpl.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed\xml-apis.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\rt.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\i18n.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\sunrsasign.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jsse.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\jce.jar;C:\Program Files\j2sdk1.4.2_03\jre\lib\charsets.jar;C:\Program Files\j2sdk1.4.2_03\jre\classes, rmi.server.port=0, hibernate.dbcp.maxWait=120000, sun.java2d.fontpath=, java.vm.specification.vendor=Sun Microsystems Inc., java.runtime.version=1.4.2_03-b02, user.name=Mark, hibernate.dbcp.ps.maxIdle=10, connection.driver_class=net.sourceforge.jtds.jdbc.Driver, hibernate.dbcp.maxActive=100, hibernate.dbcp.maxIdle=10, user.language=en, sun.boot.library.path=C:\Program Files\j2sdk1.4.2_03\jre\bin, dialect=net.sf.hibernate.dialect.SQLServerDialect, java.version=1.4.2_03, user.timezone=Europe/London, dbcp.ps.whenExhaustedAction=1, sun.arch.data.model=32, java.endorsed.dirs=C:\Program Files\j2sdk1.4.2_03\jre\lib\endorsed, sun.cpu.isalist=pentium i486 i386, file.encoding.pkg=sun.io, file.separator=\, java.specification.name=Java Platform API Specification, hibernate.cglib.use_reflection_optimizer=true, java.class.version=48.0, user.country=GB, connection.url=jdbc:jtds:sqlserver://localhost/test;SelectMethod=cursor, java.home=C:\Program Files\j2sdk1.4.2_03\jre, hibernate.dbcp.whenExhaustedAction=1, java.vm.info=mixed mode, hibernate.dbcp.ps.whenExhaustedAction=1, os.version=5.1, transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, hibernate.transaction.factory_class=net.sf.hibernate.transaction.JTATransactionFactory, path.separator=;, connection.password=test, java.vm.version=1.4.2_03-b02, java.util.prefs.PreferencesFactory=java.util.prefs.WindowsPreferencesFactory, hibernate.connection.password=test, user.variant=, java.awt.printerjob=sun.awt.windows.WPrinterJob, sun.io.unicode.encoding=UnicodeLittle, awt.toolkit=sun.awt.windows.WToolkit, hibernate.connection.username=sa, transaction.manager_lookup_class=net.sf.hibernate.transaction.JOTMTransactionManagerLookup, dbcp.maxWait=120000, query.substitutions=true 1, false 0, yes 'Y', no 'N', dbcp.maxActive=100, user.home=C:\Documents and Settings\Mark, hibernate.query.substitutions=true 1, false 0, yes 'Y', no 'N', java.specification.vendor=Sun Microsystems Inc., hibernate.dbcp.ps.maxActive=100, java.library.path=C:\Program Files\j2sdk1.4.2_03\bin;.;C:\WINDOWS\System32;C:\WINDOWS;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\Program Files\j2sdk1.4.2_03\bin;C:\Program Files\jikes-1.21\bin;C:\Program Files\Unrar;C:\Program Files\apache-ant-1.6.1\bin;C:\Program Files\Interact Commerce\SalesLogix\Common Files;C:\Program Files\Microsoft SQL Server\80\Tools\BINN;C:\Program Files\Microsoft SQL Server\80\Tools\Binn\;C:\Program Files\cygwin\bin;C:\Program Files\aspectj1.2\bin;C:\Program Files\Subversion\bin;C:\Documents and Settings\Mark\My Documents\apps\java\maven-1.0-rc2\bin, java.vendor.url=http://java.sun.com/, hibernate.connection.driver_class=net.sourceforge.jtds.jdbc.Driver, connection.username=sa, java.vm.vendor=Sun Microsystems Inc., hibernate.dialect=net.sf.hibernate.dialect.SQLServerDialect, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, java.class.path=C:\Documents and Settings\Mark\My Documents\projects\work\test\target\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\target\test-classes;\test\classes;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-collections-2.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\cglib-full-2.0.1.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\commons-logging-1.0.3.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\log4j.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\dom4j-1.4.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\ehcache-0.7.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\hibernate2.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\jdbc2_0-stdext.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\hibernate\odmg-3.0.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\jdbc\postgres-jdbc.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\picocontainer\picocontainer-1.0-beta-5.jar;C:\Documents and Settings\Mark\My Documents\projects\work\test\lib\common\jta.jar;C:\Documents and Settings\Mark\My Documents\pro

Hm, what particularly strikes me is the

18:22:45,890 DEBUG jta:416 - number of enlisted=0

Where does Hibernate retrieve JDBC connections from in your setup? Probably JOTM is not managing them?

Hmm, phpBB doesn't seem to like big posts ;)

The full log's here: http://www.iizuka.co.uk/temp/log.txt

Hibernate's configured to use DBCP to obtain JDBC connections - does JOTM need to manage the connections in the Hibernate JTA model then?

Mark

Yes, I would strongly suspect the Transaction Manager has to manage all your transactional resources. I have zero experience with JOTM however, so I can't really tell you how to enlist your resources with it though. - There are some examples here http://jotm.objectweb.org/current/jotm/examples/jdbc/, probably you'd have to write your own ConnectionProvider or something to enlist the connections with JOTM.

Thanks, I was just looking at that example & that seems to be where I must be going wrong. I'll have a play with integrating XAPool into JOTM and hopefully see some data in the database!

Cheers for your help,

Mark