Joined: Sat Oct 02, 2004 4:53 am Posts: 3
|
I have been playing with Hibernate's optimistic locking with versioning and I have found a certain behaviour and I would like to know whether this is Hibernate's expected behaviour.
I have written a small test program in which I am trying to simulate the following:
- User 1 queries database and gets a row back.
- User 1 alters the row
- User 1 waits some time for before updating the altered row.
Meanwhile before User 1 updates the database a second user comes along:
- User 2 queries database and gets the same row back.
- User 2 alters row
- User 2 updates the database with the row's new values.
My expectation was that User 1 gets a 'Stale data Exception' when they try and update the database. In fact, this is exactly what happens expcept in one case: when User 1 sets the row back to its original values. In this case no 'Stale Data Exception' is thown and the row has User 2's values.
I had a look at the log files and what I think may be happening is that in the case when the User 1 sets the row back to its original value the changes are seen as being 'dirty' and no updates on the database are made and hence no version conflicts are detected.
Is this the expected behaviour? I would have thought that optimistc locking a 'Stale Data Exception' should be thrown even in the case where a user sets the data back to its original values.
Hibernate 2.1.6
<?xml version='1.0' encoding='utf-8'?> <!DOCTYPE hibernate-configuration PUBLIC "-//Hibernate/Hibernate Configuration DTD 2.0//EN"
"http://hibernate.sourceforge.net/hibernate-configuration-2.0.dtd">
<hibernate-configuration>
<!-- a SessionFactory instance listed as /jndi/name --> <session-factory>
<!-- properties --> <property name="show_sql">true</property> <property name="dialect">net.sf.hibernate.dialect.PostgreSQLDialect</property> <property name="connection.driver_class">org.postgresql.Driver</property> <property name="connection.url">jdbc:postgresql://localhost/michael</property> <property name="connection.username">michael</property> <property name="connection.password">micjael</property> <property name="connection.pool_size">3</property> <property name="max_fetch_depth">1</property> <property name="jdbc.batch_size" >0</property> <property name="connection.isolation">2</property> <!-- <property name="transaction.factory_class"> net.sf.hibernate.transaction.JTATransactionFactory </property> <property name="jta.UserTransaction">java:comp/UserTransaction</property> -->
<!-- mapping files --> <mapping resource="domain/IntProperties.hbm.xml"/> </session-factory>
</hibernate-configuration>
<?xml version="1.0"?> <!DOCTYPE hibernate-mapping PUBLIC "-//Hibernate/Hibernate Mapping DTD 2.0//EN" "http://hibernate.sourceforge.net/hibernate-mapping-2.0.dtd">
<hibernate-mapping>
<class name="domain.IntProperties" table="int_properties" lazy="true" optimistic-lock="version" > <id name="id" type="long" column="id"> <generator class="native"/> </id> <version name="version" column="version" type="long" /> <property name="name" column="name" type="string"/> <property name="value" column="value" type="int"/> </class>
</hibernate-mapping>
package main;
import net.sf.hibernate.HibernateException; import net.sf.hibernate.Session;
import org.apache.log4j.Logger;
import util.HibernateUtil; import domain.*;
public class IntPropertiesMain { private static Logger log = Logger.getLogger(IntPropertiesMain.class);
private boolean updated;
public void readAndUpdate1() throws HibernateException { Session s = HibernateUtil.getSession(); HibernateUtil.beginTransaction(); int currentValue;
// My table on has one row in it, so I can use .uniqueResult() IntProperties p = (IntProperties) s.createQuery("from IntProperties").uniqueResult(); currentValue = p.getValue(); p.setValue(currentValue*2); // Un-comment this line to set to to its original value. //p.setValue(currentValue); synchronized (this) { while (updated == false) { try { log.info("Waiting for another thread to do update"); wait(); } catch (InterruptedException e) { log.error(e.getMessage(), e); } } s.save(p); HibernateUtil.commitTransaction(); s.close(); updated = false; notifyAll(); } }
public void readAndUpdate2() throws HibernateException { Session s = HibernateUtil.getSession(); HibernateUtil.beginTransaction(); // My table on has one row in it, so I can use .uniqueResult() IntProperties p = (IntProperties) s.createQuery("from IntProperties").uniqueResult(); int currentValue; currentValue = p.getValue(); p.setValue(currentValue*3);
synchronized (this) { s.save(p); HibernateUtil.commitTransaction(); s.close(); updated = true; notifyAll(); } }
public static void main(String[] args) throws Exception { final IntPropertiesMain pt = new IntPropertiesMain();
Runnable r1 = new Runnable() { public void run() { try { pt.readAndUpdate1(); } catch (HibernateException e) { log.error(e.getMessage(), e); e.printStackTrace(); } } };
Runnable r2 = new Runnable() { public void run() { try { pt.readAndUpdate2(); } catch (HibernateException e) { log.error(e.getMessage(), e); e.printStackTrace(); } } };
Thread t1 = new Thread(r1); t1.start(); log.debug("Waiting a few seconds to do 2nd update"); Thread.sleep(3*1000); Thread t2 = new Thread(r2); t2.start(); } }
Full stack trace of any exception that occurs: N/A
Postgres 7.3.2
Hibernate: select intpropert0_.id as id, intpropert0_.version as version, intpropert0_.name as name, intpropert0_.value as value from int_properties intpropert0_
Hibernate: select intpropert0_.id as id, intpropert0_.version as version, intpropert0_.name as name, intpropert0_.value as value from int_properties intpropert0_
Hibernate: update int_properties set version=?, name=?, value=? where id=? and version=?
[18:29:10,870] [DEBUG] [main.IntPropertiesMain] main .main () ==> Waiting a few seconds to do 2nd update
[18:29:10,947] [INFO ] [net.sf.hibernate.cfg.Environment] Thread-0 .<clinit> () ==> Hibernate 2.1.6
[18:29:10,948] [INFO ] [net.sf.hibernate.cfg.Environment] Thread-0 .<clinit> () ==> hibernate.properties not found
[18:29:10,953] [INFO ] [net.sf.hibernate.cfg.Environment] Thread-0 .<clinit> () ==> using CGLIB reflection optimizer
[18:29:10,963] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .configure () ==> configuring from resource: /hibernate.cfg.xml
[18:29:10,964] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .getConfigurationInputStream() ==> Configuration resource: /hibernate.cfg.xml
[18:29:11,040] [DEBUG] [net.sf.hibernate.util.DTDEntityResolver] Thread-0 .resolveEntity() ==> trying to locate http://hibernate.sourceforge.net/hibern ... on-2.0.dtd in classpath under net/sf/hibernate/
[18:29:11,041] [DEBUG] [net.sf.hibernate.util.DTDEntityResolver] Thread-0 .resolveEntity() ==> found http://hibernate.sourceforge.net/hibern ... on-2.0.dtd in classpath
[18:29:11,089] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> show_sql=true
[18:29:11,089] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> dialect=net.sf.hibernate.dialect.PostgreSQLDialect
[18:29:11,090] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> connection.driver_class=org.postgresql.Driver
[18:29:11,090] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> connection.url=jdbc:postgresql://localhost/michael
[18:29:11,091] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> connection.username=michael
[18:29:11,091] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> connection.password=micjael
[18:29:11,093] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> connection.pool_size=3
[18:29:11,094] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> max_fetch_depth=1
[18:29:11,094] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> jdbc.batch_size=0
[18:29:11,095] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .addProperties() ==> connection.isolation=2
[18:29:11,097] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .doConfigure() ==> null<-org.dom4j.tree.DefaultAttribute@1c0e45a [Attribute: name resource value "domain/IntProperties.hbm.xml"]
[18:29:11,097] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .addResource() ==> Mapping resource: domain/IntProperties.hbm.xml
[18:29:11,104] [DEBUG] [net.sf.hibernate.util.DTDEntityResolver] Thread-0 .resolveEntity() ==> trying to locate http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath under net/sf/hibernate/
[18:29:11,105] [DEBUG] [net.sf.hibernate.util.DTDEntityResolver] Thread-0 .resolveEntity() ==> found http://hibernate.sourceforge.net/hibern ... ng-2.0.dtd in classpath
[18:29:11,234] [INFO ] [net.sf.hibernate.cfg.Binder] Thread-0 .bindRootClass() ==> Mapping class: domain.IntProperties -> int_properties
[18:29:11,332] [DEBUG] [net.sf.hibernate.cfg.Binder] Thread-0 .bindProperty() ==> Mapped property: id -> id, type: long
[18:29:11,334] [DEBUG] [net.sf.hibernate.cfg.Binder] Thread-0 .bindProperty() ==> Mapped property: version -> version, type: long
[18:29:11,351] [DEBUG] [net.sf.hibernate.cfg.Binder] Thread-0 .bindProperty() ==> Mapped property: name -> name, type: string
[18:29:11,352] [DEBUG] [net.sf.hibernate.cfg.Binder] Thread-0 .bindProperty() ==> Mapped property: value -> value, type: integer
[18:29:11,353] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .doConfigure() ==> Configured SessionFactory: null
[18:29:11,353] [DEBUG] [net.sf.hibernate.cfg.Configuration] Thread-0 .doConfigure() ==> properties: {hibernate.connection.password=micjael, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=/usr/java/j2sdk1.4.2_03/jre/lib/i386, java.vm.version=1.4.2_03-b02, hibernate.connection.username=michael, 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.os.patch.level=unknown, hibernate.connection.isolation=2, java.vm.specification.name=Java Virtual Machine Specification, user.dir=/home/data/code/hibernate_query, java.runtime.version=1.4.2_03-b02, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.endorsed.dirs=/usr/java/j2sdk1.4.2_03/jre/lib/endorsed, os.arch=i386, java.io.tmpdir=/tmp, line.separator= , java.vm.specification.vendor=Sun Microsystems Inc., os.name=Linux, sun.java2d.fontpath=, log4j.configuration=file:log4j.xml, connection.isolation=2, java.library.path=/usr/java/j2sdk1.4.2_03/jre/lib/i386/client:/usr/java/j2sdk1.4.2_03/jre/lib/i386:/usr/java/j2sdk1.4.2_03/jre/../lib/i386, java.specification.name=Java Platform API Specification, java.class.version=48.0, hibernate.connection.pool_size=3, java.util.prefs.PreferencesFactory=java.util.prefs.FileSystemPreferencesFactory, os.version=2.4.20-8, connection.password=micjael, user.home=/home/michael, user.timezone=Australia/Sydney, connection.username=michael, java.awt.printerjob=sun.print.PSPrinterJob, file.encoding=ISO-8859-1, java.specification.version=1.4, hibernate.connection.driver_class=org.postgresql.Driver, show_sql=true, log4j.debug=true, user.name=michael, java.class.path=/home/data/code/hibernate_query/build/classes:/home/data/code/hibernate_query/lib/ant-1.5.3.jar:/home/data/code/hibernate_query/lib/ant-optional-1.5.3.jar:/home/data/code/hibernate_query/lib/c3p0-0.8.4.5.jar:/home/data/code/hibernate_query/lib/cglib-full-2.0.2.jar:/home/data/code/hibernate_query/lib/commons-collections-2.1.1.jar:/home/data/code/hibernate_query/lib/commons-dbcp-1.2.1.jar:/home/data/code/hibernate_query/lib/commons-lang-1.0.1.jar:/home/data/code/hibernate_query/lib/commons-logging-1.0.4.jar:/home/data/code/hibernate_query/lib/commons-pool-1.2.jar:/home/data/code/hibernate_query/lib/concurrent-1.3.3.jar:/home/data/code/hibernate_query/lib/connector.jar:/home/data/code/hibernate_query/lib/dom4j-1.4.jar:/home/data/code/hibernate_query/lib/ehcache-0.9.jar:/home/data/code/hibernate_query/lib/jaas.jar:/home/data/code/hibernate_query/lib/jboss-cache.jar:/home/data/code/hibernate_query/lib/jboss-common.jar:/home/data/code/hibernate_query/lib/jboss-jmx.jar:/home/data/code/hibernate_query/lib/jboss-system.jar:/home/data/code/hibernate_query/lib/jcs-1.0-dev.jar:/home/data/code/hibernate_query/lib/jdbc2_0-stdext.jar:/home/data/code/hibernate_query/lib/jgroups-2.2.3.jar:/home/data/code/hibernate_query/lib/jta.jar:/home/data/code/hibernate_query/lib/junit-3.8.1.jar:/home/data/code/hibernate_query/lib/log4j-1.2.8.jar:/home/data/code/hibernate_query/lib/odmg-3.0.jar:/home/data/code/hibernate_query/lib/oscache-2.0.jar:/home/data/code/hibernate_query/lib/proxool-0.8.3.jar:/home/data/code/hibernate_query/lib/swarmcache-1.0rc2.jar:/home/data/code/hibernate_query/lib/xalan-2.4.0.jar:/home/data/code/hibernate_query/lib/xerces-2.4.0.jar:/home/data/code/hibernate_query/lib/xml-apis.jar:/home/data/code/hibernate_query/lib/hibernate2.jar:/home/data/code/hibernate_query/lib/pg74.1jdbc3.jar, hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=/usr/java/j2sdk1.4.2_03/jre, sun.arch.data.model=32, jdbc.batch_size=0, hibernate.connection.url=jdbc:postgresql://localhost/michael, hibernate.dialect=net.sf.hibernate.dialect.PostgreSQLDialect, connection.pool_size=3, user.language=en, java.specification.vendor=Sun Microsystems Inc., hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.4.2_03, java.ext.dirs=/usr/java/j2sdk1.4.2_03/jre/lib/ext, sun.boot.class.path=/usr/java/j2sdk1.4.2_03/jre/lib/rt.jar:/usr/java/j2sdk1.4.2_03/jre/lib/i18n.jar:/usr/java/j2sdk1.4.2_03/jre/lib/sunrsasign.jar:/usr/java/j2sdk1.4.2_03/jre/lib/jsse.jar:/usr/java/j2sdk1.4.2_03/jre/lib/jce.jar:/usr/java/j2sdk1.4.2_03/jre/lib/charsets.jar:/usr/java/j2sdk1.4.2_03/jre/classes, java.vendor=Sun Microsystems Inc., hibernate.jdbc.batch_size=0, connection.driver_class=org.postgresql.Driver, file.separator=/, max_fetch_depth=1, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, hibernate.max_fetch_depth=1, connection.url=jdbc:postgresql://localhost/michael, dialect=net.sf.hibernate.dialect.PostgreSQLDialect, sun.cpu.isalist=}
[18:29:11,354] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .secondPassCompile() ==> processing one-to-many association mappings
[18:29:11,354] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .secondPassCompile() ==> processing one-to-one association property references
[18:29:11,355] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .secondPassCompile() ==> processing foreign key constraints
[18:29:11,385] [INFO ] [net.sf.hibernate.dialect.Dialect] Thread-0 .<init> () ==> Using dialect: net.sf.hibernate.dialect.PostgreSQLDialect
[18:29:11,387] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> Maximim outer join fetch depth: 1
[18:29:11,388] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> Use outer join fetching: true
[18:29:11,394] [INFO ] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .configure () ==> Using Hibernate built-in connection pool (not for production use!)
[18:29:11,395] [INFO ] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .configure () ==> Hibernate connection pool size: 3
[18:29:11,397] [INFO ] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .configure () ==> JDBC isolation level: READ_COMMITTED
[18:29:11,404] [INFO ] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .configure () ==> using driver: org.postgresql.Driver at URL: jdbc:postgresql://localhost/michael
[18:29:11,405] [INFO ] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .configure () ==> connection properties: {user=michael, password=micjael}
[18:29:11,413] [INFO ] [net.sf.hibernate.transaction.TransactionManagerLookupFactory] Thread-0 .getTransactionManagerLookup() ==> No TransactionManagerLookup configured (in JTA environment, use of process level read-write cache is not recommended)
[18:29:11,414] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .getConnection() ==> total checked-out connections: 0
[18:29:11,414] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .getConnection() ==> opening new JDBC connection
[18:29:11,533] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .getConnection() ==> created connection to: jdbc:postgresql://localhost/michael, Isolation Level: 2
[18:29:11,555] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .closeConnection() ==> returning connection to pool, pool size: 1
[18:29:11,555] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> Use scrollable result sets: true
[18:29:11,556] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> Use JDBC3 getGeneratedKeys(): false
[18:29:11,556] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> Optimize cache for minimal puts: false
[18:29:11,557] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> echoing all SQL to stdout
[18:29:11,557] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> Query language substitutions: {}
[18:29:11,560] [INFO ] [net.sf.hibernate.cfg.SettingsFactory] Thread-0 .buildSettings() ==> cache provider: net.sf.hibernate.cache.EhCacheProvider
[18:29:11,563] [INFO ] [net.sf.hibernate.cfg.Configuration] Thread-0 .configureCaches() ==> instantiating and configuring caches
[18:29:11,698] [INFO ] [net.sf.hibernate.impl.SessionFactoryImpl] Thread-0 .<init> () ==> building session factory
[18:29:11,700] [DEBUG] [net.sf.hibernate.impl.SessionFactoryImpl] Thread-0 .<init> () ==> instantiating session factory with properties: {hibernate.connection.password=micjael, java.runtime.name=Java(TM) 2 Runtime Environment, Standard Edition, sun.boot.library.path=/usr/java/j2sdk1.4.2_03/jre/lib/i386, java.vm.version=1.4.2_03-b02, hibernate.connection.username=michael, 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.os.patch.level=unknown, hibernate.connection.isolation=2, java.vm.specification.name=Java Virtual Machine Specification, user.dir=/home/data/code/hibernate_query, java.runtime.version=1.4.2_03-b02, java.awt.graphicsenv=sun.awt.X11GraphicsEnvironment, java.endorsed.dirs=/usr/java/j2sdk1.4.2_03/jre/lib/endorsed, os.arch=i386, java.io.tmpdir=/tmp, line.separator= , java.vm.specification.vendor=Sun Microsystems Inc., os.name=Linux, sun.java2d.fontpath=, log4j.configuration=file:log4j.xml, connection.isolation=2, java.library.path=/usr/java/j2sdk1.4.2_03/jre/lib/i386/client:/usr/java/j2sdk1.4.2_03/jre/lib/i386:/usr/java/j2sdk1.4.2_03/jre/../lib/i386, java.specification.name=Java Platform API Specification, java.class.version=48.0, hibernate.connection.pool_size=3, java.util.prefs.PreferencesFactory=java.util.prefs.FileSystemPreferencesFactory, os.version=2.4.20-8, connection.password=micjael, user.home=/home/michael, user.timezone=Australia/Sydney, connection.username=michael, java.awt.printerjob=sun.print.PSPrinterJob, file.encoding=ISO-8859-1, java.specification.version=1.4, hibernate.connection.driver_class=org.postgresql.Driver, show_sql=true, log4j.debug=true, user.name=michael, java.class.path=/home/data/code/hibernate_query/build/classes:/home/data/code/hibernate_query/lib/ant-1.5.3.jar:/home/data/code/hibernate_query/lib/ant-optional-1.5.3.jar:/home/data/code/hibernate_query/lib/c3p0-0.8.4.5.jar:/home/data/code/hibernate_query/lib/cglib-full-2.0.2.jar:/home/data/code/hibernate_query/lib/commons-collections-2.1.1.jar:/home/data/code/hibernate_query/lib/commons-dbcp-1.2.1.jar:/home/data/code/hibernate_query/lib/commons-lang-1.0.1.jar:/home/data/code/hibernate_query/lib/commons-logging-1.0.4.jar:/home/data/code/hibernate_query/lib/commons-pool-1.2.jar:/home/data/code/hibernate_query/lib/concurrent-1.3.3.jar:/home/data/code/hibernate_query/lib/connector.jar:/home/data/code/hibernate_query/lib/dom4j-1.4.jar:/home/data/code/hibernate_query/lib/ehcache-0.9.jar:/home/data/code/hibernate_query/lib/jaas.jar:/home/data/code/hibernate_query/lib/jboss-cache.jar:/home/data/code/hibernate_query/lib/jboss-common.jar:/home/data/code/hibernate_query/lib/jboss-jmx.jar:/home/data/code/hibernate_query/lib/jboss-system.jar:/home/data/code/hibernate_query/lib/jcs-1.0-dev.jar:/home/data/code/hibernate_query/lib/jdbc2_0-stdext.jar:/home/data/code/hibernate_query/lib/jgroups-2.2.3.jar:/home/data/code/hibernate_query/lib/jta.jar:/home/data/code/hibernate_query/lib/junit-3.8.1.jar:/home/data/code/hibernate_query/lib/log4j-1.2.8.jar:/home/data/code/hibernate_query/lib/odmg-3.0.jar:/home/data/code/hibernate_query/lib/oscache-2.0.jar:/home/data/code/hibernate_query/lib/proxool-0.8.3.jar:/home/data/code/hibernate_query/lib/swarmcache-1.0rc2.jar:/home/data/code/hibernate_query/lib/xalan-2.4.0.jar:/home/data/code/hibernate_query/lib/xerces-2.4.0.jar:/home/data/code/hibernate_query/lib/xml-apis.jar:/home/data/code/hibernate_query/lib/hibernate2.jar:/home/data/code/hibernate_query/lib/pg74.1jdbc3.jar, hibernate.show_sql=true, java.vm.specification.version=1.0, java.home=/usr/java/j2sdk1.4.2_03/jre, sun.arch.data.model=32, jdbc.batch_size=0, hibernate.connection.url=jdbc:postgresql://localhost/michael, hibernate.dialect=net.sf.hibernate.dialect.PostgreSQLDialect, connection.pool_size=3, user.language=en, java.specification.vendor=Sun Microsystems Inc., hibernate.cglib.use_reflection_optimizer=true, java.vm.info=mixed mode, java.version=1.4.2_03, java.ext.dirs=/usr/java/j2sdk1.4.2_03/jre/lib/ext, sun.boot.class.path=/usr/java/j2sdk1.4.2_03/jre/lib/rt.jar:/usr/java/j2sdk1.4.2_03/jre/lib/i18n.jar:/usr/java/j2sdk1.4.2_03/jre/lib/sunrsasign.jar:/usr/java/j2sdk1.4.2_03/jre/lib/jsse.jar:/usr/java/j2sdk1.4.2_03/jre/lib/jce.jar:/usr/java/j2sdk1.4.2_03/jre/lib/charsets.jar:/usr/java/j2sdk1.4.2_03/jre/classes, java.vendor=Sun Microsystems Inc., hibernate.jdbc.batch_size=0, connection.driver_class=org.postgresql.Driver, file.separator=/, max_fetch_depth=1, java.vendor.url.bug=http://java.sun.com/cgi-bin/bugreport.cgi, sun.io.unicode.encoding=UnicodeLittle, sun.cpu.endian=little, hibernate.max_fetch_depth=1, connection.url=jdbc:postgresql://localhost/michael, dialect=net.sf.hibernate.dialect.PostgreSQLDialect, sun.cpu.isalist=}
[18:29:12,196] [DEBUG] [net.sf.hibernate.impl.SessionFactoryObjectFactory] Thread-0 .<clinit> () ==> initializing class SessionFactoryObjectFactory
[18:29:12,200] [DEBUG] [net.sf.hibernate.impl.SessionFactoryObjectFactory] Thread-0 .addInstance() ==> registered: ff808081ff5de81600ff5de818800000 (unnamed)
[18:29:12,201] [INFO ] [net.sf.hibernate.impl.SessionFactoryObjectFactory] Thread-0 .addInstance() ==> Not binding factory to JNDI, no JNDI name configured
[18:29:12,201] [DEBUG] [net.sf.hibernate.impl.SessionFactoryImpl] Thread-0 .<init> () ==> instantiated session factory
[18:29:12,204] [DEBUG] [util.HibernateUtil] Thread-0 .getSession() ==> Opening new Session for this thread.
[18:29:12,264] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .<init> () ==> opened session
[18:29:12,265] [DEBUG] [util.HibernateUtil] Thread-0 .beginTransaction() ==> Starting new database transaction in this thread.
[18:29:12,269] [DEBUG] [net.sf.hibernate.transaction.JDBCTransaction] Thread-0 .begin () ==> begin
[18:29:12,269] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .getConnection() ==> total checked-out connections: 0
[18:29:12,270] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .getConnection() ==> using pooled JDBC connection, pool size: 0
[18:29:12,271] [DEBUG] [net.sf.hibernate.transaction.JDBCTransaction] Thread-0 .begin () ==> current autocommit status:false
[18:29:12,284] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .find () ==> find: from IntProperties
[18:29:12,291] [DEBUG] [net.sf.hibernate.engine.QueryParameters] Thread-0 .traceParameters() ==> named parameters: {}
[18:29:12,312] [DEBUG] [net.sf.hibernate.hql.QueryTranslator] Thread-0 .compile () ==> compiling query
[18:29:12,329] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEverything() ==> flushing session
[18:29:12,333] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEntities() ==> Flushing entities and processing referenced collections
[18:29:12,333] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushCollections() ==> Processing unreferenced collections
[18:29:12,333] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushCollections() ==> Scheduling collection removes/(re)creates/updates
[18:29:12,334] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEverything() ==> Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
[18:29:12,334] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEverything() ==> Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[18:29:12,334] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .autoFlushIfRequired() ==> Dont need to execute flush
[18:29:12,335] [DEBUG] [net.sf.hibernate.hql.QueryTranslator] Thread-0 .logQuery () ==> HQL: from domain.IntProperties
[18:29:12,335] [DEBUG] [net.sf.hibernate.hql.QueryTranslator] Thread-0 .logQuery () ==> SQL: select intpropert0_.id as id, intpropert0_.version as version, intpropert0_.name as name, intpropert0_.value as value from int_properties intpropert0_
[18:29:12,335] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-0 .logOpenPreparedStatement() ==> about to open: 0 open PreparedStatements, 0 open ResultSets
[18:29:12,338] [DEBUG] [net.sf.hibernate.SQL] Thread-0 .log () ==> select intpropert0_.id as id, intpropert0_.version as version, intpropert0_.name as name, intpropert0_.value as value from int_properties intpropert0_
[18:29:12,339] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-0 .getPreparedStatement() ==> preparing statement
[18:29:12,345] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-0 .doQuery () ==> processing result set
[18:29:12,346] [DEBUG] [net.sf.hibernate.type.LongType] Thread-0 .nullSafeGet() ==> returning '1' as column: id
[18:29:12,347] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-0 .getRow () ==> result row: 1
[18:29:12,348] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-0 .loadFromResultSet() ==> Initializing object from ResultSet: 1
[18:29:12,349] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-0 .hydrate () ==> Hydrating entity: domain.IntProperties#1
[18:29:12,350] [DEBUG] [net.sf.hibernate.type.LongType] Thread-0 .nullSafeGet() ==> returning '3' as column: version
[18:29:12,351] [DEBUG] [net.sf.hibernate.type.StringType] Thread-0 .nullSafeGet() ==> returning 'test_of_int_props' as column: name
[18:29:12,351] [DEBUG] [net.sf.hibernate.type.IntegerType] Thread-0 .nullSafeGet() ==> returning '1' as column: value
[18:29:12,353] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .postHydrate() ==> Version: 3
[18:29:12,356] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-0 .doQuery () ==> done processing result set (1 rows)
[18:29:12,356] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-0 .logClosePreparedStatement() ==> done closing: 0 open PreparedStatements, 0 open ResultSets
[18:29:12,358] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-0 .closePreparedStatement() ==> closing statement
[18:29:12,358] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-0 .initializeEntitiesAndCollections() ==> total objects hydrated: 1
[18:29:12,360] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .initializeEntity() ==> resolving associations for [domain.IntProperties#1]
[18:29:12,361] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .initializeEntity() ==> done materializing entity [domain.IntProperties#1]
[18:29:12,361] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .initializeNonLazyCollections() ==> initializing non-lazy collections
[18:29:12,361] [INFO ] [main.IntPropertiesMain] Thread-0 .readAndUpdate1() ==> Waiting for another thread to do update
[18:29:13,877] [DEBUG] [util.HibernateUtil] Thread-1 .getSession() ==> Opening new Session for this thread.
[18:29:13,877] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .<init> () ==> opened session
[18:29:13,878] [DEBUG] [util.HibernateUtil] Thread-1 .beginTransaction() ==> Starting new database transaction in this thread.
[18:29:13,878] [DEBUG] [net.sf.hibernate.transaction.JDBCTransaction] Thread-1 .begin () ==> begin
[18:29:13,878] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-1 .getConnection() ==> total checked-out connections: 1
[18:29:13,878] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-1 .getConnection() ==> opening new JDBC connection
[18:29:13,925] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-1 .getConnection() ==> created connection to: jdbc:postgresql://localhost/michael, Isolation Level: 2
[18:29:13,925] [DEBUG] [net.sf.hibernate.transaction.JDBCTransaction] Thread-1 .begin () ==> current autocommit status:false
[18:29:13,926] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .find () ==> find: from IntProperties
[18:29:13,926] [DEBUG] [net.sf.hibernate.engine.QueryParameters] Thread-1 .traceParameters() ==> named parameters: {}
[18:29:13,928] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEverything() ==> flushing session
[18:29:13,928] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEntities() ==> Flushing entities and processing referenced collections
[18:29:13,928] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushCollections() ==> Processing unreferenced collections
[18:29:13,929] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushCollections() ==> Scheduling collection removes/(re)creates/updates
[18:29:13,929] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEverything() ==> Flushed: 0 insertions, 0 updates, 0 deletions to 0 objects
[18:29:13,929] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEverything() ==> Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[18:29:13,930] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .autoFlushIfRequired() ==> Dont need to execute flush
[18:29:13,930] [DEBUG] [net.sf.hibernate.hql.QueryTranslator] Thread-1 .logQuery () ==> HQL: from domain.IntProperties
[18:29:13,930] [DEBUG] [net.sf.hibernate.hql.QueryTranslator] Thread-1 .logQuery () ==> SQL: select intpropert0_.id as id, intpropert0_.version as version, intpropert0_.name as name, intpropert0_.value as value from int_properties intpropert0_
[18:29:13,931] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .logOpenPreparedStatement() ==> about to open: 0 open PreparedStatements, 0 open ResultSets
[18:29:13,931] [DEBUG] [net.sf.hibernate.SQL] Thread-1 .log () ==> select intpropert0_.id as id, intpropert0_.version as version, intpropert0_.name as name, intpropert0_.value as value from int_properties intpropert0_
[18:29:13,933] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .getPreparedStatement() ==> preparing statement
[18:29:13,938] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-1 .doQuery () ==> processing result set
[18:29:13,939] [DEBUG] [net.sf.hibernate.type.LongType] Thread-1 .nullSafeGet() ==> returning '1' as column: id
[18:29:13,939] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-1 .getRow () ==> result row: 1
[18:29:13,940] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-1 .loadFromResultSet() ==> Initializing object from ResultSet: 1
[18:29:13,940] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-1 .hydrate () ==> Hydrating entity: domain.IntProperties#1
[18:29:13,940] [DEBUG] [net.sf.hibernate.type.LongType] Thread-1 .nullSafeGet() ==> returning '3' as column: version
[18:29:13,941] [DEBUG] [net.sf.hibernate.type.StringType] Thread-1 .nullSafeGet() ==> returning 'test_of_int_props' as column: name
[18:29:13,941] [DEBUG] [net.sf.hibernate.type.IntegerType] Thread-1 .nullSafeGet() ==> returning '1' as column: value
[18:29:13,942] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .postHydrate() ==> Version: 3
[18:29:13,942] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-1 .doQuery () ==> done processing result set (1 rows)
[18:29:13,942] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .logClosePreparedStatement() ==> done closing: 0 open PreparedStatements, 0 open ResultSets
[18:29:13,943] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .closePreparedStatement() ==> closing statement
[18:29:13,945] [DEBUG] [net.sf.hibernate.loader.Loader] Thread-1 .initializeEntitiesAndCollections() ==> total objects hydrated: 1
[18:29:13,945] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .initializeEntity() ==> resolving associations for [domain.IntProperties#1]
[18:29:13,945] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .initializeEntity() ==> done materializing entity [domain.IntProperties#1]
[18:29:13,946] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .initializeNonLazyCollections() ==> initializing non-lazy collections
[18:29:13,946] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .save () ==> object already associated with session
[18:29:13,947] [DEBUG] [util.HibernateUtil] Thread-1 .commitTransaction() ==> Committing database transaction of this thread.
[18:29:13,947] [DEBUG] [net.sf.hibernate.transaction.JDBCTransaction] Thread-1 .commit () ==> commit
[18:29:13,947] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEverything() ==> flushing session
[18:29:13,949] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEntities() ==> Flushing entities and processing referenced collections
[18:29:13,950] [DEBUG] [net.sf.hibernate.persister.AbstractEntityPersister] Thread-1 .findDirty () ==> domain.IntProperties.value is dirty
[18:29:13,951] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEntity() ==> Updating entity: [domain.IntProperties#1]
[18:29:13,951] [DEBUG] [net.sf.hibernate.engine.Versioning] Thread-1 .increment () ==> Incrementing: 3 to 4
[18:29:13,955] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushCollections() ==> Processing unreferenced collections
[18:29:13,955] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushCollections() ==> Scheduling collection removes/(re)creates/updates
[18:29:13,957] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEverything() ==> Flushed: 0 insertions, 1 updates, 0 deletions to 1 objects
[18:29:13,957] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .flushEverything() ==> Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[18:29:13,957] [DEBUG] [net.sf.hibernate.impl.Printer] Thread-1 .toString () ==> listing entities:
[18:29:13,958] [DEBUG] [net.sf.hibernate.impl.Printer] Thread-1 .toString () ==> domain.IntProperties{value=3, name=test_of_int_props, id=1, version=3}
[18:29:13,958] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .execute () ==> executing flush
[18:29:13,959] [DEBUG] [net.sf.hibernate.persister.EntityPersister] Thread-1 .update () ==> Updating entity: [domain.IntProperties#1]
[18:29:13,959] [DEBUG] [net.sf.hibernate.persister.EntityPersister] Thread-1 .update () ==> Existing version: 3 -> New version: 4
[18:29:13,960] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .logOpenPreparedStatement() ==> about to open: 0 open PreparedStatements, 0 open ResultSets
[18:29:13,960] [DEBUG] [net.sf.hibernate.SQL] Thread-1 .log () ==> update int_properties set version=?, name=?, value=? where id=? and version=?
[18:29:13,961] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .getPreparedStatement() ==> preparing statement
[18:29:13,961] [DEBUG] [net.sf.hibernate.persister.EntityPersister] Thread-1 .dehydrate () ==> Dehydrating entity: [domain.IntProperties#1]
[18:29:13,962] [DEBUG] [net.sf.hibernate.type.LongType] Thread-1 .nullSafeSet() ==> binding '4' to parameter: 1
[18:29:13,962] [DEBUG] [net.sf.hibernate.type.StringType] Thread-1 .nullSafeSet() ==> binding 'test_of_int_props' to parameter: 2
[18:29:13,963] [DEBUG] [net.sf.hibernate.type.IntegerType] Thread-1 .nullSafeSet() ==> binding '3' to parameter: 3
[18:29:13,963] [DEBUG] [net.sf.hibernate.type.LongType] Thread-1 .nullSafeSet() ==> binding '1' to parameter: 4
[18:29:13,965] [DEBUG] [net.sf.hibernate.type.LongType] Thread-1 .nullSafeSet() ==> binding '3' to parameter: 5
[18:29:13,967] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .logClosePreparedStatement() ==> done closing: 0 open PreparedStatements, 0 open ResultSets
[18:29:13,968] [DEBUG] [net.sf.hibernate.impl.BatcherImpl] Thread-1 .closePreparedStatement() ==> closing statement
[18:29:13,968] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .postFlush () ==> post flush
[18:29:13,976] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .afterTransactionCompletion() ==> transaction completion
[18:29:13,987] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .close () ==> closing session
[18:29:13,988] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .disconnect() ==> disconnecting session
[18:29:13,990] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-1 .closeConnection() ==> returning connection to pool, pool size: 1
[18:29:13,991] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-1 .afterTransactionCompletion() ==> transaction completion
[18:29:13,991] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .save () ==> object already associated with session
[18:29:13,991] [DEBUG] [util.HibernateUtil] Thread-0 .commitTransaction() ==> Committing database transaction of this thread.
[18:29:13,992] [DEBUG] [net.sf.hibernate.transaction.JDBCTransaction] Thread-0 .commit () ==> commit
[18:29:13,992] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEverything() ==> flushing session
[18:29:13,992] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEntities() ==> Flushing entities and processing referenced collections
[18:29:13,993] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushCollections() ==> Processing unreferenced collections
[18:29:13,993] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushCollections() ==> Scheduling collection removes/(re)creates/updates
[18:29:13,993] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEverything() ==> Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
[18:29:13,993] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .flushEverything() ==> Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
[18:29:13,995] [DEBUG] [net.sf.hibernate.impl.Printer] Thread-0 .toString () ==> listing entities:
[18:29:13,995] [DEBUG] [net.sf.hibernate.impl.Printer] Thread-0 .toString () ==> domain.IntProperties{value=1, name=test_of_int_props, id=1, version=3}
[18:29:13,996] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .execute () ==> executing flush
[18:29:13,996] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .postFlush () ==> post flush
[18:29:13,997] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .afterTransactionCompletion() ==> transaction completion
[18:29:13,997] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .close () ==> closing session
[18:29:13,998] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .disconnect() ==> disconnecting session
[18:29:13,998] [DEBUG] [net.sf.hibernate.connection.DriverManagerConnectionProvider] Thread-0 .closeConnection() ==> returning connection to pool, pool size: 2
[18:29:13,998] [DEBUG] [net.sf.hibernate.impl.SessionImpl] Thread-0 .afterTransactionCompletion() ==> transaction completion
|
|