Allocation failure scavenge might not succeed

[fishcharlie]

• Node.js Version: v10.16.0
• OS: macOS 10.15.2 (19C57)
• Scope (install, code, runtime, meta, other?): Runtime/Code
• Module (and version) (if relevant): Unsure

I'm getting a crash on Node.js. It took a while to get to this crash, and the error is not very descriptive about what is going on here.

What I also find weird, is below in the logs, towards the end it was only printing odd indexes. 20100688 was the last even number that was printed in the indexes. So I'm not sure if one of those child processes failed or what happened. It didn't actually run the .on("close" method until the very end tho, which is weird.

Any ideas of what is going on here?

Command Ran

node index.js 2

index.js

const StellarHDWallet = require("stellar-hd-wallet");
const { spawn } = require("child_process");

const mnemonic = StellarHDWallet.generateMnemonic();
const wallet = StellarHDWallet.fromMnemonic(mnemonic);

const args = [...process.argv].slice(2);
const runNumber = parseInt(args[0]);
let items = [];

console.log(mnemonic);

for (let i = 0; i < runNumber; i++) {
	const item = spawn("node", ["process.js", mnemonic.split(" ").join("-"), runNumber, i]);

	item.stdout.on("data", (data) => {
		console.log(data.toString().trim());
	});

	item.on("close", (code) => {
		console.log(`${i} closed`);
		items.forEach((a) => a.kill());
	});

	items.push(item);
}

process.js

const StellarHDWallet = require("stellar-hd-wallet");

const args = [...process.argv].slice(2);
const mnemonic = args[0].split("-").join(" ");

const wallet = StellarHDWallet.fromMnemonic(mnemonic);

const runNumber = parseInt(args[2]);
const runTimes = parseInt(args[1]);
let done = false;
let index = runNumber;
while (!done) {
	const val = wallet.getPublicKey(index);
	const bLetter = val[1];
	if (val.startsWith(`G${bLetter}ABCDE`)) { // Changed ABCDE from something else
		done = true;
		console.log(val, index);
	}
	console.log(index);
	if (index >= 2147483647) {
		console.log("Ran out.");
		return;
	}
	index += runTimes;
}

Latest Logs

20100676
20111355
20100678
20100680
20111357
20100682
20100684
20100686
20111359
20100688
20111361
20111363
20111365

...

20112965
20112967
20112969
20112971
20112973
20112975
20112977
20112979
20112981
20112983
20112985
20112987
20112989
20112991
20112993
20112995
20112997
20112999
20113001
20113003
20113005
20113007
20113009
20113011
20113013
20113015
20113017
20113019
20113021
20113023
20113025
20113027
20113029
20113031
20113033
20113035
20113037
20113039
20113041
20113043
20113045
20113047
20113049
20113051
20113053
20113055
20113057
20113059
<--- Last few GCs --->

[25406:0x102802000]  2772590 ms: Mark-sweep 1394.2 (1429.2) -> 1390.3 (1429.2) MB, 1812.1 / 0.0 ms  (average mu = 0.115, current mu = 0.048) allocation failure scavenge might not succeed
[25406:0x102802000]  2774476 ms: Mark-sweep 1394.2 (1429.2) -> 1390.3 (1429.2) MB, 1771.6 / 0.0 ms  (average mu = 0.088, current mu = 0.061) allocation failure scavenge might not succeed


<--- JS stacktrace --->

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

    0: ExitFrame [pc: 0x224ba25be3d]
    1: StubFrame [pc: 0x224ba260c95]
Security context: 0x201dbac1e6e9 <JSObject>
    2: toLowerCase [0x201dbac108c1](this=0x201ddfd12c29 <String[6]: sha512>)
    3: createHmac(aka createHmac) [0x201ddfd19d91] [/Users/charliefish/tmp/node_modules/create-hmac/browser.js:54] [bytecode=0x201d6237d871 offset=7](this=0x201d138826f1 <undefined>,alg=0x201ddfd12c29 <String[6]: sha512>,key=0x201d59675379 <String...
0 closed
1 closed

[Hakerh400]

I'm getting a crash on Node.js. It took a while to get to this crash, and the error is not very descriptive about what is going on here.

You get a crash because console.log is asynchronous and should not be used in a long while loop (see nodejs/node#23729 for details and alternative synchronous methods). The error is not descriptive, because it is a generic out-of-memory error reported by V8 engine. There is no way for Node.js to detect at runtime what exactly caused the error.

What I also find weird, is below in the logs, towards the end it was only printing odd indexes.

That is expected. When you spawn two processes, one prints odd and the other prints even numbers. Their stdouts interleave and you see that in the log. When one process dies (due to out-of-memory error), it prints the error to its stderr stream. However, it may be delayed several millisecond and in the meantime the other process keeps printing to its stdout, so you see odd numbers between these two events.

Any ideas of what is going on here?

As explained, console.log (and also process.stdout.write which is internally used by console.log) is asynchronous. You should use this instead

require('fs').writeSync(process.stdout.fd, val + ' ' + index + '\n');

[addaleax]

Any ideas of what is going on here?

As explained, console.log (and also process.stdout.write whis is internally used by console.log) is asynchronous. You should use this instead

require('fs').writeSync(process.stdout.fd, val + ' ' + index + '\n');

I would disagree here – one, this doesn’t properly work on Windows, and two, it’s better to write code so that it handles backpressure correctly.

Additionally, this problem should be far less impactful from Node.js v13.3.0 upwards.

[Hakerh400]

this doesn’t properly work on Windows

I'm not really sure what you mean by this... It works fine on all machines I tested, from windows 7 to windows 10 with all versions of Node.js from v8.x to the current master.
Edit: If you mean that ASCII color codes are broken - that's true, but here it is irrelevant.

it’s better to write code so that it handles backpressure correctly.

Sure, in a production code I would suggest using either an async function, or callbacks on process.stdout.write

[fishcharlie]

Would changing it to the following work (since making it async won't act in a blocking way and allow things to be deallocated)?

function loop() {
	const val = wallet.getPublicKey(index);
	const bLetter = val[1];
	if (val.startsWith(`G${bLetter}ABCDE`)) { // Changed ABCDE from something else
		done = true;
		console.log(val, index);
	}
	console.log(index);
	if (index >= 2147483647) {
		console.log("Ran out.");
		return;
	}
	index += runTimes;

	if (!done) {
		setImmediate(loop)
	}
}

[Hakerh400]

Would changing it to the following work

Yes, that should work fine. If you still experience crash with the new code, you probably have some other memory leak in your application or in dependencies.

Note that after PR nodejs/node#30710 (released in v13.3.0), even with the sync usage of console.log it is much harder for memory leak to appear (still possible, but less probably).

[addaleax]

Would changing it to the following work

setImmediate() would not be enough to guarantee that writes to stdout have finished, but it would solve any problems coming from the console.log() implementation itself.

[addaleax]

One approach that would be “correct” in a sense would be to use process.stdout.write(...) instead of console.log(), see if it returns false during the loop, and if it does, then delay the next call of loop() with process.stdout.on('drain', loop) rather than setImmediate().

[gireeshpunathil]

closing as answered, pls reopen if there is anything outstanding.