Bug 99000

Summary: versioning records duplicate "remove" events, causing it to blow up on rollback
Product: [Retired] Red Hat Web Application Framework Reporter: Vadim Nasardinov <vnasardinov>
Component: otherAssignee: Vadim Nasardinov <vnasardinov>
Status: CLOSED CURRENTRELEASE QA Contact: Jon Orris <jorris>
Severity: medium Docs Contact:
Priority: medium    
Version: nightly   
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2003-10-10 21:48:14 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 98546    

Description Vadim Nasardinov 2003-07-11 15:46:00 UTC
Description of problem:

If I author and publish an article, then unpublish it, and try
to view (or rollback to) an earlier version (such the earliest
versioned tagged with the "authored" tag), a versioning exception
is raised.


Steps to Reproduce:

1. Create an article, fill out its lead, body, image, and assign a category.
2. Finish the "author" task.  Reject the "edit" task, causing
the "author" task to be reenabled.
3. In the newly enabled "author" task, change the lead, body,
image, and the category of the article.
4. Finish the "author", "edit", "deploy" tasks.  Publish.
5. Unpublish.
6. Go to the History tab and try to view, or rollback to, the earliest
version that is tagged "authored".
7. Observe the rollback process blow up with the following exception:    

com.arsdigita.versioning.ProxyDataObject$CollectionAttributeException:
slaveVersions has already been processed.
attr: com.arsdigita.persistence.OID:12:
serialized=com.arsdigita.cms.Folder;id:1:246
deserialized=[com.arsdigita.cms.Folder:{id=246}]
operation: [com.arsdigita.versioning.GenericOperation:{id=605}]
attribute=slaveVersions
changeset=[com.arsdigita.versioning.DataObjectChange:{id=480}]
eventType=[com.arsdigita.versioning.EventType:{id=4}]
id=605
javaclass=[com.arsdigita.versioning.JavaClass:{id=12}]
subtype=1
value=com.arsdigita.cms.Folder;id:1:246

  ProxyDataObject$Collection.add(ProxyDataObject.java:688)
  ProxyDataObject.add(ProxyDataObject.java:236)
  ProxyDataObject.undoRemove(ProxyDataObject.java:435)
  ProxyDataObject.undoEvent(ProxyDataObject.java:394)
  RollbackRecord.unroll(RollbackRecord.java:211)
  RollbackRecord.computeDifferences(RollbackRecord.java:159)
  RollbackRecord.rollback(RollbackRecord.java:145)
  Versions.rollback(Versions.java:166)
  RollerBacker.rollback(RollerBacker.java:64)



Additional info:

Examining the versioning log manually shows that the remove event
for the "slaveVersions" property of the "Folder" object was recorded
twice within the same txn:

select
  op.attribute, op.id, change_id, gop.value
from
  vcx_operations op,
  vcx_generic_operations gop
where
  op.id = gop.id
  and event_type_id = 4
  and op.attribute = 'slaveVersions'
order by id;

ATTRIBUTE     |  ID| CHANGE_ID|VALUE
--------------|----|----------|---------------------------------
slaveVersions | 435|       434|ArticleImageAssociation;id:1:248
slaveVersions | 457|       456|contenttypes.Article;id:1:244
slaveVersions | 472|       471|TextAsset;id:1:247
slaveVersions | 492|       419|ContentBundle;id:1:245
slaveVersions | 605|       480|Folder;id:1:246
slaveVersions | 609|       480|Folder;id:1:246

The last two rows are the offending data.

Comment 1 Vadim Nasardinov 2003-07-11 15:46:57 UTC
reassigning to myself

Comment 2 Vadim Nasardinov 2003-07-11 22:57:41 UTC
Fixed in p4 33544.

The duplicate remove events turned out to be created during the unpublishing
of a live item.  Rather than trying to deal with how and why these
duplicate events occur, I simply modified the unpublish method to
suspend versioning for the duration of the txn in which unpublishing
happens.

For the record, the first offending "remove" event was created
via this execution path:

com.arsdigita.developersupport.StackTraces.captureStackTrace(StackTraces.java:115)
com.redhat.persistence.RemoveEvent.<init>(RemoveEvent.java:26)
com.redhat.persistence.Expander.reverseUpdateOld(Expander.java:225)
com.redhat.persistence.Expander.onSet(Expander.java:146)
com.redhat.persistence.SetEvent.dispatch(SetEvent.java:29)
com.redhat.persistence.Expander.expand(Expander.java:47)
com.redhat.persistence.Expander.onDelete(Expander.java:127)
com.redhat.persistence.DeleteEvent.dispatch(DeleteEvent.java:24)
com.redhat.persistence.Expander.expand(Expander.java:47)
com.redhat.persistence.Session.delete(Session.java:202)
com.arsdigita.persistence.DataObjectImpl.delete(DataObjectImpl.java:340)
com.arsdigita.domain.DomainObject.delete(DomainObject.java:324)
com.arsdigita.cms.Folder.delete(Folder.java:137)
com.arsdigita.cms.ContentItem.setLive(ContentItem.java:1082)
com.arsdigita.cms.ContentItem.unpublish(ContentItem.java:1189)
com.arsdigita.cms.Folder.unpublish(Folder.java:313)
com.arsdigita.cms.ContentItem.setLive(ContentItem.java:1091)
com.arsdigita.cms.ContentItem.unpublish(ContentItem.java:1189)
com.arsdigita.cms.ContentItem.setLive(ContentItem.java:1091)
com.arsdigita.cms.ContentItem.unpublish(ContentItem.java:1189)


The second "remove" event was created via this path:

com.arsdigita.developersupport.StackTraces.captureStackTrace(StackTraces.java:115)
com.redhat.persistence.RemoveEvent.<init>(RemoveEvent.java:26)
com.redhat.persistence.RemoveEvent.<init>(RemoveEvent.java:19)
com.redhat.persistence.Session$4.onRole(Session.java:302)
com.redhat.persistence.metadata.Role.dispatch(Role.java:77)
com.redhat.persistence.Session.remove(Session.java:300)
com.redhat.persistence.Session.remove(Session.java:288)
com.arsdigita.persistence.DataAssociationImpl.remove(DataAssociationImpl.java:59)
com.arsdigita.domain.DomainObject.remove(DomainObject.java:403)
com.arsdigita.domain.DomainObject.remove(DomainObject.java:410)
com.arsdigita.cms.ContentItem.removeVersion(ContentItem.java:998)
com.arsdigita.cms.ContentItem.setLiveVersion(ContentItem.java:968)
com.arsdigita.cms.ContentItem.setLive(ContentItem.java:1097)
com.arsdigita.cms.ContentItem.unpublish(ContentItem.java:1189)
com.arsdigita.cms.Folder.unpublish(Folder.java:313)
com.arsdigita.cms.ContentItem.setLive(ContentItem.java:1091)
com.arsdigita.cms.ContentItem.unpublish(ContentItem.java:1189)
com.arsdigita.cms.ContentItem.setLive(ContentItem.java:1091)
com.arsdigita.cms.ContentItem.unpublish(ContentItem.java:1189)