Skip to content
Snippets Groups Projects

rspec background_migration pg14 single-db 13/17

Passed Started by
Simon Tomlinson
@stomlinson
Log timestamps in UTC.
122:06:53Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
222:06:53 on blue-2.private.runners-manager.gitlab.com/gitlab.com/gitlab-org QvBVRoXM, system ID: s_49b872f8ccf6
322:06:53 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
422:06:53Resolving secrets
5 22:06:53 Preparing the "docker+machine" executor 00:09
622:06: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:06:55Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
822:06:55Authenticating with credentials from job payload (GitLab Registry)
922:06:55Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1022:06:56Using 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:06:56WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1222:06:56WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1322:06:56Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1422:06:56Authenticating with credentials from job payload (GitLab Registry)
1522:06:56Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1622:06:57Using 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:06:57Starting service redis:6.2-alpine...
1822:06:57Pulling docker image redis:6.2-alpine ...
1922:06:58Using docker image sha256:4100b5bd17430263e85ad9d8ab851959b234acaaf378e093f1f98400f4998815 for redis:6.2-alpine with digest redis@sha256:eaba718fecd1196d88533de7ba49bf903ad33664a92debb24660a922ecd9cac8 ...
2022:06:58Waiting for services to be up and running (timeout 30 seconds)...
2122:07:02Authenticating with credentials from job payload (GitLab Registry)
2222:07:02Pulling 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:07: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:07:02 Preparing environment 00:01
2522:07:03Running on runner-qvbvroxm-project-278964-concurrent-0 via runner-qvbvroxm-private-1731529257-fae20d8b...
26 22:07:03 Getting source from Git repository 00:00
2722:07:03Skipping Git repository setup
2822:07:03Skipping Git checkout
2922:07:03Skipping Git submodules setup
30 22:07:03 Restoring cache 00:18
3122:07:04Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20...
3222:07:04cache.zip is up to date
3322:07:15Successfully extracted cache
34 22:07:21 Downloading artifacts 00:52
3522:07:21Downloading artifacts for clone-gitlab-repo (8353286583)...
3622:07:32Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286583 responseStatus=200 OK token=glcbt-66
3722:07:32WARNING: Part of .git directory is on the list of files to extract
3822:07:32WARNING: This may introduce unexpected problems
3922:07:44Downloading artifacts for compile-test-assets (8353286630)...
4022:07:49Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286630 responseStatus=200 OK token=glcbt-66
4122:07:55Downloading artifacts for detect-tests (8353286649)...
4222:07:56Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286649 responseStatus=200 OK token=glcbt-66
4322:07:56Downloading artifacts for retrieve-tests-metadata (8353286664)...
4422:07:56Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286664 responseStatus=200 OK token=glcbt-66
4522:07:56Downloading artifacts for setup-test-env (8353286635)...
4622:08:01Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286635 responseStatus=200 OK token=glcbt-66
47 22:08:13 Executing "step_script" stage of the job script
4822:08:13Using 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:08:13$ echo $FOSS_ONLY
5022:08:13$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
5122:08:13$ export GOPATH=$CI_PROJECT_DIR/.go
5222:08:13$ mkdir -p $GOPATH
5322:08:14$ source scripts/utils.sh
5422:08:14$ log_disk_usage "true"
5522:08:14*******************************************************
5622:08:14This runner currently has 73G free disk space.
5722:08:14*******************************************************
58 22:08:14 Disk usage detail 00:07
5922:08:14df -h
6022:08:14Filesystem Size Used Avail Use% Mounted on
6122:08:14overlay 95G 22G 73G 24% /
6222:08:14tmpfs 64M 0 64M 0% /dev
6322:08:14shm 64M 0 64M 0% /dev/shm
6422:08:14/dev/sda1 95G 22G 73G 24% /cache
6522:08:14tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6622:08:14du -h -d 1
6722:08:147.4M ./workhorse
6822:08:14148K ./bin
6922:08:141.2M ./.gitlab
7022:08:14167M ./.git
7122:08:144.0K ./builds
7222:08:1428M ./lib
7322:08:148.0K ./.vscode
7422:08:14560K ./storybook
7522:08:1424K ./log
7622:08:141.8M ./data
7722:08:1411M ./qa
7822:08:143.2M ./.rubocop_todo
7922:08:14856M ./vendor
8022:08:141023M ./public
8122:08:1462M ./doc
8222:08:14484K ./danger
8322:08:1432K ./rspec
8422:08:14556K ./tooling
8522:08:14145M ./ee
8622:08:141.3M ./knapsack
8722:08:14300K ./patches
8822:08:144.3M ./changelogs
8922:08:1420K ./haml_lint
9022:08:1428K ./metrics_server
9122:08:14108K ./keeps
9222:08:1436K ./shared
9322:08:1444K ./generator_templates
9422:08:141.3M ./scripts
9522:08:14763M ./tmp
9622:08:14127M ./spec
9722:08:1420K ./file_hooks
9822:08:1432K ./crystalball
9922:08:1416K ./sidekiq_cluster
10022:08:1417M ./gems
10122:08:141.2M ./fixtures
10222:08:14964K ./rubocop
10322:08:144.0K ./.go
10422:08:1433M ./db
10522:08:1412K ./.github
10622:08:14129M ./locale
10722:08:1420M ./config
10822:08:1482M ./app
10922:08:1420K ./.lefthook
11022:08:143.5G .
11122:08:14$ source scripts/prepare_build.sh
112 22:08:14 Installing gems 00:17
14322:08:31Using two connections, single database config (config/database.yml.postgresql)
14422:08:31Disabling ci connection in config/database.yml
14522:08:31Geo DB won't be set up.
14622:08:31Embedding DB won't be set up.
147 22:08:31 Setting up DBs 00:52
17222:09:23$ source ./scripts/rspec_helpers.sh
17322:09:23$ run_timed_command "gem install knapsack --no-document"
17422:09:23$ gem install knapsack --no-document
17522:09:24Successfully installed knapsack-4.0.0
17622:09:241 gem installed
17722:09:23==> 'gem install knapsack --no-document' succeeded in 1 seconds.
17822:09:24$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
179 22:09:24 Spawning Gitaly 00:04
18322:09:28$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
18422:09:28$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
18522:09:28$ tooling/bin/create_job_metrics_file || true
18622:09:31[job-metrics] Creating the job metrics file for the CI/CD job.
18722:09:31$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
188 22:09:31 RSpec 32:50
18922:09:31[22:09:31] Starting rspec_parallelized_job
19022:09:24RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
19122:09:32KNAPSACK_GENERATE_REPORT: true
19222:09:32FLAKY_RSPEC_GENERATE_REPORT: true
19322:09:32KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
19422:09:32KNAPSACK_LOG_LEVEL: debug
19522:09:32KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_single-db_13_17_278964_report.json
19622:09:32FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
19722:09:32FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_single-db_13_17_278964_report.json
19822:09:32NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_single-db_13_17_278964_report.json
19922:09:32RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8353287238.txt
20022:09:32CRYSTALBALL:
20122:09:32RSPEC_TESTS_MAPPING_ENABLED:
20222:09:32RSPEC_TESTS_FILTER_FILE:
20322:09:32Shell set options (set -o) enabled:
20422:09:32braceexpand on
20522:09:32hashall on
20622:09:32interactive-comments on
20722:09:32pipefail on
20822:09:38Knapsack report generator started!
20922:09:32/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!
21022:09:50 ██  ██  █████  ██████  ███  ██ ██ ███  ██  ██████ 
21122:09:50 ██  ██ ██   ██ ██   ██ ████  ██ ██ ████  ██ ██      
21222:09:50 ██  █  ██ ███████ ██████  ██ ██  ██ ██ ██ ██  ██ ██  ███ 
21322:09:50 ██ ███ ██ ██   ██ ██   ██ ██  ██ ██ ██ ██  ██ ██ ██  ██ 
21422:09:50  ███ ███  ██  ██ ██  ██ ██   ████ ██ ██   ████  ██████  
21522:09:50******************************************************************************
21622:09:50 Your database has a single connection, and single connections were
21722:09:50 deprecated in GitLab 15.9 https://docs.gitlab.com/ee/update/deprecations.html#single-database-connection-is-deprecated.
21822:09:50 In GitLab 17.0 and later, you must have the two main: and ci: sections in your database.yml.
21922:09:50 Please add a :ci section to your database, following these instructions:
22022:09:50 https://docs.gitlab.com/ee/install/installation.html#configure-gitlab-db-settings.
22122:09:50******************************************************************************
22222:10:19DEPRECATION 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)
22322:10:31warning: parser/current is loading parser/ruby32, which recognizes 3.2.6-compliant syntax, but you are running 3.2.5.
22422:10:31Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
22522:10:34Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
22622:10:34# [RSpecRunTime] Starting RSpec timer...
22722:10:34[TEST PROF INFO] EventProf enabled (sql.active_record)
22822:10:34unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
22922:10:39Test environment set up in 1.875773703 seconds
23022:10:40# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb. Expected to take 2 minutes 18.12 seconds.
23122:10:40Gitlab::BackgroundMigration::DisableLegacyOpenSourceLicenseForOneMemberNoRepoProjects
23222:12:57WARNING: Active Record does not support composite primary key.
23322:12:57project_authorizations has composite primary key. Composite primary key is ignored.
23422:13:00 sets `legacy_open_source_license_available` to false only for public projects with 1 member and no repo
23522:13:28INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
23622:13:28INFO: analyzing "public.ci_pipeline_variables"
23722:13:28INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23822:13:30INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
23922:13:30INFO: analyzing "public.ci_pipeline_variables"
24022:13:30INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24122:13:36INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
24222:13:36INFO: analyzing "public.ci_job_artifacts"
24322:13:36INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24422:13:39INFO: analyzing "public.p_ci_stages" inheritance tree
24522:13:39INFO: analyzing "public.ci_stages"
24622:13:39INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24722:14:44INFO: analyzing "public.p_ci_pipelines" inheritance tree
24822:14:44INFO: analyzing "public.ci_pipelines"
24922:14:44INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
25022:15:18# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb. It took 4 minutes 37.94 seconds. Expected to take 2 minutes 18.12 seconds.
25122:15:18# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb. Expected to take 2 minutes 4.42 seconds.
25222:15:18Gitlab::BackgroundMigration::BackfillPackagesTagsProjectId
25322:17:27 backfills the missing project_id for the batch
25422:17:46INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
25522:17:46INFO: analyzing "public.ci_pipeline_variables"
25622:17:46INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
25722:17:48INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
25822:17:48INFO: analyzing "public.ci_pipeline_variables"
25922:17:48INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
26022:17:53INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
26122:17:53INFO: analyzing "public.ci_job_artifacts"
26222:17:53INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
26322:17:57INFO: analyzing "public.p_ci_stages" inheritance tree
26422:17:57INFO: analyzing "public.ci_stages"
26522:17:57INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
26622:19:02INFO: analyzing "public.p_ci_pipelines" inheritance tree
26722:19:02INFO: analyzing "public.ci_pipelines"
26822:19:02INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
26922:19:37# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb. It took 4 minutes 19.05 seconds. Expected to take 2 minutes 4.42 seconds.
27022:19:37# [RSpecRunTime] RSpec elapsed time: 9 minutes 3.2 seconds. Current RSS: ~1239M. Threads: 1. load average: 1.02 1.09 1.14 1/275 388
27122:19:37.
27222:19:37# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. Expected to take 1 minute 41.26 seconds.
27322:19:37Gitlab::BackgroundMigration::BackfillIssueSearchDataNamespaceId
27422:21:26WARNING: Active Record does not support composite primary key.
27522:21:26issue_search_data has composite primary key. Composite primary key is ignored.
27622:21:26WARNING: Active Record does not support composite primary key.
27722:21:26issue_search_data has composite primary key. Composite primary key is ignored.
27822:21:29 backfills namespace_id for the specified records
27922:21:34INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
28022:21:34INFO: analyzing "public.ci_pipeline_variables"
28122:21:34INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
28222:21:36INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
28322:21:36INFO: analyzing "public.ci_pipeline_variables"
28422:21:36INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
28522:21:42INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
28622:21:42INFO: analyzing "public.ci_job_artifacts"
28722:21:42INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
28822:21:46INFO: analyzing "public.p_ci_stages" inheritance tree
28922:21:46INFO: analyzing "public.ci_stages"
29022:21:46INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29122:22:50INFO: analyzing "public.p_ci_pipelines" inheritance tree
29222:22:50INFO: analyzing "public.ci_pipelines"
29322:22:50INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29422:23:25# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. It took 3 minutes 48.23 seconds. Expected to take 1 minute 41.26 seconds.
29522:23:25# [RSpecRunTime] RSpec elapsed time: 12 minutes 51.64 seconds. Current RSS: ~1241M. Threads: 1. load average: 0.98 1.02 1.09 1/276 389
29622:23:25.
29722:23:25# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_approval_merge_request_rules_project_id_spec.rb. Expected to take 1 minute 26.89 seconds.
29822:23:25Gitlab::BackgroundMigration::BackfillApprovalMergeRequestRulesProjectId
29922:24:51 constructs a valid query
30022:25:03 performs without error
30122:26:00INFO: analyzing "public.p_ci_pipelines" inheritance tree
30222:26:00INFO: analyzing "public.ci_pipelines"
30322:26:00INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
30422:26:35# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_approval_merge_request_rules_project_id_spec.rb. It took 3 minutes 10.12 seconds. Expected to take 1 minute 26.89 seconds.
30522:26:35# [RSpecRunTime] RSpec elapsed time: 16 minutes 1.81 seconds. Current RSS: ~1238M. Threads: 1. load average: 1.06 1.08 1.10 1/277 390
30622:26:35.
30722:26:35# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_merge_request_blocks_project_id_spec.rb. Expected to take 1 minute 14.0 seconds.
30822:26:35Gitlab::BackgroundMigration::BackfillMergeRequestBlocksProjectId
30922:27:45 performs without error
31022:27:54 constructs a valid query
31122:28:35INFO: analyzing "public.p_ci_pipelines" inheritance tree
31222:28:35INFO: analyzing "public.ci_pipelines"
31322:28:35INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
31422:29:10# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_merge_request_blocks_project_id_spec.rb. It took 2 minutes 34.4 seconds. Expected to take 1 minute 14.0 seconds.
31522:29:10# [RSpecRunTime] RSpec elapsed time: 18 minutes 36.27 seconds. Current RSS: ~1237M. Threads: 1. load average: 1.00 1.04 1.08 1/276 391
31622:29:10.
31722:29:10# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_merge_request_assignment_events_project_id_spec.rb. Expected to take 1 minute 9.05 seconds.
31822:29:10Gitlab::BackgroundMigration::BackfillMergeRequestAssignmentEventsProjectId
31922:30:17 constructs a valid query
32022:30:26 performs without error
32122:31:06INFO: analyzing "public.p_ci_pipelines" inheritance tree
32222:31:06INFO: analyzing "public.ci_pipelines"
32322:31:06INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
32422:31:41# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_merge_request_assignment_events_project_id_spec.rb. It took 2 minutes 30.96 seconds. Expected to take 1 minute 9.05 seconds.
32522:31:41# [RSpecRunTime] RSpec elapsed time: 21 minutes 7.29 seconds. Current RSS: ~1234M. Threads: 1. load average: 1.08 1.07 1.08 1/276 392
32622:31:41.
32722:31:41# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_model_metadata_project_id_spec.rb. Expected to take 59.98 seconds.
32822:31:41Gitlab::BackgroundMigration::BackfillMlModelMetadataProjectId
32922:32:32 performs without error
33022:32:38 constructs a valid query
33122:33:03INFO: analyzing "public.p_ci_pipelines" inheritance tree
33222:33:03INFO: analyzing "public.ci_pipelines"
33322:33:03INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
33422:33:35# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_model_metadata_project_id_spec.rb. It took 1 minute 53.76 seconds. Expected to take 59.98 seconds.
33522:33:35# [RSpecRunTime] RSpec elapsed time: 23 minutes 1.11 seconds. Current RSS: ~1231M. Threads: 1. load average: 1.11 1.08 1.09 1/277 393
33622:33:35.
33722:33:35# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_signatures_project_id_spec.rb. Expected to take 56.73 seconds.
33822:33:35Gitlab::BackgroundMigration::BackfillVulnerabilityFindingSignaturesProjectId
33922:34:25 constructs a valid query
34022:34:31 performs without error
34122:34:57INFO: analyzing "public.p_ci_pipelines" inheritance tree
34222:34:57INFO: analyzing "public.ci_pipelines"
34322:34:57INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
34422:35:30# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_signatures_project_id_spec.rb. It took 1 minute 55.63 seconds. Expected to take 56.73 seconds.
34522:35:30# [RSpecRunTime] RSpec elapsed time: 24 minutes 56.78 seconds. Current RSS: ~1232M. Threads: 1. load average: 1.05 1.08 1.09 1/277 394
34622:35:30.
34722:35:30# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_epic_dates_to_work_item_dates_sources_spec.rb. Expected to take 46.65 seconds.
34822:35:30Gitlab::BackgroundMigration::BackfillEpicDatesToWorkItemDatesSources
34922:36:11 when backfilling all epics
35022:36:18 backfills data correctly
35122:36:18# [RSpecRunTime] RSpec elapsed time: 25 minutes 43.94 seconds. Current RSS: ~1226M. Threads: 1. load average: 1.12 1.09 1.09 1/277 395
35222:36:18.
35322:36:39INFO: analyzing "public.p_ci_pipelines" inheritance tree
35422:36:39INFO: analyzing "public.ci_pipelines"
35522:36:39INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
35622:37:12# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_epic_dates_to_work_item_dates_sources_spec.rb. It took 1 minute 41.61 seconds. Expected to take 46.65 seconds.
35722:37:12# [RSpecRunTime] RSpec elapsed time: 26 minutes 38.45 seconds. Current RSS: ~1234M. Threads: 1. load average: 1.00 1.06 1.08 2/277 396
35822:37:12.
35922:37:12# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_group_id_spec.rb. Expected to take 41.45 seconds.
36022:37:12Gitlab::BackgroundMigration::BackfillProtectedEnvironmentDeployAccessLevelsProtectedEnvironmentGroupId
36122:37:46 performs without error
36222:37:51 constructs a valid query
36322:37:58INFO: analyzing "public.p_ci_pipelines" inheritance tree
36422:37:58INFO: analyzing "public.ci_pipelines"
36522:37:58INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
36622:38:30# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_group_id_spec.rb. It took 1 minute 18.09 seconds. Expected to take 41.45 seconds.
36722:38:30# [RSpecRunTime] RSpec elapsed time: 27 minutes 56.6 seconds. Current RSS: ~1231M. Threads: 1. load average: 0.98 1.04 1.07 1/277 397
36822:38:30.
36922:38:30# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_pypi_metadata_project_id_spec.rb. Expected to take 24.85 seconds.
37022:38:30Gitlab::BackgroundMigration::BackfillPackagesPypiMetadataProjectId
37122:38:49 performs without error
37222:38:53 constructs a valid query
37322:39:18# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_pypi_metadata_project_id_spec.rb. It took 47.46 seconds. Expected to take 24.85 seconds.
37422:39:18# [RSpecRunTime] RSpec elapsed time: 28 minutes 44.11 seconds. Current RSS: ~1232M. Threads: 1. load average: 0.95 1.02 1.06 1/277 398
37522:39:18.
37622:39:18# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_security_findings_project_id_spec.rb. Expected to take 17.23 seconds.
37722:39:18Gitlab::BackgroundMigration::BackfillSecurityFindingsProjectId
37822:39:29 performs without error
37922:39:33 constructs a valid query
38022:39:47# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_security_findings_project_id_spec.rb. It took 29.31 seconds. Expected to take 17.23 seconds.
38122:39:47# [RSpecRunTime] RSpec elapsed time: 29 minutes 13.48 seconds. Current RSS: ~1227M. Threads: 1. load average: 1.02 1.03 1.07 1/277 399
38222:39:47.
38322:39:47# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/redis/backfill_project_pipeline_status_ttl_spec.rb. Expected to take 16.5 seconds.
38422:39:47Gitlab::BackgroundMigration::Redis::BackfillProjectPipelineStatusTtl
38522:39:48 #redis
38622:39:52 is expected to eq "#<Redis client v5.3.0 for 172.22.0.3:7001 172.22.0.3:7002 172.22.0.3:7003>"
38722:39:52# [RSpecRunTime] RSpec elapsed time: 29 minutes 18.1 seconds. Current RSS: ~1226M. Threads: 1. load average: 1.10 1.05 1.07 1/277 400
38822:39:52.
38922:39:52 #scan_match_pattern
39022:39:56 finds all the required keys only
39122:39:56# [RSpecRunTime] RSpec elapsed time: 29 minutes 22.0 seconds. Current RSS: ~1221M. Threads: 1. load average: 1.09 1.05 1.07 1/277 401
39222:39:56.
39322:39:56 #perform
39422:40:00 sets a ttl on given keys
39522:40:00# [RSpecRunTime] RSpec elapsed time: 29 minutes 25.9 seconds. Current RSS: ~1222M. Threads: 1. load average: 1.09 1.05 1.07 1/276 402
39622:40:00.
39722:40:05# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/redis/backfill_project_pipeline_status_ttl_spec.rb. It took 17.52 seconds. Expected to take 16.5 seconds.
39822:40:05# [RSpecRunTime] RSpec elapsed time: 29 minutes 31.05 seconds. Current RSS: ~1213M. Threads: 1. load average: 1.09 1.05 1.07 1/277 403
39922:40:05.
40022:40:05# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/project_bot_user_details_bot_namespace_migration_spec.rb. Expected to take 6.68 seconds.
40122:40:05Gitlab::BackgroundMigration::ProjectBotUserDetailsBotNamespaceMigration
40222:40:11 populates bot_namespace_id correctly
40322:40:16# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/project_bot_user_details_bot_namespace_migration_spec.rb. It took 11.08 seconds. Expected to take 6.68 seconds.
40422:40:16# [RSpecRunTime] RSpec elapsed time: 29 minutes 42.19 seconds. Current RSS: ~1219M. Threads: 1. load average: 0.99 1.03 1.06 1/276 404
40522:40:16.
40622:40:16# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ci_runner_machines_partitioned_table_spec.rb. Expected to take 5.87 seconds.
40722:40:16Gitlab::BackgroundMigration::BackfillCiRunnerMachinesPartitionedTable
40822:40:16 #perform
40922:40:20 backfills with valid runner managers
41022:40:20# [RSpecRunTime] RSpec elapsed time: 29 minutes 46.56 seconds. Current RSS: ~1221M. Threads: 1. load average: 0.99 1.03 1.06 3/276 405
41122:40:20.
41222:40:25# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ci_runner_machines_partitioned_table_spec.rb. It took 9.35 seconds. Expected to take 5.87 seconds.
41322:40:25# [RSpecRunTime] RSpec elapsed time: 29 minutes 51.59 seconds. Current RSS: ~1215M. Threads: 1. load average: 0.99 1.03 1.06 1/276 406
41422:40:25.
41522:40:57auto_explain log contains 1167 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-single-db-13-17.341.main.ndjson.gz
41622:40:57took 31.759379977
41722:40:57[TEST PROF INFO] EventProf results for sql.active_record
41822:40:57Total time: 17:25.021 of 29:45.421 (58.53%)
41922:40:57Total events: 697099
42022:40:57Top 5 slowest suites (by time):
42122:40:57Gitlab::Backg...NoRepoProjects (./spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb:5) – 02:47.890 (112297 / 1) of 04:37.937 (60.41%)
42222:40:57Gitlab::Backg...sTagsProjectId (./spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb:5) – 02:35.865 (105838 / 1) of 04:19.259 (60.12%)
42322:40:57Gitlab::Backg...ataNamespaceId (./spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb:5) – 02:19.683 (94462 / 1) of 03:48.282 (61.19%)
42422:40:57Gitlab::Backg...RulesProjectId (./spec/lib/gitlab/background_migration/backfill_approval_merge_request_rules_project_id_spec.rb:5) – 01:50.739 (74078 / 2) of 03:10.174 (58.23%)
42522:40:57Gitlab::Backg...locksProjectId (./spec/lib/gitlab/background_migration/backfill_merge_request_blocks_project_id_spec.rb:5) – 01:28.286 (53745 / 2) of 02:34.460 (57.16%)
42622:40:57Knapsack report was generated. Preview:
42722:40:57{
42822:40:57 "spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_one_member_no_repo_projects_spec.rb": 141.40726742700008,
42922:40:57 "spec/lib/gitlab/background_migration/backfill_packages_tags_project_id_spec.rb": 128.98533035499986,
43022:40:57 "spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb": 111.73380668000027,
43122:40:57 "spec/lib/gitlab/background_migration/backfill_approval_merge_request_rules_project_id_spec.rb": 98.17132156700063,
43222:40:57 "spec/lib/gitlab/background_migration/backfill_merge_request_blocks_project_id_spec.rb": 78.94691202600006,
43322:40:57 "spec/lib/gitlab/background_migration/backfill_merge_request_assignment_events_project_id_spec.rb": 76.2843282849999,
43422:40:57 "spec/lib/gitlab/background_migration/backfill_ml_model_metadata_project_id_spec.rb": 56.76155636600015,
43522:40:57 "spec/lib/gitlab/background_migration/backfill_vulnerability_finding_signatures_project_id_spec.rb": 56.47417480900003,
43622:40:57 "spec/lib/gitlab/background_migration/backfill_epic_dates_to_work_item_dates_sources_spec.rb": 47.1755026589999,
43722:40:57 "spec/lib/gitlab/background_migration/backfill_protected_environment_deploy_access_levels_protected_environment_group_id_spec.rb": 38.42019125600018,
43822:40:57 "spec/lib/gitlab/background_migration/backfill_packages_pypi_metadata_project_id_spec.rb": 22.528413363001164,
43922:40:57 "spec/lib/gitlab/background_migration/backfill_security_findings_project_id_spec.rb": 14.78522988000077,
44022:40:57 "spec/lib/gitlab/background_migration/redis/backfill_project_pipeline_status_ttl_spec.rb": 12.445910644000833,
44122:40:57 "spec/lib/gitlab/background_migration/project_bot_user_details_bot_namespace_migration_spec.rb": 6.2413349010003,
44222:40:57 "spec/lib/gitlab/background_migration/backfill_ci_runner_machines_partitioned_table_spec.rb": 4.393745855000816
44322:40:57}
44422:40:57Knapsack global time execution for tests: 14m 54s
44522:40:57Finished in 30 minutes 23 seconds (files took 59.09 seconds to load)
44622:40:5725 examples, 0 failures
44722:40:57Randomized with seed 44669
44822:41:03[TEST PROF INFO] Time spent in factories: 00:00.333 (0.02% of total time)
44922:41:03RSpec exited with 0.
45022:41:03No examples to retry, congrats!
451 22:41:03 Running after_script 00:16
45222:41:04Running after script...
45322:41:04$ source scripts/utils.sh
45422:41:04$ log_disk_usage
45522:41:04*******************************************************
45622:41:04This runner currently has 71G free disk space.
45722:41:04*******************************************************
458 22:41:04 Disk usage detail 00:07
51422:41:11$ bundle exec gem list gitlab_quality-test_tooling
51522:41:14gitlab_quality-test_tooling (2.1.0)
51622:41:14$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
517 22:41:14 Report test failures 00:00
51922:41:14$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
520 22:41:14 Report test flakiness 00:00
52222:41:14$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
523 22:41:14 Report test slowness 00:00
52522:41:14$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
526 22:41:14 Report test slowness in MR note 00:01
52922:41:15$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
530 22:41:15 Report test files close to timing out 00:02
53322:41:17$ tooling/bin/push_job_metrics || true
53422:41:19[job-metrics] Pushing job metrics file for the CI/CD job.
53522:41:19[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
536 22:41:19 Saving cache for successful job 00:01
53722:41:20Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20 due to policy
538 22:41:20 Uploading artifacts for successful job 00:05
53922:41:21Uploading artifacts...
54022:41:21auto_explain/: found 2 matching artifact files and directories
54122:41:21coverage/: found 5 matching artifact files and directories
54222:41:21crystalball/: found 2 matching artifact files and directories
54322:41:21WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
54422:41:21knapsack/: found 4 matching artifact files and directories
54522:41:21rspec/: found 16 matching artifact files and directories
54622:41:21WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
54722:41:21log/*.log: found 13 matching artifact files and directories
54822:41:21WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353287238/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
54922:41:21WARNING: Retrying... context=artifacts-uploader error=request redirected
55022:41:23Uploading artifacts as "archive" to coordinator... 201 Created id=8353287238 responseStatus=201 Created token=glcbt-66
55122:41:23Uploading artifacts...
55222:41:24rspec/rspec-*.xml: found 1 matching artifact files and directories
55322:41:24WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353287238/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
55422:41:24WARNING: Retrying... context=artifacts-uploader error=request redirected
55522:41:25Uploading artifacts as "junit" to coordinator... 201 Created id=8353287238 responseStatus=201 Created token=glcbt-66
556 22:41:25 Cleaning up project directory and file based variables 00:01
55722:41:34Job succeeded