Skip to content
Snippets Groups Projects

rspec-ee migration pg14 single-db-ci-connection 2/2

Passed Started by
Krasimir Angelov
@krasio
1Running with gitlab-runner 17.0.0~pre.88.g761ae5dd (761ae5dd)
2 on green-4.shared-gitlab-org.runners-manager.gitlab.com/default x5QiHUKw, system ID: s_b9637080a79e
3 feature flags: FF_NETWORK_PER_BUILD:true
4Resolving secrets
5 Preparing the "docker+machine" executor 01:15
6Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.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:c6abddbb4223951cf5cb54a19d4a83418582fa69c97c0458ab4f0974f24f119c ...
20WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.
21WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.
22Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 ...
23Authenticating with credentials from job payload (GitLab Registry)
24Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 ...
25Using docker image sha256:df819140e3df737cdc7b8d6fb73ce804b05058c790e025b5f52840956feb1734 for registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:7bdf349fc3dd9da64bc6581d44c0e906bffd38977ddbd2668ba34adb5dedfe38 ...
26Starting service elasticsearch:7.17.6 ...
27Pulling docker image elasticsearch:7.17.6 ...
28Using docker image sha256:5fad10241ffd65d817ed0ddfaf6e87eee1f7dc2a7db33db1047835560ea71fda for elasticsearch:7.17.6 with digest elasticsearch@sha256:6c128de5d01c0c130a806022d6bd99b3e4c27a9af5bfc33b6b81861ae117d028 ...
29Starting service registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:latest ...
30Authenticating with credentials from job payload (GitLab Registry)
31Pulling docker image registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:latest ...
32Using docker image sha256:3c5f1e3ac1332b78854a67ecf17c55922502c097ba3ed70937f702c71f19f962 for registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:latest with digest registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway@sha256:c2c912f0676a3a3f4c804a2d3a170926653fb50791020260f13f5c408fcf4aa0 ...
33Waiting for services to be up and running (timeout 30 seconds)...
34Authenticating with credentials from job payload (GitLab Registry)
35Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.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 ...
36Using docker image sha256:d10d211334d3c94a5e626cf961467431b7d3f3bd8b6109e5caf9357421c0117b for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.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.2.patched-golang-1.21-rust-1.73-node-20.12-postgresql-14@sha256:3c4cd9a237deb59350b4836552151ba2aae96247034074c8f0c2ccaff4558cab ...
37 Preparing environment 00:01
38Running on runner-x5qihukw-project-278964-concurrent-0 via runner-x5qihukw-shared-gitlab-org-1717022422-ea9d7db1...
39 Getting source from Git repository 00:00
40Skipping Git repository setup
41Skipping Git checkout
42Skipping Git submodules setup
43 Restoring cache 00:16
44Checking cache for ruby-gems-debian-bookworm-ruby-3.2-17...
45cache.zip is up to date
46Successfully extracted cache
47 Downloading artifacts 00:43
48Downloading artifacts for clone-gitlab-repo (6975007209)...
49Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6975007209 responseStatus=200 OK token=glcbt-65
50WARNING: Part of .git directory is on the list of files to extract
51WARNING: This may introduce unexpected problems
52Downloading artifacts for compile-test-assets (6975007223)...
53Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6975007223 responseStatus=200 OK token=glcbt-65
54Downloading artifacts for detect-tests (6975007229)...
55Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6975007229 responseStatus=200 OK token=glcbt-65
56Downloading artifacts for retrieve-tests-metadata (6975007235)...
57Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6975007235 responseStatus=200 OK token=glcbt-65
58Downloading artifacts for setup-test-env (6975007225)...
59Downloading artifacts from coordinator... ok host=storage.googleapis.com id=6975007225 responseStatus=200 OK token=glcbt-65
60 Executing "step_script" stage of the job script
61Using docker image sha256:d10d211334d3c94a5e626cf961467431b7d3f3bd8b6109e5caf9357421c0117b for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.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.2.patched-golang-1.21-rust-1.73-node-20.12-postgresql-14@sha256:3c4cd9a237deb59350b4836552151ba2aae96247034074c8f0c2ccaff4558cab ...
62$ echo $FOSS_ONLY
63$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
64$ export GOPATH=$CI_PROJECT_DIR/.go
65$ mkdir -p $GOPATH
66$ source scripts/utils.sh
67$ source scripts/prepare_build.sh
68 Installing gems 00:17
768Using two connections, single database config (config/database.yml.postgresql)
769Geo DB will be set up.
770Embedding DB will be set up.
771 Setting up DBs 01:06
784$ source ./scripts/rspec_helpers.sh
785$ run_timed_command "gem install knapsack --no-document"
786$ gem install knapsack --no-document
787Successfully installed knapsack-4.0.0
7881 gem installed
789==> 'gem install knapsack --no-document' succeeded in 1 seconds.
790$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
791 Spawning Gitaly 00:05
795$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
796$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
797$ tooling/bin/create_job_metrics_file || true
798[job-metrics] Creating the job metrics file for the CI/CD job.
799$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
800 RSpec 13:54
801[23:33:06] Starting rspec_parallelized_job
802RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
803KNAPSACK_GENERATE_REPORT: true
804FLAKY_RSPEC_GENERATE_REPORT: true
805KNAPSACK_TEST_FILE_PATTERN: {ee/}spec/{migrations}{,/**/}*_spec.rb
806KNAPSACK_LOG_LEVEL: debug
807KNAPSACK_REPORT_PATH: knapsack/rspec-ee_migration_pg14_single-db-ci-connection_2_2_278964_report.json
808FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
809FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec-ee_migration_pg14_single-db-ci-connection_2_2_278964_report.json
810NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec-ee_migration_pg14_single-db-ci-connection_2_2_278964_report.json
811RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-6975007962.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!
821warning: parser/current is loading parser/ruby32, which recognizes 3.2.3-compliant syntax, but you are running 3.2.4.
822Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
823Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
824# [RSpecRunTime] Starting RSpec timer...
825[TEST PROF INFO] EventProf enabled (sql.active_record)
826unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
827Test environment set up in 2.289981678 seconds
828# [RSpecRunTime] Starting example group ee/spec/migrations/update_ci_max_total_yaml_size_bytes_default_value_spec.rb. Expected to take 2 minutes 8.27 seconds.
829UpdateCiMaxTotalYamlSizeBytesDefaultValue
830 #up
831main: == [advisory_lock_connection] object_id: 17416980, pg_backend_pid: 178
832main: == 20230808135859 UpdateCiMaxTotalYamlSizeBytesDefaultValue: migrating ========
833main: -- execute("UPDATE application_settings\nSET ci_max_total_yaml_size_bytes =\nCASE WHEN max_yaml_size_bytes * ci_max_includes >= 2147483647\nTHEN 2147483647 ELSE max_yaml_size_bytes * ci_max_includes END\n")
834main: -> 0.0032s
835main: == 20230808135859 UpdateCiMaxTotalYamlSizeBytesDefaultValue: migrated (0.0133s)
836main: == [advisory_lock_connection] object_id: 17416980, pg_backend_pid: 178
837 #up
838 when the value is larger than 2147483647 (max int value)
839main: == [advisory_lock_connection] object_id: 18032920, pg_backend_pid: 181
840main: == 20230808135859 UpdateCiMaxTotalYamlSizeBytesDefaultValue: migrating ========
841main: -- execute("UPDATE application_settings\nSET ci_max_total_yaml_size_bytes =\nCASE WHEN max_yaml_size_bytes * ci_max_includes >= 2147483647\nTHEN 2147483647 ELSE max_yaml_size_bytes * ci_max_includes END\n")
842main: -> 0.0031s
843main: == 20230808135859 UpdateCiMaxTotalYamlSizeBytesDefaultValue: migrated (0.0122s)
844main: == [advisory_lock_connection] object_id: 18032920, pg_backend_pid: 181
845 sets it to 2147483647
846INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
847INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
848INFO: "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
849INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
850INFO: "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
851INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
852INFO: "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
853INFO: analyzing "public.p_ci_job_annotations" inheritance tree
854INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
855INFO: "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
856INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
857INFO: "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
858INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
859INFO: "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
860INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
861INFO: analyzing "public.ci_builds_metadata"
862INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
863INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
864INFO: "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
865INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
866INFO: "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
867INFO: analyzing "public.p_ci_builds" inheritance tree
868INFO: analyzing "public.ci_builds"
869INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
870INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
871INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
872INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
873INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
874INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
875INFO: analyzing "public.ci_pipeline_variables"
876INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
877INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
878INFO: analyzing "public.ci_pipeline_variables"
879INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
880INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
881INFO: analyzing "public.ci_job_artifacts"
882INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
883INFO: analyzing "public.p_ci_stages" inheritance tree
884INFO: analyzing "public.ci_stages"
885INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
886# [RSpecRunTime] Finishing example group ee/spec/migrations/update_ci_max_total_yaml_size_bytes_default_value_spec.rb. It took 3 minutes 10.0 seconds. Expected to take 2 minutes 8.27 seconds.
887# [RSpecRunTime] RSpec elapsed time: 3 minutes 15.86 seconds. Current RSS: ~1125M. Threads: 2. load average: 1.06 1.29 1.21 1/394 406
888.
889# [RSpecRunTime] Starting example group ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb. Expected to take 1 minute 52.15 seconds.
890QueueUpdateWorkspacesConfigVersion
891main: == [advisory_lock_connection] object_id: 52811520, pg_backend_pid: 215
892main: == 20230910120000 QueueUpdateWorkspacesConfigVersion: migrating ===============
893main: == 20230910120000 QueueUpdateWorkspacesConfigVersion: migrated (0.0697s) ======
894main: == [advisory_lock_connection] object_id: 52811520, pg_backend_pid: 215
895 schedules a new batched migration
896INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
897INFO: analyzing "public.ci_pipeline_variables"
898INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
899INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
900INFO: analyzing "public.ci_pipeline_variables"
901INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
902INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
903INFO: analyzing "public.ci_job_artifacts"
904INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
905INFO: analyzing "public.p_ci_stages" inheritance tree
906INFO: analyzing "public.ci_stages"
907INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
908# [RSpecRunTime] Finishing example group ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb. It took 2 minutes 49.42 seconds. Expected to take 1 minute 52.15 seconds.
909# [RSpecRunTime] RSpec elapsed time: 6 minutes 5.7 seconds. Current RSS: ~1135M. Threads: 2. load average: 0.84 1.15 1.17 3/394 408
910.
911# [RSpecRunTime] Starting example group ee/spec/migrations/20230909120000_queue_backfill_workspace_personal_access_token_spec.rb. Expected to take 1 minute 45.72 seconds.
912QueueBackfillWorkspacePersonalAccessToken
913main: == [advisory_lock_connection] object_id: 87006900, pg_backend_pid: 250
914main: == 20230909120000 QueueBackfillWorkspacePersonalAccessToken: migrating ========
915main: == 20230909120000 QueueBackfillWorkspacePersonalAccessToken: migrated (0.0618s)
916main: == [advisory_lock_connection] object_id: 87006900, pg_backend_pid: 250
917 schedules a new batched migration
918INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
919INFO: analyzing "public.ci_pipeline_variables"
920INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
921INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
922INFO: analyzing "public.ci_pipeline_variables"
923INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
924INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
925INFO: analyzing "public.ci_job_artifacts"
926INFO: "ci_job_artifacts": 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_stages" inheritance tree
928INFO: analyzing "public.ci_stages"
929INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
930# [RSpecRunTime] Finishing example group ee/spec/migrations/20230909120000_queue_backfill_workspace_personal_access_token_spec.rb. It took 2 minutes 50.92 seconds. Expected to take 1 minute 45.72 seconds.
931# [RSpecRunTime] RSpec elapsed time: 8 minutes 56.68 seconds. Current RSS: ~1131M. Threads: 2. load average: 1.10 1.14 1.16 1/398 409
932.
933# [RSpecRunTime] Starting example group ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb. Expected to take 21.07 seconds.
934MigrateLfsObjectsToSeparateRegistry
935 #up
936geo: == [advisory_lock_connection] object_id: 105124080, pg_backend_pid: 285
937== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============
938-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")
939 -> 0.0011s
940-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")
941 -> 0.0033s
942-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")
943 -> 0.0024s
944-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")
945 -> 0.0016s
946== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0237s) =====
947geo: == [advisory_lock_connection] object_id: 105124080, pg_backend_pid: 285
948 migrates all file registries for LFS objects to its own data table
949geo: == [advisory_lock_connection] object_id: 105860720, pg_backend_pid: 292
950== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============
951-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")
952 -> 0.0012s
953-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")
954 -> 0.0032s
955-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")
956 -> 0.0025s
957-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")
958 -> 0.0015s
959== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0236s) =====
960geo: == [advisory_lock_connection] object_id: 105860720, pg_backend_pid: 292
961 creates a new lfs object registry with the trigger
962geo: == [advisory_lock_connection] object_id: 106437280, pg_backend_pid: 298
963== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============
964-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")
965 -> 0.0011s
966-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")
967 -> 0.0027s
968-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")
969 -> 0.0024s
970-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")
971 -> 0.0013s
972== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0309s) =====
973geo: == [advisory_lock_connection] object_id: 106437280, pg_backend_pid: 298
974 updates a new lfs object with the trigger
975geo: == [advisory_lock_connection] object_id: 107159600, pg_backend_pid: 304
976== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============
977-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")
978 -> 0.0013s
979-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")
980 -> 0.0032s
981-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")
982 -> 0.0031s
983-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")
984 -> 0.0014s
985== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0240s) =====
986geo: == [advisory_lock_connection] object_id: 107159600, pg_backend_pid: 304
987 creates a new lfs object using the next ID
988# [RSpecRunTime] RSpec elapsed time: 9 minutes 13.08 seconds. Current RSS: ~1133M. Threads: 2. load average: 1.06 1.13 1.16 1/398 410
989.
990 #down
991geo: == [advisory_lock_connection] object_id: 107733320, pg_backend_pid: 310
992== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrating ==============
993-- execute("LOCK TABLE file_registry IN EXCLUSIVE MODE")
994 -> 0.0014s
995-- execute("INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\nSELECT created_at, retry_at, file_id, bytes, retry_count, missing_on_primary, success, sha256::bytea\nFROM file_registry WHERE file_type = 'lfs'\n")
996 -> 0.0031s
997-- execute("CREATE OR REPLACE FUNCTION replicate_lfs_object_registry()\nRETURNS trigger AS\n$BODY$\nBEGIN\n IF (TG_OP = 'UPDATE') THEN\n UPDATE lfs_object_registry\n SET (retry_at, bytes, retry_count, missing_on_primary, success, sha256) =\n (NEW.retry_at, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea)\n WHERE lfs_object_id = NEW.file_id;\n ELSEIF (TG_OP = 'INSERT') THEN\n INSERT INTO lfs_object_registry (created_at, retry_at, lfs_object_id, bytes, retry_count, missing_on_primary, success, sha256)\n VALUES (NEW.created_at, NEW.retry_at, NEW.file_id, NEW.bytes, NEW.retry_count, NEW.missing_on_primary, NEW.success, NEW.sha256::bytea);\nEND IF;\nRETURN NEW;\nEND;\n$BODY$\nLANGUAGE 'plpgsql'\nVOLATILE;\n")
998 -> 0.0025s
999-- execute("CREATE TRIGGER replicate_lfs_object_registry\nAFTER INSERT OR UPDATE ON file_registry\nFOR EACH ROW WHEN (NEW.file_type = 'lfs') EXECUTE PROCEDURE replicate_lfs_object_registry();\n")
1000 -> 0.0015s
1001== 20191010204941 MigrateLfsObjectsToSeparateRegistry: migrated (0.0247s) =====
1002geo: == [advisory_lock_connection] object_id: 107733320, pg_backend_pid: 310
1003 rolls back data properly
1004# [RSpecRunTime] RSpec elapsed time: 9 minutes 17.01 seconds. Current RSS: ~1126M. Threads: 2. load average: 1.06 1.13 1.16 1/398 411
1005.
1006# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb. It took 29.38 seconds. Expected to take 21.07 seconds.
1007# [RSpecRunTime] RSpec elapsed time: 9 minutes 26.11 seconds. Current RSS: ~1123M. Threads: 2. load average: 1.05 1.12 1.16 1/398 412
1008.
1009# [RSpecRunTime] Starting example group ee/spec/migrations/geo/fix_state_column_in_file_registry_spec.rb. Expected to take 4.79 seconds.
1010FixStateColumnInFileRegistry
1011geo: == [advisory_lock_connection] object_id: 108611660, pg_backend_pid: 351
1012== 20210818111211 FixStateColumnInFileRegistry: migrating =====================
1013-- exec_query("SELECT COUNT(*) AS count FROM \"file_registry\" WHERE \"file_registry\".\"success\" = TRUE")
1014 -> 0.0038s
1015-- exec_query("SELECT \"file_registry\".\"id\" FROM \"file_registry\" WHERE \"file_registry\".\"success\" = TRUE ORDER BY \"file_registry\".\"id\" ASC LIMIT 1")
1016 -> 0.0019s
1017-- exec_query("SELECT \"file_registry\".\"id\" FROM \"file_registry\" WHERE \"file_registry\".\"id\" >= 23 AND \"file_registry\".\"success\" = TRUE ORDER BY \"file_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
1018 -> 0.0020s
1019-- transaction(nil)
1020-- execute("UPDATE \"file_registry\" SET \"state\" = 2 WHERE \"file_registry\".\"id\" >= 23 AND \"file_registry\".\"id\" < 25 AND \"file_registry\".\"success\" = TRUE")
1021 -> 0.0026s
1022 -> 0.0054s
1023-- exec_query("SELECT \"file_registry\".\"id\" FROM \"file_registry\" WHERE \"file_registry\".\"id\" >= 25 AND \"file_registry\".\"success\" = TRUE ORDER BY \"file_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
1024 -> 0.0019s
1025-- transaction(nil)
1026-- execute("UPDATE \"file_registry\" SET \"state\" = 2 WHERE \"file_registry\".\"id\" >= 25 AND \"file_registry\".\"success\" = TRUE")
1027 -> 0.0025s
1028 -> 0.0036s
1029== 20210818111211 FixStateColumnInFileRegistry: migrated (0.0208s) ============
1030geo: == [advisory_lock_connection] object_id: 108611660, pg_backend_pid: 351
1031 correctly sets registry state value
1032# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/fix_state_column_in_file_registry_spec.rb. It took 12.96 seconds. Expected to take 4.79 seconds.
1033# [RSpecRunTime] RSpec elapsed time: 9 minutes 39.12 seconds. Current RSS: ~1124M. Threads: 2. load average: 0.89 1.08 1.14 1/398 413
1034.
1035# [RSpecRunTime] Starting example group ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb. Expected to take 4.57 seconds.
1036FixStateColumnInLfsObjectRegistry
1037geo: == [advisory_lock_connection] object_id: 109513160, pg_backend_pid: 387
1038== 20210624160455 FixStateColumnInLfsObjectRegistry: migrating ================
1039-- exec_query("SELECT COUNT(*) AS count FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"success\" = TRUE")
1040 -> 0.0021s
1041-- exec_query("SELECT \"lfs_object_registry\".\"id\" FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"success\" = TRUE ORDER BY \"lfs_object_registry\".\"id\" ASC LIMIT 1")
1042 -> 0.0019s
1043-- exec_query("SELECT \"lfs_object_registry\".\"id\" FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"id\" >= 19 AND \"lfs_object_registry\".\"success\" = TRUE ORDER BY \"lfs_object_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
1044 -> 0.0019s
1045-- transaction(nil)
1046-- execute("UPDATE \"lfs_object_registry\" SET \"state\" = 2 WHERE \"lfs_object_registry\".\"id\" >= 19 AND \"lfs_object_registry\".\"id\" < 21 AND \"lfs_object_registry\".\"success\" = TRUE")
1047 -> 0.0026s
1048 -> 0.0039s
1049-- exec_query("SELECT \"lfs_object_registry\".\"id\" FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"id\" >= 21 AND \"lfs_object_registry\".\"success\" = TRUE ORDER BY \"lfs_object_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
1050 -> 0.0018s
1051-- transaction(nil)
1052-- execute("UPDATE \"lfs_object_registry\" SET \"state\" = 2 WHERE \"lfs_object_registry\".\"id\" >= 21 AND \"lfs_object_registry\".\"success\" = TRUE")
1053 -> 0.0023s
1054 -> 0.0036s
1055== 20210624160455 FixStateColumnInLfsObjectRegistry: migrated (0.0173s) =======
1056geo: == [advisory_lock_connection] object_id: 109513160, pg_backend_pid: 387
1057 correctly sets registry state value
1058# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb. It took 13.06 seconds. Expected to take 4.57 seconds.
1059# [RSpecRunTime] RSpec elapsed time: 9 minutes 52.24 seconds. Current RSS: ~1124M. Threads: 2. load average: 0.91 1.08 1.14 1/398 414
1060.
1061auto_explain log contains 930 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-migration-pg14-single-db-ci-connection-2-2.341.main.ndjson.gz
1062took 15.352122024
1063auto_explain log contains 931 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-migration-pg14-single-db-ci-connection-2-2.341.ci.ndjson.gz
1064took 12.92640858
1065[TEST PROF INFO] EventProf results for sql.active_record
1066Total time: 05:47.034 of 09:46.429 (59.18%)
1067Total events: 263176
1068Top 5 slowest suites (by time):
1069UpdateCiMaxTo...esDefaultValue (./ee/spec/migrations/update_ci_max_total_yaml_size_bytes_default_value_spec.rb:6) – 01:52.659 (78096 / 2) of 03:10.417 (59.16%)
1070QueueBackfill...nalAccessToken (./ee/spec/migrations/20230909120000_queue_backfill_workspace_personal_access_token_spec.rb:6) – 01:41.914 (72198 / 1) of 02:50.968 (59.61%)
1071QueueUpdateWo...sConfigVersion (./ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb:6) – 01:41.179 (72170 / 1) of 02:49.477 (59.7%)
1072MigrateLfsObj...parateRegistry (./ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb:6) – 00:15.870 (20582 / 5) of 00:29.433 (53.92%)
1073FixStateColum...ObjectRegistry (./ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb:7) – 00:07.725 (10078 / 1) of 00:13.120 (58.88%)
1074Knapsack report was generated. Preview:
1075{
1076 "ee/spec/migrations/update_ci_max_total_yaml_size_bytes_default_value_spec.rb": 114.69901841799992,
1077 "ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb": 98.81525290799982,
1078 "ee/spec/migrations/20230909120000_queue_backfill_workspace_personal_access_token_spec.rb": 100.327727675,
1079 "ee/spec/migrations/geo/migrate_lfs_objects_to_separate_registry_spec.rb": 20.45434492000004,
1080 "ee/spec/migrations/geo/fix_state_column_in_file_registry_spec.rb": 4.631559037000443,
1081 "ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb": 4.683753098000125
1082}
1083Knapsack global time execution for tests: 05m 43s
1084Finished in 10 minutes 21 seconds (files took 1 minute 51.8 seconds to load)
108511 examples, 0 failures
1086Randomized with seed 27976
1087[TEST PROF INFO] Time spent in factories: 00:00.081 (0.01% of total time)
1088RSpec exited with 0.
1089No examples to retry, congrats!
1090 Running after_script 00:07
1091Running after script...
1092$ source scripts/utils.sh
1093$ bundle exec gem list gitlab_quality-test_tooling
1094gitlab_quality-test_tooling (1.26.0)
1095$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
1096 Report test failures 00:00
1098$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
1099 Report test flakiness 00:00
1101$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
1102 Report test slowness 00:00
1104$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
1105 Report test slowness in MR note 00:02
1108$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
1109 Report test files close to timing out 00:01
1112$ tooling/bin/push_job_metrics || true
1113[job-metrics] Pushing job metrics file for the CI/CD job.
1114[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
1115 Saving cache for successful job 00:00
1116Not uploading cache ruby-gems-debian-bookworm-ruby-3.2-17 due to policy
1117 Uploading artifacts for successful job 00:05
1118Uploading artifacts...
1119auto_explain/: found 3 matching artifact files and directories
1120coverage/: found 5 matching artifact files and directories
1121crystalball/: found 2 matching artifact files and directories
1122WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1123knapsack/: found 4 matching artifact files and directories
1124rspec/: found 16 matching artifact files and directories
1125WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
1126log/*.log: found 13 matching artifact files and directories
1127WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6975007962/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
1128WARNING: Retrying... context=artifacts-uploader error=request redirected
1129Uploading artifacts as "archive" to coordinator... 201 Created id=6975007962 responseStatus=201 Created token=glcbt-65
1130Uploading artifacts...
1131rspec/rspec-*.xml: found 1 matching artifact files and directories
1132WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/6975007962/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
1133WARNING: Retrying... context=artifacts-uploader error=request redirected
1134Uploading artifacts as "junit" to coordinator... 201 Created id=6975007962 responseStatus=201 Created token=glcbt-65
1135 Cleaning up project directory and file based variables 00:01
1136Job succeeded