feat(viewer): instrument SSR with structured Workers Logs telemetry

packages/viewer/src/app.d.ts

@@ -0,0 +1,14 @@
+// See https://svelte.dev/docs/kit/types#app.d.ts
+import type { IncomingRequestCfProperties } from '@cloudflare/workers-types'
+
+declare global {
+  namespace App {
+    interface Platform {
+      // `verifiedBotCategory` (Cloudflare's bot classification, which we read for telemetry)
+      // isn't yet in the upstream `IncomingRequestCfProperties` type.
+      cf?: IncomingRequestCfProperties & { verifiedBotCategory?: string }
+    }
+  }
+}
+
+export {}

packages/viewer/src/debug.ts

@@ -1,7 +1,81 @@
+import { browser, building } from '$app/environment'
 import createDebug from 'debug'
 
 export const debug = createDebug('pi-base:viewer')
 
+// The structured schema we emit to Workers Logs during runtime SSR. Each event
+// is one queryable log entry; `requestId` ($metadata.requestId) lets us join
+// these back to the platform's own per-invocation telemetry (cpuTimeMs,
+// wallTimeMs) so any field below can slice those numbers.
+//
+// Timing note: on Workers `Date.now()` is clamped and only advances after I/O,
+// so wall-clock deltas around *CPU-bound* work read as ~0. We therefore record
+// reliable counts (and the platform's cpuTimeMs) rather than home-rolled CPU
+// timers; the one `ms` we keep (`bundle_sync`) wraps a real network fetch, where
+// the clock does advance.
+export type ServerEvent =
+  | {
+      // One per SSR Worker invocation (static assets bypass the Worker). Carries
+      // the SvelteKit route *pattern* — which the platform telemetry can't give
+      // us — plus the isolate cold flag and Cloudflare's verified bot category.
+      evt: 'request'
+      routeId: string | null
+      method: string
+      status: number
+      cold: boolean
+      botCategory: string | null
+    }
+  | {
+      // One per bundle sync. `changed` is true on a 200 (full parse+transform),
+      // false on a 304. Counts size the parse/transform work; `ms` is the (valid)
+      // network fetch duration.
+      evt: 'bundle_sync'
+      changed: boolean
+      spaces: number
+      properties: number
+      theorems: number
+      traits: number
+      ms: number
+    }
+  | {
+      // One per deduction run, logged synchronously at run *start*. `planned` is
+      // the number of spaces the run intends to deduce — the reliable proxy for
+      // deduction work, since the eager run finishes after the SSR response is
+      // sent, so a completion-time count is dropped. `reset` marks a full re-run
+      // (e.g. from a refresh) vs an incremental top-up.
+      evt: 'deduce_run'
+      planned: number
+      reset: boolean
+    }
+
+// Emit one structured Workers Logs event. We log the *object* (not a JSON
+// string) so Workers Logs indexes each field as a queryable key, the same way
+// the platform's `$workers.*` fields are. No-ops in the browser so we don't spam
+// the client console, and while prerendering so logs reflect only real runtime
+// invocations — use `debug`/`trace` for client-side tracing.
+export function serverLog(event: ServerEvent): void {
+  if (browser || building) {
+    return
+  }
+
+  console.log({ source: 'pi-base:viewer', ...event })
+}
+
+// Cold-start latch for the current Worker isolate. Module state survives across
+// requests in a warm isolate, so the first read returns true (this isolate just
+// booted: full JS init + first bundle parse) and every later request reads
+// false. Read it from exactly one place per request (hooks.server.ts) so the
+// latch flips once; combined with the platform's per-invocation cpuTimeMs this
+// separates one-time isolate/parse cost from steady-state request cost.
+let warmed = false
+export function isolateCold(): boolean {
+  if (warmed) {
+    return false
+  }
+  warmed = true
+  return true
+}
+
 export type Event =
   | { event: 'remote_fetch_started'; host: string; branch: string }
   | { event: 'remote_fetch_complete'; result: unknown }

packages/viewer/src/gateway.ts

@@ -1,7 +1,7 @@
 import * as pb from '@pi-base/core'
 
 import { Id, type Property, type Space, type Trait } from './models'
-import { trace } from './debug'
+import { serverLog, trace } from './debug'
 
 export type Sync = (
   host: string,
@@ -24,12 +24,28 @@ export function sync(
 ): Sync {
   return async (host: string, branch: string, etag?: string) => {
     trace({ event: 'remote_fetch_started', host, branch })
+    // `ms` wraps the network fetch — real I/O, so the Workers clock advances and
+    // this is a trustworthy duration (unlike CPU-bound timings). Faithful to
+    // current behaviour: there is no isolate bundle cache, so every SSR request
+    // re-fetches and (on a 200) re-parses/transforms the whole bundle.
+    const startedAt = Date.now()
     const result = bundle
       ? { bundle, etag: 'etag' }
       : await pb.bundle.fetch({ host, branch, etag, fetch })
+    const ms = Date.now() - startedAt
 
     if (result) {
       trace({ event: 'remote_fetch_complete', result })
+      const { spaces, properties, theorems, traits } = result.bundle
+      serverLog({
+        evt: 'bundle_sync',
+        changed: true,
+        spaces: spaces.size,
+        properties: properties.size,
+        theorems: theorems.size,
+        traits: traits.size,
+        ms,
+      })
       return {
         spaces: transform(space, result.bundle.spaces),
         properties: transform(property, result.bundle.properties),
@@ -40,6 +56,15 @@ export function sync(
       }
     } else if (etag) {
       trace({ event: 'bundle_unchanged', etag })
+      serverLog({
+        evt: 'bundle_sync',
+        changed: false,
+        spaces: 0,
+        properties: 0,
+        theorems: 0,
+        traits: 0,
+        ms,
+      })
     }
   }
 }

packages/viewer/src/hooks.server.ts

@@ -1,12 +1,30 @@
 import type { Handle } from '@sveltejs/kit'
 
+import { isolateCold, serverLog } from '@/debug'
+
 // See https://kit.svelte.dev/docs/hooks#server-hooks
 export const handle: Handle = async ({ event, resolve }) => {
-  return resolve(event, {
+  const response = await resolve(event, {
     // We use the `etag` header from S3 to determine whether the bundle has
     // changed (and deduction needs to be re-run), so we need to preserve it.
     filterSerializedResponseHeaders(name, _value) {
       return name === 'etag'
     },
   })
+
+  // Only SSR/endpoint requests reach this hook — static assets are served by the
+  // Workers assets layer without invoking the Worker. Logging the route pattern,
+  // isolate cold flag, and Cloudflare's verified bot category here lets us slice
+  // the platform's per-invocation cpuTimeMs/wallTimeMs (joined by requestId) by
+  // page, by cold vs warm isolate, and by human vs crawler.
+  serverLog({
+    evt: 'request',
+    routeId: event.route.id,
+    method: event.request.method,
+    status: response.status,
+    cold: isolateCold(),
+    botCategory: event.platform?.cf?.verifiedBotCategory ?? null,
+  })
+
+  return response
 }

packages/viewer/src/stores/deduction.ts

@@ -17,6 +17,7 @@ import type {
   Trait,
   Traits,
 } from '@/models'
+import { serverLog } from '@/debug'
 import { eachTick, read, subscribeUntil } from '@/util'
 
 export type State = {
@@ -109,6 +110,13 @@ export function create(
       }
     })
 
+    // Log the planned work *synchronously*, before the async loop. On the eager
+    // SSR model the loop finishes after the response is sent (the page resolves
+    // as soon as its space is reached), so a completion-time count is dropped;
+    // `planned` (spaces this run intends to deduce) is captured pre-response and
+    // reliably sizes the deduction work, joinable to platform cpuTimeMs.
+    serverLog({ evt: 'deduce_run', planned: unchecked.length, reset })
+
     return eachTick(unchecked, (s: Space, halt: () => void) => {
       store.update(state => ({ ...state, checking: s.name }))
 

packages/viewer/wrangler.jsonc

@@ -18,9 +18,10 @@
     "directory": ".svelte-kit/cloudflare"
   },
   "env": {
+    // Persist Workers Logs + traces for both sites (queryable in the dashboard
+    // and via the observability API). invocation_logs gives per-request
+    // cpuTimeMs/wallTimeMs; traces give the auto I/O waterfall (bundle fetch).
     "topology": {
-      // Persist Workers Logs for the production site (queryable in the
-      // dashboard and via the observability API). graphs can opt in later.
       "observability": {
         "enabled": true,
         "logs": {
@@ -30,6 +31,15 @@
         "traces": { "enabled": true, "head_sampling_rate": 1 }
       }
     },
-    "graphs": {}
+    "graphs": {
+      "observability": {
+        "enabled": true,
+        "logs": {
+          "enabled": true,
+          "invocation_logs": true
+        },
+        "traces": { "enabled": true, "head_sampling_rate": 1 }
+      }
+    }
   }
 }