Skip to content
Snippets Groups Projects

rspec background_migration pg14 3/10

Passed Started by
🤖 GitLab Bot 🤖
@gitlab-bot
1Running with gitlab-runner 17.0.0~pre.88.g761ae5dd (761ae5dd)
2 on green-1.private.runners-manager.gitlab.com/gitlab.com/gitlab-org 4bq1s9yM, system ID: s_9d15f3e4e7ae
3 feature flags: FF_NETWORK_PER_BUILD:true
4Resolving secrets
5 Preparing the "docker+machine" executor 00:54
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:07
25Running on runner-4bq1s9ym-project-278964-concurrent-0 via runner-4bq1s9ym-private-1722413833-1f6675ce...
26 Getting source from Git repository 00:00
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
30 Restoring cache 00:18
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:16
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$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
102==> 'gem install knapsack --no-document' succeeded in 1 seconds.
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 27:52
113[10:15:13] 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_3_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_3_10_278964_report.json
122NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_3_10_278964_report.json
123RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-7471345477.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 1.647997974 seconds
141# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_statistics_storage_size_with_recent_size_spec.rb. Expected to take 2 minutes 37.71 seconds.
142Gitlab::BackgroundMigration::BackfillProjectStatisticsStorageSizeWithRecentSize
143 #filter_batch
144 filters out project_statistics with no repository_size
145 when on GitLab.com
146 behaves like filters out project_statistics updated since recent objects went live
147 filters out project_statistics updated since recent objects went live
148 when Gitlab.dev_or_test_env? is true
149 behaves like filters out project_statistics updated since recent objects went live
150 filters out project_statistics updated since recent objects went live
151# [RSpecRunTime] RSpec elapsed time: 1 minute 52.93 seconds. Current RSS: ~1464M. Threads: 2. load average: 1.09 1.20 1.21 1/277 405
152.
153 when on self-managed
154 does not filter out project_statistics updated since recent objects went live
155# [RSpecRunTime] RSpec elapsed time: 2 minutes 4.96 seconds. Current RSS: ~1506M. Threads: 2. load average: 1.07 1.19 1.20 1/278 406
156.
157 #perform
158 coerces a null wiki_size to 0
159 coerces a null snippets_size to 0
160 when project_statistics backfill runs
161 uses repository#recent_objects_size for repository_size
162# [RSpecRunTime] RSpec elapsed time: 2 minutes 36.95 seconds. Current RSS: ~1521M. Threads: 2. load average: 1.21 1.22 1.21 1/276 408
163.
164INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
165INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
166INFO: "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
167INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
168INFO: "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
169INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
170INFO: "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
171INFO: analyzing "public.p_ci_job_annotations" inheritance tree
172INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
173INFO: "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
174INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
175INFO: "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
176INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
177INFO: "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
178INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
179INFO: analyzing "public.ci_builds_metadata"
180INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
181INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
182INFO: "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
183INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
184INFO: "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
185INFO: analyzing "public.p_ci_builds" inheritance tree
186INFO: analyzing "public.ci_builds"
187INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
188INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
189INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
190INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
191INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
192I, [2024-07-31T10:19:39.444741 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
193I, [2024-07-31T10:19:59.440033 #327] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
194INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
195INFO: analyzing "public.ci_pipeline_variables"
196INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
197I, [2024-07-31T10:20:00.977595 #327] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
198I, [2024-07-31T10:20:00.979158 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
199I, [2024-07-31T10:20:00.979955 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
200INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
201INFO: analyzing "public.ci_pipeline_variables"
202INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
203INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
204INFO: analyzing "public.ci_job_artifacts"
205INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
206I, [2024-07-31T10:20:07.053371 #327] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
207I, [2024-07-31T10:20:07.054854 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
208I, [2024-07-31T10:20:07.055854 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
209INFO: analyzing "public.p_ci_stages" inheritance tree
210INFO: analyzing "public.ci_stages"
211INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
212I, [2024-07-31T10:20:10.391825 #327] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
213I, [2024-07-31T10:20:10.392965 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
214I, [2024-07-31T10:20:10.393785 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
215I, [2024-07-31T10:20:11.616280 #327] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
216I, [2024-07-31T10:20:17.902080 #327] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
217I, [2024-07-31T10:20:31.457263 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
218I, [2024-07-31T10:20:31.458304 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
219I, [2024-07-31T10:20:31.459125 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
220I, [2024-07-31T10:20:43.319069 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
221I, [2024-07-31T10:20:50.248714 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
222# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_statistics_storage_size_with_recent_size_spec.rb. It took 3 minutes 57.67 seconds. Expected to take 2 minutes 37.71 seconds.
223# [RSpecRunTime] RSpec elapsed time: 4 minutes 2.73 seconds. Current RSS: ~1372M. Threads: 2. load average: 1.00 1.13 1.18 1/276 409
224.
225# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb. Expected to take 1 minute 40.24 seconds.
226Gitlab::BackgroundMigration::BackfillTopicsTitle
227 correctly backfills the title of the topics
228INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
229INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
230INFO: "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
231INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
232INFO: "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
233INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
234INFO: "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
235INFO: analyzing "public.p_ci_job_annotations" inheritance tree
236INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
237INFO: "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
238INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
239INFO: "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
240INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
241INFO: "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
242INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
243INFO: analyzing "public.ci_builds_metadata"
244INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
245INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
246INFO: "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
247INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
248INFO: "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
249INFO: analyzing "public.p_ci_builds" inheritance tree
250INFO: analyzing "public.ci_builds"
251INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
252INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
253INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
254INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
255INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
256I, [2024-07-31T10:22:56.354792 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
257I, [2024-07-31T10:23:16.602654 #327] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
258INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
259INFO: analyzing "public.ci_pipeline_variables"
260INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
261I, [2024-07-31T10:23:18.216582 #327] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
262I, [2024-07-31T10:23:18.217897 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
263I, [2024-07-31T10:23:18.218615 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
264INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
265INFO: analyzing "public.ci_pipeline_variables"
266INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
267INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
268INFO: analyzing "public.ci_job_artifacts"
269INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
270I, [2024-07-31T10:23:24.605551 #327] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
271I, [2024-07-31T10:23:24.606686 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
272I, [2024-07-31T10:23:24.607549 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
273INFO: analyzing "public.p_ci_stages" inheritance tree
274INFO: analyzing "public.ci_stages"
275INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
276I, [2024-07-31T10:23:27.982052 #327] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
277I, [2024-07-31T10:23:27.983280 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
278I, [2024-07-31T10:23:27.984153 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
279I, [2024-07-31T10:23:29.270184 #327] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
280I, [2024-07-31T10:23:35.768304 #327] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
281I, [2024-07-31T10:23:49.570964 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
282I, [2024-07-31T10:23:49.572430 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
283I, [2024-07-31T10:23:49.573178 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
284I, [2024-07-31T10:24:01.408208 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
285I, [2024-07-31T10:24:08.353910 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
286# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb. It took 3 minutes 17.79 seconds. Expected to take 1 minute 40.24 seconds.
287# [RSpecRunTime] RSpec elapsed time: 7 minutes 20.57 seconds. Current RSS: ~1354M. Threads: 2. load average: 0.96 1.06 1.15 3/277 410
288.
289# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb. Expected to take 1 minute 26.65 seconds.
290Gitlab::BackgroundMigration::BackfillUserPreferencesWithDefaults
291 backfills the null values with the default values
292INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
293INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
294INFO: "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
295INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
296INFO: "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
297INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
298INFO: "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
299INFO: analyzing "public.p_ci_job_annotations" inheritance tree
300INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
301INFO: "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
302INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
303INFO: "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
304INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
305INFO: "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
306INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
307INFO: analyzing "public.ci_builds_metadata"
308INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
309INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
310INFO: "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
311INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
312INFO: "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
313INFO: analyzing "public.p_ci_builds" inheritance tree
314INFO: analyzing "public.ci_builds"
315INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
316INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
317INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
318INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
319INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
320I, [2024-07-31T10:25:47.805457 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
321I, [2024-07-31T10:26:08.404510 #327] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
322INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
323INFO: analyzing "public.ci_pipeline_variables"
324INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
325I, [2024-07-31T10:26:10.043628 #327] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
326I, [2024-07-31T10:26:10.044822 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
327I, [2024-07-31T10:26:10.045656 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
328INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
329INFO: analyzing "public.ci_pipeline_variables"
330INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
331INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
332INFO: analyzing "public.ci_job_artifacts"
333INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
334I, [2024-07-31T10:26:15.958412 #327] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
335I, [2024-07-31T10:26:15.959651 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
336I, [2024-07-31T10:26:15.960411 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
337INFO: analyzing "public.p_ci_stages" inheritance tree
338INFO: analyzing "public.ci_stages"
339INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
340I, [2024-07-31T10:26:19.293455 #327] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
341I, [2024-07-31T10:26:19.294646 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
342I, [2024-07-31T10:26:19.295497 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
343I, [2024-07-31T10:26:20.599343 #327] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
344I, [2024-07-31T10:26:26.854480 #327] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
345I, [2024-07-31T10:26:40.787071 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
346I, [2024-07-31T10:26:40.788955 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
347I, [2024-07-31T10:26:40.789862 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
348I, [2024-07-31T10:26:52.591293 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
349I, [2024-07-31T10:26:59.510765 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
350# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb. It took 2 minutes 51.07 seconds. Expected to take 1 minute 26.65 seconds.
351# [RSpecRunTime] RSpec elapsed time: 10 minutes 11.72 seconds. Current RSS: ~1368M. Threads: 2. load average: 0.88 1.00 1.10 1/276 411
352.
353# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. Expected to take 1 minute 4.67 seconds.
354Gitlab::BackgroundMigration::BackfillIssueSearchDataNamespaceId
355WARNING: Active Record does not support composite primary key.
356issue_search_data has composite primary key. Composite primary key is ignored.
357WARNING: Active Record does not support composite primary key.
358issue_search_data has composite primary key. Composite primary key is ignored.
359 backfills namespace_id for the specified records
360I, [2024-07-31T10:28:12.811495 #327] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
361INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
362INFO: analyzing "public.ci_pipeline_variables"
363INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
364I, [2024-07-31T10:28:14.475731 #327] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
365I, [2024-07-31T10:28:14.477156 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
366I, [2024-07-31T10:28:14.477949 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
367INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
368INFO: analyzing "public.ci_pipeline_variables"
369INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
370INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
371INFO: analyzing "public.ci_job_artifacts"
372INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
373I, [2024-07-31T10:28:20.584735 #327] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
374I, [2024-07-31T10:28:20.585818 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
375I, [2024-07-31T10:28:20.586683 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
376INFO: analyzing "public.p_ci_stages" inheritance tree
377INFO: analyzing "public.ci_stages"
378INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
379I, [2024-07-31T10:28:24.026119 #327] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
380I, [2024-07-31T10:28:24.027826 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
381I, [2024-07-31T10:28:24.028647 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
382I, [2024-07-31T10:28:25.138681 #327] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
383I, [2024-07-31T10:28:31.538698 #327] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
384I, [2024-07-31T10:28:45.087397 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
385I, [2024-07-31T10:28:45.088531 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
386I, [2024-07-31T10:28:45.089245 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
387I, [2024-07-31T10:28:56.619855 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
388I, [2024-07-31T10:29:03.500789 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
389# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. It took 2 minutes 4.04 seconds. Expected to take 1 minute 4.67 seconds.
390# [RSpecRunTime] RSpec elapsed time: 12 minutes 15.81 seconds. Current RSS: ~1354M. Threads: 2. load average: 0.88 0.98 1.08 1/276 412
391.
392# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. Expected to take 58.21 seconds.
393Gitlab::BackgroundMigration::DropVulnerabilitiesWithoutFindingId
394 #perform
395 removes all Vulnerabilities without a finding_id
396# [RSpecRunTime] RSpec elapsed time: 13 minutes 10.21 seconds. Current RSS: ~1392M. Threads: 2. load average: 0.82 0.95 1.06 1/276 413
397.
398INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
399INFO: analyzing "public.ci_job_artifacts"
400INFO: "ci_job_artifacts": 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:30:11.854325 #327] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
402I, [2024-07-31T10:30:11.855486 #327] 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:30:11.856328 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
404INFO: analyzing "public.p_ci_stages" inheritance tree
405INFO: analyzing "public.ci_stages"
406INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
407I, [2024-07-31T10:30:15.213547 #327] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
408I, [2024-07-31T10:30:15.214729 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
409I, [2024-07-31T10:30:15.215585 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
410I, [2024-07-31T10:30:16.397077 #327] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
411I, [2024-07-31T10:30:22.802469 #327] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
412I, [2024-07-31T10:30:36.540727 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
413I, [2024-07-31T10:30:36.541854 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
414I, [2024-07-31T10:30:36.542650 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
415I, [2024-07-31T10:30:48.287914 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
416I, [2024-07-31T10:30:55.210561 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
417# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. It took 1 minute 51.59 seconds. Expected to take 58.21 seconds.
418# [RSpecRunTime] RSpec elapsed time: 14 minutes 7.46 seconds. Current RSS: ~1355M. Threads: 2. load average: 0.85 0.95 1.05 1/277 414
419.
420# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_approval_project_rules_users_project_id_spec.rb. Expected to take 48.17 seconds.
421Gitlab::BackgroundMigration::BackfillApprovalProjectRulesUsersProjectId
422 constructs a valid query
423 performs without error
424I, [2024-07-31T10:32:05.182034 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
425I, [2024-07-31T10:32:05.183156 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
426I, [2024-07-31T10:32:05.183940 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
427I, [2024-07-31T10:32:16.549808 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
428I, [2024-07-31T10:32:23.442741 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
429# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_approval_project_rules_users_project_id_spec.rb. It took 1 minute 28.08 seconds. Expected to take 48.17 seconds.
430# [RSpecRunTime] RSpec elapsed time: 15 minutes 35.59 seconds. Current RSS: ~1320M. Threads: 2. load average: 0.87 0.95 1.04 1/278 415
431.
432# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_boards_epic_lists_group_id_spec.rb. Expected to take 35.06 seconds.
433Gitlab::BackgroundMigration::BackfillBoardsEpicListsGroupId
434 performs without error
435 constructs a valid query
436I, [2024-07-31T10:33:06.664407 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
437I, [2024-07-31T10:33:06.665641 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
438I, [2024-07-31T10:33:06.666447 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
439I, [2024-07-31T10:33:17.696481 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
440I, [2024-07-31T10:33:24.227424 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
441# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_boards_epic_lists_group_id_spec.rb. It took 1 minute 0.43 second. Expected to take 35.06 seconds.
442# [RSpecRunTime] RSpec elapsed time: 16 minutes 36.08 seconds. Current RSS: ~1352M. Threads: 2. load average: 0.75 0.89 1.01 1/279 416
443.
444# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_debian_group_distribution_keys_group_id_spec.rb. Expected to take 31.74 seconds.
445Gitlab::BackgroundMigration::BackfillPackagesDebianGroupDistributionKeysGroupId
446 constructs a valid query
447 performs without error
448I, [2024-07-31T10:34:15.662103 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
449I, [2024-07-31T10:34:22.458109 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
450# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_debian_group_distribution_keys_group_id_spec.rb. It took 58.41 seconds. Expected to take 31.74 seconds.
451# [RSpecRunTime] RSpec elapsed time: 17 minutes 34.54 seconds. Current RSS: ~1360M. Threads: 2. load average: 0.90 0.91 1.00 1/279 417
452.
453# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_boards_epic_user_preferences_group_id_spec.rb. Expected to take 31.0 seconds.
454Gitlab::BackgroundMigration::BackfillBoardsEpicUserPreferencesGroupId
455 performs without error
456 constructs a valid query
457I, [2024-07-31T10:35:04.268830 #327] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
458I, [2024-07-31T10:35:04.269933 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
459I, [2024-07-31T10:35:04.270660 #327] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
460I, [2024-07-31T10:35:16.240217 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
461I, [2024-07-31T10:35:22.749861 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
462# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_boards_epic_user_preferences_group_id_spec.rb. It took 59.95 seconds. Expected to take 31.0 seconds.
463# [RSpecRunTime] RSpec elapsed time: 18 minutes 34.55 seconds. Current RSS: ~1358M. Threads: 2. load average: 1.17 0.99 1.02 1/279 418
464.
465# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_dast_profiles_tags_project_id_spec.rb. Expected to take 30.33 seconds.
466Gitlab::BackgroundMigration::BackfillDastProfilesTagsProjectId
467 performs without error
468 constructs a valid query
469I, [2024-07-31T10:36:14.895171 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
470I, [2024-07-31T10:36:21.722442 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
471# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_dast_profiles_tags_project_id_spec.rb. It took 59.1 seconds. Expected to take 30.33 seconds.
472# [RSpecRunTime] RSpec elapsed time: 19 minutes 33.7 seconds. Current RSS: ~1357M. Threads: 2. load average: 1.00 0.98 1.01 1/279 419
473.
474# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_release_links_project_id_spec.rb. Expected to take 29.6 seconds.
475Gitlab::BackgroundMigration::BackfillReleaseLinksProjectId
476 performs without error
477 constructs a valid query
478I, [2024-07-31T10:37:12.926586 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
479I, [2024-07-31T10:37:19.689275 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
480# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_release_links_project_id_spec.rb. It took 58.18 seconds. Expected to take 29.6 seconds.
481# [RSpecRunTime] RSpec elapsed time: 20 minutes 31.94 seconds. Current RSS: ~1357M. Threads: 2. load average: 1.05 1.00 1.01 1/279 420
482.
483# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_or_drop_ci_pipeline_on_project_id_spec.rb. Expected to take 23.3 seconds.
484Gitlab::BackgroundMigration::BackfillOrDropCiPipelineOnProjectId
485 #perform
486WARNING: Active Record does not support composite primary key.
487p_ci_builds has composite primary key. Composite primary key is ignored.
488 backfills if applicable otherwise deletes
489 for migrations with merge_request
490WARNING: Active Record does not support composite primary key.
491p_ci_builds has composite primary key. Composite primary key is ignored.
492 backfills from merge_request
493# [RSpecRunTime] RSpec elapsed time: 20 minutes 48.04 seconds. Current RSS: ~1476M. Threads: 2. load average: 1.04 1.00 1.01 1/279 421
494.
495 when associations are invalid as well
496WARNING: Active Record does not support composite primary key.
497p_ci_builds has composite primary key. Composite primary key is ignored.
498WARNING: Active Record does not support composite primary key.
499p_ci_builds has composite primary key. Composite primary key is ignored.
500 deletes pipeline if associations do not have project_id
501# [RSpecRunTime] RSpec elapsed time: 20 minutes 52.65 seconds. Current RSS: ~1494M. Threads: 2. load average: 1.03 1.00 1.01 1/279 422
502.
503# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_or_drop_ci_pipeline_on_project_id_spec.rb. It took 35.11 seconds. Expected to take 23.3 seconds.
504# [RSpecRunTime] RSpec elapsed time: 21 minutes 7.11 seconds. Current RSS: ~1392M. Threads: 2. load average: 0.96 0.98 1.00 2/279 423
505.
506# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_candidate_metadata_project_id_spec.rb. Expected to take 17.76 seconds.
507Gitlab::BackgroundMigration::BackfillMlCandidateMetadataProjectId
508 constructs a valid query
509 performs without error
510I, [2024-07-31T10:38:23.647300 #327] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
511I, [2024-07-31T10:38:29.981753 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
512# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_candidate_metadata_project_id_spec.rb. It took 34.72 seconds. Expected to take 17.76 seconds.
513# [RSpecRunTime] RSpec elapsed time: 21 minutes 41.88 seconds. Current RSS: ~1345M. Threads: 2. load average: 1.03 1.00 1.00 1/279 424
514.
515# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_users_group_id_spec.rb. Expected to take 17.12 seconds.
516Gitlab::BackgroundMigration::BackfillApprovalGroupRulesUsersGroupId
517 performs without error
518 constructs a valid query
519I, [2024-07-31T10:39:03.971915 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
520# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_users_group_id_spec.rb. It took 34.03 seconds. Expected to take 17.12 seconds.
521# [RSpecRunTime] RSpec elapsed time: 22 minutes 15.96 seconds. Current RSS: ~1346M. Threads: 2. load average: 0.92 0.97 1.00 1/278 425
522.
523# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_epic_issues_namespace_id_spec.rb. Expected to take 12.08 seconds.
524Gitlab::BackgroundMigration::BackfillEpicIssuesNamespaceId
525 performs without error
526 constructs a valid query
527I, [2024-07-31T10:39:27.022019 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
528# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_epic_issues_namespace_id_spec.rb. It took 23.57 seconds. Expected to take 12.08 seconds.
529# [RSpecRunTime] RSpec elapsed time: 22 minutes 39.59 seconds. Current RSS: ~1386M. Threads: 2. load average: 0.92 0.97 0.99 1/279 426
530.
531# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_work_item_hierarchy_for_epics_spec.rb. Expected to take 10.75 seconds.
532Gitlab::BackgroundMigration::BackfillWorkItemHierarchyForEpics
533 backfills data correctly
534I, [2024-07-31T10:39:51.148156 #327] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
535# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_work_item_hierarchy_for_epics_spec.rb. It took 23.49 seconds. Expected to take 10.75 seconds.
536# [RSpecRunTime] RSpec elapsed time: 23 minutes 3.14 seconds. Current RSS: ~1366M. Threads: 2. load average: 0.95 0.97 1.00 1/279 427
537.
538# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_upstream_pipeline_partition_id_on_p_ci_builds_spec.rb. Expected to take 4.98 seconds.
539Gitlab::BackgroundMigration::BackfillUpstreamPipelinePartitionIdOnPCiBuilds
540 #perform
541 backfills upstream_pipeline_partition_id
542# [RSpecRunTime] RSpec elapsed time: 23 minutes 7.66 seconds. Current RSS: ~1385M. Threads: 2. load average: 1.03 0.99 1.00 1/279 428
543.
544# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_upstream_pipeline_partition_id_on_p_ci_builds_spec.rb. It took 11.95 seconds. Expected to take 4.98 seconds.
545# [RSpecRunTime] RSpec elapsed time: 23 minutes 15.14 seconds. Current RSS: ~1383M. Threads: 2. load average: 1.03 0.99 1.00 1/279 429
546.
547# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb. Expected to take 4.76 seconds.
548Gitlab::BackgroundMigration::PopulateOperationVisibilityPermissionsFromOperations
549 updates all project settings records from their operations_access_level
550# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb. It took 11.81 seconds. Expected to take 4.76 seconds.
551# [RSpecRunTime] RSpec elapsed time: 23 minutes 27.01 seconds. Current RSS: ~1391M. Threads: 2. load average: 1.10 1.01 1.01 1/279 430
552.
553# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration_spec.rb. Expected to take 3.11 seconds.
554Gitlab::BackgroundMigration
555 .queue
556 returns background migration worker queue
557 .steal
558 when the queue contains unprocessed jobs
559 uses the coordinator to steal jobs
560 when a custom predicate is given
561 steals jobs that match the predicate
562 does not steal jobs that do not match the predicate
563 when retry_dead_jobs is true
564 steals from the dead and retry queue
565 .perform
566 uses the coordinator to perform a background migration
567 .exists?
568 uses the coordinator to find if a job exists
569 uses the coordinator to find a job does not exist
570 .remaining
571 uses the coordinator to find the number of remaining jobs
572# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration_spec.rb. It took 2.62 seconds. Expected to take 3.11 seconds.
573auto_explain log contains 1017 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-3-10.327.main.ndjson.gz
574took 27.728865331
575auto_explain log contains 1018 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-3-10.327.ci.ndjson.gz
576took 25.643143477
577[TEST PROF INFO] EventProf results for sql.active_record
578Total time: 15:18.897 of 23:24.616 (65.42%)
579Total events: 706307
580Top 5 slowest suites (by time):
581Gitlab::Backg...illTopicsTitle (./spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb:5) – 02:22.107 (94303 / 1) of 03:17.859 (71.82%)
582Gitlab::Backg...WithRecentSize (./spec/lib/gitlab/background_migration/backfill_project_statistics_storage_size_with_recent_size_spec.rb:5) – 02:12.384 (101459 / 7) of 03:57.724 (55.69%)
583Gitlab::Backg...esWithDefaults (./spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb:5) – 02:01.187 (88426 / 1) of 02:51.125 (70.82%)
584Gitlab::Backg...ataNamespaceId (./spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb:5) – 01:28.720 (68295 / 1) of 02:04.096 (71.49%)
585Gitlab::Backg...thoutFindingId (./spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb:5) – 01:19.117 (61813 / 1) of 01:51.645 (70.86%)
586Knapsack report was generated. Preview:
587{
588 "spec/lib/gitlab/background_migration/backfill_project_statistics_storage_size_with_recent_size_spec.rb": 152.42946623700027,
589 "spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb": 97.0996625100006,
590 "spec/lib/gitlab/background_migration/backfill_user_preferences_with_defaults_spec.rb": 84.82327603700014,
591 "spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb": 59.89105966599982,
592 "spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb": 54.52465614999983,
593 "spec/lib/gitlab/background_migration/backfill_approval_project_rules_users_project_id_spec.rb": 45.53944006100028,
594 "spec/lib/gitlab/background_migration/backfill_boards_epic_lists_group_id_spec.rb": 31.347654502000296,
595 "spec/lib/gitlab/background_migration/backfill_packages_debian_group_distribution_keys_group_id_spec.rb": 28.585300190000453,
596 "spec/lib/gitlab/background_migration/backfill_boards_epic_user_preferences_group_id_spec.rb": 30.040201519999755,
597 "spec/lib/gitlab/background_migration/backfill_dast_profiles_tags_project_id_spec.rb": 28.892015481998897,
598 "spec/lib/gitlab/background_migration/backfill_release_links_project_id_spec.rb": 29.12446615599947,
599 "spec/lib/gitlab/background_migration/backfill_or_drop_ci_pipeline_on_project_id_spec.rb": 20.975673913999344,
600 "spec/lib/gitlab/background_migration/backfill_ml_candidate_metadata_project_id_spec.rb": 17.11766746899957,
601 "spec/lib/gitlab/background_migration/backfill_approval_group_rules_users_group_id_spec.rb": 16.61957778299984,
602 "spec/lib/gitlab/background_migration/backfill_epic_issues_namespace_id_spec.rb": 11.600993852000101,
603 "spec/lib/gitlab/background_migration/backfill_work_item_hierarchy_for_epics_spec.rb": 10.2184937359998,
604 "spec/lib/gitlab/background_migration/backfill_upstream_pipeline_partition_id_on_p_ci_builds_spec.rb": 4.642219934999957,
605 "spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb": 4.689915991000817,
606 "spec/lib/gitlab/background_migration_spec.rb": 2.6244386750004196
607}
608Knapsack global time execution for tests: 12m 10s
609Finished in 24 minutes 24 seconds (files took 1 minute 42.46 seconds to load)
61044 examples, 0 failures
611Randomized with seed 15029
612[TEST PROF INFO] Time spent in factories: 00:00.312 (0.02% of total time)
613RSpec exited with 0.
614No examples to retry, congrats!
615 Running after_script 00:09
616Running after script...
617$ source scripts/utils.sh
618$ bundle exec gem list gitlab_quality-test_tooling
619gitlab_quality-test_tooling (1.33.0)
620$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
621 Report test failures 00:02
624$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
625 Report test flakiness 00:00
627$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
628 Report test slowness 00:02
631$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
632 Report test slowness in MR note 00:00
634$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
635 Report test files close to timing out 00:01
638$ tooling/bin/push_job_metrics || true
639[job-metrics] Pushing job metrics file for the CI/CD job.
640[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
641 Saving cache for successful job 00:00
642Not uploading cache ruby-gems-debian-bookworm-ruby-3.1.5-17 due to policy
643 Uploading artifacts for successful job 00:05
644Uploading artifacts...
645auto_explain/: found 3 matching artifact files and directories
646coverage/: found 5 matching artifact files and directories
647crystalball/: found 5 matching artifact files and directories
648WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
649knapsack/: found 4 matching artifact files and directories
650rspec/: found 12 matching artifact files and directories
651WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
652log/*.log: found 13 matching artifact files and directories
653WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471345477/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
654WARNING: Retrying... context=artifacts-uploader error=request redirected
655Uploading artifacts as "archive" to coordinator... 201 Created id=7471345477 responseStatus=201 Created token=glcbt-66
656Uploading artifacts...
657rspec/rspec-*.xml: found 1 matching artifact files and directories
658WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471345477/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
659WARNING: Retrying... context=artifacts-uploader error=request redirected
660Uploading artifacts as "junit" to coordinator... 201 Created id=7471345477 responseStatus=201 Created token=glcbt-66
661 Cleaning up project directory and file based variables 00:01
662Job succeeded