"invalidations out of order" when committing a blob in ZODB 3.8.5

[David Glick]

We're occasionally getting the following traceback when committing a transaction including a new blob, using ZODB 3.8.5.

Traceback (innermost last):
  Module ZPublisher.Publish, line 125, in publish
  Module Zope2.App.startup, line 238, in commit
  Module transaction._manager, line 93, in commit
  Module transaction._transaction, line 325, in commit
  Module transaction._transaction, line 424, in _commitResources
  Module ZODB.Connection, line 540, in commit
  Module ZODB.Connection, line 1140, in _commit_savepoint
  Module ZODB.Connection, line 336, in invalidate
AssertionError: invalidations out of order, None < '\x03\x83k\xd8\xcb4b\x99'

Can you provide more information on what causes this exception so that I can determine whether it is a ZODB issue or an app issue? I see from http://svn.zope.org/ZODB/branches/3.8/?view=rev&rev=106543 that this AssertionError was added for 3.8.5, so wanted to be sure to call it to your attention in case it's a new issue.

[Jim Fulton (jim-zope)]

On Tue, Jan 19, 2010 at 2:32 PM, David Glick <email address hidden> wrote:
> Public bug reported:
>
> We're occasionally getting the following traceback when committing a
> transaction including a new blob, using ZODB 3.8.5.
>
> Traceback (innermost last):
>  Module ZPublisher.Publish, line 125, in publish
>  Module Zope2.App.startup, line 238, in commit
>  Module transaction._manager, line 93, in commit
>  Module transaction._transaction, line 325, in commit
>  Module transaction._transaction, line 424, in _commitResources
>  Module ZODB.Connection, line 540, in commit
>  Module ZODB.Connection, line 1140, in _commit_savepoint
>  Module ZODB.Connection, line 336, in invalidate
> AssertionError: invalidations out of order, None < '\x03\x83k\xd8\xcb4b\x99'

Interesting.

> Can you provide more information on what causes this exception so that I
> can determine whether it is a ZODB issue or an app issue?

I'm sure it is a ZODB issue. I'll have to dig into it.

> I see from
> http://svn.zope.org/ZODB/branches/3.8/?view=rev&rev=106543 that this
> AssertionError was added for 3.8.5, so wanted to be sure to call it to
> your attention in case it's a new issue.

Yup. Thanks.

Jim

--
Jim Fulton

[Graham Perrin (grahamperrin-gmail)]

I noted
AssertionError: invalidations out of order, None
around 12 January; <http://n2.nabble.com/-tp4291640p4291640.html>

[Martijn Jacobs (martijn-fourdigits)]

I can confirm this behaviour with ZODB 3.8.5 with blob storage enabled. The problem goes away when using ZODB 3.8.4.

[Hanno Schlichting (hannosch)]

I have seen the same behavior in a site of ours.

[Christian Zagrodnick (zagy)]

I also see this with ZODB 3.9.4 but not with ZODB 3.9.3

[Christian Zagrodnick (zagy)]

Any update on this? Can I help somehow?

[Jim Fulton (jim-zope)]

On Fri, Jun 11, 2010 at 5:31 AM, Christian Zagrodnick <email address hidden> wrote:
> Any update on this?

No. I don't consider this a burning priority. I'm just glad I added the
assertion. The transaction fails, rather than causing database
inconsistency.

> Can I help somehow?

Obviously, figuring out how to reproduce this would be
wildly helpful. :)

Jim

--
Jim Fulton

[Christian Zagrodnick (zagy)]

I added a test case to svn+ssh://svn.zope.org/repos/main/ZODB/branches/zagy-lp509801 (test -t savepoint_commit)

It works in

BlobAdaptedFileStorageBlobTests
BlobFileStorageBlobTests
MVCCMappingBlobTests

It is broken in:

ClientStorageNonSharedBlobsBlobTests
ClientStorageSharedBlobsBlobTests

The problem seems to be that the savepoint_storage._tid is None (storeBlob returns self._tid). But I don't know what that means or if that's good or bad ;)

Does that help a bit, Jim?

[Jim Fulton (jim-zope)]

On Fri, Jun 11, 2010 at 10:49 AM, Christian Zagrodnick <email address hidden> wrote:
> I added a test case to svn+ssh://svn.zope.org/repos/main/ZODB/branches
> /zagy-lp509801 (test -t savepoint_commit)
>
> It works in
>
> BlobAdaptedFileStorageBlobTests
> BlobFileStorageBlobTests
> MVCCMappingBlobTests
>
> It is broken in:
>
> ClientStorageNonSharedBlobsBlobTests
> ClientStorageSharedBlobsBlobTests
>
> The problem seems to be that the savepoint_storage._tid is None
> (storeBlob returns self._tid). But I don't know what that means  or if
> that's good or bad ;)
>
> Does that help a bit, Jim?

It should help a lot. Thanks!

Jim

--
Jim Fulton

[Christian Zagrodnick (zagy)]

Christian Theune volunteered do fix that.

[Jim Fulton (jim-zope)]

On Mon, Jun 14, 2010 at 3:45 AM, Christian Zagrodnick <email address hidden> wrote:
> Christian Theune volunteered do fix that.

Cool. I want to review the fix before it is committed to trunk.

Jim

--
Jim Fulton

[Christian Theune (ctheune)]

Ok. Looking at the code it seems like invalidate() is called explicitly without needing to know the serial but we simply need to ensure to satisfy the guard.

I made a fix on Zagy's branch in revision 113519.

Jim: can you review?

[Christian Zagrodnick (zagy)]

Jim, would you have a look at it?

[Jim Fulton (jim-zope)]

On Mon, Jun 21, 2010 at 10:54 AM, Christian Zagrodnick <email address hidden> wrote:
> Jim, would you have a look at it?

Absolutely. I just haven't gotten to it yet.

Jim

--
Jim Fulton

[Harald Friessnegger (frisi)]

i do have a couple of these errors in the error_log of a plone4.0 portal as well. today it lead to objects not beeing addable to a folder until i restarted the instance.

as there seems to be a fix for this already it would be great if it gets reviewed and released soon so it can be included in the next zope 2.12.X release.