Mailing List Archive

DCOracle2 and ConnectionReleasedError
Hi

We are using DCOracle2 from CVS head branch, but I'm testing
chrisw_fixconnectionleak_branch branch created by chrisw and
I've fallen into some errors with this.

First of all, is chrisw_fixconnectionleak_branch branch the
recommended one? I've seen Carsten Gerner question about the
version of DCOracle but the answer says only about cvs version...

I have a page that renders a table with 70 rows and when I'm
refreshing this page fast for a few times I'm receiving
the errors like:

*Error Type: ConnectionReleasedError*
*Error Value: 3

I've added some debugging commands to connections.py file
and the output is a bit strange for me. Below modified (with print
commands) connections.py file and it's output.

As far as I've analyzed this I see that 'close' function is called
somehow, but I don't know why and by what.

I've checked db.py and query method which calls 'close' for some
kinds of exceptions but it is not this piece of code that is executed.

**Any ideas what is happening? Are these leaking connections?

With older version of DCOracle2 (from CVS trunk) compiled with
Oracle8 there are no errors.**

My Zope is 2.7.2, Python 2.3.5. Zope is running with 10 threads
(I tried 4 but no difference) in ZEO. DCOracle2 is compiled for
Oracle9.


**#---------------------------------------------------------------
# Output
*2005-07-13T08:16:51 INFO(0) Zope Ready to handle requests
close; thread: <_DummyThread(Dummy-3, started daemon)>
_register; thread: <_DummyThread(Dummy-3, started daemon)>
assignConnection; creatingConnection: 0; time:1121235431.48; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 0; time: 1121235431.48; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 0; time: 1121235431.48; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 0; time: 1121235431.51; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 0; time: 1121235431.62; thread:
<_DummyThread(Dummy-3, started daemon)>
returnConnection; deleting assigned id: 0; time: 1121235431.62;
thread:<_DummyThread(Dummy-3, started daemon)>
_register; thread: <_DummyThread(Dummy-3, started daemon)>
assignConnection; getting availaible: 0; time: 1121235431.73; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 0; time: 1121235431.73; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 0; time: 1121235431.91; thread:
<_DummyThread(Dummy-3, started daemon)>
returnConnection; deleting assigned id: 0; time: 1121235431.91;
thread:<_DummyThread(Dummy-3, started daemon)>
close; thread: <_DummyThread(Dummy-3, started daemon)>
_register; thread: <_DummyThread(Dummy-3, started daemon)>
assignConnection; creatingConnection: 1; time:1121235437.68; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235437.68; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235437.69; thread:
<_DummyThread(Dummy-3, started daemon)>
returnConnection; deleting assigned id: 1; time: 1121235437.69;
thread:<_DummyThread(Dummy-3, started daemon)>
_register; thread: <_DummyThread(Dummy-3, started daemon)>
assignConnection; getting availaible: 1; time: 1121235438.23; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235438.23; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235438.44; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235438.71; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235438.96; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235439.07; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235439.07; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235439.17; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235439.84; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235440.25; thread:
<_DummyThread(Dummy-3, started daemon)>
returnConnection; deleting assigned id: 1; time: 1121235440.25;
thread:<_DummyThread(Dummy-3, started daemon)>
_register; thread: <_DummyThread(Dummy-3, started daemon)>
assignConnection; getting availaible: 1; time: 1121235448.29; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235448.29; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235448.3; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235448.34; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235448.43; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235448.43; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235448.48; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235448.52; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235449.4; thread:
<_DummyThread(Dummy-3, started daemon)>
returnConnection; deleting assigned id: 1; time: 1121235449.4;
thread:<_DummyThread(Dummy-3, started daemon)>
_register; thread: <_DummyThread(Dummy-3, started daemon)>
assignConnection; getting availaible: 1; time: 1121235456.17; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235456.17; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235456.17; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235456.22; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235456.32; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235456.33; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235456.39; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Returned connection: 1; time: 1121235456.42; thread:
<_DummyThread(Dummy-3, started daemon)>
close; thread: <_DummyThread(Dummy-1, started daemon)>
_register; thread: <_DummyThread(Dummy-1, started daemon)>
assignConnection; creatingConnection: 2; time:1121235458.33; thread:
<_DummyThread(Dummy-1, started daemon)>
getConnection; Returned connection: 2; time: 1121235458.33; thread:
<_DummyThread(Dummy-1, started daemon)>
getConnection; Exception: 1; time: 1121235458.88; thread:
<_DummyThread(Dummy-3, started daemon)>
getConnection; Exception: 1; time: 1121235458.89; thread:
<_DummyThread(Dummy-3, started daemon)>
_register; thread: <_DummyThread(Dummy-2, started daemon)>
assignConnection; creatingConnection: 3; time:1121235459.07; thread:
<_DummyThread(Dummy-2, started daemon)>
getConnection; Returned connection: 3; time: 1121235459.07; thread:
<_DummyThread(Dummy-2, started daemon)>
getConnection; Returned connection: 2; time: 1121235459.41; thread:
<_DummyThread(Dummy-1, started daemon)>
close; thread: <_DummyThread(Dummy-4, started daemon)>
_register; thread: <_DummyThread(Dummy-4, started daemon)>
assignConnection; creatingConnection: 4; time:1121235459.54; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Returned connection: 4; time: 1121235459.54; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Exception: 3; time: 1121235459.89; thread:
<_DummyThread(Dummy-2, started daemon)>
getConnection; Returned connection: 4; time: 1121235460.23; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Exception: 2; time: 1121235460.87; thread:
<_DummyThread(Dummy-1, started daemon)>
getConnection; Returned connection: 4; time: 1121235461.12; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Returned connection: 4; time: 1121235461.23; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Returned connection: 4; time: 1121235461.23; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Returned connection: 4; time: 1121235461.46; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Returned connection: 4; time: 1121235461.69; thread:
<_DummyThread(Dummy-4, started daemon)>
getConnection; Returned connection: 4; time: 1121235462.67; thread:
<_DummyThread(Dummy-4, started daemon)>
returnConnection; deleting assigned id: 4; time: 1121235462.67;
thread:<_DummyThread(Dummy-4, started daemon)>
getConnection; Exception: 2; time: 1121235462.76; thread:
<_DummyThread(Dummy-1, started daemon)>
getConnection; Exception: 3; time: 1121235462.76; thread:
<_DummyThread(Dummy-2, started daemon)>
*#
--------------------------------------------------------------------------------



*

*#
--------------------------------------------------------------------------------
# connections.py
import DCOracle2
import threading

from Shared.DC.ZRDB.TM import Surrogate
from exceptions import ConnectionReleasedError, NoConnectionError
import time

# a pool of connections
# connection string -> list of available connections
pool = {}

# connections currently in use
# connection id -> connection object
assigned = {}

# connection count of created connections
# connecting string -> number of connections around
connection_count = {}


# the next id to be assigned
next_id = 0

# the big fat lock for when modifying the above
lock = threading.Lock()

def assignConnection(connectionString):
global lock
global pool
global assigned
global next_id
global connection_count
id = 0
try:

lock.acquire()

available = pool.get(connectionString,None)

if available is None:
available = pool[connectionString] = []

if available:
id, conn = available.pop()
print 'assignConnection; getting availaible: %s; time: %s;
thread: %s' % (id, time.time(), threading.currentThread())
else:
conn = DCOracle2.connect(connectionString)
id = next_id
next_id += 1

connection_count[
connectionString
] = connection_count.get(
connectionString,
0) + 1
print 'assignConnection; creatingConnection: %s; time:%s;
thread: %s' % (id, time.time(),threading.currentThread() )
assigned[id]=(conn,connectionString)

finally:

lock.release()

return id

def getConnection(id):
try:
connpair = assigned[id]
print 'getConnection; Returned connection: %s; time: %s; thread:
%s' % (id, time.time(), threading.currentThread())
except KeyError,e:
print 'getConnection; Exception: %s; time: %s; thread: %s' %
(e.args[0], time.time(), threading.currentThread())
if e.args:
raise ConnectionReleasedError,e.args[0]
else:
raise NoConnectionError,id
return connpair[0]

def returnConnection(id):
global lock
global pool
global assigned

try:

lock.acquire()

try:
conn,connectionString = assigned[id]
except KeyError,e:
print 'returnConnection; Exception: %s; thread:' %
(e.args[0], threading.currentThread())
if e.args:
raise ConnectionReleasedError,e.args[0]
else:
raise NoConnectionError,id
print 'returnConnection; deleting assigned id: %s; time: %s;
thread:%s' % (id, time.time(), threading.currentThread())
del assigned[id]

pool[connectionString].append((id,conn))

finally:

lock.release()

def close(connectionString=None, theId=None):
global lock
global pool
global assigned
global next_id
global connection_count
print 'close; thread: %s' % (threading.currentThread())
try:

lock.acquire()

for connstring,connections in pool.items():
if connectionString is None or connstring==connectionString:
for id,conn in connections:
if theId is None or id==theId:
pool[connstring].remove((id,conn))
conn.cursor().close()
conn.close()
if not pool[connstring]:
del pool[connstring]

for id,connpair in assigned.items():
if theId is None or id==theId:
conn,connstring = connpair
if connectionString is None or connstring==connectionString:
conn.cursor().close()
conn.close()
del assigned[id]

if connectionString is None and theId is None:

next_id = 0

for key in connection_count.keys():
del connection_count[key]

elif theId is None:

if connection_count.has_key(connectionString):
del connection_count[connectionString]

else:

connection_count[connectionString] -= 1

finally:

lock.release()

def countConnections(connectionString):
return connection_count.get(connectionString,0)

class CTM:
"""A class providing transaction manager support
for connection pooling.
Also stores _registered and _finalised as
_v_ variables"""

_v_connection_id = _v_registered = None

def _register(self):
print '_register; thread: %s' % (threading.currentThread())
if not self._v_registered:
get_transaction().register(Surrogate(self))
self._begin()
self._v_registered = 1
self._v_finalize = 0

def tpc_begin(self, *ignored): pass
commit=tpc_begin

def tpc_vote(self, *ignored):
self._v_finalize = 1

def tpc_finish(self, *ignored):

if self._v_finalize:
try: self._finish()
finally: self._v_registered=0

def abort(self, *ignored):
try: self._abort()
finally: self._v_registered=0

tpc_abort = abort

def sortKey(self, *ignored):
""" The sortKey method is used for recent ZODB compatibility which
needs to have a known commit order for lock acquisition. Most
DA's talking to RDBMS systems do not care about commit order, so
return the constant 1
"""
return 1

def getDB(self):
if self._v_connection_id is None:
self._register()
return getConnection(
self._v_connection_id
)

def __del__(self):
if self._v_connection_id is not None:
returnConnection(
self._v_connection_id
)
self._v_connection_id = None

def _begin(self):
# assertion checks we've not already got a
# connection which would get leaked at this
# point
assert self._v_connection_id is None

# either use the connection string
# or, if it's not there (we're a stored procedure)
# then get the connection string from our DA
self._v_connection_id = assignConnection(
getattr(self,'connection_string',None) or \
getattr(self,self.connection).connection_string
)

def _finish(self, *ignored):
if self._v_connection_id is not None:
db = getConnection(
self._v_connection_id
)
db.commit()
returnConnection(
self._v_connection_id
)
self._v_connection_id = None

def _abort(self, *ignored):
if self._v_connection_id is not None:
db = getConnection(
self._v_connection_id
)
db.rollback()
returnConnection(
self._v_connection_id
)
self._v_connection_id = None

#---------------------------------------------------------------


--
Maciej Wisniowski
*
_______________________________________________
Zope-DB mailing list
Zope-DB@zope.org
http://mail.zope.org/mailman/listinfo/zope-db
Re: DCOracle2 and ConnectionReleasedError [ In reply to ]
Hi there,

Maciej Wisniowski wrote:
> We are using DCOracle2 from CVS head branch, but I'm testing
> chrisw_fixconnectionleak_branch branch created by chrisw and
> I've fallen into some errors with this.

Indeed you will I'm afraid. It was a pretty big rewrite and involves
using module-level locking to enable Zope's threads to share a pool of
connections. It was only lightly load tested when I developed it, and
since then, anyone who's hammered it properly has seen the errors you
describe.

> First of all, is chrisw_fixconnectionleak_branch branch the
> recommended one? I've seen Carsten Gerner question about the
> version of DCOracle but the answer says only about cvs version...

Take your pick: Oracle Disconnected errors or ConnectionReleasedErrors,
all available versions have problems, and no-ones around to maintain
them :-S

> As far as I've analyzed this I see that 'close' function is called
> somehow, but I don't know why and by what.

import pdb, pdb.set_trace() is your friend ;-)
Tha twill help you find out what is calling the close method.

> With older version of DCOracle2 (from CVS trunk) compiled with
> Oracle8 there are no errors.**

Then use that ;-)

> My Zope is 2.7.2, Python 2.3.5. Zope is running with 10 threads
> (I tried 4 but no difference) in ZEO. DCOracle2 is compiled for
> Oracle9.

Well, you're doing well on the debug front with the print statements,
but make sure you watch those times, threading means the time something
prints isn't necessarilly the time something ran ;-)

If it was me, I'd drop down to one thread and see if you can reproduce.
If not, and I suspect that will be the case, try 2 threads. Still no
errors, try 3 and so on.

...then try and figure out what's causing it to fail and see if you can
come up with an artificial test case.

I'm sorry I can't help more :-S I really want to maintain DCOracle2 but
simply have no time. Matt Kromer can help with C-level bugs, but all the
current problems are with the Python database adapter for Zope.

I was hoping that my current big project would need this, but it turns
out it's easier just to wait until the underlying database gets moved
onto MS SQL Server and then just use eGenix's excellent ODBC adapter.
You may even want to see if you can use that to connect to Oracle, they
think you can ;-)

Anyway, good luck, I'm afraid you're going to need it!

Chris

--
Simplistix - Content Management, Zope & Python Consulting
- http://www.simplistix.co.uk

_______________________________________________
Zope-DB mailing list
Zope-DB@zope.org
http://mail.zope.org/mailman/listinfo/zope-db
Re: DCOracle2 and ConnectionReleasedError [ In reply to ]
> Well, you're doing well on the debug front with the print
> statements, but make sure you watch those times,
> threading means the time something prints isn't necessarilly
> the time something ran ;-)
Good to know :)

> If it was me, I'd drop down to one thread and see if you
> can reproduce. If not, and I suspect that will be the case,
> try 2 threads. Still no errors, try 3 and so on.
> ...then try and figure out what's causing it to fail and see
> if you can come up with an artificial test case.

> I'm sorry I can't help more :-S I really want to maintain
> DCOracle2 but simply have no time. Matt Kromer can
> help with C-level bugs, but all the current problems are
> with the Python database adapter for Zope.
Thanks for your reply. Maybe I'll try to look at this if I'll
have enough time.

> I was hoping that my current big project would need this,
> but it turns out it's easier just to wait until the underlying
> database gets moved onto MS SQL Server and then
> just use eGenix's excellent ODBC adapter.
> You may even want to see if you can use that to connect
> to Oracle, they think you can ;-)
We're using mxODBC to connect to Sybase and it
works perfectly, but the problem was with Oracle and it's
stored procedures and input/output variables.

Now we are trying SQLRelay. I've changed SQLRelayDA to
return values just like DCOracle and I've created simple product
that allows to call stored Oracle procedures/functions from Zope
and these SP objects returns values from output variables just like
DCOracle2 does, so maybe it will be possible even to
simply switch from DCOracle to SQLRelay with one click
(one script) :) Simple test says that SQLRelay is faster than
DCOracle2 but it may depend from result size.

This kind of product (SP) may be created for mxODBC
too but it'll not be possible to simply exchange DCOracle
because AFAIR mxODBC supports only cursor binds
from Oracle or something like this.

If somebody is interested in switching from DCOracle2
to SQLRelay, and in my SQLRelaySP
(stored procedures product) please tell me. It is very
first version but any opinions tests etc. should be interesting.


> Anyway, good luck, I'm afraid you're going to need it!
Thanks :)

--
Maciej Wisniowski
_______________________________________________
Zope-DB mailing list
Zope-DB@zope.org
http://mail.zope.org/mailman/listinfo/zope-db