diff --git a/python/packages/devui/agent_framework_devui/_mapper.py b/python/packages/devui/agent_framework_devui/_mapper.py index 07f87fec3f..86db4a0e26 100644 --- a/python/packages/devui/agent_framework_devui/_mapper.py +++ b/python/packages/devui/agent_framework_devui/_mapper.py @@ -1056,6 +1056,7 @@ class MessageMapper: output_index=context["output_index"], sequence_number=self._next_sequence(context), item=executor_item, + created_at=float(time.time()), ) ] @@ -1088,6 +1089,7 @@ class MessageMapper: output_index=context.get("output_index", 0), sequence_number=self._next_sequence(context), item=executor_item, + created_at=float(time.time()), ) ] @@ -1121,6 +1123,7 @@ class MessageMapper: output_index=context.get("output_index", 0), sequence_number=self._next_sequence(context), item=executor_item, + created_at=float(time.time()), ) ] diff --git a/python/packages/devui/agent_framework_devui/models/_openai_custom.py b/python/packages/devui/agent_framework_devui/models/_openai_custom.py index e59d72b892..d64b1ec49c 100644 --- a/python/packages/devui/agent_framework_devui/models/_openai_custom.py +++ b/python/packages/devui/agent_framework_devui/models/_openai_custom.py @@ -64,6 +64,7 @@ class CustomResponseOutputItemAddedEvent(BaseModel): output_index: int sequence_number: int item: dict[str, Any] | ExecutorActionItem | Any # Flexible item type + created_at: float | None = None # Unix timestamp; used by frontend for accurate workflow timings class CustomResponseOutputItemDoneEvent(BaseModel): @@ -77,6 +78,7 @@ class CustomResponseOutputItemDoneEvent(BaseModel): output_index: int sequence_number: int item: dict[str, Any] | ExecutorActionItem | Any # Flexible item type + created_at: float | None = None # Unix timestamp; used by frontend for accurate workflow timings class ResponseWorkflowEventComplete(BaseModel): diff --git a/python/packages/devui/frontend/src/components/features/workflow/execution-timeline.tsx b/python/packages/devui/frontend/src/components/features/workflow/execution-timeline.tsx index 286d1e27f0..b9b2fc7da4 100644 --- a/python/packages/devui/frontend/src/components/features/workflow/execution-timeline.tsx +++ b/python/packages/devui/frontend/src/components/features/workflow/execution-timeline.tsx @@ -356,8 +356,10 @@ export function ExecutionTimeline({ const runNumber = (runCount.get(executorId) || 0) + 1; runCount.set(executorId, runNumber); - // Create synthetic item ID for fallback format (no real item.id from backend) - const syntheticItemId = `fallback_${executorId}_${uiTimestamp}`; + // Create synthetic item ID using the run counter for guaranteed uniqueness. + // Using uiTimestamp here caused collisions when the same executor ran + // twice within the same second (both fallback entries would share an ID). + const syntheticItemId = `fallback_${executorId}_run${runNumber}`; runs.push({ executorId, diff --git a/python/packages/devui/frontend/src/components/features/workflow/workflow-view.tsx b/python/packages/devui/frontend/src/components/features/workflow/workflow-view.tsx index 6a3e3f4b11..4696ef57a5 100644 --- a/python/packages/devui/frontend/src/components/features/workflow/workflow-view.tsx +++ b/python/packages/devui/frontend/src/components/features/workflow/workflow-view.tsx @@ -576,17 +576,37 @@ export function WorkflowView({ openAIEvent.type === "response.workflow_event.complete" // Fallback variant ) { setOpenAIEvents((prev) => { - // Generate unique timestamp for each event + // Derive a server-side timestamp from the event, in priority order: + // 1. top-level created_at (custom output-item events) + // 2. response.created_at (response.created / lifecycle events) + // 3. data.timestamp (response.workflow_event.completed ISO string) + // Fall back to a synthesized timestamp only when none is present. + const anyEvent = openAIEvent as Record; + const eventTimestamp: number | undefined = + typeof anyEvent["created_at"] === "number" && anyEvent["created_at"] + ? (anyEvent["created_at"] as number) + : typeof (anyEvent["response"] as Record | undefined)?.["created_at"] === "number" + ? ((anyEvent["response"] as Record)["created_at"] as number) + : (() => { + const ts = (anyEvent["data"] as Record | undefined)?.["timestamp"]; + if (typeof ts !== "string") return undefined; + const ms = new Date(ts).getTime(); + // Guard against NaN: Python isoformat() emits microseconds without Z, + // which some JS engines cannot parse. Number.isFinite rejects NaN. + return Number.isFinite(ms) ? ms / 1000 : undefined; + })(); const baseTimestamp = Math.floor(Date.now() / 1000); const lastTimestamp = prev.length > 0 ? (prev[prev.length - 1] as { _uiTimestamp?: number }) ._uiTimestamp || 0 : 0; - const uniqueTimestamp = Math.max( - baseTimestamp, - lastTimestamp + 1 - ); + // When we have a real server timestamp clamp to lastTimestamp (no +1s gap). + // When synthesizing, keep the +1 s gap so ordering is always monotonic. + const uniqueTimestamp = + eventTimestamp !== undefined + ? Math.max(eventTimestamp, lastTimestamp) + : Math.max(baseTimestamp, lastTimestamp + 1); return [ ...prev, @@ -992,14 +1012,37 @@ export function WorkflowView({ openAIEvent.type === "response.workflow_event.completed" ) { setOpenAIEvents((prev) => { - // Generate unique timestamp for each event + // Derive a server-side timestamp from the event, in priority order: + // 1. top-level created_at (custom output-item events) + // 2. response.created_at (response.created / lifecycle events) + // 3. data.timestamp (response.workflow_event.completed ISO string) + // Fall back to a synthesized timestamp only when none is present. + const anyEvent = openAIEvent as Record; + const eventTimestamp: number | undefined = + typeof anyEvent["created_at"] === "number" && anyEvent["created_at"] + ? (anyEvent["created_at"] as number) + : typeof (anyEvent["response"] as Record | undefined)?.["created_at"] === "number" + ? ((anyEvent["response"] as Record)["created_at"] as number) + : (() => { + const ts = (anyEvent["data"] as Record | undefined)?.["timestamp"]; + if (typeof ts !== "string") return undefined; + const ms = new Date(ts).getTime(); + // Guard against NaN: Python isoformat() emits microseconds without Z, + // which some JS engines cannot parse. Number.isFinite rejects NaN. + return Number.isFinite(ms) ? ms / 1000 : undefined; + })(); const baseTimestamp = Math.floor(Date.now() / 1000); const lastTimestamp = prev.length > 0 ? (prev[prev.length - 1] as { _uiTimestamp?: number }) ._uiTimestamp || 0 : 0; - const uniqueTimestamp = Math.max(baseTimestamp, lastTimestamp + 1); + // When we have a real server timestamp clamp to lastTimestamp (no +1s gap). + // When synthesizing, keep the +1 s gap so ordering is always monotonic. + const uniqueTimestamp = + eventTimestamp !== undefined + ? Math.max(eventTimestamp, lastTimestamp) + : Math.max(baseTimestamp, lastTimestamp + 1); return [ ...prev, diff --git a/python/packages/devui/tests/devui/test_mapper.py b/python/packages/devui/tests/devui/test_mapper.py index bab2130a99..b26900a89f 100644 --- a/python/packages/devui/tests/devui/test_mapper.py +++ b/python/packages/devui/tests/devui/test_mapper.py @@ -391,6 +391,94 @@ async def test_executor_failed_event(mapper: MessageMapper, test_request: AgentF assert "Executor failed" in str(item["error"]) +async def test_executor_events_carry_created_at_timestamp( + mapper: MessageMapper, test_request: AgentFrameworkRequest +) -> None: + """REGRESSION TEST: Executor mapped events must include a created_at timestamp. + + Without created_at, the frontend synthesizes timestamps using + Math.max(baseTimestamp, lastTimestamp + 1) with second precision, forcing + a minimum 1-second gap between sequential events regardless of their actual + elapsed time. This makes instant workflows appear to take multiple seconds + in the DevUI timeline. + """ + invoke_event = create_executor_invoked_event(executor_id="exec_ts") + complete_event = create_executor_completed_event(executor_id="exec_ts") + fail_event = create_executor_failed_event(executor_id="exec_ts_fail") + + invoked_results = await mapper.convert_event(invoke_event, test_request) + completed_results = await mapper.convert_event(complete_event, test_request) + + # Set up a separate context for the failed path + mapper2 = MessageMapper() + await mapper2.convert_event(create_executor_invoked_event(executor_id="exec_ts_fail"), test_request) + failed_results = await mapper2.convert_event(fail_event, test_request) + + for label, results in [ + ("executor_invoked", invoked_results), + ("executor_completed", completed_results), + ("executor_failed", failed_results), + ]: + assert results, f"mapper.convert_event should return events for {label}" + for event in results: + assert getattr(event, "created_at", None) is not None, ( + f"{label} mapped event {type(event).__name__} is missing 'created_at'. " + "The frontend relies on this field for accurate workflow timeline timings." + ) + assert event.created_at > 0, ( + f"{label} mapped event {type(event).__name__} has a non-positive " + f"created_at value ({event.created_at!r}); expected a valid Unix timestamp." + ) + + +def test_custom_output_item_event_models_have_created_at_field() -> None: + """MODEL TEST: CustomResponseOutputItemAddedEvent and Done must declare created_at. + + This guards against accidentally removing the field from the model definition. + A missing field causes a downstream ValidationError instead of a clear test failure. + """ + from agent_framework_devui.models._openai_custom import ( + CustomResponseOutputItemAddedEvent, + CustomResponseOutputItemDoneEvent, + ) + + assert "created_at" in CustomResponseOutputItemAddedEvent.model_fields, ( + "CustomResponseOutputItemAddedEvent is missing 'created_at' in model_fields. " + "The frontend uses this field for accurate workflow timeline timings." + ) + assert "created_at" in CustomResponseOutputItemDoneEvent.model_fields, ( + "CustomResponseOutputItemDoneEvent is missing 'created_at' in model_fields. " + "The frontend uses this field for accurate workflow timeline timings." + ) + + +async def test_executor_completed_maps_to_output_item_done_event( + mapper: MessageMapper, test_request: AgentFrameworkRequest +) -> None: + """Test executor_completed events are mapped to CustomResponseOutputItemDoneEvent. + + Ensures executor_completed does not fall through to the legacy + ResponseWorkflowEventComplete path, which lacks a top-level created_at field. + """ + from agent_framework_devui.models._openai_custom import ResponseWorkflowEventComplete + + invoke_event = create_executor_invoked_event(executor_id="exec_output_item") + await mapper.convert_event(invoke_event, test_request) + + complete_event = create_executor_completed_event(executor_id="exec_output_item") + results = await mapper.convert_event(complete_event, test_request) + + assert results, "mapper.convert_event should return events for executor_completed" + + workflow_events = [r for r in results if isinstance(r, ResponseWorkflowEventComplete)] + assert not workflow_events, ( + "executor_completed should map to CustomResponseOutputItemDoneEvent, not ResponseWorkflowEventComplete." + ) + + output_item_done = [r for r in results if r.type == "response.output_item.done"] + assert output_item_done, f"Expected at least one response.output_item.done event; got: {[r.type for r in results]}" + + # ============================================================================= # Workflow Lifecycle Event Tests # =============================================================================