fix(web): WhiteGlove per-block durations use sequence-canonical edges, not timestamp min/max

Customer report (session fcb44595): dashboard said 115 min, session detail
said 5h 2m for the same pre-provisioned enrollment. The detail's per-block
duration calc took min/max over ALL event timestamps inside each
sequence-block, which two real-world timestamp shapes break:

- an app_install_started re-emitted by the ImeLogTracker after the Part-2
  resume legitimately carries its historical Part-1 event time -> the User
  Enrollment block stretched back across the sealed pause (56m -> 3h18m)
- a do_telemetry with a +1h source timestamp (IME log line with a wrong
  timezone bias, just under the agent's 1h future-skew clamp) stretched
  Pre-Provisioning (58m -> 1h44m)

Sum: exactly the "5h 2m" the customer saw.

Block spans are now anchored on the first/last event BY SEQUENCE (sequence
is the canonical order), with Part 1 starting at session.startedAt for
backend DurationSeconds parity. Extracted as pure helper
computeWhiteGloveDurations with tests modeled on the real session; replay
against the customer's 880 events yields 1h 54m == backend 6872s.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Oliver Kieselbach
2026-07-23 14:26:33 +02:00
parent 90012d9a66
commit 45d7c03ccf
3 changed files with 169 additions and 28 deletions
@@ -3,7 +3,7 @@
import { useMemo } from "react";
import { EnrollmentEvent, Session } from "@/types";
import { V1_PHASE_NAMES, V2_PHASE_NAMES, V1_PHASE_ORDER, V2_PHASE_ORDER } from "../utils/phaseConstants";
import { computeWhiteGloveSplitSequence, groupEventsByPhase } from "../utils/eventHelpers";
import { computeWhiteGloveDurations, computeWhiteGloveSplitSequence, groupEventsByPhase } from "../utils/eventHelpers";
interface PhaseGrouping {
eventsByPhase: Record<string, EnrollmentEvent[]>;
@@ -176,33 +176,8 @@ export function useSessionDerivedData(
if (!isWhiteGloveSession) {
return { preProvDuration: null as string | null, userEnrollDuration: null as string | null, combinedDuration: null as string | null };
}
const preProvEvts = whiteGloveSplitSequence < 0 ? events : events.filter(e => e.sequence <= whiteGloveSplitSequence);
const userEnrollEvts = whiteGloveSplitSequence < 0 ? [] : events.filter(e => e.sequence > whiteGloveSplitSequence);
const calcMs = (evts: EnrollmentEvent[]): number => {
if (evts.length === 0) return 0;
const ts = evts.map(e => new Date(e.timestamp).getTime());
return Math.max(...ts) - Math.min(...ts);
};
const fmt = (ms: number): string | null => {
const sec = Math.round(ms / 1000);
if (sec < 1) return null;
if (sec < 60) return `${sec}s`;
if (sec < 3600) return `${Math.floor(sec / 60)}m ${sec % 60}s`;
return `${Math.floor(sec / 3600)}h ${Math.floor((sec % 3600) / 60)}m`;
};
const preProvMs = calcMs(preProvEvts);
const userEnrollMs = calcMs(userEnrollEvts);
return {
preProvDuration: fmt(preProvMs),
userEnrollDuration: fmt(userEnrollMs),
combinedDuration: fmt(preProvMs + userEnrollMs),
};
}, [events, isWhiteGloveSession, whiteGloveSplitSequence]);
return computeWhiteGloveDurations(events, whiteGloveSplitSequence, session?.startedAt);
}, [events, isWhiteGloveSession, whiteGloveSplitSequence, session?.startedAt]);
// Group events by phase — single timeline for normal sessions, two groups for WhiteGlove
const { eventsByPhase, orderedPhases } = useMemo(() => {
@@ -66,6 +66,69 @@ export function computeWhiteGloveSplitSequence(events: EnrollmentEvent[]): numbe
return -1;
}
// Pure helper — per-block durations for WhiteGlove sessions.
// Duration 1 = pre-provisioning, Duration 2 = user enrollment, combined = D1 + D2
// (the sealed pause between reseal and resume is excluded).
//
// Block spans are anchored on the SEQUENCE-canonical edge events (first/last event by
// sequence), NOT on min/max over all timestamps in the block. Two real-world cases break
// the min/max approach:
// - Events re-emitted after the Part-2 resume can legitimately carry historical event
// times (e.g. an app_install_started the ImeLogTracker re-parses from the IME log,
// stamped with the Part-1 install start). min() would stretch the User Enrollment
// block back across the sealed pause.
// - A single clock-skewed source timestamp (e.g. an IME log line with a wrong timezone
// bias that slips under the agent's 1h future-skew clamp) would stretch the block
// the other way.
// Sequence is the canonical event order, so the block edges by sequence are the robust
// span anchors. Part 1 additionally starts at session.startedAt (registration) when
// provided — the same anchor the backend uses for DurationSeconds.
export interface WhiteGloveDurations {
preProvDuration: string | null;
userEnrollDuration: string | null;
combinedDuration: string | null;
}
export function computeWhiteGloveDurations(
events: EnrollmentEvent[],
splitSequence: number,
startedAt?: string,
): WhiteGloveDurations {
const preProvEvts = splitSequence < 0 ? events : events.filter(e => e.sequence <= splitSequence);
const userEnrollEvts = splitSequence < 0 ? [] : events.filter(e => e.sequence > splitSequence);
const spanMs = (evts: EnrollmentEvent[], startOverrideMs?: number): number => {
if (evts.length === 0) return 0;
let first = evts[0];
let last = evts[0];
for (const e of evts) {
if (e.sequence < first.sequence) first = e;
if (e.sequence > last.sequence) last = e;
}
const start = startOverrideMs ?? new Date(first.timestamp).getTime();
const end = new Date(last.timestamp).getTime();
return Math.max(0, end - start);
};
const fmt = (ms: number): string | null => {
const sec = Math.round(ms / 1000);
if (sec < 1) return null;
if (sec < 60) return `${sec}s`;
if (sec < 3600) return `${Math.floor(sec / 60)}m ${sec % 60}s`;
return `${Math.floor(sec / 3600)}h ${Math.floor((sec % 3600) / 60)}m`;
};
const startedAtMs = startedAt ? new Date(startedAt).getTime() : NaN;
const preProvMs = spanMs(preProvEvts, Number.isFinite(startedAtMs) ? startedAtMs : undefined);
const userEnrollMs = spanMs(userEnrollEvts);
return {
preProvDuration: fmt(preProvMs),
userEnrollDuration: fmt(userEnrollMs),
combinedDuration: fmt(preProvMs + userEnrollMs),
};
}
// Pure helper — groups a flat event list into phase buckets.
// Extracted from the useMemo so it can be called multiple times for WhiteGlove split timelines.
//
@@ -0,0 +1,103 @@
import { describe, it, expect } from "vitest";
import { computeWhiteGloveDurations } from "../../app/sessions/[sessionId]/utils/eventHelpers";
import type { EnrollmentEvent } from "@/types";
// Fixture builder — sequence and timestamp are the only fields that matter here.
function ev(seq: number, eventType: string, isoTs: string): EnrollmentEvent {
return {
eventId: `e${seq}`,
sessionId: "s1",
timestamp: isoTs,
eventType,
severity: "Info",
source: "Agent",
phase: 0,
message: eventType,
sequence: seq,
};
}
describe("computeWhiteGloveDurations", () => {
it("computes both blocks from the sequence-canonical edge events", () => {
const events = [
ev(1, "agent_started", "2026-07-23T08:31:00Z"),
ev(2, "esp_phase_changed", "2026-07-23T08:35:00Z"),
ev(3, "agent_shutting_down", "2026-07-23T09:28:00Z"), // Part 1 ends (reseal)
ev(4, "agent_started", "2026-07-23T11:00:00Z"), // Part 2 boot after sealed pause
ev(5, "enrollment_complete", "2026-07-23T11:56:00Z"),
];
const d = computeWhiteGloveDurations(events, 3);
expect(d.preProvDuration).toBe("57m 0s");
expect(d.userEnrollDuration).toBe("56m 0s");
expect(d.combinedDuration).toBe("1h 53m"); // pause 09:28→11:00 excluded
});
it("ignores a historical event time re-emitted into the user block (post-resume IME re-parse)", () => {
// Real case (session fcb44595): after the Part-2 resume the ImeLogTracker re-emits an
// app_install_started carrying the ORIGINAL Part-1 install time. min/max over timestamps
// stretched the user block back across the sealed pause (56m became 3h18m).
const events = [
ev(1, "agent_started", "2026-07-23T08:31:00Z"),
ev(2, "agent_shutting_down", "2026-07-23T09:28:00Z"),
ev(3, "agent_started", "2026-07-23T11:00:00Z"),
ev(4, "app_install_started", "2026-07-23T08:37:57Z"), // historical event time, Part-2 sequence
ev(5, "enrollment_complete", "2026-07-23T11:56:00Z"),
];
const d = computeWhiteGloveDurations(events, 2);
expect(d.userEnrollDuration).toBe("56m 0s");
expect(d.combinedDuration).toBe("1h 53m");
});
it("ignores a clock-skewed outlier timestamp inside the pre-provisioning block", () => {
// Real case (session fcb44595): a do_telemetry event carried a +1h source timestamp
// (IME log line with a wrong timezone bias, just under the agent's future-skew clamp).
// min/max stretched Part 1 from 57m to 1h44m.
const events = [
ev(1, "agent_started", "2026-07-23T08:31:00Z"),
ev(2, "do_telemetry", "2026-07-23T10:13:42Z"), // +1h skewed, mid-block by sequence
ev(3, "agent_shutting_down", "2026-07-23T09:28:00Z"),
ev(4, "agent_started", "2026-07-23T11:00:00Z"),
ev(5, "enrollment_complete", "2026-07-23T11:56:00Z"),
];
const d = computeWhiteGloveDurations(events, 3);
expect(d.preProvDuration).toBe("57m 0s");
});
it("anchors Part 1 at session.startedAt when provided (backend DurationSeconds parity)", () => {
const events = [
ev(1, "agent_started", "2026-07-23T08:31:00Z"),
ev(2, "agent_shutting_down", "2026-07-23T09:28:00Z"),
ev(3, "agent_started", "2026-07-23T11:00:00Z"),
ev(4, "enrollment_complete", "2026-07-23T11:56:00Z"),
];
const d = computeWhiteGloveDurations(events, 2, "2026-07-23T08:29:41Z");
expect(d.preProvDuration).toBe("58m 19s"); // 08:29:41 → 09:28:00
});
it("treats everything as Part 1 while no split point exists yet", () => {
const events = [
ev(1, "agent_started", "2026-07-23T08:31:00Z"),
ev(2, "esp_phase_changed", "2026-07-23T08:45:00Z"),
];
const d = computeWhiteGloveDurations(events, -1);
expect(d.preProvDuration).toBe("14m 0s");
expect(d.userEnrollDuration).toBeNull();
expect(d.combinedDuration).toBe("14m 0s");
});
it("returns nulls for an empty event list", () => {
const d = computeWhiteGloveDurations([], -1);
expect(d.preProvDuration).toBeNull();
expect(d.userEnrollDuration).toBeNull();
expect(d.combinedDuration).toBeNull();
});
it("never returns a negative span when edge timestamps are disordered", () => {
const events = [
ev(1, "agent_started", "2026-07-23T09:00:00Z"),
ev(2, "agent_shutting_down", "2026-07-23T08:59:00Z"), // straggler stamped before the boot
];
const d = computeWhiteGloveDurations(events, 2, "2026-07-23T09:30:00Z");
expect(d.preProvDuration).toBeNull(); // clamped to 0 → formatted as null
});
});