Object storage calls in a logging path can time out POST /api/v4/jobs/request and strand a build in running

Summary

The endpoint POST /api/v4/jobs/request (runner job request endpoint) fails intermittently with Rack::Timeout::RequestTimeoutException: Request ran for longer than 60000ms. The root cause is that Ci::RegisterJobService#log_build_dependencies_size (app/services/ci/register_job_service.rb:406) issues one object storage metadata request per dependency via build.artifacts_file.size, serially, inside the synchronous job-assignment request. This code path is gated behind feature flag ci_build_dependencies_artifacts_logger (ops FF, default_enabled: false, introduced in 15.3, rollout issue #369441 (closed)). The backtrace below shows it is enabled on GitLab.com.

The same size value already exists in the ci_job_artifacts.size column and is exposed via Ci::Build#artifacts_size (app/models/ci/build.rb:848), requiring no network call. Gitlab::Ci::Artifacts::Logger.log_created already uses that column for the same purpose.

When the timeout fires, the build is left stranded: present_build! runs after assign_runner! has already committed build.run! (app/services/ci/register_job_service.rb:245), so the build is already running with a runner assigned. Since Rack::Timeout::RequestTimeoutException inherits from Exception, not StandardError, it is not caught by the rescue StandardError in process_build that would normally call scheduler_failure!. The runner receives a 500 without the job payload, while the build remains running in the database with no runner polling it, until it hits its own job timeout. A Puma thread is also held for the full 60 seconds.

Steps to reproduce

This is not deterministically reproducible. It occurs under the following conditions:

  • The instance uses object storage for artifacts.
  • Feature flag ci_build_dependencies_artifacts_logger is enabled.
  • A runner requests a job whose dependencies have artifacts.
  • log_build_dependencies_size then issues one object storage metadata call per dependency.
  • Any stall in one of those calls (in the observed case, a hung Google OAuth token refresh) is charged against the same 60-second request budget until rack-timeout kills it.

Example Project

Not applicable. This is internal to job assignment on GitLab.com, not something reproducible via an example project.

What is the current bug behavior?

The per-dependency object storage metadata calls are serial, so the cost scales with dependency count. Ci::BuildDependencies#all (app/models/ci/build_dependencies.rb:13) is uncapped: it returns all builds from earlier stages, or all needs: entries with artifacts.

The captured backtrace shows the stall that pushed one request to the full 60 seconds was in a Google OAuth access-token refresh triggered by apply_request_options, not in the metadata call itself:

  • signet builds its token request on Faraday.default_connection with no open or read timeout configured, so it falls back to Net::HTTP defaults.
  • GitLab's connect patch (gems/gitlab-http/lib/net_http/connect_patch.rb:65) wraps TCPSocket.open in Timeout.timeout(@open_timeout) per candidate address, so an unreachable address under dual stack can consume the open timeout more than once before failing over.
  • Retries compound this further: googleauth allows up to 5 attempts, and Google::Apis::RequestOptions.default.retries is set to 3 in config/initializers/google_api_client.rb:12.
  • Token refresh happens roughly hourly per process, so this shows up as an intermittent tail rather than steady slowness.

A recently added protection does not help here: present_build! is wrapped in with_phase_timeout(:present_build), which raises PresentBuildTimeoutError, a StandardError that process_build would catch and handle via scheduler_failure (dropping and retrying the build). That protection is gated behind feature flag ci_register_job_phase_timeouts, which is not enabled yet.

What is the expected correct behavior?

Job assignment should not make object storage calls. The dependency-size log should be computed from the existing ci_job_artifacts.size column instead of round-tripping to object storage. No logging-only code path should be able to time out a job-assignment request or leave a build stuck in running with no runner attached.

Relevant logs and/or screenshots

Abridged backtrace from the timed-out request. Line numbers correspond to the deployed revision.

Rack::Timeout::RequestTimeoutException: Request ran for longer than 60000ms

gems/gitlab-http/lib/net_http/connect_patch.rb:66:in `open'
timeout (0.6.1) lib/timeout.rb:304:in `timeout'
gems/gitlab-http/lib/net_http/connect_patch.rb:65:in `block in connect'
net-http (0.6.0) lib/net/http.rb:1642:in `do_start'
faraday-net_http (3.1.0) lib/faraday/adapter/net_http.rb:112:in `request_with_wrapped_block'
faraday (2.14.3) lib/faraday/connection.rb:280:in `post'
signet (0.19.0) lib/signet/oauth_2/client.rb:1039:in `fetch_access_token'
googleauth (1.14.0) lib/googleauth/signet.rb:77:in `fetch_access_token!'
googleauth (1.14.0) lib/googleauth/service_account.rb:132:in `apply!'
google-apis-core (0.18.0) lib/google/apis/core/http_command.rb:345:in `apply_request_options'
google-apis-core (0.18.0) lib/google/apis/core/http_command.rb:321:in `execute_once'
retriable (3.1.2) lib/retriable.rb:56:in `retriable'
google-apis-storage_v1 (0.56.0) lib/google/apis/storage_v1/service.rb:2761:in `get_object'
fog-google (1.29.4) lib/fog/google/storage/storage_json/requests/get_object_metadata.rb:18:in `get_object_metadata'
fog-google (1.29.4) lib/fog/google/storage/storage_json/models/files.rb:57:in `metadata'
carrierwave (1.3.4) lib/carrierwave/storage/fog.rb:473:in `file'
carrierwave (1.3.4) lib/carrierwave/storage/fog.rb:304:in `size'
carrierwave (1.3.4) lib/carrierwave/uploader/proxy.rb:55:in `size'
app/services/ci/register_job_service.rb:415:in `block (2 levels) in log_build_dependencies_size'
app/services/ci/register_job_service.rb:414:in `sum'
app/services/ci/register_job_service.rb:413:in `log_build_dependencies_size'
app/services/ci/register_job_service.rb:400:in `block in present_build!'
app/services/ci/register_job_service.rb:398:in `present_build!'
app/services/ci/register_job_service.rb:353:in `block in present_build_with_instrumentation!'
app/services/ci/register_job_service.rb:255:in `process_build'
app/services/ci/register_job_service.rb:115:in `process_queue'
app/services/ci/register_job_service.rb:81:in `execute'
lib/api/ci/helpers/job_request.rb:59:in `acquire_ci_job!'
lib/api/ci/runner.rb:237:in `block (2 levels) in <class:Runner>'
[... Grape / Rack middleware ...]
rack-timeout (0.7.0) lib/rack/timeout/core.rb:153:in `call'

Output of checks

This bug happens on GitLab.com.

Results of GitLab environment info

Expand for output related to GitLab environment info 
Not applicable, this is GitLab.com.

Results of GitLab application Check

Expand for output related to the GitLab application check 
Not applicable, this is GitLab.com.

Related issues

#569685 (closed) ("Improve performance of all_dependencies call on Ci::RegisterJobService") proposed moving this same logging to an async worker. It was closed as wont-do in September 2025 after a Kibana check showed the present_build_logs instrumentation typically completes very quickly, so the cost was judged acceptable.

That finding is about the typical case; this report is about the tail. The call has no bounded latency because it depends on a remote object storage request, and when that stalls it consumes the whole request budget and leaves the build stranded in running. Reading the size from the existing database column removes that tail without requiring an async worker.

Possible fixes

The following are options to weigh, not a decided plan:

  • In log_build_dependencies_size, sum build.artifacts_size instead of build.artifacts_file.size — same value, read from the ci_job_artifacts.size column, no network call, removes object storage from the job-request path entirely.
    • The same request already reads this size from the column elsewhere: the runner response exposes it through API::Entities::Ci::JobArtifactFile, which serialises JobArtifactUploader#cached_size (app/uploaders/job_artifact_uploader.rb:14), and that method returns ci_job_artifacts.size when the column is populated rather than asking object storage.
    • The column is nullable (size bigint, with no NOT NULL constraint and no presence validation on the model), so the sum needs to be nil-safe, for example build.artifacts_size.to_i. In practice nothing writes a NULL: before_save :set_size (app/models/ci/job_artifact.rb:50) fires on every creation path, and a sample of recent production artifacts found no null sizes.
  • Enable feature flag ci_register_job_phase_timeouts as defense in depth, so any remaining unbounded I/O in the read-only phases of job registration fails as a droppable StandardError instead of a Rack::Timeout::RequestTimeoutException that strands the build.
  • Longer term, and beyond the scope of this issue: signet's token-fetch connection has no open or read timeout configured, which affects every object storage caller in a web request, not just this one.

Patch release information for backports

If the bug fix needs to be backported in a patch release to a version under the maintenance policy, please follow the steps on the patch release runbook for GitLab engineers.

Refer to the internal "Release Information" dashboard for information about the next patch release, including the targeted versions, expected release date, and current status.

High-severity bug remediation

To remediate high-severity issues requiring an internal release for single-tenant SaaS instances, refer to the internal release process for engineers.

Edited by 🤖 GitLab Bot 🤖