Hibernate version:3.2
DB used:hsqldb v1.8

Hi,

I've got a problem when trying to insert a record into my database. The insert itself seems to work fine (no warnings/errors) in the console logs when I run the below code, and I can even see where hibernate has generated my new Track_ID number (for index column in db).
However when I check the actual db once the insert has allegedly been flushed and committed the new row does not appear there?????

Below is initial stuff that I hope will let someone solve my problem, if there 's something else somebody wants to see, let me know and I'll add to the post.

Java code (simple main method containing the following) to do the actual insert (called from an ant task running under eclipse) :-

public static void main(String args[]) throws Exception {
Configuration config = new Configuration();

config.addClass(Track.class);

SessionFactory sessionFactory = config.buildSessionFactory();

Session session = sessionFactory.openSession();
Transaction tx = null;
try {
// Create some data and persist it
tx = session.beginTransaction();

Track track = new Track("Russian Trance",
"vol2/album610/track02.mp3",
Time.valueOf("00:03:30"), new Date(),
(short)7);

System.out.println("**************\nTrack in memory is : "+track.toString()+"\n**************");

session.save(track);
tx.commit();
System.out.println("***********COMMITED *************");
} catch (Exception e) {
if (tx != null) {
e.printStackTrace();
// Something went wrong; discard all partial changes
tx.rollback();
System.out.println("***********ROLLBACK *************");
System.out.println("EXCEPTION :-");
e.printStackTrace();
}
throw e;
} finally {
session.close();
}
sessionFactory.close();
}

The log output that comes out of running above (anything with "*****" are my system.out debug statements, see code above. the reason it generates track id 101 is because I manually inserted a record id of 100 to make sure that code was generating correct id's) :-

Buildfile: D:\Dev\Java\EclipseProjects\Hibernate\build.xml
prepare:
compile:
ctest:
[java] 01:28:40,440 INFO Environment:514 - Hibernate 3.2.5
[java] 01:28:40,448 INFO Environment:532 - loaded properties from resource hibernate.properties: {hibernate.connection.username=sa, hibernate.connection.password=****, hibernate.dialect=org.hibernate.dialect.HSQLDialect, hibernate.connection.url=jdbc:hsqldb:file:data/music, hibernate.bytecode.use_reflection_optimizer=false, hibernate.connection.driver_class=org.hsqldb.jdbcDriver}
[java] 01:28:40,450 INFO Environment:681 - Bytecode provider name : cglib
[java] 01:28:40,455 INFO Environment:598 - using JDK 1.4 java.sql.Timestamp handling
[java] 01:28:40,538 INFO Configuration:585 - Reading mappings from resource: com/oreilly/hh/Track.hbm.xml
[java] 01:28:40,539 INFO Configuration:530 - Reading mappings from resource: com/oreilly/hh/Track.hbm.xml
[java] 01:28:40,780 DEBUG DTDEntityResolver:38 - trying to resolve system-id [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd]
[java] 01:28:40,780 DEBUG DTDEntityResolver:40 - recognized hibernate namespace; attempting to resolve on classpath under org/hibernate/
[java] 01:28:40,783 DEBUG DTDEntityResolver:50 - located [http://hibernate.sourceforge.net/hibernate-mapping-3.0.dtd] in classpath
[java] 01:28:40,933 INFO HbmBinder:300 - Mapping class: com.oreilly.hh.Track -> TRACK
[java] 01:28:40,941 DEBUG HbmBinder:1270 - Mapped property: id -> TRACK_ID
[java] 01:28:40,951 DEBUG HbmBinder:1270 - Mapped property: title -> title
[java] 01:28:40,952 DEBUG HbmBinder:1270 - Mapped property: filePath -> filePath
[java] 01:28:40,952 DEBUG HbmBinder:1270 - Mapped property: playTime -> playTime
[java] 01:28:40,953 DEBUG HbmBinder:1270 - Mapped property: added -> added
[java] 01:28:40,954 DEBUG HbmBinder:1270 - Mapped property: volume -> volume
[java] 01:28:40,955 DEBUG Configuration:1285 - Preparing to build session factory with filters : {}
[java] 01:28:40,955 DEBUG Configuration:1120 - processing extends queue
[java] 01:28:40,956 DEBUG Configuration:1124 - processing collection mappings
[java] 01:28:40,956 DEBUG Configuration:1135 - processing native query and ResultSetMapping mappings
[java] 01:28:40,956 DEBUG Configuration:1143 - processing association property references
[java] 01:28:40,956 DEBUG Configuration:1165 - processing foreign key constraints
[java] 01:28:41,038 INFO DriverManagerConnectionProvider:41 - Using Hibernate built-in connection pool (not for production use!)
[java] 01:28:41,039 INFO DriverManagerConnectionProvider:42 - Hibernate connection pool size: 20
[java] 01:28:41,039 INFO DriverManagerConnectionProvider:45 - autocommit mode: false
[java] 01:28:41,048 INFO DriverManagerConnectionProvider:80 - using driver: org.hsqldb.jdbcDriver at URL: jdbc:hsqldb:file:data/music
[java] 01:28:41,049 INFO DriverManagerConnectionProvider:83 - connection properties: {user=sa, password=}
[java] 01:28:41,049 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
[java] 01:28:41,049 DEBUG DriverManagerConnectionProvider:109 - opening new JDBC connection
[java] 01:28:41,387 DEBUG DriverManagerConnectionProvider:115 - created connection to: jdbc:hsqldb:file:data/music, Isolation Level: 0
[java] 01:28:41,415 INFO SettingsFactory:89 - RDBMS: HSQL Database Engine, version: 1.8.0
[java] 01:28:41,415 INFO SettingsFactory:90 - JDBC driver: HSQL Database Engine Driver, version: 1.8.0
[java] 01:28:41,416 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
[java] 01:28:41,444 INFO Dialect:152 - Using dialect: org.hibernate.dialect.HSQLDialect
[java] 01:28:41,451 INFO TransactionFactoryFactory:31 - Using default transaction strategy (direct JDBC transactions)
[java] 01:28:41,454 INFO TransactionManagerLookupFactory:33 - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
[java] 01:28:41,454 INFO SettingsFactory:143 - Automatic flush during beforeCompletion(): disabled
[java] 01:28:41,454 INFO SettingsFactory:147 - Automatic session close at end of transaction: disabled
[java] 01:28:41,454 INFO SettingsFactory:154 - JDBC batch size: 15
[java] 01:28:41,457 INFO SettingsFactory:157 - JDBC batch updates for versioned data: disabled
[java] 01:28:41,459 INFO SettingsFactory:162 - Scrollable result sets: enabled
[java] 01:28:41,461 DEBUG SettingsFactory:166 - Wrap result sets: disabled
[java] 01:28:41,462 INFO SettingsFactory:170 - JDBC3 getGeneratedKeys(): disabled
[java] 01:28:41,462 INFO SettingsFactory:178 - Connection release mode: auto
[java] 01:28:41,464 INFO SettingsFactory:205 - Default batch fetch size: 1
[java] 01:28:41,464 INFO SettingsFactory:209 - Generate SQL with comments: disabled
[java] 01:28:41,464 INFO SettingsFactory:213 - Order SQL updates by primary key: disabled
[java] 01:28:41,464 INFO SettingsFactory:217 - Order SQL inserts for batching: disabled
[java] 01:28:41,465 INFO SettingsFactory:386 - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
[java] 01:28:41,467 INFO ASTQueryTranslatorFactory:24 - Using ASTQueryTranslatorFactory
[java] 01:28:41,468 INFO SettingsFactory:225 - Query language substitutions: {}
[java] 01:28:41,468 INFO SettingsFactory:230 - JPA-QL strict compliance: disabled
[java] 01:28:41,468 INFO SettingsFactory:235 - Second-level cache: enabled
[java] 01:28:41,468 INFO SettingsFactory:239 - Query cache: disabled
[java] 01:28:41,469 INFO SettingsFactory:373 - Cache provider: org.hibernate.cache.NoCacheProvider
[java] 01:28:41,469 INFO SettingsFactory:254 - Optimize cache for minimal puts: disabled
[java] 01:28:41,469 INFO SettingsFactory:263 - Structured second-level cache entries: disabled
[java] 01:28:41,471 DEBUG SQLExceptionConverterFactory:52 - Using dialect defined converter
[java] 01:28:41,476 INFO SettingsFactory:290 - Statistics: disabled
[java] 01:28:41,476 INFO SettingsFactory:294 - Deleted entity synthetic identifier rollback: disabled
[java] 01:28:41,476 INFO SettingsFactory:309 - Default entity-mode: pojo
[java] 01:28:41,477 INFO SettingsFactory:313 - Named query checking : enabled
[java] 01:28:41,559 INFO SessionFactoryImpl:161 - building session factory
[java] 01:28:41,560 DEBUG SessionFactoryImpl:173 - Session factory constructed with filter configurations : {}
[java] 01:28:41,560 DEBUG SessionFactoryImpl:177 - instantiating session factory with properties: {java.runtime.name=Java(TM) SE Runtime Environment, hibernate.connection.password=, sun.boot.library.path=C:\Sun\SDK\jdk\jre\bin, java.vm.version=1.6.0_02-b05, hibernate.connection.username=sa, 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=GB, sun.java.launcher=SUN_STANDARD, sun.os.patch.level=, java.vm.specification.name=Java Virtual Machine Specification, user.dir=D:\Dev\Java\EclipseProjects\Hibernate, java.runtime.version=1.6.0_02-b05, java.awt.graphicsenv=sun.awt.Win32GraphicsEnvironment, java.endorsed.dirs=C:\Sun\SDK\jdk\jre\lib\endorsed, os.arch=x86, java.io.tmpdir=C:\Users\steve\AppData\Local\Temp\, line.separator=
[java] , java.vm.specification.vendor=Sun Microsystems Inc., user.variant=, os.name=Windows Vista, sun.jnu.encoding=Cp1252, java.library.path=C:\Sun\SDK\jdk\jre\bin;.;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Sun\SDK\jdk\bin\..\jre\bin\client;C:\Sun\SDK\jdk\bin\..\jre\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Program Files\Common Files\Roxio Shared\DLLShared\;C:\Program Files\Common Files\Roxio Shared\DLLShared\;C:\Program Files\Common Files\Roxio Shared\9.0\DLLShared\;C:\Sun\SDK\jdk\bin;C:\apache-tomcat-6.0.14\lib;C:\Program Files\QuickTime\QTSystem\;C:\Sun\SDK\bin;C:\Program Files\Java\bin;C:\Sun\SDK\bin, java.specification.name=Java Platform API Specification, java.class.version=50.0, sun.management.compiler=HotSpot Client Compiler, os.version=6.0, user.home=C:\Users\steve, user.timezone=Pacific/Guadalcanal, java.awt.printerjob=sun.awt.windows.WPrinterJob, file.encoding=Cp1252, java.specification.version=1.6, hibernate.connection.driver_class=org.hsqldb.jdbcDriver, user.name=steve, java.class.path=D:\Dev\Java\EclipseProjects\Hibernate\classes;D:\Dev\Java\EclipseProjects\Hibernate\lib\ant-1.6.5.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\ant-antlr.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\ant-junit-1.6.5.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\ant-launcher.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\antlr-2.7.6.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\asm-attrs.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\asm.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\bsh-2.0b1.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\bsh-core-2.0b4.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\cglib-2.1.3.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\commons-collections-2.1.1.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\commons-logging-1.0.4.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\dom4j-1.6.1.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\ehcache-1.2.3.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\freemarker.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\hibernate-tools.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\hibernate3.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\hsqldb.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\jta.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\jtidy-r8-20060801.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\log4j-1.2.11.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\xerces-2.6.2.jar;D:\Dev\Java\EclipseProjects\Hibernate\lib\xml-apis.jar;D:\Hibernate\hibernate-3.2\lib\ant-1.6.5.jar;D:\Hibernate\hibernate-3.2\lib\ant-antlr-1.6.5.jar;D:\Hibernate\hibernate-3.2\lib\ant-junit-1.6.5.jar;D:\Hibernate\hibernate-3.2\lib\ant-launcher-1.6.5.jar;D:\Hibernate\hibernate-3.2\lib\ant-swing-1.6.5.jar;D:\Hibernate\hibernate-3.2\lib\antlr-2.7.6.jar;D:\Hibernate\hibernate-3.2\lib\asm-attrs.jar;D:\Hibernate\hibernate-3.2\lib\asm.jar;D:\Hibernate\hibernate-3.2\lib\c3p0-0.9.1.jar;D:\Hibernate\hibernate-3.2\lib\cglib-2.1.3.jar;D:\Hibernate\hibernate-3.2\lib\checkstyle-all.jar;D:\Hibernate\hibernate-3.2\lib\cleanimports.jar;D:\Hibernate\hibernate-3.2\lib\commons-collections-2.1.1.jar;D:\Hibernate\hibernate-3.2\lib\commons-logging-1.0.4.jar;D:\Hibernate\hibernate-3.2\lib\concurrent-1.3.2.jar;D:\Hibernate\hibernate-3.2\lib\connector.jar;D:\Hibernate\hibernate-3.2\lib\dom4j-1.6.1.jar;D:\Hibernate\hibernate-3.2\lib\ehcache-1.2.3.jar;D:\Hibernate\hibernate-3.2\lib\jaas.jar;D:\Hibernate\hibernate-3.2\lib\jacc-1_0-fr.jar;D:\Hibernate\hibernate-3.2\lib\javassist.jar;D:\Hibernate\hibernate-3.2\lib\jaxen-1.1-beta-7.jar;D:\Hibernate\hibernate-3.2\lib\jboss-cache.jar;D:\Hibernate\hibernate-3.2\lib\jboss-common.jar;D:\Hibernate\hibernate-3.2\lib\jboss-jmx.jar;D:\Hibernate\hibernate-3.2\lib\jboss-system.jar;D:\Hibernate\hibernate-3.2\lib\jdbc2_0-stdext.jar;D:\Hibernate\hibernate-3.2\lib\jgroups-2.2.8.jar;D:\Hibernate\hibernate-3.2\lib\jta.jar;D:\Hibernate\hibernate-3.2\lib\junit-3.8.1.jar;D:\Hibernate\hibernate-3.2\lib\log4j-1.2.11.jar;D:\Hibernate\hibernate-3.2\lib\oscache-2.1.jar;D:\Hibernate\hibernate-3.2\lib\proxool-0.8.3.jar;D:\Hibernate\hibernate-3.2\lib\swarmcache-1.0rc2.jar;D:\Hibernate\hibernate-3.2\lib\syndiag2.jar;D:\Hibernate\hibernate-3.2\lib\versioncheck.jar;D:\Hibernate\hibernate-3.2\lib\xerces-2.6.2.jar;D:\Hibernate\hibernate-3.2\lib\xml-apis.jar, hibernate.bytecode.use_reflection_optimizer=false, java.vm.specification.version=1.0, sun.arch.data.model=32, java.home=C:\Sun\SDK\jdk\jre, hibernate.connection.url=jdbc:hsqldb:file:data/music, hibernate.dialect=org.hibernate.dialect.HSQLDialect, java.specification.vendor=Sun Microsystems Inc., user.language=en, awt.toolkit=sun.awt.windows.WToolkit, java.vm.info=mixed mode, java.version=1.6.0_02, java.ext.dirs=C:\Sun\SDK\jdk\jre\lib\ext;C:\Windows\Sun\Java\lib\ext, sun.boot.class.path=C:\Sun\SDK\jdk\jre\lib\resources.jar;C:\Sun\SDK\jdk\jre\lib\rt.jar;C:\Sun\SDK\jdk\jre\lib\sunrsasign.jar;C:\Sun\SDK\jdk\jre\lib\jsse.jar;C:\Sun\SDK\jdk\jre\lib\jce.jar;C:\Sun\SDK\jdk\jre\lib\charsets.jar;C:\Sun\SDK\jdk\jre\classes, java.vendor=Sun Microsystems Inc., file.separator=\, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.cpu.endian=little, sun.io.unicode.encoding=UnicodeLittle, sun.desktop=windows, sun.cpu.isalist=}
[java] 01:28:41,863 DEBUG AbstractEntityPersister:2738 - Static SQL for entity: com.oreilly.hh.Track
[java] 01:28:41,863 DEBUG AbstractEntityPersister:2743 - Version select: select TRACK_ID from TRACK where TRACK_ID =?
[java] 01:28:41,864 DEBUG AbstractEntityPersister:2746 - Snapshot select: select track_.TRACK_ID, track_.title as title0_, track_.filePath as filePath0_, track_.playTime as playTime0_, track_.added as added0_, track_.volume as volume0_ from TRACK track_ where track_.TRACK_ID=?
[java] 01:28:41,864 DEBUG AbstractEntityPersister:2749 - Insert 0: insert into TRACK (title, filePath, playTime, added, volume, TRACK_ID) values (?, ?, ?, ?, ?, ?)
[java] 01:28:41,864 DEBUG AbstractEntityPersister:2750 - Update 0: update TRACK set title=?, filePath=?, playTime=?, added=?, volume=? where TRACK_ID=?
[java] 01:28:41,867 DEBUG AbstractEntityPersister:2751 - Delete 0: delete from TRACK where TRACK_ID=?
[java] 01:28:41,867 DEBUG AbstractEntityPersister:2755 - Identity insert: insert into TRACK (TRACK_ID, title, filePath, playTime, added, volume) values (null, ?, ?, ?, ?, ?)
[java] 01:28:41,894 DEBUG EntityLoader:79 - Static select for entity com.oreilly.hh.Track: select track0_.TRACK_ID as TRACK1_0_0_, track0_.title as title0_0_, track0_.filePath as filePath0_0_, track0_.playTime as playTime0_0_, track0_.added as added0_0_, track0_.volume as volume0_0_ from TRACK track0_ where track0_.TRACK_ID=?
[java] 01:28:41,895 DEBUG EntityLoader:79 - Static select for entity com.oreilly.hh.Track: select track0_.TRACK_ID as TRACK1_0_0_, track0_.title as title0_0_, track0_.filePath as filePath0_0_, track0_.playTime as playTime0_0_, track0_.added as added0_0_, track0_.volume as volume0_0_ from TRACK track0_ where track0_.TRACK_ID=?
[java] 01:28:41,896 DEBUG EntityLoader:79 - Static select for entity com.oreilly.hh.Track: select track0_.TRACK_ID as TRACK1_0_0_, track0_.title as title0_0_, track0_.filePath as filePath0_0_, track0_.playTime as playTime0_0_, track0_.added as added0_0_, track0_.volume as volume0_0_ from TRACK track0_ where track0_.TRACK_ID=?
[java] 01:28:41,897 DEBUG EntityLoader:79 - Static select for entity com.oreilly.hh.Track: select track0_.TRACK_ID as TRACK1_0_0_, track0_.title as title0_0_, track0_.filePath as filePath0_0_, track0_.playTime as playTime0_0_, track0_.added as added0_0_, track0_.volume as volume0_0_ from TRACK track0_ where track0_.TRACK_ID=?
[java] 01:28:41,898 DEBUG EntityLoader:79 - Static select for entity com.oreilly.hh.Track: select track0_.TRACK_ID as TRACK1_0_0_, track0_.title as title0_0_, track0_.filePath as filePath0_0_, track0_.playTime as playTime0_0_, track0_.added as added0_0_, track0_.volume as volume0_0_ from TRACK track0_ where track0_.TRACK_ID=?
[java] 01:28:41,908 DEBUG EntityLoader:34 - Static select for action ACTION_MERGE on entity com.oreilly.hh.Track: select track0_.TRACK_ID as TRACK1_0_0_, track0_.title as title0_0_, track0_.filePath as filePath0_0_, track0_.playTime as playTime0_0_, track0_.added as added0_0_, track0_.volume as volume0_0_ from TRACK track0_ where track0_.TRACK_ID=?
[java] 01:28:41,909 DEBUG EntityLoader:34 - Static select for action ACTION_REFRESH on entity com.oreilly.hh.Track: select track0_.TRACK_ID as TRACK1_0_0_, track0_.title as title0_0_, track0_.filePath as filePath0_0_, track0_.playTime as playTime0_0_, track0_.added as added0_0_, track0_.volume as volume0_0_ from TRACK track0_ where track0_.TRACK_ID=?
[java] 01:28:41,918 DEBUG SessionFactoryObjectFactory:39 - initializing class SessionFactoryObjectFactory
[java] 01:28:41,922 DEBUG SessionFactoryObjectFactory:76 - registered: 4028801818b7fe070118b7fe09380000 (unnamed)
[java] 01:28:41,922 INFO SessionFactoryObjectFactory:82 - Not binding factory to JNDI, no JNDI name configured
[java] 01:28:41,924 DEBUG SessionFactoryImpl:308 - instantiated session factory
[java] 01:28:41,924 DEBUG SessionFactoryImpl:392 - Checking 0 named HQL queries
[java] 01:28:41,924 DEBUG SessionFactoryImpl:412 - Checking 0 named SQL queries
[java] 01:28:41,978 DEBUG SessionImpl:220 - opened session at timestamp: 12056777219
[java] 01:28:41,982 DEBUG JDBCTransaction:54 - begin
[java] 01:28:41,982 DEBUG ConnectionManager:421 - opening JDBC connection
[java] 01:28:41,982 DEBUG DriverManagerConnectionProvider:93 - total checked-out connections: 0
[java] 01:28:41,982 DEBUG DriverManagerConnectionProvider:99 - using pooled JDBC connection, pool size: 0
[java] 01:28:41,983 DEBUG JDBCTransaction:59 - current autocommit status: false
[java] 01:28:41,983 DEBUG JDBCContext:210 - after transaction begin
[java] **************
[java] Track in memory is : id:0; title:Russian Trance; path:vol2/album610/track02.mp3; volume7
[java] **************
[java] 01:28:41,991 DEBUG DefaultSaveOrUpdateEventListener:158 - saving transient instance
[java] 01:28:41,993 DEBUG AbstractSaveEventListener:153 - saving [com.oreilly.hh.Track#<null>]
[java] 01:28:41,993 DEBUG AbstractSaveEventListener:244 - executing insertions
[java] 01:28:42,011 DEBUG AbstractSaveEventListener:297 - executing identity-insert immediately
[java] 01:28:42,013 DEBUG AbstractEntityPersister:2144 - Inserting entity: com.oreilly.hh.Track (native id)
[java] 01:28:42,015 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[java] 01:28:42,016 DEBUG SQL:401 - insert into TRACK (TRACK_ID, title, filePath, playTime, added, volume) values (null, ?, ?, ?, ?, ?)
[java] 01:28:42,017 DEBUG AbstractBatcher:484 - preparing statement
[java] 01:28:42,024 DEBUG AbstractEntityPersister:1992 - Dehydrating entity: [com.oreilly.hh.Track#<null>]
[java] 01:28:42,030 DEBUG AbstractBatcher:374 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[java] 01:28:42,032 DEBUG AbstractBatcher:533 - closing statement
[java] 01:28:42,033 DEBUG AbstractBatcher:366 - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
[java] 01:28:42,034 DEBUG SQL:401 - call identity()
[java] 01:28:42,034 DEBUG AbstractBatcher:484 - preparing statement
[java] 01:28:42,034 DEBUG IdentifierGeneratorFactory:37 - Natively generated identity: 101
[java] 01:28:42,035 DEBUG AbstractBatcher:374 - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
[java] 01:28:42,035 DEBUG AbstractBatcher:533 - closing statement
[java] 01:28:42,039 DEBUG JDBCTransaction:103 - commit
[java] 01:28:42,040 DEBUG SessionImpl:337 - automatically flushing session
[java] 01:28:42,040 DEBUG AbstractFlushingEventListener:58 - flushing session
[java] 01:28:42,041 DEBUG AbstractFlushingEventListener:111 - processing flush-time cascades
[java] 01:28:42,042 DEBUG AbstractFlushingEventListener:154 - dirty checking collections
[java] 01:28:42,042 DEBUG AbstractFlushingEventListener:171 - Flushing entities and processing referenced collections
[java] 01:28:42,047 DEBUG AbstractFlushingEventListener:210 - Processing unreferenced collections
[java] 01:28:42,047 DEBUG AbstractFlushingEventListener:224 - Scheduling collection removes/(re)creates/updates
[java] 01:28:42,047 DEBUG AbstractFlushingEventListener:85 - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
[java] 01:28:42,047 DEBUG AbstractFlushingEventListener:91 - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[java] 01:28:42,049 DEBUG Printer:83 - listing entities:
[java] 01:28:42,050 DEBUG Printer:90 - com.oreilly.hh.Track{id=101, title=Russian Trance, playTime=00:03:30, added=17 March 2008, filePath=vol2/album610/track02.mp3, volume=7}
[java] 01:28:42,050 DEBUG AbstractFlushingEventListener:290 - executing flush
[java] 01:28:42,052 DEBUG ConnectionManager:469 - registering flush begin
[java] 01:28:42,052 DEBUG ConnectionManager:478 - registering flush end
[java] 01:28:42,052 DEBUG AbstractFlushingEventListener:321 - post flush
[java] 01:28:42,052 DEBUG JDBCContext:201 - before transaction completion
[java] 01:28:42,052 DEBUG SessionImpl:393 - before transaction completion
[java] 01:28:42,053 DEBUG JDBCTransaction:116 - committed JDBC Connection
[java] 01:28:42,053 DEBUG JDBCContext:215 - after transaction completion
[java] 01:28:42,053 DEBUG ConnectionManager:404 - aggressively releasing JDBC connection
[java] 01:28:42,053 DEBUG ConnectionManager:441 - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
[java] 01:28:42,055 DEBUG DriverManagerConnectionProvider:129 - returning connection to pool, pool size: 1
[java] 01:28:42,055 DEBUG SessionImpl:422 - after transaction completion
[java] ***********COMMITED *************
[java] 01:28:42,055 DEBUG SessionImpl:273 - closing session
[java] 01:28:42,055 DEBUG ConnectionManager:375 - connection already null in cleanup : no action
[java] 01:28:42,058 INFO SessionFactoryImpl:769 - closing
[java] 01:28:42,058 INFO DriverManagerConnectionProvider:147 - cleaning up connection pool: jdbc:hsqldb:file:data/music
BUILD SUCCESSFUL
Total time: 2 seconds

My hibernate.properties file (located at root of src directory and copied over to output src dir when ant does the prepare task for the project) :-

hibernate.dialect=org.hibernate.dialect.HSQLDialect
hibernate.connection.driver_class=org.hsqldb.jdbcDriver
hibernate.connection.url=jdbc:hsqldb:file:data/music
hibernate.connection.username=sa
hibernate.connection.password=

Any help on this one greatly appreciated as it's driving me up the wall!!!!

Ran a couple more things to try and find out whats going on but to no avail, its still stumping me??????!!!!!!!

* used the wasCommitted() method of the session to check what it reports and getting 'true' value back which would indicate the inserts have been committed but again checking the db later shows no row inserted.

* Manually added a row to db for testing. If i use hibernate to load the manually inputted row it successfully pulls it back and I get the expected Track object

* Tried changing the flush method on the session to ALWAYS via calling session.setFlushMode(FlushMode.ALWAYS);
but as with everything else it makes no difference

PLEASE can someone help as this is driving me crazy. I'd imagine its some stupid little thing that I've overlooked but I can't for the life of me figure out what at the moment, am losing moooooocho hair over this one!!!!!!!

hmmmmmmmmmmmmmmmmm............. I appear to have solved the problem, but how I solved it doesn't make much sense!!

While trying to view the logs from the database while the transaction was in progress I threw in a Thread.sleep(20*1000) just after the tx.commit() statement and for some reason this caused the transaction to be permanently committed to the db!

I've played around with the delay I need to use and for some reason it has to be no less than 19 seconds or the transaction doesn't seem to get committed.

So now my question has changed to :-
Anybody have any idea why this delay seems to work?????

Thanks for any replies

Was posting this problem to another forum and someone there found the solution! It was the default of the WRITE_DELAY setting in HSQL db that was causing the problem, it's set at 20 seconds. Turning the WRITE_DELAY function off in the db sorted the problem.

Because I'm running the db in a mode which means its only ever up when I run my application code, the db was never alive for more than 20 seconds thus the committed additions were never committed to file.

Cheers for no-ones help and thankyou to more helpful people on other forums. :)