#43 — versioning broken with alpha4?

by Jeff Hammel — last modified Feb 21, 2009 08:54 PM
State Confirmed
Version: 1.0alpha4
Area Functionality
Issue type Bug
Severity Important
Submitted by Jeff Hammel
Submitted on Dec 07, 2006
Responsible Gregoire Weber
Target release: 1.0.1
Return to tracker


Maybe this is just an OpenPlans issue (see below), but when I install a new plone site (default customization) and edit the homepage I get the following:

2006-12-07 15:34:25 ERROR Zope.SiteErrorLog http://127.0.0.1:6666/plainplone/front-page/document_view
Traceback (innermost last):
  Module ZPublisher.Publish, line 115, in publish
  Module ZPublisher.mapply, line 88, in mapply
  Module ZPublisher.Publish, line 41, in call_object
  Module Shared.DC.Scripts.Bindings, line 311, in __call__
  Module Shared.DC.Scripts.Bindings, line 348, in _bindAndExec
  Module Products.CMFCore.FSPageTemplate, line 195, in _exec
  Module Products.CacheSetup.patch_cmf, line 18, in FSPT_pt_render
  Module Products.CacheSetup.patch_utils, line 9, in call_pattern
  Module Products.CMFCore.FSPageTemplate, line 134, in pt_render
  Module Products.CacheSetup.patch_cmf, line 56, in PT_pt_render
  Module Products.CacheSetup.patch_utils, line 9, in call_pattern
  Module Products.PageTemplates.PageTemplate, line 104, in pt_render
   - <FSPageTemplate at /plainplone/document_view used for /plainplone/front-page>
  Module TAL.TALInterpreter, line 238, in __call__
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 749, in do_useMacro
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 457, in do_optTag_tal
  Module TAL.TALInterpreter, line 442, in do_optTag
  Module TAL.TALInterpreter, line 437, in no_tag
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 780, in do_defineSlot
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 457, in do_optTag_tal
  Module TAL.TALInterpreter, line 442, in do_optTag
  Module TAL.TALInterpreter, line 437, in no_tag
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 728, in do_defineMacro
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 772, in do_defineSlot
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 457, in do_optTag_tal
  Module TAL.TALInterpreter, line 442, in do_optTag
  Module TAL.TALInterpreter, line 437, in no_tag
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 728, in do_defineMacro
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 457, in do_optTag_tal
  Module TAL.TALInterpreter, line 442, in do_optTag
  Module TAL.TALInterpreter, line 437, in no_tag
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 749, in do_useMacro
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 715, in do_condition
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 715, in do_condition
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 457, in do_optTag_tal
  Module TAL.TALInterpreter, line 442, in do_optTag
  Module TAL.TALInterpreter, line 437, in no_tag
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 749, in do_useMacro
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 715, in do_condition
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 457, in do_optTag_tal
  Module TAL.TALInterpreter, line 442, in do_optTag
  Module TAL.TALInterpreter, line 437, in no_tag
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 715, in do_condition
  Module TAL.TALInterpreter, line 281, in interpret
  Module TAL.TALInterpreter, line 690, in do_loop_tal
  Module Products.PageTemplates.TALES, line 71, in next
  Module ZTUtils.Iterator, line 46, in next
  Module ZTUtils.Iterator, line 152, in prep_next
  Module Products.CMFEditions.CopyModifyMergeRepositoryTool, line 702, in next
  Module Products.CMFEditions.CopyModifyMergeRepositoryTool, line 680, in __getitem__
  Module Products.CMFEditions.CopyModifyMergeRepositoryTool, line 412, in _retrieve
  Module Products.CMFEditions.CopyModifyMergeRepositoryTool, line 468, in _recursiveRetrieve
  Module Products.CMFEditions.ArchivistTool, line 310, in retrieve
  Module Products.CMFEditions.ArchivistTool, line 417, in __getitem__
  Module Products.CMFEditions.ZVCStorageTool, line 450, in __getitem__
  Module Products.CMFEditions.ZVCStorageTool, line 200, in _retrieve
  Module Products.ZopeVersionControl.Repository, line 462, in getVersionOfResource
AttributeError: 'NoneType' object has no attribute 'copyState'

I am using the openplans bundle, and so far haven't tested it with a plain plone site. I'll try that next and update this issue.

Of course this breaks the OpenPlans stuff too, which I'll give steps to reproduce below. But if you install the software, you can make a plain plone site, portal_quickinstaller CMFEditions, and you'll get the above bug. Same thing, as best i can tell.

There is also a failing test in the Products/OpenPlans/tests directory , test_history under test_projects.py


Steps to reproduce:
0) make sure you don't have zope or zeo running
1) install workingenv and do `workingenv topp.deploy`
2) `cd topp.deploy; source bin/activate`
3) `builder ~/bug_test`
4) after this finishes (it'll take awhile), point your browser at localhost:8080/manage_main and login as admin/admin
5) cruise on over to localhost:8080/openplans
6) edit the main page (really, you can make another account and edit your homepage or what not. doesn't matter)
7) go to the 'history' link. you should get the AttributeError: 'NoneType' object has no attribute 'copyState'
Added by Jeff Hammel on Dec 07, 2006 09:41 PM
Severity: Important → Medium
Target release: 1.0.1 → None
Responsible manager: gregweb → (UNASSIGNED)
This also occurs with the Plone 2.5 (Plone-2.5.1-final.tar.gz) release, with only CMFEditions and ZopeVersionControl addons. Using the Zope 2.9 svn trunk.

Is alpha4 supposed to work with Plone 2.5?
Added by Jeff Hammel on Dec 11, 2006 06:16 PM
just tried this with a bare Plone-2.1.4.tar.gz install using ZopeVersionControl-0.3.3 and ZopeVersionControl-0.3.1+
Added by Jeff Hammel on Dec 11, 2006 06:17 PM
no dice with Plone 2.1.4. is alpha4 supposed to work ootb?
Added by Gregoire Weber on Dec 12, 2006 06:24 PM
Target release: None → 1.0.1
Sorry, 1.0alpha4 is so old that it is only tested with Plone 2.1.2 that was out at that time. Unfortunately I do not understand what the issue is that a minor upgrade of plone may break CMFEditions.

The intended upgrade path was (and still is):

1. migrate CMFEditions history storage from 1.0alphaN
   (N == last alpha, currently 4) to 1.0rc1 (currently).
2. migrate to Plone 2.1.4

Unfortunately, step number one doesn't work for sites in production (with some amount of data). It only worked in my test setup with about a total of 100 versions.
In May (or June?) when I had time to work on that I didn't have access to a Data.fs and products in production to find the issues. In the meantime I got a Data.fs of someone but I missed and am still missing time to check and correct the issue.

Just to know:

- I won't leave you out in the rain. It's only matter of time.
- The upcoming final won't correct this issue. But there will be
  at least one maintainance release (1.0.x) for that issue.

Questions:

- May you from openplan.org in principle give away the Data.fs and
  all of the Products for searching the issue? I may sign a non
  disclosure agreement. The only problem currently is, that I can't
  give any pointers about when I'll have time. But it's just good to
  know so you may prepare.
- Or do you have the resources and the knowledge doing that?

Sidenote for those using betas and rc and the upcoming final:

- I remember that a half a year ago I saw a problem with the alpha
  ZVC storage tools implementation which is corrected with the totally
  refactored version of the storage tool.
Added by Alec Mitchell on Dec 12, 2006 07:00 PM
Hey gregoire,

I can give you the openplans data (the only reason I didn't already is because I thought you already had other data which demonstrated the issue). If your time is limited though, it may be most useful for you to just give me and the other openplans folks a hint as to where you suspect these migration breakages are. We can probably figure it out, and perhaps fix it for 1.0 final if we know where to start looking.
Added by Rob Miller on Dec 12, 2006 07:34 PM
Issue state: unconfirmed → open
Severity: Medium → Important
hi gregoire (and everyone else following this issue),

here's a bit more info:

- the bug that was originally reported here in 1.0a4 is the result of some recent changes in Zope's DateTime implementation. before, if you tried to do DateTime('1') (a string representation of an integer) it would fail, raising an exception; now it no longer fails but changes the string to an integer for the conversion. this exposes a bug in Products.ZopeVersionControl.Repository.Repository.getVersionOfResource(), because it will now mistakenly think that you're asking for a timestamp lookup when you ask for version numbers that don't exist. if we fixed the bug in ZopeVersionControl, then there would be no issues w/ using 1.0a4 with recent versions of Zope (the DateTime changes happened after the release of Zope 2.9.5).

- the changes in the CMFEditions storage after 1.0a4 mean that recent versions of CMFEditions 1.0 don't seem to be as susceptible to the ZopeVersionControl issue. of course, since our live site is running 1.0a4 this means we have the migration problem to deal with. we're happy to provide you with some live data for testing and debugging the migration, but we'd like to get it resolved pretty quickly, so we might just end up working on it ourselves. i didn't realize until today that there was a separate migration script that you had to run explicitly (not paying attention, apparently...), so i'm currently testing that out with a recent data set from our live site. my first attempt to run the migration wouldn't even complete, so we've got a starting point for our debugging, we'll report back here as we make more progress.
Added by Rob Miller on Dec 12, 2006 10:55 PM
okay, i've tried running the migration using an actual openplans.org data set and i have some more info about the migration problems:

in the ZVCStorageTool.migrateStorage() method the _history_id_mapping is stored in the hidMapping variable, which has history ids as the keys and VersionInfo objects as the values. then an hidReverseMapping data structure is created, with the history_id of the VersionInfo objects as keys and original keys as the values.

in our data set, there are 1123 items in the hidMapping. the hash keys for the first 798 of these are simple integers that range sequentially in order from 1 to 798, and the VersionInfo.history_id is a string representation of a 10 digit integer. after this, however, something changes, and the REST of the hash keys (i.e. from what would be 799 onward) are string representations of 10 digit integers, which match exactly the corresponding VersionInfo.history_id values.

what's worse, some (all?) of the 10 digit history ids are repeated, i.e. they exist with low valued integer keys and also with 10 digit keys. this means that when the hidReverseMapping is created, these entries will be written in twice, with the second (pathological?) entries (i.e. the ones with the same value twice) overriding the original entry.

i let the migration continue, and then did a spot-check of a couple of migrated histories. i looked at one object that had different values for the key/value pair in the hidReverseMapping, and at another object that had the same values. sure enough, the one with the differing values had the history migrated successfully, but the other one did not, the history was still empty.

i'm not at all clear how our data got into this pathological state, nor am i certain (just yet) how to clean things up, but i'm definitely making progress.
Added by Rob Miller on Dec 13, 2006 01:36 AM
last little bit of info for today. it looks as though ALL of the pathological entries in the ZVCStorageTool._history_id_mapping (i.e. the ones where the keys match the VersionInfo.history_id values) are duplicates; each one that has a bogus entry also has a valid entry. also, the number of entries in the ZopeRepository's _histories BTree exactly matches the number of valid entries in the _history_id_mapping. this implies that the pathological entries in _history_id_mapping shouldn't even be there at all.

i tested this out by deleting the entries by hand on a debug prompt, and then running the CMFEditions history storage migration; at first glance this seems to have worked, all of the pages i spot-checked had their history, even when they didn't before. we'll need to write a script that spiders our site before and after migration to make sure that this is actually complete, but if so then we have a workaround.

it's still a mystery where those entries came from in the first place. if it turns out that the other sites reporting migration problems are having the same issue, it would be a simple matter to change the migration routine to fix things up before doing the migration. i've attached a patch (untested) that would accomplish this.

i realize there are now two separate issues attached to this ticket... there's the original issue which is that 1.0a4 is not compatible w/ the recent changes to Zope's DateTime implementation (arguably this is due to a ZVC bug), and then there's the migration issue. i'll leave it to gregweb to decide what to do with the issues... ;-)
Added by Rob Miller on Jan 02, 2007 08:41 AM
whoops, the patch i committed before had a bug, the pop() on the hidMapping BTree was interfering with the iteration over the hidMapping keys. new patch attached.
Added by Gregoire Weber on Jan 10, 2007 09:37 PM
Responsible manager: (UNASSIGNED) → gregweb
Thanks Rob for your investigations and writing about your findings. Glad to hear that you finaly could fix the issue for your site. I remember that a user of CMFEditions had these pathalogical entries also. It was and is the total mistery for me. I'll need to have a look to make the mistery explainable ...

What did your spider completenes test result in you mentioned in your post on December 13?

No responses can be added.