Skip to content

feat: wide-event, LogLayer-compatible observability architecture - #45

Merged
haydenshively merged 9 commits into
mainfrom
observability
Aug 25, 2026
Merged

feat: wide-event, LogLayer-compatible observability architecture#45
haydenshively merged 9 commits into
mainfrom
observability

Conversation

@haydenshively

@haydenshively haydenshively commented May 22, 2026

Copy link
Copy Markdown
Collaborator

Adds optional structured observability to viem-dlc, following the wide event model: one enriched event per call rather than a scatter of log lines.

Using it

import { withLogging } from '@morpho-org/viem-dlc'

await withLogging(() => client.request({ method: 'eth_getLogs', params: [filter] }), {
  logger,             // any LogLayer instance, or anything matching the `Logger` interface
  service: 'indexer', // extra opts become context fields on every event
})

loglayer is not a peer dependency — Logger is a local structural interface, so consumers who don't opt in neither install it nor need it to typecheck. Outside a withLogging scope the library emits nothing.

What gets emitted

Each outermost client.request inside the scope emits exactly one "concluded" event carrying call_id, duration_ms, status, the (size-trimmed) req, and every field contributed by the transports it passed through. Success emits at info; failure emits at error with the error attached via withError, so a host wired to forward withError entries to an ErrorReporter captures it automatically — one call, both a log and a Sentry event.

How transports contribute

Each transport declares its identity once, at factory scope:

const facetId = createFacetId(cacheTransportKey)   // one per composition node

request: observe(request, facetId)                 // counts crossings, pins the label
getObservability()?.facet(facetId).sub('eth_call') // accumulates fields

The FacetId object is both the field-name prefix and the instance token, so the two call sites can't drift apart. Fields land under the transport's key — viem-dlc-logs-divider.logs_fetched, viem-dlc-failover.succeeded_index. When one call crosses several instances of the same transport (a cache per failover branch, say), the first writes the bare key and later ones get .1, .2 in first-touch order, which is stable for a given composition. A layer crossed many times per call — the sieve and enricher run once per chunk under a divider fan-out — reuses its slot and aggregates via add/stat/push. Every boundary also stamps crossings, so the event records which transports the call traversed and how many times each.

Facets expose set (last-write-wins, for once-per-call facts), add (counters), stat (streaming count/min/max/avg), push (bounded arrays), and sub (name scoping). Event size is bounded: a 32KB budget drops the largest fields first and names them in truncated_fields.

Notable fields

Transport Fields
cache blob_key, gaps_fetched, n_followers, input_elements[_unique], elements_fetched, cache/read/write timings
logs-divider from_block/to_block/latest_block, nominal_ranges, logs_fetched, splits_*, fetch_durations_ms histogram, failed_ranges
failover branches_attempted, succeeded_index, branch_durations_ms, branch_errors
deployless input_elements, nominal_batches, batch_bytes (packing utilization), splits_*
rate-limiter queue_wait_ms — separates time queued behind our own limits from upstream latency
logs-sieve logs_dropped, dropped_log_bytes — shows whether maxBytes is well-tuned

failed_ranges is worth calling out: Promise.all surfaces only the first rejection, so this bounded list is the only record of sibling chunks that failed in parallel.

Implementation

AsyncLocalStorage with exactly two levels — the withLogging seed, and one per-call store created by the outermost observe. Inner boundaries mutate that shared state rather than opening nested contexts, so ambient enrichment costs no per-layer plumbing and parallel calls stay isolated. In environments without AsyncLocalStorage (unpolyfilled browsers), withLogging degrades to a pass-through and the module is never imported.

Also here

logsSieve, logsDivider, and cache gained no behavioral changes; withRateLimit gained an optional onAdmitted callback, invoked after the caller's own await so wait samples are attributed to the call that waited rather than to whichever call happened to drain the queue.

@haydenshively haydenshively self-assigned this May 22, 2026
github-code-quality[bot]

This comment was marked as resolved.

Every viem-dlc transport boundary is wrapped in `observe`, and each
outermost `client.request` inside a `withLogging` scope emits exactly one
enriched "concluded" event: `info` on success, `error` with `withError`
on failure so hosts forwarding to an ErrorReporter capture it.

Transports enrich that event through facets. A transport declares its
identity once via `createFacetId(key)` at factory scope and passes it to
both `observe` and `facet()`; the object's reference doubles as the
instance token, so the pair cannot drift. The first id of a key touched
in a call writes bare `key.field`, later ones get `.1`, `.2` in
first-touch order — so a cache under each failover branch reports
separately, while a layer crossed once per chunk aggregates via
add/stat/push. Every boundary stamps `crossings`, recording which
transports a call traversed and how many times.

Fields are bounded: a 32KB per-event budget drops the largest fields
first into `truncated_fields`, and `push` caps arrays.

New telemetry: rate-limiter `queue_wait_ms` (admission wait, separating
self-imposed queueing from upstream latency), logs-sieve
`dropped_log_bytes`, and deployless `batch_bytes` for packing
utilization.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@haydenshively
haydenshively marked this pull request as ready for review August 24, 2026 21:57
@haydenshively haydenshively changed the title Observability feat: wide-event, LogLayer-compatible observability architecture Aug 24, 2026

@devin-ai-integration devin-ai-integration Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Devin Review found 2 potential issues.

Open in Devin Review

Comment thread src/observability.ts Outdated
Comment thread README.md Outdated

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 445eeff196

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

Comment thread src/observability.ts Outdated
Comment thread src/stores/lru.ts Outdated
haydenshively and others added 2 commits August 24, 2026 17:07
Semantic resolutions beyond the textual conflicts:

- LruStore: our branch changed the constructor from positional
  `LruStore(maxBytes)` to `LruStore({ maxBytes, logger? })`. main's new
  test/stores/ttl.test.ts and three README examples still used the
  positional form. Git merged both sides cleanly, but the result silently
  left `maxBytes` undefined, disabling byte-cap eviction. Updated all 22
  call sites. Not caught by typecheck — tsconfig only includes `src`.

- failover: both branches added the transport independently (ours locally,
  main via #43). Verified main's is functionally identical to ours minus
  observability, so took ours wholesale.

- deployless/cache: main added gas-budget batching (`gasLimit`,
  `batch.gas`, `packByByteBudget` -> `packBatches`); ours added facets.
  Both intents kept at every call site, and `batch_bytes` still measures
  the ranges the new packer produces.

- cache: adopted main's hoisted `HandlerContext` and non-async request fn,
  with `facetId` added to the hoisted context.

- package.json: main's dependency bumps plus our `loglayer` devDep;
  pnpm-lock regenerated from main's rather than hand-merged.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
`loadAls` checked `als`, awaited the dynamic import, then assigned — so two
`withLogging` calls racing the first import each built their own
AsyncLocalStorage. The module variable kept whichever was assigned last, so
the other scope was invisible to `observe` and its call emitted nothing.
Memoize the in-flight promise so all racing callers share one instance.

`LruStore` took an options object but only checked `maxBytes < 1`, so the
superseded `new LruStore(bytes)` form left `maxBytes` undefined: every size
comparison false, eviction disabled, unbounded map. Reject non-finite and
non-number values so it fails loudly instead.

Both reported on #45 by Codex and Devin.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
haydenshively and others added 3 commits August 24, 2026 23:45
Brings in paged lenses with partial results (#49), and extends observability
onto the paths it introduces.

Semantic resolutions beyond the textual conflicts:

- utils/deployless/call.ts: took main's rewrite wholesale and re-applied the
  facet instrumentation onto it. `fetchRecursive` lost the `depth` parameter
  in the rewrite, so `splits_max_depth` was silently reduced to 0 until it
  was threaded back through the bisect path.

- New telemetry for the paged path, kept apart from `splits_*` because a
  lens stopping early is normal rather than a chunk being too big:
  `pages_continued`, `pages_waves`, and `elements_missing`. The last mirrors
  `DeploylessPartialResultError.missing`, so a partial result is queryable
  without parsing the error.

- failover: kept our instrumented loop and adopted main's `isTerminalError`
  guard ahead of `shouldThrow`, recording it as `terminated_by_terminal_error`
  so a partial-result payload surviving instead of falling over is visible.

- cache eth_call: adopted main's `onResolved` buffering and partial-result
  rebasing; `write_cache_ms` now times the final flush, since upserts are
  spread across chunks rather than done in one batch.

- test/transports/deployless.test.ts: main removed RETURN mode, so our
  observability test's enclosing `exfil` loop no longer existed and it
  referenced an undefined variable. Rebased onto the revert-only harness.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…d merge

Review of the #49 merge (Codex) found three fields whose names outran what
they measured:

- `elements_fetched` was stamped from the input count before any RPC ran, so
  a wholly failed call still reported every element fetched. Split into
  `elements_requested` (planned) and `elements_fetched`, now counted from
  committed entries — which also makes partial success visible.

- `elements_missing` counted deduped cache entries while the thrown
  `DeploylessPartialResultError` counts caller indices, so a repeated input
  could be missing twice in the error and once in telemetry. The cache path
  restamps it after rebasing. Regression test included.

- `write_cache_ms` timed a flush that hands off to the store without awaiting
  it, so remote write latency was never in the number. Renamed
  `flush_cache_ms`.

Also: `pages_*` and `elements_missing` are emitted only for paged lenses, so
their presence marks a paged run — previously a paged call that finished in
one wave was indistinguishable from an ordinary one, leaving no denominator
for a continuation rate. `batch_bytes` and the README now say they sample the
initial packing only, and the failover docstring covers terminal errors.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@haydenshively
haydenshively merged commit c273f6f into main Aug 25, 2026
3 checks passed
@haydenshively
haydenshively deleted the observability branch August 25, 2026 05:24
@linear-code

linear-code Bot commented Aug 25, 2026

Copy link
Copy Markdown

APPS-1259

haydenshively added a commit that referenced this pull request Aug 25, 2026
Follow-up to #49, which shipped paged lenses but had the transport drop
half the
lens's declared return value.

## The problem

A paged lens declares `(U[] results, uint256[] skipped)`. The transport
reassembled
the chunks and handed back a bare `U[]`, discarding `skipped`. That made
paged lenses
unreadable through `readContract`, `decodeFunctionResult`, and contract
instances —
the entire viem contract layer — because the response no longer matched
the fragment:

```
readContract(client, { abi: [pageAbi], ... })
// Position `129` is out of bounds (`0 < position < 128`)
```

`call2` existed to work around this, handing back `{ data, missing }`
from a thrown
error because the real shape had nowhere to go.

## The fix

Return the tuple the abi declares. The honest aggregate of N chunk-pages
*is* a page —
`results` is everything served, `skipped` is everything that wasn't,
rebased from
chunk-local to caller-global indices (and expanded across deduplicated
inputs). Nothing
is lost, and `readContract` works:

```ts
const [results, skipped] = await readContract(client, {
  abi: [pageAbi], functionName: 'page', args: [inputs],
  factory, factoryData, address: to,
  stateOverride: [policy({ abi: pageAbi, paged: true })],
})
```

Unpaged lenses are untouched — no `skipped` array to report into, so an
unservable
element still throws exactly as before.

## What this deletes

Everything built to route the dropped array around viem:

| Removed | Why it existed |
|---|---|
| `call2` | catch the error carrying the dropped array |
| `DeploylessPartialResultError` | be that error |
| `TERMINAL_ERROR` / `isTerminalError` | stop `failover` re-running on
it |
| `failover` terminal check + telemetry | same |
| `code = -32099` | stop viem retrying it |

A partial result is now a successful response, so `failover` never sees
it and viem
cannot retry it — both resolved structurally instead of by
classification. Net
**−368 lines**.

## Trade-offs, accepted deliberately

A caller who ignores `skipped` silently gets fewer elements where they'd
previously
have caught an exception. The abi forces the array to exist, and
re-throwing is one
`if` at the call site.

`skipped` merges elements the lens declined with elements that exhausted
the frame
even alone. The second depends on the node's `eth_call` gas cap, so
another provider
might serve them, whereas a decline is a property of the element. Called
out in the
README and the `policy` TSDoc.

## Verification

492 tests pass, typecheck / build / biome clean. New coverage:
`readContract` against
a paged lens through a real client, the aggregated tuple shape, and the
empty-input
page. The two observability tests from #45 that asserted `status:
"error"` on a partial
result now assert `"ok"` — `elements_missing` still stamps, and still
matches the
`skipped` array the caller receives.

---------

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants