oracle / python-oracledb

Python driver for Oracle Database conforming to the Python DB API 2.0 specification. This is the renamed, new major release of cx_Oracle
https://oracle.github.io/python-oracledb
Other
342 stars 69 forks source link

Connection don't closed just after call timeout acquired #386

Closed golubovai closed 1 month ago

golubovai commented 3 months ago
  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
  1. Is it an error or a hang or a crash? It's error.
  2. 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.
anthony-tuininga commented 3 months ago

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 commented 2 months ago

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

anthony-tuininga commented 2 months ago

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

golubovai commented 2 months ago

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

golubovai commented 2 months ago

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 commented 2 months ago

Proecess explorer shows 10 open sockets to database. image

anthony-tuininga commented 2 months ago

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 commented 1 month ago

Closing - no update