Skip to content
Open
Show file tree
Hide file tree
Changes from 1 commit
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
4 changes: 4 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -264,6 +264,10 @@ The full v2 docs live at **[docs.deco.cx/v2](https://docs.deco.cx/v2/en/getting-
- [Migration](https://docs.deco.cx/v2/en/migration/overview) — v1 → v2 playbook + script + skill.
- [Case studies](https://docs.deco.cx/v2/en/case-studies/overview) — three production stores end-to-end.

In-repo references:

- [Observability](./docs/observability.md) — `instrumentWorker`, span/metric reference, Cloudflare wiring, ClickHouse query patterns.

---

## Peer dependencies
Expand Down
204 changes: 204 additions & 0 deletions docs/observability.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,204 @@
# Observability

`@decocms/start` ships a thin, opinionated observability layer for Deco storefronts on Cloudflare Workers. Spans, logs, and metrics flow through Cloudflare's managed export — there is no in-Worker OTLP exporter. The framework's job is to emit a well-shaped signal; transport is solved by Cloudflare Destinations and the `deco-otel-ingest` Worker.

## Architecture

```
┌────────────────────────────┐
│ site Worker │ instrumentWorker(handler, ...) wires:
│ instrumentWorker(...) │ - structured JSON logger → console.* (capture by CF Logs)
│ withTracing(...) │ - AE meter (when DECO_METRICS binding present)
│ logger.info|warn|error │ - bridge to @opentelemetry/api global tracer
└─────────────┬──────────────┘
│ OTLP/HTTP JSON via observability.{logs,traces}.destinations
┌────────────────────────────┐
│ deco-otel-ingest (Worker) │ Maps OTLP → ClickHouse clickhouseexporter schema,
│ redacts PII (cookie, │ redacts sensitive headers, persists to stats-lake.
│ authorization, x-vtex-*) │
└─────────────┬──────────────┘
┌────────────────────────────┐
│ stats-lake ClickHouse │ default.otel_traces / default.otel_logs (30-day TTL)
└─────────────┬──────────────┘
┌────────────────────────────┐
│ ClickStack UI │ hyperdx.clickhouse.cloud
│ (HyperDX-compatible) │
└────────────────────────────┘
```

## What's instrumented

| Span | Source | Key attributes |
| --------------------------------- | --------------------------------------------- | ---------------------------------------------------------------------- |
| `deco.http.request` | `workerEntry` root | `http.method`, `url.path` |
| `deco.cms.resolvePage` | `resolveDecoPage` | `deco.route` |
| `deco.section.loaders.batch` | `runSectionLoaders` | `section.count` |
| `deco.section.loader` | `runSingleSectionLoader` (per section) | `deco.section` |
| `deco.section.deferred.load` | `loadDeferredSection` (server fn) | `section.name`, `section.index`, `page.path` |
| `deco.cache.lookup` | edge cache `cache.match` | `cache.profile`, `cache.kind` (`html` \| `serverFn`) |
| `deco.cache.store` | edge cache `cache.put` (background) | `cache.profile`, `cache.kind` |
| `deco.admin.meta` | `/live/_meta`, `/deco/meta` | — |
| `deco.admin.decofile.read` | `GET /.decofile` | — |
| `deco.admin.decofile.reload` | `POST /.decofile` | — |
| `deco.admin.render` | `/live/previews/*`, `/deco/render` | `cms.component` |
| `deco.admin.invoke` | `/deco/invoke/$` | `invoke.key`, `invoke.batch` |

All framework spans also carry the per-span attribute floor described under **Identity**.

## What's measured

The meter is plugged at boot when `DECO_METRICS` (Workers Analytics Engine) is bound:

| Metric | Type | Source | Labels |
| ------------------------------ | --------- | ----------------------------------- | ------------------------------- |
| `http_requests_total` | counter | `workerEntry` | `method`, `path`, `status` |
| `http_request_duration_ms` | histogram | `workerEntry` | `method`, `path`, `status` |
| `http_request_errors_total` | counter | `workerEntry` (status >= 500) | `method`, `path`, `status` |
| `cache_hit_total` | counter | edge cache decision | `profile`, `decision` |
| `cache_miss_total` | counter | edge cache decision | `profile`, `decision` |
| `resolve_duration_ms` | histogram | `resolveDecoPage` | — |

`decision` values mirror the `X-Cache` response header: `HIT`, `STALE-HIT`, `STALE-ERROR`, `MISS`, `BYPASS`.

## Identity stamped on every span and log

`instrumentWorker(handler, { serviceName: "my-store" })` stamps the following on every framework-created span AND every log line via the logger attribute floor:

- `service.name` — the value passed to `instrumentWorker`, or `env.DECO_SITE_NAME`, or `"deco-site"`
- `service.version` — `env.CF_VERSION_METADATA?.id` (omitted when the binding isn't present)
- `deco.runtime.version` — `@decocms/start` build-time constant
- `deployment.environment` — `env.DECO_ENV_NAME` or `"production"`
- `deco.apps.version` — optional, passed via `OtelOptions.decoAppsVersion`

In addition, every log emitted inside a `withTracing(...)` scope carries:

- `trace_id` and `span_id` — pulled from the active span's `spanContext()`

That makes it possible to jump from any log line straight to its trace in ClickStack/HyperDX.

## Required `wrangler.jsonc` shape

```jsonc
{
"name": "my-store",
"main": "./src/worker-entry.ts",
"compatibility_date": "2026-02-14",
"compatibility_flags": ["nodejs_compat", "no_handle_cross_request_promise_resolution"],
"observability": {
"enabled": true,
"logs": {
"enabled": true,
"invocation_logs": true,
"head_sampling_rate": 1,
"persist": true,
"destinations": [
{
"id": "deco-otel-ingest-logs",
"kind": "otlp_http",
"endpoint": "https://deco-otel-ingest.deco-cx.workers.dev/v1/logs"
}
]
},
"traces": {
"enabled": true,
"head_sampling_rate": 0.1,
"persist": true,
"destinations": [
{
"id": "deco-otel-ingest-traces",
"kind": "otlp_http",
"endpoint": "https://deco-otel-ingest.deco-cx.workers.dev/v1/traces"
}
]
}
},
"version_metadata": { "binding": "CF_VERSION_METADATA" },
"analytics_engine_datasets": [
{ "binding": "DECO_METRICS", "dataset": "deco_metrics_my_store" }
]
}
```

The `version_metadata` binding is what makes `service.version` show up on spans and logs — without it, the framework still works but you can't correlate regressions to a specific deployment.

## Wiring `instrumentWorker`

```ts
// src/worker-entry.ts
import { createDecoWorkerEntry } from "@decocms/start/sdk/workerEntry";
import { instrumentWorker } from "@decocms/start/sdk/otel";
import serverEntry from "./server";

const handler = createDecoWorkerEntry(serverEntry, options);
export default instrumentWorker(handler, { serviceName: "my-store" });
```

`OtelOptions` also accepts a function `(env) => OtelOptions` if your service name comes from env.

## Log shape (and how to query it)

Cloudflare Destinations wraps every `console.log` line into an OTLP `LogRecord` with the JSON body in `body.stringValue`. The ingest Worker maps that to ClickHouse's `otel_logs.Body` verbatim. To filter logs by a structured field, use `JSONExtract` in ClickHouse:

```sql
-- Error rate by service over the last hour
SELECT
ServiceName,
countIf(JSONExtractString(Body, 'level') = 'error') AS errors,
count() AS total,
errors / total AS error_rate
FROM otel_logs
WHERE Timestamp > now() - INTERVAL 1 HOUR
GROUP BY ServiceName
ORDER BY error_rate DESC;
```

```sql
-- All logs for a given trace
SELECT Timestamp, SeverityText, Body
FROM otel_logs
WHERE JSONExtractString(Body, 'trace_id') = '0123456789abcdef0123456789abcdef'
ORDER BY Timestamp ASC;
```

In the ClickStack UI you can also filter logs panel by `trace_id` directly — paste the ID from a span and the matching log lines appear.

## Outbound trace propagation

For any outbound `fetch` issued during a request (VTEX, Shopify, internal APIs), inject a W3C `traceparent` header so upstream services that participate in OTel can join your trace:

```ts
import { injectTraceContext } from "@decocms/start/sdk/observability";

async function tracedFetch(url: string, init?: RequestInit) {
const headers = new Headers(init?.headers);
injectTraceContext(headers);
return fetch(url, { ...init, headers });
}
```

`injectTraceContext` is a no-op when no span is active and when the active span doesn't expose `spanContext()` — safe to call unconditionally. In `@decocms/apps`, the canonical `createInstrumentedFetch` helper calls this for every outbound call, so most sites don't have to think about it.

## Sampling

`head_sampling_rate` on `observability.traces` decides at trace start whether to forward to the destination. Cloudflare Destinations does NOT support tail sampling (status-aware filtering). The current pragmatic default is:

- `traces.head_sampling_rate: 0.1` — keep 10% of traces
- `logs.head_sampling_rate: 1.0` — keep 100% of logs (logs are cheap, error context comes from here)

When dashboards need 100% of error traces, the upgrade path is **ingest-side filtering**: set `head_sampling_rate: 1.0` and let `deco-otel-ingest` drop OK traces deterministically by `TraceId` while keeping all error traces. Lives in the ingest Worker, not the framework.

## Identity & cardinality notes

- `path` labels on `http_*` metrics are normalized via `normalizePath` (dynamic IDs collapsed to `:id`, PDP slugs to `:slug/p`) to keep AE label cardinality bounded.
- `cache.profile` is one of the built-in profiles (`product`, `listing`, `search`, `static`, `cart`, `private`, `none`) plus any custom profile registered via the site's `cacheHeaders` overrides. Small, fixed set — safe as a label.
- `deco.section` carries the section component key (e.g. `site/sections/ProductShelf.tsx`). Cardinality scales with the number of sections in the catalog — typically <100, fine for ClickHouse but **not** safe as an AE metric label (use it as a span attribute only).

## Out of scope

- **In-Worker OTLP exporter.** Removed in 5.0.0. CF Destinations handles transport; the framework only emits.
- **Tail-on-error sampling.** Lives in `deco-otel-ingest` or a CF Tail Worker if/when needed.
- **Commerce-specific spans.** Per-app (VTEX, Shopify) HTTP spans live in `@decocms/apps` via `createInstrumentedFetch`.
- **PII redaction.** Handled at the ingest Worker; no per-site code required.
40 changes: 36 additions & 4 deletions src/core/cms/sectionLoaders.test.ts
Original file line number Diff line number Diff line change
@@ -1,9 +1,11 @@
import { beforeEach, describe, expect, it, vi } from "vitest";
import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
import { configureTracer, type Span } from "../sdk/observability";
import type { ResolvedSection } from "./resolve";
import {
registerCacheableSections,
registerLayoutSections,
registerSectionLoader,
runSectionLoaders,
runSingleSectionLoader,
} from "./sectionLoaders";

Expand All @@ -25,9 +27,7 @@ const makeSection = (component: string, props: Record<string, unknown> = {}): Re
describe("runSingleSectionLoader — page context injection", () => {
it("injects __pageUrl and __pagePath into loader props", async () => {
// Two-arg signature so loader.mock.calls[0] types as [props, req].
const loader = vi.fn(
async (props: Record<string, unknown>, _req: Request) => props,
);
const loader = vi.fn(async (props: Record<string, unknown>, _req: Request) => props);
registerSectionLoader("site/sections/SearchBanner.tsx", loader);

const section = makeSection("site/sections/SearchBanner.tsx", { foo: "bar" });
Expand Down Expand Up @@ -274,3 +274,35 @@ describe("runSingleSectionLoader — nested section recursion", () => {
});
});
});

describe("runSectionLoaders — batch span", () => {
afterEach(() => {
configureTracer({ startSpan: () => ({ end: () => {} }) });
});

it("emits one deco.section.loaders.batch parent with section.count", async () => {
const spans: Array<{ name: string; attrs?: Record<string, unknown> }> = [];
configureTracer({
startSpan: (name, attrs) => {
spans.push({ name, attrs });
const s: Span = { end: () => {} };
return s;
},
});

registerSectionLoader("a", async (p) => p);
registerSectionLoader("b", async (p) => p);

await runSectionLoaders(
[makeSection("a"), makeSection("b"), makeSection("c-no-loader")],
new Request("https://site/"),
);

const batch = spans.find((s) => s.name === "deco.section.loaders.batch");
expect(batch).toBeDefined();
expect(batch?.attrs).toMatchObject({ "section.count": 3 });

const perSection = spans.filter((s) => s.name === "deco.section.loader");
expect(perSection).toHaveLength(3);
});
});
8 changes: 6 additions & 2 deletions src/core/cms/sectionLoaders.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,9 +9,9 @@
* inside the TanStack Start server function.
*/

import { withTracing } from "../sdk/observability";
import { getCacheProfile } from "../sdk/cacheHeaders";
import { djb2 } from "../sdk/djb2";
import { withTracing } from "../sdk/observability";
import type { ResolvedSection } from "./resolve";

export type SectionLoaderFn = (
Expand Down Expand Up @@ -267,7 +267,11 @@ export async function runSectionLoaders(
}
}
}
return Promise.all(sections.map((section) => runSingleSectionLoader(section, request)));
return withTracing(
"deco.section.loaders.batch",
() => Promise.all(sections.map((section) => runSingleSectionLoader(section, request))),
{ "section.count": sections.length },
);
}

/**
Expand Down
66 changes: 66 additions & 0 deletions src/core/sdk/logger.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -265,3 +265,69 @@ describe("serializeError", () => {
});
});
});

describe("trace correlation", () => {
afterEach(() => {
configureLogger(defaultLoggerAdapter);
setLogLevel("info");
});

it("includes trace_id/span_id when emitted inside withTracing", async () => {
const { configureTracer, setObservabilitySpanStore, withTracing } = await import(
"./observability"
);

let current: unknown = null;
setObservabilitySpanStore({
get: () => current as never,
run<R>(value: never, fn: () => R): R {
const prev = current;
current = value;
try {
const result = fn();
if (result instanceof Promise) {
return result.finally(() => {
current = prev;
}) as unknown as R;
}
current = prev;
return result;
} catch (err) {
current = prev;
throw err;
}
},
});
configureTracer({
startSpan: () => ({
end: () => {},
spanContext: () => ({
traceId: "deadbeefdeadbeefdeadbeefdeadbeef",
spanId: "1234567890abcdef",
traceFlags: 1,
}),
}),
});

const seen: Array<Record<string, unknown> | undefined> = [];
configureLogger({
log(_l, _m, attrs) {
seen.push(attrs);
},
});

await withTracing("t", async () => {
logger.info("inside-span", { custom: "yes" });
});
logger.info("outside-span", { custom: "no" });

expect(seen[0]).toMatchObject({
trace_id: "deadbeefdeadbeefdeadbeefdeadbeef",
span_id: "1234567890abcdef",
custom: "yes",
});
expect(seen[1]).toEqual({ custom: "no" });

setObservabilitySpanStore(undefined);
});
});
Loading
Loading