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
37 changes: 37 additions & 0 deletions .changeset/observability.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@
---
"@btravstack/observability": minor
---

**`@btravstack/observability`** — observability for the kernel, starting with
logging.

`Logger` is a di port over a deliberately strict interface, and every
difference from NestJS's logger is a defect it does not have: a port rather
than a class you `new` (no static instance, no `useLogger` reaching past DI),
`with(attributes)` returning a new logger rather than `setContext` mutating the
one every caller shares, a flat record of scalars rather than `any` varargs, a
dedicated `cause` channel (an `Error`'s `message` and `stack` are
non-enumerable, so `JSON.stringify` alone drops exactly the part worth
keeping), six fixed levels, and a guarantee that a log call cannot throw — a
broken sink is swallowed rather than becoming an outage.

- **Correlation is not the caller's job.** `createLogger` reads
`currentUnit()` **per call**, so every line written inside a unit carries its
`traceId`, `unitId` and `tenantId` — one application-scope logger, correct
for every request, with nothing threaded through the call stack.
- **`observability({ sink?, level? })`** provides `Logger` and `LoggerConfig`,
bound from `LOG_LEVEL` (default `info`) and validated once: a level outside
the six is a `ConfigInvalid` naming the variable, exit `78` under `runMain`,
rather than a silent fallback.
- **`jsonSink`** is the default — one JSON object per line on stdout, no
runtime dependency — with the unit's ids as top-level fields a log backend
indexes. **`pinoSink`** lives behind the `@btravstack/observability/pino`
subpath, with `pino` as an optional peer; the level filter stays this
package's, so there is one filter in the process.
- **`kernelEvents(logger)`** turns the kernel's nine lifecycle events into log
lines in that same stream, keeping each event's fields as attributes — pass
it as `StartOptions.onEvent`.

Traces and metrics are not here yet; the package is named for the whole because
logs, traces and metrics share a correlation id, a resource, a config slice and
a flush-on-shutdown lifecycle.
195 changes: 161 additions & 34 deletions CLAUDE.md

Large diffs are not rendered by default.

3 changes: 3 additions & 0 deletions docs/.vitepress/config.ts
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ const GUIDE_SIDEBAR = [
text: "How-to guides",
items: [
{ text: "Configure from the environment", link: "/how-to/configure-from-the-environment" },
{ text: "Log and correlate", link: "/how-to/log-and-correlate" },
{ text: "Serve an oRPC contract over HTTP", link: "/how-to/serve-orpc-over-http" },
{ text: "Run a Temporal worker", link: "/how-to/run-a-temporal-worker" },
{ text: "Consume AMQP messages", link: "/how-to/consume-amqp-messages" },
Expand Down Expand Up @@ -66,6 +67,7 @@ const GUIDE_SIDEBAR = [
{ text: "Probes", link: "/reference/core/probes" },
],
},
{ text: "@btravstack/observability", link: "/reference/observability" },
{ text: "@btravstack/testing", link: "/reference/testing" },
{ text: "@btravstack/http", link: "/reference/http" },
{ text: "@btravstack/temporal", link: "/reference/temporal" },
Expand Down Expand Up @@ -202,6 +204,7 @@ export default defineConfig({
{ text: "@btravstack/di", link: "/api/di/" },
{ text: "@btravstack/config", link: "/api/config/" },
{ text: "@btravstack/core", link: "/api/core/" },
{ text: "@btravstack/observability", link: "/api/observability/" },
{ text: "@btravstack/testing", link: "/api/testing/" },
{ text: "@btravstack/http", link: "/api/http/" },
{ text: "@btravstack/temporal", link: "/api/temporal/" },
Expand Down
10 changes: 9 additions & 1 deletion docs/api/index.md
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,8 @@ description: The generated reference for every published package — each export
Generated from the source with [TypeDoc](https://typedoc.org/) at build time —
every exported symbol, with its signature and TSDoc. One page per package,
following the dependency direction: `di` → `config` → `core`, then the test
harness and the three starters on top of `core`.
harness, the observability starter and the three transport starters on top of
`core`.

- **[`@btravstack/di`](/api/di/)** — `Port` (and `Port.many`), `Provider`,
`Module` (`Module.scoped`, `Module.forkScope`), `Context`, and the type
Expand All @@ -30,6 +31,13 @@ harness and the three starters on top of `core`.
`withApp`, `testRuntime`, `TestRuntimePort`, `createFakeClock`, and the
types `Boot`, `BootDefaults`, `ServicesOf`, `TestRuntime`,
`TestRuntimeInfo`, `SubmittedUnit`, `FakeClock`.
- **[`@btravstack/observability`](/api/observability/)** — **two entry
points**. The main one: the `Logger` and `LoggerConfig` ports,
`createLogger`, `jsonSink`, `observability`, `logLevel`, `kernelEvents`,
`LEVELS`, and the types `LoggerService`, `LoggerSettings`, `Level`,
`Attributes`, `Line`, `Sink`, `ObservabilityOptions`. The
`@btravstack/observability/pino` subpath carries `pinoSink` alone, so `pino`
stays an optional peer.
- **[`@btravstack/http`](/api/http/)** — `HttpModule`, `HttpRouter`, `http`,
the ports `HttpRuntime` and `HttpConfig`, and the types `HttpModuleOptions`,
`HttpOptions`, `HttpInfo`.
Expand Down
32 changes: 23 additions & 9 deletions docs/examples/order-amqp-worker.md
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,9 @@ publisher does not know it exists.
handlers port, typed for the contract — its service the record the contract
wants, `WorkerInferHandlers<OrderContract>`, no injected context; no class, no
name, since a consumer serves one handlers record — so the handler is built
from what it declares like any use case:
from what it declares like any use case, `Logger` here being
[`@btravstack/observability`](/reference/observability)'s port rather than one
this example writes:

```ts
export const orderHandlers = AmqpHandlers(orderContract)([Logger], {
Expand All @@ -58,8 +60,12 @@ export const orderHandlers = AmqpHandlers(orderContract)([Logger], {
}
logger.info(
payload === null
? `order ${id} is gone — notifying`
: `order ${id} placed — notifying (${payload.quantity} items)`,
? "order gone — notifying"
: "order placed — notifying",
{
orderId: id,
...(payload === null ? {} : { quantity: payload.quantity }),
},
);
return OkAsync();
},
Expand Down Expand Up @@ -151,13 +157,16 @@ the runtime's `stop`). `drain` stays the consumer's alone — draining means
export const OrderAmqpWorker = AmqpModule("OrderAmqpWorker")({
contract: orderContract,
handlers: orderHandlers,
imports: [ApplicationModule, PersistenceModule],
imports: [ApplicationModule, PersistenceModule, observability()],
provides: [relayConfig, outboxRelay],
exports: [PlaceOrder, OrderRepository, Outbox, Logger],
});
```

The same application pair, the starter over `orderHandlers`, and both halves
The same application pair, the starter over `orderHandlers`,
[`observability()`](/reference/observability) for the `Logger` both halves
write to — `LOG_LEVEL`, JSON per line on stdout, every consumer line
correlated with the delivery's own unit — and both halves
of the outbox pattern in one graph. The exports are the writer's surface —
what a writer in the same process places and cancels through, and what the
specs tap. `main.ts` is `await runMain(OrderAmqpWorker);`.
Expand Down Expand Up @@ -204,10 +213,14 @@ await use(async (module, options) => {
```

Every app is stopped by `boot`'s teardown when the test ends. The `tapped`
fixture is `tapped(OrderAmqpWorker, [PlaceOrder, OrderRepository, Outbox,
Logger])`: the writer the spec places orders through, the outbox it asserts
against and the logger the consumer writes to — the very instances the
running app uses, not fresh ones.
fixture composes the root's own shape with `observability({ sink })` and taps
the services on top of it —
`tapped(recording, [PlaceOrder, OrderRepository, Outbox])`: the writer the
spec places orders through and the outbox it asserts against are the very
instances the running app uses, not fresh ones, while the consumer's own lines
need no tap at all — the sink hands them over as `Line` values, so the
assertions read `{ message, orderId, quantity }` rather than a formatted
sentence.

Five specs, each a fact crossing the outbox, the broker and the queue: a
committed write comes back as the consumer's notification, with the write
Expand Down Expand Up @@ -241,6 +254,7 @@ const HandlerlessAmqp = Module("HandlerlessAmqp")({
imports: [
ApplicationModule,
PersistenceModule,
observability(),
amqp({ contract: orderContract }),
],
exports: [AmqpRuntime, PlaceOrder, Logger],
Expand Down
60 changes: 41 additions & 19 deletions docs/examples/order-api.md
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
---
title: Order API example
description: The HTTP deployment — HttpRouter over the order contract with one exhaustive triage from domain Err to ORPCError, HttpModule as the whole composition root, RequestModule forked per request, a one-line main.ts, and the three compile-time gates pinned by needs-gate.test-d.ts.
description: The HTTP deployment — HttpRouter over the order contract with one exhaustive triage from domain Err to ORPCError, HttpModule as the whole composition root, RequestModule forked per request, a main.ts that is one runMain call with the kernel's events on the application's own logger, and the three compile-time gates pinned by needs-gate.test-d.ts.
---

# Order API (HTTP)
Expand Down Expand Up @@ -87,29 +87,41 @@ than a fallback.
```ts
export const OrderApi = HttpModule("OrderApi")({
router: orderRouter,
imports: [ApplicationModule, PersistenceModule],
imports: [ApplicationModule, PersistenceModule, observability()],
exports: [Logger],
});
```

`HttpModule` imports the starter (`http()` — `HttpRuntime`, `HttpConfig` bound
from `PORT` / `HOST`, the router mounted under `/rpc`, needing the router the
root provides), provides `orderRouter` and exports `HttpRuntime`, and returns
exactly the module `Module("OrderApi")({...})` would have. `Logger` is exported
for the request scope below. It is a **constant**: configuration is read inside
the graph from the `Env` port the kernel provides, so nothing is passed in from
`main.ts`, and a spec boots this very module with `env: { PORT: "0", HOST:
"127.0.0.1" }`.
exactly the module `Module("OrderApi")({...})` would have.
[`observability()`](/reference/observability) brings the `Logger` the
interactors and the request scope write to — bound from `LOG_LEVEL`, one JSON
object per line on stdout, every line carrying the unit's trace id — and
`Logger` is exported for the request scope below. It is a **constant**:
configuration is read inside the graph from the `Env` port the kernel provides,
so nothing is passed in from `main.ts`, and a spec boots this very module with
`env: { PORT: "0", HOST: "127.0.0.1" }`.

`main.ts` is one statement:

```ts
await runMain(OrderApi, { unit: RequestModule });
await runMain(OrderApi, {
unit: RequestModule,
onEvent: kernelEvents(createLogger(jsonSink())),
});
```

The process reads `PORT` (default `3000`), `HOST` (default `0.0.0.0`) and
`PROBE_PORT` (default `9000`) — inside the graph — and a malformed one is a
`startFailed` event and exit `78`.
The process reads `PORT` (default `3000`), `HOST` (default `0.0.0.0`),
`LOG_LEVEL` (default `info`) and `PROBE_PORT` (default `9000`) — inside the
graph — and a malformed one is a `startFailed` event and exit `78`.
`kernelEvents` puts the kernel's nine lifecycle events in the same stream and
the same shape as the application's own lines, instead of the default JSON on
stderr; the logger there is built by hand because `building` is emitted while
the graph still is, so a sink taken out of the context it is watching would
have nothing to write the two events that matter most with. See
[Log and correlate](/how-to/log-and-correlate).

## A request scope over the application scope

Expand All @@ -130,7 +142,9 @@ export const RequestModule = Module("Request")({
const startedAt = Date.now();
return {
finish: () =>
logger.info(`request finished in ${Date.now() - startedAt}ms`),
logger.info("request finished", {
durationMs: Date.now() - startedAt,
}),
};
},
onStop: (span) => span.finish(),
Expand All @@ -153,7 +167,9 @@ wraps it in `serve`, where every spec starts, real composition root included:

```ts
export const it = test.extend<ApiFixtures>({
boot: bootFixture({ env: { PORT: "0", HOST: "127.0.0.1" } }),
boot: bootFixture({
env: { PORT: "0", HOST: "127.0.0.1", LOG_LEVEL: "fatal" },
}),

serve: async ({ boot }, use) => {
await use((module, options) =>
Expand All @@ -166,11 +182,15 @@ export const it = test.extend<ApiFixtures>({

`boot` brings a test's defaults (`signals: false`, `probes: false`,
`preDrainDelayMs: 0`, a silent sink) and stops every app it started when the
test ends; `serve` adds the per-request `RequestModule`. The port comes back
test ends; `serve` adds the per-request `RequestModule`, and `LOG_LEVEL:
"fatal"` keeps the real root — whose sink is the production `jsonSink()` on
stdout — out of the runner's own output. The port comes back
from `Serving.info` through `app.runtimeInfo()` — the kernel's own channel
for it — and the client is built from the contract alone. Where a spec needs
the very `Logger` the use cases wrote to, `tapped(OrderApi, [Logger])`
hands back the instance the running graph holds. The suite then pins what matters: a `DuplicateOrder` arrives as an
the lines the running graph wrote, the seam is
`observability({ sink })`: the `recording` fixture composes the root's shape
with a sink that keeps every `Line`, so an assertion reads `line.unit.traceId`
as a field rather than parsing a prefix out of a string. The suite then pins what matters: a `DuplicateOrder` arrives as an
`Err` holding an inferable `CONFLICT`, a value the client matches by code, not
a thrown 500:

Expand All @@ -188,7 +208,8 @@ expect(conflict).toBeErrWith(
An unmodeled repository failure collapses to `INTERNAL_SERVER_ERROR` without
leaking its message, and the process keeps serving afterwards; each call runs
in its own unit with its own trace id (two calls, four log lines, two distinct
ids, never `[-]`); a call held open in the repository finishes during a drain
`line.unit.traceId`s, none written outside a unit); a call held open in the
repository finishes during a drain
and is counted `completed`, one still hung at a zero deadline is counted
`abandoned`; `/livez` and `/readyz` answer while serving, and readiness goes
false before liveness during the drain.
Expand All @@ -209,7 +230,7 @@ on arity.

```ts
const RouterlessApi = Module("RouterlessApi")({
imports: [ApplicationModule, PersistenceModule, http()],
imports: [ApplicationModule, PersistenceModule, observability(), http()],
exports: [HttpRuntime, Logger],
});

Expand All @@ -231,7 +252,8 @@ const _unitUnmet = start(UnloggedApi, { ...options, unit: RequestModule });

The `unit` half, in both directions: `start(OrderApi, { unit: RequestModule })`
is an ordinary call because `OrderApi` exports the `Logger` the fork reads,
and `UnloggedApi` — runtime and router present, `Logger` not exported — is
and `UnloggedApi` — runtime and router present, `observability()` imported so
the port exists in the graph, `Logger` simply not exported — is
rejected by the unit arm alone.

## Where to go next
Expand Down
45 changes: 28 additions & 17 deletions docs/examples/order-application.md
Original file line number Diff line number Diff line change
Expand Up @@ -89,9 +89,12 @@ export class OrderRepository extends Port("OrderRepository")<{
Beside it: `Outbox` (the read side of the transactional outbox — `pending`
and `markPublished`, both `E = never`, because a database that will not
answer is a defect, not a domain outcome), `StockService` and
`ShippingService` (the two fulfillment ports the saga orchestrates), `Logger`,
and the two use-case ports `PlaceOrder` and `FindOrder`. The interactors are
classes provided with di's `class` arm:
`ShippingService` (the two fulfillment ports the saga orchestrates), and the
two use-case ports `PlaceOrder` and `FindOrder`. The `Logger` the interactors
write to is **not** declared here: it is
[`@btravstack/observability`](/reference/observability)'s port, imported like
any other dependency. The interactors are classes provided with di's `class`
arm:

```ts
export const placeOrderProvider = Provider(PlaceOrder)(
Expand All @@ -102,25 +105,31 @@ export const placeOrderProvider = Provider(PlaceOrder)(
);
```

The module provides everything **except** `OrderRepository`:
The module provides neither `OrderRepository` nor `Logger`:

```ts
export const ApplicationModule = Module("Application")({
provides: [loggerProvider, placeOrderProvider, findOrderProvider],
exports: [PlaceOrder, FindOrder, Logger],
provides: [placeOrderProvider, findOrderProvider],
exports: [PlaceOrder, FindOrder],
});
```

Both interactors depend on it and nothing here satisfies it, so di propagates
it as an unmet need. That is what makes this layer testable with no database
at all — its specs provide a stub repository from a `TestModule` — and it is
what makes the layering a compile error rather than a convention (see the type
tests below).

The one kernel touchpoint is `logger.ts`, which reads `currentUnit()` fresh on
every call so each line carries the trace id of the unit that wrote it —
`PlaceOrderInteractor` depends on both and nothing here satisfies either, so di
propagates both as unmet needs — the repository because the layer below fills
it, the logger because the framework does, and there is nothing to re-export in
either direction. That is what makes this layer testable with no database at
all — its specs provide a stub repository from a `TestModule` that imports
`observability({ sink, level: "trace" })` — and it is what makes the layering a
compile error rather than a convention (see the type tests below).

There is no kernel touchpoint left here. The log calls are structured —
`this.#logger.info("placing an order", { orderId: id, quantity })`, a constant
message with the ids as fields — and correlation is not this layer's job:
`@btravstack/observability`'s implementation reads `currentUnit()` fresh on
every call, so each line carries the trace id of the unit that wrote it —
data from the ambient store, never a capability (see
[Ambient data, injected capabilities](/explanation/ambient-vs-context)).
[Ambient data, injected capabilities](/explanation/ambient-vs-context) and
[Log and correlate](/how-to/log-and-correlate)).

## The infrastructure: P-codes stop here

Expand Down Expand Up @@ -249,8 +258,10 @@ const _unwired = Module.scoped(ApplicationModule, (ctx) =>
);
```

The positive half composes `ApplicationModule` with a stub repository and
calls `Module.scoped` as an ordinary two-argument call. The three deployment
The positive half composes `ApplicationModule` with a stub repository and a
`Provider(Logger)({ value: createLogger(() => {}) })` — the starter is the
default, not the only way — and calls `Module.scoped` as an ordinary
two-argument call. The three deployment
pages carry the other kind — `start`'s gate.

## Where to go next
Expand Down
Loading
Loading