Skip to content
Snippets Groups Projects

rspec background_migration pg14 5/5

Passed Started by
🤖 GitLab Bot 🤖
@gitlab-bot
1Running with gitlab-runner 16.11.0~pre.21.gaa21be2d (aa21be2d)
2 on blue-3.private.runners-manager.gitlab.com/gitlab.com/gitlab-org 6io2xoDD, system ID: s_8f94f7760223
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:08
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:57763d55554967cf0a9b05258512282482807d361c68b10fd9599ac9732bfb04 for redis:6.2-alpine with digest redis@sha256:3fcb624d83a9c478357f16dc173c58ded325ccc5fd2a4375f3916c04cc579f70 ...
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:4d97a6e6b48a500f28599f739761ccb23dc0b775b23fe71357e1f48df9074e52 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:56b23cca550b55e86db3c2471a1223d2b3a97ddff9a4bf6bd246dcef3ec64284 ...
24 Preparing environment 00:01
25Running on runner-6io2xodd-project-278964-concurrent-0 via runner-6io2xodd-private-1712134860-901743f1...
26 Getting source from Git repository 00:01
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
30 Restoring cache 00:18
31Checking cache for ruby-gems-debian-bookworm-ruby-3.1-17...
32Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/278964/ruby-gems-debian-bookworm-ruby-3.1-17
33Successfully extracted cache
34 Downloading artifacts 00:37
35Downloading artifacts for clone-gitlab-repo (6536638914)...
36Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6536638914 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 (6536638957)...
40Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6536638957 responseStatus=200 OK token=glcbt-65
41Downloading artifacts for detect-tests (6536638978)...
42Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6536638978 responseStatus=200 OK token=glcbt-65
43Downloading artifacts for retrieve-tests-metadata (6536638983)...
44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6536638983 responseStatus=200 OK token=glcbt-65
45Downloading artifacts for setup-test-env (6536638964)...
46Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6536638964 responseStatus=200 OK token=glcbt-65
47 Executing "step_script" stage of the job script
48Using docker image sha256:4d97a6e6b48a500f28599f739761ccb23dc0b775b23fe71357e1f48df9074e52 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:56b23cca550b55e86db3c2471a1223d2b3a97ddff9a4bf6bd246dcef3ec64284 ...
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:19
731Using decomposed database config (config/database.yml.decomposed-postgresql)
732Geo DB won't be set up.
733Embedding DB won't be set up.
734 Setting up DBs 01:02
745$ source ./scripts/rspec_helpers.sh
746$ run_timed_command "gem install knapsack --no-document"
747$ gem install knapsack --no-document
748Successfully installed knapsack-4.0.0
7491 gem installed
750==> 'gem install knapsack --no-document' succeeded in 0 seconds.
751$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
752 Spawning Gitaly 00:04
756$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
757$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
758$ tooling/bin/create_job_metrics_file || true
759[job-metrics] Creating the job metrics file for the CI/CD job.
760$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
761 RSpec 25:46
762[10:33:14] Starting rspec_parallelized_job
763RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
764KNAPSACK_GENERATE_REPORT: true
765FLAKY_RSPEC_GENERATE_REPORT: true
766KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
767KNAPSACK_LOG_LEVEL: debug
768KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_5_5_278964_report.json
769FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
770FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_5_5_278964_report.json
771NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_5_5_278964_report.json
772RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-6536639210.txt
773CRYSTALBALL:
774RSPEC_TESTS_MAPPING_ENABLED:
775RSPEC_TESTS_FILTER_FILE:
776Shell set options (set -o) enabled:
777braceexpand on
778hashall on
779interactive-comments on
780pipefail on
781Knapsack report generator started!
782Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
783# [RSpecRunTime] Starting RSpec timer...
784[TEST PROF INFO] EventProf enabled (sql.active_record)
785unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
786unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
787Test environment set up in 1.26028181 seconds
788# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb. Expected to take 1 minute 20.11 seconds.
789Gitlab::BackgroundMigration::BackfillResourceLinkEvents
790 #perform
791 does nothing when relevant notes do not exist
792 for 'relate_to_parent' system_note_metadata record
793 when issue_type_name is `issue`
794 behaves like a resource_link_event is correctly created
795 correctly backfills a resource_link_event record
796 when issue_type_name is not `issue`
797 behaves like a resource_link_event is correctly created
798 correctly backfills a resource_link_event record
799# [RSpecRunTime] RSpec elapsed time: 1 minute 10.0 seconds. Current RSS: ~1396M. load average: 0.96 1.06 1.20 1/271 386
800 for 'unrelate_to_parent' system_note_metadata record
801 when issue_type_name is `issue`
802 behaves like a resource_link_event is correctly created
803 correctly backfills a resource_link_event record
804# [RSpecRunTime] RSpec elapsed time: 1 minute 13.81 seconds. Current RSS: ~1389M. load average: 1.04 1.08 1.20 1/271 387
805 when issue_type_name is not `issue`
806 behaves like a resource_link_event is correctly created
807 correctly backfills a resource_link_event record
808# [RSpecRunTime] RSpec elapsed time: 1 minute 18.77 seconds. Current RSS: ~1384M. load average: 1.04 1.08 1.20 1/271 388
809 when a backfilled note exists
810 correctly backfills the system notes without those that have been backfilled
811# [RSpecRunTime] RSpec elapsed time: 1 minute 22.46 seconds. Current RSS: ~1391M. load average: 1.12 1.09 1.21 1/271 389
812 with unexpected note content
813 when note iid is prefixed
814 does not create resource_link_events record
815# [RSpecRunTime] RSpec elapsed time: 1 minute 26.07 seconds. Current RSS: ~1394M. load average: 1.12 1.09 1.21 1/271 390
816INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
817INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
818INFO: "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
819INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
820INFO: "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
821INFO: analyzing "public.p_ci_job_annotations" inheritance tree
822INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
823INFO: "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
824INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
825INFO: "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
826INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
827INFO: analyzing "public.ci_builds_metadata"
828INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
829INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
830INFO: "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
831INFO: analyzing "public.p_ci_builds" inheritance tree
832INFO: analyzing "public.ci_builds"
833INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
834INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
835INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
836I, [2024-04-03T10:36:00.160476 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
837INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
838INFO: analyzing "public.ci_pipeline_variables"
839INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
840I, [2024-04-03T10:36:22.785833 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
841I, [2024-04-03T10:36:22.787181 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
842I, [2024-04-03T10:36:22.788054 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
843I, [2024-04-03T10:36:23.357278 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
844INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
845INFO: analyzing "public.ci_job_artifacts"
846INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
847I, [2024-04-03T10:36:24.956502 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
848I, [2024-04-03T10:36:24.957903 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
849I, [2024-04-03T10:36:24.958830 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
850INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
851INFO: analyzing "public.ci_pipeline_variables"
852INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
853INFO: analyzing "public.p_ci_stages" inheritance tree
854INFO: analyzing "public.ci_stages"
855INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
856I, [2024-04-03T10:36:31.835810 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
857I, [2024-04-03T10:36:31.837223 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
858I, [2024-04-03T10:36:31.838200 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
859I, [2024-04-03T10:36:33.653305 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
860# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb. It took 2 minutes 29.74 seconds. Expected to take 1 minute 20.11 seconds.
861# [RSpecRunTime] RSpec elapsed time: 2 minutes 33.72 seconds. Current RSS: ~1379M. load average: 1.00 1.07 1.19 1/267 392
862# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batched_migration_job_spec.rb. Expected to take 1 minute 15.1 seconds.
863Gitlab::BackgroundMigration::BatchedMigrationJob
864 .generic_instance
865 defines generic instance with only some of the attributes set
866# [RSpecRunTime] RSpec elapsed time: 2 minutes 37.89 seconds. Current RSS: ~1376M. load average: 1.00 1.07 1.19 1/267 393
867 .job_arguments
868 defines methods
869 when no job arguments are defined
870 job_arguments_count is 0
871# [RSpecRunTime] RSpec elapsed time: 2 minutes 44.97 seconds. Current RSS: ~1374M. load average: 1.00 1.07 1.18 1/267 394
872 .operation_name
873 defines method
874 when `operation_name` is not defined
875 raises an exception
876# [RSpecRunTime] RSpec elapsed time: 2 minutes 52.28 seconds. Current RSS: ~1377M. load average: 1.00 1.06 1.18 1/266 395
877 .scope_to
878 when additional scoping is defined
879 applies additional scope to the provided relation
880# [RSpecRunTime] RSpec elapsed time: 2 minutes 55.96 seconds. Current RSS: ~1378M. load average: 1.00 1.06 1.18 1/266 396
881 when there is no additional scoping defined
882 returns provided relation as is
883# [RSpecRunTime] RSpec elapsed time: 2 minutes 59.54 seconds. Current RSS: ~1379M. load average: 0.92 1.04 1.17 1/266 397
884 .feature_category
885 when jobs does not have feature_category attribute set
886 returns :database as default
887# [RSpecRunTime] RSpec elapsed time: 3 minutes 3.33 seconds. Current RSS: ~1379M. load average: 0.93 1.04 1.17 1/266 398
888 when jobs have feature_category attribute set
889 returns the provided value
890# [RSpecRunTime] RSpec elapsed time: 3 minutes 6.88 seconds. Current RSS: ~1378M. load average: 0.93 1.04 1.17 1/266 399
891 descendants
892 have the same method signature for #perform
893 do not use .batching_scope
894# [RSpecRunTime] RSpec elapsed time: 3 minutes 13.92 seconds. Current RSS: ~1378M. load average: 0.94 1.04 1.17 1/266 400
895 #perform
896 raises an error if not overridden
897 when the subclass uses sub-batching
898 calls the operation for each sub-batch
899 instruments the batch operation
900 pauses after each sub-batch
901 with additional scoping
902 respects #filter_batch
903# [RSpecRunTime] RSpec elapsed time: 3 minutes 31.57 seconds. Current RSS: ~1376M. load average: 1.03 1.06 1.17 1/266 401
904 when using a sub batch exception for timeouts
905 raises the expected error type
906# [RSpecRunTime] RSpec elapsed time: 3 minutes 35.19 seconds. Current RSS: ~1377M. load average: 1.03 1.06 1.17 1/266 402
907 when batching_arguments are given
908 forwards them for batching
909# [RSpecRunTime] RSpec elapsed time: 3 minutes 38.87 seconds. Current RSS: ~1377M. load average: 1.03 1.05 1.17 1/266 403
910 when the subclass uses distinct each batch
911 calls the operation for each distinct batch
912 stores the affected rows
913 when used in combination with scope_to
914 raises an error
915# [RSpecRunTime] RSpec elapsed time: 3 minutes 49.54 seconds. Current RSS: ~1376M. load average: 0.95 1.04 1.17 1/266 404
916# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batched_migration_job_spec.rb. It took 1 minute 23.47 seconds. Expected to take 1 minute 15.1 seconds.
917# [RSpecRunTime] RSpec elapsed time: 3 minutes 57.24 seconds. Current RSS: ~1358M. load average: 0.96 1.03 1.16 1/267 405
918# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_wiki_repositories_spec.rb. Expected to take 58.33 seconds.
919Gitlab::BackgroundMigration::BackfillProjectWikiRepositories
920 #perform
921 creates project_wiki_repositories entries for all projects in range
922 does nothing if project_id already exist in project_wiki_repositories
923# [RSpecRunTime] RSpec elapsed time: 4 minutes 56.52 seconds. Current RSS: ~1384M. load average: 0.94 1.01 1.15 1/267 406
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 "gitlab_partitions_dynamic.ci_job_annotations_101"
933INFO: "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
934INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
935INFO: analyzing "public.ci_builds_metadata"
936INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
937INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
938INFO: "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
939INFO: analyzing "public.p_ci_builds" inheritance tree
940INFO: analyzing "public.ci_builds"
941INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
942INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
943INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
944I, [2024-04-03T10:39:30.145436 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
945INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
946INFO: analyzing "public.ci_pipeline_variables"
947INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
948I, [2024-04-03T10:39:53.427514 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
949I, [2024-04-03T10:39:53.429221 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
950I, [2024-04-03T10:39:53.430533 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
951I, [2024-04-03T10:39:54.045845 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
952INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
953INFO: analyzing "public.ci_job_artifacts"
954INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
955I, [2024-04-03T10:39:55.571936 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
956I, [2024-04-03T10:39:55.573226 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
957I, [2024-04-03T10:39:55.574087 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
958INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
959INFO: analyzing "public.ci_pipeline_variables"
960INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
961INFO: analyzing "public.p_ci_stages" inheritance tree
962INFO: analyzing "public.ci_stages"
963INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
964I, [2024-04-03T10:40:02.494046 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
965I, [2024-04-03T10:40:02.495251 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
966I, [2024-04-03T10:40:02.496056 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
967I, [2024-04-03T10:40:04.387726 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
968# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_wiki_repositories_spec.rb. It took 2 minutes 7.14 seconds. Expected to take 58.33 seconds.
969# [RSpecRunTime] RSpec elapsed time: 6 minutes 4.42 seconds. Current RSS: ~1371M. load average: 1.01 1.02 1.14 1/268 408
970# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. Expected to take 56.32 seconds.
971Gitlab::BackgroundMigration::DestroyInvalidMembers
972 tracks timings of queries
973 removes invalid memberships but keeps valid ones
974 logs IDs of deleted records
975INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
976INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
977INFO: "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
978INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
979INFO: "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
980INFO: analyzing "public.p_ci_job_annotations" inheritance tree
981INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
982INFO: "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
983INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
984INFO: "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
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
993INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
994INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
995I, [2024-04-03T10:41:39.075320 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
996INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
997INFO: analyzing "public.ci_pipeline_variables"
998INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
999I, [2024-04-03T10:42:02.170191 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1000I, [2024-04-03T10:42:02.171332 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1001I, [2024-04-03T10:42:02.172220 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1002I, [2024-04-03T10:42:02.712404 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1003INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1004INFO: analyzing "public.ci_job_artifacts"
1005INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1006I, [2024-04-03T10:42:04.152686 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1007I, [2024-04-03T10:42:04.154732 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1008I, [2024-04-03T10:42:04.155706 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1009INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1010INFO: analyzing "public.ci_pipeline_variables"
1011INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1012INFO: analyzing "public.p_ci_stages" inheritance tree
1013INFO: analyzing "public.ci_stages"
1014INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1015I, [2024-04-03T10:42:11.161401 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1016I, [2024-04-03T10:42:11.162731 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1017I, [2024-04-03T10:42:11.163643 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1018I, [2024-04-03T10:42:12.988158 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1019# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. It took 2 minutes 8.3 seconds. Expected to take 56.32 seconds.
1020# [RSpecRunTime] RSpec elapsed time: 8 minutes 12.76 seconds. Current RSS: ~1356M. load average: 1.00 1.01 1.12 1/268 409
1021# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/set_legacy_open_source_license_available_for_non_public_projects_spec.rb. Expected to take 54.08 seconds.
1022Gitlab::BackgroundMigration::SetLegacyOpenSourceLicenseAvailableForNonPublicProjects
1023 sets `legacy_open_source_license_available` attribute to false for non-public projects
1024INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1025INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1026INFO: "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
1027INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1028INFO: "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
1029INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1030INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1031INFO: "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
1032INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
1033INFO: "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
1034INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1035INFO: analyzing "public.ci_builds_metadata"
1036INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1037INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1038INFO: "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
1039INFO: analyzing "public.p_ci_builds" inheritance tree
1040INFO: analyzing "public.ci_builds"
1041INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1042INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1043INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1044I, [2024-04-03T10:43:41.201506 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1045INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1046INFO: analyzing "public.ci_pipeline_variables"
1047INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1048I, [2024-04-03T10:44:04.991619 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1049I, [2024-04-03T10:44:04.993287 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1050I, [2024-04-03T10:44:04.994120 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1051I, [2024-04-03T10:44:05.554202 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1052INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1053INFO: analyzing "public.ci_job_artifacts"
1054INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1055I, [2024-04-03T10:44:07.022939 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1056I, [2024-04-03T10:44:07.024586 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1057I, [2024-04-03T10:44:07.025429 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1058INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1059INFO: analyzing "public.ci_pipeline_variables"
1060INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1061INFO: analyzing "public.p_ci_stages" inheritance tree
1062INFO: analyzing "public.ci_stages"
1063INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1064I, [2024-04-03T10:44:14.242111 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1065I, [2024-04-03T10:44:14.243298 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1066I, [2024-04-03T10:44:14.244162 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1067I, [2024-04-03T10:44:15.963866 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1068# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/set_legacy_open_source_license_available_for_non_public_projects_spec.rb. It took 2 minutes 3.02 seconds. Expected to take 54.08 seconds.
1069# [RSpecRunTime] RSpec elapsed time: 10 minutes 15.83 seconds. Current RSS: ~1355M. load average: 1.00 1.00 1.09 1/268 410
1070# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb. Expected to take 53.19 seconds.
1071Gitlab::BackgroundMigration::BackfillDesignManagementRepositories
1072 #perform
1073 creates design_management_repositories entries for all projects in range
1074 when project_id already exists in design_management_repositories
1075 doesn't duplicate project_id
1076# [RSpecRunTime] RSpec elapsed time: 11 minutes 15.21 seconds. Current RSS: ~1375M. load average: 1.10 1.03 1.09 1/268 411
1077INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1078INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1079INFO: "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
1080INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1081INFO: "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
1082INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1083INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1084INFO: "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
1085INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
1086INFO: "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
1087INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1088INFO: analyzing "public.ci_builds_metadata"
1089INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1090INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1091INFO: "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
1092INFO: analyzing "public.p_ci_builds" inheritance tree
1093INFO: analyzing "public.ci_builds"
1094INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1095INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1096INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1097I, [2024-04-03T10:45:49.779077 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1098INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1099INFO: analyzing "public.ci_pipeline_variables"
1100INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1101I, [2024-04-03T10:46:13.322768 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1102I, [2024-04-03T10:46:13.323985 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1103I, [2024-04-03T10:46:13.324871 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1104I, [2024-04-03T10:46:13.863537 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1105INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1106INFO: analyzing "public.ci_job_artifacts"
1107INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1108I, [2024-04-03T10:46:15.325885 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1109I, [2024-04-03T10:46:15.327175 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1110I, [2024-04-03T10:46:15.328090 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1111INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1112INFO: analyzing "public.ci_pipeline_variables"
1113INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1114INFO: analyzing "public.p_ci_stages" inheritance tree
1115INFO: analyzing "public.ci_stages"
1116INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1117I, [2024-04-03T10:46:22.633675 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1118I, [2024-04-03T10:46:22.634996 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1119I, [2024-04-03T10:46:22.635906 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1120I, [2024-04-03T10:46:24.416358 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1121# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb. It took 2 minutes 8.36 seconds. Expected to take 53.19 seconds.
1122# [RSpecRunTime] RSpec elapsed time: 12 minutes 24.23 seconds. Current RSS: ~1351M. load average: 0.92 0.99 1.07 1/268 412
1123# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb. Expected to take 51.93 seconds.
1124Gitlab::BackgroundMigration::BackfillNamespaceIdOfVulnerabilityReads
1125 sets the namespace_id of existing record
1126INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1127INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1128INFO: "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
1129INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1130INFO: "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
1131INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1132INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1133INFO: "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
1134INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
1135INFO: "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
1136INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1137INFO: analyzing "public.ci_builds_metadata"
1138INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1139INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1140INFO: "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
1141INFO: analyzing "public.p_ci_builds" inheritance tree
1142INFO: analyzing "public.ci_builds"
1143INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1144INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1145INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1146I, [2024-04-03T10:47:56.498866 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1147INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1148INFO: analyzing "public.ci_pipeline_variables"
1149INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1150I, [2024-04-03T10:48:20.028110 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1151I, [2024-04-03T10:48:20.029172 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1152I, [2024-04-03T10:48:20.029946 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1153I, [2024-04-03T10:48:20.535742 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1154INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1155INFO: analyzing "public.ci_job_artifacts"
1156INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1157I, [2024-04-03T10:48:21.948347 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1158I, [2024-04-03T10:48:21.949895 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1159I, [2024-04-03T10:48:21.950789 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1160INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1161INFO: analyzing "public.ci_pipeline_variables"
1162INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1163INFO: analyzing "public.p_ci_stages" inheritance tree
1164INFO: analyzing "public.ci_stages"
1165INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1166I, [2024-04-03T10:48:29.167652 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1167I, [2024-04-03T10:48:29.168814 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1168I, [2024-04-03T10:48:29.169665 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1169I, [2024-04-03T10:48:30.970827 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1170# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb. It took 2 minutes 6.46 seconds. Expected to take 51.93 seconds.
1171# [RSpecRunTime] RSpec elapsed time: 14 minutes 30.74 seconds. Current RSS: ~1342M. load average: 0.97 1.00 1.07 1/268 413
1172# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. Expected to take 45.47 seconds.
1173Gitlab::BackgroundMigration::BackfillDefaultBranchProtectionNamespaceSetting
1174 updates default_branch_protection_defaults to a correct value
1175INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1176INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1177INFO: "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
1178INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1179INFO: "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
1180INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1181INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1182INFO: "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
1183INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
1184INFO: "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
1185INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1186INFO: analyzing "public.ci_builds_metadata"
1187INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1188INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1189INFO: "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
1190INFO: analyzing "public.p_ci_builds" inheritance tree
1191INFO: analyzing "public.ci_builds"
1192INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1193INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1194INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1195I, [2024-04-03T10:49:51.345870 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1196INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1197INFO: analyzing "public.ci_pipeline_variables"
1198INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1199I, [2024-04-03T10:50:14.812001 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1200I, [2024-04-03T10:50:14.813151 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1201I, [2024-04-03T10:50:14.813967 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1202I, [2024-04-03T10:50:15.355867 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1203INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1204INFO: analyzing "public.ci_job_artifacts"
1205INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1206I, [2024-04-03T10:50:16.809249 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1207I, [2024-04-03T10:50:16.811232 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1208I, [2024-04-03T10:50:16.812262 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1209INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1210INFO: analyzing "public.ci_pipeline_variables"
1211INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1212INFO: analyzing "public.p_ci_stages" inheritance tree
1213INFO: analyzing "public.ci_stages"
1214INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1215I, [2024-04-03T10:50:24.062722 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1216I, [2024-04-03T10:50:24.063966 #339] 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-04-03T10:50:24.064835 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1218I, [2024-04-03T10:50:25.837235 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1219# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. It took 1 minute 54.83 seconds. Expected to take 45.47 seconds.
1220# [RSpecRunTime] RSpec elapsed time: 16 minutes 25.61 seconds. Current RSS: ~1348M. load average: 0.97 0.99 1.05 1/266 414
1221# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_finding_id_in_vulnerabilities_spec.rb. Expected to take 40.05 seconds.
1222Gitlab::BackgroundMigration::BackfillFindingIdInVulnerabilities
1223 #perform
1224 backfills finding_id column in the vulnerabilities table
1225 does not affect rows with finding_id populated
1226# [RSpecRunTime] RSpec elapsed time: 17 minutes 6.64 seconds. Current RSS: ~1344M. load average: 1.19 1.05 1.07 1/267 415
1227The application_settings (main) table has 1261 columns.
1228Recreating the database
1229Dropped database 'gitlabhq_test'
1230Dropped database 'gitlabhq_test_ci'
1231Created database 'gitlabhq_test'
1232Created database 'gitlabhq_test_ci'
1233main: == [advisory_lock_connection] object_id: 160136800, pg_backend_pid: 286
1234main: == [advisory_lock_connection] object_id: 160136800, pg_backend_pid: 286
1235ci: == [advisory_lock_connection] object_id: 160143980, pg_backend_pid: 288
1236ci: == [advisory_lock_connection] object_id: 160143980, pg_backend_pid: 288
1237Databases re-creation done in 14.326465051000014
1238# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_finding_id_in_vulnerabilities_spec.rb. It took 55.59 seconds. Expected to take 40.05 seconds.
1239# [RSpecRunTime] RSpec elapsed time: 17 minutes 21.25 seconds. Current RSS: ~1344M. load average: 1.43 1.11 1.09 1/267 418
1240# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/copy_column_using_background_migration_job_spec.rb. Expected to take 32.14 seconds.
1241Gitlab::BackgroundMigration::CopyColumnUsingBackgroundMigrationJob
1242 is expected to be < Gitlab::BackgroundMigration::BatchedMigrationJob
1243 #perform
1244 tracks timings of queries
1245 primary keys
1246 copies all in range
1247# [RSpecRunTime] RSpec elapsed time: 17 minutes 30.98 seconds. Current RSS: ~1349M. load average: 1.28 1.09 1.08 1/267 419
1248 foreign keys
1249 copies all in range
1250# [RSpecRunTime] RSpec elapsed time: 17 minutes 34.09 seconds. Current RSS: ~1351M. load average: 1.18 1.08 1.08 1/267 420
1251 columns with NULLs
1252 copies all in range
1253# [RSpecRunTime] RSpec elapsed time: 17 minutes 37.22 seconds. Current RSS: ~1344M. load average: 1.08 1.06 1.07 1/267 421
1254 when multiple columns are given
1255 copies all values in the range
1256 when the number of source and target columns does not match
1257 raises an error
1258# [RSpecRunTime] RSpec elapsed time: 17 minutes 43.73 seconds. Current RSS: ~1340M. load average: 1.16 1.07 1.08 1/268 422
1259 pause interval between sub-batches
1260 sleeps for the specified time between sub-batches
1261 when pause_ms value is negative
1262 treats it as a 0
1263# [RSpecRunTime] RSpec elapsed time: 17 minutes 49.87 seconds. Current RSS: ~1337M. load average: 1.15 1.07 1.08 1/268 423
1264# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/copy_column_using_background_migration_job_spec.rb. It took 35.7 seconds. Expected to take 32.14 seconds.
1265# [RSpecRunTime] RSpec elapsed time: 17 minutes 56.99 seconds. Current RSS: ~1326M. load average: 1.12 1.07 1.08 1/268 424
1266# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb. Expected to take 26.54 seconds.
1267Gitlab::BackgroundMigration::BackfillDesiredShardingKeyJob
1268 #constuct_query
1269 constructs a query using the supplied job arguments
1270# [RSpecRunTime] RSpec elapsed time: 18 minutes 21.33 seconds. Current RSS: ~1375M. load average: 1.09 1.06 1.08 1/269 425
1271 #perform
1272 backfills the missing project_id for the batch
1273# [RSpecRunTime] RSpec elapsed time: 18 minutes 25.75 seconds. Current RSS: ~1386M. load average: 1.16 1.08 1.08 1/268 426
1274INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1275INFO: analyzing "public.ci_pipeline_variables"
1276INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1277I, [2024-04-03T10:52:47.137350 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1278I, [2024-04-03T10:52:47.138719 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1279I, [2024-04-03T10:52:47.139617 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1280I, [2024-04-03T10:52:47.684089 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1281INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1282INFO: analyzing "public.ci_job_artifacts"
1283INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1284I, [2024-04-03T10:52:49.193558 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1285I, [2024-04-03T10:52:49.194768 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1286I, [2024-04-03T10:52:49.195663 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1287INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1288INFO: analyzing "public.ci_pipeline_variables"
1289INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1290INFO: analyzing "public.p_ci_stages" inheritance tree
1291INFO: analyzing "public.ci_stages"
1292INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1293I, [2024-04-03T10:52:55.863945 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1294I, [2024-04-03T10:52:55.865205 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1295I, [2024-04-03T10:52:55.866078 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1296I, [2024-04-03T10:52:57.661474 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1297# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb. It took 1 minute 0.39 second. Expected to take 26.54 seconds.
1298# [RSpecRunTime] RSpec elapsed time: 18 minutes 57.42 seconds. Current RSS: ~1384M. load average: 0.97 1.04 1.07 1/268 427
1299# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/loose_index_scan_batching_strategy_spec.rb. Expected to take 16.73 seconds.
1300Gitlab::BackgroundMigration::BatchingStrategies::LooseIndexScanBatchingStrategy#next_batch
1301 is expected to be < Gitlab::BackgroundMigration::BatchingStrategies::BaseStrategy
1302 when starting on the first batch
1303 returns the bounds of the next batch
1304# [RSpecRunTime] RSpec elapsed time: 19 minutes 4.25 seconds. Current RSS: ~1396M. load average: 0.97 1.04 1.07 1/268 428
1305 when additional batches remain
1306 returns the bounds of the next batch
1307# [RSpecRunTime] RSpec elapsed time: 19 minutes 7.56 seconds. Current RSS: ~1396M. load average: 1.05 1.05 1.07 1/268 429
1308 when on the final batch
1309 returns the bounds of the next batch
1310# [RSpecRunTime] RSpec elapsed time: 19 minutes 11.0 seconds. Current RSS: ~1397M. load average: 1.05 1.05 1.07 1/268 430
1311 when no additional batches remain
1312 returns nil
1313# [RSpecRunTime] RSpec elapsed time: 19 minutes 14.26 seconds. Current RSS: ~1390M. load average: 0.97 1.03 1.07 1/268 431
1314# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/loose_index_scan_batching_strategy_spec.rb. It took 24.0 seconds. Expected to take 16.73 seconds.
1315# [RSpecRunTime] RSpec elapsed time: 19 minutes 21.47 seconds. Current RSS: ~1360M. load average: 0.97 1.03 1.06 1/268 432
1316# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_metadata_spec.rb. Expected to take 14.23 seconds.
1317Gitlab::BackgroundMigration::BackfillPartitionIdCiPipelineMetadata
1318 #perform
1319 when second partition does not exist
1320 does not execute the migration
1321# [RSpecRunTime] RSpec elapsed time: 19 minutes 33.34 seconds. Current RSS: ~1358M. load average: 0.90 1.01 1.06 1/268 433
1322 when second partition exists
1323 fixes invalid records in the wrong the partition
1324# [RSpecRunTime] RSpec elapsed time: 19 minutes 36.42 seconds. Current RSS: ~1381M. load average: 0.90 1.01 1.06 1/268 434
1325I, [2024-04-03T10:53:45.147881 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1326INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1327INFO: analyzing "public.ci_job_artifacts"
1328INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1329I, [2024-04-03T10:53:46.765239 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1330I, [2024-04-03T10:53:46.766881 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1331I, [2024-04-03T10:53:46.767825 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1332INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1333INFO: analyzing "public.ci_pipeline_variables"
1334INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1335INFO: analyzing "public.p_ci_stages" inheritance tree
1336INFO: analyzing "public.ci_stages"
1337INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1338I, [2024-04-03T10:53:53.518107 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1339I, [2024-04-03T10:53:53.519296 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1340I, [2024-04-03T10:53:53.520152 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1341I, [2024-04-03T10:53:55.266335 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1342# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_metadata_spec.rb. It took 33.38 seconds. Expected to take 14.23 seconds.
1343# [RSpecRunTime] RSpec elapsed time: 19 minutes 54.9 seconds. Current RSS: ~1369M. load average: 0.93 1.01 1.06 1/268 435
1344# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_invalid_protected_tag_create_access_levels_spec.rb. Expected to take 13.94 seconds.
1345Gitlab::BackgroundMigration::DeleteInvalidProtectedTagCreateAccessLevels
1346 when there are push access levels
1347 deletes push access levels with groups that do not have project_group_links to the project
1348# [RSpecRunTime] RSpec elapsed time: 20 minutes 8.36 seconds. Current RSS: ~1367M. load average: 0.86 0.99 1.05 1/268 436
1349INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1350INFO: analyzing "public.ci_pipeline_variables"
1351INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1352I, [2024-04-03T10:54:18.945889 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1353I, [2024-04-03T10:54:18.947283 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1354I, [2024-04-03T10:54:18.948074 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1355I, [2024-04-03T10:54:19.484008 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1356INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1357INFO: analyzing "public.ci_job_artifacts"
1358INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1359I, [2024-04-03T10:54:20.960741 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1360I, [2024-04-03T10:54:20.961982 #339] 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-04-03T10:54:20.962879 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1362INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1363INFO: analyzing "public.ci_pipeline_variables"
1364INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1365INFO: analyzing "public.p_ci_stages" inheritance tree
1366INFO: analyzing "public.ci_stages"
1367INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1368I, [2024-04-03T10:54:27.710921 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1369I, [2024-04-03T10:54:27.712694 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1370I, [2024-04-03T10:54:27.713511 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1371I, [2024-04-03T10:54:29.645722 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1372# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_invalid_protected_tag_create_access_levels_spec.rb. It took 34.31 seconds. Expected to take 13.94 seconds.
1373# [RSpecRunTime] RSpec elapsed time: 20 minutes 29.25 seconds. Current RSS: ~1366M. load average: 0.82 0.98 1.04 1/268 437
1374# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb. Expected to take 12.47 seconds.
1375Gitlab::BackgroundMigration::DeleteInvalidProtectedBranchMergeAccessLevels
1376 when there are merge access levels
1377 deletes merge access levels with groups that do not have project_group_links to the project
1378# [RSpecRunTime] RSpec elapsed time: 20 minutes 42.46 seconds. Current RSS: ~1369M. load average: 0.78 0.96 1.04 1/268 438
1379INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1380INFO: analyzing "public.ci_pipeline_variables"
1381INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1382I, [2024-04-03T10:54:52.878588 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1383I, [2024-04-03T10:54:52.879712 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1384I, [2024-04-03T10:54:52.880530 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1385I, [2024-04-03T10:54:53.414445 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1386INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1387INFO: analyzing "public.ci_job_artifacts"
1388INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1389I, [2024-04-03T10:54:54.992027 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1390I, [2024-04-03T10:54:54.993718 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1391I, [2024-04-03T10:54:54.994605 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1392INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1393INFO: analyzing "public.ci_pipeline_variables"
1394INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1395INFO: analyzing "public.p_ci_stages" inheritance tree
1396INFO: analyzing "public.ci_stages"
1397INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1398I, [2024-04-03T10:55:01.782485 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1399I, [2024-04-03T10:55:01.784018 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1400I, [2024-04-03T10:55:01.785298 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1401I, [2024-04-03T10:55:03.614964 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1402# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb. It took 33.95 seconds. Expected to take 12.47 seconds.
1403# [RSpecRunTime] RSpec elapsed time: 21 minutes 3.24 seconds. Current RSS: ~1353M. load average: 0.84 0.97 1.03 6/268 439
1404# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. Expected to take 9.34 seconds.
1405Gitlab::BackgroundMigration::SetCorrectVulnerabilityState
1406 #filter_batch
1407 filters out vulnerabilities where dismissed_at is null
1408# [RSpecRunTime] RSpec elapsed time: 21 minutes 6.74 seconds. Current RSS: ~1358M. load average: 0.84 0.97 1.03 1/268 440
1409 #perform
1410 changes vulnerability state to `dismissed` when dismissed_at is not nil
1411 does not change the state when dismissed_at is nil
1412# [RSpecRunTime] RSpec elapsed time: 21 minutes 13.25 seconds. Current RSS: ~1372M. load average: 0.94 0.99 1.04 1/268 441
1413# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. It took 16.98 seconds. Expected to take 9.34 seconds.
1414# [RSpecRunTime] RSpec elapsed time: 21 minutes 20.27 seconds. Current RSS: ~1344M. load average: 0.95 0.99 1.04 1/268 442
1415# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. Expected to take 7.14 seconds.
1416Gitlab::BackgroundMigration::BackfillHasRemediationsOfVulnerabilityReads
1417 does not modify has_remediations of vulnerabilities which do not have remediations
1418 when finding_remediation record exists
1419 updates vulnerability_reads records which has remediations
1420# [RSpecRunTime] RSpec elapsed time: 21 minutes 27.28 seconds. Current RSS: ~1364M. load average: 0.88 0.97 1.03 1/268 443
1421# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. It took 13.92 seconds. Expected to take 7.14 seconds.
1422# [RSpecRunTime] RSpec elapsed time: 21 minutes 34.23 seconds. Current RSS: ~1347M. load average: 0.89 0.97 1.03 1/268 444
1423# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_orphaned_operational_vulnerabilities_spec.rb. Expected to take 3.71 seconds.
1424Gitlab::BackgroundMigration::DeleteOrphanedOperationalVulnerabilities
1425 drops Cluster Image Scanning and Custom Vulnerabilities without any Findings
1426# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_orphaned_operational_vulnerabilities_spec.rb. It took 10.4 seconds. Expected to take 3.71 seconds.
1427# [RSpecRunTime] RSpec elapsed time: 21 minutes 44.67 seconds. Current RSS: ~1347M. load average: 0.91 0.97 1.03 1/268 445
1428# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/nullify_creator_id_column_of_orphaned_projects_spec.rb. Expected to take 3.62 seconds.
1429Gitlab::BackgroundMigration::NullifyCreatorIdColumnOfOrphanedProjects
1430 nullifies the `creator_id` column of projects whose creators do not exist
1431# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/nullify_creator_id_column_of_orphaned_projects_spec.rb. It took 10.27 seconds. Expected to take 3.62 seconds.
1432# [RSpecRunTime] RSpec elapsed time: 21 minutes 54.99 seconds. Current RSS: ~1346M. load average: 0.92 0.97 1.03 1/268 446
1433# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/prune_stale_project_export_jobs_spec.rb. Expected to take 3.58 seconds.
1434Gitlab::BackgroundMigration::PruneStaleProjectExportJobs
1435 removes export jobs and associated relations older than 7 days
1436# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/prune_stale_project_export_jobs_spec.rb. It took 10.53 seconds. Expected to take 3.58 seconds.
1437# [RSpecRunTime] RSpec elapsed time: 22 minutes 5.56 seconds. Current RSS: ~1337M. load average: 0.94 0.97 1.03 1/268 447
1438# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_feature_package_registry_access_level_spec.rb. Expected to take 3.4 seconds.
1439Gitlab::BackgroundMigration::BackfillProjectFeaturePackageRegistryAccessLevel
1440 backfills project_features.package_registry_access_level
1441# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_feature_package_registry_access_level_spec.rb. It took 10.5 seconds. Expected to take 3.4 seconds.
1442# [RSpecRunTime] RSpec elapsed time: 22 minutes 16.1 seconds. Current RSS: ~1337M. load average: 0.95 0.97 1.03 1/268 448
1443# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb. Expected to take 3.29 seconds.
1444Gitlab::BackgroundMigration::BatchingStrategies::BaseStrategy#next_batch
1445 #next_batch
1446 raises an error if not overridden by a subclass
1447# [RSpecRunTime] RSpec elapsed time: 22 minutes 19.41 seconds. Current RSS: ~1344M. load average: 0.95 0.98 1.03 1/268 449
1448# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb. It took 10.54 seconds. Expected to take 3.29 seconds.
1449# [RSpecRunTime] RSpec elapsed time: 22 minutes 26.68 seconds. Current RSS: ~1336M. load average: 0.95 0.98 1.03 1/268 450
1450# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/base_job_spec.rb. Expected to take 3.25 seconds.
1451Gitlab::BackgroundMigration::BaseJob#perform
1452 #perform
1453 raises an error if not overridden by a subclass
1454# [RSpecRunTime] RSpec elapsed time: 22 minutes 29.93 seconds. Current RSS: ~1340M. load average: 0.96 0.98 1.03 1/268 451
1455# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/base_job_spec.rb. It took 10.1 seconds. Expected to take 3.25 seconds.
1456# [RSpecRunTime] RSpec elapsed time: 22 minutes 36.83 seconds. Current RSS: ~1334M. load average: 1.04 0.99 1.03 1/268 452
1457auto_explain log contains 905 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-5-5.339.main.ndjson.gz
1458took 19.54108763
1459auto_explain log contains 905 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-5-5.339.ci.ndjson.gz
1460took 18.605722296
1461[TEST PROF INFO] EventProf results for sql.active_record
1462Total time: 15:42.381 of 22:32.881 (69.66%)
1463Total events: 619993
1464Top 5 slowest suites (by time):
1465Gitlab::Backg...urceLinkEvents (./spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb:5) – 01:42.783 (62578 / 7) of 02:29.790 (68.62%)
1466Gitlab::Backg...ntRepositories (./spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb:9) – 01:37.653 (51812 / 2) of 02:08.403 (76.05%)
1467Gitlab::Backg...erabilityReads (./spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb:5) – 01:37.544 (49722 / 1) of 02:06.504 (77.11%)
1468Gitlab::Backg...InvalidMembers (./spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb:6) – 01:36.065 (54043 / 3) of 02:08.337 (74.85%)
1469Gitlab::Backg...kiRepositories (./spec/lib/gitlab/background_migration/backfill_project_wiki_repositories_spec.rb:8) – 01:35.489 (51810 / 2) of 02:07.182 (75.08%)
1470Knapsack report was generated. Preview:
1471{
1472 "spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb": 83.96952250100003,
1473 "spec/lib/gitlab/background_migration/batched_migration_job_spec.rb": 75.9279203570004,
1474 "spec/lib/gitlab/background_migration/backfill_project_wiki_repositories_spec.rb": 59.43420575300024,
1475 "spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb": 62.00387489999957,
1476 "spec/lib/gitlab/background_migration/set_legacy_open_source_license_available_for_non_public_projects_spec.rb": 55.18582007800069,
1477 "spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb": 59.510940969999865,
1478 "spec/lib/gitlab/background_migration/backfill_namespace_id_of_vulnerability_reads_spec.rb": 57.73623233499984,
1479 "spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb": 52.2092377859999,
1480 "spec/lib/gitlab/background_migration/backfill_finding_id_in_vulnerabilities_spec.rb": 41.15794423100033,
1481 "spec/lib/gitlab/background_migration/copy_column_using_background_migration_job_spec.rb": 28.72945548699954,
1482 "spec/lib/gitlab/background_migration/backfill_desired_sharding_key_job_spec.rb": 28.879053042999658,
1483 "spec/lib/gitlab/background_migration/batching_strategies/loose_index_scan_batching_strategy_spec.rb": 16.938852000000225,
1484 "spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_metadata_spec.rb": 15.044165742999212,
1485 "spec/lib/gitlab/background_migration/delete_invalid_protected_tag_create_access_levels_spec.rb": 13.56570894000015,
1486 "spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb": 13.30645892999928,
1487 "spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb": 10.108281182999235,
1488 "spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb": 7.1059073770002215,
1489 "spec/lib/gitlab/background_migration/delete_orphaned_operational_vulnerabilities_spec.rb": 3.6215706510001837,
1490 "spec/lib/gitlab/background_migration/nullify_creator_id_column_of_orphaned_projects_spec.rb": 3.528217764999681,
1491 "spec/lib/gitlab/background_migration/prune_stale_project_export_jobs_spec.rb": 3.6178802320000614,
1492 "spec/lib/gitlab/background_migration/backfill_project_feature_package_registry_access_level_spec.rb": 3.7478015759998016,
1493 "spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb": 3.420293008999579,
1494 "spec/lib/gitlab/background_migration/base_job_spec.rb": 3.3573178320002626
1495}
1496Knapsack global time execution for tests: 11m 42s
1497Finished in 23 minutes 15 seconds (files took 51.18 seconds to load)
149871 examples, 0 failures
1499Randomized with seed 56319
1500[TEST PROF INFO] Time spent in factories: 00:00.339 (0.02% of total time)
1501RSpec exited with 0.
1502No examples to retry, congrats!
1503 Running after_script 00:06
1504Running after script...
1505$ source scripts/utils.sh
1506$ bundle exec gem list gitlab_quality-test_tooling
1507gitlab_quality-test_tooling (1.21.0)
1508$ section_start "relate-failure-issue" "Report test failures" # collapsed multi-line command
1509 Report test failures 00:00
1510$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
1511 Report test flakiness 00:00
1512$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
1513 Report test slowness 00:00
1514$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
1515 Report test slowness in MR note 00:02
1518$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
1519 Report test files close to timing out 00:01
1522$ tooling/bin/push_job_metrics || true
1523[job-metrics] Pushing job metrics file for the CI/CD job.
1524[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
1525 Saving cache for successful job 00:01
1526Not uploading cache ruby-gems-debian-bookworm-ruby-3.1-17 due to policy
1527 Uploading artifacts for successful job 00:05
1528Uploading artifacts...
1529auto_explain/: found 3 matching artifact files and directories
1530coverage/: found 5 matching artifact files and directories
1531crystalball/: found 2 matching artifact files and directories
1532WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1533knapsack/: found 4 matching artifact files and directories
1534rspec/: found 16 matching artifact files and directories
1535WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1536log/*.log: found 13 matching artifact files and directories
1537WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6536639210/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
1538WARNING: Retrying... context=artifacts-uploader error=request redirected
1539Uploading artifacts as "archive" to coordinator... 201 Created id=6536639210 responseStatus=201 Created token=glcbt-65
1540Uploading artifacts...
1541rspec/rspec-*.xml: found 1 matching artifact files and directories
1542WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6536639210/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
1543WARNING: Retrying... context=artifacts-uploader error=request redirected
1544Uploading artifacts as "junit" to coordinator... 201 Created id=6536639210 responseStatus=201 Created token=glcbt-65
1545 Cleaning up project directory and file based variables 00:00
1546Job succeeded