[worker] mask secrets in the records written to worker stdout

.changeset/mask-worker-stdout.md

@@ -0,0 +1,5 @@
+---
+'@expo/worker': patch
+---
+
+Mask secrets in every record the worker process writes to its stdout: the build log records and the worker's own records.

packages/worker/src/__unit__/logger.test.ts

@@ -1,5 +1,6 @@
 import { TransformCallback, Writable } from 'node:stream';
 import { EnvironmentSecretType } from '@expo/eas-build-job';
+import { LoggerLevel } from '@expo/logger';
 import z from 'zod';
 
 jest.mock('@expo/build-tools', () => {
@@ -8,14 +9,12 @@ jest.mock('@expo/build-tools', () => {
 
   class MockRemoteLoggerStream extends Writable {
     public static readonly CompressionMethod = actual.RemoteLoggerStream.CompressionMethod;
-    public static readonly instances: MockRemoteLoggerStream[] = [];
 
     public readonly writes: any[] = [];
 
     constructor(...args: any[]) {
       super({ objectMode: true });
       void args;
-      MockRemoteLoggerStream.instances.push(this);
     }
 
     public async init(): Promise<void> {}
@@ -62,41 +61,37 @@ jest.mock('@expo/build-tools', () => {
   };
 });
 
-import config from '../config';
-import { createBuildLoggerWithSecretsFilter } from '../logger';
+type BuildToolsMock = {
+  HttpLogStream: { instances: Array<{ config: Record<string, unknown>; writes: any[] }> };
+};
+
+let config: typeof import('../config').default;
+let defaultLogger: typeof import('../logger').default;
+let createBuildLoggerWithSecretsFilter: typeof import('../logger').createBuildLoggerWithSecretsFilter;
+let HttpLogStream: BuildToolsMock['HttpLogStream'];
 
 async function waitForStreamFlush(): Promise<void> {
   await new Promise(resolve => setImmediate(resolve));
 }
 
-const { HttpLogStream, RemoteLoggerStream } = jest.requireMock('@expo/build-tools') as {
-  HttpLogStream: {
-    instances: Array<{
-      config: Record<string, unknown>;
-      writes: any[];
-    }>;
-  };
-  RemoteLoggerStream: {
-    instances: Array<{
-      writes: any[];
-    }>;
-  };
-};
-
 describe('logger', () => {
-  const originalHttpBaseUrl = config.loggers.http.baseUrl;
-  const originalBuildId = config.buildId;
-  const originalGcsSignedUploadUrlForLogs = config.loggers.gcs.signedUploadUrlForLogs;
+  let stdoutRecords: any[];
+  let stdoutWrite: jest.SpyInstance;
 
   beforeEach(() => {
-    HttpLogStream.instances.length = 0;
-    RemoteLoggerStream.instances.length = 0;
+    jest.resetModules();
+    config = require('../config').default;
+    ({ default: defaultLogger, createBuildLoggerWithSecretsFilter } = require('../logger'));
+    ({ HttpLogStream } = jest.requireMock('@expo/build-tools'));
+    stdoutRecords = [];
+    stdoutWrite = jest.spyOn(process.stdout, 'write').mockImplementation(chunk => {
+      stdoutRecords.push(JSON.parse(String(chunk)));
+      return true;
+    });
   });
 
   afterEach(() => {
-    config.loggers.http.baseUrl = originalHttpBaseUrl;
-    config.buildId = originalBuildId;
-    config.loggers.gcs.signedUploadUrlForLogs = originalGcsSignedUploadUrlForLogs;
+    stdoutWrite.mockRestore();
   });
 
   it('obfuscates secrets in logs', async () => {
@@ -183,6 +178,89 @@ describe('logger', () => {
     expect(logs.map(log => log.msg)).toEqual(['token: ***************, prefix: ***']);
   });
 
+  it('masks command output before writing it to process stdout', async () => {
+    const { logger, addBuildLogMask } = await createBuildLoggerWithSecretsFilter({});
+    addBuildLogMask('leased-token');
+
+    logger.child({ source: 'stdout' }).info('token: leased-token');
+    await waitForStreamFlush();
+
+    expect(stdoutRecords).toMatchObject([{ source: 'stdout', msg: 'token: ************' }]);
+  });
+
+  it('keeps the other streams flowing while stdout is not drained', async () => {
+    stdoutWrite.mockImplementation(() => false);
+    const { logger, outputStream } = await createBuildLoggerWithSecretsFilter({});
+    const logs: any[] = [];
+    outputStream.pipe(
+      new Writable({
+        objectMode: true,
+        write(chunk: any, _encoding: BufferEncoding, callback: TransformCallback) {
+          logs.push(chunk);
+          callback(null, chunk);
+        },
+      })
+    );
+
+    const lineCount = 2 * outputStream.readableHighWaterMark;
+    for (let i = 0; i < lineCount; i++) {
+      logger.info(`line ${i}`);
+    }
+    await waitForStreamFlush();
+
+    expect(logs).toHaveLength(lineCount);
+  });
+
+  it("masks the worker's own records on stdout", async () => {
+    const { addBuildLogMask } = await createBuildLoggerWithSecretsFilter({});
+    addBuildLogMask('leased-token');
+
+    defaultLogger.error({ err: new Error('request with leased-token failed') }, 'Job failed');
+    await waitForStreamFlush();
+
+    expect(stdoutRecords).toMatchObject([
+      { msg: 'Job failed', err: { message: 'request with ************ failed' } },
+    ]);
+  });
+
+  it('writes a circular field as unserializable when no secret is registered and keeps going', async () => {
+    const { logger } = await createBuildLoggerWithSecretsFilter({});
+    const circular: Record<string, unknown> = {};
+    circular.self = circular;
+
+    logger.info({ circular }, 'first');
+    logger.info('second');
+    await waitForStreamFlush();
+
+    expect(stdoutRecords).toMatchObject([
+      { msg: 'first', circular: '[Unserializable]' },
+      { msg: 'second' },
+    ]);
+  });
+
+  it('keeps a deeply nested value when no secret is registered', async () => {
+    const { logger } = await createBuildLoggerWithSecretsFilter({});
+    let nested: any = { leaf: 'kept' };
+    for (let index = 0; index < 30; index++) {
+      nested = { nested };
+    }
+
+    logger.info({ nested }, 'deep');
+    await waitForStreamFlush();
+
+    expect(JSON.stringify(stdoutRecords[0].nested)).toContain('"leaf":"kept"');
+  });
+
+  it("copies the default logger's level when the build logger is created", async () => {
+    defaultLogger.level(LoggerLevel.DEBUG);
+    const { logger } = await createBuildLoggerWithSecretsFilter({});
+
+    logger.debug('debug line');
+    await waitForStreamFlush();
+
+    expect(stdoutRecords).toMatchObject([{ msg: 'debug line' }]);
+  });
+
   describe('structured fields', () => {
     async function logWithSecretAsync(
       log: (

packages/worker/src/logger.ts

@@ -7,11 +7,6 @@ import config from './config';
 import { maybeStringBase64Decode, simpleSecretsWhitelist } from './secrets';
 import { uuidv7 } from 'uuidv7';
 
-const defaultLogger = createLogger({
-  name: config.loggers.base.name,
-  level: LoggerLevel.INFO,
-});
-
 const MAX_LINES_IN_BUFFER = 100;
 
 interface CachedLog {
@@ -90,10 +85,7 @@ function createTransformStream(secretPatterns: ReadonlySet<string>): Transform {
       const chunk: Record<string, unknown> = {};
       for (const [key, value] of Object.entries(rest)) {
         // Secrets can be in any field, such as a serialized error's message and stack.
-        chunk[key] =
-          secretPatterns.size === 0 || UNMASKED_FIELDS.has(key)
-            ? value
-            : maskSecretsInValue(value, secretPatterns);
+        chunk[key] = UNMASKED_FIELDS.has(key) ? value : maskSecretsInValue(value, secretPatterns);
       }
       // Add logId to each log.
       chunk.logId = uuidv7();
@@ -127,7 +119,7 @@ function maskSecretsInValue(value: unknown, secrets: ReadonlySet<string>): unkno
   } catch {
     return '[Unserializable]';
   }
-  return maskSecretsInJsonValue(json, secrets, 0);
+  return secrets.size === 0 ? json : maskSecretsInJsonValue(json, secrets, 0);
 }
 
 function maskSecretsInJsonValue(
@@ -158,45 +150,55 @@ function maskSecretsInJsonValue(
   );
 }
 
-function createDiscardStream(): Writable {
+function createStdoutStream(): Writable {
   return new Writable({
     objectMode: true,
-    write(_chunk: any, _encoding: BufferEncoding, callback: (error?: Error | null) => void) {
+    write(chunk: any, _encoding: BufferEncoding, callback: (error?: Error | null) => void) {
+      process.stdout.write(`${JSON.stringify(chunk)}\n`);
       callback(null);
     },
   });
 }
 
+const secretPatterns = new Set<string>();
+
+function addBuildLogMask(secret: string): void {
+  for (const pattern of [secret, maybeStringBase64Decode(secret)]) {
+    if (pattern && pattern.length > 1 && !simpleSecretsWhitelist.includes(pattern)) {
+      secretPatterns.add(pattern);
+    }
+  }
+}
+
+function createStdoutMaskingStream(): Transform {
+  const transformStream = createTransformStream(secretPatterns);
+  transformStream.pipe(createStdoutStream());
+  return transformStream;
+}
+
+const defaultLogger = createLogger({
+  name: config.loggers.base.name,
+  level: LoggerLevel.INFO,
+  streams: [{ type: 'raw', stream: createStdoutMaskingStream(), reemitErrorEvents: true }],
+});
+
 export async function createBuildLoggerWithSecretsFilter(secrets: Job['secrets']): Promise<{
   logger: bunyan;
   addBuildLogMask: (secret: string) => void;
   cleanUp: () => Promise<void>;
   logBuffer: WorkerLogBuffer;
   outputStream: Readable;
 }> {
-  const buildLogger = defaultLogger.child({ phase: BuildPhase.UNKNOWN });
-
-  const secretPatterns = new Set<string>();
-  const addBuildLogMask = (secret: string): void => {
-    for (const pattern of [secret, maybeStringBase64Decode(secret)]) {
-      if (pattern && pattern.length > 1 && !simpleSecretsWhitelist.includes(pattern)) {
-        secretPatterns.add(pattern);
-      }
-    }
-  };
   for (const { value } of secrets?.environmentSecrets ?? []) {
     addBuildLogMask(value);
   }
 
-  const transformStream = createTransformStream(secretPatterns);
-  const discardStream = createDiscardStream();
-  transformStream.pipe(discardStream);
-
-  buildLogger.addStream({
-    type: 'raw',
-    stream: transformStream,
-    reemitErrorEvents: true,
-    level: buildLogger.level(),
+  const transformStream = createStdoutMaskingStream();
+  const buildLogger = createLogger({
+    name: config.loggers.base.name,
+    level: defaultLogger.level(),
+    phase: BuildPhase.UNKNOWN,
+    streams: [{ type: 'raw', stream: transformStream, reemitErrorEvents: true }],
   });
 
   let remoteLoggerStream: RemoteLoggerStream | null = null;

packages/worker/src/ws.ts

@@ -47,7 +47,6 @@ function handleConnection(socket: WebSocket, service: BuildService): void {
 
   wsServer.onMessage((message: LauncherMessage.Message) => {
     try {
-      logger.debug({ message }, 'WebSocket message received');
       const { handled } = handleMessage(service, message) || { handled: false };
       if (!handled) {
         throw new Error(