>
>
> the code here isn’t really showing me the nature of the two separate
> connections. They will be different unless you’re using “threadlocal” on
> the engine or pool and both are in the same thread. A simple comparison of
> the “raw” DBAPI connections to see if they are different objects will
> suffice (make sure you’re on the ultimate DBAPI connection though, not the
> “fairy” object). However note that Microsoft ODBC drivers also feature
> connection pooling, so you’d need to turn it off at the ODBC configuration
> level as well.
>
Hopefully the following details will help. Here is the sanitized code and
logs:
class QueryObj (object):
#blah blah
def select (qry, other params):
#This is simplified from the real code
eng = get_engine() #Threadsafe method to get engine
raw_con = eng.connect().connection.connection
logger.debug("Raw connection %s" % raw_con)
crsr = raw_con.cursor()
logger.debug("Cursor: %s" % cursor)
raw_con.autocommit= True
res = crsr.execute (qry, *multiparams) #multiparams is empty here
raw_con.autocommit= False
res_fetched = res.fetchall()
res.close()
class ParTest (Thread):
def __init__(self):
Thread.__init__(self)
def run (self):
q = QueryObj (My params)
for _ in range(5):
try:
resultset= q.select("My query which takes a few seconds", other
params like Db etc.)
except Exception:
pass
def main ():
lst = []
for i in range(10):
lst.append(ParTest())
for i in range(10):
lst[i].start()
Here is the log (apologies for the rather lengthy log). The structure of
the log statements is:
*Thread id - timestamp - level - log statement*
30848 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
26188 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
30148 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
31624 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
27788 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
30624 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
31008 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
14832 - 2014-05-12 13:05:32,104 - DEBUG - Start query: My query
22108 - 2014-05-12 13:05:32,102 - DEBUG - Start query: My query
30364 - 2014-05-12 13:05:32,104 - DEBUG - Start query: My query
30848 - 2014-05-12 13:05:32,246 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3870>
30848 - 2014-05-12 13:05:32,246 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000004A74B10>
26188 - 2014-05-12 13:05:32,259 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3978>
26188 - 2014-05-12 13:05:32,260 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000004A74B70>
31624 - 2014-05-12 13:05:32,272 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED39D0>
31624 - 2014-05-12 13:05:32,273 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000004A74C90>
30148 - 2014-05-12 13:05:32,285 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3A28>
30148 - 2014-05-12 13:05:32,286 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000004A74BD0>
30624 - 2014-05-12 13:05:32,298 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3A80>
30624 - 2014-05-12 13:05:32,299 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000004A74CF0>
27788 - 2014-05-12 13:05:32,358 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3AD8>
31008 - 2014-05-12 13:05:32,358 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3B30>
14832 - 2014-05-12 13:05:32,358 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3B88>
22108 - 2014-05-12 13:05:32,358 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3BE0>
30364 - 2014-05-12 13:05:32,358 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3C38>
27788 - 2014-05-12 13:05:32,359 - ERROR - Error: Attempt to use a closed
connection.. Query My query
Traceback (most recent call last):
File "QueryObj.py", line 503, in execute
cursor = raw_con.cursor()
ProgrammingError: Attempt to use a closed connection.
31008 - 2014-05-12 13:05:32,359 - ERROR - Error: Attempt to use a closed
connection.. Query My query
Traceback (most recent call last):
File "QueryObj.py", line 503, in execute
cursor = raw_con.cursor()
ProgrammingError: Attempt to use a closed connection.
14832 - 2014-05-12 13:05:32,361 - ERROR - Error: Attempt to use a closed
connection.. Query My query
Traceback (most recent call last):
File "QueryObj.py", line 503, in execute
cursor = raw_con.cursor()
ProgrammingError: Attempt to use a closed connection.
22108 - 2014-05-12 13:05:32,361 - ERROR - Error: Attempt to use a closed
connection.. Query My query
Traceback (most recent call last):
File "QueryObj.py", line 503, in execute
cursor = raw_con.cursor()
ProgrammingError: Attempt to use a closed connection.
30364 - 2014-05-12 13:05:32,362 - ERROR - Error: Attempt to use a closed
connection.. Query My query
Traceback (most recent call last):
File "QueryObj.py", line 503, in execute
cursor = raw_con.cursor()
ProgrammingError: Attempt to use a closed connection.
27788 - 2014-05-12 13:05:32,365 - ERROR - Error Attempt to use a closed
connection. fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
ProgrammingError: Attempt to use a closed connection.
31008 - 2014-05-12 13:05:32,367 - ERROR - Error Attempt to use a closed
connection. fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
ProgrammingError: Attempt to use a closed connection.
14832 - 2014-05-12 13:05:32,368 - ERROR - Error Attempt to use a closed
connection. fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
ProgrammingError: Attempt to use a closed connection.
22108 - 2014-05-12 13:05:32,368 - ERROR - Error Attempt to use a closed
connection. fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
ProgrammingError: Attempt to use a closed connection.
30364 - 2014-05-12 13:05:32,368 - ERROR - Error Attempt to use a closed
connection. fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
ProgrammingError: Attempt to use a closed connection.
27788 - 2014-05-12 13:05:32,369 - DEBUG - Start query: My query
31008 - 2014-05-12 13:05:32,371 - DEBUG - Start query: My query
14832 - 2014-05-12 13:05:32,371 - DEBUG - Start query: My query
22108 - 2014-05-12 13:05:32,372 - DEBUG - Start query: My query
30364 - 2014-05-12 13:05:32,374 - DEBUG - Start query: My query
27788 - 2014-05-12 13:05:32,374 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3870>
31008 - 2014-05-12 13:05:32,375 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3978>
14832 - 2014-05-12 13:05:32,375 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED39D0>
22108 - 2014-05-12 13:05:32,375 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3A28>
30364 - 2014-05-12 13:05:32,377 - DEBUG - Raw connection <pyodbc.Connection
object at 0x0000000007ED3A80>
27788 - 2014-05-12 13:05:32,377 - DEBUG - Cursor: <pyodbc.Cursor object at
0x00000000080EBF90>
31008 - 2014-05-12 13:05:32,378 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000008181030>
14832 - 2014-05-12 13:05:32,378 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000008181090>
22108 - 2014-05-12 13:05:32,378 - DEBUG - Cursor: <pyodbc.Cursor object at
0x00000000081810F0>
30364 - 2014-05-12 13:05:32,380 - DEBUG - Cursor: <pyodbc.Cursor object at
0x0000000008181150>
27788 - 2014-05-12 13:05:32,381 - ERROR - Error: ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)'). Query My query on ,
Traceback (most recent call last):
File "QueryObj.py", line 508, in execute
res = cursor.execute (qry, *multiparams)
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
31008 - 2014-05-12 13:05:32,381 - ERROR - Error: ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)'). Query My query on ,
Traceback (most recent call last):
File "QueryObj.py", line 508, in execute
res = cursor.execute (qry, *multiparams)
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
14832 - 2014-05-12 13:05:32,381 - ERROR - Error: ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)'). Query My query on ,
Traceback (most recent call last):
File "QueryObj.py", line 508, in execute
res = cursor.execute (qry, *multiparams)
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
22108 - 2014-05-12 13:05:32,381 - ERROR - Error: ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)'). Query My query on ,
Traceback (most recent call last):
File "QueryObj.py", line 508, in execute
res = cursor.execute (qry, *multiparams)
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
30364 - 2014-05-12 13:05:32,382 - ERROR - Error: ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)'). Query My query on ,
Traceback (most recent call last):
File "QueryObj.py", line 508, in execute
res = cursor.execute (qry, *multiparams)
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
27788 - 2014-05-12 13:05:32,384 - ERROR - Error ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)') fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
31008 - 2014-05-12 13:05:32,384 - ERROR - Error ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)') fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
14832 - 2014-05-12 13:05:32,385 - ERROR - Error ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)') fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
22108 - 2014-05-12 13:05:32,385 - ERROR - Error ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)') fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
30364 - 2014-05-12 13:05:32,387 - ERROR - Error ('HY000', '[HY000]
[Microsoft][ODBC SQL Server Driver]Connection is busy with results for
another hstmt (0) (SQLExecDirectW)') fetching results.
Traceback (most recent call last):
File "QueryObj.py", line 999, in select
res= execute (selectQry, My params)
File "QueryObj.py", line 666, in execute
raise e
Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server Driver]Connection is
busy with results for another hstmt (0) (SQLExecDirectW)')
[Removed log statements]
30848 - 2014-05-12 13:06:40,200 - DEBUG - Finish query: My query
[Removed log statements]
*What the code does:*
The code is simply trying to run in parallel, a query that takes a few
seconds to execute.
*Notes on the log statements:*
For thread id *27788 *- When this thread starts for the first time, it gets
the pyodbc connection object at 7ED3AD8. This object is not being used by
any other thread, yet it encounters ProgrammingError: Attempt to use a
closed connection. *Why would this be?*
Later, at 13:05:32,374- thread id 27788 retries. It gets pyodbc
connection 7ED3870, and cursor 80EBF90. This pyodbc connection (but not
this cursor) was already given to thread id 30848 at 13:05:32,246, and is
still in use there. Hence, when 27788 tries to execute a query it runs
into: Error: ('HY000', '[HY000] [Microsoft][ODBC SQL Server
Driver]Connection is busy with results for another hstmt (0)
(SQLExecDirectW)').
*It does seem like the error being thrown is legitimate, given that the
connection is actually being used elsewhere. I do not understand why the
engine.connect() function, when executed by thread id 27788 returns the
pyodbc object at 7ED3870, while it is being used in thread id 30848. Is
this expected? *
My understanding of how this pool works is: 30848 checks out the connection
from the pool when it runs the eng.connect() statement. This connection is
returned to the pool only when the res.close() statement is run, which is
after all the results have been fetched. While the connection has been
checked out, the pool should not be giving the same connection to other
threads.
I also tried turning off the ODBC connection pooling by going to the
control panel, that did not help either.
Thanks for your help!
--
You received this message because you are subscribed to the Google Groups
"sqlalchemy" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to sqlalchemy+unsubscr...@googlegroups.com.
To post to this group, send email to sqlalchemy@googlegroups.com.
Visit this group at http://groups.google.com/group/sqlalchemy.
For more options, visit https://groups.google.com/d/optout.
