Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
384 changes: 384 additions & 0 deletions packages/core/src/telemetry/log-to-span-processor.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -751,4 +751,388 @@ describe('LogToSpanProcessor', () => {
deriveTraceId('fresh-session'),
);
});

describe('export failure diagnostics', () => {
function makeFailingProcessor(error: Error | undefined) {
const failingExporter = {
export: vi.fn((_spans, cb) => cb({ code: 1, error })),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter;
return new LogToSpanProcessor(failingExporter, 60000);
}

async function flushOne(p: LogToSpanProcessor) {
p.onEmit({
body: 'event',
hrTime: [1000, 0] as [number, number],
attributes: { 'event.name': 'event' },
} as unknown as ReadableLogRecord);
await p.forceFlush();
}

it('falls back to error.name when message is empty (HTTP/2 / stripped reason phrase)', async () => {
await processor.shutdown();
const err = Object.assign(new Error(''), {
name: 'OTLPExporterError',
code: 403,
data: 'Forbidden: invalid license',
});
processor = makeFailingProcessor(err);
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);

try {
await flushOne(processor);
expect(stderrWrite).toHaveBeenCalledWith(
'[LogToSpan] export failed: code=1 error="OTLPExporterError" httpCode=403 data="Forbidden: invalid license"\n',
);
} finally {
stderrWrite.mockRestore();
}
});

it('JSON-escapes embedded newlines in message and data so the record stays on one line', async () => {
await processor.shutdown();
const err = Object.assign(new Error('line1\nline2'), {
name: 'OTLPExporterError',
code: 500,
data: '{\n "error": "boom"\n}',
});
const sink = vi.fn();
processor = new LogToSpanProcessor(
{
export: vi.fn((_s, cb) => cb({ code: 1, error: err })),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, diagnosticsSink: sink },
);

await flushOne(processor);
const msg = sink.mock.calls[0][0] as string;
expect(msg).not.toContain('\n');
expect(msg).toContain('error="line1\\nline2"');
expect(msg).toContain('data="{\\n \\"error\\": \\"boom\\"\\n}"');
});

it('truncates response data snippets to 200 characters before stringifying', async () => {
await processor.shutdown();
const err = Object.assign(new Error(''), {
name: 'OTLPExporterError',
code: 500,
data: 'x'.repeat(500),
});
processor = makeFailingProcessor(err);
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);

try {
await flushOne(processor);
const msg = stderrWrite.mock.calls[0][0] as string;
expect(msg).toContain('httpCode=500');
expect(msg).toContain(`data="${'x'.repeat(200)}"`);
expect(msg).not.toContain('x'.repeat(201));
} finally {
stderrWrite.mockRestore();
}
});

it('omits httpCode when err.code is a non-numeric networking code (ECONNREFUSED)', async () => {
await processor.shutdown();
const err = Object.assign(new Error('connect ECONNREFUSED 127.0.0.1'), {
code: 'ECONNREFUSED',
});
processor = makeFailingProcessor(err);
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);

try {
await flushOne(processor);
const msg = stderrWrite.mock.calls[0][0] as string;
expect(msg).not.toContain('httpCode=');
expect(msg).toContain('error="connect ECONNREFUSED 127.0.0.1"');
} finally {
stderrWrite.mockRestore();
}
});

it('reports error="unknown" when result.error is missing', async () => {
await processor.shutdown();
processor = makeFailingProcessor(undefined);
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);

try {
await flushOne(processor);
expect(stderrWrite).toHaveBeenCalledWith(
'[LogToSpan] export failed: code=1 error="unknown"\n',
);
} finally {
stderrWrite.mockRestore();
}
});

it('omits data field when err.data is a non-string truthy value (e.g. Buffer)', async () => {
await processor.shutdown();
const err = Object.assign(new Error('fail'), {
code: 500,
data: Buffer.from('binary'),
});
processor = makeFailingProcessor(err as unknown as Error);
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);

try {
await flushOne(processor);
const msg = stderrWrite.mock.calls[0][0] as string;
expect(msg).toContain('httpCode=500');
expect(msg).not.toContain('data=');
} finally {
stderrWrite.mockRestore();
}
});

it('falls back to "unknown" when both message and name are empty (e.g. minified Error)', async () => {
await processor.shutdown();
const err = Object.assign(new Error(''), { name: '' });
processor = makeFailingProcessor(err);
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);

try {
await flushOne(processor);
expect(stderrWrite).toHaveBeenCalledWith(
'[LogToSpan] export failed: code=1 error="unknown"\n',
);
} finally {
stderrWrite.mockRestore();
}
});

it('omits data field when err.data is an empty string (guards against length>0 loosening)', async () => {
await processor.shutdown();
const err = Object.assign(new Error('fail'), { code: 500, data: '' });
processor = makeFailingProcessor(err);
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);

try {
await flushOne(processor);
const msg = stderrWrite.mock.calls[0][0] as string;
expect(msg).toContain('httpCode=500');
expect(msg).not.toContain('data=');
} finally {
stderrWrite.mockRestore();
}
});

it('routes diagnostics to an injected sink without touching stderr', async () => {
await processor.shutdown();
const sink = vi.fn();
const stderrWrite = vi
.spyOn(process.stderr, 'write')
.mockImplementation(() => true);
const failingExporter = {
export: vi.fn((_spans, cb) =>
cb({ code: 1, error: new Error('boom') }),
),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter;
processor = new LogToSpanProcessor(failingExporter, {
flushIntervalMs: 60000,
diagnosticsSink: sink,
});

try {
await flushOne(processor);
expect(sink).toHaveBeenCalledWith(
'[LogToSpan] export failed: code=1 error="boom"',
);
expect(stderrWrite).not.toHaveBeenCalled();
} finally {
stderrWrite.mockRestore();
}
});

it('routes buffer-overflow warnings through the injected sink', async () => {
await processor.shutdown();
const sink = vi.fn();
processor = new LogToSpanProcessor(
{
export: vi.fn((_s, cb) => cb({ code: 0 })),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, maxBufferSize: 2, diagnosticsSink: sink },
);

for (const body of ['a', 'b', 'c']) {
processor.onEmit({
body,
hrTime: [1000, 0] as [number, number],
attributes: { 'event.name': body },
} as unknown as ReadableLogRecord);
}

expect(sink).toHaveBeenCalledWith(
expect.stringContaining('[LogToSpan] buffer exceeded max size'),
);
});

it('routes export timeout through the injected sink', async () => {
await processor.shutdown();
vi.useFakeTimers();
const sink = vi.fn();
try {
processor = new LogToSpanProcessor(
{
// Never invoke the callback — force the timeout branch.
export: vi.fn(),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, diagnosticsSink: sink },
);
processor.onEmit({
body: 'event',
hrTime: [1000, 0] as [number, number],
attributes: { 'event.name': 'event' },
} as unknown as ReadableLogRecord);

const flushPromise = processor.forceFlush();
// EXPORT_TIMEOUT_MS is 30_000 — advance past it.
await vi.advanceTimersByTimeAsync(31_000);
await flushPromise;

expect(sink).toHaveBeenCalledWith(
expect.stringMatching(
/^\[LogToSpan] export timeout after \d+ms \(\d+ span\(s\)\)$/,
),
);
} finally {
vi.useRealTimers();
}
});

it('routes export-threw (synchronous exporter exception) through the injected sink', async () => {
await processor.shutdown();
const sink = vi.fn();
processor = new LogToSpanProcessor(
{
export: vi.fn(() => {
throw new Error('exporter exploded synchronously');
}),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, diagnosticsSink: sink },
);

await flushOne(processor);
expect(sink).toHaveBeenCalledWith(
'[LogToSpan] export threw: error="exporter exploded synchronously"',
);
});

it('surfaces httpCode/data when a sync-thrown error carries OTLPExporterError fields', async () => {
await processor.shutdown();
const sink = vi.fn();
const err = Object.assign(new Error('Bad Request'), {
name: 'OTLPExporterError',
code: 400,
data: 'malformed payload',
});
processor = new LogToSpanProcessor(
{
export: vi.fn(() => {
throw err;
}),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, diagnosticsSink: sink },
);

await flushOne(processor);
expect(sink).toHaveBeenCalledWith(
'[LogToSpan] export threw: error="Bad Request" httpCode=400 data="malformed payload"',
);
});

it('JSON-escapes export-threw payloads with embedded newlines (single-line invariant)', async () => {
await processor.shutdown();
const sink = vi.fn();
processor = new LogToSpanProcessor(
{
export: vi.fn(() => {
throw new Error('line1\nline2');
}),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, diagnosticsSink: sink },
);

await flushOne(processor);
const msg = sink.mock.calls[0][0] as string;
expect(msg).not.toContain('\n');
expect(msg).toBe('[LogToSpan] export threw: error="line1\\nline2"');
});

it('handles non-Error throws (e.g. throw "string") in the export-threw path', async () => {
await processor.shutdown();
const sink = vi.fn();
processor = new LogToSpanProcessor(
{
export: vi.fn(() => {
// Deliberate non-Error throw to exercise the String(err) branch.
// eslint-disable-next-line no-restricted-syntax
throw 'raw string thrown';
}),
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, diagnosticsSink: sink },
);

await flushOne(processor);
expect(sink).toHaveBeenCalledWith(
'[LogToSpan] export threw: error="raw string thrown"',
);
});

it('keeps processing exports after the sink throws', async () => {
await processor.shutdown();
const sink = vi.fn(() => {
throw new Error('sink exploded');
});
const exportFn = vi.fn(
(_spans, cb: (r: { code: number; error?: Error }) => void) =>
cb({ code: 1, error: new Error('boom') }),
);
processor = new LogToSpanProcessor(
{
export: exportFn,
shutdown: vi.fn().mockResolvedValue(undefined),
forceFlush: vi.fn().mockResolvedValue(undefined),
} as unknown as SpanExporter,
{ flushIntervalMs: 60000, diagnosticsSink: sink },
);

await flushOne(processor);
await flushOne(processor);

expect(exportFn).toHaveBeenCalledTimes(2);
expect(sink).toHaveBeenCalledTimes(2);
});
});
});
Loading
Loading