Merge pull request #23453 from backstage/blam/redact-scaffolder-secrets

scaffolder: Redacting of `secrets` in log streams

.changeset/blue-plums-beam.md

@@ -0,0 +1,5 @@
+---
+'@backstage/plugin-scaffolder-node': minor
+---
+
+**DEPRECATION** - Deprecated the `logStream` in the `ActionContext`. Please move to using `ctx.logger.x` instead.

.changeset/bright-beers-dress.md

@@ -0,0 +1,7 @@
+---
+'@backstage/plugin-scaffolder-backend': minor
+'@backstage/plugin-scaffolder-backend-module-cookiecutter': patch
+'@backstage/plugin-scaffolder-backend-module-rails': patch
+---
+
+Move away from using `ctx.logStream`

.changeset/real-cows-flow.md

@@ -0,0 +1,5 @@
+---
+'@backstage/plugin-scaffolder-backend': minor
+---
+
+Enable the redaction of secrets using the redacting logger and the secrets from the `TaskSpec`

plugins/scaffolder-backend-module-cookiecutter/src/actions/fetch/cookiecutter.test.ts

@@ -23,6 +23,7 @@ import { createFetchCookiecutterAction } from './cookiecutter';
 import { join } from 'path';
 import type { ActionContext } from '@backstage/plugin-scaffolder-node';
 import { createMockActionContext } from '@backstage/plugin-scaffolder-node-test-utils';
+import { Writable } from 'stream';
 
 const executeShellCommand = jest.fn();
 const commandExists = jest.fn();
@@ -166,7 +167,7 @@ describe('fetch:cookiecutter', () => {
           join(mockTmpDir, 'template'),
           '--verbose',
         ],
-        logStream: mockContext.logStream,
+        logStream: expect.any(Writable),
       }),
     );
   });
@@ -187,7 +188,7 @@ describe('fetch:cookiecutter', () => {
         },
         workingDir: '/input',
         envVars: { HOME: '/tmp' },
-        logStream: mockContext.logStream,
+        logStream: expect.any(Writable),
       }),
     );
   });

plugins/scaffolder-backend-module-cookiecutter/src/actions/fetch/cookiecutter.ts

@@ -25,7 +25,7 @@ import { ScmIntegrations } from '@backstage/integration';
 import commandExists from 'command-exists';
 import fs from 'fs-extra';
 import path, { resolve as resolvePath } from 'path';
-import { Writable } from 'stream';
+import { PassThrough, Writable } from 'stream';
 import {
   createTemplateAction,
   fetchContents,
@@ -245,10 +245,15 @@ export function createFetchCookiecutterAction(options: {
         _extensions: ctx.input.extensions,
       };
 
+      const logStream = new PassThrough();
+      logStream.on('data', chunk => {
+        ctx.logger.info(chunk.toString());
+      });
+
       // Will execute the template in ./template and put the result in ./result
       await cookiecutter.run({
         workspacePath: workDir,
-        logStream: ctx.logStream,
+        logStream,
         values: values,
         imageName: ctx.input.imageName,
         templateDir: templateDir,

plugins/scaffolder-backend-module-rails/src/actions/fetch/rails/index.test.ts

@@ -35,6 +35,7 @@ import { createFetchRailsAction } from './index';
 import { fetchContents } from '@backstage/plugin-scaffolder-node';
 import { createMockDirectory } from '@backstage/backend-test-utils';
 import { createMockActionContext } from '@backstage/plugin-scaffolder-node-test-utils';
+import { Writable } from 'stream';
 
 describe('fetch:rails', () => {
   const mockDir = createMockDirectory();
@@ -104,7 +105,7 @@ describe('fetch:rails', () => {
 
     expect(mockRailsTemplater.run).toHaveBeenCalledWith({
       workspacePath: mockContext.workspacePath,
-      logStream: mockContext.logStream,
+      logStream: expect.any(Writable),
       values: mockContext.input.values,
     });
   });
@@ -120,7 +121,7 @@ describe('fetch:rails', () => {
 
     expect(mockRailsTemplater.run).toHaveBeenCalledWith({
       workspacePath: mockContext.workspacePath,
-      logStream: mockContext.logStream,
+      logStream: expect.any(Writable),
       values: {
         ...mockContext.input.values,
         imageName: 'foo/rails-custom-image',

plugins/scaffolder-backend-module-rails/src/actions/fetch/rails/index.ts

@@ -26,6 +26,7 @@ import {
 
 import { resolve as resolvePath } from 'path';
 import { RailsNewRunner } from './railsNewRunner';
+import { PassThrough } from 'stream';
 
 /**
  * Creates the `fetch:rails` Scaffolder action.
@@ -215,10 +216,15 @@ export function createFetchRailsAction(options: {
         throw new Error(`Image ${imageName} is not allowed`);
       }
 
+      const logStream = new PassThrough();
+      logStream.on('data', chunk => {
+        ctx.logger.info(chunk.toString());
+      });
+
       // Will execute the template in ./template and put the result in ./result
       await templateRunner.run({
         workspacePath: workDir,
-        logStream: ctx.logStream,
+        logStream,
         values: { ...ctx.input.values, imageName },
       });
 

plugins/scaffolder-backend/package.json

@@ -1,18 +1,30 @@
 {
   "name": "@backstage/plugin-scaffolder-backend",
-  "description": "The Backstage backend plugin that helps you create new things",
   "version": "1.22.0-next.1",
-  "main": "src/index.ts",
-  "types": "src/index.ts",
-  "license": "Apache-2.0",
+  "description": "The Backstage backend plugin that helps you create new things",
+  "backstage": {
+    "role": "backend-plugin"
+  },
   "publishConfig": {
     "access": "public"
   },
+  "keywords": [
+    "backstage"
+  ],
+  "homepage": "https://backstage.io",
+  "repository": {
+    "type": "git",
+    "url": "https://github.com/backstage/backstage",
+    "directory": "plugins/scaffolder-backend"
+  },
+  "license": "Apache-2.0",
   "exports": {
     ".": "./src/index.ts",
     "./alpha": "./src/alpha.ts",
     "./package.json": "./package.json"
   },
+  "main": "src/index.ts",
+  "types": "src/index.ts",
   "typesVersions": {
     "*": {
       "alpha": [
@@ -23,27 +35,21 @@
       ]
     }
   },
-  "backstage": {
-    "role": "backend-plugin"
-  },
-  "homepage": "https://backstage.io",
-  "repository": {
-    "type": "git",
-    "url": "https://github.com/backstage/backstage",
-    "directory": "plugins/scaffolder-backend"
-  },
-  "keywords": [
-    "backstage"
+  "files": [
+    "dist",
+    "migrations",
+    "config.d.ts",
+    "assets"
   ],
   "scripts": {
-    "start": "backstage-cli package start",
     "build": "backstage-cli package build",
+    "build:assets": "node scripts/build-nunjucks.js",
+    "clean": "backstage-cli package clean",
     "lint": "backstage-cli package lint",
-    "test": "backstage-cli package test",
     "prepack": "backstage-cli package prepack",
     "postpack": "backstage-cli package postpack",
-    "clean": "backstage-cli package clean",
-    "build:assets": "node scripts/build-nunjucks.js"
+    "start": "backstage-cli package start",
+    "test": "backstage-cli package test"
   },
   "dependencies": {
     "@backstage/backend-common": "workspace:^",
@@ -81,6 +87,7 @@
     "jsonschema": "^1.2.6",
     "knex": "^3.0.0",
     "lodash": "^4.17.21",
+    "logform": "^2.3.2",
     "luxon": "^3.0.0",
     "nunjucks": "^3.2.3",
     "p-limit": "^3.1.0",
@@ -105,11 +112,5 @@
     "supertest": "^6.1.3",
     "wait-for-expect": "^3.0.2"
   },
-  "files": [
-    "dist",
-    "migrations",
-    "config.d.ts",
-    "assets"
-  ],
   "configSchema": "config.d.ts"
 }

plugins/scaffolder-backend/src/scaffolder/actions/builtin/catalog/write.ts

@@ -49,7 +49,7 @@ export function createCatalogWriteAction() {
     examples,
     supportsDryRun: true,
     async handler(ctx) {
-      ctx.logStream.write(`Writing catalog-info.yaml`);
+      ctx.logger.info(`Writing catalog-info.yaml`);
       const { filePath, entity } = ctx.input;
       const path = filePath ?? 'catalog-info.yaml';
 

plugins/scaffolder-backend/src/scaffolder/actions/builtin/debug/log.examples.test.ts

@@ -15,23 +15,23 @@
  */
 
 import { createMockActionContext } from '@backstage/plugin-scaffolder-node-test-utils';
-import { Writable } from 'stream';
 import { createDebugLogAction } from './log';
 import { join } from 'path';
 import yaml from 'yaml';
 import { examples } from './log.examples';
 import { createMockDirectory } from '@backstage/backend-test-utils';
+import { Logger } from 'winston';
 
 describe('debug:log examples', () => {
-  const logStream = {
-    write: jest.fn(),
-  } as jest.Mocked<Partial<Writable>> as jest.Mocked<Writable>;
+  const logger = {
+    info: jest.fn(),
+  } as unknown as jest.Mocked<Logger>;
 
   const mockDir = createMockDirectory();
   const workspacePath = mockDir.resolve('workspace');
 
   const mockContext = createMockActionContext({
-    logStream,
+    logger,
     workspacePath,
   });
 
@@ -51,8 +51,7 @@ describe('debug:log examples', () => {
       input: yaml.parse(examples[0].example).steps[0].input,
     });
 
-    expect(logStream.write).toHaveBeenCalledTimes(1);
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining('Hello Backstage!'),
     );
   });
@@ -63,11 +62,10 @@ describe('debug:log examples', () => {
       input: yaml.parse(examples[1].example).steps[0].input,
     });
 
-    expect(logStream.write).toHaveBeenCalledTimes(1);
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining('README.md'),
     );
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining(join('a-directory', 'index.md')),
     );
   });

plugins/scaffolder-backend/src/scaffolder/actions/builtin/debug/log.test.ts

@@ -15,21 +15,21 @@
  */
 
 import { createMockActionContext } from '@backstage/plugin-scaffolder-node-test-utils';
-import { Writable } from 'stream';
+import { Logger } from 'winston';
 import { createDebugLogAction } from './log';
 import { join } from 'path';
 import yaml from 'yaml';
 import { createMockDirectory } from '@backstage/backend-test-utils';
 
 describe('debug:log', () => {
-  const logStream = {
-    write: jest.fn(),
-  } as jest.Mocked<Partial<Writable>> as jest.Mocked<Writable>;
+  const logger = {
+    info: jest.fn(),
+  } as unknown as jest.Mocked<Logger>;
 
   const mockDir = createMockDirectory();
   const workspacePath = mockDir.resolve('workspace');
 
-  const mockContext = createMockActionContext({ workspacePath, logStream });
+  const mockContext = createMockActionContext({ workspacePath, logger });
 
   const action = createDebugLogAction();
 
@@ -41,12 +41,6 @@ describe('debug:log', () => {
     jest.resetAllMocks();
   });
 
-  it('should do nothing', async () => {
-    await action.handler(mockContext);
-
-    expect(logStream.write).toHaveBeenCalledTimes(0);
-  });
-
   it('should log the workspace content, if active', async () => {
     const context = {
       ...mockContext,
@@ -57,11 +51,10 @@ describe('debug:log', () => {
 
     await action.handler(context);
 
-    expect(logStream.write).toHaveBeenCalledTimes(1);
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining('README.md'),
     );
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining(join('a-directory', 'index.md')),
     );
   });
@@ -76,8 +69,7 @@ describe('debug:log', () => {
 
     await action.handler(context);
 
-    expect(logStream.write).toHaveBeenCalledTimes(1);
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining('Hello Backstage!'),
     );
   });
@@ -94,11 +86,10 @@ describe('debug:log', () => {
 
     await action.handler(context);
 
-    expect(logStream.write).toHaveBeenCalledTimes(1);
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining('README.md'),
     );
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining(join('a-directory', 'index.md')),
     );
   });
@@ -115,8 +106,7 @@ describe('debug:log', () => {
 
     await action.handler(context);
 
-    expect(logStream.write).toHaveBeenCalledTimes(1);
-    expect(logStream.write).toHaveBeenCalledWith(
+    expect(logger.info).toHaveBeenCalledWith(
       expect.stringContaining('Hello Backstage!'),
     );
   });

plugins/scaffolder-backend/src/scaffolder/actions/builtin/debug/log.ts

@@ -60,12 +60,12 @@ export function createDebugLogAction() {
       ctx.logger.info(JSON.stringify(ctx.input, null, 2));
 
       if (ctx.input?.message) {
-        ctx.logStream.write(ctx.input.message);
+        ctx.logger.info(ctx.input.message);
       }
 
       if (ctx.input?.listWorkspace) {
         const files = await recursiveReadDir(ctx.workspacePath);
-        ctx.logStream.write(
+        ctx.logger.info(
           `Workspace:\n${files
             .map(f => `  - ${relative(ctx.workspacePath, f)}`)
             .join('\n')}`,

plugins/scaffolder-backend/src/scaffolder/tasks/NunjucksWorkflowRunner.ts

@@ -54,6 +54,8 @@ import { scaffolderActionRules } from '../../service/rules';
 import { actionExecutePermission } from '@backstage/plugin-scaffolder-common/alpha';
 import { TaskRecovery } from '@backstage/plugin-scaffolder-common';
 import { PermissionsService } from '@backstage/backend-plugin-api';
+import { loggerToWinstonLogger } from '@backstage/backend-common';
+import { WinstonLogger } from './logger';
 
 type NunjucksWorkflowRunnerOptions = {
   workingDirectory: string;
@@ -100,26 +102,43 @@ const createStepLogger = ({
   task: TaskContext;
   step: TaskStep;
 }) => {
-  const metadata = { stepId: step.id };
-  const taskLogger = winston.createLogger({
+  const stepLogStream = new PassThrough();
+  stepLogStream.on('data', async data => {
+    const message = data.toString().trim();
+    if (message?.length > 1) {
+      await task.emitLog(message, { stepId: step.id });
+    }
+  });
+
+  const taskLogger = WinstonLogger.create({
     level: process.env.LOG_LEVEL || 'info',
     format: winston.format.combine(
       winston.format.colorize(),
       winston.format.simple(),
     ),
-    defaultMeta: {},
+    transports: [
+      new winston.transports.Console(),
+      new winston.transports.Stream({ stream: stepLogStream }),
+    ],
   });
 
+  taskLogger.addRedactions(Object.values(task.secrets ?? {}));
+
+  // This stream logger should be deprecated. We're going to replace it with
+  // just using the logger directly, as all those logs get written to step logs
+  // using the stepLogStream above.
+  // Initially this stream used to be the only way to write to the client logs, but that
+  // has changed over time, there's not really a need for this anymore.
+  // You can just create a simple wrapper like the below in your action to write to the main logger.
+  // This way we also get recactions for free.
   const streamLogger = new PassThrough();
   streamLogger.on('data', async data => {
     const message = data.toString().trim();
     if (message?.length > 1) {
-      await task.emitLog(message, metadata);
+      taskLogger.info(message);
     }
   });
 
-  taskLogger.add(new winston.transports.Stream({ stream: streamLogger }));
-
   return { taskLogger, streamLogger };
 };
 
@@ -355,7 +374,8 @@ export class NunjucksWorkflowRunner implements WorkflowRunner {
         await action.handler({
           input: iteration.input,
           secrets: task.secrets ?? {},
-          logger: taskLogger,
+          // TODO(blam): move to LoggerService and away from Winston
+          logger: loggerToWinstonLogger(taskLogger),
           logStream: streamLogger,
           workspacePath,
           async checkpoint<U extends JsonValue>(

plugins/scaffolder-backend/src/scaffolder/tasks/logger.ts

@@ -0,0 +1,182 @@
+/*
+ * Copyright 2024 The Backstage Authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+import {
+  LoggerService,
+  RootLoggerService,
+} from '@backstage/backend-plugin-api';
+import { JsonObject } from '@backstage/types';
+import { Format, TransformableInfo } from 'logform';
+import {
+  Logger,
+  format,
+  createLogger,
+  transports,
+  transport as Transport,
+} from 'winston';
+
+/**
+ * Escapes a given string to be used inside a RegExp.
+ *
+ * Taken from https://developer.mozilla.org/en-US/docs/Web/JavaScript/Guide/Regular_Expressions
+ */
+const escapeRegExp = (text: string) => {
+  return text.replace(/[.*+?^${}(\)|[\]\\]/g, '\\$&');
+};
+
+interface WinstonLoggerOptions {
+  meta?: JsonObject;
+  level: string;
+  format: Format;
+  transports: Transport[];
+}
+
+export class WinstonLogger implements RootLoggerService {
+  #winston: Logger;
+  #addRedactions?: (redactions: Iterable<string>) => void;
+
+  /**
+   * Creates a {@link WinstonLogger} instance.
+   */
+  static create(options: WinstonLoggerOptions): WinstonLogger {
+    const redacter = WinstonLogger.redacter();
+
+    let logger = createLogger({
+      level: options.level,
+      format: format.combine(redacter.format, options.format),
+      transports: options.transports ?? new transports.Console(),
+    });
+    if (options.meta) {
+      logger = logger.child(options.meta);
+    }
+
+    return new WinstonLogger(logger, redacter.add);
+  }
+
+  /**
+   * Creates a winston log formatter for redacting secrets.
+   */
+  static redacter(): {
+    format: Format;
+    add: (redactions: Iterable<string>) => void;
+  } {
+    const redactionSet = new Set<string>();
+
+    let redactionPattern: RegExp | undefined = undefined;
+
+    return {
+      format: format(info => {
+        if (redactionPattern && typeof info.message === 'string') {
+          info.message = info.message.replace(redactionPattern, '[REDACTED]');
+        }
+        if (redactionPattern && typeof info.stack === 'string') {
+          info.stack = info.stack.replace(redactionPattern, '[REDACTED]');
+        }
+        return info;
+      })(),
+      add(newRedactions) {
+        let added = 0;
+        for (const redactionToTrim of newRedactions) {
+          // Trimming the string ensures that we don't accdentally get extra
+          // newlines or other whitespace interfering with the redaction; this
+          // can happen for example when using string literals in yaml
+          const redaction = redactionToTrim.trim();
+          // Exclude secrets that are empty or just one character in length. These
+          // typically mean that you are running local dev or tests, or using the
+          // --lax flag which sets things to just 'x'.
+          if (redaction.length <= 1) {
+            continue;
+          }
+          if (!redactionSet.has(redaction)) {
+            redactionSet.add(redaction);
+            added += 1;
+          }
+        }
+        if (added > 0) {
+          const redactions = Array.from(redactionSet)
+            .map(r => escapeRegExp(r))
+            .join('|');
+          redactionPattern = new RegExp(`(${redactions})`, 'g');
+        }
+      },
+    };
+  }
+
+  /**
+   * Creates a pretty printed winston log formatter.
+   */
+  static colorFormat(): Format {
+    const colorizer = format.colorize();
+
+    return 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}`;
+      }),
+    );
+  }
+
+  private constructor(
+    winston: Logger,
+    addRedactions?: (redactions: Iterable<string>) => void,
+  ) {
+    this.#winston = winston;
+    this.#addRedactions = addRedactions;
+  }
+
+  error(message: string, meta?: JsonObject): void {
+    this.#winston.error(message, meta);
+  }
+
+  warn(message: string, meta?: JsonObject): void {
+    this.#winston.warn(message, meta);
+  }
+
+  info(message: string, meta?: JsonObject): void {
+    this.#winston.info(message, meta);
+  }
+
+  debug(message: string, meta?: JsonObject): void {
+    this.#winston.debug(message, meta);
+  }
+
+  child(meta: JsonObject): LoggerService {
+    return new WinstonLogger(this.#winston.child(meta));
+  }
+
+  addRedactions(redactions: Iterable<string>) {
+    this.#addRedactions?.(redactions);
+  }
+}

plugins/scaffolder-node/src/actions/types.ts

@@ -31,7 +31,9 @@ export type ActionContext<
   TActionInput extends JsonObject,
   TActionOutput extends JsonObject = JsonObject,
 > = {
+  // TODO(blam): move this to LoggerService
   logger: Logger;
+  /** @deprecated - use `ctx.logger` instead */
   logStream: Writable;
   secrets?: TaskSecrets;
   workspacePath: string;

yarn.lock

@@ -8766,6 +8766,7 @@ __metadata:
     jsonschema: ^1.2.6
     knex: ^3.0.0
     lodash: ^4.17.21
+    logform: ^2.3.2
     luxon: ^3.0.0
     nunjucks: ^3.2.3
     p-limit: ^3.1.0