Skip to content
Snippets Groups Projects

rspec background_migration pg14 1/10

Passed Started by
George Koltsov
@georgekoltsov
Log timestamps in UTC.
116:54:03Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
216:54:03 on blue-1.private.runners-manager.gitlab.com/gitlab.com/gitlab-org 1zzGUpzq, system ID: s_fc31da7ae46e
316:54:03 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
416:54:03Resolving secrets
5 16:54:03 Preparing the "docker+machine" executor 00:11
616:54:03Using 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 ...
716:54:05Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
816:54:05Authenticating with credentials from job payload (GitLab Registry)
916:54:05Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1016:54:05Using 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 ...
1116:54:06WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1216:54:06WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1316:54:06Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1416:54:06Authenticating with credentials from job payload (GitLab Registry)
1516:54:06Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1616:54:06Using 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 ...
1716:54:07Starting service redis:6.2-alpine...
1816:54:07Pulling docker image redis:6.2-alpine ...
1916:54:07Using docker image sha256:ec1b0a84ddf9124276ac189cc4d98ef28f0aea95ebd148d9e4c18b28928dd999 for redis:6.2-alpine with digest redis@sha256:2ba50e1ac3a0ea17b736ce9db2b0a9f6f8b85d4c27d5f5accc6a416d8f42c6d5 ...
2016:54:08Waiting for services to be up and running (timeout 30 seconds)...
2116:54:14Authenticating with credentials from job payload (GitLab Registry)
2216:54:14Pulling 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 ...
2316:54:14Using 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 16:54:14 Preparing environment 00:01
2516:54:15Running on runner-1zzgupzq-project-278964-concurrent-0 via runner-1zzgupzq-private-1729253594-d8496eaf...
26 16:54:15 Getting source from Git repository 00:01
2716:54:16Skipping Git repository setup
2816:54:16Skipping Git checkout
2916:54:16Skipping Git submodules setup
30 16:54:16 Restoring cache 00:17
3116:54:16Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-19...
3216:54:17cache.zip is up to date
3316:54:27Successfully extracted cache
34 16:54:33 Downloading artifacts 00:45
3516:54:34Downloading artifacts for clone-gitlab-repo (8126558001)...
3616:54:38Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8126558001 responseStatus=200 OK token=glcbt-66
3716:54:38WARNING: Part of .git directory is on the list of files to extract
3816:54:38WARNING: This may introduce unexpected problems
3916:54:51Downloading artifacts for compile-test-assets (8126558064)...
4016:54:55Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8126558064 responseStatus=200 OK token=glcbt-66
4116:55:01Downloading artifacts for detect-tests (8126558090)...
4216:55:02Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8126558090 responseStatus=200 OK token=glcbt-66
4316:55:02Downloading artifacts for retrieve-tests-metadata (8126558100)...
4416:55:02Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8126558100 responseStatus=200 OK token=glcbt-66
4516:55:02Downloading artifacts for setup-test-env (8126558072)...
4616:55:06Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8126558072 responseStatus=200 OK token=glcbt-66
47 16:55:18 Executing "step_script" stage of the job script
4816:55:18Using 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 ...
4916:55:18$ echo $FOSS_ONLY
5016:55:18$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
5116:55:18$ export GOPATH=$CI_PROJECT_DIR/.go
5216:55:18$ mkdir -p $GOPATH
5316:55:18$ source scripts/utils.sh
5416:55:18$ log_disk_usage "true"
5516:55:18*******************************************************
5616:55:18This runner currently has 75G free disk space.
5716:55:18*******************************************************
58 16:55:18 Disk usage detail 00:07
5916:55:18df -h
6016:55:18Filesystem Size Used Avail Use% Mounted on
6116:55:18overlay 95G 20G 75G 22% /
6216:55:18tmpfs 64M 0 64M 0% /dev
6316:55:18shm 64M 0 64M 0% /dev/shm
6416:55:18/dev/sda1 95G 20G 75G 22% /cache
6516:55:18tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6616:55:18du -h -d 1
6716:55:187.4M ./workhorse
6816:55:18148K ./bin
6916:55:181.2M ./.gitlab
7016:55:18177M ./.git
7116:55:184.0K ./builds
7216:55:1828M ./lib
7316:55:188.0K ./.vscode
7416:55:18532K ./storybook
7516:55:1820K ./log
7616:55:181.8M ./data
7716:55:1810M ./qa
7816:55:182.8M ./.rubocop_todo
7916:55:18819M ./vendor
8016:55:191006M ./public
8116:55:1959M ./doc
8216:55:19492K ./danger
8316:55:19108K ./rspec
8416:55:19552K ./tooling
8516:55:19142M ./ee
8616:55:191.3M ./knapsack
8716:55:19296K ./patches
8816:55:194.3M ./changelogs
8916:55:1920K ./haml_lint
9016:55:1928K ./metrics_server
9116:55:1988K ./keeps
9216:55:1948K ./shared
9316:55:1944K ./generator_templates
9416:55:191.2M ./scripts
9516:55:19690M ./tmp
9616:55:19126M ./spec
9716:55:1920K ./file_hooks
9816:55:1932K ./crystalball
9916:55:1916K ./sidekiq_cluster
10016:55:1917M ./gems
10116:55:191.2M ./fixtures
10216:55:19968K ./rubocop
10316:55:194.0K ./.go
10416:55:1931M ./db
10516:55:1912K ./.github
10616:55:19129M ./locale
10716:55:1919M ./config
10816:55:1981M ./app
10916:55:1920K ./.lefthook
11016:55:193.3G .
11116:55:19$ source scripts/prepare_build.sh
112 16:55:19 Installing gems 00:22
14316:55:41Using decomposed database config (config/database.yml.decomposed-postgresql)
14416:55:41Geo DB won't be set up.
14516:55:41Embedding DB won't be set up.
146 16:55:41 Setting up DBs 01:12
15816:56:53$ source ./scripts/rspec_helpers.sh
15916:56:53$ run_timed_command "gem install knapsack --no-document"
16016:56:53$ gem install knapsack --no-document
16116:56:54Successfully installed knapsack-4.0.0
16216:56:541 gem installed
16316:56:53==> 'gem install knapsack --no-document' succeeded in 1 seconds.
16416:56:54$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
165 16:56:54 Spawning Gitaly 00:05
16916:56:59$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
17016:56:59$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
17116:56:59$ tooling/bin/create_job_metrics_file || true
17216:57:01[job-metrics] Creating the job metrics file for the CI/CD job.
17316:57:01$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
174 16:57:01 RSpec 41:25
17516:57:01[16:57:01] Starting rspec_parallelized_job
17616:56:54RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
17716:57:01KNAPSACK_GENERATE_REPORT: true
17816:57:01FLAKY_RSPEC_GENERATE_REPORT: true
17916:57:01KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
18016:57:01KNAPSACK_LOG_LEVEL: debug
18116:57:01KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_1_10_278964_report.json
18216:57:01FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
18316:57:01FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_1_10_278964_report.json
18416:57:01NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_1_10_278964_report.json
18516:57:01RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8126558223.txt
18616:57:01CRYSTALBALL:
18716:57:01RSPEC_TESTS_MAPPING_ENABLED:
18816:57:01RSPEC_TESTS_FILTER_FILE:
18916:57:01Shell set options (set -o) enabled:
19016:57:01braceexpand on
19116:57:01hashall on
19216:57:01interactive-comments on
19316:57:01pipefail on
19416:57:08Knapsack report generator started!
19516:57:01/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!
19616:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:19: warning: already initialized constant Integrations::Base::BaseIntegration::UnknownType
19716:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:19: warning: previous definition of UnknownType was here
19816:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:24: warning: already initialized constant Integrations::Base::BaseIntegration::INTEGRATION_NAMES
19916:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:24: warning: previous definition of INTEGRATION_NAMES was here
20016:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:34: warning: already initialized constant Integrations::Base::BaseIntegration::INSTANCE_LEVEL_ONLY_INTEGRATION_NAMES
20116:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:34: warning: previous definition of INSTANCE_LEVEL_ONLY_INTEGRATION_NAMES was here
20216:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:39: warning: already initialized constant Integrations::Base::BaseIntegration::PROJECT_LEVEL_ONLY_INTEGRATION_NAMES
20316:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:39: warning: previous definition of PROJECT_LEVEL_ONLY_INTEGRATION_NAMES was here
20416:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:44: warning: already initialized constant Integrations::Base::BaseIntegration::PROJECT_AND_GROUP_LEVEL_ONLY_INTEGRATION_NAMES
20516:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:44: warning: previous definition of PROJECT_AND_GROUP_LEVEL_ONLY_INTEGRATION_NAMES was here
20616:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:49: warning: already initialized constant Integrations::Base::BaseIntegration::DEV_INTEGRATION_NAMES
20716:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:49: warning: previous definition of DEV_INTEGRATION_NAMES was here
20816:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:54: warning: already initialized constant Integrations::Base::BaseIntegration::BASE_CLASSES
20916:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:54: warning: previous definition of BASE_CLASSES was here
21016:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:64: warning: already initialized constant Integrations::Base::BaseIntegration::BASE_ATTRIBUTES
21116:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:64: warning: previous definition of BASE_ATTRIBUTES was here
21216:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:67: warning: already initialized constant Integrations::Base::BaseIntegration::SECTION_TYPE_CONFIGURATION
21316:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:67: warning: previous definition of SECTION_TYPE_CONFIGURATION was here
21416:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:68: warning: already initialized constant Integrations::Base::BaseIntegration::SECTION_TYPE_CONNECTION
21516:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:68: warning: previous definition of SECTION_TYPE_CONNECTION was here
21616:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:69: warning: already initialized constant Integrations::Base::BaseIntegration::SECTION_TYPE_TRIGGER
21716:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:69: warning: previous definition of SECTION_TYPE_TRIGGER was here
21816:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:71: warning: already initialized constant Integrations::Base::BaseIntegration::SNOWPLOW_EVENT_ACTION
21916:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:71: warning: previous definition of SNOWPLOW_EVENT_ACTION was here
22016:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:72: warning: already initialized constant Integrations::Base::BaseIntegration::SNOWPLOW_EVENT_LABEL
22116:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_integration.rb:72: warning: previous definition of SNOWPLOW_EVENT_LABEL was here
22216:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:16: warning: already initialized constant Integrations::Base::BaseJira::PROJECTS_PER_PAGE
22316:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:16: warning: previous definition of PROJECTS_PER_PAGE was here
22416:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:17: warning: already initialized constant Integrations::Base::BaseJira::JIRA_CLOUD_HOST
22516:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:17: warning: previous definition of JIRA_CLOUD_HOST was here
22616:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:19: warning: already initialized constant Integrations::Base::BaseJira::ATLASSIAN_REFERRER_GITLAB_COM
22716:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:19: warning: previous definition of ATLASSIAN_REFERRER_GITLAB_COM was here
22816:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:22: warning: already initialized constant Integrations::Base::BaseJira::ATLASSIAN_REFERRER_SELF_MANAGED
22916:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:22: warning: previous definition of ATLASSIAN_REFERRER_SELF_MANAGED was here
23016:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:26: warning: already initialized constant Integrations::Base::BaseJira::API_ENDPOINTS
23116:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:26: warning: previous definition of API_ENDPOINTS was here
23216:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:35: warning: already initialized constant Integrations::Base::BaseJira::SECTION_TYPE_JIRA_TRIGGER
23316:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:35: warning: previous definition of SECTION_TYPE_JIRA_TRIGGER was here
23416:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:36: warning: already initialized constant Integrations::Base::BaseJira::SECTION_TYPE_JIRA_ISSUES
23516:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:36: warning: previous definition of SECTION_TYPE_JIRA_ISSUES was here
23616:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:37: warning: already initialized constant Integrations::Base::BaseJira::SECTION_TYPE_JIRA_ISSUE_CREATION
23716:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:37: warning: previous definition of SECTION_TYPE_JIRA_ISSUE_CREATION was here
23816:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:39: warning: already initialized constant Integrations::Base::BaseJira::AUTH_TYPE_BASIC
23916:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:39: warning: previous definition of AUTH_TYPE_BASIC was here
24016:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:40: warning: already initialized constant Integrations::Base::BaseJira::AUTH_TYPE_PAT
24116:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:40: warning: previous definition of AUTH_TYPE_PAT was here
24216:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:42: warning: already initialized constant Integrations::Base::BaseJira::SNOWPLOW_EVENT_CATEGORY
24316:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:42: warning: previous definition of SNOWPLOW_EVENT_CATEGORY was here
24416:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:44: warning: already initialized constant Integrations::Base::BaseJira::RE2_SYNTAX_DOC_URL
24516:57:36/builds/gitlab-org/gitlab/app/models/integrations/base/base_jira.rb:44: warning: previous definition of RE2_SYNTAX_DOC_URL was here
24616:57:55warning: parser/current is loading parser/ruby32, which recognizes 3.2.4-compliant syntax, but you are running 3.2.5.
24716:57:55Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
24816:57:58Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
24916:57:58# [RSpecRunTime] Starting RSpec timer...
25016:57:58[TEST PROF INFO] EventProf enabled (sql.active_record)
25116:57:58unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
25216:57:58unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
25316:58:03Test environment set up in 1.227343221 seconds
25416:58:03# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb. Expected to take 6 minutes 44.15 seconds.
25516:58:03Gitlab::BackgroundMigration::BackfillRootStorageStatisticsForkStorageSizes
25616:59:43 #perform
25716:59:57 updates the public_forks_storage_size
25817:00:11 totals the size of public forks in the namespace
25917:00:25 updates the internal_forks_storage_size
26017:00:38 totals the size of internal forks in the namespace
26117:00:52 updates the private_forks_storage_size
26217:01:06 totals the size of private forks in the namespace
26317:01:20 counts only the size of forks
26417:01:33 sums forks for multiple namespaces
26517:01:47 counts the size of forks in subgroups
26617:02:00 counts the size of forks in more nested subgroups
26717:02:13 counts forks of forks
26817:02:26 counts multiple forks of the same project
26917:02:39 updates a namespace with no forks
27017:02:55 skips the update if the public_forks_storage_size has already been set
27117:03:13 skips the update if the internal_forks_storage_size has already been set
27217:03:27 skips the update if the private_forks_storage_size has already been set
27317:03:40 skips the update if the namespace is not found
27417:03:42I, [2024-10-18T17:03:42.970240 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
27517:04:03I, [2024-10-18T17:04:03.197207 #341] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
27617:04:04INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
27717:04:04INFO: analyzing "public.ci_pipeline_variables"
27817:04:04INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
27917:04:04I, [2024-10-18T17:04:04.820938 #341] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
28017:04:04I, [2024-10-18T17:04:04.822064 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
28117:04:04I, [2024-10-18T17:04:04.822845 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
28217:04:06INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
28317:04:06INFO: analyzing "public.ci_pipeline_variables"
28417:04:06INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
28517:04:11INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
28617:04:11INFO: analyzing "public.ci_job_artifacts"
28717:04:11INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
28817:04:11I, [2024-10-18T17:04:11.195544 #341] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
28917:04:11I, [2024-10-18T17:04:11.196650 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
29017:04:11I, [2024-10-18T17:04:11.197442 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
29117:04:14INFO: analyzing "public.p_ci_stages" inheritance tree
29217:04:14INFO: analyzing "public.ci_stages"
29317:04:14INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
29417:04:14I, [2024-10-18T17:04:14.634598 #341] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
29517:04:14I, [2024-10-18T17:04:14.635940 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
29617:04:14I, [2024-10-18T17:04:14.636816 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
29717:04:15I, [2024-10-18T17:04:15.855475 #341] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
29817:04:22I, [2024-10-18T17:04:22.376982 #341] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
29917:04:35I, [2024-10-18T17:04:35.847186 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
30017:04:35I, [2024-10-18T17:04:35.848499 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
30117:04:35I, [2024-10-18T17:04:35.849413 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
30217:04:47I, [2024-10-18T17:04:47.301542 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
30317:04:53I, [2024-10-18T17:04:53.938695 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
30417:05:01I, [2024-10-18T17:05:01.984097 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
30517:05:04I, [2024-10-18T17:05:04.727300 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
30617:05:08INFO: analyzing "public.p_ci_pipelines" inheritance tree
30717:05:08INFO: analyzing "public.ci_pipelines"
30817:05:08INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
30917:05:08I, [2024-10-18T17:05:08.594197 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
31017:05:08I, [2024-10-18T17:05:08.595644 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
31117:05:08I, [2024-10-18T17:05:08.596481 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
31217:05:14I, [2024-10-18T17:05:14.453752 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
31317:05:36# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb. It took 7 minutes 32.69 seconds. Expected to take 6 minutes 44.15 seconds.
31417:05:36# [RSpecRunTime] RSpec elapsed time: 7 minutes 37.86 seconds. Current RSS: ~1238M. Threads: 1. load average: 0.99 1.07 1.09 1/277 387
31517:05:36.
31617:05:36# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. Expected to take 1 minute 31.69 seconds.
31717:05:36Gitlab::BackgroundMigration::BackfillIssueSearchDataNamespaceId
31817:07:03WARNING: Active Record does not support composite primary key.
31917:07:03issue_search_data has composite primary key. Composite primary key is ignored.
32017:07:03WARNING: Active Record does not support composite primary key.
32117:07:03issue_search_data has composite primary key. Composite primary key is ignored.
32217:07:06 backfills namespace_id for the specified records
32317:07:09I, [2024-10-18T17:07:09.962006 #341] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
32417:07:11INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
32517:07:11INFO: analyzing "public.ci_pipeline_variables"
32617:07:11INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
32717:07:11I, [2024-10-18T17:07:11.771354 #341] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
32817:07:11I, [2024-10-18T17:07:11.801667 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
32917:07:11I, [2024-10-18T17:07:11.802723 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33017:07:13INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
33117:07:13INFO: analyzing "public.ci_pipeline_variables"
33217:07: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
33317:07:18INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
33417:07:18INFO: analyzing "public.ci_job_artifacts"
33517:07: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
33617:07:18I, [2024-10-18T17:07:18.583076 #341] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
33717:07:18I, [2024-10-18T17:07:18.584641 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
33817:07:18I, [2024-10-18T17:07:18.585706 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
33917:07:22INFO: analyzing "public.p_ci_stages" inheritance tree
34017:07:22INFO: analyzing "public.ci_stages"
34117:07:22INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
34217:07:22I, [2024-10-18T17:07:22.246773 #341] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
34317:07:22I, [2024-10-18T17:07:22.248078 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
34417:07:22I, [2024-10-18T17:07:22.248957 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
34517:07:23I, [2024-10-18T17:07:23.610065 #341] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
34617:07:30I, [2024-10-18T17:07:30.427212 #341] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
34717:07:45I, [2024-10-18T17:07:45.192934 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
34817:07:45I, [2024-10-18T17:07:45.194190 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
34917:07:45I, [2024-10-18T17:07:45.195038 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
35017:07:57I, [2024-10-18T17:07:57.754464 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
35117:08:04I, [2024-10-18T17:08:04.763277 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
35217:08:12I, [2024-10-18T17:08:12.610153 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
35317:08:15I, [2024-10-18T17:08:15.211009 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
35417:08:19INFO: analyzing "public.p_ci_pipelines" inheritance tree
35517:08:19INFO: analyzing "public.ci_pipelines"
35617:08:19INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
35717:08:19I, [2024-10-18T17:08:19.229571 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
35817:08:19I, [2024-10-18T17:08:19.231022 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
35917:08:19I, [2024-10-18T17:08:19.231882 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
36017:08:25I, [2024-10-18T17:08:25.143234 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
36117:08:45# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb. It took 3 minutes 9.28 seconds. Expected to take 1 minute 31.69 seconds.
36217:08:45# [RSpecRunTime] RSpec elapsed time: 10 minutes 47.37 seconds. Current RSS: ~1251M. Threads: 1. load average: 1.00 1.09 1.09 1/277 388
36317:08:45.
36417:08:45# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb. Expected to take 1 minute 20.39 seconds.
36517:08:45Gitlab::BackgroundMigration::BackfillHasIssuesForExternalIssueLinks
36617:09:57 sets has_issues of an existing record
36717:09:57 when there exists a record with has_issues
36817:10:05 does not modify existing records with has_issues
36917:10:05# [RSpecRunTime] RSpec elapsed time: 12 minutes 7.8 seconds. Current RSS: ~1271M. Threads: 1. load average: 1.25 1.16 1.11 1/277 389
37017:10:05.
37117:10:09I, [2024-10-18T17:10:09.094296 #341] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
37217:10:24I, [2024-10-18T17:10:24.150350 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
37317:10:24I, [2024-10-18T17:10:24.151591 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
37417:10:24I, [2024-10-18T17:10:24.152391 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
37517:10:35I, [2024-10-18T17:10:35.956719 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
37617:10:42I, [2024-10-18T17:10:42.736027 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
37717:10:50I, [2024-10-18T17:10:50.587575 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
37817:10:53I, [2024-10-18T17:10:53.251773 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
37917:10:56INFO: analyzing "public.p_ci_pipelines" inheritance tree
38017:10:56INFO: analyzing "public.ci_pipelines"
38117:10:56INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
38217:10:56I, [2024-10-18T17:10:56.991039 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
38317:10:56I, [2024-10-18T17:10:56.992877 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
38417:10:56I, [2024-10-18T17:10:56.993703 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
38517:11:02I, [2024-10-18T17:11:02.400545 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
38617:11:21# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb. It took 2 minutes 35.65 seconds. Expected to take 1 minute 20.39 seconds.
38717:11:21# [RSpecRunTime] RSpec elapsed time: 13 minutes 23.07 seconds. Current RSS: ~1237M. Threads: 1. load average: 1.10 1.13 1.10 1/277 390
38817:11:21.
38917:11:21# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_remote_development_agent_configs_project_id_spec.rb. Expected to take 1 minute 4.13 seconds.
39017:11:21Gitlab::BackgroundMigration::BackfillRemoteDevelopmentAgentConfigsProjectId
39117:12:16 constructs a valid query
39217:12:23 performs without error
39317:12:24I, [2024-10-18T17:12:24.647955 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
39417:12:24I, [2024-10-18T17:12:24.649547 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
39517:12:24I, [2024-10-18T17:12:24.650450 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
39617:12:37I, [2024-10-18T17:12:37.981927 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
39717:12:46I, [2024-10-18T17:12:46.142373 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
39817:12:54I, [2024-10-18T17:12:54.927838 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
39917:12:57I, [2024-10-18T17:12:57.892834 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
40017:13:02INFO: analyzing "public.p_ci_pipelines" inheritance tree
40117:13:02INFO: analyzing "public.ci_pipelines"
40217:13:02INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
40317:13:02I, [2024-10-18T17:13:02.109117 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
40417:13:02I, [2024-10-18T17:13:02.110319 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
40517:13:02I, [2024-10-18T17:13:02.111133 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
40617:13:08I, [2024-10-18T17:13:08.405482 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
40717:13:29# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_remote_development_agent_configs_project_id_spec.rb. It took 2 minutes 8.47 seconds. Expected to take 1 minute 4.13 seconds.
40817:13:29# [RSpecRunTime] RSpec elapsed time: 15 minutes 31.58 seconds. Current RSS: ~1241M. Threads: 1. load average: 1.09 1.11 1.09 1/277 391
40917:13:29.
41017:13:29# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_design_management_designs_namespace_id_spec.rb. Expected to take 1 minute 2.35 seconds.
41117:13:29Gitlab::BackgroundMigration::BackfillDesignManagementDesignsNamespaceId
41217:14:28 constructs a valid query
41317:14:35 performs without error
41417:14:37I, [2024-10-18T17:14:37.397922 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
41517:14:37I, [2024-10-18T17:14:37.399265 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
41617:14:37I, [2024-10-18T17:14:37.400263 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
41717:14:49I, [2024-10-18T17:14:49.911383 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
41817:14:57I, [2024-10-18T17:14:57.378073 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
41917:15:06I, [2024-10-18T17:15:05.999340 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
42017:15:08I, [2024-10-18T17:15:08.725501 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
42117:15:12INFO: analyzing "public.p_ci_pipelines" inheritance tree
42217:15:12INFO: analyzing "public.ci_pipelines"
42317:15:12INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
42417:15:12I, [2024-10-18T17:15:12.561537 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
42517:15:12I, [2024-10-18T17:15:12.562801 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
42617:15:12I, [2024-10-18T17:15:12.563667 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
42717:15:18I, [2024-10-18T17:15:18.567917 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
42817:15:38# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_design_management_designs_namespace_id_spec.rb. It took 2 minutes 8.96 seconds. Expected to take 1 minute 2.35 seconds.
42917:15:38# [RSpecRunTime] RSpec elapsed time: 17 minutes 40.59 seconds. Current RSS: ~1244M. Threads: 1. load average: 1.01 1.06 1.08 1/278 392
43017:15:38.
43117:15:38# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ml_experiment_metadata_project_id_spec.rb. Expected to take 1 minute 0.94 second.
43217:15:38Gitlab::BackgroundMigration::BackfillMlExperimentMetadataProjectId
43317:16:32 performs without error
43417:16:40 constructs a valid query
43517:16:52I, [2024-10-18T17:16:52.981852 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
43617:17:00I, [2024-10-18T17:17:00.456367 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
43717:17:09I, [2024-10-18T17:17:09.024191 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
43817:17:11I, [2024-10-18T17:17:11.805451 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
43917:17:15INFO: analyzing "public.p_ci_pipelines" inheritance tree
44017:17:15INFO: analyzing "public.ci_pipelines"
44117:17:15INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
44217:17:15I, [2024-10-18T17:17:15.774423 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
44317:17:15I, [2024-10-18T17:17:15.775670 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
44417:17:15I, [2024-10-18T17:17:15.776544 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
44517:17:21I, [2024-10-18T17:17:21.825936 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
44617:17:42# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ml_experiment_metadata_project_id_spec.rb. It took 2 minutes 3.55 seconds. Expected to take 1 minute 0.94 second.
44717:17:42# [RSpecRunTime] RSpec elapsed time: 19 minutes 44.18 seconds. Current RSS: ~1248M. Threads: 1. load average: 1.07 1.08 1.08 1/281 393
44817:17:42.
44917:17:42# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_user_achievements_namespace_id_spec.rb. Expected to take 59.47 seconds.
45017:17:42Gitlab::BackgroundMigration::BackfillUserAchievementsNamespaceId
45117:18:39 performs without error
45217:18:46 constructs a valid query
45317:18:59I, [2024-10-18T17:18:59.175170 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
45417:19:06I, [2024-10-18T17:19:06.327555 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
45517:19:14I, [2024-10-18T17:19:14.347930 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
45617:19:17I, [2024-10-18T17:19:17.007204 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
45717:19:21INFO: analyzing "public.p_ci_pipelines" inheritance tree
45817:19:21INFO: analyzing "public.ci_pipelines"
45917:19:21INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
46017:19:21I, [2024-10-18T17:19:21.105969 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
46117:19:21I, [2024-10-18T17:19:21.107350 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
46217:19:21I, [2024-10-18T17:19:21.108515 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
46317:19:26I, [2024-10-18T17:19:26.851399 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
46417:19:46# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_user_achievements_namespace_id_spec.rb. It took 2 minutes 3.56 seconds. Expected to take 59.47 seconds.
46517:19:46# [RSpecRunTime] RSpec elapsed time: 21 minutes 47.89 seconds. Current RSS: ~1248M. Threads: 1. load average: 0.99 1.03 1.07 1/281 394
46617:19:46.
46717:19:46# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_namespace_id_spec.rb. Expected to take 56.92 seconds.
46817:19:46Gitlab::BackgroundMigration::BackfillDesignManagementRepositoriesNamespaceId
46917:20:40 performs without error
47017:20:47 constructs a valid query
47117:20:49I, [2024-10-18T17:20:49.243084 #341] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
47217:20:49I, [2024-10-18T17:20:49.244333 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
47317:20:49I, [2024-10-18T17:20:49.245144 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
47417:21:01I, [2024-10-18T17:21:01.133557 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
47517:21:08I, [2024-10-18T17:21:08.881815 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
47617:21:16I, [2024-10-18T17:21:16.801578 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
47717:21:19I, [2024-10-18T17:21:19.642228 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
47817:21:23INFO: analyzing "public.p_ci_pipelines" inheritance tree
47917:21:23INFO: analyzing "public.ci_pipelines"
48017:21:23INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
48117:21:23I, [2024-10-18T17:21:23.703978 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
48217:21:23I, [2024-10-18T17:21:23.705169 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
48317:21:23I, [2024-10-18T17:21:23.706007 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
48417:21:29I, [2024-10-18T17:21:29.425709 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
48517:21:49# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_design_management_repositories_namespace_id_spec.rb. It took 2 minutes 3.1 seconds. Expected to take 56.92 seconds.
48617:21:49# [RSpecRunTime] RSpec elapsed time: 23 minutes 51.03 seconds. Current RSS: ~1243M. Threads: 1. load average: 0.99 1.03 1.06 1/281 395
48717:21:49.
48817:21:49# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_vulnerability_flags_project_id_spec.rb. Expected to take 49.08 seconds.
48917:21:49Gitlab::BackgroundMigration::BackfillVulnerabilityFlagsProjectId
49017:22:31 performs without error
49117:22:37 constructs a valid query
49217:22:38I, [2024-10-18T17:22:38.432866 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
49317:22:45I, [2024-10-18T17:22:45.568921 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
49417:22:53I, [2024-10-18T17:22:53.919003 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
49517:22:56I, [2024-10-18T17:22:56.619881 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
49617:23:00INFO: analyzing "public.p_ci_pipelines" inheritance tree
49717:23:00INFO: analyzing "public.ci_pipelines"
49817:23:00INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
49917:23:00I, [2024-10-18T17:23:00.760341 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
50017:23:00I, [2024-10-18T17:23:00.761626 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
50117:23:00I, [2024-10-18T17:23:00.762572 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
50217:23:06I, [2024-10-18T17:23:06.841092 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
50317:23:27# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_vulnerability_flags_project_id_spec.rb. It took 1 minute 37.84 seconds. Expected to take 49.08 seconds.
50417:23:27# [RSpecRunTime] RSpec elapsed time: 25 minutes 28.91 seconds. Current RSS: ~1244M. Threads: 1. load average: 1.00 1.02 1.05 1/278 396
50517:23:27.
50617:23:27# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_merge_requests_closing_issues_project_id_spec.rb. Expected to take 47.24 seconds.
50717:23:27Gitlab::BackgroundMigration::BackfillMergeRequestsClosingIssuesProjectId
50817:24:10 constructs a valid query
50917:24:15 performs without error
51017:24:16I, [2024-10-18T17:24:16.843344 #341] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
51117:24:24I, [2024-10-18T17:24:24.394278 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
51217:24:32I, [2024-10-18T17:24:32.666278 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
51317:24:35I, [2024-10-18T17:24:35.352552 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
51417:24:39INFO: analyzing "public.p_ci_pipelines" inheritance tree
51517:24:39INFO: analyzing "public.ci_pipelines"
51617:24:39INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
51717:24:39I, [2024-10-18T17:24:39.432049 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
51817:24:39I, [2024-10-18T17:24:39.433254 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
51917:24:39I, [2024-10-18T17:24:39.434049 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
52017:24:45I, [2024-10-18T17:24:45.278909 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
52117:25:05# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_merge_requests_closing_issues_project_id_spec.rb. It took 1 minute 38.43 seconds. Expected to take 47.24 seconds.
52217:25:05# [RSpecRunTime] RSpec elapsed time: 27 minutes 7.4 seconds. Current RSS: ~1246M. Threads: 1. load average: 0.89 0.98 1.03 1/278 397
52317:25:05.
52417:25:05# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_protected_branches_group_id_spec.rb. Expected to take 43.02 seconds.
52517:25:05Gitlab::BackgroundMigration::BackfillApprovalGroupRulesProtectedBranchesGroupId
52617:25:47 constructs a valid query
52717:25:52 performs without error
52817:25:59I, [2024-10-18T17:25:59.991651 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
52917:26:08I, [2024-10-18T17:26:08.347921 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
53017:26:11I, [2024-10-18T17:26:11.039157 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
53117:26:15INFO: analyzing "public.p_ci_pipelines" inheritance tree
53217:26:15INFO: analyzing "public.ci_pipelines"
53317:26:15INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
53417:26:15I, [2024-10-18T17:26:15.138632 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
53517:26:15I, [2024-10-18T17:26:15.139848 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
53617:26:15I, [2024-10-18T17:26:15.141098 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
53717:26:21I, [2024-10-18T17:26:21.260338 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
53817:26:41# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_approval_group_rules_protected_branches_group_id_spec.rb. It took 1 minute 35.79 seconds. Expected to take 43.02 seconds.
53917:26:41# [RSpecRunTime] RSpec elapsed time: 28 minutes 43.23 seconds. Current RSS: ~1251M. Threads: 1. load average: 0.90 0.96 1.01 1/278 398
54017:26:41.
54117:26:41# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_users_color_mode_id_spec.rb. Expected to take 41.25 seconds.
54217:26:41Gitlab::BackgroundMigration::BackfillUsersColorModeId
54317:27:23 backfills with the default values
54417:27:29I, [2024-10-18T17:27:29.319575 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
54517:27:38I, [2024-10-18T17:27:38.035182 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
54617:27:40I, [2024-10-18T17:27:40.919668 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
54717:27:45INFO: analyzing "public.p_ci_pipelines" inheritance tree
54817:27:45INFO: analyzing "public.ci_pipelines"
54917:27:45INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
55017:27:45I, [2024-10-18T17:27:45.198897 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
55117:27:45I, [2024-10-18T17:27:45.200200 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
55217:27:45I, [2024-10-18T17:27:45.201041 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
55317:27:51I, [2024-10-18T17:27:51.380831 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
55417:28:11# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_users_color_mode_id_spec.rb. It took 1 minute 30.52 seconds. Expected to take 41.25 seconds.
55517:28:11# [RSpecRunTime] RSpec elapsed time: 30 minutes 13.8 seconds. Current RSS: ~1252M. Threads: 1. load average: 1.42 1.10 1.05 1/278 399
55617:28:11.
55717:28:11# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_related_epic_links_to_issue_links_spec.rb. Expected to take 34.9 seconds.
55817:28:11Gitlab::BackgroundMigration::BackfillRelatedEpicLinksToIssueLinks
55917:28:52 backfills data correctly
56017:28:57I, [2024-10-18T17:28:57.085722 #341] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
56117:29:05I, [2024-10-18T17:29:05.821820 #341] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
56217:29:08I, [2024-10-18T17:29:08.557276 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
56317:29:12INFO: analyzing "public.p_ci_pipelines" inheritance tree
56417:29:12INFO: analyzing "public.ci_pipelines"
56517:29:12INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
56617:29:12I, [2024-10-18T17:29:12.849393 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
56717:29:12I, [2024-10-18T17:29:12.850906 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
56817:29:12I, [2024-10-18T17:29:12.851829 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
56917:29:19I, [2024-10-18T17:29:19.087361 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
57017:29:39# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_related_epic_links_to_issue_links_spec.rb. It took 1 minute 27.89 seconds. Expected to take 34.9 seconds.
57117:29:39# [RSpecRunTime] RSpec elapsed time: 31 minutes 41.74 seconds. Current RSS: ~1242M. Threads: 1. load average: 1.22 1.10 1.05 1/278 400
57217:29:39.
57317:29:39# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb. Expected to take 33.35 seconds.
57417:29:39Gitlab::BackgroundMigration::BackfillCiResourcesProjectId
57517:30:07 performs without error
57617:30:11 constructs a valid query
57717:30:43# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb. It took 1 minute 3.54 seconds. Expected to take 33.35 seconds.
57817:30:43# [RSpecRunTime] RSpec elapsed time: 32 minutes 45.32 seconds. Current RSS: ~1233M. Threads: 1. load average: 0.96 1.06 1.04 1/278 401
57917:30:43.
58017:30:43# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/delete_packages_composer_cache_file_records_spec.rb. Expected to take 24.13 seconds.
58117:30:43Gitlab::BackgroundMigration::DeletePackagesComposerCacheFileRecords
58217:31:07 deletes the linked files
58317:31:11 deletes packages composer cache files
58417:31:13INFO: analyzing "public.p_ci_pipelines" inheritance tree
58517:31:13INFO: analyzing "public.ci_pipelines"
58617:31:13INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
58717:31:13I, [2024-10-18T17:31:13.935583 #341] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
58817:31:13I, [2024-10-18T17:31:13.936907 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
58917:31:13I, [2024-10-18T17:31:13.937844 #341] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
59017:31:19I, [2024-10-18T17:31:19.898201 #341] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
59117:31:41# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/delete_packages_composer_cache_file_records_spec.rb. It took 57.65 seconds. Expected to take 24.13 seconds.
59217:31:41# [RSpecRunTime] RSpec elapsed time: 33 minutes 43.02 seconds. Current RSS: ~1249M. Threads: 1. load average: 1.13 1.09 1.05 1/278 402
59317:31:41.
59417:31:41# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_partition_job_spec.rb. Expected to take 22.53 seconds.
59517:31:41Gitlab::BackgroundMigration::BackfillDesiredShardingKeyPartitionJob
59617:31:41 #constuct_query
59717:31:41 batch_column: :id
59817:31:45 constructs a query using the supplied job arguments
59917:31:46# [RSpecRunTime] RSpec elapsed time: 33 minutes 47.8 seconds. Current RSS: ~1256M. Threads: 1. load average: 1.12 1.09 1.05 1/278 403
60017:31:46.
60117:31:46 batch_column: :build_id
60217:31:50 constructs a query using the supplied job arguments
60317:31:50# [RSpecRunTime] RSpec elapsed time: 33 minutes 51.97 seconds. Current RSS: ~1249M. Threads: 1. load average: 1.11 1.09 1.05 1/278 404
60417:31:50.
60517:31:50 #perform
60617:31:50 when batch_column is id
60717:31:50 behaves like a migration backfilling the missing project_id for the batch
60817:31:54 backfills the missing project_id for the batch
60917:31:54# [RSpecRunTime] RSpec elapsed time: 33 minutes 56.63 seconds. Current RSS: ~1244M. Threads: 1. load average: 1.10 1.09 1.05 1/278 405
61017:31:54.
61117:31:54 when batch_column is build_id
61217:31:54 behaves like a migration backfilling the missing project_id for the batch
61317:31:59 backfills the missing project_id for the batch
61417:31:59# [RSpecRunTime] RSpec elapsed time: 34 minutes 0.87 second. Current RSS: ~1245M. Threads: 1. load average: 1.09 1.08 1.05 1/278 406
61517:31:59.
61617:31:59 when batch_column is invalid
61717:32:03 does not backfill the missing project_id for the batch
61817:32:03# [RSpecRunTime] RSpec elapsed time: 34 minutes 5.11 seconds. Current RSS: ~1243M. Threads: 1. load average: 1.00 1.07 1.05 1/278 407
61917:32:03.
62017:32:11# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_desired_sharding_key_partition_job_spec.rb. It took 30.56 seconds. Expected to take 22.53 seconds.
62117:32:11# [RSpecRunTime] RSpec elapsed time: 34 minutes 13.65 seconds. Current RSS: ~1239M. Threads: 1. load average: 1.00 1.07 1.05 1/278 408
62217:32:11.
62317:32:11# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb. Expected to take 16.27 seconds.
62417:32:11Gitlab::BackgroundMigration::BackfillIncidentManagementOncallRotationsProjectId
62517:32:24 constructs a valid query
62617:32:28 performs without error
62717:32:48# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb. It took 36.77 seconds. Expected to take 16.27 seconds.
62817:32:48# [RSpecRunTime] RSpec elapsed time: 34 minutes 50.47 seconds. Current RSS: ~1250M. Threads: 1. load average: 1.00 1.06 1.04 1/278 409
62917:32:48.
63017:32:48# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_dast_scanner_profiles_builds_project_id_spec.rb. Expected to take 14.74 seconds.
63117:32:48Gitlab::BackgroundMigration::BackfillDastScannerProfilesBuildsProjectId
63217:33:00 constructs a valid query
63317:33:04 performs without error
63417:33:23# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_dast_scanner_profiles_builds_project_id_spec.rb. It took 34.71 seconds. Expected to take 14.74 seconds.
63517:33:23# [RSpecRunTime] RSpec elapsed time: 35 minutes 25.23 seconds. Current RSS: ~1254M. Threads: 1. load average: 1.06 1.06 1.04 1/278 410
63617:33:23.
63717:33:23# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/fix_pick_up_at_ci_deleted_object_spec.rb. Expected to take 10.45 seconds.
63817:33:23Gitlab::BackgroundMigration::FixPickUpAtCiDeletedObject
63917:33:25 #perform
64017:33:25 when there are invalid records
64117:33:35 resets pick_up_at values
64217:33:35# [RSpecRunTime] RSpec elapsed time: 35 minutes 37.05 seconds. Current RSS: ~1272M. Threads: 1. load average: 1.19 1.09 1.05 1/278 411
64317:33:35.
64417:33:50# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/fix_pick_up_at_ci_deleted_object_spec.rb. It took 27.11 seconds. Expected to take 10.45 seconds.
64517:33:50# [RSpecRunTime] RSpec elapsed time: 35 minutes 52.38 seconds. Current RSS: ~1254M. Threads: 1. load average: 1.14 1.09 1.05 1/278 412
64617:33:50.
64717:33:50# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_members_request_accepted_at_spec.rb. Expected to take 8.74 seconds.
64817:33:50Gitlab::BackgroundMigration::BackfillMembersRequestAcceptedAt
64917:33:55 #perform
65017:33:55 when `requested_at`, `invite_token`, `invite_accepted_at` and `request_accepted_at` are set to nil
65117:33:59 backfills `request_accepted_at` column to `created_at` for eligible members
65217:33:59# [RSpecRunTime] RSpec elapsed time: 36 minutes 1.31 seconds. Current RSS: ~1264M. Threads: 1. load average: 1.12 1.08 1.05 1/278 413
65317:33:59.
65417:34:14# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_members_request_accepted_at_spec.rb. It took 23.75 seconds. Expected to take 8.74 seconds.
65517:34:14# [RSpecRunTime] RSpec elapsed time: 36 minutes 16.18 seconds. Current RSS: ~1260M. Threads: 1. load average: 1.01 1.06 1.05 1/278 414
65617:34:14.
65717:34:14# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/resync_epic_dates_to_work_items_dates_sources_spec.rb. Expected to take 5.44 seconds.
65817:34:14Gitlab::BackgroundMigration::ResyncEpicDatesToWorkItemsDatesSources
65917:34:14 when backfilling all epics
66017:34:19 backfills data correctly
66117:34:19# [RSpecRunTime] RSpec elapsed time: 36 minutes 21.62 seconds. Current RSS: ~1271M. Threads: 1. load average: 1.01 1.06 1.04 1/277 415
66217:34:19.
66317:34:28# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/resync_epic_dates_to_work_items_dates_sources_spec.rb. It took 14.54 seconds. Expected to take 5.44 seconds.
66417:34:28# [RSpecRunTime] RSpec elapsed time: 36 minutes 30.78 seconds. Current RSS: ~1255M. Threads: 1. load average: 1.01 1.06 1.04 1/277 416
66517:34:28.
66617:34:28# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_packages_dependencies_project_id_spec.rb. Expected to take 4.82 seconds.
66717:34:28Gitlab::BackgroundMigration::BackfillPackagesDependenciesProjectId
66817:34:34 backfills the missing `project_id` for packages dependencies
66917:34:42# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/backfill_packages_dependencies_project_id_spec.rb. It took 13.5 seconds. Expected to take 4.82 seconds.
67017:34:42# [RSpecRunTime] RSpec elapsed time: 36 minutes 44.33 seconds. Current RSS: ~1244M. Threads: 1. load average: 1.00 1.06 1.04 1/278 417
67117:34:42.
67217:34:42# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb. Expected to take 4.52 seconds.
67317:34:42Gitlab::BackgroundMigration::PopulateOperationVisibilityPermissionsFromOperations
67417:34:47 updates all project settings records from their operations_access_level
67517:34:55# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb. It took 13.13 seconds. Expected to take 4.52 seconds.
67617:34:55# [RSpecRunTime] RSpec elapsed time: 36 minutes 57.51 seconds. Current RSS: ~1234M. Threads: 1. load average: 1.00 1.05 1.04 1/278 418
67717:34:55.
67817:34:55# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/restore_opt_in_to_gitlab_com_spec.rb. Missing expected duration from Knapsack report for spec/lib/gitlab/background_migration/restore_opt_in_to_gitlab_com_spec.rb.
67917:34:55Gitlab::BackgroundMigration::RestoreOptInToGitlabCom
68017:34:56 #perform
68117:35:00 updates user_details from the temporary table
68217:35:00# [RSpecRunTime] RSpec elapsed time: 37 minutes 2.47 seconds. Current RSS: ~1254M. Threads: 1. load average: 1.00 1.05 1.04 1/278 419
68317:35:00.
68417:35:09# [RSpecRunTime] Finishing example group spec/lib/gitlab/background_migration/restore_opt_in_to_gitlab_com_spec.rb. It took 13.42 seconds. Missing expected duration from Knapsack report for spec/lib/gitlab/background_migration/restore_opt_in_to_gitlab_com_spec.rb.
68517:35:09# [RSpecRunTime] RSpec elapsed time: 37 minutes 10.97 seconds. Current RSS: ~1240M. Threads: 1. load average: 1.00 1.05 1.04 1/278 420
68617:35:09.
68717:35:53auto_explain log contains 1176 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-1-10.341.main.ndjson.gz
68817:35:53took 44.015346507
68917:36:34auto_explain log contains 1177 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-1-10.341.ci.ndjson.gz
69017:36:34took 40.477352318
69117:36:34[TEST PROF INFO] EventProf results for sql.active_record
69217:36:34Total time: 22:21.255 of 37:05.831 (60.26%)
69317:36:34Total events: 953004
69417:36:34Top 5 slowest suites (by time):
69517:36:34Gitlab::Backg...rkStorageSizes (./spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb:5) – 03:10.246 (145547 / 17) of 07:32.910 (42.01%)
69617:36:34Gitlab::Backg...ataNamespaceId (./spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb:5) – 02:11.179 (92177 / 1) of 03:09.329 (69.29%)
69717:36:34Gitlab::Backg...rnalIssueLinks (./spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb:5) – 01:43.524 (75175 / 2) of 02:35.693 (66.49%)
69817:36:34Gitlab::Backg...gnsNamespaceId (./spec/lib/gitlab/background_migration/backfill_design_management_designs_namespace_id_spec.rb:5) – 01:24.380 (54020 / 2) of 02:09.004 (65.41%)
69917:36:34Gitlab::Backg...nfigsProjectId (./spec/lib/gitlab/background_migration/backfill_remote_development_agent_configs_project_id_spec.rb:5) – 01:23.534 (53213 / 2) of 02:08.520 (65.0%)
70017:36:34Knapsack report was generated. Preview:
70117:36:34{
70217:36:34 "spec/lib/gitlab/background_migration/backfill_root_storage_statistics_fork_storage_sizes_spec.rb": 337.82116413100084,
70317:36:34 "spec/lib/gitlab/background_migration/backfill_issue_search_data_namespace_id_spec.rb": 90.70092047000071,
70417:36:34 "spec/lib/gitlab/background_migration/backfill_has_issues_for_external_issue_links_spec.rb": 80.4449773669985,
70517:36:34 "spec/lib/gitlab/background_migration/backfill_remote_development_agent_configs_project_id_spec.rb": 62.645280221000576,
70617:36:34 "spec/lib/gitlab/background_migration/backfill_design_management_designs_namespace_id_spec.rb": 66.21532475999993,
70717:36:34 "spec/lib/gitlab/background_migration/backfill_ml_experiment_metadata_project_id_spec.rb": 61.29286058499929,
70817:36:34 "spec/lib/gitlab/background_migration/backfill_user_achievements_namespace_id_spec.rb": 64.06220360299994,
70917:36:34 "spec/lib/gitlab/background_migration/backfill_design_management_repositories_namespace_id_spec.rb": 61.77024658599839,
71017:36:34 "spec/lib/gitlab/background_migration/backfill_vulnerability_flags_project_id_spec.rb": 47.89721064499827,
71117:36:34 "spec/lib/gitlab/background_migration/backfill_merge_requests_closing_issues_project_id_spec.rb": 48.78304509000009,
71217:36:34 "spec/lib/gitlab/background_migration/backfill_approval_group_rules_protected_branches_group_id_spec.rb": 47.0114799289986,
71317:36:34 "spec/lib/gitlab/background_migration/backfill_users_color_mode_id_spec.rb": 42.01040451700101,
71417:36:34 "spec/lib/gitlab/background_migration/backfill_related_epic_links_to_issue_links_spec.rb": 40.57325783399938,
71517:36:34 "spec/lib/gitlab/background_migration/backfill_ci_resources_project_id_spec.rb": 31.541687091001222,
71617:36:34 "spec/lib/gitlab/background_migration/delete_packages_composer_cache_file_records_spec.rb": 28.362241506998544,
71717:36:34 "spec/lib/gitlab/background_migration/backfill_desired_sharding_key_partition_job_spec.rb": 22.09424277600192,
71817:36:34 "spec/lib/gitlab/background_migration/backfill_incident_management_oncall_rotations_project_id_spec.rb": 16.59978404299909,
71917:36:34 "spec/lib/gitlab/background_migration/backfill_dast_scanner_profiles_builds_project_id_spec.rb": 15.753585066999221,
72017:36:34 "spec/lib/gitlab/background_migration/fix_pick_up_at_ci_deleted_object_spec.rb": 11.861331129999598,
72117:36:34 "spec/lib/gitlab/background_migration/backfill_members_request_accepted_at_spec.rb": 8.941622715999983,
72217:36:34 "spec/lib/gitlab/background_migration/resync_epic_dates_to_work_items_dates_sources_spec.rb": 5.450286523999239,
72317:36:34 "spec/lib/gitlab/background_migration/backfill_packages_dependencies_project_id_spec.rb": 5.231723822002095,
72417:36:34 "spec/lib/gitlab/background_migration/populate_operation_visibility_permissions_from_operations_spec.rb": 4.8537953779996315,
72517:36:34 "spec/lib/gitlab/background_migration/restore_opt_in_to_gitlab_com_spec.rb": 4.980054283001664
72617:36:34}
72717:36:34Knapsack global time execution for tests: 20m 06s
72817:36:34Finished in 38 minutes 36 seconds (files took 53.44 seconds to load)
72917:36:3457 examples, 0 failures
73017:36:34Randomized with seed 7389
73117:36:42[TEST PROF INFO] Time spent in factories: 00:00.487 (0.02% of total time)
73217:36:43RSpec exited with 0.
73317:36:43No examples to retry, congrats!
734 17:36:43 Running after_script 00:16
73517:36:44Running after script...
73617:36:44$ source scripts/utils.sh
73717:36:44$ log_disk_usage
73817:36:44*******************************************************
73917:36:44This runner currently has 73G free disk space.
74017:36:44*******************************************************
741 17:36:44 Disk usage detail 00:07
79717:36:51$ bundle exec gem list gitlab_quality-test_tooling
79817:36:54gitlab_quality-test_tooling (2.0.0)
79917:36:54$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
800 17:36:54 Report test failures 00:00
80217:36:54$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
803 17:36:54 Report test flakiness 00:00
80517:36:54$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
806 17:36:54 Report test slowness 00:00
80817:36:54$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
809 17:36:54 Report test slowness in MR note 00:01
81217:36:55$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
813 17:36:55 Report test files close to timing out 00:02
81717:36:57$ tooling/bin/push_job_metrics || true
81817:36:59[job-metrics] Pushing job metrics file for the CI/CD job.
81917:36:59[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
820 17:36:59 Saving cache for successful job 00:01
82117:37:00Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-19 due to policy
822 17:37:00 Uploading artifacts for successful job 00:06
82317:37:01Uploading artifacts...
82417:37:01auto_explain/: found 3 matching artifact files and directories
82517:37:01coverage/: found 5 matching artifact files and directories
82617:37:01crystalball/: found 2 matching artifact files and directories
82717:37:01WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
82817:37:01knapsack/: found 4 matching artifact files and directories
82917:37:01rspec/: found 16 matching artifact files and directories
83017:37:01WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
83117:37:01log/*.log: found 13 matching artifact files and directories
83217:37:02WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8126558223/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
83317:37:02WARNING: Retrying... context=artifacts-uploader error=request redirected
83417:37:04Uploading artifacts as "archive" to coordinator... 201 Created id=8126558223 responseStatus=201 Created token=glcbt-66
83517:37:04Uploading artifacts...
83617:37:04rspec/rspec-*.xml: found 1 matching artifact files and directories
83717:37:04WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8126558223/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
83817:37:04WARNING: Retrying... context=artifacts-uploader error=request redirected
83917:37:06Uploading artifacts as "junit" to coordinator... 201 Created id=8126558223 responseStatus=201 Created token=glcbt-66
840 17:37:06 Cleaning up project directory and file based variables 00:01
84117:37:15Job succeeded