src: fix v8::CpuProfiler idle sampling #2324

OleksandrChekhovskyi · 2015-08-07T13:56:52Z

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?):

After the fix (now actually looks like reality):

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.

thefourtheye · 2015-08-07T14:11:09Z

src/node.cc

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

+#ifdef __POSIX__


What will happen in Windows?

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 · 2015-08-07T14:19:30Z

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

OleksandrChekhovskyi · 2015-08-07T14:31:52Z

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 · 2015-08-07T14:48:38Z

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.

OleksandrChekhovskyi · 2015-08-07T15:24:55Z

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

bnoordhuis · 2015-08-07T17:09:35Z

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

OleksandrChekhovskyi · 2015-08-07T17:53:44Z

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

OleksandrChekhovskyi · 2015-08-10T11:21:10Z

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).

bnoordhuis · 2015-08-18T18:42:51Z

test/addons/cpu-profiler/binding.cc

+               v8::FunctionTemplate::New(isolate, End)->GetFunction());
+}
+
+NODE_MODULE(test, Initialize)


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

OleksandrChekhovskyi · 2015-08-19T07:50:03Z

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

bnoordhuis · 2015-08-20T21:53:10Z

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

bnoordhuis · 2015-08-25T10:21:27Z

CI: https://jenkins-iojs.nodesource.com/job/node-test-pull-request/152/

OleksandrChekhovskyi · 2015-08-25T11:16:42Z

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

bnoordhuis · 2015-08-25T11:38:51Z

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

bnoordhuis · 2015-08-25T11:58:06Z

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 · 2015-08-25T12:04:24Z

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 · 2015-08-25T15:14:13Z

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 · 2015-08-28T09:19:28Z

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 · 2015-09-01T07:04:20Z

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.

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 · 2015-09-12T04:50:29Z

Thanks Oleksandr, landed in 8e14135.

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>

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

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

thefourtheye reviewed Aug 7, 2015
View reviewed changes

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 force-pushed the master branch from 7973727 to a9729fd Compare August 10, 2015 11:13

bnoordhuis reviewed Aug 18, 2015
View reviewed changes

OleksandrChekhovskyi force-pushed the master branch from a9729fd to 4b690ce Compare August 19, 2015 07:45

OleksandrChekhovskyi force-pushed the master branch from 4b690ce to 214ca22 Compare August 28, 2015 09:13

src: fix v8::CpuProfiler idle sampling

9ba84d8

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

OleksandrChekhovskyi force-pushed the master branch from 214ca22 to 9ba84d8 Compare August 28, 2015 09:15

rvagg force-pushed the master branch from 11c25c2 to ba02bd0 Compare September 6, 2015 11:55

bnoordhuis mentioned this pull request Sep 12, 2015

src: reduce cpu profiler overhead nodejs/node-v0.x-archive#8791

Closed

bnoordhuis closed this Sep 12, 2015

Fishrock123 mentioned this pull request Sep 13, 2015

Release proposal: v4.1.0 #2844

Closed

7 tasks

rvagg mentioned this pull request Sep 15, 2015

Release proposal: v3.3.1 #2698

Merged

rvagg mentioned this pull request Sep 22, 2015

Release proposal: v4.1.1 #2995

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

src: fix v8::CpuProfiler idle sampling #2324

src: fix v8::CpuProfiler idle sampling #2324

OleksandrChekhovskyi commented Aug 7, 2015

thefourtheye Aug 7, 2015

OleksandrChekhovskyi Aug 7, 2015

bnoordhuis commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 7, 2015

bnoordhuis commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 7, 2015

bnoordhuis commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 10, 2015

bnoordhuis Aug 18, 2015

OleksandrChekhovskyi commented Aug 19, 2015

bnoordhuis commented Aug 20, 2015

bnoordhuis commented Aug 25, 2015

OleksandrChekhovskyi commented Aug 25, 2015

bnoordhuis commented Aug 25, 2015

bnoordhuis commented Aug 25, 2015

OleksandrChekhovskyi commented Aug 25, 2015

bnoordhuis commented Aug 25, 2015

OleksandrChekhovskyi commented Aug 28, 2015

OleksandrChekhovskyi commented Sep 1, 2015

bnoordhuis commented Sep 12, 2015

src: fix v8::CpuProfiler idle sampling #2324

src: fix v8::CpuProfiler idle sampling #2324

Conversation

OleksandrChekhovskyi commented Aug 7, 2015

thefourtheye Aug 7, 2015

Choose a reason for hiding this comment

OleksandrChekhovskyi Aug 7, 2015

Choose a reason for hiding this comment

bnoordhuis commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 7, 2015

bnoordhuis commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 7, 2015

bnoordhuis commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 7, 2015

OleksandrChekhovskyi commented Aug 10, 2015

bnoordhuis Aug 18, 2015

Choose a reason for hiding this comment

OleksandrChekhovskyi commented Aug 19, 2015

bnoordhuis commented Aug 20, 2015

bnoordhuis commented Aug 25, 2015

OleksandrChekhovskyi commented Aug 25, 2015

bnoordhuis commented Aug 25, 2015

bnoordhuis commented Aug 25, 2015

OleksandrChekhovskyi commented Aug 25, 2015

bnoordhuis commented Aug 25, 2015

OleksandrChekhovskyi commented Aug 28, 2015

OleksandrChekhovskyi commented Sep 1, 2015

bnoordhuis commented Sep 12, 2015