[ZODB-Dev] RelStorage MySQL - StorageError: Unable to acquire commit lock

[Rudá Porto Filgueiras]

On Wed, Aug 12, 2009 at 5:35 PM, Jürgen
Herrmann<Juergen.Herrmann at xlhost.de> wrote:
>
> On Wed, August 12, 2009 22:23, Rudá Porto Filgueiras wrote:
>> I begin to use RelStorage in a production site with Plone 2.5.
>> Everything was running without failures since 01 august 2009.
>> But today after a failure in tpc_abort, all instances conneceted to
>> MySQL can't acquire commit lock.
>>
>> Follow tpc_abort traceback:
>>
>> 2009-08-12T14:12:08 ERROR txn.1115806016 Error in tpc_abort() on
>> manager <MultiObjectResourceAdapter for <ZODB.DB.TransactionalUndo
>> object at 0x210f6790> at 654293328>
>> Traceback (most recent call last):
>>   File
>> "/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/transaction/_transaction.py",
>> line 533, in _cleanup
>>     rm.tpc_abort(self)
>>   File
>> "/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/transaction/_transaction.py",
>> line 628, in tpc_abort
>>     self.manager.tpc_abort(txn)
>>   File
>> "/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/BaseStorage.py",
>> line 194, in tpc_abort
>>     self._abort()
>>   File
>> "/usr/local/zope/agecom-virtual/eggs/RelStorage-1.2.0b2-py2.4.egg/relstorage/relstorage.py",
>> line 710, in _abort
>>     self._rollback_load_connection()
>>   File
>> "/usr/local/zope/agecom-virtual/eggs/RelStorage-1.2.0b2-py2.4.egg/relstorage/relstorage.py",
>> line 166, in _rollback_load_connection
>>     self._load_conn.rollback()
>> OperationalError: (2006, 'MySQL server has gone away')
>>
>> And after, all instances report this exeption:
>>
>> 2009-08-12T14:21:53 ERROR Zope.SiteErrorLog
>> http://adm.agecom.ba.gov.br/login_form
>> Traceback (innermost last):
>>   Module ZPublisher.Publish, line 121, in publish
>>   Module Zope2.App.startup, line 240, in commit
>>   Module transaction._manager, line 96, in commit
>>   Module transaction._transaction, line 395, in commit
>>   Module transaction._transaction, line 498, in _commitResources
>>   Module ZODB.Connection, line 730, in tpc_vote
>>   Module relstorage.relstorage, line 675, in tpc_vote
>>   Module relstorage.relstorage, line 659, in _vote
>>   Module relstorage.relstorage, line 566, in _prepare_tid
>>   Module relstorage.adapters.mysql, line 506, in start_commit
>>   Module relstorage.adapters.mysql, line 672, in _hold_commit_lock
>> StorageError: Unable to acquire commit lock
>>
>> I solve the problem restarting all instances, and the site became
>> operational again, but I have some questions:
>>
>> This can be a bug or there is any problem in my enviroment/application?
>> There is another solution to release commit lock without restart all instances?
>>
>> Cheers,
>>
>> --
>> Rudá Porto Filgueiras
>> http://python-blog.blogspot.com
>> _______________________________________________
>> For more information about ZODB, see the ZODB Wiki:
>> http://www.zope.org/Wikis/ZODB/
>>
>> ZODB-Dev mailing list  -  ZODB-Dev at zope.org
>> http://mail.zope.org/mailman/listinfo/zodb-dev
>>
>
> i just came back from reading relstorage code (research work for
> radosstorage) and the lock is actually held on the mysql server.
> my guess is that the connection drop you experience earlier left
> the lock in place on the mysql-server. obviously the mysql-server
> did not notice you connection dying, otherwise it would have
> released the lock,see
> http://dev.mysql.com/doc/refman/5.0/en/miscellaneous-functions.html#function_get-lock

But the MySQL is hosted in the same machine, it's not a network failure. :-(
I supose this query can solve the problem too:

SELECT RELEASE_LOCK(CONCAT(DATABASE(), '.commit'))

> probably restarting mysql would have solved your issue?!

I think so, but I can't test it. :-(

But the question remain, why the database connection was not safely
closed when tcp_abort fail?
I guess MySQL adapter.close raise a close_exception and it's not logged.

But, it's not the first time this issue happen, I saw the same problem
but it's not easy to reproduce.
How to detect that a connection die in the midle of transaction and
has left the commit lock *LOCKED*?

If it can be detect and FLAGED, adapter.close or load_connection
should take care to execute MySQL RELEASE_LOCK?

> regards, jürgen
> --
>>> XLhost.de - eXperts in Linux hosting ® <<
>
> XLhost.de GmbH
> Jürgen Herrmann, Geschäftsführer
> Boelckestrasse 21, 93051 Regensburg, Germany
>
> Geschäftsführer: Volker Geith, Jürgen Herrmann
> Registriert unter: HRB9918
> Umsatzsteuer-Identifikationsnummer: DE245931218
>
> Fon:  +49 (0)800 XLHOSTDE [0800 95467833]
> Fax:  +49 (0)800 95467830
>
> WEB:  http://www.XLhost.de
> IRC:  #XLhost at irc.quakenet.org
>
>



-- 
Rudá Porto Filgueiras
http://python-blog.blogspot.com