Initial Commit
This commit is contained in:
@@ -0,0 +1,111 @@
|
||||
# OpenSpec Change: logger-silent-failure-fix
|
||||
|
||||
- **Change ID**: logger-silent-failure-fix
|
||||
- **Package**: `@suaveplan/logger`
|
||||
- **Status**: PROPOSED
|
||||
- **Date**: 2026-04-27
|
||||
|
||||
## Summary
|
||||
|
||||
Close two silent-failure bugs in `@suaveplan/logger` and tighten
|
||||
`openspec/specs/logging/spec.md` to cover substrate behaviours
|
||||
already shipped by the package: `MultiSink` fan-out semantics,
|
||||
`EventLogger`, `StorageLogger`, `enable/disable`, `resetMetrics`,
|
||||
and the `Sensitive<T>` redaction envelope. Pin every behavioural
|
||||
fix and every previously-undocumented surface behind a
|
||||
`*.spec-conformance.test.ts` so the 5-gate publish flow catches
|
||||
drift.
|
||||
|
||||
## Current state
|
||||
|
||||
`@suaveplan/logger` is fully implemented and ships 171 passing
|
||||
tests at 100% coverage, but two paths fail silently:
|
||||
|
||||
1. **Sink dispatch swallows everything.** `dispatchToSinks`
|
||||
(`src/abstract/abstract-logger.ts`) catches every sink throw
|
||||
and promise rejection and increments a single
|
||||
`droppedByBackpressure++` counter. Spec defines a
|
||||
`LOGGER.SINK` error code, but the dispatch path never raises
|
||||
it — only `BufferedSink.flush` does. A serializer crash inside
|
||||
a sink is misclassified as backpressure with no error surfaced
|
||||
anywhere.
|
||||
|
||||
2. **`BufferedSink` block-policy deadlock.** Under
|
||||
`policy: "block"`, `write()` parks writers in a private
|
||||
`flushWaiters` list. Drain only happens when an external
|
||||
caller invokes `flush()`. If nobody ever does, blocked writers
|
||||
hang forever — there is no internal timer, no inline drain,
|
||||
and no construction-time guard.
|
||||
|
||||
Additionally, requirements LG-11 / LG-12 / LG-13 don't reflect
|
||||
the new failure-mode taxonomy and the spec lacks requirements
|
||||
for `MultiSink`, the concrete loggers, lifecycle methods, and
|
||||
`Sensitive<T>`.
|
||||
|
||||
## What changes
|
||||
|
||||
1. **Modify Requirement: LG-11 Metrics** — add
|
||||
`droppedBySinkError: number` to the `LoggerMetrics` shape.
|
||||
2. **Modify Requirement: LG-12 OTel instrumentation** — extend
|
||||
the `logger.dropped_total` counter's `reason` attribute set
|
||||
to include `"sink_error"`.
|
||||
3. **Modify Requirement: LG-13 Structured errors** — codify
|
||||
that `LOGGER.SINK` is raised by the dispatch path (not just
|
||||
`BufferedSink.flush`) and routed to a configurable
|
||||
`fallbackSink`.
|
||||
4. **ADD Requirement: LG-21 Sink dispatch isolation** —
|
||||
per-sink try/catch; one bad sink never halts the others;
|
||||
each failure produces a `LoggerError(LOGGER.SINK)` written
|
||||
to `fallbackSink` (default: a sink that calls
|
||||
`console.error`).
|
||||
5. **ADD Requirement: LG-22 BufferedSink no-deadlock contract**
|
||||
— under `policy: "block"`, `write()` drains the head record
|
||||
inline before pushing. No parked-writer list, no external
|
||||
`flush()` required for forward progress.
|
||||
6. **ADD Requirement: LG-23 MultiSink fan-out semantics** —
|
||||
parallel dispatch via `Promise.all`; per-sink errors
|
||||
isolated and reported to the parent logger's `fallbackSink`;
|
||||
all sinks attempted regardless of order.
|
||||
7. **ADD Requirement: LG-24 Generic Logger surface** —
|
||||
`Logger<TMetadata>` is generic over metadata shape;
|
||||
defaults to `Record<string, unknown>` for back-compat with
|
||||
the original LG-02 `ctx: Record<string, unknown>` clause.
|
||||
8. **ADD Requirement: LG-25 Concrete loggers** — `EventLogger`
|
||||
and `StorageLogger` are documented exports with their
|
||||
minimal contracts.
|
||||
9. **ADD Requirement: LG-26 Lifecycle controls** — `enable()`,
|
||||
`disable()`, `isEnabled()`, `resetMetrics()` are part of
|
||||
the supported public surface.
|
||||
10. **ADD Requirement: LG-27 Sensitive<T> envelope** —
|
||||
`RedactionEngine` recognises `Sensitive`-tagged values and
|
||||
redacts them automatically (LG-07 already names this; the
|
||||
new requirement pins the verification path).
|
||||
11. **Add `src/conformance.spec-conformance.test.ts`** pinning
|
||||
LG-21, LG-22, and LG-23 so future drift exits the 5-gate
|
||||
non-zero.
|
||||
12. **Add `**Verified by:**` lines** to every requirement
|
||||
(existing + new) in the folded spec.
|
||||
|
||||
## Why now
|
||||
|
||||
Both bugs are silent — the only signal a misbehaving sink emits
|
||||
today is a generic counter increment with no error text, no
|
||||
stack, no fallback record. The block-policy deadlock is
|
||||
undetectable at construction time. Both ship green through the
|
||||
existing 5-gate. Tightening the contract behind conformance
|
||||
tests is the smallest possible change that prevents recurrence.
|
||||
|
||||
## Impact
|
||||
|
||||
- `@suaveplan/logger` — `LoggerMetrics` gains
|
||||
`droppedBySinkError`. `AbstractLoggerConfig` gains
|
||||
`fallbackSink?: Sink`. Two existing assertions in
|
||||
`abstract-logger.test.ts` and one in
|
||||
`abstract-logger.spec-conformance.test.ts` flip from
|
||||
`droppedByBackpressure` / `reason: "backpressure"` to
|
||||
`droppedBySinkError` / `reason: "sink_error"`. Coverage stays
|
||||
at 100%.
|
||||
- Downstream consumers — none affected; new metric and config
|
||||
field are additive. `LOGGER.SINK` error code already exists.
|
||||
- Spec readers — get an accurate picture of the dispatch
|
||||
contract, the fallback sink, and the concrete loggers.
|
||||
@@ -0,0 +1,152 @@
|
||||
# Spec Delta — logging
|
||||
|
||||
## MODIFIED Requirements
|
||||
|
||||
### LG-11 — Metrics
|
||||
|
||||
`AbstractLogger` MUST expose `getMetrics()` returning:
|
||||
|
||||
```ts
|
||||
{
|
||||
totalLogs: number;
|
||||
logsByLevel: Record<LogLevel, number>;
|
||||
droppedBySampling: number;
|
||||
droppedByBackpressure: number;
|
||||
/** Records lost because a sink threw or rejected during dispatch. */
|
||||
droppedBySinkError: number;
|
||||
lastLogTime?: Date;
|
||||
}
|
||||
```
|
||||
|
||||
`droppedByBackpressure` is reserved for downstream queue saturation
|
||||
(e.g. `BufferedSink` overflow under `policy: "drop"`). Sink throws
|
||||
and rejections during `dispatchToSinks` MUST increment
|
||||
`droppedBySinkError` instead — never `droppedByBackpressure`.
|
||||
|
||||
**Verified by:** `src/conformance.spec-conformance.test.ts` (sink-error counter scenarios) and `src/abstract/abstract-logger.test.ts`.
|
||||
|
||||
### LG-12 — OTel instrumentation
|
||||
|
||||
For every `log()` call the implementation MUST:
|
||||
|
||||
- Increment a `logger.records_total` counter (attributes: `level`)
|
||||
- Record a `logger.record_size_bytes` histogram (attributes: `level`)
|
||||
- Increment `logger.dropped_total` when a record is dropped, with a
|
||||
`reason` attribute drawn from the closed set
|
||||
`"sampling" | "backpressure" | "sink_error"`. `sink_error` MUST be
|
||||
fired for sink throws and rejections caught by the dispatch path.
|
||||
|
||||
All via `@opentelemetry/api` — no-op when no exporter is registered.
|
||||
|
||||
**Verified by:** `src/abstract/abstract-logger.spec-conformance.test.ts` (records_total + record_size_bytes + dropped_total{reason:"sampling"} + dropped_total{reason:"sink_error"}).
|
||||
|
||||
### LG-13 — Structured errors
|
||||
|
||||
All errors thrown by `@suaveplan/logger` MUST be instances of
|
||||
`LoggerError extends SuaveplanError` with stable codes registered
|
||||
via `defineCodes`:
|
||||
|
||||
| Code constant | Trigger |
|
||||
|---------------|---------|
|
||||
| `LOGGER.SINK` | A sink's `write()` rejected or threw, OR `BufferedSink.flush()`'s inner `write` rejected. The dispatch path MUST surface this code through `fallbackSink` (it MUST NOT throw out of `log()`). |
|
||||
| `LOGGER.SERIALIZE` | JSON serialisation of a log record failed |
|
||||
| `LOGGER.CONFIG` | Invalid configuration detected at construction time, including `BufferedSink` `maxQueueSize <= 0` |
|
||||
| `LOGGER.FLUSH` | `flush()` aborted via `AbortSignal` |
|
||||
|
||||
**Verified by:** `src/conformance.spec-conformance.test.ts` (LOGGER.SINK from dispatch + LOGGER.CONFIG from BufferedSink constructor) and `src/sink/sink.test.ts` (LOGGER.FLUSH from BufferedSink.flush).
|
||||
|
||||
## ADDED Requirements
|
||||
|
||||
### LG-21 — Sink dispatch isolation
|
||||
|
||||
`AbstractLogger.dispatchToSinks(record)` MUST:
|
||||
|
||||
1. Iterate sinks in registration order.
|
||||
2. Wrap each `sink.write(record)` in an isolated try/catch (sync) and
|
||||
`.catch(...)` (async). A throw / rejection in sink `i` MUST NOT
|
||||
prevent sinks `i+1, …, n-1` from being attempted.
|
||||
3. On any sink failure: increment `droppedBySinkError`, fire
|
||||
`logger.dropped_total{reason:"sink_error"}`, build a
|
||||
`LoggerError(LOGGER.SINK)` (with `cause` set to the original
|
||||
`Error`, if any), and write a fallback `LogRecord` to
|
||||
`config.fallbackSink`. The fallback record MUST carry the
|
||||
serialised `LoggerError` under `record.error` and include the
|
||||
failing sink's index under `record.ctx.__sink_index`.
|
||||
4. The default `fallbackSink` MUST write via `console.error`.
|
||||
5. `dispatchToSinks` MUST NOT throw out of the `log()` call.
|
||||
|
||||
**Verified by:** `src/conformance.spec-conformance.test.ts` (sync throw, async rejection, two-sink isolation, fallbackSink record shape).
|
||||
|
||||
### LG-22 — BufferedSink no-deadlock contract
|
||||
|
||||
`BufferedSink` under `overflowPolicy: "block"` MUST make forward
|
||||
progress without requiring an external `flush()`. When the queue is
|
||||
already at `maxQueueSize` and `write()` is called, the
|
||||
implementation MUST drain the head record inline (await
|
||||
`inner.write(head)`) before pushing the new record. There MUST NOT
|
||||
be an external waiter list that depends on `flush()` for resolution.
|
||||
|
||||
The constructor MUST throw `LoggerError(LOGGER.CONFIG)` if
|
||||
`maxQueueSize` is not a positive integer.
|
||||
|
||||
**Verified by:** `src/conformance.spec-conformance.test.ts` (forward-progress without flush + invalid maxQueueSize) and `src/sink/sink.test.ts`.
|
||||
|
||||
### LG-23 — MultiSink fan-out semantics
|
||||
|
||||
`MultiSink([a, b, …])` MUST dispatch each record to every wrapped
|
||||
sink in parallel via `Promise.all`. When composed under
|
||||
`AbstractLogger`, per-sink failures inherit the LG-21 contract: an
|
||||
inner sink throw / rejection inside the parallel fan-out is reported
|
||||
to the parent logger's `fallbackSink` and does not prevent the
|
||||
other inner sinks from receiving the record. `flush()` and
|
||||
`close()` similarly fan out in parallel and aggregate via
|
||||
`Promise.all`.
|
||||
|
||||
**Verified by:** `src/conformance.spec-conformance.test.ts` (two-sink parallel dispatch) and `src/sink/sink.test.ts`.
|
||||
|
||||
### LG-24 — Generic Logger surface
|
||||
|
||||
The exported `Logger` interface MUST be generic over metadata
|
||||
shape: `Logger<TMetadata extends Record<string, unknown> = Record<string, unknown>>`. Concrete loggers (`ConsoleLogger`,
|
||||
`StorageLogger`, `EventLogger`) and `AbstractLogger` MUST honour
|
||||
the same generic. The default parameter preserves the original
|
||||
LG-02 `ctx: Record<string, unknown>` clause for callers that don't
|
||||
specialise.
|
||||
|
||||
**Verified by:** `src/conformance.spec-conformance.test.ts` (typed-metadata scenario) and `src/abstract/abstract-logger.test.ts`.
|
||||
|
||||
### LG-25 — Concrete loggers
|
||||
|
||||
The package MUST export the following concrete loggers, each
|
||||
extending `AbstractLogger`:
|
||||
|
||||
| Class | `writeLog` behaviour |
|
||||
|-------|----------------------|
|
||||
| `ConsoleLogger` | Routes `LogEntry` to `console[level]` (with optional formatting). |
|
||||
| `StorageLogger` | Persists each `LogEntry` to a `StorageLike` adapter. |
|
||||
| `EventLogger` | Publishes each `LogEntry` to an `EventBusLike`. |
|
||||
|
||||
Each MUST be importable both from the package root and from a
|
||||
dedicated subpath export (`./console`, `./storage`, `./event`).
|
||||
|
||||
**Verified by:** `src/console/console-logger.test.ts`, `src/storage/storage-logger.test.ts`, `src/event/event-logger.test.ts`.
|
||||
|
||||
### LG-26 — Lifecycle controls
|
||||
|
||||
`AbstractLogger` MUST expose `enable()`, `disable()`,
|
||||
`isEnabled()`, and `resetMetrics()` as part of the public surface.
|
||||
`disable()` suppresses every subsequent `log()` call (including
|
||||
sink dispatch and metrics). `resetMetrics()` returns the metrics
|
||||
struct to its zero state without affecting configuration.
|
||||
|
||||
**Verified by:** `src/abstract/abstract-logger.test.ts` (enable/disable + resetMetrics scenarios).
|
||||
|
||||
### LG-27 — Sensitive<T> envelope
|
||||
|
||||
`RedactionEngine` MUST recognise values wrapped in the
|
||||
`Sensitive<T>` envelope from `@suaveplan/error/redact` (or the
|
||||
package's own re-export) and replace them with `"[REDACTED]"` in
|
||||
the redacted record. Detection MUST occur regardless of whether
|
||||
the field path matches a configured `RedactionRule`.
|
||||
|
||||
**Verified by:** `src/redaction/redaction.test.ts`.
|
||||
@@ -0,0 +1,35 @@
|
||||
# Tasks: logger-silent-failure-fix
|
||||
|
||||
## 1. Spec delta
|
||||
|
||||
- [x] 1.1 Author `specs/logging/spec.md` delta with `## MODIFIED Requirements` (LG-11, LG-12, LG-13) and `## ADDED Requirements` (LG-21 sink dispatch isolation, LG-22 BufferedSink no-deadlock, LG-23 MultiSink fan-out, LG-24 generic Logger, LG-25 concrete loggers, LG-26 lifecycle controls, LG-27 Sensitive<T> envelope).
|
||||
- [x] 1.2 Add `**Verified by:**` line to every existing LG-NN requirement in the folded spec on fold.
|
||||
|
||||
## 2. Implementation
|
||||
|
||||
- [x] 2.1 Add `fallbackSink?: Sink` to `AbstractLoggerConfig`; default to a sink that writes failure records via `console.error`.
|
||||
- [x] 2.2 Replace `dispatchToSinks` body with per-sink try/catch that emits `LoggerError(LOGGER.SINK)` to `fallbackSink`, increments `droppedBySinkError`, fires `logger.dropped_total{reason:"sink_error"}`, and continues to remaining sinks.
|
||||
- [x] 2.3 Add `droppedBySinkError: number` to `LoggerMetrics` and initialise in `freshMetrics`.
|
||||
- [x] 2.4 Replace `BufferedSink` block-policy waiter list with inline-drain on overflow; throw `LoggerError(LOGGER.CONFIG)` on non-positive `maxQueueSize`.
|
||||
- [x] 2.5 Update affected unit / conformance tests.
|
||||
|
||||
## 3. Conformance test
|
||||
|
||||
- [x] 3.1 Add `packages/observability/logger/src/conformance.spec-conformance.test.ts` pinning:
|
||||
- sink throw is captured into `fallbackSink` with code `LOGGER.SINK` and increments `droppedBySinkError`;
|
||||
- sink rejection is captured into `fallbackSink` and increments `droppedBySinkError`;
|
||||
- the second sink in a list still receives the record when the first throws (per-sink isolation);
|
||||
- `BufferedSink({ overflowPolicy: "block", maxQueueSize: 1 })` makes forward progress without an external `flush()`;
|
||||
- `BufferedSink({ maxQueueSize: 0 })` throws `LoggerError(LOGGER.CONFIG)` at construction;
|
||||
- `MultiSink([a,b])` writes to both `a` and `b` in parallel.
|
||||
|
||||
## 4. Gate
|
||||
|
||||
- [ ] 4.1 `bunx turbo lint typecheck test --filter=@suaveplan/logger` green.
|
||||
- [ ] 4.2 `bunx turbo test:coverage --filter=@suaveplan/logger` 100/100/100/100.
|
||||
- [ ] 4.3 `bun scripts/openspec-conformance.ts @suaveplan/logger` exits 0.
|
||||
|
||||
## 5. Fold + archive
|
||||
|
||||
- [ ] 5.1 Fold delta into `openspec/specs/logging/spec.md`.
|
||||
- [ ] 5.2 Move `openspec/changes/logger-silent-failure-fix/` to `openspec/archive/2026-04-27-logger-silent-failure-fix/`.
|
||||
Reference in New Issue
Block a user