Version 1.2.0 crashing node red if Show Hidden Files selected

[colinl]

Software and Package Versions

Software	Version
Node.JS	10.18.1
npm	6.13.4
Node-RED	1.0.2
fs node	1.2.0
OS	Ubuntu 19.10
Browser	Waterfox Classic

Note that a browser version less than current-2 or IE < v11 very unlikely to work.

How is Node-RED installed?

Using the Pi install script

To reproduce

Configure the fs list node to show hidden files, and drive it via an inject node. Click the inject node about 20 times, it is not necessary to do it fast as far as I can see. Node red crashes with the error below. Clearing Show Hidden Files appears to solve the problem. Rolling back to v1.1.1 also solves it. On a Pi Zero running Raspbian the same situation hogs the processor rather than crashing it. Sample flow:

[{"id":"a8bcf9a2.709be8","type":"fs-file-lister","z":"5bb5a6a6.97527","name":"","start":"/","pattern":"fred","folders":"","hidden":true,"lstype":"files","path":false,"single":false,"depth":0,"stat":false,"x":348,"y":501,"wires":[["46bcb3a2.6fffec"]]},{"id":"c12ea2b0.a615d8","type":"inject","z":"5bb5a6a6.97527","name":"","topic":"","payload":"","payloadType":"date","repeat":"","crontab":"","once":false,"onceDelay":0.1,"x":181,"y":500,"wires":[["a8bcf9a2.709be8"]]},{"id":"46bcb3a2.6fffec","type":"debug","z":"5bb5a6a6.97527","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"false","x":509,"y":500,"wires":[]}]

Node red log:

--- Last few GCs --->
[20213:0x42edca0]   370577 ms: Mark-sweep 253.0 (261.9) -> 252.6 (262.4) MB, 182.7 / 0.0 ms  (average mu = 0.145, current mu = 0.012) allocation failure scavenge might not succeed
[20213:0x42edca0]   370866 ms: Mark-sweep 253.4 (262.4) -> 253.1 (262.9) MB, 286.5 / 0.0 ms  (average mu = 0.065, current mu = 0.008) allocation failure scavenge might not succeed
<--- JS stacktrace --->
==== JS stack trace =========================================
    0: ExitFrame [pc: 0x11ff2755be1d]
    1: StubFrame [pc: 0x11ff2754dac0]
Security context: 0x0de13351e6e9 <JSObject>
    2: replace [0xde1335105e9](this=0x02e8e53dfb49 <String[10]: .........*>,0x00081dc1d751 <JSRegExp <String[16]: (\\?)((\W)(\3*))>>,0x1ea7b40d5029 <JSFunction input.replace (sfi = 0x1aff74a0f8e9)>)
    3: parse(aka parse) [0x28e23a399eb1] [/home/colinl/.node-red/node_modules/picomatch/lib/parse.js:~55] [pc=0x11ff278672b...
FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0x8fa090 node::Abort() [node-red]
 2: 0x8fa0dc  [node-red]
 3: 0xb0039e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node-red]
 4: 0xb005d4 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node-red]
 5: 0xef4ae2  [node-red]
 6: 0xef4be8 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [node-red]
 7: 0xf00cc2 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [node-red]
 8: 0xf015f4 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node-red]
 9: 0xf04261 v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [node-red]
10: 0xecd6e4 v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [node-red]
11: 0x116d86e v8::internal::Runtime_AllocateInNewSpace(int, v8::internal::Object**, v8::internal::Isolate*) [node-red]
12: 0x11ff2755be1d
nodered.service: Main process exited, code=dumped, status=6/ABRT
nodered.service: Failed with result 'core-dump'.

[TotallyInformation]

There appears to be some high memory use in there.

and the garbage collector then fails to clear enough heap space.

Happens on Windows not just Linux.

Not sure if Paul (@juggledad) can see what the issue might be. I'll try to take a look if I get time.

Clearly related to PR #17

[juggledad]

With Colin's flow, if I flood the node with a lot of msg's, I do see a slowdown (on my Pi3) but it is doing a recursive search. I'm sure on a pi zero (w) it will be worse due to the slower processer and it having only 512 MB of ram.

I don't know if there is a way to single thread the calls to readdirp to let if finish one before processing the next...

[TotallyInformation]

No, this is much more than limited resources. I'm running it on an Intel i7 with 16GB of RAM and it still fails.

Looking at the memory utilisation, I can see that heap is being allocated much faster than it is being cleared. If you run it say 10 times and then stop for 2 minutes or so, you should find that you can do the same again.

I think this is something to do with readdirp

[colinl]

Also the depth is set to 0 so it is only doing a single level isn't it?

[TotallyInformation]

Yes, not sure what it is doing but my last claim wasn't quite right:

I left a good period between the first multiple batch and the second. But it crashed anyway. V8 has access to 2GB on my dev PC and you can see that is where it crashed once RSS hit 2GB.

[TotallyInformation]

Another test shows that once readdirp is called a second time before the first finishes, that appears to be when it crashes:

I think that we have to say that readdirp just isn't up to the job.

Time to look for an alternative library? There really isn't anything complex in the node itself, all the work is done in readdirp. I've checked that the node isn't doing anything odd with variable allocation and it doesn't appear to be a normal memory leak.

[colinl]

What is the significance of Show Hidden Files in this though? Also the previous version doesn't suffer from the problem as far as I can tell.

[juggledad]

Ahhh, I just caused it to crash NR on my Mac. I had to flood it with a lot of requests and I got a bunch os 'server not responding' windows then NR crashed. Not sure if this will help, but this is the log

<--- Last few GCs --->

[26918:0x1028c0000]  4178031 ms: Mark-sweep 2046.5 (2051.4) -> 2046.1 (2051.7) MB, 4324.1 / 0.0 ms  (average mu = 0.043, current mu = 0.001) allocation failure scavenge might not succeed

<--- JS stacktrace --->

==== JS stack trace =========================================

    0: ExitFrame [pc: 0x10092fbd9]
Security context: 0x1878d33c08a1 <JSObject>
    1: normalizeFilter(aka normalizeFilter) [0x1878fd5ce119] [/Users/Paul/.node-red/node_modules/readdirp/index.js:~32] [pc=0x1348d5419f09](this=0x1878b55004a9 <undefined>,0x18781be990a1 <JSArray[524288]>)
    2: new ReaddirpStream [0x1878933d1e71] [/Users/Paul/.node-red/node_modules/readdirp/index.js:89] [bytecode=0x187846ed6991 offset=164](this=0x1878ae5c0171...

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

Failed to open Node.js report file: report.20200113.172507.26918.0.001.json (errno: 13)
 1: 0x10007e743 node::Abort() [/usr/local/bin/node]
 2: 0x10007e8c7 node::OnFatalError(char const*, char const*) [/usr/local/bin/node]
 3: 0x100176267 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
 4: 0x100176203 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
 5: 0x1002fa2b5 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/usr/local/bin/node]
 6: 0x1002fb984 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [/usr/local/bin/node]
 7: 0x1002f8857 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/local/bin/node]
 8: 0x1002f683d v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/local/bin/node]
 9: 0x100301f54 v8::internal::Heap::AllocateRawWithLightRetry(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [/usr/local/bin/node]
10: 0x100301fcf v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [/usr/local/bin/node]
11: 0x1002cd9a9 v8::internal::Factory::NewFixedArrayWithFiller(v8::internal::RootIndex, int, v8::internal::Object, v8::internal::AllocationType) [/usr/local/bin/node]
12: 0x1004380da v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedObjectElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)2> >::ConvertElementsWithCapacity(v8::internal::Handle<v8::internal::JSObject>, v8::internal::Handle<v8::internal::FixedArrayBase>, v8::internal::ElementsKind, unsigned int, unsigned int, unsigned int) [/usr/local/bin/node]
13: 0x1004368a6 v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedObjectElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)2> >::GrowCapacity(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/usr/local/bin/node]
14: 0x1005d1cf4 v8::internal::Runtime_GrowArrayElements(int, unsigned long*, v8::internal::Isolate*) [/usr/local/bin/node]
15: 0x10092fbd9 Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_NoBuiltinExit [/usr/local/bin/node]
Abort trap: 6

[juggledad]

What is the significance of Show Hidden Files in this though? Also the previous version doesn't suffer from the problem as far as I can tell.

The previous version wasn't looking at the folders correctly. Now it is iterating thru folders to look for the files and it is looking thru all the hidden folders too.

[TotallyInformation]

OK, good call. Definitely only happening with the hidden files option turned on.

Without that, I can run it loads of times very quickly with no issues. RSS does go up slowly but the heap goes up and down as expected.

[colinl]

It isn't iterating through ../ is it?

[TotallyInformation]

It shouldn't be because you've got it set to files only.

[fs:18:28:48] root: \, options:  {
  type: 'files',
  depth: 0,
  fileFilter: [ 'fred', '.fred' ],
  directoryFilter: [ '*', '.*' ]
}

But it is hard to know since readdirp is so complex internally. No, just tested it with an existing folder name and it doesn't fine it.

[TotallyInformation]

OK, found the issue!

Inside the node.on('input', function(msg, send, done) { ... } function we there were a bunch of replace functions on the node object.

They didn't need to be inside there and should be outside the input function. That's where I've moved them to and it makes a MASSIVE difference!

Gotta run for tea right now. I'll try to get a new version out tonight if I can but I've a few things to do so I might have to wait for a day or so.

[TotallyInformation]

Fixed in v1.3.1 - thanks for your help and support.