Solved? Re: Can't get into snapshot, was Re: Backup aborted - why? (dirstor 1.1.9)

> On Tuesday 28 December 2004 21:07, Paul Winkler wrote:
>
>> Aaaand now that that's taken care of, and I've restarted
>> the ZEO server and confirmed that it leaves snapshot mode
>> after startup, I can no longer get into snapshot mode :-(
>>
>> Here's the error:
>> Traceback (most recent call last):
>>   File "snapshot.py", line 260, in ?
>>     main()
>>   File "snapshot.py", line 61, in main
>>     s.acquire()
>>   File "snapshot.py", line 108, in acquire
>>     lock_file(f)
>>   File "/zope/Zope-2.7.3-0-SoftwareHome/lib/python/ZODB/lock_file.py",
>> line
> 42, in lock_file
>>     fcntl.flock(file.fileno(), _flags)
>> IOError: [Errno 11] Resource temporarily unavailable
>
> Something has locked the file misc/sublock. On linux 'lsof' will tell
> you  what.

OK, it looks like it's the current ZEO process that has the lock:

$ sudo /usr/sbin/lsof +D /zope/ZopeInstanceHome/var/DirStor/misc
COMMAND    PID USER   FD   TYPE DEVICE SIZE   NODE NAME
python2.3 2442 zope    4u   REG    8,3    0 737230
/zope/ZopeInstanceHome/var/DirStor/misc/lock
python2.3 2442 zope    5u   REG    8,3    0 737236
/zope/ZopeInstanceHome/var/DirStor/misc/sublock
python2.3 2444 zope    4u   REG    8,3    0 737230
/zope/ZopeInstanceHome/var/DirStor/misc/lock
python2.3 2444 zope    5u   REG    8,3    0 737236
/zope/ZopeInstanceHome/var/DirStor/misc/sublock
python2.3 2445 zope    4u   REG    8,3    0 737230
/zope/ZopeInstanceHome/var/DirStor/misc/lock
python2.3 2445 zope    5u   REG    8,3    0 737236
/zope/ZopeInstanceHome/var/DirStor/misc/sublock

$ ps wax | grep py
 2442 ?        S      0:00 /usr/local/bin/python2.3
/zope/ZopeSoftwareHome/lib/python/ZEO/runzeo.py -C
/zope/ZopeInstanceHome/etc/ze
 2444 ?        S      0:00 /usr/local/bin/python2.3
/zope/ZopeSoftwareHome/lib/python/ZEO/runzeo.py -C
/zope/ZopeInstanceHome/etc/ze
 2445 ?        S      0:00 /usr/local/bin/python2.3
/zope/ZopeSoftwareHome/lib/python/ZEO/runzeo.py -C
/zope/ZopeInstanceHome/etc/ze
 2526 pts/0    S      0:00 grep py

> But this is strange.... The only call to lock_file in acquire in
> snapshot.py  is inside an exception handler for IOError. It should be
> converting this  exception to a DirectoryStorageError('could not lock
> storage directory')
>
> That line is commented # Forget to patch ZEO? See doc/install and
> http://dirstorage.sourceforge.net/install.html.
> That patch is only for older ZEO versions, and your log indicates that
> the  remote method call is getting through. Maybe there is some other
> version  incompatibility here.

I dunno how that could be... I've just confirmed that
all zope servers and the zeo server in this cluster are running
zope 2.7.3 and DirectoryStorage 1.1.9.

>> Here's the server log since the restart... is that PROBLEM line
>> something to worry about?
>
> This one?...
>
>> 2004-12-28T15:46:10 PROBLEM(100) DirectoryStorage shutdown without
>> snapshot
>
> It normally puts the storage into snapshot mode when shutting down. This
>  message indicates that it tried and failed.

Probably as a result of the disk being full?
Remember, that seems to be what got me into this mess...

> On startup there is no message "Engaging in snapshot mode", so that file
> lock  had definitely been released at that point.
>
>
> That gives you plenty of strange things for further debugging. Sorry I
> cant be  of more direct help.

Weird stuff.  And here's one more oddity - visiting my DSToolkit instance
gives this error:

------
2004-12-29T12:58:24 ERROR(200) SiteError
http://localhost:7776/DSToolkit/manage_DirectoryStorageToolkitForm
Traceback (most recent call last):
  File "/zope/ZopeSoftwareHome/lib/python/ZPublisher/Publish.py", line
101, in publish
    request, bind=1)
  File "/zope/ZopeSoftwareHome/lib/python/ZPublisher/mapply.py", line 88,
in mapply
    if debug is not None: return debug(object,args,context)
  File "/zope/ZopeSoftwareHome/lib/python/ZPublisher/Publish.py", line 39,
in call_object
    result=apply(object,args) # Type s<cr> to step into published object.
  File "/zope/ZopeSoftwareHome/lib/python/Shared/DC/Scripts/Bindings.py",
line 306, in __call__
    return self._bindAndExec(args, kw, None)
  File "/zope/ZopeSoftwareHome/lib/python/Shared/DC/Scripts/Bindings.py",
line 343, in _bindAndExec
    return self._exec(bound_data, args, kw)
  File "/zope/ZopeSoftwareHome/lib/python/App/special_dtml.py", line 175,
in _exec
    try: result = render_blocks(self._v_blocks, ns)
  File
"/zope/ZopeInstanceHome/Products/DirectoryStorageToolkit/DirectoryStorageToolkit.py",
line 55, in is_directorystorage
    self._v_is_directory_storage = fn()
  File "/zope/ZopeSoftwareHome/lib/python/ZEO/ServerStub.py", line 159, in
call
    return self.rpc.call(self.name, *a, **kwa)
  File "/zope/ZopeSoftwareHome/lib/python/ZEO/zrpc/connection.py", line
368, in
call
    raise DisconnectedError()
DisconnectedError
------


Restarting the Zope process seems to clear this one up.
So maybe after a disk full error on a zeo server,
it's necessary to restart the zeo clients too?
(even if they're on different hosts??)
I don't understand how that could be true, but it seems to be
the case...

AND - once I've done that, and restarted zeo again for good measure,
I seem to be able to get the storage into snapshot mode.
Backup script is proceeding currently and so far all seems well.

I guess I should've applied the old "when in doubt, restart" principle
more liberally :-\

Well, thanks for the help.
As the developer / maintainer, I wonder if you would find it interesting
to see what happens if you deliberately run out of room on a test
storage running zeo... hopefully my experience is repeatable, if not,
we'll just pretend this never happened ;-)

(p.s. the storage is on reiser 3, if that matters.)

--PW




-------------------------------------------------------
SF email is sponsored by - The IT Product Guide
Read honest & candid reviews on hundreds of IT Products from real users.
Discover which products truly live up to the hype. Start reading now. 
http://productguide.itmanagersjournal.com/