Merge pull request #19989 from backstage/rugvip/lazylog

backend-common: lazy root logger initialization

.changeset/friendly-teachers-attend.md

@@ -0,0 +1,5 @@
+---
+'@backstage/backend-common': patch
+---
+
+The root logger is now initialized lazily, fixing a circular dependency issue with `@backstage/backend-app-api` that would result in `Cannot read properties of undefined (reading 'redacter')`.

packages/backend-common/src/logging/createRootLogger.ts

@@ -17,12 +17,26 @@
 import { WinstonLogger } from '@backstage/backend-app-api';
 import { merge } from 'lodash';
 import * as winston from 'winston';
-import { LoggerOptions } from 'winston';
+import { format, LoggerOptions } from 'winston';
 import { setRootLogger } from './globalLoggers';
+import { TransformableInfo } from 'logform';
 
-const redacter = WinstonLogger.redacter();
+const getRedacter = (() => {
+  let redacter: ReturnType<typeof WinstonLogger.redacter> | undefined =
+    undefined;
+  return () => {
+    if (!redacter) {
+      redacter = WinstonLogger.redacter();
+    }
+    return redacter;
+  };
+})();
 
-export const setRootLoggerRedactionList = redacter.add;
+export const setRootLoggerRedactionList = (
+  redactions: Iterable<string>,
+): void => {
+  getRedacter().add(redactions);
+};
 
 /**
  * A winston formatting function that finds occurrences of filteredKeys
@@ -33,15 +47,44 @@ export const setRootLoggerRedactionList = redacter.add;
 export function redactWinstonLogLine(
   info: winston.Logform.TransformableInfo,
 ): winston.Logform.TransformableInfo {
-  return redacter.format.transform(info) as winston.Logform.TransformableInfo;
+  return getRedacter().format.transform(
+    info,
+  ) as winston.Logform.TransformableInfo;
 }
 
+const colorizer = format.colorize();
+
+// NOTE: This is a copy of the WinstonLogger.colorFormat to avoid a circular dependency
 /**
  * Creates a pretty printed winston log formatter.
  *
  * @public
  */
-export const coloredFormat = WinstonLogger.colorFormat();
+export const coloredFormat = format.combine(
+  format.timestamp(),
+  format.colorize({
+    colors: {
+      timestamp: 'dim',
+      prefix: 'blue',
+      field: 'cyan',
+      debug: 'grey',
+    },
+  }),
+  format.printf((info: TransformableInfo) => {
+    const { timestamp, level, message, plugin, service, ...fields } = info;
+    const prefix = plugin || service;
+    const timestampColor = colorizer.colorize('timestamp', timestamp);
+    const prefixColor = colorizer.colorize('prefix', prefix);
+
+    const extraFields = Object.entries(fields)
+      .map(
+        ([key, value]) => `${colorizer.colorize('field', `${key}`)}=${value}`,
+      )
+      .join(' ');
+
+    return `${timestampColor} ${prefixColor} ${level} ${message} ${extraFields}`;
+  }),
+);
 
 /**
  * Creates a default "root" logger. This also calls {@link setRootLogger} under
@@ -64,7 +107,7 @@ export function createRootLogger(
         {
           level: env.LOG_LEVEL || 'info',
           format: winston.format.combine(
-            redacter.format,
+            getRedacter().format,
             env.NODE_ENV === 'production'
               ? winston.format.json()
               : WinstonLogger.colorFormat(),
@@ -84,5 +127,3 @@ export function createRootLogger(
 
   return logger;
 }
-
-setRootLogger(createRootLogger());

packages/backend-common/src/logging/globalLoggers.ts

@@ -15,6 +15,7 @@
  */
 
 import * as winston from 'winston';
+import { createRootLogger } from './createRootLogger';
 
 /**
  * A logger that just throws away all messages.
@@ -35,6 +36,9 @@ let rootLogger: winston.Logger;
  * @public
  */
 export function getRootLogger(): winston.Logger {
+  if (!rootLogger) {
+    rootLogger = createRootLogger();
+  }
   return rootLogger;
 }
 

plugins/app-backend/src/service/appPlugin.test.ts

@@ -19,6 +19,10 @@ import { resolve as resolvePath } from 'path';
 import fetch from 'node-fetch';
 import { mockServices, startTestBackend } from '@backstage/backend-test-utils';
 import { appPlugin } from './appPlugin';
+import { createRootLogger } from '@backstage/backend-common';
+
+// Make sure root logger is initialized ahead of FS mock
+createRootLogger();
 
 describe('appPlugin', () => {
   beforeEach(() => {

plugins/scaffolder-backend/src/scaffolder/actions/builtin/publish/githubPullRequest.test.ts

@@ -14,7 +14,7 @@
  * limitations under the License.
  */
 
-import { getRootLogger } from '@backstage/backend-common';
+import { createRootLogger, getRootLogger } from '@backstage/backend-common';
 import { ConfigReader } from '@backstage/config';
 import {
   GithubCredentialsProvider,
@@ -33,6 +33,9 @@ import {
   OctokitWithPullRequestPluginClient,
 } from './githubPullRequest';
 
+// Make sure root logger is initialized ahead of FS mock
+createRootLogger();
+
 const root = os.platform() === 'win32' ? 'C:\\root' : '/root';
 const workspacePath = resolvePath(root, 'my-workspace');
 

plugins/scaffolder-backend/src/scaffolder/actions/builtin/publish/gitlabMergeRequest.test.ts

@@ -13,7 +13,7 @@
  * See the License for the specific language governing permissions and
  * limitations under the License.
  */
-import { getRootLogger } from '@backstage/backend-common';
+import { createRootLogger, getRootLogger } from '@backstage/backend-common';
 import { ConfigReader } from '@backstage/config';
 import { ScmIntegrations } from '@backstage/integration';
 import { TemplateAction } from '@backstage/plugin-scaffolder-node';
@@ -23,6 +23,9 @@ import { resolve as resolvePath } from 'path';
 import { Writable } from 'stream';
 import { createPublishGitlabMergeRequestAction } from './gitlabMergeRequest';
 
+// Make sure root logger is initialized ahead of FS mock
+createRootLogger();
+
 const root = os.platform() === 'win32' ? 'C:\\root' : '/root';
 const workspacePath = resolvePath(root, 'my-workspace');