Skip to content

fix(ci): A network port for each half, and say what the load test did - #2839

Merged
krlmlr merged 2 commits into
claude/preflight-shared-deps-8mj8p1from
claude/revdep2-parallel-port-8mj8p1
Aug 16, 2026
Merged

fix(ci): A network port for each half, and say what the load test did#2839
krlmlr merged 2 commits into
claude/preflight-shared-deps-8mj8p1from
claude/revdep2-parallel-port-8mj8p1

Conversation

@krlmlr

@krlmlr krlmlr commented Aug 15, 2026

Copy link
Copy Markdown
Contributor

Prepared with Claude Code. Stacked on #2834, on top of the merged #2838.

Why the two halves collided on the same port

cia and TDApplied were reported newly_broken in run 31893156685 with nothing wrong with them:

Error in serverSocket(port = port) :
  creation of server socket failed: port 11477 cannot be opened
Calls: SampleChains -> <Anonymous> -> makePSOCKcluster -> serverSocket

parallel picks its default PSOCK port once, when its namespace loads — in initDefaultClusterOptions(), not per makeCluster() call:

ran1 <- sample.int(.Machine$integer.max - 1L, 1L) / .Machine$integer.max
port <- 11000 + 1000 * ((ran1 + unclass(Sys.time())/300) %% 1)

The random term is the reason. sample.int draws from the session's RNG stream, so it is only random while that stream is. Anything calling set.seed() before parallel first loads — which examples, vignettes and testthat do constantly, for reproducibility — makes it deterministic, and both halves draw the same number. Measured:

port
three sessions, set.seed(42) first 11181, 11183, 11183
three sessions, unseeded 11005, 11214, 11652

The time term cannot separate them. It sweeps 1000 ports over 300 seconds — 3.3 ports per second, 0.3 s per port — so two halves that load parallel within a third of a second of each other land on the same integer port. They start together and run the same script, so they do.

And it is not a one-shot risk. The choice is per session, so once the halves agree, every cluster either of them opens races for that one port for the rest of the check. Verified: two clusters in one session, and the option two seconds later, all gave 11800.

Why staggering is not the fix

You asked how long we would have to wait. From the 0.3 s/port sweep:

stagger port separation
0.3 s 1
1 s 3
15 s 50
150 s 500 (maximal)
300 s 0 — wraps

Three problems with using that. The separation has to hold at the moment each half loads parallel, not at check start — and the halves drift apart by minutes over a check, so a start offset says nothing about the offset at load time. One port of separation is no margin. And the sweep wraps at 300 s, so a large stagger can land you back where you started.

The fix

R_PARALLEL_PORT, 20000 for old and 30000 for new, set in check-pair.sh.

I flagged this last time as needing care, on the theory that a fixed port might break packages opening clusters back-to-back. That was wrong, and the session-fixity result above is why: R already fixes one port per session and reuses it for every cluster. Setting the variable changes nothing within a half — it only stops the two halves agreeing. It is strictly safer than the status quo, and both values are far from R's own 11000–12000 band, so a session inheriting neither cannot wander into either.

Verified end to end — the seeded pair that collided now separates:

before:  11978  11979
after:   20000  30000

Should the load test log 500 more lines? Yes, folded

Your log is the argument for it:

Preflight: load-testing 498 of 1416 installed package(s) ... 4 at a time, 10 min each
[resources] 19:35:24 ... load 1.59
...
[resources] 19:38:25 ... load 5.37
Packed 1449 package(s) into library.tar (3 Gb)

Three minutes of a job people watch, and the only thing telling you it is alive is the resource sampler. (Which does confirm the parallelism is working — load climbs 1.6 → 6.4 → 5.4 for four jobs.) And there was nowhere for a package that loads slowly to appear, though every check of anything downstream of it pays that cost again.

So: every tested package gets a line with what it cost, in a collapsed ::group:: sorted slowest first, with the slowest few repeated outside it where they are actually read:

::group::Load test: 498 package(s), slowest first
    34s  slowpkg
     3s  curl
     2s  brokenpkg                      FAILED
     1s  jsonlite
::endgroup::
Load test: 497 ok, 1 failed, 6.2 min of CPU across 4 job(s); slowest: slowpkg (34s), curl (3s), ...

The 500 lines are ones the default view never shows — that is what makes the trade worth taking. Integration-tested on 24 real packages: 24 lines, 3.8 s at 4-way.

Incidentally your log confirms the roots projection: 498 of 1416, against the 33% I measured on the full universe.

Not in this PR

cia and TDApplied should not be reported upstream — nothing is wrong with them, and they are the only two newly_broken packages in that run absent from #2646. With this fix they should return to ok.

  • By submitting this pull request, I assign the copyright of my contribution to The igraph development team.

Generated by Claude Code

claude added 2 commits August 15, 2026 19:42
Two packages in run 31893156685 -- `cia` and `TDApplied` -- were
reported newly broken with nothing wrong with them:

  Error in serverSocket(port = port) :
    creation of server socket failed: port 11477 cannot be opened
  Calls: SampleChains -> makePSOCKcluster -> serverSocket

`parallel` picks its default PSOCK port once, when its namespace loads:

  ran1 <- sample.int(.Machine$integer.max - 1L, 1L) / .Machine$integer.max
  port <- 11000 + 1000 * ((ran1 + unclass(Sys.time())/300) %% 1)

The random term is only random while the RNG stream is. Anything that
calls set.seed() before `parallel` first loads -- which examples,
vignettes and testthat do constantly -- makes it deterministic, and both
halves draw the same number. Measured: three sessions seeded with 42
gave 11181, 11183, 11183, against 11005, 11214, 11652 unseeded.

The time term cannot separate them either. It sweeps 1000 ports over
300 seconds, 3.3 per second, so two halves loading `parallel` within a
third of a second of each other get the same integer port -- and they
start together and run the same script. The choice is per session, not
per cluster, so from then on every cluster either half opens races for
that one port.

Staggering is not a fix: the separation would have to hold at the moment
each half loads `parallel`, the two drift apart by minutes over a check,
and at 300 seconds the sweep wraps back onto itself. `R_PARALLEL_PORT`
is, and it costs nothing that was not already the case -- R fixes one
port per session and reuses it regardless. 20000 and 30000, both far
from R's own 11000-12000 band. Verified: the seeded pair that collided
on 11978/11979 now gets 20000 and 30000.

And the load test says what it did. It announced "load-testing 498 of
1416" and then printed nothing at all until the summary, which is a poor
trade for three minutes of a job people watch. Every tested package now
gets a line with what it cost, in a collapsed group sorted slowest
first, and the slowest few are repeated outside it. ~500 lines the
default view never shows, and the only place a package that loads
*slowly* appears -- though every check of anything downstream of it pays
that cost again.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D1xpHRV7yVfgtJg4vp9P7z
`--as-cran` sets `_R_CHECK_TIMINGS_` to 10, which stamps every stage
slower than that with its own `[user/elapsed]` pair and appends an
"Examples with CPU ... > 5s" table. Both are wall clock measured on two
checks racing each other for the same four cores, so they differ between
the halves by construction -- every one of them a line in the diff that
says nothing about the package:

  -permutation_model_inference 0.236  0.016  10.302
  +permutation_model_inference 0.246  0.011  10.303

`neutral_log()` strips them so the comparison is not fooled, and it
still does, because a reused baseline or an older artifact may carry
them. This stops them being produced at all, so the diff a human reads
is only what changed. `_R_CHECK_TIMINGS_=""` for the stamps and
`_R_CHECK_EXAMPLE_TIMING_THRESHOLD_=99999` for the table -- both
measured: 0 stamps and 0 tables, against 1 and 1 with `--as-cran`'s
defaults. Setting the threshold to 0 or -1 does the opposite and stamps
everything, which is worth knowing before someone tries it.

Nothing is lost. What a stage cost is still recorded, per line and for
every stage rather than only the slow ones, by the elapsed stamping in
check-pair.sh -- which is on the driver log, not on the file the halves
are compared through.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01D1xpHRV7yVfgtJg4vp9P7z
@krlmlr
krlmlr merged commit be6df90 into claude/preflight-shared-deps-8mj8p1 Aug 16, 2026
1 check passed
@krlmlr
krlmlr deleted the claude/revdep2-parallel-port-8mj8p1 branch August 16, 2026 05:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants