Skip to content

Commit c3db157

Browse files
d-csclaude
andcommitted
fix(webapp): emit mollifier drainer LOG event as marker, not back-dated bar
engine.trigger rewrites the run's root span at materialisation (adopts the synth root via traceId/spanId carryover but updates start_time to "now"). A back-dated LOG event with startTime = bufferedAt landed before that root start and got clipped from the trace tree — persisted in ClickHouse but invisible to the admin viewing the page. Emit it as a zero-duration marker AT materialisation time instead, matching the [engine] QUEUED / PENDING_EXECUTING pattern. The historical window is preserved in metadata so admins can still read bufferedAt / dwellMs / attempts off the span detail pane. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
1 parent 6076610 commit c3db157

2 files changed

Lines changed: 31 additions & 20 deletions

File tree

apps/webapp/app/v3/mollifier/mollifierDrainerHandler.server.ts

Lines changed: 22 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -184,23 +184,32 @@ export function createDrainerHandler(deps: {
184184
}
185185

186186
// Admin-only audit trail emitted once engine.trigger has
187-
// landed a PG row. `recordRunDebugLog` flips this to
188-
// `TaskEventKind.LOG`, which the trace view + logs download
189-
// already gate behind admin
187+
// landed a PG row. `recordRunDebugLog` flips this to the
188+
// admin-gated debug kind (TaskEventKind.LOG in the PG store /
189+
// DEBUG_EVENT in the ClickHouse store) which the trace view +
190+
// logs download already strip for non-admins
190191
// (`eventRepository.server.ts:108`,
191-
// `resources.runs.$runParam.logs.download.ts:118`). Encoding
192-
// the buffered window as `startTime` + `duration` makes the
193-
// event render at the historical instant inside the run's
194-
// existing trace — admins see "Mollifier buffered for Xms"
195-
// sitting between trigger and dequeue. Best-effort: the
196-
// helper has its own try/catch and returns a result, so it
197-
// never throws into the materialisation path. Failures are
198-
// logged but not surfaced because the customer-visible run
199-
// has already landed.
192+
// `resources.runs.$runParam.logs.download.ts:118`).
193+
//
194+
// Placement: emit as a zero-duration marker AT materialisation
195+
// time, not as a back-dated bar spanning the buffered window.
196+
// `engine.trigger` rewrites the run's root span at
197+
// materialisation (it adopts the synth root via traceId/spanId
198+
// carryover but updates start_time to "now"), so the trace
199+
// renderer treats materialisation time as t=0. A back-dated
200+
// event with startTime = bufferedAt would land before that t=0
201+
// and get clipped from the tree. Same pattern as the
202+
// `[engine] QUEUED` markers. The window itself is preserved
203+
// in metadata so admins can read it off the span detail pane.
204+
//
205+
// Best-effort: `recordRunDebugLog` has its own try/catch and
206+
// returns a result, so it never throws into the materialisation
207+
// path. Failures are logged but not surfaced because the
208+
// customer-visible run has already landed.
200209
if (triggerSucceeded) {
201210
const debugResult = await recordRunDebugLog(
202211
RunId.fromFriendlyId(input.runId),
203-
`Mollifier buffered for ${dwellMs}ms before materialising`,
212+
`Mollifier buffered ${dwellMs}ms before materialising`,
204213
{
205214
attributes: {
206215
runId: input.runId,
@@ -211,8 +220,6 @@ export function createDrainerHandler(deps: {
211220
"mollifier.attempts": input.attempts,
212221
},
213222
},
214-
startTime: input.createdAt,
215-
duration: dwellMs * 1_000_000,
216223
parentId: snapshotSpanId,
217224
}
218225
);

apps/webapp/test/mollifierDrainerHandler.test.ts

Lines changed: 9 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -418,14 +418,18 @@ describe("createDrainerHandler", () => {
418418
// Internal cuid derived from the friendlyId, mirroring what
419419
// `findRunForEventCreation` queries on.
420420
expect(callRunId).toBe("z");
421-
expect(message).toMatch(/Mollifier buffered for \d+ms/);
422-
// Encodes the historical buffered window so the trace view places
423-
// the LOG event between trigger and dequeue (not at "now").
424-
expect(options.startTime).toBe(bufferedAt);
425-
expect(options.duration).toBeGreaterThan(0);
421+
expect(message).toMatch(/Mollifier buffered \d+ms before materialising/);
422+
// Emitted as a marker at materialisation time (no `startTime` /
423+
// `duration` overrides) — engine.trigger has just rewritten the
424+
// root span's start_time to "now", so back-dating the event would
425+
// clip it off-screen in the trace renderer. The historical window
426+
// is preserved in metadata so admins can still read it.
427+
expect(options.startTime).toBeUndefined();
428+
expect(options.duration).toBeUndefined();
426429
expect(options.parentId).toBe("snapspan");
427430
expect(options.attributes.metadata["mollifier.bufferedAt"]).toBe(bufferedAt.toISOString());
428431
expect(options.attributes.metadata["mollifier.attempts"]).toBe(2);
432+
expect(options.attributes.metadata["mollifier.dwellMs"]).toBeGreaterThan(0);
429433
});
430434

431435
it("does NOT emit the admin LOG event when engine.trigger fails non-retryably", async () => {

0 commit comments

Comments
 (0)