@aauth/call-log 0.1.0: the aauth.call record, at each end

.github/workflows/release.yml

@@ -78,7 +78,7 @@ jobs:
       - run: npm ci
       - name: Build packages (dependency order)
         run: |
-          for pkg in protocol interaction-code local-keys agent resource bootstrap fetch mcp-openclaw mcp-stdio; do
+          for pkg in protocol interaction-code call-log local-keys agent resource bootstrap fetch mcp-openclaw mcp-stdio; do
             echo "Building $pkg..."
             (cd "$pkg" && npm run build)
           done
@@ -88,7 +88,7 @@ jobs:
       # all-must-match gate.
       - name: Publish changed packages with provenance
         run: |
-          for pkg in protocol interaction-code local-keys agent resource bootstrap fetch mcp-openclaw mcp-stdio; do
+          for pkg in protocol interaction-code call-log local-keys agent resource bootstrap fetch mcp-openclaw mcp-stdio; do
             version=$(node -p "require('./$pkg/package.json').version")
             published=$(npm view "@aauth/$pkg" version 2>/dev/null || echo "0.0.0")
             if [ "$version" = "$published" ]; then

call-log/README.md

@@ -0,0 +1,87 @@
+# @aauth/call-log
+
+One log record per HTTP call between AAuth roles, written at each end. The
+AAuth call log (`monitor.aauth.dev`) joins the caller's and the callee's record
+on `call_id` and shows one row: who called whom, the request, the response.
+
+The record is `aauth.call`, specified in `aauth-dev/monitor`
+`plan/CALL_RECORD.md`. No dependencies. Runs in Cloudflare Workers
+(`nodejs_compat`) and Node.
+
+## What it does
+
+- **Tokens are logged as `{ type, payload }`** — the JWT's `typ` header and its
+  claims — wherever they appear: in `signed` and in place of the JWT string in
+  a body, at any depth. Never the JWT, so no log holds a presentable token.
+- **Bodies are logged.** JSON bodies as values; anything else as its content
+  type and size. A record over 30 KB has its larger body cut to text and
+  `truncated: true`.
+- **`call_id`** is base64url SHA-256 of the `Signature` header. Both ends hold
+  it, so their records join with no new header on the wire.
+- **`parent`** is the call being handled when an outbound call is made. It is
+  carried in AsyncLocalStorage from the middleware to any logged fetch in its
+  async continuation, so call sites pass nothing. Where the chain is broken on
+  purpose — a queue consumer, an alarm — pass `parent` yourself.
+- **Levels:** 30; 40 for a 4xx that is not a challenge, a peer's 5xx, or a
+  fetch that threw; 50 only for a 5xx the logging party answered itself.
+
+## The host
+
+```ts
+import { callLogMiddleware, loggedFetch, nameAgent, type CallLogHost } from '@aauth/call-log'
+
+const host = (c: Context): CallLogHost => ({
+  origin: c.env.ORIGIN,           // this party's server identifier
+  role: 'resource',               // agent | resource | ps | as
+  log: (record) => emit(c, record), // your event sink: adds service, timestamp, event_id
+  defer: (p) => c.executionCtx.waitUntil(p),
+})
+```
+
+`log` is called once per record, never awaited, wrapped in try/catch. Bodies
+are read from clones inside `defer`, after the response has gone.
+
+## The callee side
+
+```ts
+app.use('*', async (c, next) => callLogMiddleware(host(c))(c, next))
+```
+
+One record per request, skipping `OPTIONS`, `HEAD`, `/.well-known/*`,
+`/health` and `/openapi.json` (`skip` overrides). The caller is named from
+`Signature-Key` without verification, so a refused call still says who
+called. A person token names no agent; when your verifier resolves one, say so:
+
+```ts
+nameAgent(verified.agent_id)
+```
+
+## The caller side
+
+With `@aauth/agent`'s `createSignedFetch`, which reports the on-wire request
+through `onSigned`:
+
+```ts
+const psFetch = loggedFetch(
+  (onSigned) => createSignedFetch(keyMaterial, { signBody: true, onSigned }),
+  host(c),
+  { to_role: 'ps' },
+)
+```
+
+`makeFetch` is called once per call, so concurrent calls never swap reports.
+With `@hellocoop/httpsig`'s `fetch`:
+
+```ts
+const send = loggedHttpsigFetch(httpsigFetch, host(c), { to_role: 'as' })
+const res = await send(url, { method: 'POST', body, signingKey, signatureKey })
+```
+
+For a fetch you cannot wrap, `failedFetch(host, { url, status | error })`
+records a failure.
+
+## Pieces
+
+`callIdOf`, `tokenOf`, `tokenize`, `signerOf`, `paramsOf`, `errorOf`,
+`levelOf`, `partOf`, `cap`, `buildRecord`, `targetOf` are exported for a host
+that builds records its own way (Wallet's Fastify hooks do).

call-log/package.json

@@ -0,0 +1,38 @@
+{
+  "name": "@aauth/call-log",
+  "version": "0.1.0",
+  "description": "The aauth.call record: one log record per HTTP call between AAuth roles, at each end. A pure builder, a Hono-shaped middleware for the callee side, and logged fetch wrappers for the caller side.",
+  "type": "module",
+  "exports": {
+    ".": {
+      "types": "./dist/index.d.ts",
+      "default": "./dist/index.js"
+    }
+  },
+  "files": [
+    "dist"
+  ],
+  "scripts": {
+    "build": "tsc",
+    "prepublishOnly": "npm run build"
+  },
+  "keywords": [
+    "aauth",
+    "logging",
+    "observability"
+  ],
+  "author": "Dick Hardt <dick.hardt@hello.coop>",
+  "license": "MIT",
+  "publishConfig": {
+    "access": "public"
+  },
+  "repository": {
+    "type": "git",
+    "url": "https://github.com/aauth-dev/packages-js",
+    "directory": "call-log"
+  },
+  "devDependencies": {
+    "@types/node": "^20.0.0",
+    "typescript": "^5.0.0"
+  }
+}

call-log/src/callee.ts

@@ -0,0 +1,100 @@
+// The callee side: a Hono-shaped middleware. It names the call before the
+// handler runs (so the handler's outbound calls carry it as `parent`), then
+// writes the record once the response is known, reading the cloned bodies
+// off the request path.
+//
+// Typed against the little of Hono it uses, so the package depends on
+// nothing: `c.req.raw` (a Request), `c.res` (a Response after `next()`),
+// `c.executionCtx.waitUntil` when there is one.
+
+import { callIdOf, signerOf, withThumbprint, paramsOf, errorOf, partOf, buildRecord } from './record.js'
+import { runInCall, currentCall, type CallContext } from './context.js'
+import { emit, defer, type CallLogHost } from './host.js'
+
+export interface ContextLike {
+  req: { raw: Request }
+  res: Response
+  executionCtx?: { waitUntil(p: Promise<unknown>): void }
+}
+export type Next = () => Promise<void>
+
+export interface CalleeOptions {
+  /** Paths (or a test) that are not calls between roles: metadata, health, an SSE stream. */
+  skip?: (request: Request) => boolean
+}
+
+const skipByDefault = (request: Request) => {
+  if (request.method === 'OPTIONS' || request.method === 'HEAD') return true
+  const path = new URL(request.url).pathname
+  return path.startsWith('/.well-known/') || path === '/health' || path === '/openapi.json'
+}
+
+// A request body is read once by the handler. Clone before `next()` only
+// when it is worth logging: JSON, and small. Cloning tees the stream, and a
+// tee that nobody drains holds the bytes.
+const worthCloning = (request: Request) => {
+  if (!request.body) return false
+  const type = request.headers.get('content-type') ?? ''
+  if (!/json/i.test(type)) return false
+  const length = Number(request.headers.get('content-length'))
+  return !(Number.isFinite(length) && length > 256 * 1024)
+}
+
+/**
+ * `app.use('*', callLogMiddleware(host))`, before the routes. Every request
+ * not skipped gets one callee record.
+ */
+export function callLogMiddleware(host: CallLogHost, options: CalleeOptions = {}) {
+  const skip = options.skip ?? skipByDefault
+  return async (c: ContextLike, next: Next): Promise<void> => {
+    const request = c.req.raw
+    if (skip(request)) return next()
+    const started = new Date()
+    const callId = await callIdOf(request.headers.get('signature'))
+    const requestClone = worthCloning(request) ? request.clone() : null
+    const context: CallContext = { callId }
+    await runInCall(context, next)
+    const response = c.res
+    const ended = Date.now()
+    const responseClone = response.clone()
+    const hostWithCtx: CallLogHost = c.executionCtx?.waitUntil
+      ? { ...host, defer: host.defer ?? ((p) => c.executionCtx!.waitUntil(p)) }
+      : host
+    defer(
+      hostWithCtx,
+      (async () => {
+        const signer = await withThumbprint(signerOf(request.headers.get('signature-key')))
+        const agent = context.agent ?? signer.agent
+        const params = paramsOf(response.headers)
+        const url = new URL(request.url)
+        const requestPart = await partOf(requestClone)
+        const responsePart = await partOf(responseClone, params)
+        emit(
+          hostWithCtx,
+          buildRecord({
+            side: 'callee',
+            call_id: callId,
+            from: signer.from ?? agent,
+            from_role: signer.from_role ?? (agent ? 'agent' : undefined),
+            to: host.origin,
+            to_role: host.role,
+            agent,
+            method: request.method,
+            path: url.pathname,
+            query: url.search.slice(1) || undefined,
+            status: response.status,
+            started_at: started.toISOString(),
+            duration_ms: ended - started.getTime(),
+            signed: signer.signed,
+            request: requestPart,
+            response: responsePart,
+            error: response.status >= 400 ? errorOf(params, responsePart?.body) : undefined,
+          }),
+        )
+      })(),
+    )
+  }
+}
+
+/** The call being handled, for a handler that wants to know: its id. */
+export const currentCallId = (): string | undefined => currentCall()?.callId