Skip to content
Snippets Groups Projects

rspec migration pg14 no_gitaly_transactions 26/26

Passed Started by
🤖 GitLab Bot 🤖
@gitlab-bot
1Running with gitlab-runner 17.0.0~pre.88.g761ae5dd (761ae5dd)
2 on green-3.private.runners-manager.gitlab.com/gitlab.com/gitlab-org QuQPoFsC, system ID: s_fc023362bf2f
3 feature flags: FF_NETWORK_PER_BUILD:true
4Resolving secrets
5 Preparing the "docker+machine" executor 00:07
6Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
7Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
8Authenticating with credentials from job payload (GitLab Registry)
9Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
10Using 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 ...
11WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
12WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 is already created. Ignoring.
13Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
14Authenticating with credentials from job payload (GitLab Registry)
15Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.2.12 ...
16Using 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 ...
17Starting service redis:6.2-alpine ...
18Pulling docker image redis:6.2-alpine ...
19Using docker image sha256:36c1d3cfe18f4b12d4640576f7048068acbfc3625027b6bbb46bba0e31b11831 for redis:6.2-alpine with digest redis@sha256:e3b17ba9479deec4b7d1eeec1548a253acc5374d68d3b27937fcfe4df8d18c7e ...
20Waiting for services to be up and running (timeout 30 seconds)...
21Authenticating with credentials from job payload (GitLab Registry)
22Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
23Using docker image sha256:b26253b493531cada33f45ef568f38c50a310442d05c39f517656e0f7d305dc7 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-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.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:543339542a02edc250c2c0424c5077b673f1fca2877024fdc5fb670eff44f8cf ...
24 Preparing environment 00:01
25Running on runner-quqpofsc-project-278964-concurrent-0 via runner-quqpofsc-private-1722407397-97c6c6b2...
26 Getting source from Git repository 00:01
27Skipping Git repository setup
28Skipping Git checkout
29Skipping Git submodules setup
30 Restoring cache 00:18
31Checking cache for ruby-gems-debian-bookworm-ruby-3.1.5-17...
32Downloading cache from https://storage.googleapis.com/gitlab-com-runners-cache/project/278964/ruby-gems-debian-bookworm-ruby-3.1.5-17
33Successfully extracted cache
34 Downloading artifacts 00:40
35Downloading artifacts for clone-gitlab-repo (7471344368)...
36Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344368 responseStatus=200 OK token=glcbt-66
37WARNING: Part of .git directory is on the list of files to extract
38WARNING: This may introduce unexpected problems
39Downloading artifacts for compile-test-assets (7471344747)...
40Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344747 responseStatus=200 OK token=glcbt-66
41Downloading artifacts for retrieve-tests-metadata (7471344898)...
42Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344898 responseStatus=200 OK token=glcbt-66
43Downloading artifacts for setup-test-env (7471344810)...
44Downloading artifacts from coordinator... ok host=storage.googleapis.com id=7471344810 responseStatus=200 OK token=glcbt-66
45 Executing "step_script" stage of the job script
46Using docker image sha256:b26253b493531cada33f45ef568f38c50a310442d05c39f517656e0f7d305dc7 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14:rubygems-3.4-git-2.36-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.1.5-golang-1.22-rust-1.73-node-20.12-postgresql-14@sha256:543339542a02edc250c2c0424c5077b673f1fca2877024fdc5fb670eff44f8cf ...
47$ echo $FOSS_ONLY
48$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
49$ export GOPATH=$CI_PROJECT_DIR/.go
50$ mkdir -p $GOPATH
51$ source scripts/utils.sh
52$ source scripts/prepare_build.sh
53 Installing gems 00:20
82Using decomposed database config (config/database.yml.decomposed-postgresql)
83Geo DB won't be set up.
84Embedding DB won't be set up.
85 Setting up DBs 01:09
96$ source ./scripts/rspec_helpers.sh
97$ run_timed_command "gem install knapsack --no-document"
98$ gem install knapsack --no-document
99Successfully installed knapsack-4.0.0
1001 gem installed
101==> 'gem install knapsack --no-document' succeeded in 1 seconds.
102$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
103 Spawning Gitaly 00:05
107$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
108$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
109$ tooling/bin/create_job_metrics_file || true
110[job-metrics] Creating the job metrics file for the CI/CD job.
111$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house"
112 RSpec 25:25
113[10:14:37] Starting rspec_parallelized_job
114RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
115KNAPSACK_GENERATE_REPORT: true
116FLAKY_RSPEC_GENERATE_REPORT: true
117KNAPSACK_TEST_FILE_PATTERN: spec/{migrations}{,/**/}*_spec.rb
118KNAPSACK_LOG_LEVEL: debug
119KNAPSACK_REPORT_PATH: knapsack/rspec_migration_pg14_no_gitaly_transactions_26_26_278964_report.json
120FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
121FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_migration_pg14_no_gitaly_transactions_26_26_278964_report.json
122NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_migration_pg14_no_gitaly_transactions_26_26_278964_report.json
123RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-7471346437.txt
124CRYSTALBALL: true
125RSPEC_TESTS_MAPPING_ENABLED:
126RSPEC_TESTS_FILTER_FILE:
127Shell set options (set -o) enabled:
128braceexpand on
129hashall on
130interactive-comments on
131pipefail on
132Knapsack report generator started!
133warning: parser/current is loading parser/ruby31, which recognizes 3.1.6-compliant syntax, but you are running 3.1.5.
134Please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
135Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true}
136# [RSpecRunTime] Starting RSpec timer...
137[TEST PROF INFO] EventProf enabled (sql.active_record)
138unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
139unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
140Test environment set up in 1.72459599 seconds
141# [RSpecRunTime] Starting example group spec/migrations/20230809104753_swap_epic_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb. Expected to take 2 minutes 17.12 seconds.
142SwapEpicUserMentionsNoteIdToBigintForSelfHosts
143 #up
144 when GitLab.com, dev, or test
145 does not swap the columns
146 when self-managed instance with the columns already swapped
147main: == [advisory_lock_connection] object_id: 20011260, pg_backend_pid: 158
148main: == 20230809104753 SwapEpicUserMentionsNoteIdToBigintForSelfHosts: migrating ===
149main: -- column_exists?("epic_user_mentions", "note_id_convert_to_bigint")
150main: -> 0.0068s
151main: -- columns("epic_user_mentions")
152main: -> 0.0065s
153main: == 20230809104753 SwapEpicUserMentionsNoteIdToBigintForSelfHosts: migrated (0.0291s)
154main: == [advisory_lock_connection] object_id: 20011260, pg_backend_pid: 158
155 does not swap the columns
156# [RSpecRunTime] RSpec elapsed time: 2 minutes 3.87 seconds. Current RSS: ~1461M. Threads: 2. load average: 1.05 0.90 0.91 1/276 402
157.
158 when self-managed instance with the `note_id_convert_to_bigint` column already dropped
159 does not swap the columns
160# [RSpecRunTime] RSpec elapsed time: 2 minutes 25.8 seconds. Current RSS: ~1400M. Threads: 2. load average: 1.04 0.91 0.91 1/276 403
161.
162 when self-managed instance
163 swaps the columns
164# [RSpecRunTime] RSpec elapsed time: 2 minutes 47.38 seconds. Current RSS: ~1426M. Threads: 2. load average: 1.10 0.93 0.92 1/276 404
165.
166INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
167INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
168INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
169INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
170INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
171INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
172INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
173INFO: analyzing "public.p_ci_job_annotations" inheritance tree
174INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
175INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
176INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
177INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
178INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
179INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
180INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
181INFO: analyzing "public.ci_builds_metadata"
182INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
183INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
184INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
185INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
186INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
187INFO: analyzing "public.p_ci_builds" inheritance tree
188INFO: analyzing "public.ci_builds"
189INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
190INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
191INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
192INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
193INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
194I, [2024-07-31T10:19:09.010336 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
195I, [2024-07-31T10:19:29.937217 #324] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
196INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
197INFO: analyzing "public.ci_pipeline_variables"
198INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
199I, [2024-07-31T10:19:31.571001 #324] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
200I, [2024-07-31T10:19:31.572266 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
201I, [2024-07-31T10:19:31.573359 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
202INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
203INFO: analyzing "public.ci_pipeline_variables"
204INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
205INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
206INFO: analyzing "public.ci_job_artifacts"
207INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
208I, [2024-07-31T10:19:37.864040 #324] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
209I, [2024-07-31T10:19:37.865307 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
210I, [2024-07-31T10:19:37.866192 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
211INFO: analyzing "public.p_ci_stages" inheritance tree
212INFO: analyzing "public.ci_stages"
213INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
214I, [2024-07-31T10:19:41.258759 #324] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
215I, [2024-07-31T10:19:41.260105 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
216I, [2024-07-31T10:19:41.261021 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
217I, [2024-07-31T10:19:42.686824 #324] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
218I, [2024-07-31T10:19:49.239134 #324] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
219I, [2024-07-31T10:20:03.144489 #324] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
220I, [2024-07-31T10:20:03.145844 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
221I, [2024-07-31T10:20:03.146780 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
222I, [2024-07-31T10:20:15.465168 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
223I, [2024-07-31T10:20:22.551891 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
224# [RSpecRunTime] Finishing example group spec/migrations/20230809104753_swap_epic_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb. It took 4 minutes 12.41 seconds. Expected to take 2 minutes 17.12 seconds.
225# [RSpecRunTime] RSpec elapsed time: 4 minutes 17.28 seconds. Current RSS: ~1373M. Threads: 2. load average: 0.97 0.94 0.92 1/276 405
226.
227# [RSpecRunTime] Starting example group spec/migrations/20230814144045_swap_timelogs_note_id_to_bigint_for_self_hosts_spec.rb. Expected to take 2 minutes 15.72 seconds.
228SwapTimelogsNoteIdToBigintForSelfHosts
229 #up
230 when GitLab.com, dev, or test
231 behaves like column `note_id_convert_to_bigint` is already dropped
232 does not swaps the columns
233# [RSpecRunTime] RSpec elapsed time: 5 minutes 55.14 seconds. Current RSS: ~1382M. Threads: 2. load average: 1.02 0.98 0.94 1/274 406
234.
235 when self-managed instance with the `note_id_convert_to_bigint` column already dropped
236 behaves like column `note_id_convert_to_bigint` is already dropped
237 does not swaps the columns
238# [RSpecRunTime] RSpec elapsed time: 6 minutes 16.04 seconds. Current RSS: ~1435M. Threads: 2. load average: 1.01 0.99 0.94 1/274 407
239.
240 when self-managed instance columns already swapped
241 does not swaps the columns
242# [RSpecRunTime] RSpec elapsed time: 6 minutes 28.26 seconds. Current RSS: ~1485M. Threads: 2. load average: 1.09 1.00 0.95 1/274 408
243.
244 when self-managed instance
245 swaps the columns
246# [RSpecRunTime] RSpec elapsed time: 6 minutes 47.43 seconds. Current RSS: ~1379M. Threads: 2. load average: 1.06 1.00 0.95 3/275 409
247.
248INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
249INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
250INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
251INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
252INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
253INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
254INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
255INFO: analyzing "public.p_ci_job_annotations" inheritance tree
256INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
257INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
258INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
259INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
260INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
261INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
262INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
263INFO: analyzing "public.ci_builds_metadata"
264INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
265INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
266INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
267INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
268INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
269INFO: analyzing "public.p_ci_builds" inheritance tree
270INFO: analyzing "public.ci_builds"
271INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
272INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
273INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
274INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
275INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
276I, [2024-07-31T10:23:09.140211 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
277I, [2024-07-31T10:23:29.801847 #324] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
278INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
279INFO: analyzing "public.ci_pipeline_variables"
280INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
281I, [2024-07-31T10:23:31.487123 #324] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
282I, [2024-07-31T10:23:31.488352 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
283I, [2024-07-31T10:23:31.489219 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
284INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
285INFO: analyzing "public.ci_pipeline_variables"
286INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
287INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
288INFO: analyzing "public.ci_job_artifacts"
289INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
290I, [2024-07-31T10:23:37.751320 #324] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
291I, [2024-07-31T10:23:37.752504 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
292I, [2024-07-31T10:23:37.753381 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
293INFO: analyzing "public.p_ci_stages" inheritance tree
294INFO: analyzing "public.ci_stages"
295INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
296I, [2024-07-31T10:23:41.150155 #324] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
297I, [2024-07-31T10:23:41.151295 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
298I, [2024-07-31T10:23:41.152227 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
299I, [2024-07-31T10:23:42.398568 #324] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
300I, [2024-07-31T10:23:48.972278 #324] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
301I, [2024-07-31T10:24:02.930663 #324] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
302I, [2024-07-31T10:24:02.931909 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
303I, [2024-07-31T10:24:02.932750 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
304I, [2024-07-31T10:24:15.088239 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
305I, [2024-07-31T10:24:22.206660 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
306# [RSpecRunTime] Finishing example group spec/migrations/20230814144045_swap_timelogs_note_id_to_bigint_for_self_hosts_spec.rb. It took 3 minutes 59.94 seconds. Expected to take 2 minutes 15.72 seconds.
307# [RSpecRunTime] RSpec elapsed time: 8 minutes 17.27 seconds. Current RSS: ~1369M. Threads: 2. load average: 0.98 0.99 0.96 1/276 410
308.
309# [RSpecRunTime] Starting example group spec/migrations/20230816152540_ensure_dum_note_id_bigint_backfill_is_finished_for_self_managed_spec.rb. Expected to take 1 minute 33.59 seconds.
310EnsureDumNoteIdBigintBackfillIsFinishedForSelfManaged
311 #up
312main: == [advisory_lock_connection] object_id: 103915640, pg_backend_pid: 213
313main: == 20230816152540 EnsureDumNoteIdBigintBackfillIsFinishedForSelfManaged: migrating
314main: == 20230816152540 EnsureDumNoteIdBigintBackfillIsFinishedForSelfManaged: migrated (0.0106s)
315main: == [advisory_lock_connection] object_id: 103915640, pg_backend_pid: 213
316 ensures the migration is completed for self-managed instances
317main: == [advisory_lock_connection] object_id: 104934080, pg_backend_pid: 216
318main: == 20230816152540 EnsureDumNoteIdBigintBackfillIsFinishedForSelfManaged: migrating
319main: == 20230816152540 EnsureDumNoteIdBigintBackfillIsFinishedForSelfManaged: migrated (0.0091s)
320main: == [advisory_lock_connection] object_id: 104934080, pg_backend_pid: 216
321 skips the check for GitLab.com, dev, or test
322# [RSpecRunTime] RSpec elapsed time: 9 minutes 54.76 seconds. Current RSS: ~1478M. Threads: 2. load average: 1.20 1.06 0.99 1/276 411
323.
324INFO: analyzing "public.p_ci_runner_machine_builds" inheritance tree
325INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_100"
326INFO: "ci_runner_machine_builds_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
327INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_101"
328INFO: "ci_runner_machine_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
329INFO: analyzing "gitlab_partitions_dynamic.ci_runner_machine_builds_102"
330INFO: "ci_runner_machine_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
331INFO: analyzing "public.p_ci_job_annotations" inheritance tree
332INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_100"
333INFO: "ci_job_annotations_100": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
334INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_101"
335INFO: "ci_job_annotations_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
336INFO: analyzing "gitlab_partitions_dynamic.ci_job_annotations_102"
337INFO: "ci_job_annotations_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
338INFO: analyzing "public.p_ci_builds_metadata" inheritance tree
339INFO: analyzing "public.ci_builds_metadata"
340INFO: "ci_builds_metadata": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
341INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_101"
342INFO: "ci_builds_metadata_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
343INFO: analyzing "gitlab_partitions_dynamic.ci_builds_metadata_102"
344INFO: "ci_builds_metadata_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
345INFO: analyzing "public.p_ci_builds" inheritance tree
346INFO: analyzing "public.ci_builds"
347INFO: "ci_builds": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
348INFO: analyzing "gitlab_partitions_dynamic.ci_builds_101"
349INFO: "ci_builds_101": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
350INFO: analyzing "gitlab_partitions_dynamic.ci_builds_102"
351INFO: "ci_builds_102": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
352I, [2024-07-31T10:26:14.897465 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_build_ch_sync_events': Lock Writes
353I, [2024-07-31T10:26:35.896400 #324] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
354INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
355INFO: analyzing "public.ci_pipeline_variables"
356INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
357I, [2024-07-31T10:26:37.605371 #324] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
358I, [2024-07-31T10:26:37.606716 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
359I, [2024-07-31T10:26:37.607642 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
360INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
361INFO: analyzing "public.ci_pipeline_variables"
362INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
363INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
364INFO: analyzing "public.ci_job_artifacts"
365INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
366I, [2024-07-31T10:26:43.761413 #324] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
367I, [2024-07-31T10:26:43.762577 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
368I, [2024-07-31T10:26:43.763472 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
369INFO: analyzing "public.p_ci_stages" inheritance tree
370INFO: analyzing "public.ci_stages"
371INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
372I, [2024-07-31T10:26:47.163765 #324] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
373I, [2024-07-31T10:26:47.164983 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
374I, [2024-07-31T10:26:47.166320 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
375I, [2024-07-31T10:26:48.503201 #324] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
376I, [2024-07-31T10:26:55.037540 #324] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
377I, [2024-07-31T10:27:08.806833 #324] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
378I, [2024-07-31T10:27:08.807947 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
379I, [2024-07-31T10:27:08.808698 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
380I, [2024-07-31T10:27:21.173466 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
381I, [2024-07-31T10:27:28.298673 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
382# [RSpecRunTime] Finishing example group spec/migrations/20230816152540_ensure_dum_note_id_bigint_backfill_is_finished_for_self_managed_spec.rb. It took 3 minutes 5.8 seconds. Expected to take 1 minute 33.59 seconds.
383# [RSpecRunTime] RSpec elapsed time: 11 minutes 23.13 seconds. Current RSS: ~1398M. Threads: 2. load average: 1.10 1.06 1.00 1/276 412
384.
385# [RSpecRunTime] Starting example group spec/migrations/20231019145202_add_status_to_packages_npm_metadata_caches_spec.rb. Expected to take 1 minute 17.94 seconds.
386AddStatusToPackagesNpmMetadataCaches
387main: == [advisory_lock_connection] object_id: 143639440, pg_backend_pid: 233
388main: == 20231019145202 AddStatusToPackagesNpmMetadataCaches: migrating =============
389main: -- add_column(:packages_npm_metadata_caches, :status, :integer, {:default=>0, :null=>false, :limit=>2})
390main: -> 0.0024s
391main: == 20231019145202 AddStatusToPackagesNpmMetadataCaches: migrated (0.0113s) ====
392main: == [advisory_lock_connection] object_id: 143639440, pg_backend_pid: 233
393 correctly migrates up and down
394I, [2024-07-31T10:29:17.400938 #324] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
395INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
396INFO: analyzing "public.ci_pipeline_variables"
397INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
398I, [2024-07-31T10:29:19.098759 #324] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
399I, [2024-07-31T10:29:19.099980 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
400I, [2024-07-31T10:29:19.100933 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
401INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
402INFO: analyzing "public.ci_pipeline_variables"
403INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
404INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
405INFO: analyzing "public.ci_job_artifacts"
406INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
407I, [2024-07-31T10:29:25.318749 #324] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
408I, [2024-07-31T10:29:25.320029 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
409I, [2024-07-31T10:29:25.320947 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
410INFO: analyzing "public.p_ci_stages" inheritance tree
411INFO: analyzing "public.ci_stages"
412INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
413I, [2024-07-31T10:29:28.829230 #324] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
414I, [2024-07-31T10:29:28.830434 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
415I, [2024-07-31T10:29:28.831281 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
416I, [2024-07-31T10:29:30.085143 #324] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
417I, [2024-07-31T10:29:36.488213 #324] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
418I, [2024-07-31T10:29:50.031425 #324] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
419I, [2024-07-31T10:29:50.032770 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
420I, [2024-07-31T10:29:50.033629 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
421I, [2024-07-31T10:30:02.056651 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
422I, [2024-07-31T10:30:08.880405 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
423# [RSpecRunTime] Finishing example group spec/migrations/20231019145202_add_status_to_packages_npm_metadata_caches_spec.rb. It took 2 minutes 40.79 seconds. Expected to take 1 minute 17.94 seconds.
424# [RSpecRunTime] RSpec elapsed time: 14 minutes 3.97 seconds. Current RSS: ~1375M. Threads: 2. load average: 1.13 1.11 1.03 1/276 413
425.
426# [RSpecRunTime] Starting example group spec/migrations/20240118170849_add_time_tracking_widget_definition_to_work_item_types_spec.rb. Expected to take 1 minute 6.91 seconds.
427AddTimeTrackingWidgetDefinitionToWorkItemTypes
428 behaves like migration that adds widget to work items definitions
429 #up
430main: == [advisory_lock_connection] object_id: 177778460, pg_backend_pid: 251
431main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrating ===
432main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrated (0.0789s)
433main: == [advisory_lock_connection] object_id: 177778460, pg_backend_pid: 251
434 creates widget definition in all types
435main: == [advisory_lock_connection] object_id: 178617220, pg_backend_pid: 253
436main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrating ===
437main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrated (0.0674s)
438main: == [advisory_lock_connection] object_id: 178617220, pg_backend_pid: 253
439 logs a warning if the type is missing
440 when the widget already exists
441main: == [advisory_lock_connection] object_id: 178640140, pg_backend_pid: 255
442main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrating ===
443main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrated (0.0562s)
444main: == [advisory_lock_connection] object_id: 178640140, pg_backend_pid: 255
445 upserts the widget definitions and raises no error
446# [RSpecRunTime] RSpec elapsed time: 15 minutes 7.99 seconds. Current RSS: ~1439M. Threads: 2. load average: 0.99 1.07 1.02 1/276 414
447.
448 #down
449main: == [advisory_lock_connection] object_id: 178742120, pg_backend_pid: 257
450main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrating ===
451main: == 20240118170849 AddTimeTrackingWidgetDefinitionToWorkItemTypes: migrated (0.0772s)
452main: == [advisory_lock_connection] object_id: 178742120, pg_backend_pid: 257
453 removes definitions for widget
454# [RSpecRunTime] RSpec elapsed time: 15 minutes 11.34 seconds. Current RSS: ~1489M. Threads: 2. load average: 0.99 1.07 1.02 1/276 415
455.
456I, [2024-07-31T10:31:28.185547 #324] INFO -- : Database: 'main', Table: 'ci_job_token_group_scope_links': Lock Writes
457INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
458INFO: analyzing "public.ci_pipeline_variables"
459INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
460I, [2024-07-31T10:31:29.881017 #324] INFO -- : Database: 'main', Table: 'p_ci_pipeline_variables': Lock Writes
461I, [2024-07-31T10:31:29.882325 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
462I, [2024-07-31T10:31:29.883222 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
463INFO: analyzing "public.p_ci_pipeline_variables" inheritance tree
464INFO: analyzing "public.ci_pipeline_variables"
465INFO: "ci_pipeline_variables": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
466INFO: analyzing "public.p_ci_job_artifacts" inheritance tree
467INFO: analyzing "public.ci_job_artifacts"
468INFO: "ci_job_artifacts": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
469I, [2024-07-31T10:31:37.423326 #324] INFO -- : Database: 'main', Table: 'p_ci_job_artifacts': Lock Writes
470I, [2024-07-31T10:31:37.424367 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
471I, [2024-07-31T10:31:37.425161 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
472INFO: analyzing "public.p_ci_stages" inheritance tree
473INFO: analyzing "public.ci_stages"
474INFO: "ci_stages": scanned 0 of 0 pages, containing 0 live rows and 0 dead rows; 0 rows in sample, 0 estimated total rows
475I, [2024-07-31T10:31:40.785987 #324] INFO -- : Database: 'main', Table: 'p_ci_stages': Lock Writes
476I, [2024-07-31T10:31:40.787056 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
477I, [2024-07-31T10:31:40.787868 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
478I, [2024-07-31T10:31:41.911883 #324] INFO -- : Database: 'main', Table: 'p_ci_build_names': Lock Writes
479I, [2024-07-31T10:31:48.472429 #324] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
480I, [2024-07-31T10:32:02.323279 #324] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
481I, [2024-07-31T10:32:02.324459 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
482I, [2024-07-31T10:32:02.325258 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
483I, [2024-07-31T10:32:14.194019 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
484I, [2024-07-31T10:32:21.278847 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
485# [RSpecRunTime] Finishing example group spec/migrations/20240118170849_add_time_tracking_widget_definition_to_work_item_types_spec.rb. It took 2 minutes 12.13 seconds. Expected to take 1 minute 6.91 seconds.
486# [RSpecRunTime] RSpec elapsed time: 16 minutes 16.15 seconds. Current RSS: ~1346M. Threads: 2. load average: 0.85 1.01 1.00 1/277 416
487.
488# [RSpecRunTime] Starting example group spec/migrations/20240327214545_add_development_widget_to_work_item_types_spec.rb. Expected to take 49.12 seconds.
489AddDevelopmentWidgetToWorkItemTypes
490 behaves like migration that adds widget to work items definitions
491 #up
492main: == [advisory_lock_connection] object_id: 205250360, pg_backend_pid: 272
493main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrating ==============
494main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrated (0.0393s) =====
495main: == [advisory_lock_connection] object_id: 205250360, pg_backend_pid: 272
496 creates widget definition in all types
497main: == [advisory_lock_connection] object_id: 206443100, pg_backend_pid: 274
498main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrating ==============
499main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrated (0.0524s) =====
500main: == [advisory_lock_connection] object_id: 206443100, pg_backend_pid: 274
501 logs a warning if the type is missing
502 when the widget already exists
503main: == [advisory_lock_connection] object_id: 207521880, pg_backend_pid: 276
504main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrating ==============
505main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrated (0.0318s) =====
506main: == [advisory_lock_connection] object_id: 207521880, pg_backend_pid: 276
507 upserts the widget definitions and raises no error
508# [RSpecRunTime] RSpec elapsed time: 17 minutes 6.86 seconds. Current RSS: ~1437M. Threads: 2. load average: 0.98 1.02 1.00 1/278 417
509.
510 #down
511main: == [advisory_lock_connection] object_id: 207579420, pg_backend_pid: 278
512main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrating ==============
513main: == 20240327214545 AddDevelopmentWidgetToWorkItemTypes: migrated (0.0545s) =====
514main: == [advisory_lock_connection] object_id: 207579420, pg_backend_pid: 278
515 removes definitions for widget
516# [RSpecRunTime] RSpec elapsed time: 17 minutes 9.37 seconds. Current RSS: ~1455M. Threads: 2. load average: 0.99 1.02 1.00 1/278 418
517.
518I, [2024-07-31T10:33:33.185794 #324] INFO -- : Database: 'main', Table: 'p_ci_builds_execution_configs': Lock Writes
519I, [2024-07-31T10:33:47.382798 #324] INFO -- : Database: 'main', Table: 'p_ci_build_sources': Lock Writes
520I, [2024-07-31T10:33:47.384014 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Lock timeout is set", :current_iteration=>1, :lock_timeout_in_ms=>100}
521I, [2024-07-31T10:33:47.384885 #324] INFO -- : {:method=>"with_lock_retries", :class=>"gitlab:db:lock_writes", :message=>"Migration finished", :current_iteration=>1, :lock_timeout_in_ms=>100}
522I, [2024-07-31T10:33:59.694879 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
523I, [2024-07-31T10:34:06.945969 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
524# [RSpecRunTime] Finishing example group spec/migrations/20240327214545_add_development_widget_to_work_item_types_spec.rb. It took 1 minute 45.8 seconds. Expected to take 49.12 seconds.
525# [RSpecRunTime] RSpec elapsed time: 18 minutes 2.01 seconds. Current RSS: ~1344M. Threads: 2. load average: 0.97 1.02 1.00 1/279 419
526.
527# [RSpecRunTime] Starting example group spec/migrations/20240611121101_remove_project_statistics_storage_size_and_project_id_index_spec.rb. Expected to take 27.07 seconds.
528RemoveProjectStatisticsStorageSizeAndProjectIdIndex
529 #up
530 does nothing when not on gitlab.com
531main: -- index_exists?(:project_statistics, [:storage_size, :project_id], {:name=>"index_project_statistics_on_storage_size_and_project_id"})
532main: -> 0.0151s
533main: -- quote_column_name("index_project_statistics_on_storage_size_and_project_id")
534main: -> 0.0002s
535 prepares async index removal when on gitlab.com
536# [RSpecRunTime] RSpec elapsed time: 18 minutes 19.32 seconds. Current RSS: ~1460M. Threads: 2. load average: 1.13 1.05 1.01 1/279 420
537.
538 #down
539 does nothing when not on gitlab.com
540 unprepares async index removal when on gitlab.com
541# [RSpecRunTime] RSpec elapsed time: 18 minutes 27.18 seconds. Current RSS: ~1509M. Threads: 2. load average: 1.12 1.05 1.01 1/279 421
542.
543I, [2024-07-31T10:34:51.526915 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
544# [RSpecRunTime] Finishing example group spec/migrations/20240611121101_remove_project_statistics_storage_size_and_project_id_index_spec.rb. It took 44.62 seconds. Expected to take 27.07 seconds.
545# [RSpecRunTime] RSpec elapsed time: 18 minutes 46.67 seconds. Current RSS: ~1362M. Threads: 2. load average: 1.07 1.04 1.01 1/279 422
546.
547# [RSpecRunTime] Starting example group spec/migrations/20240521090846_queue_backfill_boards_epic_board_labels_group_id_spec.rb. Expected to take 24.17 seconds.
548QueueBackfillBoardsEpicBoardLabelsGroupId
549main: == [advisory_lock_connection] object_id: 229131680, pg_backend_pid: 304
550main: == 20240521090846 QueueBackfillBoardsEpicBoardLabelsGroupId: migrating ========
551main: == 20240521090846 QueueBackfillBoardsEpicBoardLabelsGroupId: migrated (0.0635s)
552main: == [advisory_lock_connection] object_id: 229131680, pg_backend_pid: 304
553 schedules a new batched migration
554I, [2024-07-31T10:35:33.367775 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
555I, [2024-07-31T10:35:40.492928 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
556# [RSpecRunTime] Finishing example group spec/migrations/20240521090846_queue_backfill_boards_epic_board_labels_group_id_spec.rb. It took 48.41 seconds. Expected to take 24.17 seconds.
557# [RSpecRunTime] RSpec elapsed time: 19 minutes 35.14 seconds. Current RSS: ~1350M. Threads: 2. load average: 1.07 1.05 1.01 1/279 423
558.
559# [RSpecRunTime] Starting example group spec/migrations/20240607105241_queue_backfill_packages_debian_group_distribution_keys_group_id_spec.rb. Expected to take 18.74 seconds.
560QueueBackfillPackagesDebianGroupDistributionKeysGroupId
561main: == [advisory_lock_connection] object_id: 236034740, pg_backend_pid: 316
562main: == 20240607105241 QueueBackfillPackagesDebianGroupDistributionKeysGroupId: migrating
563main: == 20240607105241 QueueBackfillPackagesDebianGroupDistributionKeysGroupId: migrated (0.0608s)
564main: == [advisory_lock_connection] object_id: 236034740, pg_backend_pid: 316
565 schedules a new batched migration
566I, [2024-07-31T10:36:14.213551 #324] INFO -- : Database: 'main', Table: 'p_ci_finished_pipeline_ch_sync_events': Lock Writes
567I, [2024-07-31T10:36:21.134811 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
568# [RSpecRunTime] Finishing example group spec/migrations/20240607105241_queue_backfill_packages_debian_group_distribution_keys_group_id_spec.rb. It took 40.71 seconds. Expected to take 18.74 seconds.
569# [RSpecRunTime] RSpec elapsed time: 20 minutes 15.9 seconds. Current RSS: ~1342M. Threads: 2. load average: 1.09 1.06 1.01 1/279 424
570.
571# [RSpecRunTime] Starting example group spec/migrations/20240604205241_delete_abuse_report_records_from_notes_spec.rb. Expected to take 14.28 seconds.
572DeleteAbuseReportRecordsFromNotes
573 #up
574main: == [advisory_lock_connection] object_id: 241271720, pg_backend_pid: 328
575main: == 20240604205241 DeleteAbuseReportRecordsFromNotes: migrating ================
576main: == 20240604205241 DeleteAbuseReportRecordsFromNotes: migrated (0.0727s) =======
577main: == [advisory_lock_connection] object_id: 241271720, pg_backend_pid: 328
578 deletes abuse report notes
579# [RSpecRunTime] RSpec elapsed time: 20 minutes 30.2 seconds. Current RSS: ~1393M. Threads: 2. load average: 1.07 1.05 1.01 1/279 425
580.
581I, [2024-07-31T10:36:53.178665 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
582# [RSpecRunTime] Finishing example group spec/migrations/20240604205241_delete_abuse_report_records_from_notes_spec.rb. It took 31.94 seconds. Expected to take 14.28 seconds.
583# [RSpecRunTime] RSpec elapsed time: 20 minutes 47.9 seconds. Current RSS: ~1334M. Threads: 2. load average: 0.98 1.03 1.00 1/279 426
584.
585# [RSpecRunTime] Starting example group spec/migrations/20240624142014_queue_backfill_merge_requests_closing_issues_project_id_spec.rb. Expected to take 12.58 seconds.
586QueueBackfillMergeRequestsClosingIssuesProjectId
587main: == [advisory_lock_connection] object_id: 245459240, pg_backend_pid: 338
588main: == 20240624142014 QueueBackfillMergeRequestsClosingIssuesProjectId: migrating =
589main: == 20240624142014 QueueBackfillMergeRequestsClosingIssuesProjectId: migrated (0.0606s)
590main: == [advisory_lock_connection] object_id: 245459240, pg_backend_pid: 338
591 schedules a new batched migration
592I, [2024-07-31T10:37:21.220501 #324] INFO -- : Database: 'main', Table: 'p_ci_build_tags': Lock Writes
593# [RSpecRunTime] Finishing example group spec/migrations/20240624142014_queue_backfill_merge_requests_closing_issues_project_id_spec.rb. It took 27.81 seconds. Expected to take 12.58 seconds.
594# [RSpecRunTime] RSpec elapsed time: 21 minutes 15.76 seconds. Current RSS: ~1334M. Threads: 2. load average: 1.05 1.05 1.01 1/279 427
595.
596auto_explain log contains 967 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-migration-pg14-no-gitaly-transactions-26-26.324.main.ndjson.gz
597took 22.385534224
598auto_explain log contains 968 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-migration-pg14-no-gitaly-transactions-26-26.324.ci.ndjson.gz
599took 21.324608208
600[TEST PROF INFO] EventProf results for sql.active_record
601Total time: 12:56.517 of 21:10.939 (61.1%)
602Total events: 578975
603Top 5 slowest suites (by time):
604SwapEpicUserM...ntForSelfHosts (./spec/migrations/20230809104753_swap_epic_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb:6) – 02:14.483 (96399 / 4) of 04:12.465 (53.27%)
605SwapTimelogsN...ntForSelfHosts (./spec/migrations/20230814144045_swap_timelogs_note_id_to_bigint_for_self_hosts_spec.rb:6) – 02:09.503 (95464 / 4) of 03:59.992 (53.96%)
606EnsureDumNote...ForSelfManaged (./spec/migrations/20230816152540_ensure_dum_note_id_bigint_backfill_is_finished_for_self_managed_spec.rb:7) – 02:05.121 (90842 / 2) of 03:05.856 (67.32%)
607AddStatusToPa...MetadataCaches (./spec/migrations/20231019145202_add_status_to_packages_npm_metadata_caches_spec.rb:6) – 01:50.249 (80662 / 1) of 02:40.840 (68.55%)
608AddTimeTracki...oWorkItemTypes (./spec/migrations/20240118170849_add_time_tracking_widget_definition_to_work_item_types_spec.rb:6) – 01:27.356 (64904 / 4) of 02:12.180 (66.09%)
609Knapsack report was generated. Preview:
610{
611 "spec/migrations/20230809104753_swap_epic_user_mentions_note_id_to_bigint_for_self_hosts_spec.rb": 163.18819924799936,
612 "spec/migrations/20230814144045_swap_timelogs_note_id_to_bigint_for_self_hosts_spec.rb": 150.36106676300005,
613 "spec/migrations/20230816152540_ensure_dum_note_id_bigint_backfill_is_finished_for_self_managed_spec.rb": 97.63808097500078,
614 "spec/migrations/20231019145202_add_status_to_packages_npm_metadata_caches_spec.rb": 82.23445239499961,
615 "spec/migrations/20240118170849_add_time_tracking_widget_definition_to_work_item_types_spec.rb": 67.50614393400065,
616 "spec/migrations/20240327214545_add_development_widget_to_work_item_types_spec.rb": 53.355638215,
617 "spec/migrations/20240611121101_remove_project_statistics_storage_size_and_project_id_index_spec.rb": 25.323776090999672,
618 "spec/migrations/20240521090846_queue_backfill_boards_epic_board_labels_group_id_spec.rb": 21.615265645001273,
619 "spec/migrations/20240607105241_queue_backfill_packages_debian_group_distribution_keys_group_id_spec.rb": 18.157869310000024,
620 "spec/migrations/20240604205241_delete_abuse_report_records_from_notes_spec.rb": 14.431207295001514,
621 "spec/migrations/20240624142014_queue_backfill_merge_requests_closing_issues_project_id_spec.rb": 12.44833084200036
622}
623Knapsack global time execution for tests: 11m 46s
624Finished in 22 minutes 0 seconds (files took 1 minute 34.45 seconds to load)
62527 examples, 0 failures
626Randomized with seed 7435
627[TEST PROF INFO] Time spent in factories: 00:00.205 (0.02% of total time)
628RSpec exited with 0.
629No examples to retry, congrats!
630 Running after_script 00:09
631Running after script...
632$ source scripts/utils.sh
633$ bundle exec gem list gitlab_quality-test_tooling
634gitlab_quality-test_tooling (1.33.0)
635$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
636 Report test failures 00:02
639$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
640 Report test flakiness 00:00
642$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
643 Report test slowness 00:02
646$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
647 Report test slowness in MR note 00:00
649$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
650 Report test files close to timing out 00:01
653$ tooling/bin/push_job_metrics || true
654[job-metrics] Pushing job metrics file for the CI/CD job.
655[job-metrics] Pushed 4 CI job metric entries to InfluxDB.
656 Saving cache for successful job 00:00
657Not uploading cache ruby-gems-debian-bookworm-ruby-3.1.5-17 due to policy
658 Uploading artifacts for successful job 00:05
659Uploading artifacts...
660auto_explain/: found 3 matching artifact files and directories
661coverage/: found 5 matching artifact files and directories
662crystalball/: found 5 matching artifact files and directories
663WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
664knapsack/: found 4 matching artifact files and directories
665rspec/: found 12 matching artifact files and directories
666WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)
667log/*.log: found 13 matching artifact files and directories
668WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346437/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
669WARNING: Retrying... context=artifacts-uploader error=request redirected
670Uploading artifacts as "archive" to coordinator... 201 Created id=7471346437 responseStatus=201 Created token=glcbt-66
671Uploading artifacts...
672rspec/rspec-*.xml: found 1 matching artifact files and directories
673WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/7471346437/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
674WARNING: Retrying... context=artifacts-uploader error=request redirected
675Uploading artifacts as "junit" to coordinator... 201 Created id=7471346437 responseStatus=201 Created token=glcbt-66
676 Cleaning up project directory and file based variables 00:01
677Job succeeded