| 1 | import * as NodeSdk from "@effect/opentelemetry/NodeSdk" |
| 2 | import * as OtelLogger from "@effect/opentelemetry/OtelLogger" |
| 3 | import * as Resource from "@effect/opentelemetry/Resource" |
| 4 | import { assert, describe, it } from "@effect/vitest" |
| 5 | import { SeverityNumber } from "@opentelemetry/api-logs" |
| 6 | import { InMemoryLogRecordExporter, type LogRecordProcessor, SimpleLogRecordProcessor } from "@opentelemetry/sdk-logs" |
| 7 | import { InMemorySpanExporter, SimpleSpanProcessor } from "@opentelemetry/sdk-trace-base" |
| 8 | import * as Clock from "effect/Clock" |
| 9 | import * as Effect from "effect/Effect" |
| 10 | import * as Layer from "effect/Layer" |
| 11 | import * as References from "effect/References" |
| 12 | |
| 13 | describe("Logger", () => { |
| 14 | it.effect("shuts down the logger provider after forceFlush rejects", () => |
| 15 | Effect.gen(function*() { |
| 16 | let shutdowns = 0 |
| 17 | const processor: LogRecordProcessor = { |
| 18 | onEmit() {}, |
| 19 | forceFlush: () => Promise.reject(new Error("flush failed")), |
| 20 | shutdown: () => { |
| 21 | shutdowns++ |
| 22 | return Promise.resolve() |
| 23 | } |
| 24 | } |
| 25 | yield* Effect.exit( |
| 26 | Effect.scoped(Layer.build(OtelLogger.layerLoggerProvider(processor)).pipe(Effect.provide(Resource.layerEmpty))) |
| 27 | ) |
| 28 | assert.strictEqual(shutdowns, 1) |
| 29 | })) |
| 30 | |
| 31 | describe("provided", () => { |
| 32 | const exporter = new InMemoryLogRecordExporter() |
| 33 | |
| 34 | const TracingLayer = NodeSdk.layer(Effect.sync(() => ({ |
| 35 | resource: { |
| 36 | serviceName: "test" |
| 37 | }, |
| 38 | logRecordProcessor: [new SimpleLogRecordProcessor({ exporter })] |
| 39 | }))) |
| 40 | |
| 41 | it.effect("emits log records", () => |
| 42 | Effect.gen(function*() { |
| 43 | yield* Effect.log("test").pipe( |
| 44 | Effect.repeat({ times: 9 }) |
| 45 | ) |
| 46 | assert.lengthOf(exporter.getFinishedLogRecords(), 10) |
| 47 | }).pipe(Effect.provide(TracingLayer))) |
| 48 | |
| 49 | it.effect("maps Effect LogLevel to OTel SeverityNumber spec values", () => { |
| 50 | const severityExporter = new InMemoryLogRecordExporter() |
| 51 | const SeverityLayer = NodeSdk.layer(Effect.sync(() => ({ |
| 52 | resource: { serviceName: "test" }, |
| 53 | logRecordProcessor: [new SimpleLogRecordProcessor({ exporter: severityExporter })] |
| 54 | }))) |
| 55 | |
| 56 | return Effect.gen(function*() { |
| 57 | yield* Effect.logTrace("trace") |
| 58 | yield* Effect.logDebug("debug") |
| 59 | yield* Effect.logInfo("info") |
| 60 | yield* Effect.logWarning("warn") |
| 61 | yield* Effect.logError("error") |
| 62 | yield* Effect.logFatal("fatal") |
| 63 | |
| 64 | const records = severityExporter.getFinishedLogRecords() |
| 65 | const byText = Object.fromEntries(records.map((r) => [r.severityText, r.severityNumber])) |
| 66 | |
| 67 | assert.strictEqual(byText.Trace, SeverityNumber.TRACE) |
| 68 | assert.strictEqual(byText.Debug, SeverityNumber.DEBUG) |
| 69 | assert.strictEqual(byText.Info, SeverityNumber.INFO) |
| 70 | assert.strictEqual(byText.Warn, SeverityNumber.WARN) |
| 71 | assert.strictEqual(byText.Error, SeverityNumber.ERROR) |
| 72 | assert.strictEqual(byText.Fatal, SeverityNumber.FATAL) |
| 73 | }).pipe( |
| 74 | Effect.provide(SeverityLayer.pipe(Layer.provideMerge(Layer.succeed(References.MinimumLogLevel, "Trace")))) |
| 75 | ) |
| 76 | }) |
| 77 | |
| 78 | it.effect("uses wall-clock timestamps and keeps them aligned with spans", () => { |
| 79 | const logExporter = new InMemoryLogRecordExporter() |
| 80 | const spanExporter = new InMemorySpanExporter() |
| 81 | const wallTimeNanos = 1_735_689_600_123_456_789n |
| 82 | const monotonicTimeNanos = 123_456_789n |
| 83 | const expectedTime: readonly [number, number] = [ |
| 84 | Number(wallTimeNanos / BigInt(1_000_000_000)), |
| 85 | Number(wallTimeNanos % BigInt(1_000_000_000)) |
| 86 | ] |
| 87 | const skewedClock: Clock.Clock = { |
| 88 | currentTimeMillisUnsafe: () => 1, |
| 89 | currentTimeMillis: Effect.succeed(1), |
| 90 | currentTimeNanosUnsafe: () => wallTimeNanos, |
| 91 | currentTimeNanos: Effect.succeed(wallTimeNanos), |
| 92 | monotonicTimeNanosUnsafe: () => monotonicTimeNanos, |
| 93 | monotonicTimeNanos: Effect.succeed(monotonicTimeNanos), |
| 94 | sleep: () => Effect.void |
| 95 | } |
| 96 | |
| 97 | const TracingLayer = NodeSdk.layer(Effect.sync(() => ({ |
| 98 | resource: { |
| 99 | serviceName: "test" |
| 100 | }, |
| 101 | spanProcessor: [new SimpleSpanProcessor(spanExporter)], |
| 102 | logRecordProcessor: [new SimpleLogRecordProcessor({ exporter: logExporter })] |
| 103 | }))) |
| 104 | |
| 105 | return Effect.gen(function*() { |
| 106 | yield* Effect.log("test").pipe( |
| 107 | Effect.withSpan("parent") |
| 108 | ) |
| 109 | |
| 110 | const logs = logExporter.getFinishedLogRecords() |
| 111 | const spans = spanExporter.getFinishedSpans() |
| 112 | assert.lengthOf(logs, 1) |
| 113 | assert.lengthOf(spans, 1) |
| 114 | const log = logs[0]! |
| 115 | const span = spans[0]! |
| 116 | |
| 117 | assert.deepStrictEqual(log.hrTime, expectedTime) |
| 118 | assert.deepStrictEqual(log.hrTimeObserved, expectedTime) |
| 119 | assert.deepStrictEqual(log.hrTime, span.startTime) |
| 120 | assert.strictEqual(log.attributes.spanId, span.spanContext().spanId) |
| 121 | assert.strictEqual(log.attributes.traceId, span.spanContext().traceId) |
| 122 | }).pipe( |
| 123 | Effect.provide(TracingLayer), |
| 124 | Effect.provideService(Clock.Clock, skewedClock) |
| 125 | ) |
| 126 | }) |
| 127 | |
| 128 | it.effect("does not let annotations overwrite active span correlation", () => { |
| 129 | const logExporter = new InMemoryLogRecordExporter() |
| 130 | const spanExporter = new InMemorySpanExporter() |
| 131 | const TracingLayer = NodeSdk.layer(Effect.sync(() => ({ |
| 132 | resource: { serviceName: "test" }, |
| 133 | spanProcessor: [new SimpleSpanProcessor(spanExporter)], |
| 134 | logRecordProcessor: [new SimpleLogRecordProcessor({ exporter: logExporter })] |
| 135 | }))) |
| 136 | |
| 137 | return Effect.gen(function*() { |
| 138 | yield* Effect.log("test").pipe( |
| 139 | Effect.annotateLogs({ traceId: "spoof-trace", spanId: "spoof-span" }), |
| 140 | Effect.withSpan("parent") |
| 141 | ) |
| 142 | |
| 143 | const log = logExporter.getFinishedLogRecords()[0]! |
| 144 | const span = spanExporter.getFinishedSpans()[0]! |
| 145 | assert.strictEqual(log.attributes.traceId, span.spanContext().traceId) |
| 146 | assert.strictEqual(log.attributes.spanId, span.spanContext().spanId) |
| 147 | }).pipe(Effect.provide(TracingLayer)) |
| 148 | }) |
| 149 | }) |
| 150 | |
| 151 | describe("not provided", () => { |
| 152 | const exporter = new InMemoryLogRecordExporter() |
| 153 | |
| 154 | const TracingLayer = NodeSdk.layer(Effect.sync(() => ({ |
| 155 | resource: { |
| 156 | serviceName: "test" |
| 157 | } |
| 158 | }))) |
| 159 | |
| 160 | it.effect("withSpan", () => |
| 161 | Effect.gen(function*() { |
| 162 | yield* Effect.log("test") |
| 163 | assert.lengthOf(exporter.getFinishedLogRecords(), 0) |
| 164 | }).pipe(Effect.provide(TracingLayer))) |
| 165 | }) |
| 166 | }) |