feat(supervisor): emit start_time on wide events

Author: nicktrn

apps/supervisor/src/wideEvents/emit.test.ts

@@ -35,6 +35,26 @@ describe("emit", () => {
     expect(out.duration_ms).toBe(5);
   });
 
+  it("emits start_time as an ISO timestamp set by newState", () => {
+    const s = newState({ service: "supervisor", env: {} });
+    s.statusCode = 200;
+    s.ok = true;
+    const out = captureEmit(s);
+    expect(typeof out.start_time).toBe("string");
+    // Microsecond-precision RFC3339 (6 fractional digits), parseable as a date.
+    expect(out.start_time).toMatch(/^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{6}Z$/);
+    expect(Number.isNaN(new Date(out.start_time as string).getTime())).toBe(false);
+  });
+
+  it("omits start_time when unset", () => {
+    const s = newState({ service: "supervisor", env: {} });
+    delete s.startTime;
+    s.statusCode = 200;
+    s.ok = true;
+    const out = captureEmit(s);
+    expect(out).not.toHaveProperty("start_time");
+  });
+
   it("omits empty optional fields", () => {
     const s = newState({ service: "supervisor", env: {} });
     s.statusCode = 200;

apps/supervisor/src/wideEvents/emit.ts

@@ -21,6 +21,7 @@ export function emit(state: State): void {
   };
 
   if (state.traceId) out.trace_id = state.traceId;
+  appendIfSet(out, "start_time", state.startTime);
   appendIfSet(out, "service", state.service);
   appendIfSet(out, "version", state.version);
   appendIfSet(out, "commit_sha", state.commitSha);

apps/supervisor/src/wideEvents/new.ts

@@ -58,6 +58,7 @@ export function newState(opts: NewStateOptions): State {
   const requestId = isValidRequestId(inbound) ? inbound : newRequestId();
 
   return {
+    startTime: nowRfc3339(),
     requestId,
     traceId: parseTraceId(traceparent),
     traceparent,
@@ -80,3 +81,16 @@ export function newState(opts: NewStateOptions): State {
 function newRequestId(): string {
   return "req-" + randomBytes(16).toString("hex");
 }
+
+/**
+ * Current wall-clock time as an RFC3339 string with microsecond precision.
+ * `Date.toISOString()` only has millisecond resolution, which is too coarse to
+ * order multiple wide events emitted within the same millisecond.
+ * `performance.timeOrigin + performance.now()` gives a sub-millisecond wall-clock
+ * reading; we append the microsecond digits to the millisecond ISO string.
+ */
+function nowRfc3339(): string {
+  const ms = performance.timeOrigin + performance.now();
+  const micros = Math.floor((ms % 1) * 1000); // microseconds within the millisecond (0..999)
+  return new Date(ms).toISOString().slice(0, -1) + String(micros).padStart(3, "0") + "Z";
+}

apps/supervisor/src/wideEvents/state.ts

@@ -5,6 +5,13 @@
  * events stay compact.
  */
 export type State = {
+  /**
+   * Wall-clock time the event began, as an ISO-8601 string. Emitted as
+   * `start_time` so log collection orders events by when work started rather
+   * than by the collector's ingestion time.
+   */
+  startTime?: string;
+
   // Cross-stack correlation.
   requestId: string;
   traceId: string;