[ZODB-Dev] Relstorage pack problems

[Santi Camps]

On Fri, Jan 23, 2009 at 2:38 AM, Shane Hathaway <shane at hathawaymix.org> wrote:
> Santi,
>
> I hope you don't mind me discussing your database in public.  I'm not going
> to talk about anything that looks like it could be private.  Other
> RelStorage users might benefit from the analysis.
>

Hi Shane

That's right, of course.  Furthermore, thanks a lot for this analysis.

> Looking at your database, I see that something bad happened just before
> transaction 250499913441768123.  That number is an encoded time stamp:
>
>  >>> from ZODB.TimeStamp import TimeStamp
>  >>> from ZODB.utils import p64
>  >>> str(TimeStamp(p64(250499913441768123)))
>  '2008-11-17 19:36:04.913130'
>
> The transaction log entry says "initial database creation", which means that
> the database had no root object (OID 0), so ZODB created one and started a
> brand new database.  Strange!  This happened about an hour after a
> transaction labeled:
>
>  /asp_ekartek/kmkey_iso/portal_setup/manage_doUpgrades
>
> I'm guessing that an upgrade script did something horribly wrong that day.
>

I've been revising what happens this day, and I think we are near to
get the guilty.    This day the database was migrated from
DirectoryStorage to Relstorage.    AFAIK, the upgrade should be done
in DirectoryStorage, before the conversion to Relstorage.   I don't
think the upgrade can corrupt the database, all operations ara high
level ones, and we never change ZODB objects by hand.   So, the
problem should be in the conversion process.

I attach the script we use to do the conversion.   Be free to include
in Relstorage if you think it's useful and it is well done (as I said,
I really don't know much about ZODB, I just mix zodbconvert.py with
some DirectoryStorage code)

> Furthermore, the entry for OID 0 in the current_object table points to an
> old transaction rather than the most recent transaction that modified OID 0.
>  That's not supposed to happen, even when you undo.  I hope RelStorage
> didn't do that!
>
> Did you or someone on your team change current_object by hand?  I can
> understand why you would, since a simple modification to current_object
> would be a nice quick fix for the broken upgrade.  The fix would not be
> complete, though, because now the object_state table and the current_object
> table disagree on the current state of OID 0.
>
> According to object_state, even now, the current state of OID 0 still points
> to the small object graph that was accidentally created on November 17.  The
> pack code relies more on object_state than on current_object, so the pack
> code sees only a handful of objects that are reachable.  Packing with
> garbage collection removes everything that is not reachable.
>
> The current_object table is really just a cache of object_state.  If the
> schema were fully normalized, there would not be a current_object table.  In
> theory, the current_object table makes it possible to load ZODB objects
> quickly.  But if the current_object table results in problems like this, I
> need to consider alternatives.
>

We've used the attached script to convert a lot of others databases,
that are packing successfully, so something special should occurs in
this case.    The only explanation I can found is that the conversion
would be done without unmounting the DirectoryStorage database from
its Zope mount point, and that caused the problem.   The right way we
use to convert databases from DS to RS is, first of all, detach them
from Zope, then convert, and then mount the resultant RS, but It's
possible that were a human mistake that day.

> In any case, I believe you can get out of this mess pretty easily.  You need
> to delete the extra object states for OID 0 created on November 17.  I tried
> this in my copy of your database:
>
> delete from object_state where zoid = 0 and tid in (
>  250499913441768123, 250499913748614178);
>
> After that, "select count(1) from object_state where zoid = 0;" should tell
> you there is only one state in the database for OID 0.  Packing should work
> fine then.  It seemed to do the right thing on my copy, but I don't have
> your application code to check it.
>

Thank you very much for that information.  I really could not be able
to found it myself.    We will try it as soon as possible and let you
know the results

Regards
-- 
Santi Camps (Earcon S.L.)
http://www.earcon.com
http://www.kmkey.com
-------------- next part --------------
A non-text attachment was scrubbed...
Name: relstorageconvert.py
Type: text/x-python
Size: 3456 bytes
Desc: not available
Url : http://mail.zope.org/pipermail/zodb-dev/attachments/20090123/c0a37f23/attachment-0001.py