-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 6 posts ] 
Author Message
 Post subject: wrong version timestamp and StaleObjectException
PostPosted: Mon Jan 19, 2004 7:28 am 
Newbie

Joined: Tue Oct 28, 2003 8:00 am
Posts: 16
Location: Karlsruhe, Germany
hi,

we use Interceptor to check changes of attributes in Interceptor.findDirty and have the following problem if we do our own checking of attribute changes:
If we return null in findDirty all updates and timestamps are ok, but if we return an array of
the changed indices of the attributes from vorgangVO we get an hibernate exception
net.sf.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction.
When we look at the log output from hibernate we can see, that after a few updates
on vorgangVO the timestamp property from vorgang has wrong values.

is this a bug from hibernate (we use 2.1.1 and oracle 8 as database) or do we
use interceptor and versioned data in the wrong way ?

why does our own checking of changed attributes has an influence at
the handling of old version ?

thanks

Bertram


debug log of all updates to Vorgang:

DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:53,484 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Existing version: 2004-01-19 11:35:53.406 -> New version: 2004-01-19 11:35:53.421
2004-01-19 11:35:53,484 [RMI TCP Connection(3)-172.21.1.182] DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-01-19 11:35:53,484 [RMI TCP Connection(3)-172.21.1.182] DEBUG - update VORGANG set TIME_MODIFIED=?, MANDANT_ID=?, ZUSTAENDIG_ID=?, VG_STATUS=?, GN_STATUS=?, FLAGKNEHMER2=?, AUF TIME_CREATED=?, MODIFIED_BY=? where VOID=? and TIME_MODIFIED=?

saveOrUpdate() persistent instance
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - cascading to collection: vo.VorgangVO.sicherheitenPool
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - done processing cascades for: vo.VorgangVO
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - processing cascades for: vo.BearbeitungsinfoVO
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - cascading to collection: vo.BearbeitungsinfoVO.letzterArbeitsschritt
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - done processing cascades for: vo.BearbeitungsinfoVO
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Flushing entities and processing referenced collections
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - DaoInterceptor.findDirty vo.VorgangVO@2c958136fa2db1f100fa2db35c9f0001 no changed attributes !
2004-01-19 11:35:53,515 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Collection found: [vo.VorgangVO.anwenderrollen#2c95813

DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:53,828 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Existing version: 2004-01-19 11:35:53.421 -> New version: 2004-01-19 11:35:53.828
2004-01-19 11:35:53,828 [RMI TCP Connection(3)-172.21.1.182] DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-01-19 11:35:53,828 [RMI TCP Connection(3)-172.21.1.182] DEBUG - update VORGANG set TIME_MODIFIED=?, MANDANT_ID=?, ZUSTAENDIG_ID=?, VG_STATUS=?, GN_STATUS=?, FLAGKNEHMER2=?, AUF TIME_CREATED=?, MODIFIED_BY=? where VOID=? and TIME_MODIFIED=?

DEBUG - DaoInterceptor.findDirty vo.VorgangVO@2c958136fa2db1f100fa2db35c9f0001 changed attributes: 21 66 1
2004-01-19 11:35:55,125 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:55,125 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Incrementing: 2004-01-19 11:35:53.828 to 2004-01-19 11:35:55.125

DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:55,171 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Existing version: 2004-01-19 11:35:53.828 -> New version: 2004-01-19 11:35:55.125
2004-01-19 11:35:55,171 [RMI TCP Connection(3)-172.21.1.182] DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-01-19 11:35:55,171 [RMI TCP Connection(3)-172.21.1.182] DEBUG - update VORGANG set TIME_MODIFIED=?, MANDANT_ID=?, ZUSTAENDIG_ID=?, VG_STATUS=?, GN_STATUS=?, FLAGKNEHMER2=?, AUF TIME_CREATED=?, MODIFIED_BY=? where VOID=? and TIME_MODIFIED=?

2004-01-19 11:35:55,234 [RMI TCP Connection(3)-172.21.1.182] DEBUG - DaoInterceptor.findDirty vo.VorgangVO@2c958136fa2db1f100fa2db35c9f0001 : no changed attributes

now existing version ist older than the last new version :

2004-01-19 11:35:55,343 [RMI TCP Connection(3)-172.21.1.182] DEBUG - DaoInterceptor.findDirty vo.VorgangVO@2c958136fa2db1f100fa2db35c9f0001 changed attributes: 1
2004-01-19 11:35:55,343 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:55,343 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Incrementing: 2004-01-19 11:35:55.0 to 2004-01-19 11:35:55.343

DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:55,359 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Existing version: 2004-01-19 11:35:55.0 -> New version: 2004-01-19 11:35:55.343
2004-01-19 11:35:55,359 [RMI TCP Connection(3)-172.21.1.182] DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-01-19 11:35:55,359 [RMI TCP Connection(3)-172.21.1.182] DEBUG - update VORGANG set TIME_MODIFIED=?, MANDANT_ID=?, ZUSTAENDIG_ID=?, VG_STATUS=?, GN_STATUS=?, FLAGKNEHMER2=?, AUF TIME_CREATED=?, MODIFIED_BY=? where VOID=? and TIME_MODIFIED=?

DEBUG - Flushing entities and processing referenced collections
2004-01-19 11:35:55,375 [RMI TCP Connection(3)-172.21.1.182] DEBUG - DaoInterceptor.findDirty vo.VorgangVO@2c958136fa2db1f100fa2db35c9f0001 : no changed attributes

2004-01-19 11:35:57,390 [RMI TCP Connection(3)-172.21.1.182] DEBUG - DaoInterceptor.findDirty vo.VorgangVO@2c958136fa2db1f100fa2db35c9f0001 : changed attributes: 1
2004-01-19 11:35:57,390 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:57,390 [RMI TCP Connection(3)-172.21.1.182] DEBUG - VorgangVO@1119f9e:2c958136fa2db1f100fa2db35c9f0001..setLoadedState: Collections: M-A1:anwenderrollen=(, vo.Anwen
2004-01-19 11:35:57,390 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Incrementing: 2004-01-19 11:35:55.0 to 2004-01-19 11:35:57.39

hibernate makes an update to vorgang but the existing version ist the same as the last existing version

DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Existing version: 2004-01-19 11:35:55.0 -> New version: 2004-01-19 11:35:57.39
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - about to open: 0 open PreparedStatements, 0 open ResultSets
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - update VORGANG set TIME_MODIFIED=?, MANDANT_ID=?, ZUSTAENDIG_ID=?, VG_STATUS=?, GN_STATUS=?, FLAGKNEHMER2=?, AUF TIME_CREATED=?, MODIFIED_BY=? where VOID=? and TIME_MODIFIED=?
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] INFO - Hibernate: update VORGANG set TIME_MODIFIED=?, MANDANT_ID=?, ZUSTAENDIG_ID=?, VG_STATUS=?, GN_STATUS=?, FLAGKNEHMER2=?, AUFLAGE=?, AUSZBEDINGUNG=?, EIGENE_RECHNUNG=?, EGLBTR=?, EGLWHG=?, EGMBTR=?, EGMWHG=?, EBEGRUENDUNG1=?, FU_MASK=?, GSKBTR=?, GSKWHG=?, KPTTRAEGER=?, KSBTR=?, KSWHG=?, WAEHRUNG_CLASS=?, WAEHRUNG_KEY=?, ANFBLBTR=?, ANFBLWHG=?, FRMNTBTR=?, FRMNTWHG=?, SUMEINBTR=?, SUMEINWHG=?, SUMVERFNBTR=?, SUMVERFNWHG=?, SUMVERVNBTR=?, SUMVERVNWHG=?, ZFRBTR=?, ZFRWHG=?, FRBRBTR=?, FRBRWHG=?, LFDKRBTR=?, LFDKRWHG=?, BERATER=?, VERMITTLER=?, EVORGANGID=?, GESAMTBEWERTUNG=?, NTVMBTR=?, NTVMWHG=?, BONITAET=?, RATINGGS=?, QUALMERKM=?, TRGBLKRZ=?, TRGBLLGF=?, KANTWORT=?, KANTWDAT=?, KFRISTDAT=?, BEARBHINW=?, BGRABL1=?, BGRABL2=?, BSVERTRVEREINB=?, ENTSCHP1=?, ENTSCHP2=?, ENTSCH1=?, ENTSCH2=?, ENTSCH1DAT=?, ENTSCH2DAT=?, MINUNTERL=?, OFFENLDAT=?, OFFENLPFL=?, STELLNAHME=?, TMARGE=?, ZUSUNTERL=?, EBEGRUENDUNG2=?, P18GEPR=?, UP18ERBR=?, UP18ERBRDAT=?, BERG_GEPRUEFT=?, STATE_ARCHIV=?, DELETED=?, TIME_CREATED=?, MODIFIED_BY=? where VOID=? and TIME_MODIFIED=?
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - preparing statement
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - Dehydrating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding '19 Januar 2004 11:35:57' to parameter: 1
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding '1' to parameter: 2
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding '2c958136fa2db1f100fa2db35e440002' to parameter: 3
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding '2' to parameter: 4

2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding null to parameter: 74
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding 'false' to parameter: 75
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding '19 Januar 2004 11:35:53' to parameter: 76
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding null to parameter: 77
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding '2c958136fa2db1f100fa2db35c9f0001' to parameter: 78
2004-01-19 11:35:57,406 [RMI TCP Connection(3)-172.21.1.182] DEBUG - binding '19 Januar 2004 11:35:55' to parameter: 79
2004-01-19 11:35:57,421 [RMI TCP Connection(3)-172.21.1.182] DEBUG - done closing: 0 open PreparedStatements, 0 open ResultSets


..

saveOrUpdate() persistent instance
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - done processing cascades for: vo.BearbeitungsinfoVO
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Collection dirty: [vo.VorgangVO.vorhabenListe#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Flushing entities and processing referenced collections
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - DaoInterceptor.findDirty vo.VorgangVO@2c958136fa2db1f100fa2db35c9f0001 changed attribute: 9
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Updating entity: [vo.VorgangVO#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Incrementing: 2004-01-19 11:35:55.125 to 2004-01-19 11:36:08.843
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Collection found: [vo.VorgangVO.anwenderrollen#2c958136fa2db1f100fa2db35c9f0001], was: [vo.VorgangVO.anwenderrollen#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Collection found: [vo.VorgangVO.beteiligteParteien#2c958136fa2db1f100fa2db35c9f0001], was: [vo.VorgangVO.beteiligteParteien#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Collection found: [vo.VorgangVO.unterlagen#2c958136fa2db1f100fa2db35c9f0001], was: [vo.VorgangVO.unterlagen#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Collection found: [vo.VorgangVO.vorhabenListe#2c958136fa2db1f100fa2db35c9f0001], was: [vo.VorgangVO.vorhabenListe#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Collection found: [vo.VorgangVO.sicherheitenPool#2c958136fa2db1f100fa2db35c9f0001], was: [vo.VorgangVO.sicherheitenPool#2c958136fa2db1f100fa2db35c9f0001]
2004-01-19 11:36:08,843 [RMI TCP Connection(8)-172.21.1.182] DEBUG - Wrapped collection in role: vo.VorhabenVO.pakete

ERROR - An operation failed due to stale data
net.sf.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) for VorgangVO instance with identifier: 2c958136fa2db1f100fa2db35c9f0001
at net.sf.hibernate.persister.AbstractEntityPersister.check(AbstractEntityPersister.java:505)



that is the mapping of VorgangVO:

<?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="vo.VorgangVO"
table="VORGANG"
dynamic-update="false"
dynamic-insert="false"
>

<id
name="id"
column="VOID"
type="string"
length="32"
unsaved-value="null"
>
<generator class="uuid.hex">
</generator>
</id>

<timestamp
name="aenderungszeitpunkt"
column="TIME_MODIFIED"
/>

<map
name="anwenderrollen"
lazy="false"
sort="unsorted"
inverse="false"
cascade="all"
>

<key
column="VORGANG_ID"
/>

<index
column="INTERNROLLE_ID"
type="integer"
/>

<one-to-many
class="vo.AnwenderRolleVO"
/>
</map>

<map
name="beteiligteParteien"
lazy="false"
sort="unsorted"
inverse="false"
cascade="all"
>

<key
column="VORGANG_ID"
/>

<index
column="INTART_ID"
type="integer"
/>

<one-to-many
class="vo.PersonenListeVO"
/>
</map>

<list
name="vorhabenListe"
lazy="false"
inverse="false"
cascade="all"
>

<key
column="VORGANG_ID"
/>

<index
column="NR"
type="integer"
/>

<one-to-many
class="vo.VorhabenVO"
/>
</list>

<one-to-one
name="bearbeitungsinfo"
class="vo.BearbeitungsinfoVO"
cascade="all"
outer-join="auto"
constrained="false"
/>





<property
name="erstellungszeitpunkt"
type="timestamp"
update="true"
insert="true"
column="TIME_CREATED"
/>



</class>

</hibernate-mapping>


Top
 Profile  
 
 Post subject:
PostPosted: Mon Jan 19, 2004 8:20 am 
Hibernate Team
Hibernate Team

Joined: Sun Sep 14, 2003 3:54 am
Posts: 7256
Location: Paris, France
I'm not sure this is related but http://www.hibernate.org/80.html

_________________
Emmanuel


Top
 Profile  
 
 Post subject:
PostPosted: Mon Jan 19, 2004 8:51 am 
Newbie

Joined: Tue Oct 28, 2003 8:00 am
Posts: 16
Location: Karlsruhe, Germany
ok,

oracle takes only full seconds in update but if we let hibernate find the dirty attributes the timestamps in old version and new version is correct and all updates are successfull.
but if we give hibernate an array of the dirty attributes hibernate takes wrong old versions which are more than 1 second too old.

We have mad tests on MySql too and we get the same problem.


Top
 Profile  
 
 Post subject:
PostPosted: Mon Jan 19, 2004 10:24 am 
Hibernate Team
Hibernate Team

Joined: Sun Sep 14, 2003 3:54 am
Posts: 7256
Location: Paris, France
For my knowledge, does this work if you use <version> instead of <timestamp>

_________________
Emmanuel


Top
 Profile  
 
 Post subject:
PostPosted: Mon Jan 19, 2004 11:37 am 
Newbie

Joined: Tue Oct 28, 2003 8:00 am
Posts: 16
Location: Karlsruhe, Germany
hi,

we found the problem, two different sessions have written the same db object.


Top
 Profile  
 
 Post subject:
PostPosted: Mon Jan 19, 2004 11:43 am 
Hibernate Team
Hibernate Team

Joined: Sun Sep 14, 2003 3:54 am
Posts: 7256
Location: Paris, France
Eheh, we missed the most obvious :)

_________________
Emmanuel


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 6 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.