drivers/cargo: a test binary is run whole though t itself expects it to take 89 minutes under its 60-minute limit: every CI job of tilo's tilo-session::it has timed out since 05:04Z 11-14 #73

Open
opened 2026-11-14 10:39:03 +00:00 by xemmerling · 0 comments
Owner

Production, 2026-11-14, c6dca088 (and the two builds before it, 618f31ea and 67588367). Every CI job that runs tilo's tilo-session::it test binary has ended timed_out since 05:04Z: 13 of 13, each 67.6 to 77.2 minutes, about 4,100 to 4,280 CPU seconds. Three of people's jobs ended the same way. The front head runs each stand on one of these jobs, and a join whose owner timed out runs the binary again for another 70 minutes. After the 08:57Z promote four head runs finished in 85 minutes.

No test hangs. In five logs the "test that never ended" is a different one each time: the one running when the hour was over.

What I read

Fact Value Where
Tests of tilo-session::it (by the tables' times tilo folded about 120 integration-test binaries into it around 03:00Z) 689 t.test_samples
Sum of their measured medians 4,414 s same
Longest test, median test 380 s, 2.5 s same
Fixed-cost samples, newest first, ms 4425, 5968, 1236659, 1236701, 1231066, 904668, 894268, 905845, 15526 t.fixed_costs, last kept 05:19Z
Their median 904.7 s
What the fixed cost is nextest setup script lounge-siblings (tools/build-sibling-binaries.sh 'tilo-relay:tilo-relay=tilo-relay/agents'): 318 s, 907 s, 1,004 s in three logs job logs
Threads the cut is made for, and each job's width 1 job_history.width
The job's limit 3,600 s of its own time JobSpec::timeout_secs

Why it is run whole

shards::pack with these figures:

  • floor = 3 × fixed = 2,714 s (the rule that a shard's fixed cost is at most a quarter of its time, mine, 67ac8442)
  • target = max(longest 380 s, floor 2,714 s, spread 4,414 / 32 = 138 s) = 2,714 s
  • two bins: 2,714 s and 1,700 s; the second is under the floor and is merged into the first
  • one bin, so cut returns the whole binary

expected_ms for that one shard is 905 + 4,414 = 5,319 s. t asks for a job it expects to take 89 minutes under a limit of 60.

Why it stays so

record_test_facts keeps a fixed cost only from a passing job with a nextest summary. A job that times out leaves none, so the median stays at 905 s and the next cut is the same. Nothing but a pass of the whole binary can change it, and the whole binary cannot pass.

The missing rule

The cut does not know its job's limit. The quarter rule saves work; it must give way where it makes a shard that is expected past the limit. Proposed, in pack alone, nothing in booking or admission:

  • a shard's expected time (fixed cost and its tests' run on its threads) is at most half its job's limit, where its tests can be cut that fine
  • the floor is min(3 × fixed, limit / 2 - fixed), in the fit and in the merge
  • with today's figures: five shards of about 30 minutes each on one thread, instead of one that cannot end

I am having this built as a change to shards.rs and its caller, with tilo's figures as the test. Say so here if you want it done another way, for example by the threads the whole run is booked: at 8 threads the whole binary is expected in about 24 minutes.

tilo's side, not t's

  • The relay build inside every test job of this binary costs 5 to 17 minutes a shard at one thread.
  • Tests failing in most of the five logs: directory::a_workspace_joined_brings_the_chat_written_before_it (about 255 s), repl_door::a_repl_named_when_the_session_starts_is_admitted_without_asking, repl_door::the_person_admits_the_repl_on_the_sheet_and_it_works_as_them, search::the_sessions_own_actions_are_found_and_run_on_its_published_surface (about 122 s), and the lib test shell::tests::the_device_surface_file_is_what_the_session_publishes.

2026-11-14 11:15Z: landed

The rule is on main as 099a17b6 (cut takes the job's limit; floor = min(3 × fixed, limit/2 − fixed); a merge of small shards only within that). With the figures above it cuts five shards on one thread, the longest expected in 30.0 minutes. t's whole check set passed for it on testing three times, on 58b70474, 5e58a972 and 189786f6. Not on production yet.

A whole job already running at a promote is taken over as it stands (taking_left) and will still time out; only binaries asked after the promote get the new cut.

Production, 2026-11-14, c6dca088 (and the two builds before it, 618f31ea and 67588367). Every CI job that runs tilo's `tilo-session::it` test binary has ended `timed_out` since 05:04Z: 13 of 13, each 67.6 to 77.2 minutes, about 4,100 to 4,280 CPU seconds. Three of people's jobs ended the same way. The front head runs each stand on one of these jobs, and a join whose owner timed out runs the binary again for another 70 minutes. After the 08:57Z promote four head runs finished in 85 minutes. No test hangs. In five logs the "test that never ended" is a different one each time: the one running when the hour was over. ## What I read | Fact | Value | Where | |---|---|---| | Tests of `tilo-session::it` (by the tables' times tilo folded about 120 integration-test binaries into it around 03:00Z) | 689 | `t.test_samples` | | Sum of their measured medians | 4,414 s | same | | Longest test, median test | 380 s, 2.5 s | same | | Fixed-cost samples, newest first, ms | 4425, 5968, 1236659, 1236701, 1231066, 904668, 894268, 905845, 15526 | `t.fixed_costs`, last kept 05:19Z | | Their median | 904.7 s | | | What the fixed cost is | nextest setup script `lounge-siblings` (`tools/build-sibling-binaries.sh 'tilo-relay:tilo-relay=tilo-relay/agents'`): 318 s, 907 s, 1,004 s in three logs | job logs | | Threads the cut is made for, and each job's width | 1 | `job_history.width` | | The job's limit | 3,600 s of its own time | `JobSpec::timeout_secs` | ## Why it is run whole `shards::pack` with these figures: - floor = 3 × fixed = 2,714 s (the rule that a shard's fixed cost is at most a quarter of its time, mine, 67ac8442) - target = max(longest 380 s, floor 2,714 s, spread 4,414 / 32 = 138 s) = 2,714 s - two bins: 2,714 s and 1,700 s; the second is under the floor and is merged into the first - one bin, so `cut` returns the whole binary `expected_ms` for that one shard is 905 + 4,414 = 5,319 s. t asks for a job it expects to take 89 minutes under a limit of 60. ## Why it stays so `record_test_facts` keeps a fixed cost only from a passing job with a nextest summary. A job that times out leaves none, so the median stays at 905 s and the next cut is the same. Nothing but a pass of the whole binary can change it, and the whole binary cannot pass. ## The missing rule The cut does not know its job's limit. The quarter rule saves work; it must give way where it makes a shard that is expected past the limit. Proposed, in `pack` alone, nothing in booking or admission: - a shard's expected time (fixed cost and its tests' run on its threads) is at most half its job's limit, where its tests can be cut that fine - the floor is `min(3 × fixed, limit / 2 - fixed)`, in the fit and in the merge - with today's figures: five shards of about 30 minutes each on one thread, instead of one that cannot end I am having this built as a change to `shards.rs` and its caller, with tilo's figures as the test. Say so here if you want it done another way, for example by the threads the whole run is booked: at 8 threads the whole binary is expected in about 24 minutes. ## tilo's side, not t's - The relay build inside every test job of this binary costs 5 to 17 minutes a shard at one thread. - Tests failing in most of the five logs: `directory::a_workspace_joined_brings_the_chat_written_before_it` (about 255 s), `repl_door::a_repl_named_when_the_session_starts_is_admitted_without_asking`, `repl_door::the_person_admits_the_repl_on_the_sheet_and_it_works_as_them`, `search::the_sessions_own_actions_are_found_and_run_on_its_published_surface` (about 122 s), and the lib test `shell::tests::the_device_surface_file_is_what_the_session_publishes`. ## 2026-11-14 11:15Z: landed The rule is on main as 099a17b6 (`cut` takes the job's limit; floor = min(3 × fixed, limit/2 − fixed); a merge of small shards only within that). With the figures above it cuts five shards on one thread, the longest expected in 30.0 minutes. t's whole check set passed for it on testing three times, on 58b70474, 5e58a972 and 189786f6. Not on production yet. A whole job already running at a promote is taken over as it stands (`taking_left`) and will still time out; only binaries asked after the promote get the new cut.
Sign in to join this conversation.
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
tilo/t#73
No description provided.