Skip to content
Snippets Groups Projects

rspec background_migration pg14 single-db-ci-connection 10/17

Passed Started by
Simon Tomlinson
@stomlinson
Log timestamps in UTC.
122:07:53Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
222:07:53 on blue-2.private.runners-manager.gitlab.com/gitlab.com/gitlab-org QvBVRoXM, system ID: s_49b872f8ccf6
322:07:53 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
422:07:53Resolving secrets
5 22:07:53 Preparing the "docker+machine" executor 00:09
622:07:53Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
722:07:55Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
822:07:55Authenticating with credentials from job payload (GitLab Registry)
922:07:55Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1022:07:55Using 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 ...
1122:07:56WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1222:07:56WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1322:07:56Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1422:07:56Authenticating with credentials from job payload (GitLab Registry)
1522:07:56Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1622:07:56Using 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 ...
1722:07:57Starting service redis:6.2-alpine...
1822:07:57Pulling docker image redis:6.2-alpine ...
1922:07:57Using docker image sha256:4100b5bd17430263e85ad9d8ab851959b234acaaf378e093f1f98400f4998815 for redis:6.2-alpine with digest redis@sha256:eaba718fecd1196d88533de7ba49bf903ad33664a92debb24660a922ecd9cac8 ...
2022:07:58Waiting for services to be up and running (timeout 30 seconds)...
2122:08:01Authenticating with credentials from job payload (GitLab Registry)
2222:08:01Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
2322:08:02Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-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.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
24 22:08:02 Preparing environment 00:00
2522:08:02Running on runner-qvbvroxm-project-278964-concurrent-0 via runner-qvbvroxm-private-1731530690-26d13619...
26 22:08:02 Getting source from Git repository 00:01
2722:08:03Skipping Git repository setup
2822:08:03Skipping Git checkout
2922:08:03Skipping Git submodules setup
30 22:08:03 Restoring cache 00:18
3122:08:03Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20...
3222:08:04cache.zip is up to date
3322:08:15Successfully extracted cache
34 22:08:21 Downloading artifacts 00:46
3522:08:22Downloading artifacts for clone-gitlab-repo (8353286583)...
3622:08:27Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286583 responseStatus=200 OK token=glcbt-66
3722:08:27WARNING: Part of .git directory is on the list of files to extract
3822:08:27WARNING: This may introduce unexpected problems
3922:08:39Downloading artifacts for compile-test-assets (8353286630)...
4022:08:43Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286630 responseStatus=200 OK token=glcbt-66
4122:08:49Downloading artifacts for detect-tests (8353286649)...
4222:08:49Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286649 responseStatus=200 OK token=glcbt-66
4322:08:49Downloading artifacts for retrieve-tests-metadata (8353286664)...
4422:08:50Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286664 responseStatus=200 OK token=glcbt-66
4522:08:50Downloading artifacts for setup-test-env (8353286635)...
4622:08:55Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286635 responseStatus=200 OK token=glcbt-66
47 22:09:07 Executing "step_script" stage of the job script
4822:09:07Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-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.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
4922:09:08$ echo $FOSS_ONLY
5022:09:08$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
5122:09:08$ export GOPATH=$CI_PROJECT_DIR/.go
5222:09:08$ mkdir -p $GOPATH
5322:09:08$ source scripts/utils.sh
5422:09:08$ log_disk_usage "true"
5522:09:08*******************************************************
5622:09:08This runner currently has 77G free disk space.
5722:09:08*******************************************************
58 22:09:08 Disk usage detail 00:09
5922:09:08df -h
6022:09:08Filesystem Size Used Avail Use% Mounted on
6122:09:08overlay 95G 19G 77G 20% /
6222:09:08tmpfs 64M 0 64M 0% /dev
6322:09:08shm 64M 0 64M 0% /dev/shm
6422:09:08/dev/sda1 95G 19G 77G 20% /cache
6522:09:08tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6622:09:08du -h -d 1
6722:09:087.4M ./workhorse
6822:09:08148K ./bin
6922:09:081.2M ./.gitlab
7022:09:08167M ./.git
7122:09:084.0K ./builds
7222:09:0828M ./lib
7322:09:088.0K ./.vscode
7422:09:08560K ./storybook
7522:09:0824K ./log
7622:09:081.8M ./data
7722:09:0811M ./qa
7822:09:083.2M ./.rubocop_todo
7922:09:08856M ./vendor
8022:09:081023M ./public
8122:09:0862M ./doc
8222:09:08484K ./danger
8322:09:0832K ./rspec
8422:09:08556K ./tooling
8522:09:08145M ./ee
8622:09:081.3M ./knapsack
8722:09:08300K ./patches
8822:09:084.3M ./changelogs
8922:09:0820K ./haml_lint
9022:09:0828K ./metrics_server
9122:09:08108K ./keeps
9222:09:0836K ./shared
9322:09:0844K ./generator_templates
9422:09:081.3M ./scripts
9522:09:08763M ./tmp
9622:09:08127M ./spec
9722:09:0820K ./file_hooks
9822:09:0832K ./crystalball
9922:09:0816K ./sidekiq_cluster
10022:09:0817M ./gems
10122:09:081.2M ./fixtures
10222:09:08964K ./rubocop
10322:09:084.0K ./.go
10422:09:0833M ./db
10522:09:0812K ./.github
10622:09:08129M ./locale
10722:09:0820M ./config
10822:09:0882M ./app
10922:09:0820K ./.lefthook
11022:09:083.5G .
11122:09:08$ source scripts/prepare_build.sh
112 22:09:08 Installing gems 00:19
14322:09:27Using two connections, single database config (config/database.yml.postgresql)
14422:09:27Geo DB won't be set up.
14522:09:27Embedding DB won't be set up.
146 22:09:27 Setting up DBs 00:49
15922:10:16$ source ./scripts/rspec_helpers.sh
16022:10:16$ run_timed_command "gem install knapsack --no-document"
16122:10:15$ gem install knapsack --no-document
16222:10:17Successfully installed knapsack-4.0.0
16322:10:171 gem installed
16422:10:16==> 'gem install knapsack --no-document' succeeded in 1 seconds.
16522:10:17$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
166 22:10:17 Spawning Gitaly 00:04
17022:10:21$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
17122:10:21$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
17222:10:21$ tooling/bin/create_job_metrics_file || true
17322:10:23[job-metrics] Creating the job metrics file for the CI/CD job.
17422:10:23$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
175 22:10:23 RSpec 29:59
17622:10:23[22:10:23] Starting rspec_parallelized_job
17722:10:17RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
17822:10:24KNAPSACK_GENERATE_REPORT: true
17922:10:24FLAKY_RSPEC_GENERATE_REPORT: true
18022:10:24KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
18122:10:24KNAPSACK_LOG_LEVEL: debug
18222:10:24KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_single-db-ci-connection_10_17_278964_report.json
18322:10:24FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
18422:10:24FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_single-db-ci-connection_10_17_278964_report.json
18522:10:24NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_single-db-ci-connection_10_17_278964_report.json
18622:10:24RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8353287367.txt
18722:10:24CRYSTALBALL:
18822:10:24RSPEC_TESTS_MAPPING_ENABLED:
18922:10:24RSPEC_TESTS_FILTER_FILE:
19022:10:24Shell set options (set -o) enabled:
19122:10:24braceexpand on
19222:10:24hashall on
19322:10:24interactive-comments on
19422:10:24pipefail on
19522:10:29Knapsack report generator started!
19622:10:24/builds/gitlab-org/gitlab/vendor/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!
19722:11:03DEPRECATION WARNING: Support for Rails versions < 7.1 is deprecated and will be removed from ViewComponent 4.0.0 (ViewComponent v4 will remove support for Rails versions < 7.1 no earlier than April 1, 2025) (called from <top (required)> at /builds/gitlab-org/gitlab/config/environment.rb:7)
19822:11:13warning: parser/current is loading parser/ruby32, which recognizes 3.2.6-compliant syntax, but you are running 3.2.5.
19922:11:13Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
20022:11:16Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
20122:11:16# [RSpecRunTime] Starting RSpec timer...
20222:11:16[TEST PROF INFO] EventProf enabled (sql.active_record)
20322:11:16unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20422:11:25Test environment set up in 3.277229935 seconds
20522:11:26# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_orphaned_packages_dependencies_spec.rb. Expected to take 2 minutes 26.26 seconds.
20622:11:26Gitlab::BackgroundMigration::DeleteOrphanedPackagesDependencies
20722:13:22 executes 3 queries
20822:13:38 deletes only orphaned dependencies
20922:14:03INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
21022:14:03INFO: analyzing "public.ci_pipeline_variables"
21122:14:03INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
21222:14:05INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
21322:14:05INFO: analyzing "public.ci_pipeline_variables"
21422:14:05INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
21522:14:09INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
21622:14:09INFO: analyzing "public.ci_job_artifacts"
21722:14:09INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
21822:14:13INFO: analyzing "public.p_ci_stages" inheritance tree
21922:14:13INFO: analyzing "public.ci_stages"
22022:14:13INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22122:15:11INFO: analyzing "public.p_ci_pipelines" inheritance tree
22222:15:11INFO: analyzing "public.ci_pipelines"
22322:15:11INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22422:15:49# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_orphaned_packages_dependencies_spec.rb. It took 4 minutes 23.66 seconds. Expected to take 2 minutes 26.26 seconds.
22522:15:49# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb. Expected to take 2 minutes 0.24 second.
22622:15:49Gitlab::BackgroundMigration::BackfillVsCodeSettingsUuid
22722:17:23 #perform
22822:17:23 when it finds vs_code_setting rows with empty uuid
22922:17:38 populates uuid column with a generated uuid
23022:17:38# [RSpecRunTime] RSpec elapsed time: 6 minutes 21.77 seconds. Current RSS: ~1171M. Threads: 1. load average: 1.26 1.31 1.53 1/276 387
23122:17:38.
23222:17:38 when it finds vs_code_setting rows with non-empty uuid
23322:17:53 populates uuid column with a generated uuid
23422:17:53# [RSpecRunTime] RSpec elapsed time: 6 minutes 36.37 seconds. Current RSS: ~1164M. Threads: 1. load average: 1.20 1.29 1.52 1/276 388
23522:17:53.
23622:18:03INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
23722:18:03INFO: analyzing "public.ci_pipeline_variables"
23822:18:03INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23922:18:05INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
24022:18:05INFO: analyzing "public.ci_pipeline_variables"
24122:18:05INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24222:18:10INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
24322:18:10INFO: analyzing "public.ci_job_artifacts"
24422:18:10INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24522:18:14INFO: analyzing "public.p_ci_stages" inheritance tree
24622:18:14INFO: analyzing "public.ci_stages"
24722:18:14INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24822:19:14INFO: analyzing "public.p_ci_pipelines" inheritance tree
24922:19:14INFO: analyzing "public.ci_pipelines"
25022:19:14INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
25122:19:53# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb. It took 4 minutes 3.56 seconds. Expected to take 2 minutes 0.24 second.
25222:19:53# [RSpecRunTime] RSpec elapsed time: 8 minutes 36.4 seconds. Current RSS: ~1163M. Threads: 1. load average: 0.98 1.17 1.45 1/276 389
25322:19:53.
25422:19:53# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_work_item_parent_links_namespace_id_spec.rb. Expected to take 1 minute 39.88 seconds.
25522:19:53Gitlab::BackgroundMigration::BackfillWorkItemParentLinksNamespaceId
25622:21:12 constructs a valid query
25722:21:22 performs without error
25822:22:15INFO: analyzing "public.p_ci_pipelines" inheritance tree
25922:22:15INFO: analyzing "public.ci_pipelines"
26022:22:15INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
26122:22:54# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_work_item_parent_links_namespace_id_spec.rb. It took 3 minutes 1.36 seconds. Expected to take 1 minute 39.88 seconds.
26222:22:54# [RSpecRunTime] RSpec elapsed time: 11 minutes 37.81 seconds. Current RSS: ~1165M. Threads: 1. load average: 1.23 1.16 1.39 1/276 390
26322:22:54.
26422:22:54# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb. Expected to take 1 minute 18.12 seconds.
26522:22:54Gitlab::BackgroundMigration::BackfillVulnerabilityStateTransitionsProjectId
26622:23:57 constructs a valid query
26722:24:06 performs without error
26822:24:42INFO: analyzing "public.p_ci_pipelines" inheritance tree
26922:24:42INFO: analyzing "public.ci_pipelines"
27022:24:42INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
27122:25:21# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb. It took 2 minutes 26.81 seconds. Expected to take 1 minute 18.12 seconds.
27222:25:21# [RSpecRunTime] RSpec elapsed time: 14 minutes 4.66 seconds. Current RSS: ~1166M. Threads: 1. load average: 0.96 1.09 1.33 1/277 391
27322:25:21.
27422:25:21# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb. Expected to take 1 minute 14.91 seconds.
27522:25:21Gitlab::BackgroundMigration::BackfillProjectRepositories
27622:25:22 Gitlab::BackgroundMigration::BackfillProjectRepositories::ShardFinder
27722:25:22 #find_shard_id
27822:25:27 creates a new shard when it does not exist yet
27922:25:32 returns the shard when it exists
28022:25:37 only queries the database once to retrieve shards
28122:25:37# [RSpecRunTime] RSpec elapsed time: 14 minutes 20.72 seconds. Current RSS: ~1157M. Threads: 1. load average: 1.12 1.12 1.33 1/277 392
28222:25:37.
28322:25:37 Gitlab::BackgroundMigration::BackfillProjectRepositories::Project
28422:25:37 .on_hashed_storage
28522:25:46 finds projects with repository on hashed storage
28622:25:46# [RSpecRunTime] RSpec elapsed time: 14 minutes 29.59 seconds. Current RSS: ~1209M. Threads: 3. load average: 1.18 1.13 1.34 1/288 404
28722:25:46.
28822:25:46 .on_legacy_storage
28922:25:54 finds projects with repository on legacy storage
29022:25:54# [RSpecRunTime] RSpec elapsed time: 14 minutes 37.92 seconds. Current RSS: ~1201M. Threads: 3. load average: 1.16 1.13 1.33 1/288 405
29122:25:54.
29222:25:54 .without_project_repository
29322:26:03 finds projects which do not have a projects_repositories entry
29422:26:03# [RSpecRunTime] RSpec elapsed time: 14 minutes 46.58 seconds. Current RSS: ~1200M. Threads: 3. load average: 1.14 1.12 1.33 1/288 406
29522:26:03.
29622:26:03 #disk_path
29722:26:03 for projects on hashed storage
29822:26:11 returns the correct disk_path
29922:26:11# [RSpecRunTime] RSpec elapsed time: 14 minutes 54.98 seconds. Current RSS: ~1207M. Threads: 3. load average: 1.42 1.18 1.35 1/288 407
30022:26:11.
30122:26:11 for projects on legacy storage
30222:26:20 returns the correct disk_path
30322:26:29 returns the correct disk_path using the route entry
30422:26:29# [RSpecRunTime] RSpec elapsed time: 15 minutes 12.85 seconds. Current RSS: ~1201M. Threads: 3. load average: 1.25 1.16 1.34 1/288 408
30522:26:29.
30622:26:40# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb. It took 1 minute 19.01 seconds. Expected to take 1 minute 14.91 seconds.
30722:26:40# [RSpecRunTime] RSpec elapsed time: 15 minutes 23.72 seconds. Current RSS: ~1168M. Threads: 3. load average: 1.19 1.15 1.33 1/288 409
30822:26:40.
30922:26:40# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_build_infos_project_id_spec.rb. Expected to take 1 minute 11.74 seconds.
31022:26:40Gitlab::BackgroundMigration::BackfillPackagesBuildInfosProjectId
31122:27:43 constructs a valid query
31222:27:52 performs without error
31322:28:28INFO: analyzing "public.p_ci_pipelines" inheritance tree
31422:28:28INFO: analyzing "public.ci_pipelines"
31522:28:28INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
31622:29:06# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_build_infos_project_id_spec.rb. It took 2 minutes 25.65 seconds. Expected to take 1 minute 11.74 seconds.
31722:29:06# [RSpecRunTime] RSpec elapsed time: 17 minutes 49.4 seconds. Current RSS: ~1173M. Threads: 3. load average: 1.14 1.15 1.30 1/288 410
31822:29:06.
31922:29:06# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_debian_group_components_group_id_spec.rb. Expected to take 1 minute 5.84 seconds.
32022:29:06Gitlab::BackgroundMigration::BackfillPackagesDebianGroupComponentsGroupId
32122:29:56 performs without error
32222:30:03 constructs a valid query
32322:30:27INFO: analyzing "public.p_ci_pipelines" inheritance tree
32422:30:27INFO: analyzing "public.ci_pipelines"
32522:30:27INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
32622:31:05# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_debian_group_components_group_id_spec.rb. It took 1 minute 58.59 seconds. Expected to take 1 minute 5.84 seconds.
32722:31:05# [RSpecRunTime] RSpec elapsed time: 19 minutes 48.03 seconds. Current RSS: ~1168M. Threads: 3. load average: 1.08 1.14 1.28 1/287 411
32822:31:05.
32922:31:05# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_occurrence_identifiers_project_id_spec.rb. Expected to take 51.03 seconds.
33022:31:05Gitlab::BackgroundMigration::BackfillVulnerabilityOccurrenceIdentifiersProjectId
33122:31:46 constructs a valid query
33222:31:52 performs without error
33322:32:09INFO: analyzing "public.p_ci_pipelines" inheritance tree
33422:32:09INFO: analyzing "public.ci_pipelines"
33522:32:09INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
33622:32:46# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_occurrence_identifiers_project_id_spec.rb. It took 1 minute 41.65 seconds. Expected to take 51.03 seconds.
33722:32:46# [RSpecRunTime] RSpec elapsed time: 21 minutes 29.8 seconds. Current RSS: ~1172M. Threads: 3. load average: 0.95 1.09 1.24 1/289 412
33822:32:46.
33922:32:46# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_user_details_spec.rb. Expected to take 50.57 seconds.
34022:32:46Gitlab::BackgroundMigration::BackfillUserDetails
34122:33:19 #perform
34222:33:26 creates only the needed user_details entries
34322:33:26 when there are no user_details that are missing for user records
34422:33:32 creates only the needed user_details entries
34522:33:32# [RSpecRunTime] RSpec elapsed time: 22 minutes 15.14 seconds. Current RSS: ~1165M. Threads: 3. load average: 0.99 1.07 1.23 1/289 413
34622:33:32.
34722:33:44INFO: analyzing "public.p_ci_pipelines" inheritance tree
34822:33:44INFO: analyzing "public.ci_pipelines"
34922:33:44INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
35022:34:21# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_user_details_spec.rb. It took 1 minute 35.08 seconds. Expected to take 50.57 seconds.
35122:34:21# [RSpecRunTime] RSpec elapsed time: 23 minutes 4.93 seconds. Current RSS: ~1175M. Threads: 3. load average: 0.92 1.04 1.21 1/289 414
35222:34:21.
35322:34:21# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/remove_namespace_from_os_type_sbom_components_spec.rb. Expected to take 31.26 seconds.
35422:34:21Gitlab::BackgroundMigration::RemoveNamespaceFromOsTypeSbomComponents
35522:34:38 #perform
35622:34:43 successfully removes the os namespace prefix
35722:34:43 with existing record in regards to name, purl_type and component_type
35822:34:49 rescues valid ActiveRecord::RecordNotUnique errors
35922:34:49# [RSpecRunTime] RSpec elapsed time: 23 minutes 32.09 seconds. Current RSS: ~1167M. Threads: 3. load average: 0.94 1.04 1.20 1/290 415
36022:34:49.
36122:34:49 with unexpected ActiveRecord::RecordNotUnique error
36222:34:54 raises unknown ActiveRecord::RecordNotUnique errors
36322:34:54# [RSpecRunTime] RSpec elapsed time: 23 minutes 37.68 seconds. Current RSS: ~1165M. Threads: 3. load average: 0.94 1.04 1.20 1/290 416
36422:34:54.
36522:35:26# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/remove_namespace_from_os_type_sbom_components_spec.rb. It took 1 minute 4.18 seconds. Expected to take 31.26 seconds.
36622:35:26# [RSpecRunTime] RSpec elapsed time: 24 minutes 9.15 seconds. Current RSS: ~1171M. Threads: 3. load average: 0.97 1.03 1.19 1/290 417
36722:35:26.
36822:35:26# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_milestone_releases_project_id_spec.rb. Expected to take 27.89 seconds.
36922:35:26Gitlab::BackgroundMigration::BackfillMilestoneReleasesProjectId
37022:35:45 performs without error
37122:35:50 constructs a valid query
37222:36:21# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_milestone_releases_project_id_spec.rb. It took 55.81 seconds. Expected to take 27.89 seconds.
37322:36:22# [RSpecRunTime] RSpec elapsed time: 25 minutes 5.0 seconds. Current RSS: ~1174M. Threads: 3. load average: 0.99 1.02 1.18 1/290 418
37422:36:22.
37522:36:22# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_id_to_security_scans_spec.rb. Expected to take 24.22 seconds.
37622:36:22Gitlab::BackgroundMigration::BackfillProjectIdToSecurityScans
37722:36:23 when security_scan is missing project_id
37822:36:28 sets the project_id to build.project_id
37922:36:33 touches updated_at
38022:36:33# [RSpecRunTime] RSpec elapsed time: 25 minutes 16.93 seconds. Current RSS: ~1171M. Threads: 3. load average: 0.99 1.02 1.18 1/290 419
38122:36:33.
38222:36:33 when security_scan.build_id does not exist
38322:36:38 deletes the security_scan
38422:36:39# [RSpecRunTime] RSpec elapsed time: 25 minutes 22.02 seconds. Current RSS: ~1169M. Threads: 3. load average: 0.91 1.01 1.17 1/290 420
38522:36:39.
38622:36:39 when security_scan does not need to be changed
38722:36:44 does not update the scan
38822:36:44# [RSpecRunTime] RSpec elapsed time: 25 minutes 27.16 seconds. Current RSS: ~1172M. Threads: 3. load average: 1.00 1.02 1.17 1/290 421
38922:36:44.
39022:36:56# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_id_to_security_scans_spec.rb. It took 34.59 seconds. Expected to take 24.22 seconds.
39122:36:56# [RSpecRunTime] RSpec elapsed time: 25 minutes 39.63 seconds. Current RSS: ~1171M. Threads: 3. load average: 0.93 1.00 1.17 1/290 422
39222:36:56.
39322:36:56# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_stale_packages_npm_metadata_caches_spec.rb. Expected to take 10.83 seconds.
39422:36:56Gitlab::BackgroundMigration::DeleteStalePackagesNpmMetadataCaches
39522:37:05 deletes entries with missing `project_id`
39622:37:21# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_stale_packages_npm_metadata_caches_spec.rb. It took 24.67 seconds. Expected to take 10.83 seconds.
39722:37:21# [RSpecRunTime] RSpec elapsed time: 26 minutes 4.34 seconds. Current RSS: ~1177M. Threads: 3. load average: 0.95 1.00 1.16 1/290 423
39822:37:21.
39922:37:21# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/fix_synced_epic_work_item_parent_links_spec.rb. Expected to take 8.85 seconds.
40022:37:21Gitlab::BackgroundMigration::FixSyncedEpicWorkItemParentLinks
40122:37:22 when backfilling
40222:37:29 fixes the records
40322:37:29# [RSpecRunTime] RSpec elapsed time: 26 minutes 12.34 seconds. Current RSS: ~1185M. Threads: 3. load average: 0.96 1.00 1.16 1/290 424
40422:37:29.
40522:37:40# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/fix_synced_epic_work_item_parent_links_spec.rb. It took 18.83 seconds. Expected to take 8.85 seconds.
40622:37:40# [RSpecRunTime] RSpec elapsed time: 26 minutes 23.22 seconds. Current RSS: ~1179M. Threads: 3. load average: 0.96 1.00 1.16 1/290 425
40722:37:40.
40822:37:40# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/batching_strategies/dismissed_vulnerabilities_strategy_spec.rb. Expected to take 6.15 seconds.
40922:37:40Gitlab::BackgroundMigration::BatchingStrategies::DismissedVulnerabilitiesStrategy#next_batch
41022:37:46 is expected to be < Gitlab::BackgroundMigration::BatchingStrategies::PrimaryKeyBatchingStrategy
41122:37:57# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/batching_strategies/dismissed_vulnerabilities_strategy_spec.rb. It took 17.32 seconds. Expected to take 6.15 seconds.
41222:37:57# [RSpecRunTime] RSpec elapsed time: 26 minutes 40.58 seconds. Current RSS: ~1171M. Threads: 3. load average: 0.91 0.98 1.15 1/290 426
41322:37:57.
41422:38:27auto_explain log contains 1192 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-single-db-ci-connection-10-17.341.main.ndjson.gz
41522:38:27took 30.220996831
41622:38:56auto_explain log contains 1193 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-single-db-ci-connection-10-17.341.ci.ndjson.gz
41722:38:56took 28.538636447
41822:38:56[TEST PROF INFO] EventProf results for sql.active_record
41922:38:56Total time: 14:39.012 of 26:31.425 (55.23%)
42022:38:56Total events: 675810
42122:38:56Top 5 slowest suites (by time):
42222:38:56Gitlab::Backg...esDependencies (./spec/lib/gitlab/background_migration/delete_orphaned_packages_dependencies_spec.rb:5) – 02:34.852 (118216 / 2) of 04:23.655 (58.73%)
42322:38:56Gitlab::Backg...deSettingsUuid (./spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb:5) – 02:22.997 (105524 / 2) of 04:03.601 (58.7%)
42422:38:56Gitlab::Backg...nksNamespaceId (./spec/lib/gitlab/background_migration/backfill_work_item_parent_links_namespace_id_spec.rb:5) – 01:45.968 (79575 / 2) of 03:01.404 (58.42%)
42522:38:56Gitlab::Backg...InfosProjectId (./spec/lib/gitlab/background_migration/backfill_packages_build_infos_project_id_spec.rb:5) – 01:24.056 (59433 / 2) of 02:25.690 (57.7%)
42622:38:56Gitlab::Backg...tionsProjectId (./spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb:5) – 01:23.928 (58857 / 2) of 02:26.849 (57.15%)
42722:38:56Knapsack report was generated. Preview:
42822:38:56{
42922:38:56 "spec/lib/gitlab/background_migration/delete_orphaned_packages_dependencies_spec.rb": 132.97572327600028,
43022:38:56 "spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb": 123.60150501599946,
43122:38:56 "spec/lib/gitlab/background_migration/backfill_work_item_parent_links_namespace_id_spec.rb": 89.13085634400068,
43222:38:56 "spec/lib/gitlab/background_migration/backfill_vulnerability_state_transitions_project_id_spec.rb": 71.41387113899964,
43322:38:56 "spec/lib/gitlab/background_migration/backfill_project_repositories_spec.rb": 68.20879712199985,
43422:38:56 "spec/lib/gitlab/background_migration/backfill_packages_build_infos_project_id_spec.rb": 71.39917301900005,
43522:38:56 "spec/lib/gitlab/background_migration/backfill_packages_debian_group_components_group_id_spec.rb": 57.07232363999992,
43622:38:56 "spec/lib/gitlab/background_migration/backfill_vulnerability_occurrence_identifiers_project_id_spec.rb": 47.680676425000456,
43722:38:56 "spec/lib/gitlab/background_migration/backfill_user_details_spec.rb": 45.36213658699944,
43822:38:56 "spec/lib/gitlab/background_migration/remove_namespace_from_os_type_sbom_components_spec.rb": 32.77250543300033,
43922:38:56 "spec/lib/gitlab/background_migration/backfill_milestone_releases_project_id_spec.rb": 24.47030684099991,
44022:38:56 "spec/lib/gitlab/background_migration/backfill_project_id_to_security_scans_spec.rb": 22.171363591000045,
44122:38:56 "spec/lib/gitlab/background_migration/delete_stale_packages_npm_metadata_caches_spec.rb": 8.95072999399963,
44222:38:56 "spec/lib/gitlab/background_migration/fix_synced_epic_work_item_parent_links_spec.rb": 8.01149997399989,
44322:38:56 "spec/lib/gitlab/background_migration/batching_strategies/dismissed_vulnerabilities_strategy_spec.rb": 6.656951195000147
44422:38:56}
44522:38:56Knapsack global time execution for tests: 13m 29s
44622:38:56Finished in 27 minutes 39 seconds (files took 49.91 seconds to load)
44722:38:5637 examples, 0 failures
44822:38:56Randomized with seed 25462
44922:39:05[TEST PROF INFO] Time spent in factories: 00:20.566 (1.24% of total time)
45022:39:05RSpec exited with 0.
45122:39:05No examples to retry, congrats!
452 22:39:06 Running after_script 00:16
45322:39:06Running after script...
45422:39:06$ source scripts/utils.sh
45522:39:06$ log_disk_usage
45622:39:06*******************************************************
45722:39:06This runner currently has 75G free disk space.
45822:39:06*******************************************************
459 22:39:06 Disk usage detail 00:09
51522:39:15$ bundle exec gem list gitlab_quality-test_tooling
51622:39:17gitlab_quality-test_tooling (2.1.0)
51722:39:17$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
518 22:39:17 Report test failures 00:00
52022:39:17$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
521 22:39:17 Report test flakiness 00:00
52322:39:17$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
524 22:39:17 Report test slowness 00:00
52622:39:17$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
527 22:39:17 Report test slowness in MR note 00:02
53022:39:19$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
531 22:39:19 Report test files close to timing out 00:02
53422:39:21$ tooling/bin/push_job_metrics || true
53522:39:22[job-metrics] Pushing job metrics file for the CI/CD job.
53622:39:22[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
537 22:39:22 Saving cache for successful job 00:01
53822:39:23Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20 due to policy
539 22:39:23 Uploading artifacts for successful job 00:05
54022:39:23Uploading artifacts...
54122:39:23auto_explain/: found 3 matching artifact files and directories
54222:39:23coverage/: found 5 matching artifact files and directories
54322:39:23crystalball/: found 2 matching artifact files and directories
54422:39:23WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
54522:39:23knapsack/: found 4 matching artifact files and directories
54622:39:23rspec/: found 16 matching artifact files and directories
54722:39:23WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
54822:39:23log/*.log: found 13 matching artifact files and directories
54922:39:24WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353287367/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
55022:39:24WARNING: Retrying... context=artifacts-uploader error=request redirected
55122:39:27Uploading artifacts as "archive" to coordinator... 201 Created id=8353287367 responseStatus=201 Created token=glcbt-66
55222:39:27Uploading artifacts...
55322:39:27rspec/rspec-*.xml: found 1 matching artifact files and directories
55422:39:27WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353287367/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
55522:39:27WARNING: Retrying... context=artifacts-uploader error=request redirected
55622:39:28Uploading artifacts as "junit" to coordinator... 201 Created id=8353287367 responseStatus=201 Created token=glcbt-66
557 22:39:28 Cleaning up project directory and file based variables 00:01
55822:39:37Job succeeded