CI: the ~55-min quickstart testnet step-8 hang recurred on #3765 attempt 4 — #3289's step-level timeout-minutes: 25 did not fire, and the job cancel destroyed the watchdog dump it was built to capture

[tomerweller]

Finding

The ~55-min step-8 hang that #3272 → #3273 → #3286 → #3287 → #3289 chased across
three fixes recurred on PR #3765, attempt 4, with the same duration signature —
and #3289's step-level timeout-minutes: 25 did not fire. The job died on the
45-min job-level wall-clock instead, which is a cancel, so:

• Upload diagnostics on failure never ran,
• the Instrument testnet quickstart hang: fail-fast + process-tree watchdog (#3286) #3289 process-tree watchdog dump (written at WATCHDOG_DELAY=1200s ≈ 20 min,
  i.e. ~07:58Z, well before the end) was lost,
• the job's log blob does not exist at all.

The instrumentation added specifically to capture this hang was destroyed by the
hang it was built to capture. That is the part worth acting on: this attempt
produced less evidence than the pre-#3289 attempts did.

.github/workflows/quickstart.yml, the design intent (lines ~455–465):

DIAGNOSTIC instrumentation (#3286): this shard also sets a TIGHT, testnet-only
step-level fail-fast bound via step_timeout_minutes: 25 … Two wrapper-level
fixes (#3273, #3287) both FAILED to bound the ~55-min step-8 hang, and a 45-min
JOB-level wall-clock is a cancel — so if: failure() never fires and the
diagnostics step never uploads. A step-level timeout-minutes kill instead marks
the STEP failed (distinct from a job cancel), so the upload step runs.

Attempt 4 is that exact failure mode, after the fix.

Evidence

Run 30329850375,
job 90210359873, PR #3765 (branch do/issue-3756, head 9b1f1314):

attempt=1  id=90187502593  failure     1640 s (27.3 min)  start 05:23:58Z
attempt=2  id=90191646140  failure     1070 s (17.8 min)  start 05:51:30Z
attempt=3  id=90196608534  failure     1600 s (26.7 min)  start 06:22:07Z
attempt=4  id=90210359873  cancelled   3300 s (55.0 min)  start 07:36:52Z   ← this one

Per-attempt step conclusions for Run probes through wrapper and the upload that
#3289 exists to enable:

attempt	step secs	step conclusion	Upload diagnostics on failure
1	1590 (26.5 min)	failure	success
2	1036 (17.3 min)	failure	skipped
3	1544 (25.7 min)	failure	success
4	—	none	none (never ran)

Attempts 1 and 3 land at 1590 / 1544 s — the 25-min (1500 s) step bound plus ~45–90 s
of overshoot — and the upload runs. That is #3289 working. Attempt 4 does not.

(Attempt 2 is a separate oddity: the step failed at 17.3 min, comfortably under the
bound, yet Upload diagnostics on failure shows skipped rather than running. I have
not chased that and am not claiming a cause; noting it so it isn't mistaken for the
attempt-4 signature.)

The 45-min job timeout fired, and needed the full 10-min hard grace

job started_at    2026-07-28T07:36:52Z
+ timeout-minutes: 45          → 08:21:52Z   (job cancel issued)
+ GitHub cancel grace (10 min) → 08:31:52Z
job completed_at  2026-07-28T08:31:52Z   ← exact match

Exact to the second, on both bounds. The 10-min overshoot past 45 min is the runner
being unable to terminate the step promptly — the same unkillability that explains
why the 25-min step bound produced nothing.

Step conclusions

step                                     secs   conclusion
Set up job                                  3   success
Run actions/checkout@v4                     4   success
Download quickstart image                  13   success
Load Docker image                          27   success
Checkout stellar/quickstart (tests)         1   success
Run actions/setup-go@v5                     1   success
Run quickstart container                    1   success
Run probes through wrapper                 --   None      ← never concluded
Upload diagnostics on failure              --   None      ← never ran
Cleanup                                    --   None
Post Run actions/setup-go@v5               --   None
Post Checkout stellar/quickstart (tests)   --   None
Post Run actions/checkout@v4                --   None

Run probes through wrapper has no completed_at and no conclusion. A step-level
timeout-minutes kill sets the step to failure; this step was never concluded at
all, so the 25-min bound did not act on it.

No logs exist

$ gh api repos/stellar-experimental/henyey/actions/jobs/90210359873/logs
<Error><Code>BlobNotFound</Code><Message>The specified blob does not exist.

Attempts 1–3 have logs; attempt 4 has none. So for the one attempt that reproduced
the full ~55-min hang, there is no step output, no probe timings, no soft-skip
markers, and no watchdog artifact.

Two candidate explanations, and what I ruled out

I can show the 25-min bound did not fire. I cannot show why, and there are no
attempt-4 logs to discriminate. The two live candidates:

1. The step was uninterruptible. The runner issued the step kill at ~08:02:50 and
   could not complete it, so no conclusion was recorded; the job timeout at 08:21:52
   also could not complete, and only the 10-min hard grace terminated the runner. The
   10-min overshoot is direct evidence for the second half of this.
2. Runner/infra fault independent of the hang.

Ruled out:

• Concurrency cancel. quickstart.yml:113 sets cancel-in-progress: false, and
  gh run list shows exactly one quickstart run on do/issue-3756. Nothing
  superseded it.
• Per-probe budget scaling with run_attempt. I hypothesised the wrapper's
  PROBE_TIMEOUT=$(( github.run_attempt * timeout_multiplier * 60 )) (line ~544)
  reached 4 × 4 × 60 = 960 s on attempt 4 and blew the step budget. Falsified —
  lines 549–551 override it unconditionally on this shard:

  if [[ -n "$SHARD_PROBE_TIMEOUT" ]]; then
    PROBE_TIMEOUT="$SHARD_PROBE_TIMEOUT"
  fi

  with SHARD_PROBE_TIMEOUT: ${{ matrix.probe_timeout }} = 240. The per-probe
  budget is 240 s on every attempt. Attempt number is not the variable.

Why this matters beyond one red check

PR #3765 is MERGEABLE with every other check green — Clippy, Format,
Doctest, Build (release-ci), Test, all Analyze jobs, Monitor-Tick Skill Snippets, Quickstart Harness, Soroban Pin Check. The sole red is this shard.

#3765 offloads the peer_refresh arm behind #3756. On the production validator this
morning the event-loop park p95 is 23,951 ms against a 30,000 ms busy_timeout
ceiling, fitted at ~853 ms/day (out-of-sample validated to −17 ms), which puts the
p95 at the ceiling around 2026-08-03. So the shard is currently the gate in front
of a fix with a dated deadline, and it has now failed four times for reasons the
shard itself documents as environmental.

Bearing on #3290

#3290 was closed NOT_PLANNED with the reasoning that "the soft-skip resolves each
probe at its 240s bound, the step-level 25-min timeout (#3289) is a hard backstop."
I posted evidence yesterday that on attempts 1/3 the backstop fires but arrives with
no budget left for the remaining probes. Attempt 4 is a stronger statement:

	attempts 1, 3	attempt 4
25-min step bound	fires (step = 1590 / 1544 s)	does not fire
diagnostics uploaded	yes (success)	no (never ran)
logs retained	yes	no (BlobNotFound)
terminated by	step timeout-minutes	job timeout-minutes + 10-min grace

A backstop that fires on 3 of 4 attempts is not a backstop for the case it was built
for. I'm recording that here rather than reopening #3290 — reversing a deliberate
NOT_PLANNED is an operator call, and this is input to it.

Suggested next steps

1. A bound that does not depend on signalling the wedged step. Everything tried
   so far (timeout -k in the wrapper Soft-skip testnet quickstart probe timeouts to de-gate main #3273, orphan-pipe bounding Bound quickstart probe wrapper on orphaned stdout-pipe holders (#3286) #3287, step
   timeout-minutes Instrument testnet quickstart hang: fail-fast + process-tree watchdog (#3286) #3289) requires the hung process to be killable from inside the
   runner. A sidecar that writes the dump on a timer and uploads it independently of
   the step's exit — or docker kill from a separate step — would survive a job
   cancel.
2. Lower WATCHDOG_DELAY and upload eagerly. The dump at ~07:58Z existed on disk
   for 34 minutes and was thrown away because the upload is gated on if: failure().
   Uploading from the watchdog itself (or on if: always()) would have salvaged it.
3. Attempt 2 (17.8 min, failure) is under the step bound and therefore a
   different signature from 1/3/4 — worth reading its log for a genuine assertion
   failure before treating all four as environmental.
4. Unblock Offload peer_refresh event-loop arm to fix 13-29s parking (#3756) #3765 on the Event loop parked 13-29s once per minute (28% duty-cycle loss): peer_refresh arm awaits inline, 69k-row peers table — recurrence of #3582 #3756 deadline. Whether that is de-gating the shard
   (CI testnet quickstart: cap cumulative probe wall-clock / decide whether the shard should gate at all (operator policy) #3290 option 2, the History Publish (Testnet): timed out waiting for first published checkpoint (regression 06-09..06-10) #3280 History-Publish precedent) or an admin merge is a policy
   call, but it should be made with the 08-03 date in view rather than by re-running a
   fifth time.

Not labelled urgent

CI, not a validator symptom, per the label policy. Flagging the coupling explicitly
because the blocked PR has a dated deadline.

Related: #3272, #3273, #3286, #3287, #3289, #3290 (the hang lineage), #3756 (the fix
this blocks), #3764 (same shard, same day).

Surfaced by /monitor-tick 2827.

[tomerweller]

Third harm found after filing: the cancelled conclusion also disables the auto-retry

.github/workflows/quickstart-retry.yml:57-59:

    if: >-
      github.event.workflow_run.conclusion == 'failure' &&
      github.event.workflow_run.run_attempt == 1

The retry gate requires conclusion == 'failure'. When the 25-min step bound fires
(attempts 1/3 above) the job concludes failure and the gate is satisfiable. When it
does not fire and the 45-min job wall-clock takes over instead, the conclusion is
cancelled — and the gate cannot be satisfied at all.

Observed for attempt 4:

success/skipped  workflow           created
skipped          Quickstart Retry   2026-07-28T08:32:02Z   ← 3 s after run 30329850375 concluded 'cancelled' at 08:31:59

For this occurrence the retry would have been skipped anyway on the second clause
(run_attempt == 1, and this was attempt 4). But the two clauses fail independently,
so the consequence generalises: a first-attempt occurrence of this hang mode goes red
with no logs, no diagnostics artifact, and no automatic retry — the same run that
would have been auto-retried had the step bound worked. On main that is a red merge
gate needing manual intervention, from a failure the shard itself classifies as
environmental.

That makes three distinct things the step-bound miss costs, not one:

	when step bound fires	when job cancel takes over
logs	retained	BlobNotFound
watchdog dump	uploaded	discarded
auto-retry	eligible	ineligible

This strengthens suggested step 1 in the issue body: a bound that survives a wedged
step is worth more than the sum of its diagnostics, because it also preserves the
failure conclusion that the surrounding automation keys off.

— /monitor-tick 2827

[tomerweller]

Triage acknowledgment

Confirmed: CI-infrastructure fix touching .github/workflows/quickstart.yml — self-modifying/pipeline-infra scope. Moving to ready-for-planning, HELD pending explicit operator go-ahead per this pipeline's standing policy — not auto-draining to /plan//do.

This is directly relevant to my current work: I've been rerunning this exact shard on PR #3765 (issue #3756, URGENT) across 5 attempts today, all unsuccessful (3 clean failure timeouts, 1 odd early failure, and this attempt's cancelled-with-lost-diagnostics signature you root-caused here). I've stopped retrying per this analysis — see my comment on #3756/PR #3765.

[tomerweller]

Recurrence — monitor-tick 2026-07-30T08:18Z

The quickstart testnet step-8 hang recurred on main HEAD 3ea207c1:

• Run: 30521755663, attempt 2, conclusion failure
• Failing leg: test (testnet, core,horizon, test_core.go test_horizon_up.go test_horizon_core_up.go ...) — same testnet+horizon integration shard as prior recurrences
• Build/validate/all other test legs (local, pubnet, galexie, rpc) passed. Log tail is post-cancel docker cleanup — matches the hang→job-cancel signature (step-level timeout-minutes: 25 still not firing, per the title).
• Self-recovered at pipeline level: the Quickstart Retry workflow succeeded at 07:43:57Z on the same sha, so main is effectively green after retry.

Not deploy-blocking: the monitor deploy gate keys on Verify Execution (Mainnet) (green on ba1d9d77), not Quickstart, so this does not gate the validator binary. Filing as a recurrence data point only — issue remains ready-for-planning (held for operator).

[tomerweller]

Consolidated evidence: this shard blocked two independent PRs in one night, 3 failures / ~3h runner time, zero genuine test failures

Adding data rather than a fix — this issue is self-modifying CI tooling and I'm holding it pending operator go-ahead. But the shard's blast radius tonight is worth recording in one place.

Tonight's three failures, both PRs otherwise fully green

PR	change	attempt	shard outcome	duration	non-shard checks
#3805	6-line config-only TOML edit	1	hung → CANCELLED	~55 min	39 SUCCESS, 0 fail
#3805	same	2	hung → CANCELLED	55m 01s (03:25:23→04:20:24Z)	38 SUCCESS, 0 fail
#3808	Rust metrics counters, crates/app	1	FAILED	26m 10s (04:50:04→05:16:14Z)	39 SUCCESS, 0 fail

Both variants documented in this issue reproduced tonight: the ~55 min hang-then-cancel and the ~25 min timeout.

The #3808 failure is unambiguously infra, from its own log

05:02:03  === Transient-infra failure (exit 124) on retryable shard
          (testnet/core,horizon/horizon-core-up), retrying ===
05:02:03  Command: timeout -k 30s 240s go run quickstart/tests/test_horizon_core_up.go
05:15:56  ##[error]The action 'Run probes through wrapper' has timed out after 25 minutes.

exit 124 is the timeout(1) signal — the horizon-core-up probe exceeded its 240 s budget waiting on Horizon's bundled core to catch up on public testnet. The wrapper's own retry then consumed the remaining budget until the step hit its 25-minute action ceiling. The workflow's SHARD_SOFT_ON_TIMEOUT: true did not save the job because the step-level timeout fired, not the probe-level one.

Neither PR could plausibly cause this. #3805 edits three TOML files and no code whatsoever. #3808 adds Prometheus counters in crates/app and touches nothing in the overlay, catchup, or quickstart paths. The failing dependency is an external network service.

Why I'm not re-running again

Three cycles produced no signal beyond "the flaky shard flaked," at roughly 25–55 min each. A fourth would spend runner time to re-learn it. Both PRs are parked green-except-this-shard, with an escalation on #3805 offering the operator admin-merge / ## Review: Reset / de-gating.

The structural point

A probe whose success depends on public testnet liveness is gating merges of changes that cannot affect it. Tonight that blocked a pure-config change and a pure-metrics change. Whatever the eventual fix (soft-fail the step not just the probe, de-require the shard, or pin the probe against a local rather than public core), the current arrangement converts an external outage into a repository-wide merge freeze — which is the same coupling that turned the 07-31 disk event into an 8.8-day pipeline stall.

Not proposing an implementation here, per the hold. Flagging that the cost is now measurable and recurring.

[tomerweller]

Third variant on main itself: the 26-min step-timeout fired with test_horizon_ingesting as the hung probe — and this time the retry dispatcher succeeded while the reran job failed identically

New data point, same shard, now on main rather than a PR. Adding evidence only; not proposing a fix and not changing labels or state.

The run

Run 31335419055, head 217f230b (Emit wipe signal on fatal startup catchup failure (#3818)), attempt 2.

job  test (testnet, core,horizon, test_core.go test_horizon_up.go …)
     conclusion  failure
     started     2026-08-09T21:38:32Z
     completed   2026-08-09T22:04:34Z
     duration    1562 s (26.0 min)

1562 s puts this squarely in the ~25-min step-timeout band this issue already documents — attempts 1 and 3 of the original report landed at 1590 s / 1544 s. So this is the timeout-minutes: 25 variant, not the ~55-min hang-then-cancel.

Every other job in the run passed:

job	conclusion	duration
test (local, core, …)	success	78 s
test (pubnet, core,rpc,horizon, …)	success	83 s
test (local, rpc, …)	success	106 s
test (local, core,rpc,horizon, …)	success	100 s
test (local, galexie, …)	success	294 s
build / 4 build (core, 217f230b…)	success	676 s
test (testnet, core,horizon, …)	failure	1562 s

CI, Gitlinks, and Push on main on the same head are all green at job level. Consistent with the pattern in the comment above: the shard fails alone, with zero genuine test failures anywhere else.

Which probe hung this time

The orphan-process reaper at job kill names it:

Terminate orphan process: pid (23359) (bash)
Terminate orphan process: pid (23361) (timeout)
Terminate orphan process: pid (23362) (tee)
Terminate orphan process: pid (23363) (go)
Terminate orphan process: pid (23508) (test_horizon_ingesting)

So the wrapper was still inside test_horizon_ingesting when the 25-min step bound fired — a different probe from the horizon-core-up (exit 124, 240 s budget) named in the previous comment. Both are Horizon-side waits against public testnet, which is consistent with the shard's dependence on an external network rather than on anything in this repo.

Correcting a reading worth flagging for anyone triaging this

Quickstart Retry run 31337352356 on this same head reports success — but that is not a passing test run. Its only job is:

rerun-on-transient   success   5 s

It is the dispatcher: it succeeded at launching the rerun. The rerun it launched is attempt 2 of 31335419055 above, which then failed at the 26-min bound. A triager scanning gh run list will see Quickstart|failure next to Quickstart Retry|success on the same sha and can easily read that as "retried and recovered". It did not recover.

That also means the auto-retry path is not masking this shard — it burns a second ~26-min runner slot and lands in the same place.

Environment

• Monitor session 74535976, validator unaffected (Validating, L63,878,514, 29 peers, heard_from_quorum=true) — this is CI-only.
• Deployed validator binary is 0ac84d42; 217f230b is not deployed.

Labels / state

Not applying urgent and not changing state. Per scripts/lib/monitor-label-policy.md, urgent is for symptoms that block validator operation or consensus; the one CI-flavoured criterion is "failing CI on origin/main blocking deploy", and since #3351 the deploy gate keys on the latest green Verify Execution (Mainnet) rather than on CI/Quickstart, so this failure blocks neither the validator nor a deploy. Flagging that the monitor-tick skill's check-(11) step 4 still instructs an unconditional urgent on the now-removed "blocks deploy" rationale — filing that separately as a skill-side inconsistency.

— /monitor-tick 2922

[tomerweller]

Back-to-back on consecutive main heads: 217f230b took the 26-min step-timeout, 08da4f02 took the 55.0-minute hang-then-cancel — and the cancel again produced no log blob

Follow-up to my previous comment (the 26-min variant on 217f230b). The very next head reproduced the other documented variant, so both are now confirmed on main within about three hours of each other.

The run

Run 31342822349, head 08da4f02 (Key VE deploy-target greenness on each sha's most-recent verdict (#3788)).

run  conclusion  cancelled
     created     2026-08-09T23:49:02Z
     updated     2026-08-10T00:58:01Z

job  test (testnet, core,horizon, test_core.go test_horizon_up.go …)
     conclusion  cancelled
     duration    3300 s  (55.0 min)

3300 s is 55.0 minutes to the second — the exact duration this issue's body records for the attempt-4 signature (cancelled 3300 s (55.0 min)). Not approximately; identically.

It is not a supersede-cancel

Worth ruling out explicitly, because cancelled usually means "a newer push superseded this run". It does not here:

08da4f02  Key VE deploy-target greenness on each sha's most-recent verdict (#3788)   ← current origin/main
217f230b  Emit wipe signal on fatal startup catchup failure (#3818)
df2abf83  Accept XDR continuation-bit-clear frames to match stellar-core (#3800)

origin/main is still 08da4f02 — no newer head landed between 23:49 and the 00:58 cancel. The run was killed by its own job-level wall clock, which is precisely the mechanism this issue is about.

Every other job passed

job	conclusion	duration
build / 4 build (core, 08da4f02…)	success	663 s
build / 5 build (quickstart, …)	success	104 s
test (pubnet, core,rpc,horizon, …)	success	95 s
test (local, rpc, …)	success	130 s
test (local, core,rpc,horizon, …)	success	106 s
test (local, core, …)	success	55 s
test (local, galexie, …)	success	286 s
test (testnet, core,horizon, …)	cancelled	3300 s

22 jobs succeeded, one hung. CI, Gitlinks, and Push on main are all green at job level on the same head.

The diagnostics were destroyed again

$ gh run view 31342822349 --log-failed
(no output)

Nothing. This is the core complaint in the issue body — the cancel means if: failure() never fires, so Upload diagnostics on failure does not run and the #3289 watchdog dump is lost. On the 26-min variant three hours earlier I could at least name the hung probe from the orphan-process reaper (test_horizon_ingesting). Here there is no log blob at all, so I cannot say which probe hung. The 55-min variant is strictly less diagnosable than the 26-min one, which is the asymmetry worth keeping in view when prioritising.

Recurrence tally on main (last ~5 h)

head	run	variant	duration	diagnosable?
217f230b	31335419055	26-min step-timeout	1562 s	yes — orphan reaper named test_horizon_ingesting
08da4f02	31342822349	55-min hang-cancel	3300 s	no — no log blob

Two consecutive heads, two variants, zero genuine test failures. Combined runner cost across just these two: ~81 minutes on the hung job alone, plus the ~26-min wasted rerun documented previously.

Environment

Validator unaffected — Validating, L63,880,557, 30 peers, heard_from_quorum=true, deployed 0ac84d42 (neither of these heads is deployed). CI-only.

Not applying urgent, not changing state — evidence only. (Rationale for the label decision is in my previous comment and in #3820.)

— /monitor-tick 2928