-
-
Notifications
You must be signed in to change notification settings - Fork 959
fix(webapp): reconcile trace with run lifecycle to handle ClickHouse lag #2875
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from 8 commits
bfda16b
e8d84fa
b591e28
425c3b4
4b19a1f
e030cc2
4c3f0e8
4dfadb9
80c5baf
17dbcd0
960b23f
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -6,7 +6,7 @@ import { getUsername } from "~/utils/username"; | |
| import { resolveEventRepositoryForStore } from "~/v3/eventRepository/index.server"; | ||
| import { SpanSummary } from "~/v3/eventRepository/eventRepository.types"; | ||
| import { getTaskEventStoreTableForRun } from "~/v3/taskEventStore.server"; | ||
| import { isFinalRunStatus } from "~/v3/taskStatus"; | ||
| import { isFailedRunStatus, isFinalRunStatus } from "~/v3/taskStatus"; | ||
| import { env } from "~/env.server"; | ||
|
|
||
| type Result = Awaited<ReturnType<RunPresenter["call"]>>; | ||
|
|
@@ -211,49 +211,47 @@ export class RunPresenter { | |
| let totalDuration = tree?.data.duration ?? 0; | ||
| const events = tree | ||
| ? flattenTree(tree).map((n) => { | ||
| const offset = millisecondsToNanoseconds( | ||
| n.data.startTime.getTime() - treeRootStartTimeMs | ||
| ); | ||
| //only let non-debug events extend the total duration | ||
| if (!n.data.isDebug) { | ||
| totalDuration = Math.max(totalDuration, offset + n.data.duration); | ||
| } | ||
| return { | ||
| ...n, | ||
| data: { | ||
| ...n.data, | ||
| timelineEvents: createTimelineSpanEventsFromSpanEvents( | ||
| n.data.events, | ||
| user?.admin ?? false, | ||
| treeRootStartTimeMs | ||
| ), | ||
| //set partial nodes to null duration | ||
| duration: n.data.isPartial ? null : n.data.duration, | ||
| offset, | ||
| isRoot: n.id === traceSummary.rootSpan.id, | ||
| }, | ||
| }; | ||
| }) | ||
| const offset = millisecondsToNanoseconds( | ||
| n.data.startTime.getTime() - treeRootStartTimeMs | ||
| ); | ||
| //only let non-debug events extend the total duration | ||
| if (!n.data.isDebug) { | ||
| totalDuration = Math.max(totalDuration, offset + n.data.duration); | ||
| } | ||
| return { | ||
| ...n, | ||
| data: { | ||
| ...n.data, | ||
| timelineEvents: createTimelineSpanEventsFromSpanEvents( | ||
| n.data.events, | ||
| user?.admin ?? false, | ||
| treeRootStartTimeMs | ||
| ), | ||
| //set partial nodes to null duration | ||
| duration: n.data.isPartial ? null : n.data.duration, | ||
| offset, | ||
| isRoot: n.id === traceSummary.rootSpan.id, | ||
| }, | ||
| }; | ||
| }) | ||
| : []; | ||
|
|
||
| //total duration should be a minimum of 1ms | ||
| totalDuration = Math.max(totalDuration, millisecondsToNanoseconds(1)); | ||
|
|
||
| let rootSpanStatus: "executing" | "completed" | "failed" = "executing"; | ||
| if (events[0]) { | ||
| if (events[0].data.isError) { | ||
| rootSpanStatus = "failed"; | ||
| } else if (!events[0].data.isPartial) { | ||
| rootSpanStatus = "completed"; | ||
| } | ||
| } | ||
| const reconciled = reconcileTraceWithRunLifecycle( | ||
| runData, | ||
| traceSummary.rootSpan.id, | ||
| events, | ||
| totalDuration | ||
| ); | ||
|
|
||
| return { | ||
| run: runData, | ||
| trace: { | ||
| rootSpanStatus, | ||
| events: events, | ||
| duration: totalDuration, | ||
| rootSpanStatus: reconciled.rootSpanStatus, | ||
| events: reconciled.events, | ||
| duration: reconciled.totalDuration, | ||
| rootStartedAt: tree?.data.startTime, | ||
| startedAt: run.startedAt, | ||
| queuedDuration: run.startedAt | ||
|
|
@@ -265,3 +263,68 @@ export class RunPresenter { | |
| }; | ||
| } | ||
| } | ||
|
|
||
| // NOTE: Clickhouse trace ingestion is eventually consistent. | ||
| // When a run is marked finished in Postgres, we reconcile the | ||
| // root span to reflect completion even if telemetry is still partial. | ||
| // This is a deliberate UI-layer tradeoff to prevent stale or "stuck" | ||
| // run states in the dashboard. | ||
| export function reconcileTraceWithRunLifecycle( | ||
| runData: { | ||
| isFinished: boolean; | ||
| status: Run["status"]; | ||
| createdAt: Date; | ||
| completedAt: Date | null; | ||
| rootTaskRun: { createdAt: Date } | null; | ||
| }, | ||
coderabbitai[bot] marked this conversation as resolved.
Outdated
Show resolved
Hide resolved
|
||
| rootSpanId: string, | ||
| events: RunEvent[], | ||
| totalDuration: number | ||
| ): { | ||
| events: RunEvent[]; | ||
| totalDuration: number; | ||
| rootSpanStatus: "executing" | "completed" | "failed"; | ||
| } { | ||
| const rootEvent = events.find((e) => e.id === rootSpanId); | ||
|
||
| const currentStatus: "executing" | "completed" | "failed" = rootEvent | ||
| ? rootEvent.data.isError | ||
| ? "failed" | ||
| : !rootEvent.data.isPartial | ||
| ? "completed" | ||
| : "executing" | ||
| : "executing"; | ||
|
|
||
| if (!runData.isFinished) { | ||
| return { events, totalDuration, rootSpanStatus: currentStatus }; | ||
| } | ||
|
|
||
| const postgresRunDuration = runData.completedAt | ||
| ? millisecondsToNanoseconds( | ||
| runData.completedAt.getTime() - | ||
| (runData.rootTaskRun?.createdAt ?? runData.createdAt).getTime() | ||
| ) | ||
| : 0; | ||
|
|
||
| const updatedTotalDuration = Math.max(totalDuration, postgresRunDuration); | ||
|
|
||
| const updatedEvents = events.map((e) => { | ||
| if (e.id === rootSpanId && e.data.isPartial) { | ||
| return { | ||
| ...e, | ||
| data: { | ||
| ...e.data, | ||
| isPartial: false, | ||
| duration: Math.max(e.data.duration ?? 0, postgresRunDuration), | ||
| isError: isFailedRunStatus(runData.status), | ||
| }, | ||
| }; | ||
| } | ||
| return e; | ||
| }); | ||
|
|
||
| return { | ||
| events: updatedEvents, | ||
| totalDuration: updatedTotalDuration, | ||
| rootSpanStatus: isFailedRunStatus(runData.status) ? "failed" : "completed", | ||
| }; | ||
| } | ||
coderabbitai[bot] marked this conversation as resolved.
Outdated
Show resolved
Hide resolved
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,89 @@ | ||
| import { millisecondsToNanoseconds } from "@trigger.dev/core/v3"; | ||
| import { isFailedRunStatus } from "~/v3/taskStatus"; | ||
| import type { TaskRunStatus } from "@trigger.dev/database"; | ||
|
|
||
| export type ReconcileRunData = { | ||
| isFinished: boolean; | ||
| status: TaskRunStatus; | ||
| createdAt: Date; | ||
| completedAt: Date | null; | ||
| rootTaskRun: { createdAt: Date } | null; | ||
| }; | ||
|
|
||
| export type ReconcileEvent = { | ||
| id: string; | ||
| data: { | ||
| isPartial: boolean; | ||
| isError: boolean; | ||
| duration?: number | null; | ||
| }; | ||
| }; | ||
|
|
||
| export type ReconcileResult = { | ||
| events: any[]; | ||
| totalDuration: number; | ||
| rootSpanStatus: "executing" | "completed" | "failed"; | ||
| }; | ||
|
|
||
| // NOTE: Clickhouse trace ingestion is eventually consistent. | ||
| // When a run is marked finished in Postgres, we reconcile the | ||
| // root span to reflect completion even if telemetry is still partial. | ||
| // This is a deliberate UI-layer tradeoff to prevent stale or "stuck" | ||
| // run states in the dashboard. | ||
| export function reconcileTraceWithRunLifecycle( | ||
| runData: ReconcileRunData, | ||
| rootSpanId: string, | ||
| events: any[], | ||
| totalDuration: number | ||
| ): ReconcileResult { | ||
| const rootEvent = events[0]; | ||
| const isActualRoot = rootEvent?.id === rootSpanId; | ||
|
|
||
| const currentStatus: "executing" | "completed" | "failed" = | ||
| isActualRoot && rootEvent | ||
| ? rootEvent.data.isError | ||
| ? "failed" | ||
| : !rootEvent.data.isPartial | ||
| ? "completed" | ||
| : "executing" | ||
| : "executing"; | ||
|
|
||
| if (!runData.isFinished) { | ||
| return { events, totalDuration, rootSpanStatus: currentStatus }; | ||
| } | ||
|
|
||
| const postgresRunDuration = runData.completedAt | ||
| ? millisecondsToNanoseconds( | ||
| runData.completedAt.getTime() - | ||
| (runData.rootTaskRun?.createdAt ?? runData.createdAt).getTime() | ||
| ) | ||
| : 0; | ||
|
|
||
| const updatedTotalDuration = Math.max(totalDuration, postgresRunDuration); | ||
|
|
||
| // We only need to potentially update the root event (the first one) if it matches our ID | ||
| if (isActualRoot && rootEvent && rootEvent.data.isPartial) { | ||
| const updatedEvents = [...events]; | ||
| updatedEvents[0] = { | ||
| ...rootEvent, | ||
| data: { | ||
| ...rootEvent.data, | ||
| isPartial: false, | ||
| duration: Math.max(rootEvent.data.duration ?? 0, postgresRunDuration), | ||
| isError: isFailedRunStatus(runData.status), | ||
| }, | ||
| }; | ||
|
|
||
| return { | ||
| events: updatedEvents, | ||
| totalDuration: updatedTotalDuration, | ||
| rootSpanStatus: isFailedRunStatus(runData.status) ? "failed" : "completed", | ||
| }; | ||
| } | ||
|
|
||
| return { | ||
| events, | ||
| totalDuration: updatedTotalDuration, | ||
| rootSpanStatus: isFailedRunStatus(runData.status) ? "failed" : "completed", | ||
| }; | ||
| } |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -1,20 +1,28 @@ | ||
| //From: https://kettanaito.com/blog/debounce-vs-throttle | ||
|
|
||
| /** A very simple throttle. Will execute the function at the end of each period and discard any other calls during that period. */ | ||
| /** A throttle that fires the first call immediately and ensures the last call during the duration is also fired. */ | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. this throttle change is here now, just curious why you keep adding this to your PRs?
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Regarding the throttle change: It was originally in PR #2874, but after your feedback that it was unrelated to the SDK fix, I've isolated it here. In this PR (#2875), it's one of the two main components of the fix for the dashboard refresh bug (#2798). The original throttle could drop final status updates; this trailing-edge version ensures the completion events are always delivered to the UI |
||
| export function throttle( | ||
| func: (...args: any[]) => void, | ||
| durationMs: number | ||
| ): (...args: any[]) => void { | ||
| let isPrimedToFire = false; | ||
|
|
||
| return (...args: any[]) => { | ||
| if (!isPrimedToFire) { | ||
| isPrimedToFire = true; | ||
| let timeoutId: NodeJS.Timeout | null = null; | ||
| let nextArgs: any[] | null = null; | ||
|
|
||
| setTimeout(() => { | ||
| func(...args); | ||
| isPrimedToFire = false; | ||
| }, durationMs); | ||
| const wrapped = (...args: any[]) => { | ||
| if (timeoutId) { | ||
| nextArgs = args; | ||
| return; | ||
| } | ||
|
|
||
| func(...args); | ||
|
|
||
| timeoutId = setTimeout(() => { | ||
| timeoutId = null; | ||
| if (nextArgs) { | ||
| const argsToUse = nextArgs; | ||
| nextArgs = null; | ||
| wrapped(...argsToUse); | ||
| } | ||
| }, durationMs); | ||
| }; | ||
|
|
||
| return wrapped; | ||
| } | ||
Uh oh!
There was an error while loading. Please reload this page.