From 49cdaf2ac2a71bd32db7d407e63f31a8afe4aa73 Mon Sep 17 00:00:00 2001
From: Sergei Zharinov <zharinov@users.noreply.github.com>
Date: Fri, 3 Feb 2023 10:00:58 +0300
Subject: [PATCH] feat: Support for logging once per repo (#20168)

---
 lib/logger/index.ts                           |  19 ++-
 lib/logger/once.spec.ts                       | 139 ++++++++++++++++++
 lib/logger/once.ts                            |  59 ++++++++
 lib/logger/types.ts                           |   4 +
 .../repository/dependency-dashboard.spec.ts   |   1 +
 lib/workers/repository/init/index.ts          |   1 +
 test/setup.ts                                 |   2 +-
 7 files changed, 221 insertions(+), 4 deletions(-)
 create mode 100644 lib/logger/once.spec.ts
 create mode 100644 lib/logger/once.ts

diff --git a/lib/logger/index.ts b/lib/logger/index.ts
index bd0b5dffc1..43add78c9f 100644
--- a/lib/logger/index.ts
+++ b/lib/logger/index.ts
@@ -4,6 +4,7 @@ import { nanoid } from 'nanoid';
 import cmdSerializer from './cmd-serializer';
 import configSerializer from './config-serializer';
 import errSerializer from './err-serializer';
+import { once, reset as onceReset } from './once';
 import { RenovateStream } from './pretty-stdout';
 import type { BunyanRecord, Logger } from './types';
 import { ProblemStream, validateLogLevel, withSanitizer } from './utils';
@@ -61,7 +62,7 @@ const bunyanLogger = bunyan.createLogger({
 });
 
 const logFactory =
-  (level: bunyan.LogLevelString): any =>
+  (level: bunyan.LogLevelString) =>
   (p1: any, p2: any): void => {
     if (p2) {
       // meta and msg provided
@@ -84,10 +85,22 @@ const loggerLevels: bunyan.LogLevelString[] = [
   'fatal',
 ];
 
-export const logger: Logger = {} as any;
+export const logger: Logger = { once: { reset: onceReset } } as any;
 
 loggerLevels.forEach((loggerLevel) => {
-  logger[loggerLevel] = logFactory(loggerLevel);
+  logger[loggerLevel] = logFactory(loggerLevel) as never;
+
+  const logOnceFn = (p1: any, p2: any): void => {
+    once(() => {
+      const logFn = logger[loggerLevel];
+      if (is.undefined(p2)) {
+        logFn(p1);
+      } else {
+        logFn(p1, p2);
+      }
+    }, logOnceFn);
+  };
+  logger.once[loggerLevel] = logOnceFn as never;
 });
 
 export function setContext(value: string): void {
diff --git a/lib/logger/once.spec.ts b/lib/logger/once.spec.ts
new file mode 100644
index 0000000000..64523e2120
--- /dev/null
+++ b/lib/logger/once.spec.ts
@@ -0,0 +1,139 @@
+import { once, reset } from './once';
+import { logger } from '.';
+
+jest.unmock('.');
+
+describe('logger/once', () => {
+  afterEach(() => {
+    reset();
+  });
+
+  describe('core', () => {
+    it('should call a function only once', () => {
+      const innerFn = jest.fn();
+
+      function outerFn() {
+        once(innerFn);
+      }
+
+      outerFn();
+      outerFn();
+      outerFn();
+      expect(innerFn).toHaveBeenCalledTimes(1);
+    });
+
+    it('supports support distinct calls', () => {
+      const innerFn1 = jest.fn();
+      const innerFn2 = jest.fn();
+
+      function outerFn() {
+        once(innerFn1);
+        once(innerFn2);
+      }
+
+      outerFn();
+      outerFn();
+      outerFn();
+      expect(innerFn1).toHaveBeenCalledTimes(1);
+      expect(innerFn2).toHaveBeenCalledTimes(1);
+    });
+
+    it('resets keys', () => {
+      const innerFn = jest.fn();
+
+      function outerFn() {
+        once(innerFn);
+      }
+
+      outerFn();
+      reset();
+      outerFn();
+
+      expect(innerFn).toHaveBeenCalledTimes(2);
+    });
+  });
+
+  describe('logger', () => {
+    it('logs once per function call', () => {
+      const debug = jest.spyOn(logger, 'debug');
+
+      function doSomething() {
+        logger.once.debug('test');
+      }
+
+      doSomething();
+      doSomething();
+      doSomething();
+      expect(debug).toHaveBeenCalledTimes(1);
+    });
+
+    it('distincts between log levels', () => {
+      const debug = jest.spyOn(logger, 'debug');
+      const info = jest.spyOn(logger, 'info');
+
+      function doSomething() {
+        logger.once.debug('test');
+        logger.once.info('test');
+      }
+
+      doSomething();
+      doSomething();
+      doSomething();
+      expect(debug).toHaveBeenCalledTimes(1);
+      expect(info).toHaveBeenCalledTimes(1);
+    });
+
+    it('distincts between different log statements', () => {
+      const debug = jest.spyOn(logger, 'debug');
+
+      function doSomething() {
+        logger.once.debug('foo');
+        logger.once.debug('bar');
+        logger.once.debug('baz');
+      }
+
+      doSomething();
+      doSomething();
+      doSomething();
+      expect(debug).toHaveBeenNthCalledWith(1, 'foo');
+      expect(debug).toHaveBeenNthCalledWith(2, 'bar');
+      expect(debug).toHaveBeenNthCalledWith(3, 'baz');
+    });
+
+    it('allows mixing single-time and regular logging', () => {
+      const debug = jest.spyOn(logger, 'debug');
+
+      function doSomething() {
+        logger.once.debug('foo');
+        logger.debug('bar');
+        logger.once.debug({ some: 'data' }, 'baz');
+      }
+
+      doSomething();
+      doSomething();
+      doSomething();
+
+      expect(debug).toHaveBeenNthCalledWith(1, 'foo');
+      expect(debug).toHaveBeenNthCalledWith(2, 'bar');
+      expect(debug).toHaveBeenNthCalledWith(3, { some: 'data' }, 'baz');
+
+      expect(debug).toHaveBeenNthCalledWith(4, 'bar');
+
+      expect(debug).toHaveBeenNthCalledWith(5, 'bar');
+    });
+
+    it('supports reset method', () => {
+      const debug = jest.spyOn(logger, 'debug');
+
+      function doSomething() {
+        logger.once.debug('foo');
+      }
+
+      doSomething();
+      logger.once.reset();
+      doSomething();
+
+      expect(debug).toHaveBeenCalledTimes(2);
+    });
+  });
+});
diff --git a/lib/logger/once.ts b/lib/logger/once.ts
new file mode 100644
index 0000000000..7bb3447b82
--- /dev/null
+++ b/lib/logger/once.ts
@@ -0,0 +1,59 @@
+type OmitFn = (...args: any[]) => any;
+
+/**
+ * Get the single frame of this function's callers stack.
+ *
+ * @param omitFn Starting from this function, stack frames will be ignored.
+ * @returns The string containing file name, line number and column name.
+ *
+ * @example getCallSite() // => 'Object.<anonymous> (/path/to/file.js:10:15)'
+ */
+function getCallSite(omitFn: OmitFn = getCallSite): string | null {
+  const stackTraceLimitOrig = Error.stackTraceLimit;
+  const prepareStackTraceOrig = Error.prepareStackTrace;
+
+  let result: string | null = null;
+  try {
+    const res: { stack: string[] } = { stack: [] };
+
+    Error.stackTraceLimit = 1;
+    Error.prepareStackTrace = (_err, stack) => stack;
+    Error.captureStackTrace(res, omitFn);
+
+    const [callsite] = res.stack;
+    if (callsite) {
+      result = callsite.toString();
+    }
+  } catch (_err) /* istanbul ignore next */ {
+    // no-op
+  } finally {
+    Error.stackTraceLimit = stackTraceLimitOrig;
+    Error.prepareStackTrace = prepareStackTraceOrig;
+  }
+
+  return result;
+}
+
+const keys = new Set<string>();
+
+export function once(callback: () => void, omitFn: OmitFn = once): void {
+  const key = getCallSite(omitFn);
+
+  // istanbul ignore if
+  if (!key) {
+    return;
+  }
+
+  if (!keys.has(key)) {
+    keys.add(key);
+    callback();
+  }
+}
+
+/**
+ * Before processing each repository,
+ * all keys are supposed to be reset.
+ */
+export function reset(): void {
+  keys.clear();
+}
diff --git a/lib/logger/types.ts b/lib/logger/types.ts
index a4fa07fe2d..4e0fd628e1 100644
--- a/lib/logger/types.ts
+++ b/lib/logger/types.ts
@@ -20,6 +20,10 @@ export interface Logger {
   error(meta: Record<string, any>, msg?: string): void;
   fatal(msg: string): void;
   fatal(meta: Record<string, any>, msg?: string): void;
+
+  once: Logger & {
+    reset: () => void;
+  };
 }
 
 export interface BunyanRecord extends Record<string, any> {
diff --git a/lib/workers/repository/dependency-dashboard.spec.ts b/lib/workers/repository/dependency-dashboard.spec.ts
index f2a748c7f2..6170c3dcdc 100644
--- a/lib/workers/repository/dependency-dashboard.spec.ts
+++ b/lib/workers/repository/dependency-dashboard.spec.ts
@@ -161,6 +161,7 @@ describe('workers/repository/dependency-dashboard', () => {
     beforeEach(() => {
       PackageFiles.add('main', null);
       GlobalConfig.reset();
+      logger.getProblems.mockReturnValue([]);
     });
 
     it('do nothing if dependencyDashboard is disabled', async () => {
diff --git a/lib/workers/repository/init/index.ts b/lib/workers/repository/init/index.ts
index c07d0ef73b..89296f134f 100644
--- a/lib/workers/repository/init/index.ts
+++ b/lib/workers/repository/init/index.ts
@@ -33,6 +33,7 @@ export async function initRepo(
   PackageFiles.clear();
   let config: RenovateConfig = initializeConfig(config_);
   await resetCaches();
+  logger.once.reset();
   config = await initApis(config);
   await initializeCaches(config as WorkerPlatformConfig);
   config = await getRepoConfig(config);
diff --git a/test/setup.ts b/test/setup.ts
index 7a4b2a9fde..959b6c5b1c 100644
--- a/test/setup.ts
+++ b/test/setup.ts
@@ -21,7 +21,7 @@ jest.mock('../lib/modules/platform', () => ({
   initPlatform: jest.fn(),
   getPlatformList: jest.fn(),
 }));
-jest.mock('../lib/logger');
+jest.mock('../lib/logger', () => jest.createMockFromModule('../lib/logger'));
 
 //------------------------------------------------
 // Required global jest types
-- 
GitLab