diff --git a/.github/workflows/master.yaml b/.github/workflows/master.yaml index 3d90068..7d38b5f 100644 --- a/.github/workflows/master.yaml +++ b/.github/workflows/master.yaml @@ -25,6 +25,20 @@ jobs: # Same suite in real Chromium via the official Playwright Docker image. - run: npm run test-browser + OTLP-test: + runs-on: ubuntu-24.04 + # End-to-end check: export to a real (pinned) OpenTelemetry Collector and assert it parsed both + # our JSON and protobuf output. index.js is built in Docker (deps in the container), so the host + # needs only Docker plus Node to run the driver — no `npm ci`. + steps: + - uses: actions/checkout@v7 + with: + persist-credentials: false + - uses: actions/setup-node@v6 + with: + node-version: 22.x + - run: npm run test-otlp + Lint: runs-on: ubuntu-24.04 # eslint 10 / eslint-plugin-perfectionist need Node 20+; lint is static, so run it once diff --git a/AGENTS.md b/AGENTS.md new file mode 100644 index 0000000..8cc03b1 --- /dev/null +++ b/AGENTS.md @@ -0,0 +1,20 @@ +# AGENTS + +Guidance for agents working on `@larvit/log`. Keep changes aligned with the priorities below. + +## What this is + +Structured logging with a tiny API and first-class OTLP (logs + traces) over `fetch`, with no OpenTelemetry SDK dependency. Works as a plain stdout/stderr logger when OTLP is not configured. + +## Design priorities (in order) + +1. **Works everywhere** — Node.js, Bun, Deno and other server runtimes, plus browsers and React Native. Lean on the common JS surface (global `fetch`); add fallbacks where a runtime lacks an API rather than dropping support. +2. **A very easy API** — "just log" must stay trivial. Don't make the caller learn OTLP to use it. +3. **Composable** — instances inherit context/spans/traces and can attach to upstream headers/spans/traces. Favour designs that slot into existing setups. +4. **Low footprint for the consumer** — minimise runtime cost and install weight shipped to consumers. Dev-time build/codegen steps in this repo are fine, as long as they don't reach consumers. + +## Working here + +- Source is a single `index.ts`, compiled + uglified to `index.js` for publish. +- Tests-first. The suite (`test.ts`) injects `stdout`/`stderr` and stubs the global `fetch`, so the same tests cover console + OTLP in both Node and the browser. +- See [README](README.md) for build/test/release commands. Keep the README and this file in sync with any priority or workflow change. diff --git a/README.md b/README.md index fe773b1..6781bb3 100644 --- a/README.md +++ b/README.md @@ -6,10 +6,10 @@ Structured logging with a simple interface and support for OTLP. In priority order: -1. **A simple API** — small surface, easy to drop in. -2. **Runs anywhere JavaScript runs** — both browsers and server-side (Node.js >= 18). The only requirement is a runtime with the global `fetch` (used by the OTLP transport). -3. **Strong OTLP support** — the OTLP payloads are hand-built JSON over `fetch` (no OpenTelemetry SDK dependency) to stay portable across runtimes. -4. **stdout/stderr support** — works as a plain console logger when OTLP is not configured. +1. **Works everywhere** — Node.js, Bun, Deno and other server runtimes, plus browsers and React Native. Leans on the common JavaScript surface (global `fetch`), with graceful fallbacks where a runtime lacks an API. +2. **A very easy API** — "just log" must stay trivial. Developers pick it up fast without needing to understand OTLP internals. +3. **Composable** — attach to upstream headers/spans/traces and inherit logs, spans and traces between instances. A chameleon that slots into most setups. +4. **Low footprint for the consumer** — small runtime cost and install weight in the consumer's app. Build/codegen steps in *this* library's own development are fine, as long as they don't carry over to consumers. ## Installation @@ -111,6 +111,12 @@ const log = new Log({ // Added in 1.3.0 otlpHttpBaseURI: null, + // OTLP wire format: "http/json" (default) or "http/protobuf". + // Both POST to the same endpoint; protobuf sends Content-Type: application/x-protobuf. + // Use protobuf for collectors that don't accept JSON. + // Added in 2.2.0 + otlpProtocol: "http/json", + // Group logs together under a specific parent // Used for spans and traces in Open Telemetry etc. // Defaults to null, creating no span in otlp @@ -159,6 +165,12 @@ exact same tests exercise the console output and the OTLP transport in Node and The container runs `npm run ci` / `ci-browser` internally — run those directly only if you already have deps installed locally. +- `npm run test-otlp` — end-to-end OTLP check: exports to a real (pinned) OpenTelemetry Collector and + asserts it parsed both the JSON **and** protobuf output. This validates the hand-built protobuf + encoder against the reference implementation, not just our own decoder. `index.js` is built inside + Docker and the driver runs on the host with plain Node, so — like the suites above — it needs only + Docker, no local `npm install`. See `scripts/run-otlp-tests.mjs` (`OTLP_DEBUG=1` dumps exactly what + the collector received). - `npm run lint` — eslint over the sources. Linting needs Node 20+ (eslint 10), so CI runs it once in its own job rather than inside the Node 18–26 test matrix. Needs deps installed locally. @@ -184,6 +196,16 @@ To publish manually instead: `npm run build-and-publish`. ## Changelog +### v2.2.0 + +- OTLP can now export over **HTTP/protobuf**, not only HTTP/JSON. Opt in with + `otlpProtocol: "http/protobuf"` (default stays `"http/json"`); both POST to the same endpoint. + The protobuf encoder is hand-built and dependency-free, so the library stays a single + self-contained file that runs anywhere. Useful for collectors that only accept protobuf. +- Fixed: `clone()` now inherits OTLP settings (`otlpHttpBaseURI`, `otlpProtocol`, + `otlpAdditionalHeaders`) and `printTraceInfo`, which it previously dropped silently. A clone still + gets its own span — it is not made a child of the original. + ### v2.1.0 - `Metadata` values may now be `number` or `boolean`, not only `string` (new exported `MetadataValue` diff --git a/index.ts b/index.ts index ca918e1..5f08a63 100644 --- a/index.ts +++ b/index.ts @@ -12,6 +12,7 @@ export type LogConf = { logLevel?: LogLevel | "none"; otlpAdditionalHeaders?: Record; otlpHttpBaseURI?: string; + otlpProtocol?: "http/json" | "http/protobuf"; parentLog?: LogInt; printTraceInfo?: boolean; spanName?: string; @@ -320,6 +321,175 @@ function buildSpanPayload(opts: { }; } +// --- OTLP/HTTP protobuf encoding ------------------------------------------- +// Hand-rolled protobuf wire encoder for the small, frozen OTLP message subset this library emits. +// Zero dependencies keeps the library a single self-contained file that runs in any JS runtime +// (priority: works everywhere). Field numbers below are from the OTLP proto definitions (v1). + +const WIRE_VARINT = 0; +const WIRE_FIXED64 = 1; +const WIRE_LEN = 2; + +class ProtoWriter { + private readonly buf: number[] = []; + + // Uint8Array (not the ArrayBufferLike default) so the result is a valid fetch BodyInit. + finish(): Uint8Array { + return new Uint8Array(this.buf); + } + + // Non-negative integer < 2^53 (tags, lengths, enums, counts). Modulo/division sidesteps the + // 32-bit truncation of bitwise ops, so no BigInt is needed for these. + private pushVarint(value: number): void { + while (value > 0x7f) { + this.buf.push((value % 128) | 0x80); + value = Math.floor(value / 128); + } + this.buf.push(value); + } + + private pushTag(fieldNo: number, wireType: number): void { + this.pushVarint((fieldNo * 8) + wireType); + } + + private pushLen(fieldNo: number, data: ArrayLike): void { + this.pushTag(fieldNo, WIRE_LEN); + this.pushVarint(data.length); + for (let i = 0; i < data.length; i++) { + this.buf.push(data[i]); + } + } + + // int32/uint32/enum/bool field. + uint(fieldNo: number, value: number): this { + this.pushTag(fieldNo, WIRE_VARINT); + this.pushVarint(value); + + return this; + } + + // fixed64 field from a decimal string (eg. a ns timestamp that overflows Number). 8 bytes, LE. + fixed64(fieldNo: number, decimal: string): this { + this.pushTag(fieldNo, WIRE_FIXED64); + let rest = BigInt(decimal); + const mask = BigInt(0xff); + const eight = BigInt(8); + + for (let i = 0; i < 8; i++) { + this.buf.push(Number(rest & mask)); + rest = rest >> eight; + } + + return this; + } + + string(fieldNo: number, value: string): this { + this.pushLen(fieldNo, new TextEncoder().encode(value)); + + return this; + } + + bytes(fieldNo: number, value: Uint8Array): this { + this.pushLen(fieldNo, value); + + return this; + } + + // Embedded message: encode into a sub-writer, then write it length-delimited. + message(fieldNo: number, write: (sub: ProtoWriter) => void): this { + const sub = new ProtoWriter(); + + write(sub); + this.pushLen(fieldNo, sub.buf); + + return this; + } +} + +function hexToBytes(hex: string): Uint8Array { + const out = new Uint8Array(hex.length / 2); + + for (let i = 0; i < out.length; i++) { + out[i] = parseInt(hex.slice(i * 2, (i * 2) + 2), 16); + } + + return out; +} + +// KeyValue { key = 1, value = 2: AnyValue { string_value = 1 } } +function writeKeyValue(writer: ProtoWriter, attr: OtlpAttribute): void { + writer.string(1, attr.key); + writer.message(2, value => value.string(1, attr.value.stringValue)); +} + +// Resource / Span / LogRecord attributes are all repeated KeyValue. +function writeAttributes(writer: ProtoWriter, fieldNo: number, attributes: OtlpAttribute[]): void { + for (const attr of attributes) { + writer.message(fieldNo, attrMsg => writeKeyValue(attrMsg, attr)); + } +} + +function encodeOtlpLogPayload(payload: OtlpLogPayload): Uint8Array { + const root = new ProtoWriter(); // ExportLogsServiceRequest + + for (const resourceLog of payload.resourceLogs) { + root.message(1, resLogs => { // resource_logs = 1 + resLogs.message(1, resource => writeAttributes(resource, 1, resourceLog.resource.attributes)); // ResourceLogs.resource = 1 + for (const scopeLog of resourceLog.scopeLogs) { + resLogs.message(2, scopeMsg => { // ResourceLogs.scope_logs = 2 + for (const record of scopeLog.logRecords) { + scopeMsg.message(2, logRec => { // ScopeLogs.log_records = 2 + logRec.fixed64(1, record.timeUnixNano); // time_unix_nano = 1 + logRec.uint(2, record.severityNumber); // severity_number = 2 + logRec.string(3, record.severityText); // severity_text = 3 + logRec.message(5, body => body.string(1, record.body.stringValue)); // body = 5 (AnyValue.string_value) + writeAttributes(logRec, 6, record.attributes ?? []); // attributes = 6 + if (record.traceId) logRec.bytes(9, hexToBytes(record.traceId)); // trace_id = 9 + if (record.spanId) logRec.bytes(10, hexToBytes(record.spanId)); // span_id = 10 + }); + } + }); + } + }); + } + + return root.finish(); +} + +function encodeOtlpSpanPayload(payload: OtlpSpanPayload): Uint8Array { + const root = new ProtoWriter(); // ExportTraceServiceRequest + + for (const resourceSpan of payload.resourceSpans) { + root.message(1, resSpans => { // resource_spans = 1 + resSpans.message(1, resource => writeAttributes(resource, 1, resourceSpan.resource.attributes)); // ResourceSpans.resource = 1 + for (const scopeSpan of resourceSpan.scopeSpans) { + resSpans.message(2, scopeMsg => { // ResourceSpans.scope_spans = 2 + scopeMsg.message(1, scope => scope.string(1, scopeSpan.scope.name)); // ScopeSpans.scope = 1 (InstrumentationScope.name = 1) + for (const span of scopeSpan.spans) { + scopeMsg.message(2, spanMsg => { // ScopeSpans.spans = 2 + spanMsg.bytes(1, hexToBytes(span.traceId)); // trace_id = 1 + spanMsg.bytes(2, hexToBytes(span.spanId)); // span_id = 2 + if (span.parentSpanId) spanMsg.bytes(4, hexToBytes(span.parentSpanId)); // parent_span_id = 4 + spanMsg.string(5, span.name); // name = 5 + spanMsg.uint(6, span.kind); // kind = 6 + spanMsg.fixed64(7, span.startTimeUnixNano); // start_time_unix_nano = 7 + spanMsg.fixed64(8, span.endTimeUnixNano); // end_time_unix_nano = 8 + writeAttributes(spanMsg, 9, span.attributes); // attributes = 9 + if (span.status.code) spanMsg.message(15, status => status.uint(3, span.status.code)); // status = 15 (Status.code = 3) + }); + } + }); + } + }); + } + + return root.finish(); +} + +function encodeOtlpProtobuf(payload: OtlpLogPayload | OtlpSpanPayload): Uint8Array { + return "resourceLogs" in payload ? encodeOtlpLogPayload(payload) : encodeOtlpSpanPayload(payload); +} + export class Log implements LogInt { context: Metadata; ended: boolean = false; @@ -408,34 +578,31 @@ export class Log implements LogInt { conf = { logLevel: conf }; } - if (conf.logLevel === undefined) { - conf.logLevel = this.conf.logLevel; - } - // Resolve the formatter from the effective format, so json<->text can be changed in either direction. if (conf.entryFormatter === undefined) { if (conf.format === "json") { conf.entryFormatter = msgJsonFormatter; } else if (conf.format === "text") { conf.entryFormatter = msgTextFormatter; - } else { - conf.entryFormatter = this.conf.entryFormatter; } } - if (conf.stderr === undefined) { - conf.stderr = this.conf.stderr; - } - - if (conf.stdout === undefined) { - conf.stdout = this.conf.stdout; - } - + // Merge context per-key (overrides win) instead of replacing it wholesale. conf.context = { ...this.context, ...conf.context, }; + // Inherit every other setting not explicitly overridden — log level, sinks, OTLP endpoint/ + // protocol/headers, printTraceInfo, etc. — mirroring how the constructor inherits from a + // parentLog. parentLog and spanName are excluded: a clone is its own span, not a child of the + // original. (A manual allow-list here previously dropped OTLP options added after clone existed.) + for (const key of Object.keys(this.conf) as (keyof LogConf)[]) { + if (key !== "parentLog" && key !== "spanName" && conf[key] === undefined) { + conf[key] = this.conf[key] as never; + } + } + return new Log(conf); } @@ -535,8 +702,10 @@ export class Log implements LogInt { const basePath = base.pathname.replace(/\/$/, ""); // keep any base path prefix, drop a trailing slash const url = `${base.protocol}//${base.username ? `${base.username}:${base.password}@` : "" }${base.host}${basePath}${path}`; - const headers = { - "Content-Type": "application/json", + const protobuf = this.conf.otlpProtocol === "http/protobuf"; + + const headers: Record = { + "Content-Type": protobuf ? "application/x-protobuf" : "application/json", }; if (this.conf.otlpAdditionalHeaders) { @@ -549,7 +718,7 @@ export class Log implements LogInt { try { const res = await fetch(url, { - body: JSON.stringify(payload), + body: protobuf ? encodeOtlpProtobuf(payload) : JSON.stringify(payload), headers, method: "POST", signal: controller.signal, @@ -563,11 +732,15 @@ export class Log implements LogInt { throw err; } - const resBody = await res.json(); + // Protobuf responses are binary (usually empty); a 2xx is success. Only the JSON + // transport inspects the response body. + if (!protobuf) { + const resBody = await res.json(); - const resBodyStr = JSON.stringify(resBody); - if (resBodyStr !== "{\"partialSuccess\":{}}" && resBodyStr !== "{}") { - throw new Error("Invalid response body from OTLP service. Expected '{\"partialSuccess\":{}}' or '{}' but got: '" + JSON.stringify(resBody) + "'"); + const resBodyStr = JSON.stringify(resBody); + if (resBodyStr !== "{\"partialSuccess\":{}}" && resBodyStr !== "{}") { + throw new Error("Invalid response body from OTLP service. Expected '{\"partialSuccess\":{}}' or '{}' but got: '" + JSON.stringify(resBody) + "'"); + } } return true; diff --git a/package.json b/package.json index 878978c..f7a407b 100644 --- a/package.json +++ b/package.json @@ -16,6 +16,7 @@ "lint": "eslint index.ts tap.ts test.ts", "replace-version-string": "grep -o '\"version\": \"[^\"]*\"' package.json | cut -d'\"' -f4 | xargs -I {} sed -i.bak 's/__version__/{}/g' index.js && rm -f index.js.bak", "test-node": "node .tmp/test/test.js", + "test-otlp": "docker build -t larvit-log-test-node . && docker run --rm larvit-log-test-node sh -c \"npm run build >/dev/null && cat index.js\" > index.js && node scripts/run-otlp-tests.mjs", "test-docker": "docker build -t larvit-log-test-node --build-arg BASE_IMAGE=\"${NODE_IMAGE:-node:22-bookworm-slim}\" . && docker run --rm larvit-log-test-node npm run ci", "test-browser": "docker build -t larvit-log-test-browser --build-arg BASE_IMAGE=mcr.microsoft.com/playwright:v$(node -p \"require('./package.json').devDependencies.playwright\")-noble . && docker run --rm --init --ipc=host larvit-log-test-browser npm run ci-browser", "test": "npm run test-docker && npm run test-browser" diff --git a/scripts/otel-collector-config.yaml b/scripts/otel-collector-config.yaml new file mode 100644 index 0000000..7b6f53f --- /dev/null +++ b/scripts/otel-collector-config.yaml @@ -0,0 +1,22 @@ +# OTLP receiver -> file exporter. Used by scripts/run-otlp-tests.mjs to verify the library's real +# OTLP output (both JSON and protobuf) against the reference OpenTelemetry Collector: whatever the +# collector parses is written to a file the test reads back and asserts on. +receivers: + otlp: + protocols: + http: + endpoint: 0.0.0.0:4318 + +exporters: + file: + # /data is a host directory mounted by scripts/run-otlp-tests.mjs (the image is distroless, no /tmp). + path: /data/otlp-received.json + +service: + pipelines: + logs: + receivers: [otlp] + exporters: [file] + traces: + receivers: [otlp] + exporters: [file] diff --git a/scripts/run-otlp-tests.mjs b/scripts/run-otlp-tests.mjs new file mode 100644 index 0000000..7205b46 --- /dev/null +++ b/scripts/run-otlp-tests.mjs @@ -0,0 +1,159 @@ +// End-to-end OTLP verification. Drives the library against a real OpenTelemetry Collector and asserts +// the collector parsed our output — over BOTH http/json and http/protobuf — into the expected +// telemetry. The collector is the OTLP reference implementation, so this validates the hand-rolled +// protobuf encoder against the spec itself, a stronger oracle than the in-suite decoder. +// +// Needs Docker + Node. Run via `npm run test-otlp` (builds index.js first). The collector image is +// pinned to an exact version for reproducibility. + +import assert from "node:assert/strict"; +import { execFile as execFileCb } from "node:child_process"; +import { chmod, mkdir, readFile, rm } from "node:fs/promises"; +import { dirname, resolve } from "node:path"; +import { fileURLToPath } from "node:url"; +import { promisify } from "node:util"; + +import { Log } from "../index.js"; + +const execFile = promisify(execFileCb); + +const SCRIPT_DIR = dirname(fileURLToPath(import.meta.url)); +const IMAGE = "otel/opentelemetry-collector-contrib:0.154.0"; +const CONTAINER = "larvit-log-otlp-verify"; +const ENDPOINT = "http://127.0.0.1:4318"; +const CONFIG = resolve(SCRIPT_DIR, "otel-collector-config.yaml"); +// Host dir mounted into the container at /data; the collector's file exporter writes here and the +// test reads it back. The contrib image is distroless (no /tmp, no shell), so a mount is required. +const DATA_DIR = resolve(SCRIPT_DIR, "..", ".tmp", "otlp"); +const RECEIVED = resolve(DATA_DIR, "otlp-received.json"); + +const PROTOCOLS = [["http/json", "verify-json"], ["http/protobuf", "verify-protobuf"]]; + +const sleep = ms => new Promise(done => setTimeout(done, ms)); +const docker = (args, opts = {}) => execFile("docker", args, opts); + +// The library's console output (incl. any OTLP export errors) is buffered and only printed on failure. +const logSink = []; + +async function removeContainer() { + try { + await docker(["rm", "-f", CONTAINER]); + } catch { + // not running — fine + } +} + +async function waitUntil(label, check, { tries = 60, delayMs = 500 } = {}) { + for (let i = 0; i < tries; i++) { + try { + if (await check()) return; + } catch { + // keep polling + } + await sleep(delayMs); + } + + throw new Error(`Timed out waiting for: ${label}`); +} + +// All telemetry the collector has parsed and written back, as parsed OTLP-JSON lines. +async function readReceived() { + const raw = await readFile(RECEIVED, "utf8"); + + return raw.split("\n").filter(Boolean).map(line => JSON.parse(line)); +} + +async function exportTelemetry(protocol, serviceName) { + const log = new Log({ + context: { "service.name": serviceName }, + otlpHttpBaseURI: ENDPOINT, + otlpProtocol: protocol, + spanName: `${serviceName}-span`, + stderr: line => logSink.push(line), + stdout: () => {}, + }); + + log.error(`hello over ${protocol}`, { active: true, count: 17, foo: "bar" }); + await log.end(); +} + +const resourceHasService = (resource, name) => + (resource.attributes ?? []).some(attr => attr.key === "service.name" && attr.value?.stringValue === name); + +function assertLog(received, serviceName, protocol) { + const resourceLog = received.flatMap(line => line.resourceLogs ?? []).find(rl => resourceHasService(rl.resource, serviceName)); + + assert.ok(resourceLog, `[${protocol}] collector received a log for ${serviceName}`); + + const record = resourceLog.scopeLogs[0].logRecords[0]; + + assert.equal(record.body.stringValue, `hello over ${protocol}`, `[${protocol}] log body`); + assert.equal(record.severityText, "ERROR", `[${protocol}] log severityText`); + + const attrs = Object.fromEntries((record.attributes ?? []).map(attr => [attr.key, attr.value.stringValue])); + + assert.equal(attrs.active, "true", `[${protocol}] log attr active`); + assert.equal(attrs.count, "17", `[${protocol}] log attr count`); + assert.equal(attrs.foo, "bar", `[${protocol}] log attr foo`); + + return { spanId: record.spanId, traceId: record.traceId }; +} + +function assertSpan(received, serviceName, protocol, ids) { + const resourceSpan = received.flatMap(line => line.resourceSpans ?? []).find(rs => resourceHasService(rs.resource, serviceName)); + + assert.ok(resourceSpan, `[${protocol}] collector received a span for ${serviceName}`); + + const span = resourceSpan.scopeSpans[0].spans[0]; + + assert.equal(span.name, `${serviceName}-span`, `[${protocol}] span name`); + assert.equal(span.traceId, ids.traceId, `[${protocol}] span.traceId matches the log's traceId`); + assert.equal(span.spanId, ids.spanId, `[${protocol}] span.spanId matches the log's spanId`); +} + +try { + await removeContainer(); + // Fresh, world-writable data dir so the container's (distroless, non-root) user can write the export. + await rm(DATA_DIR, { force: true, recursive: true }); + await mkdir(DATA_DIR, { recursive: true }); + await chmod(DATA_DIR, 0o777); + + await docker(["run", "-d", "--name", CONTAINER, "-p", "4318:4318", "-v", `${CONFIG}:/etc/otel-config.yaml:ro`, "-v", `${DATA_DIR}:/data`, IMAGE, "--config", "/etc/otel-config.yaml"]); + + await waitUntil("collector HTTP endpoint", async () => { + await fetch(ENDPOINT); + + return true; + }); + + for (const [protocol, name] of PROTOCOLS) { + await exportTelemetry(protocol, name); + } + + let received = []; + + await waitUntil("collector to flush received telemetry", async () => { + received = await readReceived(); + const logs = received.flatMap(line => line.resourceLogs ?? []); + const spans = received.flatMap(line => line.resourceSpans ?? []); + + return logs.length >= PROTOCOLS.length && spans.length >= PROTOCOLS.length; + }); + + // Set OTLP_DEBUG=1 to dump exactly what the collector parsed (handy when tightening assertions). + if (process.env.OTLP_DEBUG) console.log(JSON.stringify(received, null, 2)); + + for (const [protocol, name] of PROTOCOLS) { + const ids = assertLog(received, name, protocol); + + assertSpan(received, name, protocol, ids); + } + + console.log(`OTLP verification passed: collector ${IMAGE.split(":")[1]} parsed both JSON and protobuf output correctly.`); +} catch (err) { + console.error("OTLP verification FAILED:", err.message); + if (logSink.length) console.error("library output:\n" + logSink.join("\n")); + process.exitCode = 1; +} finally { + await removeContainer(); +} diff --git a/test.ts b/test.ts index cb729df..e086eee 100644 --- a/test.ts +++ b/test.ts @@ -42,13 +42,15 @@ function okResponse(json: unknown = { partialSuccess: {} }) { // transport can be asserted without a real HTTP server (deterministic, no express dependency). // The harness restores globalThis.fetch after each test, so callers never restore it themselves. function stubFetch(responder?: (path: string, body: unknown) => ReturnType | undefined) { - const calls: { body: any, path: string, url: string }[] = []; + const calls: { body: any, contentType: string, path: string, rawBody: any, url: string }[] = []; - globalThis.fetch = (async (url: string, init: { body: string }) => { - const body = JSON.parse(init.body); + globalThis.fetch = (async (url: string, init: { body: any, headers: Record }) => { + const contentType = init.headers?.["Content-Type"]; const path = new URL(String(url)).pathname; + // Only JSON bodies are parsed; protobuf bodies are raw bytes, inspected via rawBody. + const body = contentType === "application/json" ? JSON.parse(init.body) : undefined; - calls.push({ body, path, url: String(url) }); + calls.push({ body, contentType, path, rawBody: init.body, url: String(url) }); return responder?.(path, body) ?? okResponse(); }) as unknown as typeof fetch; @@ -56,6 +58,124 @@ function stubFetch(responder?: (path: string, body: unknown) => ReturnType { + const fields = new Map(); + let pos = 0; + + while (pos < buf.length) { + const [tag, afterTag] = pbReadVarint(buf, pos); + + pos = afterTag; + const fieldNo = Number(tag >> 3n); + const wireType = Number(tag & 0x7n); + let value: bigint | Uint8Array; + + if (wireType === 0) { + [value, pos] = pbReadVarint(buf, pos); + } else if (wireType === 1) { + let acc = 0n; + + for (let i = 7; i >= 0; i--) acc = (acc << 8n) | BigInt(buf[pos + i]); + value = acc; + pos += 8; + } else if (wireType === 2) { + let len: bigint; + + [len, pos] = pbReadVarint(buf, pos); + value = buf.slice(pos, pos + Number(len)); + pos += Number(len); + } else { + throw new Error(`unsupported wire type ${wireType}`); + } + + const arr = fields.get(fieldNo) ?? []; + + arr.push(value); + fields.set(fieldNo, arr); + } + + return fields; +} + +const pbStr = (bytes: bigint | Uint8Array) => new TextDecoder().decode(bytes as Uint8Array); +const pbHex = (bytes: bigint | Uint8Array) => Array.from(bytes as Uint8Array).map(byte => byte.toString(16).padStart(2, "0")).join(""); +const pbMsg = (field: bigint | Uint8Array) => pbDecode(field as Uint8Array); + +// KeyValue { key=1: string, value=2: AnyValue { string_value=1 } } +function pbKeyValue(bytes: bigint | Uint8Array) { + const fields = pbDecode(bytes as Uint8Array); + + return { key: pbStr(fields.get(1)![0]), value: { stringValue: pbStr(pbMsg(fields.get(2)![0]).get(1)![0]) } }; +} + +// Resource { attributes=1: repeated KeyValue } +const pbResourceAttrs = (bytes: bigint | Uint8Array) => (pbDecode(bytes as Uint8Array).get(1) ?? []).map(pbKeyValue); + +// ExportLogsServiceRequest -> ResourceLogs[0] -> ScopeLogs[0] -> LogRecord[0] +function pbDecodeLogs(buf: Uint8Array) { + const resLog = pbMsg(pbDecode(buf).get(1)![0]); + const rec = pbMsg(pbMsg(resLog.get(2)![0]).get(2)![0]); + + return { + logRecord: { + attributes: (rec.get(6) ?? []).map(pbKeyValue), + body: pbStr(pbMsg(rec.get(5)![0]).get(1)![0]), + severityNumber: Number(rec.get(2)![0]), + severityText: pbStr(rec.get(3)![0]), + spanId: pbHex(rec.get(10)![0]), + timeUnixNano: String(rec.get(1)![0]), + traceId: pbHex(rec.get(9)![0]), + }, + resourceAttrs: pbResourceAttrs(resLog.get(1)![0]), + }; +} + +// ExportTraceServiceRequest -> ResourceSpans[0] -> ScopeSpans[0] -> Span[0] +function pbDecodeSpans(buf: Uint8Array) { + const resSpan = pbMsg(pbDecode(buf).get(1)![0]); + const scopeSpan = pbMsg(resSpan.get(2)![0]); + const span = pbMsg(scopeSpan.get(2)![0]); + + return { + resourceAttrs: pbResourceAttrs(resSpan.get(1)![0]), + scopeName: pbStr(pbMsg(scopeSpan.get(1)![0]).get(1)![0]), // ScopeSpans.scope (msg) -> InstrumentationScope.name + + span: { + attributes: (span.get(9) ?? []).map(pbKeyValue), + endTimeUnixNano: String(span.get(8)![0]), + kind: Number(span.get(6)![0]), + name: pbStr(span.get(5)![0]), + spanId: pbHex(span.get(2)![0]), + startTimeUnixNano: String(span.get(7)![0]), + statusCode: span.get(15) ? Number(pbMsg(span.get(15)![0]).get(3)?.[0] ?? 0n) : 0, + traceId: pbHex(span.get(1)![0]), + }, + }; +} + // --- console output -------------------------------------------------------- test("Should log to info.", t => { @@ -271,6 +391,34 @@ test("clone can downgrade json format to text", t => { t.end(); }); +test("clone() inherits OTLP config and printTraceInfo, but keeps its own span", async t => { + const { calls } = stubFetch(); + const stdout: string[] = []; + const base = new Log({ + otlpHttpBaseURI: "http://127.0.0.1:4318", + otlpProtocol: "http/protobuf", + printTraceInfo: true, + stderr: () => {}, + stdout: line => stdout.push(line), + }); + + const child = base.clone({ context: { cloned: "yes" } }); + + child.info("from clone"); + await child.end(); + + // OTLP endpoint + protocol are inherited: the clone actually exports, and as protobuf. + t.ok(calls.some(call => call.path === "/v1/logs"), "clone exported a log to the inherited OTLP endpoint"); + t.ok(calls.length > 0 && calls.every(call => call.contentType === "application/x-protobuf"), "clone inherited otlpProtocol http/protobuf"); + + // printTraceInfo is inherited: console output carries span/trace info. + t.ok(stdout[0].includes("spanId"), "clone inherited printTraceInfo"); + + // ...but the clone is its own span, not a child of base. + t.notStrictEqual(child.span.traceId, base.span.traceId, "clone has its own traceId, not base's"); + t.end(); +}); + test("constructor throws on malformed otlpHttpBaseURI", t => { t.throws(() => new Log({ otlpHttpBaseURI: "not a valid uri" }), "malformed otlpHttpBaseURI throws at construction"); t.doesNotThrow(() => new Log({ otlpHttpBaseURI: "http://127.0.0.1:4318" }), "valid uri does not throw"); @@ -329,6 +477,7 @@ test("OLTP simple log", async t => { t.ok(logsBody, "a /v1/logs call was made"); t.ok(tracesBody, "a /v1/traces call was made"); + t.ok(calls.every(call => call.contentType === "application/json"), "default protocol sends JSON content-type"); t.strictEqual(logsBody.resourceLogs.length, 1, "Exactly one resourceLog in /v1/logs body"); t.strictEqual(logsBody.resourceLogs[0].scopeLogs.length, 1, "Exactly one scopeLog in /v1/logs body"); @@ -417,6 +566,56 @@ test("OLTP simple log with metadata", async t => { t.end(); }); +test("OTLP protobuf encodes logs and spans on the wire", async t => { + const { calls } = stubFetch(); + const log = new Log({ + context: { "service.name": "proto-svc" }, + otlpHttpBaseURI: "http://127.0.0.1:4318", + otlpProtocol: "http/protobuf", + spanName: "proto-span", + stderr: () => {}, + }); + + log.warn("protobuf works", { active: true, count: 17, foo: "bar" }); + await log.end(); + + const logsCall = calls.find(call => call.path === "/v1/logs")!; + const tracesCall = calls.find(call => call.path === "/v1/traces")!; + + t.strictEqual(logsCall.contentType, "application/x-protobuf", "logs are sent as protobuf"); + t.strictEqual(tracesCall.contentType, "application/x-protobuf", "traces are sent as protobuf"); + + const { logRecord, resourceAttrs: logResourceAttrs } = pbDecodeLogs(logsCall.rawBody); + const { resourceAttrs: spanResourceAttrs, scopeName, span } = pbDecodeSpans(tracesCall.rawBody); + + t.strictEqual(logRecord.body, "protobuf works", "decoded log body matches"); + t.strictEqual(logRecord.severityNumber, 13, "decoded severityNumber is WARN (13)"); + t.strictEqual(logRecord.severityText, "WARN", "decoded severityText is WARN"); + t.deepEqual( + logRecord.attributes, + [ + { key: "active", value: { stringValue: "true" } }, + { key: "count", value: { stringValue: "17" } }, + { key: "foo", value: { stringValue: "bar" } }, + ], + "decoded log attributes match, values stringified", + ); + t.strictEqual(logResourceAttrs.find(attr => attr.key === "service.name")!.value.stringValue, "proto-svc", "service.name is on the log resource"); + t.notOk(logRecord.attributes.find(attr => attr.key === "service.name"), "service.name is not duplicated in record attributes"); + t.ok(isNanoTimestampWithinHour(logRecord.timeUnixNano), "log timeUnixNano is reasonable"); + + t.strictEqual(scopeName, "proto-span", "scope name is the span name"); + t.strictEqual(span.name, "proto-span", "decoded span name matches"); + t.strictEqual(span.kind, 1, "decoded span kind is 1"); + t.strictEqual(span.statusCode, 0, "decoded span status code is 0"); + t.strictEqual(span.traceId, logRecord.traceId, "span and log share the traceId"); + t.strictEqual(span.spanId, logRecord.spanId, "span and log share the spanId"); + t.strictEqual(spanResourceAttrs.find(attr => attr.key === "service.name")!.value.stringValue, "proto-svc", "service.name is on the span resource"); + t.ok(isNanoTimestampWithinHour(span.startTimeUnixNano), "span startTimeUnixNano is reasonable"); + t.ok(isNanoTimestampWithinHour(span.endTimeUnixNano), "span endTimeUnixNano is reasonable"); + t.end(); +}); + test("OLTP multiple instances should work independently", async t => { const { calls } = stubFetch(); const otlp = { otlpHttpBaseURI: "http://127.0.0.1:4318", stderr: () => {} };