Artifact upload endpoint timeout leads to stale records and runner 400s
Everyone can contribute. Help move this issue forward while earning points, leveling up and collecting rewards.
Description
When the runner tries to persist an artifact, there is a run_after_commit hook that often fails, making the API return 500 errors.
The problem is that the records aren't being rolled back, leading to 400s when the runner retries because the old artifact already exists with the same name.
Analysis
For 500s there is a Rack timeout (logs).
The timeout itself happens in some run_after_commit code for scheduling to update project_daily_statistics.
The persist operations run in a transaction block, but the timeout occurs after the artifacts transaction has been committed.
Full Logs: https://log.gprd.gitlab.net/app/discover#/?_g=h@6c7023e&_a=h@e6c98cd
Sample Logs
"exception": {
"backtrace": [
"activerecord (7.1.5.1) lib/active_record/connection_adapters/postgresql_adapter.rb:349:in `exec'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/postgresql_adapter.rb:349:in `block in active?'",
"activesupport (7.1.5.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/postgresql_adapter.rb:347:in `active?'",
"gems/activerecord-gitlab/lib/active_record/gitlab_patches/abstract_adapter.rb:79:in `verify!'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract_adapter.rb:1018:in `block in with_raw_connection'",
"activesupport (7.1.5.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract_adapter.rb:999:in `with_raw_connection'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/postgresql_adapter.rb:893:in `block in exec_no_cache'",
"activesupport (7.1.5.1) lib/active_support/notifications/instrumenter.rb:58:in `instrument'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract_adapter.rb:1142:in `log'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/postgresql_adapter.rb:892:in `exec_no_cache'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/postgresql_adapter.rb:872:in `execute_and_clear'",
"marginalia (1.11.1) lib/marginalia.rb:91:in `execute_and_clear_with_marginalia'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/postgresql/database_statements.rb:64:in `internal_exec_query'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/database_statements.rb:630:in `select'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/database_statements.rb:71:in `select_all'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/query_cache.rb:112:in `block in select_all'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/query_cache.rb:152:in `block in cache_sql'",
"activesupport (7.1.5.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/query_cache.rb:147:in `cache_sql'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/query_cache.rb:112:in `select_all'",
"lib/gitlab/database/load_balancing/load_balancer.rb:338:in `block in wal_diff'",
"lib/gitlab/database/load_balancing/load_balancer.rb:145:in `block in read_write'",
"lib/gitlab/database/load_balancing/load_balancer.rb:239:in `retry_with_backoff'",
"lib/gitlab/database/load_balancing/load_balancer.rb:135:in `read_write'",
"lib/gitlab/database/load_balancing/load_balancer.rb:329:in `wal_diff'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/duplicate_job.rb:197:in `pg_wal_lsn_diff'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/duplicate_job.rb:103:in `block in update_latest_wal_location!'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/duplicate_job.rb:102:in `each'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/duplicate_job.rb:102:in `update_latest_wal_location!'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/strategies/deduplicates_when_scheduling.rb:44:in `deduplicate?'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/strategies/deduplicates_when_scheduling.rb:18:in `schedule'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/duplicate_job.rb:37:in `schedule'",
"lib/gitlab/sidekiq_middleware/duplicate_jobs/client.rb:8:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"lib/gitlab/sidekiq_middleware/concurrency_limit/middleware.rb:23:in `schedule'",
"lib/gitlab/sidekiq_middleware/concurrency_limit/client.rb:8:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"lib/gitlab/sidekiq_middleware/pause_control/strategies/base.rb:21:in `schedule'",
"lib/gitlab/sidekiq_middleware/pause_control/strategy_handler.rb:15:in `schedule'",
"lib/gitlab/sidekiq_middleware/pause_control/client.rb:8:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"lib/gitlab/database/load_balancing/sidekiq_client_middleware.rb:25:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"gitlab-labkit (0.39.0) lib/labkit/middleware/sidekiq/client.rb:21:in `block in call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:180:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"gitlab-labkit (0.39.0) lib/labkit/middleware/sidekiq/context/client.rb:23:in `block in call'",
"gitlab-labkit (0.39.0) lib/labkit/context.rb:35:in `with_context'",
"gitlab-labkit (0.39.0) lib/labkit/middleware/sidekiq/context/client.rb:20:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:173:in `invoke'",
"gitlab-labkit (0.39.0) lib/labkit/middleware/sidekiq/client.rb:20:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"lib/gitlab/application_context.rb:173:in `block in use'",
"gitlab-labkit (0.39.0) lib/labkit/context.rb:35:in `with_context'",
"lib/gitlab/application_context.rb:173:in `use'",
"lib/gitlab/application_context.rb:96:in `with_context'",
"lib/gitlab/sidekiq_middleware/worker_context/client.rb:36:in `block in call'",
"lib/gitlab/sidekiq_middleware/worker_context.rb:9:in `wrap_in_optional_context'",
"lib/gitlab/sidekiq_middleware/worker_context/client.rb:18:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"lib/gitlab/sidekiq_middleware/concurrency_limit/resume.rb:17:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:183:in `block in traverse'",
"sentry-sidekiq (5.23.0) lib/sentry/sidekiq/sentry_context_middleware.rb:103:in `block in call'",
"sentry-ruby (5.23.0) lib/sentry/hub.rb:138:in `with_child_span'",
"sentry-ruby (5.23.0) lib/sentry-ruby.rb:515:in `with_child_span'",
"sentry-sidekiq (5.23.0) lib/sentry/sidekiq/sentry_context_middleware.rb:100:in `call'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:182:in `traverse'",
"vendor/gems/sidekiq/lib/sidekiq/middleware/chain.rb:173:in `invoke'",
"vendor/gems/sidekiq/lib/sidekiq/client.rb:105:in `push'",
"vendor/gems/sidekiq/lib/sidekiq/job.rb:372:in `client_push'",
"vendor/gems/sidekiq/lib/sidekiq/job.rb:342:in `perform_in'",
"config/initializers/forbid_sidekiq_in_transactions.rb:60:in `block (2 levels) in <module:NoEnqueueingFromTransactions>'",
"app/workers/concerns/application_worker.rb:119:in `block (4 levels) in <module:ApplicationWorker>'",
"lib/gitlab/sidekiq_sharding/router.rb:37:in `block (2 levels) in route'",
"vendor/gems/sidekiq/lib/sidekiq/client.rb:184:in `via'",
"lib/gitlab/sidekiq_sharding/validator.rb:17:in `via'",
"lib/gitlab/sidekiq_sharding/router.rb:36:in `block in route'",
"lib/gitlab/application_context.rb:173:in `block in use'",
"gitlab-labkit (0.39.0) lib/labkit/context.rb:35:in `with_context'",
"lib/gitlab/application_context.rb:173:in `use'",
"lib/gitlab/application_context.rb:96:in `with_context'",
"lib/gitlab/sidekiq_sharding/router.rb:35:in `route'",
"app/workers/concerns/application_worker.rb:118:in `block (3 levels) in <module:ApplicationWorker>'",
"lib/gitlab/counters/buffered_counter.rb:84:in `increment'",
"app/models/concerns/counter_attribute.rb:130:in `block in increment_counter'",
"app/models/concerns/after_commit_queue.rb:34:in `instance_eval'",
"app/models/concerns/after_commit_queue.rb:34:in `run_after_commit_or_now'",
"app/models/concerns/counter_attribute.rb:129:in `increment_counter'",
"app/models/project_statistics.rb:136:in `increment_statistic'",
"app/models/project_statistics.rb:121:in `block in increment_statistic'",
"activesupport (7.1.5.1) lib/active_support/core_ext/object/try.rb:12:in `try'",
"app/models/project_statistics.rb:120:in `increment_statistic'",
"app/models/concerns/update_project_statistics.rb:84:in `block in schedule_update_project_statistic'",
"app/models/concerns/after_commit_queue.rb:44:in `instance_eval'",
"app/models/concerns/after_commit_queue.rb:44:in `_run_after_commit_queue'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:403:in `block in make_lambda'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:274:in `block in simple'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:602:in `block in invoke_after'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:602:in `each'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:602:in `invoke_after'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:111:in `run_callbacks'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:952:in `_run_commit_callbacks'",
"activerecord (7.1.5.1) lib/active_record/transactions.rb:332:in `committed!'",
"config/initializers/skip_transaction_checks.rb:8:in `block (2 levels) in committed!'",
"config/initializers/forbid_sidekiq_in_transactions.rb:10:in `skipping_transaction_check'",
"config/initializers/skip_transaction_checks.rb:8:in `block in committed!'",
"lib/gitlab/exclusive_lease.rb:114:in `skipping_transaction_check'",
"config/initializers/skip_transaction_checks.rb:7:in `committed!'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/transaction.rb:237:in `block in commit_records'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/transaction.rb:263:in `run_action_on_records'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/transaction.rb:236:in `commit_records'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/transaction.rb:515:in `block in commit_transaction'",
"activesupport (7.1.5.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/transaction.rb:503:in `commit_transaction'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/transaction.rb:565:in `block in within_new_transaction'",
"activesupport (7.1.5.1) lib/active_support/concurrency/null_lock.rb:9:in `synchronize'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/transaction.rb:532:in `within_new_transaction'",
"activerecord (7.1.5.1) lib/active_record/connection_adapters/abstract/database_statements.rb:344:in `transaction'",
"lib/gitlab/database/load_balancing/connection_proxy.rb:127:in `public_send'",
"lib/gitlab/database/load_balancing/connection_proxy.rb:127:in `block in write_using_load_balancer'",
"lib/gitlab/database/load_balancing/load_balancer.rb:145:in `block in read_write'",
"lib/gitlab/database/load_balancing/load_balancer.rb:239:in `retry_with_backoff'",
"lib/gitlab/database/load_balancing/load_balancer.rb:135:in `read_write'",
"lib/gitlab/database/load_balancing/connection_proxy.rb:126:in `write_using_load_balancer'",
"lib/gitlab/database/load_balancing/connection_proxy.rb:78:in `transaction'",
"activerecord (7.1.5.1) lib/active_record/transactions.rb:212:in `transaction'",
"lib/gitlab/database.rb:397:in `transaction'",
"app/models/concerns/cross_database_modification.rb:82:in `transaction'",
"activerecord (7.1.5.1) lib/active_record/transactions.rb:301:in `transaction'",
"app/services/ci/job_artifacts/create_service.rb:145:in `persist_artifact'",
"app/services/ci/job_artifacts/create_service.rb:58:in `execute'",
"lib/api/ci/runner.rb:367:in `block (2 levels) in <class:Runner>'",
"grape (2.0.0) lib/grape/endpoint.rb:58:in `call'",
"grape (2.0.0) lib/grape/endpoint.rb:58:in `block (2 levels) in generate_api_method'",
"activesupport (7.1.5.1) lib/active_support/notifications.rb:208:in `instrument'",
"grape (2.0.0) lib/grape/endpoint.rb:57:in `block in generate_api_method'",
"grape (2.0.0) lib/grape/endpoint.rb:328:in `execute'",
"grape (2.0.0) lib/grape/endpoint.rb:260:in `block in run'",
"activesupport (7.1.5.1) lib/active_support/notifications.rb:208:in `instrument'",
"grape (2.0.0) lib/grape/endpoint.rb:240:in `run'",
"grape (2.0.0) lib/grape/endpoint.rb:316:in `block in build_stack'",
"grape (2.0.0) lib/grape/middleware/base.rb:36:in `call!'",
"grape (2.0.0) lib/grape/middleware/base.rb:29:in `call'",
"grape (2.0.0) lib/grape/middleware/base.rb:36:in `call!'",
"grape (2.0.0) lib/grape/middleware/base.rb:29:in `call'",
"lib/gitlab/middleware/ip_address.rb:14:in `block in call'",
"lib/gitlab/ip_address_state.rb:11:in `with'",
"lib/gitlab/middleware/ip_address.rb:13:in `call'",
"grape (2.0.0) lib/grape/middleware/base.rb:36:in `call!'",
"grape (2.0.0) lib/grape/middleware/base.rb:29:in `call'",
"grape (2.0.0) lib/grape/middleware/base.rb:36:in `call!'",
"grape (2.0.0) lib/grape/middleware/base.rb:29:in `call'",
"lib/api/api_guard.rb:266:in `call'",
"grape (2.0.0) lib/grape/middleware/base.rb:36:in `call!'",
"grape (2.0.0) lib/grape/middleware/base.rb:29:in `call'",
"rack-oauth2 (2.2.1) lib/rack/oauth2/server/resource.rb:20:in `_call'",
"rack-oauth2 (2.2.1) lib/rack/oauth2/server/resource/bearer.rb:8:in `_call'",
"rack-oauth2 (2.2.1) lib/rack/oauth2/server/abstract/handler.rb:17:in `call'",
"grape (2.0.0) lib/grape/middleware/error.rb:39:in `block in call!'",
"grape (2.0.0) lib/grape/middleware/error.rb:38:in `catch'",
"grape (2.0.0) lib/grape/middleware/error.rb:38:in `call!'",
"grape (2.0.0) lib/grape/middleware/base.rb:29:in `call'",
"grape_logging (1.8.4) lib/grape_logging/middleware/request_logger.rb:60:in `block in call!'",
"grape_logging (1.8.4) lib/grape_logging/middleware/request_logger.rb:58:in `catch'",
"grape_logging (1.8.4) lib/grape_logging/middleware/request_logger.rb:58:in `call!'",
"grape (2.0.0) lib/grape/middleware/base.rb:29:in `call'",
"rack (2.2.13) lib/rack/head.rb:12:in `call'",
"grape (2.0.0) lib/grape/endpoint.rb:224:in `call!'",
"grape (2.0.0) lib/grape/endpoint.rb:218:in `call'",
"grape (2.0.0) lib/grape/router/route.rb:58:in `exec'",
"grape (2.0.0) lib/grape/router.rb:120:in `process_route'",
"grape (2.0.0) lib/grape/router.rb:74:in `block in identity'",
"grape (2.0.0) lib/grape/router.rb:94:in `transaction'",
"grape (2.0.0) lib/grape/router.rb:72:in `identity'",
"grape (2.0.0) lib/grape/router.rb:56:in `block in call'",
"grape (2.0.0) lib/grape/router.rb:136:in `with_optimization'",
"grape (2.0.0) lib/grape/router.rb:55:in `call'",
"grape (2.0.0) lib/grape/api/instance.rb:165:in `call'",
"grape (2.0.0) lib/grape/api/instance.rb:70:in `call!'",
"grape (2.0.0) lib/grape/api/instance.rb:65:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/routing/mapper.rb:31:in `block in <class:Constraints>'",
"actionpack (7.1.5.1) lib/action_dispatch/routing/mapper.rb:60:in `serve'",
"actionpack (7.1.5.1) lib/action_dispatch/journey/router.rb:51:in `block in serve'",
"config/initializers/action_dispatch_journey_router.rb:52:in `block in find_routes'",
"config/initializers/action_dispatch_journey_router.rb:25:in `map!'",
"config/initializers/action_dispatch_journey_router.rb:25:in `find_routes'",
"actionpack (7.1.5.1) lib/action_dispatch/journey/router.rb:32:in `serve'",
"actionpack (7.1.5.1) lib/action_dispatch/routing/route_set.rb:882:in `call'",
"gitlab-experiment (0.9.1) lib/gitlab/experiment/middleware.rb:19:in `call'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:202:in `call!'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:169:in `call'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:470:in `call_app!'",
"ee/lib/omni_auth/strategies/group_saml.rb:41:in `other_phase'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:195:in `call!'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:169:in `call'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:202:in `call!'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:169:in `call'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:202:in `call!'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:169:in `call'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:202:in `call!'",
"omniauth (2.1.2) lib/omniauth/strategy.rb:169:in `call'",
"flipper (0.28.3) lib/flipper/middleware/memoizer.rb:72:in `memoized_call'",
"flipper (0.28.3) lib/flipper/middleware/memoizer.rb:37:in `call'",
"lib/gitlab/metrics/elasticsearch_rack_middleware.rb:16:in `call'",
"lib/gitlab/middleware/sidekiq_shard_awareness_validation.rb:20:in `block in call'",
"lib/gitlab/sidekiq_sharding/validator.rb:42:in `enabled'",
"lib/gitlab/middleware/sidekiq_shard_awareness_validation.rb:20:in `call'",
"lib/gitlab/middleware/memory_report.rb:13:in `call'",
"lib/gitlab/middleware/speedscope.rb:13:in `call'",
"lib/gitlab/database/load_balancing/rack_middleware.rb:23:in `call'",
"lib/gitlab/middleware/rails_queue_duration.rb:33:in `call'",
"lib/gitlab/etag_caching/middleware.rb:21:in `call'",
"lib/gitlab/metrics/rack_middleware.rb:16:in `block in call'",
"lib/gitlab/metrics/web_transaction.rb:46:in `run'",
"lib/gitlab/metrics/rack_middleware.rb:16:in `call'",
"lib/gitlab/middleware/go.rb:21:in `call'",
"lib/gitlab/middleware/query_analyzer.rb:11:in `block in call'",
"lib/gitlab/database/query_analyzer.rb:83:in `within'",
"lib/gitlab/middleware/query_analyzer.rb:11:in `call'",
"lib/ci/job_token/middleware.rb:11:in `call'",
"batch-loader (2.0.5) lib/batch_loader/middleware.rb:11:in `call'",
"rack-attack (6.7.0) lib/rack/attack.rb:103:in `call'",
"apollo_upload_server (2.1.6) lib/apollo_upload_server/middleware.rb:32:in `call'",
"lib/gitlab/middleware/multipart.rb:178:in `block in call'",
"lib/gitlab/middleware/multipart.rb:63:in `with_open_files'",
"lib/gitlab/middleware/multipart.rb:177:in `call'",
"rack-attack (6.7.0) lib/rack/attack.rb:127:in `call'",
"warden (1.2.9) lib/warden/manager.rb:36:in `block in call'",
"warden (1.2.9) lib/warden/manager.rb:34:in `catch'",
"warden (1.2.9) lib/warden/manager.rb:34:in `call'",
"rack-cors (2.0.2) lib/rack/cors.rb:102:in `call'",
"rack (2.2.13) lib/rack/tempfile_reaper.rb:15:in `call'",
"rack (2.2.13) lib/rack/etag.rb:27:in `call'",
"rack (2.2.13) lib/rack/conditional_get.rb:40:in `call'",
"rack (2.2.13) lib/rack/head.rb:12:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/http/permissions_policy.rb:36:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/http/content_security_policy.rb:36:in `call'",
"lib/gitlab/middleware/read_only/controller.rb:50:in `call'",
"lib/gitlab/middleware/read_only.rb:18:in `call'",
"lib/gitlab/middleware/unauthenticated_session_expiry.rb:18:in `call'",
"rack (2.2.13) lib/rack/session/abstract/id.rb:266:in `context'",
"rack (2.2.13) lib/rack/session/abstract/id.rb:260:in `call'",
"lib/gitlab/middleware/secure_headers.rb:11:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/cookies.rb:689:in `call'",
"lib/gitlab/middleware/same_site_cookies.rb:27:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'",
"activesupport (7.1.5.1) lib/active_support/callbacks.rb:101:in `run_callbacks'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/callbacks.rb:28:in `call'",
"sentry-rails (5.23.0) lib/sentry/rails/rescued_exception_interceptor.rb:14:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'",
"lib/gitlab/middleware/path_traversal_check.rb:40:in `call'",
"lib/gitlab/middleware/handle_malformed_strings.rb:21:in `call'",
"sentry-ruby (5.23.0) lib/sentry/rack/capture_exceptions.rb:30:in `block (2 levels) in call'",
"sentry-ruby (5.23.0) lib/sentry/hub.rb:299:in `with_session_tracking'",
"sentry-ruby (5.23.0) lib/sentry-ruby.rb:428:in `with_session_tracking'",
"sentry-ruby (5.23.0) lib/sentry/rack/capture_exceptions.rb:21:in `block in call'",
"sentry-ruby (5.23.0) lib/sentry/hub.rb:89:in `with_scope'",
"sentry-ruby (5.23.0) lib/sentry-ruby.rb:408:in `with_scope'",
"sentry-ruby (5.23.0) lib/sentry/rack/capture_exceptions.rb:20:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'",
"lib/gitlab/middleware/basic_health_check.rb:25:in `call'",
"lograge (0.11.2) lib/lograge/rails_ext/rack/logger.rb:15:in `call_app'",
"railties (7.1.5.1) lib/rails/rack/logger.rb:24:in `block in call'",
"activesupport (7.1.5.1) lib/active_support/tagged_logging.rb:139:in `block in tagged'",
"activesupport (7.1.5.1) lib/active_support/tagged_logging.rb:39:in `tagged'",
"activesupport (7.1.5.1) lib/active_support/tagged_logging.rb:139:in `tagged'",
"activesupport (7.1.5.1) lib/active_support/broadcast_logger.rb:241:in `method_missing'",
"railties (7.1.5.1) lib/rails/rack/logger.rb:24:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/remote_ip.rb:92:in `call'",
"lib/gitlab/middleware/handle_ip_spoof_attack_error.rb:25:in `call'",
"lib/gitlab/middleware/request_context.rb:15:in `call'",
"lib/gitlab/middleware/webhook_recursion_detection.rb:15:in `call'",
"request_store (1.7.0) lib/request_store/middleware.rb:19:in `call'",
"rack (2.2.13) lib/rack/method_override.rb:24:in `call'",
"rack (2.2.13) lib/rack/runtime.rb:22:in `call'",
"rack-timeout (0.7.0) lib/rack/timeout/core.rb:154:in `block in call'",
"rack-timeout (0.7.0) lib/rack/timeout/support/timeout.rb:19:in `timeout'",
"rack-timeout (0.7.0) lib/rack/timeout/core.rb:153:in `call'",
"config/initializers/fix_local_cache_middleware.rb:11:in `call'",
"lib/gitlab/middleware/compressed_json.rb:44:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/executor.rb:14:in `call'",
"lib/gitlab/middleware/rack_multipart_tempfile_factory.rb:19:in `call'",
"lib/gitlab/metrics/requests_rack_middleware.rb:83:in `call'",
"gitlab-labkit (0.39.0) lib/labkit/middleware/rack.rb:22:in `block in call'",
"gitlab-labkit (0.39.0) lib/labkit/context.rb:35:in `with_context'",
"gitlab-labkit (0.39.0) lib/labkit/middleware/rack.rb:21:in `call'",
"rack (2.2.13) lib/rack/sendfile.rb:110:in `call'",
"actionpack (7.1.5.1) lib/action_dispatch/middleware/request_id.rb:28:in `call'",
"lib/gitlab/middleware/sidekiq_web_static.rb:20:in `call'",
"railties (7.1.5.1) lib/rails/engine.rb:536:in `call'",
"railties (7.1.5.1) lib/rails/railtie.rb:226:in `public_send'",
"railties (7.1.5.1) lib/rails/railtie.rb:226:in `method_missing'",
"lib/gitlab/middleware/release_env.rb:12:in `call'",
"rack (2.2.13) lib/rack/urlmap.rb:74:in `block in call'",
"rack (2.2.13) lib/rack/urlmap.rb:58:in `each'",
"rack (2.2.13) lib/rack/urlmap.rb:58:in `call'",
"puma (6.6.0) lib/puma/configuration.rb:279:in `call'",
"puma (6.6.0) lib/puma/request.rb:99:in `block in handle_request'",
"puma (6.6.0) lib/puma/thread_pool.rb:390:in `with_force_shutdown'",
"puma (6.6.0) lib/puma/request.rb:98:in `handle_request'",
"puma (6.6.0) lib/puma/server.rb:472:in `process_client'",
"puma (6.6.0) lib/puma/server.rb:254:in `block in run'",
"puma (6.6.0) lib/puma/thread_pool.rb:167:in `block in spawn_thread'"
],
"class": "Rack::Timeout::RequestTimeoutException",
"message": "Request ran for longer than 60000ms "
Resolution Plan
Option 1: Delete the Artifact if the runner receives a 400 when retrying
Option 2: Offload the run_after_commit operation to a different process
Post commit hooks are not a necessary part of the artifact creation operation, it is something that could be performed async. The operation fails while scheduling the async worker, we could shift to a pub-sub system to remove the overhead of scheduling the job, which causes the timeout.
This way we can decouple the side effects from the main request and also allow better flexibility in case of scheduling failures.
Edited by 🤖 GitLab Bot 🤖