Random crashes with "Maximum call stack size exceeded"

Node-RED randomly crashes after 5-20 mins with the error:

4 Sep 13:20:29 - [red] Uncaught Exception:
4 Sep 13:20:29 - RangeError: Maximum call stack size exceeded
    at Function.[Symbol.hasInstance] (<anonymous>)
    at ReadStream (/home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js:194:14)

I've looked at other threads discussing the "Maximum call stack size exceeded" error, but haven't been able to find anything relevant for my case (e.g. I don't have any nodes looping back, and I don't send huge volumes of messages at any point). How can I go about pinning down which node/message it is that's causing this?

I’d say step one is figuring out what causes graceful-fs to do this, which is through figuring out which node/library uses it. Go to the node-red folder and try the command npm ls graceful-fs This should show you a dependency tree. When you find out which thing(s) depend on it, try looking into those to see how it connects to your flow.

Someone raised an issue against uibuilder that had this error recently. It went away when uibuilder was updated to the current version.

The problem with graceful-fs is that it is embedded in lots of places, especially in fs-extra which is itself used in various places including the Node-RED core and uibuilder.

To track down this problem, it will take someone putting a manual change into their installed version of graceful-fs to trigger a stack dump so that we can see the call chain and work back up the chain until we find the culprit.

Could you also, from the command line, do:

cd ~/.node-red
npm ls graceful-fs

to find out what version(s) are in use?

1 Like

Thanks guys, graceful-fs is indeed required by several modules in my project:

~/.node-red $ npm ls graceful-fs
node-red-project@0.0.1 /home/nodered/.node-red
β”œβ”€β”¬ node-gyp@5.0.3 (git+https://github.com/nodejs/node-gyp.git#0a4d8c84ce924c003aa9aaf135cc1a99333ac647)
β”‚ └── graceful-fs@4.1.15 
β”œβ”€β”¬ node-red-contrib-camerapi@0.0.38
β”‚ └─┬ fs-extra@7.0.1
β”‚   β”œβ”€β”€ graceful-fs@4.1.15  deduped
β”‚   └─┬ jsonfile@4.0.0
β”‚     └── graceful-fs@4.1.15  deduped
β”œβ”€β”¬ node-red-contrib-npm@1.0.0 (git+https://github.com/clickworkorange/node-red-contrib-npm.git#5d62d5fcff239490f3d33f18a30211bdb03700ff)
β”‚ └─┬ npm@6.11.2
β”‚   β”œβ”€β”¬ bin-links@1.1.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ cacache@12.0.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ cmd-shim@3.0.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ fs-vacuum@1.2.10
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ fs-write-stream-atomic@1.0.10
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ gentle-fs@2.2.1
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”€ graceful-fs@4.2.2 
β”‚   β”œβ”€β”¬ libcipm@4.0.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ node-gyp@5.0.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ npm-lifecycle@3.1.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ read-cmd-shim@1.0.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ read-installed@4.0.3
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ read-package-json@2.1.0
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ readdir-scoped-modules@1.1.0
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ sha@3.0.0
β”‚   β”‚ └── graceful-fs@4.2.2  deduped
β”‚   β”œβ”€β”¬ update-notifier@2.5.0
β”‚   β”‚ └─┬ configstore@3.1.2
β”‚   β”‚   └── graceful-fs@4.2.2  deduped
β”‚   └─┬ write-file-atomic@2.4.3
β”‚     └── graceful-fs@4.2.2  deduped
└─┬ npm-lifecycle@2.1.0 (git+https://github.com/clickworkorange/npm-lifecycle.git#759441ffcdea279cf308d1758513262ee515cb2b)
  β”œβ”€β”€ graceful-fs@4.1.15  deduped
  └─┬ node-gyp@4.0.0
    └── graceful-fs@4.1.15  deduped

How do I add stack trace output to graceful-fs? I assume this should go in /home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js? The relevant lines in there (line 194 is where it blows up) are:

193  function ReadStream (path, options) {
194    if (this instanceof ReadStream)
195      return fs$ReadStream.apply(this, arguments), this
196    else
197      return ReadStream.apply(Object.create(ReadStream.prototype), arguments)
198  }

Interesting. Looks like the npm node is a common factor here.

I would put the following statement after line 193:

console.trace('TRACING GRACEFUL-FS')

You will get a call trace output to the Node-RED log.

If that produces too many traces, wrap the whole if statement in a try and put the trace in the catch part. But do use console.trace as this shows you the full call trace.

I notice that there are two different versions of graceful-fs 4.1.15, 4.2.2 - the 4.2.2 version was released 22 days ago...

Indeed. The project claims that updates are deliberately slow because it is so heavily embedded in other projects (like fs-extra which is itself used very extensively, including by Node-RED core and uibuilder). You can do npm -g ls graceful-fs to see the dependency chain for Node-RED itself.

Only one person out of all the people using uibuilder reported a problem and the only common factor I can see at the moment is having the npm node installed.

The trace should show us however the actual failing call chain so we can properly attribute the issue.

Thanks guys - I also suspect the npm node; it's a pretty complex beast with its fingers deep in the pie. The reason it took so long for me to reply was I suddenly could not get Node-RED to crash - this was probably due to some quantum mechanical effect, simply becasue I was looking at it. Of course as soon as I forgot about having inserted that trace, and stopped watching the tail, it went boom and spit out a 75Mb syslog :slight_smile: It looks like this:

Sep  6 08:57:54 sentry Node-RED[25175]: CameraPi (log): Tempfile - /home/nodered/pic_93db66eb-eb5e-4e91-82a1-e7636a0ff7cd.jpg
Sep  6 08:57:57 sentry Node-RED[25175]: CameraPi (log): /home/nodered/pic_93db66eb-eb5e-4e91-82a1-e7636a0ff7cd.jpg remove success!
Sep  6 08:58:05 sentry Node-RED[25175]: [object Object]
Sep  6 08:58:05 sentry Node-RED[25175]: at new ReadStream (/home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js:194:13)
Sep  6 08:58:05 sentry Node-RED[25175]: at Object.createReadStream (/home/nodered/.node-red/node_modules/npm/node_modules/graceful-fs/graceful-fs.js:302:12)
Sep  6 08:58:05 sentry Node-RED[25175]: at SendStream.stream (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:797:19)
Sep  6 08:58:05 sentry Node-RED[25175]: at SendStream.send (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:708:8)
Sep  6 08:58:05 sentry Node-RED[25175]: at onstat (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:730:10)
Sep  6 08:58:05 sentry Node-RED[25175]: at callback (/home/nodered/.node-red/node_modules/npm/node_modules/graceful-fs/polyfills.js:295:20)
Sep  6 08:58:05 sentry Node-RED[25175]: at FSReqWrap.oncomplete (fs.js:154:5)
Sep  6 08:58:05 sentry Node-RED[25175]: [object Object]
Sep  6 08:58:05 sentry Node-RED[25175]: at ReadStream (/home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js:194:13)
Sep  6 08:58:05 sentry Node-RED[25175]: at new ReadStream (/home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js:196:28)
Sep  6 08:58:05 sentry Node-RED[25175]: at Object.createReadStream (/home/nodered/.node-red/node_modules/npm/node_modules/graceful-fs/graceful-fs.js:302:12)
Sep  6 08:58:05 sentry Node-RED[25175]: at SendStream.stream (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:797:19)
Sep  6 08:58:05 sentry Node-RED[25175]: at SendStream.send (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:708:8)
Sep  6 08:58:05 sentry Node-RED[25175]: at onstat (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:730:10)
Sep  6 08:58:05 sentry Node-RED[25175]: at callback (/home/nodered/.node-red/node_modules/npm/node_modules/graceful-fs/polyfills.js:295:20)

And on, and on, and on it goes, seventy five megabytes of it :smiley: This particular crash is preceded by CameraPI taking a picture, but I think that's just coincidence; a full eight seconds pass between it having done it's thing and Graceful-FS crashing. So I'm not sure I'm any wiser.

Edit: Then finally, 207,716 lines later, it goes:

Sep  6 08:59:14 sentry Node-RED[25175]: 6 Sep 08:58:52 - [red] Uncaught Exception:
Sep  6 08:59:14 sentry Node-RED[25175]: 6 Sep 08:58:52 - RangeError: Maximum call stack size exceeded
Sep  6 08:59:14 sentry Node-RED[25175]: at Array.join (native)
Sep  6 08:59:14 sentry Node-RED[25175]: at Function.prepareStackTrace (/home/nodered/.node-red/node_modules/source-map-support/source-map-support.js:396:6)
Sep  6 08:59:14 sentry Node-RED[25175]: at Console.trace (console.js:274:18)
Sep  6 08:59:14 sentry Node-RED[25175]: at ReadStream (/home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js:194:13)

Edit 2: Digging deeper, I do indeed find mention of the npm node:

Sep  6 08:58:05 sentry Node-RED[25175]: at new ReadStream (/home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js:196:28)
Sep  6 08:58:05 sentry Node-RED[25175]: at Object.createReadStream (/home/nodered/.node-red/node_modules/npm/node_modules/graceful-fs/graceful-fs.js:302:12)
Sep  6 08:58:05 sentry Node-RED[25175]: at SendStream.stream (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:797:19)
Sep  6 08:58:05 sentry Node-RED[25175]: at SendStream.send (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:708:8)
Sep  6 08:58:05 sentry Node-RED[25175]: at onstat (/usr/local/lib/node_modules/node-red/node_modules/send/index.js:730:10)
Sep  6 08:58:05 sentry Node-RED[25175]: [object Object]
Sep  6 08:58:05 sentry Node-RED[25175]: at ReadStream (/home/nodered/.node-red/node_modules/graceful-fs/graceful-fs.js:194:13)

Edit 3: I see now that the npm node is also mentioned at the start of the trace. I only use this node to include the nmea-0183 NodeJS module, for decoding NMEA0183 sentences - I might just copy paste it's code into a Node-RED function node instead. Always annoyed me that the npm node insists on re-installing the nmea-0183 module on every restart of Node-RED.

Either that or do it the "old" way. Install it manually, then require it to a globals variable in settings.js and then global.get it in your function node.

If you don't want to hit the server's command line for the install, you could even misuse uibuilder's npm interface to install the package. Though you will end up with the packages installation folder being statically served - shouldn't have any real impact though.

1 Like

Ah. I'm not familiar with this "old" way, but that sounds like a good option; the nmea-0183 module is fairly large & complex, so not a good fit for putting in a function node - much better to link it in the way you suggest. I'm on the server's command line all the time so manuall installation is fine. Haven't tried uibuilder yet - in fact I only recently became aware of it, but I think I've reached the limit of what can be done with node-red-dashboard and I'm building up to make the switch.

Just ignore that comment if you are happy with the command line.

If you are feeling adventurous, you could always build the nmea package into a custom node :mage:

But for now, if you look at the settings.js file in your userDir folder, you will see the globals section with some examples. Just adjust one of the examples for the nmea package and you will be fine.

In settings.json

    functionGlobalContext: {
        nmea: require('nmea-0183'),
    },

In your function:

const nmea = global.get('nmea')
...
1 Like

Thank you, this works perfectly - and I no longer have to put up with node-red-contrib-npm reinstalling the nmea-0183 module on every restart of Nore-RED. Win-win-triple-win!

1 Like

Holy **** getting rid of node-red-contrib-npm sure cleared out a truckload of modules. Probably mostly old versions of other ones, but man that thing has some dependencies!

nodered@sentry:~/.node-red $ npm remove node-red-contrib-npm
npm WARN node-red-project@0.0.1 No repository field.
npm WARN node-red-project@0.0.1 No license field.

removed 434 packages and audited 997 packages in 51.929s
found 0 vulnerabilities

Any way to see a log of what npm just did there?

Edit: Pffffff....

nodered@sentry:~/.node-red/node_modules $ ls -l | grep ^d | wc -l
246
1 Like

I think that it creates a detailed log somewhere but probably the easiest thing to do is to just look at its package.json on github.

It only has 2 direct dependencies:

But one of them is npm itself which is enormous!

Urgh!

1 Like

Ah yes, and I'm on npm 6.4.1, which IIRC was what Raspbian repo provided. So node-red-contrib-npm had an entire (newer) copy of npm for itself? That might explain the crashes...

More accurate to do:

npm ls | sed '/deduped$/d' | wc -l

from the right folder.

nodered@sentry:~/.node-red/node_modules $ npm ls | sed '/deduped$/d' | wc -l
314

No comprendo. Manually copy/pasting the output to a texteditor gives 248 lines (not including .. and .). Mind you one item is a symlink to my own copy of node-red-nodes . But why the discrepancy?

Edit: The discrepancy of course comes from npm ls showing every installed module and ls -l in .node-red/node_modules dir only those local to Node-RED.

The npm ls command lists everything including duplicates, the sed command removes the dups. In the node_modules folder, there are also some sub-folders that aren't packages.

npm ls shows every module installed; I was just looking at the top level. Should have done this before & after the uninstall, just for a laugh. Or even just a df. This is running on a Pi after all, and every resource is precious - it's nice to know I not only solved the crashes but also got rid of a lot of "stuff". Great solution!

1 Like