jsonStringify util regularly causes out of memory crash

[dvtate]

Prerequisites

• Checked that your issue hasn't already been filed by cross-referencing issues with the faq label
• Checked next-gen ES issues and syntax problems by using the same environment and/or transpiler configuration without Mocha to ensure it isn't just a feature that actually isn't supported in the environment in question or a bug in your code.
• 'Smoke tested' the code to be tested by running it outside the real test suite to get a better sense of whether the problem is in the code under test, your usage of Mocha, or Mocha itself
• Ensured that there is no discrepancy between the locally and globally installed versions of Mocha. You can find them with: node node_modules/.bin/mocha --version(Local) and mocha --version(Global). We recommend that you not install Mocha globally.

Description

• We have some objects that have a few reasonably complicated deep/cyclic references.
• Relevant Objects have toJSON methods that remove the cyclic references (in JSON.stringify spec).
• When one of our Chai assertions fails it uses your stringify util function
• The functions in utils.js use the entirety of our systems resources for >30 seconds and the test runner dies with an out of memory error

Steps to Reproduce

• Have a large object (ie: array with multiple THREE.Object3D instances ()
• call jsonStringify or cannonicalize on that object
• RIP ur pc

Expected behavior: [What you expect to happen]

• Prints same output to console.log
• Doesn't crash
• Executes in under 1 second

Actual behavior: [What actually happens]

• CPU throttles for 20+ seconds
• fatal out of memory error

Reproduces how often: [What percentage of the time does it reproduce?]
100% of time with complex objects and even simple objects with deep complex references

Versions

• 8.1.1
• Likely earlier too: utils.canonicalize runs out of memory #3472

Additional Information

Will include some traces below

Reccomendations

Two possible routes:

1. Really should not reinvent builtin functionality since native implementations are more performant and better tested
2. Please follow JSON.stringify spec more closely
   • http://www.ecma-international.org/ecma-262/11.0/index.html#sec-serializejsonproperty
   • http://ecma-international.org/ecma-262/11.0/index.html#sec-json.stringify
   • Noteably when an object has a .toJSON method you should use it

[dvtate]

... 8/22: EditorTest.signalHandlers()
<--- Last few GCs --->
ca[308:0x31c52a0]    79563 ms: Mark-sweep 2047.2 (2051.0) -> 2046.8 (2051.3) MB, 2252.4 / 0.0 ms  (+ 48.8 ms in 8 steps since start of marking, biggest step 21.2 ms, walltime since start of marking 2304 ms) (average mu = 0.116, current mu = 0.001) allocatio[308:0x31c52a0]    81988 ms: Mark-sweep 2047.5 (2051.3) -> 2047.1 (2051.5) MB, 2371.3 / 0.0 ms  (+ 50.2 ms in 10 steps since start of marking, biggest step 19.6 ms, walltime since start of marking 2425 ms) (average mu = 0.058, current mu = 0.002) allocati

<--- JS stacktrace --->

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

    0: ExitFrame [pc: 0x13cce79]
Security context: 0x3c8f619808d1 <JSObject>
    1: jsonStringify(aka jsonStringify) [0x1084e7b9be19] [/opt/caemate/extern/node/node_modules/mocha/lib/utils.js:~218] [pc=0x22206bf84620](this=0x18acd72404b1 <undefined>,0x362b53665b79 <Object map = 0xcb32858e359>,2,21)
    2: _stringify(aka _stringify) [0x354d71006931] [/opt/caemate/extern/node/node_modules/mocha/lib/utils.js:~237] [pc=0x22206bf86d19](this=0x...

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0xa0bb60 node::Abort() [/usr/bin/node_orig]
 2: 0xa0bf6c node::OnFatalError(char const*, char const*) [/usr/bin/node_orig]
 3: 0xb820fe v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/usr/bin/node_orig]
 4: 0xb82479 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/bin/node_orig]
 5: 0xd2ee35  [/usr/bin/node_orig]
 6: 0xd2f4c6 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [/usr/bin/node_orig]
 7: 0xd3bd45 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/bin/node_orig]
 8: 0xd3cbf5 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/bin/node_orig]
 9: 0xd3f6ac v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/usr/bin/node_orig]
10: 0xd0615b v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [/usr/bin/node_orig]
11: 0x1047d9e v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [/usr/bin/node_orig]
12: 0x13cce79  [/usr/bin/node_orig]
Run 22 tests in 87.412 s.
Process finished with exit code 0

---

... 3/3: ModelTest.results() [26.527 s]
FAILURE: should have "getter" and "setter" ------------


<--- Last few GCs --->

[134:0x336a2a0]    49712 ms: Mark-sweep 2044.6 (2056.1) -> 2043.8 (2048.6) MB, 70.9 / 0.0 ms  (+ 285.8 ms in 39 steps since start of marking, biggest step 21.8 ms, walltime since start of marking 378 ms) (average mu = 0.124, current mu = 0.092) finalize i[134:0x336a2a0]    49730 ms: Scavenge 2045.7 (2048.6) -> 2044.3 (2061.1) MB, 7.5 / 0.0 ms  (average mu = 0.124, current mu = 0.092) allocation failure 


<--- JS stacktrace --->

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

    0: ExitFrame [pc: 0x13cce79]
Security context: 0x11d8618c08d1 <JSObject>
    1: escapeFn(aka escapeFn) [0x3785ecd0bf31] [internal/util/inspect.js:~410] [pc=0x284d3143425e](this=0x34425e5c04b1 <undefined>,0x11d8618f3aa9 <String[#1]: \>)
    2: StubFrame [pc: 0x14094bc]
    3: replace [0x11d8618ccc71](this=0x2da965861a59 <Very long string[16313]>,0x3785ecd0bc91 <JSRegExp <String[#19]: [\x00-\x1f\x27\x5c]>>,0x3785ecd0bf31 <JSFunction esc...

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0xa0bb60 node::Abort() [/usr/bin/node_orig]
 2: 0xa0bf6c node::OnFatalError(char const*, char const*) [/usr/bin/node_orig]
 3: 0xb820fe v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/usr/bin/node_orig]
 4: 0xb82479 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/bin/node_orig]
 5: 0xd2ee35  [/usr/bin/node_orig]
 6: 0xd2f4c6 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [/usr/bin/node_orig]
 7: 0xd3bd45 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/bin/node_orig]
 8: 0xd3cbf5 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/bin/node_orig]
 9: 0xd3e29f v8::internal::Heap::HandleGCRequest() [/usr/bin/node_orig]
10: 0xcecd85 v8::internal::StackGuard::HandleInterrupts() [/usr/bin/node_orig]
11: 0x1047a46 v8::internal::Runtime_StackGuard(int, unsigned long*, v8::internal::Isolate*) [/usr/bin/node_orig]
12: 0x13cce79  [/usr/bin/node_orig]
Run 3 tests in 58.685 s.
Process finished with exit code 0

[boneskull]

@dvtate Thanks. We really would need sample code to generate such an object so we can confirm the behavior.

[dvtate]

Ok so we're emulating a webgl environment in headless node unit tests for our 100k+ loc propietary project but I think I can make an simpler example this weekend that can replicate the results

[dvtate]

Ok so I managed to recreate the problem without using company's code. It seems that mocha is trying to print the entirety of each Sprite which can have references to massive texture objects that shouldn't be printed.

In the test I also included console.log (could also use util.inspect) which prints a summary instantly without using an unreasonable amount of memory or CPU

With only 5 labels the test fails very slowly and prints a lot of grabage to the terminal, but doubling the number of labels causes the test to take several minutes and several hundred megs of RAM.

https://github.com/dvtate/browser-mock-test

[dvtate]

I'd recommend:

• Don't try to print every little detail when object is so massive
• Any time you're operating on strings longer than 65kb things are going to be slow, maybe have it return array of strings that can the be printed to reduce number of O(N) + operations?

[boneskull]

thanks for getting that.

the lib we use internally for assertions, unexpected, has a default maximum depth setting. I think adding a feature like that might work.

[boneskull]

this code is not really so easy to work with... not having luck simply patching it, but feel free to take a crack at it to solve this immediate problem. I think this is a dupe of #3675 anyway.

[dvtate]

Yea, fixing #3675 would probably also fix this. Unfortunately I'm busy with work+uni so not a lot of free time currently. The example I made is kinda weird because it's testing something that normally would only be run in browser using node. Right now at work I replaced chai with builtin assert so at least it's not an immediate problem, but would improve readability