Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RAM&speed blocking issue in eval rewriting #4

Closed
SichangHe opened this issue Nov 12, 2024 · 2 comments
Closed

RAM&speed blocking issue in eval rewriting #4

SichangHe opened this issue Nov 12, 2024 · 2 comments

Comments

@SichangHe
Copy link
Owner

Crashed while loading Google Search because of OOM.
$ node tests/browser_w_eval.js
Rewriting JS from https://www.gstatic.com/og/_/js/k=og.asy.en_US.pUEBjE-my4A.2019.O/rt=j/m=_ac,_awd,ada,lldp,qads/exm=/d=1/ed=1/rs=AA2YrTuRS3D-o47aViTwVe7tA6g4fjGbNQ

<--- Last few GCs --->

[25699:0x148008000]    67473 ms: Mark-Compact 4070.1 (4139.0) -> 4070.1 (4139.0) MB, pooled: 0 MB, 5180.83 / 0.00 ms  (average mu = 0.237, current mu = 0.022) allocation failure; scavenge might not succeed
[25699:0x148008000]    75144 ms: Mark-Compact 4078.0 (4139.0) -> 4078.0 (4171.0) MB, pooled: 0 MB, 7660.67 / 0.00 ms  (average mu = 0.108, current mu = 0.001) allocation failure; scavenge might not succeed


<--- JS stacktrace --->

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
----- Native stack trace -----

 1: 0x1052970c8 node::OOMErrorHandler(char const*, v8::OOMDetails const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 2: 0x10543f1f4 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, v8::OOMDetails const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 3: 0x10543f1a8 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, v8::OOMDetails const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 4: 0x1055e5dcc v8::internal::Heap::CallGCPrologueCallbacks(v8::GCType, v8::GCCallbackFlags, v8::internal::GCTracer::Scope::ScopeId) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 5: 0x1055e4c54 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 6: 0x1055db394 v8::internal::HeapAllocator::AllocateRawWithLightRetrySlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 7: 0x1055dbb00 v8::internal::HeapAllocator::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 8: 0x1055c2e74 v8::internal::Factory::NewFillerObject(int, v8::internal::AllocationAlignment, v8::internal::AllocationType, v8::internal::AllocationOrigin) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 9: 0x1058d9f20 v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
10: 0x105085e9c Builtins_WasmCEntry [/opt/homebrew/Cellar/node/22.9.0/bin/node]
11: 0x1050862e4 Builtins_StringAdd_CheckNone [/opt/homebrew/Cellar/node/22.9.0/bin/node]
12: 0x105108018 Builtins_RegExpReplace [/opt/homebrew/Cellar/node/22.9.0/bin/node]
13: 0x105072c58 Builtins_StringPrototypeReplace [/opt/homebrew/Cellar/node/22.9.0/bin/node]
14: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
15: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
16: 0x1050b465c Builtins_ArrayMap [/opt/homebrew/Cellar/node/22.9.0/bin/node]
17: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
18: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
19: 0x1050b6f7c Builtins_ArrayReduceRight [/opt/homebrew/Cellar/node/22.9.0/bin/node]
20: 0x10e10dfb8 
21: 0x10e10cda8 
22: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
23: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
24: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
25: 0x104ff0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
26: 0x10e0210d8 
27: 0x10502d290 Builtins_AsyncFunctionAwaitResolveClosure [/opt/homebrew/Cellar/node/22.9.0/bin/node]
28: 0x1050f84d8 Builtins_PromiseFulfillReactionJob [/opt/homebrew/Cellar/node/22.9.0/bin/node]
29: 0x10501d594 Builtins_RunMicrotasks [/opt/homebrew/Cellar/node/22.9.0/bin/node]
30: 0x104feeaf4 Builtins_JSRunMicrotasksEntry [/opt/homebrew/Cellar/node/22.9.0/bin/node]
31: 0x105551c10 v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
32: 0x105552318 v8::internal::(anonymous namespace)::InvokeWithTryCatch(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
33: 0x1055751bc v8::internal::MicrotaskQueue::RunMicrotasks(v8::internal::Isolate*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
34: 0x105574f4c v8::internal::MicrotaskQueue::PerformCheckpointInternal(v8::Isolate*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
35: 0x1051a5638 node::InternalCallbackScope::Close() [/opt/homebrew/Cellar/node/22.9.0/bin/node]
36: 0x1051a5bb8 node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context, v8::Local<v8::Value>) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
37: 0x1051a5fa4 node::InternalMakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context, v8::Local<v8::Value>) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
38: 0x10522b9bc node::Environment::CheckImmediate(uv_check_s*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
39: 0x1093ef6f8 uv__run_check [/opt/homebrew/Cellar/libuv/1.49.0/lib/libuv.1.dylib]
40: 0x1093ea0e0 uv_run [/opt/homebrew/Cellar/libuv/1.49.0/lib/libuv.1.dylib]
41: 0x1051a647c node::SpinEventLoopInternal(node::Environment*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
42: 0x1052e4b18 node::NodeMainInstance::Run(node::ExitCode*, node::Environment*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
43: 0x1052e486c node::NodeMainInstance::Run() [/opt/homebrew/Cellar/node/22.9.0/bin/node]
44: 0x1052520f4 node::Start(int, char**) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
45: 0x19575bf28 start [/usr/lib/dyld]
fish: Job 1, 'node tests/browser_w_eval.js' terminated by signal SIGABRT (Abort)
# 1m15s
I then downloaded the 205k file itself and confirmed that Node was using 3.5GB of memory and then killed itself due to the JS heap OOM.
$ node tests/rewrite_js_tests.js

<--- Last few GCs --->

[34929:0x158008000]    54629 ms: Mark-Compact 4061.3 (4137.6) -> 4061.3 (4137.6) MB, pooled: 0 MB, 4937.83 / 0.00 ms  (average mu = 0.291, current mu = 0.039) allocation failure; scavenge might not succeed
[34929:0x158008000]    63079 ms: Mark-Compact 4077.1 (4137.6) -> 4077.1 (4169.6) MB, pooled: 0 MB, 8423.83 / 0.00 ms  (average mu = 0.129, current mu = 0.003) allocation failure; scavenge might not succeed


<--- JS stacktrace --->

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
----- Native stack trace -----

 1: 0x100f970c8 node::OOMErrorHandler(char const*, v8::OOMDetails const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 2: 0x10113f1f4 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, v8::OOMDetails const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 3: 0x10113f1a8 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, v8::OOMDetails const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 4: 0x1012e5dcc v8::internal::Heap::CallGCPrologueCallbacks(v8::GCType, v8::GCCallbackFlags, v8::internal::GCTracer::Scope::ScopeId) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 5: 0x1012e4c54 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 6: 0x1012db394 v8::internal::HeapAllocator::AllocateRawWithLightRetrySlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 7: 0x1012dbb00 v8::internal::HeapAllocator::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 8: 0x1012c2e74 v8::internal::Factory::NewFillerObject(int, v8::internal::AllocationAlignment, v8::internal::AllocationType, v8::internal::AllocationOrigin) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
 9: 0x1015d9f20 v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
10: 0x100d85e9c Builtins_WasmCEntry [/opt/homebrew/Cellar/node/22.9.0/bin/node]
11: 0x100d862e4 Builtins_StringAdd_CheckNone [/opt/homebrew/Cellar/node/22.9.0/bin/node]
12: 0x100e08018 Builtins_RegExpReplace [/opt/homebrew/Cellar/node/22.9.0/bin/node]
13: 0x100d72c58 Builtins_StringPrototypeReplace [/opt/homebrew/Cellar/node/22.9.0/bin/node]
14: 0x109c239a8 
15: 0x109c23adc 
16: 0x100db465c Builtins_ArrayMap [/opt/homebrew/Cellar/node/22.9.0/bin/node]
17: 0x109cca8d4 
18: 0x109ccacac 
19: 0x100db6f7c Builtins_ArrayReduceRight [/opt/homebrew/Cellar/node/22.9.0/bin/node]
20: 0x109c21398 
21: 0x109c20188 
22: 0x109c20188 
23: 0x109c20188 
24: 0x109c20188 
25: 0x100cf0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
26: 0x100cf0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
27: 0x100d2f5a4 Builtins_GeneratorPrototypeNext [/opt/homebrew/Cellar/node/22.9.0/bin/node]
28: 0x100ceec0c Builtins_JSEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
29: 0x100cee8f4 Builtins_JSEntry [/opt/homebrew/Cellar/node/22.9.0/bin/node]
30: 0x101251c38 v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
31: 0x101252318 v8::internal::(anonymous namespace)::InvokeWithTryCatch(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
32: 0x101528264 v8::internal::SourceTextModule::ExecuteModule(v8::internal::Isolate*, v8::internal::Handle<v8::internal::SourceTextModule>, v8::internal::MaybeHandle<v8::internal::Object>*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
33: 0x101527da4 v8::internal::SourceTextModule::InnerModuleEvaluation(v8::internal::Isolate*, v8::internal::Handle<v8::internal::SourceTextModule>, v8::internal::ZoneForwardList<v8::internal::Handle<v8::internal::SourceTextModule>>*, unsigned int*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
34: 0x1015278bc v8::internal::SourceTextModule::Evaluate(v8::internal::Isolate*, v8::internal::Handle<v8::internal::SourceTextModule>) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
35: 0x1014ecea8 v8::internal::Module::Evaluate(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Module>) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
36: 0x101145f9c v8::Module::Evaluate(v8::Local<v8::Context>) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
37: 0x100f49720 node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
38: 0x100cf2f98 Builtins_CallApiCallbackGeneric [/opt/homebrew/Cellar/node/22.9.0/bin/node]
39: 0x100cf0ef0 Builtins_InterpreterEntryTrampoline [/opt/homebrew/Cellar/node/22.9.0/bin/node]
40: 0x100d2d290 Builtins_AsyncFunctionAwaitResolveClosure [/opt/homebrew/Cellar/node/22.9.0/bin/node]
41: 0x100df84d8 Builtins_PromiseFulfillReactionJob [/opt/homebrew/Cellar/node/22.9.0/bin/node]
42: 0x100d1d594 Builtins_RunMicrotasks [/opt/homebrew/Cellar/node/22.9.0/bin/node]
43: 0x100ceeaf4 Builtins_JSRunMicrotasksEntry [/opt/homebrew/Cellar/node/22.9.0/bin/node]
44: 0x101251c10 v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
45: 0x101252318 v8::internal::(anonymous namespace)::InvokeWithTryCatch(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
46: 0x1012751bc v8::internal::MicrotaskQueue::RunMicrotasks(v8::internal::Isolate*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
47: 0x101274f4c v8::internal::MicrotaskQueue::PerformCheckpointInternal(v8::Isolate*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
48: 0x100ea5638 node::InternalCallbackScope::Close() [/opt/homebrew/Cellar/node/22.9.0/bin/node]
49: 0x100ea5498 node::InternalCallbackScope::~InternalCallbackScope() [/opt/homebrew/Cellar/node/22.9.0/bin/node]
50: 0x10100e5d8 node::PerIsolatePlatformData::RunForegroundTask(std::__1::unique_ptr<v8::Task, std::__1::default_delete<v8::Task>>) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
51: 0x10100e2f0 node::PerIsolatePlatformData::FlushForegroundTasksInternal() [/opt/homebrew/Cellar/node/22.9.0/bin/node]
52: 0x10100d668 node::NodePlatform::DrainTasks(v8::Isolate*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
53: 0x100ea6498 node::SpinEventLoopInternal(node::Environment*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
54: 0x100fe4b18 node::NodeMainInstance::Run(node::ExitCode*, node::Environment*) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
55: 0x100fe486c node::NodeMainInstance::Run() [/opt/homebrew/Cellar/node/22.9.0/bin/node]
56: 0x100f520f4 node::Start(int, char**) [/opt/homebrew/Cellar/node/22.9.0/bin/node]
57: 0x19575bf28 start [/usr/lib/dyld]
fish: Job 1, 'node tests/rewrite_js_tests.js' terminated by signal SIGABRT (Abort)
# 1m3s

I increased heap limit to 10GB. It used around 8GB of RAM and eventually threw an error saying the string is too long for String.replace:

$ node --max-old-space-size=10000 tests/rewrite_js_tests.js
file:///JSphere/headless_browser/rewrite_js.js:509
    return s.replace(/\\/g, "\\\\").replace(/`/g, "\\`")
             ^

RangeError: Invalid string length
    at String.replace (<anonymous>)
    at escapeBackticksSlashes (file:///JSphere/headless_browser/rewrite_js.js:509:14)
    at file:///JSphere/headless_browser/rewrite_js.js:488:29
    at Array.map (<anonymous>)
    at makeEvalBlock (file:///JSphere/headless_browser/rewrite_js.js:488:10)
    at file:///JSphere/headless_browser/rewrite_js.js:441:31
    at Array.reduceRight (<anonymous>)
    at rewriteStatements (file:///JSphere/headless_browser/rewrite_js.js:438:41)
    at rewriteStatements (file:///JSphere/headless_browser/rewrite_js.js:373:35)
    at rewriteStatements (file:///JSphere/headless_browser/rewrite_js.js:373:35)

Node.js v22.9.0
# 1m36s

The string length limit in V8 is 512MB, so the rewritten string is clearly too long. We need to find ways to reduce its size.

Also, this process takes over a minute, too slow. Not sure where the bottleneck comes from. Maybe should not have written it in JS.

@SichangHe
Copy link
Owner Author

Apparently, 5af9d82 made the overhead effectively linear, improved the speed to become a few hundreds of milliseconds, and helped the script not crash. However, the generated rewritten_google_crashed_us.js crashes the browser tab when pasted into one.

@SichangHe
Copy link
Owner Author

The crashes do not provide useful information:
Screenshot

However, Uncaught RangeError: Maximum call stack size exceeded showed up a few times in my testing, so it is safe to assume this would be the reason.

Increasing the stack size to 4GB seems to allow for a maximum 8 nested evals. Further increasing the stack size causes crashes without visiting any webpages.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant