Skip to content

Looping async functions with Promise.race() allocates excessive memory #29385

Closed
Closed
Looping async functions with Promise.race() allocates excessive memory#29385
Labels
confirmed-bugIssues and PRs for confirmed bugs.promisesIssues and PRs related to ECMAScript promises.v8 engineIssues and PRs related to the V8 dependency.

Description

@Slayer95
Slayer95
opened on Aug 31, 2019
  • Version: v10.15.3, node 12.0.0-nightly20190331bb98f27181, node 12.0.0-v8-canary201903313c649ecee6, v13.0.0-nightly20190822775048d54c
  • Platform: Ubuntu 14.04.5 LTS, Trusty Tahr x64 / Win7x64,
  • Subsystem:

Test case: https://gist.github.com/Slayer95/1aed510b091dbacacbb3d4e61704a1a8

What steps will reproduce the problem?

  1. Run the test case.
  2. Watch the memory consumption. Increase total run time with the constant SUITE_SIZE

What is the expected output?
Memory consumption is kept constant.

What do you see instead?
An increasingly high memory consumption over time, and the process crashes for OOM.

Supporting info:

  • Memory consumption was constant under Node 8.15.1
  • Switching the deepCloneSync() function for any of its commented-out variants removes the leak.
  • Awaiting for a setImmediate() to resolve every nth "game" is run suppresses the leak.

Originally reported as https://bugs.chromium.org/p/v8/issues/detail?id=9069

/cc @MayaLekova

Activity

  1. bnoordhuis
    added
    confirmed-bugIssues and PRs for confirmed bugs.
    promisesIssues and PRs related to ECMAScript promises.
    v8 engineIssues and PRs related to the V8 dependency.
    on Aug 31, 2019

  2. bnoordhuis commented on Aug 31, 2019

    @bnoordhuis
    bnoordhuis
    on Aug 31, 2019
    Member

    I took a look and I can't really find anything inside Node.js that seems to be at fault. I'm inclined to say this is a V8 issue after all, probably in the way its Promise.race() implementation retains references to the subordinate promises.

    If I change your test case like below it runs in constant time and memory. Tweaking logOutput confirms it's still behaving the same as before.

    --- tmp/bug29385.orig.js        2019-08-31 13:02:36.000000000 +0200
+++ tmp/bug29385.js     2019-08-31 13:10:41.000000000 +0200
@@ -5,7 +5,7 @@
 const RESULT_OBJECT = new Array(128).fill(0).map(x => ~~(Math.random() * 128));
 
 const STREAM_LENGTH = 10;
-const SUITE_SIZE = 10000;
+const SUITE_SIZE = 1e5;
 
 function deepCloneInner(obj) {
        /* Some heavy sync operation */
@@ -77,12 +77,22 @@
        },
 };
 
+function race(a, b) {
+       return new Promise(r => {
+               const k = x => {
+                       if (r) r(x);
+                       r = null;
+               };
+               a.then(k);
+               b.then(k);
+       });
+}
+
 async function runGame(logOutput) {
        let chunk;
        let x = Promise.resolve();
 
-       // Changing this to chunk = await MY_STREAM.read() removes the leak.
-       while ((chunk = await Promise.race([MY_STREAM.read(), x]))) {
+       while ((chunk = await race(MY_STREAM.read(), x))) {
                if (logOutput) console.log(chunk);
        }
 }

    I'm reproducing your test case below for posterity.

    Details 
    'use strict';

/* global gc */

const RESULT_OBJECT = new Array(128).fill(0).map(x => ~~(Math.random() * 128));

const STREAM_LENGTH = 10;
const SUITE_SIZE = 10000;

function deepCloneInner(obj) {
	/* Some heavy sync operation */
	if (obj === null || typeof obj !== 'object') return obj;
	if (Array.isArray(obj)) return obj.map(prop => deepCloneInner(prop));
	const clone = Object.create(Object.getPrototypeOf(obj));
	for (const key of Object.keys(obj)) {
		clone[key] = deepCloneInner(obj[key]);
	}
	return clone;
}

function deepCloneSync(obj) {
	return deepCloneInner(obj);
}

async function deepClone(obj) {
	return deepCloneInner(obj);
}

async function deepCloneNextTick(obj) {
	return new Promise((resolve, reject) => {
		process.nextTick(() => resolve(deepCloneInner(obj)));
	});
}

async function deepCloneSetImmediate(obj) {
	return new Promise((resolve, reject) => {
		setImmediate(() => resolve(deepCloneInner(obj)));
	});
}

async function deepCloneAwait(obj) {
	await 'ayuwoki';
	return deepCloneInner(obj);
}

const MY_STREAM = {
	iterations: 0,
	async read() {
		if (++this.iterations % STREAM_LENGTH === 0) {
			return null;
		}

		/*
		 * Using deepCloneSync() causes a leak of Promises in Node 10.15.3 (V8 6.8.275.32-node.51),
		 * but it doesn't leak in Node 8.15.1 (V8 6.2.414.75)
		 *
		 * Leak also confirmed (Increase SUITE_SIZE x10) in:
		 *   node 12.0.0-nightly20190331bb98f27181, v8 7.4.288.13-node.13
		 *   node 12.0.0-v8-canary201903313c649ecee6, v8 7.5.149-node.0
		 *   
		 */
		return deepCloneSync(RESULT_OBJECT);
		// return deepClone(RESULT_OBJECT);
		// return deepCloneNextTick(RESULT_OBJECT);
		// return deepCloneSetImmediate(RESULT_OBJECT);
		// return deepCloneAwait(RESULT_OBJECT);
	},
};

const ENV = {
	iterations: 0,
	getNextGameParameters() {
		if (++this.iterations % SUITE_SIZE === 0) {
			return null;
		}
		return this.iterations % 2 ? 'arg1' : 'arg2';
	},
};

async function runGame(logOutput) {
	let chunk;
	let x = Promise.resolve();

	// Changing this to chunk = await MY_STREAM.read() removes the leak.
	while ((chunk = await Promise.race([MY_STREAM.read(), x]))) {
		if (logOutput) console.log(chunk);
	}
}

async function runSuite() {
	let parameters;
	let iterations = 0;
	while ((parameters = ENV.getNextGameParameters())) {
		await runGame().catch(err => {
			console.error(`Error for parameters ${parameters}\n${err.stack}`);
		});

		// Uncommenting fixes the leak (Node.js only)
		/*
		if (iterations++ % 50 === 0) {
			await new Promise(resolve => setImmediate(resolve));
		}
		//*/
	}
}

(async () => {
	await runSuite();
})();

  3. MayaLekova commented on Sep 2, 2019

    @MayaLekova
    MayaLekova
    on Sep 2, 2019
    Contributor

    Running the test in V8's simple REPL, d8 doesn't show any growth in memory, see details in the V8 issue. That's why I suspected it has to do with something Node.js specific.

  4. bnoordhuis commented on Sep 2, 2019

    @bnoordhuis
    bnoordhuis
    on Sep 2, 2019
    Member

    @MayaLekova That was my hunch too. Specifically: async_hooks - but those aren't enabled when this test runs and that also wouldn't explain why my ersatz Promise.race() doesn't exhibit the same behavior.

    We're at V8 7.7.299.8-node.12. Have there been upstream changes that might have fixed this? Any other suggestions I could try out?

  5. MayaLekova commented on Sep 2, 2019

    @MayaLekova
    MayaLekova
    on Sep 2, 2019
    Contributor

    About the upstream changes - not that I know of, sorry. Does enabling async hooks change anything?

    About suggestions - not clear ones, but I'm thinking if there's any difference between how d8 handles the microtask queue vs. how it's embedded in Node.js. For instance I know that d8's setImmediate implementation is a dummy one, so there might be something in the actual implementation related to the cause of the leak (why does it supress it?).

  6. bnoordhuis commented on Sep 2, 2019

    @bnoordhuis
    bnoordhuis
    on Sep 2, 2019
    Member

    Enabling async_hooks slows it down by about a factor of 5 but doesn't otherwise impact behavior.

    FWIW, when I use a race() that's a bit more faithful to (my reading of) the Promise.race() spec, I see the same memory consumption as with the built-in Promise.race():

    function race(promises) {
  return new Promise((resolve, reject) => {
    for (const p of promises) p.then(resolve, reject);
  });
}

    I checked the other day whether manually flushing the microtask queue makes any difference but it doesn't. If you want to try for yourself, start node with --expose-internals and add this code:

    const {internalBinding} = require('internal/test/binding');
const {runMicrotasks} = internalBinding('task_queue');
runMicrotasks();  // takes no arguments

  7. MayaLekova commented on Sep 2, 2019

    @MayaLekova
    MayaLekova
    on Sep 2, 2019
    Contributor

    Not sure whether it's really important, but I've tried runMicrotasks() each 50 iterations (as suggested), as well as await new Promise(resolve => queueMicrotask(resolve)) - both don't remove the leak. So it looks like the difference between queueMicrotask and setImmediate/setTimeout(0) is what's causing it. Will experiment further, thanks for the extra info!

  8. thaaddeus commented on Nov 6, 2019

    @thaaddeus
    thaaddeus
    on Nov 6, 2019

    Hi, I've also stumbled on this issue. I wonder, does anyone knows user space workaround that would prevent leaks, like custom impl of race function? Or they only way to make Promise.race usable is to have that fixed in Node.js source? Thanks!

  9. thaaddeus commented on Nov 26, 2019

    @thaaddeus
    thaaddeus
    on Nov 26, 2019

    Is seems like it works fine in v13, was that V8 thing after all?

  10. Slayer95 commented on Nov 26, 2019

    @Slayer95
    Slayer95
    on Nov 26, 2019
    ContributorAuthor

    @tardis, reproduced with node-v13.2.0-win-x64. Are you running a different test case or environment?

  11. thaaddeus commented on Nov 26, 2019

    @thaaddeus
    thaaddeus
    on Nov 26, 2019

    Hmm, indeed I was running different test case, reverted back to v12.13.1 and it also seems to be working fine - GC is keeping up, must be something with my code then. Sorry for confusion.

  12. jasnell commented on Nov 27, 2019

    @jasnell
    jasnell
    on Nov 27, 2019
    Member

    Digging in on this a bit... in the original code, if you increase the number of iterations to 100 and run it through the clinicjs.org clinic doctor tool, you'll see that clinic gives you a data analysis error, looking at the underlying trace event file that is collected by clinic, you'll find that the code is getting stuck when running the microtaskqueue. This is caused by the creation of a large number of orphaned Promises in a tight sync loop. If you take a heap snapshot, you'll see that the Promises are being retained by queueMicrotask. I believe the workarounds that have been identified are working only because they end up giving the garbage collector a chance to catch up. If you increase the number of iterations, the workarounds don't appear to work and you'll end up with a memory error being thrown.

    image

    For d8, it would be interesting to increase the number of iterations to see if the problem occurs there as well. If it doesn't, then it would appear that there is definitely something a bit wonky about the way Node.js is handling the microtaskqueue ... however, just in general I would say that this is yet another reason to avoid using Promise.race(), especially with synchronous loops.

  13. jasnell commented on Nov 27, 2019

    @jasnell
    jasnell
    on Nov 27, 2019
    Member

    Bit more analysis... with the original code, after enabling trace event tracking using clinic bubble and reducing the number of iterations to 5... running grep -o '\"PROMISE"\B' 8552.clinic-bubbleprof-traceevent | wc -l returns 579948.

  14. jasnell commented on Jun 19, 2020

    @jasnell
    jasnell
    on Jun 19, 2020
    Member

    I don't believe there's anything actionable for Node.js in this issue. Closing. Can reopen if new information is received that does point to anything we can do in Node.js

  15. jasnell
    closed this as completedon Jun 19, 2020
  16. thaaddeus
    added a commit that references this issue on Jul 3, 2020

    fix: get rid of Promise.race in combine function as in some edge case…

    f6d1b99

  17. cefn commented on Jan 17, 2024

    @cefn
    cefn
    on Jan 17, 2024

    It looks like this was a more complex variant of the simpler repro at #51452 which still exists in Node (and apparently not in V8).

  18. chamojtrles32165
    added a commit that references this issue on Oct 6, 2025

    fix: get rid of Promise.race in combine function as in some edge case…

    f05d85b
  19. rollup-hacker56n
    added a commit that references this issue on Oct 20, 2025

    fix: get rid of Promise.race in combine function as in some edge case…

    8c411b1
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    confirmed-bugIssues and PRs for confirmed bugs.promisesIssues and PRs related to ECMAScript promises.v8 engineIssues and PRs related to the V8 dependency.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions