[worker] Mask secrets in all build log fields without stalling on stdout

Write to stdout without waiting for it to flush, so uploads and the error
log buffer are not held back. Mask every string field except logger
metadata, and serialize records safely so circular or BigInt values
cannot throw into the logging call site.

Co-Authored-By: Claude Opus 5.5 <[email protected]>

.changeset/mask-worker-stdout.md

@@ -0,0 +1,5 @@
+---
+'@expo/worker': patch
+---
+
+Mask build secrets in every build log field, worker stdout and the build error log buffer.

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

@@ -71,6 +71,16 @@ async function waitForStreamFlush(): Promise<void> {
   await new Promise(resolve => setImmediate(resolve));
 }
 
+function captureStdout(): { output: string[]; write: jest.SpyInstance } {
+  const output: string[] = [];
+  // Never call the write callback, like a stdout that has not flushed yet.
+  const write = jest.spyOn(process.stdout, 'write').mockImplementation(chunk => {
+    output.push(String(chunk));
+    return true;
+  });
+  return { output, write };
+}
+
 const { HttpLogStream, RemoteLoggerStream } = jest.requireMock('@expo/build-tools') as {
   HttpLogStream: {
     instances: Array<{
@@ -135,6 +145,107 @@ describe('logger', () => {
     expect(logs[1].msg).toBe('another ****** in base64 is ********************');
   });
 
+  it('masks stdout and stderr messages before writing process output and the log buffer', async () => {
+    const { logger, logBuffer } = await createBuildLoggerWithSecretsFilter({
+      environmentSecrets: [
+        { name: 'TOKEN', value: 'fake-provider-token', type: EnvironmentSecretType.STRING },
+      ],
+    });
+    const { output, write } = captureStdout();
+    try {
+      logger.child({ source: 'stdout' }).info('stdout: fake-provider-token');
+      logger.child({ source: 'stderr' }).error('stderr: fake-provider-token');
+      await waitForStreamFlush();
+
+      expect(output.map(line => JSON.parse(line).msg)).toEqual([
+        'stdout: *******************',
+        'stderr: *******************',
+      ]);
+      expect(logBuffer.getLogs()).toEqual([
+        'stdout: *******************',
+        'stderr: *******************',
+      ]);
+    } finally {
+      write.mockRestore();
+    }
+  });
+
+  it('masks secrets in every field except logger metadata', async () => {
+    const { logger, outputStream } = await createBuildLoggerWithSecretsFilter({
+      environmentSecrets: [
+        { name: 'TOKEN', value: 'fake-provider-token', type: EnvironmentSecretType.STRING },
+        { name: 'SOURCE', value: 'stdout', type: EnvironmentSecretType.STRING },
+      ],
+    });
+    const logs: any[] = [];
+    outputStream.on('data', log => logs.push(log));
+
+    const err = new Error('request with fake-provider-token failed');
+    logger
+      .child({ source: 'stdout', buildStepDisplayName: 'Use fake-provider-token' })
+      .error({ err, request: { headers: ['Bearer fake-provider-token'] } }, 'failed');
+    await waitForStreamFlush();
+
+    expect(logs).toHaveLength(1);
+    expect(JSON.stringify(logs[0])).not.toContain('fake-provider-token');
+    expect(logs[0].err.message).toBe('request with ******************* failed');
+    expect(logs[0].err.stack).toContain('request with ******************* failed');
+    expect(logs[0].request.headers).toEqual(['Bearer *******************']);
+    expect(logs[0].buildStepDisplayName).toBe('Use *******************');
+    expect(logs[0].source).toBe('stdout');
+    expect(typeof logs[0].time).toBe('string');
+  });
+
+  it('writes records JSON.stringify would reject instead of throwing', async () => {
+    const { logger, logBuffer } = await createBuildLoggerWithSecretsFilter({
+      environmentSecrets: [
+        { name: 'TOKEN', value: 'fake-provider-token', type: EnvironmentSecretType.STRING },
+      ],
+    });
+    const { output, write } = captureStdout();
+    try {
+      const circular: Record<string, unknown> = { token: 'fake-provider-token' };
+      circular.self = circular;
+      const throwing = {
+        toJSON() {
+          throw new Error('nope');
+        },
+      };
+
+      expect(() => {
+        logger.child({ source: 'stdout' }).info({ circular, count: 1n }, 'circular');
+        logger.child({ source: 'stdout' }).info({ throwing }, 'throwing fake-provider-token');
+      }).not.toThrow();
+      await waitForStreamFlush();
+
+      const records = output.map(line => JSON.parse(line));
+      expect(records).toHaveLength(2);
+      expect(records[0].circular).toEqual({ token: '*******************', self: '[Circular]' });
+      expect(records[0].count).toBe('1');
+      expect(records[1].msg).toBe('throwing *******************');
+      expect(records[1].throwing).toBeUndefined();
+      expect(logBuffer.getLogs()).toEqual(['circular', 'throwing *******************']);
+    } finally {
+      write.mockRestore();
+    }
+  });
+
+  it('does not hold other destinations back while stdout flushes', async () => {
+    const { logger, logBuffer } = await createBuildLoggerWithSecretsFilter({});
+    const write = jest.spyOn(process.stdout, 'write').mockImplementation(() => true);
+    try {
+      await waitForStreamFlush();
+      const stdoutLogger = logger.child({ source: 'stdout' });
+      for (let i = 0; i < 100; i++) {
+        stdoutLogger.info(`line ${i}`);
+      }
+
+      expect(logBuffer.getLogs()).toHaveLength(100);
+    } finally {
+      write.mockRestore();
+    }
+  });
+
   it('adds logId to each log', async () => {
     const { logger, outputStream } = await createBuildLoggerWithSecretsFilter({});
 

packages/worker/src/logger.ts

@@ -62,43 +62,108 @@ function createTransformStream(secrets: EnvironmentSecret[]): Transform {
     ...secretValues,
     ...secretValues.map(maybeStringBase64Decode).filter((i): i is string => !!i),
   ].filter(i => i.length > 1 && !simpleSecretsWhitelist.includes(i));
+  const maskSecrets = (value: string): string =>
+    secretList.reduce((acc: string, pattern: string): string => {
+      return acc.replaceAll(pattern, '*'.repeat(pattern.length));
+    }, value);
 
   return new Transform({
     readableObjectMode: true,
     writableObjectMode: true,
-    transform(_chunk: any, _encoding: BufferEncoding, callback: TransformCallback) {
-      let chunk = _chunk;
-      if (chunk && typeof chunk === 'object') {
-        // Remove hostname from logs since we don't need it.
-        const { hostname: _hostname, ...rest } = chunk;
-        chunk = {
-          ...rest,
-          // Add logId to each log.
-          logId: uuidv7(),
-        };
-      }
-
-      if (chunk && typeof chunk === 'object' && chunk.msg) {
-        const msgWithoutSecrets = secretList.reduce((acc: string, pattern: string): string => {
-          return acc.replaceAll(pattern, '*'.repeat(pattern.length));
-        }, chunk.msg as string);
-
-        callback(null, {
-          ...chunk,
-          msg: msgWithoutSecrets,
-        });
-      } else {
+    transform(chunk: any, _encoding: BufferEncoding, callback: TransformCallback) {
+      if (!chunk || typeof chunk !== 'object') {
         callback(null, chunk);
+        return;
       }
+      // Remove hostname from logs since we don't need it.
+      const { hostname: _hostname, ...rest } = chunk;
+      callback(
+        null,
+        toMaskedJsonRecord(
+          {
+            ...rest,
+            // Add logId to each log.
+            logId: uuidv7(),
+          },
+          maskSecrets
+        )
+      );
     },
   });
 }
 
-function createDiscardStream(): Writable {
+// Set by the logger and build tooling rather than by build output. Masking them could
+// break grouping and filtering, e.g. a secret equal to "stdout" or part of a timestamp.
+const UNMASKED_RECORD_FIELDS = new Set([
+  'name',
+  'pid',
+  'level',
+  'time',
+  'v',
+  'logId',
+  'phase',
+  'source',
+  'buildStepId',
+  'buildStepInternalId',
+  'marker',
+  'result',
+]);
+
+// Every destination writes records as JSON, so return a plain JSON value with secrets
+// masked in every string, not only in `msg`. Like bunyan's own stdout stream, tolerate
+// values JSON.stringify rejects instead of throwing into the code that logged.
+function toMaskedJsonRecord(
+  record: Record<string, unknown>,
+  maskSecrets: (value: string) => string
+): Record<string, unknown> {
+  const createReplacer = (seen?: WeakSet<object>) =>
+    function (this: unknown, key: string, value: unknown): unknown {
+      if (typeof value === 'bigint') {
+        value = value.toString();
+      }
+      if (this === record && UNMASKED_RECORD_FIELDS.has(key)) {
+        return value;
+      }
+      if (typeof value === 'string') {
+        return maskSecrets(value);
+      }
+      if (seen && value && typeof value === 'object') {
+        if (seen.has(value)) {
+          return '[Circular]';
+        }
+        seen.add(value);
+      }
+      return value;
+    };
+
+  try {
+    return JSON.parse(JSON.stringify(record, createReplacer()));
+  } catch {}
+  try {
+    return JSON.parse(JSON.stringify(record, createReplacer(new WeakSet())));
+  } catch {}
+  // Something like a throwing toJSON(); keep the top-level values that are safe to log.
+  const fallback: Record<string, unknown> = {};
+  for (const [key, value] of Object.entries(record)) {
+    if (typeof value === 'string') {
+      fallback[key] = UNMASKED_RECORD_FIELDS.has(key) ? value : maskSecrets(value);
+    } else if (typeof value === 'number' || typeof value === 'boolean' || value === null) {
+      fallback[key] = value;
+    } else if (value instanceof Date && !Number.isNaN(value.getTime())) {
+      fallback[key] = value.toISOString();
+    }
+  }
+  return fallback;
+}
+
+function createStdoutStream(): Writable {
   return new Writable({
     objectMode: true,
-    write(_chunk: any, _encoding: BufferEncoding, callback: (error?: Error | null) => void) {
-      callback(null);
+    write(chunk: any, _encoding: BufferEncoding, callback: (error?: Error | null) => void) {
+      // Like bunyan's stdout stream, do not wait for stdout to flush. The other
+      // destinations are piped from the same source and would wait with it.
+      process.stdout.write(`${JSON.stringify(chunk)}\n`);
+      callback();
     },
   });
 }
@@ -109,17 +174,16 @@ export async function createBuildLoggerWithSecretsFilter(secrets: Job['secrets']
   logBuffer: WorkerLogBuffer;
   outputStream: Readable;
 }> {
-  const buildLogger = defaultLogger.child({ phase: BuildPhase.UNKNOWN });
-
   const transformStream = createTransformStream(secrets?.environmentSecrets ?? []);
-  const discardStream = createDiscardStream();
-  transformStream.pipe(discardStream);
+  transformStream.pipe(createStdoutStream());
 
-  buildLogger.addStream({
-    type: 'raw',
-    stream: transformStream,
-    reemitErrorEvents: true,
-    level: buildLogger.level(),
+  // Do not inherit defaultLogger's stdout stream: every build-log destination must
+  // receive the filtered record.
+  const buildLogger = createLogger({
+    name: config.loggers.base.name,
+    phase: BuildPhase.UNKNOWN,
+    level: defaultLogger.level(),
+    streams: [{ type: 'raw', stream: transformStream, reemitErrorEvents: true }],
   });
 
   let remoteLoggerStream: RemoteLoggerStream | null = null;
@@ -137,12 +201,7 @@ export async function createBuildLoggerWithSecretsFilter(secrets: Job['secrets']
   }
 
   const logBuffer = new WorkerLogBuffer(MAX_LINES_IN_BUFFER);
-  buildLogger.addStream({
-    type: 'raw',
-    stream: logBuffer,
-    reemitErrorEvents: true,
-    level: buildLogger.level(),
-  });
+  transformStream.pipe(logBuffer);
 
   let httpLogStream: HttpLogStream | null = null;
   if (config.loggers.http.baseUrl && secrets?.robotAccessToken) {