2025-02-24T17:23:48.933610Z 00O [0KRunning with gitlab-runner 17.7.0~pre.103.g896916a8 (896916a8)[0;m
2025-02-24T17:23:48.933680Z 00O [0K on green-4.private.runners-manager.gitlab.com/gitlab.com/gitlab-org rpvz2FF9, system ID: s_d704414ba02a[0;m
2025-02-24T17:23:48.933780Z 00O [0K feature flags: FF_NETWORK_PER_BUILD:true, FF_USE_FASTZIP:true, FF_TIMESTAMPS:true[0;m
2025-02-24T17:23:48.933920Z 00O [0K[36;1mResolving secrets[0;m[0;m
2025-02-24T17:23:48.935540Z 00O section_start:1740417828:prepare_executor
2025-02-24T17:23:48.935560Z 00O+[0K[0K[36;1mPreparing the "docker+machine" executor[0;m[0;m
2025-02-24T17:23:48.252440Z 00O [0KUsing 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 ...[0;m
2025-02-24T17:23:50.820785Z 00O [0KStarting service registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1...[0;m
2025-02-24T17:23:50.822550Z 00O [0KAuthenticating with credentials from job payload (GitLab Registry)[0;m
2025-02-24T17:23:50.822571Z 00O [0KPulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:postgres-14-pgvector-0.4.1 ...[0;m
2025-02-24T17:23:51.897820Z 00O [0KUsing 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 ...[0;m
2025-02-24T17:23:51.556294Z 00O [0;33mWARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0 is already created. Ignoring.[0;m
2025-02-24T17:23:51.556537Z 00O [0;33mWARNING: Service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0 is already created. Ignoring.[0;m
2025-02-24T17:23:51.556590Z 00O [0KStarting service registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0...[0;m
2025-02-24T17:23:51.558514Z 00O [0KAuthenticating with credentials from job payload (GitLab Registry)[0;m
2025-02-24T17:23:51.558533Z 00O [0KPulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images:redis-cluster-6.0 ...[0;m
2025-02-24T17:23:51.871442Z 00O [0KUsing 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 ...[0;m
2025-02-24T17:23:52.305651Z 00O [0KStarting service redis:6.0-alpine...[0;m
2025-02-24T17:23:52.307627Z 00O [0KPulling docker image redis:6.0-alpine ...[0;m
2025-02-24T17:23:52.774028Z 00O [0KUsing docker image sha256:19150f5e615e35503bf28b1e8f215ed641da1460a168f39038c754d07315d4c6 for redis:6.0-alpine with digest redis@sha256:2b35fc7d2908e25aa6aa197f97882c8a67829d3b106ad5ea5c8028f816f26aa8 ...[0;m
2025-02-24T17:23:53.205024Z 00O [0KWaiting for services to be up and running (timeout 30 seconds)...[0;m
2025-02-24T17:23:56.856662Z 00O [0KAuthenticating with credentials from job payload (GitLab Registry)[0;m
2025-02-24T17:23:56.856680Z 00O [0KPulling 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 ...[0;m
2025-02-24T17:23:57.118691Z 00O [0KUsing 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 ...[0;m
2025-02-24T17:23:57.118781Z 00O section_end:1740417837:prepare_executor
2025-02-24T17:23:57.118785Z 00O+[0Ksection_start:1740417837:prepare_script
2025-02-24T17:23:57.118901Z 00O+[0K[0K[36;1mPreparing environment[0;m[0;m
2025-02-24T17:23:57.567590Z 01O Running on runner-rpvz2ff9-project-278964-concurrent-0 via runner-rpvz2ff9-private-1740406346-e5493e49...
2025-02-24T17:23:57.714411Z 00O section_end:1740417837:prepare_script
2025-02-24T17:23:57.714417Z 00O+[0Ksection_start:1740417837:get_sources
2025-02-24T17:23:57.715504Z 00O+[0K[0K[36;1mGetting source from Git repository[0;m[0;m
2025-02-24T17:23:58.456237Z 01O [32;1mSkipping Git repository setup[0;m
2025-02-24T17:23:58.458765Z 01O [32;1mSkipping Git checkout[0;m
2025-02-24T17:23:58.458769Z 01O [32;1mSkipping Git submodules setup[0;m
2025-02-24T17:23:58.622271Z 00O section_end:1740417838:get_sources
2025-02-24T17:23:58.622277Z 00O+[0Ksection_start:1740417838:restore_cache
2025-02-24T17:23:58.624800Z 00O+[0K[0K[36;1mRestoring cache[0;m[0;m
2025-02-24T17:23:59.207081Z 01O [32;1mChecking cache for ruby-gems-debian-bookworm-ruby-3.3.7-gemfile-Gemfile-21...[0;m
2025-02-24T17:23:59.344624Z 01E cache.zip is up to date [0;m
2025-02-24T17:24:08.629243Z 01O [32;1mSuccessfully extracted cache[0;m
2025-02-24T17:24:14.992136Z 00O section_end:1740417854:restore_cache
2025-02-24T17:24:14.992142Z 00O+[0Ksection_start:1740417854:download_artifacts
2025-02-24T17:24:14.993246Z 00O+[0K[0K[36;1mDownloading artifacts[0;m[0;m
2025-02-24T17:24:15.552205Z 01O [32;1mDownloading artifacts for clone-gitlab-repo (9229131147)...[0;m
2025-02-24T17:24:21.419139Z 01E Downloading artifacts from coordinator... ok [0;m host[0;m=storage.googleapis.com id[0;m=9229131147 responseStatus[0;m=200 OK token[0;m=glcbt-66
2025-02-24T17:24:30.285277Z 01O [32;1mDownloading artifacts for compile-test-assets (9229131452)...[0;m
2025-02-24T17:24:33.361977Z 01E Downloading artifacts from coordinator... ok [0;m host[0;m=storage.googleapis.com id[0;m=9229131452 responseStatus[0;m=200 OK token[0;m=glcbt-66
2025-02-24T17:24:36.358630Z 01O [32;1mDownloading artifacts for db:setup pg14 (9229131450)...[0;m
2025-02-24T17:24:37.130240Z 01E Downloading artifacts from coordinator... ok [0;m host[0;m=storage.googleapis.com id[0;m=9229131450 responseStatus[0;m=200 OK token[0;m=glcbt-66
2025-02-24T17:24:37.867210Z 01O [32;1mDownloading artifacts for detect-tests (9229131497)...[0;m
2025-02-24T17:24:37.689092Z 01E Downloading artifacts from coordinator... ok [0;m host[0;m=storage.googleapis.com id[0;m=9229131497 responseStatus[0;m=200 OK token[0;m=glcbt-66
2025-02-24T17:24:37.703281Z 01O [32;1mDownloading artifacts for retrieve-tests-metadata (9229131509)...[0;m
2025-02-24T17:24:38.298990Z 01E Downloading artifacts from coordinator... ok [0;m host[0;m=storage.googleapis.com id[0;m=9229131509 responseStatus[0;m=200 OK token[0;m=glcbt-66
2025-02-24T17:24:38.312229Z 01O [32;1mDownloading artifacts for setup-test-env (9229131457)...[0;m
2025-02-24T17:24:44.746220Z 01E Downloading artifacts from coordinator... ok [0;m host[0;m=storage.googleapis.com id[0;m=9229131457 responseStatus[0;m=200 OK token[0;m=glcbt-66
2025-02-24T17:24:56.526010Z 00O section_end:1740417896:download_artifacts
2025-02-24T17:24:56.526060Z 00O+[0Ksection_start:1740417896:step_script
2025-02-24T17:24:56.537160Z 00O+[0K[0K[36;1mExecuting "step_script" stage of the job script[0;m[0;m
2025-02-24T17:24:56.572820Z 00O [0KUsing 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 ...[0;m
2025-02-24T17:24:56.699320Z 01O [32;1m$ echo $FOSS_ONLY[0;m
2025-02-24T17:24:56.699325Z 01O
2025-02-24T17:24:56.699326Z 01O [32;1m$ [ "$FOSS_ONLY" = "1" ] && rm -rf ee/ qa/spec/ee/ qa/qa/specs/features/ee/ qa/qa/ee/ qa/qa/ee.rb[0;m
2025-02-24T17:24:56.699406Z 01O [32;1m$ export GOPATH=$CI_PROJECT_DIR/.go[0;m
2025-02-24T17:24:56.699408Z 01O [32;1m$ mkdir -p $GOPATH[0;m
2025-02-24T17:24:56.701477Z 01O [32;1m$ source scripts/utils.sh[0;m
2025-02-24T17:24:56.702928Z 01O [32;1m$ log_disk_usage "true"[0;m
2025-02-24T17:24:56.705602Z 01O *******************************************************
2025-02-24T17:24:56.705606Z 01O This runner currently has 71G free disk space.
2025-02-24T17:24:56.705608Z 01O *******************************************************
2025-02-24T17:24:56.706808Z 01O section_start:1740417896:log_disk_usage[collapsed=true]
[0KDisk usage detail
2025-02-24T17:24:56.706843Z 01O df -h
2025-02-24T17:24:56.708322Z 01O Filesystem Size Used Avail Use% Mounted on
2025-02-24T17:24:56.708339Z 01O overlay 95G 24G 71G 26% /
2025-02-24T17:24:56.708341Z 01O tmpfs 64M 0 64M 0% /dev
2025-02-24T17:24:56.708343Z 01O shm 64M 0 64M 0% /dev/shm
2025-02-24T17:24:56.708344Z 01O /dev/sda1 95G 24G 71G 26% /cache
2025-02-24T17:24:56.708346Z 01O tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
2025-02-24T17:24:56.708365Z 01O du -h -d 1
2025-02-24T17:24:56.711112Z 01O 7.4M ./workhorse
2025-02-24T17:24:56.711199Z 01O 148K ./bin
2025-02-24T17:24:56.711956Z 01O 1.2M ./.gitlab
2025-02-24T17:24:56.712195Z 01O 216M ./.git
2025-02-24T17:24:56.712204Z 01O 4.0K ./builds
2025-02-24T17:24:56.736456Z 01O 29M ./lib
2025-02-24T17:24:56.736462Z 01O 8.0K ./.vscode
2025-02-24T17:24:56.736582Z 01O 588K ./storybook
2025-02-24T17:24:56.736683Z 01O 20K ./log
2025-02-24T17:24:56.738120Z 01O 2.1M ./data
2025-02-24T17:24:56.748357Z 01O 11M ./qa
2025-02-24T17:24:56.749237Z 01O 3.0M ./.rubocop_todo
2025-02-24T17:24:56.972522Z 01O 858M ./vendor
2025-02-24T17:24:57.419600Z 01O 660M ./public
2025-02-24T17:24:57.224550Z 01O 63M ./doc
2025-02-24T17:24:57.232700Z 01O 508K ./danger
2025-02-24T17:24:57.233920Z 01O 32K ./rspec
2025-02-24T17:24:57.241900Z 01O 580K ./tooling
2025-02-24T17:24:57.180153Z 01O 154M ./ee
2025-02-24T17:24:57.180158Z 01O 1.4M ./knapsack
2025-02-24T17:24:57.180164Z 01O 68K ./patches
2025-02-24T17:24:57.180184Z 01O 5.7M ./changelogs
2025-02-24T17:24:57.180365Z 01O 20K ./haml_lint
2025-02-24T17:24:57.180369Z 01O 28K ./metrics_server
2025-02-24T17:24:57.180456Z 01O 116K ./keeps
2025-02-24T17:24:57.180617Z 01O 36K ./shared
2025-02-24T17:24:57.180807Z 01O 44K ./generator_templates
2025-02-24T17:24:57.181775Z 01O 1.3M ./scripts
2025-02-24T17:24:57.190762Z 01O 773M ./tmp
2025-02-24T17:24:57.289132Z 01O 132M ./spec
2025-02-24T17:24:57.289135Z 01O 20K ./file_hooks
2025-02-24T17:24:57.289279Z 01O 36K ./crystalball
2025-02-24T17:24:57.289280Z 01O 16K ./sidekiq_cluster
2025-02-24T17:24:57.294920Z 01O 4.3M ./gems
2025-02-24T17:24:57.295045Z 01O 1.2M ./fixtures
2025-02-24T17:24:57.296390Z 01O 972K ./rubocop
2025-02-24T17:24:57.296393Z 01O 4.0K ./.go
2025-02-24T17:24:57.319916Z 01O 36M ./db
2025-02-24T17:24:57.319919Z 01O 12K ./.github
2025-02-24T17:24:57.319919Z 01O 64K ./.eslint_todo
2025-02-24T17:24:57.321179Z 01O 137M ./locale
2025-02-24T17:24:57.335079Z 01O 20M ./config
2025-02-24T17:24:57.417676Z 01O 89M ./app
2025-02-24T17:24:57.417680Z 01O 20K ./.lefthook
2025-02-24T17:24:57.417866Z 01O 3.2G .
2025-02-24T17:24:57.420120Z 01O section_end:1740417897:log_disk_usage
[0K
2025-02-24T17:24:57.655752Z 01O [32;1m$ source scripts/prepare_build.sh[0;m
2025-02-24T17:24:57.659804Z 01O section_start:1740417897:bundle-install[collapsed=true]
[0KInstalling gems
2025-02-24T17:24:57.773649Z 01O 3.6.2
2025-02-24T17:24:57.993799Z 01O Bundler version 2.6.2
2025-02-24T17:24:58.698566Z 01O production:development
2025-02-24T17:24:59.142611Z 01O Settings are listed in order of priority. The top value will be used.
2025-02-24T17:24:59.142614Z 01O clean
2025-02-24T17:24:59.142614Z 01O Set for your local app (/builds/gitlab-org/gitlab/.bundle/config): true
2025-02-24T17:24:59.142615Z 01O
2025-02-24T17:24:59.142616Z 01O frozen
2025-02-24T17:24:59.142616Z 01O Set via BUNDLE_FROZEN: true
2025-02-24T17:24:59.142617Z 01O
2025-02-24T17:24:59.142617Z 01O gemfile
2025-02-24T17:24:59.142618Z 01O Set via BUNDLE_GEMFILE: "/builds/gitlab-org/gitlab/Gemfile"
2025-02-24T17:24:59.142619Z 01O
2025-02-24T17:24:59.142843Z 01O install_flags
2025-02-24T17:24:59.142844Z 01O Set via BUNDLE_INSTALL_FLAGS: "--jobs=$(nproc) --retry=3"
2025-02-24T17:24:59.142845Z 01O
2025-02-24T17:24:59.142845Z 01O path
2025-02-24T17:24:59.142846Z 01O Set for your local app (/builds/gitlab-org/gitlab/.bundle/config): "/builds/gitlab-org/gitlab/vendor"
2025-02-24T17:24:59.142847Z 01O
2025-02-24T17:24:59.142847Z 01O without
2025-02-24T17:24:59.142848Z 01O Set via BUNDLE_WITHOUT: [:production, :development]
2025-02-24T17:24:59.142849Z 01O
2025-02-24T17:24:59.148472Z 01E [0;32m$ bundle install --jobs=$(nproc) --retry=3
2025-02-24T17:24:59.148478Z 01E [0mDon't run Bundler as root. Installing your bundle as root will break this
2025-02-24T17:24:59.654971Z 01E application for all non-root users on this machine.
2025-02-24T17:24:59.866286Z 01O Patching bundler with bundler-checksum...
2025-02-24T17:25:00.931474Z 01O Bundle complete! 366 Gemfile dependencies, 682 gems now installed.
2025-02-24T17:25:00.931480Z 01O Gems in the groups 'production' and 'development' were not installed.
2025-02-24T17:25:00.931666Z 01O Bundled gems are installed into `./vendor`
2025-02-24T17:25:00.987307Z 01O 6 installed gems you directly depend on are looking for funding.
2025-02-24T17:25:00.987317Z 01O Run `bundle fund` for details
2025-02-24T17:25:01.297000Z 01E [0;32m==> 'bundle install --jobs=$(nproc) --retry=3 ' succeeded in 2 seconds.
2025-02-24T17:25:01.297500Z 01E [0m[0;32m$ bundle pristine pg
2025-02-24T17:25:03.166222Z 01O Patching bundler with bundler-checksum...
2025-02-24T17:25:03.981333Z 01O Installing pg 1.5.9 with native extensions
2025-02-24T17:25:02.639289Z 01E [0m[0;32m==> 'bundle pristine pg' succeeded in 15 seconds.
2025-02-24T17:25:17.176138Z 01O section_end:1740417917:bundle-install
[0K
2025-02-24T17:25:17.191260Z 01O Using SEC decomposed database config (config/database.yml.decomposed-sec-postgresql)
2025-02-24T17:25:17.175402Z 01E [0m[0;33mGeo DB won't be set up.
2025-02-24T17:25:17.192925Z 01E [0m[0;33mEmbedding DB won't be set up.
2025-02-24T17:25:17.203473Z 01O section_start:1740417917:setup-db[collapsed=true]
[0KSetting up DBs
2025-02-24T17:25:17.203919Z 01O Found pg_dumpall.sql, applying!
2025-02-24T17:25:17.194671Z 01E [0mERROR: role "postgres" already exists
2025-02-24T17:25:41.137215Z 01O section_end:1740417941:setup-db
[0K
2025-02-24T17:25:41.137226Z 01O [32;1m$ source ./scripts/rspec_helpers.sh[0;m
2025-02-24T17:25:41.137645Z 01O [32;1m$ run_timed_command "gem install knapsack --no-document"[0;m
2025-02-24T17:25:41.139138Z 01E [0;32m$ gem install knapsack --no-document
2025-02-24T17:25:41.935336Z 01O Successfully installed knapsack-4.0.0
2025-02-24T17:25:41.935341Z 01O 1 gem installed
2025-02-24T17:25:41.139142Z 01E [0m[0;32m==> 'gem install knapsack --no-document' succeeded in 0 seconds.
2025-02-24T17:25:41.942405Z 01O [32;1m$ section_start "gitaly-test-spawn" "Spawning Gitaly"; scripts/gitaly-test-spawn; section_end "gitaly-test-spawn"[0;m
2025-02-24T17:25:41.943757Z 01O section_start:1740417941:gitaly-test-spawn[collapsed=true]
[0KSpawning Gitaly
2025-02-24T17:25:45.292452Z 01O Trying to connect to gitaly: ...... OK
2025-02-24T17:25:46.409075Z 01O Trying to connect to gitaly2: ........... OK
2025-02-24T17:25:46.409082Z 01O Starting Praefect with in-memory election strategyTrying to connect to praefect: ..... OK
2025-02-24T17:25:46.978219Z 01O section_end:1740417946:gitaly-test-spawn
[0K
2025-02-24T17:25:46.978351Z 01O [32;1m$ export RSPEC_SKIPPED_TESTS_REPORT_PATH="rspec/skipped_tests-${CI_JOB_ID}.txt"[0;m
2025-02-24T17:25:46.978356Z 01O [32;1m$ export RSPEC_RETRIED_TESTS_REPORT_PATH="rspec/retried_tests-${CI_JOB_ID}.txt"[0;m
2025-02-24T17:25:46.978358Z 01O [32;1m$ tooling/bin/create_job_metrics_file || true[0;m
2025-02-24T17:25:50.650636Z 01O [job-metrics] Creating the job metrics file for the CI/CD job.
2025-02-24T17:25:50.664761Z 01O [32;1m$ rspec_section rspec_fail_fast "${MATCHING_TESTS_PATH}" "--fail-fast=${RSPEC_FAIL_FAST_THRESHOLD} --tag ~quarantine --tag ~zoekt --tag ~click_house --tag ~real_ai_request"[0;m
2025-02-24T17:25:50.673623Z 01O section_start:1740417950:rspec[collapsed=false]
[0KRSpec
2025-02-24T17:25:41.942347Z 01E [0m[0;33mRunning RSpec command: bin/rspec -Ispec -rspec_helper --color --failure-exit-code 1 --error-exit-code 2 --format documentation --format Support::Formatters::JsonFormatter --out rspec/rspec-9229132014.json --format RspecJunitFormatter --out rspec/rspec-9229132014.xml --fail-fast=20 --tag ~quarantine --tag ~zoekt --tag ~click_house --tag ~real_ai_request spec/scripts/internal_events/cli_spec.rb spec/support_specs/matchers/internal_events_matchers_spec.rb
2025-02-24T17:27:08.129023Z 01O Run options: exclude {:quarantine=>true, :zoekt=>true, :click_house=>true, :real_ai_request=>true}
2025-02-24T17:27:08.130632Z 01O
2025-02-24T17:27:08.130635Z 01O # [RSpecRunTime] Starting RSpec timer...
2025-02-24T17:27:08.153839Z 01O [TEST PROF INFO] EventProf enabled (sql.active_record)
2025-02-24T17:25:50.741627Z 01E [0munknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
2025-02-24T17:27:08.189138Z 01E unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
2025-02-24T17:27:08.265575Z 01E unknown OID 2249: failed to recognize type of 'pg_stat_file'. It will be treated as String.
2025-02-24T17:27:17.354609Z 01O
2025-02-24T17:27:17.354613Z 01O Test environment set up in 3.106798199 seconds
2025-02-24T17:27:18.260194Z 01O # [RSpecRunTime] Starting example group spec/scripts/internal_events/cli_spec.rb. Expected to take 3.67 seconds.
2025-02-24T17:27:18.260200Z 01O
2025-02-24T17:27:18.260201Z 01O Cli
2025-02-24T17:27:18.274216Z 01O when offline
2025-02-24T17:27:18.274229Z 01O behaves like creates the right definition files
2025-02-24T17:27:19.221610Z 01E tput: No value for $TERM and no -T specified
2025-02-24T17:27:19.257306Z 01O in scenario: Creates a new event with product stage/section/group input manually
2025-02-24T17:27:19.257640Z 01O behaves like creates the right definition files
2025-02-24T17:27:19.641175Z 01E tput: No value for $TERM and no -T specified
2025-02-24T17:27:20.300673Z 01E tput: No value for $TERM and no -T specified
2025-02-24T17:27:20.330388Z 01O in scenario: Creates a new metric with product stage/section/group input manually
2025-02-24T17:27:20.424061Z 01O # [RSpecRunTime] RSpec elapsed time: 12.2 seconds. Current RSS: ~1324M. Threads: 2. load average: 1.24 1.06 1.09 1/278 506
2025-02-24T17:27:20.424070Z 01O .
2025-02-24T17:27:20.424071Z 01O
2025-02-24T17:27:20.424338Z 01O when window size is unavailable
2025-02-24T17:27:20.424673Z 01O behaves like creates the right definition files
2025-02-24T17:27:20.691139Z 01O in scenario: Terminal size does not prevent file creation
2025-02-24T17:27:20.691155Z 01O behaves like definition fixtures are valid
2025-02-24T17:27:20.764721Z 01O for events
2025-02-24T17:27:20.764928Z 01O behaves like definition fixtures are valid
2025-02-24T17:27:20.840032Z 01O for metrics
2025-02-24T17:27:21.871891Z 01O
2025-02-24T17:27:21.871906Z 01O # [RSpecRunTime] Finishing example group spec/scripts/internal_events/cli_spec.rb. It took 3.63 seconds. Expected to take 3.67 seconds.
2025-02-24T17:27:21.931387Z 01O # [RSpecRunTime] RSpec elapsed time: 13.74 seconds. Current RSS: ~1346M. Threads: 2. load average: 1.22 1.05 1.09 1/278 508
2025-02-24T17:27:21.931393Z 01O .
2025-02-24T17:27:21.931394Z 01O
2025-02-24T17:27:21.931667Z 01O # [RSpecRunTime] Starting example group spec/support_specs/matchers/internal_events_matchers_spec.rb. Expected to take 4.49 seconds.
2025-02-24T17:27:21.931672Z 01O
2025-02-24T17:27:21.931673Z 01O Internal Events matchers
2025-02-24T17:27:24.240710Z 01O when chaining both matchers
2025-02-24T17:27:24.508941Z 01O handles triggering events that increment metrics
2025-02-24T17:27:24.587340Z 01O handles triggering events that do not increment metrics
2025-02-24T17:27:24.681705Z 01O handles multiple triggered events and incremented metrics
2025-02-24T17:27:24.771141Z 01O handles chaining multiple triggered events and incremented metrics with different args
2025-02-24T17:27:24.970752Z 01O accepts other chained matchers with #and
2025-02-24T17:27:25.322100Z 01O # [RSpecRunTime] RSpec elapsed time: 16.84 seconds. Current RSS: ~1373M. Threads: 4. load average: 1.22 1.05 1.09 1/288 519
2025-02-24T17:27:25.322180Z 01O .
2025-02-24T17:27:25.322190Z 01O
2025-02-24T17:27:25.323190Z 01O when using the 'internal event tracking' shared example
2025-02-24T17:27:25.326910Z 01O with identifiers
2025-02-24T17:27:25.328630Z 01O behaves like internal event tracking
2025-02-24T17:27:25.177078Z 01O logs to Snowplow, Redis, and product analytics tooling
2025-02-24T17:27:25.177179Z 01O with additional properties
2025-02-24T17:27:25.177357Z 01O behaves like internal event tracking
2025-02-24T17:27:25.295413Z 01O logs to Snowplow, Redis, and product analytics tooling
2025-02-24T17:27:25.295540Z 01O behaves like internal event tracking
2025-02-24T17:27:25.397469Z 01O logs to Snowplow, Redis, and product analytics tooling
2025-02-24T17:27:25.397648Z 01O behaves like internal event tracking
2025-02-24T17:27:25.504629Z 01O logs to Snowplow, Redis, and product analytics tooling
2025-02-24T17:27:25.504743Z 01O with incorrect value being provided in additional_properties.
2025-02-24T17:27:25.504745Z 01O behaves like internal event tracking
2025-02-24T17:27:25.609364Z 01O logs to Snowplow, Redis, and product analytics tooling (PENDING: This example should always fail. Protects against false positives.)
2025-02-24T17:27:25.609389Z 01O behaves like internal event tracking
2025-02-24T17:27:25.708590Z 01O logs to Snowplow, Redis, and product analytics tooling (PENDING: This example should always fail. Protects against false positives.)
2025-02-24T17:27:25.708678Z 01O behaves like internal event tracking
2025-02-24T17:27:25.815062Z 01O logs to Snowplow, Redis, and product analytics tooling (PENDING: This example should always fail. Protects against false positives.)
2025-02-24T17:27:25.815248Z 01O :increment_usage_metrics
2025-02-24T17:27:27.451214Z 01O handles database-based metrics
2025-02-24T17:27:27.549076Z 01O accepts chained metric counts like #change
2025-02-24T17:27:27.587872Z 01O handles non-integer values [ALPHA] (not strictly supported)
2025-02-24T17:27:27.588034Z 01O behaves like matcher and negated matcher both raise expected error
2025-02-24T17:27:27.623092Z 01O is expected to raise ArgumentError with "increment_usage_metrics matcher requires key_paths argument"
2025-02-24T17:27:27.679493Z 01O # [RSpecRunTime] RSpec elapsed time: 19.49 seconds. Current RSS: ~1379M. Threads: 4. load average: 1.20 1.05 1.09 1/289 521
2025-02-24T17:27:27.679499Z 01O .
2025-02-24T17:27:27.679500Z 01O
2025-02-24T17:27:27.679733Z 01O behaves like matcher and negated matcher both raise expected error
2025-02-24T17:27:27.729678Z 01O is expected to raise ArgumentError with "Cannot find metric definition for 'redis_hll_counters.bad_metric_name'!"
2025-02-24T17:27:27.729739Z 01O behaves like matcher and negated matcher both raise expected error
2025-02-24T17:27:27.772879Z 01O is expected to raise ArgumentError with "Cannot find metric definition for 'g_edit_by_sfe' -- did you mean 'redis_hll_counters.ide_edit.g_edit_by_sfe_monthly'?"
2025-02-24T17:27:27.773052Z 01O when :increment_usage_metrics should fail
2025-02-24T17:27:27.773059Z 01O with a single metric failure
2025-02-24T17:27:27.821270Z 01O returns a meaningful failure message for :increment_usage_metrics
2025-02-24T17:27:27.821353Z 01O with a multiple metric failures
2025-02-24T17:27:27.874725Z 01O returns a meaningful failure message for :increment_usage_metrics
2025-02-24T17:27:27.874806Z 01O with a multiple metric failures across chained assertions
2025-02-24T17:27:27.933277Z 01O returns a meaningful failure message for :increment_usage_metrics
2025-02-24T17:27:27.933475Z 01O when :not_increment_usage_metrics should fail
2025-02-24T17:27:27.933746Z 01O with a single metric failure
2025-02-24T17:27:28.435000Z 01O returns a meaningful failure message for :increment_usage_metrics
2025-02-24T17:27:28.445000Z 01O with a multiple metric failures
2025-02-24T17:27:28.768630Z 01O returns a meaningful failure message for :increment_usage_metrics
2025-02-24T17:27:28.770370Z 01O with a multiple metric failures across chained assertions
2025-02-24T17:27:28.149421Z 01O returns a meaningful failure message for :increment_usage_metrics
2025-02-24T17:27:28.149602Z 01O :trigger_internal_events
2025-02-24T17:27:28.149790Z 01O when testing HTML with data attributes
2025-02-24T17:27:28.150036Z 01O html_input: rendered_html
2025-02-24T17:27:28.150225Z 01O when using positive matcher
2025-02-24T17:27:28.193076Z 01O matches elements with correct tracking attribute
2025-02-24T17:27:28.230191Z 01O raises error when multiple events are provided
2025-02-24T17:27:28.271096Z 01O raises error when using incompatible chain methods
2025-02-24T17:27:28.271337Z 01O with incorrect tracking attribute
2025-02-24T17:27:28.324711Z 01O does not match elements
2025-02-24T17:27:28.325165Z 01O with non existing tracking event
2025-02-24T17:27:28.375635Z 01O does not match elements
2025-02-24T17:27:28.375690Z 01O with additional properties
2025-02-24T17:27:28.426255Z 01O matches elements
2025-02-24T17:27:28.426371Z 01O with tracking-load attribute
2025-02-24T17:27:28.473403Z 01O matches elements
2025-02-24T17:27:28.473435Z 01O when using negated matcher
2025-02-24T17:27:28.528258Z 01O matches elements without tracking attribute
2025-02-24T17:27:28.567844Z 01O raises error when passing events to negated matcher
2025-02-24T17:27:28.607687Z 01O raises error when using chain methods with negated matcher
2025-02-24T17:27:28.607820Z 01O html_input: capybara_node
2025-02-24T17:27:28.607973Z 01O when using positive matcher
2025-02-24T17:27:28.647637Z 01O matches elements with correct tracking attribute
2025-02-24T17:27:28.684180Z 01O raises error when multiple events are provided
2025-02-24T17:27:28.722479Z 01O raises error when using incompatible chain methods
2025-02-24T17:27:28.722484Z 01O with incorrect tracking attribute
2025-02-24T17:27:28.764948Z 01O does not match elements
2025-02-24T17:27:28.764983Z 01O with non existing tracking event
2025-02-24T17:27:28.804520Z 01O does not match elements
2025-02-24T17:27:28.804662Z 01O with additional properties
2025-02-24T17:27:28.843564Z 01O matches elements
2025-02-24T17:27:28.843716Z 01O with tracking-load attribute
2025-02-24T17:27:28.884148Z 01O matches elements
2025-02-24T17:27:28.884301Z 01O when using negated matcher
2025-02-24T17:27:28.934135Z 01O matches elements without tracking attribute
2025-02-24T17:27:28.971707Z 01O raises error when passing events to negated matcher
2025-02-24T17:27:29.924500Z 01O raises error when using chain methods with negated matcher
2025-02-24T17:27:29.928000Z 01O with backend events
2025-02-24T17:27:29.472170Z 01O raises error if no events are passed to :trigger_internal_events
2025-02-24T17:27:29.181198Z 01O does not raises error if no events are passed to :not_trigger_internal_events
2025-02-24T17:27:29.233721Z 01O bubbles up failure messages
2025-02-24T17:27:29.284852Z 01O bubbles up failure messages for negated matcher
2025-02-24T17:27:29.343478Z 01O handles events that should not be triggered
2025-02-24T17:27:29.406238Z 01O ignores extra/irrelevant triggered events
2025-02-24T17:27:29.494878Z 01O accepts chained event counts like #receive for multiple different events
2025-02-24T17:27:29.494905Z 01O behaves like matcher and negated matcher both raise expected error
2025-02-24T17:27:29.533918Z 01O is expected to raise ArgumentError with "Unknown event 'bad_event_name'! trigger_internal_events matcher accepts only existing events"
2025-02-24T17:27:29.533999Z 01O with additional properties
2025-02-24T17:27:29.592022Z 01O accepts correct additional properties
2025-02-24T17:27:29.592030Z 01O with extra attributes
2025-02-24T17:27:29.653210Z 01O accepts correct extra attributes
2025-02-24T17:27:29.653295Z 01O with wrong label value
2025-02-24T17:27:29.653459Z 01O behaves like raises error for unexpected event args
2025-02-24T17:27:29.717377Z 01O is expected to raise RSpec::Expectations::ExpectationNotMetError with message matching /received :event with unexpected arguments/
2025-02-24T17:27:29.718097Z 01O with extra attributes expected but not tracked
2025-02-24T17:27:29.718166Z 01O behaves like raises error for unexpected event args
2025-02-24T17:27:29.793439Z 01O is expected to raise RSpec::Expectations::ExpectationNotMetError with message matching /received :event with unexpected arguments/
2025-02-24T17:27:29.793694Z 01O with extra attributes tracked but not expected
2025-02-24T17:27:29.793847Z 01O behaves like raises error for unexpected event args
2025-02-24T17:27:29.886964Z 01O is expected to raise RSpec::Expectations::ExpectationNotMetError with message matching /received :event with unexpected arguments/
2025-02-24T17:27:29.901012Z 01O
2025-02-24T17:27:29.901019Z 01O # [RSpecRunTime] Finishing example group spec/support_specs/matchers/internal_events_matchers_spec.rb. It took 7.97 seconds. Expected to take 4.49 seconds.
2025-02-24T17:27:30.823570Z 01O auto_explain log contains 893 entries for main, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-fail-fast.343.main.ndjson.gz
2025-02-24T17:27:30.823578Z 01O took 0.49346616
2025-02-24T17:27:31.326706Z 01O auto_explain log contains 894 entries for ci, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-fail-fast.343.ci.ndjson.gz
2025-02-24T17:27:31.326710Z 01O took 0.49256552
2025-02-24T17:27:31.770424Z 01O auto_explain log contains 894 entries for sec, writing to /builds/gitlab-org/gitlab/auto_explain/rspec-fail-fast.343.sec.ndjson.gz
2025-02-24T17:27:31.770439Z 01O took 0.433491474
2025-02-24T17:27:31.772171Z 01O [TEST PROF INFO] EventProf results for sql.active_record
2025-02-24T17:27:31.772178Z 01O
2025-02-24T17:27:31.772180Z 01O Total time: 00:02.195 of 00:11.639 (18.86%)
2025-02-24T17:27:31.772182Z 01O Total events: 966
2025-02-24T17:27:31.772183Z 01O
2025-02-24T17:27:31.772184Z 01O Top 5 slowest suites (by time):
2025-02-24T17:27:31.772185Z 01O
2025-02-24T17:27:31.772186Z 01O Internal Events matchers (./spec/support_specs/matchers/internal_events_matchers_spec.rb:5) – 00:02.105 (924 / 57) of 00:07.969 (26.43%)
2025-02-24T17:27:31.772189Z 01O Cli (./spec/scripts/internal_events/cli_spec.rb:8) – 00:00.089 (42 / 5) of 00:03.670 (2.43%)
2025-02-24T17:27:31.772191Z 01O
2025-02-24T17:27:31.798984Z 01O
2025-02-24T17:27:31.798990Z 01O Pending: (Failures listed here are expected and do not affect your suite's status)
2025-02-24T17:27:31.798992Z 01O
2025-02-24T17:27:31.798993Z 01O 1) Internal Events matchers when using the 'internal event tracking' shared example with additional properties with incorrect value being provided in additional_properties. behaves like internal event tracking logs to Snowplow, Redis, and product analytics tooling
2025-02-24T17:27:31.798997Z 01O # This example should always fail. Protects against false positives.
2025-02-24T17:27:31.798999Z 01O Got 1 failure:
2025-02-24T17:27:31.799000Z 01O Shared Example Group: "internal event tracking" called from ./spec/support_specs/matchers/internal_events_matchers_spec.rb:527
2025-02-24T17:27:31.799003Z 01O
2025-02-24T17:27:31.799004Z 01O 1.1) Failure/Error:
2025-02-24T17:27:31.799005Z 01O expect { subject }
2025-02-24T17:27:31.799006Z 01O .to trigger_internal_events(event)
2025-02-24T17:27:31.799008Z 01O .with(expected_attributes)
2025-02-24T17:27:31.799010Z 01O .and increment_usage_metrics(*all_metrics)
2025-02-24T17:27:31.799011Z 01O
2025-02-24T17:27:31.799012Z 01O #<InstanceDouble(Gitlab::Tracking::Destinations::Snowplow) (anonymous)> received :event with unexpected arguments
2025-02-24T17:27:31.799015Z 01O expected: ("InternalEventTracking", "push_package_to_registry", include {:context => (contain exactly (have attributes {:class => SnowplowTracker::SelfDescribingJson...", :data => (include {:event_name => "push_package_to_registry"})})})), :label => "BAD label value"})
2025-02-24T17:27:31.799044Z 01O got: ("InternalEventTracking", "push_package_to_registry", {:context=>[#<SnowplowTracker::SelfDescribingJson:0x00007e0b863daf08 @schema="iglu:com.gitlab/gitlab_...:data_source=>:redis_hll, :event_name=>"push_package_to_registry"}>], :label=>"Awesome label value"})
2025-02-24T17:27:31.799049Z 01O Diff:
2025-02-24T17:27:31.799050Z 01O @@ -1,4 +1,7 @@
2025-02-24T17:27:31.799051Z 01O ["InternalEventTracking",
2025-02-24T17:27:31.799053Z 01O "push_package_to_registry",
2025-02-24T17:27:31.799055Z 01O - "include {:context => (contain exactly (have attributes {:class => SnowplowTracker::SelfDescribingJson, :to_json => (include {:schema => \"ig..., :project_id => 1, :namespace_id => 1, :feature_enabled_by_namespace_ids => nil, :extra => {}})})}) and (have attributes {:class => SnowplowTracker::SelfDescribingJson, :to_json => (include {:schema => \"ig...b_service_ping/jsonschema/1-0-1\", :data => (include {:event_name => \"push_package_to_registry\"})})})), :label => \"BAD label value\"}"]
2025-02-24T17:27:31.799067Z 01O + {:context=>
2025-02-24T17:27:31.799068Z 01O + [#<SnowplowTracker::SelfDescribingJson:0x00007e0b863daf08 @schema="iglu:com.gitlab/gitlab_standard/jsonschema/1-1-1", @data={:environment=>"development", :source=>"gitlab-rails", :correlation_id=>"307e011e3255db8a42c01ad03d4be886", :plan=>"default", :extra=>{}, :user_id=>1, :global_user_id=>"QWe9ebiJPrQUPqG/tkOT+K7s5hny4VoaidCKveIcP+w=", :is_gitlab_team_member=>nil, :namespace_id=>1, :project_id=>1, :feature_enabled_by_namespace_ids=>nil, :realm=>"self-managed", :instance_id=>"uuid-not-set", :host_name=>"runner-rpvz2ff9-project-278964-concurrent-0", :instance_version=>"17.10.0", :context_generated_at=>Mon, 24 Feb 2025 17:27:25.578708314 UTC +00:00}>,
2025-02-24T17:27:31.799074Z 01O + #<SnowplowTracker::SelfDescribingJson:0x00007e0b863d93b0 @schema="iglu:com.gitlab/gitlab_service_ping/jsonschema/1-0-1", @data={:data_source=>:redis_hll, :event_name=>"push_package_to_registry"}>],
2025-02-24T17:27:31.799076Z 01O + :label=>"Awesome label value"}]
2025-02-24T17:27:31.799077Z 01O # ./spec/support/shared_examples/controllers/internal_event_tracking_examples.rb:59:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799080Z 01O # ./spec/spec_helper.rb:457:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799081Z 01O # ./lib/gitlab/sidekiq_sharding/validator.rb:42:in `enabled'
2025-02-24T17:27:31.799083Z 01O # ./spec/spec_helper.rb:456:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799085Z 01O # ./spec/spec_helper.rb:451:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799087Z 01O # ./spec/support/sidekiq_middleware.rb:9:in `with_sidekiq_server_middleware'
2025-02-24T17:27:31.799088Z 01O # ./spec/spec_helper.rb:442:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799090Z 01O # ./spec/spec_helper.rb:438:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799092Z 01O # ./lib/gitlab/application_context.rb:100:in `with_raw_context'
2025-02-24T17:27:31.799094Z 01O # ./spec/spec_helper.rb:438:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799096Z 01O # ./spec/spec_helper.rb:409:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799098Z 01O # ./lib/gitlab/ci/config/feature_flags.rb:38:in `ensure_correct_usage'
2025-02-24T17:27:31.799099Z 01O # ./spec/spec_helper.rb:408:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799101Z 01O # ./spec/spec_helper.rb:273:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799103Z 01O # ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799105Z 01O # ./spec/support/redis.rb:18:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799116Z 01O # ./spec/support/fast_quarantine.rb:22:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799118Z 01O # ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799121Z 01O # ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
2025-02-24T17:27:31.799123Z 01O # ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799125Z 01O
2025-02-24T17:27:31.799126Z 01O 2) Internal Events matchers when using the 'internal event tracking' shared example with additional properties with incorrect value being provided in additional_properties. behaves like internal event tracking logs to Snowplow, Redis, and product analytics tooling
2025-02-24T17:27:31.799130Z 01O # This example should always fail. Protects against false positives.
2025-02-24T17:27:31.799132Z 01O Got 1 failure:
2025-02-24T17:27:31.799133Z 01O Shared Example Group: "internal event tracking" called from ./spec/support_specs/matchers/internal_events_matchers_spec.rb:531
2025-02-24T17:27:31.799136Z 01O
2025-02-24T17:27:31.799137Z 01O 2.1) Failure/Error:
2025-02-24T17:27:31.799138Z 01O expect { subject }
2025-02-24T17:27:31.799140Z 01O .to trigger_internal_events(event)
2025-02-24T17:27:31.799141Z 01O .with(expected_attributes)
2025-02-24T17:27:31.799143Z 01O .and increment_usage_metrics(*all_metrics)
2025-02-24T17:27:31.799145Z 01O
2025-02-24T17:27:31.799146Z 01O #<InstanceDouble(Gitlab::Tracking::Destinations::Snowplow) (anonymous)> received :event with unexpected arguments
2025-02-24T17:27:31.799148Z 01O expected: ("InternalEventTracking", "push_package_to_registry", include {:context => (contain exactly (have attributes {:class => SnowplowTracker::SelfDescribingJson...", :data => (include {:event_name => "push_package_to_registry"})})})), :label => "BAD label value"})
2025-02-24T17:27:31.799152Z 01O got: ("InternalEventTracking", "push_package_to_registry", {:context=>[#<SnowplowTracker::SelfDescribingJson:0x00007e0b8600c750 @schema="iglu:com.gitlab/gitlab_...:data_source=>:redis_hll, :event_name=>"push_package_to_registry"}>], :label=>"Awesome label value"})
2025-02-24T17:27:31.799157Z 01O Diff:
2025-02-24T17:27:31.799158Z 01O @@ -1,4 +1,7 @@
2025-02-24T17:27:31.799159Z 01O ["InternalEventTracking",
2025-02-24T17:27:31.799161Z 01O "push_package_to_registry",
2025-02-24T17:27:31.799162Z 01O - "include {:context => (contain exactly (have attributes {:class => SnowplowTracker::SelfDescribingJson, :to_json => (include {:schema => \"ig..., :project_id => 1, :namespace_id => 1, :feature_enabled_by_namespace_ids => nil, :extra => {}})})}) and (have attributes {:class => SnowplowTracker::SelfDescribingJson, :to_json => (include {:schema => \"ig...b_service_ping/jsonschema/1-0-1\", :data => (include {:event_name => \"push_package_to_registry\"})})})), :label => \"BAD label value\"}"]
2025-02-24T17:27:31.799167Z 01O + {:context=>
2025-02-24T17:27:31.799168Z 01O + [#<SnowplowTracker::SelfDescribingJson:0x00007e0b8600c750 @schema="iglu:com.gitlab/gitlab_standard/jsonschema/1-1-1", @data={:environment=>"development", :source=>"gitlab-rails", :correlation_id=>"044d81cc1161f316f299956c197e6e7e", :plan=>"default", :extra=>{}, :user_id=>1, :global_user_id=>"QWe9ebiJPrQUPqG/tkOT+K7s5hny4VoaidCKveIcP+w=", :is_gitlab_team_member=>nil, :namespace_id=>1, :project_id=>1, :feature_enabled_by_namespace_ids=>nil, :realm=>"self-managed", :instance_id=>"uuid-not-set", :host_name=>"runner-rpvz2ff9-project-278964-concurrent-0", :instance_version=>"17.10.0", :context_generated_at=>Mon, 24 Feb 2025 17:27:25.677562918 UTC +00:00}>,
2025-02-24T17:27:31.799173Z 01O + #<SnowplowTracker::SelfDescribingJson:0x00007e0b8600b670 @schema="iglu:com.gitlab/gitlab_service_ping/jsonschema/1-0-1", @data={:data_source=>:redis_hll, :event_name=>"push_package_to_registry"}>],
2025-02-24T17:27:31.799184Z 01O + :label=>"Awesome label value"}]
2025-02-24T17:27:31.799185Z 01O # ./spec/support/shared_examples/controllers/internal_event_tracking_examples.rb:59:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799188Z 01O # ./spec/spec_helper.rb:457:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799190Z 01O # ./lib/gitlab/sidekiq_sharding/validator.rb:42:in `enabled'
2025-02-24T17:27:31.799192Z 01O # ./spec/spec_helper.rb:456:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799194Z 01O # ./spec/spec_helper.rb:451:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799195Z 01O # ./spec/support/sidekiq_middleware.rb:9:in `with_sidekiq_server_middleware'
2025-02-24T17:27:31.799197Z 01O # ./spec/spec_helper.rb:442:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799199Z 01O # ./spec/spec_helper.rb:438:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799201Z 01O # ./lib/gitlab/application_context.rb:100:in `with_raw_context'
2025-02-24T17:27:31.799203Z 01O # ./spec/spec_helper.rb:438:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799204Z 01O # ./spec/spec_helper.rb:409:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799206Z 01O # ./lib/gitlab/ci/config/feature_flags.rb:38:in `ensure_correct_usage'
2025-02-24T17:27:31.799208Z 01O # ./spec/spec_helper.rb:408:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799210Z 01O # ./spec/spec_helper.rb:273:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799212Z 01O # ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799214Z 01O # ./spec/support/redis.rb:18:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799216Z 01O # ./spec/support/fast_quarantine.rb:22:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799218Z 01O # ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799220Z 01O # ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
2025-02-24T17:27:31.799223Z 01O # ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799225Z 01O
2025-02-24T17:27:31.799226Z 01O 3) Internal Events matchers when using the 'internal event tracking' shared example with additional properties with incorrect value being provided in additional_properties. behaves like internal event tracking logs to Snowplow, Redis, and product analytics tooling
2025-02-24T17:27:31.799230Z 01O # This example should always fail. Protects against false positives.
2025-02-24T17:27:31.799232Z 01O Got 1 failure:
2025-02-24T17:27:31.799233Z 01O Shared Example Group: "internal event tracking" called from ./spec/support_specs/matchers/internal_events_matchers_spec.rb:535
2025-02-24T17:27:31.799236Z 01O
2025-02-24T17:27:31.799237Z 01O 3.1) Failure/Error:
2025-02-24T17:27:31.799238Z 01O expect { subject }
2025-02-24T17:27:31.799239Z 01O .to trigger_internal_events(event)
2025-02-24T17:27:31.799241Z 01O .with(expected_attributes)
2025-02-24T17:27:31.799243Z 01O .and increment_usage_metrics(*all_metrics)
2025-02-24T17:27:31.799244Z 01O
2025-02-24T17:27:31.799245Z 01O #<InstanceDouble(Gitlab::Tracking::Destinations::Snowplow) (anonymous)> received :event with unexpected arguments
2025-02-24T17:27:31.799248Z 01O expected: ("InternalEventTracking", "push_package_to_registry", include {:context => (contain exactly (have attributes {:class => SnowplowTracker::SelfDescribingJson...", :data => (include {:event_name => "push_package_to_registry"})})})), :label => "BAD label value"})
2025-02-24T17:27:31.799259Z 01O got: ("InternalEventTracking", "push_package_to_registry", {:context=>[#<SnowplowTracker::SelfDescribingJson:0x00007e0b85cd8ae8 @schema="iglu:com.gitlab/gitlab_...:data_source=>:redis_hll, :event_name=>"push_package_to_registry"}>], :label=>"Awesome label value"})
2025-02-24T17:27:31.799262Z 01O Diff:
2025-02-24T17:27:31.799263Z 01O @@ -1,4 +1,7 @@
2025-02-24T17:27:31.799264Z 01O ["InternalEventTracking",
2025-02-24T17:27:31.799264Z 01O "push_package_to_registry",
2025-02-24T17:27:31.799265Z 01O - "include {:context => (contain exactly (have attributes {:class => SnowplowTracker::SelfDescribingJson, :to_json => (include {:schema => \"ig..., :project_id => 1, :namespace_id => 1, :feature_enabled_by_namespace_ids => nil, :extra => {}})})}) and (have attributes {:class => SnowplowTracker::SelfDescribingJson, :to_json => (include {:schema => \"ig...b_service_ping/jsonschema/1-0-1\", :data => (include {:event_name => \"push_package_to_registry\"})})})), :label => \"BAD label value\"}"]
2025-02-24T17:27:31.799270Z 01O + {:context=>
2025-02-24T17:27:31.799271Z 01O + [#<SnowplowTracker::SelfDescribingJson:0x00007e0b85cd8ae8 @schema="iglu:com.gitlab/gitlab_standard/jsonschema/1-1-1", @data={:environment=>"development", :source=>"gitlab-rails", :correlation_id=>"a92795bed9a4acf20948deb372e575fd", :plan=>"default", :extra=>{}, :user_id=>1, :global_user_id=>"QWe9ebiJPrQUPqG/tkOT+K7s5hny4VoaidCKveIcP+w=", :is_gitlab_team_member=>nil, :namespace_id=>1, :project_id=>1, :feature_enabled_by_namespace_ids=>nil, :realm=>"self-managed", :instance_id=>"uuid-not-set", :host_name=>"runner-rpvz2ff9-project-278964-concurrent-0", :instance_version=>"17.10.0", :context_generated_at=>Mon, 24 Feb 2025 17:27:25.785664571 UTC +00:00}>,
2025-02-24T17:27:31.799280Z 01O + #<SnowplowTracker::SelfDescribingJson:0x00007e0b85cd7eb8 @schema="iglu:com.gitlab/gitlab_service_ping/jsonschema/1-0-1", @data={:data_source=>:redis_hll, :event_name=>"push_package_to_registry"}>],
2025-02-24T17:27:31.799283Z 01O + :label=>"Awesome label value"}]
2025-02-24T17:27:31.799285Z 01O # ./spec/support/shared_examples/controllers/internal_event_tracking_examples.rb:59:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799287Z 01O # ./spec/spec_helper.rb:457:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799289Z 01O # ./lib/gitlab/sidekiq_sharding/validator.rb:42:in `enabled'
2025-02-24T17:27:31.799291Z 01O # ./spec/spec_helper.rb:456:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799293Z 01O # ./spec/spec_helper.rb:451:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799295Z 01O # ./spec/support/sidekiq_middleware.rb:9:in `with_sidekiq_server_middleware'
2025-02-24T17:27:31.799297Z 01O # ./spec/spec_helper.rb:442:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799299Z 01O # ./spec/spec_helper.rb:438:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799301Z 01O # ./lib/gitlab/application_context.rb:100:in `with_raw_context'
2025-02-24T17:27:31.799302Z 01O # ./spec/spec_helper.rb:438:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799304Z 01O # ./spec/spec_helper.rb:409:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799306Z 01O # ./lib/gitlab/ci/config/feature_flags.rb:38:in `ensure_correct_usage'
2025-02-24T17:27:31.799308Z 01O # ./spec/spec_helper.rb:408:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799310Z 01O # ./spec/spec_helper.rb:273:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799311Z 01O # ./spec/support/system_exit_detected.rb:7:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799312Z 01O # ./spec/support/redis.rb:18:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799327Z 01O # ./spec/support/fast_quarantine.rb:22:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799330Z 01O # ./spec/support/database/prevent_cross_joins.rb:106:in `block (3 levels) in <top (required)>'
2025-02-24T17:27:31.799332Z 01O # ./spec/support/database/prevent_cross_joins.rb:60:in `with_cross_joins_prevented'
2025-02-24T17:27:31.799334Z 01O # ./spec/support/database/prevent_cross_joins.rb:106:in `block (2 levels) in <top (required)>'
2025-02-24T17:27:31.799349Z 01O
2025-02-24T17:27:31.799350Z 01O Finished in 23.64 seconds (files took 1 minute 14.26 seconds to load)
2025-02-24T17:27:31.799352Z 01O 62 examples, 0 failures, 3 pending
2025-02-24T17:27:31.802882Z 01O
2025-02-24T17:27:31.802887Z 01O Randomized with seed 3029
2025-02-24T17:27:31.802888Z 01O
2025-02-24T17:27:41.514499Z 01O [TEST PROF INFO] Time spent in factories: 00:03.882 (14.3% of total time)
2025-02-24T17:27:41.800201Z 01E [0;32mNo examples to retry, congrats!
2025-02-24T17:27:41.800207Z 01E [0m
2025-02-24T17:27:42.310746Z 00O section_end:1740418062:step_script
2025-02-24T17:27:42.310749Z 00O+[0Ksection_start:1740418062:after_script
2025-02-24T17:27:42.312428Z 00O+[0K[0K[36;1mRunning after_script[0;m[0;m
2025-02-24T17:27:42.862151Z 01O [32;1mRunning after script...[0;m
2025-02-24T17:27:42.862156Z 01O [32;1m$ source scripts/utils.sh[0;m
2025-02-24T17:27:42.863503Z 01O [32;1m$ log_disk_usage[0;m
2025-02-24T17:27:42.902457Z 01O *******************************************************
2025-02-24T17:27:42.902463Z 01O This runner currently has 70G free disk space.
2025-02-24T17:27:42.902465Z 01O *******************************************************
2025-02-24T17:27:42.951896Z 01O section_start:1740418062:log_disk_usage[collapsed=true]
[0KDisk usage detail
2025-02-24T17:27:42.951902Z 01O df -h
2025-02-24T17:27:42.953331Z 01O Filesystem Size Used Avail Use% Mounted on
2025-02-24T17:27:42.953334Z 01O overlay 95G 25G 70G 26% /
2025-02-24T17:27:42.953335Z 01O tmpfs 64M 0 64M 0% /dev
2025-02-24T17:27:42.953336Z 01O shm 64M 0 64M 0% /dev/shm
2025-02-24T17:27:42.953336Z 01O /dev/sda1 95G 25G 70G 26% /cache
2025-02-24T17:27:42.953337Z 01O tmpfs 3.9G 0 3.9G 0% /sys/devices/virtual/dmi/id
2025-02-24T17:27:42.953568Z 01O du -h -d 1
2025-02-24T17:27:42.972725Z 01O 7.4M ./workhorse
2025-02-24T17:27:42.972888Z 01O 148K ./bin
2025-02-24T17:27:42.973575Z 01O 1.2M ./.gitlab
2025-02-24T17:27:42.973726Z 01O 216M ./.git
2025-02-24T17:27:42.973832Z 01O 4.0K ./builds
2025-02-24T17:27:42.973834Z 01O 18M ./coverage
2025-02-24T17:27:43.565562Z 01O 29M ./lib
2025-02-24T17:27:43.565566Z 01O 8.0K ./.vscode
2025-02-24T17:27:43.565892Z 01O 588K ./storybook
2025-02-24T17:27:43.566078Z 01O 100K ./log
2025-02-24T17:27:43.567375Z 01O 2.1M ./data
2025-02-24T17:27:43.716081Z 01O 11M ./qa
2025-02-24T17:27:43.717439Z 01O 3.0M ./.rubocop_todo
2025-02-24T17:27:45.784693Z 01O 858M ./vendor
2025-02-24T17:27:46.174315Z 01O 660M ./public
2025-02-24T17:27:46.216226Z 01O 63M ./doc
2025-02-24T17:27:46.217129Z 01O 508K ./danger
2025-02-24T17:27:46.217300Z 01O 116K ./rspec
2025-02-24T17:27:46.217366Z 01O 8.0K ./.bundle
2025-02-24T17:27:46.218223Z 01O 580K ./tooling
2025-02-24T17:27:48.191822Z 01O 154M ./ee
2025-02-24T17:27:48.191830Z 01O 1.4M ./knapsack
2025-02-24T17:27:48.192511Z 01O 68K ./patches
2025-02-24T17:27:48.192519Z 01O 5.7M ./changelogs
2025-02-24T17:27:48.192677Z 01O 20K ./haml_lint
2025-02-24T17:27:48.192829Z 01O 28K ./metrics_server
2025-02-24T17:27:48.192957Z 01O 116K ./keeps
2025-02-24T17:27:48.194390Z 01O 36K ./shared
2025-02-24T17:27:48.194533Z 01O 44K ./generator_templates
2025-02-24T17:27:48.196122Z 01O 1.3M ./scripts
2025-02-24T17:27:48.308616Z 01O 1.2G ./tmp
2025-02-24T17:27:48.672376Z 01O 132M ./spec
2025-02-24T17:27:48.672382Z 01O 20K ./file_hooks
2025-02-24T17:27:48.672383Z 01O 36K ./crystalball
2025-02-24T17:27:48.672384Z 01O 16K ./sidekiq_cluster
2025-02-24T17:27:48.675819Z 01O 4.3M ./gems
2025-02-24T17:27:48.676038Z 01O 1.2M ./fixtures
2025-02-24T17:27:48.686453Z 01O 972K ./rubocop
2025-02-24T17:27:48.686461Z 01O 4.0K ./.go
2025-02-24T17:27:48.706634Z 01O 36M ./db
2025-02-24T17:27:48.706637Z 01O 244K ./auto_explain
2025-02-24T17:27:48.706768Z 01O 12K ./.github
2025-02-24T17:27:48.706770Z 01O 64K ./.eslint_todo
2025-02-24T17:27:48.714203Z 01O 137M ./locale
2025-02-24T17:27:48.726505Z 01O 20M ./config
2025-02-24T17:27:48.803429Z 01O 89M ./app
2025-02-24T17:27:48.803433Z 01O 20K ./.lefthook
2025-02-24T17:27:48.803434Z 01O 3.6G .
2025-02-24T17:27:48.805375Z 01O section_end:1740418068:log_disk_usage
[0K
2025-02-24T17:27:48.805387Z 01O [32;1m$ bundle exec gem list gitlab_quality-test_tooling[0;m
2025-02-24T17:27:50.809512Z 01O gitlab_quality-test_tooling (2.8.0)
2025-02-24T17:27:50.817564Z 01O [32;1m$ section_start "failed-test-issues" "Report test failures" # collapsed multi-line command[0;m
2025-02-24T17:27:50.818638Z 01O section_start:1740418070:failed-test-issues[collapsed=true]
[0KReport test failures
2025-02-24T17:27:50.818829Z 01E [0;33mNot reporting test failures because $CREATE_RAILS_TEST_FAILURE_ISSUES != 'true' or TEST_FAILURES_PROJECT_TOKEN is not set
2025-02-24T17:27:50.820550Z 01O section_end:1740418070:failed-test-issues
[0K
2025-02-24T17:27:50.820600Z 01O [32;1m$ section_start "flaky-test-issues" "Report test flakiness" # collapsed multi-line command[0;m
2025-02-24T17:27:50.822007Z 01O section_start:1740418070:flaky-test-issues[collapsed=true]
[0KReport test flakiness
2025-02-24T17:27:50.818833Z 01E [0m[0;33mNot reporting test flakiness because $CREATE_RAILS_FLAKY_TEST_ISSUES != 'true' or TEST_FAILURES_PROJECT_TOKEN is not set
2025-02-24T17:27:50.823481Z 01O section_end:1740418070:flaky-test-issues
[0K
2025-02-24T17:27:50.823493Z 01O [32;1m$ section_start "slow-test-issues" "Report test slowness" # collapsed multi-line command[0;m
2025-02-24T17:27:50.824791Z 01O section_start:1740418070:slow-test-issues[collapsed=true]
[0KReport test slowness
2025-02-24T17:27:50.822125Z 01E [0m[0;33mNot reporting test slowness because $CREATE_RAILS_SLOW_TEST_ISSUES != 'true' or TEST_FAILURES_PROJECT_TOKEN is not set
2025-02-24T17:27:50.826222Z 01O section_end:1740418070:slow-test-issues
[0K
2025-02-24T17:27:50.826225Z 01O [32;1m$ section_start "slow-test-merge-request-report-note" "Report test slowness in MR note" # collapsed multi-line command[0;m
2025-02-24T17:27:50.827506Z 01O section_start:1740418070:slow-test-merge-request-report-note[collapsed=true]
[0KReport test slowness in MR note
2025-02-24T17:27:52.930037Z 01O Reporting slow tests in MR 182450
2025-02-24T17:27:52.930043Z 01O => Reporting 62 tests in rspec/rspec-9229132014.json
2025-02-24T17:27:52.942653Z 01O section_end:1740418072:slow-test-merge-request-report-note
[0K
2025-02-24T17:27:52.942800Z 01O [32;1m$ section_start "knapsack-report-issues" "Report test files close to timing out" # collapsed multi-line command[0;m
2025-02-24T17:27:52.945076Z 01O section_start:1740418072:knapsack-report-issues[collapsed=true]
[0KReport test files close to timing out
2025-02-24T17:27:50.824952Z 01E [0mMissing a valid expected Knapsack report.
2025-02-24T17:27:54.975578Z 00O section_end:1740418074:after_script
2025-02-24T17:27:54.975582Z 00O+[0K[0;33mWARNING: after_script failed, but job will continue unaffected: exit code 1[0;m
2025-02-24T17:27:54.977225Z 00O section_start:1740418074:archive_cache
2025-02-24T17:27:54.977230Z 00O+[0K[0K[36;1mSaving cache for successful job[0;m[0;m
2025-02-24T17:27:55.804138Z 01O [32;1mNot uploading cache ruby-gems-debian-bookworm-ruby-3.3.7-gemfile-Gemfile-21 due to policy[0;m
2025-02-24T17:27:55.947866Z 00O section_end:1740418075:archive_cache
2025-02-24T17:27:55.947870Z 00O+[0Ksection_start:1740418075:upload_artifacts_on_success
2025-02-24T17:27:55.949219Z 00O+[0K[0K[36;1mUploading artifacts for successful job[0;m[0;m
2025-02-24T17:27:57.526501Z 01O [32;1mUploading artifacts...[0;m
2025-02-24T17:27:57.601694Z 01E auto_explain/: found 4 matching artifact files and directories[0;m
2025-02-24T17:27:57.602096Z 01E coverage/: found 5 matching artifact files and directories[0;m
2025-02-24T17:27:57.602218Z 01E crystalball/: found 2 matching artifact files and directories[0;m
2025-02-24T17:27:57.602349Z 01E [0;33mWARNING: deprecations/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)[0;m
2025-02-24T17:27:57.602631Z 01E knapsack/: found 2 matching artifact files and directories[0;m
2025-02-24T17:27:57.602973Z 01E rspec/: found 14 matching artifact files and directories[0;m
2025-02-24T17:27:57.602982Z 01E [0;33mWARNING: tmp/capybara/: no matching files. Ensure that the artifact path is relative to the working directory (/builds/gitlab-org/gitlab)[0;m
2025-02-24T17:27:57.603286Z 01E log/*.log: found 11 matching artifact files and directories[0;m
2025-02-24T17:27:57.786690Z 01E [0;33mWARNING: Upload request redirected [0;m [0;33mlocation[0;m=https://gitlab.com/api/v4/jobs/9229132014/artifacts?artifact_format=zip&artifact_type=archive&expire_in=31d [0;33mnew-url[0;m=https://gitlab.com
2025-02-24T17:27:57.786905Z 01E [0;33mWARNING: Retrying... [0;m [0;33mcontext[0;m=artifacts-uploader [0;33merror[0;m=request redirected
2025-02-24T17:28:00.829000Z 01E Uploading artifacts as "archive" to coordinator... 201 Created[0;m id[0;m=9229132014 responseStatus[0;m=201 Created token[0;m=glcbt-66
2025-02-24T17:28:00.811750Z 01O [32;1mUploading artifacts...[0;m
2025-02-24T17:28:00.140155Z 01E rspec/rspec-*.xml: found 1 matching artifact files and directories[0;m
2025-02-24T17:28:00.210347Z 01E [0;33mWARNING: Upload request redirected [0;m [0;33mlocation[0;m=https://gitlab.com/api/v4/jobs/9229132014/artifacts?artifact_format=gzip&artifact_type=junit&expire_in=31d [0;33mnew-url[0;m=https://gitlab.com
2025-02-24T17:28:00.210355Z 01E [0;33mWARNING: Retrying... [0;m [0;33mcontext[0;m=artifacts-uploader [0;33merror[0;m=request redirected
2025-02-24T17:28:01.928513Z 01E Uploading artifacts as "junit" to coordinator... 201 Created[0;m id[0;m=9229132014 responseStatus[0;m=201 Created token[0;m=glcbt-66
2025-02-24T17:28:02.982470Z 00O section_end:1740418082:upload_artifacts_on_success
2025-02-24T17:28:02.982530Z 00O+[0Ksection_start:1740418082:cleanup_file_variables
2025-02-24T17:28:02.983220Z 00O+[0K[0K[36;1mCleaning up project directory and file based variables[0;m[0;m
2025-02-24T17:28:02.618742Z 00O section_end:1740418082:cleanup_file_variables
2025-02-24T17:28:02.618793Z 00O+[0K
2025-02-24T17:28:11.260677Z 00O [32;1mJob succeeded[0;m