Closed jabbera closed 8 months ago
Example code and error that fails without this PR. It passes with it and 3.8 set.
Traceback (most recent call last):
File "/mnt/z/research_hub/work/test.py", line 21, in <module>
connection.execute(table)
pyodbc.ProgrammingError: ('42S01', "[42S01] [Microsoft][ODBC Driver 17 for SQL Server][SQL Server]There is already an object named '#TemporaryTable' in the database. (2714) (SQLExecDirectW)")
import pyodbc
# pyodbc.odbcversion = "3.8" # Exception above is generated without this patch
table = """
CREATE TABLE #TemporaryTable
(
Col1 int,
Col2 varchar(10)
);
"""
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
odbcinst.ini:
[ODBC]
Pooling = Yes
What I notice about the repro code is that it seems to assume that pyodbc explicitly closes a connection created by a context manager. That is not the case, ref: https://github.com/mkleehammer/pyodbc/issues/48
While I can reproduce the error using the original repro code (with pyodbc 4.0.39), changing it to
table = """
CREATE TABLE #TemporaryTable
(
Col1 int,
Col2 varchar(10)
);
"""
connection = pyodbc.connect(connection_string)
connection.execute(table)
connection.close()
connection = pyodbc.connect(connection_string)
connection.execute(table)
connection.close()
connection = pyodbc.connect(connection_string)
connection.execute(table)
connection.close()
connection = pyodbc.connect(connection_string)
connection.execute(table)
connection.close()
connection = pyodbc.connect(connection_string)
connection.execute(table)
connection.close()
does not reproduce the error. The difference is that the original repro code results in the SQLEndTran
call being immediately followed by a SQLAllocHandle
call for the "new" connection
[ODBC][8739][1696267076.950987][SQLEndTran.c][566]
Exit:[SQL_SUCCESS]
[ODBC][8739][1696267076.951042][SQLAllocHandle.c][395]
Entry:
Handle Type = 2
Input Handle = 0x141da00
UNICODE Using encoding ASCII 'UTF-8' and UNICODE 'UTF16LE'
while explicitly closing the connection adds SQLDisconnect
and SQLFreeHandle
calls prior to the new SQLAllocHandle
[ODBC][9042][1696267851.430281][SQLEndTran.c][566]
Exit:[SQL_SUCCESS]
[ODBC][9042][1696267851.430313][SQLDisconnect.c][208]
Entry:
Connection = 0x10a9d00
[ODBC][9042][1696267851.430344][SQLDisconnect.c][302]
Exit:[SQL_SUCCESS]
[ODBC][9042][1696267851.430374][SQLFreeHandle.c][290]
Entry:
Handle Type = 2
Input Handle = 0x10a9d00
[ODBC][9042][1696267851.430408][SQLFreeHandle.c][339]
Exit:[SQL_SUCCESS]
[ODBC][9042][1696267851.430458][SQLAllocHandle.c][395]
Entry:
Handle Type = 2
Input Handle = 0x114c0d0
UNICODE Using encoding ASCII 'UTF-8' and UNICODE 'UTF16LE'
I also notice that the original repro code fails on the third context manager, not the second, which makes me suspect that "closing" a connection by clobbering the existing connection
variable with another .connect()
call might not behave as one might assume.
TL;DR - I'm just a bit confused. Perhaps @v-chojas might have some insights on this.
I'll certainly wait on the expert to comment but I'll add my 2c here also. Even if the particular issue demoed can be resolved by using the connection correctly I'd think we would want the ability for the connection to be reset when it gets added back into the pool which only happens with 3.8. Some of the items it does are not covered by the endtran call. Additionally if a connection leaks (not calling close) accidentally you won't end up with a dirty connection.
Also, while I demoed this issue using pyodbc directly I stumbled across it using sqlalchemy with the nullpool because we prefer unixodbc pooling. I would be shocked if they were missing the close call, but I'll dig into it.
Leaving for posterity but this behavior is groked by the comment below.
@gordthompson now I'm really confused. With 4.0.39 this produces the error even though the connection is being closed and it's ugly python exploiting weird scoping:
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
connection.close()
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
connection.close()
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
connection.close()
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
connection.close()
with pyodbc.connect(connection_string) as connection:
connection.execute(table)
connection.close()
The traces are identical until the very end where the non working case has 2 SqlEndTran entries in the log the first of which has a Completion Type of 0.
nonworking:
[ODBC][9306][1696343875.010144][SQLEndTran.c][417]
Entry:
Connection = 0x645b80526100
Completion Type = 0
[ODBC][9306][1696343875.010989][SQLGetInfo.c][236]
Entry:
Connection = 0x645b80526100
Info Type = SQL_CURSOR_COMMIT_BEHAVIOR (23)
Info Value = 0x645b80527580
Buffer Length = 2
StrLen = 0x7ffd1827515e
[ODBC][9306][1696343875.011008][SQLGetInfo.c][236]
Entry:
Connection = 0x645b80526100
Info Type = SQL_CURSOR_ROLLBACK_BEHAVIOR (24)
Info Value = 0x645b80527582
Buffer Length = 2
StrLen = 0x7ffd1827515e
[ODBC][9306][1696343875.011018][SQLEndTran.c][566]
Exit:[SQL_SUCCESS]
[ODBC][9306][1696343875.011036][SQLEndTran.c][417]
Entry:
Connection = 0x645b80526100
Completion Type = 1
[ODBC][9306][1696343875.011046][SQLEndTran.c][566]
Exit:[SQL_SUCCESS]
[ODBC][9306][1696343875.011056][SQLDisconnect.c][208]
Entry:
Connection = 0x645b80526100
[ODBC][9306][1696343875.011066][SQLDisconnect.c][302]
Exit:[SQL_SUCCESS]
[ODBC][9306][1696343875.011076][SQLFreeHandle.c][324]
Entry:
Handle Type = 2
Input Handle = 0x645b80526100
[ODBC][9306][1696343875.011087][SQLFreeHandle.c][373]
Exit:[SQL_SUCCESS]
working:
[ODBC][9334][1696343896.284380][SQLEndTran.c][417]
Entry:
Connection = 0x5cc26697d4d0
Completion Type = 1
[ODBC][9334][1696343896.287287][SQLGetInfo.c][236]
Entry:
Connection = 0x5cc26697d4d0
Info Type = SQL_CURSOR_COMMIT_BEHAVIOR (23)
Info Value = 0x5cc26697e950
Buffer Length = 2
StrLen = 0x7ffdb07b0ebe
[ODBC][9334][1696343896.287304][SQLGetInfo.c][236]
Entry:
Connection = 0x5cc26697d4d0
Info Type = SQL_CURSOR_ROLLBACK_BEHAVIOR (24)
Info Value = 0x5cc26697e952
Buffer Length = 2
StrLen = 0x7ffdb07b0ebe
[ODBC][9334][1696343896.287314][SQLEndTran.c][566]
Exit:[SQL_SUCCESS]
[ODBC][9334][1696343896.287325][SQLDisconnect.c][208]
Entry:
Connection = 0x5cc26697d4d0
[ODBC][9334][1696343896.287335][SQLDisconnect.c][302]
Exit:[SQL_SUCCESS]
[ODBC][9334][1696343896.287344][SQLFreeHandle.c][324]
Entry:
Handle Type = 2
Input Handle = 0x5cc26697d4d0
[ODBC][9334][1696343896.287377][SQLFreeHandle.c][373]
Exit:[SQL_SUCCESS]
notice the Completion type of 0 that is only in the non working example (and is 1 in the same spot in the working example):
[ODBC][9306][1696343875.010144][SQLEndTran.c][417]
Entry:
Connection = 0x645b80526100
Completion Type = 0
followed by the Completion Type of 1 that is in both, but is in a different location in the trace compared to the working example:
[ODBC][9306][1696343875.011036][SQLEndTran.c][417]
Entry:
Connection = 0x645b80526100
Completion Type = 1
[ODBC][9306][1696343875.011046][SQLEndTran.c][566]
Exit:[SQL_SUCCESS]
@gordthompson I think you have a bug in your test case. Because autocommit is not enabled the close call in your case rolls back the transaction that creates the temporary table. Therefore it is not associated with the session any longer. If you turn on autocommit or add a commit statement the issue reproduces fine:
for i in range(20):
connection = pyodbc.connect(connection_string)
connection.execute(table)
connection.commit()
connection.close()
Thanks. In the future, we might want to add an error message if the user tries something unsupported like "3.9".
Fixes https://github.com/mkleehammer/pyodbc/issues/1277
My cpp is VERY rusty. Let me know if there is a better solution for this.