Skip to content
Snippets Groups Projects

rspec background_migration pg14 3/5

Passed Started by
Alper Akgun
@a_akgun
1Running with gitlab-runner 16.8.0~beta.67.gb5664e8e (b5664e8e)
2 on blue-1.private.runners-manager.gitlab.com/gitlab.com/gitlab-org 1zzGUpzq, system ID: s_fc31da7ae46e
3 feature flags: FF_NETWORK_PER_BUILD:true, FF_USE_IMPROVED_URL_MASKING:true
4 Resolving secrets 00:00
5 Preparing the "docker+machine" executor 00:06
6Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.20-rust-1.73-node-18.17-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-120-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:b6c412dc298714b5c26feca1330d8f743b48caf0b1feeadfd554d7d446f985a5 for redis:6.2-alpine with digest redis@sha256:51d6c56749a4243096327e3fb964a48ed92254357108449cb6e23999c37773c5 ...
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.patched-golang-1.20-rust-1.73-node-18.17-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-120-yarn-1.22-graphicsmagick-1.3.36 ...
23Using docker image sha256:2da9ff69af721f2e843977af3fff30c19251b52ac779c79742b680095f026b53 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.20-rust-1.73-node-18.17-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-120-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.20-rust-1.73-node-18.17-postgresql-14@sha256:6b2253621fc67a1033a6eda2566fffedc84a9492a799632fc6be996a3ec6f21e ...
24 Preparing environment 00:01
25Running on runner-1zzgupzq-project-278964-concurrent-0 via runner-1zzgupzq-private-1709184342-1faf8b60...
26 Getting source from Git repository 00:00
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
30 Restoring cache 00:15
31Checking cache for ruby-gems-debian-bookworm-ruby-3.1-16...
32cache.zip is up to date
33Successfully extracted cache
34 Downloading artifacts 00:33
35Downloading artifacts for clone-gitlab-repo (6285087661)...
36Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6285087661 responseStatus=200 OK token=glcbt-65
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 (6285087711)...
40Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6285087711 responseStatus=200 OK token=glcbt-65
41Downloading artifacts for detect-tests (6285087738)...
42Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6285087738 responseStatus=200 OK token=glcbt-65
43Downloading artifacts for retrieve-tests-metadata (6285087759)...
44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6285087759 responseStatus=200 OK token=glcbt-65
45Downloading artifacts for setup-test-env (6285087723)...
46Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6285087723 responseStatus=200 OK token=glcbt-65
47 Executing "step_script" stage of the job script 32:30
48Using docker image sha256:2da9ff69af721f2e843977af3fff30c19251b52ac779c79742b680095f026b53 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.20-rust-1.73-node-18.17-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-120-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.20-rust-1.73-node-18.17-postgresql-14@sha256:6b2253621fc67a1033a6eda2566fffedc84a9492a799632fc6be996a3ec6f21e ...
49$ echo $FOSS_ONLY
50$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
51$ export GOPATH=$CI_PROJECT_DIR/.go
52$ mkdir -p $GOPATH
53$ source scripts/utils.sh
54$ source scripts/prepare_build.sh
55 Installing gems 00:14
733Using decomposed database config (config/database.yml.decomposed-postgresql)
734Geo DB won't be set up.
735Embedding DB won't be set up.
736 Setting up DBs 00:50
747$ source ./scripts/rspec_helpers.sh
748$ run_timed_command "gem install knapsack --no-document"
749$ gem install knapsack --no-document
750Successfully installed knapsack-4.0.0
7511 gem installed
752==> 'gem install knapsack --no-document' succeeded in 1 seconds.
753$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
754 Spawning Gitaly 00:03
758$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
759$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
760$ tooling/bin/create_job_metrics_file || true
761[job-metrics] Creating the job metrics file for the CI/CD job.
762$ rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
763[08:20:17] Starting rspec_parallelized_job
764RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
765KNAPSACK_GENERATE_REPORT: true
766FLAKY_RSPEC_GENERATE_REPORT: true
767KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
768KNAPSACK_LOG_LEVEL: debug
769KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_3_5_278964_report.json
770FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
771FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_3_5_278964_report.json
772NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_3_5_278964_report.json
773RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-6285087965.txt
774CRYSTALBALL:
775RSPEC_TESTS_MAPPING_ENABLED:
776RSPEC_TESTS_FILTER_FILE:
777Shell set options (set -o) enabled:
778braceexpand on
779hashall on
780interactive-comments on
781pipefail on
782Knapsack report generator started!
783Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
784# [RSpecRunTime] Starting RSpec timer...
785[TEST PROF INFO] EventProf enabled (sql.active_record)
786unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
787unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
788Test environment set up in 0.59333516 seconds
789# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb. Expected to take 1 minute 55.57 seconds.
790Gitlab::BackgroundMigration::BackfillRootStorageStatisticsForkStorageSizes
791 #perform
792 updates the public_forks_storage_size
793 totals the size of public forks in the namespace
794 updates the internal_forks_storage_size
795 totals the size of internal forks in the namespace
796 updates the private_forks_storage_size
797 totals the size of private forks in the namespace
798 counts only the size of forks
799 sums forks for multiple namespaces
800 counts the size of forks in subgroups
801 counts the size of forks in more nested subgroups
802 counts forks of forks
803 counts multiple forks of the same project
804 updates a namespace with no forks
805 skips the update if the public_forks_storage_size has already been set
806 skips the update if the internal_forks_storage_size has already been set
807 skips the update if the private_forks_storage_size has already been set
808 skips the update if the namespace is not found
809I, [2024-02-29T08:23:17.927624 #337] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
810INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
811INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
812INFO: "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
813INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
814INFO: "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
815INFO: analyzing "public.p_ci_job_annotations" inheritance tree
816INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
817INFO: "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
818INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
819INFO: analyzing "public.ci_builds_metadata"
820INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
821INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
822INFO: "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
823INFO: analyzing "public.p_ci_builds" inheritance tree
824INFO: analyzing "public.ci_builds"
825INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
826INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
827INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
828I, [2024-02-29T08:23:42.730559 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
829INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
830INFO: analyzing "public.ci_pipeline_variables"
831INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
832I, [2024-02-29T08:24:03.977207 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
833I, [2024-02-29T08:24:03.978364 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
834I, [2024-02-29T08:24:03.979240 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
835I, [2024-02-29T08:24:04.546279 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
836INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
837INFO: analyzing "public.ci_job_artifacts"
838INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
839I, [2024-02-29T08:24:06.031177 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
840I, [2024-02-29T08:24:06.032523 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
841I, [2024-02-29T08:24:06.034262 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
842INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
843INFO: analyzing "public.ci_pipeline_variables"
844INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
845INFO: analyzing "public.p_ci_stages" inheritance tree
846INFO: analyzing "public.ci_stages"
847INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
848I, [2024-02-29T08:24:11.698036 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
849I, [2024-02-29T08:24:11.699052 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
850I, [2024-02-29T08:24:11.699850 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
851# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb. It took 3 minutes 10.71 seconds. Expected to take 1 minute 55.57 seconds.
852# [RSpecRunTime] RSpec elapsed time: 3 minutes 13.73 seconds. Current RSS: ~1286M. load average: 0.99 1.04 1.02 1/267 384
853# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb. Expected to take 1 minute 21.17 seconds.
854Gitlab::BackgroundMigration::BackfillIntegrationsEnableSslVerification
855 enables SSL verification for known-good hostnames
856 only updates records within the given ID range
857 marks the job as succeeded
858I, [2024-02-29T08:25:41.898462 #337] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
859INFO: analyzing "public.p_ci_builds" inheritance tree
860INFO: analyzing "public.ci_builds"
861INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
862I, [2024-02-29T08:25:57.731583 #337] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
863I, [2024-02-29T08:25:57.733007 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
864I, [2024-02-29T08:25:57.733954 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
865I, [2024-02-29T08:26:11.708068 #337] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
866INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
867INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
868INFO: "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
869INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
870INFO: "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
871INFO: analyzing "public.p_ci_job_annotations" inheritance tree
872INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
873INFO: "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
874INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
875INFO: analyzing "public.ci_builds_metadata"
876INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
877INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
878INFO: "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
879INFO: analyzing "public.p_ci_builds" inheritance tree
880INFO: analyzing "public.ci_builds"
881INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
882I, [2024-02-29T08:26:37.239692 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
883INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
884INFO: analyzing "public.ci_pipeline_variables"
885INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
886I, [2024-02-29T08:26:58.937900 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
887I, [2024-02-29T08:26:58.939071 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
888I, [2024-02-29T08:26:58.939892 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
889I, [2024-02-29T08:26:59.492697 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
890INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
891INFO: analyzing "public.ci_job_artifacts"
892INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
893I, [2024-02-29T08:27:00.624335 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
894I, [2024-02-29T08:27:00.625808 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
895I, [2024-02-29T08:27:00.626696 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
896INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
897INFO: analyzing "public.ci_pipeline_variables"
898INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
899INFO: analyzing "public.p_ci_stages" inheritance tree
900INFO: analyzing "public.ci_stages"
901INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
902I, [2024-02-29T08:27:05.633291 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
903I, [2024-02-29T08:27:05.634413 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
904I, [2024-02-29T08:27:05.635224 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
905# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb. It took 2 minutes 53.72 seconds. Expected to take 1 minute 21.17 seconds.
906# [RSpecRunTime] RSpec elapsed time: 6 minutes 7.49 seconds. Current RSS: ~1280M. load average: 1.08 1.06 1.03 1/267 385
907# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_reads_cluster_agent_spec.rb. Expected to take 1 minute 19.22 seconds.
908Gitlab::BackgroundMigration::BackfillVulnerabilityReadsClusterAgent
909 #filter_batch
910 pick only vulnerability reads where report_type = 7
911# [RSpecRunTime] RSpec elapsed time: 7 minutes 23.32 seconds. Current RSS: ~1289M. load average: 1.25 1.11 1.04 1/273 387
912 #perform
913 backfills `casted_cluster_agent_id` for the selected records
914 tracks timings of queries
915# [RSpecRunTime] RSpec elapsed time: 7 minutes 30.26 seconds. Current RSS: ~1299M. load average: 1.21 1.10 1.04 1/273 388
916I, [2024-02-29T08:28:36.027136 #337] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
917INFO: analyzing "public.p_ci_builds" inheritance tree
918INFO: analyzing "public.ci_builds"
919INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
920I, [2024-02-29T08:28:52.405604 #337] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
921I, [2024-02-29T08:28:52.406690 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
922I, [2024-02-29T08:28:52.407567 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
923I, [2024-02-29T08:29:07.287490 #337] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
924INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
925INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
926INFO: "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
927INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
928INFO: "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
929INFO: analyzing "public.p_ci_job_annotations" inheritance tree
930INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
931INFO: "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
932INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
933INFO: analyzing "public.ci_builds_metadata"
934INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
935INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
936INFO: "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
937INFO: analyzing "public.p_ci_builds" inheritance tree
938INFO: analyzing "public.ci_builds"
939INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
940I, [2024-02-29T08:29:34.326406 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
941INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
942INFO: analyzing "public.ci_pipeline_variables"
943INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
944I, [2024-02-29T08:29:56.963684 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
945I, [2024-02-29T08:29:56.964879 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
946I, [2024-02-29T08:29:56.965814 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
947I, [2024-02-29T08:29:57.519994 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
948INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
949INFO: analyzing "public.ci_job_artifacts"
950INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
951I, [2024-02-29T08:29:58.881762 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
952I, [2024-02-29T08:29:58.882842 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
953I, [2024-02-29T08:29:58.883616 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
954INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
955INFO: analyzing "public.ci_pipeline_variables"
956INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
957INFO: analyzing "public.p_ci_stages" inheritance tree
958INFO: analyzing "public.ci_stages"
959INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
960I, [2024-02-29T08:30:04.507572 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
961I, [2024-02-29T08:30:04.508915 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
962I, [2024-02-29T08:30:04.509833 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
963# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_reads_cluster_agent_spec.rb. It took 2 minutes 59.24 seconds. Expected to take 1 minute 19.22 seconds.
964# [RSpecRunTime] RSpec elapsed time: 9 minutes 6.77 seconds. Current RSS: ~1274M. load average: 1.00 1.05 1.02 1/273 389
965# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_internal_on_notes_spec.rb. Expected to take 1 minute 17.69 seconds.
966Gitlab::BackgroundMigration::BackfillInternalOnNotes
967 #perform
968 backfills internal column on notes when confidential
969# [RSpecRunTime] RSpec elapsed time: 10 minutes 28.24 seconds. Current RSS: ~1277M. load average: 1.03 1.04 1.01 1/274 391
970I, [2024-02-29T08:31:35.044002 #337] INFO -- : Database: 'main', Table: 'p_ci_runner_machine_builds': Lock Writes
971I, [2024-02-29T08:31:35.254758 #337] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
972INFO: analyzing "public.p_ci_builds" inheritance tree
973INFO: analyzing "public.ci_builds"
974INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
975I, [2024-02-29T08:31:52.239824 #337] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
976I, [2024-02-29T08:31:52.241114 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
977I, [2024-02-29T08:31:52.242020 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
978I, [2024-02-29T08:32:07.479640 #337] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
979INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
980INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
981INFO: "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
982INFO: analyzing "public.p_ci_job_annotations" inheritance tree
983INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
984INFO: "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
985INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
986INFO: analyzing "public.ci_builds_metadata"
987INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
988INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
989INFO: "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
990INFO: analyzing "public.p_ci_builds" inheritance tree
991INFO: analyzing "public.ci_builds"
992INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
993I, [2024-02-29T08:32:35.000275 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
994INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
995INFO: analyzing "public.ci_pipeline_variables"
996INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
997I, [2024-02-29T08:32:58.040327 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
998I, [2024-02-29T08:32:58.041930 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
999I, [2024-02-29T08:32:58.042961 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1000I, [2024-02-29T08:32:58.615083 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1001INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1002INFO: analyzing "public.ci_job_artifacts"
1003INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1004I, [2024-02-29T08:33:00.138945 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1005I, [2024-02-29T08:33:00.140523 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1006I, [2024-02-29T08:33:00.141582 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1007INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1008INFO: analyzing "public.ci_pipeline_variables"
1009INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1010INFO: analyzing "public.p_ci_stages" inheritance tree
1011INFO: analyzing "public.ci_stages"
1012INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1013I, [2024-02-29T08:33:05.894433 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1014I, [2024-02-29T08:33:05.895842 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1015I, [2024-02-29T08:33:05.896829 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1016# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_internal_on_notes_spec.rb. It took 3 minutes 1.17 seconds. Expected to take 1 minute 17.69 seconds.
1017# [RSpecRunTime] RSpec elapsed time: 12 minutes 7.97 seconds. Current RSS: ~1268M. load average: 0.96 1.01 1.00 1/274 392
1018# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb. Expected to take 1 minute 16.09 seconds.
1019Gitlab::BackgroundMigration::BackfillNamespaceIdOfVulnerabilityReads
1020 sets the namespace_id of existing record
1021I, [2024-02-29T08:34:34.171973 #337] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
1022INFO: analyzing "public.p_ci_builds" inheritance tree
1023INFO: analyzing "public.ci_builds"
1024INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1025I, [2024-02-29T08:34:52.008997 #337] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
1026I, [2024-02-29T08:34:52.010352 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1027I, [2024-02-29T08:34:52.011329 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1028I, [2024-02-29T08:35:07.674006 #337] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1029INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1030INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1031INFO: "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
1032INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1033INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1034INFO: "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
1035INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1036INFO: analyzing "public.ci_builds_metadata"
1037INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1038INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1039INFO: "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
1040INFO: analyzing "public.p_ci_builds" inheritance tree
1041INFO: analyzing "public.ci_builds"
1042INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1043I, [2024-02-29T08:35:35.681079 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1044INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1045INFO: analyzing "public.ci_pipeline_variables"
1046INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1047I, [2024-02-29T08:35:59.385555 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1048I, [2024-02-29T08:35:59.386611 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1049I, [2024-02-29T08:35:59.387375 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1050I, [2024-02-29T08:35:59.872385 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1051INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1052INFO: analyzing "public.ci_job_artifacts"
1053INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1054I, [2024-02-29T08:36:01.234519 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1055I, [2024-02-29T08:36:01.236242 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1056I, [2024-02-29T08:36:01.237181 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1057INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1058INFO: analyzing "public.ci_pipeline_variables"
1059INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1060INFO: analyzing "public.p_ci_stages" inheritance tree
1061INFO: analyzing "public.ci_stages"
1062INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1063I, [2024-02-29T08:36:07.130924 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1064I, [2024-02-29T08:36:07.132276 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1065I, [2024-02-29T08:36:07.133252 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1066# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb. It took 3 minutes 1.32 seconds. Expected to take 1 minute 16.09 seconds.
1067# [RSpecRunTime] RSpec elapsed time: 15 minutes 9.33 seconds. Current RSS: ~1316M. load average: 0.98 0.98 1.00 1/271 393
1068# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_prepared_at_merge_requests_spec.rb. Expected to take 1 minute 15.2 seconds.
1069Gitlab::BackgroundMigration::BackfillPreparedAtMergeRequests
1070 updates merge requests with prepared_at nil
1071The application_settings (main) table has 1346 columns.
1072Recreating the database
1073Dropped database 'gitlabhq_test'
1074Dropped database 'gitlabhq_test_ci'
1075Created database 'gitlabhq_test'
1076Created database 'gitlabhq_test_ci'
1077main: == [advisory_lock_connection] object_id: 166919740, pg_backend_pid: 253
1078main: == [advisory_lock_connection] object_id: 166919740, pg_backend_pid: 253
1079ci: == [advisory_lock_connection] object_id: 166986840, pg_backend_pid: 255
1080ci: == [advisory_lock_connection] object_id: 166986840, pg_backend_pid: 255
1081Databases re-creation done in 12.582525977999467
1082# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_prepared_at_merge_requests_spec.rb. It took 1 minute 35.14 seconds. Expected to take 1 minute 15.2 seconds.
1083# [RSpecRunTime] RSpec elapsed time: 16 minutes 44.5 seconds. Current RSS: ~1308M. load average: 0.94 0.98 1.00 1/272 396
1084# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/mark_duplicate_npm_packages_for_destruction_spec.rb. Expected to take 1 minute 1.82 seconds.
1085Gitlab::BackgroundMigration::MarkDuplicateNpmPackagesForDestruction
1086 #perform
1087 marks duplicate npm packages for destruction
1088# [RSpecRunTime] RSpec elapsed time: 17 minutes 39.92 seconds. Current RSS: ~1308M. load average: 1.00 0.99 1.00 1/272 397
1089I, [2024-02-29T08:38:55.429663 #337] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1090INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1091INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1092INFO: "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
1093INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1094INFO: "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
1095INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1096INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1097INFO: "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
1098INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1099INFO: analyzing "public.ci_builds_metadata"
1100INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1101INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1102INFO: "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
1103INFO: analyzing "public.p_ci_builds" inheritance tree
1104INFO: analyzing "public.ci_builds"
1105INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1106INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1107INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1108I, [2024-02-29T08:39:19.907550 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1109INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1110INFO: analyzing "public.ci_pipeline_variables"
1111INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1112I, [2024-02-29T08:39:41.132517 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1113I, [2024-02-29T08:39:41.133927 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1114I, [2024-02-29T08:39:41.134639 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1115I, [2024-02-29T08:39:41.704965 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1116INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1117INFO: analyzing "public.ci_job_artifacts"
1118INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1119I, [2024-02-29T08:39:43.114948 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1120I, [2024-02-29T08:39:43.116292 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1121I, [2024-02-29T08:39:43.117148 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1122INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1123INFO: analyzing "public.ci_pipeline_variables"
1124INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1125INFO: analyzing "public.p_ci_stages" inheritance tree
1126INFO: analyzing "public.ci_stages"
1127INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1128I, [2024-02-29T08:39:49.006274 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1129I, [2024-02-29T08:39:49.007398 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1130I, [2024-02-29T08:39:49.008196 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1131# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/mark_duplicate_npm_packages_for_destruction_spec.rb. It took 2 minutes 6.28 seconds. Expected to take 1 minute 1.82 seconds.
1132# [RSpecRunTime] RSpec elapsed time: 18 minutes 50.82 seconds. Current RSS: ~1299M. load average: 0.97 0.98 1.00 1/272 398
1133# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/remove_invalid_deploy_access_level_groups_spec.rb. Expected to take 57.29 seconds.
1134Gitlab::BackgroundMigration::RemoveInvalidDeployAccessLevelGroups
1135 #perform
1136 backfill tiers for all environments in range
1137# [RSpecRunTime] RSpec elapsed time: 19 minutes 48.48 seconds. Current RSS: ~1295M. load average: 0.99 0.99 1.00 1/272 399
1138I, [2024-02-29T08:41:07.166688 #337] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1139INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1140INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1141INFO: "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
1142INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1143INFO: "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
1144INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1145INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1146INFO: "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
1147INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1148INFO: analyzing "public.ci_builds_metadata"
1149INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1150INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1151INFO: "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
1152INFO: analyzing "public.p_ci_builds" inheritance tree
1153INFO: analyzing "public.ci_builds"
1154INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1155INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1156INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1157I, [2024-02-29T08:41:32.551085 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1158INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1159INFO: analyzing "public.ci_pipeline_variables"
1160INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1161I, [2024-02-29T08:41:54.602222 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1162I, [2024-02-29T08:41:54.603553 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1163I, [2024-02-29T08:41:54.604469 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1164I, [2024-02-29T08:41:55.142815 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1165INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1166INFO: analyzing "public.ci_job_artifacts"
1167INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1168I, [2024-02-29T08:41:56.774553 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1169I, [2024-02-29T08:41:56.775630 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1170I, [2024-02-29T08:41:56.776474 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1171INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1172INFO: analyzing "public.ci_pipeline_variables"
1173INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1174INFO: analyzing "public.p_ci_stages" inheritance tree
1175INFO: analyzing "public.ci_stages"
1176INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1177I, [2024-02-29T08:42:03.092393 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1178I, [2024-02-29T08:42:03.093863 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1179I, [2024-02-29T08:42:03.094753 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1180# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/remove_invalid_deploy_access_level_groups_spec.rb. It took 2 minutes 14.51 seconds. Expected to take 57.29 seconds.
1181# [RSpecRunTime] RSpec elapsed time: 21 minutes 5.37 seconds. Current RSS: ~1292M. load average: 0.92 0.98 0.99 2/271 400
1182# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_missing_ci_cd_settings_spec.rb. Expected to take 44.22 seconds.
1183Gitlab::BackgroundMigration::BackfillMissingCiCdSettings
1184 creates ci_cd_settings for projects without ci_cd_settings
1185 creates ci_cd_settings with default values
1186INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1187INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1188INFO: "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
1189INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1190INFO: "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
1191INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1192INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1193INFO: "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
1194INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1195INFO: analyzing "public.ci_builds_metadata"
1196INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1197INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1198INFO: "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
1199INFO: analyzing "public.p_ci_builds" inheritance tree
1200INFO: analyzing "public.ci_builds"
1201INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1202INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1203INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1204I, [2024-02-29T08:43:22.708589 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1205INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1206INFO: analyzing "public.ci_pipeline_variables"
1207INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1208I, [2024-02-29T08:43:45.438860 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1209I, [2024-02-29T08:43:45.440135 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1210I, [2024-02-29T08:43:45.441059 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1211I, [2024-02-29T08:43:46.109533 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1212INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1213INFO: analyzing "public.ci_job_artifacts"
1214INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1215I, [2024-02-29T08:43:47.734801 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1216I, [2024-02-29T08:43:47.735881 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1217I, [2024-02-29T08:43:47.736705 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1218INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1219INFO: analyzing "public.ci_pipeline_variables"
1220INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1221INFO: analyzing "public.p_ci_stages" inheritance tree
1222INFO: analyzing "public.ci_stages"
1223INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1224I, [2024-02-29T08:43:53.936891 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1225I, [2024-02-29T08:43:53.938112 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1226I, [2024-02-29T08:43:53.939003 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1227# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_missing_ci_cd_settings_spec.rb. It took 1 minute 50.55 seconds. Expected to take 44.22 seconds.
1228# [RSpecRunTime] RSpec elapsed time: 22 minutes 55.96 seconds. Current RSS: ~1287M. load average: 0.99 0.99 1.00 1/271 401
1229# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/convert_credit_card_validation_data_to_hashes_spec.rb. Expected to take 33.7 seconds.
1230Gitlab::BackgroundMigration::ConvertCreditCardValidationDataToHashes
1231 #perform
1232 updates values to hash for records in the specified batch
1233 with NULL columns
1234 does not update values for records in the specified batch
1235# [RSpecRunTime] RSpec elapsed time: 23 minutes 30.61 seconds. Current RSS: ~1315M. load average: 0.88 0.96 0.99 1/271 402
1236INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1237INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1238INFO: "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
1239INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1240INFO: "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
1241INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1242INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1243INFO: "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
1244INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1245INFO: analyzing "public.ci_builds_metadata"
1246INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1247INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1248INFO: "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
1249INFO: analyzing "public.p_ci_builds" inheritance tree
1250INFO: analyzing "public.ci_builds"
1251INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1252INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1253INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1254I, [2024-02-29T08:44:39.400338 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1255INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1256INFO: analyzing "public.ci_pipeline_variables"
1257INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1258I, [2024-02-29T08:45:01.259437 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1259I, [2024-02-29T08:45:01.260711 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1260I, [2024-02-29T08:45:01.261592 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1261I, [2024-02-29T08:45:01.802805 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1262INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1263INFO: analyzing "public.ci_job_artifacts"
1264INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1265I, [2024-02-29T08:45:03.379112 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1266I, [2024-02-29T08:45:03.380390 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1267I, [2024-02-29T08:45:03.381287 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1268INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1269INFO: analyzing "public.ci_pipeline_variables"
1270INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1271INFO: analyzing "public.p_ci_stages" inheritance tree
1272INFO: analyzing "public.ci_stages"
1273INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1274I, [2024-02-29T08:45:09.511024 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1275I, [2024-02-29T08:45:09.512171 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1276I, [2024-02-29T08:45:09.513014 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1277# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/convert_credit_card_validation_data_to_hashes_spec.rb. It took 1 minute 15.48 seconds. Expected to take 33.7 seconds.
1278# [RSpecRunTime] RSpec elapsed time: 24 minutes 11.47 seconds. Current RSS: ~1288M. load average: 0.88 0.95 0.99 1/270 403
1279# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_finding_id_in_vulnerabilities_spec.rb. Expected to take 29.89 seconds.
1280Gitlab::BackgroundMigration::BackfillFindingIdInVulnerabilities
1281 #perform
1282 backfills finding_id column in the vulnerabilities table
1283 does not affect rows with finding_id populated
1284# [RSpecRunTime] RSpec elapsed time: 24 minutes 45.24 seconds. Current RSS: ~1289M. load average: 0.93 0.95 0.99 1/270 404
1285I, [2024-02-29T08:45:51.326085 #337] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1286INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1287INFO: analyzing "public.ci_pipeline_variables"
1288INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1289I, [2024-02-29T08:46:13.776952 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1290I, [2024-02-29T08:46:13.778304 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1291I, [2024-02-29T08:46:13.779140 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1292I, [2024-02-29T08:46:14.303399 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1293INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1294INFO: analyzing "public.ci_job_artifacts"
1295INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1296I, [2024-02-29T08:46:15.878223 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1297I, [2024-02-29T08:46:15.879516 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1298I, [2024-02-29T08:46:15.880649 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1299INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1300INFO: analyzing "public.ci_pipeline_variables"
1301INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1302INFO: analyzing "public.p_ci_stages" inheritance tree
1303INFO: analyzing "public.ci_stages"
1304INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1305I, [2024-02-29T08:46:22.142201 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1306I, [2024-02-29T08:46:22.143441 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1307I, [2024-02-29T08:46:22.144338 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1308# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_finding_id_in_vulnerabilities_spec.rb. It took 1 minute 12.56 seconds. Expected to take 29.89 seconds.
1309# [RSpecRunTime] RSpec elapsed time: 25 minutes 24.07 seconds. Current RSS: ~1279M. load average: 0.82 0.93 0.98 1/270 405
1310# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb. Expected to take 23.24 seconds.
1311Gitlab::BackgroundMigration::BackfillPackagesTagsProjectId
1312 backfills the missing project_id for the batch
1313INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1314INFO: analyzing "public.ci_pipeline_variables"
1315INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1316I, [2024-02-29T08:47:08.752932 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1317I, [2024-02-29T08:47:08.754454 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1318I, [2024-02-29T08:47:08.755425 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1319I, [2024-02-29T08:47:09.277426 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1320INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1321INFO: analyzing "public.ci_job_artifacts"
1322INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1323I, [2024-02-29T08:47:10.851217 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1324I, [2024-02-29T08:47:10.852987 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1325I, [2024-02-29T08:47:10.853960 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1326INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1327INFO: analyzing "public.ci_pipeline_variables"
1328INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1329INFO: analyzing "public.p_ci_stages" inheritance tree
1330INFO: analyzing "public.ci_stages"
1331INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1332I, [2024-02-29T08:47:17.246164 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1333I, [2024-02-29T08:47:17.247374 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1334I, [2024-02-29T08:47:17.248268 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1335# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb. It took 55.28 seconds. Expected to take 23.24 seconds.
1336# [RSpecRunTime] RSpec elapsed time: 26 minutes 19.38 seconds. Current RSS: ~1276M. load average: 1.01 0.96 0.99 1/271 406
1337# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_merge_request_diffs_project_id_spec.rb. Expected to take 20.52 seconds.
1338Gitlab::BackgroundMigration::BackfillMergeRequestDiffsProjectId
1339 backfills the missing project_id for the batch
1340INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1341INFO: analyzing "public.ci_pipeline_variables"
1342INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1343I, [2024-02-29T08:48:02.299856 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1344I, [2024-02-29T08:48:02.301129 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1345I, [2024-02-29T08:48:02.301954 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1346I, [2024-02-29T08:48:02.830377 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1347INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1348INFO: analyzing "public.ci_job_artifacts"
1349INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1350I, [2024-02-29T08:48:04.502631 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1351I, [2024-02-29T08:48:04.504247 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1352I, [2024-02-29T08:48:04.505224 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1353INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1354INFO: analyzing "public.ci_pipeline_variables"
1355INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1356INFO: analyzing "public.p_ci_stages" inheritance tree
1357INFO: analyzing "public.ci_stages"
1358INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1359I, [2024-02-29T08:48:10.943510 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1360I, [2024-02-29T08:48:10.944632 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1361I, [2024-02-29T08:48:10.945445 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1362# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_merge_request_diffs_project_id_spec.rb. It took 53.62 seconds. Expected to take 20.52 seconds.
1363# [RSpecRunTime] RSpec elapsed time: 27 minutes 13.04 seconds. Current RSS: ~1299M. load average: 1.00 0.97 1.00 1/271 407
1364# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/fix_incoherent_packages_size_on_project_statistics_spec.rb. Expected to take 14.13 seconds.
1365Gitlab::BackgroundMigration::FixIncoherentPackagesSizeOnProjectStatistics
1366 #perform
1367 with incoherent packages_size
1368 behaves like enqueuing a buffered updates
1369 fixes the packages_size stat
1370# [RSpecRunTime] RSpec elapsed time: 27 minutes 16.83 seconds. Current RSS: ~1302M. load average: 0.92 0.95 0.99 3/271 408
1371 with updates waiting on redis
1372 behaves like enqueuing a buffered updates
1373 fixes the packages_size stat
1374# [RSpecRunTime] RSpec elapsed time: 27 minutes 20.18 seconds. Current RSS: ~1333M. load average: 0.93 0.95 0.99 1/271 409
1375 with no incoherent packages_size
1376 behaves like not updating project statistics
1377 does not change them
1378# [RSpecRunTime] RSpec elapsed time: 27 minutes 23.55 seconds. Current RSS: ~1331M. load average: 0.93 0.95 0.99 1/271 410
1379 #filter_batch
1380 selects all package size statistics
1381# [RSpecRunTime] RSpec elapsed time: 27 minutes 26.77 seconds. Current RSS: ~1330M. load average: 0.94 0.96 1.00 1/271 411
1382# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/fix_incoherent_packages_size_on_project_statistics_spec.rb. It took 20.45 seconds. Expected to take 14.13 seconds.
1383# [RSpecRunTime] RSpec elapsed time: 27 minutes 33.53 seconds. Current RSS: ~1290M. load average: 0.94 0.96 1.00 1/271 412
1384# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_config_spec.rb. Expected to take 12.19 seconds.
1385Gitlab::BackgroundMigration::BackfillPartitionIdCiPipelineConfig
1386 #perform
1387 when second partition does not exist
1388 does not execute the migration
1389# [RSpecRunTime] RSpec elapsed time: 27 minutes 43.59 seconds. Current RSS: ~1294M. load average: 0.95 0.96 1.00 1/271 413
1390 when second partition exists
1391 fixes invalid records in the wrong the partition
1392# [RSpecRunTime] RSpec elapsed time: 27 minutes 46.56 seconds. Current RSS: ~1314M. load average: 0.95 0.96 1.00 1/271 414
1393I, [2024-02-29T08:48:52.335576 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1394INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1395INFO: analyzing "public.ci_job_artifacts"
1396INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1397I, [2024-02-29T08:48:53.912270 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1398I, [2024-02-29T08:48:53.913396 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1399I, [2024-02-29T08:48:53.914190 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1400INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1401INFO: analyzing "public.ci_pipeline_variables"
1402INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1403INFO: analyzing "public.p_ci_stages" inheritance tree
1404INFO: analyzing "public.ci_stages"
1405INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1406I, [2024-02-29T08:49:00.008954 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1407I, [2024-02-29T08:49:00.010431 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1408I, [2024-02-29T08:49:00.011339 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1409# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_config_spec.rb. It took 28.54 seconds. Expected to take 12.19 seconds.
1410# [RSpecRunTime] RSpec elapsed time: 28 minutes 2.1 seconds. Current RSS: ~1284M. load average: 0.97 0.96 1.00 1/271 415
1411# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_default_organization_owners_spec.rb. Expected to take 11.38 seconds.
1412Gitlab::BackgroundMigration::BackfillDefaultOrganizationOwners
1413 #perform
1414 runs without error for no-op
1415# [RSpecRunTime] RSpec elapsed time: 28 minutes 13.87 seconds. Current RSS: ~1296M. load average: 0.97 0.96 1.00 1/271 416
1416INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1417INFO: analyzing "public.ci_pipeline_variables"
1418INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1419I, [2024-02-29T08:49:22.274902 #337] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1420I, [2024-02-29T08:49:22.276265 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1421I, [2024-02-29T08:49:22.277198 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1422I, [2024-02-29T08:49:22.829615 #337] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1423INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1424INFO: analyzing "public.ci_job_artifacts"
1425INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1426I, [2024-02-29T08:49:24.439771 #337] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1427I, [2024-02-29T08:49:24.440909 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1428I, [2024-02-29T08:49:24.441769 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1429INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1430INFO: analyzing "public.ci_pipeline_variables"
1431INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1432INFO: analyzing "public.p_ci_stages" inheritance tree
1433INFO: analyzing "public.ci_stages"
1434INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1435I, [2024-02-29T08:49:30.533345 #337] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1436I, [2024-02-29T08:49:30.534389 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1437I, [2024-02-29T08:49:30.535155 #337] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1438# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_default_organization_owners_spec.rb. It took 30.31 seconds. Expected to take 11.38 seconds.
1439# [RSpecRunTime] RSpec elapsed time: 28 minutes 32.45 seconds. Current RSS: ~1281M. load average: 0.98 0.97 1.00 1/271 417
1440# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. Expected to take 10.2 seconds.
1441Gitlab::BackgroundMigration::SetCorrectVulnerabilityState
1442 #filter_batch
1443 filters out vulnerabilities where dismissed_at is null
1444# [RSpecRunTime] RSpec elapsed time: 28 minutes 35.75 seconds. Current RSS: ~1286M. load average: 0.98 0.97 1.00 1/271 418
1445 #perform
1446 changes vulnerability state to `dismissed` when dismissed_at is not nil
1447 does not change the state when dismissed_at is nil
1448# [RSpecRunTime] RSpec elapsed time: 28 minutes 42.05 seconds. Current RSS: ~1305M. load average: 0.98 0.97 1.00 1/271 419
1449# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. It took 16.2 seconds. Expected to take 10.2 seconds.
1450# [RSpecRunTime] RSpec elapsed time: 28 minutes 48.68 seconds. Current RSS: ~1296M. load average: 0.99 0.97 1.00 1/271 420
1451# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. Expected to take 7.35 seconds.
1452Gitlab::BackgroundMigration::BackfillHasRemediationsOfVulnerabilityReads
1453 does not modify has_remediations of vulnerabilities which do not have remediations
1454 when finding_remediation record exists
1455 updates vulnerability_reads records which has remediations
1456# [RSpecRunTime] RSpec elapsed time: 28 minutes 55.16 seconds. Current RSS: ~1297M. load average: 0.99 0.97 1.00 1/271 421
1457# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. It took 13.09 seconds. Expected to take 7.35 seconds.
1458# [RSpecRunTime] RSpec elapsed time: 29 minutes 1.81 seconds. Current RSS: ~1280M. load average: 0.91 0.96 0.99 1/271 422
1459# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/disable_legacy_open_source_licence_for_recent_public_projects_spec.rb. Expected to take 3.7 seconds.
1460Gitlab::BackgroundMigration::DisableLegacyOpenSourceLicenceForRecentPublicProjects
1461 sets `legacy_open_source_license_available` attribute to false for public projects created after threshold time
1462# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/disable_legacy_open_source_licence_for_recent_public_projects_spec.rb. It took 9.74 seconds. Expected to take 3.7 seconds.
1463# [RSpecRunTime] RSpec elapsed time: 29 minutes 11.59 seconds. Current RSS: ~1283M. load average: 0.92 0.96 1.00 1/272 423
1464# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb. Expected to take 3.64 seconds.
1465Gitlab::BackgroundMigration::DisableLegacyOpenSourceLicenseForInactivePublicProjects
1466 sets `legacy_open_source_license_available` attribute to false for inactive, public projects
1467# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb. It took 9.65 seconds. Expected to take 3.64 seconds.
1468# [RSpecRunTime] RSpec elapsed time: 29 minutes 21.27 seconds. Current RSS: ~1284M. load average: 0.94 0.96 1.00 1/272 424
1469# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_orphans_approval_project_rules_spec.rb. Expected to take 3.53 seconds.
1470Gitlab::BackgroundMigration::DeleteOrphansApprovalProjectRules
1471 #perform
1472 delete only approval rules without association with the security project and report_type equals to 4
1473# [RSpecRunTime] RSpec elapsed time: 29 minutes 24.49 seconds. Current RSS: ~1279M. load average: 0.95 0.96 1.00 1/272 425
1474# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_orphans_approval_project_rules_spec.rb. It took 9.74 seconds. Expected to take 3.53 seconds.
1475# [RSpecRunTime] RSpec elapsed time: 29 minutes 31.04 seconds. Current RSS: ~1275M. load average: 0.95 0.96 1.00 1/272 426
1476# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb. Expected to take 3.46 seconds.
1477Gitlab::BackgroundMigration::Mailers::UnconfirmMailer
1478 contains abuse report url
1479# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb. It took 9.49 seconds. Expected to take 3.46 seconds.
1480# [RSpecRunTime] RSpec elapsed time: 29 minutes 40.57 seconds. Current RSS: ~1273M. load average: 0.96 0.96 1.00 1/272 427
1481# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/dismissed_vulnerabilities_strategy_spec.rb. Expected to take 3.38 seconds.
1482Gitlab::BackgroundMigration::BatchingStrategies::DismissedVulnerabilitiesStrategy#next_batch
1483 is expected to be < Gitlab::BackgroundMigration::BatchingStrategies::PrimaryKeyBatchingStrategy
1484# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/dismissed_vulnerabilities_strategy_spec.rb. It took 9.32 seconds. Expected to take 3.38 seconds.
1485# [RSpecRunTime] RSpec elapsed time: 29 minutes 49.93 seconds. Current RSS: ~1266M. load average: 0.97 0.96 1.00 1/272 428
1486# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration_spec.rb. Expected to take 3.15 seconds.
1487Gitlab::BackgroundMigration
1488 .queue
1489 returns background migration worker queue
1490 .steal
1491 when the queue contains unprocessed jobs
1492 uses the coordinator to steal jobs
1493 when a custom predicate is given
1494 steals jobs that match the predicate
1495 does not steal jobs that do not match the predicate
1496 when retry_dead_jobs is true
1497 steals from the dead and retry queue
1498 .perform
1499 uses the coordinator to perform a background migration
1500 .exists?
1501 uses the coordinator to find if a job exists
1502 uses the coordinator to find a job does not exist
1503 .remaining
1504 uses the coordinator to find the number of remaining jobs
1505# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration_spec.rb. It took 1.18 seconds. Expected to take 3.15 seconds.
1506auto_explain log contains 968 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-3-5.337.main.ndjson.gz
1507took 17.2988196
1508auto_explain log contains 968 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-3-5.337.ci.ndjson.gz
1509took 17.131509161
1510[TEST PROF INFO] EventProf results for sql.active_record
1511Total time: 21:46.242 of 29:48.110 (73.05%)
1512Total events: 773182
1513Top 5 slowest suites (by time):
1514Gitlab::Backg...erabilityReads (./spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb:5) – 02:18.991 (68172 / 1) of 03:01.357 (76.64%)
1515Gitlab::Backg...nternalOnNotes (./spec/lib/gitlab/background_migration/backfill_internal_on_notes_spec.rb:5) – 02:18.343 (69336 / 1) of 03:01.207 (76.35%)
1516Gitlab::Backg...dsClusterAgent (./spec/lib/gitlab/background_migration/backfill_vulnerability_reads_cluster_agent_spec.rb:5) – 02:14.260 (72505 / 3) of 02:59.276 (74.89%)
1517Gitlab::Backg...rkStorageSizes (./spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb:5) – 02:12.771 (88786 / 17) of 03:10.745 (69.61%)
1518Gitlab::Backg...slVerification (./spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb:5) – 02:09.639 (72653 / 3) of 02:53.752 (74.61%)
1519Knapsack report was generated. Preview:
1520{
1521 "spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb": 116.74141702399902,
1522 "spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb": 82.57630453499951,
1523 "spec/lib/gitlab/background_migration/backfill_vulnerability_reads_cluster_agent_spec.rb": 82.90185544800079,
1524 "spec/lib/gitlab/background_migration/backfill_internal_on_notes_spec.rb": 81.59289765200083,
1525 "spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb": 80.6096537100002,
1526 "spec/lib/gitlab/background_migration/backfill_prepared_at_merge_requests_spec.rb": 82.42477779799992,
1527 "spec/lib/gitlab/background_migration/mark_duplicate_npm_packages_for_destruction_spec.rb": 55.516099713000585,
1528 "spec/lib/gitlab/background_migration/remove_invalid_deploy_access_level_groups_spec.rb": 57.7502216440007,
1529 "spec/lib/gitlab/background_migration/backfill_missing_ci_cd_settings_spec.rb": 49.63420355800008,
1530 "spec/lib/gitlab/background_migration/convert_credit_card_validation_data_to_hashes_spec.rb": 34.76006649899864,
1531 "spec/lib/gitlab/background_migration/backfill_finding_id_in_vulnerabilities_spec.rb": 33.85427088899996,
1532 "spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb": 24.058874438000203,
1533 "spec/lib/gitlab/background_migration/backfill_merge_request_diffs_project_id_spec.rb": 24.158971700999246,
1534 "spec/lib/gitlab/background_migration/fix_incoherent_packages_size_on_project_statistics_spec.rb": 13.80839664800078,
1535 "spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_config_spec.rb": 13.116210153000793,
1536 "spec/lib/gitlab/background_migration/backfill_default_organization_owners_spec.rb": 11.872643403999973,
1537 "spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb": 9.686385347000396,
1538 "spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb": 6.570900900998822,
1539 "spec/lib/gitlab/background_migration/disable_legacy_open_source_licence_for_recent_public_projects_spec.rb": 3.441008535999572,
1540 "spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb": 3.2861422160003713,
1541 "spec/lib/gitlab/background_migration/delete_orphans_approval_project_rules_spec.rb": 3.3053551250013697,
1542 "spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb": 3.2185422590009694,
1543 "spec/lib/gitlab/background_migration/batching_strategies/dismissed_vulnerabilities_strategy_spec.rb": 3.0881188370003656,
1544 "spec/lib/gitlab/background_migration_spec.rb": 1.1814627330004441
1545}
1546Knapsack global time execution for tests: 14m 39s
1547Finished in 30 minutes 26 seconds (files took 45.49 seconds to load)
154862 examples, 0 failures
1549Randomized with seed 8810
1550[TEST PROF INFO] Time spent in factories: 00:00.319 (0.02% of total time)
1551RSpec exited with 0.
1552No examples to retry, congrats!
1553 Running after_script 00:05
1554Running after script...
1555$ echo -e "\e[0Ksection_start:`date +%s`:report_results_section[collapsed=true]\r\e[0KReport results"
1556 Report results 00:03
1566$ tooling/bin/push_job_metrics || true
1567[job-metrics] Pushing job metrics file for the CI/CD job.
1568[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
1569 Saving cache for successful job 00:01
1570Not uploading cache ruby-gems-debian-bookworm-ruby-3.1-16 due to policy
1571 Uploading artifacts for successful job 00:04
1572Uploading artifacts...
1573auto_explain/: found 3 matching artifact files and directories
1574coverage/: found 5 matching artifact files and directories
1575crystalball/: found 2 matching artifact files and directories
1576WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1577knapsack/: found 4 matching artifact files and directories
1578rspec/: found 16 matching artifact files and directories
1579WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1580log/*.log: found 13 matching artifact files and directories
1581WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6285087965/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
1582WARNING: Retrying... context=artifacts-uploader error=request redirected
1583Uploading artifacts as "archive" to coordinator... 201 Created id=6285087965 responseStatus=201 Created token=glcbt-65
1584Uploading artifacts...
1585rspec/rspec-*.xml: found 1 matching artifact files and directories
1586WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6285087965/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
1587WARNING: Retrying... context=artifacts-uploader error=request redirected
1588Uploading artifacts as "junit" to coordinator... 201 Created id=6285087965 responseStatus=201 Created token=glcbt-65
1589 Cleaning up project directory and file based variables 00:00
1590Job succeeded