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

Have an e2e test against a node version that uses v8 very close to head #188

Closed
aalexand opened this issue May 2, 2018 · 21 comments
Closed
Assignees
Labels
api: cloudprofiler Issues related to the googleapis/cloud-profiler-nodejs API. type: cleanup An internal cleanup or hygiene concern.
Milestone

Comments

@aalexand
Copy link
Contributor

aalexand commented May 2, 2018

As CPU or heap profiler in v8 get any changes, we should continuously make sure those do not carry surprises for us (e.g. there is https://chromium-review.googlesource.com/c/v8/v8/+/1039825, which shouldn't break us but only green test gives confidence). To do that we need an automated e2e test run against a version of node that uses v8 very close to head. @ofrobots any recommendations on how to organize this? My naive hope would be that we could do something like "nvm install head" and the head gets v8 updated regularly (automatically?).

@nolanmar511 FYI

@ofrobots
Copy link
Contributor

ofrobots commented May 2, 2018

This is a good idea. Having feedback from potentially breaking changes in V8 as early as possible would be great. I am not sure whether the tests we have in the Node project are as extensive for the profiling/diagnostics use-cases, and this project might well be one of the most advanced users of these V8 APIs.

In the node project we run v8-canary builds which are supposed to be Node.js master integrated with a recent (within O(days) of V8 Tip-of-Tree) version of V8. Available here. We can download and unpack the tarball and go from there. I think this would be sufficient for our purposes.

If we want a build that is within O(hours) up to date, we can use the tarballs from the V8 integration build: https://uberchromegw.corp.google.com/i/client.v8.fyi/builders/V8%20Linux64%20-%20node.js%20integration. This build integrates each V8-roll (small number of commits) into a semi-recent Node.js snapshot. The built binaries are available for download as a tarball from that site too. This will provide semi-immediate feedback if a V8 commit ends up breaking us.

@aalexand
Copy link
Contributor Author

aalexand commented May 2, 2018

O(days) is good but O(hours) is better so I'd go for that.

@aalexand aalexand added this to the Agent Beta milestone May 15, 2018
@nolanmar511
Copy link
Contributor

Installing the v8-canary builds can be done in one line:

NVM_NODEJS_ORG_MIRROR=https://nodejs.org/download/v8-canary/ nvm i node

Installing the v8 integration build would be harder. There's some javascript code which does this, but it first retrieves retrieves a list of builds, then finds the latest successful build, then gets the build git revision and commit and then downloads the build. I don't think we'll need to get the revision and commit (those seem to be used to in reporting).
I think we'd need maybe ~100 lines of additional code to use the integration build, which isn't huge. Would we want to duplicate the javascript code and call it from the start-up script? Translate it to go?

@aalexand
Copy link
Contributor Author

aalexand commented Jun 6, 2018

@nolanmar511 Enabling v8-canary build is probably a good first step. Empirically, how fresh v8 is in these builds?

@nolanmar511
Copy link
Contributor

When I run node-gyp rebuild with the v8-canary version of node, I get an error:

gyp info it worked if it ends with ok
gyp info using node-gyp@3.6.2
gyp info using node@11.0.0-v8-canary20180622e30b7c112d | linux | x64
gyp http GET https://nodejs.org/download/v8-canary/v11.0.0-v8-canary20180622e30b7c112d/node-v11.0.0-v8-canary20180622e30b7c112d-headers.tar.gz
gyp http 404 https://nodejs.org/download/v8-canary/v11.0.0-v8-canary20180622e30b7c112d/node-v11.0.0-v8-canary20180622e30b7c112d-headers.tar.gz
gyp WARN install got an error, rolling back install
gyp ERR! configure error 
gyp ERR! stack Error: 404 response downloading https://nodejs.org/download/v8-canary/v11.0.0-v8-canary20180622e30b7c112d/node-v11.0.0-v8-canary20180622e30b7c112d-headers.tar.gz
gyp ERR! stack     at Request.<anonymous> (/usr/lib/node_modules/node-gyp/lib/install.js:210:14)
gyp ERR! stack     at Request.emit (events.js:187:15)
gyp ERR! stack     at Request.onRequestResponse (/usr/lib/node_modules/node-gyp/node_modules/request/request.js:1074:10)
gyp ERR! stack     at ClientRequest.emit (events.js:182:13)
gyp ERR! stack     at HTTPParser.parserOnIncomingClient (_http_client.js:554:21)
gyp ERR! stack     at HTTPParser.parserOnHeadersComplete (_http_common.js:109:17)
gyp ERR! stack     at TLSSocket.socketOnData (_http_client.js:440:20)
gyp ERR! stack     at TLSSocket.emit (events.js:182:13)
gyp ERR! stack     at addChunk (_stream_readable.js:283:12)
gyp ERR! stack     at readableAddChunk (_stream_readable.js:264:11)
gyp ERR! System Linux 4.9.0-6-amd64
gyp ERR! command "/usr/local/google/home/nolanmar/.nvm/versions/node/v11.0.0-v8-canary20180622e30b7c112d/bin/node" "/usr/bin/node-gyp" "rebuild"
gyp ERR! cwd /usr/local/google/home/nolanmar/cloud-profiler-nodejs-working/cloud-profiler-nodejs
gyp ERR! node -v v11.0.0-v8-canary20180622e30b7c112d
gyp ERR! node-gyp -v v3.6.2
gyp ERR! not ok 

Any recommendations?
Would I have this problem using the lkgr build?

@aalexand
Copy link
Contributor Author

@nolanmar511 Did you mean to tag the person your question was addressed to?

@nolanmar511
Copy link
Contributor

I asked ofrobots in meeting.
It will be necessary to clone https://github.com/nodejs/node-v8, and use the --nodedir flag to point to that directory.

Since we'll need to identify what the commit being used is, it's probably necessary to use v8-lkgr.

@aalexand
Copy link
Contributor Author

@ofrobots @nolanmar511 Based on discussion today looks like we'll use the LKGR build. Still need to figure out how get the matching V8 headers.

@aalexand
Copy link
Contributor Author

I would like to re-open this as I think using the Node.js canary build may be simple enough.

While verifying recent CPU profiler memory usage improvements, I used this command to install the canary build:

NVM_NODEJS_ORG_MIRROR=https://nodejs.org/download/v8-canary nvm install node

With that I indeed had issues installing the profiler module:

$ npm install --save @google-cloud/profiler

> @google-cloud/profiler@0.2.0 install /tmp/testprof/node_modules/@google-cloud/profiler
> node-gyp rebuild

gyp WARN install got an error, rolling back install
gyp ERR! configure error 
gyp ERR! stack Error: 404 response downloading https://nodejs.org/download/v8-canary/v11.0.0-v8-canary201807140f69779e03/node-v11.0.0-v8-canary201807140f69779e03-headers.tar.gz
gyp ERR! stack     at Request.<anonymous> (/usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/lib/node_modules/npm/node_modules/node-gyp/lib/install.js:210:14)
gyp ERR! stack     at Request.emit (events.js:187:15)
gyp ERR! stack     at Request.onRequestResponse (/usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/lib/node_modules/npm/node_modules/request/request.js:1062:10)
gyp ERR! stack     at ClientRequest.emit (events.js:182:13)
gyp ERR! stack     at HTTPParser.parserOnIncomingClient (_http_client.js:554:21)
gyp ERR! stack     at HTTPParser.parserOnHeadersComplete (_http_common.js:109:17)
gyp ERR! stack     at TLSSocket.socketOnData (_http_client.js:440:20)
gyp ERR! stack     at TLSSocket.emit (events.js:182:13)
gyp ERR! stack     at addChunk (_stream_readable.js:283:12)
gyp ERR! stack     at readableAddChunk (_stream_readable.js:264:11)
gyp ERR! System Linux 4.9.0-6-amd64
gyp ERR! command "/usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/bin/node" "/usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "rebuild"
gyp ERR! cwd /tmp/testprof/node_modules/@google-cloud/profiler
gyp ERR! node -v v11.0.0-v8-canary201807140f69779e03
gyp ERR! node-gyp -v v3.6.2
gyp ERR! not ok 
npm WARN enoent ENOENT: no such file or directory, open '/tmp/testprof/package.json'
npm WARN testprof No description
npm WARN testprof No repository field.
npm WARN testprof No README data
npm WARN testprof No license field.
npm WARN You are using a pre-release version of node and things may not work as expected

npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! @google-cloud/profiler@0.2.0 install: `node-gyp rebuild`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the @google-cloud/profiler@0.2.0 install script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /usr/local/google/home/aalexand/.npm/_logs/2018-07-20T17_55_23_203Z-debug.log

But using this trick makes things work:

$ npm install --save --nodedir=$(dirname $(dirname $(which node))) @google-cloud/profiler

> @google-cloud/profiler@0.2.0 install /tmp/testprof/node_modules/@google-cloud/profiler
> node-gyp rebuild

make: Entering directory '/tmp/testprof/node_modules/@google-cloud/profiler/build'
  CXX(target) Release/obj.target/sampling_heap_profiler/bindings/sampling-heap-profiler.o
  SOLINK_MODULE(target) Release/obj.target/sampling_heap_profiler.node
  COPY Release/sampling_heap_profiler.node
  CXX(target) Release/obj.target/time_profiler/bindings/time-profiler.o
../bindings/time-profiler.cc: In function ‘Nan::NAN_METHOD_RETURN_TYPE SetIdle(Nan::NAN_METHOD_ARGS_TYPE)’:
../bindings/time-profiler.cc:92:31: warning: ‘void v8::CpuProfiler::SetIdle(bool)’ is deprecated: Use Isolate::SetIdle(bool) instead. [-Wdeprecated-declarations]
   cpuProfiler->SetIdle(is_idle);
                               ^
In file included from /usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/include/node/v8.h:26:0,
                 from /usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/include/node/v8-profiler.h:10,
                 from ../bindings/time-profiler.cc:17:
/usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/include/node/v8-profiler.h:360:22: note: declared here
                 void SetIdle(bool is_idle));
                      ^
/usr/local/google/home/aalexand/.nvm/versions/node/v11.0.0-v8-canary201807140f69779e03/include/node/v8config.h:324:3: note: in definition of macro ‘V8_DEPRECATED’
   declarator __attribute__((deprecated(message)))
   ^~~~~~~~~~
  SOLINK_MODULE(target) Release/obj.target/time_profiler.node
  COPY Release/time_profiler.node
make: Leaving directory '/tmp/testprof/node_modules/@google-cloud/profiler/build'

> protobufjs@6.8.8 postinstall /tmp/testprof/node_modules/protobufjs
> node scripts/postinstall

npm WARN saveError ENOENT: no such file or directory, open '/tmp/testprof/package.json'
npm notice created a lockfile as package-lock.json. You should commit this file.
npm WARN enoent ENOENT: no such file or directory, open '/tmp/testprof/package.json'
npm WARN testprof No description
npm WARN testprof No repository field.
npm WARN testprof No README data
npm WARN testprof No license field.
npm WARN You are using a pre-release version of node and things may not work as expected

+ @google-cloud/profiler@0.2.0
added 117 packages from 155 contributors and audited 269 packages in 3.317s
found 0 vulnerabilities

And the headers in that location seems recent enough, at least they do include the recent line mode changes:

$ cat $(dirname $(dirname $(which node)))/include/node/v8-profiler.h | grep -C5 kCaller
  // (from the root to a leaf) will have line numbers that point to the start
  // line of the function, rather than the line of the callsite of the child.
  kLeafNodeLineNumbers,
  // In the resulting CpuProfile tree, nodes are separated based on the line
  // number of their callsite in their parent.
  kCallerLineNumbers,
};

/**
 * Interface for controlling CPU profiling. Instance of the
 * profiler can be created using v8::CpuProfiler::New method.

With that, adding testing against the canary build should be trivial?

@nolanmar511
Copy link
Contributor

I tried using --nodedir where the profiler is installed (so retry npm install --nodedir=/.nvm/versions/node/v11.0.0-v8-canary201807247c08774a29 /cloud-profiler-nodejs/google-cloud-profiler-0.2.0.tgz) and got a segmentation fault immediately after trying to collect a Wall profile.

Here's the complete output of the test run:
out.txt

@aalexand
Copy link
Contributor Author

@nolanmar511 Does it reproduce locally? Try to reproduce it locally, generate a core file and get the stack of the crash from the core file using gbd, something along these lines. That should give some clues about what is going on.

@nolanmar511
Copy link
Contributor

Yep. This reproduces locally. This is the back trace.

#0  0x0000000000fc36e5 in v8::internal::ExistingCodeLogger::LogCompiledFunctions() ()
#1  0x00000000010b684a in v8::internal::CpuProfiler::StartProcessorIfNotStarted() ()
#2  0x00000000010b6a87 in v8::internal::CpuProfiler::StartProfiling(v8::internal::String*, bool, v8::CpuProfilingMode)
    ()
#3  0x00007ffff4765068 in Nan::imp::FunctionCallbackWrapper(v8::FunctionCallbackInfo<v8::Value> const&) ()
   from /usr/local/google/home/nolanmar/test-7-25-18/node_modules/@google-cloud/profiler/build/Release/time_profiler.node
#4  0x0000000000b6051a in v8::internal::MaybeHandle<v8::internal::Object> v8::internal::(anonymous namespace)::HandleApiCallHelper<false>(v8::internal::Isolate*, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::HeapObject>, v8::internal::Handle<v8::internal::FunctionTemplateInfo>, v8::internal::Handle<v8::internal::Object>, v8::internal::BuiltinArguments) ()
#5  0x0000000000b610c9 in v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*) ()
#6  0x00002b5769bd085d in ?? ()
#7  0x00003d9c9bf74d29 in ?? ()
#8  0x00002b5769bd07c1 in ?? ()
#9  0x00007fffffff81e0 in ?? ()
#10 0x0000000000000006 in ?? ()
#11 0x00007fffffff82a0 in ?? ()
#12 0x00002b5769b8ea7b in ?? ()
#13 0x00002a35c7a825b1 in ?? ()
#14 0x00003d9c9bf762a9 in ?? ()
#15 0x0000000600000000 in ?? ()
#16 0x00002a35c7a82691 in ?? ()

@nolanmar511
Copy link
Contributor

Steps to reproduce segfault:

> NVM_NODEJS_ORG_MIRROR="https://nodejs.org/download/v8-canary" nvm install 11
> mkdir test-v8-canary
> cd test-v8-canary
> git clone git@github.com:GoogleCloudPlatform/cloud-profiler-nodejs.git
> cd cloud-profiler-nodejs/
> npm install --nodedir=$(dirname $(dirname $(which node)))
> npm run compile
> npm pack
> cp testing/busybench.js ../busybench.js
> cd ..
> npm install ./cloud-profiler-nodejs/google-cloud-profiler-0.2.0.tgz --nodedir=$(dirname $(dirname $(which node)))
> GCLOUD_PROFILER_LOGLEVEL=5 GAE_SERVICE=service GCLOUD_PROJECT=nolanmar-test-1  gdb --arg node --trace-warnings --require @google-cloud/profiler busybench.js 600
  (gdb) run
  (gdb) bt
   

@aalexand
Copy link
Contributor Author

I reproduce it with debug Node.js, see the information below. @psmarshall @ofrobots Any thoughts on this? This does not look to me like a mismatch between headers and the binary code (and I am pretty sure the headers used the profiler bindings here were the right ones).

DEBUG:@google-cloud/profiler: Attempting to create profile.
DEBUG:@google-cloud/profiler: Successfully created profile WALL.


#
# Fatal error in ../deps/v8/src/objects/managed.h, line 57
# Check failed: !v8::internal::FLAG_enable_slow_asserts || (obj->IsForeign()).
#
#
#
#FailureMessage Object: 0x7fffffff6ce0[New Thread 0x7fffe27fc700 (LWP 47059)]
[New Thread 0x7fffe2ffd700 (LWP 47058)]
[New Thread 0x7fffe37fe700 (LWP 47057)]
[New Thread 0x7ffff7ff4700 (LWP 47053)]

Program received signal SIGILL, Illegal instruction.
v8::base::OS::Abort () at ../deps/v8/src/base/platform/platform-posix.cc:398
398         V8_IMMEDIATE_CRASH();
(gdb) bt
#0  v8::base::OS::Abort () at ../deps/v8/src/base/platform/platform-posix.cc:398
#1  0x0000555557e1de03 in V8_Fatal (file=0x555558191490 "../deps/v8/src/objects/managed.h", line=57, format=0x5555581891a2 "Check failed: %s.") at ../deps/v8/src/base/logging.cc:171
#2  0x0000555556d9444b in v8::internal::Managed<v8::internal::wasm::NativeModule>::cast (obj=0x81fb4d025b1) at ../deps/v8/src/objects/managed.h:57
#3  0x0000555556d5b069 in v8::internal::WasmModuleObject::managed_native_module (this=0x1e95f0590ca1) at ../deps/v8/src/wasm/wasm-objects-inl.h:53
#4  0x0000555556d5b08c in v8::internal::WasmModuleObject::native_module (this=0x1e95f0590ca1) at ../deps/v8/src/wasm/wasm-objects-inl.h:64
#5  0x00005555575ba026 in v8::internal::ExistingCodeLogger::LogCompiledFunctions (this=0x555559729e50) at ../deps/v8/src/log.cc:2174
#6  0x00005555575b8f50 in v8::internal::Logger::LogCompiledFunctions (this=0x555559729dc0) at ../deps/v8/src/log.cc:1873
#7  0x000055555774360e in v8::internal::CpuProfiler::StartProcessorIfNotStarted (this=0x5555597de9c0) at ../deps/v8/src/profiler/cpu-profiler.cc:388
#8  0x000055555774334d in v8::internal::CpuProfiler::StartProfiling (this=0x5555597de9c0, title=0x555559946e90 "stackdriver-profiler-1532666510669-0.9410488656355149", record_samples=false, 
    mode=v8::kLeafNodeLineNumbers) at ../deps/v8/src/profiler/cpu-profiler.cc:352
#9  0x00005555577433b1 in v8::internal::CpuProfiler::StartProfiling (this=0x5555597de9c0, title=0x372cf54763e1, record_samples=false, mode=v8::kLeafNodeLineNumbers) at ../deps/v8/src/profiler/cpu-profiler.cc:358
#10 0x0000555556d8e815 in v8::CpuProfiler::StartProfiling (this=0x5555597de9c0, title=..., record_samples=false) at ../deps/v8/src/api.cc:10401
#11 0x00007ffff05b3068 in Nan::imp::FunctionCallbackWrapper(v8::FunctionCallbackInfo<v8::Value> const&) () from /usr/local/google/home/aalexand/src/cloud-profiler-nodejs/build/Release/time_profiler.node
#12 0x0000555556e5d345 in v8::internal::FunctionCallbackArguments::Call (this=0x7fffffff73a0, handler=0x2c297479571) at ../deps/v8/src/api-arguments-inl.h:119
#13 0x0000555556e5f87e in v8::internal::(anonymous namespace)::HandleApiCallHelper<false> (isolate=0x55555971f1d0, function=..., new_target=..., fun_data=..., receiver=..., args=...)
    at ../deps/v8/src/builtins/builtins-api.cc:110
#14 0x0000555556e5db81 in v8::internal::Builtin_Impl_HandleApiCall (args=..., isolate=0x55555971f1d0) at ../deps/v8/src/builtins/builtins-api.cc:140
#15 0x0000555556e5d912 in v8::internal::Builtin_HandleApiCall (args_length=6, args_object=0x7fffffff7680, isolate=0x55555971f1d0) at ../deps/v8/src/builtins/builtins-api.cc:128
#16 0x00003930b21693c4 in ?? ()
#17 0x00003930b2169321 in ?? ()

@aalexand
Copy link
Contributor Author

Oh, and I used canary-base branch to build node.

@aalexand
Copy link
Contributor Author

FWIW, the code that faults is like this in canary-base:

  const int wasm_module_objects_count =
      EnumerateWasmModuleObjects(heap, nullptr);
  std::unique_ptr<Handle<WasmModuleObject>[]> module_objects(
      new Handle<WasmModuleObject>[wasm_module_objects_count]);
  EnumerateWasmModuleObjects(heap, module_objects.get());
  for (int i = 0; i < wasm_module_objects_count; ++i) {
    module_objects[i]->native_module()->LogWasmCodes(isolate_);  <---- THE native_module() CALL IS WHAT FAILS DOWN THE ROAD
  }

but like this in master:

  const int compiled_wasm_modules_count = EnumerateWasmModules(heap, nullptr);
  ScopedVector<Handle<WasmCompiledModule>> modules(compiled_wasm_modules_count);
  EnumerateWasmModules(heap, modules.start());
  for (int i = 0; i < compiled_wasm_modules_count; ++i) {
    modules[i]->LogWasmCodes(isolate_);
  }

Maybe it will lead to some thoughts.

@aalexand
Copy link
Contributor Author

Looks like this commit changed this code - v8/v8@f318f98.

@aalexand
Copy link
Contributor Author

@psmarshall
Copy link

I logged an upstream bug here: https://bugs.chromium.org/p/v8/issues/detail?id=8003

@JustinBeckwith JustinBeckwith added the type: cleanup An internal cleanup or hygiene concern. label Sep 13, 2018
@nolanmar511
Copy link
Contributor

The original crash has been solved, but still having problems with v8 canary.

Right now, when I try NVM_NODEJS_ORG_MIRROR=https://nodejs.org/download/v8-canary nvm install node, I get this error in the output:

../deps/v8/src/base/format-macros.h:24:20: fatal error: stddef.h: No such file or directory
 #include <stddef.h>

@aalexand
Copy link
Contributor Author

@nolanmar511 I think the error happens because it tries to build the node from source and your machine doesn't have fully configured compiler. I would expect though that the canary location includes prebuilt node for linux-amd64 arch, and with nodejs/node#22757 it still doesn't seem to be the case.

@google-cloud-label-sync google-cloud-label-sync bot added the api: cloudprofiler Issues related to the googleapis/cloud-profiler-nodejs API. label Jan 31, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
api: cloudprofiler Issues related to the googleapis/cloud-profiler-nodejs API. type: cleanup An internal cleanup or hygiene concern.
Projects
None yet
Development

No branches or pull requests

5 participants