pyodbc icon indicating copy to clipboard operation
pyodbc copied to clipboard

cursor in bad state after executing statement with print statement and really long input

Open hb2638 opened this issue 2 years ago • 4 comments

Please first make sure you have looked at:

  • Documentation: https://github.com/mkleehammer/pyodbc/wiki
  • Other issues

Environment

To diagnose, we usually need to know the following, including version numbers. On Windows, be sure to specify 32-bit Python or 64-bit:

  • Python: 3.11 64-bit
  • pyodbc: 4.0.35
  • OS: Windows 10
  • DB: SQL Server 2019 (15.0.4123.1)
  • driver: ODBC Driver 18 for SQL Server (2018.181.02.01)
  • SQL.LOG

Issue

The PRINT statement is not getting outputed. (see https://github.com/mkleehammer/pyodbc/wiki/Cursor#messages). It will work if I make input less than 2070 characters.

cnxn = pyodbc.connect(cnxn_str, autocommit=True)
    crsr = cnxn .cursor()
    input = '165,2900,3123,6135,2025,1117,5673,1889,7452,6652,4088,6837,6104,4129,676,6013,5963,4516,2947,1408,255,1859,7205,3747,3553,123,6446,357,1403,1091,2140,3397,3774,5924,3379,3436,6043,1194,5618,1406,1081,4120,2252,6751,3765,826,2645,949,2993,5718,1043,2316,4438,2535,7165,6562,4436,121,7429,4433,2610,663,832,6941,3554,3698,120,6920,3077,5965,2809,527,6566,4548,3929,6724,7228,2098,119,5771,1264,5843,1508,1075,5623,1239,4338,6787,7406,6569,4190,1683,2538,1415,6672,3521,3295,118,6615,1827,6406,7329,6831,7328,3534,849,2002,5746,2742,6549,7439,6892,2082,2042,1667,7446,2192,897,3428,1435,2487,780,117,6418,1858,2016,1193,3566,1237,4525,2085,1068,6369,2049,487,494,4362,846,1646,1588,875,793,6778,6177,1067,5708,712,7414,5973,4074,3832,3571,116,6594,3287,2870,3419,3174,115,4428,4124,1823,2422,3352,540,5863,2228,1714,2143,6195,5977,3894,545,5998,6755,6253,6847,1350,4515,2666,1929,7095,114,7061,3167,6689,6185,5722,7293,6834,6354,4421,6630,113,3565,3551,661,3307,1344,5717,7072,3114,7497,1184,3454,878,468,2188,6085,7071,112,4471,4331,2668,3533,7212,461,6946,7269,3550,6545,1005,3862,716,4205,1341,3976,6074,585,2287,3582,7221,3735,5643,3343,1551,2648,5695,353,3612,1850,1573,7006,1145,6824,6246,6669,703,4081,6070,3350,6067,3135,6184,5940,2927,5857,2581,2390,4295,6157,950,7110,7294,3275,3986,7113,4313,1739,1092,7495,6126,5855,3824,5839,6226,3069,2663,6722,5831,3705,5941,111,3786,1965,6441,6602,856,6140,4158,3610,6242,2170,1887,4429,1108,6404,3327,2251,1141,4100,7344,7342,2858,7343,110,4330,3062,1796,5671,4378,800,2539,6848,109,4150,5850,3090,3362,2385,1623,6927,3763,1263,2334,7167,7203,1487,6025,7411,2102,5644,3730,2722,1778,814,2104,1595,5794,635,4184,5881,3548,3048,6932,1574,6049,2320,3543,1387,5936,7079,108,7408,3497,3959,1389,1262,5574,3098,2341,2165,5680,3485,4430,1730,6329,7451,1757,7196,6179,107,2401,6411,6165,1012,1061,2642,5847,1585,2086,2081,6678,5575,6172,1727,6676,2807,2091,6655,3969,1795,4505,5915,5571,5674,2951,3253,4449,3120,499,105,104,103,4445,102,6805,6467,1177,3480,2670,101,753,475,1111,864,100,3517,5584,5804,1235,5960,6934,2957,1444,3477'
    crsr.execute("PRINT 'HI';SELECT ?", [input])
    print(crsr.messages)

Often it is easiest to describe your issue as "expected behavior" and "observed behavior".

hb2638 avatar Dec 26 '22 06:12 hb2638

It will work if I make input less than 2070 characters.

The cutoff is actually 2000 characters (4000 bytes), which is where DAE kicks in. So when len(input) > 2000 we get

[]

whereas when len(input) <= 2000 we get

[('[01000] (0)', '[Microsoft][ODBC Driver 17 for SQL Server][SQL Server]HI')]

gordthompson avatar Dec 26 '22 16:12 gordthompson

I ran this again with the SQL Trace and I see the ODBC driver is sending back the PRINT message on line 438 but for some reason, pyodbc is not capturing it.

test_me 3da4-aef8 EXIT SQLParamData with return code 1 (SQL_SUCCESS_WITH_INFO) HSTMT 0x000001ACEBCE1740 PTR * 0x0000001895DEC2F8 DIAG [01000] [Microsoft][ODBC Driver 18 for SQL Server][SQL Server]2023-07-25 19:29:04.1355377 -04:00 (0)

The SQL trace for the below python code is @ SQL.LOG

import logging
import unittest


import pyodbc

log = logging.getLogger(__name__)


class MyTestCase(unittest.TestCase):

    def test_something(self):
        conn_str = "Driver=ODBC Driver 18 for SQL Server;Server=localhost;TrustServerCertificate=yes;Trusted_Connection=yes;APP=tests.utils.TestCase:1022::46840;MARS_Connection=yes;ConnectRetryCount=30"
        conn = pyodbc.connect(conn_str, autocommit=True)
        crsr = conn.cursor()
        input = '165,2900,3123,6135,2025,1117,5673,1889,7452,6652,4088,6837,6104,4129,676,6013,5963,4516,2947,1408,255,1859,7205,3747,3553,123,6446,357,1403,1091,2140,3397,3774,5924,3379,3436,6043,1194,5618,1406,1081,4120,2252,6751,3765,826,2645,949,2993,5718,1043,2316,4438,2535,7165,6562,4436,121,7429,4433,2610,663,832,6941,3554,3698,120,6920,3077,5965,2809,527,6566,4548,3929,6724,7228,2098,119,5771,1264,5843,1508,1075,5623,1239,4338,6787,7406,6569,4190,1683,2538,1415,6672,3521,3295,118,6615,1827,6406,7329,6831,7328,3534,849,2002,5746,2742,6549,7439,6892,2082,2042,1667,7446,2192,897,3428,1435,2487,780,117,6418,1858,2016,1193,3566,1237,4525,2085,1068,6369,2049,487,494,4362,846,1646,1588,875,793,6778,6177,1067,5708,712,7414,5973,4074,3832,3571,116,6594,3287,2870,3419,3174,115,4428,4124,1823,2422,3352,540,5863,2228,1714,2143,6195,5977,3894,545,5998,6755,6253,6847,1350,4515,2666,1929,7095,114,7061,3167,6689,6185,5722,7293,6834,6354,4421,6630,113,3565,3551,661,3307,1344,5717,7072,3114,7497,1184,3454,878,468,2188,6085,7071,112,4471,4331,2668,3533,7212,461,6946,7269,3550,6545,1005,3862,716,4205,1341,3976,6074,585,2287,3582,7221,3735,5643,3343,1551,2648,5695,353,3612,1850,1573,7006,1145,6824,6246,6669,703,4081,6070,3350,6067,3135,6184,5940,2927,5857,2581,2390,4295,6157,950,7110,7294,3275,3986,7113,4313,1739,1092,7495,6126,5855,3824,5839,6226,3069,2663,6722,5831,3705,5941,111,3786,1965,6441,6602,856,6140,4158,3610,6242,2170,1887,4429,1108,6404,3327,2251,1141,4100,7344,7342,2858,7343,110,4330,3062,1796,5671,4378,800,2539,6848,109,4150,5850,3090,3362,2385,1623,6927,3763,1263,2334,7167,7203,1487,6025,7411,2102,5644,3730,2722,1778,814,2104,1595,5794,635,4184,5881,3548,3048,6932,1574,6049,2320,3543,1387,5936,7079,108,7408,3497,3959,1389,1262,5574,3098,2341,2165,5680,3485,4430,1730,6329,7451,1757,7196,6179,107,2401,6411,6165,1012,1061,2642,5847,1585,2086,2081,6678,5575,6172,1727,6676,2807,2091,6655,3969,1795,4505,5915,5571,5674,2951,3253,4449,3120,499,105,104,103,4445,102,6805,6467,1177,3480,2670,101,753,475,1111,864,100,3517,5584,5804,1235,5960,6934,2957,1444,3477'
        crsr.setinputsizes([(pyodbc.SQL_WVARCHAR, 0,)])
        crsr.execute("PRINT SYSDATETIMEOFFSET();SELECT ?", [input])
        print(crsr.messages)
        try:
            crsr.fetchall()
        except Exception:
            pass
        while crsr.nextset():
            print(crsr.messages)
            try:
                crsr.fetchall()
            except Exception:
                pass
            print(crsr.messages)
        print(crsr.messages)


if __name__ == '__main__':
    unittest.main()

hb2638 avatar Jul 25 '23 23:07 hb2638

Reproduced with pyodbc 5.1.0 and FreeTDS ODBC.

Shorter parameter value:

import pyodbc

cnxn = pyodbc.connect(
    "Driver=FreeTDS;"
    "Server=192.168.0.199;"
    "Port=1433;"
    "Database=test;"
    "UID=scott;"
    "PWD=tiger^5HHH;"
)
crsr = cnxn.cursor()

num_chars = 1999
crsr.execute("PRINT 'HI!'; SELECT ?", "x" * num_chars)
print(crsr.messages)
# [('[01000] (0)', '[FreeTDS][SQL Server]HI!')]

trace_1999.log

Longer parameter value:

num_chars = 2001
crsr.execute("PRINT 'HI!'; SELECT ?", "x" * num_chars)
print(crsr.messages)
# []

trace_2001.log

gordthompson avatar May 07 '24 17:05 gordthompson

Compare

		Exit:[SQL_SUCCESS]                
			Column Name = []                
			Data Type = 0x7fff9f49752a -> -9
			Column Size = 0x7fff9f497530 -> 3998 (64 bits)          <--- nonzero length
			Decimal Digits = 0x7fff9f49752c -> 0                
			Nullable = 0x7fff9f49752e -> 1
[ODBC][2763][1715103186.042597][SQLDescribeColW.c][209]

with

		Exit:[SQL_SUCCESS]                
			Column Name = []                
			Data Type = 0x7ffd4d1e425a -> -9
			Column Size = 0x7ffd4d1e4260 -> 0 (64 bits)             <--- zero length
			Decimal Digits = 0x7ffd4d1e425c -> 0                
			Nullable = 0x7ffd4d1e425e -> 1

This indicates a max type, whic it seems pyODBC 5 doesn't understand (compare with the trace posted above on Windows with the msodbcsql driver, where it looks like pyODBC 4 made an attempt to fetch the data.)

v-chojas avatar May 07 '24 23:05 v-chojas