Idiomatic Streams usage with Promises causes memory leaks

[scheibo]

From https://github.com/Zarel/Pokemon-Showdown/pull/5370#discussion_r270618747

[20:29:07] @Slayer95: pre, fixed the memory leak by doing await new Promise(resolve => {setImmediate(resolve)}) every N games run
[20:30:14] @Slayer95: as it turns out, there is not a single setImmediate in the BattleStream implementation, so it's in fact a sync stream
[20:30:50] @Slayer95: now, exactly how that impacts the GC logic isn't very clear
[20:30:56] @pre: i think thats a `BattleStream` or `Steams` issue then?
[20:31:01] @pre: but thanks for figuring that out
[20:31:15] @Slayer95: there are very few articles discussing memory leaks from looping async
[20:31:19] @pre: i was literally just commenting on your callback implementation from yesterday
[20:31:42] @Slayer95: yes, a fix in BattleStream / Streams should be feasible

[Zarel]

Streams are supposed to be either sync or async depending on which you prefer.

Also, in theory the async keyword compiles to the equivalent of a setImmediate.

[Zarel]

Also: BattleStreams are designed to be sync.

[scheibo]

So this should be closed as WAI? And users should just use setImmediate as needed? Perhaps we should add that guidance to STREAMS.md?

[Zarel]

Well, if it leads to a memory leak under normal usage, clearly something needs to be fixed. We should just figure out why.

[Zarel]

It's unclear to me why using a sync stream would cause a memory leak. Do you have details?

[Slayer95]

Also, in theory the async keyword compiles to the equivalent of a setImmediate.

Not really.

await x();
y();

is mostly equivalent to

x(() => process.nextTick(y));

But ofc, nextTick() doesn't schedule y for the next tick, but for the current tick.

[Slayer95]

When running this excerpt from #5370

        while ((format = this.getNextFormat())) {
            const seed = this.prng.seed;
            lastFormat = format;
            await new Runner(Object.assign({format}, this.options)).run().catch(err => {
                failures++;
                console.error(
                    `Run \`node dev-tools/harness 1 --format=${format} --seed=${seed.join()}\` ` +
                    `to debug (optionally with \`--output\` and/or \`--input\` for more info):\n`, err);
            });
        }

The heap accumulates Promise and TickObject instances, which aren't collected even when calling gc() (with --expose-gc flag). Those magically go away by await-ing for a setImmediate() call.

Now!!! Last night I was speculating that this may be an engine regression, since V8 has put some work in optimizing promise ticks in recent versions.... And... That's indeed the case !

https://gist.github.com/Slayer95/6456a5d29ca17935d62d301f4a76d389

Test case leaks in Node v10.15.3, but it doesn't in v8.15.1 !

PS. Reproduced in v11.13.0, v12.0.0-nightly20190331bb98f27181, and v12.0.0-v8-canary201903313c649ecee6

[Zarel]

Looks like you should report a V8 bug, and I should file this away as "not my fault". ;)

Feel free to work around with the setImmediate await.

[Slayer95]

Narrowed down to this code. Only the deepCloneSync() variant leaks memory. The alternative deepClone.* functions don't.

However, I think the harness code isn't using Promise.race() right... As a matter of fact, changing runGame() to this doesn't leak at all.

async function runGame(logOutput) {
    let chunk;
    while ((chunk = await MY_STREAM.read()))) {
        if (logOutput) console.log(chunk);
    }
}

[Slayer95]

Filed https://bugs.chromium.org/p/v8/issues/detail?id=9069