Skip to content
4 changes: 3 additions & 1 deletion api/src/job.ts
Original file line number Diff line number Diff line change
Expand Up @@ -740,7 +740,9 @@ export class Job {
this.session = opts.session ?? undefined;
this.uuid = opts.session_id ?? nanoid();
this.outputSessionId = opts.output_session_id ?? this.uuid;
this.log = rootLogger.child({ job: this.uuid });
// Pino serializes child bindings outside the log-method sanitizer, so this
// binding must stay fixed and values-free.
this.log = rootLogger.child({ component: 'job' });
this.runtime = opts.runtime;
this.files = opts.files.map((file, i) => ({
id: file.id,
Expand Down
57 changes: 57 additions & 0 deletions api/src/logger.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
import { Writable } from 'node:stream';
import { describe, expect, test } from 'bun:test';
import { createOperationalLogger } from './logger';

const SENTINEL = 'PRIVATE_api_log_6Rw9mQ2p';

describe('Pino operational logging', () => {
test('sanitizes calls and keeps only approved child bindings', () => {
const chunks: string[] = [];
const stream = new Writable({
write(chunk, _encoding, callback) {
chunks.push(chunk.toString());
callback();
},
});
const capture = createOperationalLogger(stream);

const run: Record<string, unknown> = {
durationMs: 17,
output: SENTINEL,
outputBytes: 256,
};
Object.defineProperty(run, 'throwing', {
enumerable: true,
get() {
throw new Error(SENTINEL);
},
});
run.self = run;
const metadata = {
error: Object.assign(new Error(SENTINEL), { code: 'ENOSPC' }),
files: [{ filename: SENTINEL }],
method: 'get',
requestId: SENTINEL,
run,
status: 507,
};

capture.error(metadata, SENTINEL);
capture.child({ component: 'job' }).info({ success: true }, SENTINEL);
capture.flush();

expect(metadata.run).toBe(run);
expect(run.output).toBe(SENTINEL);
const output = chunks.join('');
expect(output).not.toContain(SENTINEL);
expect(output).toContain('Operational event');
expect(output).toContain('"errorCategory":"capacity"');
expect(output).toContain('"method":"GET"');
expect(output).toContain('"status":507');
expect(output).toContain('"durationMs":17');
expect(output).toContain('"outputBytes":256');
expect(output).toContain('"count":1');
expect(output).toContain('"component":"job"');
expect(output).toContain('"success":true');
});
});
29 changes: 26 additions & 3 deletions api/src/logger.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,29 @@
import pino from 'pino';
import { config } from './config';
import {
OPERATIONAL_LOG_MESSAGE,
sanitizeOperationalMetadata,
} from '../../shared/operational-log';

export const logger = pino({
level: config.log_level.toLowerCase(),
});
export function createOperationalLogger(destination?: pino.DestinationStream): pino.Logger {
const options: pino.LoggerOptions = {
level: config.log_level.toLowerCase(),
formatters: {
bindings: sanitizeOperationalMetadata,
},
hooks: {
logMethod(args, method) {
const metadata = sanitizeOperationalMetadata(args[0]);
if (Object.keys(metadata).length === 0) {
method.apply(this, [OPERATIONAL_LOG_MESSAGE]);
return;
}
method.apply(this, [metadata, OPERATIONAL_LOG_MESSAGE]);
},
},
};

return destination == null ? pino(options) : pino(options, destination);
}

export const logger = createOperationalLogger();
4 changes: 2 additions & 2 deletions api/src/tool-call-socket-proxy.ts
Original file line number Diff line number Diff line change
Expand Up @@ -662,8 +662,8 @@ if (require.main === module) {
.then(started => {
handle = started;
})
.catch(error => {
console.error('tool-call socket proxy failed to start', error);
.catch(() => {
console.error('tool-call socket proxy failed to start');
process.exit(1);
});
}
71 changes: 66 additions & 5 deletions docs/fork/patches.md
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,7 @@ States: Active, Review on sync, Draft, History only, Retired.
| Recover job completion when BullMQ events lag | Active | `b66e87e` | Upstream execution profiles and completion timeout |
| Reconnect the egress ledger after Redis outages | Active | `5e459dd` | Managed Redis |
| Bind JWT trust to verified issuers | Active | `f68acf0` | JWT verification keys and issuer configuration |
| Keep operational logs values-free | Active | `c87a14d`, `bf83dbe`, `689be7d`, `42a9743` | Winston and Pino logging sinks and public failures |

## Publish exact-SHA UZH images

Expand Down Expand Up @@ -278,6 +279,65 @@ Replay and drop condition:
recreates the Redis client after terminal disconnect, with a readiness
recovery test covering an outage longer than five attempts.

## Keep operational logs values-free

Required behavior:

- Normalize runtime log messages to fixed event text and retain only
code-declared operational metadata from an explicit allowlist.
- Remove identifiers, filenames, payloads, arbitrary errors and stacks, child
process output, network details, credentials, and caller-provided values
before Winston or Pino serializes them.
- Keep reason, stage, route, method, component, language, worker, and error
categories closed; unknown errors become `internal`.
- Sanitize without mutating caller-owned values or throwing on nested,
circular, repeated, buffered, array, error, or throwing-getter inputs.
- Return a fixed download failure body with HTTP 500 and never include the
upstream error message or a `details` field.

Owned paths:

- `api/src/logger.test.ts`
- `api/src/logger.ts`
- `service/src/logger.test.ts`
- `service/src/logger.ts`
- `shared/operational-log.ts`

Shared paths:

- `api/src/job.ts` — removes the identifier-bearing Pino child binding.
- `api/src/tool-call-socket-proxy.ts` — keeps its standalone console failure
message fixed and removes the raw startup error.
- `service/src/fileServerLogger.ts` and
`service/src/toolCallServerLogger.ts` — apply the shared policy to their
separately constructed Winston sinks.
- `service/src/service/router.ts` — logs download failures through the
values-free sink and returns only the fixed public body.
- `service/rollup.config.js`, `service/tsconfig.esm.json`, and
`service/tsconfig.json` — include the shared policy in service builds.

Source and current-upstream evidence:

- Commits `c87a14d755a406f50333bf6f8fd782ebd315ddec` and
`bf83dbe26a82cbdde97a377e5b416a5cc17729ec` define the central policy, sink
integrations, strict allowlist, bypass corrections, and capture tests.
- Commits `689be7da1f948c8dae036a92a356ed80ae32e71e` and
`42a97437fc7ef783d35b29cbd1b93b9d762c8afa` define the final inline generic
public download failure while retaining detailed diagnostics in sanitized
logs.
- Upstream `297fead1a0cd997b0e3e6e55f77fbe83b376be1a` and the reconciled UZH
baseline `83c4f7b105b6b3e69eda12701ad4ec437acba08f` serialize runtime messages,
identifiers, child output, and arbitrary error details without this policy.

Replay and drop condition:

- Reapply the shared allowlist at every enabled Winston and Pino constructor,
then re-inventory direct console, raw stream, child binding, serializer,
transport, and child-process forwarding bypasses.
- Drop only when upstream provides an equivalent values-free sink policy with
capture tests, a generic public download failure, and a current enabled-path
inventory containing no unknowns.

## Bind JWT trust to verified issuers

Required behavior:
Expand Down Expand Up @@ -334,8 +394,9 @@ Replay and drop condition:
- Every one of the 23 paths in the active merge-base-to-fork final-tree diff is
assigned above. The chart values, package resources, worker deployment, queue
module, and two routers are named shared seams in every contributing patch.
- Fork-authored non-merge commits were collapsed into the eight logical final
behaviors above. The issuer-trust package adds three owned paths outside the
original 23-path audit and shares the existing Helm README path. The only
fork merge commit is classified as history-only; no fork-authored final-tree
path is left unowned.
- Fork-authored non-merge commits were collapsed into the nine logical final
behaviors above. The values-free logging package adds thirteen owned or shared
paths outside the original 23-path audit. The issuer-trust package adds three
owned paths outside that audit and shares the existing Helm README path. The
only fork merge commit is classified as history-only; no fork-authored
final-tree path is left unowned.
2 changes: 1 addition & 1 deletion service/rollup.config.js
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ export default {
commonjs(),
typescript({
tsconfig: './tsconfig.esm.json',
include: ['src/**/*.ts', '../shared/telemetry-core.ts'],
include: ['src/**/*.ts', '../shared/operational-log.ts', '../shared/telemetry-core.ts'],
sourceMap: true,
declaration: false,
declarationMap: false,
Expand Down
5 changes: 3 additions & 2 deletions service/src/fileServerLogger.ts
Original file line number Diff line number Diff line change
@@ -1,14 +1,15 @@
import { format, transports, createLogger } from 'winston';
import { sanitizeOperationalLogInfo } from '../../shared/operational-log';

const logger = createLogger({
level: process.env.LOG_LEVEL ?? 'info',
defaultMeta: { service: 'file-server' },
format: format.combine(
format(sanitizeOperationalLogInfo)(),
format.timestamp(),
format.errors({ stack: true }),
format.json(),
),
transports: [new transports.Console()],
});

export default logger;
export default logger;
98 changes: 98 additions & 0 deletions service/src/logger.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,98 @@
import { createHash } from 'node:crypto';
import { Writable } from 'node:stream';
import { describe, expect, test } from 'bun:test';
import { createLogger, format, transports } from 'winston';
import { sanitizeOperationalMetadata } from '../../shared/operational-log';
import { operationalLogFormat } from './logger';

const SENTINEL = 'PRIVATE_service_log_9dQm2V7x';

describe('Winston operational logging', () => {
test('keeps only values-free operator metadata without mutating input', async () => {
const chunks: string[] = [];
const stream = new Writable({
write(chunk, _encoding, callback) {
chunks.push(chunk.toString());
callback();
},
});
const capture = createLogger({
format: format.combine(operationalLogFormat(), format.json()),
transports: [new transports.Stream({ stream })],
});

const run: Record<string, unknown> = {
durationMs: 12,
output: SENTINEL,
outputBytes: 128,
};
Object.defineProperty(run, 'throwing', {
enumerable: true,
get() {
throw new Error(SENTINEL);
},
});
run.self = run;
const metadata = {
error: Object.assign(new Error(SENTINEL), { code: 'ETIMEDOUT' }),
files: [{ filename: SENTINEL }],
method: 'post',
requestId: SENTINEL,
run,
status: 503,
};

capture.error(SENTINEL, metadata);
capture.end();
await new Promise<void>((resolve) => capture.on('finish', resolve));

expect(metadata.run).toBe(run);
expect(run.output).toBe(SENTINEL);
const output = chunks.join('');
for (const variant of [
SENTINEL,
createHash('sha256').update(SENTINEL).digest('hex'),
]) {
expect(output).not.toContain(variant);
}
expect(output).toContain('Operational event');
expect(output).toContain('"errorCategory":"timeout"');
expect(output).toContain('"method":"POST"');
expect(output).toContain('"status":503');
expect(output).toContain('"durationMs":12');
expect(output).toContain('"outputBytes":128');
expect(output).toContain('"count":1');
});

test('is total for circular, repeated, buffered, and throwing values', () => {
const repeated = { count: 2, secret: SENTINEL };
const value: Record<string, unknown> = {
files: Buffer.from(SENTINEL),
metrics: repeated,
run: repeated,
};
value.self = value;
Object.defineProperty(value, 'status', {
enumerable: true,
get() {
throw new Error(SENTINEL);
},
});

expect(() => sanitizeOperationalMetadata(value)).not.toThrow();
expect(sanitizeOperationalMetadata(value)).toEqual({
files: { bytes: Buffer.byteLength(SENTINEL) },
metrics: { count: 2 },
run: { count: 2 },
});
expect(sanitizeOperationalMetadata({
error: new Error(SENTINEL),
reason: SENTINEL,
stage: SENTINEL,
})).toEqual({ errorCategory: 'internal' });
expect(sanitizeOperationalMetadata({ errorCategory: SENTINEL }))
.toEqual({ errorCategory: 'internal' });
expect(sanitizeOperationalMetadata(new Error(SENTINEL)))
.toEqual({ errorCategory: 'internal' });
});
});
7 changes: 6 additions & 1 deletion service/src/logger.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,16 @@
import { format, transports, createLogger } from 'winston';
import { sanitizeOperationalLogInfo } from '../../shared/operational-log';

// A runtime string no longer carries evidence that it was a source literal.
// Normalize all messages and retain only structured, code-declared metadata.
export const operationalLogFormat = format(sanitizeOperationalLogInfo);

const logger = createLogger({
level: process.env.LOG_LEVEL ?? 'info',
defaultMeta: { service: process.env.SERVICE_NAME ?? 'service-api' },
format: format.combine(
operationalLogFormat(),
format.timestamp(),
format.errors({ stack: true }),
format.json(),
),
transports: [new transports.Console()],
Expand Down
5 changes: 1 addition & 4 deletions service/src/service/router.ts
Original file line number Diff line number Diff line change
Expand Up @@ -333,10 +333,7 @@ router.get('/download/:session_id/:fileId', downloadLimiter, sessionAuth, async
const errorDetails = getAxiosErrorDetails(error);
logger.error(`[${INSTANCE_ID}] Session ID: ${session_id} | File ID: ${fileId} | Error downloading file:`, errorDetails);

return res.status(500).json({
error: 'Error downloading file',
details: (error as Error).message
});
return res.status(500).json({ error: 'Error downloading file' });
}
});

Expand Down
3 changes: 2 additions & 1 deletion service/src/toolCallServerLogger.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,12 @@
import { format, transports, createLogger } from 'winston';
import { sanitizeOperationalLogInfo } from '../../shared/operational-log';

const logger = createLogger({
level: process.env.LOG_LEVEL ?? 'info',
defaultMeta: { service: 'tool-call-server' },
format: format.combine(
format(sanitizeOperationalLogInfo)(),
format.timestamp(),
format.errors({ stack: true }),
format.json(),
),
transports: [new transports.Console()],
Expand Down
2 changes: 1 addition & 1 deletion service/tsconfig.esm.json
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@
"@/*": ["src/*"]
}
},
"include": ["src/**/*.ts", "../shared/telemetry-core.ts"],
"include": ["src/**/*.ts", "../shared/operational-log.ts", "../shared/telemetry-core.ts"],
"exclude": [
"node_modules",
"**/*.spec.ts",
Expand Down
2 changes: 1 addition & 1 deletion service/tsconfig.json
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@
"@/*": ["src/*"]
}
},
"include": ["src/**/*.ts", "../shared/telemetry-core.ts"],
"include": ["src/**/*.ts", "../shared/operational-log.ts", "../shared/telemetry-core.ts"],
"exclude": [
"node_modules",
"**/*.spec.ts",
Expand Down
Loading
Loading