Browse Source

feat(profiling): improve import logic (#44295)

Improves the sampled profile import logic. From my tests on large JS
profiles, this improves perf by in the range of 20-30% (we have
transactions with spans so we will be able to validate this once this is
released)

The optimization is to create a reusable buffer for resolved stack
traces (we were previously allocating 1 array per sample) and to use a
preallocated array instead of 0 initialized. Surprisingly though, since
we do so many push operations, the largest win was to simply use
assignments instead of array.push
Jonas 2 years ago
parent
commit
b992bbe5ab

+ 1 - 1
package.json

@@ -47,7 +47,7 @@
     "@sentry-internal/global-search": "^0.4.1",
     "@sentry/integrations": "7.36.0",
     "@sentry/node": "7.36.0",
-    "@sentry/profiling-node": "^0.0.12",
+    "@sentry/profiling-node": "^0.1.0",
     "@sentry/react": "7.36.0",
     "@sentry/release-parser": "^1.3.1",
     "@sentry/tracing": "7.36.0",

File diff suppressed because it is too large
+ 0 - 0
static/app/utils/profiling/profile/formats/node/trace.json


+ 1 - 1
static/app/utils/profiling/profile/importProfile.tsx

@@ -211,7 +211,7 @@ function importSentrySampledProfile(
   };
 }
 
-function importSchema(
+export function importSchema(
   input: Readonly<Profiling.Schema>,
   traceID: string,
   options: ImportOptions

+ 37 - 8
static/app/utils/profiling/profile/profile.benchmark.ts

@@ -10,33 +10,62 @@ import {initializeLocale} from 'sentry/bootstrap/initializeLocale';
 import eventedTrace from './formats/android/trace.json';
 import sampledTrace from './formats/ios/trace.json';
 import jsSelfProfileTrace from './formats/jsSelfProfile/trace.json';
+import nodeTrace from './formats/node/trace.json';
 import typescriptTrace from './formats/typescript/trace.json';
 import {importProfile} from './importProfile';
 
 // This logs an error which is annoying to see in the outputs
 initializeLocale({} as any);
 
+// Note: You MUST import @sentry/tracing package before @sentry/profiling-node
+// eslint-disable-next-line simple-import-sort/imports
+import * as Sentry from '@sentry/node';
+import '@sentry/tracing';
+import {ProfilingIntegration} from '@sentry/profiling-node';
+
+if (process.env.PROFILE) {
+  Sentry.init({
+    dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302',
+    integrations: [
+      // Add our Profilling integration
+      new ProfilingIntegration(),
+    ],
+    debug: true,
+    tracesSampleRate: 1.0,
+    // Set sampling rate for profiling
+    profilesSampleRate: 1.0,
+  });
+}
+
 // We dont compare benchmark results, as we are testing a single version of the code, so we run this as a baseline,
 // store the results somewhere locally and then compare the results with the new version of our code.
 function benchmark(name: string, callback: () => void) {
   const suite = new benchmarkjs.Suite();
 
   suite
-    .add(name, callback)
+    .add(name, callback, {minSamples: 50})
     .on('cycle', event => {
       // well, we need to see the results somewhere
       // eslint-disable-next-line
-      console.log(event.target.toString());
+      console.log(event.target.toString(), (event.target.stats.mean * 1e3).toFixed(2));
     })
     .on('error', event => {
       // If something goes wrong, fail early
       throw event;
-    });
+    })
+    .on('fini');
 
-  suite.run({async: true});
+  suite.run({async: true, minSamples: 100});
 }
 
-benchmark('typescript', () => importProfile(typescriptTrace as any, ''));
-benchmark('js self profile', () => importProfile(jsSelfProfileTrace as any, ''));
-benchmark('evented profile', () => importProfile(eventedTrace as any, ''));
-benchmark('sampled profile', () => importProfile(sampledTrace as any, ''));
+benchmark('typescript', () => importProfile(typescriptTrace as any, '', 'flamechart'));
+benchmark('js self profile', () =>
+  importProfile(jsSelfProfileTrace as any, '', 'flamechart')
+);
+benchmark('evented profile', () => importProfile(eventedTrace as any, '', 'flamechart'));
+benchmark('sampled profile', () => importProfile(sampledTrace as any, '', 'flamechart'));
+benchmark('sampled node profile', () =>
+  importProfile(nodeTrace as any, '', 'flamechart')
+);
+
+// importProfile(nodeTrace, '', 'flamechart');

+ 30 - 0
static/app/utils/profiling/profile/sampledProfile.spec.tsx

@@ -234,6 +234,36 @@ describe('SampledProfile', () => {
     expect(profile.callTree.children[0].children[0].children[0].frame.selfWeight).toBe(3);
   });
 
+  it('places garbage collector calls on top of previous stack and skips stack', () => {
+    const trace: Profiling.SampledProfile = {
+      name: 'profile',
+      startValue: 0,
+      endValue: 1000,
+      unit: 'milliseconds',
+      threadID: 0,
+      type: 'sampled',
+      weights: [1, 1, 1, 1],
+      samples: [
+        [0, 1],
+        [0, 2],
+        [0, 2],
+        [0, 1],
+      ],
+    };
+
+    const profile = SampledProfile.FromProfile(
+      trace,
+      createFrameIndex('node', [
+        {name: 'f0'},
+        {name: 'f1'},
+        {name: '(garbage collector)'},
+      ]),
+      {type: 'flamechart'}
+    );
+
+    expect(profile.weights).toEqual([1, 2, 1]);
+  });
+
   it('does not place garbage collector calls on top of previous stack for node', () => {
     const trace: Profiling.SampledProfile = {
       name: 'profile',

+ 46 - 30
static/app/utils/profiling/profile/sampledProfile.tsx

@@ -1,4 +1,3 @@
-import {lastOfArray} from 'sentry/utils';
 import {CallTreeNode} from 'sentry/utils/profiling/callTreeNode';
 
 import {Frame} from './../frame';
@@ -41,6 +40,10 @@ function sortSamples(
   return stacksWithWeights(profile).sort(sortStacks);
 }
 
+function throwIfMissingFrame(index: number) {
+  throw new Error(`Could not resolve frame ${index} in frame index`);
+}
+
 // This is a simplified port of speedscope's profile with a few simplifications and some removed functionality.
 // head at commit e37f6fa7c38c110205e22081560b99cb89ce885e
 
@@ -71,17 +74,25 @@ export class SampledProfile extends Profile {
         ? sortSamples(sampledProfile)
         : stacksWithWeights(sampledProfile);
 
+    // We process each sample in the profile while maintaining a resolved stack of frames.
+    // There is a special case for GC frames where they are appended on top of the previos stack.
+    // By reusing the stack buffer, we avoid creating a new array for each sample and for GC case,
+    // also avoid re-resolving the previous stack frames as they are already in the buffer.
+
+    // If we encounter multiple consecutive GC frames, we will merge them into a single sample
+    // and sum their weights so that only one of them is processed.
+
+    // After we resolve the stack, we call appendSampleWithWeight with the stack buffer, weight
+    // and size of the stack to process. The size indicates how many items from the buffer we want
+    // to process.
+
+    const resolvedStack: Frame[] = new Array(256); // stack size limit
+
     for (let i = 0; i < samples.length; i++) {
       const stack = samples[i].stack;
       let weight = samples[i].weight;
-
-      let resolvedStack = stack.map(n => {
-        if (!frameIndex[n]) {
-          throw new Error(`Could not resolve frame ${n} in frame index`);
-        }
-
-        return frameIndex[n];
-      });
+      let size = samples[i].stack.length;
+      let useCurrentStack = true;
 
       if (
         options.type === 'flamechart' &&
@@ -91,20 +102,16 @@ export class SampledProfile extends Profile {
         // There is a good chance that this logic will at some point live on the backend
         // and when that happens, we do not want to enter this case as the GC will already
         // be placed at the top of the previous stack and the new stack length will be > 2
-        resolvedStack.length <= 2 &&
-        resolvedStack[resolvedStack.length - 1]?.name ===
-          '(garbage collector) [native code]'
+        stack.length <= 2 &&
+        frameIndex[stack[stack.length - 1]]?.name === '(garbage collector) [native code]'
       ) {
-        // The next stack we append will be previous stack + gc frame placed on top of it
-        resolvedStack = samples[i - 1].stack
-          .map(n => {
-            if (!frameIndex[n]) {
-              throw new Error(`Could not resolve frame ${n} in frame index`);
-            }
-
-            return frameIndex[n];
-          })
-          .concat(resolvedStack[resolvedStack.length - 1]);
+        // We have a GC frame, so we will use the previous stack
+        useCurrentStack = false;
+        // The next stack we will process will be the previous stack + our new gc frame.
+        // We write the GC frame on top of the previous stack and set the size to the new stack length.
+        resolvedStack[samples[i - 1].stack.length] = frameIndex[stack[stack.length - 1]];
+        // Size is not sample[i-1].size + our gc frame
+        size = samples[i - 1].stack.length + 1;
 
         // Now collect all weights of all the consecutive gc frames and skip the samples
         while (
@@ -115,20 +122,28 @@ export class SampledProfile extends Profile {
           // and when that happens, we do not want to enter this case as the GC will already
           // be placed at the top of the previous stack and the new stack length will be > 2
           samples[i + 1].stack.length <= 2 &&
-          frameIndex[samples[i + 1][samples[i + 1].stack.length - 1]]?.name ===
+          frameIndex[samples[i + 1].stack[samples[i + 1].stack.length - 1]]?.name ===
             '(garbage collector) [native code]'
         ) {
-          weight += sampledProfile.weights[++i];
+          weight += samples[++i].weight;
+        }
+      }
+
+      // If we are using the current stack, then we need to resolve the frames,
+      // else the processed frames will be the frames that were previously resolved
+      if (useCurrentStack) {
+        for (let j = 0; j < stack.length; j++) {
+          resolvedStack[j] = frameIndex[stack[j]] ?? throwIfMissingFrame(stack[j]);
         }
       }
 
-      profile.appendSampleWithWeight(resolvedStack, weight);
+      profile.appendSampleWithWeight(resolvedStack, weight, size);
     }
 
     return profile.build();
   }
 
-  appendSampleWithWeight(stack: Frame[], weight: number): void {
+  appendSampleWithWeight(stack: Frame[], weight: number, end: number): void {
     // Keep track of discarded samples and ones that may have negative weights
     this.trackSampleStats(weight);
 
@@ -140,8 +155,9 @@ export class SampledProfile extends Profile {
     let node = this.callTree;
     const framesInStack: CallTreeNode[] = [];
 
-    for (const frame of stack) {
-      const last = lastOfArray(node.children);
+    for (let i = 0; i < end; i++) {
+      const frame = stack[i];
+      const last = node.children[node.children.length - 1];
       // Find common frame between two stacks
       if (last && !last.isLocked() && last.frame === frame) {
         node = last;
@@ -167,7 +183,7 @@ export class SampledProfile extends Profile {
         start--;
       }
 
-      framesInStack.push(node);
+      framesInStack[i] = node;
     }
 
     node.addToSelfWeight(weight);
@@ -188,7 +204,7 @@ export class SampledProfile extends Profile {
     }
 
     // If node is the same as the previous sample, add the weight to the previous sample
-    if (node === lastOfArray(this.samples)) {
+    if (node === this.samples[this.samples.length - 1]) {
       this.weights[this.weights.length - 1] += weight;
     } else {
       this.samples.push(node);

+ 27 - 43
yarn.lock

@@ -2437,15 +2437,6 @@
     "@sentry/utils" "7.36.0"
     tslib "^1.9.3"
 
-"@sentry/core@7.30.0":
-  version "7.30.0"
-  resolved "https://registry.yarnpkg.com/@sentry/core/-/core-7.30.0.tgz#02d2e8747484ba64b6d712e8afe6736250efdc26"
-  integrity sha512-NeLigkBlpcK63ymM63GoIHurml6V3BUe1Vi+trwm4/qqOTzT7PQhvdJCX+o3+atzRBH+zdb6kd4VWx44Oye3KA==
-  dependencies:
-    "@sentry/types" "7.30.0"
-    "@sentry/utils" "7.30.0"
-    tslib "^1.9.3"
-
 "@sentry/core@7.36.0":
   version "7.36.0"
   resolved "https://registry.yarnpkg.com/@sentry/core/-/core-7.36.0.tgz#37c82a1ad3f74dbe2c2fcd55f45068e127012fcc"
@@ -2455,14 +2446,14 @@
     "@sentry/utils" "7.36.0"
     tslib "^1.9.3"
 
-"@sentry/hub@^7.16.0":
-  version "7.30.0"
-  resolved "https://registry.yarnpkg.com/@sentry/hub/-/hub-7.30.0.tgz#8de3d6841a799ccc000adeba3279e6519b605119"
-  integrity sha512-rQLqSKK/73/3jes9zMqhbVYY+8QkegLxiYn3QgAUMhnYyYXiGO6KtAk72TNLYCV9hG/sAdWBQmBeqtyoo3AhYw==
+"@sentry/hub@^7.34.0":
+  version "7.36.0"
+  resolved "https://registry.yarnpkg.com/@sentry/hub/-/hub-7.36.0.tgz#275d910822c276c7b0b0f6253196a5acabcb06a5"
+  integrity sha512-1vjox2DFhng1Tz7lZnH4EfpwWj7fLNLdwvFnWIdDxVDNhUJZI+uFMEAXgrIFj1sQlS3LYBz4n2TgxIoAwIMZGg==
   dependencies:
-    "@sentry/core" "7.30.0"
-    "@sentry/types" "7.30.0"
-    "@sentry/utils" "7.30.0"
+    "@sentry/core" "7.36.0"
+    "@sentry/types" "7.36.0"
+    "@sentry/utils" "7.36.0"
     tslib "^1.9.3"
 
 "@sentry/integrations@7.36.0":
@@ -2480,7 +2471,7 @@
   resolved "https://registry.yarnpkg.com/@sentry/jest-environment/-/jest-environment-4.0.0-alpha.1.tgz#7748e75ff212900308b690eb5356f31ea91765f8"
   integrity sha512-VxfW1gxLGPBf9yLGmWBYjMsBOC+UUs0wzvRor01aAwHZ5f7aMgSnzjZLVgAza26YnYvhyCP8y66DWhTL9a2QiA==
 
-"@sentry/node@7.36.0", "@sentry/node@^7.16.0":
+"@sentry/node@7.36.0", "@sentry/node@^7.34.0":
   version "7.36.0"
   resolved "https://registry.yarnpkg.com/@sentry/node/-/node-7.36.0.tgz#7c42a6a2f4d979563c1c595ccd5a0c6d5b5abc19"
   integrity sha512-nAHAY+Rbn5OlTpNX/i6wYrmw3hT/BtwPZ/vNU52cKgw7CpeE1UrCeFjnPn18rQPB7lIh7x0vNvoaPrfemRzpSQ==
@@ -2493,16 +2484,17 @@
     lru_map "^0.3.3"
     tslib "^1.9.3"
 
-"@sentry/profiling-node@^0.0.12":
-  version "0.0.12"
-  resolved "https://registry.yarnpkg.com/@sentry/profiling-node/-/profiling-node-0.0.12.tgz#e8dca42f90c5134ef486408d736aca3628575737"
-  integrity sha512-mC4HdadpXWK71FwA6LdrFPoaROeMgFrj8tZnwXwVrndCAFCA65Go055/ICLV0QHXtd0lt6QPdspsifvSvZhFqQ==
-  dependencies:
-    "@sentry/hub" "^7.16.0"
-    "@sentry/node" "^7.16.0"
-    "@sentry/tracing" "^7.16.0"
-    "@sentry/types" "^7.16.0"
-    "@sentry/utils" "^7.16.0"
+"@sentry/profiling-node@^0.1.0":
+  version "0.1.0"
+  resolved "https://registry.yarnpkg.com/@sentry/profiling-node/-/profiling-node-0.1.0.tgz#1cf770d2472688129f24044fc42ac36ede8571df"
+  integrity sha512-0VHGOAWpHhtFc4vnBcHZUNGwvvcGwH6Lw1dyjv82Trnw1oZ8QTI47Hy/xURK0ThNM3WW9+LLwQcIoc6ZFFntTw==
+  dependencies:
+    "@sentry/hub" "^7.34.0"
+    "@sentry/node" "^7.34.0"
+    "@sentry/tracing" "^7.34.0"
+    "@sentry/types" "^7.34.0"
+    "@sentry/utils" "^7.34.0"
+    detect-libc "^2.0.1"
     nan "^2.17.0"
     node-abi "^3.28.0"
     node-gyp "^9.3.0"
@@ -2532,7 +2524,7 @@
     "@sentry/types" "7.36.0"
     "@sentry/utils" "7.36.0"
 
-"@sentry/tracing@7.36.0", "@sentry/tracing@^7.16.0":
+"@sentry/tracing@7.36.0", "@sentry/tracing@^7.34.0":
   version "7.36.0"
   resolved "https://registry.yarnpkg.com/@sentry/tracing/-/tracing-7.36.0.tgz#aa38319ed07f3b642134cf47da81f43df7835629"
   integrity sha512-5R5mfWMDncOcTMmmyYMjgus1vZJzIFw4LHaSbrX7e1IRNT/6vFyNeVxATa2ePXb9mI3XHo5f2p7YrnreAtaSXw==
@@ -2542,25 +2534,12 @@
     "@sentry/utils" "7.36.0"
     tslib "^1.9.3"
 
-"@sentry/types@7.30.0":
-  version "7.30.0"
-  resolved "https://registry.yarnpkg.com/@sentry/types/-/types-7.30.0.tgz#fc2baeb5b0e1ecc4d52b07b056fcba54449cd9ce"
-  integrity sha512-l4A86typvt/SfWh5JffpdxNGkg5EEA8m35BzpIcKmCAQZUDmnb4b478r8jdD2uuOjLmPNmZr1tifdRW4NCLuxQ==
-
-"@sentry/types@7.36.0", "@sentry/types@^7.16.0":
+"@sentry/types@7.36.0", "@sentry/types@^7.34.0":
   version "7.36.0"
   resolved "https://registry.yarnpkg.com/@sentry/types/-/types-7.36.0.tgz#205baaf7332ff55d1fb35413cbde16dea4168520"
   integrity sha512-uvfwUn3okAWSZ948D/xqBrkc3Sn6TeHUgi3+p/dTTNGAXXskzavgfgQ4rSW7f3YD4LL+boZojpoIARVLodMGuA==
 
-"@sentry/utils@7.30.0":
-  version "7.30.0"
-  resolved "https://registry.yarnpkg.com/@sentry/utils/-/utils-7.30.0.tgz#1d83145399c65e31f725c1b6ae02f451a990f326"
-  integrity sha512-tSlBhr5u/LdE2emxIDTDmjmyRr99GnZGIAh5GwRxUgeDQ3VEfNUFlyFodBCbZ6yeYTYd6PWNih5xoHn1+Rf3Sw==
-  dependencies:
-    "@sentry/types" "7.30.0"
-    tslib "^1.9.3"
-
-"@sentry/utils@7.36.0", "@sentry/utils@^7.16.0":
+"@sentry/utils@7.36.0", "@sentry/utils@^7.34.0":
   version "7.36.0"
   resolved "https://registry.yarnpkg.com/@sentry/utils/-/utils-7.36.0.tgz#b81cf63c7b5daad3f0f152c4ad319203f968ba1b"
   integrity sha512-mgDi5X5Bm0sydCzXpnyKD/sD98yc2qnKXyRdNX4HRRwruhC/P53LT0hGhZXsyqsB/l8OAMl0zWXJLg0xONQsEw==
@@ -6673,6 +6652,11 @@ detab@2.0.4:
   dependencies:
     repeat-string "^1.5.4"
 
+detect-libc@^2.0.1:
+  version "2.0.1"
+  resolved "https://registry.yarnpkg.com/detect-libc/-/detect-libc-2.0.1.tgz#e1897aa88fa6ad197862937fbc0441ef352ee0cd"
+  integrity sha512-463v3ZeIrcWtdgIg6vI6XUncguvr2TnGl4SzDXinkt9mSLpBJKXT3mW6xT3VQdDN11+WVs29pgvivTc4Lp8v+w==
+
 detect-newline@^3.0.0:
   version "3.1.0"
   resolved "https://registry.yarnpkg.com/detect-newline/-/detect-newline-3.1.0.tgz#576f5dfc63ae1a192ff192d8ad3af6308991b651"

Some files were not shown because too many files changed in this diff