Skip to content
Snippets Groups Projects

rspec background_migration pg14 7/17

Passed Started by
Simon Tomlinson
@stomlinson
Log timestamps in UTC.
122:06:47Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
222:06:47 on blue-3.private.runners-manager.gitlab.com/gitlab.com/gitlab-org 6io2xoDD, system ID: s_8f94f7760223
322:06:47 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
422:06:47Resolving secrets
5 22:06:47 Preparing the "docker+machine" executor 00:12
622:06:47Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
722:06:49Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
822:06:49Authenticating with credentials from job payload (GitLab Registry)
922:06:49Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1022:06:49Using docker image sha256:82f132c22567f8ce17cc132c14b2f9aa3eaf9bb5424d91c2d966912433f0257d for registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:c55e1364ee4327b244a9cfa1750f19feea14fc774eaf792b725967d146eb45f5 ...
1122:06:49WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1222:06:49WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1322:06:49Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1422:06:49Authenticating with credentials from job payload (GitLab Registry)
1522:06:49Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1622:06:50Using docker image sha256:5c5ba5b83d6c60cb0b225bd670b7a43be8c238cc72347d24af57e5027c3648f3 for registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:46aceab84c42d0e819c8e7940f2f98ce9e184785cd7b22d95872024a35f52407 ...
1722:06:50Starting service redis:6.2-alpine...
1822:06:50Pulling docker image redis:6.2-alpine ...
1922:06:51Using docker image sha256:4100b5bd17430263e85ad9d8ab851959b234acaaf378e093f1f98400f4998815 for redis:6.2-alpine with digest redis@sha256:eaba718fecd1196d88533de7ba49bf903ad33664a92debb24660a922ecd9cac8 ...
2022:06:51Waiting for services to be up and running (timeout 30 seconds)...
2122:06:58Authenticating with credentials from job payload (GitLab Registry)
2222:06:58Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
2322:06:59Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
24 22:06:59 Preparing environment 00:00
2522:06:59Running on runner-6io2xodd-project-278964-concurrent-0 via runner-6io2xodd-private-1731517829-db066cc7...
26 22:06:59 Getting source from Git repository 00:01
2722:07:00Skipping Git repository setup
2822:07:00Skipping Git checkout
2922:07:00Skipping Git submodules setup
30 22:07:00 Restoring cache 00:19
3122:07:01Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20...
3222:07:01Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/278964/ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20 ETag="ba67364f761343c8f313528473af941a"
3322:07:13Successfully extracted cache
34 22:07:19 Downloading artifacts 00:45
3522:07:19Downloading artifacts for clone-gitlab-repo (8353286583)...
3622:07:24Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286583 responseStatus=200 OK token=glcbt-66
3722:07:24WARNING: Part of .git directory is on the list of files to extract
3822:07:24WARNING: This may introduce unexpected problems
3922:07:36Downloading artifacts for compile-test-assets (8353286630)...
4022:07:40Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286630 responseStatus=200 OK token=glcbt-66
4122:07:46Downloading artifacts for detect-tests (8353286649)...
4222:07:47Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286649 responseStatus=200 OK token=glcbt-66
4322:07:47Downloading artifacts for retrieve-tests-metadata (8353286664)...
4422:07:47Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286664 responseStatus=200 OK token=glcbt-66
4522:07:47Downloading artifacts for setup-test-env (8353286635)...
4622:07:52Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286635 responseStatus=200 OK token=glcbt-66
47 22:08:04 Executing "step_script" stage of the job script
4822:08:04Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
4922:08:05$ echo $FOSS_ONLY
5022:08:05$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
5122:08:05$ export GOPATH=$CI_PROJECT_DIR/.go
5222:08:05$ mkdir -p $GOPATH
5322:08:05$ source scripts/utils.sh
5422:08:05$ log_disk_usage "true"
5522:08:05*******************************************************
5622:08:05This runner currently has 74G free disk space.
5722:08:05*******************************************************
58 22:08:05 Disk usage detail 00:15
5922:08:05df -h
6022:08:05Filesystem Size Used Avail Use% Mounted on
6122:08:05overlay 95G 21G 74G 22% /
6222:08:05tmpfs 64M 0 64M 0% /dev
6322:08:05shm 64M 0 64M 0% /dev/shm
6422:08:05/dev/sda1 95G 21G 74G 22% /cache
6522:08:05tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6622:08:05du -h -d 1
6722:08:057.4M ./workhorse
6822:08:05148K ./bin
6922:08:051.2M ./.gitlab
7022:08:05167M ./.git
7122:08:054.0K ./builds
7222:08:0528M ./lib
7322:08:058.0K ./.vscode
7422:08:05560K ./storybook
7522:08:0524K ./log
7622:08:051.8M ./data
7722:08:0511M ./qa
7822:08:053.2M ./.rubocop_todo
7922:08:05856M ./vendor
8022:08:051023M ./public
8122:08:0562M ./doc
8222:08:05484K ./danger
8322:08:0532K ./rspec
8422:08:05556K ./tooling
8522:08:05145M ./ee
8622:08:051.3M ./knapsack
8722:08:05300K ./patches
8822:08:054.3M ./changelogs
8922:08:0520K ./haml_lint
9022:08:0528K ./metrics_server
9122:08:05108K ./keeps
9222:08:0536K ./shared
9322:08:0544K ./generator_templates
9422:08:051.3M ./scripts
9522:08:05763M ./tmp
9622:08:05127M ./spec
9722:08:0520K ./file_hooks
9822:08:0532K ./crystalball
9922:08:0516K ./sidekiq_cluster
10022:08:0517M ./gems
10122:08:051.2M ./fixtures
10222:08:05964K ./rubocop
10322:08:054.0K ./.go
10422:08:0533M ./db
10522:08:0512K ./.github
10622:08:05129M ./locale
10722:08:0520M ./config
10822:08:0582M ./app
10922:08:0520K ./.lefthook
11022:08:053.5G .
11122:08:05$ source scripts/prepare_build.sh
112 22:08:05 Installing gems 00:17
14322:08:22Using decomposed database config (config/database.yml.decomposed-postgresql)
14422:08:22Geo DB won't be set up.
14522:08:22Embedding DB won't be set up.
146 22:08:22 Setting up DBs 01:11
15922:09:33$ source ./scripts/rspec_helpers.sh
16022:09:33$ run_timed_command "gem install knapsack --no-document"
16122:09:33$ gem install knapsack --no-document
16222:09:34Successfully installed knapsack-4.0.0
16322:09:341 gem installed
16422:09:33==> 'gem install knapsack --no-document' succeeded in 1 seconds.
16522:09:34$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
166 22:09:34 Spawning Gitaly 00:04
17022:09:38$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
17122:09:38$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
17222:09:38$ tooling/bin/create_job_metrics_file || true
17322:09:41[job-metrics] Creating the job metrics file for the CI/CD job.
17422:09:41$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
175 22:09:41 RSpec 33:39
17622:09:41[22:09:41] Starting rspec_parallelized_job
17722:09:34RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
17822:09:42KNAPSACK_GENERATE_REPORT: true
17922:09:42FLAKY_RSPEC_GENERATE_REPORT: true
18022:09:42KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
18122:09:42KNAPSACK_LOG_LEVEL: debug
18222:09:42KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_7_17_278964_report.json
18322:09:42FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
18422:09:42FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_7_17_278964_report.json
18522:09:42NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_7_17_278964_report.json
18622:09:42RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8353287103.txt
18722:09:42CRYSTALBALL:
18822:09:42RSPEC_TESTS_MAPPING_ENABLED:
18922:09:42RSPEC_TESTS_FILTER_FILE:
19022:09:42Shell set options (set -o) enabled:
19122:09:42braceexpand on
19222:09:42hashall on
19322:09:42interactive-comments on
19422:09:42pipefail on
19522:09:47Knapsack report generator started!
19622:09:42/builds/gitlab-org/gitlab/vendor/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!
19722:10:23DEPRECATION WARNING: Support for Rails versions < 7.1 is deprecated and will be removed from ViewComponent 4.0.0 (ViewComponent v4 will remove support for Rails versions < 7.1 no earlier than April 1, 2025) (called from <top (required)> at /builds/gitlab-org/gitlab/config/environment.rb:7)
19822:10:33warning: parser/current is loading parser/ruby32, which recognizes 3.2.6-compliant syntax, but you are running 3.2.5.
19922:10:33Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
20022:10:37Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
20122:10:37# [RSpecRunTime] Starting RSpec timer...
20222:10:37[TEST PROF INFO] EventProf enabled (sql.active_record)
20322:10:37unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20422:10:37unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20522:10:44Test environment set up in 1.151907834 seconds
20622:10:45# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_uuid_conversion_column_in_vulnerability_occurrences_spec.rb. Expected to take 2 minutes 38.72 seconds.
20722:10:45Gitlab::BackgroundMigration::BackfillUuidConversionColumnInVulnerabilityOccurrences
20822:12:36 #perform
20922:12:56 backfills the uuid_convert_string_to_uuid column
21022:13:14 doesn't change the UUID for exisiting records
21122:13:17I, [2024-11-13T22:13:17.353700 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
21222:13:38I, [2024-11-13T22:13:38.876919 #342] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
21322:13:40INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
21422:13:40INFO: analyzing "public.ci_pipeline_variables"
21522:13:40INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
21622:13:40I, [2024-11-13T22:13:40.530570 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
21722:13:40I, [2024-11-13T22:13:40.531684 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
21822:13:40I, [2024-11-13T22:13:40.532694 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
21922:13:42INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
22022:13:42INFO: analyzing "public.ci_pipeline_variables"
22122:13:42INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22222:13:47INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
22322:13:47INFO: analyzing "public.ci_job_artifacts"
22422:13:47INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22522:13:47I, [2024-11-13T22:13:47.522509 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
22622:13:47I, [2024-11-13T22:13:47.523686 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
22722:13:47I, [2024-11-13T22:13:47.524561 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
22822:13:51INFO: analyzing "public.p_ci_stages" inheritance tree
22922:13:51INFO: analyzing "public.ci_stages"
23022:13:51INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23122:13:51I, [2024-11-13T22:13:51.207139 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
23222:13:51I, [2024-11-13T22:13:51.208469 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
23322:13:51I, [2024-11-13T22:13:51.209377 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
23422:13:52I, [2024-11-13T22:13:52.699512 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
23522:13:59I, [2024-11-13T22:13:59.627894 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
23622:14:14I, [2024-11-13T22:14:14.608578 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
23722:14:14I, [2024-11-13T22:14:14.609928 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
23822:14:14I, [2024-11-13T22:14:14.610831 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
23922:14:28I, [2024-11-13T22:14:28.086031 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
24022:14:35I, [2024-11-13T22:14:35.744043 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
24122:14:44I, [2024-11-13T22:14:44.117493 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
24222:14:46I, [2024-11-13T22:14:46.716370 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
24322:14:50INFO: analyzing "public.p_ci_pipelines" inheritance tree
24422:14:50INFO: analyzing "public.ci_pipelines"
24522:14:50INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24622:14:50I, [2024-11-13T22:14:50.670712 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
24722:14:50I, [2024-11-13T22:14:50.672087 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
24822:14:50I, [2024-11-13T22:14:50.672997 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
24922:14:56I, [2024-11-13T22:14:56.764843 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
25022:15:07I, [2024-11-13T22:15:07.989135 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
25122:15:07I, [2024-11-13T22:15:07.990549 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25222:15:07I, [2024-11-13T22:15:07.991511 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25322:15:07I, [2024-11-13T22:15:07.995800 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
25422:15:07I, [2024-11-13T22:15:07.997511 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25522:15:07I, [2024-11-13T22:15:07.998513 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25622:15:08I, [2024-11-13T22:15:08.002552 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
25722:15:08I, [2024-11-13T22:15:08.003922 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25822:15:08I, [2024-11-13T22:15:08.004802 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25922:15:08I, [2024-11-13T22:15:08.008901 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
26022:15:08I, [2024-11-13T22:15:08.010138 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26122:15:08I, [2024-11-13T22:15:08.011100 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26222:15:09I, [2024-11-13T22:15:09.194175 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
26322:15:09I, [2024-11-13T22:15:09.195470 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26422:15:09I, [2024-11-13T22:15:09.196360 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26522:15:09I, [2024-11-13T22:15:09.200095 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
26622:15:09I, [2024-11-13T22:15:09.201324 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26722:15:09I, [2024-11-13T22:15:09.202191 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26822:15:09I, [2024-11-13T22:15:09.205848 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
26922:15:09I, [2024-11-13T22:15:09.207012 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
27022:15:09I, [2024-11-13T22:15:09.207935 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
27122:15:09I, [2024-11-13T22:15:09.211684 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
27222:15:09I, [2024-11-13T22:15:09.212853 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
27322:15:09I, [2024-11-13T22:15:09.213678 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
27422:15:29# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_uuid_conversion_column_in_vulnerability_occurrences_spec.rb. It took 4 minutes 44.24 seconds. Expected to take 2 minutes 38.72 seconds.
27522:15:30# [RSpecRunTime] RSpec elapsed time: 4 minutes 52.01 seconds. Current RSS: ~1199M. Threads: 1. load average: 1.02 0.97 0.62 1/274 388
27622:15:30.
27722:15:30# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb. Expected to take 1 minute 55.9 seconds.
27822:15:30Gitlab::BackgroundMigration::BackfillUserPreferencesWithDefaults
27922:17:31 backfills the null values with the default values
28022:17:33I, [2024-11-13T22:17:33.631411 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
28122:17:55I, [2024-11-13T22:17:55.796091 #342] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
28222:17:57INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
28322:17:57INFO: analyzing "public.ci_pipeline_variables"
28422:17:57INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
28522:17:57I, [2024-11-13T22:17:57.575117 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
28622:17:57I, [2024-11-13T22:17:57.576341 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
28722:17:57I, [2024-11-13T22:17:57.577197 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
28822:17:59INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
28922:17:59INFO: analyzing "public.ci_pipeline_variables"
29022:17:59INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29122:18:04INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
29222:18:04INFO: analyzing "public.ci_job_artifacts"
29322:18:04INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29422:18:04I, [2024-11-13T22:18:04.540036 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
29522:18:04I, [2024-11-13T22:18:04.541489 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
29622:18:04I, [2024-11-13T22:18:04.542464 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
29722:18:08INFO: analyzing "public.p_ci_stages" inheritance tree
29822:18:08INFO: analyzing "public.ci_stages"
29922:18:08INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
30022:18:08I, [2024-11-13T22:18:08.342503 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
30122:18:08I, [2024-11-13T22:18:08.343726 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
30222:18:08I, [2024-11-13T22:18:08.344559 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
30322:18:09I, [2024-11-13T22:18:09.717001 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
30422:18:16I, [2024-11-13T22:18:16.705927 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
30522:18:31I, [2024-11-13T22:18:31.558020 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
30622:18:31I, [2024-11-13T22:18:31.559219 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
30722:18:31I, [2024-11-13T22:18:31.560540 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
30822:18:44I, [2024-11-13T22:18:44.869991 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
30922:18:53I, [2024-11-13T22:18:53.413156 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
31022:19:02I, [2024-11-13T22:19:02.740407 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
31122:19:05I, [2024-11-13T22:19:05.836625 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
31222:19:10INFO: analyzing "public.p_ci_pipelines" inheritance tree
31322:19:10INFO: analyzing "public.ci_pipelines"
31422:19:10INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
31522:19:10I, [2024-11-13T22:19:10.158962 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
31622:19:10I, [2024-11-13T22:19:10.160297 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
31722:19:10I, [2024-11-13T22:19:10.161136 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
31822:19:16I, [2024-11-13T22:19:16.633632 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
31922:19:28I, [2024-11-13T22:19:28.953297 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
32022:19:28I, [2024-11-13T22:19:28.954536 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32122:19:28I, [2024-11-13T22:19:28.955402 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
32222:19:28I, [2024-11-13T22:19:28.959155 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
32322:19:28I, [2024-11-13T22:19:28.960332 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32422:19:28I, [2024-11-13T22:19:28.961224 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
32522:19:28I, [2024-11-13T22:19:28.965404 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
32622:19:28I, [2024-11-13T22:19:28.966606 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32722:19:28I, [2024-11-13T22:19:28.967487 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
32822:19:28I, [2024-11-13T22:19:28.972264 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
32922:19:28I, [2024-11-13T22:19:28.973557 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33022:19:28I, [2024-11-13T22:19:28.974485 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33122:19:30I, [2024-11-13T22:19:30.188247 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
33222:19:30I, [2024-11-13T22:19:30.189649 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33322:19:30I, [2024-11-13T22:19:30.190689 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33422:19:30I, [2024-11-13T22:19:30.195171 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
33522:19:30I, [2024-11-13T22:19:30.196695 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33622:19:30I, [2024-11-13T22:19:30.197647 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33722:19:30I, [2024-11-13T22:19:30.201713 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
33822:19:30I, [2024-11-13T22:19:30.202995 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33922:19:30I, [2024-11-13T22:19:30.203940 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
34022:19:30I, [2024-11-13T22:19:30.208083 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
34122:19:30I, [2024-11-13T22:19:30.209302 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
34222:19:30I, [2024-11-13T22:19:30.210804 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
34322:19:51# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb. It took 4 minutes 21.73 seconds. Expected to take 1 minute 55.9 seconds.
34422:19:51# [RSpecRunTime] RSpec elapsed time: 9 minutes 14.07 seconds. Current RSS: ~1210M. Threads: 1. load average: 1.12 1.08 0.77 1/275 389
34522:19:51.
34622:19:51# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb. Expected to take 1 minute 37.54 seconds.
34722:19:51Gitlab::BackgroundMigration::BackfillBranchProtectionNamespaceSetting
34822:21:37 updates default_branch_protection_defaults to a correct value
34922:21:40I, [2024-11-13T22:21:40.648474 #342] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
35022:21:42INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
35122:21:42INFO: analyzing "public.ci_pipeline_variables"
35222:21:42INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
35322:21:42I, [2024-11-13T22:21:42.475399 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
35422:21:42I, [2024-11-13T22:21:42.476533 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
35522:21:42I, [2024-11-13T22:21:42.477342 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
35622:21:44INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
35722:21:44INFO: analyzing "public.ci_pipeline_variables"
35822:21:44INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
35922:21:49INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
36022:21:49INFO: analyzing "public.ci_job_artifacts"
36122:21:49INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
36222:21:49I, [2024-11-13T22:21:49.598110 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
36322:21:49I, [2024-11-13T22:21:49.599202 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
36422:21:49I, [2024-11-13T22:21:49.600031 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
36522:21:53INFO: analyzing "public.p_ci_stages" inheritance tree
36622:21:53INFO: analyzing "public.ci_stages"
36722:21:53INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
36822:21:53I, [2024-11-13T22:21:53.399343 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
36922:21:53I, [2024-11-13T22:21:53.401100 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
37022:21:53I, [2024-11-13T22:21:53.402453 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
37122:21:54I, [2024-11-13T22:21:54.748869 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
37222:22:01I, [2024-11-13T22:22:01.494706 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
37322:22:16I, [2024-11-13T22:22:16.434710 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
37422:22:16I, [2024-11-13T22:22:16.436222 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
37522:22:16I, [2024-11-13T22:22:16.437020 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
37622:22:29I, [2024-11-13T22:22:29.550430 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
37722:22:37I, [2024-11-13T22:22:37.166849 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
37822:22:45I, [2024-11-13T22:22:45.536168 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
37922:22:48I, [2024-11-13T22:22:48.239840 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
38022:22:52INFO: analyzing "public.p_ci_pipelines" inheritance tree
38122:22:52INFO: analyzing "public.ci_pipelines"
38222:22:52INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
38322:22:52I, [2024-11-13T22:22:52.323109 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
38422:22:52I, [2024-11-13T22:22:52.324317 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
38522:22:52I, [2024-11-13T22:22:52.325135 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
38622:22:58I, [2024-11-13T22:22:58.512217 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
38722:23:10I, [2024-11-13T22:23:10.150127 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
38822:23:10I, [2024-11-13T22:23:10.151223 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
38922:23:10I, [2024-11-13T22:23:10.152119 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39022:23:10I, [2024-11-13T22:23:10.155561 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
39122:23:10I, [2024-11-13T22:23:10.156695 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39222:23:10I, [2024-11-13T22:23:10.157501 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39322:23:10I, [2024-11-13T22:23:10.161102 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
39422:23:10I, [2024-11-13T22:23:10.162153 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39522:23:10I, [2024-11-13T22:23:10.163006 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39622:23:10I, [2024-11-13T22:23:10.166586 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
39722:23:10I, [2024-11-13T22:23:10.167737 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39822:23:10I, [2024-11-13T22:23:10.168618 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39922:23:11I, [2024-11-13T22:23:11.282251 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
40022:23:11I, [2024-11-13T22:23:11.283463 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
40122:23:11I, [2024-11-13T22:23:11.284305 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
40222:23:11I, [2024-11-13T22:23:11.288026 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
40322:23:11I, [2024-11-13T22:23:11.289268 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
40422:23:11I, [2024-11-13T22:23:11.290158 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
40522:23:11I, [2024-11-13T22:23:11.294040 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
40622:23:11I, [2024-11-13T22:23:11.295277 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
40722:23:11I, [2024-11-13T22:23:11.296184 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
40822:23:11I, [2024-11-13T22:23:11.300024 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
40922:23:11I, [2024-11-13T22:23:11.301206 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
41022:23:11I, [2024-11-13T22:23:11.302166 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
41122:23:31# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb. It took 3 minutes 39.42 seconds. Expected to take 1 minute 37.54 seconds.
41222:23:31# [RSpecRunTime] RSpec elapsed time: 12 minutes 53.53 seconds. Current RSS: ~1214M. Threads: 1. load average: 1.20 1.10 0.85 1/275 390
41322:23:31.
41422:23:31# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. Expected to take 1 minute 16.96 seconds.
41522:23:31Gitlab::BackgroundMigration::BackfillHasRemediationsOfVulnerabilityReads
41622:24:42 does not modify has_remediations of vulnerabilities which do not have remediations
41722:24:42 when finding_remediation record exists
41822:24:52 updates vulnerability_reads records which has remediations
41922:24:52# [RSpecRunTime] RSpec elapsed time: 14 minutes 14.49 seconds. Current RSS: ~1228M. Threads: 1. load average: 1.27 1.15 0.89 1/275 391
42022:24:52.
42122:24:57I, [2024-11-13T22:24:57.572024 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
42222:24:57I, [2024-11-13T22:24:57.573228 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
42322:24:57I, [2024-11-13T22:24:57.574056 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
42422:25:12I, [2024-11-13T22:25:12.036206 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
42522:25:20I, [2024-11-13T22:25:20.100311 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
42622:25:29I, [2024-11-13T22:25:29.091773 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
42722:25:31I, [2024-11-13T22:25:31.941429 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
42822:25:36INFO: analyzing "public.p_ci_pipelines" inheritance tree
42922:25:36INFO: analyzing "public.ci_pipelines"
43022:25:36INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
43122:25:36I, [2024-11-13T22:25:36.254934 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
43222:25:36I, [2024-11-13T22:25:36.256194 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
43322:25:36I, [2024-11-13T22:25:36.257079 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
43422:25:42I, [2024-11-13T22:25:42.744859 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
43522:25:54I, [2024-11-13T22:25:54.325863 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
43622:25:54I, [2024-11-13T22:25:54.327316 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
43722:25:54I, [2024-11-13T22:25:54.328347 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
43822:25:54I, [2024-11-13T22:25:54.332525 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
43922:25:54I, [2024-11-13T22:25:54.333857 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44022:25:54I, [2024-11-13T22:25:54.334835 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
44122:25:54I, [2024-11-13T22:25:54.338797 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
44222:25:54I, [2024-11-13T22:25:54.340150 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44322:25:54I, [2024-11-13T22:25:54.341128 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
44422:25:54I, [2024-11-13T22:25:54.345474 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
44522:25:54I, [2024-11-13T22:25:54.346712 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44622:25:54I, [2024-11-13T22:25:54.347683 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
44722:25:55I, [2024-11-13T22:25:55.487440 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
44822:25:55I, [2024-11-13T22:25:55.488721 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44922:25:55I, [2024-11-13T22:25:55.489591 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
45022:25:55I, [2024-11-13T22:25:55.493502 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
45122:25:55I, [2024-11-13T22:25:55.494678 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
45222:25:55I, [2024-11-13T22:25:55.495528 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
45322:25:55I, [2024-11-13T22:25:55.498932 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
45422:25:55I, [2024-11-13T22:25:55.500024 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
45522:25:55I, [2024-11-13T22:25:55.500844 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
45622:25:55I, [2024-11-13T22:25:55.504287 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
45722:25:55I, [2024-11-13T22:25:55.505406 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
45822:25:55I, [2024-11-13T22:25:55.506225 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
45922:26:14# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. It took 2 minutes 43.67 seconds. Expected to take 1 minute 16.96 seconds.
46022:26:15# [RSpecRunTime] RSpec elapsed time: 15 minutes 37.25 seconds. Current RSS: ~1206M. Threads: 1. load average: 1.00 1.10 0.91 1/275 392
46122:26:15.
46222:26:15# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_namespace_id_spec.rb. Expected to take 1 minute 14.1 seconds.
46322:26:15Gitlab::BackgroundMigration::BackfillDesignManagementRepositoriesNamespaceId
46422:27:22 constructs a valid query
46522:27:31 performs without error
46622:27:33I, [2024-11-13T22:27:33.646767 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
46722:27:33I, [2024-11-13T22:27:33.648109 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
46822:27:33I, [2024-11-13T22:27:33.648936 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
46922:27:48I, [2024-11-13T22:27:48.054324 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
47022:27:56I, [2024-11-13T22:27:56.573881 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
47122:28:05I, [2024-11-13T22:28:05.610830 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
47222:28:08I, [2024-11-13T22:28:08.579196 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
47322:28:12INFO: analyzing "public.p_ci_pipelines" inheritance tree
47422:28:12INFO: analyzing "public.ci_pipelines"
47522:28:12INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
47622:28:12I, [2024-11-13T22:28:12.700704 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
47722:28:12I, [2024-11-13T22:28:12.702251 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
47822:28:12I, [2024-11-13T22:28:12.703236 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
47922:28:19I, [2024-11-13T22:28:19.067240 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
48022:28:30I, [2024-11-13T22:28:30.595221 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
48122:28:30I, [2024-11-13T22:28:30.596500 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
48222:28:30I, [2024-11-13T22:28:30.597382 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
48322:28:30I, [2024-11-13T22:28:30.601250 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
48422:28:30I, [2024-11-13T22:28:30.602453 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
48522:28:30I, [2024-11-13T22:28:30.603312 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
48622:28:30I, [2024-11-13T22:28:30.606922 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
48722:28:30I, [2024-11-13T22:28:30.608138 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
48822:28:30I, [2024-11-13T22:28:30.608982 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
48922:28:30I, [2024-11-13T22:28:30.612386 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
49022:28:30I, [2024-11-13T22:28:30.613497 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
49122:28:30I, [2024-11-13T22:28:30.614298 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
49222:28:31I, [2024-11-13T22:28:31.784731 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
49322:28:31I, [2024-11-13T22:28:31.785930 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
49422:28:31I, [2024-11-13T22:28:31.787135 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
49522:28:31I, [2024-11-13T22:28:31.791043 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
49622:28:31I, [2024-11-13T22:28:31.792273 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
49722:28:31I, [2024-11-13T22:28:31.793160 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
49822:28:31I, [2024-11-13T22:28:31.796719 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
49922:28:31I, [2024-11-13T22:28:31.797849 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
50022:28:31I, [2024-11-13T22:28:31.798650 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
50122:28:31I, [2024-11-13T22:28:31.802269 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
50222:28:31I, [2024-11-13T22:28:31.803408 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
50322:28:31I, [2024-11-13T22:28:31.804671 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
50422:28:51# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_namespace_id_spec.rb. It took 2 minutes 35.99 seconds. Expected to take 1 minute 14.1 seconds.
50522:28:51# [RSpecRunTime] RSpec elapsed time: 18 minutes 13.29 seconds. Current RSS: ~1206M. Threads: 1. load average: 0.90 1.05 0.92 1/275 393
50622:28:51.
50722:28:51# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_operations_strategies_user_lists_project_id_spec.rb. Expected to take 1 minute 10.96 seconds.
50822:28:51Gitlab::BackgroundMigration::BackfillOperationsStrategiesUserListsProjectId
50922:29:53 constructs a valid query
51022:30:02 performs without error
51122:30:15I, [2024-11-13T22:30:15.138449 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
51222:30:22I, [2024-11-13T22:30:22.956298 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
51322:30:31I, [2024-11-13T22:30:31.609906 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
51422:30:34I, [2024-11-13T22:30:34.260582 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
51522:30:38INFO: analyzing "public.p_ci_pipelines" inheritance tree
51622:30:38INFO: analyzing "public.ci_pipelines"
51722:30:38INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
51822:30:38I, [2024-11-13T22:30:38.421675 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
51922:30:38I, [2024-11-13T22:30:38.422957 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52022:30:38I, [2024-11-13T22:30:38.423837 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52122:30:44I, [2024-11-13T22:30:44.709417 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
52222:30:56I, [2024-11-13T22:30:56.235717 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
52322:30:56I, [2024-11-13T22:30:56.237059 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52422:30:56I, [2024-11-13T22:30:56.237960 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52522:30:56I, [2024-11-13T22:30:56.241871 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
52622:30:56I, [2024-11-13T22:30:56.243117 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52722:30:56I, [2024-11-13T22:30:56.244012 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52822:30:56I, [2024-11-13T22:30:56.247734 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
52922:30:56I, [2024-11-13T22:30:56.248954 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53022:30:56I, [2024-11-13T22:30:56.249819 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53122:30:56I, [2024-11-13T22:30:56.253685 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
53222:30:56I, [2024-11-13T22:30:56.254903 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53322:30:56I, [2024-11-13T22:30:56.255767 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53422:30:57I, [2024-11-13T22:30:57.357371 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
53522:30:57I, [2024-11-13T22:30:57.358674 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53622:30:57I, [2024-11-13T22:30:57.359586 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53722:30:57I, [2024-11-13T22:30:57.363303 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
53822:30:57I, [2024-11-13T22:30:57.364484 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53922:30:57I, [2024-11-13T22:30:57.365361 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
54022:30:57I, [2024-11-13T22:30:57.369296 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
54122:30:57I, [2024-11-13T22:30:57.370457 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
54222:30:57I, [2024-11-13T22:30:57.371309 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
54322:30:57I, [2024-11-13T22:30:57.375110 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
54422:30:57I, [2024-11-13T22:30:57.376251 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
54522:30:57I, [2024-11-13T22:30:57.377117 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
54622:31:16# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_operations_strategies_user_lists_project_id_spec.rb. It took 2 minutes 25.12 seconds. Expected to take 1 minute 10.96 seconds.
54722:31:16# [RSpecRunTime] RSpec elapsed time: 20 minutes 38.49 seconds. Current RSS: ~1214M. Threads: 1. load average: 0.93 1.04 0.94 1/276 394
54822:31:16.
54922:31:16# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb. Expected to take 58.74 seconds.
55022:31:16Gitlab::BackgroundMigration::BackfillVulnerabilityFindingLinksProjectId
55122:31:58 performs without error
55222:32:04 constructs a valid query
55322:32:13I, [2024-11-13T22:32:13.279804 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
55422:32:16I, [2024-11-13T22:32:16.221867 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
55522:32:20INFO: analyzing "public.p_ci_pipelines" inheritance tree
55622:32:20INFO: analyzing "public.ci_pipelines"
55722:32:20INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
55822:32:20I, [2024-11-13T22:32:20.543413 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
55922:32:20I, [2024-11-13T22:32:20.544760 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56022:32:20I, [2024-11-13T22:32:20.545592 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56122:32:26I, [2024-11-13T22:32:26.970076 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
56222:32:38I, [2024-11-13T22:32:38.042938 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
56322:32:38I, [2024-11-13T22:32:38.044092 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56422:32:38I, [2024-11-13T22:32:38.044941 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56522:32:38I, [2024-11-13T22:32:38.048260 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
56622:32:38I, [2024-11-13T22:32:38.049351 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56722:32:38I, [2024-11-13T22:32:38.050157 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56822:32:38I, [2024-11-13T22:32:38.053594 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
56922:32:38I, [2024-11-13T22:32:38.054733 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57022:32:38I, [2024-11-13T22:32:38.055646 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
57122:32:38I, [2024-11-13T22:32:38.059330 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
57222:32:38I, [2024-11-13T22:32:38.060581 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57322:32:38I, [2024-11-13T22:32:38.061448 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
57422:32:39I, [2024-11-13T22:32:39.233508 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
57522:32:39I, [2024-11-13T22:32:39.234781 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57622:32:39I, [2024-11-13T22:32:39.236068 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
57722:32:39I, [2024-11-13T22:32:39.239725 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
57822:32:39I, [2024-11-13T22:32:39.240882 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57922:32:39I, [2024-11-13T22:32:39.241830 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
58022:32:39I, [2024-11-13T22:32:39.245374 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
58122:32:39I, [2024-11-13T22:32:39.246535 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
58222:32:39I, [2024-11-13T22:32:39.247388 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
58322:32:39I, [2024-11-13T22:32:39.250879 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
58422:32:39I, [2024-11-13T22:32:39.251969 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
58522:32:39I, [2024-11-13T22:32:39.252943 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
58622:32:57# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb. It took 1 minute 41.32 seconds. Expected to take 58.74 seconds.
58722:32:57# [RSpecRunTime] RSpec elapsed time: 22 minutes 19.85 seconds. Current RSS: ~1217M. Threads: 1. load average: 1.00 1.05 0.96 1/276 395
58822:32:57.
58922:32:57# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_merge_request_reviewers_project_id_spec.rb. Expected to take 57.59 seconds.
59022:32:57Gitlab::BackgroundMigration::BackfillMergeRequestReviewersProjectId
59122:33:47 performs without error
59222:33:54 constructs a valid query
59322:33:55I, [2024-11-13T22:33:55.775985 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
59422:34:03I, [2024-11-13T22:34:03.359334 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
59522:34:12I, [2024-11-13T22:34:12.162720 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
59622:34:14I, [2024-11-13T22:34:14.985018 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
59722:34:19INFO: analyzing "public.p_ci_pipelines" inheritance tree
59822:34:19INFO: analyzing "public.ci_pipelines"
59922:34:19INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
60022:34:19I, [2024-11-13T22:34:19.175365 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
60122:34:19I, [2024-11-13T22:34:19.176472 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
60222:34:19I, [2024-11-13T22:34:19.177220 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
60322:34:25I, [2024-11-13T22:34:25.534732 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
60422:34:36I, [2024-11-13T22:34:36.702032 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
60522:34:36I, [2024-11-13T22:34:36.703270 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
60622:34:36I, [2024-11-13T22:34:36.704174 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
60722:34:36I, [2024-11-13T22:34:36.708053 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
60822:34:36I, [2024-11-13T22:34:36.709254 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
60922:34:36I, [2024-11-13T22:34:36.710175 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61022:34:36I, [2024-11-13T22:34:36.713823 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
61122:34:36I, [2024-11-13T22:34:36.714901 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61222:34:36I, [2024-11-13T22:34:36.715703 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61322:34:36I, [2024-11-13T22:34:36.719148 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
61422:34:36I, [2024-11-13T22:34:36.720233 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61522:34:36I, [2024-11-13T22:34:36.721072 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61622:34:37I, [2024-11-13T22:34:37.842538 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
61722:34:37I, [2024-11-13T22:34:37.843852 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61822:34:37I, [2024-11-13T22:34:37.844781 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61922:34:37I, [2024-11-13T22:34:37.848499 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
62022:34:37I, [2024-11-13T22:34:37.849759 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
62122:34:37I, [2024-11-13T22:34:37.850927 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
62222:34:37I, [2024-11-13T22:34:37.854832 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
62322:34:37I, [2024-11-13T22:34:37.855970 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
62422:34:37I, [2024-11-13T22:34:37.856891 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
62522:34:37I, [2024-11-13T22:34:37.860843 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
62622:34:37I, [2024-11-13T22:34:37.862076 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
62722:34:37I, [2024-11-13T22:34:37.862980 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
62822:34:56# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_merge_request_reviewers_project_id_spec.rb. It took 1 minute 58.95 seconds. Expected to take 57.59 seconds.
62922:34:56# [RSpecRunTime] RSpec elapsed time: 24 minutes 18.84 seconds. Current RSS: ~1220M. Threads: 1. load average: 0.94 1.02 0.97 1/277 397
63022:34:56.
63122:34:56# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_protected_environment_approval_rules_protected_environment_group_id_spec.rb. Expected to take 45.83 seconds.
63222:34:56Gitlab::BackgroundMigration::BackfillProtectedEnvironmentApprovalRulesProtectedEnvironmentGroupId
63322:35:39 constructs a valid query
63422:35:45 performs without error
63522:35:52I, [2024-11-13T22:35:52.880554 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
63622:35:55I, [2024-11-13T22:35:55.697992 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
63722:35:59INFO: analyzing "public.p_ci_pipelines" inheritance tree
63822:35:59INFO: analyzing "public.ci_pipelines"
63922:35:59INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
64022:35:59I, [2024-11-13T22:35:59.986223 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
64122:35:59I, [2024-11-13T22:35:59.987461 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
64222:35:59I, [2024-11-13T22:35:59.988349 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
64322:36:06I, [2024-11-13T22:36:06.074575 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
64422:36:17I, [2024-11-13T22:36:17.540148 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
64522:36:17I, [2024-11-13T22:36:17.541288 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
64622:36:17I, [2024-11-13T22:36:17.542138 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
64722:36:17I, [2024-11-13T22:36:17.545433 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
64822:36:17I, [2024-11-13T22:36:17.546504 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
64922:36:17I, [2024-11-13T22:36:17.547283 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65022:36:17I, [2024-11-13T22:36:17.550403 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
65122:36:17I, [2024-11-13T22:36:17.551469 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
65222:36:17I, [2024-11-13T22:36:17.552704 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65322:36:17I, [2024-11-13T22:36:17.555899 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
65422:36:17I, [2024-11-13T22:36:17.557012 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
65522:36:17I, [2024-11-13T22:36:17.557819 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65622:36:18I, [2024-11-13T22:36:18.709695 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
65722:36:18I, [2024-11-13T22:36:18.711113 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
65822:36:18I, [2024-11-13T22:36:18.712088 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65922:36:18I, [2024-11-13T22:36:18.716524 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
66022:36:18I, [2024-11-13T22:36:18.717870 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66122:36:18I, [2024-11-13T22:36:18.718824 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66222:36:18I, [2024-11-13T22:36:18.723361 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
66322:36:18I, [2024-11-13T22:36:18.724831 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66422:36:18I, [2024-11-13T22:36:18.725863 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66522:36:18I, [2024-11-13T22:36:18.729854 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
66622:36:18I, [2024-11-13T22:36:18.730850 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66722:36:18I, [2024-11-13T22:36:18.731640 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66822:36:38# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_protected_environment_approval_rules_protected_environment_group_id_spec.rb. It took 1 minute 41.39 seconds. Expected to take 45.83 seconds.
66922:36:38# [RSpecRunTime] RSpec elapsed time: 26 minutes 0.3 second. Current RSS: ~1210M. Threads: 1. load average: 0.93 1.00 0.98 1/277 398
67022:36:38.
67122:36:38# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_project_id_spec.rb. Expected to take 42.11 seconds.
67222:36:38Gitlab::BackgroundMigration::BackfillProtectedEnvironmentDeployAccessLevelsProtectedEnvironmentProjectId
67322:37:11 performs without error
67422:37:17 constructs a valid query
67522:37:20I, [2024-11-13T22:37:20.009030 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
67622:37:24INFO: analyzing "public.p_ci_pipelines" inheritance tree
67722:37:24INFO: analyzing "public.ci_pipelines"
67822:37:24INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
67922:37:24I, [2024-11-13T22:37:24.144366 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
68022:37:24I, [2024-11-13T22:37:24.145852 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
68122:37:24I, [2024-11-13T22:37:24.146822 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
68222:37:30I, [2024-11-13T22:37:30.336904 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
68322:37:41I, [2024-11-13T22:37:41.029497 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
68422:37:41I, [2024-11-13T22:37:41.030700 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
68522:37:41I, [2024-11-13T22:37:41.031554 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
68622:37:41I, [2024-11-13T22:37:41.034872 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
68722:37:41I, [2024-11-13T22:37:41.035913 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
68822:37:41I, [2024-11-13T22:37:41.036689 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
68922:37:41I, [2024-11-13T22:37:41.039909 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
69022:37:41I, [2024-11-13T22:37:41.040955 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
69122:37:41I, [2024-11-13T22:37:41.041708 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
69222:37:41I, [2024-11-13T22:37:41.044903 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
69322:37:41I, [2024-11-13T22:37:41.046248 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
69422:37:41I, [2024-11-13T22:37:41.047029 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
69522:37:42I, [2024-11-13T22:37:42.120405 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
69622:37:42I, [2024-11-13T22:37:42.121622 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
69722:37:42I, [2024-11-13T22:37:42.122561 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
69822:37:42I, [2024-11-13T22:37:42.125967 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
69922:37:42I, [2024-11-13T22:37:42.127022 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70022:37:42I, [2024-11-13T22:37:42.127842 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
70122:37:42I, [2024-11-13T22:37:42.131231 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
70222:37:42I, [2024-11-13T22:37:42.132288 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70322:37:42I, [2024-11-13T22:37:42.133175 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
70422:37:42I, [2024-11-13T22:37:42.136896 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
70522:37:42I, [2024-11-13T22:37:42.138037 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70622:37:42I, [2024-11-13T22:37:42.139077 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
70722:38:00# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_project_id_spec.rb. It took 1 minute 22.14 seconds. Expected to take 42.11 seconds.
70822:38:00# [RSpecRunTime] RSpec elapsed time: 27 minutes 22.48 seconds. Current RSS: ~1212M. Threads: 1. load average: 0.98 1.00 0.99 1/277 399
70922:38:00.
71022:38:00# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_rpm_metadata_project_id_spec.rb. Expected to take 24.91 seconds.
71122:38:00Gitlab::BackgroundMigration::BackfillPackagesRpmMetadataProjectId
71222:38:18 performs without error
71322:38:23 constructs a valid query
71422:38:34I, [2024-11-13T22:38:34.023981 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
71522:38:34I, [2024-11-13T22:38:34.025091 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
71622:38:34I, [2024-11-13T22:38:34.025883 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
71722:38:34I, [2024-11-13T22:38:34.029787 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
71822:38:34I, [2024-11-13T22:38:34.030840 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
71922:38:34I, [2024-11-13T22:38:34.031595 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
72022:38:34I, [2024-11-13T22:38:34.034835 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
72122:38:34I, [2024-11-13T22:38:34.035901 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
72222:38:34I, [2024-11-13T22:38:34.036628 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
72322:38:34I, [2024-11-13T22:38:34.040089 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
72422:38:34I, [2024-11-13T22:38:34.041122 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
72522:38:34I, [2024-11-13T22:38:34.041882 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
72622:38:35I, [2024-11-13T22:38:35.112537 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
72722:38:35I, [2024-11-13T22:38:35.113856 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
72822:38:35I, [2024-11-13T22:38:35.114739 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
72922:38:35I, [2024-11-13T22:38:35.118345 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
73022:38:35I, [2024-11-13T22:38:35.119460 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
73122:38:35I, [2024-11-13T22:38:35.120297 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
73222:38:35I, [2024-11-13T22:38:35.124167 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
73322:38:35I, [2024-11-13T22:38:35.125304 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
73422:38:35I, [2024-11-13T22:38:35.126098 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
73522:38:35I, [2024-11-13T22:38:35.129495 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
73622:38:35I, [2024-11-13T22:38:35.130652 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
73722:38:35I, [2024-11-13T22:38:35.131460 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
73822:38:52# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_rpm_metadata_project_id_spec.rb. It took 52.53 seconds. Expected to take 24.91 seconds.
73922:38:52# [RSpecRunTime] RSpec elapsed time: 28 minutes 15.05 seconds. Current RSS: ~1215M. Threads: 1. load average: 0.92 0.98 0.98 1/278 400
74022:38:52.
74122:38:52# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_dependency_proxy_blob_states_group_id_spec.rb. Expected to take 17.37 seconds.
74222:38:52Gitlab::BackgroundMigration::BackfillDependencyProxyBlobStatesGroupId
74322:39:04 performs without error
74422:39:09 constructs a valid query
74522:39:10I, [2024-11-13T22:39:10.411144 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
74622:39:10I, [2024-11-13T22:39:10.412383 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
74722:39:10I, [2024-11-13T22:39:10.413296 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
74822:39:10I, [2024-11-13T22:39:10.416919 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
74922:39:10I, [2024-11-13T22:39:10.418111 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
75022:39:10I, [2024-11-13T22:39:10.418958 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
75122:39:10I, [2024-11-13T22:39:10.422594 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
75222:39:10I, [2024-11-13T22:39:10.423706 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
75322:39:10I, [2024-11-13T22:39:10.424548 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
75422:39:10I, [2024-11-13T22:39:10.428118 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
75522:39:10I, [2024-11-13T22:39:10.429262 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
75622:39:10I, [2024-11-13T22:39:10.430180 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
75722:39:11I, [2024-11-13T22:39:11.594825 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
75822:39:11I, [2024-11-13T22:39:11.596069 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
75922:39:11I, [2024-11-13T22:39:11.596923 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
76022:39:11I, [2024-11-13T22:39:11.600377 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
76122:39:11I, [2024-11-13T22:39:11.601859 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
76222:39:11I, [2024-11-13T22:39:11.602639 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
76322:39:11I, [2024-11-13T22:39:11.605935 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
76422:39:11I, [2024-11-13T22:39:11.607032 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
76522:39:11I, [2024-11-13T22:39:11.607892 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
76622:39:11I, [2024-11-13T22:39:11.611204 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
76722:39:11I, [2024-11-13T22:39:11.612269 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
76822:39:11I, [2024-11-13T22:39:11.613051 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
76922:39:29# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_dependency_proxy_blob_states_group_id_spec.rb. It took 36.53 seconds. Expected to take 17.37 seconds.
77022:39:29# [RSpecRunTime] RSpec elapsed time: 28 minutes 51.62 seconds. Current RSS: ~1218M. Threads: 1. load average: 1.02 1.00 0.99 1/278 401
77122:39:29.
77222:39:29# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/recover_deleted_ml_model_version_packages_spec.rb. Expected to take 14.5 seconds.
77322:39:29Gitlab::BackgroundMigration::RecoverDeletedMlModelVersionPackages
77422:39:37 creates packages for ml model versions without
77522:39:43 creates packages with correct values
77622:39:57# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/recover_deleted_ml_model_version_packages_spec.rb. It took 28.13 seconds. Expected to take 14.5 seconds.
77722:39:57# [RSpecRunTime] RSpec elapsed time: 29 minutes 19.79 seconds. Current RSS: ~1212M. Threads: 1. load average: 0.99 1.00 0.99 1/278 402
77822:39:57.
77922:39:57# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/resync_has_vulnerabilities_spec.rb. Expected to take 6.8 seconds.
78022:39:57Gitlab::BackgroundMigration::ResyncHasVulnerabilities
78122:40:04 fixes only the incorrect records
78222:40:15# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/resync_has_vulnerabilities_spec.rb. It took 17.52 seconds. Expected to take 6.8 seconds.
78322:40:15# [RSpecRunTime] RSpec elapsed time: 29 minutes 37.35 seconds. Current RSS: ~1216M. Threads: 1. load average: 1.00 1.00 1.00 1/278 403
78422:40:15.
78522:40:15# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb. Expected to take 6.13 seconds.
78622:40:15Gitlab::BackgroundMigration::UpdateUsersSetExternalIfServiceAccount
78722:40:15 #perform
78822:40:21 changes external field for service_account user
78922:40:21# [RSpecRunTime] RSpec elapsed time: 29 minutes 43.33 seconds. Current RSS: ~1224M. Threads: 1. load average: 1.00 1.00 1.00 1/278 404
79022:40:21.
79122:40:32# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb. It took 17.01 seconds. Expected to take 6.13 seconds.
79222:40:32# [RSpecRunTime] RSpec elapsed time: 29 minutes 54.4 seconds. Current RSS: ~1220M. Threads: 1. load average: 0.99 1.00 1.00 1/278 405
79322:40:32.
79422:41:04auto_explain log contains 1173 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-7-17.342.main.ndjson.gz
79522:41:04took 32.429062581
79622:41:37auto_explain log contains 1174 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-7-17.342.ci.ndjson.gz
79722:41:37took 30.783080713
79822:41:37[TEST PROF INFO] EventProf results for sql.active_record
79922:41:37Total time: 17:20.516 of 29:46.674 (58.24%)
80022:41:37Total events: 750297
80122:41:37Top 5 slowest suites (by time):
80222:41:37Gitlab::Backg...ityOccurrences (./spec/lib/gitlab/background_migration/backfill_uuid_conversion_column_in_vulnerability_occurrences_spec.rb:5) – 02:47.531 (118106 / 2) of 04:44.570 (58.87%)
80322:41:37Gitlab::Backg...esWithDefaults (./spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb:5) – 02:43.900 (115405 / 1) of 04:21.774 (62.61%)
80422:41:37Gitlab::Backg...mespaceSetting (./spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb:5) – 02:17.356 (98969 / 1) of 03:39.466 (62.59%)
80522:41:37Gitlab::Backg...erabilityReads (./spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb:5) – 01:35.009 (64649 / 2) of 02:43.714 (58.03%)
80622:41:37Gitlab::Backg...iesNamespaceId (./spec/lib/gitlab/background_migration/backfill_design_management_repositories_namespace_id_spec.rb:5) – 01:29.420 (59988 / 2) of 02:36.079 (57.29%)
80722:41:37Knapsack report was generated. Preview:
80822:41:37{
80922:41:37 "spec/lib/gitlab/background_migration/backfill_uuid_conversion_column_in_vulnerability_occurrences_spec.rb": 150.1769044270004,
81022:41:37 "spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb": 121.86819827300133,
81122:41:37 "spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb": 105.54466188199876,
81222:41:37 "spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb": 80.97554856200077,
81322:41:37 "spec/lib/gitlab/background_migration/backfill_design_management_repositories_namespace_id_spec.rb": 76.96551919599733,
81422:41:37 "spec/lib/gitlab/background_migration/backfill_operations_strategies_user_lists_project_id_spec.rb": 71.17526545799774,
81522:41:37 "spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb": 48.63004608299889,
81622:41:37 "spec/lib/gitlab/background_migration/backfill_merge_request_reviewers_project_id_spec.rb": 56.99224139600119,
81722:41:37 "spec/lib/gitlab/background_migration/backfill_protected_environment_approval_rules_protected_environment_group_id_spec.rb": 48.68310499299696,
81822:41:37 "spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_project_id_spec.rb": 39.40711088600074,
81922:41:37 "spec/lib/gitlab/background_migration/backfill_packages_rpm_metadata_project_id_spec.rb": 23.702910449999763,
82022:41:37 "spec/lib/gitlab/background_migration/backfill_dependency_proxy_blob_states_group_id_spec.rb": 16.65024156200161,
82122:41:37 "spec/lib/gitlab/background_migration/recover_deleted_ml_model_version_packages_spec.rb": 13.685895747999894,
82222:41:37 "spec/lib/gitlab/background_migration/resync_has_vulnerabilities_spec.rb": 6.621692180997343,
82322:41:37 "spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb": 5.996755393000058
82422:41:37}
82522:41:37Knapsack global time execution for tests: 14m 27s
82622:41:37Finished in 30 minutes 59 seconds (files took 52.98 seconds to load)
82722:41:3726 examples, 0 failures
82822:41:37Randomized with seed 27015
82922:41:42[TEST PROF INFO] Time spent in factories: 00:00.433 (0.02% of total time)
83022:41:42RSpec exited with 0.
83122:41:42No examples to retry, congrats!
832 22:41:43 Running after_script 00:21
83322:41:43Running after script...
83422:41:43$ source scripts/utils.sh
83522:41:43$ log_disk_usage
83622:41:43*******************************************************
83722:41:43This runner currently has 73G free disk space.
83822:41:43*******************************************************
839 22:41:43 Disk usage detail 00:15
89522:41:58$ bundle exec gem list gitlab_quality-test_tooling
89622:41:59gitlab_quality-test_tooling (2.1.0)
89722:41:59$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
898 22:41:59 Report test failures 00:00
90022:41:59$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
901 22:41:59 Report test flakiness 00:00
90322:41:59$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
904 22:41:59 Report test slowness 00:00
90622:41:59$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
907 22:41:59 Report test slowness in MR note 00:02
91022:42:01$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
911 22:42:01 Report test files close to timing out 00:02
91422:42:03$ tooling/bin/push_job_metrics || true
91522:42:04[job-metrics] Pushing job metrics file for the CI/CD job.
91622:42:04[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
917 22:42:04 Saving cache for successful job 00:02
91822:42:06Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20 due to policy
919 22:42:06 Uploading artifacts for successful job 00:06
92022:42:07Uploading artifacts...
92122:42:07auto_explain/: found 3 matching artifact files and directories
92222:42:07coverage/: found 5 matching artifact files and directories
92322:42:07crystalball/: found 2 matching artifact files and directories
92422:42:07WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
92522:42:07knapsack/: found 4 matching artifact files and directories
92622:42:07rspec/: found 16 matching artifact files and directories
92722:42:07WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
92822:42:07log/*.log: found 13 matching artifact files and directories
92922:42:08WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353287103/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
93022:42:08WARNING: Retrying... context=artifacts-uploader error=request redirected
93122:42:10Uploading artifacts as "archive" to coordinator... 201 Created id=8353287103 responseStatus=201 Created token=glcbt-66
93222:42:10Uploading artifacts...
93322:42:10rspec/rspec-*.xml: found 1 matching artifact files and directories
93422:42:10WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353287103/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
93522:42:10WARNING: Retrying... context=artifacts-uploader error=request redirected
93622:42:12Uploading artifacts as "junit" to coordinator... 201 Created id=8353287103 responseStatus=201 Created token=glcbt-66
937 22:42:12 Cleaning up project directory and file based variables 00:01
93822:42:24Job succeeded