Node Red Memory Leak When Using node-red-contrib-mssql-plus

[tjj07c]

I am using the mssql-plus node to put about 500,000 records into a sql table, 1000 records at a time. When I do this, the program will eventually crash my controller after about 3 times of running the program. It seems like the query strings are being held in the memory after the flow is completed. Is this a known issue or am I using the node incorrectly?

[Steve-Mcl]

Hi, How are you doing the insert of 1000 rows? Using TVP or a large SQL insert statement? What hardware is it and memory does it have? How many fields are in a row and what size are the fields / data you are adding?

I have personally tested sending 10000 rows using TVP parameter without issue (other than the known speed issue #35 that is waiting for the underlying node module to be update)

---

Could you test this ...

• change the MSSQL node to do something simple like "SELECT getdate()" ONLY
  • i.e. keep your flow the same, but dont do the insert
  • run your flow (does it operate normally / more than 3 times)?

---

I would be interested in replicating this issue so if you can help me I w ill take a look. I will need...

• the CREATE script for your table
• some sample data
• your flow (or the data processing and MSSQL parts)

[tjj07c]

Hello Stephen, I am using large SQL insert statements. The hardware I am using is an Opto22 GROOVE EPIC and I believe it has about 1GB dedicated to Node Red and 2 GB overall.

I will test changing the flow to do the simple select statement instead of the insert statement and get back to you.

Below is the CREATE script for my table. How would I go about getting you the flow and sample data? Do you want it just in a reply?

USE [A2ALMDB] GO /** Object: Table [dbo].[inverter_parameters] Script Date: 11/4/2020 10:54:48 AM **/ SET ANSI_NULLS ON GO SET QUOTED_IDENTIFIER ON GO CREATE TABLE [dbo].[inverter_parameters]( [INV_Name] nvarchar NULL, [INV_IP] nvarchar NULL, [Timestamp] nvarchar NULL, [Param_KKS_Name] nvarchar NULL, [Param_ID] nvarchar NULL, [Param_Value] nvarchar NULL ) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]

GO

[tjj07c]

I ran the test you suggested. I kept my very long Insert request strings in the message, but put them in a seperate msg.temp property. I ran a SELECT TOP 100 [INV_Name],[INV_IP],[Timestamp],[Param_KKS_Name],[Param_ID],[Param_Value] FROM [dbo].[inverter_parameters] query and the memory is not building up like it did with the INSERT statements. I have run it 3 times with no increase in memory so far. Usually after running 1 time, the memory would be at 400 MB used. It is just sitting at 110MB.

[Steve-Mcl]

Hi again. Would you be able to share your flow (or the parts that message the SQL inserts)

Also, how often is this very large insert expected to operate?

Lastly, so I can grasp the overall size of the 1000 insert string, could you give me a couple of insert string statements (I wish to figure out roughly how many bytes are held in memory while the commands execute).

[Steve-Mcl]

Hi, I suspect there is issue may be with VERY LARGE insert statements like yours on a device with small memory size consuming more memory than the GC can keep up with (working theory).

Would you try splitting up your inserts into smaller chunks - see if the memory still leaks (or dissipates)

Something like...

What this does is send smaller (250 rows) every 1 secs. This is more than fast enough to send 7200rows*71 invertors rows once per day.

Please let me know how you get on. I have other ideas if this doesn't work :)

demo flow...

[{"id":"ef43b17d.e31ac","type":"MSSQL","z":"86da601e.048d6","mssqlCN":"3ca28eb0.6b5822","name":"","outField":"payload","returnType":0,"throwErrors":1,"query":"","modeOpt":"","modeOptType":"query","queryOpt":"payload","queryOptType":"msg","paramsOpt":"","paramsOptType":"none","params":[],"x":1020,"y":560,"wires":[["81c7bfa2.22bca"]]},{"id":"54c8361a.9a3928","type":"function","z":"86da601e.048d6","name":"Build MSSQL Queries","func":"\nconst MAXROWS = 250;//send only xx rows at one time.\nvar len = msg.var.length;\nconst ins = `declare @ip NVARCHAR(20)\\n\ndeclare @inv NVARCHAR(200)\\n\ndeclare @ts NVARCHAR(200)\\n\nselect @ip = '${msg.INV_IP}', @inv = '${msg.INV_Name}', @ts = '${msg.timestamp}' \\n\nINSERT INTO [inverter_parameters] (INV_IP, INV_Name, Timestamp, Param_KKS_Name, Param_ID, Param_Value) \\n VALUES \\n`\n\nvar temp = ins;\nvar counter = 0;\nfor (var i=0; i<len; i++){\n    temp += `(@ip,@inv,@ts,'${msg.var[i].$.kks}','${msg.var[i].$.id}','${msg.var[i]._}')` ;\n    if(counter < MAXROWS && i<(len-1)) {\n        counter++;\n        temp += \",\\n\"\n    } else {\n        //reached MAXROWS - send what we have so far and reset counter & temp.\n        node.send({ payload: temp });\n        temp = ins;\n        counter = 0;\n    }\n}\nif(counter > 0) {\n    //send remainder\n    node.send({ payload: temp });\n}\nreturn null;","outputs":1,"noerr":0,"initialize":"","finalize":"","x":600,"y":560,"wires":[["54d06c44.4fa784"]]},{"id":"81c7bfa2.22bca","type":"debug","z":"86da601e.048d6","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","x":1050,"y":620,"wires":[]},{"id":"860b2670.16d078","type":"comment","z":"86da601e.048d6","name":"Since it is only ran once per day, send smaller inserts & spread them out","info":"","x":750,"y":520,"wires":[]},{"id":"c0ef8432.afb328","type":"function","z":"86da601e.048d6","name":"generate fake inv data","func":"// ${msg.var[i].$.kks}','${msg.var[i].$.id}','${msg.var[i]._}\n\nmsg.var = [];\n\nmsg.timestamp = Date.now() + \"\";\nmsg.INV_IP = \"192.168.0.1\";\nmsg.INV_Name = \"fake_vertor\";\n\nfunction addData(i){\n   msg.var.push({\n       $: {\n           kks: `fake.param.name.${i}`,\n           id: `R${i+1000}`,\n       },\n       _: i + Math.random()\n   }) \n}\n\n//generate 7000 fake data rows\nfor(let x = 1; x <= 7200; x++) {\n    addData(x);\n}\n\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","x":780,"y":333,"wires":[["57b55132.a16ea","54c8361a.9a3928"]]},{"id":"57b55132.a16ea","type":"debug","z":"86da601e.048d6","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","x":1010,"y":333,"wires":[]},{"id":"b3ff8e3f.e450f","type":"debug","z":"86da601e.048d6","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","x":870,"y":620,"wires":[]},{"id":"e133ea87.1f7df8","type":"MSSQL","z":"86da601e.048d6","mssqlCN":"3ca28eb0.6b5822","name":"truncate table inverter_parameters","outField":"payload","returnType":0,"throwErrors":1,"query":"-- truncate is MUCH faster than `delete from`\ntruncate table inverter_parameters","modeOpt":"","modeOptType":"query","queryOpt":"","queryOptType":"editor","paramsOpt":"","paramsOptType":"none","params":[],"x":820,"y":240,"wires":[[]]},{"id":"1184f132.55f72f","type":"inject","z":"86da601e.048d6","name":"","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"","payload":"","payloadType":"date","x":580,"y":240,"wires":[["e133ea87.1f7df8"]]},{"id":"95f8821c.ef88e","type":"comment","z":"86da601e.048d6","name":"Clear table data - delete me (or keep for test purposes)","info":"","x":720,"y":200,"wires":[]},{"id":"41a700e0.50bff","type":"comment","z":"86da601e.048d6","name":"******************* Keep this part ******************* ","info":"","x":680,"y":480,"wires":[]},{"id":"59d97c2f.677b54","type":"inject","z":"86da601e.048d6","name":"","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"","payload":"","payloadType":"date","x":580,"y":333,"wires":[["c0ef8432.afb328"]]},{"id":"f93a78d3.9ae9b8","type":"comment","z":"86da601e.048d6","name":"Faking your data - delete me (or keep for test purposes)","info":"","x":720,"y":293,"wires":[]},{"id":"54d06c44.4fa784","type":"delay","z":"86da601e.048d6","name":"","pauseType":"rate","timeout":"5","timeoutUnits":"seconds","rate":"1","nbRateUnits":"1","rateUnits":"second","randomFirst":"1","randomLast":"5","randomUnits":"seconds","drop":false,"x":810,"y":560,"wires":[["ef43b17d.e31ac","b3ff8e3f.e450f"]]},{"id":"5eee2c12.a390e4","type":"comment","z":"86da601e.048d6","name":"^ batches inserts into 250 rows","info":"","x":590,"y":600,"wires":[]},{"id":"3ca28eb0.6b5822","type":"MSSQL-CN","tdsVersion":"7_4","name":"","server":"192.168.1.38","port":"1433","encyption":true,"database":"testdb","useUTC":true,"connectTimeout":"15000","requestTimeout":"15000","cancelTimeout":"5000","pool":"5","parseJSON":false,"enableArithAbort":true}]

[tjj07c]

Hey Steve, Sorry it took me so long to get back. I tried your flow with injecting 250 rows 1 time per second, but the memory is still building up. I ran it about 3 times and it is up to 500Mb used and not going down even though the flow is done. It seems like it is saving all of the query strings and not releasing them. I took a heap snapshot and those strings look like they are taking up the majority of the space.

[tjj07c]

Hey Steve, did you need anything else from me for this issue?

[Steve-Mcl]

Hi again @tjj07c I am not familiar with how garbage collection works in nodejs & the info you showed me could be normal for all i know (sorry - not great news).

However...

I did read this: https://github.com/tediousjs/node-mssql/issues/955

in short: native promises + mssql-V6 seem to be an issue.

Are you willing to play around and test something if i provide instructions?

Essentially...

• stop node-red
• CD to where mssql-plus is installed (something like ~/.node-red/node_modules/node-red-contrib-mssql-plus)
• Install bluebird (npm install bluebird)
• modify mssql.js

  const Bluebird = require('bluebird');
  const sql = require('mssql');
  sql.Promise = Bluebird;

• start node-red
• perform your tests & please let me know the outcome.

[Steve-Mcl]

Hi @tjj07c did you get a chance to test what i proposed?

Also, I am busy adding bulk mode to the node & have tested on an RPI 3b (1GB RAM). I inserted (in one go) 500000 rows in bulk mode every hour over night. Initially, memory usage on the PI jumped from 198MB used to around 340MB used. It was still around 340MB used the next morning (promising).

If I publish a BETA release on NPM would you be willing to test?

[Steve-Mcl]

Hi again @tjj07c , hope you are still with me on this.

I have now published V0.7.0-beta.1 V0.7.0-beta.2 V0.7.0-beta.3 to NPM - https://www.npmjs.com/package/node-red-contrib-mssql-plus/v/0.7.0-beta.3

This has numerous changes but most importantly, for you, BULK INSERT mode is now implemented, Also, the MSSQL library is updated to V7.0.0-alpha (which importantly updates the tedious driver to latest version)

Install method...

• stop node-red
• open a cmd/terminal and cd to your node-red folder (often cd ~/.node-red)
• enter npm i node-red-contrib-mssql-plus@0.7.0-beta
• run node-red

Info

I have tested inserting 500000 in one go on an RPI3b with 1GB RAM. I ran it 50 times & memory did climb from 200MB peaking at 500MB but it didn't seam to leak I would recommend inserting your 7000 values per invertor 1 at a time (e.g bulk insert 7000 then once done, do 2nd set of 7000, then 3rd...).
On the RPI, 7000 rows in bulk mode took only a few seconds. NOTE: If you dont need encryption - switch that off in the connection config - i seen some speed and memory usage improvements

Note - I have included a bigger (self contained) demo of bulk insertion in the built in demos

A demo of inserting 7000 records in one go - you should be able to adapt this.

[{"id":"9bcdc5cb.758be8","type":"MSSQL","z":"30e2e9e0.eeaab6","mssqlCN":"8d9d212a.cea03","name":"bulk insert","outField":"payload","returnType":"1","throwErrors":1,"query":"inverter_parameters","modeOpt":"","modeOptType":"bulk","queryOpt":"","queryOptType":"editor","paramsOpt":"","paramsOptType":"editor","rows":"data","rowsType":"msg","params":[{"output":false,"name":"INV_IP","type":"NVarChar(200)","valueType":"msg","value":"payload"},{"output":false,"name":"INV_Name","type":"NVarChar(200)","valueType":"num","value":"0"},{"output":false,"name":"Timestamp","type":"NVarChar(200)","valueType":"num","value":"0"},{"output":false,"name":"Param_KKS_Name","type":"NVarChar(200)","valueType":"num","value":"0"},{"output":false,"name":"Param_ID","type":"NVarChar(200)","valueType":"num","value":"0"},{"output":false,"name":"Param_Value","type":"NVarChar(200)","valueType":"num","value":"0"}],"x":500,"y":540,"wires":[["37eec317.0ecccc"]]},{"id":"752ba32d.67f52c","type":"function","z":"30e2e9e0.eeaab6","name":"generate fake inv data","func":"//INSERT INTO[inverter_parameters]\n// (INV_IP, INV_Name, Timestamp, Param_KKS_Name, Param_ID, Param_Value)\n\nmsg.timestamp = Date.now() + \"\";\nmsg.INV_IP = \"192.168.0.99\";\nmsg.INV_Name = \"fake_vertor99\";\n\nvar now = (new Date()).toISOString();\n\nmsg.data = [];\n//generate 7000 fake data rows\nfor(let x = 1; x <= msg.payload; x++) {\n    msg.data.push([\n        msg.INV_IP, msg.INV_Name, now, `fake.param.name.${x}`, `R${x + 1000}`, Math.random()\n    ]);\n}\n\nreturn msg;","outputs":1,"noerr":0,"initialize":"","finalize":"","x":320,"y":540,"wires":[["9bcdc5cb.758be8"]]},{"id":"91fd8d0d.bfe3e","type":"inject","z":"30e2e9e0.eeaab6","name":"","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"rows","payload":"7000","payloadType":"num","x":140,"y":540,"wires":[["752ba32d.67f52c"]]},{"id":"631564d5.6de59c","type":"comment","z":"30e2e9e0.eeaab6","name":"Faking your data - delete me (or keep for test purposes)","info":"","x":260,"y":500,"wires":[]},{"id":"37eec317.0ecccc","type":"debug","z":"30e2e9e0.eeaab6","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","x":630,"y":540,"wires":[]},{"id":"1f26c4ea.c8733b","type":"MSSQL","z":"30e2e9e0.eeaab6","mssqlCN":"8d9d212a.cea03","name":"truncate table inverter_parameters","outField":"payload","returnType":"1","throwErrors":1,"query":"-- truncate is MUCH faster than `delete from`\ntruncate table inverter_parameters","modeOpt":"","modeOptType":"query","queryOpt":"","queryOptType":"editor","paramsOpt":"","paramsOptType":"none","params":[],"x":360,"y":460,"wires":[["db62415c.e1b14"]]},{"id":"db62415c.e1b14","type":"debug","z":"30e2e9e0.eeaab6","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","targetType":"full","x":630,"y":460,"wires":[]},{"id":"5c778331.0a519c","type":"inject","z":"30e2e9e0.eeaab6","name":"","props":[{"p":"payload"},{"p":"topic","vt":"str"}],"repeat":"","crontab":"","once":false,"onceDelay":0.1,"topic":"","payload":"","payloadType":"date","x":120,"y":460,"wires":[["1f26c4ea.c8733b"]]},{"id":"c7fea082.0e444","type":"comment","z":"30e2e9e0.eeaab6","name":"Clear table data - delete me (or keep for test purposes)","info":"","x":260,"y":420,"wires":[]},{"id":"8d9d212a.cea03","type":"MSSQL-CN","tdsVersion":"7_4","name":"My SQL Server connection","server":"192.168.1.38","port":"1433","encyption":false,"trustServerCertificate":true,"database":"testdb","useUTC":true,"connectTimeout":"15000","requestTimeout":"15000","cancelTimeout":"5000","pool":"5","parseJSON":false,"enableArithAbort":true}]

[Steve-Mcl]

@tjj07c I have been running the beta version performing bulk inserts of 500000 rows for several days. In all, the Raspberry PI has done 224 inserts and a total of 112,000,000 rows are now present in the database.

If you give it a go, please feedback so that I can gain confidence in releasing to NPM

[tjj07c]

Steve, Very sorry I haven't gotten back to you. I was out for much of the holidays. I will try testing the beta and see if this fixes the issue and get back to you.

[Steve-Mcl]

Steve, Very sorry I haven't gotten back to you. I was out for much of the holidays. I will try testing the beta and see if this fixes the issue and get back to you.

No bother. Please note, there was a small issue with beta.2. There is a beta.3 available here: https://www.npmjs.com/package/node-red-contrib-mssql-plus/v/0.7.0-beta.3

[bestlong]

https://forums.opto22.com/t/memory-leak-in-node-red-program-on-groov-epic/3376

Hi @tjj07c can u provide your flow code for debug ?

[Steve-Mcl]

@tjj07c , with mssql at V0.7.0 I have now updated master branch to v0.7.0 and is now published to NPM / flows lib.

I will close this issue but please do test and feedback any issues.

Thanks for your support

[isaaclu0897]

Hi @Steve-Mcl, we test the node version v0.6.4、v0.7.0-beta3、v0.7.3-beta4, it still have memory leak. Using the test flow as shown below.

How to resolved this problem? Could you help please ：）