rspec migration pg14 15/15

Passed Started 9 months ago by
1Running with gitlab-runner 17.0.0~pre.88.g761ae5dd (761ae5dd)
2  on green-2.private.runners-manager.gitlab.com/gitlab.com/gitlab-org GaSD-S1F, system ID: s_5651e5b5643b
3  feature flags: FF_NETWORK_PER_BUILD:true
4Resolving secrets
 5  Preparing the "docker+machine" executor  
  01:03
6Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.21-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
7Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
8Authenticating with credentials from job payload (GitLab Registry)
9Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
10Using docker image sha256:82f132c22567f8ce17cc132c14b2f9aa3eaf9bb5424d91c2d966912433f0257d for registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:c55e1364ee4327b244a9cfa1750f19feea14fc774eaf792b725967d146eb45f5 ...
11WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
12WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
13Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
14Authenticating with credentials from job payload (GitLab Registry)
15Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
16Using docker image sha256:5c5ba5b83d6c60cb0b225bd670b7a43be8c238cc72347d24af57e5027c3648f3 for registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:46aceab84c42d0e819c8e7940f2f98ce9e184785cd7b22d95872024a35f52407 ...
17Starting service redis:6.2-alpine ...
18Pulling docker image redis:6.2-alpine ...
19Using docker image sha256:0fc0b666ef9eb249e61edd4e2ec434a328e98117079727c5e7cf6dc9a00d7a94 for redis:6.2-alpine with digest redis@sha256:e31ca60b18f7e9b78b573d156702471d4eda038803c0b8e6f01559f350031e93 ...
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.21-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
23Using docker image sha256:b7f013d6c497fdb34b7c3895a9ae4f7df0abc05338ad5cb26e19d48ef6d6c4af for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.21-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.21-rust-1.73-node-20.12-postgresql-14@sha256:a86b6a5e81e97ddf8d792c86400f1d3960104b1dcecc6ef34d7fc5b154e65a4b ...
 24  Preparing environment  
  00:00
25Running on runner-gasd-s1f-project-278964-concurrent-0 via runner-gasd-s1f-private-1716560931-889bdaf5...
 26  Getting source from Git repository  
  00:01
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
 30  Restoring cache  
  00:20
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:42
35Downloading artifacts for clone-gitlab-repo (6934017441)...
36Downloading artifacts from coordinator... ok        host=storage.googleapis.com id=6934017441 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 (6934017525)...
40Downloading artifacts from coordinator... ok        host=storage.googleapis.com id=6934017525 responseStatus=200 OK token=glcbt-65
41Downloading artifacts for retrieve-tests-metadata (6934017590)...
42Downloading artifacts from coordinator... ok        host=storage.googleapis.com id=6934017590 responseStatus=200 OK token=glcbt-65
43Downloading artifacts for setup-test-env (6934017562)...
44Downloading artifacts from coordinator... ok        host=storage.googleapis.com id=6934017562 responseStatus=200 OK token=glcbt-65
 45  Executing "step_script" stage of the job script 
46Using docker image sha256:b7f013d6c497fdb34b7c3895a9ae4f7df0abc05338ad5cb26e19d48ef6d6c4af for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.21-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.patched-golang-1.21-rust-1.73-node-20.12-postgresql-14@sha256:a86b6a5e81e97ddf8d792c86400f1d3960104b1dcecc6ef34d7fc5b154e65a4b ...
47$ echo $FOSS_ONLY
48$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
49$ export GOPATH=$CI_PROJECT_DIR/.go
50$ mkdir -p $GOPATH
51$ source scripts/utils.sh
52$ source scripts/prepare_build.sh
 53  Installing gems  
  00:23
753Using decomposed database config (config/database.yml.decomposed-postgresql)
754Geo DB won't be set up.
755Embedding DB won't be set up.
 756  Setting up DBs  
  01:05
767$ source ./scripts/rspec_helpers.sh
768$ run_timed_command "gem install knapsack --no-document"
769$ gem install knapsack --no-document
770Successfully installed knapsack-4.0.0
7711 gem installed
772==> 'gem install knapsack --no-document' succeeded in 1 seconds.
773$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
 774  Spawning Gitaly  
  00:03
778$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
779$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
780$ tooling/bin/create_job_metrics_file || true
781[job-metrics] Creating the job metrics file for the CI/CD job.
782$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
 783  RSpec  
  28:04
784[15:43:50] Starting rspec_parallelized_job
785RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
786KNAPSACK_GENERATE_REPORT: true
787FLAKY_RSPEC_GENERATE_REPORT: true
788KNAPSACK_TEST_FILE_PATTERN: spec/{migrations}{,/**/}*_spec.rb
789KNAPSACK_LOG_LEVEL: debug
790KNAPSACK_REPORT_PATH: knapsack/rspec_migration_pg14_15_15_278964_report.json
791FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
792FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_migration_pg14_15_15_278964_report.json
793NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_migration_pg14_15_15_278964_report.json
794RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-6934018115.txt
795CRYSTALBALL: 
796RSPEC_TESTS_MAPPING_ENABLED: 
797RSPEC_TESTS_FILTER_FILE: 
798Shell set options (set -o) enabled:
799braceexpand    	on
800hashall        	on
801interactive-comments	on
802pipefail       	on
803Knapsack report generator started!
804warning: parser/current is loading parser/ruby31, which recognizes 3.1.4-compliant syntax, but you are running 3.1.5.
805Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
806Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
807# [RSpecRunTime] Starting RSpec timer...
808[TEST PROF INFO] EventProf enabled (sql.active_record)
809unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
810unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
811Test environment set up in 3.501991208 seconds
812# [RSpecRunTime] Starting example group spec/migrations/20230810123044_swap_snippet_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb. Expected to take 2 minutes 52.12 seconds.
813SwapSnippetUserMentionsNoteIdToBigintForSelfHosts
814  #up
815    when GitLab.com, dev, or test
816      behaves like column `note_id_convert_to_bigint` is already dropped
817        does not swaps the columns
818    when self-managed instance with the `note_id_convert_to_bigint` column already dropped
819      behaves like column `note_id_convert_to_bigint` is already dropped
820        does not swaps the columns
821# [RSpecRunTime] RSpec elapsed time: 2 minutes 7.62 seconds. Current RSS: ~1266M. load average: 0.99 1.33 1.28 1/291 411
822    when self-managed instance columns already swapped
823      does not swaps the columns
824# [RSpecRunTime] RSpec elapsed time: 2 minutes 25.61 seconds. Current RSS: ~1228M. load average: 0.91 1.29 1.27 1/291 412
825    when self-managed instance
826      swaps the columns
827# [RSpecRunTime] RSpec elapsed time: 2 minutes 58.58 seconds. Current RSS: ~1229M. load average: 0.95 1.26 1.26 1/291 413
828INFO:  analyzing "public.p_ci_runner_machine_builds" inheritance tree
829INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
830INFO:  "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
831INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
832INFO:  "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
833INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
834INFO:  "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
835INFO:  analyzing "public.p_ci_job_annotations" inheritance tree
836INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
837INFO:  "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
838INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
839INFO:  "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
840INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
841INFO:  "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
842INFO:  analyzing "public.p_ci_builds_metadata" inheritance tree
843INFO:  analyzing "public.ci_builds_metadata"
844INFO:  "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
845INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
846INFO:  "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
847INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
848INFO:  "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
849INFO:  analyzing "public.p_ci_builds" inheritance tree
850INFO:  analyzing "public.ci_builds"
851INFO:  "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
852INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_101"
853INFO:  "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
854INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_102"
855INFO:  "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
856I, [2024-05-24T15:48:31.021164 #344]  INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
857I, [2024-05-24T15:48:49.948858 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
858INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
859INFO:  analyzing "public.ci_pipeline_variables"
860INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
861I, [2024-05-24T15:48:51.536625 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
862I, [2024-05-24T15:48:51.537684 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
863I, [2024-05-24T15:48:51.538372 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
864INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
865INFO:  analyzing "public.ci_pipeline_variables"
866INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
867INFO:  analyzing "public.p_ci_job_artifacts" inheritance tree
868INFO:  analyzing "public.ci_job_artifacts"
869INFO:  "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
870I, [2024-05-24T15:48:57.200694 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
871I, [2024-05-24T15:48:57.201895 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
872I, [2024-05-24T15:48:57.203322 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
873INFO:  analyzing "public.p_ci_stages" inheritance tree
874INFO:  analyzing "public.ci_stages"
875INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
876I, [2024-05-24T15:49:00.335787 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
877I, [2024-05-24T15:49:00.336875 #344]  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-05-24T15:49:00.337626 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
879I, [2024-05-24T15:49:01.457251 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
880I, [2024-05-24T15:49:07.545433 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
881# [RSpecRunTime] Finishing example group spec/migrations/20230810123044_swap_snippet_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb. It took 3 minutes 54.0 seconds. Expected to take 2 minutes 52.12 seconds.
882# [RSpecRunTime] RSpec elapsed time: 4 minutes 0.61 second. Current RSS: ~1163M. load average: 0.92 1.19 1.23 2/292 414
883# [RSpecRunTime] Starting example group spec/migrations/20230810113227_swap_note_diff_files_note_id_to_bigint_for_self_hosts_spec.rb. Expected to take 2 minutes 49.63 seconds.
884SwapNoteDiffFilesNoteIdToBigintForSelfHosts
885  #up
886    when GitLab.com, dev, or test
887      does not swap the columns
888# [RSpecRunTime] RSpec elapsed time: 5 minutes 20.91 seconds. Current RSS: ~1210M. load average: 0.95 1.13 1.20 1/289 415
889    when self-managed instance with the columns already swapped
890main: == [advisory_lock_connection] object_id: 50781900, pg_backend_pid: 187
891main: == 20230810113227 SwapNoteDiffFilesNoteIdToBigintForSelfHosts: migrating ======
892main: -- column_exists?("note_diff_files", "diff_note_id_convert_to_bigint")
893main:    -> 0.0044s
894main: -- columns("note_diff_files")
895main:    -> 0.0039s
896main: == 20230810113227 SwapNoteDiffFilesNoteIdToBigintForSelfHosts: migrated (0.0191s) 
897main: == [advisory_lock_connection] object_id: 50781900, pg_backend_pid: 187
898      does not swap the columns
899# [RSpecRunTime] RSpec elapsed time: 5 minutes 38.01 seconds. Current RSS: ~1218M. load average: 0.96 1.12 1.20 1/290 416
900    when self-managed instance with the `diff_note_id_convert_to_bigint` column already dropped
901      does not swap the columns
902# [RSpecRunTime] RSpec elapsed time: 6 minutes 10.26 seconds. Current RSS: ~1223M. load average: 0.90 1.09 1.18 1/290 417
903    when self-managed instance
904      swaps the columns
905# [RSpecRunTime] RSpec elapsed time: 6 minutes 42.0 seconds. Current RSS: ~1221M. load average: 0.86 1.07 1.17 1/291 418
906INFO:  analyzing "public.p_ci_runner_machine_builds" inheritance tree
907INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
908INFO:  "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
909INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
910INFO:  "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
911INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
912INFO:  "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
913INFO:  analyzing "public.p_ci_job_annotations" inheritance tree
914INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
915INFO:  "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
916INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
917INFO:  "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
918INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
919INFO:  "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
920INFO:  analyzing "public.p_ci_builds_metadata" inheritance tree
921INFO:  analyzing "public.ci_builds_metadata"
922INFO:  "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
923INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
924INFO:  "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
925INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
926INFO:  "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
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
930INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_101"
931INFO:  "ci_builds_101": 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_builds_102"
933INFO:  "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
934I, [2024-05-24T15:52:14.245036 #344]  INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
935I, [2024-05-24T15:52:34.253608 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
936INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
937INFO:  analyzing "public.ci_pipeline_variables"
938INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
939I, [2024-05-24T15:52:35.905179 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
940I, [2024-05-24T15:52:35.906292 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
941I, [2024-05-24T15:52:35.907081 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
942INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
943INFO:  analyzing "public.ci_pipeline_variables"
944INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
945INFO:  analyzing "public.p_ci_job_artifacts" inheritance tree
946INFO:  analyzing "public.ci_job_artifacts"
947INFO:  "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
948I, [2024-05-24T15:52:42.014729 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
949I, [2024-05-24T15:52:42.015971 #344]  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-05-24T15:52:42.017432 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
951INFO:  analyzing "public.p_ci_stages" inheritance tree
952INFO:  analyzing "public.ci_stages"
953INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
954I, [2024-05-24T15:52:45.672323 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
955I, [2024-05-24T15:52:45.673956 #344]  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-05-24T15:52:45.674764 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
957I, [2024-05-24T15:52:47.005884 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
958I, [2024-05-24T15:52:53.808167 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
959# [RSpecRunTime] Finishing example group spec/migrations/20230810113227_swap_note_diff_files_note_id_to_bigint_for_self_hosts_spec.rb. It took 3 minutes 47.29 seconds. Expected to take 2 minutes 49.63 seconds.
960# [RSpecRunTime] RSpec elapsed time: 7 minutes 47.95 seconds. Current RSS: ~1155M. load average: 0.83 1.01 1.14 1/291 419
961# [RSpecRunTime] Starting example group spec/migrations/20230724071541_queue_backfill_default_branch_protection_namespace_setting_spec.rb. Expected to take 1 minute 41.25 seconds.
962QueueBackfillDefaultBranchProtectionNamespaceSetting
963main: == [advisory_lock_connection] object_id: 86064920, pg_backend_pid: 213
964main: == 20230724071541 QueueBackfillDefaultBranchProtectionNamespaceSetting: migrating 
965main: == 20230724071541 QueueBackfillDefaultBranchProtectionNamespaceSetting: migrated (0.0546s) 
966main: == [advisory_lock_connection] object_id: 86064920, pg_backend_pid: 213
967  schedules a new batched migration
968INFO:  analyzing "public.p_ci_runner_machine_builds" inheritance tree
969INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
970INFO:  "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
971INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
972INFO:  "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
973INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
974INFO:  "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
975INFO:  analyzing "public.p_ci_job_annotations" inheritance tree
976INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
977INFO:  "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
978INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
979INFO:  "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
980INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
981INFO:  "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
982INFO:  analyzing "public.p_ci_builds_metadata" inheritance tree
983INFO:  analyzing "public.ci_builds_metadata"
984INFO:  "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
985INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
986INFO:  "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
987INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
988INFO:  "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
989INFO:  analyzing "public.p_ci_builds" inheritance tree
990INFO:  analyzing "public.ci_builds"
991INFO:  "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
992INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_101"
993INFO:  "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
994INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_102"
995INFO:  "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
996I, [2024-05-24T15:55:09.767364 #344]  INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
997I, [2024-05-24T15:55:30.273540 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
998INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
999INFO:  analyzing "public.ci_pipeline_variables"
1000INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1001I, [2024-05-24T15:55:31.984038 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1002I, [2024-05-24T15:55:31.985175 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1003I, [2024-05-24T15:55:31.985968 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1004INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1005INFO:  analyzing "public.ci_pipeline_variables"
1006INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1007INFO:  analyzing "public.p_ci_job_artifacts" inheritance tree
1008INFO:  analyzing "public.ci_job_artifacts"
1009INFO:  "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1010I, [2024-05-24T15:55:38.249260 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1011I, [2024-05-24T15:55:38.250481 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1012I, [2024-05-24T15:55:38.251489 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1013INFO:  analyzing "public.p_ci_stages" inheritance tree
1014INFO:  analyzing "public.ci_stages"
1015INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1016I, [2024-05-24T15:55:41.686396 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1017I, [2024-05-24T15:55:41.687538 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1018I, [2024-05-24T15:55:41.688331 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1019I, [2024-05-24T15:55:42.951226 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1020I, [2024-05-24T15:55:49.254402 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1021# [RSpecRunTime] Finishing example group spec/migrations/20230724071541_queue_backfill_default_branch_protection_namespace_setting_spec.rb. It took 2 minutes 56.01 seconds. Expected to take 1 minute 41.25 seconds.
1022# [RSpecRunTime] RSpec elapsed time: 10 minutes 44.01 seconds. Current RSS: ~1171M. load average: 0.88 0.97 1.09 1/291 420
1023# [RSpecRunTime] Starting example group spec/migrations/20231019003052_swap_columns_for_ci_pipelines_pipeline_id_bigint_v2_spec.rb. Expected to take 1 minute 31.66 seconds.
1024SwapColumnsForCiPipelinesPipelineIdBigintV2
1025  when auto_canceled_by_id sql type is integer
1026    behaves like swap conversion columns
1027main: == [advisory_lock_connection] object_id: 118951200, pg_backend_pid: 230
1028main: == 20231019003052 SwapColumnsForCiPipelinesPipelineIdBigintV2: migrating ======
1029main: -- columns(:ci_pipelines)
1030main:    -> 0.0042s
1031main: -- execute("LOCK TABLE ci_pipelines IN ACCESS EXCLUSIVE MODE")
1032main:    -> 0.0009s
1033main: -- clear_cache!(nil)
1034main:    -> 0.0000s
1035main: -- quote_table_name(:ci_pipelines)
1036main:    -> 0.0000s
1037main: -- quote_column_name(:auto_canceled_by_id)
1038main:    -> 0.0000s
1039main: -- quote_column_name(:temp_name_for_renaming)
1040main:    -> 0.0000s
1041main: -- execute("ALTER TABLE \"ci_pipelines\"\n  RENAME COLUMN \"auto_canceled_by_id\" TO \"temp_name_for_renaming\"\n")
1042main:    -> 0.0009s
1043main: -- clear_cache!(nil)
1044main:    -> 0.0000s
1045main: -- quote_table_name(:ci_pipelines)
1046main:    -> 0.0000s
1047main: -- quote_column_name(:auto_canceled_by_id_convert_to_bigint)
1048main:    -> 0.0000s
1049main: -- quote_column_name(:auto_canceled_by_id)
1050main:    -> 0.0000s
1051main: -- execute("ALTER TABLE \"ci_pipelines\"\n  RENAME COLUMN \"auto_canceled_by_id_convert_to_bigint\" TO \"auto_canceled_by_id\"\n")
1052main:    -> 0.0010s
1053main: -- clear_cache!(nil)
1054main:    -> 0.0000s
1055main: -- quote_table_name(:ci_pipelines)
1056main:    -> 0.0000s
1057main: -- quote_column_name(:temp_name_for_renaming)
1058main:    -> 0.0000s
1059main: -- quote_column_name(:auto_canceled_by_id_convert_to_bigint)
1060main:    -> 0.0000s
1061main: -- execute("ALTER TABLE \"ci_pipelines\"\n  RENAME COLUMN \"temp_name_for_renaming\" TO \"auto_canceled_by_id_convert_to_bigint\"\n")
1062main:    -> 0.0009s
1063main: -- quote_table_name(:trigger_1bd97da9c1a4)
1064main:    -> 0.0000s
1065main: -- execute("ALTER FUNCTION \"trigger_1bd97da9c1a4\" RESET ALL")
1066main:    -> 0.0008s
1067main: -- quote_table_name(:ci_pipelines)
1068main:    -> 0.0000s
1069main: -- quote_column_name(:fk_262d4c2d19)
1070main:    -> 0.0000s
1071main: -- quote_column_name(:temp_name_for_renaming)
1072main:    -> 0.0000s
1073main: -- execute("ALTER TABLE \"ci_pipelines\"\nRENAME CONSTRAINT \"fk_262d4c2d19\" TO \"temp_name_for_renaming\"\n")
1074main:    -> 0.0009s
1075main: -- quote_table_name(:ci_pipelines)
1076main:    -> 0.0000s
1077main: -- quote_column_name(:fk_67e4288f3a)
1078main:    -> 0.0000s
1079main: -- quote_column_name(:fk_262d4c2d19)
1080main:    -> 0.0000s
1081main: -- execute("ALTER TABLE \"ci_pipelines\"\nRENAME CONSTRAINT \"fk_67e4288f3a\" TO \"fk_262d4c2d19\"\n")
1082main:    -> 0.0009s
1083main: -- quote_table_name(:ci_pipelines)
1084main:    -> 0.0000s
1085main: -- quote_column_name(:temp_name_for_renaming)
1086main:    -> 0.0000s
1087main: -- quote_column_name(:fk_67e4288f3a)
1088main:    -> 0.0000s
1089main: -- execute("ALTER TABLE \"ci_pipelines\"\nRENAME CONSTRAINT \"temp_name_for_renaming\" TO \"fk_67e4288f3a\"\n")
1090main:    -> 0.0009s
1091main: -- quote_table_name("index_ci_pipelines_on_auto_canceled_by_id")
1092main:    -> 0.0000s
1093main: -- quote_table_name("temp_57ca550b13")
1094main:    -> 0.0000s
1095main: -- execute("ALTER INDEX \"index_ci_pipelines_on_auto_canceled_by_id\" RENAME TO \"temp_57ca550b13\"")
1096main:    -> 0.0010s
1097main: -- quote_table_name("index_ci_pipelines_on_auto_canceled_by_id_bigint")
1098main:    -> 0.0000s
1099main: -- quote_table_name(:index_ci_pipelines_on_auto_canceled_by_id)
1100main:    -> 0.0000s
1101main: -- execute("ALTER INDEX \"index_ci_pipelines_on_auto_canceled_by_id_bigint\" RENAME TO \"index_ci_pipelines_on_auto_canceled_by_id\"")
1102main:    -> 0.0009s
1103main: -- quote_table_name("temp_57ca550b13")
1104main:    -> 0.0000s
1105main: -- quote_table_name(:index_ci_pipelines_on_auto_canceled_by_id_bigint)
1106main:    -> 0.0000s
1107main: -- execute("ALTER INDEX \"temp_57ca550b13\" RENAME TO \"index_ci_pipelines_on_auto_canceled_by_id_bigint\"")
1108main:    -> 0.0008s
1109main: == 20231019003052 SwapColumnsForCiPipelinesPipelineIdBigintV2: migrated (0.0378s) 
1110main: == [advisory_lock_connection] object_id: 118951200, pg_backend_pid: 230
1111      correctly swaps conversion columns
1112# [RSpecRunTime] RSpec elapsed time: 11 minutes 54.86 seconds. Current RSS: ~1226M. load average: 0.88 0.94 1.07 1/290 421
1113  when auto_canceled_by_id sql type is bigint
1114main: == [advisory_lock_connection] object_id: 119656040, pg_backend_pid: 235
1115main: == 20231019003052 SwapColumnsForCiPipelinesPipelineIdBigintV2: migrating ======
1116main: -- columns(:ci_pipelines)
1117main:    -> 0.0048s
1118main: == 20231019003052 SwapColumnsForCiPipelinesPipelineIdBigintV2: migrated (0.0231s) 
1119main: == [advisory_lock_connection] object_id: 119656040, pg_backend_pid: 235
1120    does nothing
1121# [RSpecRunTime] RSpec elapsed time: 12 minutes 9.98 seconds. Current RSS: ~1216M. load average: 0.91 0.94 1.07 1/290 422
1122I, [2024-05-24T15:57:53.270778 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1123INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1124INFO:  analyzing "public.ci_pipeline_variables"
1125INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1126I, [2024-05-24T15:57:55.055689 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1127I, [2024-05-24T15:57:55.058011 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1128I, [2024-05-24T15:57:55.058758 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1129INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1130INFO:  analyzing "public.ci_pipeline_variables"
1131INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1132INFO:  analyzing "public.p_ci_job_artifacts" inheritance tree
1133INFO:  analyzing "public.ci_job_artifacts"
1134INFO:  "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1135I, [2024-05-24T15:58:01.169763 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1136I, [2024-05-24T15:58:01.171441 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1137I, [2024-05-24T15:58:01.172232 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1138INFO:  analyzing "public.p_ci_stages" inheritance tree
1139INFO:  analyzing "public.ci_stages"
1140INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1141I, [2024-05-24T15:58:04.661230 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1142I, [2024-05-24T15:58:04.662269 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1143I, [2024-05-24T15:58:04.663007 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1144I, [2024-05-24T15:58:05.891621 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1145I, [2024-05-24T15:58:12.503348 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1146# [RSpecRunTime] Finishing example group spec/migrations/20231019003052_swap_columns_for_ci_pipelines_pipeline_id_bigint_v2_spec.rb. It took 2 minutes 21.93 seconds. Expected to take 1 minute 31.66 seconds.
1147# [RSpecRunTime] RSpec elapsed time: 13 minutes 5.99 seconds. Current RSS: ~1166M. load average: 0.81 0.91 1.05 1/290 423
1148# [RSpecRunTime] Starting example group spec/migrations/20230830121830_queue_update_users_set_external_if_service_account_spec.rb. Expected to take 1 minute 23.76 seconds.
1149QueueUpdateUsersSetExternalIfServiceAccount
1150main: == [advisory_lock_connection] object_id: 150529660, pg_backend_pid: 250
1151main: == 20230830121830 QueueUpdateUsersSetExternalIfServiceAccount: migrating ======
1152main: == 20230830121830 QueueUpdateUsersSetExternalIfServiceAccount: migrated (0.0551s) 
1153main: == [advisory_lock_connection] object_id: 150529660, pg_backend_pid: 250
1154  schedules a new batched migration
1155INFO:  analyzing "public.p_ci_runner_machine_builds" inheritance tree
1156INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1157INFO:  "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
1158INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1159INFO:  "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
1160INFO:  analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
1161INFO:  "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1162INFO:  analyzing "public.p_ci_job_annotations" inheritance tree
1163INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1164INFO:  "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
1165INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
1166INFO:  "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
1167INFO:  analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
1168INFO:  "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1169INFO:  analyzing "public.p_ci_builds_metadata" inheritance tree
1170INFO:  analyzing "public.ci_builds_metadata"
1171INFO:  "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1172INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1173INFO:  "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
1174INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
1175INFO:  "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1176INFO:  analyzing "public.p_ci_builds" inheritance tree
1177INFO:  analyzing "public.ci_builds"
1178INFO:  "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1179INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_101"
1180INFO:  "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1181INFO:  analyzing "gitlab_partitions_dynamic.ci_builds_102"
1182INFO:  "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1183I, [2024-05-24T15:59:55.799399 #344]  INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1184I, [2024-05-24T16:00:16.581078 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1185INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1186INFO:  analyzing "public.ci_pipeline_variables"
1187INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1188I, [2024-05-24T16:00:18.308303 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1189I, [2024-05-24T16:00:18.309369 #344]  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-05-24T16:00:18.310095 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1191INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1192INFO:  analyzing "public.ci_pipeline_variables"
1193INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1194INFO:  analyzing "public.p_ci_job_artifacts" inheritance tree
1195INFO:  analyzing "public.ci_job_artifacts"
1196INFO:  "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1197I, [2024-05-24T16:00:24.283960 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1198I, [2024-05-24T16:00:24.285026 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1199I, [2024-05-24T16:00:24.285764 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1200INFO:  analyzing "public.p_ci_stages" inheritance tree
1201INFO:  analyzing "public.ci_stages"
1202INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1203I, [2024-05-24T16:00:27.672185 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1204I, [2024-05-24T16:00:27.673568 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1205I, [2024-05-24T16:00:27.674374 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1206I, [2024-05-24T16:00:28.858677 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1207I, [2024-05-24T16:00:35.335718 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1208# [RSpecRunTime] Finishing example group spec/migrations/20230830121830_queue_update_users_set_external_if_service_account_spec.rb. It took 2 minutes 23.37 seconds. Expected to take 1 minute 23.76 seconds.
1209# [RSpecRunTime] RSpec elapsed time: 15 minutes 29.4 seconds. Current RSS: ~1161M. load average: 0.90 0.91 1.02 1/290 424
1210# [RSpecRunTime] Starting example group spec/migrations/20231003045342_migrate_sidekiq_namespaced_jobs_spec.rb. Expected to take 1 minute 22.06 seconds.
1211MigrateSidekiqNamespacedJobs
1212main: == [advisory_lock_connection] object_id: 182554900, pg_backend_pid: 267
1213main: == 20231003045342 MigrateSidekiqNamespacedJobs: migrating =====================
1214main: == 20231003045342 MigrateSidekiqNamespacedJobs: migrated (0.7198s) ============
1215main: == [advisory_lock_connection] object_id: 182554900, pg_backend_pid: 267
1216  does not creates default organization if needed
1217I, [2024-05-24T16:02:33.288297 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1218INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1219INFO:  analyzing "public.ci_pipeline_variables"
1220INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1221I, [2024-05-24T16:02:35.055171 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1222I, [2024-05-24T16:02:35.056239 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1223I, [2024-05-24T16:02:35.057112 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1224INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1225INFO:  analyzing "public.ci_pipeline_variables"
1226INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1227INFO:  analyzing "public.p_ci_job_artifacts" inheritance tree
1228INFO:  analyzing "public.ci_job_artifacts"
1229INFO:  "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1230I, [2024-05-24T16:02:41.262619 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1231I, [2024-05-24T16:02:41.263643 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1232I, [2024-05-24T16:02:41.264382 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1233INFO:  analyzing "public.p_ci_stages" inheritance tree
1234INFO:  analyzing "public.ci_stages"
1235INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1236I, [2024-05-24T16:02:44.772266 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1237I, [2024-05-24T16:02:44.773436 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1238I, [2024-05-24T16:02:44.774576 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1239I, [2024-05-24T16:02:46.070688 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1240I, [2024-05-24T16:02:52.607316 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1241# [RSpecRunTime] Finishing example group spec/migrations/20231003045342_migrate_sidekiq_namespaced_jobs_spec.rb. It took 2 minutes 16.95 seconds. Expected to take 1 minute 22.06 seconds.
1242# [RSpecRunTime] RSpec elapsed time: 17 minutes 46.39 seconds. Current RSS: ~1171M. load average: 0.95 0.91 1.00 1/291 425
1243# [RSpecRunTime] Starting example group spec/migrations/20240108121335_copy_internal_ids_for_epics_and_issues_usage_on_groups_spec.rb. Expected to take 57.81 seconds.
1244CopyInternalIdsForEpicsAndIssuesUsageOnGroups
1245  #on_insert
1246main: == [advisory_lock_connection] object_id: 210293960, pg_backend_pid: 283
1247main: == 20240108121335 CopyInternalIdsForEpicsAndIssuesUsageOnGroups: migrating ====
1248main: -- execute("CREATE OR REPLACE FUNCTION insert_or_update_internal_ids_usage()\n  RETURNS trigger\n  LANGUAGE plpgsql\nAS $$\n  DECLARE\n    namespace_type varchar;\n    copy_usage smallint;\n  BEGIN\n    IF (NEW.usage = 0) THEN\n      copy_usage = 4;\n\n      -- we only care about group level internal_ids so we check namespace type here\n      namespace_type = (SELECT type FROM namespaces WHERE id = NEW.namespace_id);\n      IF (namespace_type <> 'Group') THEN\n        RETURN NULL;\n      END IF;\n    ELSIF (NEW.usage = 4) THEN\n      copy_usage = 0;\n    ELSE\n      RETURN NULL;\n    END IF;\n\n    -- if value is the same there is nothing to update\n    IF (OLD.last_value = NEW.last_value AND (TG_OP = 'INSERT' OR TG_OP = 'UPDATE')) THEN\n      RETURN NULL;\n    END IF;\n\n    INSERT INTO internal_ids (usage, last_value, namespace_id)\n    VALUES (copy_usage, NEW.last_value, NEW.namespace_id)\n    ON CONFLICT (usage, namespace_id) WHERE namespace_id IS NOT NULL\n    DO UPDATE SET last_value = NEW.last_value;\n\n    RETURN NULL;\n  END\n$$\n")
1249main:    -> 0.0018s
1250main: -- execute("CREATE TRIGGER trigger_copy_usage_on_internal_ids_on_insert\nAFTER INSERT ON internal_ids\nFOR EACH ROW\nWHEN (((NEW.usage = 0) OR (NEW.usage = 4)) AND NEW.namespace_id IS NOT NULL)\nEXECUTE FUNCTION insert_or_update_internal_ids_usage();\n")
1251main:    -> 0.0014s
1252main: -- execute("CREATE TRIGGER trigger_copy_usage_on_internal_ids_on_update\nAFTER UPDATE ON internal_ids\nFOR EACH ROW\nWHEN (((NEW.usage = 0) OR (NEW.usage = 4)) AND NEW.namespace_id IS NOT NULL)\nEXECUTE FUNCTION insert_or_update_internal_ids_usage();\n")
1253main:    -> 0.0012s
1254main: == 20240108121335 CopyInternalIdsForEpicsAndIssuesUsageOnGroups: migrated (0.0146s) 
1255main: == [advisory_lock_connection] object_id: 210293960, pg_backend_pid: 283
1256    inserts corresponding usage record between epics and issues
1257# [RSpecRunTime] RSpec elapsed time: 18 minutes 31.27 seconds. Current RSS: ~1192M. load average: 1.07 0.94 1.01 1/291 426
1258  #on_update
1259main: == [advisory_lock_connection] object_id: 211073900, pg_backend_pid: 285
1260main: == 20240108121335 CopyInternalIdsForEpicsAndIssuesUsageOnGroups: migrating ====
1261main: -- execute("CREATE OR REPLACE FUNCTION insert_or_update_internal_ids_usage()\n  RETURNS trigger\n  LANGUAGE plpgsql\nAS $$\n  DECLARE\n    namespace_type varchar;\n    copy_usage smallint;\n  BEGIN\n    IF (NEW.usage = 0) THEN\n      copy_usage = 4;\n\n      -- we only care about group level internal_ids so we check namespace type here\n      namespace_type = (SELECT type FROM namespaces WHERE id = NEW.namespace_id);\n      IF (namespace_type <> 'Group') THEN\n        RETURN NULL;\n      END IF;\n    ELSIF (NEW.usage = 4) THEN\n      copy_usage = 0;\n    ELSE\n      RETURN NULL;\n    END IF;\n\n    -- if value is the same there is nothing to update\n    IF (OLD.last_value = NEW.last_value AND (TG_OP = 'INSERT' OR TG_OP = 'UPDATE')) THEN\n      RETURN NULL;\n    END IF;\n\n    INSERT INTO internal_ids (usage, last_value, namespace_id)\n    VALUES (copy_usage, NEW.last_value, NEW.namespace_id)\n    ON CONFLICT (usage, namespace_id) WHERE namespace_id IS NOT NULL\n    DO UPDATE SET last_value = NEW.last_value;\n\n    RETURN NULL;\n  END\n$$\n")
1262main:    -> 0.0016s
1263main: -- execute("CREATE TRIGGER trigger_copy_usage_on_internal_ids_on_insert\nAFTER INSERT ON internal_ids\nFOR EACH ROW\nWHEN (((NEW.usage = 0) OR (NEW.usage = 4)) AND NEW.namespace_id IS NOT NULL)\nEXECUTE FUNCTION insert_or_update_internal_ids_usage();\n")
1264main:    -> 0.0013s
1265main: -- execute("CREATE TRIGGER trigger_copy_usage_on_internal_ids_on_update\nAFTER UPDATE ON internal_ids\nFOR EACH ROW\nWHEN (((NEW.usage = 0) OR (NEW.usage = 4)) AND NEW.namespace_id IS NOT NULL)\nEXECUTE FUNCTION insert_or_update_internal_ids_usage();\n")
1266main:    -> 0.0012s
1267main: == 20240108121335 CopyInternalIdsForEpicsAndIssuesUsageOnGroups: migrated (0.0147s) 
1268main: == [advisory_lock_connection] object_id: 211073900, pg_backend_pid: 285
1269    updates corresponding usage record between epics and issues
1270# [RSpecRunTime] RSpec elapsed time: 18 minutes 42.26 seconds. Current RSS: ~1194M. load average: 1.06 0.94 1.01 1/291 427
1271I, [2024-05-24T16:04:14.466040 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1272INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1273INFO:  analyzing "public.ci_pipeline_variables"
1274INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1275I, [2024-05-24T16:04:16.346990 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1276I, [2024-05-24T16:04:16.348801 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1277I, [2024-05-24T16:04:16.349611 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1278INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1279INFO:  analyzing "public.ci_pipeline_variables"
1280INFO:  "ci_pipeline_variables": 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_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-05-24T16:04:22.432937 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1285I, [2024-05-24T16:04:22.434430 #344]  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-05-24T16:04:22.435110 #344]  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_stages" inheritance tree
1288INFO:  analyzing "public.ci_stages"
1289INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1290I, [2024-05-24T16:04:25.948177 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1291I, [2024-05-24T16:04:25.949316 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1292I, [2024-05-24T16:04:25.950025 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1293I, [2024-05-24T16:04:27.106804 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1294I, [2024-05-24T16:04:33.367994 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1295# [RSpecRunTime] Finishing example group spec/migrations/20240108121335_copy_internal_ids_for_epics_and_issues_usage_on_groups_spec.rb. It took 1 minute 40.22 seconds. Expected to take 57.81 seconds.
1296# [RSpecRunTime] RSpec elapsed time: 19 minutes 26.67 seconds. Current RSS: ~1167M. load average: 0.93 0.94 1.00 1/291 428
1297# [RSpecRunTime] Starting example group spec/migrations/20231019223224_backfill_catalog_resources_name_and_description_spec.rb. Expected to take 57.64 seconds.
1298BackfillCatalogResourcesNameAndDescription
1299  #up
1300main: == [advisory_lock_connection] object_id: 238517460, pg_backend_pid: 300
1301main: == 20231019223224 BackfillCatalogResourcesNameAndDescription: migrating =======
1302main: -- execute("      UPDATE catalog_resources\n      SET name = projects.name,\n          description = projects.description\n      FROM projects\n      WHERE catalog_resources.project_id = projects.id\n")
1303main:    -> 0.0025s
1304main: == 20231019223224 BackfillCatalogResourcesNameAndDescription: migrated (0.0130s) 
1305main: == [advisory_lock_connection] object_id: 238517460, pg_backend_pid: 300
1306    updates the name and description to match the project
1307# [RSpecRunTime] RSpec elapsed time: 20 minutes 23.79 seconds. Current RSS: ~1200M. load average: 0.73 0.87 0.97 1/291 429
1308I, [2024-05-24T16:06:07.057057 #344]  INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1309INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1310INFO:  analyzing "public.ci_pipeline_variables"
1311INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1312I, [2024-05-24T16:06:08.863726 #344]  INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1313I, [2024-05-24T16:06:08.864925 #344]  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-05-24T16:06:08.865651 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1315INFO:  analyzing "public.p_ci_pipeline_variables" inheritance tree
1316INFO:  analyzing "public.ci_pipeline_variables"
1317INFO:  "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1318INFO:  analyzing "public.p_ci_job_artifacts" inheritance tree
1319INFO:  analyzing "public.ci_job_artifacts"
1320INFO:  "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1321I, [2024-05-24T16:06:15.348735 #344]  INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1322I, [2024-05-24T16:06:15.349843 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1323I, [2024-05-24T16:06:15.350619 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1324INFO:  analyzing "public.p_ci_stages" inheritance tree
1325INFO:  analyzing "public.ci_stages"
1326INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1327I, [2024-05-24T16:06:19.046615 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1328I, [2024-05-24T16:06:19.047742 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1329I, [2024-05-24T16:06:19.048553 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1330I, [2024-05-24T16:06:20.358766 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1331I, [2024-05-24T16:06:26.878215 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1332# [RSpecRunTime] Finishing example group spec/migrations/20231019223224_backfill_catalog_resources_name_and_description_spec.rb. It took 1 minute 54.75 seconds. Expected to take 57.64 seconds.
1333# [RSpecRunTime] RSpec elapsed time: 21 minutes 21.47 seconds. Current RSS: ~1154M. load average: 0.85 0.90 0.98 1/291 430
1334# [RSpecRunTime] Starting example group spec/migrations/20240216020106_queue_backfill_cluster_agent_tokens_project_id_spec.rb. Expected to take 33.64 seconds.
1335QueueBackfillClusterAgentTokensProjectId
1336main: == [advisory_lock_connection] object_id: 263707660, pg_backend_pid: 313
1337main: == 20240216020106 QueueBackfillClusterAgentTokensProjectId: migrating =========
1338main: == 20240216020106 QueueBackfillClusterAgentTokensProjectId: migrated (0.0651s) 
1339main: == [advisory_lock_connection] object_id: 263707660, pg_backend_pid: 313
1340  schedules a new batched migration
1341INFO:  analyzing "public.p_ci_stages" inheritance tree
1342INFO:  analyzing "public.ci_stages"
1343INFO:  "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1344I, [2024-05-24T16:07:26.134881 #344]  INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
1345I, [2024-05-24T16:07:26.135974 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1346I, [2024-05-24T16:07:26.136759 #344]  INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1347I, [2024-05-24T16:07:27.279287 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1348I, [2024-05-24T16:07:33.456757 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1349# [RSpecRunTime] Finishing example group spec/migrations/20240216020106_queue_backfill_cluster_agent_tokens_project_id_spec.rb. It took 1 minute 5.19 seconds. Expected to take 33.64 seconds.
1350# [RSpecRunTime] RSpec elapsed time: 22 minutes 26.71 seconds. Current RSS: ~1172M. load average: 0.89 0.89 0.97 1/290 431
1351# [RSpecRunTime] Starting example group spec/migrations/20240305182005_queue_backfill_catalog_resource_version_sem_ver_spec.rb. Expected to take 31.86 seconds.
1352QueueBackfillCatalogResourceVersionSemVer
1353main: == [advisory_lock_connection] object_id: 282418320, pg_backend_pid: 326
1354main: == 20240305182005 QueueBackfillCatalogResourceVersionSemVer: migrating ========
1355main: == 20240305182005 QueueBackfillCatalogResourceVersionSemVer: migrated (0.0701s) 
1356main: == [advisory_lock_connection] object_id: 282418320, pg_backend_pid: 326
1357  schedules a new batched migration
1358I, [2024-05-24T16:08:26.546508 #344]  INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
1359I, [2024-05-24T16:08:32.762185 #344]  INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
1360# [RSpecRunTime] Finishing example group spec/migrations/20240305182005_queue_backfill_catalog_resource_version_sem_ver_spec.rb. It took 59.18 seconds. Expected to take 31.86 seconds.
1361# [RSpecRunTime] RSpec elapsed time: 23 minutes 25.94 seconds. Current RSS: ~1162M. load average: 0.96 0.91 0.98 1/290 432
1362# [RSpecRunTime] Starting example group spec/migrations/20240425205205_queue_remove_namespace_from_os_type_sbom_components_spec.rb. Expected to take 11.23 seconds.
1363QueueRemoveNamespaceFromOsTypeSbomComponents
1364main: == [advisory_lock_connection] object_id: 293636140, pg_backend_pid: 338
1365main: == 20240425205205 QueueRemoveNamespaceFromOsTypeSbomComponents: migrating =====
1366main: == 20240425205205 QueueRemoveNamespaceFromOsTypeSbomComponents: migrated (0.0540s) 
1367main: == [advisory_lock_connection] object_id: 293636140, pg_backend_pid: 338
1368  schedules a new batched migration
1369# [RSpecRunTime] Finishing example group spec/migrations/20240425205205_queue_remove_namespace_from_os_type_sbom_components_spec.rb. It took 22.81 seconds. Expected to take 11.23 seconds.
1370# [RSpecRunTime] RSpec elapsed time: 23 minutes 48.79 seconds. Current RSS: ~1155M. load average: 0.84 0.89 0.97 1/290 433
1371# [RSpecRunTime] Starting example group spec/migrations/20240521092459_queue_backfill_boards_epic_board_positions_group_id_spec.rb. Expected to take 4.45 seconds.
1372QueueBackfillBoardsEpicBoardPositionsGroupId
1373main: == [advisory_lock_connection] object_id: 297481520, pg_backend_pid: 349
1374main: == 20240521092459 QueueBackfillBoardsEpicBoardPositionsGroupId: migrating =====
1375main: == 20240521092459 QueueBackfillBoardsEpicBoardPositionsGroupId: migrated (0.0624s) 
1376main: == [advisory_lock_connection] object_id: 297481520, pg_backend_pid: 349
1377  schedules a new batched migration
1378# [RSpecRunTime] Finishing example group spec/migrations/20240521092459_queue_backfill_boards_epic_board_positions_group_id_spec.rb. It took 11.1 seconds. Expected to take 4.45 seconds.
1379# [RSpecRunTime] RSpec elapsed time: 23 minutes 59.94 seconds. Current RSS: ~1153M. load average: 0.87 0.89 0.97 1/290 434
1380auto_explain log contains 931 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-migration-pg14-15-15.344.main.ndjson.gz
1381took 22.791846817
1382auto_explain log contains 932 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-migration-pg14-15-15.344.ci.ndjson.gz
1383took 22.652631945
1384[TEST PROF INFO] EventProf results for sql.active_record
1385Total time: 13:02.708 of 23:53.367 (54.61%)
1386Total events: 634644
1387Top 5 slowest suites (by time):
1388QueueBackfill...mespaceSetting (./spec/migrations/20230724071541_queue_backfill_default_branch_protection_namespace_setting_spec.rb:6) – 01:50.721 (74027 / 1) of 02:56.052 (62.89%)
1389SwapSnippetUs...ntForSelfHosts (./spec/migrations/20230810123044_swap_snippet_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb:6) – 01:34.889 (76561 / 4) of 03:54.053 (40.54%)
1390SwapNoteDiffF...ntForSelfHosts (./spec/migrations/20230810113227_swap_note_diff_files_note_id_to_bigint_for_self_hosts_spec.rb:6) – 01:32.525 (76407 / 4) of 03:47.332 (40.7%)
1391QueueUpdateUs...ServiceAccount (./spec/migrations/20230830121830_queue_update_users_set_external_if_service_account_spec.rb:6) – 01:27.590 (68108 / 1) of 02:23.413 (61.08%)
1392MigrateSidekiqNamespacedJobs (./spec/migrations/20231003045342_migrate_sidekiq_namespaced_jobs_spec.rb:6) – 01:22.209 (63836 / 1) of 02:16.996 (60.01%)
1393Knapsack report was generated. Preview:
1394{
1395  "spec/migrations/20230810123044_swap_snippet_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb": 172.6587555039996,
1396  "spec/migrations/20230810113227_swap_note_diff_files_note_id_to_bigint_for_self_hosts_spec.rb": 161.5083649549997,
1397  "spec/migrations/20230724071541_queue_backfill_default_branch_protection_namespace_setting_spec.rb": 96.98664023499987,
1398  "spec/migrations/20231019003052_swap_columns_for_ci_pipelines_pipeline_id_bigint_v2_spec.rb": 86.08945098299955,
1399  "spec/migrations/20230830121830_queue_update_users_set_external_if_service_account_spec.rb": 80.10391354300009,
1400  "spec/migrations/20231003045342_migrate_sidekiq_namespaced_jobs_spec.rb": 77.71293665299982,
1401  "spec/migrations/20240108121335_copy_internal_ids_for_epics_and_issues_usage_on_groups_spec.rb": 55.98426502899929,
1402  "spec/migrations/20231019223224_backfill_catalog_resources_name_and_description_spec.rb": 57.231148617000144,
1403  "spec/migrations/20240216020106_queue_backfill_cluster_agent_tokens_project_id_spec.rb": 36.15835030800008,
1404  "spec/migrations/20240305182005_queue_backfill_catalog_resource_version_sem_ver_spec.rb": 31.671658991000186,
1405  "spec/migrations/20240425205205_queue_remove_namespace_from_os_type_sbom_components_spec.rb": 10.375893159999578,
1406  "spec/migrations/20240521092459_queue_backfill_boards_epic_board_positions_group_id_spec.rb": 4.261276975999863
1407}
1408Knapsack global time execution for tests: 14m 30s
1409Finished in 24 minutes 45 seconds (files took 1 minute 35.63 seconds to load)
141020 examples, 0 failures
1411Randomized with seed 10711
1412[TEST PROF INFO] Time spent in factories: 00:00.197 (0.01% of total time)
1413RSpec exited with 0.
1414No examples to retry, congrats!
 1415  Running after_script  
  00:07
1416Running after script...
1417$ source scripts/utils.sh
1418$ bundle exec gem list gitlab_quality-test_tooling
1419gitlab_quality-test_tooling (1.26.0)
1420$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
 1421  Report test failures  
  00:02
1424$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
 1425  Report test flakiness  
  00:00
1427$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
 1428  Report test slowness  
  00:01
1431$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
 1432  Report test slowness in MR note  
  00:00
1434$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
 1435  Report test files close to timing out  
  00:02
1438$ tooling/bin/push_job_metrics || true
1439[job-metrics] Pushing job metrics file for the CI/CD job.
1440[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
 1441  Saving cache for successful job  
  00:00
1442Not uploading cache ruby-gems-debian-bookworm-ruby-3.1-17 due to policy
 1443  Uploading artifacts for successful job  
  00:04
1444Uploading artifacts...
1445auto_explain/: found 3 matching artifact files and directories 
1446coverage/: found 5 matching artifact files and directories 
1447WARNING: crystalball/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab) 
1448WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab) 
1449knapsack/: found 4 matching artifact files and directories 
1450rspec/: found 12 matching artifact files and directories 
1451WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab) 
1452log/*.log: found 13 matching artifact files and directories 
1453WARNING: Upload request redirected                  location=https://gitlab.com/api/v4/jobs/6934018115/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
1454WARNING: Retrying...                                context=artifacts-uploader error=request redirected
1455Uploading artifacts as "archive" to coordinator... 201 Created  id=6934018115 responseStatus=201 Created token=glcbt-65
1456Uploading artifacts...
1457rspec/rspec-*.xml: found 1 matching artifact files and directories 
1458WARNING: Upload request redirected                  location=https://gitlab.com/api/v4/jobs/6934018115/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
1459WARNING: Retrying...                                context=artifacts-uploader error=request redirected
1460Uploading artifacts as "junit" to coordinator... 201 Created  id=6934018115 responseStatus=201 Created token=glcbt-65
 1461  Cleaning up project directory and file based variables  
  00:01
1462Job succeeded
Tags: gitlab-org
Job artifacts
The artifacts were removed 8 months ago
Commit 82c74e17
Merge branch 'backfill-desired-sharding-key-small-table-design_management_repositories' into 'master'
Related jobs

rspec-ee unit gitlab-duo-chat-qa pg14
compile-storybook
db:backup_and_restore
db:backup_and_restore single-db
db:backup_and_restore single-db-ci-connection
db:check-schema
db:migrate:multi-version-upgrade
db:migrate:multi-version-upgrade-pg13
db:migrate:reset
db:rollback
db:rollback geo
gitlab:clickhouse:rollback:main
gitlab:setup
gitlab_git_test
glfm-verify
graphql-verify
jest 1/12
jest 10/12
jest 11/12
jest 12/12
jest 2/12
jest 3/12
jest 4/12
jest 5/12
jest 6/12
jest 7/12
jest 8/12
jest 9/12
jest-build-cache
jest-integration
memory-on-boot
rspec background_migration pg14 1/5
rspec background_migration pg14 2/5
rspec background_migration pg14 3/5
rspec background_migration pg14 4/5
rspec background_migration pg14 5/5
rspec integration pg14 1/16
rspec integration pg14 10/16
rspec integration pg14 11/16
rspec integration pg14 12/16
rspec integration pg14 13/16
rspec integration pg14 14/16
rspec integration pg14 15/16
rspec integration pg14 16/16
rspec integration pg14 2/16
rspec integration pg14 3/16
rspec integration pg14 4/16
rspec integration pg14 5/16
rspec integration pg14 6/16
rspec integration pg14 7/16
rspec integration pg14 8/16
rspec integration pg14 9/16
rspec migration pg14 1/15
rspec migration pg14 10/15
rspec migration pg14 11/15
rspec migration pg14 12/15
rspec migration pg14 13/15
rspec migration pg14 14/15
rspec migration pg14 15/15
rspec migration pg14 2/15
rspec migration pg14 3/15
rspec migration pg14 4/15
rspec migration pg14 5/15
rspec migration pg14 6/15
rspec migration pg14 7/15
rspec migration pg14 8/15
rspec migration pg14 9/15
rspec system pg14 1/32
rspec system pg14 10/32
rspec system pg14 11/32
rspec system pg14 12/32
rspec system pg14 13/32
rspec system pg14 14/32
rspec system pg14 15/32
rspec system pg14 16/32
rspec system pg14 17/32
rspec system pg14 18/32
rspec system pg14 19/32
rspec system pg14 2/32
rspec system pg14 20/32
rspec system pg14 21/32
rspec system pg14 22/32
rspec system pg14 23/32
rspec system pg14 24/32
rspec system pg14 25/32
rspec system pg14 26/32
rspec system pg14 27/32
rspec system pg14 28/32
rspec system pg14 29/32
rspec system pg14 3/32
rspec system pg14 30/32
rspec system pg14 31/32
rspec system pg14 32/32
rspec system pg14 4/32
rspec system pg14 5/32
rspec system pg14 6/32
rspec system pg14 7/32
rspec system pg14 8/32
rspec system pg14 9/32
rspec unit clickhouse
rspec unit pg14 1/32
rspec unit pg14 10/32
rspec unit pg14 11/32
rspec unit pg14 12/32
rspec unit pg14 13/32
rspec unit pg14 14/32
rspec unit pg14 15/32
rspec unit pg14 16/32
rspec unit pg14 17/32
rspec unit pg14 18/32
rspec unit pg14 19/32
rspec unit pg14 2/32
rspec unit pg14 20/32
rspec unit pg14 21/32
rspec unit pg14 22/32
rspec unit pg14 23/32
rspec unit pg14 24/32
rspec unit pg14 25/32
rspec unit pg14 26/32
rspec unit pg14 27/32
rspec unit pg14 28/32
rspec unit pg14 29/32
rspec unit pg14 3/32
rspec unit pg14 30/32
rspec unit pg14 31/32
rspec unit pg14 32/32
rspec unit pg14 4/32
rspec unit pg14 5/32
rspec unit pg14 6/32
rspec unit pg14 7/32
rspec unit pg14 8/32
rspec unit pg14 9/32
rspec-ee background_migration pg14 1/2
rspec-ee background_migration pg14 2/2
rspec-ee integration pg14 1/7
rspec-ee integration pg14 2/7
rspec-ee integration pg14 3/7
rspec-ee integration pg14 4/7
rspec-ee integration pg14 5/7
rspec-ee integration pg14 6/7
rspec-ee integration pg14 7/7
rspec-ee migration pg14 1/2
rspec-ee migration pg14 2/2
rspec-ee system pg14 1/14
rspec-ee system pg14 10/14
rspec-ee system pg14 11/14
rspec-ee system pg14 12/14
rspec-ee system pg14 13/14
rspec-ee system pg14 14/14
rspec-ee system pg14 2/14
rspec-ee system pg14 3/14
rspec-ee system pg14 4/14
rspec-ee system pg14 5/14
rspec-ee system pg14 6/14
rspec-ee system pg14 7/14
rspec-ee system pg14 8/14
rspec-ee system pg14 9/14
rspec-ee unit clickhouse
rspec-ee unit pg14 1/28
rspec-ee unit pg14 10/28
rspec-ee unit pg14 11/28
rspec-ee unit pg14 12/28
rspec-ee unit pg14 13/28
rspec-ee unit pg14 14/28
rspec-ee unit pg14 15/28
rspec-ee unit pg14 16/28
rspec-ee unit pg14 17/28
rspec-ee unit pg14 18/28
rspec-ee unit pg14 19/28
rspec-ee unit pg14 2/28
rspec-ee unit pg14 20/28
rspec-ee unit pg14 21/28
rspec-ee unit pg14 22/28
rspec-ee unit pg14 23/28
rspec-ee unit pg14 24/28
rspec-ee unit pg14 25/28
rspec-ee unit pg14 26/28
rspec-ee unit pg14 27/28
rspec-ee unit pg14 28/28
rspec-ee unit pg14 3/28
rspec-ee unit pg14 4/28
rspec-ee unit pg14 5/28
rspec-ee unit pg14 6/28
rspec-ee unit pg14 7/28
rspec-ee unit pg14 8/28
rspec-ee unit pg14 9/28
run-dev-fixtures
run-dev-fixtures-ee
verify-tests-yml
webpack-dev-server
rspec-ee integration pg14 2/7