Mailing List Archive

1 2  View All
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: blocker | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by mgood):

#3788 has been marked as a duplicate.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:25>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: blocker | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by anonymous):

From my server log running r3791:

{{{
2006/09/26 14:57 CDT [HTTPChannel,5859,198.49.126.190] Exception
exceptions.AssertionError: <exceptions.AssertionError instance at
0xb76c418c> in <bound method PooledConnection.__del__ of
<trac.db.pool.PooledConnection object at 0xb583268c>> ignored
}}}

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:26>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: reopened
Priority: high | Milestone: 0.10.1
Component: general | Version: devel
Severity: major | Resolution:
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Changes (by cboos):

* status: closed => reopened
* resolution: fixed =>
* severity: blocker => major
* milestone: 0.10 => 0.10.1

Comment:

Replying to [comment:26 anonymous]:
> From my server log running r3791:
> ...

Please add some debugging info:
{{{
Index: pool.py
===================================================================
--- pool.py (revision 3791)
+++ pool.py (working copy)
@@ -102,6 +102,12 @@
try:
if tid in self._active:
num, cnx_ = self._active.get(tid)
+ if cnx is not cnx_:
+ print 'In [%d], _active -> %s\n _dormant -> %s' % \
+ (threading._get_ident(),
+ repr(self._active), repr(self._dormant))
+ print 'PooledConnection created from [%d] %s' % \
+ (tid, repr(cnx))
assert cnx is cnx_
if num > 1:
self._active[tid][0] = num - 1
}}}

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:27>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: reopened
Priority: high | Milestone: 0.10.1
Component: general | Version: devel
Severity: major | Resolution:
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by exarkun@divmod.com):

Some output from the log file with the above instrumentation added:

{{{
2006/09/26 21:16 CDT [HTTPChannel,2702,198.49.126.190] In [-1240794192],
_active -> {-1276134480: [1, <trac.db.sqlite_backend.SQLiteConnection
object at 0x8e4b70c>]}
2006/09/26 21:16 CDT [HTTPChannel,2702,198.49.126.190] _dormant -> []
2006/09/26 21:16 CDT [HTTPChannel,2702,198.49.126.190] PooledConnection
created from [-1276134480] <trac.db.sqlite_backend.SQLiteConnection object
at 0x8e3a5cc>
2006/09/26 21:16 CDT [HTTPChannel,2702,198.49.126.190] Exception
exceptions.AssertionError: <exceptions.AssertionError instance at
0x8e4b8ac> in <bound method PooledConnection.__del__ of
<trac.db.pool.PooledConnection object at 0x8e4144c>> ignored
2006/09/26 21:16 CDT [HTTPChannel,2884,198.49.126.190] In [-1267741776],
_active -> {-1218258000: [1, <trac.db.sqlite_backend.SQLiteConnection
object at 0x8730d0c>]}
2006/09/26 21:16 CDT [HTTPChannel,2884,198.49.126.190] _dormant -> []
2006/09/26 21:16 CDT [HTTPChannel,2884,198.49.126.190] PooledConnection
created from [-1218258000] <trac.db.sqlite_backend.SQLiteConnection object
at 0x8ab222c>
2006/09/26 21:16 CDT [HTTPChannel,2884,198.49.126.190] Exception
exceptions.AssertionError: <exceptions.AssertionError instance at
0x8ab2ecc> in <bound method PooledConnection.__del__ of
<trac.db.pool.PooledConnection object at 0x8ab25ec>> ignored
2006/09/26 21:16 CDT [HTTPChannel,3021,198.49.126.190] In [-1364345936],
_active -> {-1267741776: [2, <trac.db.sqlite_backend.SQLiteConnection
object at 0x85e3aac>]}
2006/09/26 21:16 CDT [HTTPChannel,3021,198.49.126.190] _dormant -> []
2006/09/26 21:16 CDT [HTTPChannel,3021,198.49.126.190] PooledConnection
created from [-1267741776] <trac.db.sqlite_backend.SQLiteConnection object
at 0x85d380c>
2006/09/26 21:16 CDT [HTTPChannel,3021,198.49.126.190] Exception
exceptions.AssertionError: <exceptions.AssertionError instance at
0x8604f8c> in <bound method PooledConnection.__del__ of
<trac.db.pool.PooledConnection object at 0xb584b5ac>> ignored
}}}

I don't know if this is related, but very shortly afterwards:

{{{
2006/09/26 21:17 CDT [-] Exception rendering:
2006/09/26 21:17 CDT [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.4/threading.py", line 422, in run
self.__target(*self.__args, **self.__kwargs)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/threadpool.py", line
148, in _worker
context.call(ctx, function, *args, **kwargs)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/context.py", line 59, in
callWithContext
return self.currentContext().callWithContext(ctx, func, *args,
**kw)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/context.py", line 37, in
callWithContext
return func(*args,**kw)
--- <exception caught here> ---
File "/home/trac/Projects/Twisted/trunk/twisted/web2/wsgi.py",
line 138, in run
result = self.application(self.environment,
self.startWSGIResponse)
File "/home/trac/Run/trac/external.py", line 74, in __call__
return self.application(environ, start_response)
File "/home/trac/Run/trac/external.py", line 115, in
tracApplication
return trac.web.main.dispatch_request(environ, start_response)
File "/home/trac/Projects/trac/trunk/trac/web/main.py", line
389, in dispatch_request
req.send_error(sys.exc_info(), status=500)
File "/home/trac/Projects/trac/trunk/trac/web/api.py", line 375,
in send_error
data = self.hdf.render(template)
File "/home/trac/Projects/trac/trunk/trac/web/clearsilver.py",
line 289, in render
return template.render()
neo_util.Error: Traceback (innermost last):
File "csparse.c", line 3170, in cs_render()
File "csparse.c", line 3156, in render_node()
File "csparse.c", line 2410, in each_eval()
File "csparse.c", line 3156, in render_node()
File "csparse.c", line 2410, in each_eval()
File "csparse.c", line 3156, in render_node()
File "csparse.c", line 2073, in var_eval()
File "neo_cs.c", line 142, in render_cb()
File "neo_str.c", line 124, in string_append()
File "neo_str.c", line 105, in string_check_length()
MemoryError: Unable to allocate STRING buf of size 1024
}}}

and then

{{{
2006/09/26 21:17 CDT [-] Exception rendering:
2006/09/26 21:17 CDT [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.4/threading.py", line 422, in run
self.__target(*self.__args, **self.__kwargs)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/threadpool.py", line
148, in _worker
context.call(ctx, function, *args, **kwargs)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/context.py", line 59, in
callWithContext
return self.currentContext().callWithContext(ctx, func, *args,
**kw)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/context.py", line 37, in
callWithContext
return func(*args,**kw)
--- <exception caught here> ---
File "/home/trac/Projects/Twisted/trunk/twisted/web2/wsgi.py",
line 138, in run
result = self.application(self.environment,
self.startWSGIResponse)
File "/home/trac/Run/trac/external.py", line 64, in __call__
path_parts = filter(None, path_info.split('/'))
exceptions.MemoryError:
}}}

and finally

{{{
2006/09/26 21:17 CDT [HTTPChannel,3293,198.49.126.190] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.4/threading.py", line 442, in __bootstrap
self.run()
File "/usr/lib/python2.4/threading.py", line 422, in run
self.__target(*self.__args, **self.__kwargs)
--- <exception caught here> ---
File
"/home/trac/Projects/Twisted/trunk/twisted/python/threadpool.py", line
148, in _worker
context.call(ctx, function, *args, **kwargs)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/context.py", line 59, in
callWithContext
return self.currentContext().callWithContext(ctx, func, *args,
**kw)
File
"/home/trac/Projects/Twisted/trunk/twisted/python/context.py", line 37, in
callWithContext
return func(*args,**kw)
File "/home/trac/Projects/Twisted/trunk/twisted/web2/wsgi.py",
line 142, in run
reactor.callFromThread(self.__error, failure.Failure())
exceptions.MemoryError:
}}}

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:28>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: reopened
Priority: high | Milestone: 0.10.1
Component: general | Version: devel
Severity: major | Resolution:
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by cboos):

Replying to [comment:28 exarkun@divmod.com]:

The various `MemoryError`s mean that your server is leaking memory, for
some reason.
I hope it's not due to our little pool issue ;)

I think I understood what's going on with the !AssertionError, finally. It
can be explained if the thread ids are reused quickly, before all the
!PooledConnection created in the previous "same" thread are GCed. Can you
try out attachment:debug_thread_reuse.diff in order to verify this
hypothesis?

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:29>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: reopened
Priority: high | Milestone: 0.10.1
Component: general | Version: devel
Severity: major | Resolution:
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by cboos):

... and if this is indeed the problem, the fix would be to simply
acknowledge that this can happen:
{{{
#!diff
Index: pool.py
===================================================================
--- pool.py (revision 3791)
+++ pool.py (working copy)
@@ -102,11 +102,13 @@
try:
if tid in self._active:
num, cnx_ = self._active.get(tid)
- assert cnx is cnx_
- if num > 1:
- self._active[tid][0] = num - 1
- else:
- self._cleanup(tid)
+ if cnx is cnx_:
+ if num > 1:
+ self._active[tid][0] = num - 1
+ else:
+ self._cleanup(tid)
+ # otherwise, cnx was already cleaned up during a
shutdown(tid),
+ # and in the meantime, `tid` has been reused (#3504)
finally:
self._available.release()

}}}

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:30>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: reopened
Priority: high | Milestone: 0.10.1
Component: general | Version: devel
Severity: major | Resolution:
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by cboos):

It just occurred to me that you're probably using a Thread pool in
Twisted.
Is that the case?
That would explain why you're seeing that error relatively often.
With tracd on windows, I do observe thread id reuse, but probably in this
case the reuse interval is large enough to give time to all the
!PooledConnection to be GCed before the reuse happens. With a Thread pool,
the reuse interval is certainly much shorter.

But no matter if the thread id gets reused because of a thread pool or
because the OS creates a new thread with a "recycled" id, the analysis and
"fix" remains correct, I think.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:31>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: reopened
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: major | Resolution:
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by exarkun@divmod.com):

Yes, there's a thread pool.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:33>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Changes (by cboos):

* status: reopened => closed
* resolution: => fixed
* severity: major => critical

Comment:

So I've committed r3798.

exarkun: I'd like to see what attachment:debug_thread_reuse.diff (on top
of r3797) produces, if you find time to do this test.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:34>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by exarkun@divmod.com):

I updated to r3798 before I noticed that patch, so I modified it slightly
in order to get it all to apply. The difference is that the 2nd to last
hunk in pool.py now looks like:

{{{
@@ -102,6 +123,15 @@
try:
if tid in self._active:
num, cnx_ = self._active.get(tid)
+ if cnx is not cnx_:
+ print 'ConnectionPool is ', repr(self)
+ print 'In [%d], _active -> %s\n _dormant -> %s' % \
+ (threading._get_ident(),
+ repr(self._active), repr(self._dormant))
+ print 'Available connections: %d/%d' % \
+ (self._cursize, self._maxsize)
+ print 'PooledConnection created from [%d] %s' % \
+ (tid, repr(cnx))
if cnx is cnx_:
if num > 1:
self._active[tid][0] = num - 1
}}}

Here's some preliminary output.

{{{
2006/09/27 09:51 CDT [HTTPChannel,10,198.49.126.190] [-1217746000] THREAD
REUSED (10)
2006/09/27 09:51 CDT [HTTPChannel,10,198.49.126.190] [-1217746000] THREAD
REUSED (10)
2006/09/27 09:51 CDT [HTTPChannel,10,198.49.126.190] [-1217746000] THREAD
REUSED (10)
2006/09/27 09:51 CDT [HTTPChannel,14,198.49.126.190] [-1217746000] THREAD
REUSED (14)
2006/09/27 09:51 CDT [HTTPChannel,14,198.49.126.190] [-1217746000] THREAD
REUSED (14)
2006/09/27 09:51 CDT [HTTPChannel,14,198.49.126.190] [-1217746000] THREAD
REUSED (14)
2006/09/27 09:51 CDT [HTTPChannel,17,198.49.126.190] [-1217746000] THREAD
REUSED (17)
2006/09/27 09:51 CDT [HTTPChannel,17,198.49.126.190] [-1217746000] THREAD
REUSED (17)
2006/09/27 09:51 CDT [HTTPChannel,17,198.49.126.190] [-1217746000] THREAD
REUSED (17)
2006/09/27 09:51 CDT [HTTPChannel,18,198.49.126.190] [-1217746000] THREAD
REUSED (18)
2006/09/27 09:51 CDT [HTTPChannel,18,198.49.126.190] [-1217746000] THREAD
REUSED (18)
2006/09/27 09:51 CDT [HTTPChannel,18,198.49.126.190] [-1217746000] THREAD
REUSED (18)
2006/09/27 09:51 CDT [HTTPChannel,19,198.49.126.190] [-1217746000] THREAD
REUSED (19)
2006/09/27 09:51 CDT [HTTPChannel,19,198.49.126.190] [-1217746000] THREAD
REUSED (19)
2006/09/27 09:51 CDT [HTTPChannel,19,198.49.126.190] [-1217746000] THREAD
REUSED (19)
2006/09/27 09:51 CDT [HTTPChannel,20,198.49.126.190] [-1217746000] THREAD
REUSED (20)
2006/09/27 09:51 CDT [HTTPChannel,20,198.49.126.190] [-1217746000] THREAD
REUSED (20)
2006/09/27 09:52 CDT [HTTPChannel,30,198.49.126.190] [-1217746000] THREAD
REUSED (30)
2006/09/27 09:52 CDT [HTTPChannel,30,198.49.126.190] [-1217746000] THREAD
REUSED (30)
2006/09/27 09:52 CDT [HTTPChannel,30,198.49.126.190] [-1217746000] THREAD
REUSED (30)
2006/09/27 09:52 CDT [HTTPChannel,34,198.49.126.190] [-1217746000] THREAD
REUSED (34)
2006/09/27 09:52 CDT [HTTPChannel,34,198.49.126.190] [-1217746000] THREAD
REUSED (34)
2006/09/27 09:52 CDT [HTTPChannel,35,198.49.126.190] [-1217746000] THREAD
REUSED (35)
2006/09/27 09:52 CDT [HTTPChannel,35,198.49.126.190] [-1217746000] THREAD
REUSED (35)
2006/09/27 09:52 CDT [HTTPChannel,35,198.49.126.190] [-1217746000] THREAD
REUSED (35)
2006/09/27 09:52 CDT [HTTPChannel,39,198.49.126.190] [-1240282192] THREAD
REUSED (1)
2006/09/27 09:52 CDT [HTTPChannel,39,198.49.126.190] [-1240282192] THREAD
REUSED (1)
2006/09/27 09:52 CDT [HTTPChannel,39,198.49.126.190] [-1240282192] THREAD
REUSED (1)
2006/09/27 09:52 CDT [HTTPChannel,39,198.49.126.190] [-1240282192] THREAD
REUSED (1)
2006/09/27 09:52 CDT [HTTPChannel,39,198.49.126.190] [-1240282192] THREAD
REUSED (1)
2006/09/27 09:52 CDT [HTTPChannel,39,198.49.126.190] [-1240282192] THREAD
REUSED (1)
2006/09/27 09:52 CDT [HTTPChannel,40,198.49.126.190] [-1217746000] THREAD
REUSED (37)
2006/09/27 09:52 CDT [HTTPChannel,40,198.49.126.190] [-1217746000] THREAD
REUSED (37)
2006/09/27 09:52 CDT [HTTPChannel,40,198.49.126.190] [-1217746000] THREAD
REUSED (37)
2006/09/27 09:52 CDT [HTTPChannel,40,198.49.126.190] [-1217746000] THREAD
REUSED (37)
2006/09/27 09:52 CDT [HTTPChannel,40,198.49.126.190] [-1217746000] THREAD
REUSED (37)
2006/09/27 09:52 CDT [HTTPChannel,40,198.49.126.190] [-1217746000] THREAD
REUSED (37)
2006/09/27 09:52 CDT [HTTPChannel,41,198.49.126.190] [-1240282192] THREAD
REUSED (2)
2006/09/27 09:52 CDT [HTTPChannel,41,198.49.126.190] [-1240282192] THREAD
REUSED (2)
2006/09/27 09:52 CDT [HTTPChannel,41,198.49.126.190] [-1240282192] THREAD
REUSED (2)
2006/09/27 09:52 CDT [HTTPChannel,42,198.49.126.190] [-1217746000] THREAD
REUSED (38)
2006/09/27 09:52 CDT [HTTPChannel,42,198.49.126.190] [-1217746000] THREAD
REUSED (38)
2006/09/27 09:52 CDT [HTTPChannel,51,198.49.126.190] [-1240282192] THREAD
REUSED (7)
2006/09/27 09:52 CDT [HTTPChannel,51,198.49.126.190] [-1240282192] THREAD
REUSED (7)
2006/09/27 09:52 CDT [HTTPChannel,51,198.49.126.190] [-1240282192] THREAD
REUSED (7)
2006/09/27 09:52 CDT [HTTPChannel,51,198.49.126.190] [-1240282192] THREAD
REUSED (7)
2006/09/27 09:52 CDT [HTTPChannel,51,198.49.126.190] [-1240282192] THREAD
REUSED (7)
2006/09/27 09:52 CDT [HTTPChannel,51,198.49.126.190] [-1240282192] THREAD
REUSED (7)
2006/09/27 09:52 CDT [HTTPChannel,52,198.49.126.190] [-1217746000] THREAD
REUSED (43)
2006/09/27 09:52 CDT [HTTPChannel,52,198.49.126.190] [-1217746000] THREAD
REUSED (43)
2006/09/27 09:52 CDT [HTTPChannel,52,198.49.126.190] [-1217746000] THREAD
REUSED (43)
2006/09/27 09:52 CDT [HTTPChannel,52,198.49.126.190] [-1217746000] THREAD
REUSED (43)
2006/09/27 09:52 CDT [HTTPChannel,52,198.49.126.190] [-1217746000] THREAD
REUSED (43)
2006/09/27 09:52 CDT [HTTPChannel,52,198.49.126.190] [-1217746000] THREAD
REUSED (43)
2006/09/27 09:53 CDT [HTTPChannel,53,198.49.126.190] [-1240282192] THREAD
REUSED (8)
2006/09/27 09:53 CDT [HTTPChannel,53,198.49.126.190] [-1240282192] THREAD
REUSED (8)
2006/09/27 09:53 CDT [HTTPChannel,53,198.49.126.190] [-1240282192] THREAD
REUSED (8)
2006/09/27 09:53 CDT [HTTPChannel,54,198.49.126.190] [-1217746000] THREAD
REUSED (44)
2006/09/27 09:53 CDT [HTTPChannel,54,198.49.126.190] [-1217746000] THREAD
REUSED (44)
2006/09/27 09:53 CDT [HTTPChannel,54,198.49.126.190] [-1217746000] THREAD
REUSED (44)
2006/09/27 09:53 CDT [HTTPChannel,56,198.49.126.190] [-1240282192] THREAD
REUSED (9)
2006/09/27 09:53 CDT [HTTPChannel,56,198.49.126.190] [-1240282192] THREAD
REUSED (9)
2006/09/27 09:54 CDT [HTTPChannel,57,198.49.126.190] [-1217746000] THREAD
REUSED (46)
2006/09/27 09:54 CDT [HTTPChannel,57,198.49.126.190] [-1217746000] THREAD
REUSED (46)
2006/09/27 09:54 CDT [HTTPChannel,58,198.49.126.190] [-1240282192] THREAD
REUSED (10)
2006/09/27 09:54 CDT [HTTPChannel,58,198.49.126.190] [-1240282192] THREAD
REUSED (10)
2006/09/27 09:54 CDT [HTTPChannel,59,198.49.126.190] [-1217746000] THREAD
REUSED (47)
2006/09/27 09:54 CDT [HTTPChannel,59,198.49.126.190] [-1217746000] THREAD
REUSED (47)
2006/09/27 09:54 CDT [HTTPChannel,59,198.49.126.190] [-1217746000] THREAD
REUSED (47)
2006/09/27 09:54 CDT [HTTPChannel,59,198.49.126.190] [-1217746000] THREAD
REUSED (47)
2006/09/27 09:54 CDT [HTTPChannel,59,198.49.126.190] [-1217746000] THREAD
REUSED (47)
2006/09/27 09:54 CDT [HTTPChannel,59,198.49.126.190] [-1217746000] THREAD
REUSED (47)
2006/09/27 09:54 CDT [HTTPChannel,60,198.49.126.190] [-1240282192] THREAD
REUSED (11)
2006/09/27 09:54 CDT [HTTPChannel,60,198.49.126.190] [-1240282192] THREAD
REUSED (11)
2006/09/27 09:54 CDT [HTTPChannel,60,198.49.126.190] [-1240282192] THREAD
REUSED (11)
2006/09/27 09:54 CDT [HTTPChannel,60,198.49.126.190] [-1240282192] THREAD
REUSED (11)
2006/09/27 09:54 CDT [HTTPChannel,60,198.49.126.190] [-1240282192] THREAD
REUSED (11)
2006/09/27 09:54 CDT [HTTPChannel,60,198.49.126.190] [-1240282192] THREAD
REUSED (11)
2006/09/27 09:54 CDT [HTTPChannel,60,198.49.126.190] [-1240282192] THREAD
REUSED (11)
2006/09/27 09:54 CDT [HTTPChannel,63,198.49.126.190] [-1217746000] THREAD
REUSED (50)
2006/09/27 09:54 CDT [HTTPChannel,63,198.49.126.190] [-1217746000] THREAD
REUSED (50)
2006/09/27 09:54 CDT [HTTPChannel,63,198.49.126.190] [-1217746000] THREAD
REUSED (50)
2006/09/27 09:54 CDT [HTTPChannel,63,198.49.126.190] [-1217746000] THREAD
REUSED (50)
2006/09/27 09:54 CDT [HTTPChannel,63,198.49.126.190] [-1217746000] THREAD
REUSED (50)
2006/09/27 09:54 CDT [HTTPChannel,64,198.49.126.190] [-1240282192] THREAD
REUSED (12)
2006/09/27 09:54 CDT [HTTPChannel,64,198.49.126.190] [-1240282192] THREAD
REUSED (12)
2006/09/27 09:54 CDT [HTTPChannel,64,198.49.126.190] [-1240282192] THREAD
REUSED (12)
2006/09/27 09:54 CDT [HTTPChannel,64,198.49.126.190] [-1240282192] THREAD
REUSED (12)
2006/09/27 09:54 CDT [HTTPChannel,64,198.49.126.190] [-1240282192] THREAD
REUSED (12)
2006/09/27 09:54 CDT [HTTPChannel,64,198.49.126.190] [-1240282192] THREAD
REUSED (12)
2006/09/27 09:55 CDT [HTTPChannel,65,198.49.126.190] [-1217746000] THREAD
REUSED (51)
2006/09/27 09:55 CDT [HTTPChannel,65,198.49.126.190] [-1217746000] THREAD
REUSED (51)
2006/09/27 09:55 CDT [HTTPChannel,66,198.49.126.190] [-1240282192] THREAD
REUSED (13)
2006/09/27 09:55 CDT [HTTPChannel,66,198.49.126.190] [-1240282192] THREAD
REUSED (13)
2006/09/27 09:56 CDT [HTTPChannel,76,198.49.126.190] [-1240282192] THREAD
REUSED (18)
2006/09/27 09:56 CDT [HTTPChannel,76,198.49.126.190] [-1240282192] THREAD
REUSED (18)
2006/09/27 09:56 CDT [HTTPChannel,77,198.49.126.190] [-1217746000] THREAD
REUSED (57)
2006/09/27 09:56 CDT [HTTPChannel,77,198.49.126.190] [-1217746000] THREAD
REUSED (57)
2006/09/27 09:56 CDT [HTTPChannel,83,198.49.126.190] [-1217746000] THREAD
REUSED (60)
2006/09/27 09:56 CDT [HTTPChannel,83,198.49.126.190] [-1217746000] THREAD
REUSED (60)
2006/09/27 09:57 CDT [HTTPChannel,84,198.49.126.190] [-1240282192] THREAD
REUSED (22)
2006/09/27 09:57 CDT [HTTPChannel,84,198.49.126.190] [-1240282192] THREAD
REUSED (22)
2006/09/27 09:57 CDT [HTTPChannel,84,198.49.126.190] [-1240282192] THREAD
REUSED (22)
2006/09/27 09:57 CDT [HTTPChannel,85,198.49.126.190] [-1217746000] THREAD
REUSED (61)
2006/09/27 09:57 CDT [HTTPChannel,85,198.49.126.190] [-1217746000] THREAD
REUSED (61)
2006/09/27 09:57 CDT [HTTPChannel,84,198.49.126.190] [-1240282192] THREAD
REUSED (22)
2006/09/27 09:57 CDT [HTTPChannel,84,198.49.126.190] [-1240282192] THREAD
REUSED (22)
2006/09/27 09:57 CDT [HTTPChannel,95,198.49.126.190] [-1217746000] THREAD
REUSED (71)
2006/09/27 09:57 CDT [HTTPChannel,95,198.49.126.190] [-1217746000] THREAD
REUSED (71)
2006/09/27 09:57 CDT [HTTPChannel,95,198.49.126.190] [-1217746000] THREAD
REUSED (71)
2006/09/27 09:57 CDT [HTTPChannel,96,198.49.126.190] [-1240282192] THREAD
REUSED (23)
2006/09/27 09:57 CDT [HTTPChannel,96,198.49.126.190] [-1240282192] THREAD
REUSED (23)
2006/09/27 09:57 CDT [HTTPChannel,97,198.49.126.190] [-1217746000] THREAD
REUSED (72)
2006/09/27 09:57 CDT [HTTPChannel,97,198.49.126.190] [-1217746000] THREAD
REUSED (72)
2006/09/27 09:57 CDT [HTTPChannel,97,198.49.126.190] [-1217746000] THREAD
REUSED (72)
2006/09/27 09:57 CDT [HTTPChannel,107,198.49.126.190] [-1240282192] THREAD
REUSED (28)
2006/09/27 09:57 CDT [HTTPChannel,107,198.49.126.190] [-1240282192] THREAD
REUSED (28)
}}}

I can provide more later if you want.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:35>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by cboos):

Replying to [comment:35 exarkun@divmod.com]:
> ...
>
> I can provide more later if you want.
>

It would be interesting to see if you get an !AssertionError for `assert
pooled_connections_per_thread == 0`. If this is the case, then this is the
situation which would have triggered an !AssertionError for `assert cnx is
cnx_` in the "old" code.

Other than that, I think we now have a satisfactory implementation of the
connection pool, until we make 2.4 mandatory and can use thread-local
storage ;)

Ah, it would be also interesting to see if you still have your out-of-
memory issues, but I think they are not related...

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:36>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by anonymous):

I haven't seen any log message other than the THREAD REUSED message so
far. With about the same frequency of the previous AttributeError,
though, the server now stops responding to all requests and needs to be
SIGKILL'd and restarted.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:37>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by cboos):

Replying to [comment:37 anonymous]:
> I haven't seen any log message other than the THREAD REUSED message so
far. With about the same frequency of the previous !AttributeError,
though, the server now stops responding to all requests and needs to be
SIGKILL'd and restarted.

Hm, that's probably due to the `assert pooled_connections_per_thread ==
0`. Simply revert all the debugging changes and see if this freeze still
happens with stock 0.10.

Two related questions:
- what was that frequency, approximately?
- what about the out-of-memory errors, do they still happen?

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:38>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by exarkun@divmod.com):

Okay, running with the same revision minus the debug changes. I'll
comment again in a few days with a summary of the behavior.

The frequency of hangs was somewhere around twice per day. I haven't seen
any out of memory errors since the ones I included in that comment.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:39>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by anonymous):

The frequency of hangs has fallen quite a bit. I've only seen one in the
week or so since updating last.

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:40>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---
Re: [The Trac Project] #3504: AssertionError in trac.db.pool.PooledConnection.__del__ [ In reply to ]
#3504: AssertionError in trac.db.pool.PooledConnection.__del__
--------------------------------------+-------------------------------------
Reporter: exarkun@divmod.com | Owner: cboos
Type: defect | Status: closed
Priority: high | Milestone: 0.10
Component: general | Version: devel
Severity: critical | Resolution: fixed
Keywords: database connection pool |
--------------------------------------+-------------------------------------
Comment (by cboos):

Replying to [comment:40 anonymous]:
> ... I've only seen one in the week or so since updating last.

Good... and bad, this means the possibility of hangs is still there.
After looking at the code a bit more, I think there was one more bug...

If you don't mind testing a bit more, I've prepared a new
[attachment:db_pool_timeout-r3868.patch patch] (on trunk, but should
probably apply on 0.10 as well).
Also, if there's still a hang due to Trac, it will get replaced by a user
visible "!TimeoutError" exception.

(Side note: while stress-testing the code, I still couldn't trigger any
''Database is locked'' exception with SQLite, so it looks like r3830 was
really a good idea ;) )

--
Ticket URL: <http://trac.edgewall.org/ticket/3504#comment:41>
The Trac Project <http://trac.edgewall.org/>

--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups "Trac Tickets" group.
To post to this group, send email to trac-tickets@googlegroups.com
To unsubscribe from this group, send email to trac-tickets-unsubscribe@googlegroups.com
For more options, visit this group at http://groups.google.se/group/trac-tickets
-~----------~----~----~----~------~----~------~--~---

1 2  View All