diff --git a/.changeset/worker-mask-logged-errors.md b/.changeset/worker-mask-logged-errors.md new file mode 100644 index 0000000000..933334e01d --- /dev/null +++ b/.changeset/worker-mask-logged-errors.md @@ -0,0 +1,5 @@ +--- +'@expo/worker': patch +--- + +Mask secrets in every field of uploaded job log records, such as logged errors, not only in log messages. diff --git a/packages/worker/src/__unit__/logger.test.ts b/packages/worker/src/__unit__/logger.test.ts index ad31acf8cc..ca8219f653 100644 --- a/packages/worker/src/__unit__/logger.test.ts +++ b/packages/worker/src/__unit__/logger.test.ts @@ -185,6 +185,100 @@ describe('logger', () => { expect(logs.map(log => log.msg)).toEqual(['token: ***************, prefix: ***']); }); + describe('structured fields', () => { + async function logWithSecretAsync( + log: ( + logger: Awaited>['logger'] + ) => void + ): Promise { + const { logger, outputStream } = await createBuildLoggerWithSecretsFilter({ + environmentSecrets: [ + { name: 'TOKEN', value: 'secret-token', type: EnvironmentSecretType.STRING }, + { name: 'PIN', value: '123456789', type: EnvironmentSecretType.STRING }, + ], + }); + const logs: any[] = []; + outputStream.pipe( + new Writable({ + objectMode: true, + write(chunk: any, _encoding: BufferEncoding, callback: TransformCallback) { + logs.push(chunk); + callback(null, chunk); + }, + }) + ); + log(logger); + await waitForStreamFlush(); + // The upload streams send JSON.stringify(record). + for (const record of logs) { + expect(JSON.stringify(record)).not.toContain('secret-token'); + expect(JSON.stringify(record)).not.toContain('123456789'); + } + return logs; + } + + it('masks errors, including when the message is empty', async () => { + const err = new Error('git clone https://secret-token@github.com/acme/app failed'); + const logs = await logWithSecretAsync(logger => { + logger.error({ err }, ''); + logger.error({ err }); + }); + + expect(logs).toHaveLength(2); + for (const log of logs) { + expect(log.err.message).toBe('git clone https://************@github.com/acme/app failed'); + expect(log.err.stack).toContain( + 'git clone https://************@github.com/acme/app failed' + ); + } + expect(logs[0].msg).toBe(''); + expect(logs[1].msg).toBe('git clone https://************@github.com/acme/app failed'); + }); + + it('masks other fields, keys and numbers, and keeps metadata fields', async () => { + const job = { env: { TOKEN_COPY: 'secret-token', 'secret-token': 'key', PIN: 123456789 } }; + const logs = await logWithSecretAsync(logger => { + logger.info({ job, source: 'stdout', buildStepId: 'step-1' }, 'Builder is ready'); + }); + + expect(logs[0].job).toEqual({ + env: { TOKEN_COPY: '************', '************': 'key', PIN: '*********' }, + }); + expect(logs[0].source).toBe('stdout'); + expect(logs[0].buildStepId).toBe('step-1'); + // The caller's object, which bunyan also hands to other streams, is not changed. + expect(job.env.TOKEN_COPY).toBe('secret-token'); + }); + + it('masks what a toJSON method returns', async () => { + const logs = await logWithSecretAsync(logger => { + logger.error( + { + err: { + token: 'secret-token', + toJSON: () => ({ token: 'secret-token', at: new Date(0) }), + }, + }, + 'failed' + ); + }); + + expect(logs[0].err).toEqual({ token: '************', at: '1970-01-01T00:00:00.000Z' }); + }); + + it('truncates deeply nested values instead of uploading them unmasked', async () => { + let nested: any = { token: 'secret-token' }; + for (let index = 0; index < 30; index++) { + nested = { nested }; + } + const logs = await logWithSecretAsync(logger => { + logger.error({ err: nested }, 'failed'); + }); + + expect(JSON.stringify(logs[0].err)).toContain('[Truncated]'); + }); + }); + it('adds logId to each log', async () => { const { logger, outputStream } = await createBuildLoggerWithSecretsFilter({}); diff --git a/packages/worker/src/logger.ts b/packages/worker/src/logger.ts index 167ca2f6ab..20d84bffb9 100644 --- a/packages/worker/src/logger.ts +++ b/packages/worker/src/logger.ts @@ -59,30 +59,45 @@ export class WorkerLogBuffer extends Writable implements LogBuffer { } } +// Bunyan's own fields and fields that identify a log line, which never hold user data. +const UNMASKED_FIELDS = new Set([ + 'name', + 'pid', + 'level', + 'time', + 'v', + 'phase', + 'source', + 'marker', + 'result', + 'buildStepId', + 'buildStepInternalId', +]); +const MAX_MASKED_DEPTH = 20; + function createTransformStream(secretPatterns: ReadonlySet): Transform { 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') { + callback(null, _chunk); + return; } - - if (chunk && typeof chunk === 'object' && chunk.msg) { - callback(null, { - ...chunk, - msg: maskSecrets(chunk.msg as string, secretPatterns), - }); - } else { - callback(null, chunk); + // Remove hostname from logs since we don't need it. Bunyan shares the record with other + // streams, so build a copy instead of changing it. + const { hostname: _hostname, ...rest } = _chunk; + 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); } + // Add logId to each log. + chunk.logId = uuidv7(); + callback(null, chunk); }, }); } @@ -101,6 +116,48 @@ function maskSecrets(message: string, secrets: Iterable): string { return characters.join(''); } +function maskSecretsInValue(value: unknown, secrets: ReadonlySet): unknown { + if (value === null || typeof value !== 'object') { + return maskSecretsInJsonValue(value, secrets, 0); + } + // Mask what the upload streams will serialize, so a toJSON method can't bring back the original. + let json: unknown; + try { + json = JSON.parse(JSON.stringify(value)); + } catch { + return '[Unserializable]'; + } + return maskSecretsInJsonValue(json, secrets, 0); +} + +function maskSecretsInJsonValue( + value: unknown, + secrets: ReadonlySet, + depth: number +): unknown { + if (typeof value === 'string') { + return maskSecrets(value, secrets); + } + if (typeof value === 'number') { + return secrets.has(String(value)) ? maskSecrets(String(value), secrets) : value; + } + if (value === null || typeof value !== 'object') { + return value; + } + if (depth >= MAX_MASKED_DEPTH) { + return '[Truncated]'; + } + if (Array.isArray(value)) { + return value.map(item => maskSecretsInJsonValue(item, secrets, depth + 1)); + } + return Object.fromEntries( + Object.entries(value).map(([key, item]) => [ + maskSecrets(key, secrets), + maskSecretsInJsonValue(item, secrets, depth + 1), + ]) + ); +} + function createDiscardStream(): Writable { return new Writable({ objectMode: true,