@refack build started: https://ci.nodejs.org/blue/organizations/jenkins/node-test-pull-request-lite-pipeline/detail/node-test-pull-request-lite-pipeline/550/pipeline

Stress CI: https://ci.nodejs.org/job/node-stress-single-test/1988/nodes=freebsd11-x64/

/ping @nodejs/v8 on "shouldn't setting to undefined cause garbage collection in this situation?" and maybe also the "why does this crash?" As @joyeecheung points out, this shouldn't crash, so something weird is up. Not sure if it's specific to FreeBSD or specific to something we've configured that happens to be on our FreeBSD machines in CI. (Or something else?) See nodejs/reliability#12 for a small bit of context.

I've started another stress test (1989 pending the current one 1988) with master for comparison

/CC @nodejs/testing some low hanging time optimization fruit:

18:21:53 + python tools/test.py -p tap --mode=release 'addons/stringbytes-external-exceed-max/test-stringbytes*'
18:21:54 TAP version 13
18:21:54 1..8
18:22:08 ok 1 addons/stringbytes-external-exceed-max/test-stringbytes-external-at-max
18:22:08   ---
18:22:08   duration_ms: 13.920
18:22:08   ...
18:23:09 ok 2 addons/stringbytes-external-exceed-max/test-stringbytes-external-exceed-max
18:23:09   ---
18:23:09   duration_ms: 60.658
18:23:09   ...
18:23:19 ok 3 addons/stringbytes-external-exceed-max/test-stringbytes-external-exceed-max-by-1-ascii
18:23:19   ---
18:23:19   duration_ms: 10.175
18:23:19   ...
18:23:44 ok 4 addons/stringbytes-external-exceed-max/test-stringbytes-external-exceed-max-by-1-base64
18:23:44   ---
18:23:44   duration_ms: 24.288
18:23:44   ...
18:24:17 ok 5 addons/stringbytes-external-exceed-max/test-stringbytes-external-exceed-max-by-1-binary
18:24:17   ---
18:24:17   duration_ms: 33.149
18:24:17   ...
18:25:06 ok 6 addons/stringbytes-external-exceed-max/test-stringbytes-external-exceed-max-by-1-hex
18:25:06   ---
18:25:06   duration_ms: 49.453
18:25:06   ...
18:25:07 ok 7 addons/stringbytes-external-exceed-max/test-stringbytes-external-exceed-max-by-1-utf8
18:25:07   ---
18:25:07   duration_ms: 0.399
18:25:07   ...
18:25:21 ok 8 addons/stringbytes-external-exceed-max/test-stringbytes-external-exceed-max-by-2
18:25:21   ---
18:25:21   duration_ms: 13.908
18:25:21   ...
18:25:21 + OK=21
18:25:21 + echo '21   OK: 21   NOT OK: 0   TOTAL: 100'
18:25:21 21   OK: 21   NOT OK: 0   TOTAL: 100

@Trott

shouldn't setting to undefined cause garbage collection in this situation?

v8 has a fairly lazy gc by default. setting a variable to undefined clears the reference to the value but the value might not be deleted until the next gc, and even then it might be removed from v8's heap but v8's heap might not shrink. there is a new method in v8 called EnableMemorySavingsMode which might help with this.

why does this crash?

v8 will allocate the second and third strings without deleting the previous ones. as far as i know v8 doesn't track how much memory the system actually has. because of this it has a method called LowMemoryNotification and another one called MemoryPressureNotification which enable the embedder to tell v8 that there isn't any more memory for it to use.

someone actually brought up on irc yesterday this topic about having more control over how node (and by extension v8) is using memory. i'm wondering if maybe we could work on exposing some options around that to applications.

@devsnek ExternString::NewFromCopy is supposed to return an empty maybe when there is not enough memory so that an error can be thrown later, v8 failing to GC the previous strings are not supposed to cause crashes..

By the way I can't seem to reproduce this in a new FreeBSD box, maybe it has something to do with the resource usage on our CI machines and you'd need to hit a certain threshold to get the crash. @refack have you managed to get a core dump?

@joyeecheung i meant that if v8 tries to allocate and hits OOM it will abort. there might also be a callback to catch that. i don't know what it does if it fails to deallocate.

@devsnek The majority of the allocation is not supposed to happen in the V8 heap, since it's an external string...also nodejs/reliability#12 (comment) didn't give us the usual OOM message from V8, it's killed by the system so it's probably caused by some system call hitting the resource limit (whereas if the OOM happens in V8's heap V8 will print that OOM message before aborting). The actual V8 heap is only a few megabytes in https://www.irccloud.com/pastebin/FI3zgCwR/

CI: https://ci.nodejs.org/job/node-test-pull-request/16431/
If it's green, I'm gonna land (since this unbreaks CI)

I've started another stress test (1989 pending the current one 1988) with master for comparison

Stress test against master crashed after 5 repeats:

echo '5   OK: 1   NOT OK: 4   TOTAL: 100'

But I think that is a significant enough result.

👍 here to fast-track.

Resume build: https://ci.nodejs.org/job/node-test-pull-request/16433/

Although it looks like https://ci.nodejs.org/job/node-test-pull-request/16432/ is a Resume Build that's already green so mine is unnecessary. This can land once we get a second fast-track approval. Someone? Anyone?

setting a variable to undefined clears the reference to the value but the value might not be deleted until the next gc, and even then it might be removed from v8's heap but v8's heap might not shrink.

@devsnek - does this mean that (large and complex) applications should explicitly invoke gc() to avoid garbage pileup? that is in direct contradiction with the automatic garbage collection promise. I would assume gc() to abort only after it has cleared up even the last byte of garbage and still cannot allocate the current request.

To me, this looks like a v8 bug.

@ulan @hannespayer I'm also a bit surprised that you need to explicitly call GC to avoid OOM.

@gireeshpunathil

does this mean that (large and complex) applications should explicitly invoke gc() to avoid garbage pileup? ... I would assume gc() to abort only after it has cleared up even the last byte of garbage and still cannot allocate the current request.

that is how v8 behaves (https://github.com/v8/v8/blob/3f0346cdedb230a89dc433ade7e46ac7129ba5e4/src/heap/heap.cc#L4608-L4648)

there was some missing context here... this test allocates external strings, not v8 heap strings, so from what i understand the failure is actually a bug with node, not v8. this fact, of course, plugs into hashseed's comment.

Landed in 4ce744a

Looks like the test is still crashing https://ci.nodejs.org/job/node-test-commit-freebsd/19642/nodes=freebsd11-x64/console

EDIT: that CI was not rebased against this commit

tl;dr: This should be fixed by V8 soon.

V8 relies on embedders calling AdjustAmountOfExternalAllocatedMemory for memory that externally allocated. This is error prone and the API does not follow any growing strategy for allocated memory, making it likely that it is not doing not enough or too many GCs.

We know that this is an issue and there's ongoing work that is about to be landed on master handling types where V8 has more knowledge (externalized strings & array buffers).

Specifically, the external string issue should be fixed as soon as that CL lands.