Exception ThreadLock.error: 'release unlocked lock'
Hello Zope experts, First of all I must thank everyone involved in the Zope development effort for a fantastic system. Thank you so much! It seems I've become a Zope evangelist in the company I work for, and not entirely without success even :) Now, after playing a bit with Zope, I decided to use it as a base for two separate projects. I seem to be having problems (ZODB corruption, I'm afraid) with both of these setups. The first one was found to be due to the partition where zope/var resides becoming full (although there was no other indication of this problem than weird corruption of objects to a point where they can't even be removed anymore). This was on Zope 2.0.0 binary release on Debian 2.1. My real problem is my recent install of Zope 2.0.1 from the binary tarball onto another server running Red Hat 6.0. I use SOLID RDBMS with jrush's ZODBCDA. I have a top-level UserDb handling all access control from my custom user info table (has the four standard fields, but others too). I made a snapshot from my home system (which seems to work fine) and imported it into the production server (SOLID tools for SQL data and Zope Export for DTML and SQL methods). Things seemed to work fine for a few hours, but soon I could not log in to the system anymore (traceback showed a cookie/LoginRequired related error), I just kept getting the UserDb login page. Restarting Zope helped. The thing that worries me is that from the console where I start Zope from manually, I get this error e.g. whenever I refresh the management interface: Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8529f20> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8539ed0> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 850eb68> ignored ...etc, with just the address changing every time. Is this the reason to the login problem I saw? Does this mean that ZODB corruption might be occurring? I have no knowledge as to the innards of Zope. What should I think of this/what can I do to fix it? Finally, I apologize but I'd like to ask you to please cc any answers directly to me as well, as I am not subscribed to this list. Thank you in advance for any help, -- Teemu Yli-Elsila Oulu, Finland
On Tue, Nov 09, 1999 at 01:53:28AM +0200, Teemu Yli-Elsilä wrote:
Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8529f20> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8539ed0> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 850eb68> ignored
I get this all the time too, but since everything else seemed to be working I hadn't got around to looking at it yet. Has anyone who's seen this worked out what's happening? -- Evan ~ThunderFoot~ Gibson ~ nihil mutatem, omni deletum ~ May the machines watch over you with loving grace.
At 01:37 09/11/99 , Evan Gibson wrote:
On Tue, Nov 09, 1999 at 01:53:28AM +0200, Teemu Yli-Elsilä wrote:
Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8529f20> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8539ed0> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 850eb68> ignored
I get this all the time too, but since everything else seemed to be working I hadn't got around to looking at it yet.
Has anyone who's seen this worked out what's happening?
I had never seen this until a customer of ours sent the exact same error messages to me yesterday. Everything works fine, except for that. I was planning to look deeper into the cause of this today. They occur when one method calls a Z SQL Method (to insert a row into a PostgreSQL DB), and sends an email using a MailHost object. The log states: NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 84db300> ignored NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 84fc168> ignored NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8530350> ignored The customer also reports that an extra thread appears.. (? He says there is an extra z2.py, but as he runs Linux, that's probably an extra thread). Although apparently not harmful, I do suspect that eventually the process will run out of threads. -- Martijn Pieters, Web Developer | Antraciet http://www.antraciet.nl | Tel: +31-35-7502100 Fax: +31-35-7502111 | mailto:mj@antraciet.nl http://www.antraciet.nl/~mj | PGP: http://wwwkeys.nl.pgp.net:11371/pks/lookup?op=get&search=0xA8A32149 ------------------------------------------
NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 84db300> ignored NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 84fc168> ignored NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8530350> ignored
The customer also reports that an extra thread appears.. (? He says there is an extra z2.py, but as he runs Linux, that's probably an extra thread).
Although apparently not harmful, I do suspect that eventually the process will run out of threads.
Hmm.. The error occurs within the THUNKed database adapter, it's a problem with the ThreadLock. I think something goes wrong with the _register method of the THUNK class (either register or self._begin fails), causing the freshly acquired lock to be released again. Then, when the transaction is finished, tpc_finish is called, which releases a unlocked lock, which throws the exception. But because the transaction was already finished, we get the aforementioned log message. Zope just continues to run. The question is, what, if any, side effects does this cause, and how does this problem occur, so we can put an end to it? -- Martijn Pieters, Web Developer | Antraciet http://www.antraciet.nl | Tel: +31-35-7502100 Fax: +31-35-7502111 | mailto:mj@antraciet.nl http://www.antraciet.nl/~mj | PGP: http://wwwkeys.nl.pgp.net:11371/pks/lookup?op=get&search=0xA8A32149 ------------------------------------------
On Tue, 9 Nov 1999, Martijn Pieters wrote:
Although apparently not harmful, I do suspect that eventually the process will run out of threads.
Hmm.. The error occurs within the THUNKed database adapter, it's a problem with the ThreadLock. I think something goes wrong with the _register method of the THUNK class (either register or self._begin fails), causing the freshly acquired lock to be released again.
Then, when the transaction is finished, tpc_finish is called, which releases a unlocked lock, which throws the exception. But because the transaction was already finished, we get the aforementioned log message. Zope just continues to run.
The question is, what, if any, side effects does this cause, and how does this problem occur, so we can put an end to it?
In my case the problem is real. I have a UserDb folder at the top level (/) handling all Zope users. What happens is that a few hours after inactivity (no accesses) Zope is no longer accepting any logins. You can view the public pages, but UserDb seems to deny all login attempts. I have had to restart Zope whenever this occurs to get into the server. My config again: - Red Hat Linux 6.0 - Zope 2.0.1 (binary tarball from zope.org) - Solid RDBMS v2.3 - Jeff Rush's ZODBCDA/Solid (binary tarball) - UserDb 1.3.0 Is there anything I could do to provide more information in order to get help solving the problem? Thank you, -Teemu
At 08:03 10/11/99 , Teemu Yli-Elsilä wrote:
On Tue, 9 Nov 1999, Martijn Pieters wrote: In my case the problem is real. I have a UserDb folder at the top level (/) handling all Zope users. What happens is that a few hours after inactivity (no accesses) Zope is no longer accepting any logins. You can view the public pages, but UserDb seems to deny all login attempts. I have had to restart Zope whenever this occurs to get into the server.
My config again:
- Red Hat Linux 6.0 - Zope 2.0.1 (binary tarball from zope.org) - Solid RDBMS v2.3 - Jeff Rush's ZODBCDA/Solid (binary tarball) - UserDb 1.3.0
Is there anything I could do to provide more information in order to get help solving the problem?
Can you see how many threads are running in the z2.py process? Do any ThreadLock errors occur during the period of inactivity? Can you sure that this inactivity problem is not a time-out within the ZODBCDA/Solid product? -- Martijn Pieters, Web Developer | Antraciet http://www.antraciet.nl | Tel: +31-35-7502100 Fax: +31-35-7502111 | mailto:mj@antraciet.nl http://www.antraciet.nl/~mj | PGP: http://wwwkeys.nl.pgp.net:11371/pks/lookup?op=get&search=0xA8A32149 ------------------------------------------
On Tue, 09 Nov 1999, Martijn Pieters wrote:
At 01:37 09/11/99 , Evan Gibson wrote:
On Tue, Nov 09, 1999 at 01:53:28AM +0200, Teemu Yli-Elsilä wrote:
Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8529f20> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8539ed0> ignored Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 850eb68> ignored
I get this all the time too, but since everything else seemed to be working I hadn't got around to looking at it yet.
Has anyone who's seen this worked out what's happening?
I had never seen this until a customer of ours sent the exact same error messages to me yesterday. Everything works fine, except for that. I was planning to look deeper into the cause of this today.
They occur when one method calls a Z SQL Method (to insert a row into a PostgreSQL DB), and sends an email using a MailHost object.
The log states:
NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 84db300> ignored NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 84fc168> ignored NOTICE: UserAbortTransactionBlock and not in in-progress state Exception ThreadLock.error: 'release unlocked lock' in <method Transaction.__del__ of Transaction instance at 8530350> ignored
The customer also reports that an extra thread appears.. (? He says there is an extra z2.py, but as he runs Linux, that's probably an extra thread).
Although apparently not harmful, I do suspect that eventually the process will run out of threads.
I see this error message also and in the same sort of circumstance i.e. Z SQL Method (inserting a row in a PostgreSQL DB) followed by a 'sendmail' element (used to send mail directly) rather than a MailHost object call. I have not had time to play around (i.e. take out the sendmail and see if it still works) so I can't add anymore. I have not seen any other side affects apart from new 'thread' being created as described above (yet). I imported my Zope site into Zope2 from a Zope1 setup, is this common amongst those that see this error message? Richard
On Tue, Nov 09, 1999 at 02:03:14PM +0000, Richard Taylor wrote:
I see this error message also and in the same sort of circumstance i.e. Z SQL Method (inserting a row in a PostgreSQL DB) followed by a 'sendmail' element (used to send mail directly) rather than a MailHost object call.
I'm not using any sendmail or MailHost calls, just SQL queries (currently into Gadfly, but I got bitten by not being able to extend tables easily so I'll be moving to something else soon)
I have not had time to play around (i.e. take out the sendmail and see if it still works) so I can't add anymore.
I don't know the exact triggers that cause the messages... I can't see the terminal from this far away, smile. But I don't think it's the sendmail/Mailhost part, or if it is that's just incidental and other things can trigger the same problem.
I imported my Zope site into Zope2 from a Zope1 setup, is this common amongst those that see this error message?
No. Mine started as Zope 2.
Richard
-- Evan ~ThunderFoot~ Gibson ~ nihil mutatem, omni deletum ~ May the machines watch over you with loving grace.
participants (4)
-
Evan Gibson -
Martijn Pieters -
Richard Taylor -
Teemu Yli-Elsilä