Hi All,
I have a big problem with optimistic lock.
I have two threads that update at the same time the value of property 'pending' of class IcCredito.
When one thread modify the value after the first thread have already read the value of the file at line
Code:
tx.commit();
I have the correct exception
Code:
StaleObjectStateException
.
I catch it and I refresh the item (
Code:
session.refresh(utenteDb);
).
When I retry to commit the log log.debug("updateCrediti Version: "+vv); and log.debug("updateCrediti newPending: "+newPending); shown the new correct value updated by first thared but
at commit instruction the values commited are the old valuesand also the version is the old. For this reason all new retry of commit launch the StaleObjectStateException. The version after refresh instruction is 25 but the commit instruction have the version 18: what is my big error?
Thank's at all and sorry for my bad english.
Hibernate version:3.0.5 MySQL 5.0Mapping documents:
######################
....
<hibernate-mapping package="icontact.sms.beans.hibernate">
<class name="IcUtente" table="ic_utenti" lazy="true">
<id name="id" type="int">
<column name="id" precision="11" scale="0" />
<generator class="identity"/>
</id>
...
<one-to-one
name="credito"
class="IcCredito"
cascade="all"
property-ref="idutente"
/>
...
</class>
</hibernate-mapping>
######################
...
<hibernate-mapping package="icontact.sms.beans.hibernate">
<class name="IcCredito" table="ic_crediti">
<id name="id" type="int">
<column name="id" precision="11" scale="0" />
<generator class="identity"/>
</id>
<version name="version" column="lastmodify"/>
<property name="idutente" type="int">
<column name="idutente"/>
</property>
<property name="costosingolo" type="double">
<column name="costosingolo" precision="5" scale="3"/>
</property>
<property name="credito" type="double">
<column name="credito" precision="7" scale="3"/>
</property>
<property name="pending" type="double">
<column name="pending" precision="7" scale="3"/>
</property>
</class>
</hibernate-mapping>
######################
Code:
Code:
public boolean updateCrediti(int idutente,double pendingOffset,double creditoOffset){
Session session = null;
Transaction tx = null;
try {
/* get session of the current thread */
session = HibernateUtil.getCurrentSession();
IcUtente utenteDb = (IcUtente)
session.get(IcUtente.class,idutente);
boolean isOk = true;
int retry = 0;
do {
try{
tx = session.beginTransaction();
double currentPending=utenteDb.getCredito().getPending();
double newPending=currentPending+pendingOffset;
int vv = utenteDb.getCredito().getVersion();
log.debug("updateCrediti Version: "+vv);
log.debug("updateCrediti newPending: "+newPending);
utenteDb.getCredito().setPending(newPending);
session.update(utenteDb);
tx.commit();
isOk = true;
} catch (StaleObjectStateException sose){
tx.rollback();
log.info("updateCrediti Ricarico oggetto...");
session.refresh(utenteDb);
double currentPending=
utenteDb.getCredito().getPending();
log.debug("updateCrediti newPending dopo
refresh:"+currentPending);
log.debug("updateCrediti Version dopo refresh "+utenteDbtt.getCredito().getVersion());
isOk = false;
retry++;
if(retry>5){
throw new Exception("Troppi tentativi");
}
}
} while (!isOk);
return true;
} catch (Exception e){
log.error("Exception:",e);
tx.rollback();
return false;
}
}
}
Refresh log
------------------------------------------------------------
hEventListener] TP-Processor8 refreshing [icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,177 DEBUG [org.hibernate.persister.entity.BasicEntityPersister] TP-Processor8 Materializing entity: [icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,177 DEBUG [org.hibernate.loader.Loader] TP-Processor8 loading entity: [icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,177 DEBUG [org.hibernate.jdbc.AbstractBatcher] TP-Processor8 about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-06-11 16:38:32,177 DEBUG [org.hibernate.jdbc.ConnectionManager] TP-Processor8 opening JDBC connection
2006-06-11 16:38:32,177 DEBUG [org.hibernate.SQL] TP-Processor8 select iccredito0_.id as id0_, iccredito0_.lastmodify as lastmodify0_0_, iccredito0_.idutente as idutente0
_0_, iccredito0_.costosingolo as costosin4_0_0_, iccredito0_.credito as credito0_0_, iccredito0_.pending as pending0_0_ from ic_crediti iccredito0_ where iccredito0_.id=?
2006-06-11 16:38:32,177 DEBUG [org.hibernate.jdbc.AbstractBatcher] TP-Processor8 preparing statement
2006-06-11 16:38:32,178 DEBUG [org.hibernate.type.IntegerType] TP-Processor8 binding '3' to parameter: 1
2006-06-11 16:38:32,178 DEBUG [org.hibernate.jdbc.AbstractBatcher] TP-Processor8 about to open ResultSet (open ResultSets: 0, globally: 0)
2006-06-11 16:38:32,178 DEBUG [org.hibernate.loader.Loader] TP-Processor8 processing result set
2006-06-11 16:38:32,178 DEBUG [org.hibernate.loader.Loader] TP-Processor8 result set row: 0
2006-06-11 16:38:32,178 DEBUG [org.hibernate.loader.Loader] TP-Processor8 result row: EntityKey[icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,178 DEBUG [org.hibernate.loader.Loader] TP-Processor8 Initializing object from ResultSet: [icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,178 DEBUG [org.hibernate.persister.entity.BasicEntityPersister] TP-Processor8 Hydrating entity: [icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,178 DEBUG [org.hibernate.type.IntegerType] TP-Processor8 returning '25' as column: lastmodify0_0_
2006-06-11 16:38:32,178 DEBUG [org.hibernate.type.IntegerType] TP-Processor8 returning '1' as column: idutente0_0_
2006-06-11 16:38:32,179 DEBUG [org.hibernate.type.DoubleType] TP-Processor8 returning '0.075' as column: costosin4_0_0_
2006-06-11 16:38:32,179 DEBUG [org.hibernate.type.DoubleType] TP-Processor8 returning '1999.3' as column: credito0_0_
2006-06-11 16:38:32,179 DEBUG [org.hibernate.type.DoubleType] TP-Processor8 returning '1.1' as column: pending0_0_
2006-06-11 16:38:32,179 DEBUG [org.hibernate.engine.TwoPhaseLoad] TP-Processor8
Version: 25
---------------------------------------------------------------------------
Log after refresh
ectionManager] TP-Processor8 opening JDBC connection
2006-06-11 16:38:32,182 DEBUG [org.hibernate.transaction.JDBCTransaction] TP-Processor8 current autocommit status: true
2006-06-11 16:38:32,182 DEBUG [org.hibernate.transaction.JDBCTransaction] TP-Processor8 disabling autocommit
2006-06-11 16:38:32,182 DEBUG [icontact.sms.manager.UtentiManager] TP-Processor8 updateCrediti currentCredito:1999.3
2006-06-11 16:38:32,182 DEBUG [icontact.sms.manager.UtentiManager] TP-Processor8 updateCrediti currentPending:1.1
2006-06-11 16:38:32,182 DEBUG [icontact.sms.manager.UtentiManager]
TP-Processor8 updateCrediti Version: 25
2006-06-11 16:38:32,182 DEBUG [icontact.sms.manager.UtentiManager] TP-Processor8 updateCrediti newCredito: 1999.3
2006-06-11 16:38:32,182 DEBUG [icontact.sms.manager.UtentiManager] TP-Processor8 updateCrediti newPending: 1.20
----------------------------------------------------------------
Log of commit
[org.hibernate.event.def.AbstractFlushingEventListener] TP-Processor8 executing flush
2006-06-11 16:38:32,188 DEBUG [org.hibernate.persister.entity.BasicEntityPersister] TP-Processor8 Updating entity: [icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,188 DEBUG [org.hibernate.persister.entity.BasicEntityPersister] TP-Processor8
Existing version: 18 -> New version: 19
2006-06-11 16:38:32,188 DEBUG [org.hibernate.jdbc.AbstractBatcher] TP-Processor8 about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2006-06-11 16:38:32,188 DEBUG [org.hibernate.SQL] TP-Processor8 update ic_crediti set lastmodify=?, idutente=?, costosingolo=?, credito=?, pending=? where id=? and lastmo
dify=?
2006-06-11 16:38:32,188 DEBUG [org.hibernate.jdbc.AbstractBatcher] TP-Processor8 preparing statement
2006-06-11 16:38:32,188 DEBUG [org.hibernate.persister.entity.BasicEntityPersister] TP-Processor8 Dehydrating entity: [icontact.sms.beans.hibernate.IcCredito#3]
2006-06-11 16:38:32,188 DEBUG [org.hibernate.type.IntegerType] TP-Processor8 binding '19' to parameter: 1
2006-06-11 16:38:32,188 DEBUG [org.hibernate.type.IntegerType] TP-Processor8 binding '1' to parameter: 2
2006-06-11 16:38:32,188 DEBUG [org.hibernate.type.DoubleType] TP-Processor8 binding '0.075' to parameter: 3
2006-06-11 16:38:32,189 DEBUG [org.hibernate.type.DoubleType] TP-Processor8 binding '2000.0' to parameter: 4
2006-06-11 16:38:32,189 DEBUG [org.hibernate.type.DoubleType] TP-Processor8 binding '1.90' to parameter: 5
2006-06-11 16:38:32,189 DEBUG [org.hibernate.type.IntegerType] TP-Processor8 binding '3' to parameter: 6
2006-06-11 16:38:32,189 DEBUG [org.hibernate.type.IntegerType] TP-Processor8 binding '18' to parameter: 7
-----------------------------------------------------