Skip to content
Snippets Groups Projects

rspec background_migration pg14 5/5

Passed Started by
Drew Blessing
@dblessing
1Running with gitlab-runner 16.8.0~beta.67.gb5664e8e (b5664e8e)
2 on blue-3.shared-gitlab-org.runners-manager.gitlab.com/default sUrYYgEG, system ID: s_35f98e2af465
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:09
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:0704d2ebff510f3d6f608cd8e9064640a9dd041c4e3ac1e1ff2afb5fe22850bc 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:bbf2c8a67a31469f488a4541826628901b6eb5c0a4d68147919aca0b98107df6 ...
24 Preparing environment 00:00
25Running on runner-suryygeg-project-278964-concurrent-0 via runner-suryygeg-shared-gitlab-org-1708468094-afb5ea5d...
26 Getting source from Git repository 00:01
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
30 Restoring cache 00:18
31Checking cache for ruby-gems-debian-bookworm-ruby-3.1-16...
32cache.zip is up to date
33Successfully extracted cache
34 Downloading artifacts 00:37
35Downloading artifacts for clone-gitlab-repo (6218670526)...
36Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6218670526 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 (6218670555)...
40Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6218670555 responseStatus=200 OK token=glcbt-65
41Downloading artifacts for retrieve-tests-metadata (6218670576)...
42Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6218670576 responseStatus=200 OK token=glcbt-65
43Downloading artifacts for setup-test-env (6218670568)...
44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6218670568 responseStatus=200 OK token=glcbt-65
45 Executing "step_script" stage of the job script 27:04
46Using docker image sha256:0704d2ebff510f3d6f608cd8e9064640a9dd041c4e3ac1e1ff2afb5fe22850bc 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:bbf2c8a67a31469f488a4541826628901b6eb5c0a4d68147919aca0b98107df6 ...
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:17
731Using decomposed database config (config/database.yml.decomposed-postgresql)
732Geo DB won't be set up.
733Embedding DB won't be set up.
734 Setting up DBs 00:53
785$ source ./scripts/rspec_helpers.sh
786$ run_timed_command "gem install knapsack --no-document"
787$ gem install knapsack --no-document
788Successfully installed knapsack-4.0.0
7891 gem installed
790==> 'gem install knapsack --no-document' succeeded in 1 seconds.
791$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
792 Spawning Gitaly 00:03
796$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
797$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
798$ tooling/bin/create_job_metrics_file || true
799[job-metrics] Creating the job metrics file for the CI/CD job.
800$ rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
801[23:18:51] Starting rspec_parallelized_job
802RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
803KNAPSACK_GENERATE_REPORT: true
804FLAKY_RSPEC_GENERATE_REPORT: true
805KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
806KNAPSACK_LOG_LEVEL: debug
807KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_5_5_278964_report.json
808FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
809FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_5_5_278964_report.json
810NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_5_5_278964_report.json
811RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-6218670755.txt
812CRYSTALBALL:
813RSPEC_TESTS_MAPPING_ENABLED:
814RSPEC_TESTS_FILTER_FILE:
815Shell set options (set -o) enabled:
816braceexpand on
817hashall on
818interactive-comments on
819pipefail on
820Knapsack report generator started!
821Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
822# [RSpecRunTime] Starting RSpec timer...
823[TEST PROF INFO] EventProf enabled (sql.active_record)
824unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
825unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
826Test environment set up in 1.183618694 seconds
827# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/legacy_upload_mover_spec.rb. Expected to take 1 minute 40.08 seconds.
828Gitlab::BackgroundMigration::LegacyUploadMover
829 when no note found for the upload
830 behaves like legacy upload deletion
831 removes the upload record
832 when upload does not belong to a note
833 does not remove the upload
834# [RSpecRunTime] RSpec elapsed time: 16.62 seconds. Current RSS: ~1300M. load average: 1.40 1.46 1.37 1/282 397
835 when the upload move fails
836 behaves like move error
837 does not remove the upload file
838# [RSpecRunTime] RSpec elapsed time: 22.06 seconds. Current RSS: ~1306M. load average: 1.36 1.45 1.37 1/282 398
839 when the upload is in local storage
840 when the upload file does not exist on the filesystem
841 behaves like legacy upload deletion
842 removes the upload record
843# [RSpecRunTime] RSpec elapsed time: 27.29 seconds. Current RSS: ~1308M. load average: 1.33 1.44 1.37 1/282 399
844 when an upload belongs to a legacy_diff_note
845 when the file does not exist for the upload
846 behaves like move error
847 does not remove the upload file
848# [RSpecRunTime] RSpec elapsed time: 32.61 seconds. Current RSS: ~1312M. load average: 1.23 1.42 1.36 1/282 400
849 when the file does not exist on expected path
850 behaves like move error
851 does not remove the upload file
852# [RSpecRunTime] RSpec elapsed time: 37.92 seconds. Current RSS: ~1312M. load average: 1.21 1.41 1.36 1/282 401
853 when the file path does not include system/note/attachment
854 behaves like move error
855 does not remove the upload file
856# [RSpecRunTime] RSpec elapsed time: 43.16 seconds. Current RSS: ~1312M. load average: 1.27 1.42 1.36 1/282 402
857 when the file move raises an error
858 behaves like move error
859 does not remove the upload file
860# [RSpecRunTime] RSpec elapsed time: 48.41 seconds. Current RSS: ~1312M. load average: 1.17 1.40 1.36 1/282 403
861 when upload has mount_point nil
862 behaves like migrates the file correctly
863 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
864# [RSpecRunTime] RSpec elapsed time: 53.94 seconds. Current RSS: ~1312M. load average: 1.16 1.39 1.35 1/282 404
865 when the file can be handled correctly
866 behaves like migrates the file correctly
867 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
868# [RSpecRunTime] RSpec elapsed time: 59.33 seconds. Current RSS: ~1313M. load average: 1.06 1.37 1.35 1/282 405
869 when object storage is disabled for FileUploader
870 when the file belongs to a legacy project
871 behaves like migrates the file correctly
872 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
873# [RSpecRunTime] RSpec elapsed time: 1 minute 4.57 seconds. Current RSS: ~1311M. load average: 1.14 1.38 1.35 1/282 406
874 when the file belongs to a hashed project
875 behaves like migrates the file correctly
876 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
877# [RSpecRunTime] RSpec elapsed time: 1 minute 9.76 seconds. Current RSS: ~1310M. load average: 1.13 1.37 1.35 1/282 407
878 when object storage is enabled for FileUploader
879 when the file belongs to a legacy project
880 behaves like migrates the file correctly
881 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
882# [RSpecRunTime] RSpec elapsed time: 1 minute 15.07 seconds. Current RSS: ~1311M. load average: 1.12 1.37 1.35 1/281 408
883 when the file belongs to a hashed project
884 behaves like migrates the file correctly
885 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
886# [RSpecRunTime] RSpec elapsed time: 1 minute 20.37 seconds. Current RSS: ~1309M. load average: 1.11 1.36 1.34 1/282 409
887 when legacy uploads are stored in object storage
888 when the upload file does not exist on the filesystem
889 behaves like legacy upload deletion
890 removes the upload record
891# [RSpecRunTime] RSpec elapsed time: 1 minute 25.6 seconds. Current RSS: ~1306M. load average: 1.10 1.35 1.34 1/281 410
892 when the file belongs to a legacy project
893 behaves like migrates the file correctly
894 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
895# [RSpecRunTime] RSpec elapsed time: 1 minute 32.76 seconds. Current RSS: ~1307M. load average: 1.08 1.34 1.34 1/281 411
896 when the file belongs to a hashed project
897 behaves like migrates the file correctly
898 creates a new upload record correctly, updates the legacy upload note so that it references the file in the markdown, removes the attachment from the note model, removes the file, moves legacy uploads to the correct location, removes the upload record
899# [RSpecRunTime] RSpec elapsed time: 1 minute 38.06 seconds. Current RSS: ~1326M. load average: 1.08 1.34 1.34 1/281 412
900# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/legacy_upload_mover_spec.rb. It took 1 minute 43.37 seconds. Expected to take 1 minute 40.08 seconds.
901# [RSpecRunTime] RSpec elapsed time: 1 minute 47.53 seconds. Current RSS: ~1299M. load average: 1.06 1.32 1.33 1/281 413
902# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb. Expected to take 1 minute 35.54 seconds.
903Gitlab::BackgroundMigration::BackfillResourceLinkEvents
904 #perform
905 does nothing when relevant notes do not exist
906 for 'relate_to_parent' system_note_metadata record
907 when issue_type_name is `issue`
908 behaves like a resource_link_event is correctly created
909 correctly backfills a resource_link_event record
910# [RSpecRunTime] RSpec elapsed time: 2 minutes 54.94 seconds. Current RSS: ~1320M. load average: 1.12 1.28 1.31 1/280 414
911 when issue_type_name is not `issue`
912 behaves like a resource_link_event is correctly created
913 correctly backfills a resource_link_event record
914# [RSpecRunTime] RSpec elapsed time: 2 minutes 58.39 seconds. Current RSS: ~1323M. load average: 1.03 1.26 1.31 1/280 415
915 for 'unrelate_to_parent' system_note_metadata record
916 when issue_type_name is `issue`
917 behaves like a resource_link_event is correctly created
918 correctly backfills a resource_link_event record
919# [RSpecRunTime] RSpec elapsed time: 3 minutes 1.83 seconds. Current RSS: ~1318M. load average: 1.03 1.26 1.31 1/280 416
920 when issue_type_name is not `issue`
921 behaves like a resource_link_event is correctly created
922 correctly backfills a resource_link_event record
923# [RSpecRunTime] RSpec elapsed time: 3 minutes 5.29 seconds. Current RSS: ~1318M. load average: 1.03 1.25 1.31 1/280 417
924 when a backfilled note exists
925 correctly backfills the system notes without those that have been backfilled
926# [RSpecRunTime] RSpec elapsed time: 3 minutes 8.7 seconds. Current RSS: ~1313M. load average: 0.95 1.23 1.30 1/280 418
927 with unexpected note content
928 when note iid is prefixed
929 does not create resource_link_events record
930# [RSpecRunTime] RSpec elapsed time: 3 minutes 12.18 seconds. Current RSS: ~1309M. load average: 0.87 1.21 1.29 1/280 419
931INFO: analyzing "public.p_ci_builds" inheritance tree
932INFO: analyzing "public.ci_builds"
933INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
934I, [2024-02-20T23:22:54.036325 #339] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
935I, [2024-02-20T23:22:54.037620 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
936I, [2024-02-20T23:22:54.038919 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
937I, [2024-02-20T23:23:07.013771 #339] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
938INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
939INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
940INFO: "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
941INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
942INFO: "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
943INFO: analyzing "public.p_ci_job_annotations" inheritance tree
944INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
945INFO: "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
946INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
947INFO: analyzing "public.ci_builds_metadata"
948INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
949INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
950INFO: "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
951INFO: analyzing "public.p_ci_builds" inheritance tree
952INFO: analyzing "public.ci_builds"
953INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
954I, [2024-02-20T23:23:31.565012 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
955INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
956INFO: analyzing "public.ci_pipeline_variables"
957INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
958I, [2024-02-20T23:23:53.131984 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
959I, [2024-02-20T23:23:53.133236 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
960I, [2024-02-20T23:23:53.134130 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
961I, [2024-02-20T23:23:53.743205 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
962INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
963INFO: analyzing "public.ci_job_artifacts"
964INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
965I, [2024-02-20T23:23:54.944283 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
966I, [2024-02-20T23:23:54.945372 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
967I, [2024-02-20T23:23:54.946173 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
968INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
969INFO: analyzing "public.ci_pipeline_variables"
970INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
971# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb. It took 2 minutes 40.02 seconds. Expected to take 1 minute 35.54 seconds.
972# [RSpecRunTime] RSpec elapsed time: 4 minutes 27.59 seconds. Current RSS: ~1295M. load average: 1.13 1.23 1.29 1/281 420
973# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. Expected to take 1 minute 26.57 seconds.
974Gitlab::BackgroundMigration::DestroyInvalidMembers
975 tracks timings of queries
976 logs IDs of deleted records
977 removes invalid memberships but keeps valid ones
978I, [2024-02-20T23:25:28.261581 #339] 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-02-20T23:25:44.835332 #339] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
983I, [2024-02-20T23:25:44.836488 #339] 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-02-20T23:25:44.837312 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
985I, [2024-02-20T23:25:59.005991 #339] 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-02-20T23:26:24.886920 #339] 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-02-20T23:26:46.428525 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1007I, [2024-02-20T23:26:46.429601 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1008I, [2024-02-20T23:26:46.430414 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1009I, [2024-02-20T23:26:46.944441 #339] 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-02-20T23:26:48.172562 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1014I, [2024-02-20T23:26:48.173739 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1015I, [2024-02-20T23:26:48.174650 #339] 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
1019# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb. It took 2 minutes 53.36 seconds. Expected to take 1 minute 26.57 seconds.
1020# [RSpecRunTime] RSpec elapsed time: 7 minutes 20.98 seconds. Current RSS: ~1312M. load average: 1.05 1.18 1.26 1/283 421
1021# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb. Expected to take 1 minute 20.2 seconds.
1022Gitlab::BackgroundMigration::BackfillDesignManagementRepositories
1023 #perform
1024 creates design_management_repositories entries for all projects in range
1025 when project_id already exists in design_management_repositories
1026 doesn't duplicate project_id
1027# [RSpecRunTime] RSpec elapsed time: 8 minutes 32.04 seconds. Current RSS: ~1348M. load average: 0.99 1.12 1.23 1/282 422
1028INFO: analyzing "public.p_ci_builds" inheritance tree
1029INFO: analyzing "public.ci_builds"
1030INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1031I, [2024-02-20T23:28:16.518801 #339] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
1032I, [2024-02-20T23:28:16.519988 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1033I, [2024-02-20T23:28:16.520908 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1034I, [2024-02-20T23:28:31.056763 #339] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1035INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1036INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1037INFO: "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
1038INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1039INFO: "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
1040INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1041INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1042INFO: "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
1043INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1044INFO: analyzing "public.ci_builds_metadata"
1045INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1046INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1047INFO: "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
1048INFO: analyzing "public.p_ci_builds" inheritance tree
1049INFO: analyzing "public.ci_builds"
1050INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1051I, [2024-02-20T23:28:57.651211 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1052INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1053INFO: analyzing "public.ci_pipeline_variables"
1054INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1055I, [2024-02-20T23:29:20.029807 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1056I, [2024-02-20T23:29:20.031322 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1057I, [2024-02-20T23:29:20.032155 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1058I, [2024-02-20T23:29:20.571162 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1059INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1060INFO: analyzing "public.ci_job_artifacts"
1061INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1062I, [2024-02-20T23:29:21.768644 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1063I, [2024-02-20T23:29:21.770106 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1064I, [2024-02-20T23:29:21.771141 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1065INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1066INFO: analyzing "public.ci_pipeline_variables"
1067INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1068# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb. It took 2 minutes 33.54 seconds. Expected to take 1 minute 20.2 seconds.
1069# [RSpecRunTime] RSpec elapsed time: 9 minutes 54.57 seconds. Current RSS: ~1313M. load average: 0.90 1.06 1.20 1/283 423
1070# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/fix_vulnerability_reads_has_issues_spec.rb. Expected to take 1 minute 16.59 seconds.
1071Gitlab::BackgroundMigration::FixVulnerabilityReadsHasIssues
1072 only changes records with issue links
1073INFO: analyzing "public.p_ci_builds" inheritance tree
1074INFO: analyzing "public.ci_builds"
1075INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1076I, [2024-02-20T23:31:04.944721 #339] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
1077I, [2024-02-20T23:31:04.945809 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1078I, [2024-02-20T23:31:04.946699 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1079I, [2024-02-20T23:31:19.915833 #339] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1080INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1081INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1082INFO: "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
1083INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1084INFO: "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
1085INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1086INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1087INFO: "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
1088INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1089INFO: analyzing "public.ci_builds_metadata"
1090INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1091INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1092INFO: "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
1093INFO: analyzing "public.p_ci_builds" inheritance tree
1094INFO: analyzing "public.ci_builds"
1095INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1096I, [2024-02-20T23:31:47.195985 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1097INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1098INFO: analyzing "public.ci_pipeline_variables"
1099INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1100I, [2024-02-20T23:32:10.601889 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1101I, [2024-02-20T23:32:10.603277 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1102I, [2024-02-20T23:32:10.604276 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1103I, [2024-02-20T23:32:11.192682 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1104INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1105INFO: analyzing "public.ci_job_artifacts"
1106INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1107I, [2024-02-20T23:32:12.632312 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1108I, [2024-02-20T23:32:12.633604 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1109I, [2024-02-20T23:32:12.634564 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1110INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1111INFO: analyzing "public.ci_pipeline_variables"
1112INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1113# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/fix_vulnerability_reads_has_issues_spec.rb. It took 2 minutes 51.08 seconds. Expected to take 1 minute 16.59 seconds.
1114# [RSpecRunTime] RSpec elapsed time: 12 minutes 45.7 seconds. Current RSS: ~1325M. load average: 0.95 1.02 1.16 1/283 424
1115# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/reset_too_many_tags_skipped_registry_imports_spec.rb. Expected to take 1 minute 15.5 seconds.
1116Gitlab::BackgroundMigration::ResetTooManyTagsSkippedRegistryImports
1117 #up
1118 resets only qualified container repositories
1119# [RSpecRunTime] RSpec elapsed time: 14 minutes 5.38 seconds. Current RSS: ~1346M. load average: 0.96 1.00 1.13 1/283 425
1120I, [2024-02-20T23:33:43.762464 #339] INFO -- : Database: 'main', Table: 'ci_cost_settings': Lock Writes
1121INFO: analyzing "public.p_ci_builds" inheritance tree
1122INFO: analyzing "public.ci_builds"
1123INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1124I, [2024-02-20T23:34:01.920191 #339] INFO -- : Database: 'main', Table: 'p_ci_builds': Lock Writes
1125I, [2024-02-20T23:34:01.921491 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1126I, [2024-02-20T23:34:01.922377 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1127I, [2024-02-20T23:34:17.298114 #339] INFO -- : Database: 'main', Table: 'p_ci_job_annotations': Lock Writes
1128INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1129INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1130INFO: "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
1131INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1132INFO: "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
1133INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1134INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1135INFO: "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
1136INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1137INFO: analyzing "public.ci_builds_metadata"
1138INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1139INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1140INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1141INFO: analyzing "public.p_ci_builds" inheritance tree
1142INFO: analyzing "public.ci_builds"
1143INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1144I, [2024-02-20T23:34:44.746713 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1145INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1146INFO: analyzing "public.ci_pipeline_variables"
1147INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1148I, [2024-02-20T23:35:08.275303 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1149I, [2024-02-20T23:35:08.276966 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1150I, [2024-02-20T23:35:08.278208 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1151I, [2024-02-20T23:35:08.855103 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1152INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1153INFO: analyzing "public.ci_job_artifacts"
1154INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1155I, [2024-02-20T23:35:10.158596 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1156I, [2024-02-20T23:35:10.159782 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1157I, [2024-02-20T23:35:10.161022 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1158INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1159INFO: analyzing "public.ci_pipeline_variables"
1160INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1161# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/reset_too_many_tags_skipped_registry_imports_spec.rb. It took 2 minutes 57.25 seconds. Expected to take 1 minute 15.5 seconds.
1162# [RSpecRunTime] RSpec elapsed time: 15 minutes 42.99 seconds. Current RSS: ~1323M. load average: 1.02 1.01 1.12 1/282 426
1163# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/truncate_overlong_vulnerability_html_titles_spec.rb. Expected to take 1 minute 10.07 seconds.
1164Gitlab::BackgroundMigration::TruncateOverlongVulnerabilityHtmlTitles
1165 #perform
1166 truncates the vulnerability html title when longer than 800 characters
1167# [RSpecRunTime] RSpec elapsed time: 16 minutes 59.91 seconds. Current RSS: ~1342M. load average: 1.29 1.08 1.14 1/282 427
1168The application_settings (main) table has 1297 columns.
1169Recreating the database
1170Dropped database 'gitlabhq_test'
1171Dropped database 'gitlabhq_test_ci'
1172Created database 'gitlabhq_test'
1173Created database 'gitlabhq_test_ci'
1174main: == [advisory_lock_connection] object_id: 173279500, pg_backend_pid: 265
1175main: == [advisory_lock_connection] object_id: 173279500, pg_backend_pid: 265
1176ci: == [advisory_lock_connection] object_id: 173357560, pg_backend_pid: 267
1177ci: == [advisory_lock_connection] object_id: 173357560, pg_backend_pid: 267
1178Databases re-creation done in 11.956580888999724
1179# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/truncate_overlong_vulnerability_html_titles_spec.rb. It took 1 minute 29.09 seconds. Expected to take 1 minute 10.07 seconds.
1180# [RSpecRunTime] RSpec elapsed time: 17 minutes 12.12 seconds. Current RSS: ~1343M. load average: 1.22 1.08 1.13 1/282 430
1181# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb. Expected to take 59.91 seconds.
1182Gitlab::BackgroundMigration::BackfillProjectRepositories
1183 Gitlab::BackgroundMigration::BackfillProjectRepositories::ShardFinder
1184 #find_shard_id
1185 creates a new shard when it does not exist yet
1186 returns the shard when it exists
1187 only queries the database once to retrieve shards
1188# [RSpecRunTime] RSpec elapsed time: 17 minutes 21.05 seconds. Current RSS: ~1355M. load average: 1.20 1.08 1.13 1/283 431
1189 Gitlab::BackgroundMigration::BackfillProjectRepositories::Project
1190 .on_hashed_storage
1191 finds projects with repository on hashed storage
1192# [RSpecRunTime] RSpec elapsed time: 17 minutes 26.44 seconds. Current RSS: ~1383M. load average: 1.19 1.08 1.13 1/283 432
1193 .on_legacy_storage
1194 finds projects with repository on legacy storage
1195# [RSpecRunTime] RSpec elapsed time: 17 minutes 31.72 seconds. Current RSS: ~1352M. load average: 1.17 1.07 1.13 1/283 433
1196 .without_project_repository
1197 finds projects which do not have a projects_repositories entry
1198# [RSpecRunTime] RSpec elapsed time: 17 minutes 36.84 seconds. Current RSS: ~1355M. load average: 1.16 1.07 1.13 1/283 434
1199 #disk_path
1200 for projects on hashed storage
1201 returns the correct disk_path
1202# [RSpecRunTime] RSpec elapsed time: 17 minutes 42.13 seconds. Current RSS: ~1353M. load average: 1.05 1.05 1.12 1/283 435
1203 for projects on legacy storage
1204 returns the correct disk_path
1205 returns the correct disk_path using the route entry
1206 raises OrphanedNamespaceError when any parent namespace does not exist
1207# [RSpecRunTime] RSpec elapsed time: 17 minutes 57.97 seconds. Current RSS: ~1339M. load average: 0.97 1.03 1.11 1/283 436
1208# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb. It took 52.57 seconds. Expected to take 59.91 seconds.
1209# [RSpecRunTime] RSpec elapsed time: 18 minutes 4.73 seconds. Current RSS: ~1317M. load average: 0.97 1.03 1.11 1/283 437
1210# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. Expected to take 36.49 seconds.
1211Gitlab::BackgroundMigration::BackfillDefaultBranchProtectionNamespaceSetting
1212 updates default_branch_protection_defaults to a correct value
1213INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1214INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1215INFO: "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
1216INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1217INFO: "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
1218INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1219INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1220INFO: "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
1221INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
1222INFO: "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
1223INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1224INFO: analyzing "public.ci_builds_metadata"
1225INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1226INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1227INFO: "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
1228INFO: analyzing "public.p_ci_builds" inheritance tree
1229INFO: analyzing "public.ci_builds"
1230INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1231INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1232INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1233I, [2024-02-20T23:38:32.339354 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1234INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1235INFO: analyzing "public.ci_pipeline_variables"
1236INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1237I, [2024-02-20T23:38:50.865777 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1238I, [2024-02-20T23:38:50.866822 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1239I, [2024-02-20T23:38:50.867602 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1240I, [2024-02-20T23:38:51.303594 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1241INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1242INFO: analyzing "public.ci_job_artifacts"
1243INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1244I, [2024-02-20T23:38:52.514966 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1245I, [2024-02-20T23:38:52.516166 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1246I, [2024-02-20T23:38:52.516984 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1247INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1248INFO: analyzing "public.ci_pipeline_variables"
1249INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1250# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. It took 1 minute 20.1 seconds. Expected to take 36.49 seconds.
1251# [RSpecRunTime] RSpec elapsed time: 19 minutes 24.86 seconds. Current RSS: ~1314M. load average: 1.07 1.04 1.10 1/283 438
1252# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/fix_allow_descendants_override_disabled_shared_runners_spec.rb. Expected to take 35.27 seconds.
1253Gitlab::BackgroundMigration::FixAllowDescendantsOverrideDisabledSharedRunners
1254 fixes invalid allow_descendants_override_disabled_shared_runners and does not affect others
1255INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
1256INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
1257INFO: "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
1258INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
1259INFO: "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
1260INFO: analyzing "public.p_ci_job_annotations" inheritance tree
1261INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
1262INFO: "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
1263INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
1264INFO: "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
1265INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
1266INFO: analyzing "public.ci_builds_metadata"
1267INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1268INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
1269INFO: "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
1270INFO: analyzing "public.p_ci_builds" inheritance tree
1271INFO: analyzing "public.ci_builds"
1272INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1273INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
1274INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1275I, [2024-02-20T23:39:37.702916 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
1276INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1277INFO: analyzing "public.ci_pipeline_variables"
1278INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1279I, [2024-02-20T23:39:56.578165 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1280I, [2024-02-20T23:39:56.579329 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1281I, [2024-02-20T23:39:56.580192 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1282I, [2024-02-20T23:39:57.056903 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1283INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1284INFO: analyzing "public.ci_job_artifacts"
1285INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1286I, [2024-02-20T23:39:58.261023 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1287I, [2024-02-20T23:39:58.262398 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1288I, [2024-02-20T23:39:58.263205 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1289INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1290INFO: analyzing "public.ci_pipeline_variables"
1291INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1292# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/fix_allow_descendants_override_disabled_shared_runners_spec.rb. It took 1 minute 5.82 seconds. Expected to take 35.27 seconds.
1293# [RSpecRunTime] RSpec elapsed time: 20 minutes 30.72 seconds. Current RSS: ~1307M. load average: 0.98 1.02 1.09 1/283 439
1294# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/migrate_remediations_for_vulnerability_findings_spec.rb. Expected to take 30.06 seconds.
1295Gitlab::BackgroundMigration::MigrateRemediationsForVulnerabilityFindings
1296 without the presence of remediation key
1297 does not create any remediation
1298# [RSpecRunTime] RSpec elapsed time: 20 minutes 34.37 seconds. Current RSS: ~1305M. load average: 0.98 1.01 1.09 1/283 440
1299 with same raw_metadata for different projects
1300 creates new remediation for each project
1301# [RSpecRunTime] RSpec elapsed time: 20 minutes 37.87 seconds. Current RSS: ~1314M. load average: 0.98 1.01 1.09 1/283 441
1302 with remediation equals to an array of duplicated elements
1303 creates new remediation
1304# [RSpecRunTime] RSpec elapsed time: 20 minutes 42.31 seconds. Current RSS: ~1324M. load average: 0.91 1.00 1.08 1/283 442
1305 with remediation equals to an array of nil element
1306 does not create any remediation
1307# [RSpecRunTime] RSpec elapsed time: 20 minutes 45.46 seconds. Current RSS: ~1346M. load average: 0.91 1.00 1.08 1/283 443
1308 with remediation with empty string as the diff key
1309 does not create any remediation
1310# [RSpecRunTime] RSpec elapsed time: 20 minutes 48.6 seconds. Current RSS: ~1348M. load average: 0.83 0.98 1.08 1/283 444
1311 with existing remediations within raw_metadata
1312 creates new remediation
1313 when create throws exception other than ActiveRecord::RecordNotUnique
1314 rolls back all related transactions
1315# [RSpecRunTime] RSpec elapsed time: 20 minutes 55.07 seconds. Current RSS: ~1347M. load average: 0.85 0.98 1.07 1/283 445
1316 with existing remediation records
1317 does not create new remediation
1318# [RSpecRunTime] RSpec elapsed time: 20 minutes 58.37 seconds. Current RSS: ~1346M. load average: 0.78 0.96 1.07 1/283 446
1319# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/migrate_remediations_for_vulnerability_findings_spec.rb. It took 34.3 seconds. Expected to take 30.06 seconds.
1320# [RSpecRunTime] RSpec elapsed time: 21 minutes 5.06 seconds. Current RSS: ~1332M. load average: 0.80 0.97 1.07 1/283 447
1321# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/migrate_evidences_for_vulnerability_findings_spec.rb. Expected to take 24.38 seconds.
1322Gitlab::BackgroundMigration::MigrateEvidencesForVulnerabilityFindings
1323 with evidence equals to nil
1324 does not create any evidence
1325# [RSpecRunTime] RSpec elapsed time: 21 minutes 8.43 seconds. Current RSS: ~1328M. load average: 0.73 0.95 1.06 1/283 448
1326 without the presence of evidence key
1327 does not create any evidence
1328# [RSpecRunTime] RSpec elapsed time: 21 minutes 11.52 seconds. Current RSS: ~1340M. load average: 0.73 0.95 1.06 1/283 449
1329 with existing evidence records
1330 does not create new evidence
1331 with non-existing evidence
1332 creates a new evidence only to the non-existing evidence
1333# [RSpecRunTime] RSpec elapsed time: 21 minutes 17.72 seconds. Current RSS: ~1341M. load average: 0.77 0.95 1.06 1/283 450
1334 with existing evidence within raw_metadata
1335 creates new evidence for each finding
1336 when parse throws exception JSON::ParserError
1337 does not create new records
1338# [RSpecRunTime] RSpec elapsed time: 21 minutes 23.95 seconds. Current RSS: ~1340M. load average: 0.71 0.93 1.06 1/283 451
1339 with unsupported Unicode escape sequence
1340 does not create new evidence
1341# [RSpecRunTime] RSpec elapsed time: 21 minutes 27.07 seconds. Current RSS: ~1341M. load average: 0.71 0.93 1.06 1/283 452
1342# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/migrate_evidences_for_vulnerability_findings_spec.rb. It took 28.64 seconds. Expected to take 24.38 seconds.
1343# [RSpecRunTime] RSpec elapsed time: 21 minutes 33.74 seconds. Current RSS: ~1329M. load average: 0.68 0.92 1.05 1/283 453
1344# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_version_spec.rb. Expected to take 15.5 seconds.
1345Gitlab::BackgroundMigration::BackfillVsCodeSettingsVersion
1346 #perform
1347 when it finds vs_code_setting rows with version that is nil or zero
1348 sets version field with default value for setting type
1349# [RSpecRunTime] RSpec elapsed time: 21 minutes 44.86 seconds. Current RSS: ~1327M. load average: 0.73 0.92 1.05 1/283 454
1350 when it finds vs_code_setting rows with version that is not nil or zero
1351 does not set version field
1352# [RSpecRunTime] RSpec elapsed time: 21 minutes 47.68 seconds. Current RSS: ~1341M. load average: 0.75 0.93 1.05 1/283 455
1353INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1354INFO: analyzing "public.ci_pipeline_variables"
1355INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1356I, [2024-02-20T23:41:31.096374 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
1357I, [2024-02-20T23:41:31.097735 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1358I, [2024-02-20T23:41:31.098553 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1359I, [2024-02-20T23:41:31.534494 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
1360INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
1361INFO: analyzing "public.ci_job_artifacts"
1362INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1363I, [2024-02-20T23:41:32.718647 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
1364I, [2024-02-20T23:41:32.719839 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
1365I, [2024-02-20T23:41:32.720651 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
1366INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
1367INFO: analyzing "public.ci_pipeline_variables"
1368INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
1369# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_version_spec.rb. It took 31.39 seconds. Expected to take 15.5 seconds.
1370# [RSpecRunTime] RSpec elapsed time: 22 minutes 5.17 seconds. Current RSS: ~1328M. load average: 0.80 0.93 1.05 1/283 456
1371# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/fix_incoherent_packages_size_on_project_statistics_spec.rb. Expected to take 15.49 seconds.
1372Gitlab::BackgroundMigration::FixIncoherentPackagesSizeOnProjectStatistics
1373 #perform
1374 with incoherent packages_size
1375 behaves like enqueuing a buffered updates
1376 fixes the packages_size stat
1377# [RSpecRunTime] RSpec elapsed time: 22 minutes 8.83 seconds. Current RSS: ~1333M. load average: 0.82 0.93 1.05 1/283 457
1378 with updates waiting on redis
1379 behaves like enqueuing a buffered updates
1380 fixes the packages_size stat
1381# [RSpecRunTime] RSpec elapsed time: 22 minutes 12.04 seconds. Current RSS: ~1342M. load average: 0.82 0.93 1.05 1/283 458
1382 with no incoherent packages_size
1383 behaves like not updating project statistics
1384 does not change them
1385# [RSpecRunTime] RSpec elapsed time: 22 minutes 15.26 seconds. Current RSS: ~1340M. load average: 0.84 0.93 1.05 1/283 459
1386 #filter_batch
1387 selects all package size statistics
1388# [RSpecRunTime] RSpec elapsed time: 22 minutes 18.33 seconds. Current RSS: ~1339M. load average: 0.77 0.92 1.04 1/283 460
1389# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/fix_incoherent_packages_size_on_project_statistics_spec.rb. It took 19.76 seconds. Expected to take 15.49 seconds.
1390# [RSpecRunTime] RSpec elapsed time: 22 minutes 24.96 seconds. Current RSS: ~1330M. load average: 0.79 0.92 1.04 1/282 461
1391# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/rename_task_system_note_to_checklist_item_spec.rb. Expected to take 10.58 seconds.
1392Gitlab::BackgroundMigration::RenameTaskSystemNoteToChecklistItem
1393 updates in batches
1394 tracks timings of queries
1395 renames task to checklist item in task system notes that match
1396# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/rename_task_system_note_to_checklist_item_spec.rb. It took 15.81 seconds. Expected to take 10.58 seconds.
1397# [RSpecRunTime] RSpec elapsed time: 22 minutes 40.82 seconds. Current RSS: ~1316M. load average: 0.90 0.94 1.04 1/282 462
1398# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. Expected to take 9.99 seconds.
1399Gitlab::BackgroundMigration::SetCorrectVulnerabilityState
1400 #filter_batch
1401 filters out vulnerabilities where dismissed_at is null
1402# [RSpecRunTime] RSpec elapsed time: 22 minutes 44.23 seconds. Current RSS: ~1315M. load average: 0.91 0.94 1.04 1/282 463
1403 #perform
1404 changes vulnerability state to `dismissed` when dismissed_at is not nil
1405 does not change the state when dismissed_at is nil
1406# [RSpecRunTime] RSpec elapsed time: 22 minutes 50.32 seconds. Current RSS: ~1319M. load average: 0.92 0.94 1.04 1/282 464
1407# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. It took 17.1 seconds. Expected to take 9.99 seconds.
1408# [RSpecRunTime] RSpec elapsed time: 22 minutes 57.96 seconds. Current RSS: ~1315M. load average: 0.93 0.94 1.04 1/283 465
1409# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_cluster_agents_has_vulnerabilities_spec.rb. Expected to take 7.69 seconds.
1410Gitlab::BackgroundMigration::BackfillClusterAgentsHasVulnerabilities
1411 tracks timings of queries
1412 backfills `has_vulnerabilities` for the selected records
1413# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_cluster_agents_has_vulnerabilities_spec.rb. It took 13.21 seconds. Expected to take 7.69 seconds.
1414# [RSpecRunTime] RSpec elapsed time: 23 minutes 11.2 seconds. Current RSS: ~1331M. load average: 0.94 0.95 1.04 1/283 466
1415# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. Expected to take 7.42 seconds.
1416Gitlab::BackgroundMigration::BackfillHasRemediationsOfVulnerabilityReads
1417 does not modify has_remediations of vulnerabilities which do not have remediations
1418 when finding_remediation record exists
1419 updates vulnerability_reads records which has remediations
1420# [RSpecRunTime] RSpec elapsed time: 23 minutes 17.61 seconds. Current RSS: ~1340M. load average: 1.02 0.96 1.05 1/283 467
1421# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. It took 12.99 seconds. Expected to take 7.42 seconds.
1422# [RSpecRunTime] RSpec elapsed time: 23 minutes 24.22 seconds. Current RSS: ~1333M. load average: 1.02 0.97 1.04 1/283 468
1423# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb. Expected to take 3.74 seconds.
1424Gitlab::BackgroundMigration::Mailers::UnconfirmMailer
1425 contains abuse report url
1426# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb. It took 9.54 seconds. Expected to take 3.74 seconds.
1427# [RSpecRunTime] RSpec elapsed time: 23 minutes 33.8 seconds. Current RSS: ~1323M. load average: 0.86 0.93 1.03 1/283 469
1428# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/nullify_last_error_from_project_mirror_data_spec.rb. Expected to take 3.68 seconds.
1429Gitlab::BackgroundMigration::NullifyLastErrorFromProjectMirrorData
1430 nullifies last_error column on all rows
1431# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/nullify_last_error_from_project_mirror_data_spec.rb. It took 9.63 seconds. Expected to take 3.68 seconds.
1432# [RSpecRunTime] RSpec elapsed time: 23 minutes 43.47 seconds. Current RSS: ~1321M. load average: 0.81 0.92 1.03 1/283 470
1433# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb. Expected to take 3.53 seconds.
1434Gitlab::BackgroundMigration::UpdateUsersSetExternalIfServiceAccount
1435 #perform
1436 changes external field for service_account user
1437# [RSpecRunTime] RSpec elapsed time: 23 minutes 46.6 seconds. Current RSS: ~1316M. load average: 0.81 0.92 1.03 1/283 471
1438# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb. It took 9.64 seconds. Expected to take 3.53 seconds.
1439# [RSpecRunTime] RSpec elapsed time: 23 minutes 53.15 seconds. Current RSS: ~1318M. load average: 0.76 0.91 1.02 1/283 472
1440# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb. Expected to take 3.42 seconds.
1441Gitlab::BackgroundMigration::EncryptCiTriggerToken
1442 ensures all unencrypted tokens are encrypted
1443# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb. It took 9.61 seconds. Expected to take 3.42 seconds.
1444# [RSpecRunTime] RSpec elapsed time: 24 minutes 2.79 seconds. Current RSS: ~1317M. load average: 0.79 0.91 1.02 1/283 473
1445# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration_spec.rb. Expected to take 2.34 seconds.
1446Gitlab::BackgroundMigration
1447 .queue
1448 returns background migration worker queue
1449 .steal
1450 when the queue contains unprocessed jobs
1451 uses the coordinator to steal jobs
1452 when a custom predicate is given
1453 steals jobs that match the predicate
1454 does not steal jobs that do not match the predicate
1455 when retry_dead_jobs is true
1456 steals from the dead and retry queue
1457 .perform
1458 uses the coordinator to perform a background migration
1459 .exists?
1460 uses the coordinator to find if a job exists
1461 uses the coordinator to find a job does not exist
1462 .remaining
1463 uses the coordinator to find the number of remaining jobs
1464# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration_spec.rb. It took 0.86 second. Expected to take 2.34 seconds.
1465auto_explain log contains 1010 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-5-5.339.main.ndjson.gz
1466took 27.251859668
1467auto_explain log contains 1010 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-5-5.339.ci.ndjson.gz
1468took 25.228034921
1469[TEST PROF INFO] EventProf results for sql.active_record
1470Total time: 16:30.187 of 23:59.516 (68.79%)
1471Total events: 652817
1472Top 5 slowest suites (by time):
1473Gitlab::Backg...egistryImports (./spec/lib/gitlab/background_migration/reset_too_many_tags_skipped_registry_imports_spec.rb:5) – 02:16.336 (66818 / 1) of 02:57.291 (76.9%)
1474Gitlab::Backg...ReadsHasIssues (./spec/lib/gitlab/background_migration/fix_vulnerability_reads_has_issues_spec.rb:5) – 02:10.748 (64876 / 1) of 02:51.123 (76.41%)
1475Gitlab::Backg...InvalidMembers (./spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb:6) – 02:09.302 (71030 / 3) of 02:53.406 (74.57%)
1476Gitlab::Backg...urceLinkEvents (./spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb:5) – 01:59.445 (68523 / 7) of 02:40.061 (74.62%)
1477Gitlab::Backg...ntRepositories (./spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb:9) – 01:58.458 (60456 / 2) of 02:33.580 (77.13%)
1478Knapsack report was generated. Preview:
1479{
1480 "spec/lib/gitlab/background_migration/legacy_upload_mover_spec.rb": 94.94765778500005,
1481 "spec/lib/gitlab/background_migration/backfill_resource_link_events_spec.rb": 84.75498156399999,
1482 "spec/lib/gitlab/background_migration/destroy_invalid_members_spec.rb": 82.434186211,
1483 "spec/lib/gitlab/background_migration/backfill_design_management_repositories_spec.rb": 71.16271350099987,
1484 "spec/lib/gitlab/background_migration/fix_vulnerability_reads_has_issues_spec.rb": 75.7781503870001,
1485 "spec/lib/gitlab/background_migration/reset_too_many_tags_skipped_registry_imports_spec.rb": 79.79217858599986,
1486 "spec/lib/gitlab/background_migration/truncate_overlong_vulnerability_html_titles_spec.rb": 77.0143635999998,
1487 "spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb": 45.939797789000295,
1488 "spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb": 34.187053928999376,
1489 "spec/lib/gitlab/background_migration/fix_allow_descendants_override_disabled_shared_runners_spec.rb": 28.12107980900055,
1490 "spec/lib/gitlab/background_migration/migrate_remediations_for_vulnerability_findings_spec.rb": 27.73196104999988,
1491 "spec/lib/gitlab/background_migration/migrate_evidences_for_vulnerability_findings_spec.rb": 22.080360576000203,
1492 "spec/lib/gitlab/background_migration/backfill_vs_code_settings_version_spec.rb": 14.022653405999336,
1493 "spec/lib/gitlab/background_migration/fix_incoherent_packages_size_on_project_statistics_spec.rb": 13.240824821000388,
1494 "spec/lib/gitlab/background_migration/rename_task_system_note_to_checklist_item_spec.rb": 9.318363718999535,
1495 "spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb": 9.587630314999842,
1496 "spec/lib/gitlab/background_migration/backfill_cluster_agents_has_vulnerabilities_spec.rb": 6.839463457999955,
1497 "spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb": 6.49041504700017,
1498 "spec/lib/gitlab/background_migration/mailers/unconfirm_mailer_spec.rb": 3.215716059999977,
1499 "spec/lib/gitlab/background_migration/nullify_last_error_from_project_mirror_data_spec.rb": 3.2361137289999533,
1500 "spec/lib/gitlab/background_migration/update_users_set_external_if_service_account_spec.rb": 3.2173471899996002,
1501 "spec/lib/gitlab/background_migration/encrypt_ci_trigger_token_spec.rb": 3.1590093240001806,
1502 "spec/lib/gitlab/background_migration_spec.rb": 0.8549020819991711
1503}
1504Knapsack global time execution for tests: 13m 17s
1505Finished in 24 minutes 56 seconds (files took 44.97 seconds to load)
150688 examples, 0 failures
1507Randomized with seed 61454
1508[TEST PROF INFO] Time spent in factories: 00:49.020 (3.27% of total time)
1509RSpec exited with 0.
1510No examples to retry, congrats!
1511 Running after_script 00:09
1512Running after script...
1513$ echo -e "\e[0Ksection_start:`date +%s`:report_results_section[collapsed=true]\r\e[0KReport results"
1514 Report results 00:08
1525$ tooling/bin/push_job_metrics || true
1526[job-metrics] Pushing job metrics file for the CI/CD job.
1527[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
1528 Saving cache for successful job 00:01
1529Not uploading cache ruby-gems-debian-bookworm-ruby-3.1-16 due to policy
1530 Uploading artifacts for successful job 00:06
1531Uploading artifacts...
1532auto_explain/: found 3 matching artifact files and directories
1533coverage/: found 5 matching artifact files and directories
1534WARNING: crystalball/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1535WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1536knapsack/: found 4 matching artifact files and directories
1537rspec/: found 12 matching artifact files and directories
1538WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1539log/*.log: found 13 matching artifact files and directories
1540WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6218670755/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
1541WARNING: Retrying... context=artifacts-uploader error=request redirected
1542Uploading artifacts as "archive" to coordinator... 201 Created id=6218670755 responseStatus=201 Created token=glcbt-65
1543Uploading artifacts...
1544rspec/rspec-*.xml: found 1 matching artifact files and directories
1545WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6218670755/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
1546WARNING: Retrying... context=artifacts-uploader error=request redirected
1547Uploading artifacts as "junit" to coordinator... 201 Created id=6218670755 responseStatus=201 Created token=glcbt-65
1548 Cleaning up project directory and file based variables 00:00
1549Job succeeded