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

src: fix v8::CpuProfiler idle sampling #2324

Closed

Conversation

OleksandrChekhovskyi
Copy link

Correctly mark idle wait as "(idle)" instead of "(program)", and take
samples during that time.

This makes profiling with node-inspector (via v8-profiler) actually useful.


Simple test program:

var http = require("http");

http.createServer(function(req, res) {
    res.end("Hello World\n");
}).listen(1337, "127.0.0.1");

console.log("node.js version: " + process.version);
console.log("Server running at http://127.0.0.1:1337/");

Testing was done by starting profiling, waiting few seconds, loading page once in the browser, waiting few more seconds and then stopping profiling.

What profiler showed before the fix (omg, several seconds of CPU time to handle one trivial request?):
io js-2 5 0

After the fix (now actually looks like reality):
io js-2 5 0-fixed

Please cherry-pick this fix to 2.x and 3.x - having working convenient profiling can be really useful.
The fix itself was in fact tested off 2.5.0, since v8-profiler package has not been updated yet for module ABI v45.

@@ -3687,6 +3683,15 @@ void Init(int* argc,
}
}

#ifdef __POSIX__
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What will happen in Windows?

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Probably it will always collect samples during idle time (I have not tested Windows).
Note that the original code above was POSIX-only as well. It is moved here so that it can be conditional on the command line flag '--prof' (so only block SIGPROF if using v8.log-style profiling).

@bnoordhuis
Copy link
Member

Can you add a regression test? You can use test/addons/heap-profiler as a template.

@OleksandrChekhovskyi
Copy link
Author

What would you exactly test in such a test? The API 'worked', it just returned data that didn't match the reality. It's not obvious how to verify that.

@bnoordhuis
Copy link
Member

The v8::CpuProfile contains the raw timeline data, you can get it with v8::CpuProfile::GetSampleTimestamp(). I think that if the test calls setTimeout(function() {}, 100), it should see approximately 100 samples with your patch and zero or almost zero without.

@mscdex mscdex added c++ Issues and PRs that require attention from people who are familiar with C++. v8 engine Issues and PRs related to the V8 dependency. labels Aug 7, 2015
@OleksandrChekhovskyi
Copy link
Author

Possible indeed. 'Approximately' and 'almost', however, make me nervous.
Are you sure it's worth the trouble?

@bnoordhuis
Copy link
Member

A test would be good if you don't want it to regress over time.

@OleksandrChekhovskyi
Copy link
Author

Ok, I'll try to make something on Monday.

@OleksandrChekhovskyi
Copy link
Author

The patch has been updated.
Now includes a test that verifies that samples collected with v8::CpuProfiler are evenly distributed.

In the future it might be possible to make it work with uneven samples. v8::CpuProfiler now reports sample timestamps, and they are supported by current Chrome DevTools, however it'll require updating v8-profiler and node-inspector, and that's much more work. Also since that would be a breaking behavior change, ideally it should only be enabled explicitly by the user.

So let's keep it simple for now, as it enables easy/convenient profiling immediately (assuming the patch is cherry-picked to stable branches).

v8::FunctionTemplate::New(isolate, End)->GetFunction());
}

NODE_MODULE(test, Initialize)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There are a bunch of style errors in this file but once #2427 lands, make cpplint should tell you about them.

@OleksandrChekhovskyi
Copy link
Author

Style errors have been fixed, unconditional idle notifier undone, commit message updated.

@bnoordhuis
Copy link
Member

LGTM and thanks. Linking to #2428 because I'd like to see that land first.

@bnoordhuis
Copy link
Member

@OleksandrChekhovskyi
Copy link
Author

It looks like the build failed because it failed to fetch the source code from git.

@bnoordhuis
Copy link
Member

GH is pretty flaky today. Second try: https://jenkins-iojs.nodesource.com/job/node-test-pull-request/154/

@bnoordhuis
Copy link
Member

The freebsd101-64 failure is #2464 but I see the test from this PR failing on the fedora22 buildbot: https://jenkins-iojs.nodesource.com/job/node-test-commit-linux/272/nodes=fedora22/console (grep for 'not ok'.)

@OleksandrChekhovskyi
Copy link
Author

Not sure why would it fail. This might just mean that testing timing-related stuff in a unit test is not a good idea.

@bnoordhuis
Copy link
Member

V8 has CPU profiler tests that run on a wide range of platforms so it must be possible to write something that isn't timing sensitive.

Ensure that samples are evenly distributed, which is required for v8::CpuProfiler
users to work correctly (v8-profiler / node-inspector).
@OleksandrChekhovskyi
Copy link
Author

I couldn't think of any reliable way to validate this in a unit test, so I have dropped the test in the updated patch.

It needs to check either number of samples, timings between samples, or presence of samples within certain intervals, and neither of these are reliable.

I have checked V8 CPU profiler tests and those only check for specifics only if samples have been manually recorded by the code in the test.

@OleksandrChekhovskyi
Copy link
Author

Changes to v8-profiler have been upstreamed now (node-inspector/v8-profiler#73), so now only this patch is missing from the 'working profiler' picture.

bnoordhuis pushed a commit that referenced this pull request Sep 12, 2015
Ensure that samples are evenly distributed, which is required for
v8::CpuProfiler users to work correctly (v8-profiler / node-inspector).

PR-URL: #2324
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
@bnoordhuis
Copy link
Member

Thanks Oleksandr, landed in 8e14135.

@bnoordhuis bnoordhuis closed this Sep 12, 2015
@Fishrock123 Fishrock123 mentioned this pull request Sep 13, 2015
7 tasks
Fishrock123 pushed a commit that referenced this pull request Sep 15, 2015
Ensure that samples are evenly distributed, which is required for
v8::CpuProfiler users to work correctly (v8-profiler / node-inspector).

PR-URL: #2324
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
@rvagg rvagg mentioned this pull request Sep 15, 2015
Fishrock123 added a commit to Fishrock123/node that referenced this pull request Sep 17, 2015
Notable changes:

* buffer:
  - Buffers are now created in JavaScript, rather than C++. This increases the speed of buffer creation (Trevor Norris) nodejs#2866.
  - `Buffer#slice()` now uses `Uint8Array#subarray()` internally, increasing `slice()` performance (Karl Skomski) nodejs#2777.
* fs:
  - `fs.utimes()` now properly converts numeric strings, `NaN`, and `Infinity` (Yazhong Liu) nodejs#2387.
  - `fs.WriteStream` now implements `_writev`, allowing for super-fast bulk writes (Ron Korving) nodejs#2167.
* http: Fixed an issue with certain `write()` sizes causing errors when using `http.request()` (Fedor Indutny) nodejs#2824.
* npm: Upgrade to version 2.14.3, see https://github.com/npm/npm/releases/tag/v2.14.3 for more details (Kat Marchán) nodejs#2822.
* src: V8 cpu profiling no longer erroneously shows idle time (Oleksandr Chekhovskyi) nodejs#2324.
* v8: Lateral upgrade to 4.5.103.33 from 4.5.103.30, contains minor fixes (Ali Ijaz Sheikh) nodejs#2870.
  - This fixes a previously known bug where some computed object shorthand properties did not work correctly (nodejs#2507).

Refs: nodejs#2844
PR-URL: nodejs#2889
Fishrock123 added a commit that referenced this pull request Sep 17, 2015
Notable changes:

* buffer:
  - Buffers are now created in JavaScript, rather than C++. This increases the speed of buffer creation (Trevor Norris) #2866.
  - `Buffer#slice()` now uses `Uint8Array#subarray()` internally, increasing `slice()` performance (Karl Skomski) #2777.
* fs:
  - `fs.utimes()` now properly converts numeric strings, `NaN`, and `Infinity` (Yazhong Liu) #2387.
  - `fs.WriteStream` now implements `_writev`, allowing for super-fast bulk writes (Ron Korving) #2167.
* http: Fixed an issue with certain `write()` sizes causing errors when using `http.request()` (Fedor Indutny) #2824.
* npm: Upgrade to version 2.14.3, see https://github.com/npm/npm/releases/tag/v2.14.3 for more details (Kat Marchán) #2822.
* src: V8 cpu profiling no longer erroneously shows idle time (Oleksandr Chekhovskyi) #2324.
* v8: Lateral upgrade to 4.5.103.33 from 4.5.103.30, contains minor fixes (Ali Ijaz Sheikh) #2870.
  - This fixes a previously known bug where some computed object shorthand properties did not work correctly (#2507).

Refs: #2844
PR-URL: #2889
@rvagg rvagg mentioned this pull request Sep 22, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
c++ Issues and PRs that require attention from people who are familiar with C++. v8 engine Issues and PRs related to the V8 dependency.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants