Skip to content
Snippets Groups Projects

rspec background_migration pg14 no_gitaly_transactions 4/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:08
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:00
25Running on runner-4bq1s9ym-project-278964-concurrent-0 via runner-4bq1s9ym-private-1722411386-c01fb3a8...
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:38
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:07
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 24:37
113[10:14:31] 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_4_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_4_10_278964_report.json
122NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_no_gitaly_transactions_4_10_278964_report.json
123RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-7471346453.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.010019042 seconds
141# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/job_coordinator_spec.rb. Expected to take 2 minutes 23.0 seconds.
142Gitlab::BackgroundMigration::JobCoordinator
143 .for_tracking_database
144 returns an executor with the correct worker class and database
145 when an invalid value is given
146 raises an error
147 #queue
148 returns background migration worker queue
149# [RSpecRunTime] RSpec elapsed time: 17.36 seconds. Current RSS: ~1438M. Threads: 2. load average: 1.13 1.14 1.15 1/270 403
150.
151 #with_shared_connection
152 yields to the block after properly configuring SharedModel
153# [RSpecRunTime] RSpec elapsed time: 22.55 seconds. Current RSS: ~1473M. Threads: 2. load average: 1.12 1.14 1.15 1/270 404
154.
155 #pending_jobs
156 when there are enqueued jobs
157 does not include jobs for other workers
158 when using a different shard instance
159 uses the appropriate shard for the store
160# [RSpecRunTime] RSpec elapsed time: 30.32 seconds. Current RSS: ~1483M. Threads: 2. load average: 1.11 1.14 1.14 1/271 406
161.
162 when not including dead jobs
163 includes current and future jobs
164# [RSpecRunTime] RSpec elapsed time: 34.41 seconds. Current RSS: ~1486M. Threads: 2. load average: 1.10 1.14 1.14 1/271 407
165.
166 when including dead jobs
167 includes current and future jobs, and also dead and retry jobs
168# [RSpecRunTime] RSpec elapsed time: 38.83 seconds. Current RSS: ~1517M. Threads: 2. load average: 1.17 1.15 1.15 1/271 408
169.
170 #steal
171 when there are enqueued jobs present
172 when using a different shard instance
173 wraps job processing within Sidekiq::Client.via
174# [RSpecRunTime] RSpec elapsed time: 43.02 seconds. Current RSS: ~1521M. Threads: 2. load average: 1.16 1.15 1.15 1/271 409
175.
176 when queue contains unprocessed jobs
177 steals jobs from a queue
178 sets up the shared connection while stealing jobs
179 does not steal job that has already been taken
180 does not steal jobs for a different migration
181 when a custom predicate is given
182 steals jobs that match the predicate
183 does not steal jobs that do not match the predicate
184# [RSpecRunTime] RSpec elapsed time: 1 minute 6.67 seconds. Current RSS: ~1497M. Threads: 2. load average: 1.18 1.15 1.15 1/268 410
185.
186 when one of the jobs raises an error
187 enqueues the migration again and re-raises the error
188# [RSpecRunTime] RSpec elapsed time: 1 minute 11.01 seconds. Current RSS: ~1508M. Threads: 2. load average: 1.18 1.15 1.15 1/268 411
189.
190 when there are scheduled jobs present
191 steals all jobs from the scheduled sets
192# [RSpecRunTime] RSpec elapsed time: 1 minute 15.11 seconds. Current RSS: ~1517M. Threads: 2. load average: 1.17 1.15 1.15 1/268 412
193.
194 when there are enqueued and scheduled jobs present
195 steals from the scheduled sets queue first
196# [RSpecRunTime] RSpec elapsed time: 1 minute 19.07 seconds. Current RSS: ~1497M. Threads: 2. load average: 1.16 1.15 1.15 1/268 413
197.
198 when retry_dead_jobs is true
199 steals from the dead and retry queue
200# [RSpecRunTime] RSpec elapsed time: 1 minute 23.14 seconds. Current RSS: ~1495M. Threads: 2. load average: 1.14 1.14 1.15 1/268 414
201.
202 #perform
203 when the background migration does not inherit from BaseJob
204 performs a background migration with the configured shared connection
205# [RSpecRunTime] RSpec elapsed time: 1 minute 27.13 seconds. Current RSS: ~1486M. Threads: 2. load average: 1.21 1.16 1.15 1/268 415
206.
207 when the background migration inherits from BaseJob
208 passes the correct connection when constructing the migration
209# [RSpecRunTime] RSpec elapsed time: 1 minute 31.08 seconds. Current RSS: ~1514M. Threads: 2. load average: 1.21 1.16 1.15 1/268 416
210.
211 .remaining
212 is shard aware
213 when there are jobs remaining
214 returns the enqueued jobs plus the scheduled jobs
215# [RSpecRunTime] RSpec elapsed time: 1 minute 39.16 seconds. Current RSS: ~1482M. Threads: 2. load average: 1.18 1.15 1.15 1/268 417
216.
217 when there are no jobs remaining
218 returns zero
219# [RSpecRunTime] RSpec elapsed time: 1 minute 43.12 seconds. Current RSS: ~1513M. Threads: 2. load average: 1.16 1.15 1.15 1/268 418
220.
221 .exists?
222 is shard aware
223 when there are enqueued jobs present
224 returns true if specific job exists
225 returns false if specific job does not exist
226# [RSpecRunTime] RSpec elapsed time: 1 minute 55.0 seconds. Current RSS: ~1512M. Threads: 2. load average: 1.29 1.18 1.16 1/268 419
227.
228 when there are scheduled jobs present
229 returns true if specific job exists
230 returns false if specific job does not exist
231# [RSpecRunTime] RSpec elapsed time: 2 minutes 2.85 seconds. Current RSS: ~1484M. Threads: 2. load average: 1.40 1.21 1.17 1/268 420
232.
233 .dead_jobs?
234 when there are dead jobs present
235 returns true if specific job exists
236 returns false if specific job does not exist
237# [RSpecRunTime] RSpec elapsed time: 2 minutes 10.97 seconds. Current RSS: ~1479M. Threads: 2. load average: 1.37 1.20 1.17 1/268 421
238.
239 .retrying_jobs?
240 is shard aware
241 when there are dead jobs present
242 returns true if specific job exists
243 returns false if specific job does not exist
244# [RSpecRunTime] RSpec elapsed time: 2 minutes 22.57 seconds. Current RSS: ~1498M. Threads: 2. load average: 1.28 1.19 1.16 1/268 422
245.
246# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/job_coordinator_spec.rb. It took 2 minutes 26.68 seconds. Expected to take 2 minutes 23.0 seconds.
247# [RSpecRunTime] RSpec elapsed time: 2 minutes 31.19 seconds. Current RSS: ~1418M. Threads: 2. load average: 1.18 1.17 1.16 1/268 423
248.
249# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_owasp_top_ten_of_vulnerability_reads_spec.rb. Expected to take 1 minute 41.26 seconds.
250Gitlab::BackgroundMigration::BackfillOwaspTopTenOfVulnerabilityReads
251 #perform
252 with owasp top 10 data
253 updates vulnerability_reads
254 updates vulnerability_reads with correct mapping
255# [RSpecRunTime] RSpec elapsed time: 3 minutes 33.48 seconds. Current RSS: ~1442M. Threads: 2. load average: 1.31 1.20 1.17 1/269 424
256.
257 with incorrect owasp top 10 data
258 with incorrect long format external_id
259 behaves like does not update vulnerability_reads
260 is expected to be nil
261# [RSpecRunTime] RSpec elapsed time: 3 minutes 39.72 seconds. Current RSS: ~1485M. Threads: 2. load average: 1.36 1.21 1.17 1/269 425
262.
263 with incorrect short format external_id
264 behaves like does not update vulnerability_reads
265 is expected to be nil
266# [RSpecRunTime] RSpec elapsed time: 3 minutes 46.16 seconds. Current RSS: ~1491M. Threads: 2. load average: 1.33 1.21 1.17 1/269 426
267.
268 with incorrect external_type
269 behaves like does not update vulnerability_reads
270 is expected to be nil
271# [RSpecRunTime] RSpec elapsed time: 3 minutes 53.41 seconds. Current RSS: ~1512M. Threads: 2. load average: 1.28 1.20 1.17 1/269 427
272.
273 with no vulnerability identifiers match
274 does not update vulnerability_reads
275# [RSpecRunTime] RSpec elapsed time: 3 minutes 59.81 seconds. Current RSS: ~1558M. Threads: 2. load average: 1.34 1.22 1.18 1/269 428
276.
277INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
278INFO: analyzing "public.ci_pipeline_variables"
279INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
280INFO: analyzing "gitlab_partitions_dynamic.ci_pipeline_variables_102"
281INFO: "ci_pipeline_variables_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
282INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
283INFO: analyzing "public.ci_job_artifacts"
284INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
285I, [2024-07-31T10:20:09.725717 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
286I, [2024-07-31T10:20:09.726978 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
287I, [2024-07-31T10:20:09.728049 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
288INFO: analyzing "public.p_ci_stages" inheritance tree
289INFO: analyzing "public.ci_stages"
290INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
291I, [2024-07-31T10:20:13.098702 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
292I, [2024-07-31T10:20:13.099901 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
293I, [2024-07-31T10:20:13.100704 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
294I, [2024-07-31T10:20:14.311695 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
295I, [2024-07-31T10:20:20.541730 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
296I, [2024-07-31T10:20:33.765353 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
297I, [2024-07-31T10:20:33.766437 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
298I, [2024-07-31T10:20:33.767723 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
299I, [2024-07-31T10:20:45.187247 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
300I, [2024-07-31T10:20:51.723105 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
301# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_owasp_top_ten_of_vulnerability_reads_spec.rb. It took 2 minutes 26.87 seconds. Expected to take 1 minute 41.26 seconds.
302# [RSpecRunTime] RSpec elapsed time: 4 minutes 58.12 seconds. Current RSS: ~1385M. Threads: 2. load average: 1.17 1.19 1.17 1/268 429
303.
304# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb. Expected to take 1 minute 29.6 seconds.
305Gitlab::BackgroundMigration::BackfillDesiredShardingKeyJob
306 #perform
307 backfills the missing project_id for the batch
308# [RSpecRunTime] RSpec elapsed time: 6 minutes 10.28 seconds. Current RSS: ~1431M. Threads: 2. load average: 1.05 1.16 1.16 1/267 430
309.
310 #constuct_query
311 constructs a query using the supplied job arguments
312# [RSpecRunTime] RSpec elapsed time: 6 minutes 18.41 seconds. Current RSS: ~1488M. Threads: 2. load average: 1.04 1.15 1.16 1/267 431
313.
314I, [2024-07-31T10:22:35.522756 #326] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
315INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
316INFO: analyzing "public.ci_pipeline_variables"
317INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
318I, [2024-07-31T10:22:37.098531 #326] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
319I, [2024-07-31T10:22:37.099720 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
320I, [2024-07-31T10:22:37.100549 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
321INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
322INFO: analyzing "public.ci_pipeline_variables"
323INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
324INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
325INFO: analyzing "public.ci_job_artifacts"
326INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
327I, [2024-07-31T10:22:43.281203 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
328I, [2024-07-31T10:22:43.282321 #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:22:43.283246 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
330INFO: analyzing "public.p_ci_stages" inheritance tree
331INFO: analyzing "public.ci_stages"
332INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
333I, [2024-07-31T10:22:46.667180 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
334I, [2024-07-31T10:22:46.668576 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
335I, [2024-07-31T10:22:46.669631 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
336I, [2024-07-31T10:22:47.965804 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
337I, [2024-07-31T10:22:54.340637 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
338I, [2024-07-31T10:23:08.416120 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
339I, [2024-07-31T10:23:08.417214 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
340I, [2024-07-31T10:23:08.417951 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
341I, [2024-07-31T10:23:20.409664 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
342I, [2024-07-31T10:23:27.392602 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
343# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb. It took 2 minutes 35.77 seconds. Expected to take 1 minute 29.6 seconds.
344# [RSpecRunTime] RSpec elapsed time: 7 minutes 33.95 seconds. Current RSS: ~1376M. Threads: 2. load average: 0.85 1.08 1.13 1/267 432
345.
346# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb. Expected to take 1 minute 6.31 seconds.
347Gitlab::BackgroundMigration::BackfillBranchProtectionNamespaceSetting
348 updates default_branch_protection_defaults to a correct value
349I, [2024-07-31T10:24:41.223930 #326] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
350INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
351INFO: analyzing "public.ci_pipeline_variables"
352INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
353I, [2024-07-31T10:24:42.871524 #326] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
354I, [2024-07-31T10:24:42.872808 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
355I, [2024-07-31T10:24:42.873680 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
356INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
357INFO: analyzing "public.ci_pipeline_variables"
358INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
359INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
360INFO: analyzing "public.ci_job_artifacts"
361INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
362I, [2024-07-31T10:24:49.871752 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
363I, [2024-07-31T10:24:49.873100 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
364I, [2024-07-31T10:24:49.874052 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
365INFO: analyzing "public.p_ci_stages" inheritance tree
366INFO: analyzing "public.ci_stages"
367INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
368I, [2024-07-31T10:24:53.118591 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
369I, [2024-07-31T10:24:53.119818 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
370I, [2024-07-31T10:24:53.120626 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
371I, [2024-07-31T10:24:54.344241 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
372I, [2024-07-31T10:25:00.585235 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
373I, [2024-07-31T10:25:13.983711 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
374I, [2024-07-31T10:25:13.984787 #326] 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:25:13.985567 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
376I, [2024-07-31T10:25:26.214392 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
377I, [2024-07-31T10:25:33.120088 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
378# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb. It took 2 minutes 5.56 seconds. Expected to take 1 minute 6.31 seconds.
379# [RSpecRunTime] RSpec elapsed time: 9 minutes 39.57 seconds. Current RSS: ~1363M. Threads: 2. load average: 1.03 1.06 1.12 1/267 433
380.
381# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_config_spec.rb. Expected to take 1 minute 4.11 seconds.
382Gitlab::BackgroundMigration::BackfillPartitionIdCiPipelineConfig
383 #perform
384 when second partition does not exist
385 does not execute the migration
386# [RSpecRunTime] RSpec elapsed time: 10 minutes 32.98 seconds. Current RSS: ~1410M. Threads: 2. load average: 1.07 1.05 1.11 1/267 434
387.
388 when second partition exists
389 fixes invalid records in the wrong the partition
390# [RSpecRunTime] RSpec elapsed time: 10 minutes 38.86 seconds. Current RSS: ~1470M. Threads: 2. load average: 1.07 1.05 1.10 1/267 435
391.
392INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
393INFO: analyzing "public.ci_pipeline_variables"
394INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
395INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
396INFO: analyzing "public.ci_job_artifacts"
397INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
398I, [2024-07-31T10:26:49.609950 #326] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
399I, [2024-07-31T10:26:49.611415 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
400I, [2024-07-31T10:26:49.612318 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
401INFO: analyzing "public.p_ci_stages" inheritance tree
402INFO: analyzing "public.ci_stages"
403INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
404I, [2024-07-31T10:26:52.897127 #326] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
405I, [2024-07-31T10:26:52.898374 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
406I, [2024-07-31T10:26:52.899332 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
407I, [2024-07-31T10:26:54.191885 #326] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
408I, [2024-07-31T10:27:00.349133 #326] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
409I, [2024-07-31T10:27:13.857894 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
410I, [2024-07-31T10:27:13.859377 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
411I, [2024-07-31T10:27:13.860140 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
412I, [2024-07-31T10:27:25.083441 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
413I, [2024-07-31T10:27:31.852161 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
414# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_config_spec.rb. It took 1 minute 58.53 seconds. Expected to take 1 minute 4.11 seconds.
415# [RSpecRunTime] RSpec elapsed time: 11 minutes 38.16 seconds. Current RSS: ~1370M. Threads: 2. load average: 0.93 1.01 1.08 1/267 436
416.
417# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb. Expected to take 55.91 seconds.
418Gitlab::BackgroundMigration::BackfillProjectRepositories
419 Gitlab::BackgroundMigration::BackfillProjectRepositories::ShardFinder
420 #find_shard_id
421 creates a new shard when it does not exist yet
422 returns the shard when it exists
423 only queries the database once to retrieve shards
424# [RSpecRunTime] RSpec elapsed time: 11 minutes 49.83 seconds. Current RSS: ~1472M. Threads: 2. load average: 0.94 1.01 1.08 1/267 437
425.
426 Gitlab::BackgroundMigration::BackfillProjectRepositories::Project
427 .on_hashed_storage
428WARNING: All log messages before absl::InitializeLog() is called are written to STDERR
429I0000 00:00:1722421676.056475 326 rb_grpc.c:331] GRPC_RUBY: grpc_ruby_init_threads g_bg_thread_init_done=0
430 finds projects with repository on hashed storage
431# [RSpecRunTime] RSpec elapsed time: 11 minutes 58.21 seconds. Current RSS: ~1461M. Threads: 4. load average: 1.03 1.03 1.09 1/278 449
432.
433 .on_legacy_storage
434 finds projects with repository on legacy storage
435# [RSpecRunTime] RSpec elapsed time: 12 minutes 4.96 seconds. Current RSS: ~1467M. Threads: 4. load average: 1.03 1.03 1.09 1/278 450
436.
437 .without_project_repository
438 finds projects which do not have a projects_repositories entry
439# [RSpecRunTime] RSpec elapsed time: 12 minutes 11.83 seconds. Current RSS: ~1465M. Threads: 4. load average: 1.02 1.02 1.09 1/278 451
440.
441 #disk_path
442 for projects on hashed storage
443 returns the correct disk_path
444# [RSpecRunTime] RSpec elapsed time: 12 minutes 18.44 seconds. Current RSS: ~1453M. Threads: 4. load average: 1.10 1.04 1.09 1/278 452
445.
446 for projects on legacy storage
447 returns the correct disk_path
448 returns the correct disk_path using the route entry
449# [RSpecRunTime] RSpec elapsed time: 12 minutes 31.67 seconds. Current RSS: ~1458M. Threads: 4. load average: 1.09 1.04 1.09 1/278 453
450.
451# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb. It took 1 minute 1.04 seconds. Expected to take 55.91 seconds.
452# [RSpecRunTime] RSpec elapsed time: 12 minutes 39.26 seconds. Current RSS: ~1409M. Threads: 4. load average: 1.08 1.04 1.09 1/278 454
453.
454# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb. Expected to take 32.54 seconds.
455Gitlab::BackgroundMigration::BackfillVulnerabilityStateTransitionsProjectId
456 performs without error
457 constructs a valid query
458I, [2024-07-31T10:29:22.971813 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
459I, [2024-07-31T10:29:29.580300 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
460# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb. It took 56.53 seconds. Expected to take 32.54 seconds.
461# [RSpecRunTime] RSpec elapsed time: 13 minutes 35.84 seconds. Current RSS: ~1354M. Threads: 4. load average: 1.09 1.06 1.09 1/278 455
462.
463# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_dast_site_validations_project_id_spec.rb. Expected to take 31.35 seconds.
464Gitlab::BackgroundMigration::BackfillDastSiteValidationsProjectId
465 constructs a valid query
466 performs without error
467I, [2024-07-31T10:30:19.039648 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
468I, [2024-07-31T10:30:25.427233 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
469# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_dast_site_validations_project_id_spec.rb. It took 55.43 seconds. Expected to take 31.35 seconds.
470# [RSpecRunTime] RSpec elapsed time: 14 minutes 31.33 seconds. Current RSS: ~1352M. Threads: 4. load average: 1.18 1.09 1.10 1/278 456
471.
472# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_design_management_designs_namespace_id_spec.rb. Expected to take 30.56 seconds.
473Gitlab::BackgroundMigration::BackfillDesignManagementDesignsNamespaceId
474 constructs a valid query
475 performs without error
476I, [2024-07-31T10:31:04.835840 #326] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
477I, [2024-07-31T10:31:04.836967 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
478I, [2024-07-31T10:31:04.837716 #326] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
479I, [2024-07-31T10:31:16.298428 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
480I, [2024-07-31T10:31:22.387734 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
481# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_design_management_designs_namespace_id_spec.rb. It took 56.92 seconds. Expected to take 30.56 seconds.
482# [RSpecRunTime] RSpec elapsed time: 15 minutes 28.3 seconds. Current RSS: ~1364M. Threads: 4. load average: 1.10 1.09 1.09 1/278 457
483.
484# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_terraform_state_versions_project_id_spec.rb. Expected to take 30.06 seconds.
485Gitlab::BackgroundMigration::BackfillTerraformStateVersionsProjectId
486 constructs a valid query
487 performs without error
488I, [2024-07-31T10:32:12.013706 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
489I, [2024-07-31T10:32:18.175284 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
490# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_terraform_state_versions_project_id_spec.rb. It took 55.76 seconds. Expected to take 30.06 seconds.
491# [RSpecRunTime] RSpec elapsed time: 16 minutes 24.11 seconds. Current RSS: ~1365M. Threads: 4. load average: 1.00 1.06 1.08 1/278 458
492.
493# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_related_epic_links_group_id_spec.rb. Expected to take 29.11 seconds.
494Gitlab::BackgroundMigration::BackfillRelatedEpicLinksGroupId
495 constructs a valid query
496 performs without error
497I, [2024-07-31T10:33:07.198331 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
498I, [2024-07-31T10:33:13.403022 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
499# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_related_epic_links_group_id_spec.rb. It took 55.16 seconds. Expected to take 29.11 seconds.
500# [RSpecRunTime] RSpec elapsed time: 17 minutes 19.32 seconds. Current RSS: ~1380M. Threads: 4. load average: 1.06 1.07 1.09 1/278 459
501.
502# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_external_issue_links_project_id_spec.rb. Expected to take 19.23 seconds.
503Gitlab::BackgroundMigration::BackfillVulnerabilityExternalIssueLinksProjectId
504 constructs a valid query
505 performs without error
506I, [2024-07-31T10:33:41.066349 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
507I, [2024-07-31T10:33:48.732805 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
508# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_external_issue_links_project_id_spec.rb. It took 35.24 seconds. Expected to take 19.23 seconds.
509# [RSpecRunTime] RSpec elapsed time: 17 minutes 54.62 seconds. Current RSS: ~1376M. Threads: 4. load average: 1.03 1.06 1.08 1/279 460
510.
511# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_evidences_project_id_spec.rb. Expected to take 18.3 seconds.
512Gitlab::BackgroundMigration::BackfillVulnerabilityFindingEvidencesProjectId
513 performs without error
514 constructs a valid query
515I, [2024-07-31T10:34:16.790349 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
516I, [2024-07-31T10:34:24.388208 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
517# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_evidences_project_id_spec.rb. It took 35.86 seconds. Expected to take 18.3 seconds.
518# [RSpecRunTime] RSpec elapsed time: 18 minutes 30.53 seconds. Current RSS: ~1369M. Threads: 4. load average: 1.02 1.05 1.08 1/279 461
519.
520# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_signatures_project_id_spec.rb. Expected to take 17.49 seconds.
521Gitlab::BackgroundMigration::BackfillVulnerabilityFindingSignaturesProjectId
522 constructs a valid query
523 performs without error
524I, [2024-07-31T10:34:52.770501 #326] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
525I, [2024-07-31T10:34:59.061208 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
526# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_signatures_project_id_spec.rb. It took 34.53 seconds. Expected to take 17.49 seconds.
527# [RSpecRunTime] RSpec elapsed time: 19 minutes 5.12 seconds. Current RSS: ~1356M. Threads: 4. load average: 1.07 1.06 1.08 1/279 462
528.
529# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_orphans_approval_project_rules2_spec.rb. Expected to take 13.59 seconds.
530Gitlab::BackgroundMigration::DeleteOrphansApprovalProjectRules2
531 #perform
532 delete only approval rules without association with the security project and report_type equals to 4
533 with rule sources
534 deletes referenced sources
535 does not delete unreferenced sources
536# [RSpecRunTime] RSpec elapsed time: 19 minutes 17.64 seconds. Current RSS: ~1501M. Threads: 4. load average: 1.14 1.08 1.09 1/279 463
537.
538# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_orphans_approval_project_rules2_spec.rb. It took 20.93 seconds. Expected to take 13.59 seconds.
539# [RSpecRunTime] RSpec elapsed time: 19 minutes 26.1 seconds. Current RSS: ~1416M. Threads: 4. load average: 1.12 1.08 1.09 1/279 464
540.
541# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_sbom_occurrences_traversal_ids_and_archived_spec.rb. Expected to take 11.47 seconds.
542Gitlab::BackgroundMigration::BackfillSbomOccurrencesTraversalIdsAndArchived
543 backfills traversal_ids and archived
544I, [2024-07-31T10:35:44.805970 #326] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
545# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_sbom_occurrences_traversal_ids_and_archived_spec.rb. It took 25.04 seconds. Expected to take 11.47 seconds.
546# [RSpecRunTime] RSpec elapsed time: 19 minutes 51.22 seconds. Current RSS: ~1362M. Threads: 4. load average: 1.23 1.10 1.10 1/279 465
547.
548# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/recalculate_dora_deployment_frequency_score_spec.rb. Expected to take 5.11 seconds.
549Gitlab::BackgroundMigration::RecalculateDoraDeploymentFrequencyScore
550 #perform
551 updates deployment frequency score with correct value
552# [RSpecRunTime] RSpec elapsed time: 19 minutes 56.01 seconds. Current RSS: ~1386M. Threads: 4. load average: 1.21 1.10 1.09 2/279 466
553.
554# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/recalculate_dora_deployment_frequency_score_spec.rb. It took 12.23 seconds. Expected to take 5.11 seconds.
555# [RSpecRunTime] RSpec elapsed time: 20 minutes 3.51 seconds. Current RSS: ~1384M. Threads: 4. load average: 1.18 1.10 1.09 1/279 467
556.
557# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/populate_topics_slug_column_spec.rb. Expected to take 4.93 seconds.
558Gitlab::BackgroundMigration::PopulateTopicsSlugColumn
559 #perform
560 populates topics slug column
561# [RSpecRunTime] RSpec elapsed time: 20 minutes 8.12 seconds. Current RSS: ~1393M. Threads: 4. load average: 1.16 1.09 1.09 1/279 468
562.
563# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/populate_topics_slug_column_spec.rb. It took 11.9 seconds. Expected to take 4.93 seconds.
564# [RSpecRunTime] RSpec elapsed time: 20 minutes 15.47 seconds. Current RSS: ~1381M. Threads: 4. load average: 1.15 1.09 1.09 1/279 469
565.
566# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb. Expected to take 4.66 seconds.
567Gitlab::BackgroundMigration::Mailers::UnconfirmMailer
568 contains abuse report url
569# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb. It took 11.54 seconds. Expected to take 4.66 seconds.
570# [RSpecRunTime] RSpec elapsed time: 20 minutes 27.07 seconds. Current RSS: ~1395M. Threads: 4. load average: 1.12 1.09 1.09 1/279 470
571.
572auto_explain log contains 1012 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-no-gitaly-transactions-4-10.326.main.ndjson.gz
573took 30.082984565
574auto_explain log contains 1013 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-no-gitaly-transactions-4-10.326.ci.ndjson.gz
575took 28.438646736
576[TEST PROF INFO] EventProf results for sql.active_record
577Total time: 12:33.051 of 20:22.610 (61.59%)
578Total events: 654089
579Top 5 slowest suites (by time):
580Gitlab::Backg...ShardingKeyJob (./spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb:5) – 01:45.181 (80120 / 2) of 02:35.828 (67.5%)
581Gitlab::Backg...erabilityReads (./spec/lib/gitlab/background_migration/backfill_owasp_top_ten_of_vulnerability_reads_spec.rb:5) – 01:30.827 (76652 / 6) of 02:26.927 (61.82%)
582Gitlab::Backg...mespaceSetting (./spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb:5) – 01:29.236 (69088 / 1) of 02:05.617 (71.04%)
583Gitlab::Backg...PipelineConfig (./spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_config_spec.rb:5) – 01:22.523 (67767 / 2) of 01:58.586 (69.59%)
584Gitlab::Backg...JobCoordinator (./spec/lib/gitlab/background_migration/job_coordinator_spec.rb:5) – 01:08.692 (82250 / 34) of 02:26.737 (46.81%)
585Knapsack report was generated. Preview:
586{
587 "spec/lib/gitlab/background_migration/job_coordinator_spec.rb": 139.25159523399998,
588 "spec/lib/gitlab/background_migration/backfill_owasp_top_ten_of_vulnerability_reads_spec.rb": 88.74653123899952,
589 "spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb": 80.42813958900115,
590 "spec/lib/gitlab/background_migration/backfill_branch_protection_namespace_setting_spec.rb": 60.04593722699974,
591 "spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_config_spec.rb": 59.42191466700024,
592 "spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb": 53.65279795800052,
593 "spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb": 28.171996151000712,
594 "spec/lib/gitlab/background_migration/backfill_dast_site_validations_project_id_spec.rb": 28.0336322259991,
595 "spec/lib/gitlab/background_migration/backfill_design_management_designs_namespace_id_spec.rb": 28.063902755000527,
596 "spec/lib/gitlab/background_migration/backfill_terraform_state_versions_project_id_spec.rb": 27.88667726300082,
597 "spec/lib/gitlab/background_migration/backfill_related_epic_links_group_id_spec.rb": 27.09650507600054,
598 "spec/lib/gitlab/background_migration/backfill_vulnerability_external_issue_links_project_id_spec.rb": 16.62727698299932,
599 "spec/lib/gitlab/background_migration/backfill_vulnerability_finding_evidences_project_id_spec.rb": 16.968858618000013,
600 "spec/lib/gitlab/background_migration/backfill_vulnerability_finding_signatures_project_id_spec.rb": 16.950316659000237,
601 "spec/lib/gitlab/background_migration/delete_orphans_approval_project_rules2_spec.rb": 12.653216685999723,
602 "spec/lib/gitlab/background_migration/backfill_sbom_occurrences_traversal_ids_and_archived_spec.rb": 10.466509261999818,
603 "spec/lib/gitlab/background_migration/recalculate_dora_deployment_frequency_score_spec.rb": 4.91223852999974,
604 "spec/lib/gitlab/background_migration/populate_topics_slug_column_spec.rb": 4.740225706998899,
605 "spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb": 4.512028650999127
606}
607Knapsack global time execution for tests: 11m 48s
608Finished in 21 minutes 26 seconds (files took 1 minute 29.35 seconds to load)
60977 examples, 0 failures
610Randomized with seed 14299
611[TEST PROF INFO] Time spent in factories: 00:19.451 (1.47% of total time)
612RSpec exited with 0.
613No examples to retry, congrats!
614 Running after_script 00:11
615Running after script...
616$ source scripts/utils.sh
617$ bundle exec gem list gitlab_quality-test_tooling
618gitlab_quality-test_tooling (1.33.0)
619$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
620 Report test failures 00:02
623$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
624 Report test flakiness 00:00
626$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
627 Report test slowness 00:03
630$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
631 Report test slowness in MR note 00:00
633$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
634 Report test files close to timing out 00:02
637$ tooling/bin/push_job_metrics || true
638[job-metrics] Pushing job metrics file for the CI/CD job.
639[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
640 Saving cache for successful job 00:01
641Not uploading cache ruby-gems-debian-bookworm-ruby-3.1.5-17 due to policy
642 Uploading artifacts for successful job 00:05
643Uploading artifacts...
644auto_explain/: found 3 matching artifact files and directories
645coverage/: found 5 matching artifact files and directories
646crystalball/: found 5 matching artifact files and directories
647WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
648knapsack/: found 4 matching artifact files and directories
649rspec/: found 12 matching artifact files and directories
650WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
651log/*.log: found 13 matching artifact files and directories
652WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346453/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
653WARNING: Retrying... context=artifacts-uploader error=request redirected
654Uploading artifacts as "archive" to coordinator... 201 Created id=7471346453 responseStatus=201 Created token=glcbt-66
655Uploading artifacts...
656rspec/rspec-*.xml: found 1 matching artifact files and directories
657WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346453/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
658WARNING: Retrying... context=artifacts-uploader error=request redirected
659Uploading artifacts as "junit" to coordinator... 201 Created id=7471346453 responseStatus=201 Created token=glcbt-66
660 Cleaning up project directory and file based variables 00:01
661Job succeeded