A storage error occurred during the second phase of the two-phase commit. Resources may be in an inconsistent state.

"Boylan, Ross" <[email protected]>
Newsgroups gmane.comp.web.zope.zodb
Message-ID <[email protected]> 
I got the indicated error, and a lot of other ones, during a run.  The traceback didn't help much figuring out where in my code  the program was when the exception got thrown.  The overall structure of the program is that it uses ZEO to track information about jobs that it must run, and runs those jobs in threads which in turn spawn another processes.  Each thread opens its own connection to the shared DB object.  The ZEO server is on the same machine.

I'm looking for help figuring out what went wrong and determining if my database is  corrupt.  I understand that some updates will not have been performed, but I mean more damaged than that.

I know that the disk filled during the run, although the first definitive sign of that was 2 hours after the above error.  It has plenty of free space now (the jobs that were running used lots of disk space).

There were also messages about too many open connections after the first error.  The number increased steadily throughout the run and ended with
DB.open() has 147 open connections with a pool_size of 21  
The program uses concurrent to limit the number of simultaneous jobs to 19, and they are supposed to close the connection when they are done.  The earlier errors may have caused that code to be skipped in some cases, but the system thinks all but 18 jobs are done, and so I'm not sure why the number of open connections is so high.

I have run the same program repeatedly before without incident.  This run involved maybe 8x more jobs than any previous ones, and some of the individual runs clearly used more disk space than earlier individual runs.

Fuller details about the errors:
A storage error occurred during the second phase of the two-phase commit.  Resources may be in an inconsistent state.
Error in tpc_abort() on manager <Connection at 7fcc49553240>
Traceback (most recent call last):
  File "/home/ross/.local/lib/python3.4/site-packages/transaction-1.6.1-py3.4.egg/transaction/_transaction.py", line 398, in _commitResources
    rm.tpc_finish(self)
  File "/home/ross/.local/lib/python3.4/site-packages/ZODB-5.0.0-py3.4.egg/ZODB/Connection.py", line 672, in tpc_finish
    serial = self._storage.tpc_finish(transaction)
  File "/home/ross/.local/lib/python3.4/site-packages/ZODB-5.0.0-py3.4.egg/ZODB/mvccadapter.py", line 182, in tpc_finish
    return self._storage.tpc_finish(transaction, invalidate_finish)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/ClientStorage.py", line 877, in tpc_finish
    tid = self._server.tpc_finish(id(txn), tbuf, f)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 761, in tpc_finish
    return self.__call(self.client.tpc_finish_threadsafe, tid, updates, f)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 725, in call
    return self.wait_for_result(result, timeout)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 731, in wait_for_result
    return future.result(self.timeout if timeout is None else timeout)
  File "/usr/lib/python3.4/concurrent/futures/_base.py", line 404, in result
    raise TimeoutError()
concurrent.futures._base.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/ross/.local/lib/python3.4/site-packages/transaction-1.6.1-py3.4.egg/transaction/_transaction.py", line 431, in _cleanup
    rm.tpc_abort(self)
  File "/home/ross/.local/lib/python3.4/site-packages/ZODB-5.0.0-py3.4.egg/ZODB/Connection.py", line 606, in tpc_abort
    self._storage.tpc_abort(transaction)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/ClientStorage.py", line 864, in tpc_abort
    self._call('tpc_abort', id(txn), timeout=timeout)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 739, in call
    return self.__call(self.call_threadsafe, method, args, **kw)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 725, in call
    return self.wait_for_result(result, timeout)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 731, in wait_for_result
    return future.result(self.timeout if timeout is None else timeout)
  File "/usr/lib/python3.4/concurrent/futures/_base.py", line 404, in result
    raise TimeoutError()
concurrent.futures._base.TimeoutError
Error in tpc_abort() on manager <Connection at 7fcc49590c50>
Traceback (most recent call last):
  File "/home/ross/.local/lib/python3.4/site-packages/transaction-1.6.1-py3.4.egg/transaction/_transaction.py", line 393, in _commitResources
    rm.tpc_vote(self)
  File "/home/ross/.local/lib/python3.4/site-packages/ZODB-5.0.0-py3.4.egg/ZODB/Connection.py", line 657, in tpc_vote
    s = vote(transaction)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/ClientStorage.py", line 750, in tpc_vote
    for oid in self._call('vote', id(txn)) or ():
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 739, in call
    return self.__call(self.call_threadsafe, method, args, **kw)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 725, in call
    return self.wait_for_result(result, timeout)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 731, in wait_for_result
    return future.result(self.timeout if timeout is None else timeout)
  File "/usr/lib/python3.4/concurrent/futures/_base.py", line 404, in result
    raise TimeoutError()
concurrent.futures._base.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/ross/.local/lib/python3.4/site-packages/transaction-1.6.1-py3.4.egg/transaction/_transaction.py", line 431, in _cleanup
    rm.tpc_abort(self)
  File "/home/ross/.local/lib/python3.4/site-packages/ZODB-5.0.0-py3.4.egg/ZODB/Connection.py", line 606, in tpc_abort
    self._storage.tpc_abort(transaction)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/ClientStorage.py", line 864, in tpc_abort
    self._call('tpc_abort', id(txn), timeout=timeout)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 739, in call
    return self.__call(self.call_threadsafe, method, args, **kw)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 725, in call
    return self.wait_for_result(result, timeout)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 731, in wait_for_result
    return future.result(self.timeout if timeout is None else timeout)
  File "/usr/lib/python3.4/concurrent/futures/_base.py", line 404, in result
    raise TimeoutError()
concurrent.futures._base.TimeoutError

# and many more
My high level code has
       executor = concurrent.futures.ThreadPoolExecutor(max_workers=nSimultaneous)
        fs = []
        for chunk in self.chunks():
            fs.append(executor.submit(do_chunk, db, chunk._p_oid, EmergencyStop, sasFile))
        while True:
            done, not_done = concurrent.futures.wait(fs, timeout=reportEvery)
 So I think some of the timeout may be coming from the last line.  But I'm  not sure about that, since it's supposed to, and normally does,  just break every 30 minutes, give a progress report, and resume waiting (unless all are done).

There were also some 
data_received 4 0 True
Traceback (most recent call last):
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/base.py", line 130, in data_received
    self.message_received(collected)
  File "/home/ross/.local/lib/python3.4/site-packages/ZEO-5.0.1-py3.4.egg/ZEO/asyncio/client.py", line 204, in message_received
    future = self.futures.pop(msgid)
KeyError: 86
DB.open() has 22 open connections with a pool_size of 21
DB.open() has 23 open connections with a pool_size of 21

Ross

-- 
You received this message because you are subscribed to the Google Groups "zodb" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [email protected].
For more options, visit https://groups.google.com/d/optout.
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.