Skip to content

Runner cancels a healthy running job after 10 cumulative (not consecutive) retriable broker poll errors #4820

Open

Description

@arqulus

Version / environment: runner v2.338.0 (the same code is on main; I did not read the v2.338.1 tag itself), Linux ARM64, self-hosted, systemd service.

What happens

While a job is running, the listener keeps polling the broker (GET .../message?...&status=Busy). On our network some of these long-polls hit the client's 100 s HTTP timeout. Each one that escapes the inner request retry is logged as Retriable exception: The HTTP request timed out after 00:01:40. and the listener backs off and polls again, as intended.

But after the 10th such exception during the same job, the listener shuts down its job dispatcher and sends a cancellation to the worker, even though the job itself is healthy (job renewals were still succeeding). The job ends as cancelled. On our machine a retriable exception escapes about every 9.5 minutes, so every job that runs longer than about 95 minutes is cancelled at that point. Three jobs in one day were cancelled at 95.4, 95.6 and 96.1 minutes; a job that finished at 93.75 minutes passed.

Log sequence at the cancellation (session ids removed):

[... INFO BrokerMessageListener] Retriable exception: The HTTP request timed out after 00:01:40.
[... INFO JobDispatcher] Shutting down JobDispatcher. Make sure all WorkerDispatcher has finished.
[... INFO JobDispatcher] Ensure WorkerDispatcher for job ... run to finish, cancel any running job.
[... INFO JobDispatcher] Send job cancellation message to worker for job ...
[... INFO JobDispatcher] finish job request for job ... with result: Canceled

In both logs I checked, this was exactly the 10th Retriable exception after the job started.

Cause in the source

src/Runner.Listener/BrokerMessageListener.cs, GetNextMessageAsync (v2.338.0, lines 281-371; the same lines on main):

  • line 281: int continuousError = 0;
  • line 284: var maxRetryCount = 10;
  • line 361: continuousError++; on every retriable exception
  • lines 369-371: else if (continuousError >= maxRetryCount) { throw; }

continuousError is never set back to 0. A poll that returns no message just does continue (lines ~306-309), and nothing else resets it. The call to GetNextMessageAsync stays open for the whole time a job runs, so the counter accumulates every poll failure over the job's lifetime, not consecutive ones as the name and the "random backoff ... consecutive error" comments suggest. Any sufficiently long job on a network with occasional dropped long-polls will eventually reach 10.

Expected behaviour

Only 10 consecutive failed polls should give up. A successful poll (including one that returns no message) should reset the counter.

Possible fix

Reset continuousError (and encounteringError) to 0 after a poll completes without throwing, i.e. just before the if (message == null) { continue; } check. I have not built or tested a patched runner. It may also be worth making maxRetryCount configurable.

Workaround

Keep jobs shorter than the point where the 10th escaped timeout happens (about 95 minutes for us).

Not established

Why the broker long-polls time out at 100 s on our network. They also happen on idle runners, and a renewjob POST sometimes fails with "The response ended prematurely". That may be our network; this issue is only about the listener treating cumulative errors as consecutive.

Activity

  1. alejandrogarcia-hub commented on Oct 26, 2026

    @alejandrogarcia-hub

    We see the same on ephemeral AWS CodeBuild-managed runners (Linux x64, runner v2.338.1). It started 2026-10-24 around 07:23 UTC and is still happening on 2026-10-26 at 11:30 UTC.

    • In 175 of 179 sampled jobs since the onset, the listener logs Runner connect error: The HTTP request timed out after 00:01:40.. Retrying until reconnected. 8.7–9.3 min after Running job:. Two more log it later (around minute 38), and two short jobs never log it. None of them ever logs Runner reconnected.
    • Long jobs are cancelled while healthy. Since the onset, 84 jobs have been cancelled this way, all 95–97 min after the job started (two later, where the first timeout came later). The listener console ends with An error occurred: The HTTP request timed out after 00:01:40. and Runner listener exit with retryable error, re-launch runner in 5 seconds., and the job log shows The operation was canceled.
    • Before the onset there were no such errors. In the 4.5 days before, 112 jobs ran 100 min or more successfully, some of them on v2.338.1, so the 2.338.1 bump is not the trigger.

    Our reading of the code matches yours. In BrokerMessageListener.GetNextMessageAsync, continuousError (and encounteringError) are never reset after a successful poll. MessageListener.GetNextMessageAsync resets both when it reconnects. The same code is in v2.330.0, so this looks like a latent bug that something started triggering around 2026-10-24.

    Two questions:

    1. Could the counter be reset after a poll that completes without an exception, as MessageListener does?
    2. Did anything change in the broker long-poll on 2026-10-24 between 07:00 and 08:00 UTC? The onset was sharp, and the first timeout lands at the same minute of every job, which looks timer-driven rather than like random packet loss.

    We are capturing _diag logs and will add the timestamp of each timeout here.

    Edit 2026-10-26: corrected the count of cancelled jobs. The cancels at about 46 and 82 min that I first included were manual cancels, not this issue. See also my follow-up below: every broker poll fails in our case, so a counter reset alone would not help.

  2. alejandrogarcia-hub commented on Oct 26, 2026

    @alejandrogarcia-hub

    Follow-up with our _diag data, and a correction to my comment above.

    In a job that does nothing but sleep (CodeBuild-managed runner, v2.338.1), the listener logged 10 escaped failures at 8.9, 18.4, 27.9, 37.4, 46.7, 56.1, 65.8, 75.3, 85.2 and 94.9 min. In the same second as the 10th it logged Shutting down JobDispatcher and Send job cancellation message to worker.

    The correction: every broker poll failed, not some. All 50 GET .../message?...&status=Busy requests timed out after 100 s, starting with the first one. BrokerServer retries each failure internally (5 attempts of about 110 s each), so only one failure escapes to BrokerMessageListener, roughly every 9.5 min. That is where the 9.5-min rhythm comes from. No poll succeeded in between, so in our case counting the failures cumulatively or consecutively makes no difference: resetting the counter after a successful poll would not have saved these jobs. If you also see about 9.5 min between escaped failures, your polls may be failing continuously too.

    In our case the cause is the network path. A GitHub-hosted job running at the same time for 110 min was not affected. A separate test from our runner showed that when *.actions.githubusercontent.com closes a connection on the server side, our runner never sees the close: its next request gets a reset, or no answer at all. A GitHub-hosted runner sees the same close immediately. We are taking that to our network team.

    One runner-side suggestion: while renewjob keeps succeeding, the job is healthy, so cancelling it only because message polls fail is harsh. When the listener gives up, a log line that says it is cancelling the job because broker polls keep failing would have saved us a day spent looking at our build timeouts.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions