Timeout on CLOB read() for certain tables

[jwlkns]

I was asked to post my finding as a bug report, so you can look into the problem further. Here is my question for the problem on stackoverflow. It turned out the issue was that sometimes the program froze on the read part of the returned CLOB object after querying for the ddl of the table. I could not establish a real pattern as to why it only sometimes froze, but when it froze, it was always on the same tables.

This is one of the tables that kept freezing up. (I trimmed the column names for the gist)

The fix for it, was not using read but instead setting the oracledb.defaults.fetch_lobs = False flag and working with the returned strings directly. After that I got no more freezes and crashes.

Additionally, due to adding the call_timeout, after the timeout passed, the program would exit without throwing any exception. Without setting a timeout the program would just freeze indefinitely.

1. What versions are you using? Database: 19c platform.platform: Windows-10-10.0.19044-SP0 sys.maxsize > 2**32: True platform.python_version: 3.10.8 oracledb.version: 1.3.1

2. Is it an error or a hang or a crash? It is a hang, which results in a crash if I set call_timeout to something other than 0 without throwing a catchable exception

3. What error(s) or behavior you are seeing? python-oracle db executes the query and as soon as I start working with the resulting CLOB the program hangs / crashes

4. Does your application call init_oracle_client()? No

5. Include a runnable Python script that shows the problem.

   
   import oracledb

def _get_ddl(dbconnection: oracledb.Connection, table: str, schema: str): dbconnection.call_timeout = 2000 # 2 seconds

try:
    # Add semicolons as terminators for this session
    cursor = dbconnection.cursor()
    cursor.execute("BEGIN\n"
                   "    DBMS_METADATA.SET_TRANSFORM_PARAM(DBMS_METADATA.SESSION_TRANSFORM, 'SQLTERMINATOR', true);\n"
                   "END;")
    # Query DDL
    cursor.execute(f"SELECT DBMS_METADATA.GET_DDL('TABLE', '{table}') AS DDL FROM DUAL")
    # Program breaks in the read() part here
    ddl = cursor.fetchone()[0].read()

    # Query indeces
    cursor = dbconnection.cursor()
    cursor.execute(f"SELECT DBMS_METADATA.GET_DDL('INDEX', index_name) FROM all_indexes WHERE table_name = '{table}' AND owner = '{schema.upper()}'")
    indeces = list(str(x[0]) for x in cursor.fetchall())

    # Parses the retreived ddl and indeces into custom type
    return ddl + indeces
except BaseException:
    raise

[cjbj]

Thank for reporting it.

[anthony-tuininga]

I tried the table you provided. I had to guess at what the X values are in order to actually create the table! I did not get a hang and the call timeout worked as expected. If you are able to get it to happen consistently can you provide me the output of the program after setting the environment variable PYO_DEBUG_PACKETS to any value? I only need the packets starting with the call to dbms_metadata. The ones before that can be ignored. Thanks!

[jwlkns]

Sorry for the extra step you had to go through, it's just I am working for a client, and I'd better be safe than sorry and mask some of the data.

Anyways, for me, it will not hang every time either. It's more like 30% of the time or something. After setting PYO_DEBUG_PACKETS=1 I could no longer get the program to get stuck. After ~50 attempts, everything worked fine.

In case it still helps you, here is the log after the first call to DBMS for setting the terminator. Do you need the packets with the call for the ddl as well? Because that is about 2000 lines.

2023-07-25 10:40:22.206 [socket: 1240] Sending packet:
0000 : 00 00 00 B6 06 00 00 00 |........|
0008 : 00 00 03 5E 03 01 21 00 |...^..!.|
0016 : 01 01 69 01 01 0D 00 00 |..i.....|
0024 : 00 01 01 04 7F FF FF FF |........|
0032 : 00 00 00 00 00 00 00 00 |........|
0040 : 00 00 00 01 00 00 00 00 |........|
0048 : 00 00 00 00 00 00 00 00 |........|
0056 : 00 00 00 69 42 45 47 49 |...iBEGI|
0064 : 4E 0A 20 20 20 20 44 42 |N.....DB|
0072 : 4D 53 5F 4D 45 54 41 44 |MS_METAD|
0080 : 41 54 41 2E 53 45 54 5F |ATA.SET_|
0088 : 54 52 41 4E 53 46 4F 52 |TRANSFOR|
0096 : 4D 5F 50 41 52 41 4D 28 |M_PARAM(|
0104 : 44 42 4D 53 5F 4D 45 54 |DBMS_MET|
0112 : 41 44 41 54 41 2E 53 45 |ADATA.SE|
0120 : 53 53 49 4F 4E 5F 54 52 |SSION_TR|
0128 : 41 4E 53 46 4F 52 4D 2C |ANSFORM,|
0136 : 20 27 53 51 4C 54 45 52 |.'SQLTER|
0144 : 4D 49 4E 41 54 4F 52 27 |MINATOR'|
0152 : 2C 20 74 72 75 65 29 3B |,.true);|
0160 : 0A 45 4E 44 3B 01 01 01 |.END;...|
0168 : 01 00 00 00 00 00 00 00 |........|
0176 : 02 80 00 00 00 00       |......  |

2023-07-25 10:40:22.237 [socket: 1240] Receiving packet:
0000 : 00 00 00 54 06 00 00 00 |...T....|
0008 : 00 00 08 01 06 04 37 68 |......7h|
0016 : 86 1E 01 0B 01 02 00 00 |........|
0024 : 00 00 01 01 00 01 0B 0B |........|
0032 : 80 00 00 00 3E 3C 3C 80 |....><<.|
0040 : 00 00 00 01 A3 00 04 01 |........|
0048 : 01 02 CB 2D 01 01 00 00 |...-....|
0056 : 00 01 02 00 2F 00 00 00 |..../...|
0064 : 00 00 00 00 00 00 00 00 |........|
0072 : 00 03 00 01 01 00 00 00 |........|
0080 : 00 00 01 01             |....    |

[anthony-tuininga]

Thanks. Understood about masking the data! I only need the packets when the hang occurs, so if you aren't getting it now then there isn't much point! If you do manage to get a hang the last 5 or 6 packets is probably sufficiient as well -- but keep all of them just in case! This begins to sound like another situation that someone else experienced but with thick mode. He also only found that it happened on Windows and intermittently. If you are able to get it to happen again, please provide the packets; otherwise, there's not much I can do!

[anthony-tuininga]

Closing - no further information provided