feat(measurements): collect heap usage (#187)

* feat(profiling): collect heap usage * fix test type * fix test type * fix(profile): dont throw if profile was never started * fix test type * fix(include): include functional * fix: reorder fields * fix: cast size to uint64_t * fix: remove time_ref * ref(review): remove statics * ref(review): add const return and init without assignment * feat(measurements): add cpu measurements (#188) * ref(heapticker): generalize the ticker * feat(metrics): collect cpu usage * ref(review): remove statics * ref(review): remove statics * ref(cleanup): rename param * ref(cleanup): free * test: handle segfault * test str * test str * test str * test str * test removing listeners * explicit init * explicit init * test(measurements): add tests * fix(ticker): adjust count * fix(ticker): remove segfault handler * fix(ticker): remove segfault handler * fix(cpp): remove compiler warning * fix(cpp): add remove safety so we dont overflow max measurements
getsentry · Aug 29, 2023 · 1c2c350 · 1c2c350
1 parent ea07a2f
commit 1c2c350
Show file tree

Hide file tree

Showing 8 changed files with 546 additions and 61 deletions.
diff --git a/bindings/cpu_profiler.cc b/bindings/cpu_profiler.cc
diff --git a/playground/express/index.js b/playground/express/index.js
@@ -9,7 +9,7 @@ Sentry.init({
   dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302',
   tracesSampleRate: 1,
   profilesSampleRate: 0.3,
-  debug: true,
+  // debug: true,
   integrations: [
     // enable HTTP calls tracing
     new Sentry.Integrations.Http({ tracing: true }),
@@ -52,4 +52,3 @@ app.use(function onError(_err, _req, res, _next) {
 app.listen(3000, () => {
   console.log('Server listening on port 3000');
 });
-
diff --git a/src/cpu_profiler.test.ts b/src/cpu_profiler.test.ts
@@ -1,5 +1,10 @@
 import { CpuProfilerBindings, PrivateCpuProfilerBindings } from './cpu_profiler';
-import type { ThreadCpuProfile } from './types';
+import type { ThreadCpuProfile, RawThreadCpuProfile } from './types';
+
+// Required because we test a hypothetical long profile
+// and we cannot use advance timers as the c++ relies on
+// actual event loop ticks that we cannot advance from jest.
+jest.setTimeout(60_000);
 
 function fail(message: string): never {
   throw new Error(message);
@@ -39,6 +44,20 @@ const assertValidSamplesAndStacks = (stacks: ThreadCpuProfile['stacks'], samples
   }
 };
 
+const assertValidMeasurements = (measurement: RawThreadCpuProfile['measurements']['memory_footprint'] | undefined) => {
+  if (!measurement) {
+    throw new Error('Measurement is undefined');
+  }
+  expect(measurement).not.toBe(undefined);
+  expect(typeof measurement.unit).toBe('string');
+  expect(measurement.unit.length).toBeGreaterThan(0);
+
+  for (let i = 0; i < measurement.values.length; i++) {
+    expect(measurement?.values?.[i]?.elapsed_since_start_ns).toBeGreaterThan(0);
+    expect(measurement?.values?.[i]?.value).toBeGreaterThan(0);
+  }
+};
+
 describe('Private bindings', () => {
   it('does not crash if collect resources is false', async () => {
     PrivateCpuProfilerBindings.startProfiling('profiled-program');
@@ -190,6 +209,43 @@ describe('Profiler bindings', () => {
     }
   });
 
+  it('collects memory footprint', async () => {
+    CpuProfilerBindings.startProfiling('profile');
+    await wait(1000);
+    const profile = CpuProfilerBindings.stopProfiling('profile');
+
+    const heap_usage = profile?.measurements['memory_footprint'];
+    if (!heap_usage) {
+      throw new Error('memory_footprint is null');
+    }
+    expect(heap_usage.values.length).toBeGreaterThan(6);
+    expect(heap_usage.values.length).toBeLessThanOrEqual(10);
+    assertValidMeasurements(profile.measurements['memory_footprint']);
+  });
+
+  it('collects cpu usage', async () => {
+    CpuProfilerBindings.startProfiling('profile');
+    await wait(1000);
+    const profile = CpuProfilerBindings.stopProfiling('profile');
+
+    const cpu_usage = profile?.measurements['cpu_usage'];
+    if (!cpu_usage) {
+      throw new Error('cpu_usage is null');
+    }
+    expect(cpu_usage.values.length).toBeGreaterThan(6);
+    expect(cpu_usage.values.length).toBeLessThanOrEqual(10);
+    assertValidMeasurements(profile.measurements['cpu_usage']);
+  });
+
+  it('does not overflow measurement buffer if profile runs longer than 30s', async () => {
+    CpuProfilerBindings.startProfiling('profile');
+    await wait(35000);
+    const profile = CpuProfilerBindings.stopProfiling('profile');
+    expect(profile).not.toBe(null);
+    expect(profile?.measurements?.['cpu_usage']?.values.length).toBeLessThanOrEqual(300);
+    expect(profile?.measurements?.['memory_footprint']?.values.length).toBeLessThanOrEqual(300);
+  });
+
   it.skip('includes deopt reason', async () => {
     // https://github.com/petkaantonov/bluebird/wiki/Optimization-killers#52-the-object-being-iterated-is-not-a-simple-enumerable
     function iterateOverLargeHashTable() {

diff --git a/src/hubextensions.hub.test.ts b/src/hubextensions.hub.test.ts
@@ -117,6 +117,7 @@ describe('hubextensions', () => {
             elapsed_since_start_ns: '10'
           }
         ],
+        measurements: {},
         stacks: [[0]],
         frames: [],
         resources: [],
@@ -157,6 +158,7 @@ describe('hubextensions', () => {
             elapsed_since_start_ns: '10'
           }
         ],
+        measurements: {},
         resources: [],
         stacks: [[0]],
         frames: [],
@@ -346,6 +348,7 @@ describe('hubextensions', () => {
             elapsed_since_start_ns: '10'
           }
         ],
+        measurements: {},
         resources: ['filename.js', 'filename2.js'],
         stacks: [[0]],
         frames: [],

diff --git a/src/integration.test.ts b/src/integration.test.ts
@@ -29,6 +29,7 @@ function makeProfiledEvent(): ProfiledEvent {
             stack_id: 0
           }
         ],
+        measurements: {},
         frames: [],
         stacks: [],
         resources: []

diff --git a/src/types.ts b/src/types.ts
@@ -15,6 +15,14 @@ type Frame = {
   colno: number;
 };
 
+interface Measurement {
+  unit: string;
+  values: {
+    elapsed_since_start_ns: number;
+    value: number;
+  }[];
+}
+
 export interface DebugImage {
   code_file: string;
   type: string;
@@ -39,6 +47,7 @@ export interface RawThreadCpuProfile {
   frames: ReadonlyArray<Frame>;
   resources: ReadonlyArray<string>;
   profiler_logging_mode: 'eager' | 'lazy';
+  measurements: Record<string, Measurement>;
 }
 export interface ThreadCpuProfile {
   stacks: ReadonlyArray<Stack>;
@@ -92,4 +101,5 @@ export interface Profile {
     trace_id: string;
     active_thread_id: string;
   };
+  measurements: Record<string, Measurement>;
 }
diff --git a/src/utils.test.ts b/src/utils.test.ts
@@ -46,6 +46,7 @@ function makeProfile(
       { elapsed_since_start_ns: '0', thread_id: '0', stack_id: 0 },
       { elapsed_since_start_ns: '10', thread_id: '0', stack_id: 0 }
     ],
+    measurements: {},
     resources: [],
     frames: [],
     ...props

diff --git a/src/utils.ts b/src/utils.ts
@@ -211,6 +211,7 @@ function createProfilePayload(
     version: FORMAT_VERSION,
     release: release,
     environment: environment,
+    measurements: cpuProfile.measurements,
     runtime: {
       name: 'node',
       version: versions.node || ''