diff --git a/docs/rust-server-port-checkpoints/2026-10-22-cleanup-finished-at.md b/docs/rust-server-port-checkpoints/2026-10-22-cleanup-finished-at.md new file mode 100644 index 000000000..3e7346910 --- /dev/null +++ b/docs/rust-server-port-checkpoints/2026-10-22-cleanup-finished-at.md @@ -0,0 +1,30 @@ +# October 22, cancellation cleanup finish time + +- **Found by.** The Shared Server fixtures workflow on main. Since the merge + of #561 it has failed in `codec-deadline-health` on every database, + `execution-and-codec`, `mysql-execution` and `postgres-storage`. These are + not required checks, so merges continued. Main run 39671560431 shows the + same assertion in each of them, `cleanup closes at persisted terminal + time`: + - expected `2026-10-21T23:12:52.433000Z`, the run's `closed_at`; + - actual `2026-10-21T23:12:52.433Z`, the `WorkflowCancelled` payload's + `cancellation_cleanup.finished_at`. +- **Cause.** Native wrote `finished_at` as a raw chrono time, which serde + prints with as few fractional digits as the value needs. Its + `cleanup_deadline_at` and `requested_at` beside it, and the run's + `closed_at`, use six digits. Published Workflow writes the cleanup's + `finished_at` as the run's `closed_at->toISOString()`, and + `CancellationCascadeView` treats a different string as a mismatch. +- **Source.** `finished_at` now uses the same six-digit form as the other + cancellation times. +- **Verification.** The cooperative cleanup integration test compared the two + values as parsed instants. It now also compares them as text. It fails + without the change (`…22.519Z` against `…22.519000Z`) and passes with it. + The SQLite cleanup, cancellation and cooperative tests pass (54). +- **Still open.** In the same run, `postgres-storage (postgres-17)` stopped + earlier, in the operator metrics `waiting_after_redispatch` stage. Its + health snapshot warned `durable_resume_paths`, but the metrics snapshot + taken just before it counted no run needing repair. The two are separate + requests, so the run's summary changed between them. That is a timing + difference in the fixture or a native summary refresh. It is diagnosed + separately once this assertion no longer hides it. diff --git a/rust/src/runtime/cooperative.rs b/rust/src/runtime/cooperative.rs index 52158880e..adbdfa476 100644 --- a/rust/src/runtime/cooperative.rs +++ b/rust/src/runtime/cooperative.rs @@ -558,7 +558,7 @@ where "workflow_instance_id":DB::string(run,"workflow_instance_id")?,"workflow_run_id":run_id,"failure_id":failure_id, "failure_category":"cancelled","closed_reason":"cancelled","exception_class":EXCEPTION,"message":message,"reason":reason, "cancellation_cleanup":{"request_id":request_id,"outcome":outcome,"cleanup_deadline_at":timestamp(deadline), - "delivery_history_event_id":delivery_id,"delivery_sequence":delivery_sequence,"finished_at":at}}); + "delivery_history_event_id":delivery_id,"delivery_sequence":delivery_sequence,"finished_at":timestamp(at)}}); Self::append( tx, &run_id, diff --git a/rust/tests/execution.rs b/rust/tests/execution.rs index 89fa3a9cd..0da1c4e39 100644 --- a/rust/tests/execution.rs +++ b/rust/tests/execution.rs @@ -3848,6 +3848,9 @@ async fn cooperative_delivery_cleanup_and_original_deadline_survive_fresh_runtim assert_eq!(described.1["output_envelope"], Value::Null); let instant = |value: &Value| chrono::DateTime::parse_from_rfc3339(value.as_str().unwrap()).unwrap(); assert_eq!(instant(&cleanup["finished_at"]), instant(&described.1["closed_at"])); + // PHP writes the cleanup's `finished_at` as the run's `closed_at` + // string (`CancellationCascadeView`), so the two are equal as text. + assert_eq!(cleanup["finished_at"], described.1["closed_at"]); if !cleanup_activity.is_null() { let observed = request_protocol(&app,"POST", &format!("/api/worker/activity-tasks/{}/status",cleanup_activity["task_id"].as_str().unwrap()),