Skip to content
Snippets Groups Projects

rspec background_migration pg14 10/10

Passed Started by
🤖 GitLab Bot 🤖
@gitlab-bot
Log timestamps in UTC.
103:26:49Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
203:26:49 on blue-2.private.runners-manager.gitlab.com/gitlab.com/gitlab-org QvBVRoXM, system ID: s_49b872f8ccf6
303:26:49 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
403:26:49Resolving secrets
5 03:26:49 Preparing the "docker+machine" executor 00:08
603:26:49Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
703:26:52Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
803:26:52Authenticating with credentials from job payload (GitLab Registry)
903:26:52Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1003:26:52Using 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 ...
1103:26:52WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1203:26:52WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1303:26:52Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1403:26:52Authenticating with credentials from job payload (GitLab Registry)
1503:26:52Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1603:26:52Using 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 ...
1703:26:53Starting service redis:6.2-alpine...
1803:26:53Pulling docker image redis:6.2-alpine ...
1903:26:53Using docker image sha256:ec1b0a84ddf9124276ac189cc4d98ef28f0aea95ebd148d9e4c18b28928dd999 for redis:6.2-alpine with digest redis@sha256:2ba50e1ac3a0ea17b736ce9db2b0a9f6f8b85d4c27d5f5accc6a416d8f42c6d5 ...
2003:26:54Waiting for services to be up and running (timeout 30 seconds)...
2103:26:57Authenticating with credentials from job payload (GitLab Registry)
2203:26:57Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
2303:26:57Using docker image sha256:ab7961692458f506f4ffa89e6e60bf1fc6de783a0d358136ca0b3e84c63c84a8 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:8ec7e4c24be92019bc9072c7049231de71d9a56301d7562522d046f1494470be ...
24 03:26:57 Preparing environment 00:01
2503:26:58Running on runner-qvbvroxm-project-13083-concurrent-0 via runner-qvbvroxm-private-1729043775-9132db36...
26 03:26:58 Getting source from Git repository 00:00
2703:26:58Skipping Git repository setup
2803:26:58Skipping Git checkout
2903:26:58Skipping Git submodules setup
30 03:26:58 Restoring cache 00:18
3103:26:59Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-3...
3203:26:59cache.zip is up to date
3303:27:10Successfully extracted cache
34 03:27:16 Downloading artifacts 00:37
3503:27:16Downloading artifacts for clone-gitlab-repo (8095842990)...
3603:27:20Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095842990 responseStatus=200 OK token=glcbt-66
3703:27:20WARNING: Part of .git directory is on the list of files to extract
3803:27:20WARNING: This may introduce unexpected problems
3903:27:29Downloading artifacts for compile-test-assets (8095842997)...
4003:27:31Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095842997 responseStatus=200 OK token=glcbt-66
4103:27:36Downloading artifacts for retrieve-tests-metadata (8095843012)...
4203:27:37Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095843012 responseStatus=200 OK token=glcbt-66
4303:27:37Downloading artifacts for setup-test-env (8095843004)...
4403:27:43Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095843004 responseStatus=200 OK token=glcbt-66
45 03:27:53 Executing "step_script" stage of the job script
4603:27:53Using docker image sha256:ab7961692458f506f4ffa89e6e60bf1fc6de783a0d358136ca0b3e84c63c84a8 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:8ec7e4c24be92019bc9072c7049231de71d9a56301d7562522d046f1494470be ...
4703:27:54$ echo $FOSS_ONLY
4803:27:54$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
4903:27:54$ export GOPATH=$CI_PROJECT_DIR/.go
5003:27:54$ mkdir -p $GOPATH
5103:27:54$ source scripts/utils.sh
5203:27:54$ log_disk_usage "true"
5303:27:54*******************************************************
5403:27:54This runner currently has 72G free disk space.
5503:27:54*******************************************************
56 03:27:54 Disk usage detail 00:07
5703:27:54df -h
5803:27:54Filesystem Size Used Avail Use% Mounted on
5903:27:54overlay 95G 23G 72G 24% /
6003:27:54tmpfs 64M 0 64M 0% /dev
6103:27:54shm 64M 0 64M 0% /dev/shm
6203:27:54/dev/sda1 95G 23G 72G 24% /cache
6303:27:54tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6403:27:54du -h -d 1
6503:27:547.4M ./workhorse
6603:27:54148K ./bin
6703:27:541.2M ./.gitlab
6803:27:54117M ./.git
6903:27:544.0K ./builds
7003:27:5428M ./lib
7103:27:54532K ./storybook
7203:27:5424K ./log
7303:27:541.8M ./data
7403:27:547.0M ./qa
7503:27:542.8M ./.rubocop_todo
7603:27:54828M ./vendor
7703:27:54850M ./public
7803:27:5459M ./doc
7903:27:54492K ./danger
8003:27:5492K ./rspec
8103:27:54552K ./tooling
8203:27:541.3M ./knapsack
8303:27:54296K ./patches
8403:27:543.9M ./changelogs
8503:27:5420K ./haml_lint
8603:27:5428K ./metrics_server
8703:27:5488K ./keeps
8803:27:5448K ./shared
8903:27:5444K ./generator_templates
9003:27:541.2M ./scripts
9103:27:54659M ./tmp
9203:27:54126M ./spec
9303:27:5420K ./file_hooks
9403:27:5416K ./sidekiq_cluster
9503:27:5417M ./gems
9603:27:541.2M ./fixtures
9703:27:54952K ./rubocop
9803:27:544.0K ./.go
9903:27:5431M ./db
10003:27:5412K ./.github
10103:27:54129M ./locale
10203:27:5419M ./config
10303:27:5481M ./app
10403:27:5420K ./.lefthook
10503:27:543.0G .
10603:27:54$ source scripts/prepare_build.sh
107 03:27:54 Installing gems 00:19
13803:28:13Using decomposed database config (config/database.yml.decomposed-postgresql)
13903:28:13Geo DB won't be set up.
14003:28:13Embedding DB won't be set up.
141 03:28:13 Setting up DBs 01:09
15303:29:22$ source ./scripts/rspec_helpers.sh
15403:29:22$ run_timed_command "gem install knapsack --no-document"
15503:29:22$ gem install knapsack --no-document
15603:29:24Successfully installed knapsack-4.0.0
15703:29:241 gem installed
15803:29:22==> 'gem install knapsack --no-document' succeeded in 2 seconds.
15903:29:24$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
160 03:29:24 Spawning Gitaly 00:04
16403:29:28$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
16503:29:28$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
16603:29:28$ tooling/bin/create_job_metrics_file || true
16703:29:31[job-metrics] Feature disabled because CI_JOB_METRICS_ENABLED is not set to true.
16803:29:31$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
169 03:29:31 RSpec 38:13
17003:29:31[03:29:31] Starting rspec_parallelized_job
17103:29:24RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
17203:29:32KNAPSACK_GENERATE_REPORT: true
17303:29:32FLAKY_RSPEC_GENERATE_REPORT: true
17403:29:32KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
17503:29:32KNAPSACK_LOG_LEVEL: debug
17603:29:32KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_10_10_13083_report.json
17703:29:32FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
17803:29:32FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_10_10_13083_report.json
17903:29:32NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_10_10_13083_report.json
18003:29:32RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8095843156.txt
18103:29:32CRYSTALBALL:
18203:29:32RSPEC_TESTS_MAPPING_ENABLED:
18303:29:32RSPEC_TESTS_FILTER_FILE:
18403:29:32Shell set options (set -o) enabled:
18503:29:32braceexpand on
18603:29:32hashall on
18703:29:32interactive-comments on
18803:29:32pipefail on
18903:29:39Knapsack report generator started!
19003:29:32/builds/gitlab-org/gitlab-foss/vendor/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!
19103:30:17warning: parser/current is loading parser/ruby32, which recognizes 3.2.4-compliant syntax, but you are running 3.2.5.
19203:30:17Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
19303:30:28/builds/gitlab-org/gitlab-foss/vendor/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!
19403:31:03Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
19503:31:03# [RSpecRunTime] Starting RSpec timer...
19603:31:04[TEST PROF INFO] EventProf enabled (sql.active_record)
19703:31:04unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
19803:31:04unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
19903:31:09Test environment set up in 1.210381981 seconds
20003:31:09# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. Expected to take 2 minutes 43.44 seconds.
20103:31:09Gitlab::BackgroundMigration::DestroyInvalidMembers
20203:33:06 tracks timings of queries
20303:33:23 logs IDs of deleted records
20403:33:39 removes invalid memberships but keeps valid ones
20503:33:44INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
20603:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
20703:33:44INFO: "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
20803:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
20903:33:44INFO: "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
21003:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
21103:33:44INFO: "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
21203:33:44INFO: analyzing "public.p_ci_job_annotations" inheritance tree
21303:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
21403:33:44INFO: "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
21503:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
21603:33:44INFO: "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
21703:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
21803:33:44INFO: "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
21903:33:44INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
22003:33:44INFO: analyzing "public.ci_builds_metadata"
22103:33:44INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22203:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
22303:33:44INFO: "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
22403:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
22503:33:44INFO: "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
22603:33:44INFO: analyzing "public.p_ci_builds" inheritance tree
22703:33:44INFO: analyzing "public.ci_builds"
22803:33:44INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22903:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
23003:33:44INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23103:33:44INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
23203:33:44INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23303:33:44I, [2024-10-16T03:33:44.715956 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
23403:34:04I, [2024-10-16T03:34:04.746991 #341] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
23503:34:06INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
23603:34:06INFO: analyzing "public.ci_pipeline_variables"
23703:34:06INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23803:34:06I, [2024-10-16T03:34:06.472086 #341] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
23903:34:06I, [2024-10-16T03:34:06.481686 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
24003:34:06I, [2024-10-16T03:34:06.482795 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
24103:34:08INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
24203:34:08INFO: analyzing "public.ci_pipeline_variables"
24303:34:08INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24403:34:13INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
24503:34:13INFO: analyzing "public.ci_job_artifacts"
24603:34:13INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24703:34:13I, [2024-10-16T03:34:13.131196 #341] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
24803:34:13I, [2024-10-16T03:34:13.133288 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
24903:34:13I, [2024-10-16T03:34:13.134271 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25003:34:16INFO: analyzing "public.p_ci_stages" inheritance tree
25103:34:16INFO: analyzing "public.ci_stages"
25203:34:16INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
25303:34:16I, [2024-10-16T03:34:16.682504 #341] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
25403:34:16I, [2024-10-16T03:34:16.683796 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25503:34:16I, [2024-10-16T03:34:16.684720 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25603:34:17I, [2024-10-16T03:34:17.981136 #341] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
25703:34:24I, [2024-10-16T03:34:24.667245 #341] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
25803:34:39I, [2024-10-16T03:34:39.083419 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
25903:34:39I, [2024-10-16T03:34:39.084659 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26003:34:39I, [2024-10-16T03:34:39.085458 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26103:34:50I, [2024-10-16T03:34:50.777642 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
26203:34:57I, [2024-10-16T03:34:57.580593 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
26303:35:06I, [2024-10-16T03:35:06.167000 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
26403:35:08I, [2024-10-16T03:35:08.882330 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
26503:35:12INFO: analyzing "public.p_ci_pipelines" inheritance tree
26603:35:12INFO: analyzing "public.ci_pipelines"
26703:35:12INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
26803:35:12I, [2024-10-16T03:35:12.825835 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
26903:35:12I, [2024-10-16T03:35:12.827268 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
27003:35:12I, [2024-10-16T03:35:12.828717 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
27103:35:18I, [2024-10-16T03:35:18.796165 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
27203:35:36# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. It took 4 minutes 27.18 seconds. Expected to take 2 minutes 43.44 seconds.
27303:35:36# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/job_coordinator_spec.rb. Expected to take 2 minutes 42.62 seconds.
27403:35:36Gitlab::BackgroundMigration::JobCoordinator
27503:35:37 .for_tracking_database
27603:35:42 returns an executor with the correct worker class and database
27703:35:42 when an invalid value is given
27803:35:46 raises an error
27903:35:46# [RSpecRunTime] RSpec elapsed time: 4 minutes 42.28 seconds. Current RSS: ~946M. Threads: 1. load average: 1.28 1.23 1.19 1/269 408
28003:35:46.
28103:35:46 #queue
28203:35:50 returns background migration worker queue
28303:35:50# [RSpecRunTime] RSpec elapsed time: 4 minutes 46.84 seconds. Current RSS: ~944M. Threads: 1. load average: 1.34 1.25 1.19 1/269 409
28403:35:50.
28503:35:50 #with_shared_connection
28603:35:54 yields to the block after properly configuring SharedModel
28703:35:54# [RSpecRunTime] RSpec elapsed time: 4 minutes 50.98 seconds. Current RSS: ~946M. Threads: 1. load average: 1.31 1.24 1.19 1/269 410
28803:35:54.
28903:35:54 #pending_jobs
29003:35:54 when there are enqueued jobs
29103:35:59 does not include jobs for other workers
29203:35:59 when using a different shard instance
29303:36:03 uses the appropriate shard for the store
29403:36:03# [RSpecRunTime] RSpec elapsed time: 4 minutes 59.33 seconds. Current RSS: ~944M. Threads: 1. load average: 1.34 1.25 1.19 1/267 411
29503:36:03.
29603:36:03 when not including dead jobs
29703:36:07 includes current and future jobs
29803:36:07# [RSpecRunTime] RSpec elapsed time: 5 minutes 3.65 seconds. Current RSS: ~946M. Threads: 1. load average: 1.39 1.26 1.20 1/267 412
29903:36:07.
30003:36:07 when including dead jobs
30103:36:11 includes current and future jobs, and also dead and retry jobs
30203:36:11# [RSpecRunTime] RSpec elapsed time: 5 minutes 7.91 seconds. Current RSS: ~947M. Threads: 1. load average: 1.39 1.26 1.20 1/267 413
30303:36:11.
30403:36:11 #steal
30503:36:11 when there are enqueued jobs present
30603:36:11 when using a different shard instance
30703:36:16 wraps job processing within Sidekiq::Client.via
30803:36:16# [RSpecRunTime] RSpec elapsed time: 5 minutes 12.15 seconds. Current RSS: ~949M. Threads: 1. load average: 1.36 1.26 1.20 1/267 414
30903:36:16.
31003:36:16 when queue contains unprocessed jobs
31103:36:20 steals jobs from a queue
31203:36:24 sets up the shared connection while stealing jobs
31303:36:28 does not steal job that has already been taken
31403:36:32 does not steal jobs for a different migration
31503:36:32 when a custom predicate is given
31603:36:36 steals jobs that match the predicate
31703:36:40 does not steal jobs that do not match the predicate
31803:36:40# [RSpecRunTime] RSpec elapsed time: 5 minutes 36.6 seconds. Current RSS: ~950M. Threads: 1. load average: 1.22 1.24 1.19 1/267 415
31903:36:40.
32003:36:40 when one of the jobs raises an error
32103:36:44 enqueues the migration again and re-raises the error
32203:36:44# [RSpecRunTime] RSpec elapsed time: 5 minutes 40.66 seconds. Current RSS: ~948M. Threads: 1. load average: 1.20 1.23 1.19 1/268 416
32303:36:44.
32403:36:44 when there are scheduled jobs present
32503:36:48 steals all jobs from the scheduled sets
32603:36:48# [RSpecRunTime] RSpec elapsed time: 5 minutes 44.73 seconds. Current RSS: ~948M. Threads: 1. load average: 1.19 1.23 1.19 1/267 417
32703:36:48.
32803:36:48 when there are enqueued and scheduled jobs present
32903:36:52 steals from the scheduled sets queue first
33003:36:52# [RSpecRunTime] RSpec elapsed time: 5 minutes 48.92 seconds. Current RSS: ~948M. Threads: 1. load average: 1.17 1.22 1.18 1/267 418
33103:36:52.
33203:36:52 when retry_dead_jobs is true
33303:36:56 steals from the dead and retry queue
33403:36:56# [RSpecRunTime] RSpec elapsed time: 5 minutes 53.07 seconds. Current RSS: ~950M. Threads: 1. load average: 1.17 1.22 1.18 1/266 419
33503:36:56.
33603:36:56 #perform
33703:36:56 when the background migration does not inherit from BaseJob
33803:37:01 performs a background migration with the configured shared connection
33903:37:01# [RSpecRunTime] RSpec elapsed time: 5 minutes 57.82 seconds. Current RSS: ~949M. Threads: 1. load average: 1.16 1.22 1.18 1/266 420
34003:37:01.
34103:37:01 when the background migration inherits from BaseJob
34203:37:05 passes the correct connection when constructing the migration
34303:37:05# [RSpecRunTime] RSpec elapsed time: 6 minutes 1.92 seconds. Current RSS: ~945M. Threads: 1. load average: 1.14 1.22 1.18 1/267 421
34403:37:05.
34503:37:05 .remaining
34603:37:09 is shard aware
34703:37:09 when there are jobs remaining
34803:37:13 returns the enqueued jobs plus the scheduled jobs
34903:37:13# [RSpecRunTime] RSpec elapsed time: 6 minutes 9.96 seconds. Current RSS: ~944M. Threads: 1. load average: 1.20 1.23 1.18 1/267 422
35003:37:13.
35103:37:13 when there are no jobs remaining
35203:37:17 returns zero
35303:37:17# [RSpecRunTime] RSpec elapsed time: 6 minutes 14.02 seconds. Current RSS: ~948M. Threads: 1. load average: 1.26 1.24 1.19 1/267 423
35403:37:17.
35503:37:17 .exists?
35603:37:21 is shard aware
35703:37:21 when there are enqueued jobs present
35803:37:25 returns true if specific job exists
35903:37:29 returns false if specific job does not exist
36003:37:29# [RSpecRunTime] RSpec elapsed time: 6 minutes 25.97 seconds. Current RSS: ~946M. Threads: 1. load average: 1.22 1.23 1.19 1/267 424
36103:37:29.
36203:37:29 when there are scheduled jobs present
36303:37:33 returns true if specific job exists
36403:37:37 returns false if specific job does not exist
36503:37:37# [RSpecRunTime] RSpec elapsed time: 6 minutes 34.06 seconds. Current RSS: ~948M. Threads: 1. load average: 1.34 1.26 1.19 1/267 425
36603:37:37.
36703:37:37 .dead_jobs?
36803:37:37 when there are dead jobs present
36903:37:42 returns true if specific job exists
37003:37:46 returns false if specific job does not exist
37103:37:46# [RSpecRunTime] RSpec elapsed time: 6 minutes 42.2 seconds. Current RSS: ~950M. Threads: 1. load average: 1.31 1.25 1.19 1/267 426
37203:37:46.
37303:37:46 .retrying_jobs?
37403:37:50 is shard aware
37503:37:50 when there are dead jobs present
37603:37:54 returns true if specific job exists
37703:37:57 returns false if specific job does not exist
37803:37:57# [RSpecRunTime] RSpec elapsed time: 6 minutes 53.98 seconds. Current RSS: ~950M. Threads: 1. load average: 1.24 1.24 1.19 1/267 427
37903:37:57.
38003:38:05# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/job_coordinator_spec.rb. It took 2 minutes 29.24 seconds. Expected to take 2 minutes 42.62 seconds.
38103:38:05# [RSpecRunTime] RSpec elapsed time: 7 minutes 1.98 seconds. Current RSS: ~953M. Threads: 1. load average: 1.22 1.24 1.19 1/267 428
38203:38:05.
38303:38:05# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/legacy_upload_mover_spec.rb. Expected to take 2 minutes 5.08 seconds.
38403:38:05Gitlab::BackgroundMigration::LegacyUploadMover
38503:38:06 when no note found for the upload
38603:38:06 behaves like legacy upload deletion
38703:38:13 removes the upload record
38803:38:13# [RSpecRunTime] RSpec elapsed time: 7 minutes 9.76 seconds. Current RSS: ~986M. Threads: 4. load average: 1.18 1.23 1.18 1/279 441
38903:38:13.
39003:38:13 when upload does not belong to a note
39103:38:19 does not remove the upload
39203:38:19# [RSpecRunTime] RSpec elapsed time: 7 minutes 15.39 seconds. Current RSS: ~978M. Threads: 4. load average: 1.33 1.26 1.19 1/279 442
39303:38:19.
39403:38:19 when the upload move fails
39503:38:19 behaves like move error
39603:38:24 does not remove the upload file
39703:38:24# [RSpecRunTime] RSpec elapsed time: 7 minutes 20.85 seconds. Current RSS: ~984M. Threads: 4. load average: 1.38 1.27 1.20 1/280 443
39803:38:24.
39903:38:24 when the upload is in local storage
40003:38:24 when the upload file does not exist on the filesystem
40103:38:24 behaves like legacy upload deletion
40203:38:31 removes the upload record
40303:38:31# [RSpecRunTime] RSpec elapsed time: 7 minutes 27.23 seconds. Current RSS: ~982M. Threads: 4. load average: 1.35 1.26 1.20 1/279 444
40403:38:31.
40503:38:31 when an upload belongs to a legacy_diff_note
40603:38:31 when the file does not exist for the upload
40703:38:31 behaves like move error
40803:38:36 does not remove the upload file
40903:38:36# [RSpecRunTime] RSpec elapsed time: 7 minutes 32.89 seconds. Current RSS: ~982M. Threads: 4. load average: 1.24 1.24 1.19 1/279 445
41003:38:36.
41103:38:36 when the file does not exist on expected path
41203:38:36 behaves like move error
41303:38:42 does not remove the upload file
41403:38:42# [RSpecRunTime] RSpec elapsed time: 7 minutes 38.47 seconds. Current RSS: ~985M. Threads: 4. load average: 1.21 1.23 1.19 3/279 446
41503:38:42.
41603:38:42 when the file path does not include system/note/attachment
41703:38:42 behaves like move error
41803:38:48 does not remove the upload file
41903:38:48# [RSpecRunTime] RSpec elapsed time: 7 minutes 44.95 seconds. Current RSS: ~983M. Threads: 4. load average: 1.19 1.23 1.19 1/279 447
42003:38:48.
42103:38:48 when the file move raises an error
42203:38:48 behaves like move error
42303:38:54 does not remove the upload file
42403:38:54# [RSpecRunTime] RSpec elapsed time: 7 minutes 50.59 seconds. Current RSS: ~981M. Threads: 4. load average: 1.25 1.24 1.19 1/279 448
42503:38:54.
42603:38:54 when upload has mount_point nil
42703:38:54 behaves like migrates the file correctly
42803:39:01 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
42903:39:01# [RSpecRunTime] RSpec elapsed time: 7 minutes 57.19 seconds. Current RSS: ~986M. Threads: 4. load average: 1.23 1.24 1.19 1/279 449
43003:39:01.
43103:39:01 when the file can be handled correctly
43203:39:01 behaves like migrates the file correctly
43303:39:06 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
43403:39:06# [RSpecRunTime] RSpec elapsed time: 8 minutes 3.0 seconds. Current RSS: ~983M. Threads: 4. load average: 1.21 1.24 1.19 1/279 450
43503:39:06.
43603:39:06 when object storage is disabled for FileUploader
43703:39:06 when the file belongs to a legacy project
43803:39:06 behaves like migrates the file correctly
43903:39:12 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
44003:39:12# [RSpecRunTime] RSpec elapsed time: 8 minutes 8.74 seconds. Current RSS: ~984M. Threads: 4. load average: 1.03 1.19 1.17 1/279 451
44103:39:12.
44203:39:12 when the file belongs to a hashed project
44303:39:12 behaves like migrates the file correctly
44403:39:18 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
44503:39:19# [RSpecRunTime] RSpec elapsed time: 8 minutes 15.11 seconds. Current RSS: ~986M. Threads: 4. load average: 1.02 1.19 1.17 1/279 452
44603:39:19.
44703:39:19 when object storage is enabled for FileUploader
44803:39:19 when the file belongs to a legacy project
44903:39:19 behaves like migrates the file correctly
45003:39:24 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
45103:39:24# [RSpecRunTime] RSpec elapsed time: 8 minutes 20.92 seconds. Current RSS: ~982M. Threads: 4. load average: 1.02 1.19 1.17 1/280 453
45203:39:24.
45303:39:24 when the file belongs to a hashed project
45403:39:24 behaves like migrates the file correctly
45503:39:31 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
45603:39:31# [RSpecRunTime] RSpec elapsed time: 8 minutes 27.25 seconds. Current RSS: ~987M. Threads: 4. load average: 1.02 1.18 1.17 1/280 454
45703:39:31.
45803:39:31 when legacy uploads are stored in object storage
45903:39:31 when the upload file does not exist on the filesystem
46003:39:31 behaves like legacy upload deletion
46103:39:36 removes the upload record
46203:39:36# [RSpecRunTime] RSpec elapsed time: 8 minutes 32.82 seconds. Current RSS: ~981M. Threads: 4. load average: 1.02 1.18 1.17 1/280 455
46303:39:36.
46403:39:36 when the file belongs to a legacy project
46503:39:36 behaves like migrates the file correctly
46603:39:43 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
46703:39:44# [RSpecRunTime] RSpec elapsed time: 8 minutes 40.11 seconds. Current RSS: ~983M. Threads: 4. load average: 1.10 1.19 1.17 1/280 456
46803:39:44.
46903:39:44 when the file belongs to a hashed project
47003:39:44 behaves like migrates the file correctly
47103:39:50 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
47203:39:50# [RSpecRunTime] RSpec elapsed time: 8 minutes 46.65 seconds. Current RSS: ~989M. Threads: 4. load average: 1.17 1.20 1.18 1/280 457
47303:39:50.
47403:40:00# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/legacy_upload_mover_spec.rb. It took 1 minute 54.32 seconds. Expected to take 2 minutes 5.08 seconds.
47503:40:00# [RSpecRunTime] RSpec elapsed time: 8 minutes 56.34 seconds. Current RSS: ~975M. Threads: 4. load average: 1.07 1.18 1.17 1/280 458
47603:40:00.
47703:40:00# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb. Expected to take 1 minute 48.72 seconds.
47803:40:00Gitlab::BackgroundMigration::BackfillHasIssuesForExternalIssueLinks
47903:41:12 sets has_issues of an existing record
48003:41:12 when there exists a record with has_issues
48103:41:20 does not modify existing records with has_issues
48203:41:20# [RSpecRunTime] RSpec elapsed time: 10 minutes 16.96 seconds. Current RSS: ~1016M. Threads: 4. load average: 1.29 1.20 1.18 2/280 459
48303:41:20.
48403:41:24I, [2024-10-16T03:41:24.092365 #341] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
48503:41:37I, [2024-10-16T03:41:37.801513 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
48603:41:37I, [2024-10-16T03:41:37.802683 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
48703:41:37I, [2024-10-16T03:41:37.803431 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
48803:41:49I, [2024-10-16T03:41:49.081421 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
48903:41:55I, [2024-10-16T03:41:55.489969 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
49003:42:03I, [2024-10-16T03:42:03.054654 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
49103:42:05I, [2024-10-16T03:42:05.558152 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
49203:42:09INFO: analyzing "public.p_ci_pipelines" inheritance tree
49303:42:09INFO: analyzing "public.ci_pipelines"
49403:42:09INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
49503:42:09I, [2024-10-16T03:42:09.252011 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
49603:42:09I, [2024-10-16T03:42:09.253143 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
49703:42:09I, [2024-10-16T03:42:09.253951 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
49803:42:14I, [2024-10-16T03:42:14.359290 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
49903:42:31# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb. It took 2 minutes 30.92 seconds. Expected to take 1 minute 48.72 seconds.
50003:42:31# [RSpecRunTime] RSpec elapsed time: 11 minutes 27.31 seconds. Current RSS: ~1009M. Threads: 4. load average: 1.27 1.23 1.19 1/280 460
50103:42:31.
50203:42:31# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. Expected to take 1 minute 29.84 seconds.
50303:42:31Gitlab::BackgroundMigration::DropVulnerabilitiesWithoutFindingId
50403:43:42 #perform
50503:43:52 removes all Vulnerabilities without a finding_id
50603:43:52# [RSpecRunTime] RSpec elapsed time: 12 minutes 48.43 seconds. Current RSS: ~1071M. Threads: 4. load average: 1.20 1.21 1.18 1/280 461
50703:43:52.
50803:43:55INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
50903:43:55INFO: analyzing "public.ci_job_artifacts"
51003:43:55INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
51103:43:55I, [2024-10-16T03:43:55.149917 #341] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
51203:43:55I, [2024-10-16T03:43:55.151340 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
51303:43:55I, [2024-10-16T03:43:55.152280 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
51403:43:58INFO: analyzing "public.p_ci_stages" inheritance tree
51503:43:58INFO: analyzing "public.ci_stages"
51603:43:58INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
51703:43:58I, [2024-10-16T03:43:58.561287 #341] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
51803:43:58I, [2024-10-16T03:43:58.562539 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
51903:43:58I, [2024-10-16T03:43:58.563523 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52003:43:59I, [2024-10-16T03:43:59.704433 #341] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
52103:44:06I, [2024-10-16T03:44:06.150767 #341] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
52203:44:19I, [2024-10-16T03:44:19.659615 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
52303:44:19I, [2024-10-16T03:44:19.661131 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52403:44:19I, [2024-10-16T03:44:19.662023 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52503:44:30I, [2024-10-16T03:44:30.990344 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
52603:44:37I, [2024-10-16T03:44:37.719998 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
52703:44:45I, [2024-10-16T03:44:45.613488 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
52803:44:48I, [2024-10-16T03:44:48.077720 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
52903:44:51INFO: analyzing "public.p_ci_pipelines" inheritance tree
53003:44:51INFO: analyzing "public.ci_pipelines"
53103:44:51INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
53203:44:51I, [2024-10-16T03:44:51.951034 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
53303:44:51I, [2024-10-16T03:44:51.952413 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53403:44:51I, [2024-10-16T03:44:51.953344 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53503:44:57I, [2024-10-16T03:44:57.554088 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
53603:45:14# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. It took 2 minutes 43.34 seconds. Expected to take 1 minute 29.84 seconds.
53703:45:14# [RSpecRunTime] RSpec elapsed time: 14 minutes 10.72 seconds. Current RSS: ~1026M. Threads: 4. load average: 1.16 1.20 1.18 1/280 462
53803:45:14.
53903:45:14# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb. Expected to take 1 minute 18.04 seconds.
54003:45:14Gitlab::BackgroundMigration::BackfillBoardsEpicBoardPositionsGroupId
54103:46:04 performs without error
54203:46:10 constructs a valid query
54303:46:11I, [2024-10-16T03:46:11.892611 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
54403:46:11I, [2024-10-16T03:46:11.893842 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
54503:46:11I, [2024-10-16T03:46:11.894662 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
54603:46:22I, [2024-10-16T03:46:22.838274 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
54703:46:29I, [2024-10-16T03:46:29.445713 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
54803:46:37I, [2024-10-16T03:46:37.148368 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
54903:46:39I, [2024-10-16T03:46:39.686784 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
55003:46:43INFO: analyzing "public.p_ci_pipelines" inheritance tree
55103:46:43INFO: analyzing "public.ci_pipelines"
55203:46:43INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
55303:46:43I, [2024-10-16T03:46:43.242124 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
55403:46:43I, [2024-10-16T03:46:43.243436 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
55503:46:43I, [2024-10-16T03:46:43.244335 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
55603:46:48I, [2024-10-16T03:46:48.648489 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
55703:47:05# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb. It took 1 minute 51.19 seconds. Expected to take 1 minute 18.04 seconds.
55803:47:05# [RSpecRunTime] RSpec elapsed time: 16 minutes 1.95 seconds. Current RSS: ~1031M. Threads: 4. load average: 1.01 1.15 1.16 2/281 463
55903:47:05.
56003:47:05# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_related_epic_links_group_id_spec.rb. Expected to take 1 minute 16.32 seconds.
56103:47:05Gitlab::BackgroundMigration::BackfillRelatedEpicLinksGroupId
56203:47:55 performs without error
56303:48:01 constructs a valid query
56403:48:12I, [2024-10-16T03:48:12.549628 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
56503:48:19I, [2024-10-16T03:48:19.231688 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
56603:48:26I, [2024-10-16T03:48:26.813435 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
56703:48:29I, [2024-10-16T03:48:29.304811 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
56803:48:32INFO: analyzing "public.p_ci_pipelines" inheritance tree
56903:48:32INFO: analyzing "public.ci_pipelines"
57003:48:32INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
57103:48:32I, [2024-10-16T03:48:32.967613 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
57203:48:32I, [2024-10-16T03:48:32.968805 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57303:48:32I, [2024-10-16T03:48:32.969672 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
57403:48:38I, [2024-10-16T03:48:38.611227 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
57503:48:55# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_related_epic_links_group_id_spec.rb. It took 1 minute 49.42 seconds. Expected to take 1 minute 16.32 seconds.
57603:48:55# [RSpecRunTime] RSpec elapsed time: 17 minutes 51.48 seconds. Current RSS: ~1037M. Threads: 4. load average: 1.12 1.15 1.16 1/280 464
57703:48:55.
57803:48:55# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_labels_group_id_spec.rb. Expected to take 1 minute 5.59 seconds.
57903:48:55Gitlab::BackgroundMigration::BackfillBoardsEpicBoardLabelsGroupId
58003:49:46 performs without error
58103:49:52 constructs a valid query
58203:49:53I, [2024-10-16T03:49:53.705745 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
58303:49:53I, [2024-10-16T03:49:53.706944 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
58403:49:53I, [2024-10-16T03:49:53.707705 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
58503:50:04I, [2024-10-16T03:50:04.686015 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
58603:50:11I, [2024-10-16T03:50:11.510858 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
58703:50:19I, [2024-10-16T03:50:19.119875 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
58803:50:21I, [2024-10-16T03:50:21.627982 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
58903:50:25INFO: analyzing "public.p_ci_pipelines" inheritance tree
59003:50:25INFO: analyzing "public.ci_pipelines"
59103:50:25INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
59203:50:25I, [2024-10-16T03:50:25.213503 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
59303:50:25I, [2024-10-16T03:50:25.214735 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
59403:50:25I, [2024-10-16T03:50:25.215645 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
59503:50:30I, [2024-10-16T03:50:30.437619 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
59603:50:46# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_boards_epic_board_labels_group_id_spec.rb. It took 1 minute 51.43 seconds. Expected to take 1 minute 5.59 seconds.
59703:50:46# [RSpecRunTime] RSpec elapsed time: 19 minutes 42.95 seconds. Current RSS: ~1030M. Threads: 4. load average: 1.04 1.13 1.15 1/280 465
59803:50:46.
59903:50:46# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_dora_daily_metrics_project_id_spec.rb. Expected to take 1 minute 4.0 seconds.
60003:50:46Gitlab::BackgroundMigration::BackfillDoraDailyMetricsProjectId
60103:51:36 performs without error
60203:51:42 constructs a valid query
60303:51:42I, [2024-10-16T03:51:42.784519 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
60403:51:42I, [2024-10-16T03:51:42.785676 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
60503:51:42I, [2024-10-16T03:51:42.786501 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
60603:51:53I, [2024-10-16T03:51:53.138726 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
60703:51:59I, [2024-10-16T03:51:59.642011 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
60803:52:07I, [2024-10-16T03:52:07.057428 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
60903:52:09I, [2024-10-16T03:52:09.385912 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
61003:52:12INFO: analyzing "public.p_ci_pipelines" inheritance tree
61103:52:12INFO: analyzing "public.ci_pipelines"
61203:52:12INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
61303:52:12I, [2024-10-16T03:52:12.864478 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
61403:52:12I, [2024-10-16T03:52:12.865580 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61503:52:12I, [2024-10-16T03:52:12.866392 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61603:52:17I, [2024-10-16T03:52:17.990064 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
61703:52:33# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_dora_daily_metrics_project_id_spec.rb. It took 1 minute 46.84 seconds. Expected to take 1 minute 4.0 seconds.
61803:52:33# [RSpecRunTime] RSpec elapsed time: 21 minutes 29.87 seconds. Current RSS: ~1036M. Threads: 4. load average: 0.98 1.07 1.13 1/280 466
61903:52:33.
62003:52:33# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb. Expected to take 1 minute 1.01 seconds.
62103:52:33Gitlab::BackgroundMigration::BackfillVulnerabilityStateTransitionsProjectId
62203:53:21 performs without error
62303:53:27 constructs a valid query
62403:53:38I, [2024-10-16T03:53:38.714693 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
62503:53:45I, [2024-10-16T03:53:45.064206 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
62603:53:52I, [2024-10-16T03:53:52.341850 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
62703:53:54I, [2024-10-16T03:53:54.658815 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
62803:53:58INFO: analyzing "public.p_ci_pipelines" inheritance tree
62903:53:58INFO: analyzing "public.ci_pipelines"
63003:53:58INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
63103:53:58I, [2024-10-16T03:53:58.208987 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
63203:53:58I, [2024-10-16T03:53:58.210402 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
63303:53:58I, [2024-10-16T03:53:58.211655 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
63403:54:03I, [2024-10-16T03:54:03.352038 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
63503:54:19# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb. It took 1 minute 45.63 seconds. Expected to take 1 minute 1.01 seconds.
63603:54:19# [RSpecRunTime] RSpec elapsed time: 23 minutes 15.55 seconds. Current RSS: ~1039M. Threads: 4. load average: 0.97 1.07 1.12 1/280 467
63703:54:19.
63803:54:19# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_protected_branches_group_id_spec.rb. Expected to take 58.76 seconds.
63903:54:19Gitlab::BackgroundMigration::BackfillApprovalGroupRulesProtectedBranchesGroupId
64003:54:54 constructs a valid query
64103:54:59 performs without error
64203:55:05I, [2024-10-16T03:55:05.525791 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
64303:55:12I, [2024-10-16T03:55:12.566940 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
64403:55:14I, [2024-10-16T03:55:14.813980 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
64503:55:18INFO: analyzing "public.p_ci_pipelines" inheritance tree
64603:55:18INFO: analyzing "public.ci_pipelines"
64703:55:18INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
64803:55:18I, [2024-10-16T03:55:18.243235 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
64903:55:18I, [2024-10-16T03:55:18.244529 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
65003:55:18I, [2024-10-16T03:55:18.245377 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
65103:55:23I, [2024-10-16T03:55:23.062386 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
65203:55:39# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_protected_branches_group_id_spec.rb. It took 1 minute 19.55 seconds. Expected to take 58.76 seconds.
65303:55:39# [RSpecRunTime] RSpec elapsed time: 24 minutes 35.15 seconds. Current RSS: ~1036M. Threads: 4. load average: 1.07 1.06 1.11 1/280 468
65403:55:39.
65503:55:39# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_candidate_metadata_project_id_spec.rb. Expected to take 50.98 seconds.
65603:55:39Gitlab::BackgroundMigration::BackfillMlCandidateMetadataProjectId
65703:56:11 constructs a valid query
65803:56:15 performs without error
65903:56:16I, [2024-10-16T03:56:16.230051 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
66003:56:21I, [2024-10-16T03:56:21.547356 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
66103:56:28I, [2024-10-16T03:56:28.230704 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
66203:56:30I, [2024-10-16T03:56:30.499825 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
66303:56:34INFO: analyzing "public.p_ci_pipelines" inheritance tree
66403:56:34INFO: analyzing "public.ci_pipelines"
66503:56:34INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
66603:56:34I, [2024-10-16T03:56:34.159696 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
66703:56:34I, [2024-10-16T03:56:34.160823 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66803:56:34I, [2024-10-16T03:56:34.161638 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66903:56:39I, [2024-10-16T03:56:39.013179 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
67003:56:54# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_candidate_metadata_project_id_spec.rb. It took 1 minute 15.61 seconds. Expected to take 50.98 seconds.
67103:56:54# [RSpecRunTime] RSpec elapsed time: 25 minutes 50.8 seconds. Current RSS: ~1039M. Threads: 4. load average: 1.09 1.08 1.11 1/280 469
67203:56:54.
67303:56:54# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_users_group_id_spec.rb. Expected to take 48.51 seconds.
67403:56:54Gitlab::BackgroundMigration::BackfillApprovalGroupRulesUsersGroupId
67503:57:29 constructs a valid query
67603:57:34 performs without error
67703:57:40I, [2024-10-16T03:57:40.616168 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
67803:57:47I, [2024-10-16T03:57:47.602319 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
67903:57:49I, [2024-10-16T03:57:49.806704 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
68003:57:53INFO: analyzing "public.p_ci_pipelines" inheritance tree
68103:57:53INFO: analyzing "public.ci_pipelines"
68203:57:53INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
68303:57:53I, [2024-10-16T03:57:53.226240 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
68403:57:53I, [2024-10-16T03:57:53.227425 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
68503:57:53I, [2024-10-16T03:57:53.228186 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
68603:57:57I, [2024-10-16T03:57:57.985869 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
68703:58:13# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_users_group_id_spec.rb. It took 1 minute 18.44 seconds. Expected to take 48.51 seconds.
68803:58:13# [RSpecRunTime] RSpec elapsed time: 27 minutes 9.29 seconds. Current RSS: ~1035M. Threads: 4. load average: 1.01 1.04 1.09 1/281 470
68903:58:13.
69003:58:13# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_related_epic_links_to_issue_links_spec.rb. Expected to take 41.61 seconds.
69103:58:13Gitlab::BackgroundMigration::BackfillRelatedEpicLinksToIssueLinks
69203:58:44 backfills data correctly
69303:58:48I, [2024-10-16T03:58:48.150188 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
69403:58:55I, [2024-10-16T03:58:55.014263 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
69503:58:57I, [2024-10-16T03:58:57.256609 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
69603:59:00INFO: analyzing "public.p_ci_pipelines" inheritance tree
69703:59:00INFO: analyzing "public.ci_pipelines"
69803:59:00INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
69903:59:00I, [2024-10-16T03:59:00.809914 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
70003:59:00I, [2024-10-16T03:59:00.811065 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
70103:59:00I, [2024-10-16T03:59:00.811846 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
70203:59:05I, [2024-10-16T03:59:05.838460 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
70303:59:20# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_related_epic_links_to_issue_links_spec.rb. It took 1 minute 7.77 seconds. Expected to take 41.61 seconds.
70403:59:21# [RSpecRunTime] RSpec elapsed time: 28 minutes 17.09 seconds. Current RSS: ~1041M. Threads: 4. load average: 1.05 1.03 1.08 1/281 471
70503:59:21.
70603:59:21# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_evidences_project_id_spec.rb. Expected to take 38.44 seconds.
70703:59:21Gitlab::BackgroundMigration::BackfillEvidencesProjectId
70803:59:50 constructs a valid query
70903:59:54 performs without error
71004:00:00I, [2024-10-16T04:00:00.785841 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
71104:00:02I, [2024-10-16T04:00:02.949937 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
71204:00:06INFO: analyzing "public.p_ci_pipelines" inheritance tree
71304:00:06INFO: analyzing "public.ci_pipelines"
71404:00:06INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
71504:00:06I, [2024-10-16T04:00:06.511827 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
71604:00:06I, [2024-10-16T04:00:06.512970 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
71704:00:06I, [2024-10-16T04:00:06.513757 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
71804:00:10I, [2024-10-16T04:00:10.994466 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
71904:00:25# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_evidences_project_id_spec.rb. It took 1 minute 4.59 seconds. Expected to take 38.44 seconds.
72004:00:25# [RSpecRunTime] RSpec elapsed time: 29 minutes 21.72 seconds. Current RSS: ~1037M. Threads: 4. load average: 1.06 1.03 1.08 1/281 472
72104:00:25.
72204:00:25# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_candidate_metrics_project_id_spec.rb. Expected to take 30.65 seconds.
72304:00:25Gitlab::BackgroundMigration::BackfillMlCandidateMetricsProjectId
72404:00:45 performs without error
72504:00:48 constructs a valid query
72604:00:49I, [2024-10-16T04:00:49.351382 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
72704:00:52INFO: analyzing "public.p_ci_pipelines" inheritance tree
72804:00:52INFO: analyzing "public.ci_pipelines"
72904:00:52INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
73004:00:52I, [2024-10-16T04:00:52.756269 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
73104:00:52I, [2024-10-16T04:00:52.757444 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
73204:00:52I, [2024-10-16T04:00:52.758279 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
73304:00:57I, [2024-10-16T04:00:57.341970 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
73404:01:12# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_candidate_metrics_project_id_spec.rb. It took 46.5 seconds. Expected to take 30.65 seconds.
73504:01:12# [RSpecRunTime] RSpec elapsed time: 30 minutes 8.26 seconds. Current RSS: ~1045M. Threads: 4. load average: 1.06 1.04 1.08 1/281 473
73604:01:12.
73704:01:12# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_candidate_params_project_id_spec.rb. Expected to take 26.4 seconds.
73804:01:12Gitlab::BackgroundMigration::BackfillMlCandidateParamsProjectId
73904:01:30 performs without error
74004:01:34 constructs a valid query
74104:01:37INFO: analyzing "public.p_ci_pipelines" inheritance tree
74204:01:37INFO: analyzing "public.ci_pipelines"
74304:01:37INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
74404:01:37I, [2024-10-16T04:01:37.140952 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
74504:01:37I, [2024-10-16T04:01:37.142019 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
74604:01:37I, [2024-10-16T04:01:37.142881 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
74704:01:41I, [2024-10-16T04:01:41.977772 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
74804:01:56# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_candidate_params_project_id_spec.rb. It took 44.64 seconds. Expected to take 26.4 seconds.
74904:01:56# [RSpecRunTime] RSpec elapsed time: 30 minutes 52.94 seconds. Current RSS: ~1042M. Threads: 4. load average: 1.22 1.09 1.10 1/282 474
75004:01:56.
75104:01:56# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb. Expected to take 18.18 seconds.
75204:01:56Gitlab::BackgroundMigration::BackfillIncidentManagementOncallRotationsProjectId
75304:02:06 constructs a valid query
75404:02:09 performs without error
75504:02:24# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb. It took 28.05 seconds. Expected to take 18.18 seconds.
75604:02:24# [RSpecRunTime] RSpec elapsed time: 31 minutes 21.03 seconds. Current RSS: ~1041M. Threads: 4. load average: 1.13 1.08 1.09 1/282 475
75704:02:24.
75804:02:24# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_dast_profiles_pipelines_project_id_spec.rb. Expected to take 16.89 seconds.
75904:02:24Gitlab::BackgroundMigration::BackfillDastProfilesPipelinesProjectId
76004:02:33 constructs a valid query
76104:02:37 performs without error
76204:02:51# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_dast_profiles_pipelines_project_id_spec.rb. It took 26.96 seconds. Expected to take 16.89 seconds.
76304:02:51# [RSpecRunTime] RSpec elapsed time: 31 minutes 48.03 seconds. Current RSS: ~1040M. Threads: 4. load average: 1.19 1.11 1.10 1/282 476
76404:02:51.
76504:02:51# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_alert_management_alert_metric_images_project_id_spec.rb. Expected to take 14.94 seconds.
76604:02:51Gitlab::BackgroundMigration::BackfillAlertManagementAlertMetricImagesProjectId
76704:03:01 constructs a valid query
76804:03:04 performs without error
76904:03:19# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_alert_management_alert_metric_images_project_id_spec.rb. It took 27.68 seconds. Expected to take 14.94 seconds.
77004:03:19# [RSpecRunTime] RSpec elapsed time: 32 minutes 15.75 seconds. Current RSS: ~1036M. Threads: 4. load average: 0.98 1.06 1.08 1/281 477
77104:03:19.
77204:03:19# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_issues_correct_work_item_type_id_spec.rb. Expected to take 10.34 seconds.
77304:03:19Gitlab::BackgroundMigration::BackfillIssuesCorrectWorkItemTypeId
77404:03:23 sets correct_work_item_type_id for all records in batches
77504:03:27 tracks timings of queries
77604:03:34# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_issues_correct_work_item_type_id_spec.rb. It took 15.29 seconds. Expected to take 10.34 seconds.
77704:03:34# [RSpecRunTime] RSpec elapsed time: 32 minutes 31.08 seconds. Current RSS: ~1035M. Threads: 4. load average: 0.84 1.03 1.07 1/281 478
77804:03:34.
77904:03:34# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_orphaned_deploy_tokens_spec.rb. Expected to take 7.35 seconds.
78004:03:34Gitlab::BackgroundMigration::DeleteOrphanedDeployTokens
78104:03:39 removes deploy tokens with no project or group join table record
78204:03:46# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_orphaned_deploy_tokens_spec.rb. It took 11.3 seconds. Expected to take 7.35 seconds.
78304:03:46# [RSpecRunTime] RSpec elapsed time: 32 minutes 42.42 seconds. Current RSS: ~1034M. Threads: 4. load average: 0.94 1.04 1.08 1/281 479
78404:03:46.
78504:03:46# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb. Expected to take 5.96 seconds.
78604:03:46Gitlab::BackgroundMigration::UpdateUsersSetExternalIfServiceAccount
78704:03:46 #perform
78804:03:50 changes external field for service_account user
78904:03:50# [RSpecRunTime] RSpec elapsed time: 32 minutes 46.42 seconds. Current RSS: ~1045M. Threads: 4. load average: 1.02 1.06 1.08 1/281 480
79004:03:50.
79104:03:57# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb. It took 11.13 seconds. Expected to take 5.96 seconds.
79204:03:57# [RSpecRunTime] RSpec elapsed time: 32 minutes 53.58 seconds. Current RSS: ~1032M. Threads: 4. load average: 0.94 1.04 1.08 1/281 481
79304:03:57.
79404:03:57# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/backfill_project_statistics_with_container_registry_size_batching_strategy_spec.rb. Expected to take 4.94 seconds.
79504:03:57Gitlab::BackgroundMigration::BatchingStrategies::BackfillProjectStatisticsWithContainerRegistrySizeBatchingStrategy
79604:04:01 is expected to be < Gitlab::BackgroundMigration::BatchingStrategies::PrimaryKeyBatchingStrategy
79704:04:08# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/backfill_project_statistics_with_container_registry_size_batching_strategy_spec.rb. It took 11.06 seconds. Expected to take 4.94 seconds.
79804:04:08# [RSpecRunTime] RSpec elapsed time: 33 minutes 4.69 seconds. Current RSS: ~1037M. Threads: 4. load average: 0.95 1.04 1.07 1/281 482
79904:04:08.
80004:04:08# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb. Expected to take 4.58 seconds.
80104:04:08Gitlab::BackgroundMigration::EncryptCiTriggerToken
80204:04:12 ensures all unencrypted tokens are encrypted
80304:04:19# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb. It took 11.21 seconds. Expected to take 4.58 seconds.
80404:04:19# [RSpecRunTime] RSpec elapsed time: 33 minutes 15.93 seconds. Current RSS: ~1040M. Threads: 4. load average: 1.04 1.05 1.08 1/281 483
80504:04:19.
80604:05:10auto_explain log contains 1196 entries for main, writing to /builds/gitlab-org/gitlab-foss/auto_explain/rspec-background-migration-pg14-10-10.341.main.ndjson.gz
80704:05:10took 50.485484852
80804:06:01auto_explain log contains 1197 entries for ci, writing to /builds/gitlab-org/gitlab-foss/auto_explain/rspec-background-migration-pg14-10-10.341.ci.ndjson.gz
80904:06:01took 49.98699443
81004:06:01[TEST PROF INFO] EventProf results for sql.active_record
81104:06:01Total time: 20:38.207 of 33:10.355 (62.21%)
81204:06:01Total events: 999961
81304:06:01Top 5 slowest suites (by time):
81404:06:01Gitlab::Backg...InvalidMembers (./spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb:6) – 02:41.829 (116254 / 3) of 04:27.134 (60.58%)
81504:06:01Gitlab::Backg...thoutFindingId (./spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb:5) – 01:53.422 (83993 / 1) of 02:43.376 (69.42%)
81604:06:01Gitlab::Backg...rnalIssueLinks (./spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb:5) – 01:41.502 (73504 / 2) of 02:30.998 (67.22%)
81704:06:01Gitlab::Backg...dLabelsGroupId (./spec/lib/gitlab/background_migration/backfill_boards_epic_board_labels_group_id_spec.rb:5) – 01:13.415 (52099 / 2) of 01:51.510 (65.84%)
81804:06:01Gitlab::Backg...sitionsGroupId (./spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb:5) – 01:13.315 (52083 / 2) of 01:51.297 (65.87%)
81904:06:01Knapsack report was generated. Preview:
82004:06:01{
82104:06:01 "spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb": 150.3632931279999,
82204:06:01 "spec/lib/gitlab/background_migration/job_coordinator_spec.rb": 141.27133278099973,
82304:06:01 "spec/lib/gitlab/background_migration/legacy_upload_mover_spec.rb": 104.66524967299938,
82404:06:01 "spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb": 80.61962442500044,
82504:06:01 "spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb": 81.16438337799991,
82604:06:01 "spec/lib/gitlab/background_migration/backfill_boards_epic_board_positions_group_id_spec.rb": 56.29832914100007,
82704:06:01 "spec/lib/gitlab/background_migration/backfill_related_epic_links_group_id_spec.rb": 55.28012370600027,
82804:06:01 "spec/lib/gitlab/background_migration/backfill_boards_epic_board_labels_group_id_spec.rb": 57.26018787799967,
82904:06:01 "spec/lib/gitlab/background_migration/backfill_dora_daily_metrics_project_id_spec.rb": 55.303743722000036,
83004:06:01 "spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb": 53.72691744000076,
83104:06:01 "spec/lib/gitlab/background_migration/backfill_approval_group_rules_protected_branches_group_id_spec.rb": 39.814978220999365,
83204:06:01 "spec/lib/gitlab/background_migration/backfill_ml_candidate_metadata_project_id_spec.rb": 36.59751041999971,
83304:06:01 "spec/lib/gitlab/background_migration/backfill_approval_group_rules_users_group_id_spec.rb": 39.83751790600036,
83404:06:01 "spec/lib/gitlab/background_migration/backfill_related_epic_links_to_issue_links_spec.rb": 31.24702572699971,
83504:06:01 "spec/lib/gitlab/background_migration/backfill_evidences_project_id_spec.rb": 33.23251786699984,
83604:06:01 "spec/lib/gitlab/background_migration/backfill_ml_candidate_metrics_project_id_spec.rb": 23.14657793800052,
83704:06:01 "spec/lib/gitlab/background_migration/backfill_ml_candidate_params_project_id_spec.rb": 22.214456556000187,
83804:06:01 "spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb": 13.063037318999704,
83904:06:01 "spec/lib/gitlab/background_migration/backfill_dast_profiles_pipelines_project_id_spec.rb": 12.25360595500024,
84004:06:01 "spec/lib/gitlab/background_migration/backfill_alert_management_alert_metric_images_project_id_spec.rb": 12.746800859999894,
84104:06:01 "spec/lib/gitlab/background_migration/backfill_issues_correct_work_item_type_id_spec.rb": 8.05684978699992,
84204:06:01 "spec/lib/gitlab/background_migration/delete_orphaned_deploy_tokens_spec.rb": 4.18461802299953,
84304:06:01 "spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb": 4.0099215770005685,
84404:06:01 "spec/lib/gitlab/background_migration/batching_strategies/backfill_project_statistics_with_container_registry_size_batching_strategy_spec.rb": 3.8614671760005876,
84504:06:01 "spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb": 4.194873950999863
84604:06:01}
84704:06:01Knapsack global time execution for tests: 18m 44s
84804:06:01Finished in 34 minutes 57 seconds (files took 1 minute 28.84 seconds to load)
84904:06:0192 examples, 0 failures
85004:06:01Randomized with seed 3871
85104:06:05[TEST PROF INFO] Time spent in factories: 00:31.262 (1.46% of total time)
85204:06:05RSpec exited with 0.
85304:06:05No examples to retry, congrats!
854 04:06:06 Running after_script 00:14
85504:06:06Running after script...
85604:06:06$ source scripts/utils.sh
85704:06:06$ log_disk_usage
85804:06:06*******************************************************
85904:06:06This runner currently has 70G free disk space.
86004:06:06*******************************************************
861 04:06:06 Disk usage detail 00:07
91404:06:13$ bundle exec gem list gitlab_quality-test_tooling
91504:06:15gitlab_quality-test_tooling (1.39.0)
91604:06:15$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
917 04:06:15 Report test failures 00:02
92104:06:17$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
922 04:06:17 Report test flakiness 00:00
92404:06:17$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
925 04:06:17 Report test slowness 00:02
92904:06:19$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
930 04:06:19 Report test slowness in MR note 00:00
93204:06:19$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
933 04:06:19 Report test files close to timing out 00:00
93504:06:19$ tooling/bin/push_job_metrics || true
93604:06:20[job-metrics] Feature disabled because CI_JOB_METRICS_ENABLED is not set to true.
937 04:06:20 Saving cache for successful job 00:01
93804:06:20Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-3 due to policy
939 04:06:21 Uploading artifacts for successful job 00:05
94004:06:21Uploading artifacts...
94104:06:21auto_explain/: found 3 matching artifact files and directories
94204:06:21coverage/: found 5 matching artifact files and directories
94304:06:21WARNING: crystalball/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab-foss)
94404:06:21WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab-foss)
94504:06:21knapsack/: found 4 matching artifact files and directories
94604:06:21rspec/: found 12 matching artifact files and directories
94704:06:21WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab-foss)
94804:06:21log/*.log: found 13 matching artifact files and directories
94904:06:21WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8095843156/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
95004:06:21WARNING: Retrying... context=artifacts-uploader error=request redirected
95104:06:24Uploading artifacts as "archive" to coordinator... 201 Created id=8095843156 responseStatus=201 Created token=glcbt-66
95204:06:24Uploading artifacts...
95304:06:24rspec/rspec-*.xml: found 1 matching artifact files and directories
95404:06:24WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8095843156/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
95504:06:24WARNING: Retrying... context=artifacts-uploader error=request redirected
95604:06:26Uploading artifacts as "junit" to coordinator... 201 Created id=8095843156 responseStatus=201 Created token=glcbt-66
957 04:06:26 Cleaning up project directory and file based variables 00:00
95804:06:34Job succeeded