refactor: Create utility for stats collection and reporting (#27919)

lib/util/stats.spec.ts

@@ -0,0 +1,132 @@
+import { logger } from '../../test/util';
+import * as memCache from './cache/memory';
+import { LookupStats, makeTimingReport } from './stats';
+
+describe('util/stats', () => {
+  beforeEach(() => {
+    memCache.init();
+  });
+
+  describe('makeTimingReport', () => {
+    it('supports empty data', () => {
+      const res = makeTimingReport([]);
+      expect(res).toEqual({
+        avgMs: 0,
+        count: 0,
+        maxMs: 0,
+        medianMs: 0,
+        totalMs: 0,
+      });
+    });
+
+    it('supports single data point', () => {
+      const res = makeTimingReport([100]);
+      expect(res).toEqual({
+        avgMs: 100,
+        count: 1,
+        maxMs: 100,
+        medianMs: 100,
+        totalMs: 100,
+      });
+    });
+
+    it('supports multiple data points', () => {
+      const res = makeTimingReport([100, 200, 400]);
+      expect(res).toEqual({
+        avgMs: 233,
+        count: 3,
+        maxMs: 400,
+        medianMs: 200,
+        totalMs: 700,
+      });
+    });
+  });
+
+  describe('LookupStats', () => {
+    beforeEach(() => {
+      jest.useFakeTimers();
+    });
+
+    afterEach(() => {
+      jest.useRealTimers();
+    });
+
+    it('returns empty report', () => {
+      const res = LookupStats.getReport();
+      expect(res).toEqual({});
+    });
+
+    it('writes data points', () => {
+      LookupStats.write('npm', 100);
+      LookupStats.write('npm', 200);
+      LookupStats.write('npm', 400);
+      LookupStats.write('docker', 1000);
+
+      const res = LookupStats.getReport();
+
+      expect(res).toEqual({
+        docker: {
+          avgMs: 1000,
+          count: 1,
+          maxMs: 1000,
+          medianMs: 1000,
+          totalMs: 1000,
+        },
+        npm: {
+          avgMs: 233,
+          count: 3,
+          maxMs: 400,
+          medianMs: 200,
+          totalMs: 700,
+        },
+      });
+    });
+
+    it('wraps a function', async () => {
+      const res = await LookupStats.wrap('npm', () => {
+        jest.advanceTimersByTime(100);
+        return Promise.resolve('foo');
+      });
+
+      expect(res).toBe('foo');
+      expect(LookupStats.getReport()).toEqual({
+        npm: {
+          avgMs: 100,
+          count: 1,
+          maxMs: 100,
+          medianMs: 100,
+          totalMs: 100,
+        },
+      });
+    });
+
+    it('logs report', () => {
+      LookupStats.write('npm', 100);
+      LookupStats.write('npm', 200);
+      LookupStats.write('npm', 400);
+      LookupStats.write('docker', 1000);
+
+      LookupStats.report();
+
+      expect(logger.logger.debug).toHaveBeenCalledTimes(1);
+      const [data, msg] = logger.logger.debug.mock.calls[0];
+      expect(msg).toBe('Lookup statistics');
+      expect(data).toEqual({
+        docker: {
+          avgMs: 1000,
+          count: 1,
+          maxMs: 1000,
+          medianMs: 1000,
+          totalMs: 1000,
+        },
+        npm: {
+          avgMs: 233,
+          count: 3,
+          maxMs: 400,
+          medianMs: 200,
+          totalMs: 700,
+        },
+      });
+    });
+  });
+});

lib/util/stats.ts

@@ -0,0 +1,56 @@
+import { logger } from '../logger';
+import * as memCache from './cache/memory';
+
+type LookupStatsData = Record<string, number[]>;
+
+interface TimingStatsReport {
+  count: number;
+  avgMs: number;
+  medianMs: number;
+  maxMs: number;
+  totalMs: number;
+}
+
+export function makeTimingReport(data: number[]): TimingStatsReport {
+  const count = data.length;
+  const totalMs = data.reduce((a, c) => a + c, 0);
+  const avgMs = count ? Math.round(totalMs / count) : 0;
+  const maxMs = Math.max(0, ...data);
+  const sorted = data.sort((a, b) => a - b);
+  const medianMs = count ? sorted[Math.floor(count / 2)] : 0;
+  return { count, avgMs, medianMs, maxMs, totalMs };
+}
+
+export class LookupStats {
+  static write(datasource: string, duration: number): void {
+    const data = memCache.get<LookupStatsData>('lookup-stats') ?? {};
+    data[datasource] ??= [];
+    data[datasource].push(duration);
+    memCache.set('lookup-stats', data);
+  }
+
+  static async wrap<T>(
+    datasource: string,
+    callback: () => Promise<T>,
+  ): Promise<T> {
+    const start = Date.now();
+    const result = await callback();
+    const duration = Date.now() - start;
+    LookupStats.write(datasource, duration);
+    return result;
+  }
+
+  static getReport(): Record<string, TimingStatsReport> {
+    const report: Record<string, TimingStatsReport> = {};
+    const data = memCache.get<LookupStatsData>('lookup-stats') ?? {};
+    for (const [datasource, durations] of Object.entries(data)) {
+      report[datasource] = makeTimingReport(durations);
+    }
+    return report;
+  }
+
+  static report(): void {
+    const report = LookupStats.getReport();
+    logger.debug(report, 'Lookup statistics');
+  }
+}

lib/workers/repository/index.ts

@@ -19,6 +19,7 @@ import { clearDnsCache, printDnsStats } from '../../util/http/dns';
 import * as queue from '../../util/http/queue';
 import * as throttle from '../../util/http/throttle';
 import { addSplit, getSplits, splitInit } from '../../util/split';
+import { LookupStats } from '../../util/stats';
 import { setBranchCache } from './cache';
 import { extractRepoProblems } from './common';
 import { ensureDependencyDashboard } from './dependency-dashboard';
@@ -31,7 +32,7 @@ import { ensureOnboardingPr } from './onboarding/pr';
 import { extractDependencies, updateRepo } from './process';
 import type { ExtractResult } from './process/extract-update';
 import { ProcessResult, processResult } from './result';
-import { printLookupStats, printRequestStats } from './stats';
+import { printRequestStats } from './stats';
 
 // istanbul ignore next
 export async function renovateRepository(
@@ -125,7 +126,7 @@ export async function renovateRepository(
   const splits = getSplits();
   logger.debug(splits, 'Repository timing splits (milliseconds)');
   printRequestStats();
-  printLookupStats();
+  LookupStats.report();
   printDnsStats();
   clearDnsCache();
   const cloned = isCloned();

lib/workers/repository/process/fetch.ts

@@ -10,29 +10,15 @@ import type {
   PackageFile,
 } from '../../../modules/manager/types';
 import { ExternalHostError } from '../../../types/errors/external-host-error';
-import * as memCache from '../../../util/cache/memory';
-import type { LookupStats } from '../../../util/cache/memory/types';
 import { clone } from '../../../util/clone';
 import { applyPackageRules } from '../../../util/package-rules';
 import * as p from '../../../util/promises';
 import { Result } from '../../../util/result';
+import { LookupStats } from '../../../util/stats';
 import { PackageFiles } from '../package-files';
 import { lookupUpdates } from './lookup';
 import type { LookupUpdateConfig } from './lookup/types';
 
-async function withLookupStats<T>(
-  datasource: string,
-  callback: () => Promise<T>,
-): Promise<T> {
-  const start = Date.now();
-  const result = await callback();
-  const duration = Date.now() - start;
-  const lookups = memCache.get<LookupStats[]>('lookup-stats') || [];
-  lookups.push({ datasource, duration });
-  memCache.set('lookup-stats', lookups);
-  return result;
-}
-
 async function fetchDepUpdates(
   packageFileConfig: RenovateConfig & PackageFile,
   indep: PackageDependency,
@@ -69,7 +55,7 @@ async function fetchDepUpdates(
     dep.skipReason = 'disabled';
   } else {
     if (depConfig.datasource) {
-      const { val: updateResult, err } = await withLookupStats(
+      const { val: updateResult, err } = await LookupStats.wrap(
         depConfig.datasource,
         () =>
           Result.wrap(lookupUpdates(depConfig as LookupUpdateConfig)).unwrap(),

lib/workers/repository/stats.spec.ts

@@ -1,8 +1,7 @@
 import { logger } from '../../../test/util';
 import type { Logger } from '../../logger/types';
 import * as memCache from '../../util/cache/memory';
-import type { LookupStats } from '../../util/cache/memory/types';
-import { printLookupStats, printRequestStats } from './stats';
+import { printRequestStats } from './stats';
 
 const log = logger.logger as jest.Mocked<Logger>;
 
@@ -11,44 +10,6 @@ describe('workers/repository/stats', () => {
     memCache.init();
   });
 
-  describe('printLookupStats()', () => {
-    it('runs', () => {
-      const stats: LookupStats[] = [
-        {
-          datasource: 'npm',
-          duration: 100,
-        },
-        {
-          datasource: 'npm',
-          duration: 200,
-        },
-        {
-          datasource: 'docker',
-          duration: 1000,
-        },
-      ];
-      memCache.set('lookup-stats', stats);
-      expect(printLookupStats()).toBeUndefined();
-      expect(log.debug).toHaveBeenCalledTimes(1);
-      expect(log.debug.mock.calls[0][0]).toMatchInlineSnapshot(`
-        {
-          "docker": {
-            "averageMs": 1000,
-            "count": 1,
-            "maximumMs": 1000,
-            "totalMs": 1000,
-          },
-          "npm": {
-            "averageMs": 150,
-            "count": 2,
-            "maximumMs": 200,
-            "totalMs": 300,
-          },
-        }
-      `);
-    });
-  });
-
   describe('printRequestStats()', () => {
     it('runs', () => {
       memCache.set('package-cache-gets', [30, 100, 10, 20]);

lib/workers/repository/stats.ts

@@ -2,7 +2,6 @@ import URL from 'node:url';
 import { logger } from '../../logger';
 import { sortNumeric } from '../../util/array';
 import * as memCache from '../../util/cache/memory';
-import type { LookupStats } from '../../util/cache/memory/types';
 import type { RequestStats } from '../../util/http/types';
 
 interface CacheStats {
@@ -13,24 +12,6 @@ interface CacheStats {
   totalMs?: number;
 }
 
-export function printLookupStats(): void {
-  const lookups = memCache.get<LookupStats[]>('lookup-stats') ?? [];
-  const datasourceDurations: Record<string, number[]> = {};
-  for (const lookup of lookups) {
-    datasourceDurations[lookup.datasource] ??= [];
-    datasourceDurations[lookup.datasource].push(lookup.duration);
-  }
-  const data: Record<string, unknown> = {};
-  for (const [datasource, durations] of Object.entries(datasourceDurations)) {
-    const count = durations.length;
-    const totalMs = durations.reduce((a, c) => a + c, 0);
-    const averageMs = Math.round(totalMs / count);
-    const maximumMs = Math.max(...durations);
-    data[datasource] = { count, averageMs, totalMs, maximumMs };
-  }
-  logger.debug(data, 'Package lookup durations');
-}
-
 export function printRequestStats(): void {
   const packageCacheGets = (
     memCache.get<number[]>('package-cache-gets') ?? []