diff --git a/lib/flush.js b/lib/flush.js index 775ada7..eb937ea 100644 --- a/lib/flush.js +++ b/lib/flush.js @@ -63,81 +63,139 @@ function getScope() { return cachedScope; } -function encodeAttributeValue(value) { - switch (typeof value) { - case 'string': - return { stringValue: value }; - case 'number': - return Number.isInteger(value) - ? { intValue: String(value) } - : { doubleValue: value }; - case 'boolean': - return { boolValue: value }; - default: - return { stringValue: String(value) }; +// Characters that can need escaping in a JSON string. Surrogates are +// included because a lone one must be escaped, so any string with a +// surrogate goes through JSON.stringify, which handles pairs and lone +// ones alike. +const kNeedsEscape = /[\\"\x00-\x1f\ud800-\udfff]/; + +// Encodes a string as a JSON string value. A string with none of the +// characters above is valid JSON once quoted, exactly what JSON.stringify +// would produce, so it skips the call. +function jsonString(value) { + if (!kNeedsEscape.test(value)) return `"${value}"`; + return JSON.stringify(value); +} + +// Encoded key prefixes, cached since the instrumentations write the same +// few keys on every span. The cap keeps a stream of distinct keys from +// growing the cache without bound. +const kKeyPrefixes = new Map(); +function keyPrefix(key) { + let prefix = kKeyPrefixes.get(key); + if (prefix === undefined) { + prefix = `{"key":${jsonString(key)},"value":`; + if (kKeyPrefixes.size < 256) kKeyPrefixes.set(key, prefix); } + return prefix; +} + +// Encodes a single attribute value as an OTLP AnyValue JSON fragment. +function encodeAttributeValueJson(value) { + if (typeof value === 'string') return `{"stringValue":${jsonString(value)}}`; + if (typeof value === 'number') { + if (Number.isInteger(value)) return `{"intValue":"${value}"}`; + // NaN and the infinities have no JSON number form. ProtoJSON writes + // them as the strings "NaN", "Infinity", and "-Infinity". + if (!Number.isFinite(value)) return `{"doubleValue":"${value}"}`; + return `{"doubleValue":${value}}`; + } + if (typeof value === 'boolean') return `{"boolValue":${value}}`; + return `{"stringValue":${jsonString(String(value))}}`; +} + +// Converts epoch milliseconds into an OTLP nanosecond string. For positive +// safe integers, appending six zeros is exact and skips the BigInt math. +// Anything else takes the BigInt path, so the result always matches it, +// and non-finite input still throws, which drops the span. +function timeToUnixNano(t) { + const ms = Math.round(t); + if (ms > 0 && ms <= Number.MAX_SAFE_INTEGER) return `${ms}000000`; + return `${BigInt(ms) * 1_000_000n}`; } -// Converts epoch milliseconds into an OTLP nanosecond string. Rounding -// to whole milliseconds first keeps the product exactly representable in -// double precision. -const timeToUnixNano = (t) => `${BigInt(Math.round(t)) * 1_000_000n}`; +// Builds the JSON string for one OTLP span directly, without intermediate +// objects: the string is ready for the wire. Trace and span IDs are always +// hex, from the ID generator or a validated traceparent, so they are +// written as is. Every other string goes through the escape check. +function spanToOtlpJson(span) { + let s = '{"traceId":"'; + s += span.traceId; + s += '","spanId":"'; + s += span.spanId; + s += '","name":'; + s += jsonString(String(span.name)); + s += ',"kind":'; + s += span.kind; + s += ',"startTimeUnixNano":"'; + s += timeToUnixNano(span.startTime); + s += '","endTimeUnixNano":"'; + s += timeToUnixNano(span.endTime); + s += '"'; -function spanToOtlp(span) { - // TODO(bengl): A lot of objects are created in here for all the atributes. - // As a future optimization, we could hand-write the JSON encoding. const rawAttrs = span.getAttributes(); const attrKeys = Object.keys(rawAttrs); - const attributes = []; + let attrCount = 0; for (let i = 0; i < attrKeys.length; i++) { // Unused preallocated keys stay undefined and are skipped. if (rawAttrs[attrKeys[i]] === undefined) continue; - attributes.push({ - key: attrKeys[i], - value: encodeAttributeValue(rawAttrs[attrKeys[i]]), - }); + if (attrCount === 0) s += ',"attributes":['; + else s += ','; + s += keyPrefix(attrKeys[i]); + s += encodeAttributeValueJson(rawAttrs[attrKeys[i]]); + s += '}'; + attrCount++; } + if (attrCount > 0) s += ']'; - const rawEvents = span.getEvents(); - const events = []; - for (let i = 0; i < rawEvents.length; i++) { - const event = rawEvents[i]; - const eventAttrs = []; - const eventAttrKeys = Object.keys(event.attributes); - for (let j = 0; j < eventAttrKeys.length; j++) { - if (event.attributes[eventAttrKeys[j]] === undefined) continue; - eventAttrs.push({ - key: eventAttrKeys[j], - value: encodeAttributeValue(event.attributes[eventAttrKeys[j]]), - }); + const status = span.status; + if (status.code !== 0 || status.message) { + s += ',"status":{"code":'; + s += status.code; + if (status.message) { + s += ',"message":'; + s += jsonString(status.message); } - const otlpEvent = { - name: event.name, - timeUnixNano: timeToUnixNano(event.time), - }; - if (eventAttrs.length > 0) otlpEvent.attributes = eventAttrs; - events.push(otlpEvent); + s += '}'; } - const otlpSpan = { - traceId: span.traceId, - spanId: span.spanId, - name: span.name, - kind: span.kind, - startTimeUnixNano: timeToUnixNano(span.startTime), - endTimeUnixNano: timeToUnixNano(span.endTime), - }; - - if (attributes.length > 0) otlpSpan.attributes = attributes; - - const status = span.status; - if (status.code !== 0 || status.message) otlpSpan.status = status; - - if (span.parentSpanId) otlpSpan.parentSpanId = span.parentSpanId; + if (span.parentSpanId) { + s += ',"parentSpanId":"'; + s += span.parentSpanId; + s += '"'; + } - if (events.length > 0) otlpSpan.events = events; + const rawEvents = span.getEvents(); + if (rawEvents.length > 0) { + s += ',"events":['; + for (let i = 0; i < rawEvents.length; i++) { + if (i > 0) s += ','; + const event = rawEvents[i]; + s += '{"name":'; + s += jsonString(String(event.name)); + s += ',"timeUnixNano":"'; + s += timeToUnixNano(event.time); + s += '"'; + const eAttrs = event.attributes; + const eKeys = Object.keys(eAttrs); + let eCount = 0; + for (let j = 0; j < eKeys.length; j++) { + if (eAttrs[eKeys[j]] === undefined) continue; + if (eCount === 0) s += ',"attributes":['; + else s += ','; + s += keyPrefix(eKeys[j]); + s += encodeAttributeValueJson(eAttrs[eKeys[j]]); + s += '}'; + eCount++; + } + if (eCount > 0) s += ']'; + s += '}'; + } + s += ']'; + } - return otlpSpan; + s += '}'; + return s; } function addSpan(span) { @@ -158,6 +216,11 @@ function addSpan(span) { } } +// The envelope prefix and suffix around the spans array are fixed after +// start, so they are cached once. +let envelopePrefix = null; +const envelopeSuffix = ']}]}]}'; + function flush() { if (flushTimer != null) { clearTimeout(flushTimer); @@ -169,10 +232,12 @@ function flush() { const spans = spanBuffer; spanBuffer = []; - const otlpSpans = []; + // A span that fails to serialize is skipped on its own, so one bad span + // never costs the rest of the batch. + const parts = []; for (let i = 0; i < spans.length; i++) { try { - otlpSpans.push(spanToOtlp(spans[i])); + parts.push(spanToOtlpJson(spans[i])); } catch (err) { warnExportFailure( `Failed to serialize span "${spans[i].name}": ${err.message}`, @@ -180,31 +245,13 @@ function flush() { } } - if (otlpSpans.length === 0) return; + if (parts.length === 0) return; - let payload; - try { - payload = JSON.stringify({ - resourceSpans: [ - { - resource: getResource(), - scopeSpans: [ - { - scope: getScope(), - spans: otlpSpans, - }, - ], - }, - ], - }); - } catch (err) { - warnExportFailure( - `Failed to serialize ${otlpSpans.length} spans: ${err.message}`, - ); - return; - } + envelopePrefix ??= + `{"resourceSpans":[{"resource":${JSON.stringify(getResource())},` + + `"scopeSpans":[{"scope":${JSON.stringify(getScope())},"spans":[`; - sendToCollector(payload); + sendToCollector(envelopePrefix + parts.join(',') + envelopeSuffix); } // Counts failures and emits an OTelExportWarning, throttled to at most one @@ -300,6 +347,7 @@ function startFlusher(options) { // Resets per-run state for the test suite; tracing itself never resets // once started. function resetCaches() { + envelopePrefix = null; if (flushTimer != null) { clearTimeout(flushTimer); flushTimer = null; diff --git a/lib/instrumentations.js b/lib/instrumentations.js index cecfa14..9bd81fd 100644 --- a/lib/instrumentations.js +++ b/lib/instrumentations.js @@ -127,9 +127,20 @@ function onHttpServerResponseFinish({ request, response }) { span.end(); } +// Memoizes splitAuthority for the last input: consecutive requests to the +// same server share the authority, so the common case is a cache hit that +// avoids two string allocations and an array. +let splitAuthorityCache = [null, null]; +function splitAuthority(authority) { + if (splitAuthorityCache[2] === authority) return splitAuthorityCache; + const result = _splitAuthority(authority); + splitAuthorityCache = [result[0], result[1], authority]; + return result; +} + // Splits an authority (a Host header value) into host and port. The port // is null when the authority omits it, meaning the scheme default. -function splitAuthority(authority) { +function _splitAuthority(authority) { if (authority.startsWith('[')) { // IPv6 literal: the port, if any, follows the closing bracket. const hostEnd = authority.indexOf(']'); diff --git a/test/test-flush-coverage.js b/test/test-flush-coverage.js index 2384511..3a580df 100644 --- a/test/test-flush-coverage.js +++ b/test/test-flush-coverage.js @@ -35,7 +35,8 @@ describe('flush.js coverage', () => { it('encodes boolean, double, and fallback attribute values', async () => { // A span-like object covering the OTLP encodings the instrumentations // never produce: booleans, non-integer numbers, and values of other - // types, which fall back to strings. + // types, which fall back to strings. NaN and the infinities have no + // JSON number form, so they must arrive as ProtoJSON strings. const span = { name: 'mixed-values', traceId: 'a'.repeat(32), @@ -48,6 +49,9 @@ describe('flush.js coverage', () => { bool: true, ratio: 1.5, misc: null, + nan: NaN, + inf: Infinity, + negInf: -Infinity, }; }, getEvents() { @@ -67,6 +71,9 @@ describe('flush.js coverage', () => { assert.deepStrictEqual(attrs.bool, { boolValue: true }); assert.deepStrictEqual(attrs.ratio, { doubleValue: 1.5 }); assert.deepStrictEqual(attrs.misc, { stringValue: 'null' }); + assert.deepStrictEqual(attrs.nan, { doubleValue: 'NaN' }); + assert.deepStrictEqual(attrs.inf, { doubleValue: 'Infinity' }); + assert.deepStrictEqual(attrs.negInf, { doubleValue: '-Infinity' }); }); it('flush handles spanToOtlp errors gracefully', async () => { @@ -79,9 +86,12 @@ describe('flush.js coverage', () => { }); }); - // A poisoned span-like object that throws during serialization. + // A poisoned span-like object that throws during serialization. Its + // timestamps are valid, so the throw comes from the attributes. const badSpan = { name: 'bad-span', + startTime: 1, + endTime: 2, getAttributes() { throw new Error('serialize boom'); }, @@ -95,7 +105,7 @@ describe('flush.js coverage', () => { assert.ok(warning.message.includes('serialize boom')); }); - it('flush handles JSONStringify errors gracefully', async () => { + it('drops only the span that fails to serialize', async () => { const warningPromise = new Promise((resolve) => { process.on('warning', function onWarning(w) { if (w.name === 'OTelExportWarning') { @@ -105,32 +115,166 @@ describe('flush.js coverage', () => { }); }); - // A span-like object whose BigInt name passes through spanToOtlp but - // makes JSON.stringify throw. - const fakeSpan = { - name: 1n, + const goodSpan = (spanId) => ({ + name: 'good-span', + traceId: 'a'.repeat(32), + spanId, + kind: 1, + startTime: 1, + endTime: 2, getAttributes() { return {}; }, getEvents() { return []; }, + status: { code: 0, message: '' }, + }); + + // A poisoned span between two good ones: the batch must still export + // both of the good spans. + addSpan(goodSpan('1'.repeat(16))); + addSpan({ + name: 'bad-span', + startTime: 1, + endTime: 2, + getAttributes() { + throw new Error('serialize boom'); + }, + }); + addSpan(goodSpan('2'.repeat(16))); + flush(); + + // Both are awaited before asserting, so a failed assertion cannot + // leave this payload queued for the next test. + const [warning, payload] = await Promise.all([ + warningPromise, + collector.next(), + ]); + assert.match(warning.message, /serialize boom/); + assert.deepStrictEqual( + getSpans(payload).map((s) => s.spanId), + ['1'.repeat(16), '2'.repeat(16)], + ); + }); + + it('escapes span names so the payload stays valid JSON', async () => { + // A span-like object whose name needs JSON escaping: the hand-written + // encoder must still produce a valid payload. + const fakeSpan = { + name: 'quote " backslash \\ newline \n', + getAttributes() { + return { 'url.path': 'tab\there' }; + }, + getEvents() { + return []; + }, traceId: 'a'.repeat(32), spanId: 'b'.repeat(16), parentSpanId: null, - kind: 0, + kind: 1, startTime: 1, endTime: 2, - status: { code: 0, message: '' }, + status: { code: 2, message: 'err "quoted"' }, traceFlags: 0x01, }; addSpan(fakeSpan); flush(); - const warning = await warningPromise; + // collector.next() parses the body with JSON.parse, so receiving a + // payload at all proves it is valid JSON. + const payload = await collector.next(); + const span = getSpans(payload).find((sp) => sp.spanId === 'b'.repeat(16)); + assert.ok(span, 'Expected the escaped span in the payload'); + assert.strictEqual(span.name, 'quote " backslash \\ newline \n'); + assert.strictEqual(span.status.message, 'err "quoted"'); + assert.strictEqual(span.attributes[0].value.stringValue, 'tab\there'); + }); + + it('escapes attribute keys so the payload stays valid JSON', async () => { + // setAttribute takes any key, so the encoder cannot assume keys come + // from the fixed set the instrumentations write. + const span = new Span('keys', SPAN_KIND_INTERNAL); + span.setAttribute('quote"key', 'value'); + span.setAttribute('newline\nkey', 'value'); + span.addEvent('event', { 'tab\tkey': 'value' }); + span.end(); + flush(); + + const payload = await collector.next(); + const exported = getSpans(payload).find((s) => s.spanId === span.spanId); + assert.ok(exported, 'Expected the span in the payload'); + assert.deepStrictEqual( + exported.attributes.map((a) => a.key), + ['quote"key', 'newline\nkey'], + ); + assert.strictEqual(exported.events[0].attributes[0].key, 'tab\tkey'); + }); + + it('round-trips non-ASCII and surrogate values exactly', async () => { + // Text without surrogates takes the fast path. Astral characters and + // lone surrogates go through JSON.stringify, and a lone surrogate sent + // unescaped would arrive as U+FFFD. + const values = ['é漢字\u2028\u2029', 'emoji 😀', 'lone \ud800 surrogate']; + addSpan({ + name: 'unicode', + traceId: 'a'.repeat(32), + spanId: 'c'.repeat(16), + kind: 1, + startTime: 1, + endTime: 2, + getAttributes() { + return { a: values[0], b: values[1], c: values[2] }; + }, + getEvents() { + return []; + }, + status: { code: 0, message: '' }, + }); + flush(); + + const exported = getSpans(await collector.next())[0]; + assert.deepStrictEqual( + exported.attributes.map((a) => a.value.stringValue), + values, + ); + }); + + it('formats timestamps exactly like BigInt arithmetic', async () => { + // Ordinary epoch milliseconds take the string fast path. Zero, values + // past the safe integer range, and non-finite times must still match + // BigInt arithmetic, which throws for non-finite input and so drops + // the span. + const timed = (spanId, startTime, endTime) => ({ + name: 'times', + traceId: 'a'.repeat(32), + spanId, + kind: 1, + startTime, + endTime, + getAttributes() { + return {}; + }, + getEvents() { + return []; + }, + status: { code: 0, message: '' }, + }); + + addSpan(timed('1'.repeat(16), 0, 1e21)); + addSpan(timed('2'.repeat(16), 1700000000000.4, 1700000000000.6)); + addSpan(timed('3'.repeat(16), NaN, 1)); + flush(); - assert.ok(warning.message.includes('Failed to serialize')); + const spans = getSpans(await collector.next()); + assert.deepStrictEqual( + spans.map((s) => [s.spanId, s.startTimeUnixNano, s.endTimeUnixNano]), + [ + ['1'.repeat(16), '0', '1000000000000000000000000000'], + ['2'.repeat(16), '1700000000000000000', '1700000000001000000'], + ], + ); }); it('resetCaches clears the span buffer', async () => {