Files
Evan Mattson 27f926609f Python: Fix incorrect workflow timings in DevUI by adding created_at to executor events (#5615)
* fix(devui): add created_at to custom output item events for correct workflow timings (#5545)

CustomResponseOutputItemAddedEvent and CustomResponseOutputItemDoneEvent lacked a
created_at field, causing the frontend to synthesize timestamps using integer-second
precision with a forced +1s minimum gap between events. This made instant workflows
appear to take 3+ seconds in the DevUI timeline.

Fix:
- Add optional created_at: float | None field to both custom event models
- Populate created_at=float(time.time()) in the mapper for executor_invoked,
  executor_completed, and executor_failed events

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

* fix(devui): use event created_at for accurate workflow timeline timings

workflow-view.tsx synthesized _uiTimestamp using Math.max(baseTimestamp,
lastTimestamp + 1) with integer-second precision, forcing a minimum 1-second
gap between every sequential event. This made instant workflows appear to take
several seconds in the DevUI timeline.

The fix prefers event.created_at (a float Unix timestamp populated by the
backend mapper for all executor events) and only falls back to the synthetic
timestamp when created_at is absent. This matches the pattern already used in
devuiStore.ts:addDebugEvent.

Added a regression test in test_mapper.py verifying that the mapper attaches
created_at to all executor lifecycle events (invoked, completed, failed).

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

* fix(devui): address review feedback for issue #5545

- Read data.timestamp (ISO string) and response.created_at in addition
  to top-level created_at when deriving _uiTimestamp, so
  response.workflow_event.completed events get a real server timestamp
  instead of a synthesized one
- Change uniqueTimestamp tiebreaker: when a real server timestamp is
  available use Math.max(eventTimestamp, lastTimestamp) rather than
  lastTimestamp + 1, eliminating artificial 1-second gaps while still
  preserving monotonic ordering
- Apply the same fix in the HIL streaming path (second setOpenAIEvents
  call in workflow-view.tsx)
- Add assert event.created_at > 0 to regression test to guard against
  zero or negative timestamps
- Add test_custom_output_item_event_models_have_created_at_field model-
  level test so removing the field produces a clear named failure rather
  than a downstream ValidationError

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

* fix(#5545): guard NaN timestamps, fix fallback ID uniqueness, add regression tests

- workflow-view.tsx (×2): Wrap data.timestamp ISO→number conversion in a
  Number.isFinite() guard.  Python's datetime.now().isoformat() emits
  microseconds without a trailing 'Z' (e.g. '2024-01-15T12:34:56.123456'),
  which some JS engines cannot parse, returning NaN.  NaN !== undefined is
  true so the eventTimestamp !== undefined guard did not catch it, poisoning
  _uiTimestamp and resetting the monotonic ordering seed (NaN || 0 → 0).

- execution-timeline.tsx: Replace uiTimestamp in the fallback syntheticItemId
  with the per-executor runNumber counter.  Two runs of the same executor
  within the same second previously received identical _uiTimestamp values
  and therefore identical syntheticItemIds, causing their output buckets,
  state, and run entries to collide (execution-timeline.tsx:360–408).

- Add missing test_workflow_timings_bug.py source file (only a stale .pyc
  existed).  Three regression tests:
    · test_custom_event_models_lack_created_at_field – model field guard
    · test_workflow_executor_events_lack_created_at – mapper populates created_at
    · test_rapid_workflow_events_have_no_top_level_timestamps – confirms
      data.timestamp format that requires the frontend NaN guard

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

* Address review feedback for #5545: Python: [Bug]: Workflow timings in DevUI are incorrect

* devui: move timing regression tests into test_mapper.py, remove dedicated bug file

- Delete test_workflow_timings_bug.py; tests belong in existing module files
- The two tests already present in test_mapper.py (test_executor_events_carry_created_at_timestamp
  and test_custom_output_item_event_models_have_created_at_field) cover the same ground as the
  first two tests in the deleted file
- Add test_executor_completed_maps_to_output_item_done_event to test_mapper.py, replacing the
  third test from the deleted file with a generic, issue-agnostic name and docstring

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

* Address review feedback for #5545: review comment fixes

---------

Co-authored-by: Copilot <copilot@github.com>
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
27f926609f · 2026-05-05 05:59:08 +00:00
History
..