Skip to content
Snippets Groups Projects

rspec background_migration pg14 2/10

Passed Started by
🤖 GitLab Bot 🤖
@gitlab-bot
Log timestamps in UTC.
103:26:49Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
203:26:49 on blue-2.shared-gitlab-org.runners-manager.gitlab.com/default NL4gfoBe, system ID: s_74c3e1316164
303:26:49 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
403:26:49Resolving secrets
5 03:26:49 Preparing the "docker+machine" executor 00:09
603:26:49Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
703:26:51Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
803:26:51Authenticating with credentials from job payload (GitLab Registry)
903:26:51Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1003:26:51Using 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 ...
1103:26:52WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1203:26:52WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1303:26:52Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1403:26:52Authenticating with credentials from job payload (GitLab Registry)
1503:26:52Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1603:26:52Using 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 ...
1703:26:52Starting service redis:6.2-alpine...
1803:26:52Pulling docker image redis:6.2-alpine ...
1903:26:53Using docker image sha256:ec1b0a84ddf9124276ac189cc4d98ef28f0aea95ebd148d9e4c18b28928dd999 for redis:6.2-alpine with digest redis@sha256:2ba50e1ac3a0ea17b736ce9db2b0a9f6f8b85d4c27d5f5accc6a416d8f42c6d5 ...
2003:26:53Waiting for services to be up and running (timeout 30 seconds)...
2103:26:58Authenticating with credentials from job payload (GitLab Registry)
2203:26:58Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
2303:26:58Using docker image sha256:ab7961692458f506f4ffa89e6e60bf1fc6de783a0d358136ca0b3e84c63c84a8 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-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.22-rust-1.73-node-20.12-postgresql-14@sha256:8ec7e4c24be92019bc9072c7049231de71d9a56301d7562522d046f1494470be ...
24 03:26:58 Preparing environment 00:01
2503:26:58Running on runner-nl4gfobe-project-13083-concurrent-0 via runner-nl4gfobe-shared-gitlab-org-1729046185-7e31c27b...
26 03:26:59 Getting source from Git repository 00:00
2703:26:59Skipping Git repository setup
2803:26:59Skipping Git checkout
2903:26:59Skipping Git submodules setup
30 03:26:59 Restoring cache 00:16
3103:27:00Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-3...
3203:27:00Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/13083/ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-3 ETag="73536088bbd8ad21d4ea44312bbcbed9"
3303:27:11Successfully extracted cache
34 03:27:15 Downloading artifacts 00:41
3503:27:16Downloading artifacts for clone-gitlab-repo (8095842990)...
3603:27:19Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095842990 responseStatus=200 OK token=glcbt-66
3703:27:19WARNING: Part of .git directory is on the list of files to extract
3803:27:19WARNING: This may introduce unexpected problems
3903:27:29Downloading artifacts for compile-test-assets (8095842997)...
4003:27:33Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095842997 responseStatus=200 OK token=glcbt-66
4103:27:39Downloading artifacts for retrieve-tests-metadata (8095843012)...
4203:27:39Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095843012 responseStatus=200 OK token=glcbt-66
4303:27:39Downloading artifacts for setup-test-env (8095843004)...
4403:27:44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8095843004 responseStatus=200 OK token=glcbt-66
45 03:27:56 Executing "step_script" stage of the job script
4603:27:56Using docker image sha256:ab7961692458f506f4ffa89e6e60bf1fc6de783a0d358136ca0b3e84c63c84a8 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-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.22-rust-1.73-node-20.12-postgresql-14@sha256:8ec7e4c24be92019bc9072c7049231de71d9a56301d7562522d046f1494470be ...
4703:27:56$ echo $FOSS_ONLY
4803:27:56$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
4903:27:56$ export GOPATH=$CI_PROJECT_DIR/.go
5003:27:56$ mkdir -p $GOPATH
5103:27:56$ source scripts/utils.sh
5203:27:56$ log_disk_usage "true"
5303:27:56*******************************************************
5403:27:56This runner currently has 30G free disk space.
5503:27:56*******************************************************
56 03:27:56 Disk usage detail 00:05
5703:27:56df -h
5803:27:56Filesystem Size Used Avail Use% Mounted on
5903:27:56overlay 46G 16G 30G 34% /
6003:27:56tmpfs 64M 0 64M 0% /dev
6103:27:56shm 256M 0 256M 0% /dev/shm
6203:27:56/dev/sda1 46G 16G 30G 34% /cache
6303:27:56tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6403:27:56tmpfs 3.9G 0 3.9G 0% /proc/acpi
6503:27:56tmpfs 3.9G 0 3.9G 0% /proc/scsi
6603:27:56tmpfs 3.9G 0 3.9G 0% /sys/firmware
6703:27:56du -h -d 1
6803:27:567.4M ./workhorse
6903:27:56148K ./bin
7003:27:561.2M ./.gitlab
7103:27:56117M ./.git
7203:27:564.0K ./builds
7303:27:5628M ./lib
7403:27:56532K ./storybook
7503:27:5624K ./log
7603:27:561.8M ./data
7703:27:567.0M ./qa
7803:27:562.8M ./.rubocop_todo
7903:27:57828M ./vendor
8003:27:57850M ./public
8103:27:5759M ./doc
8203:27:57492K ./danger
8303:27:5792K ./rspec
8403:27:57552K ./tooling
8503:27:571.3M ./knapsack
8603:27:57296K ./patches
8703:27:573.9M ./changelogs
8803:27:5720K ./haml_lint
8903:27:5728K ./metrics_server
9003:27:5788K ./keeps
9103:27:5748K ./shared
9203:27:5744K ./generator_templates
9303:27:571.2M ./scripts
9403:27:57659M ./tmp
9503:27:57126M ./spec
9603:27:5720K ./file_hooks
9703:27:5716K ./sidekiq_cluster
9803:27:5717M ./gems
9903:27:571.2M ./fixtures
10003:27:57952K ./rubocop
10103:27:574.0K ./.go
10203:27:5731M ./db
10303:27:5712K ./.github
10403:27:57129M ./locale
10503:27:5719M ./config
10603:27:5781M ./app
10703:27:5720K ./.lefthook
10803:27:573.0G .
10903:27:57$ source scripts/prepare_build.sh
110 03:27:57 Installing gems 00:18
14103:28:15Using decomposed database config (config/database.yml.decomposed-postgresql)
14203:28:15Geo DB won't be set up.
14303:28:15Embedding DB won't be set up.
144 03:28:15 Setting up DBs 01:12
15603:29:27$ source ./scripts/rspec_helpers.sh
15703:29:27$ run_timed_command "gem install knapsack --no-document"
15803:29:27$ gem install knapsack --no-document
15903:29:28Successfully installed knapsack-4.0.0
16003:29:281 gem installed
16103:29:27==> 'gem install knapsack --no-document' succeeded in 1 seconds.
16203:29:28$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
163 03:29:28 Spawning Gitaly 00:04
16703:29:32$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
16803:29:32$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
16903:29:32$ tooling/bin/create_job_metrics_file || true
17003:29:34[job-metrics] Feature disabled because CI_JOB_METRICS_ENABLED is not set to true.
17103:29:34$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
172 03:29:34 RSpec 46:50
17303:29:34[03:29:34] Starting rspec_parallelized_job
17403:29:28RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
17503:29:34KNAPSACK_GENERATE_REPORT: true
17603:29:34FLAKY_RSPEC_GENERATE_REPORT: true
17703:29:34KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
17803:29:34KNAPSACK_LOG_LEVEL: debug
17903:29:34KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_2_10_13083_report.json
18003:29:34FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
18103:29:34FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_2_10_13083_report.json
18203:29:34NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_2_10_13083_report.json
18303:29:34RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8095843125.txt
18403:29:34CRYSTALBALL:
18503:29:34RSPEC_TESTS_MAPPING_ENABLED:
18603:29:34RSPEC_TESTS_FILTER_FILE:
18703:29:34Shell set options (set -o) enabled:
18803:29:34braceexpand on
18903:29:34hashall on
19003:29:34interactive-comments on
19103:29:34pipefail on
19203:29:41Knapsack report generator started!
19303:29:34/builds/gitlab-org/gitlab-foss/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!
19403:30:18warning: parser/current is loading parser/ruby32, which recognizes 3.2.4-compliant syntax, but you are running 3.2.5.
19503:30:18Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
19603:30:26/builds/gitlab-org/gitlab-foss/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!
19703:31:03Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
19803:31:03# [RSpecRunTime] Starting RSpec timer...
19903:31:03[TEST PROF INFO] EventProf enabled (sql.active_record)
20003:31:03unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20103:31:04unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20203:31:09Test environment set up in 1.08649719 seconds
20303:31:09# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb. Expected to take 3 minutes 28.38 seconds.
20403:31:09Gitlab::BackgroundMigration::BackfillIntegrationsEnableSslVerification
20503:33:17 enables SSL verification for known-good hostnames
20603:33:32 only updates records within the given ID range
20703:33:48 marks the job as succeeded
20803:33:51INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
20903:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
21003:33:51INFO: "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
21103:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
21203:33:51INFO: "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
21303:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
21403:33:51INFO: "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
21503:33:51INFO: analyzing "public.p_ci_job_annotations" inheritance tree
21603:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
21703:33:51INFO: "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
21803:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
21903:33:51INFO: "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
22003:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
22103:33:51INFO: "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
22203:33:51INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
22303:33:51INFO: analyzing "public.ci_builds_metadata"
22403:33:51INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22503:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
22603:33:51INFO: "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
22703:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
22803:33:51INFO: "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
22903:33:51INFO: analyzing "public.p_ci_builds" inheritance tree
23003:33:51INFO: analyzing "public.ci_builds"
23103:33:51INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23203:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
23303:33:51INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23403:33:51INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
23503:33:51INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
23603:33:52I, [2024-10-16T03:33:52.556282 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
23703:34:14I, [2024-10-16T03:34:14.559720 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
23803:34:16INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
23903:34:16INFO: analyzing "public.ci_pipeline_variables"
24003:34:16INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24103:34:16I, [2024-10-16T03:34:16.314910 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
24203:34:16I, [2024-10-16T03:34:16.316375 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
24303:34:16I, [2024-10-16T03:34:16.317433 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
24403:34:18INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
24503:34:18INFO: analyzing "public.ci_pipeline_variables"
24603:34:18INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24703:34:23INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
24803:34:23INFO: analyzing "public.ci_job_artifacts"
24903:34:23INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
25003:34:23I, [2024-10-16T03:34:23.105806 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
25103:34:23I, [2024-10-16T03:34:23.107048 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25203:34:23I, [2024-10-16T03:34:23.107977 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25303:34:26INFO: analyzing "public.p_ci_stages" inheritance tree
25403:34:26INFO: analyzing "public.ci_stages"
25503:34:26INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
25603:34:26I, [2024-10-16T03:34:26.794653 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
25703:34:26I, [2024-10-16T03:34:26.795915 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25803:34:26I, [2024-10-16T03:34:26.796920 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25903:34:28I, [2024-10-16T03:34:28.233494 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
26003:34:35I, [2024-10-16T03:34:35.580933 #339] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
26103:34:51I, [2024-10-16T03:34:51.849458 #339] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
26203:34:51I, [2024-10-16T03:34:51.850829 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26303:34:51I, [2024-10-16T03:34:51.851749 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26403:35:04I, [2024-10-16T03:35:04.850600 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
26503:35:12I, [2024-10-16T03:35:12.246040 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
26603:35:20I, [2024-10-16T03:35:20.800167 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
26703:35:23I, [2024-10-16T03:35:23.539882 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
26803:35:27INFO: analyzing "public.p_ci_pipelines" inheritance tree
26903:35:27INFO: analyzing "public.ci_pipelines"
27003:35:27INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
27103:35:27I, [2024-10-16T03:35:27.593118 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
27203:35:27I, [2024-10-16T03:35:27.594497 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
27303:35:27I, [2024-10-16T03:35:27.595395 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
27403:35:33I, [2024-10-16T03:35:33.984081 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
27503:35:52# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb. It took 4 minutes 43.28 seconds. Expected to take 3 minutes 28.38 seconds.
27603:35:52# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. Expected to take 2 minutes 14.87 seconds.
27703:35:52Gitlab::BackgroundMigration::BackfillDefaultBranchProtectionNamespaceSetting
27803:37:59 updates default_branch_protection_defaults to a correct value
27903:38:03INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
28003:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
28103:38:03INFO: "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
28203:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
28303:38:03INFO: "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
28403:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
28503:38:03INFO: "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
28603:38:03INFO: analyzing "public.p_ci_job_annotations" inheritance tree
28703:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
28803:38:03INFO: "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
28903:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
29003:38:03INFO: "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
29103:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
29203:38:03INFO: "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
29303:38:03INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
29403:38:03INFO: analyzing "public.ci_builds_metadata"
29503:38:03INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29603:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
29703:38:03INFO: "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
29803:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
29903:38:03INFO: "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
30003:38:03INFO: analyzing "public.p_ci_builds" inheritance tree
30103:38:03INFO: analyzing "public.ci_builds"
30203:38:03INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
30303:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
30403:38:03INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
30503:38:03INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
30603:38:03INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
30703:38:03I, [2024-10-16T03:38:03.808879 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
30803:38:25I, [2024-10-16T03:38:25.877480 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
30903:38:27INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
31003:38:27INFO: analyzing "public.ci_pipeline_variables"
31103:38:27INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
31203:38:27I, [2024-10-16T03:38:27.800337 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
31303:38:27I, [2024-10-16T03:38:27.801588 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
31403:38:27I, [2024-10-16T03:38:27.802437 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
31503:38:29INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
31603:38:29INFO: analyzing "public.ci_pipeline_variables"
31703:38:29INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
31803:38:34INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
31903:38:34INFO: analyzing "public.ci_job_artifacts"
32003:38:34INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
32103:38:34I, [2024-10-16T03:38:34.658097 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
32203:38:34I, [2024-10-16T03:38:34.659430 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32303:38:34I, [2024-10-16T03:38:34.660299 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
32403:38:38INFO: analyzing "public.p_ci_stages" inheritance tree
32503:38:38INFO: analyzing "public.ci_stages"
32603:38:38INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
32703:38:38I, [2024-10-16T03:38:38.455829 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
32803:38:38I, [2024-10-16T03:38:38.457019 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32903:38:38I, [2024-10-16T03:38:38.457846 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33003:38:39I, [2024-10-16T03:38:39.822968 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
33103:38:46I, [2024-10-16T03:38:46.925704 #339] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
33203:39:02I, [2024-10-16T03:39:02.820236 #339] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
33303:39:02I, [2024-10-16T03:39:02.821582 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33403:39:02I, [2024-10-16T03:39:02.822539 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33503:39:15I, [2024-10-16T03:39:15.447483 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
33603:39:23I, [2024-10-16T03:39:23.041563 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
33703:39:31I, [2024-10-16T03:39:31.717858 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
33803:39:34I, [2024-10-16T03:39:34.466238 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
33903:39:38INFO: analyzing "public.p_ci_pipelines" inheritance tree
34003:39:38INFO: analyzing "public.ci_pipelines"
34103:39:38INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
34203:39:38I, [2024-10-16T03:39:38.536479 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
34303:39:38I, [2024-10-16T03:39:38.538043 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
34403:39:38I, [2024-10-16T03:39:38.539001 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
34503:39:44I, [2024-10-16T03:39:44.729772 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
34603:40:03# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb. It took 4 minutes 10.31 seconds. Expected to take 2 minutes 14.87 seconds.
34703:40:03# [RSpecRunTime] RSpec elapsed time: 8 minutes 59.28 seconds. Current RSS: ~954M. Threads: 1. load average: 0.93 1.01 1.00 1/262 406
34803:40:03.
34903:40:03# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb. Expected to take 1 minute 53.81 seconds.
35003:40:03Gitlab::BackgroundMigration::BackfillVsCodeSettingsUuid
35103:41:33 #perform
35203:41:33 when it finds vs_code_setting rows with empty uuid
35303:41:46 populates uuid column with a generated uuid
35403:41:46# [RSpecRunTime] RSpec elapsed time: 10 minutes 43.12 seconds. Current RSS: ~969M. Threads: 1. load average: 1.04 1.03 1.00 1/259 407
35503:41:46.
35603:41:46 when it finds vs_code_setting rows with non-empty uuid
35703:42:00 populates uuid column with a generated uuid
35803:42:00# [RSpecRunTime] RSpec elapsed time: 10 minutes 56.91 seconds. Current RSS: ~955M. Threads: 1. load average: 1.03 1.03 1.00 1/259 408
35903:42:00.
36003:42:08I, [2024-10-16T03:42:08.750823 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
36103:42:10INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
36203:42:10INFO: analyzing "public.ci_pipeline_variables"
36303:42:10INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
36403:42:10I, [2024-10-16T03:42:10.726949 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
36503:42:10I, [2024-10-16T03:42:10.728284 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
36603:42:10I, [2024-10-16T03:42:10.729254 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
36703:42:13INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
36803:42:13INFO: analyzing "public.ci_pipeline_variables"
36903:42:13INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
37003:42:18INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
37103:42:18INFO: analyzing "public.ci_job_artifacts"
37203:42:18INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
37303:42:18I, [2024-10-16T03:42:18.037056 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
37403:42:18I, [2024-10-16T03:42:18.038294 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
37503:42:18I, [2024-10-16T03:42:18.039171 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
37603:42:21INFO: analyzing "public.p_ci_stages" inheritance tree
37703:42:21INFO: analyzing "public.ci_stages"
37803:42:21INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
37903:42:21I, [2024-10-16T03:42:21.931553 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
38003:42:21I, [2024-10-16T03:42:21.933540 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
38103:42:21I, [2024-10-16T03:42:21.934552 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
38203:42:23I, [2024-10-16T03:42:23.354877 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
38303:42:30I, [2024-10-16T03:42:30.809746 #339] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
38403:42:47I, [2024-10-16T03:42:47.544780 #339] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
38503:42:47I, [2024-10-16T03:42:47.546132 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
38603:42:47I, [2024-10-16T03:42:47.547066 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
38703:43:00I, [2024-10-16T03:43:00.880101 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
38803:43:08I, [2024-10-16T03:43:08.811818 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
38903:43:17I, [2024-10-16T03:43:17.814398 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
39003:43:20I, [2024-10-16T03:43:20.707363 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
39103:43:25INFO: analyzing "public.p_ci_pipelines" inheritance tree
39203:43:25INFO: analyzing "public.ci_pipelines"
39303:43:25INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
39403:43:25I, [2024-10-16T03:43:25.169728 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
39503:43:25I, [2024-10-16T03:43:25.171118 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39603:43:25I, [2024-10-16T03:43:25.172410 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39703:43:31I, [2024-10-16T03:43:31.512198 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
39803:43:50# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb. It took 3 minutes 47.29 seconds. Expected to take 1 minute 53.81 seconds.
39903:43:50# [RSpecRunTime] RSpec elapsed time: 12 minutes 46.92 seconds. Current RSS: ~952M. Threads: 1. load average: 1.27 1.12 1.04 1/260 409
40003:43:50.
40103:43:50# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb. Expected to take 1 minute 37.66 seconds.
40203:43:50Gitlab::BackgroundMigration::DeleteInvalidProtectedBranchMergeAccessLevels
40303:45:13 when there are merge access levels
40403:45:24 deletes merge access levels with groups that do not have project_group_links to the project
40503:45:24# [RSpecRunTime] RSpec elapsed time: 14 minutes 21.1 seconds. Current RSS: ~964M. Threads: 1. load average: 1.00 1.07 1.02 1/261 410
40603:45:24.
40703:45:27I, [2024-10-16T03:45:27.051334 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
40803:45:29INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
40903:45:29INFO: analyzing "public.ci_pipeline_variables"
41003:45:29INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
41103:45:29I, [2024-10-16T03:45:29.083031 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
41203:45:29I, [2024-10-16T03:45:29.084319 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
41303:45:29I, [2024-10-16T03:45:29.085182 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
41403:45:31INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
41503:45:31INFO: analyzing "public.ci_pipeline_variables"
41603:45:31INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
41703:45:36INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
41803:45:36INFO: analyzing "public.ci_job_artifacts"
41903:45: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
42003:45:36I, [2024-10-16T03:45:36.267429 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
42103:45:36I, [2024-10-16T03:45:36.268806 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
42203:45:36I, [2024-10-16T03:45:36.269782 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
42303:45:40INFO: analyzing "public.p_ci_stages" inheritance tree
42403:45:40INFO: analyzing "public.ci_stages"
42503:45:40INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
42603:45:40I, [2024-10-16T03:45:40.183767 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
42703:45:40I, [2024-10-16T03:45:40.185255 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
42803:45:40I, [2024-10-16T03:45:40.186321 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
42903:45:41I, [2024-10-16T03:45:41.546864 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
43003:45:48I, [2024-10-16T03:45:48.506379 #339] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
43103:46:03I, [2024-10-16T03:46:03.961317 #339] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
43203:46:03I, [2024-10-16T03:46:03.962631 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
43303:46:03I, [2024-10-16T03:46:03.963552 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
43403:46:17I, [2024-10-16T03:46:17.249944 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
43503:46:25I, [2024-10-16T03:46:25.368510 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
43603:46:34I, [2024-10-16T03:46:34.254301 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
43703:46:37I, [2024-10-16T03:46:37.102071 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
43803:46:41INFO: analyzing "public.p_ci_pipelines" inheritance tree
43903:46:41INFO: analyzing "public.ci_pipelines"
44003:46:41INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
44103:46:41I, [2024-10-16T03:46:41.308366 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
44203:46:41I, [2024-10-16T03:46:41.309856 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44303:46:41I, [2024-10-16T03:46:41.310824 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
44403:46:47I, [2024-10-16T03:46:47.785476 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
44503:47:07# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb. It took 3 minutes 16.29 seconds. Expected to take 1 minute 37.66 seconds.
44603:47:07# [RSpecRunTime] RSpec elapsed time: 16 minutes 3.26 seconds. Current RSS: ~953M. Threads: 1. load average: 0.93 1.03 1.01 1/260 411
44703:47:07.
44803:47:07# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_invalid_protected_tag_create_access_levels_spec.rb. Expected to take 1 minute 33.85 seconds.
44903:47:07Gitlab::BackgroundMigration::DeleteInvalidProtectedTagCreateAccessLevels
45003:48:34 when there are push access levels
45103:48:46 deletes push access levels with groups that do not have project_group_links to the project
45203:48:46# [RSpecRunTime] RSpec elapsed time: 17 minutes 42.41 seconds. Current RSS: ~977M. Threads: 1. load average: 1.33 1.16 1.05 1/260 412
45303:48:46.
45403:48:48I, [2024-10-16T03:48:48.457400 #339] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
45503:48:50INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
45603:48:50INFO: analyzing "public.ci_pipeline_variables"
45703:48:50INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
45803:48:50I, [2024-10-16T03:48:50.363924 #339] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
45903:48:50I, [2024-10-16T03:48:50.365170 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
46003:48:50I, [2024-10-16T03:48:50.366030 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
46103:48:52INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
46203:48:52INFO: analyzing "public.ci_pipeline_variables"
46303:48:52INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
46403:48:57INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
46503:48:57INFO: analyzing "public.ci_job_artifacts"
46603:48:57INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
46703:48:57I, [2024-10-16T03:48:57.227391 #339] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
46803:48:57I, [2024-10-16T03:48:57.228683 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
46903:48:57I, [2024-10-16T03:48:57.229570 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
47003:49:01INFO: analyzing "public.p_ci_stages" inheritance tree
47103:49:01INFO: analyzing "public.ci_stages"
47203:49:01INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
47303:49:01I, [2024-10-16T03:49:01.022866 #339] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
47403:49:01I, [2024-10-16T03:49:01.024208 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
47503:49:01I, [2024-10-16T03:49:01.025235 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
47603:49:03I, [2024-10-16T03:49:03.223415 #339] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
47703:49:10I, [2024-10-16T03:49:10.598002 #339] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
47803:49:26I, [2024-10-16T03:49:26.106760 #339] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
47903:49:26I, [2024-10-16T03:49:26.107999 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
48003:49:26I, [2024-10-16T03:49:26.108849 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
48103:49:39I, [2024-10-16T03:49:39.633886 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
48203:49:47I, [2024-10-16T03:49:47.556247 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
48303:49:56I, [2024-10-16T03:49:56.345376 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
48403:49:59I, [2024-10-16T03:49:59.257132 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
48503:50:03INFO: analyzing "public.p_ci_pipelines" inheritance tree
48603:50:03INFO: analyzing "public.ci_pipelines"
48703:50:03INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
48803:50:03I, [2024-10-16T03:50:03.516089 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
48903:50:03I, [2024-10-16T03:50:03.517490 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
49003:50:03I, [2024-10-16T03:50:03.518485 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
49103:50:09I, [2024-10-16T03:50:09.894989 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
49203:50:29# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_invalid_protected_tag_create_access_levels_spec.rb. It took 3 minutes 22.55 seconds. Expected to take 1 minute 33.85 seconds.
49303:50:29# [RSpecRunTime] RSpec elapsed time: 19 minutes 25.88 seconds. Current RSS: ~955M. Threads: 1. load average: 1.03 1.10 1.04 1/260 413
49403:50:29.
49503:50:29# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_user_achievements_namespace_id_spec.rb. Expected to take 1 minute 23.08 seconds.
49603:50:29Gitlab::BackgroundMigration::BackfillUserAchievementsNamespaceId
49703:51:28 constructs a valid query
49803:51:36 performs without error
49903:51:49I, [2024-10-16T03:51:49.959845 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
50003:51:57I, [2024-10-16T03:51:57.779602 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
50103:52:06I, [2024-10-16T03:52:06.634757 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
50203:52:09I, [2024-10-16T03:52:09.571454 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
50303:52:13INFO: analyzing "public.p_ci_pipelines" inheritance tree
50403:52:13INFO: analyzing "public.ci_pipelines"
50503:52:13INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
50603:52:13I, [2024-10-16T03:52:13.864162 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
50703:52:13I, [2024-10-16T03:52:13.865584 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
50803:52:13I, [2024-10-16T03:52:13.866532 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
50903:52:20I, [2024-10-16T03:52:20.371591 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
51003:52:40# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_user_achievements_namespace_id_spec.rb. It took 2 minutes 10.67 seconds. Expected to take 1 minute 23.08 seconds.
51103:52:40# [RSpecRunTime] RSpec elapsed time: 21 minutes 36.6 seconds. Current RSS: ~952M. Threads: 1. load average: 1.07 1.06 1.03 1/261 414
51203:52:40.
51303:52:40# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_experiment_metadata_project_id_spec.rb. Expected to take 1 minute 10.49 seconds.
51403:52:40Gitlab::BackgroundMigration::BackfillMlExperimentMetadataProjectId
51503:53:36 performs without error
51603:53:43 constructs a valid query
51703:53:57I, [2024-10-16T03:53:57.036018 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
51803:54:04I, [2024-10-16T03:54:04.719016 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
51903:54:13I, [2024-10-16T03:54:13.454130 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
52003:54:16I, [2024-10-16T03:54:16.265890 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
52103:54:20INFO: analyzing "public.p_ci_pipelines" inheritance tree
52203:54:20INFO: analyzing "public.ci_pipelines"
52303:54:20INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
52403:54:20I, [2024-10-16T03:54:20.460866 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
52503:54:20I, [2024-10-16T03:54:20.462452 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
52603:54:20I, [2024-10-16T03:54:20.463498 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52703:54:26I, [2024-10-16T03:54:26.980600 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
52803:54:46# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_experiment_metadata_project_id_spec.rb. It took 2 minutes 6.08 seconds. Expected to take 1 minute 10.49 seconds.
52903:54:46# [RSpecRunTime] RSpec elapsed time: 23 minutes 42.73 seconds. Current RSS: ~951M. Threads: 1. load average: 1.07 1.08 1.03 1/261 415
53003:54:46.
53103:54:46# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. Expected to take 1 minute 6.3 seconds.
53203:54:46Gitlab::BackgroundMigration::BackfillHasRemediationsOfVulnerabilityReads
53303:55:49 does not modify has_remediations of vulnerabilities which do not have remediations
53403:55:49 when finding_remediation record exists
53503:55:57 updates vulnerability_reads records which has remediations
53603:55:57# [RSpecRunTime] RSpec elapsed time: 24 minutes 53.28 seconds. Current RSS: ~964M. Threads: 1. load average: 1.21 1.10 1.04 1/261 416
53703:55:57.
53803:56:02I, [2024-10-16T03:56:02.915342 #339] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
53903:56:02I, [2024-10-16T03:56:02.916718 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
54003:56:02I, [2024-10-16T03:56:02.917631 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
54103:56:15I, [2024-10-16T03:56:15.942464 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
54203:56:23I, [2024-10-16T03:56:23.819506 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
54303:56:32I, [2024-10-16T03:56:32.337280 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
54403:56:35I, [2024-10-16T03:56:35.387794 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
54503:56:39INFO: analyzing "public.p_ci_pipelines" inheritance tree
54603:56:39INFO: analyzing "public.ci_pipelines"
54703:56:39INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
54803:56:39I, [2024-10-16T03:56:39.532108 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
54903:56:39I, [2024-10-16T03:56:39.534221 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
55003:56:39I, [2024-10-16T03:56:39.535135 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
55103:56:45I, [2024-10-16T03:56:45.869341 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
55203:57:04# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb. It took 2 minutes 18.32 seconds. Expected to take 1 minute 6.3 seconds.
55303:57:04# [RSpecRunTime] RSpec elapsed time: 26 minutes 1.1 seconds. Current RSS: ~953M. Threads: 1. load average: 1.10 1.08 1.04 1/261 417
55403:57:04.
55503:57:04# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_dast_profiles_tags_project_id_spec.rb. Expected to take 1 minute 4.1 seconds.
55603:57:04Gitlab::BackgroundMigration::BackfillDastProfilesTagsProjectId
55703:58:01 constructs a valid query
55803:58:08 performs without error
55903:58:21I, [2024-10-16T03:58:21.392695 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
56003:58:29I, [2024-10-16T03:58:29.105246 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
56103:58:38I, [2024-10-16T03:58:38.451241 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
56203:58:41I, [2024-10-16T03:58:41.255335 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
56303:58:45INFO: analyzing "public.p_ci_pipelines" inheritance tree
56403:58:45INFO: analyzing "public.ci_pipelines"
56503:58:45INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
56603:58:45I, [2024-10-16T03:58:45.448739 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
56703:58:45I, [2024-10-16T03:58:45.450134 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56803:58:45I, [2024-10-16T03:58:45.451157 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56903:58:51I, [2024-10-16T03:58:51.589533 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
57003:59:10# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_dast_profiles_tags_project_id_spec.rb. It took 2 minutes 5.53 seconds. Expected to take 1 minute 4.1 seconds.
57103:59:10# [RSpecRunTime] RSpec elapsed time: 28 minutes 6.67 seconds. Current RSS: ~954M. Threads: 1. load average: 1.04 1.06 1.03 1/261 418
57203:59:10.
57303:59:10# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_agent_activity_events_agent_project_id_spec.rb. Expected to take 1 minute 1.83 seconds.
57403:59:10Gitlab::BackgroundMigration::BackfillAgentActivityEventsAgentProjectId
57504:00:04 constructs a valid query
57604:00:10 performs without error
57704:00:11I, [2024-10-16T04:00:11.612039 #339] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
57804:00:11I, [2024-10-16T04:00:11.613302 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
57904:00:11I, [2024-10-16T04:00:11.614125 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
58004:00:23I, [2024-10-16T04:00:23.514240 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
58104:00:31I, [2024-10-16T04:00:31.203290 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
58204:00:40I, [2024-10-16T04:00:40.793259 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
58304:00:43I, [2024-10-16T04:00:43.735598 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
58404:00:48INFO: analyzing "public.p_ci_pipelines" inheritance tree
58504:00:48INFO: analyzing "public.ci_pipelines"
58604:00:48INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
58704:00:48I, [2024-10-16T04:00:48.102830 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
58804:00:48I, [2024-10-16T04:00:48.104217 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
58904:00:48I, [2024-10-16T04:00:48.105197 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
59004:00:54I, [2024-10-16T04:00:54.420708 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
59104:01:13# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_agent_activity_events_agent_project_id_spec.rb. It took 2 minutes 2.83 seconds. Expected to take 1 minute 1.83 seconds.
59204:01:13# [RSpecRunTime] RSpec elapsed time: 30 minutes 9.55 seconds. Current RSS: ~957M. Threads: 1. load average: 1.01 1.04 1.02 1/262 420
59304:01:13.
59404:01:13# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_message_spec.rb. Expected to take 1 minute 0.35 second.
59504:01:13Gitlab::BackgroundMigration::BackfillPartitionIdCiPipelineMessage
59604:01:51 #perform
59704:01:51 when there are no invalid records
59804:01:57 does not execute the migration
59904:01:57# [RSpecRunTime] RSpec elapsed time: 30 minutes 53.59 seconds. Current RSS: ~958M. Threads: 1. load average: 1.08 1.06 1.03 1/261 421
60004:01:57.
60104:01:57 when second partition exists
60204:02:03 fixes invalid records in the wrong the partition
60304:02:03# [RSpecRunTime] RSpec elapsed time: 30 minutes 59.38 seconds. Current RSS: ~954M. Threads: 1. load average: 1.07 1.06 1.03 1/261 422
60404:02:03.
60504:02:10I, [2024-10-16T04:02:10.967926 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
60604:02:20I, [2024-10-16T04:02:20.526861 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
60704:02:23I, [2024-10-16T04:02:23.426005 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
60804:02:28INFO: analyzing "public.p_ci_pipelines" inheritance tree
60904:02:28INFO: analyzing "public.ci_pipelines"
61004:02:28INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
61104:02:28I, [2024-10-16T04:02:28.075734 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
61204:02:28I, [2024-10-16T04:02:28.077024 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
61304:02:28I, [2024-10-16T04:02:28.077968 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
61404:02:34I, [2024-10-16T04:02:34.321265 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
61504:02:52# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_message_spec.rb. It took 1 minute 39.46 seconds. Expected to take 1 minute 0.35 second.
61604:02:52# [RSpecRunTime] RSpec elapsed time: 31 minutes 49.05 seconds. Current RSS: ~952M. Threads: 1. load average: 0.80 0.99 1.00 1/261 423
61704:02:52.
61804:02:52# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_epic_issues_namespace_id_spec.rb. Expected to take 49.49 seconds.
61904:02:52Gitlab::BackgroundMigration::BackfillEpicIssuesNamespaceId
62004:03:30 constructs a valid query
62104:03:35 performs without error
62204:03:36I, [2024-10-16T04:03:36.211912 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
62304:03:44I, [2024-10-16T04:03:44.727473 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
62404:03:47I, [2024-10-16T04:03:47.586798 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
62504:03:51INFO: analyzing "public.p_ci_pipelines" inheritance tree
62604:03:51INFO: analyzing "public.ci_pipelines"
62704:03:51INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
62804:03:51I, [2024-10-16T04:03:51.861733 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
62904:03:51I, [2024-10-16T04:03:51.863116 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
63004:03:51I, [2024-10-16T04:03:51.863978 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
63104:03:58I, [2024-10-16T04:03:58.001957 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
63204:04:17# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_epic_issues_namespace_id_spec.rb. It took 1 minute 24.12 seconds. Expected to take 49.49 seconds.
63304:04:17# [RSpecRunTime] RSpec elapsed time: 33 minutes 13.21 seconds. Current RSS: ~955M. Threads: 1. load average: 0.94 1.00 1.00 1/262 424
63404:04:17.
63504:04:17# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_findings_remediations_project_id_spec.rb. Expected to take 48.57 seconds.
63604:04:17Gitlab::BackgroundMigration::BackfillVulnerabilityFindingsRemediationsProjectId
63704:04:58 performs without error
63804:05:04 constructs a valid query
63904:05:05I, [2024-10-16T04:05:05.378253 #339] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
64004:05:12I, [2024-10-16T04:05:12.237687 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
64104:05:20I, [2024-10-16T04:05:20.418922 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
64204:05:23I, [2024-10-16T04:05:23.250288 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
64304:05:28INFO: analyzing "public.p_ci_pipelines" inheritance tree
64404:05:28INFO: analyzing "public.ci_pipelines"
64504:05:28INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
64604:05:28I, [2024-10-16T04:05:28.351863 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
64704:05:28I, [2024-10-16T04:05:28.353226 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
64804:05:28I, [2024-10-16T04:05:28.354213 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
64904:05:34I, [2024-10-16T04:05:34.291271 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
65004:05:52# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_findings_remediations_project_id_spec.rb. It took 1 minute 35.29 seconds. Expected to take 48.57 seconds.
65104:05:52# [RSpecRunTime] RSpec elapsed time: 34 minutes 48.54 seconds. Current RSS: ~954M. Threads: 1. load average: 1.07 1.03 1.01 1/262 425
65204:05:52.
65304:05:52# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_users_color_mode_id_spec.rb. Expected to take 41.97 seconds.
65404:05:52Gitlab::BackgroundMigration::BackfillUsersColorModeId
65504:06:31 backfills with the default values
65604:06:37I, [2024-10-16T04:06:37.567569 #339] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
65704:06:46I, [2024-10-16T04:06:46.246785 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
65804:06:49I, [2024-10-16T04:06:49.098319 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
65904:06:53INFO: analyzing "public.p_ci_pipelines" inheritance tree
66004:06:53INFO: analyzing "public.ci_pipelines"
66104:06:53INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
66204:06:54I, [2024-10-16T04:06:54.004502 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
66304:06:54I, [2024-10-16T04:06:54.005785 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
66404:06:54I, [2024-10-16T04:06:54.006695 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
66504:07:00I, [2024-10-16T04:07:00.118192 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
66604:07:18# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_users_color_mode_id_spec.rb. It took 1 minute 26.02 seconds. Expected to take 41.97 seconds.
66704:07:18# [RSpecRunTime] RSpec elapsed time: 36 minutes 14.6 seconds. Current RSS: ~955M. Threads: 1. load average: 1.05 1.03 1.00 1/262 426
66804:07:18.
66904:07:18# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb. Expected to take 36.83 seconds.
67004:07:18Gitlab::BackgroundMigration::BackfillVulnerabilityFindingLinksProjectId
67104:07:53 constructs a valid query
67204:07:58 performs without error
67304:07:58The application_settings (main) table has 1204 columns.
67404:07:58Recreating the database
67504:07:59Dropped database 'gitlabhq_test'
67604:07:59Dropped database 'gitlabhq_test_ci'
67704:08:00Created database 'gitlabhq_test'
67804:08:00Created database 'gitlabhq_test_ci'
67904:08:11main: == [advisory_lock_connection] object_id: 383582420, pg_backend_pid: 389
68004:08:11main: == [advisory_lock_connection] object_id: 383582420, pg_backend_pid: 389
68104:08:11ci: == [advisory_lock_connection] object_id: 383689120, pg_backend_pid: 391
68204:08:11ci: == [advisory_lock_connection] object_id: 383689120, pg_backend_pid: 391
68304:08:17Databases re-creation done in 19.156578150000314
68404:08:17# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb. It took 59.44 seconds. Expected to take 36.83 seconds.
68504:08:17# [RSpecRunTime] RSpec elapsed time: 37 minutes 14.08 seconds. Current RSS: ~954M. Threads: 1. load average: 1.14 1.07 1.02 1/262 429
68604:08:17.
68704:08:17# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_occurrence_pipelines_project_id_spec.rb. Expected to take 32.93 seconds.
68804:08:17Gitlab::BackgroundMigration::BackfillVulnerabilityOccurrencePipelinesProjectId
68904:08:47 constructs a valid query
69004:08:51 performs without error
69104:08:59I, [2024-10-16T04:08:59.690802 #339] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
69204:09:02I, [2024-10-16T04:09:02.327214 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
69304:09:05INFO: analyzing "public.p_ci_pipelines" inheritance tree
69404:09:05INFO: analyzing "public.ci_pipelines"
69504:09:05INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
69604:09:05I, [2024-10-16T04:09:05.989554 #339] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
69704:09:05I, [2024-10-16T04:09:05.990813 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
69804:09:05I, [2024-10-16T04:09:05.991713 #339] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
69904:09:11I, [2024-10-16T04:09:11.354745 #339] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
70004:09:28# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_occurrence_pipelines_project_id_spec.rb. It took 1 minute 10.44 seconds. Expected to take 32.93 seconds.
70104:09:28# [RSpecRunTime] RSpec elapsed time: 38 minutes 24.56 seconds. Current RSS: ~955M. Threads: 1. load average: 0.94 1.02 1.00 1/262 430
70204:09:28.
70304:09:28# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb. Expected to take 25.09 seconds.
70404:09:28Gitlab::BackgroundMigration::BackfillCiResourcesProjectId
70504:09:48 performs without error
70604:09:52 constructs a valid query
70704:10:18# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb. It took 49.69 seconds. Expected to take 25.09 seconds.
70804:10:18# [RSpecRunTime] RSpec elapsed time: 39 minutes 14.29 seconds. Current RSS: ~954M. Threads: 1. load average: 0.98 1.01 1.00 3/263 431
70904:10:18.
71004:10:18# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_project_id_to_security_scans_spec.rb. Expected to take 20.76 seconds.
71104:10:18Gitlab::BackgroundMigration::BackfillProjectIdToSecurityScans
71204:10:18 when security_scan does not need to be changed
71304:10:22 does not update the scan
71404:10:22# [RSpecRunTime] RSpec elapsed time: 39 minutes 18.71 seconds. Current RSS: ~961M. Threads: 1. load average: 0.98 1.01 1.00 1/263 432
71504:10:22.
71604:10:22 when security_scan.build_id does not exist
71704:10:26 deletes the security_scan
71804:10:26# [RSpecRunTime] RSpec elapsed time: 39 minutes 22.65 seconds. Current RSS: ~957M. Threads: 1. load average: 0.98 1.01 1.00 1/263 433
71904:10:26.
72004:10:26 when security_scan is missing project_id
72104:10:30 sets the project_id to build.project_id
72204:10:34 touches updated_at
72304:10:34# [RSpecRunTime] RSpec elapsed time: 39 minutes 30.54 seconds. Current RSS: ~964M. Threads: 1. load average: 0.98 1.01 1.00 1/263 434
72404:10:34.
72504:10:42# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_project_id_to_security_scans_spec.rb. It took 24.65 seconds. Expected to take 20.76 seconds.
72604:10:42# [RSpecRunTime] RSpec elapsed time: 39 minutes 38.99 seconds. Current RSS: ~954M. Threads: 1. load average: 0.98 1.01 1.00 1/263 435
72704:10:42.
72804:10:42# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_rubygems_metadata_project_id_spec.rb. Expected to take 16.23 seconds.
72904:10:42Gitlab::BackgroundMigration::BackfillPackagesRubygemsMetadataProjectId
73004:10:51 constructs a valid query
73104:10:55 performs without error
73204:11:11# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_rubygems_metadata_project_id_spec.rb. It took 28.71 seconds. Expected to take 16.23 seconds.
73304:11:11# [RSpecRunTime] RSpec elapsed time: 40 minutes 7.73 seconds. Current RSS: ~960M. Threads: 1. load average: 0.85 0.98 0.99 1/263 436
73404:11:11.
73504:11:11# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. Expected to take 13.18 seconds.
73604:11:11Gitlab::BackgroundMigration::SetCorrectVulnerabilityState
73704:11:12 #filter_batch
73804:11:16 filters out vulnerabilities where dismissed_at is null
73904:11:16# [RSpecRunTime] RSpec elapsed time: 40 minutes 12.35 seconds. Current RSS: ~968M. Threads: 1. load average: 0.86 0.98 0.99 1/263 437
74004:11:16.
74104:11:16 #perform
74204:11:20 changes vulnerability state to `dismissed` when dismissed_at is not nil
74304:11:24 does not change the state when dismissed_at is nil
74404:11:24# [RSpecRunTime] RSpec elapsed time: 40 minutes 20.38 seconds. Current RSS: ~962M. Threads: 1. load average: 0.87 0.98 0.99 1/263 438
74504:11:24.
74604:11:32# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb. It took 20.99 seconds. Expected to take 13.18 seconds.
74704:11:32# [RSpecRunTime] RSpec elapsed time: 40 minutes 28.8 seconds. Current RSS: ~960M. Threads: 1. load average: 0.82 0.96 0.99 1/263 439
74804:11:32.
74904:11:32# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_incident_management_timeline_event_tag_links_project_id_spec.rb. Expected to take 12.42 seconds.
75004:11:32Gitlab::BackgroundMigration::BackfillIncidentManagementTimelineEventTagLinksProjectId
75104:11:42 constructs a valid query
75204:11:46 performs without error
75304:12:03# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_incident_management_timeline_event_tag_links_project_id_spec.rb. It took 30.9 seconds. Expected to take 12.42 seconds.
75404:12:03# [RSpecRunTime] RSpec elapsed time: 40 minutes 59.74 seconds. Current RSS: ~959M. Threads: 1. load average: 0.78 0.94 0.98 1/263 440
75504:12:03.
75604:12:03# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_members_request_accepted_at_spec.rb. Expected to take 6.67 seconds.
75704:12:03Gitlab::BackgroundMigration::BackfillMembersRequestAcceptedAt
75804:12:06 #perform
75904:12:06 when `requested_at`, `invite_token`, `invite_accepted_at` and `request_accepted_at` are set to nil
76004:12:09 backfills `request_accepted_at` column to `created_at` for eligible members
76104:12:10# [RSpecRunTime] RSpec elapsed time: 41 minutes 6.19 seconds. Current RSS: ~969M. Threads: 1. load average: 0.79 0.94 0.98 1/263 441
76204:12:10.
76304:12:22# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_members_request_accepted_at_spec.rb. It took 18.81 seconds. Expected to take 6.67 seconds.
76404:12:22# [RSpecRunTime] RSpec elapsed time: 41 minutes 18.59 seconds. Current RSS: ~960M. Threads: 1. load average: 0.70 0.91 0.97 1/263 442
76504:12:22.
76604:12:22# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/update_ci_pipeline_artifacts_unknown_locked_status_spec.rb. Expected to take 5.43 seconds.
76704:12:22Gitlab::BackgroundMigration::UpdateCiPipelineArtifactsUnknownLockedStatus
76804:12:22 #perform
76904:12:26 updates ci_pipeline_artifacts with unknown lock status
77004:12:26# [RSpecRunTime] RSpec elapsed time: 41 minutes 22.87 seconds. Current RSS: ~967M. Threads: 1. load average: 0.72 0.91 0.97 1/263 443
77104:12:26.
77204:12:34# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/update_ci_pipeline_artifacts_unknown_locked_status_spec.rb. It took 12.42 seconds. Expected to take 5.43 seconds.
77304:12:34# [RSpecRunTime] RSpec elapsed time: 41 minutes 31.06 seconds. Current RSS: ~957M. Threads: 1. load average: 0.74 0.91 0.97 1/263 444
77404:12:34.
77504:12:34# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb. Expected to take 4.79 seconds.
77604:12:34Gitlab::BackgroundMigration::DisableLegacyOpenSourceLicenseForInactivePublicProjects
77704:12:39 sets `legacy_open_source_license_available` attribute to false for inactive, public projects
77804:12:48# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb. It took 13.14 seconds. Expected to take 4.79 seconds.
77904:12:48# [RSpecRunTime] RSpec elapsed time: 41 minutes 44.25 seconds. Current RSS: ~955M. Threads: 1. load average: 0.80 0.92 0.97 1/263 445
78004:12:48.
78104:13:45auto_explain log contains 1137 entries for main, writing to /builds/gitlab-org/gitlab-foss/auto_explain/rspec-background-migration-pg14-2-10.339.main.ndjson.gz
78204:13:45took 57.866951615
78304:14:41auto_explain log contains 1137 entries for ci, writing to /builds/gitlab-org/gitlab-foss/auto_explain/rspec-background-migration-pg14-2-10.339.ci.ndjson.gz
78404:14:41took 55.853870433
78504:14:41[TEST PROF INFO] EventProf results for sql.active_record
78604:14:41Total time: 27:26.650 of 41:38.586 (65.9%)
78704:14:41Total events: 1083828
78804:14:41Top 5 slowest suites (by time):
78904:14:41Gitlab::Backg...slVerification (./spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb:5) – 02:56.240 (116254 / 3) of 04:43.277 (62.21%)
79004:14:41Gitlab::Backg...mespaceSetting (./spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb:5) – 02:53.816 (111344 / 1) of 04:10.662 (69.34%)
79104:14:41Gitlab::Backg...deSettingsUuid (./spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb:5) – 02:30.671 (97708 / 2) of 03:47.334 (66.28%)
79204:14:41Gitlab::Backg...teAccessLevels (./spec/lib/gitlab/background_migration/delete_invalid_protected_tag_create_access_levels_spec.rb:5) – 02:21.716 (89906 / 1) of 03:22.601 (69.95%)
79304:14:41Gitlab::Backg...geAccessLevels (./spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb:5) – 02:17.372 (89819 / 1) of 03:16.357 (69.96%)
79404:14:41Knapsack report was generated. Preview:
79504:14:41{
79604:14:41 "spec/lib/gitlab/background_migration/backfill_integrations_enable_ssl_verification_spec.rb": 158.67325117200016,
79704:14:41 "spec/lib/gitlab/background_migration/backfill_default_branch_protection_namespace_setting_spec.rb": 126.4539252479999,
79804:14:41 "spec/lib/gitlab/background_migration/backfill_vs_code_settings_uuid_spec.rb": 117.31854650700006,
79904:14:41 "spec/lib/gitlab/background_migration/delete_invalid_protected_branch_merge_access_levels_spec.rb": 94.19007791499962,
80004:14:41 "spec/lib/gitlab/background_migration/delete_invalid_protected_tag_create_access_levels_spec.rb": 99.12784069500049,
80104:14:41 "spec/lib/gitlab/background_migration/backfill_user_achievements_namespace_id_spec.rb": 66.86924256899965,
80204:14:41 "spec/lib/gitlab/background_migration/backfill_ml_experiment_metadata_project_id_spec.rb": 63.31705963500008,
80304:14:41 "spec/lib/gitlab/background_migration/backfill_has_remediations_of_vulnerability_reads_spec.rb": 70.56036962200051,
80404:14:41 "spec/lib/gitlab/background_migration/backfill_dast_profiles_tags_project_id_spec.rb": 63.845952489999945,
80504:14:41 "spec/lib/gitlab/background_migration/backfill_agent_activity_events_agent_project_id_spec.rb": 60.44849276200057,
80604:14:41 "spec/lib/gitlab/background_migration/backfill_partition_id_ci_pipeline_message_spec.rb": 49.83734685199943,
80704:14:41 "spec/lib/gitlab/background_migration/backfill_epic_issues_namespace_id_spec.rb": 42.422431834000236,
80804:14:41 "spec/lib/gitlab/background_migration/backfill_vulnerability_findings_remediations_project_id_spec.rb": 47.2534448360002,
80904:14:41 "spec/lib/gitlab/background_migration/backfill_users_color_mode_id_spec.rb": 39.48623089299963,
81004:14:41 "spec/lib/gitlab/background_migration/backfill_vulnerability_finding_links_project_id_spec.rb": 40.13522685099997,
81104:14:41 "spec/lib/gitlab/background_migration/backfill_vulnerability_occurrence_pipelines_project_id_spec.rb": 33.775448754000536,
81204:14:41 "spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb": 23.907977650000248,
81304:14:41 "spec/lib/gitlab/background_migration/backfill_project_id_to_security_scans_spec.rb": 16.24678861800021,
81404:14:41 "spec/lib/gitlab/background_migration/backfill_packages_rubygems_metadata_project_id_spec.rb": 12.284866531999796,
81504:14:41 "spec/lib/gitlab/background_migration/set_correct_vulnerability_state_spec.rb": 12.614953440000136,
81604:14:41 "spec/lib/gitlab/background_migration/backfill_incident_management_timeline_event_tag_links_project_id_spec.rb": 13.738693713999965,
81704:14:41 "spec/lib/gitlab/background_migration/backfill_members_request_accepted_at_spec.rb": 6.451098822999484,
81804:14:41 "spec/lib/gitlab/background_migration/update_ci_pipeline_artifacts_unknown_locked_status_spec.rb": 4.2808862649999355,
81904:14:41 "spec/lib/gitlab/background_migration/disable_legacy_open_source_license_for_inactive_public_projects_spec.rb": 5.007001619999755
82004:14:41}
82104:14:41Knapsack global time execution for tests: 21m 08s
82204:14:41Finished in 43 minutes 38 seconds (files took 1 minute 25.63 seconds to load)
82304:14:4145 examples, 0 failures
82404:14:41Randomized with seed 50098
82504:14:46RSpec exited with 0.
82604:14:46No examples to retry, congrats!
827 04:14:46 Running after_script 00:14
82804:14:47Running after script...
82904:14:47$ source scripts/utils.sh
83004:14:47$ log_disk_usage
83104:14:47*******************************************************
83204:14:47This runner currently has 28G free disk space.
83304:14:47*******************************************************
834 04:14:47 Disk usage detail 00:05
89004:14:52$ bundle exec gem list gitlab_quality-test_tooling
89104:14:54gitlab_quality-test_tooling (1.39.0)
89204:14:54$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
893 04:14:54 Report test failures 00:03
89704:14:57$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
898 04:14:57 Report test flakiness 00:00
90004:14:57$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
901 04:14:57 Report test slowness 00:02
90504:14:59$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
906 04:14:59 Report test slowness in MR note 00:00
90804:14:59$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
909 04:14:59 Report test files close to timing out 00:00
91104:14:59$ tooling/bin/push_job_metrics || true
91204:15:00[job-metrics] Feature disabled because CI_JOB_METRICS_ENABLED is not set to true.
913 04:15:00 Saving cache for successful job 00:01
91404:15:01Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-3 due to policy
915 04:15:01 Uploading artifacts for successful job 00:05
91604:15:01Uploading artifacts...
91704:15:01auto_explain/: found 3 matching artifact files and directories
91804:15:01coverage/: found 5 matching artifact files and directories
91904:15:01WARNING: crystalball/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab-foss)
92004:15:01WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab-foss)
92104:15:01knapsack/: found 4 matching artifact files and directories
92204:15:01rspec/: found 12 matching artifact files and directories
92304:15:01WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab-foss)
92404:15:01log/*.log: found 13 matching artifact files and directories
92504:15:01WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8095843125/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
92604:15:01WARNING: Retrying... context=artifacts-uploader error=request redirected
92704:15:04Uploading artifacts as "archive" to coordinator... 201 Created id=8095843125 responseStatus=201 Created token=glcbt-66
92804:15:04Uploading artifacts...
92904:15:04rspec/rspec-*.xml: found 1 matching artifact files and directories
93004:15:04WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8095843125/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
93104:15:04WARNING: Retrying... context=artifacts-uploader error=request redirected
93204:15:06Uploading artifacts as "junit" to coordinator... 201 Created id=8095843125 responseStatus=201 Created token=glcbt-66
933 04:15:06 Cleaning up project directory and file based variables 00:01
93404:15:14Job succeeded