From 673b3ad22f8a5914b037a3ef44370e3d40363f21 Mon Sep 17 00:00:00 2001 From: Ali Ijaz Sheikh Date: Fri, 6 Jul 2018 15:36:40 -0700 Subject: [PATCH 1/3] fix: distinguish idle from program time Fixes: https://github.com/GoogleCloudPlatform/cloud-profiler-nodejs/issues/38 --- ts/src/profilers/time-profiler.ts | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/ts/src/profilers/time-profiler.ts b/ts/src/profilers/time-profiler.ts index f3a72a5c..8560fccc 100644 --- a/ts/src/profilers/time-profiler.ts +++ b/ts/src/profilers/time-profiler.ts @@ -35,10 +35,20 @@ export class TimeProfiler { * @param durationMillis - time in milliseconds for which to collect profile. */ async profile(durationMillis: number): Promise { + // Node.js contains an undocumented API for reporting idle status to V8. + // This lets the profiler distinguish idle time from time spent in native + // code. Ideally this should be default behavior. Until then, use the + // undocumented API. + // See https://github.com/nodejs/node/issues/19009#issuecomment-403161559. + // tslint:disable-next-line no-any + (process as any)._startProfilerIdleNotifier(); const runName = 'stackdriver-profiler-' + Date.now() + '-' + Math.random(); profiler.startProfiling(runName); await delay(durationMillis); const result = profiler.stopProfiling(runName); - return serializeTimeProfile(result, this.intervalMicros); + const profile = serializeTimeProfile(result, this.intervalMicros); + // tslint:disable-next-line no-any + (process as any)._stopProfilerIdleNotifier(); + return profile; } } From 982a62eedfaec62ef17da1f1baf34ed6787818c9 Mon Sep 17 00:00:00 2001 From: Ali Ijaz Sheikh Date: Fri, 6 Jul 2018 16:20:12 -0700 Subject: [PATCH 2/3] [squash] add test --- ts/test/test-time-profiler.ts | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/ts/test/test-time-profiler.ts b/ts/test/test-time-profiler.ts index f2cd6c92..6759fb05 100644 --- a/ts/test/test-time-profiler.ts +++ b/ts/test/test-time-profiler.ts @@ -27,6 +27,17 @@ const v8TimeProfiler = require('bindings')('time_profiler'); describe('TimeProfiler', () => { describe('profile', () => { + it('should detect idle time', async () => { + const durationMillis = 500; + const intervalMicros = 1000; + const profiler = new TimeProfiler(intervalMicros); + const profile = await profiler.profile(durationMillis); + assert.ok(profile.stringTable); + assert.notStrictEqual(profile.stringTable!.indexOf('(idle)'), -1); + }); + }); + + describe('profile (w/ stubs)', () => { const sinonStubs: sinon.SinonStub[] = new Array(); before(() => { sinonStubs.push(sinon.stub(v8TimeProfiler, 'startProfiling')); From 3ff646ecadece41bc1e548a07336174229f298df Mon Sep 17 00:00:00 2001 From: Ali Ijaz Sheikh Date: Tue, 10 Jul 2018 20:25:13 -0700 Subject: [PATCH 3/3] [squash] shorten the duration for which we enable idle notifications --- ts/src/profilers/time-profiler.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ts/src/profilers/time-profiler.ts b/ts/src/profilers/time-profiler.ts index 8560fccc..8cd2654f 100644 --- a/ts/src/profilers/time-profiler.ts +++ b/ts/src/profilers/time-profiler.ts @@ -46,9 +46,9 @@ export class TimeProfiler { profiler.startProfiling(runName); await delay(durationMillis); const result = profiler.stopProfiling(runName); - const profile = serializeTimeProfile(result, this.intervalMicros); // tslint:disable-next-line no-any (process as any)._stopProfilerIdleNotifier(); + const profile = serializeTimeProfile(result, this.intervalMicros); return profile; } }