Transient IOErrors with blob access and Zeo

[Patrick Gerken]

Sometimes, a accessing a blob fails with the traceback below.
The bug cannot be reproduced reliably.
The blobs in question exist, this has been validated before. They have not been modified lately.
We noticed that the bug does not appear for several days after a restart of zope.
The /tmp/ directory has plenty of free space and plenty of free inodes.

Here is the traceback:

1342617765.770.306309826541 http://site/url/get_page_image
Traceback (innermost last):
  Module ZPublisher.Publish, line 127, in publish
  Module ZPublisher.mapply, line 77, in mapply
  Module ZPublisher.Publish, line 47, in call_object
  Module project.contenttypes.content.review, line 231, in get_page_image
  Module plone.app.blob.field, line 273, in get_size
  Module plone.app.blob.field, line 85, in get_size
  Module plone.app.blob.utils, line 55, in openBlob
  Module ZODB.blob, line 156, in open
  Module ZODB.blob, line 307, in __init__
IOError: [Errno 2] No such file or directory: '/tmp/tmpke0dAV'

Some things I noticed:
The method openBlob in plone.app.blob.utils:55 is the second try to open the blob, there is an exception handler trying to open the blob first, in the exception handler there is a call to blob._p_deactivate and then a second try.

From my understanding of ZODB.blob and some experimentation on the system, the "/tmp/" directory is ONLY used when the blob object has _p_jar set to None. From my understand this only happens with a fresh Blob object that has never been persisted.

I am going to add traceback logging to plone.app.blob.utils:55, to see why the IOError has been thrown in the first place, and to Blobs __init__ method to see if a fresh object gets created prior to the error.

If anybody has an idea what else to look for, I'd be very grateful.

[Patrick Gerken (do3cc)]

The stacktrace has not helped alot but using sentry for logging helped and gave me an idea.
I can now reproduce the error on two of my four zeoclients. I can confirm that the objects have not been modified.

I noticed that the files ALWAYS the same tmpfile in the variable _p_blob_uncommitted.
It does not change between requests, only between the instances.