refactor(ivy): improve micro-benchmark profiling (#32647)

PR Close #32647

packages/core/test/render3/perf/element_text_create/index.ts

@@ -74,14 +74,12 @@ resetComponentState();
 createAndRenderLView(null, embeddedTView, viewTNode);
 
 // scenario to benchmark
-const elementTextCreate = createBenchmark('element and text create', 500000, 20);
+const elementTextCreate = createBenchmark('element and text create');
 const createTime = elementTextCreate('create');
 
 console.profile('element_text_create');
-while (createTime.run()) {
-  while (createTime()) {
-    createAndRenderLView(null, embeddedTView, viewTNode);
-  }
+while (createTime()) {
+  createAndRenderLView(null, embeddedTView, viewTNode);
 }
 console.profileEnd();
 

packages/core/test/render3/perf/listeners/index.ts

@@ -85,15 +85,13 @@ resetComponentState();
 // create view once so we don't profile first template pass
 createAndRenderLView(null, embeddedTView, viewTNode);
 
-const listenersCreate = createBenchmark('listeners create', 500000, 20);
+const listenersCreate = createBenchmark('listeners create');
 const createTime = listenersCreate('create');
 
 // profile create views (run templates in creation mode)
 console.profile('create listeners');
-while (createTime.run()) {
-  while (createTime()) {
-    createAndRenderLView(null, embeddedTView, viewTNode);
-  }
+while (createTime()) {
+  createAndRenderLView(null, embeddedTView, viewTNode);
 }
 console.profileEnd();
 

packages/core/test/render3/perf/micro_bench.ts

@@ -7,65 +7,95 @@
  */
 const performance = require('perf_hooks').performance;
 
-interface Benchmark {
+const MIN_SAMPLE_COUNT_NO_IMPROVEMENT = 10;
+const MIN_SAMPLE_DURATION = 100;
+
+const UNITS = ['ms', 'us', 'ns', 'ps'];
+export interface Benchmark {
   (versionName: string): Profile;
   report(fn?: (report: string) => void): void;
 }
-interface Profile {
+export interface Profile {
   (): boolean;
   profileName: string;
-  run(): boolean;
   bestTime: number;
+  iterationCount: number;
+  sampleCount: number;
+  noImprovementCount: number;
 }
 
-export function createBenchmark(
-    benchmarkName: string, iterationCount: number, runs: number = 50): Benchmark {
+export function createBenchmark(benchmarkName: string): Benchmark {
   const profiles: Profile[] = [];
 
   const benchmark = function Benchmark(profileName: string): Profile {
-    let iterationCounter: number = iterationCount;
+    let iterationCounter: number = 0;
+    let timestamp: number = 0;
     const profile: Profile = function Profile() {
       if (iterationCounter === 0) {
-        iterationCounter = iterationCount;
-        return false;
+        let runAgain = false;
+        // if we reached the end of the iteration count than we should decide what to do next.
+        if (timestamp === 0) {
+          // this is the first time we are executing
+          iterationCounter = profile.iterationCount;
+          runAgain = true;
+          // console.log('profiling', profileName, '...');
+        } else {
+          profile.sampleCount++;
+          // we came to an end of a sample, compute the time.
+          const duration_ms = performance.now() - timestamp;
+          const iterationTime_ms = duration_ms / profile.iterationCount;
+          if (profile.bestTime > iterationTime_ms) {
+            profile.bestTime = iterationTime_ms;
+            profile.noImprovementCount = 0;
+            runAgain = true;
+          } else {
+            runAgain = (profile.noImprovementCount++) < MIN_SAMPLE_COUNT_NO_IMPROVEMENT;
+          }
+          if (duration_ms < MIN_SAMPLE_DURATION) {
+            // we have not ran for long enough so increase the iteration count.
+            profile.iterationCount <<= 1;
+            profile.noImprovementCount = 0;
+            runAgain = true;
+          }
+          if (!runAgain) {
+            // console.log('   Sample count:', profile.sampleCount, 'iterations',
+            // profile.iterationCount, 'time (ms):',  iterationTime_ms);
+          }
+        }
+        iterationCounter = profile.iterationCount;
+        timestamp = performance.now();
+        return runAgain;
       } else {
+        // this is the common path and it needs te be quick!
         iterationCounter--;
         return true;
       }
     } as Profile;
-    let lastTimestamp = 0;
-    let runCount = runs;
-    profile.run = function() {
-      const now = performance.now();
-      if (lastTimestamp !== 0) {
-        const time = now - lastTimestamp;
-        profile.bestTime = Math.min(profile.bestTime, time);
-      }
-      lastTimestamp = now;
-      if (runCount === 0) {
-        runCount = runs;
-        return false;
-      } else {
-        runCount--;
-        return true;
-      }
-    };
     profile.profileName = profileName;
     profile.bestTime = Number.MAX_SAFE_INTEGER;
+    profile.iterationCount = 1;
+    profile.noImprovementCount = 0;
+    profile.sampleCount = 0;
     profiles.push(profile);
     return profile;
   } as Benchmark;
 
   benchmark.report = function(fn?: (report: string) => void) {
-    setTimeout(() => {
-      const fastest = profiles.reduce((previous: Profile, current: Profile) => {
-        return (previous.bestTime < current.bestTime) ? previous : current;
-      });
-      (fn || console.log)(`Benchmark: ${benchmarkName}\n${profiles.map((profile: Profile) => {
-        const percent = (100 - profile.bestTime / fastest.bestTime * 100).toFixed(0);
-        return profile.profileName + ': ' + profile.bestTime.toFixed(0) + ` us(${percent} %) `;
-      }).join('\n')}`);
+    const fastest = profiles.reduce((previous: Profile, current: Profile) => {
+      return (previous.bestTime < current.bestTime) ? previous : current;
     });
+    let unitOffset = 0;
+    let time = fastest.bestTime;
+    while (time < 1 && time !== 0) {
+      time = time * 1000;
+      unitOffset++;
+    }
+    let unit: string = UNITS[unitOffset];
+    (fn || console.log)(`Benchmark: ${benchmarkName}\n${profiles.map((profile: Profile) => {
+      const time = (profile.bestTime * Math.pow(1000, unitOffset)).toFixed(3);
+      const percent = (100 - profile.bestTime / fastest.bestTime * 100).toFixed(0);
+      return '  ' + profile.profileName + ': ' + time + ' ' +unit + '(' + percent + '%)';
+    }).join('\n')}`);
   };
   return benchmark;
-}
+}

packages/core/test/render3/perf/property_binding_update/index.ts

@@ -76,17 +76,15 @@ const rootTView = rootLView[TVIEW];
 
 
 // scenario to benchmark
-const propertyBindingBenchmark = createBenchmark('property binding', 2000, 20);
+const propertyBindingBenchmark = createBenchmark('property binding');
 const updateTime = propertyBindingBenchmark('update');
 
 // run change detection where each binding value changes
 console.profile('element property update');
-while (updateTime.run()) {
-  let i = 0;
-  while (updateTime()) {
-    ctx.value = `value${i++}`;
-    refreshView(rootLView, rootTView, null, ctx);
-  }
+let i = 0;
+while (updateTime()) {
+  ctx.value = `value${i++}`;
+  refreshView(rootLView, rootTView, null, ctx);
 }
 console.profileEnd();