Skip to content
Snippets Groups Projects

rspec system predictive 6/20

Passed Started by
Vedant Jain
@vedant-jain03
Log timestamps in UTC.
118:06:45Running with gitlab-runner 17.7.0~pre.103.g896916a8 (896916a8)
218:06:45 on green-4.shared-gitlab-org.runners-manager.gitlab.com/default x5QiHUKw, system ID: s_b9637080a79e
318:06:45 feature flags: FF_NETWORK_PER_BUILD:true, FF_USE_FASTZIP:true, FF_TIMESTAMPS:true
4 18:06:45 Preparing the "docker+machine" executor 00:14
518:06:45Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.3.7-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.6-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
618:06:48Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...
718:06:48Authenticating with credentials from job payload (GitLab Registry)
818:06:48Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...
918:06:49Using 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 ...
1018:06:49WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0 is already created. Ignoring.
1118:06:49WARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0 is already created. Ignoring.
1218:06:49Starting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0...
1318:06:49Authenticating with credentials from job payload (GitLab Registry)
1418:06:49Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0 ...
1518:06:53Using docker image sha256:f9eec8a3cadee4fcc9706eb472f243abd0229ef6ee5bcabc905cdc95323054d9 for registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0 with digest registry.gitlab.com/gitlab-org/gitlab-build-images@sha256:670a6e27ed3606e57d4946906eba86847a99aa5e42f9a3717af982467cdb236d ...
1618:06:54Starting service redis:6.0-alpine...
1718:06:54Pulling docker image redis:6.0-alpine ...
1818:06:57Using docker image sha256:19150f5e615e35503bf28b1e8f215ed641da1460a168f39038c754d07315d4c6 for redis:6.0-alpine with digest redis@sha256:2b35fc7d2908e25aa6aa197f97882c8a67829d3b106ad5ea5c8028f816f26aa8 ...
1918:06:57Waiting for services to be up and running (timeout 30 seconds)...
2018:06:59Authenticating with credentials from job payload (GitLab Registry)
2118:06:59Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.3.7-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.6-git-2.45-lfs-2.9-chrome-123-yarn-1.22-graphicsmagick-1.3.36 ...
2218:06:59Using docker image sha256:a45f075f58a88b1d9b2648f62bc1d3fe67b7141448c81ee7ecb8fe8582298f50 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.3.7-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.6-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.3.7-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:f00994f76a386288e3b7cfcc4efd1c46c98d1b3f2a0eda55dd31aac29933f3a8 ...
23 18:06:59 Preparing environment 00:00
2418:06:59Running on runner-x5qihukw-project-64977230-concurrent-0 via runner-x5qihukw-shared-gitlab-org-1740502399-b3b5831c...
25 18:06:59 Getting source from Git repository 00:01
2618:07:00Skipping Git repository setup
2718:07:00Skipping Git checkout
2818:07:00Skipping Git submodules setup
29 18:07:00 Restoring cache 00:01
3018:07:00Checking cache for ruby-gems-debian-bookworm-ruby-3.3.7-gemfile-Gemfile-non_protected...
3118:07:01WARNING: file does not exist
3218:07:01Failed to extract cache
33 18:07:01 Downloading artifacts 00:40
3418:07:01Downloading artifacts for clone-gitlab-repo (9241535409)...
3518:07:07Downloading artifacts from coordinator... ok host=storage.googleapis.com id=9241535409 responseStatus=200 OK token=glcbt-66
3618:07:17Downloading artifacts for compile-test-assets (9241535517)...
3718:07:21Downloading artifacts from coordinator... ok host=storage.googleapis.com id=9241535517 responseStatus=200 OK token=glcbt-66
3818:07:23Downloading artifacts for detect-tests (9241535539)...
3918:07:24Downloading artifacts from coordinator... ok host=storage.googleapis.com id=9241535539 responseStatus=200 OK token=glcbt-66
4018:07:24Downloading artifacts for retrieve-tests-metadata (9241535555)...
4118:07:24Downloading artifacts from coordinator... ok host=storage.googleapis.com id=9241535555 responseStatus=200 OK token=glcbt-66
4218:07:24Downloading artifacts for setup-test-env (9241535525)...
4318:07:31Downloading artifacts from coordinator... ok host=storage.googleapis.com id=9241535525 responseStatus=200 OK token=glcbt-66
44 18:07:41 Executing "step_script" stage of the job script
4518:07:41Using docker image sha256:a45f075f58a88b1d9b2648f62bc1d3fe67b7141448c81ee7ecb8fe8582298f50 for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bookworm-ruby-3.3.7-golang-1.23-rust-1.73-node-20.12-postgresql-14:rubygems-3.6-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.3.7-golang-1.23-rust-1.73-node-20.12-postgresql-14@sha256:f00994f76a386288e3b7cfcc4efd1c46c98d1b3f2a0eda55dd31aac29933f3a8 ...
4618:07:43$ echo $FOSS_ONLY
4718:07:43$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb
4818:07:43$ export GOPATH=$CI_PROJECT_DIR/.go
4918:07:43$ mkdir -p $GOPATH
5018:07:43$ source scripts/utils.sh
5118:07:43$ log_disk_usage "true"
5218:07:43*******************************************************
5318:07:43This runner currently has 17G free disk space.
5418:07:43*******************************************************
55 18:07:43 Disk usage detail 00:03
5618:07:43df -h
5718:07:43Filesystem Size Used Avail Use% Mounted on
5818:07:43overlay 46G 29G 17G 65% /
5918:07:43tmpfs 64M 0 64M 0% /dev
6018:07:43shm 256M 0 256M 0% /dev/shm
6118:07:43/dev/sda1 46G 29G 17G 65% /cache
6218:07:43tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
6318:07:43tmpfs 3.9G 0 3.9G 0% /proc/acpi
6418:07:43tmpfs 3.9G 0 3.9G 0% /proc/scsi
6518:07:43tmpfs 3.9G 0 3.9G 0% /sys/firmware
6618:07:43du -h -d 1
6718:07:437.4M ./workhorse
6818:07:43148K ./bin
6918:07:431.2M ./.gitlab
7018:07:43233M ./.git
7118:07:434.0K ./builds
7218:07:4329M ./lib
7318:07:438.0K ./.vscode
7418:07:43588K ./storybook
7518:07:4324K ./log
7618:07:432.1M ./data
7718:07:4311M ./qa
7818:07:433.0M ./.rubocop_todo
7918:07:4313M ./vendor
8018:07:43661M ./public
8118:07:4363M ./doc
8218:07:43508K ./danger
8318:07:4340K ./rspec
8418:07:43580K ./tooling
8518:07:44154M ./ee
8618:07:441.4M ./knapsack
8718:07:4468K ./patches
8818:07:445.7M ./changelogs
8918:07:4420K ./haml_lint
9018:07:4428K ./metrics_server
9118:07:44116K ./keeps
9218:07:4436K ./shared
9318:07:4444K ./generator_templates
9418:07:441.3M ./scripts
9518:07:44773M ./tmp
9618:07:44132M ./spec
9718:07:4420K ./file_hooks
9818:07:4436K ./crystalball
9918:07:4416K ./sidekiq_cluster
10018:07:444.3M ./gems
10118:07:441.2M ./fixtures
10218:07:44972K ./rubocop
10318:07:444.0K ./.go
10418:07:4436M ./db
10518:07:4412K ./.github
10618:07:4464K ./.eslint_todo
10718:07:44137M ./locale
10818:07:4420M ./config
10918:07:4489M ./app
11018:07:4420K ./.lefthook
11118:07:442.4G .
11218:07:44$ source scripts/prepare_build.sh
113 18:07:44 Installing gems 05:40
151318:13:24Using SEC decomposed database config (config/database.yml.decomposed-sec-postgresql)
151418:13:24Geo DB won't be set up.
151518:13:24Embedding DB won't be set up.
1516 18:13:24 Setting up DBs 02:17
152918:15:41$ source ./scripts/rspec_helpers.sh
153018:15:41$ run_timed_command "gem install knapsack --no-document"
153118:15:40$ gem install knapsack --no-document
153218:15:42Successfully installed knapsack-4.0.0
153318:15:421 gem installed
153418:15:41==> 'gem install knapsack --no-document' succeeded in 1 seconds.
153518:15:42$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"
1536 18:15:42 Spawning Gitaly 00:05
154018:15:47$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"
154118:15:47$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"
154218:15:47$ tooling/bin/create_job_metrics_file || true
154318:15:51[job-metrics] Feature disabled because CI_JOB_METRICS_ENABLED is not set to true.
154418:15:51$ rspec_section rspec_parallelized_job "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~level:background_migration --tag ~click_house --tag ~real_ai_request"
1545 18:15:51 RSpec 16:50
154618:15:51[18:15:51] Starting rspec_parallelized_job
154718:15:42RETRY_FAILED_TESTS_IN_NEW_PROCESS: true
154818:15:51KNAPSACK_GENERATE_REPORT: true
154918:15:51FLAKY_RSPEC_GENERATE_REPORT: true
155018:15:51KNAPSACK_TEST_FILE_PATTERN: spec/{features}{,/**/}*_spec.rb
155118:15:51KNAPSACK_LOG_LEVEL: debug
155218:15:51KNAPSACK_REPORT_PATH: knapsack/rspec_system_predictive_6_20_64977230_report.json
155318:15:51FLAKY_RSPEC_SUITE_REPORT_PATH: rspec/flaky/report-suite.json
155418:15:51FLAKY_RSPEC_REPORT_PATH: rspec/flaky/all_rspec_system_predictive_6_20_64977230_report.json
155518:15:51NEW_FLAKY_RSPEC_REPORT_PATH: rspec/flaky/new_rspec_system_predictive_6_20_64977230_report.json
155618:15:51RSPEC_SKIPPED_TESTS_REPORT_PATH: rspec/skipped_tests-9241720406.txt
155718:15:51CRYSTALBALL:
155818:15:51RSPEC_TESTS_MAPPING_ENABLED: true
155918:15:51RSPEC_TESTS_FILTER_FILE: rspec/matching_tests-foss.txt
156018:15:51Shell set options (set -o) enabled:
156118:15:51braceexpand on
156218:15:51hashall on
156318:15:51interactive-comments on
156418:15:51pipefail on
156518:15:59Knapsack report generator started!
156618:17:28Run options: exclude {:quarantine=>true, :level=>"background_migration", :click_house=>true, :real_ai_request=>true}
156718:17:28# [RSpecRunTime] Starting RSpec timer...
156818:17:28[TEST PROF INFO] EventProf enabled (sql.active_record)
156918:15:51unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
157018:17:28unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
157118:17:28unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
157218:17:46Test environment set up in 3.743624043 seconds
157318:17:47# [RSpecRunTime] Starting example group spec/features/work_items/work_items_list_filters_spec.rb. Expected to take 6 minutes 5.16 seconds.
157418:17:47Work items list filters
157518:17:47Starting the Capybara driver server...
157618:18:01 for signed in user
157718:18:01 assignee
157818:18:02Capybara starting Puma...
157918:18:02* Version 6.5.0, codename: Sky's Version
158018:18:02* Min threads: 0, max threads: 4
158118:18:02* Listening on unix:///tmp/20250225-52360-qozupg
158218:19:15 filters
158318:19:15 author
158418:19:59 filters
158518:19:59# [RSpecRunTime] RSpec elapsed time: 2 minutes 31.03 seconds. Current RSS: ~1382M. Threads: 14. load average: 0.83 1.22 1.57 1/377 52772
158618:19:59.
158718:19:59 confidential
158818:20:37 filters
158918:20:37# [RSpecRunTime] RSpec elapsed time: 3 minutes 8.96 seconds. Current RSS: ~1380M. Threads: 13. load average: 0.97 1.20 1.55 1/377 52782
159018:20:37.
159118:20:37 group
159218:21:12 filters
159318:21:12# [RSpecRunTime] RSpec elapsed time: 3 minutes 44.6 seconds. Current RSS: ~1383M. Threads: 14. load average: 0.84 1.14 1.52 1/377 52789
159418:21:12.
159518:21:12 label
159618:22:01 filters
159718:22:01# [RSpecRunTime] RSpec elapsed time: 4 minutes 33.21 seconds. Current RSS: ~1392M. Threads: 14. load average: 0.93 1.13 1.49 1/377 52804
159818:22:01.
159918:22:01 milestone
160018:22:51 filters
160118:22:51# [RSpecRunTime] RSpec elapsed time: 5 minutes 23.65 seconds. Current RSS: ~1401M. Threads: 14. load average: 0.83 1.06 1.45 1/377 52820
160218:22:51.
160318:22:51 my-reaction
160418:23:36 filters
160518:23:36# [RSpecRunTime] RSpec elapsed time: 6 minutes 8.45 seconds. Current RSS: ~1401M. Threads: 13. load average: 0.99 1.07 1.43 1/376 52836
160618:23:36.
160718:23:36 search within
160818:24:14 filters
160918:24:14# [RSpecRunTime] RSpec elapsed time: 6 minutes 46.54 seconds. Current RSS: ~1387M. Threads: 13. load average: 0.72 1.00 1.40 1/376 52849
161018:24:14.
161118:24:16# [RSpecRunTime] Finishing example group spec/features/work_items/work_items_list_filters_spec.rb. It took 6 minutes 28.4 seconds. Expected to take 6 minutes 5.16 seconds.
161218:24:16# [RSpecRunTime] RSpec elapsed time: 6 minutes 48.17 seconds. Current RSS: ~1385M. Threads: 13. load average: 0.74 1.00 1.39 1/376 52850
161318:24:16.
161418:24:18auto_explain log contains 949 entries for main, writing to /builds/vedant-jain03/gitlab/auto_explain/rspec-system-predictive-6-20.52360.main.ndjson.gz
161518:24:18took 1.533474195
161618:24:20auto_explain log contains 949 entries for ci, writing to /builds/vedant-jain03/gitlab/auto_explain/rspec-system-predictive-6-20.52360.ci.ndjson.gz
161718:24:20took 1.548788773
161818:24:22auto_explain log contains 950 entries for sec, writing to /builds/vedant-jain03/gitlab/auto_explain/rspec-system-predictive-6-20.52360.sec.ndjson.gz
161918:24:22took 1.532904295
162018:24:22[TEST PROF INFO] EventProf results for sql.active_record
162118:24:22Total time: 00:23.294 of 06:28.475 (6.0%)
162218:24:22Total events: 5997
162318:24:22Top 5 slowest suites (by time):
162418:24:22Work items list filters (./spec/features/work_items/work_items_list_filters_spec.rb:5) – 00:23.294 (5997 / 8) of 06:28.475 (6.0%)
162518:24:22Knapsack report was generated. Preview:
162618:24:22{
162718:24:22 "spec/features/work_items/work_items_list_filters_spec.rb": 388.4007423660005
162818:24:22}
162918:24:22Knapsack global time execution for tests: 06m 28s
163018:24:22Finished in 6 minutes 54 seconds (files took 1 minute 33.12 seconds to load)
163118:24:228 examples, 0 failures
163218:24:22Randomized with seed 47037
163318:24:30Failed to write to log, write log/workhorse-test.log: file already closed
163418:24:31[TEST PROF INFO] Time spent in factories: 00:08.056 (1.91% of total time)
163518:24:31RSpec exited with 0.
163618:24:31No examples to retry, congrats!
1637 18:24:31 Running after_script 00:09
163818:24:32Running after script...
163918:24:32$ source scripts/utils.sh
164018:24:32$ log_disk_usage
164118:24:32*******************************************************
164218:24:32This runner currently has 15G free disk space.
164318:24:32*******************************************************
1644 18:24:32 Disk usage detail 00:03
170418:24:35$ bundle exec gem list gitlab_quality-test_tooling
170518:24:37gitlab_quality-test_tooling (2.8.0)
170618:24:37$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command
1707 18:24:37 Report test failures 00:00
170918:24:37$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command
1710 18:24:37 Report test flakiness 00:00
171218:24:37$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command
1713 18:24:37 Report test slowness 00:00
171518:24:37$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command
1716 18:24:37 Report test slowness in MR note 00:00
171818:24:37$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command
1719 18:24:37 Report test files close to timing out 00:00
172118:24:37$ tooling/bin/push_job_metrics || true
172218:24:39[job-metrics] Feature disabled because CI_JOB_METRICS_ENABLED is not set to true.
172318:24:39$ scripts/minify-simplecov-resultsets.rb
172418:24:40Minified coverage/rspec-system-predictive-6-20-64977230/.resultset.json: 17477KB -> 5668KB (-68%)
1725 18:24:40 Saving cache for successful job 00:01
172618:24:40Not uploading cache ruby-gems-debian-bookworm-ruby-3.3.7-gemfile-Gemfile-non_protected due to policy
1727 18:24:41 Uploading artifacts for successful job 00:07
172818:24:43Uploading artifacts...
172918:24:43auto_explain/: found 4 matching artifact files and directories
173018:24:43coverage/: found 5 matching artifact files and directories
173118:24:43crystalball/: found 2 matching artifact files and directories
173218:24:43WARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/vedant-jain03/gitlab)
173318:24:43knapsack/: found 4 matching artifact files and directories
173418:24:43rspec/: found 16 matching artifact files and directories
173518:24:43WARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/vedant-jain03/gitlab)
173618:24:43log/*.log: found 14 matching artifact files and directories
173718:24:43WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/9241720406/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d new-url=https://gitlab.com
173818:24:43WARNING: Retrying... context=artifacts-uploader error=request redirected
173918:24:46Uploading artifacts as "archive" to coordinator... 201 Created id=9241720406 responseStatus=201 Created token=glcbt-66
174018:24:46Uploading artifacts...
174118:24:46rspec/rspec-*.xml: found 1 matching artifact files and directories
174218:24:46WARNING: Upload request redirected location=https://gitlab.com/api/v4/jobs/9241720406/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d new-url=https://gitlab.com
174318:24:46WARNING: Retrying... context=artifacts-uploader error=request redirected
174418:24:47Uploading artifacts as "junit" to coordinator... 201 Created id=9241720406 responseStatus=201 Created token=glcbt-66
1745 18:24:48 Cleaning up project directory and file based variables 00:00
174618:24:56Job succeeded