1import { assert, describe, it } from "@effect/vitest"
2import { Exit, Scope } from "effect"
3import * as Cause from "effect/Cause"
4import * as Effect from "effect/Effect"
5import * as Layer from "effect/Layer"
6import * as Logger from "effect/Logger"
7import * as References from "effect/References"
8import * as TestConsole from "effect/testing/TestConsole"
9
10describe("Logger", () => {
11 it.effect("should output logs", () =>
12 Effect.gen(function*() {
13 yield* Effect.logInfo("info", "message").pipe(
14 Effect.annotateLogs("key", "value"),
15 Effect.withLogSpan("span")
16 )
17
18 const result = yield* TestConsole.logLines
19
20 assert.match(
21 result[0] as string,
22 /\[\d{2}:\d{2}:\d{2}\.\d{3}\]\sINFO\s\(#1\)\sspan=\dms:/
23 )
24 assert.strictEqual(result[1], "info")
25 assert.strictEqual(result[2], "message")
26 assert.deepStrictEqual(result[3], { key: "value" })
27 }))
28
29 it.effect(
30 "replace loggers",
31 Effect.fnUntraced(function*() {
32 const result: Array<string> = []
33 const context = yield* Layer.build(Logger.layer([Logger.formatJson.pipe(
34 Logger.map((inp): void => {
35 result.push(inp)
36 })
37 )]))
38 yield* Effect.logInfo("info", "message").pipe(Effect.provideContext(context))
39 assert.strictEqual(result.length, 1)
40 })
41 )
42
43 it.effect("formatLogFmt does not double quote string messages or annotations", () =>
44 Effect.gen(function*() {
45 const result: Array<string> = []
46 const logger = Logger.formatLogFmt.pipe(
47 Logger.map((output): void => {
48 result.push(output)
49 })
50 )
51
52 yield* Effect.logInfo("Welcome to the Effect Playground!").pipe(
53 Effect.annotateLogs({
54 annotation1: "first",
55 annotation2: "second",
56 annotation3: "\"omg\""
57 }),
58 Effect.provide(Logger.layer([logger]))
59 )
60
61 assert.strictEqual(result.length, 1)
62 const output = result[0] as string
63 assert.match(output, /message="Welcome to the Effect Playground!"/)
64 assert.match(output, /annotation1=first/)
65 assert.match(output, /annotation2=second/)
66 assert.match(output, /annotation3="\\"omg\\""/)
67 assert.ok(!output.includes("message=\"\\\"Welcome to the Effect Playground!\\\"\""))
68 assert.ok(!output.includes("annotation1=\"\\\"first\\\"\""))
69 }))
70
71 it.effect("formatSimple does not double quote string messages or annotations", () =>
72 Effect.gen(function*() {
73 const result: Array<string> = []
74 const logger = Logger.formatSimple.pipe(
75 Logger.map((output): void => {
76 result.push(output)
77 })
78 )
79
80 yield* Effect.logInfo("hello world").pipe(
81 Effect.annotateLogs("annotation", "value with spaces"),
82 Effect.provide(Logger.layer([logger]))
83 )
84
85 assert.strictEqual(result.length, 1)
86 const output = result[0] as string
87 assert.match(output, /message="hello world"/)
88 assert.match(output, /annotation="value with spaces"/)
89 assert.ok(!output.includes("message=\"\\\"hello world\\\"\""))
90 assert.ok(!output.includes("annotation=\"\\\"value with spaces\\\"\""))
91 }))
92
93 it.effect("formats BigInt messages consistently", () =>
94 Effect.gen(function*() {
95 const simple: Array<string> = []
96 const logFmt: Array<string> = []
97 const structured: Array<{ readonly message: unknown; readonly level: string }> = []
98 const json: Array<{ readonly message: unknown; readonly level: string }> = []
99 const loggers = [
100 Logger.formatSimple.pipe(Logger.map((output) => void simple.push(output))),
101 Logger.formatLogFmt.pipe(Logger.map((output) => void logFmt.push(output))),
102 Logger.formatStructured.pipe(Logger.map((output) => void structured.push(output))),
103 Logger.formatJson.pipe(Logger.map((output) => void json.push(JSON.parse(output))))
104 ]
105
106 yield* Effect.logInfo(123n, { value: 123n }).pipe(Effect.provide(Logger.layer(loggers)))
107
108 assert.include(simple[0], ` level=INFO fiber=`)
109 assert.include(simple[0], `message=123n message="{\\"value\\":123n}"`)
110 assert.include(logFmt[0], ` level=INFO fiber=`)
111 assert.include(logFmt[0], `message=123n message="{\\"value\\":123n}"`)
112 assert.deepStrictEqual(structured[0].message, [123n, { value: 123n }])
113 assert.strictEqual(structured[0].level, "INFO")
114 assert.deepStrictEqual(json[0].message, ["123n", { value: "123n" }])
115 assert.strictEqual(json[0].level, "INFO")
116 }))
117
118 it.effect("formatJson includes the message of plain Errors", () =>
119 Effect.gen(function*() {
120 const json: Array<{ readonly message: unknown; readonly level: string }> = []
121 const logger = Logger.formatJson.pipe(Logger.map((output) => void json.push(JSON.parse(output))))
122
123 yield* Effect.fail(new Error("boom")).pipe(
124 Effect.tapError(Effect.logError),
125 Effect.ignore,
126 Effect.provide(Logger.layer([logger]))
127 )
128
129 assert.strictEqual(json.length, 1)
130 assert.deepStrictEqual(json[0].message, { name: "Error", message: "boom" })
131 assert.strictEqual(json[0].level, "ERROR")
132 }))
133
134 it.effect("annotateLogsScoped applies annotations only while scoped", () =>
135 Effect.gen(function*() {
136 const annotations: Array<Record<string, unknown>> = []
137 const logger = Logger.make<unknown, void>((options) => {
138 annotations.push({ ...options.fiber.getRef(References.CurrentLogAnnotations) })
139 })
140
141 yield* Effect.gen(function*() {
142 yield* Effect.log("before")
143 yield* Effect.scoped(
144 Effect.gen(function*() {
145 yield* Effect.annotateLogsScoped("requestId", "req-123")
146 yield* Effect.log("inside")
147 })
148 )
149 yield* Effect.log("after")
150 }).pipe(Effect.provide(Logger.layer([logger])))
151
152 assert.deepStrictEqual(annotations, [{}, { requestId: "req-123" }, {}])
153 }))
154
155 it.effect("annotateLogsScoped restores previous annotations", () =>
156 Effect.gen(function*() {
157 const annotations: Array<Record<string, unknown>> = []
158 const logger = Logger.make<unknown, void>((options) => {
159 annotations.push({ ...options.fiber.getRef(References.CurrentLogAnnotations) })
160 })
161
162 const scope = Scope.makeUnsafe()
163
164 yield* Effect.gen(function*() {
165 yield* Effect.log("before")
166 yield* Effect.annotateLogsScoped("inner", "scope")
167 yield* Effect.log("after")
168 }).pipe(
169 Effect.annotateLogs("outer", "program"),
170 Effect.ensuring(Scope.close(scope, Exit.void)),
171 Effect.andThen(Effect.log("outside")),
172 Effect.provide(Logger.layer([logger]))
173 )
174
175 assert.deepStrictEqual(
176 annotations,
177 [{ outer: "program" }, { outer: "program", inner: "scope" }, {}]
178 )
179 }))
180
181 for (const initial of [{}, { measurement: "previous" }]) {
182 it.effect(`annotateLogsScoped ${"measurement" in initial ? "restores" : "removes"} NaN annotations`, () =>
183 Effect.gen(function*() {
184 const annotations: Array<Record<string, unknown>> = []
185 const logger = Logger.make<unknown, void>(({ fiber }) => {
186 annotations.push({ ...fiber.getRef(References.CurrentLogAnnotations) })
187 })
188 const scope = yield* Scope.make()
189
190 yield* Effect.gen(function*() {
191 yield* Effect.annotateLogsScoped("measurement", NaN)
192 yield* Effect.log("inside")
193 yield* Scope.close(scope, Exit.void)
194 yield* Effect.log("after close")
195 }).pipe(
196 Scope.provide(scope),
197 Effect.annotateLogs(initial),
198 Effect.provide(Logger.layer([logger])),
199 Effect.ensuring(Scope.close(scope, Exit.void))
200 )
201
202 assert.deepStrictEqual(annotations, [{ measurement: NaN }, initial])
203 }))
204 }
205
206 it.effect("default logger preserves message item order when logging a cause", () =>
207 Effect.gen(function*() {
208 yield* Effect.log("first", Cause.fail("boom"), "second")
209
210 const result = yield* TestConsole.logLines
211
212 assert.match(
213 result[0] as string,
214 /\[\d{2}:\d{2}:\d{2}\.\d{3}\]\sINFO\s\(#\d+\):/
215 )
216 assert.strictEqual(result[1], "first")
217 assert.strictEqual(result[2], "second")
218 assert.match(result[3] as string, /boom/)
219 }))
220})