From 31c2144a228091227959f4a0c3c0338632550506 Mon Sep 17 00:00:00 2001 From: Ash Wu Date: Thu, 29 Oct 2026 15:09:08 +0800 Subject: [PATCH] [worker] mask secrets in the records written to worker stdout --- .changeset/mask-worker-stdout.md | 5 + packages/worker/src/__unit__/logger.test.ts | 130 ++++++++++++++++---- packages/worker/src/logger.ts | 64 +++++----- packages/worker/src/ws.ts | 1 - 4 files changed, 142 insertions(+), 58 deletions(-) create mode 100644 .changeset/mask-worker-stdout.md diff --git a/.changeset/mask-worker-stdout.md b/.changeset/mask-worker-stdout.md new file mode 100644 index 0000000000..668308e0ef --- /dev/null +++ b/.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. diff --git a/packages/worker/src/__unit__/logger.test.ts b/packages/worker/src/__unit__/logger.test.ts index f5a6908cae..be1f14b2f4 100644 --- a/packages/worker/src/__unit__/logger.test.ts +++ b/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 {} @@ -62,41 +61,37 @@ jest.mock('@expo/build-tools', () => { }; }); -import config from '../config'; -import { createBuildLoggerWithSecretsFilter } from '../logger'; +type BuildToolsMock = { + HttpLogStream: { instances: Array<{ config: Record; 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 { await new Promise(resolve => setImmediate(resolve)); } -const { HttpLogStream, RemoteLoggerStream } = jest.requireMock('@expo/build-tools') as { - HttpLogStream: { - instances: Array<{ - config: Record; - 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 = {}; + 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: ( diff --git a/packages/worker/src/logger.ts b/packages/worker/src/logger.ts index 20d84bffb9..8fabd0ab9f 100644 --- a/packages/worker/src/logger.ts +++ b/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): Transform { const chunk: Record = {}; 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): unkno } catch { return '[Unserializable]'; } - return maskSecretsInJsonValue(json, secrets, 0); + return secrets.size === 0 ? json : maskSecretsInJsonValue(json, secrets, 0); } function maskSecretsInJsonValue( @@ -158,15 +150,38 @@ 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(); + +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; @@ -174,29 +189,16 @@ export async function createBuildLoggerWithSecretsFilter(secrets: Job['secrets'] logBuffer: WorkerLogBuffer; outputStream: Readable; }> { - const buildLogger = defaultLogger.child({ phase: BuildPhase.UNKNOWN }); - - const secretPatterns = new Set(); - 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; diff --git a/packages/worker/src/ws.ts b/packages/worker/src/ws.ts index ea250d117a..0f8d928bb8 100644 --- a/packages/worker/src/ws.ts +++ b/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(