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

--cpu-prof crashes in debug builds when code cache is enabled #27307

Closed
joyeecheung opened this issue Apr 19, 2019 · 8 comments
Closed

--cpu-prof crashes in debug builds when code cache is enabled #27307

joyeecheung opened this issue Apr 19, 2019 · 8 comments
Labels
confirmed-bug Issues with confirmed bugs. inspector Issues and PRs related to the V8 inspector protocol v8 engine Issues and PRs related to the V8 dependency.

Comments

@joyeecheung
Copy link
Member

joyeecheung commented Apr 19, 2019

This currently fails the debug build on master, the CPU profiler crashes when code cache is enabled (for some reason, this in v8::internal::ProfilerListener::InferScriptName turns into a nullptr in the middle of the profiling).

./configure --debug
make -C out
out/Debug/node --cpu-prof test/fixtures/workload/fibonacci.js # or any script
See stack trace
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=EXC_I386_GPFLT)
  * frame #0: 0x0000000100f738d1 node`v8::internal::ProfilerListener::InferScriptName(v8::internal::Name, v8::internal::SharedFunctionInfo) [inlined] v8::internal::Map::instance_type() const at map-inl.h:293 [opt]
    frame #1: 0x0000000100f738d1 node`v8::internal::ProfilerListener::InferScriptName(v8::internal::Name, v8::internal::SharedFunctionInfo) [inlined] v8::internal::HeapObject::IsString() const at instance-type-inl.h:70 [opt]
    frame #2: 0x0000000100f738c1 node`v8::internal::ProfilerListener::InferScriptName(this=0x0000000000000000, name=<unavailable>, info=SharedFunctionInfo @ 0x00007ffeefbfbb30) at profiler-listener.cc:265 [opt]
    frame #3: 0x0000000100f74ba8 node`v8::internal::ProfilerListener::CodeCreateEvent(this=0x0000000103e1b9b0, tag=SCRIPT_TAG, abstract_code=<unavailable>, shared=SharedFunctionInfo @ 0x00007ffeefbfbd38, script_name=Name @ 0x00007ffeefbfbc28, line=1, column=1) at profiler-listener.cc:172 [opt]
    frame #4: 0x00000001010dc732 node`v8::internal::CodeSerializer::Deserialize(v8::internal::Isolate*, v8::internal::ScriptData*, v8::internal::Handle<v8::internal::String>, v8::ScriptOriginOptions) [inlined] v8::internal::CodeEventDispatcher::CodeCreateEvent(this=<unavailable>, tag=SCRIPT_TAG, code=AbstractCode @ r12, shared=SharedFunctionInfo @ 0x00007ffeefbfbed0, source=Name @ 0x00007ffeefbfbe90, line=1, column=<unavailable>) at code-events.h:142 [opt]
    frame #5: 0x00000001010dc6dc node`v8::internal::CodeSerializer::Deserialize(isolate=0x0000000106000000, cached_data=<unavailable>, source=Handle<v8::internal::String> @ 0x00007ffeefbfbed0, origin_options=<unavailable>) at code-serializer.cc:276 [opt]
    frame #6: 0x00000001006edffe node`v8::internal::Compiler::GetWrappedFunction(source=<unavailable>, arguments=<unavailable>, context=<unavailable>, script_details=0x00007ffeefbfc1f0, origin_options=(flags_ = 1), cached_data=<unavailable>, compile_options=kConsumeCodeCache, no_cache_reason=kNoCacheNoReason) at compiler.cc:1936 [opt]
    frame #7: 0x0000000100531b50 node`v8::ScriptCompiler::CompileFunctionInContext(v8_context=<unavailable>, source=<unavailable>, arguments_count=<unavailable>, arguments=0x00000001050311d0, context_extension_count=0, context_extensions=0x0000000000000000, options=kConsumeCodeCache, no_cache_reason=kNoCacheNoReason) at api.cc:2545 [opt]
    frame #8: 0x000000010022bd19 node`node::native_module::NativeModuleLoader::LookupAndCompile(this=0x0000000102951e38, context=(val_ = 0x0000000107012720), id="path", parameters=0x00007ffeefbfced0 size=6, result=0x00007ffeefbfd054) at node_native_module.cc:217
    frame #9: 0x000000010022ad0e node`node::native_module::NativeModuleLoader::CompileAsModule(this=0x0000000102951e38, context=(val_ = 0x0000000107012720), id="path", result=0x00007ffeefbfd054) at node_native_module.cc:173
    frame #10: 0x00000001002373ae node`node::native_module::NativeModuleEnv::CompileFunction(args=0x00007ffeefbfd510) at node_native_module_env.cc:128
    frame #11: 0x000000010063765e node`v8::internal::FunctionCallbackArguments::Call(this=0x00007ffeefbfd590, handler=<unavailable>) at api-arguments-inl.h:157 [opt]
    frame #12: 0x00000001006358c4 node`v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(isolate=0x0000000106000000, function=<unavailable>, new_target=<unavailable>, fun_data=<unavailable>, receiver=<unavailable>, args=BuiltinArguments @ 0x00007ffeefbfd640) at builtins-api.cc:109 [opt]
    frame #13: 0x0000000100633105 node`v8::internal::Builtin_Impl_HandleApiCall(args=BuiltinArguments @ 0x00007ffeefbfd680, isolate=0x0000000106000000) at builtins-api.cc:139 [opt]
    frame #14: 0x0000000100632c79 node`v8::internal::Builtin_HandleApiCall(args_length=6, args_object=0x00007ffeefbfd7d8, isolate=0x0000000106000000) at builtins-api.cc:127 [opt]
    frame #15: 0x0000000101d82c09 node`Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_NoBuiltinExit + 73
    frame #16: 0x0000000101abfa35 node`Builtins_InterpreterEntryTrampoline + 981
    frame #17: 0x0000000101abfa35 node`Builtins_InterpreterEntryTrampoline + 981
    frame #18: 0x0000000101abfa35 node`Builtins_InterpreterEntryTrampoline + 981
    frame #19: 0x0000000101abfa35 node`Builtins_InterpreterEntryTrampoline + 981
    frame #20: 0x0000000101abfa35 node`Builtins_InterpreterEntryTrampoline + 981
    frame #21: 0x0000000101abfa35 node`Builtins_InterpreterEntryTrampoline + 981
    frame #22: 0x0000000101ab577d node`Builtins_JSEntryTrampoline + 93
    frame #23: 0x0000000101ab54f8 node`Builtins_JSEntry + 120
    frame #24: 0x0000000100afa3fc node`v8::internal::(anonymous namespace)::Invoke(v8::internal::Isolate*, v8::internal::(anonymous namespace)::InvokeParams const&) [inlined] v8::internal::GeneratedCode<unsigned long, unsigned long, unsigned long, unsigned long, unsigned long, long, unsigned long**>::Call(args=<unavailable>, args=<unavailable>, args=<unavailable>, args=<unavailable>, args=<unavailable>, args=<unavailable>) at simulator.h:138 [opt]
    frame #25: 0x0000000100afa3f4 node`v8::internal::(anonymous namespace)::Invoke(isolate=0x0000000106000000, params=0x00007ffeefbfdea0)::InvokeParams const&) at execution.cc:274 [opt]
    frame #26: 0x0000000100af9fb4 node`v8::internal::Execution::Call(isolate=0x0000000106000000, callable=<unavailable>, receiver=<unavailable>, argc=6, argv=0x0000000105109360) at execution.cc:366 [opt]
    frame #27: 0x000000010055a6cd node`v8::Function::Call(this=<unavailable>, context=<unavailable>, recv=<unavailable>, argc=6, argv=<unavailable>) at api.cc:4984 [opt]
    frame #28: 0x0000000100115096 node`node::ExecuteBootstrapper(env=0x0000000107016e00, id="internal/bootstrap/node", parameters=0x00007ffeefbfe2e0 size=6, arguments=0x00007ffeefbfe2b8 size=6) at node.cc:204
    frame #29: 0x00000001001164b4 node`node::RunBootstrapping(env=0x0000000107016e00) at node.cc:332
    frame #30: 0x000000010020d64e node`node::NodeMainInstance::CreateMainEnvironment(this=0x00007ffeefbff1c0, exit_code=0x00007ffeefbfee74) at node_main_instance.cc:155
    frame #31: 0x000000010020c545 node`node::NodeMainInstance::Run(this=0x00007ffeefbff1c0) at node_main_instance.cc:47
    frame #32: 0x000000010011e2ed node`node::Start(argc=3, argv=0x0000000105108a50) at node.cc:863
    frame #33: 0x000000010169615e node`main(argc=3, argv=0x00007ffeefbff630) at node_main.cc:126
    frame #34: 0x00007fff7890c015 libdyld.dylib`start + 1

It does not crash if I build it with code_cache_stub.cc, or build it in release mode.

cc @nodejs/v8 @nodejs/v8-inspector @psmarshall

@joyeecheung joyeecheung added inspector Issues and PRs related to the V8 inspector protocol v8 engine Issues and PRs related to the V8 dependency. confirmed-bug Issues with confirmed bugs. labels Apr 19, 2019
@joyeecheung
Copy link
Member Author

Another stack trace without optimized debug

* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=EXC_I386_GPFLT)
  * frame #0: 0x00000001005078ed node`v8::internal::Map::instance_type(this=0x00007ffeefbf9990) const at map-inl.h:292
    frame #1: 0x00000001005103da node`v8::internal::HeapObject::IsString(this=0x00007ffeefbf9a00) const at instance-type-inl.h:70
    frame #2: 0x000000010165cd48 node`v8::internal::ProfilerListener::InferScriptName(this=0x000000010702b120, name=Name @ 0x00007ffeefbf9a00, info=SharedFunctionInfo @ 0x00007ffeefbf99f8) at profiler-listener.cc:265
    frame #3: 0x000000010165fa50 node`v8::internal::ProfilerListener::CodeCreateEvent(this=0x000000010702b120, tag=SCRIPT_TAG, abstract_code=AbstractCode @ 0x00007ffeefbf9ed0, shared=SharedFunctionInfo @ 0x00007ffeefbf9ec8, script_name=Name @ 0x00007ffeefbf9ec0, line=1, column=1) at profiler-listener.cc:172
    frame #4: 0x00000001007c874d node`v8::internal::CodeEventDispatcher::CodeCreateEvent(this=0x0000000107002340, tag=SCRIPT_TAG, code=AbstractCode @ 0x00007ffeefbfb110, shared=SharedFunctionInfo @ 0x00007ffeefbfb108, source=Name @ 0x00007ffeefbfb100, line=1, column=1) at code-events.h:142
    frame #5: 0x00000001018005cb node`v8::internal::CodeSerializer::Deserialize(isolate=0x0000000108000000, cached_data=0x0000000105c05110, source=Handle<v8::internal::String> @ 0x00007ffeefbfb490, origin_options=(flags_ = 1)) at code-serializer.cc:276
    frame #6: 0x00000001007c55e9 node`v8::internal::Compiler::GetWrappedFunction(source=Handle<v8::internal::String> @ 0x00007ffeefbfb840, arguments=Handle<v8::internal::FixedArray> @ 0x00007ffeefbfb838, context=Handle<v8::internal::Context> @ 0x00007ffeefbfb830, script_details=0x00007ffeefbfb948, origin_options=(flags_ = 1), cached_data=0x0000000105c05110, compile_options=kConsumeCodeCache, no_cache_reason=kNoCacheNoReason) at compiler.cc:1936
    frame #7: 0x000000010053f2b1 node`v8::ScriptCompiler::CompileFunctionInContext(v8_context=(val_ = 0x000000010880c920), source=0x00007ffeefbfbcf0, arguments_count=6, arguments=0x0000000105c02f70, context_extension_count=0, context_extensions=0x0000000000000000, options=kConsumeCodeCache, no_cache_reason=kNoCacheNoReason) at api.cc:2545
    frame #8: 0x000000010022bd19 node`node::native_module::NativeModuleLoader::LookupAndCompile(this=0x000000010359d5b8, context=(val_ = 0x000000010880c920), id="path", parameters=0x00007ffeefbfc790 size=6, result=0x00007ffeefbfc914) at node_native_module.cc:217
    frame #9: 0x000000010022ad0e node`node::native_module::NativeModuleLoader::CompileAsModule(this=0x000000010359d5b8, context=(val_ = 0x000000010880c920), id="path", result=0x00007ffeefbfc914) at node_native_module.cc:173
    frame #10: 0x00000001002373ae node`node::native_module::NativeModuleEnv::CompileFunction(args=0x00007ffeefbfcda8) at node_native_module_env.cc:128
    frame #11: 0x00000001006d95b4 node`v8::internal::FunctionCallbackArguments::Call(this=0x00007ffeefbfcf58, handler=CallHandlerInfo @ 0x00007ffeefbfce70) at api-arguments-inl.h:157
    frame #12: 0x00000001006d729a node`v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(isolate=0x0000000108000000, function=Handle<v8::internal::HeapObject> @ 0x00007ffeefbfd0c0, new_target=Handle<v8::internal::HeapObject> @ 0x00007ffeefbfd0b8, fun_data=Handle<v8::internal::FunctionTemplateInfo> @ 0x00007ffeefbfd0b0, receiver=Handle<v8::internal::Object> @ 0x00007ffeefbfd0a8, args=BuiltinArguments @ 0x00007ffeefbfd0e0) at builtins-api.cc:109
    frame #13: 0x00000001006d5310 node`v8::internal::Builtin_Impl_HandleApiCall(args=BuiltinArguments @ 0x00007ffeefbfd250, isolate=0x0000000108000000) at builtins-api.cc:139
    frame #14: 0x00000001006d4da5 node`v8::internal::Builtin_HandleApiCall(args_length=6, args_object=0x00007ffeefbfd348, isolate=0x0000000108000000) at builtins-api.cc:127
    frame #15: 0x00000001028d9ba9 node`Builtins_CEntry_Return1_DontSaveFPRegs_ArgvOnStack_NoBuiltinExit + 73
    frame #16: 0x00000001025870f5 node`Builtins_InterpreterEntryTrampoline + 981
    frame #17: 0x00000001025870f5 node`Builtins_InterpreterEntryTrampoline + 981
    frame #18: 0x00000001025870f5 node`Builtins_InterpreterEntryTrampoline + 981
    frame #19: 0x00000001025870f5 node`Builtins_InterpreterEntryTrampoline + 981
    frame #20: 0x00000001025870f5 node`Builtins_InterpreterEntryTrampoline + 981
    frame #21: 0x00000001025870f5 node`Builtins_InterpreterEntryTrampoline + 981
    frame #22: 0x000000010257c7bd node`Builtins_JSEntryTrampoline + 93
    frame #23: 0x000000010257c538 node`Builtins_JSEntry + 120
    frame #24: 0x0000000100ef3f7c node`v8::internal::GeneratedCode<unsigned long, unsigned long, unsigned long, unsigned long, unsigned long, long, unsigned long**>::Call(this=0x00007ffeefbfdb08, args=4429185152, args=59452213953745, args=59453608359473, args=59452213953745, args=6, args=0x000000010702bd10) at simulator.h:138
    frame #25: 0x0000000100ef1385 node`v8::internal::(anonymous namespace)::Invoke(isolate=0x0000000108000000, params=0x00007ffeefbfdda8)::InvokeParams const&) at execution.cc:274
    frame #26: 0x0000000100ef095f node`v8::internal::Execution::Call(isolate=0x0000000108000000, callable=Handle<v8::internal::Object> @ 0x00007ffeefbfde10, receiver=Handle<v8::internal::Object> @ 0x00007ffeefbfde08, argc=6, argv=0x000000010702bd10) at execution.cc:366
    frame #27: 0x0000000100557ccd node`v8::Function::Call(this=0x00000001080568c8, context=(val_ = 0x000000010880c920), recv=(val_ = 0x0000000108000058), argc=6, argv=0x000000010702bd10) at api.cc:4984
    frame #28: 0x0000000100115096 node`node::ExecuteBootstrapper(env=0x0000000108809000, id="internal/bootstrap/node", parameters=0x00007ffeefbfe280 size=6, arguments=0x00007ffeefbfe258 size=6) at node.cc:204
    frame #29: 0x00000001001164b4 node`node::RunBootstrapping(env=0x0000000108809000) at node.cc:332
    frame #30: 0x000000010020d64e node`node::NodeMainInstance::CreateMainEnvironment(this=0x00007ffeefbff160, exit_code=0x00007ffeefbfee14) at node_main_instance.cc:155
    frame #31: 0x000000010020c545 node`node::NodeMainInstance::Run(this=0x00007ffeefbff160) at node_main_instance.cc:47
    frame #32: 0x000000010011e2ed node`node::Start(argc=3, argv=0x0000000107000000) at node.cc:863
    frame #33: 0x000000010212d15e node`main(argc=3, argv=0x00007ffeefbff5d8) at node_main.cc:126
    frame #34: 0x00007fff7890c015 libdyld.dylib`start + 1
    frame #35: 0x00007fff7890c015 libdyld.dylib`start + 1

joyeecheung added a commit that referenced this issue Apr 19, 2019
The CPU profiler crashes in debug builds when code cache is
enabled. Skip the test temporarily until it's fixed.

PR-URL: #27308
Refs: #27307
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Yongsheng Zhang <zyszys98@gmail.com>
Reviewed-By: Gus Caplan <me@gus.host>
@addaleax
Copy link
Member

https://gist.github.com/addaleax/139800e79fd687776f409edbaf35b981 fixes this for me, locally – @joyeecheung does that change look right to you? I can open a CL if you think so, but I haven’t done this kind of change in V8 before… like, whether this is enough or the handle itself should be passed as the argument instead of dereferencing it for the function calls, etc.

@joyeecheung
Copy link
Member Author

@addaleax I am not sure if this is sufficient either..please open a CL in the upstream, thanks!

@addaleax
Copy link
Member

@gengjiawen
Copy link
Member

Is this fixed on master now ?

$ out/Debug/node -p process.features
{
  inspector: true,
  debug: true,
  uv: true,
  ipv6: true,
  tls_alpn: true,
  tls_sni: true,
  tls_ocsp: true,
  tls: true,
  cached_builtins: true
}
$ out/Debug/node --cpu-prof test/fixtures/workload/fibonacci.js
9227465

@joyeecheung
Copy link
Member Author

@gengjiawen Not until https://chromium-review.googlesource.com/c/v8/v8/+/1575698 is landed but it depends on GC to reproduce so it could disappear at times

@joyeecheung
Copy link
Member Author

@nodejs/v8-update I think it would take a while for https://chromium-review.googlesource.com/c/v8/v8/+/1575698 to roll back into master. Should we cherry pick this? It does reproduce on master in tests, we only disabled a particular build config that is more likely to trigger the crash.

@targos
Copy link
Member

targos commented Apr 26, 2019

Sure. Anything can be cherry-picked if there is a good reason for it.

joyeecheung added a commit to joyeecheung/node that referenced this issue Apr 26, 2019
Original commit message:

    [snapshot] Use Handle to track name in `CodeSerializer::Deserialize`

    The `Script::InitLineEnds(Handle<Script>(script, isolate));` line
    may lead to objects being moved around on the heap, so it’s necessary
    to use a `Handle` to track that.

    This was causing crashes in Node.js in Debug mode when using the
    code cache in combination with the CPU profiler.

    Refs: nodejs#27307
    Change-Id: I392b4c00c6ebad44753f87fcbf2e3278ea7799a6
    Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1575698
    Reviewed-by: Jakob Gruber <jgruber@chromium.org>
    Reviewed-by: Peter Marshall <petermarshall@chromium.org>
    Commit-Queue: Peter Marshall <petermarshall@chromium.org>
    Cr-Commit-Position: refs/heads/master@{#61036}

Refs: v8/v8@5d0cf6b
oleavr pushed a commit to frida/v8 that referenced this issue Apr 26, 2019
The `Script::InitLineEnds(Handle<Script>(script, isolate));` line
may lead to objects being moved around on the heap, so it’s necessary
to use a `Handle` to track that.

This was causing crashes in Node.js in Debug mode when using the
code cache in combination with the CPU profiler.

Refs: nodejs/node#27307
Change-Id: I392b4c00c6ebad44753f87fcbf2e3278ea7799a6
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1575698
Reviewed-by: Jakob Gruber <jgruber@chromium.org>
Reviewed-by: Peter Marshall <petermarshall@chromium.org>
Commit-Queue: Peter Marshall <petermarshall@chromium.org>
Cr-Commit-Position: refs/heads/master@{#61036}
targos pushed a commit that referenced this issue Apr 29, 2019
Original commit message:

    [snapshot] Use Handle to track name in `CodeSerializer::Deserialize`

    The `Script::InitLineEnds(Handle<Script>(script, isolate));` line
    may lead to objects being moved around on the heap, so it’s necessary
    to use a `Handle` to track that.

    This was causing crashes in Node.js in Debug mode when using the
    code cache in combination with the CPU profiler.

    Refs: #27307
    Change-Id: I392b4c00c6ebad44753f87fcbf2e3278ea7799a6
    Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1575698
    Reviewed-by: Jakob Gruber <jgruber@chromium.org>
    Reviewed-by: Peter Marshall <petermarshall@chromium.org>
    Commit-Queue: Peter Marshall <petermarshall@chromium.org>
    Cr-Commit-Position: refs/heads/master@{#61036}

Refs: v8/v8@5d0cf6b

PR-URL: #27423
Fixes: #27307
Reviewed-By: Michaël Zasso <targos@protonmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
targos pushed a commit to targos/node that referenced this issue May 1, 2019
Original commit message:

    [snapshot] Use Handle to track name in `CodeSerializer::Deserialize`

    The `Script::InitLineEnds(Handle<Script>(script, isolate));` line
    may lead to objects being moved around on the heap, so it’s necessary
    to use a `Handle` to track that.

    This was causing crashes in Node.js in Debug mode when using the
    code cache in combination with the CPU profiler.

    Refs: nodejs#27307
    Change-Id: I392b4c00c6ebad44753f87fcbf2e3278ea7799a6
    Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/1575698
    Reviewed-by: Jakob Gruber <jgruber@chromium.org>
    Reviewed-by: Peter Marshall <petermarshall@chromium.org>
    Commit-Queue: Peter Marshall <petermarshall@chromium.org>
    Cr-Commit-Position: refs/heads/master@{#61036}

Refs: v8/v8@5d0cf6b

PR-URL: nodejs#27423
Fixes: nodejs#27307
Reviewed-By: Michaël Zasso <targos@protonmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
confirmed-bug Issues with confirmed bugs. inspector Issues and PRs related to the V8 inspector protocol v8 engine Issues and PRs related to the V8 dependency.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants