Blob temp file get's removed before it should

[Christian Zagrodnick]

That's a ZEO ClientStorage with non-shared blob directory. I really have no idea what's happening there.

Traceback (most recent call last):
File "/opt/cms/bootstrap-parts/python/lib/python2.6/asyncore.py", line 84, in write
  obj.handle_write_event()
File "/opt/cms/bootstrap-parts/python/lib/python2.6/asyncore.py", line 435, in handle_write_event
  self.handle_write()
File "/opt/cms/eggs/ZODB3-3.9.3-py2.6-linux-x86_64.egg/ZEO/zrpc/smac.py", line 276, in handle_write
  message = message.next()
File "/opt/cms/eggs/ZODB3-3.9.3-py2.6-linux-x86_64.egg/ZEO/zrpc/connection.py", line 750, in __outputIterator
  for method, args in iterator:
File "/opt/cms/eggs/ZODB3-3.9.3-py2.6-linux-x86_64.egg/ZEO/ServerStub.py", line 213, in store
  f = open(blobfilename, 'rb')
IOError: [Errno 2] No such file or directory: '/var/zeit.cms/database/blobs/app1/182/0x00zM6w1d.tmp-'

[Hanno Schlichting (hannosch)]

I have seen the same problem two times in the last week with the following traceback:

Traceback (most recent call last):
 File "/usr/lib/python2.6/asyncore.py", line 86, in write
   obj.handle_write_event()
 File "/usr/lib/python2.6/asyncore.py", line 441, in handle_write_event
   self.handle_write()
 File "/home/norden/appserver/eggs/ZODB3-3.10.0b4-py2.6-linux-i686.egg/ZEO/zrpc/smac.py", line 272, in handle_write
   message = message.next()
 File "/home/norden/appserver/eggs/ZODB3-3.10.0b4-py2.6-linux-i686.egg/ZEO/zrpc/connection.py", line 561, in <genexpr>
   self.message_output(self.marshal.encode(0, 1, method, args)
 File "/home/norden/appserver/eggs/ZODB3-3.10.0b4-py2.6-linux-i686.egg/ZEO/ServerStub.py", line 213, in store
   f = open(blobfilename, 'rb')
IOError: [Errno 2] No such file or directory: '/home/norden/appserver/var/blobcache/378/0x006b8EHY.tmp-'

I'm assuming something has cleaned away the "378" directory before the file could be opened.

[Jim Fulton (jim-zope)]

On Thu, Jun 17, 2010 at 2:19 AM, Christian Zagrodnick <email address hidden> wrote:
> Public bug reported:
>
> That's a ZEO ClientStorage with non-shared blob directory. I really have
> no idea what's happening there.
>
> Traceback (most recent call last):
> File "/opt/cms/bootstrap-parts/python/lib/python2.6/asyncore.py", line 84, in write
>  obj.handle_write_event()
> File "/opt/cms/bootstrap-parts/python/lib/python2.6/asyncore.py", line 435, in handle_write_event
>  self.handle_write()
> File "/opt/cms/eggs/ZODB3-3.9.3-py2.6-linux-x86_64.egg/ZEO/zrpc/smac.py", line 276, in handle_write
>  message = message.next()
> File "/opt/cms/eggs/ZODB3-3.9.3-py2.6-linux-x86_64.egg/ZEO/zrpc/connection.py", line 750, in __outputIterator
>  for method, args in iterator:
> File "/opt/cms/eggs/ZODB3-3.9.3-py2.6-linux-x86_64.egg/ZEO/ServerStub.py", line 213, in store
>  f = open(blobfilename, 'rb')
> IOError: [Errno 2] No such file or directory: '/var/zeit.cms/database/blobs/app1/182/0x00zM6w1d.tmp-'

Can you tell me more about this? Did this just appear in the log? Or
did it affect a web request? Was there any negative effect other than
the message in the log? (I suppose the client disconnected and reconnected.)

One possible explanation is that the transaction was aborted before
the iterator opened the file. If this is the case, then the error is
mostly harmless.

In any case, I need more information to decide how to proceed.

Jim

--
Jim Fulton

[Jim Fulton (jim-zope)]

The only way for this to happen that I can think of is that a
transaction is aborted after the commit process has started. I don't
know how this would happen in the wild.

In 3.10.3, I'm changing the ZEO tpc_abort call to the server to be
synchronous, which should address this case. Maybe there's another
case. Please report whether this goes way after upgrading to 3.10.3 or
higher.