Skip to content

Commit 3257cd0

Browse files
committed
fix(server): order AzDO synthetic steps and skip the job timeline record
Two defects on the timeline path, both instances of fixing only the path I was looking at. execution_key fell back to u32::MAX whenever runner_number was absent. TimelineRecord carries no ordinal, so every synthetic step reported over AzDO sorted after all declared steps — Set up job last, which is the exact defect the ordering commit claims to prevent. The key now has three tiers: the runner's reported number, then observed start time, then the declared manifest position for steps that have not run. The reconciliation loop also accepted the job's own record. Its id is a UUID while job_id.0 is the workflow job key, so the existing guard never matched and the job appeared as an extra step named after itself, both in run projections and in the persisted rows. Only Task records are steps. Reported on #212 by Cubic (ordering, P2 blocker) and CodeRabbit (job record).
1 parent a2677fd commit 3257cd0

3 files changed

Lines changed: 112 additions & 10 deletions

File tree

‎crates/preloop-runner-server/src/lib_tests.rs‎

Lines changed: 77 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2843,6 +2843,83 @@ async fn log_run_logs_unknown_job_is_404_not_whole_run() {
28432843
);
28442844
}
28452845

2846+
/// The AzDO timeline path orders synthetic steps and ignores the job record.
2847+
///
2848+
/// `TimelineRecord` carries no ordinal, so a synthetic step reported this way
2849+
/// has no `runner_number` and must be ordered by when it started — otherwise
2850+
/// `Set up job` sorts after every declared step. The PATCH also carries the
2851+
/// job's own record, whose UUID never equals the workflow job key, so it was
2852+
/// reconciled in as an extra step named after the job.
2853+
#[tokio::test]
2854+
async fn timeline_path_orders_synthetic_steps_and_skips_the_job_record() {
2855+
let temp = tempfile::tempdir().unwrap();
2856+
let state = AppState::new(temp.path().to_path_buf()).await.unwrap();
2857+
let app = app(state.clone(), CancellationToken::new());
2858+
let (run_id, _) = three_step_run_for_log_filters(&app, &state).await;
2859+
let ids = workflow_step_ids(&state, run_id, "build").await;
2860+
let (plan_id, timeline_id) = {
2861+
let inner = state.inner.lock().await;
2862+
let request = inner
2863+
.job_requests
2864+
.values()
2865+
.find(|request| request.run_id == run_id)
2866+
.expect("dispatched request");
2867+
(request.plan_id.clone(), request.timeline_id.to_string())
2868+
};
2869+
2870+
// Setup started before the declared steps, and the job record is sent
2871+
// alongside them exactly as the official runner does.
2872+
let setup_id = uuid::Uuid::new_v4().to_string();
2873+
let record = |id: &str, kind: &str, name: &str, start: &str| {
2874+
json!({
2875+
"id": id,
2876+
"type": kind,
2877+
"name": name,
2878+
"displayName": name,
2879+
"state": "completed",
2880+
"result": "succeeded",
2881+
"startTime": start,
2882+
})
2883+
};
2884+
let response = request_json(
2885+
&app,
2886+
Method::PATCH,
2887+
&format!("/_apis/v1/Timeline/scope/actions/{plan_id}/{timeline_id}"),
2888+
json!({"count": 5, "value": [
2889+
record(&uuid::Uuid::new_v4().to_string(), "Job", "build", "2026-01-01T00:00:00Z"),
2890+
record(&ids[0], "Task", "Run echo one", "2026-01-01T00:00:02Z"),
2891+
record(&ids[1], "Task", "Run echo two", "2026-01-01T00:00:03Z"),
2892+
record(&ids[2], "Task", "Run echo three", "2026-01-01T00:00:04Z"),
2893+
record(&setup_id, "Task", "Set up job", "2026-01-01T00:00:01Z"),
2894+
]}),
2895+
)
2896+
.await;
2897+
assert_eq!(response["count"], 5);
2898+
2899+
let run = get_run_json(&app, &run_id.to_string()).await;
2900+
let names: Vec<&str> = run["jobs_list"]
2901+
.as_array()
2902+
.unwrap()
2903+
.iter()
2904+
.find(|detail| detail["job_id"] == "build")
2905+
.expect("build detail")["steps"]
2906+
.as_array()
2907+
.unwrap()
2908+
.iter()
2909+
.map(|step| step["name"].as_str().unwrap_or_default())
2910+
.collect();
2911+
assert_eq!(
2912+
names,
2913+
vec![
2914+
"Set up job",
2915+
"Run echo one",
2916+
"Run echo two",
2917+
"Run echo three"
2918+
],
2919+
"synthetic setup must lead, and the job record must not become a step"
2920+
);
2921+
}
2922+
28462923
/// Expansion does not leave the placeholder's manifest behind.
28472924
///
28482925
/// A deferred-matrix node is dispatched as a placeholder, gets a manifest

‎crates/preloop-runner-server/src/models.rs‎

Lines changed: 26 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -145,17 +145,33 @@ impl StepRecord {
145145

146146
/// Sort key placing a step in execution order.
147147
///
148-
/// `runner_number` is the runner's own 1-based timeline position and counts
149-
/// every step it ran, so it is the truth once reported. Until then a
150-
/// declared step falls back to its manifest position, biased past any
151-
/// reported number so freshly seeded steps trail what has actually run.
152-
/// A step id is a v4 UUID and sorts randomly, so it is only the final
148+
/// Three tiers, because the two reporting paths carry different evidence:
149+
///
150+
/// 1. `runner_number` — the runner's own 1-based timeline position, which
151+
/// counts every step it ran. The broker path reports it, and it is the
152+
/// truth once present.
153+
/// 2. `started_at` — when the server first saw the step run. The AzDO
154+
/// timeline path carries no ordinal (`TimelineRecord` has no `order`
155+
/// field), so a synthetic step there has no number; without this tier
156+
/// `Set up job` sorted after every declared step on that path, which is
157+
/// the defect this ordering exists to prevent.
158+
/// 3. `workflow_index` — a declared step that has not run yet, ordered as
159+
/// the workflow declares and placed after everything that has run.
160+
///
161+
/// A step id is a v4 UUID and sorts randomly, so it is only ever the final
153162
/// tie-break for determinism.
154-
fn execution_key(&self) -> (u32, usize, &str) {
155-
match self.runner_number {
156-
Some(number) => (number, 0, self.id.as_str()),
157-
None => (
158-
u32::MAX,
163+
fn execution_key(&self) -> (u8, i64, usize, &str) {
164+
match (self.runner_number, self.started_at) {
165+
(Some(number), _) => (0, i64::from(number), 0, self.id.as_str()),
166+
(None, Some(started_at)) => (
167+
1,
168+
started_at.timestamp_micros(),
169+
self.workflow_index.unwrap_or(usize::MAX),
170+
self.id.as_str(),
171+
),
172+
(None, None) => (
173+
2,
174+
0,
159175
self.workflow_index.unwrap_or(usize::MAX),
160176
self.id.as_str(),
161177
),

‎crates/preloop-runner-server/src/timeline_logs.rs‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -156,6 +156,15 @@ pub(crate) async fn patch_timeline_records(
156156
let Some(name) = &record.display_name else {
157157
continue;
158158
};
159+
// A PATCH carries the job's own record alongside its
160+
// steps. Its id is a UUID and `job_id.0` is the workflow
161+
// job key, so the id comparison below never matched it and
162+
// the job was reconciled in as a synthetic step — showing
163+
// up in run projections as an extra step named after the
164+
// job, and persisted there. Only task records are steps.
165+
if !matches!(record.record_type, Some(azdo::TimelineRecordType::Task)) {
166+
continue;
167+
}
159168
if record.id.to_string() == job_id.0 {
160169
continue;
161170
}

0 commit comments

Comments
 (0)