feat(functions-compiler): every build records a returned 5xx as one _b44_error line

packages/functions-compiler/README.md

@@ -65,13 +65,17 @@ The first line of a compiled shard is its own manifest:
 
 `//!b44:<format>` is a fixed sentinel, so `head -1` on a script pulled from
 Cloudflare answers "what is in this?" without executing or parsing anything, and
-the payload is JSON so a tool parses it in one call. Only the app path emits it;
-the legacy single-function `bundle()` stays bannerless, which keeps that lane
-byte-comparable with the engine apper still runs.
+the payload is JSON so a tool parses it in one call. Only the app path emits it.
+The legacy single-function `bundle()` stays bannerless: it compiles one function,
+so "which functions are inside" already has its answer. apper's bundler service
+now runs this package (it no longer keeps its own engine), and nothing compares
+that lane's output byte for byte across engines.
 
 `functions` is sorted whatever order the shard was built in. `telemetry` and
 `runtimeSecrets` are there because they change the emitted bytes and a deploy has
-to pair its secrets delivery with them. `compiler` is this package's version.
+to pair its secrets delivery with them. `compiler` is this package's version; it
+also tells a consumer which wrapper features a build carries, such as the
+`_b44_error` record (see "Error records for a handled 5xx").
 
 Nothing volatile may be added: a timestamp or build id would re-mint a version
 for unchanged code, the app id would make the same functions compile differently
@@ -89,7 +93,9 @@ code that did not change, and all of these do:
 - the order the caller hands functions over in, for a single shard: that path
   builds in caller order, while a multi-shard plan sorts by name. Both branches
   are as apper has them, and `shard-build.e2e.test.ts` pins the difference;
-- either wrapper flag.
+- either wrapper flag (`postResponseTelemetry`, `runtimeSecrets`). The
+  `_b44_error` recorder is not a flag: every build carries it, so it moves the
+  bytes only when this package's version does.
 
 Two behaviours differ from apper's Python on purpose, and both are tested:
 
@@ -159,6 +165,67 @@ ask for one. Two functions in one per-app
 bundle can both list a `main.ts`, so a consumer that needs to know which
 function a frame belongs to reads that from the log line, not the map.
 
+### Error records for a handled 5xx
+
+A function that catches its own error and returns a 500 leaves Cloudflare
+nothing to record. **Every build** carries a small recorder in its generated
+entry (single-function and per-app; not actors), with no build option. That
+includes the public CLI's own builds, so an app is ready the moment it opts in,
+with no rebuild. It adds about 3 KB to a module (about 1.2 KB gzipped).
+
+The off switch is the request, not the build: the recorder does nothing unless
+the request carries `x-b44-feed-context`. The backend sends that header only for
+production calls of apps that opted in, while its tail switch is on; turning the
+switch off silences the record in every bundle, whatever built it. Without the
+header the recorder costs one header check per request and one context lookup
+per `console.*` call.
+
+When the header is present and the handler returns a `Response` with status
+≥ 500, that same response goes back at once: never rebuilt, never delayed, no
+header set. On a clone, inside `ctx.waitUntil`, the recorder:
+
+- picks the message, in this order: an Error logged during the request whose
+  message the JSON body repeats (the newest such among the last 8 Errors
+  logged, so a later unrelated warning doesn't hide it); else the body (JSON of
+  at most 2,048 bytes read within 50 ms; the first non-empty `error`,
+  `message`, `detail`, `details` or `error.message`, skipping `error` when it
+  is exactly `"Internal server error"` and `details` is present); else the last
+  Error logged during the request.
+  No message means no record;
+- takes the stack only from the logged Error that supplied the message. It is
+  that Error's raw `stack`, read inside the Worker, so it is **minified**:
+  Cloudflare remaps only the exceptions it captures, never a logged string. A
+  consumer remaps it with the same version's `source_map` (see Source maps);
+- replaces every env-binding and runtime-secret string of 8+ characters with
+  `[redacted]`, longest first, before cutting anything. This includes the strings
+  nested in JSON-valued ones (leading whitespace allowed), such as the
+  private-data-sources manifest;
+- caps `name` at 64 characters, `message` at 500 UTF-8 bytes (well-formed, cut
+  on a code point) and `stack` at 4 KB (cut at a line end);
+- logs exactly one line, with `console.error({ _b44_error: record })`.
+
+That call goes through the console patch, so **the object is not what a
+consumer sees.** A Tail Worker gets one log entry shaped like this:
+
+| Field | Value |
+|---|---|
+| the TailItem log's `level` | `"log"`. The patch writes every level through the original `console.log` |
+| the log's `message` | an array with **one** argument: the patch's wrapper object |
+| the wrapper's keys | `_b44_env`, `_b44_function` (per-app bundles only), `level`, `message` |
+| the wrapper's `level` | `"error"` |
+| the wrapper's `message` | the **JSON string** of `{ "_b44_error": { v: 1, kind: "response", status, name?, message, stack? } }` |
+
+So a consumer keeps logs whose wrapper `level` is `"error"`, then reads
+`JSON.parse(wrapper.message)._b44_error`. apper's error tail
+(`workers/base44-log-tail/src/error-tail.ts`) is that consumer, and
+`error-records.e2e.test.ts` pins this shape for both entries. The record is
+logged inside `waitUntil`, after the response has gone back, so it never lands
+in the `X-B44-Invocation-Logs` header. It is still an ordinary stamped line, so
+views built on stamped Workers log lines show it as an error line.
+
+Any failure writes nothing and never reaches the request. An uncaught throw is
+untouched: the entry still logs it and rethrows, and Cloudflare records it.
+
 ### Process isolation
 
 `installFetchGuard()` blocks outbound `fetch` other than the dependency

packages/functions-compiler/src/error-records.ts

@@ -0,0 +1,207 @@
+/**
+ * One `_b44_error` log line for a handled 5xx, for the Production Agent.
+ *
+ * A function that catches its own error and returns a 500 leaves Cloudflare
+ * nothing to record: no exception reaches the runtime, so the Tail Worker sees
+ * a status and no reason. Every generated entry (single-function and per-app;
+ * not actors) appends this prelude and routes the handler's response through
+ * `_b44RecordError`, with no build flag: an app is ready the moment it opts in,
+ * whatever compiled it.
+ *
+ * The off switch is the request, not the build: it does nothing unless the
+ * request carries `x-b44-feed-context`, which the backend sends only for
+ * production calls of apps that opted in while its tail switch is on;
+ * presence is enough. For a `Response` with status >= 500 it returns that same
+ * response at once — never rebuilt, never delayed, no header set — and inside
+ * `ctx.waitUntil` (a line logged there still belongs to the invocation's tail
+ * event) picks a message:
+ *
+ *   1. an Error logged during this request whose message the JSON body repeats
+ *      (the newest such, among the last 8 logged);
+ *   2. otherwise the body: JSON of at most 2,048 bytes read within 50 ms, first
+ *      non-empty string among `error`, `message`, `detail`, `details` and
+ *      `error.message` — skipping `error` when it is exactly
+ *      "Internal server error" and `details` is present (the SSO examples);
+ *   3. otherwise the last Error logged during this request (with a message).
+ *
+ * The stack comes only from the logged Error that supplied the message, and is
+ * minified: Cloudflare remaps the exceptions it captures, never a stack string
+ * logged from inside the Worker, so a consumer remaps it with the version's
+ * `source_map`. Every
+ * env-binding and runtime-secret string of 8+ characters (and the strings
+ * nested in JSON-valued ones, such as the private-data-sources manifest) is
+ * replaced with `[redacted]`, longest first, before anything is cut. Then it
+ * calls `console.error({ _b44_error: record })` once. Any failure writes
+ * nothing and never reaches the request.
+ *
+ * What a consumer sees is NOT that object: the call goes through the console
+ * patch. A Tail Worker gets one log entry whose `level` is "log" (the patch
+ * writes every level through the original console.log) and whose `message` is
+ * one argument, the patch's wrapper:
+ *   { _b44_env, _b44_function?, level: "error", message: "<JSON string>" }
+ * `_b44_function` is present only in per-app bundles, and `message` is the JSON
+ * string of `{ "_b44_error": { v: 1, kind: "response", status, name?, message,
+ * stack? } }`. apper's error tail (workers/base44-log-tail/src/error-tail.ts)
+ * parses exactly this; test/error-records.e2e.test.ts pins it. Change the
+ * console patch and that test must fail.
+ *
+ * Must be self-contained JS (no imports) — inlined into the generated entry
+ * after CONSOLE_PATCH. The entry provides `_b44Context` and the patched console.
+ */
+
+/** The request header that turns recording on. */
+const FEED_CONTEXT_HEADER = "x-b44-feed-context";
+
+const ERROR_RECORD_LIMITS = {
+  bodyBytes: 2048,
+  bodyDeadlineMs: 50,
+  nameChars: 64,
+  messageBytes: 500,
+  stackBytes: 4096,
+  minSecretChars: 8,
+  loggedErrors: 8,
+} as const;
+
+const L = ERROR_RECORD_LIMITS;
+
+export const ERROR_RECORDS_PATCH = [
+  `const _b44ErrorStore = (request) => request.headers.has(${JSON.stringify(FEED_CONTEXT_HEADER)}) ? { errorRecord: { logged: [] } } : {};`,
+  // The last few Errors passed to any console method during the request,
+  // oldest first, each read once at log time (a later mutation of the Error
+  // must not change the record). More than one: a handler that logs the real
+  // failure and then an unrelated warning must still match the first.
+  "const _b44NoteError = (a) => {",
+  "  const c = _b44Context();",
+  "  if (!c || !c.errorRecord) return;",
+  "  for (const x of a) {",
+  "    if (!(x instanceof Error)) continue;",
+  "    const r = (k) => { try { const v = x[k]; return typeof v === 'string' ? v : undefined; } catch (e) { return undefined; } };",
+  "    const logged = c.errorRecord.logged;",
+  "    logged.push({ name: r('name'), message: r('message'), stack: r('stack') });",
+  `    if (logged.length > ${L.loggedErrors}) logged.shift();`,
+  "  }",
+  "};",
+  "for (const _l of ['log', 'info', 'warn', 'error', 'debug']) { const _f = console[_l]; console[_l] = (...a) => { try { _b44NoteError(a); } catch (e) {} return _f(...a); }; }",
+  // JSON body of the clone: undefined when absent, too large, too slow or not JSON.
+  "const _b44ReadJson = async (res) => {",
+  "  if (!res.body) return undefined;",
+  "  const reader = res.body.getReader();",
+  "  const chunks = [];",
+  "  let size = 0;",
+  "  let timer;",
+  `  const deadline = new Promise((r) => { timer = setTimeout(() => r(null), ${L.bodyDeadlineMs}); });`,
+  "  try {",
+  "    for (;;) {",
+  "      const step = await Promise.race([reader.read(), deadline]);",
+  "      if (step === null) return undefined;",
+  "      if (step.done) break;",
+  "      size += step.value.byteLength;",
+  `      if (size > ${L.bodyBytes}) return undefined;`,
+  "      chunks.push(step.value);",
+  "    }",
+  "  } finally {",
+  "    clearTimeout(timer);",
+  "    try { reader.cancel().catch(() => {}); } catch (e) {}",
+  "  }",
+  "  const buf = new Uint8Array(size);",
+  "  let o = 0;",
+  "  for (const ch of chunks) { buf.set(ch, o); o += ch.byteLength; }",
+  "  try { return JSON.parse(new TextDecoder().decode(buf)); } catch (e) { return undefined; }",
+  "};",
+  "const _b44HasString = (v, s, d = 0) => {",
+  "  if (v === s) return true;",
+  "  if (d > 16 || !v || typeof v !== 'object') return false;",
+  "  for (const k of Object.keys(v)) if (_b44HasString(v[k], s, d + 1)) return true;",
+  "  return false;",
+  "};",
+  "const _b44BodyMessage = (b) => {",
+  "  if (!b || typeof b !== 'object' || Array.isArray(b)) return undefined;",
+  "  const s = (v) => (typeof v === 'string' && v.trim() !== '' ? v : undefined);",
+  "  const skipError = Object.prototype.hasOwnProperty.call(b, 'details') && b.error === 'Internal server error';",
+  "  const nested = b.error && typeof b.error === 'object' ? b.error.message : undefined;",
+  "  return (skipError ? undefined : s(b.error)) ?? s(b.message) ?? s(b.detail) ?? s(b.details) ?? s(nested);",
+  "};",
+  // Bindings are objects (KV, service, Hyperdrive); only strings and the
+  // values nested in JSON-valued strings are candidates.
+  "const _b44SecretValues = (c) => {",
+  "  const out = new Set();",
+  "  let budget = 10000;",
+  "  const add = (v, d) => {",
+  "    if (--budget < 0) return;",
+  "    if (typeof v === 'string') {",
+  `      if (v.length >= ${L.minSecretChars}) out.add(v);`,
+  // JSON.parse accepts leading whitespace, so the detection must too; the
+  // original string stays a candidate either way.
+  "      const t = v.trimStart();",
+  "      if (d < 2 && (t[0] === '{' || t[0] === '[')) { try { add(JSON.parse(v), d + 1); } catch (e) {} }",
+  "    } else if (d > 0 && d < 16 && v && typeof v === 'object') {",
+  "      for (const k of Object.keys(v)) add(v[k], d + 1);",
+  "    }",
+  "  };",
+  "  for (const src of [c.secrets, c.workerEnv]) {",
+  "    if (!src || typeof src !== 'object') continue;",
+  "    for (const k of Object.keys(src)) { try { add(src[k], 0); } catch (e) {} }",
+  "  }",
+  "  return [...out].sort((x, y) => y.length - x.length);",
+  "};",
+  "const _b44Scrub = (s, secrets) => { let out = s; for (const v of secrets) if (out.includes(v)) out = out.split(v).join('[redacted]'); return out; };",
+  "const _b44Well = (s) => (typeof s.toWellFormed === 'function' ? s.toWellFormed() : s);",
+  "const _b44Bytes = (s) => new TextEncoder().encode(s).length;",
+  "const _b44CutBytes = (s, max) => {",
+  "  if (_b44Bytes(s) <= max) return s;",
+  "  let n = 0;",
+  "  let out = '';",
+  "  for (const ch of s) {",
+  "    const cp = ch.codePointAt(0);",
+  "    const b = cp < 0x80 ? 1 : cp < 0x800 ? 2 : cp < 0x10000 ? 3 : 4;",
+  "    if (n + b > max) break;",
+  "    n += b;",
+  "    out += ch;",
+  "  }",
+  "  return out;",
+  "};",
+  "const _b44CutLines = (s, max) => {",
+  "  if (_b44Bytes(s) <= max) return s;",
+  "  let n = 0;",
+  "  let out = '';",
+  "  for (const line of s.split('\\n')) {",
+  "    const b = _b44Bytes(line) + (out ? 1 : 0);",
+  "    if (n + b > max) break;",
+  "    out += (out ? '\\n' : '') + line;",
+  "    n += b;",
+  "  }",
+  "  return out;",
+  "};",
+  // `logged` is the request's Errors at response time, oldest first.
+  "const _b44WriteErrorRecord = async (c, status, copy, logged) => {",
+  "  try {",
+  "    const body = await _b44ReadJson(copy);",
+  "    const usable = logged.filter((e) => e.message);",
+  "    let chosen;",
+  "    if (body !== undefined) {",
+  "      for (let i = usable.length - 1; i >= 0; i--) if (_b44HasString(body, usable[i].message)) { chosen = usable[i]; break; }",
+  "    }",
+  "    let message = chosen ? chosen.message : _b44BodyMessage(body);",
+  "    if (message === undefined && usable.length > 0) { chosen = usable[usable.length - 1]; message = chosen.message; }",
+  "    if (message === undefined) return;",
+  "    const secrets = _b44SecretValues(c);",
+  "    const clean = (s) => _b44Well(_b44Scrub(s, secrets));",
+  "    const rec = { v: 1, kind: 'response', status };",
+  `    const name = chosen && chosen.name ? Array.from(clean(chosen.name)).slice(0, ${L.nameChars}).join('') : '';`,
+  "    if (name) rec.name = name;",
+  `    rec.message = _b44CutBytes(clean(message), ${L.messageBytes});`,
+  `    const stack = chosen && chosen.stack ? _b44CutLines(clean(chosen.stack), ${L.stackBytes}) : '';`,
+  "    if (stack) rec.stack = stack;",
+  "    console.error({ _b44_error: rec });",
+  "  } catch (e) {}",
+  "};",
+  // Returns `res` itself in every path; the work rides waitUntil on a clone.
+  "const _b44RecordError = (res) => {",
+  "  try {",
+  "    const c = _b44Context();",
+  "    if (!c || !c.errorRecord || !c.waitUntil || !(res instanceof Response) || !(res.status >= 500)) return res;",
+  "    c.waitUntil(_b44WriteErrorRecord(c, res.status, res.clone(), c.errorRecord.logged.slice()));",
+  "  } catch (e) {}",
+  "  return res;",
+  "};",
+].join("\n");