Skip to content
Snippets Groups Projects

rspec background_migration pg14 no_gitaly_transactions 6/10

Passed Started by
🤖 GitLab Bot 🤖
@gitlab-bot
1Running with gitlab-runner 17.0.0~pre.88.g761ae5dd (761ae5dd)
2 on green-2.private.runners-manager.gitlab.com/gitlab.com/gitlab-org GaSD-S1F, system ID: s_5651e5b5643b
3 feature flags: FF_NETWORK_PER_BUILD:true
4Resolving secrets
5 Preparing the "docker+machine" executor 00:07
6Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
7Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
8Authenticating with credentials from job payload (GitLab Registry)
9Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
10Using 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 ...
11WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
12WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
13Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
14Authenticating with credentials from job payload (GitLab Registry)
15Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
16Using 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 ...
17Starting service redis:6.2-alpine ...
18Pulling docker image redis:6.2-alpine ...
19Using docker image sha256:36c1d3cfe18f4b12d4640576f7048068acbfc3625027b6bbb46bba0e31b11831 for redis:6.2-alpine with digest redis@sha256:e3b17ba9479deec4b7d1eeec1548a253acc5374d68d3b27937fcfe4df8d18c7e ...
20Waiting for services to be up and running (timeout 30 seconds)...
21Authenticating with credentials from job payload (GitLab Registry)
22Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
23Using docker image sha256:b26253b493531cada33f45ef568f38c50a310442d05c39f517656e0f7d305dc7 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-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.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:543339542a02edc250c2c0424c5077b673f1fca2877024fdc5fb670eff44f8cf ...
24 Preparing environment 00:01
25Running on runner-gasd-s1f-project-278964-concurrent-0 via runner-gasd-s1f-private-1722411304-d9787268...
26 Getting source from Git repository 00:01
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
30 Restoring cache 00:21
31Checking cache for ruby-gems-debian-bookworm-ruby-3.1.5-17...
32Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/278964/ruby-gems-debian-bookworm-ruby-3.1.5-17
33Successfully extracted cache
34 Downloading artifacts 00:39
35Downloading artifacts for clone-gitlab-repo (7471344368)...
36Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344368 responseStatus=200 OK token=glcbt-66
37WARNING: Part of .git directory is on the list of files to extract
38WARNING: This may introduce unexpected problems
39Downloading artifacts for compile-test-assets (7471344747)...
40Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344747 responseStatus=200 OK token=glcbt-66
41Downloading artifacts for retrieve-tests-metadata (7471344898)...
42Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344898 responseStatus=200 OK token=glcbt-66
43Downloading artifacts for setup-test-env (7471344810)...
44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344810 responseStatus=200 OK token=glcbt-66
45 Executing "step_script" stage of the job script
46Using docker image sha256:b26253b493531cada33f45ef568f38c50a310442d05c39f517656e0f7d305dc7 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-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.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:543339542a02edc250c2c0424c5077b673f1fca2877024fdc5fb670eff44f8cf ...
47$ echo $FOSS_ONLY
48$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
49$ export GOPATH=$CI_PROJECT_DIR/.go
50$ mkdir -p $GOPATH
51$ source scripts/utils.sh
52$ source scripts/prepare_build.sh
53 Installing gems 00:25
82Using decomposed database config (config/database.yml.decomposed-postgresql)
83Geo DB won't be set up.
84Embedding DB won't be set up.
85 Setting up DBs 01:11
96$ source ./scripts/rspec_helpers.sh
97$ run_timed_command "gem install knapsack --no-document"
98$ gem install knapsack --no-document
99Successfully installed knapsack-4.0.0
1001 gem installed
101==> 'gem install knapsack --no-document' succeeded in 1 seconds.
102$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
103 Spawning Gitaly 00:04
107$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
108$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
109$ tooling/bin/create_job_metrics_file || true
110[job-metrics] Creating the job metrics file for the CI/CD job.
111$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
112 RSpec 28:32
113[10:14:46] Starting rspec_parallelized_job
114RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
115KNAPSACK_GENERATE_REPORT: true
116FLAKY_RSPEC_GENERATE_REPORT: true
117KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
118KNAPSACK_LOG_LEVEL: debug
119KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_no_gitaly_transactions_6_10_278964_report.json
120FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
121FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_no_gitaly_transactions_6_10_278964_report.json
122NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_no_gitaly_transactions_6_10_278964_report.json
123RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-7471346460.txt
124CRYSTALBALL: true
125RSPEC_TESTS_MAPPING_ENABLED:
126RSPEC_TESTS_FILTER_FILE:
127Shell set options (set -o) enabled:
128braceexpand on
129hashall on
130interactive-comments on
131pipefail on
132Knapsack report generator started!
133warning: parser/current is loading parser/ruby31, which recognizes 3.1.6-compliant syntax, but you are running 3.1.5.
134Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
135Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
136# [RSpecRunTime] Starting RSpec timer...
137[TEST PROF INFO] EventProf enabled (sql.active_record)
138unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
139unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
140Test environment set up in 2.808066908 seconds
141# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. Expected to take 2 minutes 17.93 seconds.
142Gitlab::BackgroundMigration::DestroyInvalidMembers
143 tracks timings of queries
144 logs IDs of deleted records
145 removes invalid memberships but keeps valid ones
146INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
147INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
148INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
149INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
150INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
151INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
152INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
153INFO: analyzing "public.p_ci_job_annotations" inheritance tree
154INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
155INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
156INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
157INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
158INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
159INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
160INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
161INFO: analyzing "public.ci_builds_metadata"
162INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
163INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
164INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
165INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
166INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
167INFO: analyzing "public.p_ci_builds" inheritance tree
168INFO: analyzing "public.ci_builds"
169INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
170INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
171INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
172INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
173INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
174I, [2024-07-31T10:18:49.693569 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
175I, [2024-07-31T10:19:08.795309 #326] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
176INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
177INFO: analyzing "public.ci_pipeline_variables"
178INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
179I, [2024-07-31T10:19:10.335817 #326] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
180I, [2024-07-31T10:19:10.336857 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
181I, [2024-07-31T10:19:10.337650 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
182INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
183INFO: analyzing "public.ci_pipeline_variables"
184INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
185INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
186INFO: analyzing "public.ci_job_artifacts"
187INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
188I, [2024-07-31T10:19:16.131593 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
189I, [2024-07-31T10:19:16.132660 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
190I, [2024-07-31T10:19:16.133461 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
191INFO: analyzing "public.p_ci_stages" inheritance tree
192INFO: analyzing "public.ci_stages"
193INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
194I, [2024-07-31T10:19:19.354090 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
195I, [2024-07-31T10:19:19.355145 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
196I, [2024-07-31T10:19:19.355907 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
197I, [2024-07-31T10:19:20.463637 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
198I, [2024-07-31T10:19:26.614633 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
199I, [2024-07-31T10:19:39.415122 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
200I, [2024-07-31T10:19:39.416280 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
201I, [2024-07-31T10:19:39.417683 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
202I, [2024-07-31T10:19:50.176551 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
203I, [2024-07-31T10:19:56.532791 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
204# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. It took 3 minutes 34.56 seconds. Expected to take 2 minutes 17.93 seconds.
205# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb. Expected to take 1 minute 42.97 seconds.
206Gitlab::BackgroundMigration::DisableLegacyOpenSourceLicenseForOneMemberNoRepoProjects
207WARNING: Active Record does not support composite primary key.
208project_authorizations has composite primary key. Composite primary key is ignored.
209 sets `legacy_open_source_license_available` to false only for public projects with 1 member and no repo
210INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
211INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
212INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
213INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
214INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
215INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
216INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
217INFO: analyzing "public.p_ci_job_annotations" inheritance tree
218INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
219INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
220INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
221INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
222INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
223INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
224INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
225INFO: analyzing "public.ci_builds_metadata"
226INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
227INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
228INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
229INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
230INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
231INFO: analyzing "public.p_ci_builds" inheritance tree
232INFO: analyzing "public.ci_builds"
233INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
234INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
235INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
236INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
237INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
238I, [2024-07-31T10:21:58.780513 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
239I, [2024-07-31T10:22:18.970361 #326] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
240INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
241INFO: analyzing "public.ci_pipeline_variables"
242INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
243I, [2024-07-31T10:22:20.657389 #326] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
244I, [2024-07-31T10:22:20.658723 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
245I, [2024-07-31T10:22:20.659588 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
246INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
247INFO: analyzing "public.ci_pipeline_variables"
248INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
249INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
250INFO: analyzing "public.ci_job_artifacts"
251INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
252I, [2024-07-31T10:22:26.901345 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
253I, [2024-07-31T10:22:26.902600 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
254I, [2024-07-31T10:22:26.903514 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
255INFO: analyzing "public.p_ci_stages" inheritance tree
256INFO: analyzing "public.ci_stages"
257INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
258I, [2024-07-31T10:22:30.707733 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
259I, [2024-07-31T10:22:30.709054 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
260I, [2024-07-31T10:22:30.709973 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
261I, [2024-07-31T10:22:32.017433 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
262I, [2024-07-31T10:22:38.559688 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
263I, [2024-07-31T10:22:52.571904 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
264I, [2024-07-31T10:22:52.573171 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
265I, [2024-07-31T10:22:52.574639 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
266I, [2024-07-31T10:23:04.433142 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
267I, [2024-07-31T10:23:11.401603 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
268# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb. It took 3 minutes 15.18 seconds. Expected to take 1 minute 42.97 seconds.
269# [RSpecRunTime] RSpec elapsed time: 6 minutes 55.85 seconds. Current RSS: ~1356M. Threads: 2. load average: 1.18 1.06 1.12 1/276 404
270.
271# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb. Expected to take 1 minute 30.63 seconds.
272Gitlab::BackgroundMigration::BackfillNugetNormalizedVersion
273 executes 5 queries and updates the normalized_version column
274INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
275INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
276INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
277INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
278INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
279INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
280INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
281INFO: analyzing "public.p_ci_job_annotations" inheritance tree
282INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
283INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
284INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
285INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
286INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
287INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
288INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
289INFO: analyzing "public.ci_builds_metadata"
290INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
291INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
292INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
293INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
294INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
295INFO: analyzing "public.p_ci_builds" inheritance tree
296INFO: analyzing "public.ci_builds"
297INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
298INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
299INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
300INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
301INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
302I, [2024-07-31T10:24:52.043556 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
303I, [2024-07-31T10:25:12.448307 #326] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
304INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
305INFO: analyzing "public.ci_pipeline_variables"
306INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
307I, [2024-07-31T10:25:14.322870 #326] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
308I, [2024-07-31T10:25:14.324184 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
309I, [2024-07-31T10:25:14.325074 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
310INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
311INFO: analyzing "public.ci_pipeline_variables"
312INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
313INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
314INFO: analyzing "public.ci_job_artifacts"
315INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
316I, [2024-07-31T10:25:20.718696 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
317I, [2024-07-31T10:25:20.719807 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
318I, [2024-07-31T10:25:20.720693 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
319INFO: analyzing "public.p_ci_stages" inheritance tree
320INFO: analyzing "public.ci_stages"
321INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
322I, [2024-07-31T10:25:24.301000 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
323I, [2024-07-31T10:25:24.302199 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
324I, [2024-07-31T10:25:24.303045 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
325I, [2024-07-31T10:25:25.608402 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
326I, [2024-07-31T10:25:32.387745 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
327I, [2024-07-31T10:25:46.303576 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
328I, [2024-07-31T10:25:46.304750 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
329I, [2024-07-31T10:25:46.306044 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
330I, [2024-07-31T10:25:58.563545 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
331I, [2024-07-31T10:26:06.007090 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
332# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb. It took 2 minutes 54.26 seconds. Expected to take 1 minute 30.63 seconds.
333# [RSpecRunTime] RSpec elapsed time: 9 minutes 50.49 seconds. Current RSS: ~1372M. Threads: 2. load average: 0.94 1.04 1.10 1/276 405
334.
335# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb. Expected to take 1 minute 12.36 seconds.
336Gitlab::BackgroundMigration::BackfillVsCodeSettingsUuid
337 #perform
338 when it finds vs_code_setting rows with empty uuid
339 populates uuid column with a generated uuid
340# [RSpecRunTime] RSpec elapsed time: 10 minutes 56.86 seconds. Current RSS: ~1384M. Threads: 2. load average: 0.91 1.01 1.08 1/276 406
341.
342 when it finds vs_code_setting rows with non-empty uuid
343 populates uuid column with a generated uuid
344# [RSpecRunTime] RSpec elapsed time: 11 minutes 4.12 seconds. Current RSS: ~1437M. Threads: 2. load average: 0.93 1.01 1.08 1/276 407
345.
346I, [2024-07-31T10:27:37.726684 #326] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
347INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
348INFO: analyzing "public.ci_pipeline_variables"
349INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
350I, [2024-07-31T10:27:39.563794 #326] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
351I, [2024-07-31T10:27:39.565071 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
352I, [2024-07-31T10:27:39.565997 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
353INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
354INFO: analyzing "public.ci_pipeline_variables"
355INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
356INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
357INFO: analyzing "public.ci_job_artifacts"
358INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
359I, [2024-07-31T10:27:45.825922 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
360I, [2024-07-31T10:27:45.827109 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
361I, [2024-07-31T10:27:45.827934 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
362INFO: analyzing "public.p_ci_stages" inheritance tree
363INFO: analyzing "public.ci_stages"
364INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
365I, [2024-07-31T10:27:49.388699 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
366I, [2024-07-31T10:27:49.389782 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
367I, [2024-07-31T10:27:49.390601 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
368I, [2024-07-31T10:27:50.543285 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
369I, [2024-07-31T10:27:56.906009 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
370I, [2024-07-31T10:28:10.534499 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
371I, [2024-07-31T10:28:10.535657 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
372I, [2024-07-31T10:28:10.536405 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
373I, [2024-07-31T10:28:22.063632 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
374I, [2024-07-31T10:28:28.991326 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
375# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb. It took 2 minutes 22.88 seconds. Expected to take 1 minute 12.36 seconds.
376# [RSpecRunTime] RSpec elapsed time: 12 minutes 13.42 seconds. Current RSS: ~1363M. Threads: 2. load average: 0.94 1.00 1.07 1/276 408
377.
378# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_metadata_spec.rb. Expected to take 1 minute 2.77 seconds.
379Gitlab::BackgroundMigration::BackfillPartitionIdCiPipelineMetadata
380 #perform
381 when second partition does not exist
382 does not execute the migration
383# [RSpecRunTime] RSpec elapsed time: 13 minutes 9.45 seconds. Current RSS: ~1418M. Threads: 2. load average: 0.98 1.00 1.07 1/276 409
384.
385 when second partition exists
386 fixes invalid records in the wrong the partition
387# [RSpecRunTime] RSpec elapsed time: 13 minutes 15.47 seconds. Current RSS: ~1479M. Threads: 2. load average: 1.06 1.02 1.07 1/276 410
388.
389INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
390INFO: analyzing "public.ci_pipeline_variables"
391INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
392INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
393INFO: analyzing "public.ci_job_artifacts"
394INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
395I, [2024-07-31T10:29:49.907997 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
396I, [2024-07-31T10:29:49.909186 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
397I, [2024-07-31T10:29:49.910088 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
398INFO: analyzing "public.p_ci_stages" inheritance tree
399INFO: analyzing "public.ci_stages"
400INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
401I, [2024-07-31T10:29:53.562958 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
402I, [2024-07-31T10:29:53.564093 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
403I, [2024-07-31T10:29:53.564895 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
404I, [2024-07-31T10:29:54.740598 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
405I, [2024-07-31T10:30:01.178694 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
406I, [2024-07-31T10:30:14.980060 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
407I, [2024-07-31T10:30:14.981215 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
408I, [2024-07-31T10:30:14.981978 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
409I, [2024-07-31T10:30:26.885944 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
410I, [2024-07-31T10:30:33.814155 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
411# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_metadata_spec.rb. It took 2 minutes 4.76 seconds. Expected to take 1 minute 2.77 seconds.
412# [RSpecRunTime] RSpec elapsed time: 14 minutes 18.24 seconds. Current RSS: ~1360M. Threads: 2. load average: 1.10 1.03 1.07 1/276 411
413.
414# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_wiki_repository_states_project_id_spec.rb. Expected to take 48.54 seconds.
415Gitlab::BackgroundMigration::BackfillWikiRepositoryStatesProjectId
416 performs without error
417 constructs a valid query
418I, [2024-07-31T10:31:32.454413 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
419I, [2024-07-31T10:31:47.038580 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
420I, [2024-07-31T10:31:47.039729 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
421I, [2024-07-31T10:31:47.040448 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
422I, [2024-07-31T10:31:58.769333 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
423I, [2024-07-31T10:32:05.596343 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
424# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_wiki_repository_states_project_id_spec.rb. It took 1 minute 31.65 seconds. Expected to take 48.54 seconds.
425# [RSpecRunTime] RSpec elapsed time: 15 minutes 49.99 seconds. Current RSS: ~1337M. Threads: 2. load average: 0.97 1.03 1.07 1/276 412
426.
427# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_approval_merge_request_rules_project_id_spec.rb. Expected to take 45.53 seconds.
428Gitlab::BackgroundMigration::BackfillApprovalMergeRequestRulesProjectId
429 performs without error
430 constructs a valid query
431I, [2024-07-31T10:33:20.764448 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
432I, [2024-07-31T10:33:20.766416 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
433I, [2024-07-31T10:33:20.767294 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
434I, [2024-07-31T10:33:33.396147 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
435I, [2024-07-31T10:33:40.541702 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
436# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_approval_merge_request_rules_project_id_spec.rb. It took 1 minute 35.07 seconds. Expected to take 45.53 seconds.
437# [RSpecRunTime] RSpec elapsed time: 17 minutes 25.11 seconds. Current RSS: ~1381M. Threads: 2. load average: 1.18 1.10 1.09 1/276 413
438.
439# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_agent_activity_events_agent_project_id_spec.rb. Expected to take 31.07 seconds.
440Gitlab::BackgroundMigration::BackfillAgentActivityEventsAgentProjectId
441 constructs a valid query
442 performs without error
443I, [2024-07-31T10:34:22.912280 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
444I, [2024-07-31T10:34:22.913441 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
445I, [2024-07-31T10:34:22.914210 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
446I, [2024-07-31T10:34:36.034583 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
447I, [2024-07-31T10:34:42.854769 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
448# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_agent_activity_events_agent_project_id_spec.rb. It took 1 minute 2.0 seconds. Expected to take 31.07 seconds.
449# [RSpecRunTime] RSpec elapsed time: 18 minutes 27.16 seconds. Current RSS: ~1357M. Threads: 2. load average: 1.06 1.08 1.08 1/276 414
450.
451# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_issue_links_project_id_spec.rb. Expected to take 30.45 seconds.
452Gitlab::BackgroundMigration::BackfillVulnerabilityIssueLinksProjectId
453 performs without error
454 constructs a valid query
455I, [2024-07-31T10:35:34.158531 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
456I, [2024-07-31T10:35:40.705049 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
457# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_issue_links_project_id_spec.rb. It took 57.59 seconds. Expected to take 30.45 seconds.
458# [RSpecRunTime] RSpec elapsed time: 19 minutes 24.81 seconds. Current RSS: ~1353M. Threads: 2. load average: 1.02 1.06 1.08 1/276 415
459.
460# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb. Expected to take 29.79 seconds.
461Gitlab::BackgroundMigration::BackfillBoardsEpicBoardPositionsGroupId
462 constructs a valid query
463 performs without error
464I, [2024-07-31T10:36:23.086943 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
465I, [2024-07-31T10:36:23.088322 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
466I, [2024-07-31T10:36:23.089176 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
467I, [2024-07-31T10:36:35.715847 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
468I, [2024-07-31T10:36:42.399283 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
469# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb. It took 1 minute 1.83 seconds. Expected to take 29.79 seconds.
470# [RSpecRunTime] RSpec elapsed time: 20 minutes 26.69 seconds. Current RSS: ~1355M. Threads: 2. load average: 0.87 1.00 1.05 1/277 416
471.
472# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_archived_and_traversal_ids_to_vulnerability_reads_spec.rb. Expected to take 27.68 seconds.
473Gitlab::BackgroundMigration::BackfillArchivedAndTraversalIdsToVulnerabilityReads
474 backfills traversal_ids and archived
475I, [2024-07-31T10:37:22.436053 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
476I, [2024-07-31T10:37:22.437183 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
477I, [2024-07-31T10:37:22.437971 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
478I, [2024-07-31T10:37:33.638164 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
479I, [2024-07-31T10:37:40.111966 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
480# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_archived_and_traversal_ids_to_vulnerability_reads_spec.rb. It took 57.27 seconds. Expected to take 27.68 seconds.
481# [RSpecRunTime] RSpec elapsed time: 21 minutes 24.02 seconds. Current RSS: ~1351M. Threads: 2. load average: 0.77 0.95 1.03 1/277 417
482.
483# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_model_metadata_project_id_spec.rb. Expected to take 18.4 seconds.
484Gitlab::BackgroundMigration::BackfillMlModelMetadataProjectId
485 constructs a valid query
486 performs without error
487I, [2024-07-31T10:38:08.442720 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
488I, [2024-07-31T10:38:14.959547 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
489# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_model_metadata_project_id_spec.rb. It took 34.95 seconds. Expected to take 18.4 seconds.
490# [RSpecRunTime] RSpec elapsed time: 21 minutes 59.02 seconds. Current RSS: ~1346M. Threads: 2. load average: 0.79 0.94 1.02 1/277 418
491.
492# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_partitioned_table_spec.rb. Expected to take 17.67 seconds.
493Gitlab::BackgroundMigration::BackfillPartitionedTable
494 #perform
495 without the destination table
496 raises an exception
497# [RSpecRunTime] RSpec elapsed time: 22 minutes 3.35 seconds. Current RSS: ~1385M. Threads: 2. load average: 0.79 0.94 1.02 1/277 419
498.
499 with destination table being not partitioned
500 raises an exception
501# [RSpecRunTime] RSpec elapsed time: 22 minutes 7.23 seconds. Current RSS: ~1482M. Threads: 2. load average: 0.80 0.94 1.02 1/277 420
502.
503 when the destination table exists
504WARNING: Active Record does not support composite primary key.
505_test_source_table_partitioned has composite primary key. Composite primary key is ignored.
506 copies data into the destination table idempotently
507 breaks the assigned batch into smaller sub batches
508# [RSpecRunTime] RSpec elapsed time: 22 minutes 16.19 seconds. Current RSS: ~1487M. Threads: 2. load average: 0.83 0.95 1.02 1/278 421
509.
510# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_partitioned_table_spec.rb. It took 24.75 seconds. Expected to take 17.67 seconds.
511# [RSpecRunTime] RSpec elapsed time: 22 minutes 23.82 seconds. Current RSS: ~1432M. Threads: 2. load average: 0.86 0.95 1.02 1/278 422
512.
513# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/migrate_os_sbom_occurrences_to_components_without_prefix_spec.rb. Expected to take 14.19 seconds.
514Gitlab::BackgroundMigration::MigrateOsSbomOccurrencesToComponentsWithoutPrefix
515 when sbom occurrence belongs to sbom component with os prefix
516 migrates the data correctly
517 when components have no versions
518 does not raise error
519# [RSpecRunTime] RSpec elapsed time: 22 minutes 32.52 seconds. Current RSS: ~1465M. Threads: 2. load average: 0.87 0.95 1.02 1/278 423
520.
521 when components have no occurrences
522 does not raise an error
523# [RSpecRunTime] RSpec elapsed time: 22 minutes 36.55 seconds. Current RSS: ~1475M. Threads: 2. load average: 0.88 0.95 1.02 1/278 424
524.
525# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/migrate_os_sbom_occurrences_to_components_without_prefix_spec.rb. It took 21.13 seconds. Expected to take 14.19 seconds.
526# [RSpecRunTime] RSpec elapsed time: 22 minutes 45.0 seconds. Current RSS: ~1403M. Threads: 2. load average: 0.82 0.93 1.01 1/278 425
527.
528# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/update_sbom_occurrences_component_name_based_on_pep503_spec.rb. Expected to take 13.24 seconds.
529Gitlab::BackgroundMigration::UpdateSbomOccurrencesComponentNameBasedOnPep503
530 #perform
531 without data
532 does not raise exception
533# [RSpecRunTime] RSpec elapsed time: 22 minutes 49.39 seconds. Current RSS: ~1412M. Threads: 2. load average: 0.83 0.94 1.01 1/278 426
534.
535 with data
536 successfully updates name according to PEP 0503
537 with unrelated components
538 does not update the unrelated occurrence
539# [RSpecRunTime] RSpec elapsed time: 22 minutes 57.93 seconds. Current RSS: ~1510M. Threads: 2. load average: 0.85 0.94 1.01 3/278 427
540.
541# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/update_sbom_occurrences_component_name_based_on_pep503_spec.rb. It took 20.66 seconds. Expected to take 13.24 seconds.
542# [RSpecRunTime] RSpec elapsed time: 23 minutes 5.71 seconds. Current RSS: ~1391M. Threads: 2. load average: 0.87 0.94 1.01 1/278 428
543.
544# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb. Expected to take 10.95 seconds.
545Gitlab::BackgroundMigration::BackfillVulnerabilityFindingLinksProjectId
546 performs without error
547 constructs a valid query
548# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb. It took 21.23 seconds. Expected to take 10.95 seconds.
549# [RSpecRunTime] RSpec elapsed time: 23 minutes 27.01 seconds. Current RSS: ~1381M. Threads: 2. load average: 0.85 0.93 1.00 1/278 429
550.
551# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_deploy_tokens_sharding_key_spec.rb. Expected to take 5.01 seconds.
552Gitlab::BackgroundMigration::BackfillDeployTokensShardingKey
553 backfills the missing project_id or namespace_id
554# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_deploy_tokens_sharding_key_spec.rb. It took 11.7 seconds. Expected to take 5.01 seconds.
555# [RSpecRunTime] RSpec elapsed time: 23 minutes 38.77 seconds. Current RSS: ~1373M. Threads: 2. load average: 0.88 0.93 1.00 1/278 430
556.
557# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb. Expected to take 4.8 seconds.
558Gitlab::BackgroundMigration::DisableLegacyOpenSourceLicenseForInactivePublicProjects
559 sets `legacy_open_source_license_available` attribute to false for inactive, public projects
560# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb. It took 11.43 seconds. Expected to take 4.8 seconds.
561# [RSpecRunTime] RSpec elapsed time: 23 minutes 50.25 seconds. Current RSS: ~1374M. Threads: 2. load average: 0.90 0.94 1.00 1/278 431
562.
563# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/backfill_project_statistics_with_container_registry_size_batching_strategy_spec.rb. Expected to take 4.49 seconds.
564Gitlab::BackgroundMigration::BatchingStrategies::BackfillProjectStatisticsWithContainerRegistrySizeBatchingStrategy
565 is expected to be < Gitlab::BackgroundMigration::BatchingStrategies::PrimaryKeyBatchingStrategy
566# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/backfill_project_statistics_with_container_registry_size_batching_strategy_spec.rb. It took 11.14 seconds. Expected to take 4.49 seconds.
567# [RSpecRunTime] RSpec elapsed time: 24 minutes 1.44 seconds. Current RSS: ~1374M. Threads: 2. load average: 0.84 0.92 1.00 1/278 432
568.
569auto_explain log contains 1020 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-no-gitaly-transactions-6-10.326.main.ndjson.gz
570took 29.098482447
571auto_explain log contains 1021 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-no-gitaly-transactions-6-10.326.ci.ndjson.gz
572took 26.805111186
573[TEST PROF INFO] EventProf results for sql.active_record
574Total time: 16:02.385 of 23:55.260 (67.05%)
575Total events: 730567
576Top 5 slowest suites (by time):
577Gitlab::Backg...InvalidMembers (./spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb:6) – 02:23.782 (99115 / 3) of 03:34.446 (67.05%)
578Gitlab::Backg...NoRepoProjects (./spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb:5) – 02:22.037 (94398 / 1) of 03:15.559 (72.63%)
579Gitlab::Backg...malizedVersion (./spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb:5) – 02:03.926 (89089 / 1) of 02:54.310 (71.1%)
580Gitlab::Backg...deSettingsUuid (./spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb:5) – 01:38.803 (75478 / 2) of 02:22.933 (69.13%)
581Gitlab::Backg...pelineMetadata (./spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_metadata_spec.rb:5) – 01:26.276 (67784 / 2) of 02:04.865 (69.1%)
582Knapsack report was generated. Preview:
583{
584 "spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb": 118.9358505830005,
585 "spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb": 93.79459756399956,
586 "spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb": 85.05942236299961,
587 "spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb": 73.75865911300025,
588 "spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_metadata_spec.rb": 62.189385602001494,
589 "spec/lib/gitlab/background_migration/backfill_wiki_repository_states_project_id_spec.rb": 46.82985670800008,
590 "spec/lib/gitlab/background_migration/backfill_approval_merge_request_rules_project_id_spec.rb": 48.15642198800015,
591 "spec/lib/gitlab/background_migration/backfill_agent_activity_events_agent_project_id_spec.rb": 30.662173622999035,
592 "spec/lib/gitlab/background_migration/backfill_vulnerability_issue_links_project_id_spec.rb": 28.581551780000154,
593 "spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb": 30.712611670000115,
594 "spec/lib/gitlab/background_migration/backfill_archived_and_traversal_ids_to_vulnerability_reads_spec.rb": 27.271312237999155,
595 "spec/lib/gitlab/background_migration/backfill_ml_model_metadata_project_id_spec.rb": 17.065266315999907,
596 "spec/lib/gitlab/background_migration/backfill_partitioned_table_spec.rb": 17.300548879000416,
597 "spec/lib/gitlab/background_migration/migrate_os_sbom_occurrences_to_components_without_prefix_spec.rb": 12.879215851000481,
598 "spec/lib/gitlab/background_migration/update_sbom_occurrences_component_name_based_on_pep503_spec.rb": 13.139672272000098,
599 "spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb": 10.740923441999257,
600 "spec/lib/gitlab/background_migration/backfill_deploy_tokens_sharding_key_spec.rb": 4.684611568000037,
601 "spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb": 4.541035497999474,
602 "spec/lib/gitlab/background_migration/batching_strategies/backfill_project_statistics_with_container_registry_size_batching_strategy_spec.rb": 4.211218525999357
603}
604Knapsack global time execution for tests: 12m 10s
605Finished in 24 minutes 58 seconds (files took 1 minute 35.99 seconds to load)
60637 examples, 0 failures
607Randomized with seed 32085
608[TEST PROF INFO] Time spent in factories: 00:00.320 (0.02% of total time)
609RSpec exited with 0.
610No examples to retry, congrats!
611 Running after_script 00:11
612Running after script...
613$ source scripts/utils.sh
614$ bundle exec gem list gitlab_quality-test_tooling
615gitlab_quality-test_tooling (1.33.0)
616$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
617 Report test failures 00:02
620$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
621 Report test flakiness 00:00
623$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
624 Report test slowness 00:02
627$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
628 Report test slowness in MR note 00:00
630$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
631 Report test files close to timing out 00:02
634$ tooling/bin/push_job_metrics || true
635[job-metrics] Pushing job metrics file for the CI/CD job.
636[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
637 Saving cache for successful job 00:01
638Not uploading cache ruby-gems-debian-bookworm-ruby-3.1.5-17 due to policy
639 Uploading artifacts for successful job 00:06
640Uploading artifacts...
641auto_explain/: found 3 matching artifact files and directories
642coverage/: found 5 matching artifact files and directories
643crystalball/: found 5 matching artifact files and directories
644WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
645knapsack/: found 4 matching artifact files and directories
646rspec/: found 12 matching artifact files and directories
647WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
648log/*.log: found 13 matching artifact files and directories
649WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346460/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
650WARNING: Retrying... context=artifacts-uploader error=request redirected
651Uploading artifacts as "archive" to coordinator... 201 Created id=7471346460 responseStatus=201 Created token=glcbt-66
652Uploading artifacts...
653rspec/rspec-*.xml: found 1 matching artifact files and directories
654WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346460/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
655WARNING: Retrying... context=artifacts-uploader error=request redirected
656Uploading artifacts as "junit" to coordinator... 201 Created id=7471346460 responseStatus=201 Created token=glcbt-66
657 Cleaning up project directory and file based variables 00:00
658Job succeeded