mkleehammer / pyodbc

Python ODBC bridge
https://github.com/mkleehammer/pyodbc/wiki
MIT No Attribution
2.95k stars 563 forks source link

Memory leak - connection to Ingres DB #1268

Closed Damian92666 closed 1 year ago

Damian92666 commented 1 year ago

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

Issue

I have a Python application. The memory leak occurs when I'm trying to connect to my Ingres DB. The funny part is that I have a connection and I can gather information from my DB. When I switch off everything else in the application (only connection to Ingres DB is ON) the memory consumption is increasing. When I switch off connection to DB, everything works properly.

I have a log from Ingres DB:

E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'.

odbcinst.ini configuration:

$ cat odbcinst.ini [Ingres] Driver=/ingres/client/cliisC8/ingres/lib/libiiodbcdriver.1.so DriverODBCVer=3.50 DriverReadOnly=N DriverType=Ingres Vendor=Actian Corporation DontDlClose=1

Python code (connection to DB only):

def _connection_to_ingres_db(self):
    try:
        connection = pyodbc.connect("Driver={Ingres};Server=xyz123;Database=mydb")
        connection.setencoding(encoding='utf-8')
    except pyodbc.Error as e:
        logger.info('!!error connecting to server!!')
    if connection:
        connection.close()

Memory consumption increasing (second column):

346600 32616 8292 R 5.3 0.1 346600 32684 8292 S 15.3 0.1 346344 32428 8292 S 3.0 0.1 346600 32432 8292 S 5.3 0.1 346344 32428 8292 S 8.6 0.1 346344 32500 8292 S 10.5 0.1 346344 32500 8292 S 4.7 0.1 346344 32500 8292 S 6.0 0.1 346344 32560 8292 S 17.5 0.1 346344 32560 8292 S 3.3 0.1 346344 32560 8292 S 5.3 0.1 346344 32628 8292 S 17.2 0.1 346344 32628 8292 S 2.0 0.1 346344 32628 8292 S 5.3 0.1 346344 32628 8292 S 7.6 0.1 346344 32696 8292 S 13.2 0.1 346344 32696 8292 S 5.3 0.1 346344 32696 8292 S 6.3 0.1 346344 32764 8292 S 14.9 0.1 346344 32764 8292 S 3.6 0.1 346344 32764 8292 R 5.0 0.1 346344 32764 8292 S 8.3 0.1 346344 32828 8292 S 11.6 0.1 346344 32828 8292 S 0.7 0.1 346344 32828 8292 S 5.3 0.1 346344 32828 8292 S 7.0 0.1 346344 32896 8292 S 14.6 0.1

Do you have any hints for me? I think I checked everything.

Thank you in advance, Damian

v-chojas commented 1 year ago

Is it a consistent memory increase? i.e. does it seem like it'll run out of memory if run long enough, and is consistently leaking a fixed amount every connection? Post an ODBC trace of a few rounds of connecting for further analysis.

Damian92666 commented 1 year ago

Hello :) My application is checking connection every 10-15 seconds. Memory usage increases while checking the connection (I can see it in two open consoles). After e.g. 2 days I will have 10% of memory usage. I have to restart my application every 5-6 days.

Wed Aug 30 16:13:09 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:13:23 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:13:42 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:13:55 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:14:09 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:14:22 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:14:36 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:14:52 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:15:05 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'. Wed Aug 30 16:15:19 2023 E_GC0236_GCN_SVRCLASS_UNKNOWN A connection request by user 'damian' to target '/INGRES' provided a server class as part of the database name (dbname/class), but no server has registered the server class 'INGRES'.

Regards, Damian

Damian92666 commented 1 year ago

Hello. I've fixed my issue. Turned out that I had to change ODBC_WCHAR_SIZE to 2. https://docs.actian.com/ingres/10s/index.html#page/Connectivity%2FII_ODBC_WCHAR_SIZE_for_Unicode_Compatibility_wit.htm%23 BR, Damian

Damian92666 commented 1 year ago

Actually I have to reopen issue. The memory leak still occurs. After the change (ODBC_WCHAR_SIZE to 2) memory consumption increases every week by 0.1 (%MEM). Before the change it was 0.1 every 6 hours. So now it is working much better - but application still has a little problem with memory consumption.

After the change (ODBC_WCHAR_SIZE to 2) logs from Ingres DB disappeared.

Do you have an idea what I should check?

Thank you in advance, Damian

v-chojas commented 1 year ago

Do you have ability to test a different driver / DB ? It may be in the driver.

gordthompson commented 1 year ago

DontDlClose=1 suggests that you are using unixODBC's connection pooling. Can you run a test with connection pooling disabled to see if that makes a difference?

Damian92666 commented 1 year ago

@gordthompson Thank you for hints. I set Pooling=No / Pooling=0 and checked with DontDlClose=1 and without this parameter. The problem still exist :(

274412 30792 7996 S 11.3 0.1 274412 30792 7996 S 9.6 0.1 274412 30792 7996 S 8.9 0.1 274412 30796 7996 R 8.3 0.1 274412 30796 7996 S 1.6 0.1 274412 30796 7996 S 10.6 0.1 274412 30796 7996 S 9.9 0.1 274412 30796 7996 S 12.3 0.1 274412 30796 7996 S 8.9 0.1 274412 30796 7996 R 4.6 0.1 274412 30796 7996 S 4.6 0.1 274412 30800 7996 S 9.3 0.1 274412 30800 7996 S 14.6 0.1 274412 30800 7996 S 8.9 0.1 274412 30800 7996 S 10.2 0.1 274412 30800 7996 S 9.2 0.1 274412 30804 7996 S 8.9 0.1 274412 30804 7996 S 9.6 0.1 274412 30804 7996 S 9.6 0.1 274412 30804 7996 S 12.3 0.1 274412 30804 7996 S 9.6 0.1 274412 30808 7996 D 8.3 0.1 274412 30808 7996 S 1.3 0.1 274412 30808 7996 R 8.3 0.1 274412 30808 7996 S 1.0 0.1 274412 30808 7996 D 1.7 0.1 274412 30808 7996 D 1.0 0.1 274412 30808 7996 D 0.3 0.1 274412 30808 7996 D 11.6 0.1 274412 30808 7996 D 9.2 0.1

I'm checking only connection with my DB. Nothing else actually. Should I add something more here: connection = pyodbc.connect("Driver={Ingres};Server=xyz123;Database=mydb") ?

Regards, Damian

Damian92666 commented 1 year ago

@v-chojas For now it's hard to say actually. I have to contact with my colleagues from DB and ask if we have another DB where we can check connection.

gordthompson commented 1 year ago

With connection pooling disabled, when I run this code

import psutil
import pyodbc

process = psutil.Process()

def printmem(msg):
    b = process.memory_info().vms
    print(f"{msg}: {b:,} bytes")

connection_string = (
    "DRIVER=ODBC Driver 18 for SQL Server;"
    "SERVER=192.168.0.199;"
    "UID=scott;PWD=tiger^5HHH;"
    "DATABASE=test;"
    "TrustServerCertificate=yes;"
)

def _connect():
    conn = pyodbc.connect(connection_string)
    conn.close()

conn_count = 0
while conn_count <= 5_000:
    conn_count += 1
    _connect()
    if conn_count % 1_000 == 0:
        printmem(f"memory used after {conn_count:,} connections")

I get

memory used after 1,000 connections: 39,849,984 bytes
memory used after 2,000 connections: 39,849,984 bytes
memory used after 3,000 connections: 39,849,984 bytes
memory used after 4,000 connections: 39,849,984 bytes
memory used after 5,000 connections: 39,849,984 bytes

Does the above code show a memory increase when it uses your driver?

Damian92666 commented 1 year ago

Hi @gordthompson

my odbcinst.ini:

[Ingres] Driver=/ingres/client/cliisC8/ingres/lib/libiiodbcdriver.1.so DriverODBCVer=3.50 DriverReadOnly=N DriverType=Ingres Vendor=Actian Corporation DontDlClose=1 Pooling=0

I get:

memory used after 1,000 connections: 290,856,960 bytes memory used after 2,000 connections: 291,532,800 bytes memory used after 3,000 connections: 292,208,640 bytes memory used after 4,000 connections: 293,019,648 bytes memory used after 5,000 connections: 293,695,488 bytes memory used after 1,000 connections: 294,981,632 bytes memory used after 2,000 connections: 295,792,640 bytes memory used after 3,000 connections: 296,468,480 bytes memory used after 4,000 connections: 297,144,320 bytes memory used after 5,000 connections: 297,955,328 bytes memory used after 1,000 connections: 298,631,168 bytes memory used after 2,000 connections: 299,442,176 bytes memory used after 3,000 connections: 300,118,016 bytes memory used after 4,000 connections: 300,793,856 bytes memory used after 5,000 connections: 301,604,864 bytes memory used after 1,000 connections: 302,280,704 bytes memory used after 2,000 connections: 303,091,712 bytes memory used after 3,000 connections: 303,767,552 bytes memory used after 4,000 connections: 304,578,560 bytes memory used after 5,000 connections: 305,254,400 bytes memory used after 1,000 connections: 305,930,240 bytes memory used after 2,000 connections: 306,741,248 bytes memory used after 3,000 connections: 307,417,088 bytes memory used after 4,000 connections: 308,228,096 bytes memory used after 5,000 connections: 308,903,936 bytes

It seems like a topic for Ingres DB team? Is something wrong on their side? Do you an idea ? Is there anything else we could check ?

Thanks, Damian

gordthompson commented 1 year ago

Is that the entire contents of your odbcinst.ini file? Pooling= is a global setting for unixODBC, so if your odbcinst.ini contains

[ODBC]
Pooling=1

[ODBC Driver 18 for SQL Server]
…
Pooling=0

then connection pooling will not be disabled for that particular driver.

If you want to disable pooling for a particular driver, the documentation says to use CPTimeout=0, although it didn't work for me with pyodbc and unixODBC 2.3.11.

gordthompson commented 1 year ago

Note also that unixODBC 2.3.12 was released on 2023-08-08 and it fixes a number of leaks related to pooling. Details here

Damian92666 commented 1 year ago

Hello @gordthompson :)

Is that the entire contents of your odbcinst.ini file? Yes.

I was checking with CPTimeout=0 as well. I have to check the unixODBC version and maybe update to the latest version as you suggested.

Unfortunately, now I have to go on sick leave and then I have 2 weeks off. I'll check it when I get back and let you know. Thank you for your help!

Regards, Damian