Skip to content
Snippets Groups Projects

rspec background_migration pg14 8/10

Passed Started by
Eduardo Sanz García
@eduardosanz
Log timestamps in UTC.
117:44:28Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
217:44:28 on blue-2.shared-gitlab-org.runners-manager.gitlab.com/default NL4gfoBe, system ID: s_74c3e1316164
317:44:28 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
417:44:28Resolving secrets
5 17:44:28 Preparing the "docker+machine" executor 01:31
617:44:29Using 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 ...
717:44:31Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
817:44:31Authenticating with credentials from job payload (GitLab Registry)
917:44:31Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1017:44:38Using 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 ...
1117:44:42WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1217:44:42WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1317:44:42Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1417:44:42Authenticating with credentials from job payload (GitLab Registry)
1517:44:42Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1617:44:46Using 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 ...
1717:44:48Starting service redis:6.2-alpine...
1817:44:48Pulling docker image redis:6.2-alpine ...
1917:44:51Using docker image sha256:ec1b0a84ddf9124276ac189cc4d98ef28f0aea95ebd148d9e4c18b28928dd999 for redis:6.2-alpine with digest redis@sha256:2ba50e1ac3a0ea17b736ce9db2b0a9f6f8b85d4c27d5f5accc6a416d8f42c6d5 ...
2017:44:52Waiting for services to be up and running (timeout 30 seconds)...
2117:44:54Authenticating with credentials from job payload (GitLab Registry)
2217:44:54Pulling 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 ...
2317:45:59Using docker image sha256:31e981de8a825083695845b07ca34c01ce0f1c5b3e7d9e89e52e5b77c0df04a5 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:a5a9db043a920dcc296b68cfbed0958437128c3e391789aea0af2ac25d2a36db ...
24 17:45:59 Preparing environment 00:01
2517:46:00Running on runner-nl4gfobe-project-278964-concurrent-0 via runner-nl4gfobe-shared-gitlab-org-1731001267-4b58317d...
26 17:46:00 Getting source from Git repository 00:01
2717:46:00Skipping Git repository setup
2817:46:00Skipping Git checkout
2917:46:00Skipping Git submodules setup
30 17:46:01 Restoring cache 00:19
3117:46:01Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20...
3217:46:02Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/278964/ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20 ETag="7ab11bf81aafd8042bedf88f6f2e321b"
3317:46:14Successfully extracted cache
34 17:46:20 Downloading artifacts 00:51
3517:46:21Downloading artifacts for clone-gitlab-repo (8298975602)...
3617:46:25Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8298975602 responseStatus=200 OK token=glcbt-66
3717:46:25WARNING: Part of .git directory is on the list of files to extract
3817:46:25WARNING: This may introduce unexpected problems
3917:46:43Downloading artifacts for compile-test-assets (8298975678)...
4017:46:46Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8298975678 responseStatus=200 OK token=glcbt-66
4117:46:50Downloading artifacts for detect-tests (8298975687)...
4217:46:51Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8298975687 responseStatus=200 OK token=glcbt-66
4317:46:51Downloading artifacts for retrieve-tests-metadata (8298975696)...
4417:46:51Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8298975696 responseStatus=200 OK token=glcbt-66
4517:46:51Downloading artifacts for setup-test-env (8298975682)...
4617:46:57Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8298975682 responseStatus=200 OK token=glcbt-66
47 17:47:11 Executing "step_script" stage of the job script
4817:47:11Using docker image sha256:31e981de8a825083695845b07ca34c01ce0f1c5b3e7d9e89e52e5b77c0df04a5 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:a5a9db043a920dcc296b68cfbed0958437128c3e391789aea0af2ac25d2a36db ...
4917:47:12$ echo $FOSS_ONLY
5017:47:12$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
5117:47:12$ export GOPATH=$CI_PROJECT_DIR/.go
5217:47:12$ mkdir -p $GOPATH
5317:47:12$ source scripts/utils.sh
5417:47:12$ log_disk_usage "true"
5517:47:12*******************************************************
5617:47:12This runner currently has 28G free disk space.
5717:47:12*******************************************************
58 17:47:12 Disk usage detail 00:06
5917:47:12df -h
6017:47:12Filesystem Size Used Avail Use% Mounted on
6117:47:12overlay 46G 18G 28G 40% /
6217:47:12tmpfs 64M 0 64M 0% /dev
6317:47:12shm 256M 0 256M 0% /dev/shm
6417:47:12/dev/sda1 46G 18G 28G 40% /cache
6517:47:12tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6617:47:12tmpfs 3.9G 0 3.9G 0% /proc/acpi
6717:47:12tmpfs 3.9G 0 3.9G 0% /proc/scsi
6817:47:12tmpfs 3.9G 0 3.9G 0% /sys/firmware
6917:47:12du -h -d 1
7017:47:127.4M ./workhorse
7117:47:12148K ./bin
7217:47:121.2M ./.gitlab
7317:47:12176M ./.git
7417:47:124.0K ./builds
7517:47:1228M ./lib
7617:47:128.0K ./.vscode
7717:47:12560K ./storybook
7817:47:1220K ./log
7917:47:121.8M ./data
8017:47:1211M ./qa
8117:47:123.2M ./.rubocop_todo
8217:47:12817M ./vendor
8317:47:12681M ./public
8417:47:1260M ./doc
8517:47:12472K ./danger
8617:47:1240K ./rspec
8717:47:12548K ./tooling
8817:47:13145M ./ee
8917:47:131.3M ./knapsack
9017:47:13300K ./patches
9117:47:134.3M ./changelogs
9217:47:1320K ./haml_lint
9317:47:1328K ./metrics_server
9417:47:1396K ./keeps
9517:47:1336K ./shared
9617:47:1344K ./generator_templates
9717:47:131.3M ./scripts
9817:47:13764M ./tmp
9917:47:13127M ./spec
10017:47:1320K ./file_hooks
10117:47:1332K ./crystalball
10217:47:1316K ./sidekiq_cluster
10317:47:1317M ./gems
10417:47:131.2M ./fixtures
10517:47:13968K ./rubocop
10617:47:134.0K ./.go
10717:47:1332M ./db
10817:47:1312K ./.github
10917:47:13129M ./locale
11017:47:1320M ./config
11117:47:1381M ./app
11217:47:1320K ./.lefthook
11317:47:133.1G .
11417:47:13$ source scripts/prepare_build.sh
115 17:47:13 Installing gems 00:26
14617:47:39Using decomposed database config (config/database.yml.decomposed-postgresql)
14717:47:39Geo DB won't be set up.
14817:47:39Embedding DB won't be set up.
149 17:47:39 Setting up DBs 01:51
16217:49:30$ source ./scripts/rspec_helpers.sh
16317:49:30$ run_timed_command "gem install knapsack --no-document"
16417:49:29$ gem install knapsack --no-document
16517:49:31Successfully installed knapsack-4.0.0
16617:49:311 gem installed
16717:49:31$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
16817:49:30==> 'gem install knapsack --no-document' succeeded in 1 seconds.
169 17:49:31 Spawning Gitaly 00:06
17317:49:37$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
17417:49:37$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
17517:49:37$ tooling/bin/create_job_metrics_file || true
17617:49:41[job-metrics] Creating the job metrics file for the CI/CD job.
17717:49:41$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
178 17:49:41 RSpec 59:22
17917:49:41[17:49:41] Starting rspec_parallelized_job
18017:49:31RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
18117:49:41KNAPSACK_GENERATE_REPORT: true
18217:49:41FLAKY_RSPEC_GENERATE_REPORT: true
18317:49:41KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
18417:49:41KNAPSACK_LOG_LEVEL: debug
18517:49:41KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_8_10_278964_report.json
18617:49:41FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
18717:49:41FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_8_10_278964_report.json
18817:49:41NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_8_10_278964_report.json
18917:49:41RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8298976153.txt
19017:49:41CRYSTALBALL:
19117:49:41RSPEC_TESTS_MAPPING_ENABLED:
19217:49:41RSPEC_TESTS_FILTER_FILE:
19317:49:41Shell set options (set -o) enabled:
19417:49:41braceexpand on
19517:49:41hashall on
19617:49:41interactive-comments on
19717:49:41pipefail on
19817:49:49Knapsack report generator started!
19917:49:41/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!
20017:51:02DEPRECATION 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)
20117:51:16warning: parser/current is loading parser/ruby32, which recognizes 3.2.6-compliant syntax, but you are running 3.2.5.
20217:51:16Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
20317:51:22Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
20417:51:22# [RSpecRunTime] Starting RSpec timer...
20517:51:22[TEST PROF INFO] EventProf enabled (sql.active_record)
20617:51:22unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20717:51:23unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20817:51:35Test environment set up in 3.324118277 seconds
20917:51:36# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/set_legacy_open_source_license_available_for_non_public_projects_spec.rb. Expected to take 2 minutes 49.93 seconds.
21017:51:36Gitlab::BackgroundMigration::SetLegacyOpenSourceLicenseAvailableForNonPublicProjects
21117:54:21 sets `legacy_open_source_license_available` attribute to false for non-public projects
21217:54:23I, [2024-11-07T17:54:23.888116 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
21317:54:50I, [2024-11-07T17:54:50.216396 #342] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
21417:54:52INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
21517:54:52INFO: analyzing "public.ci_pipeline_variables"
21617:54:52INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
21717:54:52I, [2024-11-07T17:54:52.193605 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
21817:54:52I, [2024-11-07T17:54:52.195018 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
21917:54:52I, [2024-11-07T17:54:52.196192 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
22017:54:54INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
22117:54:54INFO: analyzing "public.ci_pipeline_variables"
22217:54:54INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22317:55:00INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
22417:55:00INFO: analyzing "public.ci_job_artifacts"
22517:55:00INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22617:55:00I, [2024-11-07T17:55:00.629762 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
22717:55:00I, [2024-11-07T17:55:00.631503 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
22817:55:00I, [2024-11-07T17:55:00.632606 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
22917:55:05INFO: analyzing "public.p_ci_stages" inheritance tree
23017:55:05INFO: analyzing "public.ci_stages"
23117:55:05INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23217:55:05I, [2024-11-07T17:55:05.115536 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
23317:55:05I, [2024-11-07T17:55:05.117079 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
23417:55:05I, [2024-11-07T17:55:05.118093 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
23517:55:06I, [2024-11-07T17:55:06.888542 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
23617:55:15I, [2024-11-07T17:55:15.325190 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
23717:55:33I, [2024-11-07T17:55:33.385928 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
23817:55:33I, [2024-11-07T17:55:33.387681 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
23917:55:33I, [2024-11-07T17:55:33.388683 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
24017:55:49I, [2024-11-07T17:55:49.789947 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
24117:55:59I, [2024-11-07T17:55:59.475761 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
24217:56:10I, [2024-11-07T17:56:10.446978 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
24317:56:13I, [2024-11-07T17:56:13.919303 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
24417:56:18INFO: analyzing "public.p_ci_pipelines" inheritance tree
24517:56:18INFO: analyzing "public.ci_pipelines"
24617:56:18INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24717:56:18I, [2024-11-07T17:56:18.867874 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
24817:56:18I, [2024-11-07T17:56:18.869414 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
24917:56:18I, [2024-11-07T17:56:18.870549 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25017:56:27I, [2024-11-07T17:56:27.060680 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
25117:56:41I, [2024-11-07T17:56:41.118799 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
25217:56:41I, [2024-11-07T17:56:41.120452 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25317:56:41I, [2024-11-07T17:56:41.121543 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25417:56:41I, [2024-11-07T17:56:41.126090 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
25517:56:41I, [2024-11-07T17:56:41.127542 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25617:56:41I, [2024-11-07T17:56:41.128583 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25717:56:41I, [2024-11-07T17:56:41.133127 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
25817:56:41I, [2024-11-07T17:56:41.134509 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25917:56:41I, [2024-11-07T17:56:41.135614 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26017:56:41I, [2024-11-07T17:56:41.141778 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
26117:56:41I, [2024-11-07T17:56:41.143579 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26217:56:41I, [2024-11-07T17:56:41.144706 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26317:56:42I, [2024-11-07T17:56:42.364077 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
26417:56:42I, [2024-11-07T17:56:42.365745 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26517:56:42I, [2024-11-07T17:56:42.366746 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26617:56:42I, [2024-11-07T17:56:42.371204 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
26717:56:42I, [2024-11-07T17:56:42.372573 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26817:56:42I, [2024-11-07T17:56:42.373567 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26917:56:42I, [2024-11-07T17:56:42.377819 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
27017:56:42I, [2024-11-07T17:56:42.379308 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
27117:56:42I, [2024-11-07T17:56:42.380368 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
27217:56:42I, [2024-11-07T17:56:42.384716 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
27317:56:42I, [2024-11-07T17:56:42.386165 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
27417:56:42I, [2024-11-07T17:56:42.387709 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
27517:57:04# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/set_legacy_open_source_license_available_for_non_public_projects_spec.rb. It took 5 minutes 28.1 seconds. Expected to take 2 minutes 49.93 seconds.
27617:57:04# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb. Expected to take 2 minutes 26.48 seconds.
27717:57:04Gitlab::BackgroundMigration::BackfillNugetNormalizedVersion
27817:59:28 executes 5 queries and updates the normalized_version column
27917:59:30I, [2024-11-07T17:59:30.705877 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
28017:59:57I, [2024-11-07T17:59:57.001841 #342] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
28117:59:59INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
28217:59:59INFO: analyzing "public.ci_pipeline_variables"
28317:59: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
28417:59:59I, [2024-11-07T17:59:59.069928 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
28517:59:59I, [2024-11-07T17:59:59.071549 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
28617:59:59I, [2024-11-07T17:59:59.072557 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
28718:00:01INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
28818:00:01INFO: analyzing "public.ci_pipeline_variables"
28918:00:01INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29018:00:07INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
29118:00:07INFO: analyzing "public.ci_job_artifacts"
29218:00:07INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29318:00:07I, [2024-11-07T18:00:07.568708 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
29418:00:07I, [2024-11-07T18:00:07.570603 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
29518:00:07I, [2024-11-07T18:00:07.571711 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
29618:00:11INFO: analyzing "public.p_ci_stages" inheritance tree
29718:00:11INFO: analyzing "public.ci_stages"
29818:00:11INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29918:00:11I, [2024-11-07T18:00:11.906459 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
30018:00:11I, [2024-11-07T18:00:11.907911 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
30118:00:11I, [2024-11-07T18:00:11.908960 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
30218:00:13I, [2024-11-07T18:00:13.566708 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
30318:00:21I, [2024-11-07T18:00:21.496334 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
30418:00:38I, [2024-11-07T18:00:38.450767 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
30518:00:38I, [2024-11-07T18:00:38.452909 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
30618:00:38I, [2024-11-07T18:00:38.453855 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
30718:00:53I, [2024-11-07T18:00:53.645542 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
30818:01:02I, [2024-11-07T18:01:02.521250 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
30918:01:12I, [2024-11-07T18:01:12.649335 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
31018:01:15I, [2024-11-07T18:01:15.878052 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
31118:01:20INFO: analyzing "public.p_ci_pipelines" inheritance tree
31218:01:20INFO: analyzing "public.ci_pipelines"
31318:01:20INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
31418:01:20I, [2024-11-07T18:01:20.513435 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
31518:01:20I, [2024-11-07T18:01:20.514780 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
31618:01:20I, [2024-11-07T18:01:20.515836 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
31718:01:27I, [2024-11-07T18:01:27.872850 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
31818:01:40I, [2024-11-07T18:01:40.602731 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
31918:01:40I, [2024-11-07T18:01:40.604716 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32018:01:40I, [2024-11-07T18:01:40.605855 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
32118:01:40I, [2024-11-07T18:01:40.611001 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
32218:01:40I, [2024-11-07T18:01:40.612478 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32318:01:40I, [2024-11-07T18:01:40.613466 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
32418:01:40I, [2024-11-07T18:01:40.617541 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
32518:01:40I, [2024-11-07T18:01:40.618775 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32618:01:40I, [2024-11-07T18:01:40.619668 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
32718:01:40I, [2024-11-07T18:01:40.624267 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
32818:01:40I, [2024-11-07T18:01:40.625452 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32918:01:40I, [2024-11-07T18:01:40.626471 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33018:01:41I, [2024-11-07T18:01:41.771732 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
33118:01:41I, [2024-11-07T18:01:41.773340 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33218:01:41I, [2024-11-07T18:01:41.774458 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33318:01:41I, [2024-11-07T18:01:41.778843 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
33418:01:41I, [2024-11-07T18:01:41.780284 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33518:01:41I, [2024-11-07T18:01:41.781270 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33618:01:41I, [2024-11-07T18:01:41.785610 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
33718:01:41I, [2024-11-07T18:01:41.786858 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33818:01:41I, [2024-11-07T18:01:41.787777 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33918:01:41I, [2024-11-07T18:01:41.791623 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
34018:01:41I, [2024-11-07T18:01:41.792870 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
34118:01:41I, [2024-11-07T18:01:41.793853 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
34218:02:03# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb. It took 4 minutes 58.39 seconds. Expected to take 2 minutes 26.48 seconds.
34318:02:03# [RSpecRunTime] RSpec elapsed time: 10 minutes 40.15 seconds. Current RSS: ~1228M. Threads: 1. load average: 1.01 1.10 1.01 2/268 389
34418:02:03.
34518:02:03# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. Expected to take 2 minutes 8.54 seconds.
34618:02:03Gitlab::BackgroundMigration::BackfillDefaultBranchProtectionNamespaceSetting
34718:04:40 updates default_branch_protection_defaults to a correct value
34818:04:42I, [2024-11-07T18:04:42.038726 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
34918:05:10I, [2024-11-07T18:05:10.032767 #342] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
35018:05:12INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
35118:05:12INFO: analyzing "public.ci_pipeline_variables"
35218:05:12INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
35318:05:12I, [2024-11-07T18:05:12.307958 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
35418:05:12I, [2024-11-07T18:05:12.309495 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
35518:05:12I, [2024-11-07T18:05:12.310528 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
35618:05:15INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
35718:05:15INFO: analyzing "public.ci_pipeline_variables"
35818:05:15INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
35918:05:21INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
36018:05:21INFO: analyzing "public.ci_job_artifacts"
36118:05:21INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
36218:05:21I, [2024-11-07T18:05:21.177201 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
36318:05:21I, [2024-11-07T18:05:21.178969 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
36418:05:21I, [2024-11-07T18:05:21.180166 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
36518:05:25INFO: analyzing "public.p_ci_stages" inheritance tree
36618:05:25INFO: analyzing "public.ci_stages"
36718:05:25INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
36818:05:25I, [2024-11-07T18:05:25.887571 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
36918:05:25I, [2024-11-07T18:05:25.888985 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
37018:05:25I, [2024-11-07T18:05:25.890028 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
37118:05:27I, [2024-11-07T18:05:27.812809 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
37218:05:36I, [2024-11-07T18:05:36.710113 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
37318:05:53I, [2024-11-07T18:05:53.948605 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
37418:05:53I, [2024-11-07T18:05:53.950013 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
37518:05:53I, [2024-11-07T18:05:53.950912 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
37618:06:10I, [2024-11-07T18:06:10.141395 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
37718:06:19I, [2024-11-07T18:06:19.622451 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
37818:06:29I, [2024-11-07T18:06:29.607147 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
37918:06:33I, [2024-11-07T18:06:33.006604 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
38018:06:37INFO: analyzing "public.p_ci_pipelines" inheritance tree
38118:06:37INFO: analyzing "public.ci_pipelines"
38218:06:37INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
38318:06:37I, [2024-11-07T18:06:37.673555 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
38418:06:37I, [2024-11-07T18:06:37.675768 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
38518:06:37I, [2024-11-07T18:06:37.676775 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
38618:06:45I, [2024-11-07T18:06:45.251589 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
38718:06:58I, [2024-11-07T18:06:58.992248 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
38818:06:58I, [2024-11-07T18:06:58.993642 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
38918:06:58I, [2024-11-07T18:06:58.994649 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39018:06:58I, [2024-11-07T18:06:58.998825 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
39118:06:59I, [2024-11-07T18:06:59.000923 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39218:06:59I, [2024-11-07T18:06:59.001908 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39318:06:59I, [2024-11-07T18:06:59.006169 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
39418:06:59I, [2024-11-07T18:06:59.007517 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39518:06:59I, [2024-11-07T18:06:59.008544 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39618:06:59I, [2024-11-07T18:06:59.012800 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
39718:06:59I, [2024-11-07T18:06:59.014032 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39818:06:59I, [2024-11-07T18:06:59.014937 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39918:07:00I, [2024-11-07T18:07:00.188238 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
40018:07:00I, [2024-11-07T18:07:00.189720 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
40118:07:00I, [2024-11-07T18:07:00.190715 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
40218:07:00I, [2024-11-07T18:07:00.194789 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
40318:07:00I, [2024-11-07T18:07:00.196150 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
40418:07:00I, [2024-11-07T18:07:00.197050 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
40518:07:00I, [2024-11-07T18:07:00.200787 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
40618:07:00I, [2024-11-07T18:07:00.202301 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
40718:07:00I, [2024-11-07T18:07:00.203199 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
40818:07:00I, [2024-11-07T18:07:00.207129 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
40918:07:00I, [2024-11-07T18:07:00.208371 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
41018:07:00I, [2024-11-07T18:07:00.209395 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
41118:07:21# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. It took 5 minutes 17.78 seconds. Expected to take 2 minutes 8.54 seconds.
41218:07:21# [RSpecRunTime] RSpec elapsed time: 15 minutes 58.4 seconds. Current RSS: ~1235M. Threads: 1. load average: 0.98 1.09 1.03 1/264 390
41318:07:21.
41418:07:21# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_default_organization_owners_spec.rb. Expected to take 1 minute 48.49 seconds.
41518:07:21Gitlab::BackgroundMigration::BackfillDefaultOrganizationOwners
41618:09:06 #perform
41718:09:23 runs without error for no-op
41818:09:23# [RSpecRunTime] RSpec elapsed time: 18 minutes 0.93 second. Current RSS: ~1262M. Threads: 1. load average: 1.08 1.08 1.03 1/265 391
41918:09:23.
42018:09:26INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
42118:09:26INFO: analyzing "public.ci_pipeline_variables"
42218:09:26INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
42318:09:26I, [2024-11-07T18:09:26.214398 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
42418:09:26I, [2024-11-07T18:09:26.215882 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
42518:09:26I, [2024-11-07T18:09:26.216862 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
42618:09:28INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
42718:09:28INFO: analyzing "public.ci_pipeline_variables"
42818:09:28INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
42918:09:34INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
43018:09:34INFO: analyzing "public.ci_job_artifacts"
43118:09:34INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
43218:09:34I, [2024-11-07T18:09:34.547189 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
43318:09:34I, [2024-11-07T18:09:34.548509 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
43418:09:34I, [2024-11-07T18:09:34.549424 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
43518:09:38INFO: analyzing "public.p_ci_stages" inheritance tree
43618:09:38INFO: analyzing "public.ci_stages"
43718:09:38INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
43818:09:38I, [2024-11-07T18:09:38.918299 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
43918:09:38I, [2024-11-07T18:09:38.920000 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44018:09:38I, [2024-11-07T18:09:38.921171 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
44118:09:40I, [2024-11-07T18:09:40.624863 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
44218:09:48I, [2024-11-07T18:09:48.906213 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
44318:10:06I, [2024-11-07T18:10:06.853681 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
44418:10:06I, [2024-11-07T18:10:06.855079 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44518:10:06I, [2024-11-07T18:10:06.856050 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
44618:10:22I, [2024-11-07T18:10:22.763982 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
44718:10:32I, [2024-11-07T18:10:32.214238 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
44818:10:42I, [2024-11-07T18:10:42.769944 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
44918:10:45I, [2024-11-07T18:10:45.997911 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
45018:10:50INFO: analyzing "public.p_ci_pipelines" inheritance tree
45118:10:50INFO: analyzing "public.ci_pipelines"
45218:10:50INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
45318:10:50I, [2024-11-07T18:10:50.880682 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
45418:10:50I, [2024-11-07T18:10:50.881946 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
45518:10:50I, [2024-11-07T18:10:50.882873 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
45618:10:58I, [2024-11-07T18:10:58.615312 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
45718:11:13I, [2024-11-07T18:11:13.031215 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
45818:11:13I, [2024-11-07T18:11:13.032646 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
45918:11:13I, [2024-11-07T18:11:13.033619 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
46018:11:13I, [2024-11-07T18:11:13.037823 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
46118:11:13I, [2024-11-07T18:11:13.039221 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
46218:11:13I, [2024-11-07T18:11:13.040175 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
46318:11:13I, [2024-11-07T18:11:13.044885 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
46418:11:13I, [2024-11-07T18:11:13.046176 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
46518:11:13I, [2024-11-07T18:11:13.047070 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
46618:11:13I, [2024-11-07T18:11:13.051026 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
46718:11:13I, [2024-11-07T18:11:13.052269 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
46818:11:13I, [2024-11-07T18:11:13.053137 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
46918:11:14I, [2024-11-07T18:11:14.309297 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
47018:11:14I, [2024-11-07T18:11:14.312328 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
47118:11:14I, [2024-11-07T18:11:14.313633 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
47218:11:14I, [2024-11-07T18:11:14.318917 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
47318:11:14I, [2024-11-07T18:11:14.320688 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
47418:11:14I, [2024-11-07T18:11:14.321804 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
47518:11:14I, [2024-11-07T18:11:14.326331 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
47618:11:14I, [2024-11-07T18:11:14.327706 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
47718:11:14I, [2024-11-07T18:11:14.329021 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
47818:11:14I, [2024-11-07T18:11:14.333423 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
47918:11:14I, [2024-11-07T18:11:14.334765 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
48018:11:14I, [2024-11-07T18:11:14.335769 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
48118:11:37# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_default_organization_owners_spec.rb. It took 4 minutes 15.67 seconds. Expected to take 1 minute 48.49 seconds.
48218:11:37# [RSpecRunTime] RSpec elapsed time: 20 minutes 14.13 seconds. Current RSS: ~1241M. Threads: 1. load average: 0.91 0.99 1.00 1/266 392
48318:11:37.
48418:11:37# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. Expected to take 1 minute 44.03 seconds.
48518:11:37Gitlab::BackgroundMigration::DropVulnerabilitiesWithoutFindingId
48618:13:13 #perform
48718:13:29 removes all Vulnerabilities without a finding_id
48818:13:29# [RSpecRunTime] RSpec elapsed time: 22 minutes 6.57 seconds. Current RSS: ~1261M. Threads: 1. load average: 1.22 1.11 1.04 1/266 393
48918:13:29.
49018:13:33INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
49118:13:33INFO: analyzing "public.ci_job_artifacts"
49218:13:33INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
49318:13:33I, [2024-11-07T18:13:33.125470 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
49418:13:33I, [2024-11-07T18:13:33.126964 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
49518:13:33I, [2024-11-07T18:13:33.128064 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
49618:13:37INFO: analyzing "public.p_ci_stages" inheritance tree
49718:13:37INFO: analyzing "public.ci_stages"
49818:13:37INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
49918:13:37I, [2024-11-07T18:13:37.281336 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
50018:13:37I, [2024-11-07T18:13:37.282610 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
50118:13:37I, [2024-11-07T18:13:37.283505 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
50218:13:38I, [2024-11-07T18:13:38.695829 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
50318:13:45I, [2024-11-07T18:13:45.841705 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
50418:14:01I, [2024-11-07T18:14:01.772987 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
50518:14:01I, [2024-11-07T18:14:01.774241 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
50618:14:01I, [2024-11-07T18:14:01.775063 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
50718:14:15I, [2024-11-07T18:14:15.861439 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
50818:14:24I, [2024-11-07T18:14:24.218902 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
50918:14:33I, [2024-11-07T18:14:33.620563 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
51018:14:36I, [2024-11-07T18:14:36.640062 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
51118:14:41INFO: analyzing "public.p_ci_pipelines" inheritance tree
51218:14:41INFO: analyzing "public.ci_pipelines"
51318:14:41INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
51418:14:41I, [2024-11-07T18:14:41.037716 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
51518:14:41I, [2024-11-07T18:14:41.038929 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
51618:14:41I, [2024-11-07T18:14:41.039782 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
51718:14:47I, [2024-11-07T18:14:47.711792 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
51818:14:59I, [2024-11-07T18:14:59.823088 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
51918:14:59I, [2024-11-07T18:14:59.824433 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52018:14:59I, [2024-11-07T18:14:59.825313 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52118:14:59I, [2024-11-07T18:14:59.828927 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
52218:14:59I, [2024-11-07T18:14:59.830149 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52318:14:59I, [2024-11-07T18:14:59.831001 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52418:14:59I, [2024-11-07T18:14:59.834867 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
52518:14:59I, [2024-11-07T18:14:59.836198 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52618:14:59I, [2024-11-07T18:14:59.837081 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52718:14:59I, [2024-11-07T18:14:59.840659 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
52818:14:59I, [2024-11-07T18:14:59.841832 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52918:14:59I, [2024-11-07T18:14:59.842766 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53018:15:00I, [2024-11-07T18:15:00.975259 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
53118:15:00I, [2024-11-07T18:15:00.976507 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53218:15:00I, [2024-11-07T18:15:00.977338 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53318:15:00I, [2024-11-07T18:15:00.980848 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
53418:15:00I, [2024-11-07T18:15:00.981986 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53518:15:00I, [2024-11-07T18:15:00.982816 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53618:15:00I, [2024-11-07T18:15:00.986341 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
53718:15:00I, [2024-11-07T18:15:00.987495 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53818:15:00I, [2024-11-07T18:15:00.988300 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53918:15:00I, [2024-11-07T18:15:00.991815 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
54018:15:00I, [2024-11-07T18:15:00.993527 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
54118:15:00I, [2024-11-07T18:15:00.994315 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
54218:15:20# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. It took 3 minutes 43.46 seconds. Expected to take 1 minute 44.03 seconds.
54318:15:20# [RSpecRunTime] RSpec elapsed time: 23 minutes 57.64 seconds. Current RSS: ~1227M. Threads: 1. load average: 1.02 1.07 1.03 1/266 394
54418:15:20.
54518:15:20# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_merge_request_assignment_events_project_id_spec.rb. Expected to take 1 minute 30.89 seconds.
54618:15:20Gitlab::BackgroundMigration::BackfillMergeRequestAssignmentEventsProjectId
54718:16:30 constructs a valid query
54818:16:40 performs without error
54918:16:54I, [2024-11-07T18:16:54.961229 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
55018:17:03I, [2024-11-07T18:17:03.648750 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
55118:17:13I, [2024-11-07T18:17:13.150411 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
55218:17:16I, [2024-11-07T18:17:16.187267 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
55318:17:20INFO: analyzing "public.p_ci_pipelines" inheritance tree
55418:17:20INFO: analyzing "public.ci_pipelines"
55518:17:20INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
55618:17:20I, [2024-11-07T18:17:20.721182 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
55718:17:20I, [2024-11-07T18:17:20.722469 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
55818:17:20I, [2024-11-07T18:17:20.723287 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
55918:17:27I, [2024-11-07T18:17:27.716986 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
56018:17:40I, [2024-11-07T18:17:40.121562 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
56118:17:40I, [2024-11-07T18:17:40.122767 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56218:17:40I, [2024-11-07T18:17:40.123692 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56318:17:40I, [2024-11-07T18:17:40.127292 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
56418:17:40I, [2024-11-07T18:17:40.128529 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56518:17:40I, [2024-11-07T18:17:40.129483 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56618:17:40I, [2024-11-07T18:17:40.133595 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
56718:17:40I, [2024-11-07T18:17:40.135081 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56818:17:40I, [2024-11-07T18:17:40.136098 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56918:17:40I, [2024-11-07T18:17:40.139804 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
57018:17:40I, [2024-11-07T18:17:40.140966 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57118:17:40I, [2024-11-07T18:17:40.141829 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
57218:17:41I, [2024-11-07T18:17:41.274493 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
57318:17:41I, [2024-11-07T18:17:41.285129 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57418:17:41I, [2024-11-07T18:17:41.286483 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
57518:17:41I, [2024-11-07T18:17:41.291410 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
57618:17:41I, [2024-11-07T18:17:41.292827 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57718:17:41I, [2024-11-07T18:17:41.293879 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
57818:17:41I, [2024-11-07T18:17:41.298745 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
57918:17:41I, [2024-11-07T18:17:41.300109 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
58018:17:41I, [2024-11-07T18:17:41.301061 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
58118:17:41I, [2024-11-07T18:17:41.305497 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
58218:17:41I, [2024-11-07T18:17:41.306862 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
58318:17:41I, [2024-11-07T18:17:41.307845 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
58418:18:00# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_merge_request_assignment_events_project_id_spec.rb. It took 2 minutes 40.36 seconds. Expected to take 1 minute 30.89 seconds.
58518:18:00# [RSpecRunTime] RSpec elapsed time: 26 minutes 38.05 seconds. Current RSS: ~1233M. Threads: 1. load average: 0.97 1.04 1.02 1/266 395
58618:18:00.
58718:18:00# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_audit_events_streaming_headers_group_id_spec.rb. Expected to take 1 minute 20.77 seconds.
58818:18:00Gitlab::BackgroundMigration::BackfillAuditEventsStreamingHeadersGroupId
58918:19:11 performs without error
59018:19:20 constructs a valid query
59118:19:22I, [2024-11-07T18:19:22.105300 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
59218:19:22I, [2024-11-07T18:19:22.106757 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
59318:19:22I, [2024-11-07T18:19:22.107817 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
59418:19:36I, [2024-11-07T18:19:36.336276 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
59518:19:44I, [2024-11-07T18:19:44.657191 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
59618:19:54I, [2024-11-07T18:19:54.170274 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
59718:19:57I, [2024-11-07T18:19:57.250691 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
59818:20:01INFO: analyzing "public.p_ci_pipelines" inheritance tree
59918:20:01INFO: analyzing "public.ci_pipelines"
60018:20:01INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
60118:20:01I, [2024-11-07T18:20:01.925746 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
60218:20:01I, [2024-11-07T18:20:01.927143 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
60318:20:01I, [2024-11-07T18:20:01.928136 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
60418:20:08I, [2024-11-07T18:20:08.986324 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
60518:20:21I, [2024-11-07T18:20:21.142977 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
60618:20:21I, [2024-11-07T18:20:21.144295 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
60718:20:21I, [2024-11-07T18:20:21.145187 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
60818:20:21I, [2024-11-07T18:20:21.148698 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
60918:20:21I, [2024-11-07T18:20:21.149824 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61018:20:21I, [2024-11-07T18:20:21.150670 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61118:20:21I, [2024-11-07T18:20:21.153986 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
61218:20:21I, [2024-11-07T18:20:21.155264 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61318:20:21I, [2024-11-07T18:20:21.156102 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61418:20:21I, [2024-11-07T18:20:21.159843 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
61518:20:21I, [2024-11-07T18:20:21.161008 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61618:20:21I, [2024-11-07T18:20:21.161916 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61718:20:22I, [2024-11-07T18:20:22.255129 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
61818:20:22I, [2024-11-07T18:20:22.256710 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61918:20:22I, [2024-11-07T18:20:22.258264 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
62018:20:22I, [2024-11-07T18:20:22.262921 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
62118:20:22I, [2024-11-07T18:20:22.264129 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
62218:20:22I, [2024-11-07T18:20:22.264975 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
62318:20:22I, [2024-11-07T18:20:22.268519 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
62418:20:22I, [2024-11-07T18:20:22.269741 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
62518:20:22I, [2024-11-07T18:20:22.270647 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
62618:20:22I, [2024-11-07T18:20:22.274563 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
62718:20:22I, [2024-11-07T18:20:22.275735 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
62818:20:22I, [2024-11-07T18:20:22.276583 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
62918:20:41# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_audit_events_streaming_headers_group_id_spec.rb. It took 2 minutes 40.21 seconds. Expected to take 1 minute 20.77 seconds.
63018:20:41# [RSpecRunTime] RSpec elapsed time: 29 minutes 18.31 seconds. Current RSS: ~1233M. Threads: 1. load average: 1.04 1.06 1.03 1/265 396
63118:20:41.
63218:20:41# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb. Expected to take 1 minute 18.43 seconds.
63318:20:41Gitlab::BackgroundMigration::BackfillBoardsEpicBoardPositionsGroupId
63418:21:49 constructs a valid query
63518:21:58 performs without error
63618:22:00I, [2024-11-07T18:22:00.213685 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
63718:22:00I, [2024-11-07T18:22:00.214943 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
63818:22:00I, [2024-11-07T18:22:00.215815 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
63918:22:14I, [2024-11-07T18:22:14.084046 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
64018:22:23I, [2024-11-07T18:22:23.051876 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
64118:22:33I, [2024-11-07T18:22:33.270637 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
64218:22:36I, [2024-11-07T18:22:36.389199 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
64318:22:40INFO: analyzing "public.p_ci_pipelines" inheritance tree
64418:22:41INFO: analyzing "public.ci_pipelines"
64518:22:41INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
64618:22:41I, [2024-11-07T18:22:41.006952 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
64718:22:41I, [2024-11-07T18:22:41.008286 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
64818:22:41I, [2024-11-07T18:22:41.009227 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
64918:22:47I, [2024-11-07T18:22:47.803556 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
65018:23:00I, [2024-11-07T18:23:00.447850 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
65118:23:00I, [2024-11-07T18:23:00.449273 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
65218:23:00I, [2024-11-07T18:23:00.450179 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65318:23:00I, [2024-11-07T18:23:00.453904 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
65418:23:00I, [2024-11-07T18:23:00.455155 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
65518:23:00I, [2024-11-07T18:23:00.456035 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65618:23:00I, [2024-11-07T18:23:00.459970 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
65718:23:00I, [2024-11-07T18:23:00.461281 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
65818:23:00I, [2024-11-07T18:23:00.462267 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65918:23:00I, [2024-11-07T18:23:00.466252 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
66018:23:00I, [2024-11-07T18:23:00.467526 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66118:23:00I, [2024-11-07T18:23:00.468385 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66218:23:01I, [2024-11-07T18:23:01.673480 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
66318:23:01I, [2024-11-07T18:23:01.674853 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66418:23:01I, [2024-11-07T18:23:01.675850 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66518:23:01I, [2024-11-07T18:23:01.679782 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
66618:23:01I, [2024-11-07T18:23:01.681162 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66718:23:01I, [2024-11-07T18:23:01.682103 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66818:23:01I, [2024-11-07T18:23:01.685927 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
66918:23:01I, [2024-11-07T18:23:01.687304 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
67018:23:01I, [2024-11-07T18:23:01.688138 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
67118:23:01I, [2024-11-07T18:23:01.691691 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
67218:23:01I, [2024-11-07T18:23:01.692887 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
67318:23:01I, [2024-11-07T18:23:01.693783 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
67418:23:21# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb. It took 2 minutes 39.78 seconds. Expected to take 1 minute 18.43 seconds.
67518:23:21# [RSpecRunTime] RSpec elapsed time: 31 minutes 58.14 seconds. Current RSS: ~1238M. Threads: 1. load average: 0.97 1.04 1.02 1/266 397
67618:23:21.
67718:23:21# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_terraform_state_versions_project_id_spec.rb. Expected to take 1 minute 14.19 seconds.
67818:23:21Gitlab::BackgroundMigration::BackfillTerraformStateVersionsProjectId
67918:24:31 constructs a valid query
68018:24:42 performs without error
68118:24:57I, [2024-11-07T18:24:57.580457 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
68218:25:06I, [2024-11-07T18:25:06.658541 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
68318:25:17I, [2024-11-07T18:25:17.370415 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
68418:25:20I, [2024-11-07T18:25:20.774843 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
68518:25:25INFO: analyzing "public.p_ci_pipelines" inheritance tree
68618:25:25INFO: analyzing "public.ci_pipelines"
68718:25:25INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
68818:25:25I, [2024-11-07T18:25:25.841293 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
68918:25:25I, [2024-11-07T18:25:25.842901 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
69018:25:25I, [2024-11-07T18:25:25.843931 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
69118:25:33I, [2024-11-07T18:25:33.378931 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
69218:25:47I, [2024-11-07T18:25:47.127448 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
69318:25:47I, [2024-11-07T18:25:47.128679 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
69418:25:47I, [2024-11-07T18:25:47.129598 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
69518:25:47I, [2024-11-07T18:25:47.133252 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
69618:25:47I, [2024-11-07T18:25:47.134612 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
69718:25:47I, [2024-11-07T18:25:47.135524 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
69818:25:47I, [2024-11-07T18:25:47.139023 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
69918:25:47I, [2024-11-07T18:25:47.140204 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70018:25:47I, [2024-11-07T18:25:47.141031 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
70118:25:47I, [2024-11-07T18:25:47.144670 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
70218:25:47I, [2024-11-07T18:25:47.145841 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70318:25:47I, [2024-11-07T18:25:47.146683 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
70418:25:48I, [2024-11-07T18:25:48.284005 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
70518:25:48I, [2024-11-07T18:25:48.285439 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70618:25:48I, [2024-11-07T18:25:48.286504 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
70718:25:48I, [2024-11-07T18:25:48.290580 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
70818:25:48I, [2024-11-07T18:25:48.291807 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70918:25:48I, [2024-11-07T18:25:48.292706 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
71018:25:48I, [2024-11-07T18:25:48.296591 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
71118:25:48I, [2024-11-07T18:25:48.297860 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
71218:25:48I, [2024-11-07T18:25:48.298762 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
71318:25:48I, [2024-11-07T18:25:48.302261 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
71418:25:48I, [2024-11-07T18:25:48.303526 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
71518:25:48I, [2024-11-07T18:25:48.304432 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
71618:26:07# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_terraform_state_versions_project_id_spec.rb. It took 2 minutes 46.47 seconds. Expected to take 1 minute 14.19 seconds.
71718:26:07# [RSpecRunTime] RSpec elapsed time: 34 minutes 44.66 seconds. Current RSS: ~1230M. Threads: 1. load average: 1.13 1.09 1.03 1/266 398
71818:26:07.
71918:26:07# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_boards_epic_lists_group_id_spec.rb. Expected to take 1 minute 12.51 seconds.
72018:26:07Gitlab::BackgroundMigration::BackfillBoardsEpicListsGroupId
72118:27:17 constructs a valid query
72218:27:27 performs without error
72318:27:28I, [2024-11-07T18:27:28.569326 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
72418:27:28I, [2024-11-07T18:27:28.570837 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
72518:27:28I, [2024-11-07T18:27:28.571789 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
72618:27:43I, [2024-11-07T18:27:43.743850 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
72718:27:52I, [2024-11-07T18:27:52.864941 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
72818:28:03I, [2024-11-07T18:28:03.214047 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
72918:28:06I, [2024-11-07T18:28:06.471545 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
73018:28:11INFO: analyzing "public.p_ci_pipelines" inheritance tree
73118:28:11INFO: analyzing "public.ci_pipelines"
73218:28:11INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
73318:28:11I, [2024-11-07T18:28:11.455731 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
73418:28:11I, [2024-11-07T18:28:11.457118 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
73518:28:11I, [2024-11-07T18:28:11.458037 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
73618:28:18I, [2024-11-07T18:28:18.930817 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
73718:28:32I, [2024-11-07T18:28:32.356204 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
73818:28:32I, [2024-11-07T18:28:32.358186 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
73918:28:32I, [2024-11-07T18:28:32.359187 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
74018:28:32I, [2024-11-07T18:28:32.363413 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
74118:28:32I, [2024-11-07T18:28:32.364687 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
74218:28:32I, [2024-11-07T18:28:32.365646 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
74318:28:32I, [2024-11-07T18:28:32.369737 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
74418:28:32I, [2024-11-07T18:28:32.371125 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
74518:28:32I, [2024-11-07T18:28:32.372067 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
74618:28:32I, [2024-11-07T18:28:32.376135 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
74718:28:32I, [2024-11-07T18:28:32.377430 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
74818:28:32I, [2024-11-07T18:28:32.378395 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
74918:28:33I, [2024-11-07T18:28:33.629854 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
75018:28:33I, [2024-11-07T18:28:33.632053 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
75118:28:33I, [2024-11-07T18:28:33.633463 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
75218:28:33I, [2024-11-07T18:28:33.638525 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
75318:28:33I, [2024-11-07T18:28:33.639927 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
75418:28:33I, [2024-11-07T18:28:33.640921 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
75518:28:33I, [2024-11-07T18:28:33.645575 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
75618:28:33I, [2024-11-07T18:28:33.646853 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
75718:28:33I, [2024-11-07T18:28:33.647827 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
75818:28:33I, [2024-11-07T18:28:33.652051 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
75918:28:33I, [2024-11-07T18:28:33.653459 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
76018:28:33I, [2024-11-07T18:28:33.654406 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
76118:28:53# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_boards_epic_lists_group_id_spec.rb. It took 2 minutes 46.11 seconds. Expected to take 1 minute 12.51 seconds.
76218:28:53# [RSpecRunTime] RSpec elapsed time: 37 minutes 30.83 seconds. Current RSS: ~1230M. Threads: 1. load average: 1.03 1.10 1.05 1/266 399
76318:28:53.
76418:28:53# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_epic_basic_fields_to_work_item_record_spec.rb. Expected to take 1 minute 5.99 seconds.
76518:28:53Gitlab::BackgroundMigration::BackfillEpicBasicFieldsToWorkItemRecord
76618:29:55 when backfilling all epics
76718:30:06 backfills the work items for specific group only
76818:30:06# [RSpecRunTime] RSpec elapsed time: 38 minutes 43.81 seconds. Current RSS: ~1251M. Threads: 1. load average: 1.14 1.12 1.06 1/266 400
76918:30:06.
77018:30:06The application_settings (main) table has 1203 columns.
77118:30:06Recreating the database
77218:30:07Dropped database 'gitlabhq_test'
77318:30:08Dropped database 'gitlabhq_test_ci'
77418:30:08Created database 'gitlabhq_test'
77518:30:08Created database 'gitlabhq_test_ci'
77618:30:21main: == [advisory_lock_connection] object_id: 350630320, pg_backend_pid: 356
77718:30:21main: == [advisory_lock_connection] object_id: 350630320, pg_backend_pid: 356
77818:30:21ci: == [advisory_lock_connection] object_id: 350630400, pg_backend_pid: 358
77918:30:21ci: == [advisory_lock_connection] object_id: 350630400, pg_backend_pid: 358
78018:30:29Databases re-creation done in 22.842245237000043
78118:30:29# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_epic_basic_fields_to_work_item_record_spec.rb. It took 1 minute 36.18 seconds. Expected to take 1 minute 5.99 seconds.
78218:30:30# [RSpecRunTime] RSpec elapsed time: 39 minutes 7.06 seconds. Current RSS: ~1238M. Threads: 1. load average: 1.09 1.11 1.06 1/266 403
78318:30:30.
78418:30:30# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_flags_project_id_spec.rb. Expected to take 1 minute 3.76 seconds.
78518:30:30Gitlab::BackgroundMigration::BackfillVulnerabilityFlagsProjectId
78618:31:21 performs without error
78718:31:29 constructs a valid query
78818:31:31I, [2024-11-07T18:31:31.476021 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
78918:31:39I, [2024-11-07T18:31:39.918675 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
79018:31:49I, [2024-11-07T18:31:49.530637 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
79118:31:52I, [2024-11-07T18:31:52.658284 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
79218:31:57INFO: analyzing "public.p_ci_pipelines" inheritance tree
79318:31:57INFO: analyzing "public.ci_pipelines"
79418:31:57INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
79518:31:57I, [2024-11-07T18:31:57.133604 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
79618:31:57I, [2024-11-07T18:31:57.135283 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
79718:31:57I, [2024-11-07T18:31:57.136419 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
79818:32:03I, [2024-11-07T18:32:03.543328 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
79918:32:15I, [2024-11-07T18:32:15.512182 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
80018:32:15I, [2024-11-07T18:32:15.513616 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
80118:32:15I, [2024-11-07T18:32:15.514546 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
80218:32:15I, [2024-11-07T18:32:15.518588 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
80318:32:15I, [2024-11-07T18:32:15.519821 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
80418:32:15I, [2024-11-07T18:32:15.520799 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
80518:32:15I, [2024-11-07T18:32:15.524684 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
80618:32:15I, [2024-11-07T18:32:15.525950 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
80718:32:15I, [2024-11-07T18:32:15.526907 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
80818:32:15I, [2024-11-07T18:32:15.531382 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
80918:32:15I, [2024-11-07T18:32:15.532655 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
81018:32:15I, [2024-11-07T18:32:15.533565 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
81118:32:16I, [2024-11-07T18:32:16.690221 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
81218:32:16I, [2024-11-07T18:32:16.691564 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
81318:32:16I, [2024-11-07T18:32:16.692603 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
81418:32:16I, [2024-11-07T18:32:16.696632 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
81518:32:16I, [2024-11-07T18:32:16.697830 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
81618:32:16I, [2024-11-07T18:32:16.698717 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
81718:32:16I, [2024-11-07T18:32:16.702639 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
81818:32:16I, [2024-11-07T18:32:16.703973 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
81918:32:16I, [2024-11-07T18:32:16.705127 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
82018:32:16I, [2024-11-07T18:32:16.708983 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
82118:32:16I, [2024-11-07T18:32:16.710198 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
82218:32:16I, [2024-11-07T18:32:16.711112 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
82318:32:36# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_flags_project_id_spec.rb. It took 2 minutes 6.27 seconds. Expected to take 1 minute 3.76 seconds.
82418:32:36# [RSpecRunTime] RSpec elapsed time: 41 minutes 13.38 seconds. Current RSS: ~1237M. Threads: 1. load average: 0.97 1.06 1.04 1/265 404
82518:32:36.
82618:32:36# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_debian_group_components_group_id_spec.rb. Expected to take 54.23 seconds.
82718:32:36Gitlab::BackgroundMigration::BackfillPackagesDebianGroupComponentsGroupId
82818:33:23 performs without error
82918:33:30 constructs a valid query
83018:33:31I, [2024-11-07T18:33:31.485799 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
83118:33:39I, [2024-11-07T18:33:39.506891 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
83218:33:48I, [2024-11-07T18:33:48.694671 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
83318:33:51I, [2024-11-07T18:33:51.677045 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
83418:33:56INFO: analyzing "public.p_ci_pipelines" inheritance tree
83518:33:56INFO: analyzing "public.ci_pipelines"
83618:33:56INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
83718:33:56I, [2024-11-07T18:33:56.062544 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
83818:33:56I, [2024-11-07T18:33:56.064192 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
83918:33:56I, [2024-11-07T18:33:56.065274 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
84018:34:02I, [2024-11-07T18:34:02.097931 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
84118:34:13I, [2024-11-07T18:34:13.245491 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
84218:34:13I, [2024-11-07T18:34:13.246786 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
84318:34:13I, [2024-11-07T18:34:13.247762 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
84418:34:13I, [2024-11-07T18:34:13.251662 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
84518:34:13I, [2024-11-07T18:34:13.252858 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
84618:34:13I, [2024-11-07T18:34:13.253740 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
84718:34:13I, [2024-11-07T18:34:13.258005 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
84818:34:13I, [2024-11-07T18:34:13.259528 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
84918:34:13I, [2024-11-07T18:34:13.260465 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
85018:34:13I, [2024-11-07T18:34:13.264631 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
85118:34:13I, [2024-11-07T18:34:13.265925 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
85218:34:13I, [2024-11-07T18:34:13.266817 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
85318:34:14I, [2024-11-07T18:34:14.374542 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
85418:34:14I, [2024-11-07T18:34:14.375882 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
85518:34:14I, [2024-11-07T18:34:14.376818 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
85618:34:14I, [2024-11-07T18:34:14.380906 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
85718:34:14I, [2024-11-07T18:34:14.382753 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
85818:34:14I, [2024-11-07T18:34:14.383651 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
85918:34:14I, [2024-11-07T18:34:14.387746 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
86018:34:14I, [2024-11-07T18:34:14.389084 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
86118:34:14I, [2024-11-07T18:34:14.390023 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
86218:34:14I, [2024-11-07T18:34:14.394013 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
86318:34:14I, [2024-11-07T18:34:14.395202 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
86418:34:14I, [2024-11-07T18:34:14.396122 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
86518:34:33# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_debian_group_components_group_id_spec.rb. It took 1 minute 56.87 seconds. Expected to take 54.23 seconds.
86618:34:33# [RSpecRunTime] RSpec elapsed time: 43 minutes 10.31 seconds. Current RSS: ~1244M. Threads: 1. load average: 0.95 1.02 1.03 1/267 405
86718:34:33.
86818:34:33# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb. Expected to take 53.84 seconds.
86918:34:33Gitlab::BackgroundMigration::BackfillCiResourcesProjectId
87018:35:15 constructs a valid query
87118:35:21 performs without error
87218:35:33I, [2024-11-07T18:35:33.164078 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
87318:35:33I, [2024-11-07T18:35:33.165769 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
87418:35:33I, [2024-11-07T18:35:33.167201 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
87518:35:33I, [2024-11-07T18:35:33.171710 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
87618:35:33I, [2024-11-07T18:35:33.173062 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
87718:35:33I, [2024-11-07T18:35:33.173979 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
87818:35:33I, [2024-11-07T18:35:33.178090 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
87918:35:33I, [2024-11-07T18:35:33.179479 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
88018:35:33I, [2024-11-07T18:35:33.180471 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
88118:35:33I, [2024-11-07T18:35:33.184572 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
88218:35:33I, [2024-11-07T18:35:33.185902 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
88318:35:33I, [2024-11-07T18:35:33.186960 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
88418:35:34I, [2024-11-07T18:35:34.324764 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
88518:35:34I, [2024-11-07T18:35:34.326184 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
88618:35:34I, [2024-11-07T18:35:34.327135 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
88718:35:34I, [2024-11-07T18:35:34.331372 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
88818:35:34I, [2024-11-07T18:35:34.332672 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
88918:35:34I, [2024-11-07T18:35:34.333567 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
89018:35:34I, [2024-11-07T18:35:34.337710 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
89118:35:34I, [2024-11-07T18:35:34.339057 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
89218:35:34I, [2024-11-07T18:35:34.340047 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
89318:35:34I, [2024-11-07T18:35:34.344156 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
89418:35:34I, [2024-11-07T18:35:34.345495 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
89518:35:34I, [2024-11-07T18:35:34.346469 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
89618:35:58I, [2024-11-07T18:35:58.099828 #342] INFO -- : Database: 'ci', Table: 'catalog_resource_component_last_usages': Lock Writes
89718:35:58I, [2024-11-07T18:35:58.374936 #342] INFO -- : Database: 'ci', Table: 'pm_cve_enrichment': Lock Writes
89818:35:58I, [2024-11-07T18:35:58.844515 #342] INFO -- : Database: 'ci', Table: 'pipl_users': Lock Writes
89918:35:59I, [2024-11-07T18:35:58.999653 #342] INFO -- : Database: 'ci', Table: 'vulnerability_representation_information': Lock Writes
90018:35:59I, [2024-11-07T18:35:59.706623 #342] INFO -- : Database: 'ci', Table: 'abuse_report_labels': Lock Writes
90118:35:59I, [2024-11-07T18:35:59.744570 #342] INFO -- : Database: 'ci', Table: 'abuse_report_label_links': Lock Writes
90218:36:00I, [2024-11-07T18:36:00.139977 #342] INFO -- : Database: 'ci', Table: 'work_item_weights_sources': Lock Writes
90318:36:00I, [2024-11-07T18:36:00.938587 #342] INFO -- : Database: 'ci', Table: 'analytics_cycle_analytics_stage_aggregations': Lock Writes
90418:36:15# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb. It took 1 minute 41.91 seconds. Expected to take 53.84 seconds.
90518:36:15# [RSpecRunTime] RSpec elapsed time: 44 minutes 52.27 seconds. Current RSS: ~1233M. Threads: 1. load average: 0.99 1.01 1.02 1/267 406
90618:36:15.
90718:36:15# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_protected_environment_approval_rules_protected_environment_project_id_spec.rb. Expected to take 45.67 seconds.
90818:36:15Gitlab::BackgroundMigration::BackfillProtectedEnvironmentApprovalRulesProtectedEnvironmentProjectId
90918:36:52 constructs a valid query
91018:36:58 performs without error
91118:37:06I, [2024-11-07T18:37:06.876913 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
91218:37:09I, [2024-11-07T18:37:09.885034 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
91318:37:14INFO: analyzing "public.p_ci_pipelines" inheritance tree
91418:37:14INFO: analyzing "public.ci_pipelines"
91518:37:14INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
91618:37:14I, [2024-11-07T18:37:14.368932 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
91718:37:14I, [2024-11-07T18:37:14.370297 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
91818:37:14I, [2024-11-07T18:37:14.371209 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
91918:37:20I, [2024-11-07T18:37:20.545816 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
92018:37:32I, [2024-11-07T18:37:32.012711 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
92118:37:32I, [2024-11-07T18:37:32.013946 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
92218:37:32I, [2024-11-07T18:37:32.014825 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
92318:37:32I, [2024-11-07T18:37:32.018544 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
92418:37:32I, [2024-11-07T18:37:32.019795 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
92518:37:32I, [2024-11-07T18:37:32.020709 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
92618:37:32I, [2024-11-07T18:37:32.024511 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
92718:37:32I, [2024-11-07T18:37:32.025706 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
92818:37:32I, [2024-11-07T18:37:32.026557 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
92918:37:32I, [2024-11-07T18:37:32.030270 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
93018:37:32I, [2024-11-07T18:37:32.031509 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
93118:37:32I, [2024-11-07T18:37:32.032385 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
93218:37:33I, [2024-11-07T18:37:33.101393 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
93318:37:33I, [2024-11-07T18:37:33.102724 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
93418:37:33I, [2024-11-07T18:37:33.103732 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
93518:37:33I, [2024-11-07T18:37:33.107667 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
93618:37:33I, [2024-11-07T18:37:33.108940 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
93718:37:33I, [2024-11-07T18:37:33.109831 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
93818:37:33I, [2024-11-07T18:37:33.114055 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
93918:37:33I, [2024-11-07T18:37:33.115384 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
94018:37:33I, [2024-11-07T18:37:33.116285 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
94118:37:33I, [2024-11-07T18:37:33.120081 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
94218:37:33I, [2024-11-07T18:37:33.121315 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
94318:37:33I, [2024-11-07T18:37:33.122220 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
94418:37:51# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_protected_environment_approval_rules_protected_environment_project_id_spec.rb. It took 1 minute 36.78 seconds. Expected to take 45.67 seconds.
94518:37:52# [RSpecRunTime] RSpec elapsed time: 46 minutes 29.1 seconds. Current RSS: ~1237M. Threads: 1. load average: 0.96 0.98 1.00 1/267 407
94618:37:52.
94718:37:52# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_group_id_spec.rb. Expected to take 38.44 seconds.
94818:37:52Gitlab::BackgroundMigration::BackfillProtectedEnvironmentDeployAccessLevelsProtectedEnvironmentGroupId
94918:38:23 constructs a valid query
95018:38:29 performs without error
95118:38:31I, [2024-11-07T18:38:31.972900 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
95218:38:36INFO: analyzing "public.p_ci_pipelines" inheritance tree
95318:38:36INFO: analyzing "public.ci_pipelines"
95418:38:36INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
95518:38:36I, [2024-11-07T18:38:36.564414 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
95618:38:36I, [2024-11-07T18:38:36.565764 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
95718:38:36I, [2024-11-07T18:38:36.566696 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
95818:38:42I, [2024-11-07T18:38:42.871853 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
95918:38:54I, [2024-11-07T18:38:54.311158 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
96018:38:54I, [2024-11-07T18:38:54.312617 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
96118:38:54I, [2024-11-07T18:38:54.313618 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
96218:38:54I, [2024-11-07T18:38:54.317563 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
96318:38:54I, [2024-11-07T18:38:54.318872 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
96418:38:54I, [2024-11-07T18:38:54.319798 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
96518:38:54I, [2024-11-07T18:38:54.323986 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
96618:38:54I, [2024-11-07T18:38:54.325269 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
96718:38:54I, [2024-11-07T18:38:54.326157 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
96818:38:54I, [2024-11-07T18:38:54.329996 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
96918:38:54I, [2024-11-07T18:38:54.331276 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
97018:38:54I, [2024-11-07T18:38:54.332169 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
97118:38:55I, [2024-11-07T18:38:55.422928 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
97218:38:55I, [2024-11-07T18:38:55.424373 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
97318:38:55I, [2024-11-07T18:38:55.425323 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
97418:38:55I, [2024-11-07T18:38:55.429142 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
97518:38:55I, [2024-11-07T18:38:55.430453 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
97618:38:55I, [2024-11-07T18:38:55.431331 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
97718:38:55I, [2024-11-07T18:38:55.434948 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
97818:38:55I, [2024-11-07T18:38:55.436167 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
97918:38:55I, [2024-11-07T18:38:55.437026 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
98018:38:55I, [2024-11-07T18:38:55.440797 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
98118:38:55I, [2024-11-07T18:38:55.442005 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
98218:38:55I, [2024-11-07T18:38:55.442942 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
98318:39:14# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_group_id_spec.rb. It took 1 minute 22.41 seconds. Expected to take 38.44 seconds.
98418:39:14# [RSpecRunTime] RSpec elapsed time: 47 minutes 51.57 seconds. Current RSS: ~1239M. Threads: 1. load average: 0.92 0.97 1.00 1/267 408
98518:39:14.
98618:39:14# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/remove_namespace_from_os_type_sbom_components_spec.rb. Expected to take 33.03 seconds.
98718:39:14Gitlab::BackgroundMigration::RemoveNamespaceFromOsTypeSbomComponents
98818:39:28 #perform
98918:39:34 successfully removes the os namespace prefix
99018:39:34 with existing record in regards to name, purl_type and component_type
99118:39:39 rescues valid ActiveRecord::RecordNotUnique errors
99218:39:39# [RSpecRunTime] RSpec elapsed time: 48 minutes 16.85 seconds. Current RSS: ~1236M. Threads: 1. load average: 0.87 0.96 0.99 1/266 409
99318:39:39.
99418:39:39 with unexpected ActiveRecord::RecordNotUnique error
99518:39:45 raises unknown ActiveRecord::RecordNotUnique errors
99618:39:45# [RSpecRunTime] RSpec elapsed time: 48 minutes 22.68 seconds. Current RSS: ~1234M. Threads: 1. load average: 0.88 0.96 0.99 1/266 410
99718:39:45.
99818:39:47I, [2024-11-07T18:39:47.063608 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
99918:39:58I, [2024-11-07T18:39:58.713126 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
100018:39:58I, [2024-11-07T18:39:58.714392 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
100118:39:58I, [2024-11-07T18:39:58.715386 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
100218:39:58I, [2024-11-07T18:39:58.721184 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
100318:39:58I, [2024-11-07T18:39:58.722960 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
100418:39:58I, [2024-11-07T18:39:58.724487 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
100518:39:58I, [2024-11-07T18:39:58.729061 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
100618:39:58I, [2024-11-07T18:39:58.730508 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
100718:39:58I, [2024-11-07T18:39:58.731563 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
100818:39:58I, [2024-11-07T18:39:58.735903 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
100918:39:58I, [2024-11-07T18:39:58.737312 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
101018:39:58I, [2024-11-07T18:39:58.738242 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
101118:39:59I, [2024-11-07T18:39:59.817219 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
101218:39:59I, [2024-11-07T18:39:59.818663 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
101318:39:59I, [2024-11-07T18:39:59.819657 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
101418:39:59I, [2024-11-07T18:39:59.823593 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
101518:39:59I, [2024-11-07T18:39:59.825107 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
101618:39:59I, [2024-11-07T18:39:59.826025 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
101718:39:59I, [2024-11-07T18:39:59.829871 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
101818:39:59I, [2024-11-07T18:39:59.831126 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
101918:39:59I, [2024-11-07T18:39:59.832031 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
102018:39:59I, [2024-11-07T18:39:59.835850 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
102118:39:59I, [2024-11-07T18:39:59.837061 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
102218:39:59I, [2024-11-07T18:39:59.837972 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
102318:40:18# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/remove_namespace_from_os_type_sbom_components_spec.rb. It took 1 minute 3.9 seconds. Expected to take 33.03 seconds.
102418:40:18# [RSpecRunTime] RSpec elapsed time: 48 minutes 55.52 seconds. Current RSS: ~1244M. Threads: 1. load average: 0.93 0.97 1.00 1/266 411
102518:40:18.
102618:40:18# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb. Expected to take 28.82 seconds.
102718:40:18Gitlab::BackgroundMigration::BackfillDesiredShardingKeyJob
102818:40:19 #constuct_query
102918:40:19 batch_column: :id
103018:40:25 constructs a query using the supplied job arguments
103118:40:25# [RSpecRunTime] RSpec elapsed time: 49 minutes 2.16 seconds. Current RSS: ~1243M. Threads: 1. load average: 1.10 1.00 1.01 1/266 412
103218:40:25.
103318:40:25 batch_column: :build_id
103418:40:30 constructs a query using the supplied job arguments
103518:40:30# [RSpecRunTime] RSpec elapsed time: 49 minutes 7.97 seconds. Current RSS: ~1242M. Threads: 1. load average: 1.01 0.98 1.00 1/266 413
103618:40:30.
103718:40:30 #perform
103818:40:30 when batch_column is id
103918:40:30 behaves like a migration backfilling the missing project_id for the batch
104018:40:36 backfills the missing project_id for the batch
104118:40:37# [RSpecRunTime] RSpec elapsed time: 49 minutes 14.05 seconds. Current RSS: ~1244M. Threads: 1. load average: 1.01 0.98 1.00 1/267 414
104218:40:37.
104318:40:37 when batch_column is build_id
104418:40:37 behaves like a migration backfilling the missing project_id for the batch
104518:40:43 backfills the missing project_id for the batch
104618:40:43# [RSpecRunTime] RSpec elapsed time: 49 minutes 20.19 seconds. Current RSS: ~1239M. Threads: 1. load average: 1.01 0.98 1.00 1/267 415
104718:40:43.
104818:40:43 when batch_column is invalid
104918:40:49 does not backfill the missing project_id for the batch
105018:40:49# [RSpecRunTime] RSpec elapsed time: 49 minutes 26.35 seconds. Current RSS: ~1242M. Threads: 1. load average: 0.93 0.97 0.99 1/267 416
105118:40:49.
105218:41:01# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb. It took 43.35 seconds. Expected to take 28.82 seconds.
105318:41:01# [RSpecRunTime] RSpec elapsed time: 49 minutes 38.92 seconds. Current RSS: ~1243M. Threads: 1. load average: 0.93 0.97 0.99 1/267 417
105418:41:01.
105518:41:01# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb. Expected to take 23.45 seconds.
105618:41:01Gitlab::BackgroundMigration::BackfillIncidentManagementOncallRotationsProjectId
105718:41:20 performs without error
105818:41:25 constructs a valid query
105918:41:37I, [2024-11-07T18:41:37.188909 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
106018:41:37I, [2024-11-07T18:41:37.190200 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
106118:41:37I, [2024-11-07T18:41:37.192512 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
106218:41:37I, [2024-11-07T18:41:37.196475 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
106318:41:37I, [2024-11-07T18:41:37.198238 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
106418:41:37I, [2024-11-07T18:41:37.199088 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
106518:41:37I, [2024-11-07T18:41:37.203110 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
106618:41:37I, [2024-11-07T18:41:37.204450 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
106718:41:37I, [2024-11-07T18:41:37.205461 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
106818:41:37I, [2024-11-07T18:41:37.209416 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
106918:41:37I, [2024-11-07T18:41:37.210625 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
107018:41:37I, [2024-11-07T18:41:37.211508 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
107118:41:38I, [2024-11-07T18:41:38.302164 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
107218:41:38I, [2024-11-07T18:41:38.303556 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
107318:41:38I, [2024-11-07T18:41:38.304586 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
107418:41:38I, [2024-11-07T18:41:38.308759 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
107518:41:38I, [2024-11-07T18:41:38.310055 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
107618:41:38I, [2024-11-07T18:41:38.311085 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
107718:41:38I, [2024-11-07T18:41:38.315119 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
107818:41:38I, [2024-11-07T18:41:38.316389 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
107918:41:38I, [2024-11-07T18:41:38.317262 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
108018:41:38I, [2024-11-07T18:41:38.321685 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
108118:41:38I, [2024-11-07T18:41:38.322929 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
108218:41:38I, [2024-11-07T18:41:38.323787 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
108318:41:56# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb. It took 54.81 seconds. Expected to take 23.45 seconds.
108418:41:56# [RSpecRunTime] RSpec elapsed time: 50 minutes 33.78 seconds. Current RSS: ~1247M. Threads: 1. load average: 1.19 1.02 1.01 1/268 418
108518:41:56.
108618:41:56# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_incident_management_escalation_rules_project_id_spec.rb. Expected to take 21.87 seconds.
108718:41:56Gitlab::BackgroundMigration::BackfillIncidentManagementEscalationRulesProjectId
108818:42:14 constructs a valid query
108918:42:20 performs without error
109018:42:32I, [2024-11-07T18:42:32.671215 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
109118:42:32I, [2024-11-07T18:42:32.672538 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
109218:42:32I, [2024-11-07T18:42:32.674067 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
109318:42:32I, [2024-11-07T18:42:32.677968 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
109418:42:32I, [2024-11-07T18:42:32.679239 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
109518:42:32I, [2024-11-07T18:42:32.680114 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
109618:42:32I, [2024-11-07T18:42:32.683900 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
109718:42:32I, [2024-11-07T18:42:32.685184 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
109818:42:32I, [2024-11-07T18:42:32.686120 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
109918:42:32I, [2024-11-07T18:42:32.690093 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
110018:42:32I, [2024-11-07T18:42:32.691329 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
110118:42:32I, [2024-11-07T18:42:32.692609 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
110218:42:33I, [2024-11-07T18:42:33.777192 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
110318:42:33I, [2024-11-07T18:42:33.778480 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
110418:42:33I, [2024-11-07T18:42:33.779544 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
110518:42:33I, [2024-11-07T18:42:33.783058 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
110618:42:33I, [2024-11-07T18:42:33.784327 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
110718:42:33I, [2024-11-07T18:42:33.785191 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
110818:42:33I, [2024-11-07T18:42:33.788773 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
110918:42:33I, [2024-11-07T18:42:33.790004 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
111018:42:33I, [2024-11-07T18:42:33.790851 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
111118:42:33I, [2024-11-07T18:42:33.794776 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
111218:42:33I, [2024-11-07T18:42:33.796140 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
111318:42:33I, [2024-11-07T18:42:33.797044 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
111418:42:52# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_incident_management_escalation_rules_project_id_spec.rb. It took 55.54 seconds. Expected to take 21.87 seconds.
111518:42:52# [RSpecRunTime] RSpec elapsed time: 51 minutes 29.37 seconds. Current RSS: ~1240M. Threads: 1. load average: 0.90 0.97 1.00 1/268 419
111618:42:52.
111718:42:52# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/update_owasp_top10_default_of_vulnerability_reads_spec.rb. Expected to take 13.73 seconds.
111818:42:52Gitlab::BackgroundMigration::UpdateOwaspTop10DefaultOfVulnerabilityReads
111918:42:53 #perform
112018:42:59 updates vulnerability_reads with NULL owasp_top_10 to -1
112118:43:05 does not change non-NULL owasp_top_10 values
112218:43:05# [RSpecRunTime] RSpec elapsed time: 51 minutes 42.33 seconds. Current RSS: ~1239M. Threads: 1. load average: 1.00 0.99 1.00 1/268 420
112318:43:05.
112418:43:19# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/update_owasp_top10_default_of_vulnerability_reads_spec.rb. It took 27.29 seconds. Expected to take 13.73 seconds.
112518:43:19# [RSpecRunTime] RSpec elapsed time: 51 minutes 56.72 seconds. Current RSS: ~1237M. Threads: 1. load average: 1.07 1.01 1.01 1/268 421
112618:43:19.
112718:43:19# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_new_audit_event_tables_spec.rb. Expected to take 11.42 seconds.
112818:43:19Gitlab::BackgroundMigration::BackfillNewAuditEventTables
112918:43:26 correctly migrates audit events into new tables
113018:43:26 when audit events are already present
113118:43:31 does not duplicate records
113218:43:31# [RSpecRunTime] RSpec elapsed time: 52 minutes 8.43 seconds. Current RSS: ~1236M. Threads: 1. load average: 1.06 1.01 1.00 1/268 422
113318:43:31.
113418:43:43# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_new_audit_event_tables_spec.rb. It took 24.18 seconds. Expected to take 11.42 seconds.
113518:43:43# [RSpecRunTime] RSpec elapsed time: 52 minutes 20.95 seconds. Current RSS: ~1237M. Threads: 1. load average: 1.13 1.02 1.01 1/268 423
113618:43:43.
113718:43:43# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb. Expected to take 7.1 seconds.
113818:43:43Gitlab::BackgroundMigration::BatchingStrategies::BaseStrategy#next_batch
113918:43:44 #next_batch
114018:43:49 raises an error if not overridden by a subclass
114118:43:49# [RSpecRunTime] RSpec elapsed time: 52 minutes 26.92 seconds. Current RSS: ~1244M. Threads: 1. load average: 1.04 1.00 1.00 1/268 424
114218:43:49.
114318:44:02# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb. It took 18.38 seconds. Expected to take 7.1 seconds.
114418:44:02# [RSpecRunTime] RSpec elapsed time: 52 minutes 39.38 seconds. Current RSS: ~1238M. Threads: 1. load average: 1.03 1.00 1.00 1/268 425
114518:44:02.
114618:44:02# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb. Expected to take 6.48 seconds.
114718:44:02Gitlab::BackgroundMigration::EncryptCiTriggerToken
114818:44:08 ensures all unencrypted tokens are encrypted
114918:44:20# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb. It took 18.46 seconds. Expected to take 6.48 seconds.
115018:44:20# [RSpecRunTime] RSpec elapsed time: 52 minutes 57.89 seconds. Current RSS: ~1241M. Threads: 1. load average: 1.09 1.02 1.01 1/268 426
115118:44:20.
115218:44:20# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb. Expected to take 6.15 seconds.
115318:44:20Gitlab::BackgroundMigration::PopulateOperationVisibilityPermissionsFromOperations
115418:44:27 updates all project settings records from their operations_access_level
115518:44:39# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb. It took 18.51 seconds. Expected to take 6.15 seconds.
115618:44:39# [RSpecRunTime] RSpec elapsed time: 53 minutes 16.45 seconds. Current RSS: ~1245M. Threads: 1. load average: 1.06 1.02 1.00 1/268 427
115718:44:39.
115818:45:33auto_explain log contains 1146 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-8-10.342.main.ndjson.gz
115918:45:33took 53.88011876
116018:46:24auto_explain log contains 1146 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-8-10.342.ci.ndjson.gz
116118:46:24took 50.755783146
116218:46:24[TEST PROF INFO] EventProf results for sql.active_record
116318:46:24Total time: 30:14.129 of 53:02.832 (57.0%)
116418:46:24Total events: 1180271
116518:46:24Top 5 slowest suites (by time):
116618:46:24Gitlab::Backg...PublicProjects (./spec/lib/gitlab/background_migration/set_legacy_open_source_license_available_for_non_public_projects_spec.rb:5) – 03:17.488 (114367 / 1) of 05:28.096 (60.19%)
116718:46:24Gitlab::Backg...mespaceSetting (./spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb:5) – 03:12.583 (113895 / 1) of 05:17.828 (60.59%)
116818:46:24Gitlab::Backg...malizedVersion (./spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb:5) – 03:04.756 (113925 / 1) of 04:58.870 (61.82%)
116918:46:24Gitlab::Backg...nizationOwners (./spec/lib/gitlab/background_migration/backfill_default_organization_owners_spec.rb:5) – 02:37.055 (94669 / 1) of 04:15.721 (61.42%)
117018:46:24Gitlab::Backg...thoutFindingId (./spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb:5) – 02:17.929 (90146 / 1) of 03:43.509 (61.71%)
117118:46:24Knapsack report was generated. Preview:
117218:46:24{
117318:46:24 "spec/lib/gitlab/background_migration/set_legacy_open_source_license_available_for_non_public_projects_spec.rb": 165.485688568,
117418:46:24 "spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb": 144.25257065400012,
117518:46:24 "spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb": 157.025979516,
117618:46:24 "spec/lib/gitlab/background_migration/backfill_default_organization_owners_spec.rb": 122.55505493600003,
117718:46:24 "spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb": 112.46345680899981,
117818:46:24 "spec/lib/gitlab/background_migration/backfill_merge_request_assignment_events_project_id_spec.rb": 79.72002960699979,
117918:46:24 "spec/lib/gitlab/background_migration/backfill_audit_events_streaming_headers_group_id_spec.rb": 79.28663583199977,
118018:46:24 "spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb": 77.48542830899987,
118118:46:24 "spec/lib/gitlab/background_migration/backfill_terraform_state_versions_project_id_spec.rb": 81.12138418399991,
118218:46:24 "spec/lib/gitlab/background_migration/backfill_boards_epic_lists_group_id_spec.rb": 79.53439259800007,
118318:46:24 "spec/lib/gitlab/background_migration/backfill_epic_basic_fields_to_work_item_record_spec.rb": 73.00582907399985,
118418:46:24 "spec/lib/gitlab/background_migration/backfill_vulnerability_flags_project_id_spec.rb": 59.686089396999705,
118518:46:24 "spec/lib/gitlab/background_migration/backfill_packages_debian_group_components_group_id_spec.rb": 54.245906199000274,
118618:46:24 "spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb": 48.19905731800009,
118718:46:24 "spec/lib/gitlab/background_migration/backfill_protected_environment_approval_rules_protected_environment_project_id_spec.rb": 43.45084707099977,
118818:46:24 "spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_group_id_spec.rb": 37.143938746,
118918:46:24 "spec/lib/gitlab/background_migration/remove_namespace_from_os_type_sbom_components_spec.rb": 31.12876284999993,
119018:46:24 "spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb": 30.87218254399977,
119118:46:24 "spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb": 23.57392333400003,
119218:46:24 "spec/lib/gitlab/background_migration/backfill_incident_management_escalation_rules_project_id_spec.rb": 24.0832824539998,
119318:46:24 "spec/lib/gitlab/background_migration/update_owasp_top10_default_of_vulnerability_reads_spec.rb": 12.974611667000318,
119418:46:24 "spec/lib/gitlab/background_migration/backfill_new_audit_event_tables_spec.rb": 11.738050410000142,
119518:46:24 "spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb": 5.993815326999993,
119618:46:24 "spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb": 6.1293162900001334,
119718:46:24 "spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb": 6.248966742999983
119818:46:24}
119918:46:24Knapsack global time execution for tests: 26m 07s
120018:46:24Finished in 55 minutes 1 second (files took 1 minute 37.76 seconds to load)
120118:46:2445 examples, 0 failures
120218:46:24Randomized with seed 6302
120318:46:32[TEST PROF INFO] Time spent in factories: 00:00.580 (0.02% of total time)
120418:46:32RSpec exited with 0.
120518:46:32No examples to retry, congrats!
1206 18:46:33 Running after_script 00:15
120718:46:33Running after script...
120818:46:33$ source scripts/utils.sh
120918:46:33$ log_disk_usage
121018:46:33*******************************************************
121118:46:33This runner currently has 26G free disk space.
121218:46:33*******************************************************
1213 18:46:33 Disk usage detail 00:06
127218:46:39$ bundle exec gem list gitlab_quality-test_tooling
127318:46:42gitlab_quality-test_tooling (2.1.0)
127418:46:42$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
1275 18:46:42 Report test failures 00:00
127718:46:42$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
1278 18:46:42 Report test flakiness 00:00
128018:46:42$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
1281 18:46:42 Report test slowness 00:00
128318:46:42$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
1284 18:46:42 Report test slowness in MR note 00:03
128718:46:45$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
1288 18:46:45 Report test files close to timing out 00:02
129118:46:47$ tooling/bin/push_job_metrics || true
129218:46:48[job-metrics] Pushing job metrics file for the CI/CD job.
129318:46:48[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
1294 18:46:48 Saving cache for successful job 00:01
129518:46:49Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20 due to policy
1296 18:46:49 Uploading artifacts for successful job 00:06
129718:46:50Uploading artifacts...
129818:46:50auto_explain/: found 3 matching artifact files and directories
129918:46:50coverage/: found 5 matching artifact files and directories
130018:46:50crystalball/: found 2 matching artifact files and directories
130118:46:50WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
130218:46:50knapsack/: found 4 matching artifact files and directories
130318:46:50rspec/: found 16 matching artifact files and directories
130418:46:50WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
130518:46:50log/*.log: found 13 matching artifact files and directories
130618:46:50WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8298976153/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
130718:46:50WARNING: Retrying... context=artifacts-uploader error=request redirected
130818:46:53Uploading artifacts as "archive" to coordinator... 201 Created id=8298976153 responseStatus=201 Created token=glcbt-66
130918:46:53Uploading artifacts...
131018:46:53rspec/rspec-*.xml: found 1 matching artifact files and directories
131118:46:54WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8298976153/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
131218:46:54WARNING: Retrying... context=artifacts-uploader error=request redirected
131318:46:55Uploading artifacts as "junit" to coordinator... 201 Created id=8298976153 responseStatus=201 Created token=glcbt-66
1314 18:46:55 Cleaning up project directory and file based variables 00:01
131518:47:04Job succeeded