Connection don't closed just after call timeout acquired

[golubovai]

1. What versions are you using?
   Oracle Database 19c

>>> import sys
>>> import platform
>>>
>>> print("platform.platform:", platform.platform())
platform.platform: Windows-11-10.0.22631-SP0
>>> print("sys.maxsize > 2**32:", sys.maxsize > 2**32)
sys.maxsize > 2**32: True
>>> print("platform.python_version:", platform.python_version())
platform.python_version: 3.12.4

>>> import oracledb
>>> print("oracledb.__version__:", oracledb.__version__)
oracledb.__version__: 2.4.1

2. Is it an error or a hang or a crash?
   It's error.
3. What error(s) or behavior you are seeing?
   Connections remain open in async version if we call .close() just after DPY-4024: call timeout of 60 ms exceeded acquired.

4. Does your application call init_oracle_client()?
   No, Thin

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

This test case not succeded.

async def test_5345(self):
        "5345 - test connection closing just after call timeout"
        for _ in range(1, 10):
            conn: AsyncConnection = None
            try:
                conn = await test_env.get_connection_async()
                conn.autocommit = False
                conn.call_timeout = 60
                conn.action = 'test_5345'
                async with conn.cursor() as cursor:
                    await cursor.execute("begin dbms_lock.sleep(0.05); end;")
                await conn.close()
            except Exception as e:
                await conn.close()
                conn = None

        await asyncio.sleep(5)
        conn2 = await test_env.get_connection_async()
        cursor2 = conn2.cursor()
        await cursor2.execute("""select count(*) from v$session where action = :1""", ['test_5345'])
        self.assertEqual(await cursor2.fetchone(), (0,))

Create schema as it is creted in tests. Test in sync mode don't have such a error.

def test_1146(self):
        "1146 - test connection closing just after call timeout"
        for _ in range(1, 10):
            conn: oracledb.Connection = None
            try:
                conn = test_env.get_connection()
                conn.autocommit = False
                conn.call_timeout = 60
                conn.action = 'test_1146'
                with conn.cursor() as cursor:
                    cursor.execute("begin dbms_lock.sleep(0.05); end;")
                conn.close()
            except Exception as e:
                conn.close()
                conn = None
        
        conn2 = test_env.get_connection()
        cursor2 = conn2.cursor()
        cursor2.execute("""select count(*) from v$session where action = :1""", ['test_5345'])
        self.assertEqual(cursor2.fetchone(), (0,))

[anthony-tuininga]

This not a bug but a timing issue. I adjusted the timing to force various scenarios and I found the same issues in both sync and async modes. I tweaked your test cases as follows:

diff --git a/tests/test_1100_connection.py b/tests/test_1100_connection.py
index 35648a5f..06f7ff83 100644
--- a/tests/test_1100_connection.py
+++ b/tests/test_1100_connection.py
@@ -801,6 +801,31 @@ class TestCase(test_env.BaseTestCase):
         with self.assertRaisesFullCode("DPY-2023"):
             test_env.get_connection(conn_class=oracledb.ConnectionPool)
 
+    def test_1146(self):
+        "1146 - test connection closing just after call timeout"
+        action = "action_1146"
+        proc_name = test_env.get_sleep_proc_name()
+        for _ in range(2):
+            conn = test_env.get_connection()
+            try:
+                conn.autocommit = False
+                conn.call_timeout = 6
+                conn.action = action
+                with conn.cursor() as cursor:
+                    cursor.callproc(proc_name, [0.08])
+            except Exception as e:
+                print("failed with", e)
+            finally:
+                conn.close()
+
+        conn = test_env.get_connection()
+        cursor = conn.cursor()
+        cursor.execute(
+            "select count(*) from v$session where action = :1",
+            [action],
+        )
+        self.assertEqual(cursor.fetchone(), (0,))
+
 
 if __name__ == "__main__":
     test_env.run_test_cases()
diff --git a/tests/test_5300_connection_async.py b/tests/test_5300_connection_async.py
index e8083cfa..b2a946d4 100644
--- a/tests/test_5300_connection_async.py
+++ b/tests/test_5300_connection_async.py
@@ -600,6 +600,30 @@ class TestCase(test_env.BaseAsyncTestCase):
         with self.assertRaises(TypeError):
             await oracledb.connect_async(pool="not a pool object")
 
+    async def test_5345(self):
+        "5345 - test connection closing just after call timeout"
+        action = "action_5345"
+        proc_name = test_env.get_sleep_proc_name()
+        for _ in range(2):
+            conn = await test_env.get_connection_async()
+            try:
+                conn.autocommit = False
+                conn.call_timeout = 6
+                conn.action = action
+                async with conn.cursor() as cursor:
+                    await cursor.callproc(proc_name, [.08])
+            except Exception as e:
+                print("failed with", e)
+            finally:
+                await conn.close()
+        conn = await test_env.get_connection_async()
+        with conn.cursor() as cursor:
+            await cursor.execute(
+                "select count(*) from v$session where action = :1",
+                [action],
+            )
+            self.assertEqual(await cursor.fetchone(), (0,))
+
 
 if __name__ == "__main__":
     test_env.run_test_cases()

You'll note the code is identical. If the call timeout is small enough that even the reset packets cannot be sent (and that depends on your computing and network infrastructure) then the connection is closed without the usual logoff packet being sent. How long it takes the database to clean up is unknown but it will clean up eventually. As such I don't consider this to be a bug.

[golubovai]

These connections remain open very long time (several days). We got connection leak by this feature.

[anthony-tuininga]

Really? I see mine go away after (usually) a few seconds at most. What database version are you using?

[golubovai]

Version 19.13.0.0.0, maybe this time depends on listener or network configuration.

[golubovai]

I retested with default installation of oracle database 19.3.0.0.0 (win64) locally.
If your python process stopped, when these connections closed immidiately. But if it's continue to work (e.g. await asyncio.sleep(500000)) then they remain connected very long time. 530 minutes left but they are still alive.

SQL> select 86400 * (sysdate - min(s.logon_time))/60 mins, count(*)
  2    from v$session s
  3   where s.action = 'test_5345'
  4  ;

      MINS   COUNT(*)
---------- ----------
530,166666          9

SQL> 

[golubovai]

Proecess explorer shows 10 open sockets to database.

[anthony-tuininga]

Since timing is so important in this case, can you send me the output of your script when you set the environment variable PYO_DEBUG_PACKETS to any value before running your script? You can e-mail the output to me if you'd rather not have it posted here.

[cjbj]

Closing - no update