Skip to content
Snippets Groups Projects

rspec background_migration pg14 4/5

Passed Started by
Rajendra Kadam
@rkadam3
1Running with gitlab-runner 16.9.1 (782c6ecb)
2 on green-6.private.runners-manager.gitlab.com/gitlab.com/gitlab-org vHriyjxu, system ID: s_44fde8db605e
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: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:fc7435a87025ef82fcd7c3a7df1e52121e8a88ab05430c94ba7ad5920fecc0d0 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:c129fa1214137f01be7f1412c5233ac179604d32d9d852cbe06113596fb24504 ...
24 Preparing environment 00:00
25Running on runner-vhriyjxu-project-278964-concurrent-0 via runner-vhriyjxu-private-1709551077-17336f95...
26 Getting source from Git repository 00:01
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
30 Restoring cache 00:16
31Checking cache for ruby-gems-debian-bookworm-ruby-3.1-17...
32cache.zip is up to date
33Successfully extracted cache
34 Downloading artifacts 00:34
35Downloading artifacts for clone-gitlab-repo (6311410718)...
36Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6311410718 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 (6311410765)...
40Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6311410765 responseStatus=200 OK token=glcbt-65
41Downloading artifacts for detect-tests (6311410787)...
42Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6311410787 responseStatus=200 OK token=glcbt-65
43Downloading artifacts for retrieve-tests-metadata (6311410799)...
44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6311410799 responseStatus=200 OK token=glcbt-65
45Downloading artifacts for setup-test-env (6311410773)...
46Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6311410773 responseStatus=200 OK token=glcbt-65
47 Executing "step_script" stage of the job script 29:26
48Using docker image sha256:fc7435a87025ef82fcd7c3a7df1e52121e8a88ab05430c94ba7ad5920fecc0d0 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:c129fa1214137f01be7f1412c5233ac179604d32d9d852cbe06113596fb24504 ...
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:16
732Using decomposed database config (config/database.yml.decomposed-postgresql)
733Geo DB won't be set up.
734Embedding DB won't be set up.
735 Setting up DBs 00:51
746$ source ./scripts/rspec_helpers.sh
747$ run_timed_command "gem install knapsack --no-document"
748$ gem install knapsack --no-document
749Successfully installed knapsack-4.0.0
7501 gem installed
751==> 'gem install knapsack --no-document' succeeded in 1 seconds.
752$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
753 Spawning Gitaly 00:03
757$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
758$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
759$ tooling/bin/create_job_metrics_file || true
760[job-metrics] Creating the job metrics file for the CI/CD job.
761$ rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
762[13:29:26] 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_4_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_4_5_278964_report.json
771NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_4_5_278964_report.json
772RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-6311411106.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 2.666186461 seconds
788# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/job_coordinator_spec.rb. Expected to take 1 minute 44.22 seconds.
789Gitlab::BackgroundMigration::JobCoordinator
790 .for_tracking_database
791 returns an executor with the correct worker class and database
792 when an invalid value is given
793 raises an error
794 #queue
795 returns background migration worker queue
796# [RSpecRunTime] RSpec elapsed time: 15.98 seconds. Current RSS: ~1336M. load average: 1.08 1.33 1.27 1/270 384
797 #with_shared_connection
798 yields to the block after properly configuring SharedModel
799# [RSpecRunTime] RSpec elapsed time: 19.36 seconds. Current RSS: ~1355M. load average: 1.07 1.33 1.27 1/270 385
800 #pending_jobs
801 when there are enqueued jobs
802 does not include jobs for other workers
803 when not including dead jobs
804 includes current and future jobs
805# [RSpecRunTime] RSpec elapsed time: 25.86 seconds. Current RSS: ~1368M. load average: 1.06 1.32 1.27 1/272 386
806 when including dead jobs
807 includes current and future jobs, and also dead and retry jobs
808# [RSpecRunTime] RSpec elapsed time: 29.08 seconds. Current RSS: ~1367M. load average: 1.06 1.32 1.27 1/272 387
809 #steal
810 when there are enqueued jobs present
811 when queue contains unprocessed jobs
812 steals jobs from a queue
813 sets up the shared connection while stealing jobs
814 does not steal job that has already been taken
815 does not steal jobs for a different migration
816 when a custom predicate is given
817 steals jobs that match the predicate
818 does not steal jobs that do not match the predicate
819# [RSpecRunTime] RSpec elapsed time: 48.46 seconds. Current RSS: ~1372M. load average: 1.12 1.32 1.27 1/272 388
820 when one of the jobs raises an error
821 enqueues the migration again and re-raises the error
822# [RSpecRunTime] RSpec elapsed time: 51.81 seconds. Current RSS: ~1371M. load average: 1.11 1.31 1.27 1/272 389
823 when there are scheduled jobs present
824 steals all jobs from the scheduled sets
825# [RSpecRunTime] RSpec elapsed time: 55.03 seconds. Current RSS: ~1370M. load average: 1.18 1.32 1.27 1/272 390
826 when there are enqueued and scheduled jobs present
827 steals from the scheduled sets queue first
828# [RSpecRunTime] RSpec elapsed time: 58.31 seconds. Current RSS: ~1368M. load average: 1.18 1.32 1.27 1/272 391
829 when retry_dead_jobs is true
830 steals from the dead and retry queue
831# [RSpecRunTime] RSpec elapsed time: 1 minute 1.76 seconds. Current RSS: ~1367M. load average: 1.17 1.32 1.27 1/273 393
832 #perform
833 when the background migration does not inherit from BaseJob
834 performs a background migration with the configured shared connection
835# [RSpecRunTime] RSpec elapsed time: 1 minute 5.1 seconds. Current RSS: ~1366M. load average: 1.23 1.33 1.28 1/273 394
836 when the background migration inherits from BaseJob
837 passes the correct connection when constructing the migration
838# [RSpecRunTime] RSpec elapsed time: 1 minute 8.4 seconds. Current RSS: ~1365M. load average: 1.23 1.33 1.28 1/273 395
839 .remaining
840 when there are jobs remaining
841 returns the enqueued jobs plus the scheduled jobs
842# [RSpecRunTime] RSpec elapsed time: 1 minute 11.63 seconds. Current RSS: ~1361M. load average: 1.21 1.32 1.27 1/273 396
843 when there are no jobs remaining
844 returns zero
845# [RSpecRunTime] RSpec elapsed time: 1 minute 14.91 seconds. Current RSS: ~1361M. load average: 1.28 1.34 1.28 1/273 397
846 .exists?
847 when there are enqueued jobs present
848 returns true if specific job exists
849 returns false if specific job does not exist
850# [RSpecRunTime] RSpec elapsed time: 1 minute 21.28 seconds. Current RSS: ~1361M. load average: 1.34 1.35 1.28 1/273 398
851 when there are scheduled jobs present
852 returns true if specific job exists
853 returns false if specific job does not exist
854# [RSpecRunTime] RSpec elapsed time: 1 minute 27.75 seconds. Current RSS: ~1358M. load average: 1.39 1.36 1.29 1/274 399
855 .dead_jobs?
856 when there are dead jobs present
857 returns true if specific job exists
858 returns false if specific job does not exist
859# [RSpecRunTime] RSpec elapsed time: 1 minute 34.38 seconds. Current RSS: ~1359M. load average: 1.33 1.35 1.28 1/274 400
860 .retrying_jobs?
861 when there are dead jobs present
862 returns true if specific job exists
863 returns false if specific job does not exist
864# [RSpecRunTime] RSpec elapsed time: 1 minute 40.76 seconds. Current RSS: ~1359M. load average: 1.22 1.32 1.27 1/274 401
865# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/job_coordinator_spec.rb. It took 1 minute 45.14 seconds. Expected to take 1 minute 44.22 seconds.
866# [RSpecRunTime] RSpec elapsed time: 1 minute 50.66 seconds. Current RSS: ~1347M. load average: 1.27 1.33 1.28 1/273 403
867# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. Expected to take 1 minute 22.49 seconds.
868Gitlab::BackgroundMigration::DestroyInvalidMembers
869 logs IDs of deleted records
870 tracks timings of queries
871 removes invalid memberships but keeps valid ones
872I, [2024-03-04T13:33:39.197498 #338] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
873INFO: analyzing "public.p_ci_builds" inheritance tree
874INFO: analyzing "public.ci_builds"
875INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
876I, [2024-03-04T13:33:54.405571 #338] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
877I, [2024-03-04T13:33:54.406553 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
878I, [2024-03-04T13:33:54.407287 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
879I, [2024-03-04T13:34:07.087451 #338] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
880INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
881INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
882INFO: "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
883INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
884INFO: "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
885INFO: analyzing "public.p_ci_job_annotations" inheritance tree
886INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
887INFO: "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
888INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
889INFO: analyzing "public.ci_builds_metadata"
890INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
891INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
892INFO: "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
893INFO: analyzing "public.p_ci_builds" inheritance tree
894INFO: analyzing "public.ci_builds"
895INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
896I, [2024-03-04T13:34:30.718821 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
897INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
898INFO: analyzing "public.ci_pipeline_variables"
899INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
900I, [2024-03-04T13:34:51.240930 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
901I, [2024-03-04T13:34:51.241988 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
902I, [2024-03-04T13:34:51.242736 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
903I, [2024-03-04T13:34:51.759189 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
904INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
905INFO: analyzing "public.ci_job_artifacts"
906INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
907I, [2024-03-04T13:34:53.046127 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
908I, [2024-03-04T13:34:53.047476 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
909I, [2024-03-04T13:34:53.048314 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
910INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
911INFO: analyzing "public.ci_pipeline_variables"
912INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
913INFO: analyzing "public.p_ci_stages" inheritance tree
914INFO: analyzing "public.ci_stages"
915INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
916I, [2024-03-04T13:34:58.408265 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
917I, [2024-03-04T13:34:58.409492 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
918I, [2024-03-04T13:34:58.410290 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
919# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. It took 2 minutes 51.15 seconds. Expected to take 1 minute 22.49 seconds.
920# [RSpecRunTime] RSpec elapsed time: 4 minutes 41.86 seconds. Current RSS: ~1352M. load average: 1.02 1.21 1.24 1/270 404
921# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb. Expected to take 1 minute 17.87 seconds.
922Gitlab::BackgroundMigration::BackfillIntegrationsEnableSslVerification
923 enables SSL verification for known-good hostnames
924 only updates records within the given ID range
925 marks the job as succeeded
926I, [2024-03-04T13:36:24.011075 #338] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
927INFO: analyzing "public.p_ci_builds" inheritance tree
928INFO: analyzing "public.ci_builds"
929INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
930I, [2024-03-04T13:36:38.878481 #338] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
931I, [2024-03-04T13:36:38.879612 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
932I, [2024-03-04T13:36:38.880438 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
933I, [2024-03-04T13:36:52.467933 #338] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
934INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
935INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
936INFO: "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
937INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
938INFO: "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
939INFO: analyzing "public.p_ci_job_annotations" inheritance tree
940INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
941INFO: "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
942INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
943INFO: analyzing "public.ci_builds_metadata"
944INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
945INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
946INFO: "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
947INFO: analyzing "public.p_ci_builds" inheritance tree
948INFO: analyzing "public.ci_builds"
949INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
950I, [2024-03-04T13:37:16.836158 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
951INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
952INFO: analyzing "public.ci_pipeline_variables"
953INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
954I, [2024-03-04T13:37:37.611669 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
955I, [2024-03-04T13:37:37.612691 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
956I, [2024-03-04T13:37:37.613469 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
957I, [2024-03-04T13:37:38.078995 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
958INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
959INFO: analyzing "public.ci_job_artifacts"
960INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
961I, [2024-03-04T13:37:39.282369 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
962I, [2024-03-04T13:37:39.283402 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
963I, [2024-03-04T13:37:39.284378 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
964INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
965INFO: analyzing "public.ci_pipeline_variables"
966INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
967INFO: analyzing "public.p_ci_stages" inheritance tree
968INFO: analyzing "public.ci_stages"
969INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
970I, [2024-03-04T13:37:44.591448 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
971I, [2024-03-04T13:37:44.592547 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
972I, [2024-03-04T13:37:44.593336 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
973# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb. It took 2 minutes 46.08 seconds. Expected to take 1 minute 17.87 seconds.
974# [RSpecRunTime] RSpec elapsed time: 7 minutes 27.99 seconds. Current RSS: ~1350M. load average: 1.10 1.18 1.22 1/270 405
975# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/nullify_creator_id_column_of_orphaned_projects_spec.rb. Expected to take 1 minute 17.24 seconds.
976Gitlab::BackgroundMigration::NullifyCreatorIdColumnOfOrphanedProjects
977 nullifies the `creator_id` column of projects whose creators do not exist
978I, [2024-03-04T13:39:05.610745 #338] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
979INFO: analyzing "public.p_ci_builds" inheritance tree
980INFO: analyzing "public.ci_builds"
981INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
982I, [2024-03-04T13:39:20.592482 #338] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
983I, [2024-03-04T13:39:20.593551 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
984I, [2024-03-04T13:39:20.594253 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
985I, [2024-03-04T13:39:34.827838 #338] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
986INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
987INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
988INFO: "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
989INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
990INFO: "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
991INFO: analyzing "public.p_ci_job_annotations" inheritance tree
992INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
993INFO: "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
994INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
995INFO: analyzing "public.ci_builds_metadata"
996INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
997INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
998INFO: "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
999INFO: analyzing "public.p_ci_builds" inheritance tree
1000INFO: analyzing "public.ci_builds"
1001INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1002I, [2024-03-04T13:39:59.185773 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1003INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1004INFO: analyzing "public.ci_pipeline_variables"
1005INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1006I, [2024-03-04T13:40:19.300464 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1007I, [2024-03-04T13:40:19.301472 #338] 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-03-04T13:40:19.302175 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1009I, [2024-03-04T13:40:19.716725 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1010INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1011INFO: analyzing "public.ci_job_artifacts"
1012INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1013I, [2024-03-04T13:40:20.711452 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1014I, [2024-03-04T13:40:20.712597 #338] 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-03-04T13:40:20.713380 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1016INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1017INFO: analyzing "public.ci_pipeline_variables"
1018INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1019INFO: analyzing "public.p_ci_stages" inheritance tree
1020INFO: analyzing "public.ci_stages"
1021INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1022I, [2024-03-04T13:40:26.220836 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1023I, [2024-03-04T13:40:26.222217 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1024I, [2024-03-04T13:40:26.223483 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1025# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/nullify_creator_id_column_of_orphaned_projects_spec.rb. It took 2 minutes 41.57 seconds. Expected to take 1 minute 17.24 seconds.
1026# [RSpecRunTime] RSpec elapsed time: 10 minutes 9.61 seconds. Current RSS: ~1338M. load average: 0.83 1.04 1.16 1/269 406
1027# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb. Expected to take 1 minute 17.05 seconds.
1028Gitlab::BackgroundMigration::BackfillTopicsTitle
1029 correctly backfills the title of the topics
1030I, [2024-03-04T13:41:47.490539 #338] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
1031INFO: analyzing "public.p_ci_builds" inheritance tree
1032INFO: analyzing "public.ci_builds"
1033INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1034I, [2024-03-04T13:42:02.249528 #338] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
1035I, [2024-03-04T13:42:02.250637 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1036I, [2024-03-04T13:42:02.251453 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1037I, [2024-03-04T13:42:16.403157 #338] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1038INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1039INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1040INFO: "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
1041INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1042INFO: "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
1043INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1044INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1045INFO: "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
1046INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1047INFO: analyzing "public.ci_builds_metadata"
1048INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1049INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1050INFO: "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
1051INFO: analyzing "public.p_ci_builds" inheritance tree
1052INFO: analyzing "public.ci_builds"
1053INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1054I, [2024-03-04T13:42:41.630725 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1055INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1056INFO: analyzing "public.ci_pipeline_variables"
1057INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1058I, [2024-03-04T13:43:03.997802 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1059I, [2024-03-04T13:43:03.998819 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1060I, [2024-03-04T13:43:03.999880 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1061I, [2024-03-04T13:43:04.492222 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1062INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1063INFO: analyzing "public.ci_job_artifacts"
1064INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1065I, [2024-03-04T13:43:05.600997 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1066I, [2024-03-04T13:43:05.602210 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1067I, [2024-03-04T13:43:05.603087 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1068INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1069INFO: analyzing "public.ci_pipeline_variables"
1070INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1071INFO: analyzing "public.p_ci_stages" inheritance tree
1072INFO: analyzing "public.ci_stages"
1073INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1074I, [2024-03-04T13:43:11.268671 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1075I, [2024-03-04T13:43:11.269839 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1076I, [2024-03-04T13:43:11.270722 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1077# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb. It took 2 minutes 45.23 seconds. Expected to take 1 minute 17.05 seconds.
1078# [RSpecRunTime] RSpec elapsed time: 12 minutes 54.88 seconds. Current RSS: ~1335M. load average: 0.97 1.00 1.12 1/269 407
1079# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/reset_too_many_tags_skipped_registry_imports_spec.rb. Expected to take 1 minute 15.94 seconds.
1080Gitlab::BackgroundMigration::ResetTooManyTagsSkippedRegistryImports
1081 #up
1082 resets only qualified container repositories
1083# [RSpecRunTime] RSpec elapsed time: 14 minutes 12.32 seconds. Current RSS: ~1347M. load average: 1.05 1.03 1.12 1/269 408
1084The application_settings (main) table has 1231 columns.
1085Recreating the database
1086Dropped database 'gitlabhq_test'
1087Dropped database 'gitlabhq_test_ci'
1088Created database 'gitlabhq_test'
1089Created database 'gitlabhq_test_ci'
1090main: == [advisory_lock_connection] object_id: 151731080, pg_backend_pid: 259
1091main: == [advisory_lock_connection] object_id: 151731080, pg_backend_pid: 259
1092ci: == [advisory_lock_connection] object_id: 151820100, pg_backend_pid: 261
1093ci: == [advisory_lock_connection] object_id: 151820100, pg_backend_pid: 261
1094Databases re-creation done in 12.65293678299895
1095# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/reset_too_many_tags_skipped_registry_imports_spec.rb. It took 1 minute 30.32 seconds. Expected to take 1 minute 15.94 seconds.
1096# [RSpecRunTime] RSpec elapsed time: 14 minutes 25.24 seconds. Current RSS: ~1350M. load average: 1.11 1.04 1.12 1/269 411
1097# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/cleanup_personal_access_tokens_with_nil_expires_at_spec.rb. Expected to take 1 minute 9.08 seconds.
1098Gitlab::BackgroundMigration::CleanupPersonalAccessTokensWithNilExpiresAt
1099 adds expiry to personal access tokens
1100INFO: analyzing "public.p_ci_builds" inheritance tree
1101INFO: analyzing "public.ci_builds"
1102INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1103I, [2024-03-04T13:45:47.619488 #338] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
1104I, [2024-03-04T13:45:47.620596 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1105I, [2024-03-04T13:45:47.621373 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1106I, [2024-03-04T13:46:00.408205 #338] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1107INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1108INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1109INFO: "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
1110INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1111INFO: "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
1112INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1113INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1114INFO: "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
1115INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1116INFO: analyzing "public.ci_builds_metadata"
1117INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1118INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1119INFO: "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
1120INFO: analyzing "public.p_ci_builds" inheritance tree
1121INFO: analyzing "public.ci_builds"
1122INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1123I, [2024-03-04T13:46:23.669033 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1124INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1125INFO: analyzing "public.ci_pipeline_variables"
1126INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1127I, [2024-03-04T13:46:44.213289 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1128I, [2024-03-04T13:46:44.214561 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1129I, [2024-03-04T13:46:44.215426 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1130I, [2024-03-04T13:46:44.855388 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1131INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1132INFO: analyzing "public.ci_job_artifacts"
1133INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1134I, [2024-03-04T13:46:46.100541 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1135I, [2024-03-04T13:46:46.102017 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1136I, [2024-03-04T13:46:46.103003 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1137INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1138INFO: analyzing "public.ci_pipeline_variables"
1139INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1140INFO: analyzing "public.p_ci_stages" inheritance tree
1141INFO: analyzing "public.ci_stages"
1142INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1143I, [2024-03-04T13:46:51.368188 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1144I, [2024-03-04T13:46:51.369304 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1145I, [2024-03-04T13:46:51.370124 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1146# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/cleanup_personal_access_tokens_with_nil_expires_at_spec.rb. It took 2 minutes 9.65 seconds. Expected to take 1 minute 9.08 seconds.
1147# [RSpecRunTime] RSpec elapsed time: 16 minutes 34.94 seconds. Current RSS: ~1337M. load average: 1.02 1.03 1.10 1/269 412
1148# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_code_suggestions_namespace_settings_spec.rb. Expected to take 55.29 seconds.
1149Gitlab::BackgroundMigration::BackfillCodeSuggestionsNamespaceSettings
1150 updates the code suggestions values only for group and user namespace
1151I, [2024-03-04T13:48:07.352202 #338] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1152INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1153INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1154INFO: "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
1155INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1156INFO: "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
1157INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1158INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1159INFO: "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
1160INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1161INFO: analyzing "public.ci_builds_metadata"
1162INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1163INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1164INFO: "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
1165INFO: analyzing "public.p_ci_builds" inheritance tree
1166INFO: analyzing "public.ci_builds"
1167INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1168I, [2024-03-04T13:48:31.399633 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1169INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1170INFO: analyzing "public.ci_pipeline_variables"
1171INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1172I, [2024-03-04T13:48:51.983183 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1173I, [2024-03-04T13:48:51.984259 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1174I, [2024-03-04T13:48:51.985028 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1175I, [2024-03-04T13:48:52.444133 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1176INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1177INFO: analyzing "public.ci_job_artifacts"
1178INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1179I, [2024-03-04T13:48:53.739316 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1180I, [2024-03-04T13:48:53.740515 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1181I, [2024-03-04T13:48:53.741400 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1182INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1183INFO: analyzing "public.ci_pipeline_variables"
1184INFO: "ci_pipeline_variables": 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_stages" inheritance tree
1186INFO: analyzing "public.ci_stages"
1187INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1188I, [2024-03-04T13:48:59.047853 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1189I, [2024-03-04T13:48:59.049011 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1190I, [2024-03-04T13:48:59.049836 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1191# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_code_suggestions_namespace_settings_spec.rb. It took 2 minutes 7.47 seconds. Expected to take 55.29 seconds.
1192# [RSpecRunTime] RSpec elapsed time: 18 minutes 42.46 seconds. Current RSS: ~1328M. load average: 0.98 1.00 1.08 1/269 413
1193# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_missing_ci_cd_settings_spec.rb. Expected to take 44.87 seconds.
1194Gitlab::BackgroundMigration::BackfillMissingCiCdSettings
1195 creates ci_cd_settings for projects without ci_cd_settings
1196 creates ci_cd_settings with default values
1197INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1198INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1199INFO: "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
1200INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1201INFO: "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
1202INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1203INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1204INFO: "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
1205INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1206INFO: analyzing "public.ci_builds_metadata"
1207INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1208INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1209INFO: "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
1210INFO: analyzing "public.p_ci_builds" inheritance tree
1211INFO: analyzing "public.ci_builds"
1212INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1213I, [2024-03-04T13:50:12.847675 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1214INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1215INFO: analyzing "public.ci_pipeline_variables"
1216INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1217I, [2024-03-04T13:50:33.797717 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1218I, [2024-03-04T13:50:33.798991 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1219I, [2024-03-04T13:50:33.799758 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1220I, [2024-03-04T13:50:34.239688 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1221INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1222INFO: analyzing "public.ci_job_artifacts"
1223INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1224I, [2024-03-04T13:50:35.284573 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1225I, [2024-03-04T13:50:35.285867 #338] 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-03-04T13:50:35.286755 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1227INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1228INFO: analyzing "public.ci_pipeline_variables"
1229INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1230INFO: analyzing "public.p_ci_stages" inheritance tree
1231INFO: analyzing "public.ci_stages"
1232INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1233I, [2024-03-04T13:50:40.585161 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1234I, [2024-03-04T13:50:40.586250 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1235I, [2024-03-04T13:50:40.587054 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1236# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_missing_ci_cd_settings_spec.rb. It took 1 minute 41.78 seconds. Expected to take 44.87 seconds.
1237# [RSpecRunTime] RSpec elapsed time: 20 minutes 24.29 seconds. Current RSS: ~1330M. load average: 1.00 1.00 1.07 1/270 414
1238# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/migrate_links_for_vulnerability_findings_spec.rb. Expected to take 39.62 seconds.
1239Gitlab::BackgroundMigration::MigrateLinksForVulnerabilityFindings
1240 without the presence of links key
1241 does not create any link
1242# [RSpecRunTime] RSpec elapsed time: 20 minutes 27.79 seconds. Current RSS: ~1330M. load average: 1.00 1.00 1.07 1/270 415
1243 when link name is too long
1244 skips creation of link and logs error
1245# [RSpecRunTime] RSpec elapsed time: 20 minutes 31.05 seconds. Current RSS: ~1332M. load average: 0.92 0.98 1.06 1/270 416
1246 with existing link records
1247 does not create new link
1248 does not raise ActiveRecord::RecordNotUnique
1249# [RSpecRunTime] RSpec elapsed time: 20 minutes 37.21 seconds. Current RSS: ~1333M. load average: 0.93 0.98 1.06 1/270 417
1250 when link url is too long
1251 skips creation of link and logs error
1252# [RSpecRunTime] RSpec elapsed time: 20 minutes 40.42 seconds. Current RSS: ~1327M. load average: 0.85 0.97 1.06 1/270 418
1253 with some elements which do not contain the key url
1254 creates links only to valid elements
1255# [RSpecRunTime] RSpec elapsed time: 20 minutes 43.73 seconds. Current RSS: ~1320M. load average: 0.85 0.97 1.06 1/270 419
1256 when Gitlab::Json throws exception JSON::ParserError
1257 does not log this error nor create new records
1258# [RSpecRunTime] RSpec elapsed time: 20 minutes 48.05 seconds. Current RSS: ~1320M. load average: 0.87 0.97 1.06 1/270 420
1259 with existing links within raw_metadata
1260 creates new link for each finding
1261# [RSpecRunTime] RSpec elapsed time: 20 minutes 51.33 seconds. Current RSS: ~1357M. load average: 0.88 0.97 1.06 1/270 421
1262 with links equals to an array of duplicated elements
1263 creates one new link
1264# [RSpecRunTime] RSpec elapsed time: 20 minutes 54.53 seconds. Current RSS: ~1368M. load average: 0.89 0.97 1.06 1/270 422
1265 with links equals to an array of nil element
1266 does not create any link
1267# [RSpecRunTime] RSpec elapsed time: 20 minutes 57.68 seconds. Current RSS: ~1374M. load average: 0.89 0.97 1.06 1/270 423
1268 with links equals to a string
1269 does not create any link
1270# [RSpecRunTime] RSpec elapsed time: 21 minutes 0.89 second. Current RSS: ~1372M. load average: 0.98 0.99 1.06 1/270 424
1271# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/migrate_links_for_vulnerability_findings_spec.rb. It took 43.31 seconds. Expected to take 39.62 seconds.
1272# [RSpecRunTime] RSpec elapsed time: 21 minutes 7.64 seconds. Current RSS: ~1363M. load average: 0.98 0.99 1.06 1/270 425
1273# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_users_with_defaults_spec.rb. Expected to take 28.59 seconds.
1274Gitlab::BackgroundMigration::BackfillUsersWithDefaults
1275 backfills the null values with the default values
1276INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1277INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1278INFO: "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
1279INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1280INFO: "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
1281INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1282INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1283INFO: "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
1284INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1285INFO: analyzing "public.ci_builds_metadata"
1286INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1287INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1288INFO: "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
1289INFO: analyzing "public.p_ci_builds" inheritance tree
1290INFO: analyzing "public.ci_builds"
1291INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1292I, [2024-03-04T13:52:04.390274 #338] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1293INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1294INFO: analyzing "public.ci_pipeline_variables"
1295INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1296I, [2024-03-04T13:52:25.576183 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1297I, [2024-03-04T13:52:25.577824 #338] 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-03-04T13:52:25.578594 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1299I, [2024-03-04T13:52:26.067164 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1300INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1301INFO: analyzing "public.ci_job_artifacts"
1302INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1303I, [2024-03-04T13:52:27.377507 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1304I, [2024-03-04T13:52:27.378716 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1305I, [2024-03-04T13:52:27.379946 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1306INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1307INFO: analyzing "public.ci_pipeline_variables"
1308INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1309INFO: analyzing "public.p_ci_stages" inheritance tree
1310INFO: analyzing "public.ci_stages"
1311INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1312I, [2024-03-04T13:52:32.908255 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1313I, [2024-03-04T13:52:32.909329 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1314I, [2024-03-04T13:52:32.910163 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1315# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_users_with_defaults_spec.rb. It took 1 minute 8.58 seconds. Expected to take 28.59 seconds.
1316# [RSpecRunTime] RSpec elapsed time: 22 minutes 16.26 seconds. Current RSS: ~1361M. load average: 1.00 1.00 1.05 1/271 426
1317# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/legacy_uploads_migrator_spec.rb. Expected to take 22.21 seconds.
1318Gitlab::BackgroundMigration::LegacyUploadsMigrator
1319 removes all legacy files
1320 removes all Note AttachmentUploader records
1321 creates new uploads for successfully migrated records
1322 does not remove appearance uploads
1323# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/legacy_uploads_migrator_spec.rb. It took 28.46 seconds. Expected to take 22.21 seconds.
1324# [RSpecRunTime] RSpec elapsed time: 22 minutes 44.78 seconds. Current RSS: ~1351M. load average: 0.97 0.99 1.05 1/284 440
1325# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb. Expected to take 20.74 seconds.
1326Gitlab::BackgroundMigration::BackfillPackagesTagsProjectId
1327 backfills the missing project_id for the batch
1328INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1329INFO: analyzing "public.ci_pipeline_variables"
1330INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1331I, [2024-03-04T13:53:45.430318 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1332I, [2024-03-04T13:53:45.431476 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1333I, [2024-03-04T13:53:45.432297 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1334I, [2024-03-04T13:53:45.908070 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1335INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1336INFO: analyzing "public.ci_job_artifacts"
1337INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1338I, [2024-03-04T13:53:47.164041 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1339I, [2024-03-04T13:53:47.165180 #338] 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-03-04T13:53:47.166139 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1341INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1342INFO: analyzing "public.ci_pipeline_variables"
1343INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1344INFO: analyzing "public.p_ci_stages" inheritance tree
1345INFO: analyzing "public.ci_stages"
1346INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1347I, [2024-03-04T13:53:52.541010 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1348I, [2024-03-04T13:53:52.542369 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1349I, [2024-03-04T13:53:52.543294 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1350# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb. It took 51.0 seconds. Expected to take 20.74 seconds.
1351# [RSpecRunTime] RSpec elapsed time: 23 minutes 35.82 seconds. Current RSS: ~1361M. load average: 0.99 1.00 1.05 1/284 441
1352# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/remove_backfilled_job_artifacts_expire_at_spec.rb. Expected to take 14.47 seconds.
1353Gitlab::BackgroundMigration::RemoveBackfilledJobArtifactsExpireAt
1354 is expected to be < Gitlab::BackgroundMigration::BatchedMigrationJob
1355 #perform
1356 with artifacts that has backfilled expire_at
1357WARNING: Active Record does not support composite primary key.
1358ci_job_artifacts has composite primary key. Composite primary key is ignored.
1359WARNING: Manually assigning ids is not allowed, the value will be ignored
1360WARNING: Manually assigning ids is not allowed, the value will be ignored
1361WARNING: Manually assigning ids is not allowed, the value will be ignored
1362WARNING: Manually assigning ids is not allowed, the value will be ignored
1363WARNING: Manually assigning ids is not allowed, the value will be ignored
1364WARNING: Manually assigning ids is not allowed, the value will be ignored
1365WARNING: Manually assigning ids is not allowed, the value will be ignored
1366WARNING: Manually assigning ids is not allowed, the value will be ignored
1367WARNING: Manually assigning ids is not allowed, the value will be ignored
1368WARNING: Manually assigning ids is not allowed, the value will be ignored
1369WARNING: Manually assigning ids is not allowed, the value will be ignored
1370WARNING: Manually assigning ids is not allowed, the value will be ignored
1371WARNING: Manually assigning ids is not allowed, the value will be ignored
1372WARNING: Manually assigning ids is not allowed, the value will be ignored
1373WARNING: Manually assigning ids is not allowed, the value will be ignored
1374WARNING: Manually assigning ids is not allowed, the value will be ignored
1375 removes expire_at on job artifacts that have expire_at on 00, 30 or 45 minute of 21, 22, 23 of the month
1376WARNING: Active Record does not support composite primary key.
1377ci_job_artifacts has composite primary key. Composite primary key is ignored.
1378WARNING: Manually assigning ids is not allowed, the value will be ignored
1379WARNING: Manually assigning ids is not allowed, the value will be ignored
1380WARNING: Manually assigning ids is not allowed, the value will be ignored
1381WARNING: Manually assigning ids is not allowed, the value will be ignored
1382WARNING: Manually assigning ids is not allowed, the value will be ignored
1383WARNING: Manually assigning ids is not allowed, the value will be ignored
1384WARNING: Manually assigning ids is not allowed, the value will be ignored
1385WARNING: Manually assigning ids is not allowed, the value will be ignored
1386WARNING: Manually assigning ids is not allowed, the value will be ignored
1387WARNING: Manually assigning ids is not allowed, the value will be ignored
1388WARNING: Manually assigning ids is not allowed, the value will be ignored
1389WARNING: Manually assigning ids is not allowed, the value will be ignored
1390WARNING: Manually assigning ids is not allowed, the value will be ignored
1391WARNING: Manually assigning ids is not allowed, the value will be ignored
1392WARNING: Manually assigning ids is not allowed, the value will be ignored
1393WARNING: Manually assigning ids is not allowed, the value will be ignored
1394 keeps expire_at on other job artifacts
1395# [RSpecRunTime] RSpec elapsed time: 23 minutes 45.14 seconds. Current RSS: ~1361M. load average: 0.99 1.00 1.05 1/284 442
1396 with trace artifacts that has backfilled expire_at
1397WARNING: Active Record does not support composite primary key.
1398ci_job_artifacts has composite primary key. Composite primary key is ignored.
1399WARNING: Manually assigning ids is not allowed, the value will be ignored
1400WARNING: Manually assigning ids is not allowed, the value will be ignored
1401 removes expire_at on trace job artifacts
1402# [RSpecRunTime] RSpec elapsed time: 23 minutes 48.12 seconds. Current RSS: ~1365M. load average: 0.99 1.00 1.05 1/284 443
1403# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/remove_backfilled_job_artifacts_expire_at_spec.rb. It took 18.75 seconds. Expected to take 14.47 seconds.
1404# [RSpecRunTime] RSpec elapsed time: 23 minutes 54.62 seconds. Current RSS: ~1350M. load average: 0.99 1.00 1.04 1/284 444
1405# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. Expected to take 12.42 seconds.
1406Gitlab::BackgroundMigration::BackfillIssueSearchDataNamespaceId
1407WARNING: Active Record does not support composite primary key.
1408issue_search_data has composite primary key. Composite primary key is ignored.
1409WARNING: Active Record does not support composite primary key.
1410issue_search_data has composite primary key. Composite primary key is ignored.
1411 backfills namespace_id for the specified records
1412INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1413INFO: analyzing "public.ci_pipeline_variables"
1414INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1415I, [2024-03-04T13:54:33.251999 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1416I, [2024-03-04T13:54:33.252998 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1417I, [2024-03-04T13:54:33.253703 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1418I, [2024-03-04T13:54:33.656011 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1419INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1420INFO: analyzing "public.ci_job_artifacts"
1421INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1422I, [2024-03-04T13:54:34.722055 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1423I, [2024-03-04T13:54:34.723030 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1424I, [2024-03-04T13:54:34.723762 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1425INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1426INFO: analyzing "public.ci_pipeline_variables"
1427INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1428INFO: analyzing "public.p_ci_stages" inheritance tree
1429INFO: analyzing "public.ci_stages"
1430INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1431I, [2024-03-04T13:54:39.683966 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1432I, [2024-03-04T13:54:39.684956 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1433I, [2024-03-04T13:54:39.686192 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1434# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. It took 28.06 seconds. Expected to take 12.42 seconds.
1435# [RSpecRunTime] RSpec elapsed time: 24 minutes 22.72 seconds. Current RSS: ~1341M. load average: 0.91 0.98 1.04 1/284 445
1436# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb. Expected to take 10.97 seconds.
1437Gitlab::BackgroundMigration::DeleteInvalidProtectedBranchMergeAccessLevels
1438 when there are merge access levels
1439 deletes merge access levels with groups that do not have project_group_links to the project
1440# [RSpecRunTime] RSpec elapsed time: 24 minutes 33.1 seconds. Current RSS: ~1351M. load average: 0.93 0.98 1.04 1/284 446
1441INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1442INFO: analyzing "public.ci_pipeline_variables"
1443INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1444I, [2024-03-04T13:54:58.952002 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1445I, [2024-03-04T13:54:58.953073 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1446I, [2024-03-04T13:54:58.953847 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1447I, [2024-03-04T13:54:59.392549 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1448INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1449INFO: analyzing "public.ci_job_artifacts"
1450INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1451I, [2024-03-04T13:55:00.574953 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1452I, [2024-03-04T13:55:00.575967 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1453I, [2024-03-04T13:55:00.576706 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1454INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1455INFO: analyzing "public.ci_pipeline_variables"
1456INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1457INFO: analyzing "public.p_ci_stages" inheritance tree
1458INFO: analyzing "public.ci_stages"
1459INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1460I, [2024-03-04T13:55:05.914064 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1461I, [2024-03-04T13:55:05.915339 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1462I, [2024-03-04T13:55:05.916090 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1463# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb. It took 26.09 seconds. Expected to take 10.97 seconds.
1464# [RSpecRunTime] RSpec elapsed time: 24 minutes 48.86 seconds. Current RSS: ~1349M. load average: 0.86 0.97 1.03 1/284 447
1465# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_push_access_levels_spec.rb. Expected to take 10.75 seconds.
1466Gitlab::BackgroundMigration::DeleteInvalidProtectedBranchPushAccessLevels
1467 when there are push access levels
1468 deletes push access levels with groups that do not have project_group_links to the project
1469# [RSpecRunTime] RSpec elapsed time: 24 minutes 59.54 seconds. Current RSS: ~1350M. load average: 0.89 0.97 1.03 1/284 448
1470INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1471INFO: analyzing "public.ci_pipeline_variables"
1472INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1473I, [2024-03-04T13:55:25.504886 #338] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1474I, [2024-03-04T13:55:25.506257 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1475I, [2024-03-04T13:55:25.507046 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1476I, [2024-03-04T13:55:25.949110 #338] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1477INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1478INFO: analyzing "public.ci_job_artifacts"
1479INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1480I, [2024-03-04T13:55:27.142005 #338] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1481I, [2024-03-04T13:55:27.143011 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1482I, [2024-03-04T13:55:27.143788 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1483INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1484INFO: analyzing "public.ci_pipeline_variables"
1485INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1486INFO: analyzing "public.p_ci_stages" inheritance tree
1487INFO: analyzing "public.ci_stages"
1488INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1489I, [2024-03-04T13:55:32.489439 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1490I, [2024-03-04T13:55:32.490394 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1491I, [2024-03-04T13:55:32.491113 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1492# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_push_access_levels_spec.rb. It took 26.75 seconds. Expected to take 10.75 seconds.
1493# [RSpecRunTime] RSpec elapsed time: 25 minutes 15.66 seconds. Current RSS: ~1343M. load average: 0.85 0.96 1.02 1/284 449
1494# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_default_organization_users_spec.rb. Expected to take 6.48 seconds.
1495Gitlab::BackgroundMigration::BackfillDefaultOrganizationUsers
1496 #perform
1497 with no entries for a regular user in organization_users
1498 adds regular users correctly with the default organization to organization_users
1499# [RSpecRunTime] RSpec elapsed time: 25 minutes 18.81 seconds. Current RSS: ~1341M. load average: 0.85 0.96 1.02 1/284 450
1500 when user already exists in organization_users as an admin user
1501 updates the organization_users entry to a regular user
1502# [RSpecRunTime] RSpec elapsed time: 25 minutes 21.69 seconds. Current RSS: ~1349M. load average: 0.86 0.96 1.02 1/284 451
1503# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_default_organization_users_spec.rb. It took 12.39 seconds. Expected to take 6.48 seconds.
1504# [RSpecRunTime] RSpec elapsed time: 25 minutes 28.09 seconds. Current RSS: ~1341M. load average: 0.87 0.96 1.02 1/284 452
1505# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. Expected to take 4.76 seconds.
1506Gitlab::BackgroundMigration::DropVulnerabilitiesWithoutFindingId
1507 #perform
1508 removes all Vulnerabilities without a finding_id
1509# [RSpecRunTime] RSpec elapsed time: 25 minutes 32.64 seconds. Current RSS: ~1340M. load average: 0.88 0.96 1.02 1/284 453
1510INFO: analyzing "public.p_ci_stages" inheritance tree
1511INFO: analyzing "public.ci_stages"
1512INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1513I, [2024-03-04T13:55:57.491828 #338] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1514I, [2024-03-04T13:55:57.493088 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1515I, [2024-03-04T13:55:57.493870 #338] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1516# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb. It took 12.48 seconds. Expected to take 4.76 seconds.
1517# [RSpecRunTime] RSpec elapsed time: 25 minutes 40.62 seconds. Current RSS: ~1336M. load average: 0.90 0.96 1.02 1/284 454
1518# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_orphaned_operational_vulnerabilities_spec.rb. Expected to take 3.67 seconds.
1519Gitlab::BackgroundMigration::DeleteOrphanedOperationalVulnerabilities
1520 drops Cluster Image Scanning and Custom Vulnerabilities without any Findings
1521# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_orphaned_operational_vulnerabilities_spec.rb. It took 9.7 seconds. Expected to take 3.67 seconds.
1522# [RSpecRunTime] RSpec elapsed time: 25 minutes 50.36 seconds. Current RSS: ~1337M. load average: 0.92 0.96 1.02 1/284 455
1523# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/prune_stale_project_export_jobs_spec.rb. Expected to take 3.58 seconds.
1524Gitlab::BackgroundMigration::PruneStaleProjectExportJobs
1525 removes export jobs and associated relations older than 7 days
1526# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/prune_stale_project_export_jobs_spec.rb. It took 9.71 seconds. Expected to take 3.58 seconds.
1527# [RSpecRunTime] RSpec elapsed time: 26 minutes 0.11 second. Current RSS: ~1338M. load average: 0.85 0.95 1.01 1/284 456
1528# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb. Expected to take 3.47 seconds.
1529Gitlab::BackgroundMigration::BatchingStrategies::BaseStrategy#next_batch
1530 #next_batch
1531 raises an error if not overridden by a subclass
1532# [RSpecRunTime] RSpec elapsed time: 26 minutes 3.31 seconds. Current RSS: ~1339M. load average: 0.85 0.95 1.01 1/284 457
1533# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb. It took 10.65 seconds. Expected to take 3.47 seconds.
1534# [RSpecRunTime] RSpec elapsed time: 26 minutes 10.81 seconds. Current RSS: ~1327M. load average: 0.87 0.95 1.01 1/284 458
1535# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/remove_backfilled_job_artifacts_expire_at_batching_strategy_spec.rb. Expected to take 3.35 seconds.
1536Gitlab::BackgroundMigration::BatchingStrategies::RemoveBackfilledJobArtifactsExpireAtBatchingStrategy
1537 is expected to be < Gitlab::BackgroundMigration::BatchingStrategies::PrimaryKeyBatchingStrategy
1538# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/remove_backfilled_job_artifacts_expire_at_batching_strategy_spec.rb. It took 9.24 seconds. Expected to take 3.35 seconds.
1539# [RSpecRunTime] RSpec elapsed time: 26 minutes 20.1 seconds. Current RSS: ~1359M. load average: 0.89 0.95 1.01 1/284 459
1540# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/base_job_spec.rb. Expected to take 3.29 seconds.
1541Gitlab::BackgroundMigration::BaseJob#perform
1542 #perform
1543 raises an error if not overridden by a subclass
1544# [RSpecRunTime] RSpec elapsed time: 26 minutes 23.17 seconds. Current RSS: ~1359M. load average: 0.89 0.95 1.01 1/284 460
1545# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/base_job_spec.rb. It took 9.52 seconds. Expected to take 3.29 seconds.
1546# [RSpecRunTime] RSpec elapsed time: 26 minutes 29.66 seconds. Current RSS: ~1352M. load average: 0.90 0.95 1.01 1/284 461
1547auto_explain log contains 950 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-4-5.338.main.ndjson.gz
1548took 19.987576446
1549auto_explain log contains 950 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-4-5.338.ci.ndjson.gz
1550took 17.880782725
1551[TEST PROF INFO] EventProf results for sql.active_record
1552Total time: 18:50.372 of 26:24.150 (71.36%)
1553Total events: 751623
1554Top 5 slowest suites (by time):
1555Gitlab::Backg...illTopicsTitle (./spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb:5) – 02:07.899 (69056 / 1) of 02:45.275 (77.39%)
1556Gitlab::Backg...InvalidMembers (./spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb:6) – 02:06.290 (73620 / 3) of 02:51.199 (73.77%)
1557Gitlab::Backg...slVerification (./spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb:5) – 02:06.018 (73278 / 3) of 02:46.124 (75.86%)
1558Gitlab::Backg...phanedProjects (./spec/lib/gitlab/background_migration/nullify_creator_id_column_of_orphaned_projects_spec.rb:5) – 02:04.885 (69084 / 1) of 02:41.617 (77.27%)
1559Gitlab::Backg...thNilExpiresAt (./spec/lib/gitlab/background_migration/cleanup_personal_access_tokens_with_nil_expires_at_spec.rb:5) – 01:40.102 (56686 / 1) of 02:09.701 (77.18%)
1560Knapsack report was generated. Preview:
1561{
1562 "spec/lib/gitlab/background_migration/job_coordinator_spec.rb": 97.28614984999967,
1563 "spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb": 84.43790616600018,
1564 "spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb": 77.99033253099878,
1565 "spec/lib/gitlab/background_migration/nullify_creator_id_column_of_orphaned_projects_spec.rb": 73.53529999900093,
1566 "spec/lib/gitlab/background_migration/backfill_topics_title_spec.rb": 73.81637723899985,
1567 "spec/lib/gitlab/background_migration/reset_too_many_tags_skipped_registry_imports_spec.rb": 77.54100776400082,
1568 "spec/lib/gitlab/background_migration/cleanup_personal_access_tokens_with_nil_expires_at_spec.rb": 56.39629830500053,
1569 "spec/lib/gitlab/background_migration/backfill_code_suggestions_namespace_settings_spec.rb": 55.98639595699933,
1570 "spec/lib/gitlab/background_migration/backfill_missing_ci_cd_settings_spec.rb": 45.82289607800158,
1571 "spec/lib/gitlab/background_migration/migrate_links_for_vulnerability_findings_spec.rb": 36.692167361999964,
1572 "spec/lib/gitlab/background_migration/backfill_users_with_defaults_spec.rb": 29.643759222999506,
1573 "spec/lib/gitlab/background_migration/legacy_uploads_migrator_spec.rb": 21.96379378399979,
1574 "spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb": 22.569021247998535,
1575 "spec/lib/gitlab/background_migration/remove_backfilled_job_artifacts_expire_at_spec.rb": 12.388353450000068,
1576 "spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb": 11.781506425999396,
1577 "spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb": 10.456656404998284,
1578 "spec/lib/gitlab/background_migration/delete_invalid_protected_branch_push_access_levels_spec.rb": 10.767172092000692,
1579 "spec/lib/gitlab/background_migration/backfill_default_organization_users_spec.rb": 6.163335749999533,
1580 "spec/lib/gitlab/background_migration/drop_vulnerabilities_without_finding_id_spec.rb": 4.636628607000603,
1581 "spec/lib/gitlab/background_migration/delete_orphaned_operational_vulnerabilities_spec.rb": 3.4381856780000817,
1582 "spec/lib/gitlab/background_migration/prune_stale_project_export_jobs_spec.rb": 3.379821586999242,
1583 "spec/lib/gitlab/background_migration/batching_strategies/base_strategy_spec.rb": 3.284009884000625,
1584 "spec/lib/gitlab/background_migration/batching_strategies/remove_backfilled_job_artifacts_expire_at_batching_strategy_spec.rb": 3.013799320999169,
1585 "spec/lib/gitlab/background_migration/base_job_spec.rb": 3.1640044050000142
1586}
1587Knapsack global time execution for tests: 13m 46s
1588Finished in 27 minutes 8 seconds (files took 55.09 seconds to load)
158974 examples, 0 failures
1590Randomized with seed 20115
1591[TEST PROF INFO] Time spent in factories: 00:09.847 (0.6% of total time)
1592RSpec exited with 0.
1593No examples to retry, congrats!
1594 Running after_script 00:05
1595Running after script...
1596$ echo -e "\e[0Ksection_start:`date +%s`:report_results_section[collapsed=true]\r\e[0KReport results"
1597 Report results 00:04
1607$ tooling/bin/push_job_metrics || true
1608[job-metrics] Pushing job metrics file for the CI/CD job.
1609[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
1610 Saving cache for successful job 00:01
1611Not uploading cache ruby-gems-debian-bookworm-ruby-3.1-17 due to policy
1612 Uploading artifacts for successful job 00:05
1613Uploading artifacts...
1614auto_explain/: found 3 matching artifact files and directories
1615coverage/: found 5 matching artifact files and directories
1616crystalball/: found 2 matching artifact files and directories
1617WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1618knapsack/: found 4 matching artifact files and directories
1619rspec/: found 16 matching artifact files and directories
1620WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1621log/*.log: found 13 matching artifact files and directories
1622WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6311411106/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
1623WARNING: Retrying... context=artifacts-uploader error=request redirected
1624Uploading artifacts as "archive" to coordinator... 201 Created id=6311411106 responseStatus=201 Created token=glcbt-65
1625Uploading artifacts...
1626rspec/rspec-*.xml: found 1 matching artifact files and directories
1627WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6311411106/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
1628WARNING: Retrying... context=artifacts-uploader error=request redirected
1629Uploading artifacts as "junit" to coordinator... 201 Created id=6311411106 responseStatus=201 Created token=glcbt-65
1630 Cleaning up project directory and file based variables 00:00
1631Job succeeded