[Zope] "error: release unlocked lock" with Zope/MySQL

[Dennis Allison]

[Reposted with a non-blank Subject field]

We've been seeing this problem for some time.  Earlier postings to the
list were helpful in that we have eliminated possible causes, but the
problem has never been resolved.  Any assistance in tracking down the
problem and fixing it would be greatly appreciated.

Our configuration:

Athlon dual processor machine
RH7.3 
Zope 2.7.6 with ZEO
Python 2.4.1  (same problem occurs with Python 2.3.5)
Mysql-Python 1.21.c3
ZMySQLDA 2.09b3
MySql-4.0.20

This is a fragment from the event log:

2005-06-07T16:06:42 ERROR(200) ZMySQLDA exception during _begin
Traceback (most recent call last):
  File "/opt/zope/zproducts/standard/ZMySQLDA/db.py", line 349, in _begin
    self.db.ping()
OperationalError: (2013, 'Lost connection to MySQL server during query')
------
2005-06-07T16:06:42 PANIC(300) ZODB A storage error occurred in the last 
phase of a two-phase commit.  This shouldn't happen. The application will 
not be allowed to commit until the site/storage is reset by a restart.
Traceback (most recent call last):
  File "/usr/local/src/zope/Zope2.7/lib/python/ZODB/Transaction.py", line 
377, in _finish_many
    jar.tpc_finish(self)
  File "/usr/local/src/zope/Zope2.7/lib/python/Shared/DC/ZRDB/TM.py", line 
59, in tpc_finish
    try: self._finish()
  File "/opt/zope/zproducts/standard/ZMySQLDA/db.py", line 376, in _finish
    self._tlock.release()
error: release unlocked lock
------
2005-06-07T16:06:42 ERROR(200) ZODB A storage error occured during object 
abort. This shouldn't happen.
Traceback (most recent call last):
  File "/usr/local/src/zope/Zope2.7/lib/python/ZODB/Transaction.py", line 
412, in _commit_error
    j.tpc_abort(self) # This should never fail
  File "/usr/local/src/zope/Zope2.7/lib/python/Shared/DC/ZRDB/TM.py", line 
63, in abort
    try: self._abort()
  File "/opt/zope/zproducts/standard/ZMySQLDA/db.py", line 389, in _abort
    self._tlock.release()
error: release unlocked lock
------
2005-06-07T16:06:42 ERROR(200) SiteError 
http://dev.agilemind.com/logged_in
Traceback (most recent call last):
  File "/usr/local/src/zope/Zope2.7/lib/python/ZPublisher/Publish.py", 
line 107, in publish
    transactions_manager.commit()
  File "/usr/local/src/zope/Zope2.7/l[safe_mysqld]
err-log=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.------
2005-08-06T20:47:21 ERROR(200) ZMySQLDA exception during _begin
Traceback (most recent call last):
  File "/opt/zope/zproducts/standard/ZMySQLDA/db.py", line 349, in _begin
    self.db.ping()
OperationalError: (2013, 'Lost connection to MySQL server during query')
------

We get the "release unlocked lock" message occasionally, frequently but
not always preceded by the connection lost message.  

Our my.cnf file for MySQL is

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
skip-innodb
set-variable=max_connections=2048
set-variable=long_query_time=1
#log-bin=/var/log/mysql/epaul-bin
#log-bin-index=/var/log/mysql/epaul-bin.index
#log-slow-queries=/var/log/mysql/epaul-slow.log
# change timeouts to close rather than wait
# interactive == 1 hour, programs == 5 mins
set-variable=interactive_timeout=3600
set-variable=wait_timeout=300
# uncomment to not log connection problems
#set-variable=log-warnings=off

[mysql.server]
user=mysql
basedir=/var/lib

[safe_mysqld]
err-log=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid


We use MyISAM tables and the MySQL autocommit mode rather than handling 
locks and transactions explicitly.

>From a user perspective, refreshing the Zope page recovers from the error 
and allows one to continue working.



_______________________________________________
Zope maillist  -  Zope at zope.org
http://mail.zope.org/mailman/listinfo/zope
**   No cross posts or HTML encoding!  **
(Related lists - 
 http://mail.zope.org/mailman/listinfo/zope-announce
 http://mail.zope.org/mailman/listinfo/zope-dev )