[ZODB-Dev] RelStorage MySQL - StorageError: Unable to acquire commit lock
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 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@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] RelStorage MySQL - StorageError: Unable to acquire commit lock
On Wed, Aug 12, 2009 at 5:35 PM, Jürgen Herrmann 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 > 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-...@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: #xlh...@irc.quakenet.org > > -- 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@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] RelStorage MySQL - StorageError: Unable to acquire commit lock
On Wed, Aug 12, 2009 at 8:20 PM, Shane Hathaway wrote: > Rudá Porto Filgueiras wrote: >> >> (...) >> 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? > > Perhaps some instance was taking a very long time to finish a transaction > commit and you didn't notice it. RelStorage does everything it can to > minimize the amount of time the commit lock is held (it uses a strategy > similar to ZEO), but applications are ultimately in control of how long it > takes to commit a transaction. > > A concurrent pack might provide another explanation. Have you ever packed > the database? No, there is no pack operation running, only people using Plone to put content. > This could also indicate a bug in MySQL. According to the documentation of > get_lock(), all locks will be released when connections terminate, but maybe > you ran into a MySQL bug that causes locks to stick around. Yeah, it sticks for ever. :-( Maybe some tunning on inactive connection time in MySQL should help? > To me, the most plausible explanation is a MySQL bug, since the other > hypotheses don't explain why one of the connections terminated prematurely. I suspect it's MySQL related, becouse it happen with Plone 2.5 and Plone 3.0, RelStorage 1.1.3 and 1.2b2. > If I were you, I would try the same application with PostgreSQL instead of > MySQL. If the bug persists, then at least we know it's not a MySQL bug. :-) I first try to use PostgreSQL, but the time to convert ZODB FileStorage was much larger than MySQL, then I decide to use MySQL. >> But the question remain, why the database connection was not safely >> closed when tcp_abort fail? > > The error message occurring in tpc_abort was "OperationalError: (2006, > 'MySQL server has gone away')", suggesting that the database connection was > *already closed*. Yes, it was closed in the midle of transaction, but if you are sure there is nothing to do with RelStorage and there is no possible or workaround to the RelStoratge MySQL adapter to lead with MySQL bugs or resistent do to network failures and recover from this "deadlock" situation (or it will an ugly hack), I will move to PostgreSQL. I also began with MySQL 5.0 from CentOS 5.0 distribution and after a change to MySQL 5.4.1 and this failure occur on both. Cheers, > Shane -- 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@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] RelStorage MySQL - StorageError: Unable to acquire commit lock
On Thu, Aug 13, 2009 at 5:45 PM, Ross J. Reedstrom wrote: > On Wed, Aug 12, 2009 at 08:57:39PM -0300, Rudá Porto Filgueiras wrote: >> On Wed, Aug 12, 2009 at 8:20 PM, Shane Hathaway wrote: >> > A concurrent pack might provide another explanation. Have you ever packed >> > the database? >> >> No, there is no pack operation running, only people using Plone to put >> content. > > Hmm, it's possible for some things in Plone to keep transactions open a > very long time: refreshing the portal_catalog for example. Yes, but there is no portal_catalog update too, only normal catalog operations. >> I first try to use PostgreSQL, but the time to convert ZODB >> FileStorage was much larger than MySQL, then I decide to use MySQL. > > > > I'm interested in knowing why you're moving from ZODB to RelStorage, > rather than ZEO? How large is your Data.fs, if you don't mind sharing > that information? Our Data.fs is not so large, it's about 5GB but it will almost reach 10GB in six months or before. One important reason to use RelStorage is backend replication possibilities (we are not using it yet) and to give better performance when many people put content in Plone at same time. ZODB is not optmized for large write operations and ZEO will scale poor than RelStraoge in multiple CPU servers, and I know that IO is normaly the problem but we have 15K HBA storage. I really wish some bechmarks scripts to run in our deploy to estimate more acurately how better is RelStorage than ZEO. Shane benchmark results was the main information that compare ZEO and RelStorage and motivate the swicth, and the number of Zope instances that will grow (new server) are another reason. > Ross > -- > Ross Reedstrom, Ph.D. reeds...@rice.edu > Systems Engineer & Admin, Research Scientist phone: 713-348-6166 > The Connexions Project http://cnx.org fax: 713-348-3665 > Rice University MS-375, Houston, TX 77005 > GPG Key fingerprint = F023 82C8 9B0E 2CC6 0D8E F888 D3AE 810E 88F0 BEDE -- 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@zope.org http://mail.zope.org/mailman/listinfo/zodb-dev
[ZODB-Dev] Repair corrupted RelStorage database
How can I repair or verify a RelStorage database? I´m using MySQL Adapter, there is any script like fsrecover.py Follow the failure when RelStorage try to load some objects: 2010-01-30T04:25:14 ERROR ZODB.Connection Couldn't load state for 0x04ef0f59 Traceback (most recent call last): File "/usr/local/zope-agecom/plone/eggs/ZODB3-3.8.4_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py", line 847, in setstate self._setstate(obj) File "/usr/local/zope-agecom/plone/eggs/ZODB3-3.8.4_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py", line 888, in _setstate p, serial = self._storage.load(obj._p_oid, self._version) File "/usr/local/zope-agecom/plone/eggs/RelStorage-1.4.0b1-py2.4.egg/relstorage/storage.py", line 432, in load raise POSKeyError(oid) POSKeyError: 0x04ef0f59 -- Rudá Porto Filgueiras http://python-blog.blogspot.com http://twitter.com/rudaporto ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] Repair corrupted RelStorage database
On Sat, Jan 30, 2010 at 6:56 AM, Shane Hathaway wrote:
> Rudá Porto Filgueiras wrote:
>
>> How can I repair or verify a RelStorage database?
>> I´m using MySQL Adapter, there is any script like fsrecover.py
>>
>> Follow the failure when RelStorage try to load some objects:
>>
>> 2010-01-30T04:25:14 ERROR ZODB.Connection Couldn't load state for
>> 0x04ef0f59
>> Traceback (most recent call last):
>> File
>> "/usr/local/zope-agecom/plone/eggs/ZODB3-3.8.4_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
>> line 847, in setstate
>>self._setstate(obj)
>> File
>> "/usr/local/zope-agecom/plone/eggs/ZODB3-3.8.4_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
>> line 888, in _setstate
>>p, serial = self._storage.load(obj._p_oid, self._version)
>> File
>> "/usr/local/zope-agecom/plone/eggs/RelStorage-1.4.0b1-py2.4.egg/relstorage/storage.py",
>> line 432, in load
>>raise POSKeyError(oid)
>> POSKeyError: 0x04ef0f59
>>
>
> To diagnose this, I would:
>
> - Examine the logs in detail. There should be a log entry giving details
> about that specific POSKeyError.
>
Follow error from november 2009 (there are some repeated (five) errors like
that on the date/time).
550308-2009-11-28T05:31:51 ERROR ZODB.Connection Couldn't load state for
0x03ebd4
550309-Traceback (most recent call last):
550310- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
line 797, in setstate
550311-self._setstate(obj)
550312- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
line 855, in _setstate
550313-self._reader.setGhostState(obj, p)
550314- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/serialize.py",
line 604, in setGhostState
550315-state = self.getState(pickle)
550316- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/serialize.py",
line 597, in getState
550317-return unpickler.load()
550318- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/serialize.py",
line 471, in _persistent_load
550319-return self.load_oid(reference)
550320- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/serialize.py",
line 537, in load_oid
550321-return self._conn.get(oid)
550322- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
line 225, in get
550323-p, serial = self._storage.load(oid, self._version)
550324- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
line 1196, in load
550325-return self._storage.load(oid, self._base_version)
550326- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZEO/ClientStorage.py",
line 727, in load
550327-return self.loadEx(oid, version)[:2]
550328- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZEO/ClientStorage.py",
line 750, in loadEx
550329-data, tid, ver = self._server.loadEx(oid, version)
550330- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZEO/ServerStub.py",
line 196, in loadEx
550331-return self.rpc.call("loadEx", oid, version)
550332- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.7.3_polling-py2.4-linux-x86_64.egg/ZEO/zrpc/connection.py",
line 650, in call
550333-raise inst # error raised by server
550334:POSKeyError: 0x06294e
This errros is today errors, there are repeated (10) errors like that:
835744:2010-01-30T09:26:47 WARNING relstorage POSKeyError on oid 1793877: no
tid found; Current transaction is 253262639700997905; Recent object tids: []
835745---
835746-2010-01-30T09:26:47 ERROR ZODB.Connection Couldn't load state for
0x1b5f55
835747-Traceback (most recent call last):
835748- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.8.4_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
line 847, in setstate
835749-self._setstate(obj)
835750- File
"/usr/local/zope/agecom-virtual/eggs/ZODB3-3.8.4_polling-py2.4-linux-x86_64.egg/ZODB/Connection.py",
line 888, in _setstate
835751-p, serial = self._storage.load(obj._p_oid, self._version)
835752- File
"/usr/local/zope/agecom-virtual/eggs/RelStorage-1.4.0b1-py2.4.egg/relstorage/storage.py",
line 432, in load
835753:raise POSKeyError(oid)
835754:POSKeyError: 0x1b5f55
835756-2010-01-30T09:26:48 INFO Archetypes
ESC[00mESC[01;32m/usr/local/zope/agecom-virtual/parts/plone/Archetypes/UIDCatalog.py[106]:getObject
835757-ESC[00
Re: [ZODB-Dev] Repair corrupted RelStorage database
On Sat, Jan 30, 2010 at 2:51 PM, Rudá Porto Filgueiras wrote: > On Sat, Jan 30, 2010 at 6:56 AM, Shane Hathaway wrote: > > >> - Run the MySQL database verification and repair tools. It's possible >> that the object you need is there, but MySQL can't find it due to corrupted >> indexes or similar. >> >> > I will do that, but it must afert 02:00 am. :-) > Only to update: After check and recover all MYISAM tables: "myisamchk -c *.MYI" and "myisamchk -r *.MYI", zodbconvert.py runs fine and read all objects and trasactions from MySQL and export to FileStorage file with 22GB. I think it solve these integrity problems, but I will run the migration process to see what will happen. Shane, thanks again by your support. Cheers, -- Rudá Porto Filgueiras http://python-blog.blogspot.com http://twitter.com/rudaporto ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] Relstorage 1.4b3 error
On Wed, Feb 24, 2010 at 12:14 PM, Shane Hathaway wrote: > Santi Camps wrote: > > * Module relstorage.cache, line 294, in after_tpc_finish > > * Module memcache, line 360, in incr > > * Module memcache, line 384, in _incrdecr > > > > ValueError: invalid literal for int(): NOT_FOUND > > This means that in some circumstances, the memcache module you chose > returns 'NOT_FOUND' when a cache entry is missing. That's broken > behavior in the memcache module. > > Please try the pylibmc_wrapper module instead. I have found pylibmc to > be not only faster but more reliable than the other memcache modules. > > But if I'm correct, pylibmc (0.9) required by RelStorage don't run with Python 2.4.x or I'm doing something wrong. Cheers, > Shane > > -- Rudá Porto Filgueiras http://python-blog.blogspot.com http://twitter.com/rudaporto ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
Re: [ZODB-Dev] Relstorage 1.4b3 error
On Thu, Feb 25, 2010 at 4:30 PM, Shane Hathaway wrote: > Rudá Porto Filgueiras wrote: > >> But if I'm correct, pylibmc (0.9) required by RelStorage don't run with >> Python 2.4.x or I'm doing something wrong. >> > > Did you try pylibmc with Python 2.4? It might just work. I try it and don't work, because it uses "with" keyword introduced on Python 2.5. :-( > > Shane > -- Rudá Porto Filgueiras http://python-blog.blogspot.com http://twitter.com/rudaporto ___ For more information about ZODB, see the ZODB Wiki: http://www.zope.org/Wikis/ZODB/ ZODB-Dev mailing list - ZODB-Dev@zope.org https://mail.zope.org/mailman/listinfo/zodb-dev
