fix(tracing): only a run that provably finished later holds the record

My previous commit compared `finished_at` and fell back to `recorded_at`,
which broke two existing tests on CI: two records written in the same
millisecond with no completion time compared equal, so the second write was
dropped and the older run stayed. Locally the two writes happened to land in
different milliseconds, so the suite passed — a timing-dependent bug, not a
CI quirk.

The rule is now narrow: a write stands unless the record already there is a
DIFFERENT run with a later `finished_at`. No completion time on either side,
the same run recorded again, or a tie to the millisecond all leave the write
to stand, so "the last run recorded" stays what a reader gets. The case the
rule exists for is unchanged: the older-finished writer arriving last does
not replace the newer one.

485 passed in lib/crewai/tests/telemetry (test_last_run run five times for
timing); ruff and mypy clean.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Joao Moura
2026-09-20 21:06:26 -07:00
parent 0f14e159cd
commit ceb4cd7301
2 changed files with 22 additions and 17 deletions

View File

@@ -70,9 +70,9 @@ def record_last_run(
or the write failed. Never raises — a run is never failed by this.
"Last" means the run that FINISHED last: a record already there for a run
that finished later — or in the same millisecond — is kept, so two crews
finishing together in one project leave the newer one whichever writer
gets to the file last."""
with a later `finished_at` is kept, so two crews finishing together in one
project leave the later-finished one whichever writer gets to the file
last. With no completion time to compare, the write stands."""
if not recording_enabled():
return None
record: dict[str, Any] = {
@@ -95,7 +95,7 @@ def record_last_run(
try:
with os.fdopen(descriptor, "w", encoding="utf-8") as handle:
handle.write(json.dumps(record, indent=2) + "\n")
if _newer_than(record, read_last_run(path.parent.parent)):
if _keep(record, read_last_run(path.parent.parent)):
os.replace(temporary, path)
else:
logger.debug(
@@ -116,19 +116,20 @@ def record_last_run(
return path
def _newer_than(record: dict[str, Any], existing: dict[str, Any] | None) -> bool:
"""Is RECORD the later-finished run? A missing or unreadable existing record,
or one without a comparable time, never wins over the run just finished; a
tie (the same millisecond) keeps what is there the times are stored to
the millisecond, and no finer order is worth a field in the file."""
def _keep(record: dict[str, Any], existing: dict[str, Any] | None) -> bool:
"""Does RECORD replace EXISTING? Only a record we can PROVE finished later
holds the file: a different run with a `finished_at` after ours. Everything
else — no record there, the same run recorded again, a missing completion
time on either side, a tie to the millisecond — leaves the write to stand,
so the last run recorded is the one a reader gets."""
if not existing or existing.get("execution_id") == record["execution_id"]:
return True
ours = record["finished_at"] or record["recorded_at"]
theirs = existing.get("finished_at") or existing.get("recorded_at")
if not isinstance(theirs, str) or not isinstance(ours, str):
return True
# Both ISO 8601 in UTC at the same precision: text order is time order.
return ours > theirs
ours, theirs = record["finished_at"], existing.get("finished_at")
if not isinstance(ours, str) or not isinstance(theirs, str):
return True # nothing to order by: the write stands
# Both ISO 8601 in UTC at the same precision, so text order is time order;
# a tie means two runs finished in the same millisecond and either is a fair "last run".
return ours >= theirs
def read_last_run(directory: Path | None = None) -> dict[str, Any] | None:

View File

@@ -110,9 +110,13 @@ def test_the_run_that_finished_last_stays_recorded_whichever_writer_comes_last(p
last_run.record_last_run(execution_id="newest", tier="ephemeral", started_at_ns=base, finished_at_ns=base + 40 * second, amp_base_url=None)
assert last_run.read_last_run(project)["execution_id"] == "newest"
# A tie to the millisecond keeps what is there: the file orders runs no finer than it stores them.
# A tie to the millisecond: either run is a fair "last run", so the write stands.
last_run.record_last_run(execution_id="same-instant", tier="ephemeral", started_at_ns=base, finished_at_ns=base + 40 * second + 400_000, amp_base_url=None)
assert last_run.read_last_run(project)["execution_id"] == "newest"
assert last_run.read_last_run(project)["execution_id"] == "same-instant"
# An OLDER run still loses that tie-free comparison, however late its writer arrives.
last_run.record_last_run(execution_id="stale", tier="ephemeral", started_at_ns=base, finished_at_ns=base + 5 * second, amp_base_url=None)
assert last_run.read_last_run(project)["execution_id"] == "same-instant"
# A record without a comparable time never blocks the run just finished.
(project / ".crewai" / "last_run.json").write_text(json.dumps({"execution_id": "legacy"}), encoding="utf-8")