Node-red-node-mysql 0.3.0 is causing a memory leak

General
1

Hi,

I've noticed that sometimes my Node-RED application crashes. Looking through system log I found that it crashes with out-of-memory error:

Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: <--- Last few GCs --->
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: [644:0x61237a0] 15074008 ms: Mark-sweep (reduce) 127.1 (129.5) -> 126.1 (130.7) MB, 268.4 / 1.0 ms  (average mu = 0.643, current mu = 0.037) task scavenge might not succeed
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: [644:0x61237a0] 15076073 ms: Mark-sweep (reduce) 127.3 (132.7) -> 126.0 (132.7) MB, 162.2 / 1.6 ms  (+ 5.6 ms in 5 steps sincestart of marking, biggest step 3.5 ms, walltime since start of marking 326 ms) (average mu = 0.847, current mu = 0.919) allocation failure
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: <--- JS stacktrace --->
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  1: 0xa389b0 node::Abort() [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  2: 0x96e0af node::FatalError(char const*, char const*) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  3: 0xbb7a4e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  4: 0xbb7dc7 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  5: 0xd73fd5  [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  6: 0xda496e v8::internal::EvacuateNewSpaceVisitor::Visit(v8::internal::HeapObject, int) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  7: 0xdb09a6 v8::internal::FullEvacuator::RawEvacuatePage(v8::internal::MemoryChunk*, long*) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  8: 0xd9cb3f v8::internal::Evacuator::EvacuatePage(v8::internal::MemoryChunk*) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]:  9: 0xd9cdb8 v8::internal::PageEvacuationTask::RunInParallel(v8::internal::ItemParallelJob::Task::Runner) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 10: 0xd8f699 v8::internal::ItemParallelJob::Run() [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 11: 0xdb2900 void v8::internal::MarkCompactCollectorBase::CreateAndExecuteEvacuationTasks<v8::internal::FullEvacuator, v8::internal::MarkCompactCollector>(v8::internal::MarkCompactCollector*, v8::internal::ItemParallelJob*, v8::internal::MigrationObserver*, long) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 12: 0xdb319c v8::internal::MarkCompactCollector::EvacuatePagesInParallel() [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 13: 0xdb3365 v8::internal::MarkCompactCollector::Evacuate() [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 14: 0xdc5361 v8::internal::MarkCompactCollector::CollectGarbage() [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 15: 0xd81628 v8::internal::Heap::MarkCompact() [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 16: 0xd83118 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 17: 0xd8655c v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 18: 0xd4bd2d v8::internal::Factory::AllocateRaw(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 19: 0xd45bb4 v8::internal::FactoryBase<v8::internal::Factory>::AllocateRawWithImmortalMap(int, v8::internal::AllocationType, v8::internal::Map, v8::internal::AllocationAlignment) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 20: 0xd46725 v8::internal::Handle<v8::internal::HeapNumber> v8::internal::FactoryBase<v8::internal::Factory>::NewHeapNumber<(v8::internal::AllocationType)0>() [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 21: 0xfac638 v8::internal::String::ToNumber(v8::internal::Isolate*, v8::internal::Handle<v8::internal::String>) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 22: 0x10a84b7 v8::internal::Runtime_StringToNumber(int, unsigned long*, v8::internal::Isolate*) [node-red]
Nov 17 21:30:15 ubuntu-nuc Node-RED[644]: 23: 0x1446379  [node-red]
Nov 17 21:30:36 ubuntu-nuc systemd[1]: Stopped Node-RED graphical event wiring tool.

Some time after Node-RED service restart there was a warning in system log:

Nov 17 21:32:00 ubuntu-nuc Node-RED[4660]: (node:4660) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 acquire listeners added to [Pool]. Use emitter.setMaxListeners() to increase limit
Nov 17 21:32:00 ubuntu-nuc Node-RED[4660]: (Use `node --trace-warnings ...` to show where the warning was created)

After adding "-- trace-warnings" to NODE_OPTIONS in /usr/lib/systemd/system/nodered.service and restarting Node-RED service I see the following messages in system log:

Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]: (node:23840) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 acquire listeners added to [Pool]. Use emitter.setMaxListeners() to increase limit
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at _addListener (events.js:475:17)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at Pool.addListener (events.js:497:10)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at MysqlDBNodeIn._inputCallback (/home/sweethome/.node-red/node_modules/node-red-node-mysql/68-mysql.js:118:50)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at /usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:203:26
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at Object.trigger (/usr/lib/node_modules/node-red/node_modules/@node-red/util/lib/hooks.js:149:13)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at MysqlDBNodeIn.Node._emitInput (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:195:11)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at MysqlDBNodeIn.Node.emit (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:179:25)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at MysqlDBNodeIn.Node.receive (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:478:10)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at Immediate.<anonymous> (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/flows/Flow.js:679:52)
Nov 18 18:50:51 ubuntu-nuc Node-RED[23840]:     at processImmediate (internal/timers.js:464:21)

Using node-red-contrib-gc I have created a memory heap usage graph in my Node-RED application dashbord. Here is how it looks for now after restarting Node-RED service yesterday around 8:40PM MSK:
изображение
I.e. within less then 24 hours almost 500MBytes leaked.

I was able to duplicate possible memory leak warning on my test machine using the following flow:

изображение
изображение1018×294 24 KB

As soon as new users can't upload files, flow.json can be downloaded from here if necessery.
5th or 6th click on middle inject button causes memory leak warning in system log.

Looking through source code in .node-red/node_modules/node-red-node-mysql/68-mysql.js I see the line 77, which, I guess, is responsible for memory releasing, is commented out:

        this.on('close', function(done) {
            if (this.tick) { clearTimeout(this.tick); }
            if (this.check) { clearInterval(this.check); }
            node.connected = false;
            // node.connection.release();
            node.emit("state"," ");
            node.pool.end(function(err) { done(); });
        });

Can this be the reason of memory leak? Something tells me that closed connection will never be used again and should be released.

I use the following configuration:
Operating system: Ubuntu Linux Server v.20.04.3
Node-RED version: v2.0.6 (my Node-RED app), v2.1.3 (test)
Node.js version: v14.18.1

Thanks,
Sergey

2

How often are you writing to the database?

Is the flow you show the only access to the database in node-red?

What specifically suggests to you that it is the MySql node causing the problem?

3

The mysql message is more a warning than reality... but there is a recent thread with a beta release you are welcome to try that does fix that [Feedback wanted] Update to mysql node

(though I do suspect the real cause is most likely elsewhere)

1 Like
4
  1. My Node-RED application writes ~3-6 times per minute, but 3 of them are very close to each other;
  2. In aplication I have two mysql nodes in two flows, in test flow there is only one node in only one flow;
  3. a) I have similar app on my home Orange Pi which uses the same nodes but don't writes to database and it do not chash;
    b) warning trace points to mysql;
    c) getting memory leak warning in syslog on 5-6th click in test flow while MaxListeners is set to 10 by default, I suspect that each click creates 2 listeners and listeners are not releasing after use.
5

What about commented line 77 in 68-mysql.js?

6

We are now using the pool of connections so the end should clean them all up...

7

It isn't a memory leak warning.

Do you mean that you have nothing else running in node-red except that flow?

Did you try the beta version suggested?

8

Ok. It is "MaxListenersExceededWarning: Possible EventEmitter memory leak detected."

Yes. Nothing except this test flow.

Not yet.

9

And running that test flow eventually gives you the memory crash?

10

No. 5-6th click on middle inject button gives me "MaxListenersExceededWarning: Possible EventEmitter memory leak detected. "

11

But does it crash node-red after an extended period? That is the problem that needs to be fixed.

Almost certainly the Listeners message is not the cause of the crash, since you are only writing a few times a minute to the database, particularly since you are only writing a small amount of information each time (the vmstats).

12

Installed node-red-node-mysql@1.0.0-beta-2 using cd ~/.node-red && npm i node-red-node-mysql@next command. Restarted Node-RED service but I still see node-red-node-mysql 0.3.0 in Node-RED editor palette.
Is that Ok?

13

no - it should show the correct version (as long as you reloaded the page also)
image

14

Everything is Ok after page reloading. I was not able to get MaxListenersExceededWarning clicking on inject button in my test application.
After upgrading mysql node in main application to v1.0.0-beta2 I did't get this warning within 20 minutes after Node-RED restart. This application bulds memory heap usage graph. I will provide it to you after 24 hours running.
Thanks a lot.

15

If you are still getting the crash then tell us more about what you are doing. Are you manipulating any large data items? Possibly photos or videos, or fetching large numbers of rows from your db, or reading large files.

Also tell us about any additional nodes you have installed. Check in manage palette to see what you have installed.

16

@dceejay, unfortunately I can't provide you 24-hours graph due to power outage I had at location where my app is running. UPS battery died before power was restored. But looking on last 12 hours graph I can state that memory leak is fixed by v1.0.0-beta-2:
изображение
Memory leak gone away. Thank you. But I got another issue (see here).

1 Like
17

expect beta3 sometime tomorrow (probably)

(uodate) - now republished with decimalNumbers flag set true

1 Like
18

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.