Skip to content
Snippets Groups Projects

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

Passed Started by
Simon Tomlinson
@stomlinson
Log timestamps in UTC.
122:08:53Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
222:08:53 on blue-2.private.runners-manager.gitlab.com/gitlab.com/gitlab-org QvBVRoXM, system ID: s_49b872f8ccf6
322:08:53 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
422:08:53Resolving secrets
5 22:08:53 Preparing the "docker+machine" executor 01:48
622:08:53Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
722:08:55Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
822:08:55Authenticating with credentials from job payload (GitLab Registry)
922:08:55Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1022:08:56Using docker image sha256:82f132c22567f8ce17cc132c14b2f9aa3eaf9bb5424d91c2d966912433f0257d for registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:c55e1364ee4327b244a9cfa1750f19feea14fc774eaf792b725967d146eb45f5 ...
1122:08:56WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1222:08:56WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1322:08:56Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1422:08:56Authenticating with credentials from job payload (GitLab Registry)
1522:08:56Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1622:08:56Using docker image sha256:5c5ba5b83d6c60cb0b225bd670b7a43be8c238cc72347d24af57e5027c3648f3 for registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:46aceab84c42d0e819c8e7940f2f98ce9e184785cd7b22d95872024a35f52407 ...
1722:08:57Starting service redis:6.2-alpine...
1822:08:57Pulling docker image redis:6.2-alpine ...
1922:08:57Using docker image sha256:4100b5bd17430263e85ad9d8ab851959b234acaaf378e093f1f98400f4998815 for redis:6.2-alpine with digest redis@sha256:eaba718fecd1196d88533de7ba49bf903ad33664a92debb24660a922ecd9cac8 ...
2022:08:58WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.
2122:08:58WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 is already created. Ignoring.
2222:08:58Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8...
2322:08:58Authenticating with credentials from job payload (GitLab Registry)
2422:08:58Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 ...
2522:09:00Using docker image sha256:df819140e3df737cdc7b8d6fb73ce804b05058c790e025b5f52840956feb1734 for registry.gitlab.com/gitlab-org/gitlab-build-images:zoekt-ci-image-1.8 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:7bdf349fc3dd9da64bc6581d44c0e906bffd38977ddbd2668ba34adb5dedfe38 ...
2622:09:01Starting service elasticsearch:7.17.6...
2722:09:01Pulling docker image elasticsearch:7.17.6 ...
2822:09:14Using docker image sha256:5fad10241ffd65d817ed0ddfaf6e87eee1f7dc2a7db33db1047835560ea71fda for elasticsearch:7.17.6 with digest elasticsearch@sha256:6c128de5d01c0c130a806022d6bd99b3e4c27a9af5bfc33b6b81861ae117d028 ...
2922:09:15Starting service registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.18.0...
3022:09:15Authenticating with credentials from job payload (GitLab Registry)
3122:09:15Pulling docker image registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.18.0 ...
3222:09:48Using docker image sha256:eb97d149d5b7fa6f8d1c3551036054839115ce4ae8b1896d5b4cc1563b098719 for registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway:v1.18.0 with digest registry.gitlab.com/gitlab-org/modelops/applied-ml/code-suggestions/ai-assist/model-gateway@sha256:d8fb36abcbce56db6ebaaff6504a26ff7345d5f463f273b9f993e0cf65c85818 ...
3322:09:52Starting service ghcr.io/berriai/litellm:main-latest...
3422:09:52Pulling docker image ghcr.io/berriai/litellm:main-latest ...
3522:10:33Using docker image sha256:006af10d9c70ad67274d5937788e42ce2cddb97f5496178c013ed1eac59ab6ae for ghcr.io/berriai/litellm:main-latest with digest ghcr.io/berriai/litellm@sha256:e7a60e9428c4946ae4b6036206bcf98b2cdb8b74e54f75793b51592d1fc005cd ...
3622:10:34Waiting for services to be up and running (timeout 30 seconds)...
3722:10:41Authenticating with credentials from job payload (GitLab Registry)
3822:10:41Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
3922:10:41Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
40 22:10:41 Preparing environment 00:01
4122:10:41Running on runner-qvbvroxm-project-278964-concurrent-0 via runner-qvbvroxm-private-1731529461-4ceb865a...
42 22:10:42 Getting source from Git repository 00:00
4322:10:42Skipping Git repository setup
4422:10:42Skipping Git checkout
4522:10:42Skipping Git submodules setup
46 22:10:42 Restoring cache 00:19
4722:10:43Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20...
4822:10:43cache.zip is up to date
4922:11:00Successfully extracted cache
50 22:11:01 Downloading artifacts 00:47
5122:11:02Downloading artifacts for clone-gitlab-repo (8353286583)...
5222:11:07Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286583 responseStatus=200 OK token=glcbt-66
5322:11:07WARNING: Part of .git directory is on the list of files to extract
5422:11:07WARNING: This may introduce unexpected problems
5522:11:21Downloading artifacts for compile-test-assets (8353286630)...
5622:11:24Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286630 responseStatus=200 OK token=glcbt-66
5722:11:31Downloading artifacts for detect-tests (8353286649)...
5822:11:32Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286649 responseStatus=200 OK token=glcbt-66
5922:11:32Downloading artifacts for retrieve-tests-metadata (8353286664)...
6022:11:32Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286664 responseStatus=200 OK token=glcbt-66
6122:11:32Downloading artifacts for setup-test-env (8353286635)...
6222:11:37Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8353286635 responseStatus=200 OK token=glcbt-66
63 22:11:48 Executing "step_script" stage of the job script
6422:11:48Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
6522:11:49$ echo $FOSS_ONLY
6622:11:49$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
6722:11:49$ export GOPATH=$CI_PROJECT_DIR/.go
6822:11:49$ mkdir -p $GOPATH
6922:11:49$ source scripts/utils.sh
7022:11:49$ log_disk_usage "true"
7122:11:49*******************************************************
7222:11:49This runner currently has 74G free disk space.
7322:11:49*******************************************************
74 22:11:49 Disk usage detail 00:11
7522:11:49df -h
7622:11:49Filesystem Size Used Avail Use% Mounted on
7722:11:49overlay 95G 21G 74G 22% /
7822:11:49tmpfs 64M 0 64M 0% /dev
7922:11:49shm 64M 0 64M 0% /dev/shm
8022:11:49/dev/sda1 95G 21G 74G 22% /cache
8122:11:49tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
8222:11:49du -h -d 1
8322:11:507.4M ./workhorse
8422:11:50148K ./bin
8522:11:501.2M ./.gitlab
8622:11:50167M ./.git
8722:11:504.0K ./builds
8822:11:5028M ./lib
8922:11:508.0K ./.vscode
9022:11:50560K ./storybook
9122:11:5024K ./log
9222:11:501.8M ./data
9322:11:5011M ./qa
9422:11:503.2M ./.rubocop_todo
9522:11:53856M ./vendor
9622:11:531023M ./public
9722:11:5362M ./doc
9822:11:53484K ./danger
9922:11:5332K ./rspec
10022:11:53556K ./tooling
10122:11:53145M ./ee
10222:11:531.3M ./knapsack
10322:11:53300K ./patches
10422:11:534.3M ./changelogs
10522:11:5320K ./haml_lint
10622:11:5328K ./metrics_server
10722:11:53108K ./keeps
10822:11:5336K ./shared
10922:11:5344K ./generator_templates
11022:11:531.3M ./scripts
11122:11:53763M ./tmp
11222:11:53127M ./spec
11322:11:5320K ./file_hooks
11422:11:5332K ./crystalball
11522:11:5316K ./sidekiq_cluster
11622:11:5317M ./gems
11722:11:531.2M ./fixtures
11822:11:53964K ./rubocop
11922:11:534.0K ./.go
12022:11:5333M ./db
12122:11:5312K ./.github
12222:11:53129M ./locale
12322:11:5320M ./config
12422:11:5482M ./app
12522:11:5420K ./.lefthook
12622:11:543.5G .
12722:11:54$ source scripts/prepare_build.sh
128 22:11:54 Installing gems 00:24
15922:12:18Using two connections, single database config (config/database.yml.postgresql)
16022:12:18Geo DB will be set up.
16122:12:18Embedding DB will be set up.
162 22:12:18 Setting up DBs 01:37
18322:13:55$ source ./scripts/rspec_helpers.sh
18422:13:55$ run_timed_command "gem install knapsack --no-document"
18522:13:54$ gem install knapsack --no-document
18622:13:57Successfully installed knapsack-4.0.0
18722:13:571 gem installed
18822:13:55==> 'gem install knapsack --no-document' succeeded in 2 seconds.
18922:13:57$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
190 22:13:57 Spawning Gitaly 00:06
19422:14:03$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
19522:14:03$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
19622:14:03$ tooling/bin/create_job_metrics_file || true
19722:14:07[job-metrics] Creating the job metrics file for the CI/CD job.
19822:14:07$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
199 22:14:07 RSpec 06:30
20022:14:07[22:14:07] Starting rspec_parallelized_job
20122:13:57RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
20222:14:07KNAPSACK_GENERATE_REPORT: true
20322:14:07FLAKY_RSPEC_GENERATE_REPORT: true
20422:14:07KNAPSACK_TEST_FILE_PATTERN: {ee/}spec/{migrations}{,/**/}*_spec.rb
20522:14:07KNAPSACK_LOG_LEVEL: debug
20622:14:07KNAPSACK_REPORT_PATH: knapsack/rspec-ee_migration_pg14_single-db-ci-connection_1_2_278964_report.json
20722:14:07FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
20822:14:07FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec-ee_migration_pg14_single-db-ci-connection_1_2_278964_report.json
20922:14:07NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec-ee_migration_pg14_single-db-ci-connection_1_2_278964_report.json
21022:14:07RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8353288385.txt
21122:14:07CRYSTALBALL:
21222:14:07RSPEC_TESTS_MAPPING_ENABLED:
21322:14:07RSPEC_TESTS_FILTER_FILE:
21422:14:07Shell set options (set -o) enabled:
21522:14:07braceexpand on
21622:14:07hashall on
21722:14:07interactive-comments on
21822:14:07pipefail on
21922:14:15Knapsack report generator started!
22022:14:07/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!
22122:15:28DEPRECATION WARNING: Support for Rails versions < 7.1 is deprecated and will be removed from ViewComponent 4.0.0 (ViewComponent v4 will remove support for Rails versions < 7.1 no earlier than April 1, 2025) (called from <top (required)> at /builds/gitlab-org/gitlab/config/environment.rb:7)
22222:15:41warning: parser/current is loading parser/ruby32, which recognizes 3.2.6-compliant syntax, but you are running 3.2.5.
22322:15:41Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
22422:15:56/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!
22522:16:12DEPRECATION WARNING: Support for Rails versions < 7.1 is deprecated and will be removed from ViewComponent 4.0.0 (ViewComponent v4 will remove support for Rails versions < 7.1 no earlier than April 1, 2025) (called from <main> at /builds/gitlab-org/gitlab/config/environment.rb:7)
22622:16:34Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
22722:16:34# [RSpecRunTime] Starting RSpec timer...
22822:16:34[TEST PROF INFO] EventProf enabled (sql.active_record)
22922:16:34unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
23022:16:44Test environment set up in 3.793329826 seconds
23122:16:45# [RSpecRunTime] Starting example group ee/spec/migrations/geo/migrate_ci_job_artifacts_to_separate_registry_spec.rb. Expected to take 28.48 seconds.
23222:16:45MigrateCiJobArtifactsToSeparateRegistry
23322:16:47 #up
23422:16:47geo: == [advisory_lock_connection] object_id: 881920, pg_backend_pid: 193
23522:16:47== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrating ==========
23622:16:47== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrated (0.0412s) =
23722:16:47geo: == [advisory_lock_connection] object_id: 881920, pg_backend_pid: 193
23822:16:52 migrates all job artifacts to its own data table
23922:16:52geo: == [advisory_lock_connection] object_id: 1636580, pg_backend_pid: 200
24022:16:52== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrating ==========
24122:16:52== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrated (0.0382s) =
24222:16:52geo: == [advisory_lock_connection] object_id: 1636580, pg_backend_pid: 200
24322:16:57 creates a new artifact with the trigger
24422:16:57geo: == [advisory_lock_connection] object_id: 2328580, pg_backend_pid: 206
24522:16:58== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrating ==========
24622:16:58== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrated (0.0573s) =
24722:16:58geo: == [advisory_lock_connection] object_id: 2328580, pg_backend_pid: 206
24822:17:03 updates a new artifact with the trigger
24922:17:03geo: == [advisory_lock_connection] object_id: 3038740, pg_backend_pid: 212
25022:17:03== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrating ==========
25122:17:03== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrated (0.0427s) =
25222:17:03geo: == [advisory_lock_connection] object_id: 3038740, pg_backend_pid: 212
25322:17:08 creates a new artifact using the next ID
25422:17:08 #down
25522:17:08geo: == [advisory_lock_connection] object_id: 3731160, pg_backend_pid: 219
25622:17:08== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrating ==========
25722:17:08== 20180322062741 MigrateCiJobArtifactsToSeparateRegistry: migrated (0.0353s) =
25822:17:08geo: == [advisory_lock_connection] object_id: 3731160, pg_backend_pid: 219
25922:17:13 rolls back data properly
26022:17:14# [RSpecRunTime] RSpec elapsed time: 39.01 seconds. Current RSS: ~1147M. Threads: 1. load average: 1.24 1.34 1.23 1/406 409
26122:17:14.
26222:17:27# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/migrate_ci_job_artifacts_to_separate_registry_spec.rb. It took 42.49 seconds. Expected to take 28.48 seconds.
26322:17:27# [RSpecRunTime] RSpec elapsed time: 52.93 seconds. Current RSS: ~1148M. Threads: 1. load average: 1.12 1.31 1.22 1/406 410
26422:17:27.
26522:17:27# [RSpecRunTime] Starting example group ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb. Expected to take 5.64 seconds.
26622:17:27FixStateColumnInLfsObjectRegistry
26722:17:28geo: == [advisory_lock_connection] object_id: 4702100, pg_backend_pid: 260
26822:17:28== 20210624160455 FixStateColumnInLfsObjectRegistry: migrating ================
26922:17:28-- exec_query("SELECT COUNT(*) AS count FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"success\" = TRUE")
27022:17:28 -> 0.0029s
27122:17:28-- exec_query("SELECT \"lfs_object_registry\".\"id\" FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"success\" = TRUE ORDER BY \"lfs_object_registry\".\"id\" ASC LIMIT 1")
27222:17:28 -> 0.0026s
27322:17:28-- exec_query("SELECT \"lfs_object_registry\".\"id\" FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"id\" >= 2 AND \"lfs_object_registry\".\"success\" = TRUE ORDER BY \"lfs_object_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
27422:17:28 -> 0.0021s
27522:17:28-- transaction(nil)
27622:17:28-- execute("UPDATE \"lfs_object_registry\" SET \"state\" = 2 WHERE \"lfs_object_registry\".\"id\" >= 2 AND \"lfs_object_registry\".\"id\" < 4 AND \"lfs_object_registry\".\"success\" = TRUE")
27722:17:28 -> 0.0027s
27822:17:28 -> 0.0042s
27922:17:28-- exec_query("SELECT \"lfs_object_registry\".\"id\" FROM \"lfs_object_registry\" WHERE \"lfs_object_registry\".\"id\" >= 4 AND \"lfs_object_registry\".\"success\" = TRUE ORDER BY \"lfs_object_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
28022:17:28 -> 0.0018s
28122:17:28-- transaction(nil)
28222:17:28-- execute("UPDATE \"lfs_object_registry\" SET \"state\" = 2 WHERE \"lfs_object_registry\".\"id\" >= 4 AND \"lfs_object_registry\".\"success\" = TRUE")
28322:17:28 -> 0.0024s
28422:17:28 -> 0.0038s
28522:17:28== 20210624160455 FixStateColumnInLfsObjectRegistry: migrated (0.0211s) =======
28622:17:28geo: == [advisory_lock_connection] object_id: 4702100, pg_backend_pid: 260
28722:17:34 correctly sets registry state value
28822:17:46# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb. It took 18.84 seconds. Expected to take 5.64 seconds.
28922:17:46# [RSpecRunTime] RSpec elapsed time: 1 minute 11.82 seconds. Current RSS: ~1139M. Threads: 1. load average: 1.09 1.29 1.22 1/406 411
29022:17:46.
29122:17:46# [RSpecRunTime] Starting example group ee/spec/migrations/geo/fix_state_column_in_file_registry_spec.rb. Expected to take 5.54 seconds.
29222:17:46FixStateColumnInFileRegistry
29322:17:47geo: == [advisory_lock_connection] object_id: 5684260, pg_backend_pid: 297
29422:17:47== 20210818111211 FixStateColumnInFileRegistry: migrating =====================
29522:17:47-- exec_query("SELECT COUNT(*) AS count FROM \"file_registry\" WHERE \"file_registry\".\"success\" = TRUE")
29622:17:47 -> 0.0025s
29722:17:47-- exec_query("SELECT \"file_registry\".\"id\" FROM \"file_registry\" WHERE \"file_registry\".\"success\" = TRUE ORDER BY \"file_registry\".\"id\" ASC LIMIT 1")
29822:17:47 -> 0.0022s
29922:17:47-- exec_query("SELECT \"file_registry\".\"id\" FROM \"file_registry\" WHERE \"file_registry\".\"id\" >= 23 AND \"file_registry\".\"success\" = TRUE ORDER BY \"file_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
30022:17:47 -> 0.0023s
30122:17:47-- transaction(nil)
30222:17:47-- execute("UPDATE \"file_registry\" SET \"state\" = 2 WHERE \"file_registry\".\"id\" >= 23 AND \"file_registry\".\"id\" < 25 AND \"file_registry\".\"success\" = TRUE")
30322:17:47 -> 0.0027s
30422:17:47 -> 0.0043s
30522:17:47-- exec_query("SELECT \"file_registry\".\"id\" FROM \"file_registry\" WHERE \"file_registry\".\"id\" >= 25 AND \"file_registry\".\"success\" = TRUE ORDER BY \"file_registry\".\"id\" ASC LIMIT 1 OFFSET 1")
30622:17:47 -> 0.0018s
30722:17:47-- transaction(nil)
30822:17:47-- execute("UPDATE \"file_registry\" SET \"state\" = 2 WHERE \"file_registry\".\"id\" >= 25 AND \"file_registry\".\"success\" = TRUE")
30922:17:47 -> 0.0028s
31022:17:47 -> 0.0043s
31122:17:47== 20210818111211 FixStateColumnInFileRegistry: migrated (0.0209s) ============
31222:17:47geo: == [advisory_lock_connection] object_id: 5684260, pg_backend_pid: 297
31322:17:52 correctly sets registry state value
31422:18:04# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/fix_state_column_in_file_registry_spec.rb. It took 18.19 seconds. Expected to take 5.54 seconds.
31522:18:04# [RSpecRunTime] RSpec elapsed time: 1 minute 30.06 seconds. Current RSS: ~1139M. Threads: 1. load average: 0.84 1.22 1.20 1/406 412
31622:18:04.
31722:18:04# [RSpecRunTime] Starting example group ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb. Missing expected duration from Knapsack report for ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb.
31822:18:04QueueUpdateWorkspacesConfigVersion
31922:18:04 schedules a new batched migration (PENDING: Skipping because migration QueueUpdateWorkspacesConfigVersion is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
32022:18:04# [RSpecRunTime] Finishing example group ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb. It took 0.02 second. Missing expected duration from Knapsack report for ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb.
32122:18:04# [RSpecRunTime] Starting example group ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb. Missing expected duration from Knapsack report for ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb.
32222:18:04QueueUpdateWorkspacesConfigVersion3
32322:18:04 schedules a new batched migration (PENDING: Skipping because migration QueueUpdateWorkspacesConfigVersion3 is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
32422:18:04# [RSpecRunTime] Finishing example group ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb. It took 0.03 second. Missing expected duration from Knapsack report for ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb.
32522:18:04# [RSpecRunTime] Starting example group ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb. Missing expected duration from Knapsack report for ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb.
32622:18:04ResyncDirectUploadJobArtifactRegistry
32722:18:04 #up
32822:18:04 when direct upload is enabled for job artifacts
32922:18:04 when the site is a Geo secondary
33022:18:04 when sync_object_storage is enabled for the current Geo site
33122:18:04 with job artifact registry rows
33222:18:04 marks pending if synced between 2023-06-22 and 2024-02-03 (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
33322:18:04 does not update if not synced (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
33422:18:04 does not update if synced before 2023-06-22 (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
33522:18:04 does not update if synced after 2024-02-03 (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
33622:18:04 when sync_object_storage is disabled for the current Geo site
33722:18:04 does not update job artifact registry (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
33822:18:04 when the site is a Geo primary
33922:18:04 does not update job artifact registry (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
34022:18:04 when direct upload is disabled for job artifacts
34122:18:04 does not update job artifact registry (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
34222:18:04 when object storage is disabled for job artifacts
34322:18:04 does not update job artifact registry (PENDING: Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.)
34422:18:04# [RSpecRunTime] Finishing example group ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb. It took 0.02 second. Missing expected duration from Knapsack report for ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb.
34522:18:08auto_explain log contains 799 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-migration-pg14-single-db-ci-connection-1-2.346.main.ndjson.gz
34622:18:08took 3.870527956
34722:18:10auto_explain log contains 800 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-ee-migration-pg14-single-db-ci-connection-1-2.346.ci.ndjson.gz
34822:18:10took 1.584699757
34922:18:10[TEST PROF INFO] EventProf results for sql.active_record
35022:18:10Total time: 00:35.852 of 01:19.706 (44.98%)
35122:18:10Total events: 43652
35222:18:10Top 5 slowest suites (by time):
35322:18:10MigrateCiJobA...parateRegistry (./ee/spec/migrations/geo/migrate_ci_job_artifacts_to_separate_registry_spec.rb:6) – 00:18.540 (22452 / 5) of 00:42.487 (43.64%)
35422:18:10FixStateColumnInFileRegistry (./ee/spec/migrations/geo/fix_state_column_in_file_registry_spec.rb:7) – 00:08.661 (10575 / 1) of 00:18.249 (47.46%)
35522:18:10FixStateColum...ObjectRegistry (./ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb:7) – 00:08.638 (10601 / 1) of 00:18.891 (45.73%)
35622:18:10QueueUpdateWo...sConfigVersion (./ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb:6) – 00:00.004 (8 / 1) of 00:00.021 (19.68%)
35722:18:10QueueUpdateWo...ConfigVersion3 (./ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb:6) – 00:00.003 (8 / 1) of 00:00.034 (11.19%)
35822:18:10Knapsack report was generated. Preview:
35922:18:10{
36022:18:10 "ee/spec/migrations/geo/migrate_ci_job_artifacts_to_separate_registry_spec.rb": 29.129362814999695,
36122:18:10 "ee/spec/migrations/geo/fix_state_column_in_lfs_object_registry_spec.rb": 6.688484487999631,
36222:18:10 "ee/spec/migrations/geo/fix_state_column_in_file_registry_spec.rb": 6.019755312000598
36322:18:10}
36422:18:10Knapsack global time execution for tests: 41s
36522:18:10Pending: (Failures listed here are expected and do not affect your suite's status)
36622:18:10 1) QueueUpdateWorkspacesConfigVersion schedules a new batched migration
36722:18:10 # Skipping because migration QueueUpdateWorkspacesConfigVersion is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
36822:18:10 # ./ee/spec/migrations/20230901120000_queue_update_workspaces_config_version_spec.rb:9
36922:18:10 2) QueueUpdateWorkspacesConfigVersion3 schedules a new batched migration
37022:18:10 # Skipping because migration QueueUpdateWorkspacesConfigVersion3 is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
37122:18:10 # ./ee/spec/migrations/20240104085448_queue_update_workspaces_config_version3_spec.rb:9
37222:18:10 3) ResyncDirectUploadJobArtifactRegistry#up when direct upload is enabled for job artifacts when the site is a Geo secondary when sync_object_storage is enabled for the current Geo site with job artifact registry rows marks pending if synced between 2023-06-22 and 2024-02-03
37322:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
37422:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:34
37522:18:10 4) ResyncDirectUploadJobArtifactRegistry#up when direct upload is enabled for job artifacts when the site is a Geo secondary when sync_object_storage is enabled for the current Geo site with job artifact registry rows does not update if not synced
37622:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
37722:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:44
37822:18:10 5) ResyncDirectUploadJobArtifactRegistry#up when direct upload is enabled for job artifacts when the site is a Geo secondary when sync_object_storage is enabled for the current Geo site with job artifact registry rows does not update if synced before 2023-06-22
37922:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
38022:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:54
38122:18:10 6) ResyncDirectUploadJobArtifactRegistry#up when direct upload is enabled for job artifacts when the site is a Geo secondary when sync_object_storage is enabled for the current Geo site with job artifact registry rows does not update if synced after 2024-02-03
38222:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
38322:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:63
38422:18:10 7) ResyncDirectUploadJobArtifactRegistry#up when direct upload is enabled for job artifacts when the site is a Geo secondary when sync_object_storage is disabled for the current Geo site does not update job artifact registry
38522:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
38622:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:77
38722:18:10 8) ResyncDirectUploadJobArtifactRegistry#up when direct upload is enabled for job artifacts when the site is a Geo primary does not update job artifact registry
38822:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
38922:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:96
39022:18:10 9) ResyncDirectUploadJobArtifactRegistry#up when direct upload is disabled for job artifacts does not update job artifact registry
39122:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
39222:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:117
39322:18:10 10) ResyncDirectUploadJobArtifactRegistry#up when object storage is disabled for job artifacts does not update job artifact registry
39422:18:10 # Skipping because migration ResyncDirectUploadJobArtifactRegistry is outside the test window. Run with `RUN_ALL_MIGRATION_TESTS=1 bundle exec rspec <spec> if you need to run this spec.
39522:18:10 # ./ee/spec/migrations/geo/resync_direct_upload_job_artifact_registry_spec.rb:137
39622:18:10Finished in 1 minute 35.72 seconds (files took 2 minutes 23.7 seconds to load)
39722:18:1017 examples, 0 failures, 10 pending
39822:18:16[TEST PROF INFO] Time spent in factories: 00:00.079 (0.05% of total time)
39922:18:17RSpec exited with 0.
40022:18:17No examples to retry, congrats!
401 22:18:18 Running after_script 00:18
40222:18:18Running after script...
40322:18:18$ source scripts/utils.sh
40422:18:18$ log_disk_usage
40522:18:19*******************************************************
40622:18:19This runner currently has 73G free disk space.
40722:18:19*******************************************************
408 22:18:19 Disk usage detail 00:11
46422:18:30$ bundle exec gem list gitlab_quality-test_tooling
46522:18:31gitlab_quality-test_tooling (2.1.0)
46622:18:31$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
467 22:18:31 Report test failures 00:00
46922:18:31$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
470 22:18:31 Report test flakiness 00:00
47222:18:31$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
473 22:18:31 Report test slowness 00:00
47522:18:31$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
476 22:18:31 Report test slowness in MR note 00:02
47922:18:33$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
480 22:18:33 Report test files close to timing out 00:02
48322:18:35$ tooling/bin/push_job_metrics || true
48422:18:36[job-metrics] Pushing job metrics file for the CI/CD job.
48522:18:36[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
486 22:18:36 Saving cache for successful job 00:01
48722:18:37Not uploading cache ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20 due to policy
488 22:18:37 Uploading artifacts for successful job 00:05
48922:18:37Uploading artifacts...
49022:18:37auto_explain/: found 3 matching artifact files and directories
49122:18:37coverage/: found 5 matching artifact files and directories
49222:18:37crystalball/: found 2 matching artifact files and directories
49322:18:37WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
49422:18:37knapsack/: found 4 matching artifact files and directories
49522:18:37rspec/: found 16 matching artifact files and directories
49622:18:37WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
49722:18:37log/*.log: found 13 matching artifact files and directories
49822:18:37WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353288385/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
49922:18:37WARNING: Retrying... context=artifacts-uploader error=request redirected
50022:18:40Uploading artifacts as "archive" to coordinator... 201 Created id=8353288385 responseStatus=201 Created token=glcbt-66
50122:18:40Uploading artifacts...
50222:18:40rspec/rspec-*.xml: found 1 matching artifact files and directories
50322:18:40WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8353288385/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
50422:18:40WARNING: Retrying... context=artifacts-uploader error=request redirected
50522:18:41Uploading artifacts as "junit" to coordinator... 201 Created id=8353288385 responseStatus=201 Created token=glcbt-66
506 22:18:42 Cleaning up project directory and file based variables 00:00
50722:18:52Job succeeded