run_r leaks later timers, which stalls the R test suite for ten minutes

[jat255]

R CMD check on pkg-r/ spends about ten minutes idle. Run 33796849087 took 15m22s, and the checking tests step was 11m25s of that. Check reports the split itself:

Running 'testthat.R' [2m/11m]

Two minutes of CPU, eleven minutes of wall clock. Every other check step takes a few seconds. The same stall happens locally, where the suite looks hung on test-trajectory-review.R.

Cause

shiny::testServer() reads an output through MockShinySession$getOutput(), which calls shiny:::extract() and then shiny:::wait_for_it():

wait_for_it <- function() {
  while (!later::loop_empty()) later::run_now(0.1)
}

That does not wait for the output's own promise. It waits until the whole global later queue is empty, so anything left on the queue has to fire first.

run_r_tool() leaves things on that queue. Every call ends in schedule_worker_reap(), which arms a timer at commons.run_r_idle_timeout + 1, 601 seconds by default. Each call also arms a timeout timer in worker_await() at commons.run_r_timeout, 60 seconds by default. Neither is cancelled when the call settles, and worker_close() does not cancel them either.

So test-run-r.R finishes in ten seconds and hands the global loop 70 pending callbacks. test-trajectory-review.R then reads output$entries inside a testServer() block (test-trajectory-review.R#L297), and that read cannot return until the last 601 second timer fires.

Measurements

Immediately after test-run-r.R, the global loop holds 70 callbacks in two clusters: 34 at 46 to 60 seconds, and 35 at 587 to 601 seconds. The two clusters match the two option defaults. The farthest is 600.9 seconds out, and draining the loop the way wait_for_it() does takes 600.9 seconds.

Running test-run-r.R and then test-trajectory-review.R in one session, the test "the viewer filters conversations and follows selection" takes 601.1 seconds. With commons.run_r_idle_timeout = 2 and commons.run_r_timeout = 2, the same test takes 3.1 seconds. A bisect over every other test file shows test-run-r.R is the only one that triggers this. Run on its own, the whole suite is about 40 seconds.

A stack sample of the stalled process shows it parked in pthread_cond_timedwait at about 0% CPU, which is why the job burns wall clock and not CPU.

Fix

later::later() and later::later_fd() each return a canceller function. Keep those handles on the worker, call them when the call settles, and call them again in worker_close(). Note that later::cancel() is not exported and does not exist in later 1.4.8.

The comment above schedule_worker_reap() says stray timers are harmless because they check recency before acting. That holds for correctness, but not for any caller that waits on later::loop_empty().

Only MockShinySession$getOutput() reaches wait_for_it(), so deployed apps do not stall. The leak itself is still real there.