Memory leak with 4.1.0 5.1.0 and 5.4.0

[devpratishthan]

1. What versions are you using? We tried using 4.1.0,5.1.0 and 5.4.0 and all had the memory leak. platform linux version v18.1.0 arch x64 version string 5.4.0 oracleclient 19.8.0.0.0 oracle DB: 19.0.0.0.ru-2021-10.rur-2021-10.r1

2. Is it an error or a hang or a crash? It crashes after a while with OOM

3. What error(s) or behavior you are seeing? When we use a connection pool(max 30 min 10) and if we are fetching records from a table which has more than 250+ columns where few are clobs. The memory keeps on increasing and this memory increase is in RSS. This memory never comes down and the app crashes with OOM after a certain time. We were initially using the loopback 3 framework with oracle client, but we were able to simulate the same using the default connectionPool code given in your sample files (https://github.com/oracle/node-oracledb/blob/main/examples/connectionpool.js)

4. Include a runnable Node.js script that shows the problem. oracleLeak.zip This has insert script and create table scripts. Please run them first and then modify sample.js for DB connection.

We tested this with min pool as 10, max pool as 30 and UV_THREADPOOL_SIZE as 30

[itsvinayak]

hi @cjbj, can you have a look at this issue

[pvenkatraman]

will take a look at this. Thx.

[devpratishthan]

Hi @pvenkatraman were you able to simulate this ?

[FacundoCerezo]

Hi, any news for this issue? We are having the same problem with our project.

[pvenkatraman]

Working on this, will update. Thx

[FacundoCerezo]

Here is some info from ODPI during memory allocation:

ODPI [00001] 2022-08-02 15:45:04.580: ODPI-C 4.2.1
ODPI [00001] 2022-08-02 15:45:04.580: debugging messages initialized at level 127

[...] 

ODPI [00040] 2022-08-02 12:48:42.760: SQL BEGIN
               XXX.PROCEDURE_YYY(:cursor,:0,:1,:2,:3);
               END;
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiConn_prepareStmt(0x7fdc74046770) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_getInfo(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiStmt_getInfo(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_bindByName(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.760: allocated 256 bytes at 0x7fdc64047f10 (allocate bind vars)
ODPI [00040] 2022-08-02 12:48:42.760: allocated 1 bytes at 0x7fdc640569d0 (allocate memory for name)
ODPI [00040] 2022-08-02 12:48:42.760: ref 0x5764fc0 (dpiVar) -> 2
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiStmt_bindByName(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_bindByName(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.760: allocated 1 bytes at 0x7fdc64047ef0 (allocate memory for name)
ODPI [00040] 2022-08-02 12:48:42.760: ref 0x5302540 (dpiVar) -> 2
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiStmt_bindByName(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_bindByName(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.760: allocated 1 bytes at 0x7fdc64046bd0 (allocate memory for name)
ODPI [00040] 2022-08-02 12:48:42.760: ref 0x5618b40 (dpiVar) -> 2
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiStmt_bindByName(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_bindByName(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.760: allocated 1 bytes at 0x7fdc64056970 (allocate memory for name)
ODPI [00040] 2022-08-02 12:48:42.760: ref 0x5616fc0 (dpiVar) -> 2
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiStmt_bindByName(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_bindByName(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.760: allocated 6 bytes at 0x7fdc64046bf0 (allocate memory for name)
ODPI [00040] 2022-08-02 12:48:42.760: ref 0x578cda0 (dpiVar) -> 2
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiStmt_bindByName(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_setPrefetchRows(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.760: fn end dpiStmt_setPrefetchRows(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.760: fn start dpiStmt_execute(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_execute(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiStmt_getRowCount(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_getRowCount(0x7fdc64046600) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiStmt_getNumQueryColumns(0x5774370)
ODPI [00040] 2022-08-02 12:48:42.762: allocated 32 bytes at 0x7fdc64056940 (allocate query vars)
ODPI [00040] 2022-08-02 12:48:42.762: allocated 256 bytes at 0x7fdc64048020 (allocate query info)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_getNumQueryColumns(0x5774370) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiStmt_getQueryInfo(0x5774370)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_getQueryInfo(0x5774370) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiStmt_getQueryInfo(0x5774370)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_getQueryInfo(0x5774370) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiStmt_getQueryInfo(0x5774370)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_getQueryInfo(0x5774370) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiStmt_getQueryInfo(0x5774370)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_getQueryInfo(0x5774370) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiContext_getClientVersion(0x58352f0)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiContext_getClientVersion(0x58352f0) -> 0
ODPI [00040] 2022-08-02 12:48:42.762: fn start dpiStmt_getImplicitResult(0x7fdc64046600)
ODPI [00040] 2022-08-02 12:48:42.762: fn end dpiStmt_getImplicitResult(0x7fdc64046600) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: fn start dpiStmt_addRef(0x5774370)
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5774370 (dpiStmt) -> 2
ODPI [00001] 2022-08-02 12:48:42.762: fn end dpiStmt_addRef(0x5774370) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: fn start dpiStmt_release(0x7fdc64046600)
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x7fdc64046600 (dpiStmt) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5764fc0 (dpiVar) -> 1
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x7fdc640569d0
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5302540 (dpiVar) -> 1
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x7fdc64047ef0
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5618b40 (dpiVar) -> 1
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x7fdc64046bd0
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5616fc0 (dpiVar) -> 1
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x7fdc64056970
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x578cda0 (dpiVar) -> 1
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x7fdc64046bf0
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x7fdc64047f10
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x7fdc74046770 (dpiConn) -> 7
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x7fdc64046600
ODPI [00001] 2022-08-02 12:48:42.762: fn end dpiStmt_release(0x7fdc64046600) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: fn start dpiVar_release(0x5764fc0)
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5764fc0 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5614c80
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5468c30
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5777ff0
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x53024d0
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x54794d0
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x7fdc74046770 (dpiConn) -> 6
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5764fc0
ODPI [00001] 2022-08-02 12:48:42.762: fn end dpiVar_release(0x5764fc0) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: fn start dpiVar_release(0x5302540)
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5302540 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5302600
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5302640
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5302620
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5302660
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5198380
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x7fdc74046770 (dpiConn) -> 5
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5302540
ODPI [00001] 2022-08-02 12:48:42.762: fn end dpiVar_release(0x5302540) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: fn start dpiVar_release(0x5618b40)
ODPI [00001] 2022-08-02 12:48:42.762: ref 0x5618b40 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.762: freed ptr at 0x5618c00
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x53235b0
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5323590
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5764800
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x53026a0
ODPI [00001] 2022-08-02 12:48:42.763: ref 0x7fdc74046770 (dpiConn) -> 4
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5618b40
ODPI [00001] 2022-08-02 12:48:42.763: fn end dpiVar_release(0x5618b40) -> 0
ODPI [00001] 2022-08-02 12:48:42.763: fn start dpiVar_release(0x5616fc0)
ODPI [00001] 2022-08-02 12:48:42.763: ref 0x5616fc0 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5617080
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5613bc0
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5613ba0
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5320cf0
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5789550
ODPI [00001] 2022-08-02 12:48:42.763: ref 0x7fdc74046770 (dpiConn) -> 3
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5616fc0
ODPI [00001] 2022-08-02 12:48:42.763: fn end dpiVar_release(0x5616fc0) -> 0
ODPI [00001] 2022-08-02 12:48:42.763: fn start dpiVar_release(0x578cda0)
ODPI [00001] 2022-08-02 12:48:42.763: ref 0x578cda0 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.763: ref 0x5774370 (dpiStmt) -> 1
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x578cbf0
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5320d30
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x578cb90
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x578cbb0
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x5613be0
ODPI [00001] 2022-08-02 12:48:42.763: ref 0x7fdc74046770 (dpiConn) -> 2
ODPI [00001] 2022-08-02 12:48:42.763: freed ptr at 0x578cda0
ODPI [00001] 2022-08-02 12:48:42.763: fn end dpiVar_release(0x578cda0) -> 0
ODPI [00043] 2022-08-02 12:48:42.764: fn start dpiConn_newVar(0x7fdc74046770)
ODPI [00043] 2022-08-02 12:48:42.764: allocated 176 bytes at 0x7fdc58127430 (allocate handle)
ODPI [00043] 2022-08-02 12:48:42.764: ref 0x7fdc58127430 (dpiVar) -> 1 [NEW]
ODPI [00043] 2022-08-02 12:48:42.764: ref 0x7fdc74046770 (dpiConn) -> 3
ODPI [00043] 2022-08-02 12:48:42.764: allocated 2200000 bytes at 0x7fdc5812f240 (allocate buffer)
ODPI [00043] 2022-08-02 12:48:42.765: allocated 200000 bytes at 0x7fdc58060b90 (allocate indicator)
ODPI [00043] 2022-08-02 12:48:42.765: allocated 400000 bytes at 0x7fdc580918e0 (allocate actual length)
ODPI [00043] 2022-08-02 12:48:42.766: allocated 4800000 bytes at 0x7fdc58348410 (allocate external data)
ODPI [00043] 2022-08-02 12:48:42.776: fn end dpiConn_newVar(0x7fdc74046770) -> 0
ODPI [00043] 2022-08-02 12:48:42.776: fn start dpiConn_newVar(0x7fdc74046770)
ODPI [00043] 2022-08-02 12:48:42.776: allocated 176 bytes at 0x7fdc5805e530 (allocate handle)
ODPI [00043] 2022-08-02 12:48:42.776: ref 0x7fdc5805e530 (dpiVar) -> 1 [NEW]
ODPI [00043] 2022-08-02 12:48:42.776: ref 0x7fdc74046770 (dpiConn) -> 4
ODPI [00043] 2022-08-02 12:48:42.776: allocated 80000000 bytes at 0x7fdbeb3b4010 (allocate buffer)
ODPI [00043] 2022-08-02 12:48:42.776: allocated 200000 bytes at 0x7fdc580f3370 (allocate indicator)
ODPI [00043] 2022-08-02 12:48:42.776: allocated 400000 bytes at 0x7fdc587dc220 (allocate actual length)
ODPI [00043] 2022-08-02 12:48:42.777: allocated 200000 bytes at 0x7fdc5883dcb0 (allocate return code)
ODPI [00043] 2022-08-02 12:48:42.777: allocated 4800000 bytes at 0x7fdc5886ea00 (allocate external data)
ODPI [00043] 2022-08-02 12:48:42.788: fn end dpiConn_newVar(0x7fdc74046770) -> 0
ODPI [00043] 2022-08-02 12:48:42.788: fn start dpiConn_newVar(0x7fdc74046770)
ODPI [00043] 2022-08-02 12:48:42.788: allocated 176 bytes at 0x7fdc5800c9e0 (allocate handle)
ODPI [00043] 2022-08-02 12:48:42.788: ref 0x7fdc5800c9e0 (dpiVar) -> 1 [NEW]
ODPI [00043] 2022-08-02 12:48:42.788: ref 0x7fdc74046770 (dpiConn) -> 5
ODPI [00043] 2022-08-02 12:48:42.788: allocated 2200000 bytes at 0x7fdc58d02810 (allocate buffer)
ODPI [00043] 2022-08-02 12:48:42.788: allocated 200000 bytes at 0x7fdc58f1b9e0 (allocate indicator)
ODPI [00043] 2022-08-02 12:48:42.788: allocated 400000 bytes at 0x7fdc58f4c730 (allocate actual length)
ODPI [00043] 2022-08-02 12:48:42.789: allocated 4800000 bytes at 0x7fdc58fae1c0 (allocate external data)
ODPI [00043] 2022-08-02 12:48:42.800: fn end dpiConn_newVar(0x7fdc74046770) -> 0
ODPI [00043] 2022-08-02 12:48:42.800: fn start dpiConn_newVar(0x7fdc74046770)
ODPI [00043] 2022-08-02 12:48:42.800: allocated 176 bytes at 0x7fdc5800caa0 (allocate handle)
ODPI [00043] 2022-08-02 12:48:42.800: ref 0x7fdc5800caa0 (dpiVar) -> 1 [NEW]
ODPI [00043] 2022-08-02 12:48:42.800: ref 0x7fdc74046770 (dpiConn) -> 6
ODPI [00043] 2022-08-02 12:48:42.800: allocated 2200000 bytes at 0x7fdc59441fd0 (allocate buffer)
ODPI [00043] 2022-08-02 12:48:42.800: allocated 200000 bytes at 0x7fdc5965b1a0 (allocate indicator)
ODPI [00043] 2022-08-02 12:48:42.801: allocated 400000 bytes at 0x7fdc5968bef0 (allocate actual length)
ODPI [00043] 2022-08-02 12:48:42.802: allocated 4800000 bytes at 0x7fdc596ed980 (allocate external data)
ODPI [00043] 2022-08-02 12:48:42.810: fn end dpiConn_newVar(0x7fdc74046770) -> 0
ODPI [00043] 2022-08-02 12:48:42.810: fn start dpiStmt_define(0x5774370)
ODPI [00043] 2022-08-02 12:48:42.810: ref 0x7fdc58127430 (dpiVar) -> 2
ODPI [00043] 2022-08-02 12:48:42.810: fn end dpiStmt_define(0x5774370) -> 0
ODPI [00043] 2022-08-02 12:48:42.810: fn start dpiStmt_define(0x5774370)
ODPI [00043] 2022-08-02 12:48:42.810: ref 0x7fdc5805e530 (dpiVar) -> 2
ODPI [00043] 2022-08-02 12:48:42.810: fn end dpiStmt_define(0x5774370) -> 0
ODPI [00043] 2022-08-02 12:48:42.810: fn start dpiStmt_define(0x5774370)
ODPI [00043] 2022-08-02 12:48:42.810: ref 0x7fdc5800c9e0 (dpiVar) -> 2
ODPI [00043] 2022-08-02 12:48:42.810: fn end dpiStmt_define(0x5774370) -> 0
ODPI [00043] 2022-08-02 12:48:42.810: fn start dpiStmt_define(0x5774370)
ODPI [00043] 2022-08-02 12:48:42.810: ref 0x7fdc5800caa0 (dpiVar) -> 2
ODPI [00043] 2022-08-02 12:48:42.810: fn end dpiStmt_define(0x5774370) -> 0
ODPI [00043] 2022-08-02 12:48:42.810: fn start dpiStmt_setFetchArraySize(0x5774370)
ODPI [00043] 2022-08-02 12:48:42.810: fn end dpiStmt_setFetchArraySize(0x5774370) -> 0
ODPI [00043] 2022-08-02 12:48:42.810: fn start dpiStmt_fetchRows(0x5774370)
ODPI [00043] 2022-08-02 12:48:42.812: fn end dpiStmt_fetchRows(0x5774370) -> 0
ODPI [00037] 2022-08-02 12:48:42.814: fn start dpiStmt_close(0x5774370)
ODPI [00037] 2022-08-02 12:48:42.814: ref 0x7fdc58127430 (dpiVar) -> 1
ODPI [00037] 2022-08-02 12:48:42.814: ref 0x7fdc5805e530 (dpiVar) -> 1
ODPI [00037] 2022-08-02 12:48:42.814: ref 0x7fdc5800c9e0 (dpiVar) -> 1
ODPI [00037] 2022-08-02 12:48:42.814: ref 0x7fdc5800caa0 (dpiVar) -> 1
ODPI [00037] 2022-08-02 12:48:42.814: freed ptr at 0x7fdc64056940
ODPI [00037] 2022-08-02 12:48:42.814: freed ptr at 0x7fdc64048020
ODPI [00037] 2022-08-02 12:48:42.814: fn end dpiStmt_close(0x5774370) -> 0
ODPI [00001] 2022-08-02 12:48:42.814: fn start dpiStmt_release(0x5774370)
ODPI [00001] 2022-08-02 12:48:42.815: ref 0x5774370 (dpiStmt) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc74046770 (dpiConn) -> 5
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x5774370
ODPI [00001] 2022-08-02 12:48:42.816: fn end dpiStmt_release(0x5774370) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: fn start dpiVar_release(0x7fdc58127430)
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc58127430 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc58060b90
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc580918e0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc58348410
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5812f240
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc74046770 (dpiConn) -> 4
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc58127430
ODPI [00001] 2022-08-02 12:48:42.816: fn end dpiVar_release(0x7fdc58127430) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: fn start dpiVar_release(0x7fdc5805e530)
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc5805e530 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc580f3370
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5883dcb0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc587dc220
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5886ea00
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdbeb3b4010
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc74046770 (dpiConn) -> 3
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5805e530
ODPI [00001] 2022-08-02 12:48:42.816: fn end dpiVar_release(0x7fdc5805e530) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: fn start dpiVar_release(0x7fdc5800c9e0)
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc5800c9e0 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc58f1b9e0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc58f4c730
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc58fae1c0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc58d02810
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc74046770 (dpiConn) -> 2
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5800c9e0
ODPI [00001] 2022-08-02 12:48:42.816: fn end dpiVar_release(0x7fdc5800c9e0) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: fn start dpiVar_release(0x7fdc5800caa0)
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc5800caa0 (dpiVar) -> 0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5965b1a0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5968bef0
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc596ed980
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc59441fd0
ODPI [00001] 2022-08-02 12:48:42.816: ref 0x7fdc74046770 (dpiConn) -> 1
ODPI [00001] 2022-08-02 12:48:42.816: freed ptr at 0x7fdc5800caa0
ODPI [00001] 2022-08-02 12:48:42.816: fn end dpiVar_release(0x7fdc5800caa0) -> 0
ODPI [00042] 2022-08-02 12:48:42.817: fn start dpiConn_close(0x7fdc74046770)
ODPI [00042] 2022-08-02 12:48:42.817: fn end dpiConn_close(0x7fdc74046770) -> 0
ODPI [00001] 2022-08-02 12:48:42.817: fn start dpiConn_release(0x7fdc74046770)
ODPI [00001] 2022-08-02 12:48:42.817: ref 0x7fdc74046770 (dpiConn) -> 0
ODPI [00001] 2022-08-02 12:48:42.817: ref 0x7fdc7800c920 (dpiPool) -> 1
ODPI [00001] 2022-08-02 12:48:42.817: freed ptr at 0x7fdc74046910
ODPI [00001] 2022-08-02 12:48:42.818: freed ptr at 0x7fdc740468c0
ODPI [00001] 2022-08-02 12:48:42.818: freed ptr at 0x7fdc740469b0
ODPI [00001] 2022-08-02 12:48:42.818: freed ptr at 0x7fdc74046960
ODPI [00001] 2022-08-02 12:48:42.818: freed ptr at 0x7fdc74046a50
ODPI [00001] 2022-08-02 12:48:42.818: freed ptr at 0x7fdc74046a00
ODPI [00001] 2022-08-02 12:48:42.818: freed ptr at 0x7fdc74046770
ODPI [00001] 2022-08-02 12:48:42.818: fn end dpiConn_release(0x7fdc74046770) -> 0

We are having the same memory behaviour as @devpratishthan (rss not releasing) Running oracle-instant-client 19.5 inside a Docker container with node:lts-buster-slim base (debian 10.12, node 16.15.1 amd64) Docker host runs 5.10.0-11 kernel, node-oracle: 5.2.0 (but happens with 5.4.0 too).

[LaeraFelipe]

News about this fix?

[cjbj]

I saw email from @pvenkatraman last night that he was still debugging.

Has anyone checked whether this is a Node.js garbage collection "thing"?

@FacundoCerezo @LaeraFelipe what are your testcases?

[devpratishthan]

Hi @cjbj , According to our analysis, its not a garbage collection issue as the memory is continuously increasing during the test heavily. It is also observed that there are certain times where there is a sudden spike in the memory post the run.

One input from our side, when fetchRows is set to 1, the continuous memory increase has come down. But still we could see sudden spikes post the run.

[cjbj]

Did you have a testcase that invokes parallel calls on the pool without using a Promise? Does it reproduce for you with webapp.js?

[devpratishthan]

In Our actual use case we use this library using a wrapper from loopback. Our application is hosted where the requests may land parallely. That is the reason we have opted for connection pool and yes they will run parallely queries on the same table.

Here I have written a dummy application to simulate the same. And that is the reason I have used for loops and promises to acheive this parallel processing and to remove any overhead of the other application code.

[FacundoCerezo]

Hi, I don't have a test case to share yet. I'll try to make one soon.

We've already made v8 memory analysis but it doesn't look like it's a heap problem. Instead, we suspect it's happening within node-oracle native bindings/native library (we can check that using process.memoryUsage(), and also with ODPI memory allocation logs).

We didn't find any change whether we used promises or not.

In the meantime, we found a correlation with #1194 and we replaced getRows() with a getRow() loop as a workaround within our code (as mentioned in https://github.com/oracle/node-oracledb/issues/1194#issuecomment-579279555), running on node 16. This was enough to prevent the memory leak from happening but sounds like unexpected behavior worth checking.

[pvenkatraman]

Working on this, will update soon. Thx

[pvenkatraman]

Hi few comments:

1. I rewrote the checkMemory function as follows: async function checkMemory () { const stats = process.memoryUsage (); const text1 = rss: ${stats.rss}, heapTotal: ${stats.heapTotal}, ; const text2 = heapUsed: ${stats.heapUsed}, external: ${stats.external}\n; console.log ( text1, text2 ) ; }

2. After the query, close all LOB columns as follows: let connection = await pool.getConnection () ; let result = await connection.execute ( sql, binds, options ) ; for ( let row = 0 ; row < result.rows.length; row ++ ) { await result.rows.FIELD219.destroy (); await result.rows.FIELD237.destroy ();

3. Avoid using Promise.all()

With these changes I notice the rss being stable for some iterations before getting bumped up.

Let me know your observations. Thanks

[cjbj]

Any updates from anyone experiencing this?

[vegarringdal]

I dont know if this is any help

I have a server/pod I just called a lot with 4 queries streaming 55k/20 ish columns rows to client Colum types is just number/date/varchar2 You can see on the CPU/nettwork when I had a break/started again. Im the only user on this one atm Would have expected memory to go down a lot more... so was hoping this issue had some magical fix :-)

Update: pushed it a little more, but looks like RSS did go down a little

[devpratishthan]

Hi,

we tried @pvenkatraman changes. There were few syntax issues. we fixed it but getting the following exception

    throw er; // Unhandled 'error' event
  ^

Error: DPI-1010: not connected Emitted 'error' event on Lob instance at: at emitErrorNT (node:internal/streams/destroy:151:8) at emitErrorCloseNT (node:internal/streams/destroy:116:3) at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { errorNum: 0, offset: 0 }

This is coming after changing the following lines for ( let row = 0 ; row < result.rows.length; row ++ ) { await result.rows[row].FIELD219.destroy(); await result.rows[row].FIELD263.destroy(); await result.rows[row].FIELD266.destroy();

If we use the one suggested by you i.e await result.rows.FIELD219.destroy(); Getting following exception TypeError: Cannot read properties of undefined (reading 'destroy') at dostuff (/home/ubuntu/hkfps/testDir/sample.js:156:29) at async loop (/home/ubuntu/hkfps/testDir/sample.js:127:3) at async Promise.all (index 4)

[pvenkatraman]

@devpratishthan can you upload your modified script, I can take a look.

result.rows[row].FIELD219.destroy () -> destroy () can only be called on LOB columns. And you will have to know which columns are CLOB columns in your case by name as your OUTPUT type is OBJECT.

You can add a check for null before calling destroy to avoid "cannot read properties of undefined" If you use the OUTPUT type as ARRAY, then you can use extendedMetaData which can provide DB column type and based on that you call destroy().

DPI-1010 - at that context the connection is not established. If you can provide me the script I can take a look Thnx

[devpratishthan]

Hi,

The changes I have made is

const result = await connection.execute(sql, binds, options); for ( let row = 0 ; row < result.rows.length; row ++ ) { //console.log('219',result.rows[row].FIELD219,'266',result.rows[row].FIELD266,'263',result.rows[row].FIELD263) await result.rows[row].FIELD219.destroy(); await result.rows.FIELD263.destroy(); await result.rows.FIELD266.destroy();

    //console.log(result.rows[row]);
    //process.exit(1);
    //await result.rows[row].FIELD219.destroy();
    //await result.rows[row].FIELD237.destroy();
}

And next is Modified checkMemory Func.

sample.js.zip

[devpratishthan]

This is the console log result.. So all are having a lob 219 Lob { _readableState: ReadableState { objectMode: false, highWaterMark: 16384, buffer: BufferList { head: null, tail: null, length: 0 }, length: 0, pipes: [], flowing: null, ended: false, endEmitted: false, reading: false, constructed: true, sync: true, needReadable: false, emittedReadable: false, readableListening: false, resumeScheduled: false, errorEmitted: false, emitClose: true, autoDestroy: true, destroyed: false, errored: null, closed: false, closeEmitted: false, defaultEncoding: 'utf8', awaitDrainWriters: null, multiAwaitDrain: false, readingMore: false, dataEmitted: false, decoder: null, encoding: null, [Symbol(kPaused)]: null }, _events: [Object: null prototype] { finish: [Function: bound onceWrapper] { listener: [Function (anonymous)] } }, _eventsCount: 1, _maxListeners: undefined, _writableState: WritableState { objectMode: false, highWaterMark: 16384, finalCalled: false, needDrain: false, ending: false, ended: false, finished: false, destroyed: false, decodeStrings: false, defaultEncoding: 'utf8', length: 0, writing: false, corked: 0, sync: true, bufferProcessing: false, onwrite: [Function: bound onwrite], writecb: null, writelen: 0, afterWriteTickInfo: null, buffered: [], bufferedIndex: 0, allBuffers: true, allNoop: true, pendingcb: 0, constructed: true, prefinished: false, errorEmitted: false, emitClose: true, autoDestroy: true, errored: null, closed: false, closeEmitted: false, [Symbol(kOnFinished)]: [] }, allowHalfOpen: true, offset: 1, _isActive: false, _parentObj: ResultSet { _rowCache: [], _processingStarted: false, _convertedToStream: false, _allowGetRowCall: false, _isActive: false, _parentObj: Connection { _events: [Object: null prototype], _eventsCount: 1, _maxListeners: undefined, _dbObjectClasses: {}, _requestQueue: [], _inProgress: false, _closing: false, _pool: [Pool], _newSession: true, [Symbol(kCapture)]: false } }, [Symbol(kCapture)]: false } 266 Lob { _readableState: ReadableState { objectMode: false, highWaterMark: 16384, buffer: BufferList { head: null, tail: null, length: 0 }, length: 0, pipes: [], flowing: null, ended: false, endEmitted: false, reading: false, constructed: true, sync: true, needReadable: false, emittedReadable: false, readableListening: false, resumeScheduled: false, errorEmitted: false, emitClose: true, autoDestroy: true, destroyed: false, errored: null, closed: false, closeEmitted: false, defaultEncoding: 'utf8', awaitDrainWriters: null, multiAwaitDrain: false, readingMore: false, dataEmitted: false, decoder: null, encoding: null, [Symbol(kPaused)]: null }, _events: [Object: null prototype] { finish: [Function: bound onceWrapper] { listener: [Function (anonymous)] } }, _eventsCount: 1, _maxListeners: undefined, _writableState: WritableState { objectMode: false, highWaterMark: 16384, finalCalled: false, needDrain: false, ending: false, ended: false, finished: false, destroyed: false, decodeStrings: false, defaultEncoding: 'utf8', length: 0, writing: false, corked: 0, sync: true, bufferProcessing: false, onwrite: [Function: bound onwrite], writecb: null, writelen: 0, afterWriteTickInfo: null, buffered: [], bufferedIndex: 0, allBuffers: true, allNoop: true, pendingcb: 0, constructed: true, prefinished: false, errorEmitted: false, emitClose: true, autoDestroy: true, errored: null, closed: false, closeEmitted: false, [Symbol(kOnFinished)]: [] }, allowHalfOpen: true, offset: 1, _isActive: false, _parentObj: ResultSet { _rowCache: [], _processingStarted: false, _convertedToStream: false, _allowGetRowCall: false, _isActive: false, _parentObj: Connection { _events: [Object: null prototype], _eventsCount: 1, _maxListeners: undefined, _dbObjectClasses: {}, _requestQueue: [], _inProgress: false, _closing: false, _pool: [Pool], _newSession: true, [Symbol(kCapture)]: false } }, [Symbol(kCapture)]: false } 263 Lob { _readableState: ReadableState { objectMode: false, highWaterMark: 16384, buffer: BufferList { head: null, tail: null, length: 0 }, length: 0, pipes: [], flowing: null, ended: false, endEmitted: false, reading: false, constructed: true, sync: true, needReadable: false, emittedReadable: false, readableListening: false, resumeScheduled: false, errorEmitted: false, emitClose: true, autoDestroy: true, destroyed: false, errored: null, closed: false, closeEmitted: false, defaultEncoding: 'utf8', awaitDrainWriters: null, multiAwaitDrain: false, readingMore: false, dataEmitted: false, decoder: null, encoding: null, [Symbol(kPaused)]: null }, _events: [Object: null prototype] { finish: [Function: bound onceWrapper] { listener: [Function (anonymous)] } }, _eventsCount: 1, _maxListeners: undefined, _writableState: WritableState { objectMode: false, highWaterMark: 16384, finalCalled: false, needDrain: false, ending: false, ended: false, finished: false, destroyed: false, decodeStrings: false, defaultEncoding: 'utf8', length: 0, writing: false, corked: 0, sync: true, bufferProcessing: false, onwrite: [Function: bound onwrite], writecb: null, writelen: 0, afterWriteTickInfo: null, buffered: [], bufferedIndex: 0, allBuffers: true, allNoop: true, pendingcb: 0, constructed: true, prefinished: false, errorEmitted: false, emitClose: true, autoDestroy: true, errored: null, closed: false, closeEmitted: false, [Symbol(kOnFinished)]: [] }, allowHalfOpen: true, offset: 1, _isActive: false, _parentObj: ResultSet { _rowCache: [], _processingStarted: false, _convertedToStream: false, _allowGetRowCall: false, _isActive: false, _parentObj: Connection { _events: [Object: null prototype], _eventsCount: 1, _maxListeners: undefined, _dbObjectClasses: {}, _requestQueue: [], _inProgress: false, _closing: false, _pool: [Pool], _newSession: true, [Symbol(kCapture)]: false } }, [Symbol(kCapture)]: false }

[pvenkatraman]

Looking at the sample, will respond. Thx

[devpratishthan]

hi @pvenkatraman any update on this ??

[pvenkatraman]

@devpratishthan still working on this, no update yet.

[devpratishthan]

Hi @pvenkatraman @cjbj any update on this ??

[pvenkatraman]

Ran the sample again and again. On Windows/Linux also.

rss: 61890560, heapTotal: 17879040, heapUsed: 11086400, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11102864, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11119176, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11135640, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11151952, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11168416, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11184728, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11201192, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11217504, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11233968, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11250280, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11266744, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11283056, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11299520, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11315864, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11332328, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11348640, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11365104, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11381416, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11397880, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11414192, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11430656, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11446968, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11463432, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11479744, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11496208, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11512520, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11528984, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11545296, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11561992, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11578304, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11594768, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11611080, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11627544, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11643856, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11660320, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11676632, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11693096, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11709408, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11725872, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11742184, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11758648, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11774960, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11791424, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11807736, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11824200, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11840512, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11856976, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11873288, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11889752, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11906064, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11922528, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11938840, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11955304, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11971616, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 11988080, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12004392, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12020856, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12037168, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12053632, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12069944, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12086416, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12102728, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12119192, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12135504, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12151968, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12168280, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12184744, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12201056, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12217520, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12233832, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12250296, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12266608, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12283072, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12299384, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12315848, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12332160, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12348672, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12364984, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12381448, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12397760, external: 453952 rss: 61890560, heapTotal: 17879040, heapUsed: 12414440, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12430752, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12447216, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12463528, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12479992, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12496304, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12512768, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12529080, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12545544, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12561856, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12578320, external: 462144 rss: 61890560, heapTotal: 17879040, heapUsed: 12594648, external: 462144 rss: 61902848, heapTotal: 17879040, heapUsed: 12611112, external: 462144

The RSS memory seem to be stabilizing after some time and is not increasing exponentially.

[revoorunischal]

Hi @pvenkatraman that increase is not acceptable right?

If it keep increasing it can reach OOM right?

[sharadraju]

@revoorunischal Can you let us know what is the 'increase' you are talking about? From @pvenkatraman's comment on Oct 19, 2022, the RSS memory seems to be stable. Are you talking about the increase in 'heapUsed' memory here?

[revoorunischal]

Hi @sharadraju I retested the sample attached on the first comment with versions 4.1.0,5.4.0 and 5.5.0 in all 3 even now the rss memory keeps increasing and never comes down.

I ran the code for 15 mins+ logs.tar.gz

[anthony-tuininga]

Are you still using Node v18.1.0? The latest release is v18.13.0 and there are a number of memory leaks corrected in the releases between v18.1.0 and v18.13.0! I just tried your code with v18.12.1 and I don't see any memory leak. Please upgrade your version of Node and try again, please!

[anthony-tuininga]

FYI, I had to modify your example to change the bind value to the value ['1234'], as that was what was inserted in the table using your script DB_INS.sql. My logs show the following (at the end):

Changed Memory usage by rss, 368.218112MB 
Changed Memory usage by heapTotal, 41.025536MB 
Changed Memory usage by rss, 368.226304MB 
Changed Memory usage by rss, 368.18944MB 
Changed Memory usage by rss, 368.152576MB 
Changed Memory usage by rss, 368.214016MB 
Changed Memory usage by rss, 368.484352MB 
Changed Memory usage by rss, 368.447488MB 
Changed Memory usage by rss, 368.410624MB 
Changed Memory usage by rss, 367.886336MB 
Changed Memory usage by heapTotal, 40.501248MB 
Changed Memory usage by heapTotal, 40.763392MB 
Changed Memory usage by heapTotal, 41.025536MB 
Changed Memory usage by rss, 368.152576MB 
Changed Memory usage by rss, 368.132096MB 
Changed Memory usage by rss, 368.095232MB 
Changed Memory usage by rss, 368.058368MB 
Changed Memory usage by rss, 367.546368MB 
Changed Memory usage by heapTotal, 40.501248MB 

That value differed only slightly over the course of the run. Interestingly, I tried it with v18.1.0 as well and didn't notice any significant differences -- so perhaps something else is contributing to this? Please double check everything and repost your example if needed. Thanks!