Skip to content
Snippets Groups Projects

rspec background_migration pg14 15/17

Canceled Created by
Simon Tomlinson
@stomlinson
Log timestamps in UTC.
122:24:48Running with gitlab-runner 17.4.0~pre.110.g27400594 (27400594)
222:24:48 on blue-6.private.runners-manager.gitlab.com/gitlab.com/gitlab-org mKJTFBei, system ID: s_90a66139ec06
322:24:48 feature flags: FF_NETWORK_PER_BUILD:true, FF_TIMESTAMPS:true
422:24:48Resolving secrets
5 22:24:48 Preparing the "docker+machine" executor 00:08
622:24:48Using 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:24:50Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
822:24:50Authenticating with credentials from job payload (GitLab Registry)
922:24:50Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
1022:24:51Using docker image sha256:82f132c22567f8ce17cc132c14b2f9aa3eaf9bb5424d91c2d966912433f0257d for registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:c55e1364ee4327b244a9cfa1750f19feea14fc774eaf792b725967d146eb45f5 ...
1122:24:51WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1222:24:51WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
1322:24:51Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12...
1422:24:51Authenticating with credentials from job payload (GitLab Registry)
1522:24:51Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
1622:24:51Using 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:24:52Starting service redis:6.2-alpine...
1822:24:52Pulling docker image redis:6.2-alpine ...
1922:24:52Using docker image sha256:4100b5bd17430263e85ad9d8ab851959b234acaaf378e093f1f98400f4998815 for redis:6.2-alpine with digest redis@sha256:77c6e37734720700cd47d8b7d9e8a9a6f24fc32862833b064c76e830145bebce ...
2022:24:53Waiting for services to be up and running (timeout 30 seconds)...
2122:24:56Authenticating with credentials from job payload (GitLab Registry)
2222:24:56Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
2322:24:56Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
24 22:24:56 Preparing environment 00:01
2522:24:57Running on runner-mkjtfbei-project-278964-concurrent-0 via runner-mkjtfbei-private-1731427877-52b532a4...
26 22:24:57 Getting source from Git repository 00:01
2722:24:58Skipping Git repository setup
2822:24:58Skipping Git checkout
2922:24:58Skipping Git submodules setup
30 22:24:58 Restoring cache 00:17
3122:24:58Checking cache for ruby-gems-debian-bookworm-ruby-3.2.5-gemfile-Gemfile-20...
3222:24:58cache.zip is up to date
3322:25:10Successfully extracted cache
34 22:25:15 Downloading artifacts 00:45
3522:25:16Downloading artifacts for clone-gitlab-repo (8340695645)...
3622:25:21Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8340695645 responseStatus=200 OK token=glcbt-66
3722:25:21WARNING: Part of .git directory is on the list of files to extract
3822:25:21WARNING: This may introduce unexpected problems
3922:25:33Downloading artifacts for compile-test-assets (8340695686)...
4022:25:37Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8340695686 responseStatus=200 OK token=glcbt-66
4122:25:43Downloading artifacts for detect-tests (8340695701)...
4222:25:43Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8340695701 responseStatus=200 OK token=glcbt-66
4322:25:43Downloading artifacts for retrieve-tests-metadata (8340695705)...
4422:25:44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8340695705 responseStatus=200 OK token=glcbt-66
4522:25:44Downloading artifacts for setup-test-env (8340695688)...
4622:25:48Downloading artifacts from coordinator... ok host=storage.googleapis.com id=8340695688 responseStatus=200 OK token=glcbt-66
47 22:26:00 Executing "step_script" stage of the job script
4822:26:00Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
4922:26:01$ echo $FOSS_ONLY
5022:26:01$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
5122:26:01$ export GOPATH=$CI_PROJECT_DIR/.go
5222:26:01$ mkdir -p $GOPATH
5322:26:01$ source scripts/utils.sh
5422:26:01$ log_disk_usage "true"
5522:26:01*******************************************************
5622:26:01This runner currently has 73G free disk space.
5722:26:01*******************************************************
58 22:26:01 Disk usage detail 00:06
5922:26:01df -h
6022:26:01Filesystem Size Used Avail Use% Mounted on
6122:26:01overlay 95G 22G 73G 24% /
6222:26:01tmpfs 64M 0 64M 0% /dev
6322:26:01shm 64M 0 64M 0% /dev/shm
6422:26:01/dev/sda1 95G 22G 73G 24% /cache
6522:26:01tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6622:26:01du -h -d 1
6722:26:017.4M ./workhorse
6822:26:01148K ./bin
6922:26:011.2M ./.gitlab
7022:26:01168M ./.git
7122:26:014.0K ./builds
7222:26:0128M ./lib
7322:26:018.0K ./.vscode
7422:26:01560K ./storybook
7522:26:0124K ./log
7622:26:011.8M ./data
7722:26:0111M ./qa
7822:26:013.2M ./.rubocop_todo
7922:26:01856M ./vendor
8022:26:011022M ./public
8122:26:0162M ./doc
8222:26:01484K ./danger
8322:26:0132K ./rspec
8422:26:01556K ./tooling
8522:26:01145M ./ee
8622:26:011.3M ./knapsack
8722:26:01300K ./patches
8822:26:014.3M ./changelogs
8922:26:0120K ./haml_lint
9022:26:0128K ./metrics_server
9122:26:0196K ./keeps
9222:26:0136K ./shared
9322:26:0144K ./generator_templates
9422:26:011.3M ./scripts
9522:26:01763M ./tmp
9622:26:01127M ./spec
9722:26:0120K ./file_hooks
9822:26:0132K ./crystalball
9922:26:0116K ./sidekiq_cluster
10022:26:0117M ./gems
10122:26:011.2M ./fixtures
10222:26:01964K ./rubocop
10322:26:014.0K ./.go
10422:26:0133M ./db
10522:26:0112K ./.github
10622:26:01129M ./locale
10722:26:0120M ./config
10822:26:0182M ./app
10922:26:0120K ./.lefthook
11022:26:013.5G .
11122:26:02$ source scripts/prepare_build.sh
112 22:26:02 Installing gems 00:15
14322:26:17Using decomposed database config (config/database.yml.decomposed-postgresql)
14422:26:17Geo DB won't be set up.
14522:26:17Embedding DB won't be set up.
146 22:26:17 Setting up DBs 01:12
15922:27:29$ source ./scripts/rspec_helpers.sh
16022:27:29$ run_timed_command "gem install knapsack --no-document"
16122:27:29$ gem install knapsack --no-document
16222:27:30Successfully installed knapsack-4.0.0
16322:27:301 gem installed
16422:27:29==> 'gem install knapsack --no-document' succeeded in 1 seconds.
16522:27:30$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
166 22:27:30 Spawning Gitaly 00:04
17022:27:34$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
17122:27:34$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
17222:27:34$ tooling/bin/create_job_metrics_file || true
17322:27:37[job-metrics] Creating the job metrics file for the CI/CD job.
17422:27:37$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
175 22:27:37 RSpec 07:02
17622:27:37[22:27:37] Starting rspec_parallelized_job
17722:27:30RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
17822:27:37KNAPSACK_GENERATE_REPORT: true
17922:27:37FLAKY_RSPEC_GENERATE_REPORT: true
18022:27:37KNAPSACK_TEST_FILE_PATTERN: spec/{lib/gitlab/background_migration,lib/ee/gitlab/background_migration}{,/**/}*_spec.rb
18122:27:37KNAPSACK_LOG_LEVEL: debug
18222:27:37KNAPSACK_REPORT_PATH: knapsack/rspec_background_migration_pg14_15_17_278964_report.json
18322:27:37FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
18422:27:37FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_background_migration_pg14_15_17_278964_report.json
18522:27:37NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_background_migration_pg14_15_17_278964_report.json
18622:27:37RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-8340695926.txt
18722:27:37CRYSTALBALL:
18822:27:37RSPEC_TESTS_MAPPING_ENABLED:
18922:27:37RSPEC_TESTS_FILTER_FILE:
19022:27:37Shell set options (set -o) enabled:
19122:27:37braceexpand on
19222:27:37hashall on
19322:27:37interactive-comments on
19422:27:37pipefail on
19522:27:43Knapsack report generator started!
19622:27:37/builds/gitlab-org/gitlab/vendor/ruby/3.2.0/gems/io-event-1.6.5/lib/io/event/support.rb:27: warning: IO::Buffer is experimental and both the Ruby and C interface may change in the future!
19722:28:19DEPRECATION WARNING: Support for Rails versions < 7.1 is deprecated and will be removed from ViewComponent 4.0.0 (ViewComponent v4 will remove support for Rails versions < 7.1 no earlier than April 1, 2025) (called from <top (required)> at /builds/gitlab-org/gitlab/config/environment.rb:7)
19822:28:29warning: parser/current is loading parser/ruby32, which recognizes 3.2.6-compliant syntax, but you are running 3.2.5.
19922:28:29Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
20022:28:34Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
20122:28:34# [RSpecRunTime] Starting RSpec timer...
20222:28:34[TEST PROF INFO] EventProf enabled (sql.active_record)
20322:28:34unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20422:28:34unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
20522:28:42Test environment set up in 2.92706592 seconds
20622:28:43# [RSpecRunTime] Starting example group spec/lib/gitlab/background_migration/backfill_nuget_normalized_version_spec.rb. Expected to take 2 minutes 23.73 seconds.
20722:28:43Gitlab::BackgroundMigration::BackfillNugetNormalizedVersion
20822:30:47 executes 5 queries and updates the normalized_version column
20922:30:49I, [2024-11-12T22:30:49.645456 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
21022:31:10I, [2024-11-12T22:31:10.777831 #342] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
21122:31:12INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
21222:31:12INFO: analyzing "public.ci_pipeline_variables"
21322:31:12INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
21422:31:12I, [2024-11-12T22:31:12.440060 #342] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
21522:31:12I, [2024-11-12T22:31:12.441247 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
21622:31:12I, [2024-11-12T22:31:12.442009 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
21722:31:14INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
21822:31:14INFO: analyzing "public.ci_pipeline_variables"
21922:31:14INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22022:31:19INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
22122:31:19INFO: analyzing "public.ci_job_artifacts"
22222:31:19INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22322:31:19I, [2024-11-12T22:31:19.240316 #342] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
22422:31:19I, [2024-11-12T22:31:19.241466 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
22522:31:19I, [2024-11-12T22:31:19.242422 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
22622:31:22INFO: analyzing "public.p_ci_stages" inheritance tree
22722:31:22INFO: analyzing "public.ci_stages"
22822:31:22INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
22922:31:22I, [2024-11-12T22:31:22.726989 #342] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
23022:31:22I, [2024-11-12T22:31:22.728175 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
23122:31:22I, [2024-11-12T22:31:22.728927 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
23222:31:24I, [2024-11-12T22:31:24.033558 #342] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
23322:31:30I, [2024-11-12T22:31:30.662499 #342] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
23422:31:44I, [2024-11-12T22:31:44.974212 #342] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
23522:31:44I, [2024-11-12T22:31:44.975383 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
23622:31:44I, [2024-11-12T22:31:44.976171 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
23722:31:57I, [2024-11-12T22:31:57.588264 #342] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
23822:32:04I, [2024-11-12T22:32:04.969771 #342] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
23922:32:13I, [2024-11-12T22:32:13.312343 #342] INFO -- : Database: 'main', Table: 'p_ci_build_trace_metadata': Lock Writes
24022:32:16I, [2024-11-12T22:32:16.299237 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines_config': Lock Writes
24122:32:20INFO: analyzing "public.p_ci_pipelines" inheritance tree
24222:32:20INFO: analyzing "public.ci_pipelines"
24322:32:20INFO: "ci_pipelines": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
24422:32:20I, [2024-11-12T22:32:20.344888 #342] INFO -- : Database: 'main', Table: 'p_ci_pipelines': Lock Writes
24522:32:20I, [2024-11-12T22:32:20.346093 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
24622:32:20I, [2024-11-12T22:32:20.346942 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
24722:32:26I, [2024-11-12T22:32:26.682781 #342] INFO -- : Database: 'main', Table: 'ci_job_token_authorizations': Lock Writes
24822:32:37I, [2024-11-12T22:32:37.828445 #342] INFO -- : Database: 'main', Table: 'ci_runners_e59bb2812d': Lock Writes
24922:32:37I, [2024-11-12T22:32:37.830081 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25022:32:37I, [2024-11-12T22:32:37.831112 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25122:32:37I, [2024-11-12T22:32:37.834872 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runners_e59bb2812d': Lock Writes
25222:32:37I, [2024-11-12T22:32:37.836063 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25322:32:37I, [2024-11-12T22:32:37.836919 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25422:32:37I, [2024-11-12T22:32:37.842015 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runners_e59bb2812d': Lock Writes
25522:32:37I, [2024-11-12T22:32:37.843350 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25622:32:37I, [2024-11-12T22:32:37.844338 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
25722:32:37I, [2024-11-12T22:32:37.848186 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runners_e59bb2812d': Lock Writes
25822:32:37I, [2024-11-12T22:32:37.849316 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
25922:32:37I, [2024-11-12T22:32:37.850174 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26022:32:38I, [2024-11-12T22:32:38.961913 #342] INFO -- : Database: 'main', Table: 'ci_runner_machines_687967fa8a': Lock Writes
26122:32:38I, [2024-11-12T22:32:38.963123 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26222:32:38I, [2024-11-12T22:32:38.963969 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26322:32:38I, [2024-11-12T22:32:38.967416 #342] INFO -- : Database: 'main', Table: 'instance_type_ci_runner_machines_687967fa8a': Lock Writes
26422:32:38I, [2024-11-12T22:32:38.968537 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26522:32:38I, [2024-11-12T22:32:38.969355 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26622:32:38I, [2024-11-12T22:32:38.972704 #342] INFO -- : Database: 'main', Table: 'group_type_ci_runner_machines_687967fa8a': Lock Writes
26722:32:38I, [2024-11-12T22:32:38.974055 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
26822:32:38I, [2024-11-12T22:32:38.974857 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
26922:32:38I, [2024-11-12T22:32:38.978265 #342] INFO -- : Database: 'main', Table: 'project_type_ci_runner_machines_687967fa8a': Lock Writes
27022:32:38I, [2024-11-12T22:32:38.979394 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
27122:32:38I, [2024-11-12T22:32:38.980177 #342] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
27222:32:59auto_explain log contains 1118 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-background-migration-pg14-15-17.342.main.ndjson.gz
27322:32:59took 7.147247201
27422:33:01Terminated
27522:33:02WARNING: script canceled externally (UI, API)
276 22:33:02 Running after_script
27722:33:02Using docker image sha256:e83f017c5ffd177beb4bc3b4bfabde989d741e04fef90cd764896cf9b670552f for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.5-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.2.5-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:770feb0a974e36f8b83d22a3cb18310d0cfeae11e02f6195b1577c73ce26b398 ...
27822:33:02Running after script...
27922:33:02$ source scripts/utils.sh
28022:33:02$ log_disk_usage
28122:33:03*******************************************************
28222:33:03This runner currently has 72G free disk space.
28322:33:03*******************************************************
284 22:33:03 Disk usage detail 00:06
33922:33:09$ bundle exec gem list gitlab_quality-test_tooling
34022:33:11gitlab_quality-test_tooling (2.1.0)
34122:33:11$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
342 22:33:11 Report test failures 00:00
34422:33:11$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
345 22:33:11 Report test flakiness 00:00
34722:33:11$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
348 22:33:11 Report test slowness 00:00
35022:33:11$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
351 22:33:11 Report test slowness in MR note 00:11
38222:33:13WARNING: after_script failed, but job will continue unaffected: exit code 1
383 22:33:13 Uploading artifacts for failed job 00:06
38422:33:15Uploading artifacts...
38522:33:15auto_explain/: found 3 matching artifact files and directories
38622:33:15WARNING: coverage/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
38722:33:15crystalball/: found 2 matching artifact files and directories
38822:33:15WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
38922:33:15knapsack/: found 4 matching artifact files and directories
39022:33:15rspec/: found 15 matching artifact files and directories
39122:33:15WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
39222:33:15log/*.log: found 13 matching artifact files and directories
39322:33:15WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8340695926/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
39422:33:15WARNING: Retrying... context=artifacts-uploader error=request redirected
39522:33:17Uploading artifacts as "archive" to coordinator... 201 Created id=8340695926 responseStatus=201 Created token=glcbt-66
39622:33:17Uploading artifacts...
39722:33:17rspec/rspec-*.xml: found 1 matching artifact files and directories
39822:33:17WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/8340695926/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
39922:33:17WARNING: Retrying... context=artifacts-uploader error=request redirected
40022:33:19Uploading artifacts as "junit" to coordinator... 201 Created id=8340695926 responseStatus=201 Created token=glcbt-66
401 22:33:19 Cleaning up project directory and file based variables 00:01
40222:33:28ERROR: Job failed: canceled