-
-
Notifications
You must be signed in to change notification settings - Fork 1.1k
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
Changes from 8 commits
bfda16b
e8d84fa
b591e28
425c3b4
4b19a1f
e030cc2
4c3f0e8
4dfadb9
80c5baf
17dbcd0
960b23f
805eae7
972db5f
be43941
389e037
3052cc4
92fd9f9
c6ebc5a
27fd2db
838980c
daab67c
c743d9d
52311e7
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, | ||
|
Contributor
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. 🔴 Reconciliation fails for child task runs due to incorrect root span ID comparison The reconciliation logic does not update the root span's Click to expandRoot CauseIn const reconciled = reconcileTraceWithRunLifecycle(
runData,
traceSummary.rootSpan.id, // This is the TRACE's root span
events,
totalDuration
);However, the const tree = createTreeFromFlatItems(traceSummary.spans, run.spanId);This means In the reconciliation function (
|
||
| 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", | ||
devin-ai-integration[bot] marked this conversation as resolved.
Outdated
Show resolved
Hide resolved
|
||
| }; | ||
| } | ||
| 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?
Contributor
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.