419 lines
19 KiB
TypeScript
419 lines
19 KiB
TypeScript
import assert from 'node:assert/strict';
|
|
import { Writable } from 'node:stream';
|
|
import test from 'node:test';
|
|
import type { ActiveSession } from '../src/auth.js';
|
|
import { loadConfig } from '../src/config.js';
|
|
import { getPool } from '../src/db.js';
|
|
import {
|
|
diagnosticDurationMs,
|
|
diagnosticError,
|
|
diagnosticRequestPath,
|
|
normalizeRequestId
|
|
} from '../src/diagnostics.js';
|
|
import { buildServer, createControlPlaneLogger } from '../src/server.js';
|
|
import { TaskError, TaskService, type TaskEvent } from '../src/task-service.js';
|
|
|
|
function testConfig(overrides: NodeJS.ProcessEnv = {}) {
|
|
return loadConfig({
|
|
NODE_ENV: 'test',
|
|
FIELD_ENCRYPTION_KEY: Buffer.alloc(32, 41).toString('base64'),
|
|
DATABASE_URL: 'postgresql://invalid:invalid@127.0.0.1:1/invalid',
|
|
...overrides
|
|
});
|
|
}
|
|
|
|
function logCollector(): { destination: Writable; records: Array<Record<string, unknown>> } {
|
|
const chunks: string[] = [];
|
|
const records: Array<Record<string, unknown>> = [];
|
|
const destination = new Writable({
|
|
write(chunk, _encoding, callback) {
|
|
chunks.push(String(chunk));
|
|
const lines = chunks.join('').split('\n');
|
|
chunks.length = 0;
|
|
const remainder = lines.pop() || '';
|
|
if (remainder) chunks.push(remainder);
|
|
for (const line of lines) {
|
|
if (line.trim()) records.push(JSON.parse(line) as Record<string, unknown>);
|
|
}
|
|
callback();
|
|
}
|
|
});
|
|
return { destination, records };
|
|
}
|
|
|
|
const heartbeatSession: ActiveSession = {
|
|
id: '33333333-3333-4333-8333-333333333333',
|
|
csrfTokenHash: Buffer.alloc(32),
|
|
user: {
|
|
id: '22222222-2222-4222-8222-222222222222',
|
|
organizationId: '11111111-1111-4111-8111-111111111111',
|
|
username: 'heartbeat-test',
|
|
role: 'user',
|
|
erpAccount: 'test-erp'
|
|
}
|
|
};
|
|
|
|
test('diagnostic errors preserve code and stack location without leaking the error message', () => {
|
|
const secret = 'customer-secret-value';
|
|
const error = new Error(`download https://user:password@example.test/list.xlsx?token=${secret}`) as Error & {
|
|
code: string;
|
|
errno: number;
|
|
syscall: string;
|
|
};
|
|
error.code = 'ECONNRESET';
|
|
error.errno = -54;
|
|
error.syscall = 'read';
|
|
const metadata = diagnosticError(error, 'download_failed');
|
|
const serialized = JSON.stringify(metadata);
|
|
assert.equal(metadata.error_code, 'ECONNRESET');
|
|
assert.equal(metadata.error_name, 'Error');
|
|
assert.match(String(metadata.error_fingerprint), /^[a-f0-9]{24}$/u);
|
|
assert.equal(metadata.error_errno, -54);
|
|
assert.equal(metadata.error_syscall, 'read');
|
|
assert.doesNotMatch(serialized, /customer-secret-value|password|example\.test|list\.xlsx/u);
|
|
});
|
|
|
|
test('diagnostic request identifiers and paths are stable and query-safe', () => {
|
|
assert.equal(normalizeRequestId('request:wechat:12345678'), 'request:wechat:12345678');
|
|
const generated = normalizeRequestId('token=must-not-be-used');
|
|
assert.match(generated, /^[a-f0-9-]{36}$/u);
|
|
assert.doesNotMatch(generated, /token/u);
|
|
assert.equal(diagnosticRequestPath('/api/tasks/TASK-1?token=secret#fragment'), '/api/tasks/TASK-1');
|
|
const startedAt = process.hrtime.bigint() - 2_000_000n;
|
|
assert.ok(diagnosticDurationMs(startedAt) >= 1);
|
|
});
|
|
|
|
test('control-plane logger redacts credentials and includes deployment identity', async () => {
|
|
const { destination, records } = logCollector();
|
|
const logger = createControlPlaneLogger(testConfig({ DEPLOYMENT_REVISION: 'commit-2360506' }), destination);
|
|
logger.info({
|
|
diagnostic_event: 'test.redaction',
|
|
password: 'root-secret',
|
|
nested: { token: 'nested-secret' },
|
|
safe_value: 'visible'
|
|
}, 'diagnostic test');
|
|
await new Promise((resolve) => setImmediate(resolve));
|
|
assert.equal(records.length, 1);
|
|
assert.equal(records[0].service, 'ltjt-control-plane');
|
|
assert.equal(records[0].deployment_revision, 'commit-2360506');
|
|
assert.equal(records[0].password, '[REDACTED]');
|
|
assert.deepEqual(records[0].nested, { token: '[REDACTED]' });
|
|
assert.equal(records[0].safe_value, 'visible');
|
|
});
|
|
|
|
test('HTTP diagnostics reuse one request ID and never log query values', async () => {
|
|
const { destination, records } = logCollector();
|
|
const { app } = await buildServer({
|
|
config: testConfig(),
|
|
startParserLoop: false,
|
|
loggerDestination: destination,
|
|
parser: {
|
|
async parse() {
|
|
return { blockers: ['test parser'] };
|
|
},
|
|
async checkConnection() {
|
|
return { ok: false, configured: false };
|
|
}
|
|
}
|
|
});
|
|
app.get('/api/diagnostic-test', async () => ({ ok: true }));
|
|
const response = await app.inject({
|
|
method: 'GET',
|
|
url: '/api/diagnostic-test?token=query-secret',
|
|
headers: { 'x-request-id': 'request:test:12345678' }
|
|
});
|
|
assert.equal(response.statusCode, 200);
|
|
assert.equal(response.headers['x-request-id'], 'request:test:12345678');
|
|
await app.close();
|
|
await new Promise((resolve) => setImmediate(resolve));
|
|
|
|
const started = records.find((record) => record.diagnostic_event === 'http.request.started');
|
|
const completed = records.find((record) => record.diagnostic_event === 'http.request.completed');
|
|
assert.equal(started?.request_id, 'request:test:12345678');
|
|
assert.equal(completed?.request_id, 'request:test:12345678');
|
|
assert.equal(started?.path, '/api/diagnostic-test');
|
|
assert.equal(completed?.path, '/api/diagnostic-test');
|
|
assert.equal(completed?.status_code, 200);
|
|
assert.doesNotMatch(JSON.stringify(records), /query-secret/u);
|
|
});
|
|
|
|
test('successful heartbeats, health probes and workbench polling stay silent while their handlers still run', async (t) => {
|
|
const { destination, records } = logCollector();
|
|
const config = testConfig({ LOG_LEVEL: 'debug' });
|
|
const { app, auth, tasks } = await buildServer({
|
|
config,
|
|
startParserLoop: false,
|
|
loggerDestination: destination,
|
|
parser: { async parse() { return { blockers: ['test parser'] }; } }
|
|
});
|
|
t.after(() => app.close());
|
|
const query = t.mock.method(getPool(config), 'query', async () => ({ rows: [{ applied: true }] }));
|
|
t.mock.method(auth, 'getActiveSession', async () => heartbeatSession);
|
|
t.mock.method(auth, 'verifyCsrf', async () => true);
|
|
const listTasks = t.mock.method(tasks, 'listTasksPage', async () => ({
|
|
tasks: [], total: 0, offset: 0, limit: 200, has_more: false
|
|
}));
|
|
t.mock.method(tasks, 'parserConnectionEvidence', async () => ({
|
|
authenticated: null, source: null, lastSuccessAt: null, lastAuthFailureAt: null, lastAuthFailureCode: null
|
|
}));
|
|
const worker = { execution_ready: true, erp_account_matched: true, worker_connection_id: 'test-browser' };
|
|
const heartbeat = t.mock.method(tasks, 'heartbeat', async (..._args: Parameters<TaskService['heartbeat']>) => worker);
|
|
records.length = 0;
|
|
|
|
for (const method of ['GET', 'HEAD'] as const) {
|
|
for (const path of ['/health/live', '/health/ready', '/api/status', '/api/tasks']) {
|
|
const response = await app.inject({
|
|
method,
|
|
url: `${path}?token=probe-secret`,
|
|
headers: { 'x-request-id': 'request:probe:12345678' }
|
|
});
|
|
assert.equal(response.statusCode, 200);
|
|
assert.equal(response.headers['x-request-id'], 'request:probe:12345678');
|
|
if (method === 'GET') assert.equal(response.json().ok, true);
|
|
}
|
|
}
|
|
for (let index = 0; index < 3; index += 1) {
|
|
const response = await app.inject({
|
|
method: 'POST',
|
|
url: '/api/connections/heartbeat?token=probe-secret',
|
|
headers: { 'x-request-id': `request:heartbeat:${index}` },
|
|
payload: { connection_id: 'test-browser', extension_version: 'test-version' }
|
|
});
|
|
assert.equal(response.statusCode, 200);
|
|
assert.equal(response.headers['x-request-id'], `request:heartbeat:${index}`);
|
|
assert.deepEqual(response.json(), { ok: true, connected: true, ...worker });
|
|
}
|
|
assert.equal(query.mock.callCount(), 8);
|
|
assert.equal(listTasks.mock.callCount(), 2);
|
|
assert.equal(heartbeat.mock.callCount(), 3);
|
|
assert.equal(heartbeat.mock.calls[0].arguments[1], 'test-browser');
|
|
assert.equal(heartbeat.mock.calls[0].arguments[2], 'test-version');
|
|
await new Promise((resolve) => setImmediate(resolve));
|
|
assert.deepEqual(records, []);
|
|
});
|
|
|
|
test('failed heartbeats and readiness probes retain severity, error codes and request correlation', async (t) => {
|
|
const { destination, records } = logCollector();
|
|
const config = testConfig();
|
|
const { app, auth, tasks } = await buildServer({
|
|
config,
|
|
startParserLoop: false,
|
|
loggerDestination: destination,
|
|
parser: { async parse() { return { blockers: ['test parser'] }; } }
|
|
});
|
|
t.after(() => app.close());
|
|
let session: ActiveSession | null = null;
|
|
let heartbeatError: Error = new TaskError('browser_account_inactive', 'inactive', 403);
|
|
t.mock.method(auth, 'getActiveSession', async () => session);
|
|
t.mock.method(auth, 'verifyCsrf', async () => true);
|
|
t.mock.method(tasks, 'heartbeat', async () => { throw heartbeatError; });
|
|
t.mock.method(getPool(config), 'query', async () => {
|
|
throw Object.assign(new Error('database-secret'), { code: 'ECONNRESET' });
|
|
});
|
|
records.length = 0;
|
|
|
|
const cases = [
|
|
{ status: 401, error: 'authentication_required', payload: { connection_id: 'test-browser' } },
|
|
{ status: 400, error: 'invalid_request', payload: {} },
|
|
{ status: 403, error: 'browser_account_inactive', payload: { connection_id: 'test-browser' } },
|
|
{ status: 500, error: 'ECONNRESET', payload: { connection_id: 'test-browser' } },
|
|
{ status: 503, error: 'ECONNRESET', payload: undefined }
|
|
];
|
|
for (const scenario of cases) {
|
|
if (scenario.status !== 401) session = heartbeatSession;
|
|
if (scenario.status === 500) {
|
|
heartbeatError = Object.assign(new Error('heartbeat-secret'), { code: 'ECONNRESET' });
|
|
}
|
|
const requestId = `request:failure:${scenario.status}`;
|
|
const path = scenario.status === 503 ? '/health/ready' : '/api/connections/heartbeat';
|
|
const response = await app.inject({
|
|
method: scenario.status === 503 ? 'GET' : 'POST',
|
|
url: `${path}?token=probe-secret`,
|
|
headers: { 'x-request-id': requestId },
|
|
...(scenario.payload ? { payload: scenario.payload } : {})
|
|
});
|
|
assert.equal(response.statusCode, scenario.status);
|
|
assert.equal(response.headers['x-request-id'], requestId);
|
|
const completed = records.find((record) => record.diagnostic_event === 'http.request.completed'
|
|
&& record.request_id === requestId);
|
|
assert.equal(completed?.status_code, scenario.status);
|
|
assert.equal(completed?.path, path);
|
|
assert.equal(completed?.level, scenario.status >= 500 ? 50 : 40);
|
|
assert.equal(typeof completed?.duration_ms, 'number');
|
|
assert.ok(records.some((record) => record.error_code === scenario.error
|
|
&& record.request_id === requestId), `${scenario.status}: ${scenario.error}`);
|
|
}
|
|
assert.equal(records.some((record) => record.diagnostic_event === 'http.request.started'), false);
|
|
assert.doesNotMatch(JSON.stringify(records), /probe-secret|heartbeat-secret|database-secret/u);
|
|
});
|
|
|
|
test('polling failures stay visible and task writes and detail reads keep access logs', async (t) => {
|
|
const { destination, records } = logCollector();
|
|
const config = testConfig();
|
|
const { app, auth, tasks } = await buildServer({
|
|
config,
|
|
startParserLoop: false,
|
|
loggerDestination: destination,
|
|
parser: { async parse() { return { blockers: ['test parser'] }; } }
|
|
});
|
|
t.after(() => app.close());
|
|
let session: ActiveSession | null = null;
|
|
t.mock.method(auth, 'getActiveSession', async () => session);
|
|
t.mock.method(auth, 'verifyCsrf', async () => true);
|
|
t.mock.method(getPool(config), 'query', async () => ({ rows: [{ applied: true }] }));
|
|
const failQuery = async () => { throw Object.assign(new Error('query-secret'), { code: 'ECONNRESET' }); };
|
|
t.mock.method(tasks, 'listTasksPage', failQuery);
|
|
t.mock.method(tasks, 'parserConnectionEvidence', failQuery);
|
|
const task = { task_id: 'TASK-TEST', status: 'awaiting_attachment' } as Awaited<ReturnType<TaskService['createTask']>>;
|
|
t.mock.method(tasks, 'createTask', async () => task);
|
|
t.mock.method(tasks, 'getTask', async () => task);
|
|
records.length = 0;
|
|
|
|
const cases = [
|
|
{ url: '/api/tasks?status=active', status: 401, error: 'authentication_required' },
|
|
{ url: '/api/tasks?limit=0', status: 400, error: 'invalid_request' },
|
|
{ url: '/api/tasks?status=confirmed', status: 500, error: 'ECONNRESET' },
|
|
{ url: '/api/status', status: 500, error: 'ECONNRESET' }
|
|
];
|
|
for (const [index, scenario] of cases.entries()) {
|
|
if (index > 0) session = heartbeatSession;
|
|
const requestId = `request:polling:${index}`;
|
|
const response = await app.inject({ method: 'GET', url: scenario.url, headers: { 'x-request-id': requestId } });
|
|
assert.equal(response.statusCode, scenario.status);
|
|
const logs = records.filter((record) => record.request_id === requestId);
|
|
assert.equal(logs.some((record) => record.diagnostic_event === 'http.request.started'), false);
|
|
assert.ok(logs.some((record) => record.error_code === scenario.error));
|
|
assert.ok(logs.some((record) => record.diagnostic_event === 'http.request.completed'
|
|
&& record.status_code === scenario.status && record.level === (scenario.status >= 500 ? 50 : 40)));
|
|
}
|
|
for (const method of ['POST', 'GET'] as const) {
|
|
const requestId = `request:business:${method}`;
|
|
const response = await app.inject({
|
|
method,
|
|
url: method === 'POST' ? '/api/tasks' : '/api/tasks/TASK-TEST',
|
|
headers: { 'x-request-id': requestId },
|
|
...(method === 'POST' ? { payload: { raw_text: 'business-secret' } } : {})
|
|
});
|
|
assert.equal(response.statusCode, 200);
|
|
assert.equal(response.json().task.task_id, task.task_id);
|
|
const logs = records.filter((record) => record.request_id === requestId);
|
|
assert.ok(logs.some((record) => record.diagnostic_event === 'http.request.started' && record.level === 30));
|
|
assert.ok(logs.some((record) => record.diagnostic_event === 'http.request.completed' && record.level === 30));
|
|
}
|
|
assert.doesNotMatch(JSON.stringify(records), /query-secret|business-secret/u);
|
|
});
|
|
|
|
test('automation settings reads are quiet but failures and actual settings changes remain visible', async (t) => {
|
|
const { destination, records } = logCollector();
|
|
const { app, auth, tasks } = await buildServer({
|
|
config: testConfig({ LOG_LEVEL: 'debug' }),
|
|
startParserLoop: false,
|
|
loggerDestination: destination,
|
|
parser: { async parse() { return { blockers: ['test parser'] }; } }
|
|
});
|
|
t.after(() => app.close());
|
|
const admin: ActiveSession = { ...heartbeatSession, user: { ...heartbeatSession.user, role: 'admin' } };
|
|
let session: ActiveSession | null = admin;
|
|
let failRead = false;
|
|
const settings = { organization_id: admin.user.organizationId, enabled: true };
|
|
t.mock.method(auth, 'getActiveSession', async () => session);
|
|
t.mock.method(auth, 'verifyCsrf', async () => true);
|
|
const read = t.mock.method(tasks, 'getAutomationSettings', async () => {
|
|
if (failRead) throw Object.assign(new Error('settings-secret'), { code: 'ECONNRESET' });
|
|
return settings;
|
|
});
|
|
const write = t.mock.method(tasks, 'setAutomationEnabled', async () => settings);
|
|
records.length = 0;
|
|
for (const method of ['GET', 'HEAD'] as const) {
|
|
const response = await app.inject({ method, url: '/api/settings/automation?token=probe-secret' });
|
|
assert.equal(response.statusCode, 200);
|
|
if (method === 'GET') assert.deepEqual(response.json().settings, settings);
|
|
}
|
|
assert.equal(read.mock.callCount(), 2);
|
|
assert.equal(records.length, 0);
|
|
|
|
for (const status of [401, 403, 500]) {
|
|
session = status === 401 ? null : status === 403 ? heartbeatSession : admin;
|
|
failRead = status === 500;
|
|
const requestId = `request:settings:${status}`;
|
|
const response = await app.inject({
|
|
method: 'GET', url: '/api/settings/automation', headers: { 'x-request-id': requestId }
|
|
});
|
|
assert.equal(response.statusCode, status);
|
|
const logs = records.filter((record) => record.request_id === requestId);
|
|
assert.equal(logs.some((record) => record.diagnostic_event === 'http.request.started'), false);
|
|
assert.ok(logs.some((record) => record.diagnostic_event === 'http.request.completed'
|
|
&& record.status_code === status && record.level === (status >= 500 ? 50 : 40)
|
|
&& typeof record.duration_ms === 'number'));
|
|
assert.ok(logs.some((record) => record.error_code));
|
|
}
|
|
session = admin;
|
|
const requestId = 'request:settings:write';
|
|
const response = await app.inject({
|
|
method: 'PUT', url: '/api/settings/automation', headers: { 'x-request-id': requestId }, payload: { enabled: true }
|
|
});
|
|
assert.equal(response.statusCode, 200);
|
|
assert.equal(write.mock.callCount(), 1);
|
|
const logs = records.filter((record) => record.request_id === requestId);
|
|
assert.ok(logs.some((record) => record.diagnostic_event === 'http.request.started' && record.level === 30));
|
|
assert.ok(logs.some((record) => record.diagnostic_event === 'http.request.completed' && record.level === 30));
|
|
assert.doesNotMatch(JSON.stringify(records), /settings-secret|probe-secret/u);
|
|
});
|
|
|
|
test('task state and audit diagnostics record keys but never business values', async () => {
|
|
const logs: Array<Record<string, unknown>> = [];
|
|
const service = new TaskService(
|
|
testConfig(),
|
|
{} as never,
|
|
{
|
|
info(metadata) { logs.push(metadata); },
|
|
warn(metadata) { logs.push(metadata); },
|
|
error(metadata) { logs.push(metadata); }
|
|
}
|
|
) as unknown as {
|
|
notify(event: TaskEvent): void;
|
|
audit(
|
|
client: { query: (...args: unknown[]) => Promise<{ rowCount: number }> },
|
|
context: { organizationId: string; userId: string; requestId: string },
|
|
eventType: string,
|
|
entityId: string,
|
|
metadata: Record<string, unknown>
|
|
): Promise<void>;
|
|
};
|
|
service.notify({
|
|
id: 8,
|
|
organization_id: 'org-secret',
|
|
task_id: 'TASK-DIAGNOSTIC-1',
|
|
status: 'awaiting_attachment',
|
|
stage: 'input',
|
|
message: 'customer-secret-message',
|
|
payload: { customer_name: 'customer-secret-value', row_count: 12 },
|
|
created_at: new Date().toISOString()
|
|
});
|
|
await service.audit(
|
|
{ async query() { return { rowCount: 1 }; } },
|
|
{ organizationId: 'org-secret', userId: 'user-secret', requestId: 'request:audit:12345678' },
|
|
'task.passenger_roster_attachment_rejected',
|
|
'TASK-DIAGNOSTIC-1',
|
|
{ customer_name: 'customer-secret-value', error_code: 'roster_file_invalid' }
|
|
);
|
|
|
|
assert.ok(logs.some((log) => log.diagnostic_event === 'task.state.emitted'
|
|
&& Array.isArray(log.payload_keys)
|
|
&& (log.payload_keys as string[]).includes('customer_name')));
|
|
assert.ok(logs.some((log) => log.diagnostic_event === 'audit.event.staged'
|
|
&& log.request_id === 'request:audit:12345678'));
|
|
assert.doesNotMatch(JSON.stringify(logs), /customer-secret-value|customer-secret-message|org-secret|user-secret/u);
|
|
});
|
|
|
|
test('production configuration rejects raw AgentBus payload logging', () => {
|
|
assert.throws(
|
|
() => testConfig({ NODE_ENV: 'production', AGENTBUS_LOG_PAYLOADS: 'true' }),
|
|
/AGENTBUS_LOG_PAYLOADS must remain false in production/u
|
|
);
|
|
assert.throws(
|
|
() => testConfig({ LOG_LEVEL: 'verbose' }),
|
|
/Invalid enum value/u
|
|
);
|
|
});
|