gitaly-cluster
Passed Started
by
@gitlab-bot

🤖 GitLab Bot 🤖
1Running with gitlab-runner 15.11.0 (436955cb)2 on gitlab-org-qa-runner ss7o3c7p, system ID: s_6a73791243695Using Docker executor with image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bullseye-ruby-3.0:bundler-2.3-docker-23.0.1 ...6Starting service docker:23.0.1-dind ...7Pulling docker image docker:23.0.1-dind ...8Using docker image sha256:0965b14b96d892eee2a963801769af5328817a64ed1af67ec4d76364ddd62706 for docker:23.0.1-dind with digest docker@sha256:d9a0fd8bdd156aae6e9be5db0264e0bc99e000e89e92055d4567e27ff13daff0 ...9Waiting for services to be up and running (timeout 30 seconds)...10Authenticating with credentials from job payload (GitLab Registry)11Pulling docker image registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bullseye-ruby-3.0:bundler-2.3-docker-23.0.1 ...12Using docker image sha256:c542c7445bbcd8902b4aff9c0c23d65f9021b3d5ce9f8bef0c5978e178ee97cb for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bullseye-ruby-3.0:bundler-2.3-docker-23.0.1 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bullseye-ruby-3.0@sha256:3c33cd32b8b2bb06c7a413f6ed11411c2b00d5fcbd116ed9342af59ead5ca236 ...14Running on runner-ss7o3c7p-project-278964-concurrent-0 via runner-ss7o3c7p-gitlab-org-qa-1689386719-96fb7b1d-gcp...16Fetching changes with git depth set to 20...17Initialized empty Git repository in /builds/gitlab-org/gitlab/.git/18Created fresh repository.19remote: Enumerating objects: 189940, done. 20remote: Counting objects: 100% (189940/189940), done. 21remote: Compressing objects: 100% (123114/123114), done. 22remote: Total 189940 (delta 93892), reused 127297 (delta 59544), pack-reused 0 23Receiving objects: 100% (189940/189940), 147.07 MiB | 44.87 MiB/s, done.24Resolving deltas: 100% (93892/93892), done.26 * [new ref] refs/pipelines/932118365 -> refs/pipelines/93211836527 * [new branch] master -> origin/master28Checking out a2b87e91 as detached HEAD (ref is master)...29Skipping Git submodules setup31Checking cache for qa-e2e-ruby-3.0-25fc54ff225c814107db3bf4a8c26e7a-16...32Downloading cache.zip from https://storage.googleapis.com/gitlab-qa-runner-cache-1/project/278964/qa-e2e-ruby-3.0-25fc54ff225c814107db3bf4a8c26e7a-16 33WARNING: .gems/gems/deprecation_toolkit-2.0.3/gemfiles/test/deprecations: chmod .gems/gems/deprecation_toolkit-2.0.3/gemfiles/test/deprecations: no such file or directory (suppressing repeats) 34Successfully extracted cache36Downloading artifacts for download-knapsack-report (4659949916)...37Downloading artifacts from coordinator... ok host=storage.googleapis.com id=4659949916 responseStatus=200 OK token=64_nK7Ly39Using docker image sha256:c542c7445bbcd8902b4aff9c0c23d65f9021b3d5ce9f8bef0c5978e178ee97cb for registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bullseye-ruby-3.0:bundler-2.3-docker-23.0.1 with digest registry.gitlab.com/gitlab-org/gitlab-build-images/debian-bullseye-ruby-3.0@sha256:3c33cd32b8b2bb06c7a413f6ed11411c2b00d5fcbd116ed9342af59ead5ca236 ...40$ echo "SUITE_RAN=true" > $QA_SUITE_STATUS_ENV_FILE41$ export BUNDLE_PREFIX=$([ "$RUN_WITH_BUNDLE" != "true" ] || echo "bundle exec")42$ if [ "$RUN_WITH_BUNDLE" == "true" ]; then # collapsed multi-line command43Bundle complete! 37 Gemfile dependencies, 135 gems now installed.44Use `bundle info [gemname]` to see where a bundled gem is installed.45$ export QA_COMMAND="$BUNDLE_PREFIX gitlab-qa ${QA_SCENARIO:=Test::Instance::Image} $RELEASE $GITLAB_QA_OPTS -- $QA_TESTS $QA_RSPEC_TAGS $RSPEC_REPORT_OPTS"46$ echo "Running - '$QA_COMMAND'"47Running - 'bundle exec gitlab-qa Test::Integration::GitalyCluster registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b -- --format QA::Support::JsonFormatter --out tmp/rspec-4659949946.json --format RspecJunitFormatter --out tmp/rspec-4659949946.xml --format html --out tmp/rspec-$(echo gitaly-cluster | sed 's/[ /]/_/g').htm --color --format documentation'48$ eval "$QA_COMMAND"49[Jul 15 2023 03:21:06 UTC (Gitlab QA)] INFO -- Shell command: `docker pull -q postgres:11`50[Jul 15 2023 03:21:10 UTC (Gitlab QA)] INFO -- Shell command: `docker container list --all --format '{{.Names}}' --filter name=^postgres$`51[Jul 15 2023 03:21:10 UTC (Gitlab QA)] INFO -- Shell command: `docker network list --format '{{.Name}}' --filter name=^test$`52[Jul 15 2023 03:21:10 UTC (Gitlab QA)] INFO -- Shell command: `docker network create test`53[Jul 15 2023 03:21:10 UTC (Gitlab QA)] INFO -- Shell command: `docker run -d --name postgres --net test --env POSTGRES_PASSWORD="SQL_PASSWORD" postgres:11`54[Jul 15 2023 03:21:12 UTC (Gitlab QA)] INFO -- Shell command: `docker exec postgres bash -c "psql -U postgres template1"`55[Jul 15 2023 03:21:13 UTC (Gitlab QA)] ERROR -- Shell command output:56psql: connection to server on socket "/var/run/postgresql/.s.PGSQL.5432" failed: No such file or directory57 Is the server running locally and accepting connections on that socket?58[Jul 15 2023 03:21:18 UTC (Gitlab QA)] INFO -- Shell command: `docker exec postgres bash -c "psql -U postgres template1"`59[Jul 15 2023 03:21:18 UTC (Gitlab QA)] INFO -- Shell command: `docker exec postgres bash -c "psql -U postgres -d template1 -c \"CREATE DATABASE praefect_production OWNER postgres\""`60[Jul 15 2023 03:21:18 UTC (Gitlab QA)] INFO -- Starting Gitaly Cluster61[Jul 15 2023 03:21:18 UTC (Gitlab QA)] INFO -- Shell command: `docker container list --all --format '{{.Names}}' --filter name=^alpine-bd5c45ff$`62[Jul 15 2023 03:21:18 UTC (Gitlab QA)] INFO -- Shell command: `docker login --username "gitlab-ci-token" --password "*****" registry.gitlab.com`63[Jul 15 2023 03:21:18 UTC (Gitlab QA)] INFO -- Shell command: `docker run -d --name alpine-bd5c45ff --volume authority:/etc/gitlab/trusted-certs:Z --volume gitlab-ssl:/etc/gitlab/ssl:Z alpine:latest tail -f /dev/null`64[Jul 15 2023 03:21:18 UTC (Gitlab QA)] INFO -- Shell command: `docker pull -q registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`65[Jul 15 2023 03:21:24 UTC (Gitlab QA)] INFO -- Shell command: `docker cp /builds/gitlab-org/gitlab/.gems/gems/gitlab-qa-12.1.0/tls_certificates/authority/. alpine-bd5c45ff:/etc/gitlab/trusted-certs`66[Jul 15 2023 03:21:25 UTC (Gitlab QA)] INFO -- Shell command: `docker cp /builds/gitlab-org/gitlab/.gems/gems/gitlab-qa-12.1.0/tls_certificates/gitlab/. alpine-bd5c45ff:/etc/gitlab/ssl`67[Jul 15 2023 03:21:25 UTC (Gitlab QA)] INFO -- Shell command: `docker ps -f name=alpine-bd5c45ff`68[Jul 15 2023 03:21:25 UTC (Gitlab QA)] INFO -- Shell command: `docker rm -f alpine-bd5c45ff`69[Jul 15 2023 03:21:30 UTC (Gitlab QA)] INFO -- Shell command: `docker login --username "gitlab-ci-token" --password "*****" registry.gitlab.com`70[Jul 15 2023 03:21:30 UTC (Gitlab QA)] INFO -- Shell command: `docker pull -q registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`71[Jul 15 2023 03:21:51 UTC (Gitlab QA)] INFO -- Shell command: `docker container list --all --format '{{.Names}}' --filter name=^gitlab-gitaly-cluster$`72[Jul 15 2023 03:21:51 UTC (Gitlab QA)] INFO -- Shell command: `docker container list --all --format '{{.Names}}' --filter name=^gitaly1$`73[Jul 15 2023 03:21:51 UTC (Gitlab QA)] INFO -- Shell command: `docker network list --format '{{.Name}}' --filter name=^test$`74[Jul 15 2023 03:21:51 UTC (Gitlab QA)] INFO -- Shell command: `docker network list --format '{{.Name}}' --filter name=^test$`75[Jul 15 2023 03:21:52 UTC (Gitlab QA)] INFO -- Shell command: `docker run -d --name gitlab-gitaly-cluster --net test --hostname gitlab-gitaly-cluster.test -p 80 --volume authority:/etc/gitlab/trusted-certs:Z --volume gitlab-ssl:/etc/gitlab/ssl:Z --volume /builds/gitlab-org/gitlab/gitlab-qa-run-2023-07-15-03-21-06-859725e3/gitlab-gitaly-cluster/logs:/var/log/gitlab:Z registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`76[Jul 15 2023 03:21:52 UTC (Gitlab QA)] INFO -- Shell command: `docker run -d --name gitaly1 --net test --hostname gitaly1.test -p 8075 --volume /builds/gitlab-org/gitlab/gitlab-qa-run-2023-07-15-03-21-06-859725e3/gitaly1/logs:/var/log/gitlab:z registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`77[Jul 15 2023 03:22:11 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly1 bash -c "echo \"postgresql['enable'] = false;78redis['enable'] = false;79nginx['enable'] = false;80puma['enable'] = false;81sidekiq['enable'] = false;82gitlab_workhorse['enable'] = false;83gitlab_rails['rake_cache_clear'] = false;84gitlab_rails['auto_migrate'] = false;85gitlab_exporter['enable'] = false;86praefect['enable'] = false;87prometheus['enable'] = true;88gitaly['enable'] = true;89gitaly['configuration'] = {90 'listen_addr': '0.0.0.0:8075',91 'prometheus_listen_addr': '0.0.0.0:9236',92 'auth_token': 'PRAEFECT_INTERNAL_TOKEN'93}94gitlab_shell['secret_token'] = 'GITLAB_SHELL_SECRET_TOKEN';95gitlab_rails['internal_api_url'] = 'http://gitlab-gitaly-cluster.test';96git_data_dirs({97 'gitaly1' => {98 'path' => '/var/opt/gitlab/git-data'99 },100 'gitaly2' => {101 'path' => '/var/opt/gitlab/git-data'102 },103 'gitaly3' => {104 'path' => '/var/opt/gitlab/git-data'105 }106});107\" > /etc/gitlab/gitlab.rb;"`108[Jul 15 2023 03:22:11 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitlab-gitaly-cluster bash -c "echo \"# Generated by GitLab QA Omnibus Configurator at 2023-07-15 03:21:06109# Gitlab::QA::Runtime::OmnibusConfigurations::Default110gitlab_rails['gitlab_default_theme'] = 10 # Light Red Theme111gitlab_rails['gitlab_disable_animations'] = true # Disable animations112gitlab_rails['application_settings_cache_seconds'] = 0 # Settings cache expiry113gitlab_rails['initial_root_password'] = '5iveL!fe' # Initial root password114external_url 'http://gitlab-gitaly-cluster.test';115git_data_dirs({116 'default' => {117 'gitaly_address' => 'tcp://praefect.test:2305',118 'gitaly_token' => 'PRAEFECT_EXTERNAL_TOKEN'119 }120});121gitaly['enable'] = false;122gitlab_shell['secret_token'] = 'GITLAB_SHELL_SECRET_TOKEN';123prometheus['scrape_configs'] = [124 {125 'job_name' => 'praefect',126 'static_configs' => [127 'targets' => [128 'praefect.test:9652'129 ]130 ]131 },132 {133 'job_name' => 'praefect-gitaly',134 'static_configs' => [135 'targets' => [136 'gitaly1.test:9236',137 'gitaly2.test:9236',138 'gitaly3.test:9236'139 ]140 ]141 }142];143gitlab_rails['env'] = {'GITLAB_LICENSE_MODE'=>'test', 'CUSTOMER_PORTAL_URL'=>'https://customers.staging.gitlab.com', 'GITLAB_QA_USER_AGENT'=>'*****', 'GITLAB_ALLOW_SEPARATE_CI_DATABASE'=>'true'}\" > /etc/gitlab/gitlab.rb;"`144[Jul 15 2023 03:22:11 UTC (Gitlab QA)] INFO -- Shell command: `docker attach --sig-proxy=false gitaly1`145[Jul 15 2023 03:22:11 UTC (Gitlab QA)] INFO -- Shell command: `docker attach --sig-proxy=false gitlab-gitaly-cluster`146[Jul 15 2023 03:23:28 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly1 bash -c "mkdir -p /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d"`147[Jul 15 2023 03:23:28 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly1 bash -c "echo '#!/usr/bin/env bash148if [[ \$GL_PROJECT_PATH =~ 'reject-prereceive' ]]; then149 echo 'GL-HOOK-ERR: Custom error message rejecting prereceive hook for projects with GL_PROJECT_PATH matching pattern reject-prereceive'150 exit 1151fi152' > /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/pre-receive.d;"`153[Jul 15 2023 03:23:28 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly1 bash -c "chmod +x /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/*"`154[Jul 15 2023 03:23:28 UTC (Gitlab QA)] INFO -- Shell command: `docker login --username "gitlab-ci-token" --password "*****" registry.gitlab.com`155[Jul 15 2023 03:23:28 UTC (Gitlab QA)] INFO -- Shell command: `docker pull -q registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`156[Jul 15 2023 03:23:29 UTC (Gitlab QA)] INFO -- Shell command: `docker container list --all --format '{{.Names}}' --filter name=^gitaly2$`157[Jul 15 2023 03:23:29 UTC (Gitlab QA)] INFO -- Shell command: `docker network list --format '{{.Name}}' --filter name=^test$`158[Jul 15 2023 03:23:29 UTC (Gitlab QA)] INFO -- Shell command: `docker run -d --name gitaly2 --net test --hostname gitaly2.test -p 8075 --volume /builds/gitlab-org/gitlab/gitlab-qa-run-2023-07-15-03-21-06-859725e3/gitaly2/logs:/var/log/gitlab:z registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`159[Jul 15 2023 03:23:29 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly2 bash -c "echo \"postgresql['enable'] = false;160redis['enable'] = false;161nginx['enable'] = false;162puma['enable'] = false;163sidekiq['enable'] = false;164gitlab_workhorse['enable'] = false;165gitlab_rails['rake_cache_clear'] = false;166gitlab_rails['auto_migrate'] = false;167gitlab_exporter['enable'] = false;168praefect['enable'] = false;169prometheus['enable'] = true;170gitaly['enable'] = true;171gitaly['configuration'] = {172 'listen_addr': '0.0.0.0:8075',173 'prometheus_listen_addr': '0.0.0.0:9236',174 'auth_token': 'PRAEFECT_INTERNAL_TOKEN'175}176gitlab_shell['secret_token'] = 'GITLAB_SHELL_SECRET_TOKEN';177gitlab_rails['internal_api_url'] = 'http://gitlab-gitaly-cluster.test';178git_data_dirs({179 'gitaly1' => {180 'path' => '/var/opt/gitlab/git-data'181 },182 'gitaly2' => {183 'path' => '/var/opt/gitlab/git-data'184 },185 'gitaly3' => {186 'path' => '/var/opt/gitlab/git-data'187 }188});189\" > /etc/gitlab/gitlab.rb;"`190[Jul 15 2023 03:23:29 UTC (Gitlab QA)] INFO -- Shell command: `docker attach --sig-proxy=false gitaly2`191[Jul 15 2023 03:24:45 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly2 bash -c "mkdir -p /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d"`192[Jul 15 2023 03:24:46 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly2 bash -c "echo '#!/usr/bin/env bash193if [[ \$GL_PROJECT_PATH =~ 'reject-prereceive' ]]; then194 echo 'GL-HOOK-ERR: Custom error message rejecting prereceive hook for projects with GL_PROJECT_PATH matching pattern reject-prereceive'195 exit 1196fi197' > /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/pre-receive.d;"`198[Jul 15 2023 03:24:46 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly2 bash -c "chmod +x /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/*"`199[Jul 15 2023 03:24:46 UTC (Gitlab QA)] INFO -- Shell command: `docker login --username "gitlab-ci-token" --password "*****" registry.gitlab.com`200[Jul 15 2023 03:24:46 UTC (Gitlab QA)] INFO -- Shell command: `docker pull -q registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`201[Jul 15 2023 03:24:46 UTC (Gitlab QA)] INFO -- Shell command: `docker container list --all --format '{{.Names}}' --filter name=^gitaly3$`202[Jul 15 2023 03:24:46 UTC (Gitlab QA)] INFO -- Shell command: `docker network list --format '{{.Name}}' --filter name=^test$`203[Jul 15 2023 03:24:46 UTC (Gitlab QA)] INFO -- Shell command: `docker run -d --name gitaly3 --net test --hostname gitaly3.test -p 8075 --volume /builds/gitlab-org/gitlab/gitlab-qa-run-2023-07-15-03-21-06-859725e3/gitaly3/logs:/var/log/gitlab:z registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`204[Jul 15 2023 03:24:48 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly3 bash -c "echo \"postgresql['enable'] = false;205redis['enable'] = false;206nginx['enable'] = false;207puma['enable'] = false;208sidekiq['enable'] = false;209gitlab_workhorse['enable'] = false;210gitlab_rails['rake_cache_clear'] = false;211gitlab_rails['auto_migrate'] = false;212gitlab_exporter['enable'] = false;213praefect['enable'] = false;214prometheus['enable'] = true;215gitaly['enable'] = true;216gitaly['configuration'] = {217 'listen_addr': '0.0.0.0:8075',218 'prometheus_listen_addr': '0.0.0.0:9236',219 'auth_token': 'PRAEFECT_INTERNAL_TOKEN'220}221gitlab_shell['secret_token'] = 'GITLAB_SHELL_SECRET_TOKEN';222gitlab_rails['internal_api_url'] = 'http://gitlab-gitaly-cluster.test';223git_data_dirs({224 'gitaly1' => {225 'path' => '/var/opt/gitlab/git-data'226 },227 'gitaly2' => {228 'path' => '/var/opt/gitlab/git-data'229 },230 'gitaly3' => {231 'path' => '/var/opt/gitlab/git-data'232 }233});234\" > /etc/gitlab/gitlab.rb;"`235[Jul 15 2023 03:24:48 UTC (Gitlab QA)] INFO -- Shell command: `docker attach --sig-proxy=false gitaly3`236[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- Waiting for GitLab to become healthy ...237[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- Shell command: `docker inspect --format='{{json .State.Health.Status}}' gitlab-gitaly-cluster`238[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- Shell command: `docker port gitlab-gitaly-cluster 80/tcp`239[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- -> GitLab is available at `http://docker:32769`!240[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitlab-gitaly-cluster bash -c "mkdir -p /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d"`241[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitlab-gitaly-cluster bash -c "echo '#!/usr/bin/env bash242if [[ \$GL_PROJECT_PATH =~ 'reject-prereceive' ]]; then243 echo 'GL-HOOK-ERR: Custom error message rejecting prereceive hook for projects with GL_PROJECT_PATH matching pattern reject-prereceive'244 exit 1245fi246' > /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/pre-receive.d;"`247[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitlab-gitaly-cluster bash -c "chmod +x /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/*"`248[Jul 15 2023 03:25:35 UTC (Gitlab QA)] INFO -- Shell command: `docker cp /builds/gitlab-org/gitlab/.gems/gems/gitlab-qa-12.1.0/support/data gitlab-gitaly-cluster:/tmp/data-seeds`249[Jul 15 2023 03:25:36 UTC (Gitlab QA)] INFO -- Running exec_commands...250[Jul 15 2023 03:25:36 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitlab-gitaly-cluster bash -c "gitlab-rails runner /tmp/data-seeds/admin_access_token_seed.rb"`251[Jul 15 2023 03:25:42 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly3 bash -c "mkdir -p /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d"`252[Jul 15 2023 03:25:42 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly3 bash -c "echo '#!/usr/bin/env bash253if [[ \$GL_PROJECT_PATH =~ 'reject-prereceive' ]]; then254 echo 'GL-HOOK-ERR: Custom error message rejecting prereceive hook for projects with GL_PROJECT_PATH matching pattern reject-prereceive'255 exit 1256fi257' > /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/pre-receive.d;"`258[Jul 15 2023 03:25:42 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitaly3 bash -c "chmod +x /opt/gitlab/embedded/service/gitlab-shell/hooks/pre-receive.d/*"`259[Jul 15 2023 03:25:42 UTC (Gitlab QA)] INFO -- Shell command: `docker login --username "gitlab-ci-token" --password "*****" registry.gitlab.com`260[Jul 15 2023 03:25:43 UTC (Gitlab QA)] INFO -- Shell command: `docker pull -q registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`261[Jul 15 2023 03:25:43 UTC (Gitlab QA)] INFO -- Shell command: `docker container list --all --format '{{.Names}}' --filter name=^praefect$`262[Jul 15 2023 03:25:44 UTC (Gitlab QA)] INFO -- Shell command: `docker network list --format '{{.Name}}' --filter name=^test$`263[Jul 15 2023 03:25:44 UTC (Gitlab QA)] INFO -- Shell command: `docker run -d --name praefect --net test --hostname praefect.test -p 2305 --volume /builds/gitlab-org/gitlab/gitlab-qa-run-2023-07-15-03-21-06-859725e3/praefect/logs:/var/log/gitlab:z registry.gitlab.com/gitlab-org/build/omnibus-gitlab-mirror/gitlab-ce:a2b87e9110db59ac657374e5596d908371351a2b`264[Jul 15 2023 03:25:45 UTC (Gitlab QA)] INFO -- Shell command: `docker exec praefect bash -c "echo \"postgresql['enable'] = false;265redis['enable'] = false;266nginx['enable'] = false;267puma['enable'] = false;268sidekiq['enable'] = false;269gitlab_workhorse['enable'] = false;270gitlab_rails['rake_cache_clear'] = false;271gitlab_rails['auto_migrate'] = false;272gitlab_exporter['enable'] = false;273gitaly['enable'] = false;274prometheus['enable'] = true;275praefect['enable'] = true;276praefect['configuration'] = {277 listen_addr: '0.0.0.0:2305',278 prometheus_listen_addr: '0.0.0.0:9652',279 auth: {280 token: 'PRAEFECT_EXTERNAL_TOKEN'281 },282 reconciliation: {283 scheduling_interval: '10s'284 },285 database: {286 host: 'postgres.test',287 port: 5432,288 user: 'postgres',289 password: 'SQL_PASSWORD',290 dbname: 'praefect_production',291 sslmode: 'disable'292 },293 virtual_storage: [294 {295 name: 'default',296 node: [297 {298 'storage': 'gitaly1',299 'address': 'tcp://gitaly1.test:8075',300 'token': 'PRAEFECT_INTERNAL_TOKEN'301 },302 {303 'storage': 'gitaly2',304 'address': 'tcp://gitaly2.test:8075',305 'token': 'PRAEFECT_INTERNAL_TOKEN'306 },307 {308 'storage': 'gitaly3',309 'address': 'tcp://gitaly3.test:8075',310 'token': 'PRAEFECT_INTERNAL_TOKEN'311 }312 ],313 }314 ]315}316\" > /etc/gitlab/gitlab.rb;"`317[Jul 15 2023 03:25:45 UTC (Gitlab QA)] INFO -- Shell command: `docker attach --sig-proxy=false praefect`318[Jul 15 2023 03:26:32 UTC (Gitlab QA)] INFO -- Shell command: `docker exec praefect bash -c "praefect -config /var/opt/gitlab/praefect/cluster_config.toml check || true"`319[Jul 15 2023 03:26:33 UTC (Gitlab QA)] INFO -- Shell command: `docker inspect -f '{{range.NetworkSettings.Networks}}{{.IPAddress}}{{end}}' praefect`320[Jul 15 2023 03:26:33 UTC (Gitlab QA)] INFO -- Gitaly Cluster Ready321[Jul 15 2023 03:26:33 UTC (Gitlab QA)] INFO -- Running Gitaly Cluster specs!322[Jul 15 2023 03:26:33 UTC (Gitlab QA)] INFO -- Shell command: `docker login --username "gitlab-ci-token" --password "*****" registry.gitlab.com`323[Jul 15 2023 03:26:33 UTC (Gitlab QA)] INFO -- Shell command: `docker pull -q registry.gitlab.com/gitlab-org/gitlab/gitlab-ce-qa:a2b87e9110db59ac657374e5596d908371351a2b`324[Jul 15 2023 03:27:32 UTC (Gitlab QA)] INFO -- Running test suite `Test::Instance::All` for gitlab-ce325[Jul 15 2023 03:27:32 UTC (Gitlab QA)] INFO -- Shell command: `docker run -t --rm --net=test --env QA_AWS_S3_REGION="$QA_AWS_S3_REGION" --env QA_FACEBOOK_OAUTH_APP_ID="$QA_FACEBOOK_OAUTH_APP_ID" --env QA_GOOGLE_CDN_JSON_KEY="$QA_GOOGLE_CDN_JSON_KEY" --env QA_SUITE_STATUS_ENV_FILE="$QA_SUITE_STATUS_ENV_FILE" --env QA_THIRD_PARTY_DOCKER_REGISTRY="$QA_THIRD_PARTY_DOCKER_REGISTRY" --env QA_SAVE_TEST_METRICS="$QA_SAVE_TEST_METRICS" --env QA_GOOGLE_CDN_SIGNURL_KEY_NAME="$QA_GOOGLE_CDN_SIGNURL_KEY_NAME" --env QA_1P_PASSWORD="$QA_1P_PASSWORD" --env QA_REMOTE_GRID_USERNAME="$QA_REMOTE_GRID_USERNAME" --env QA_GOOGLE_CDN_SIGNURL_KEY="$QA_GOOGLE_CDN_SIGNURL_KEY" --env QA_TEST_CASE_PROJECT_TOKEN="$QA_TEST_CASE_PROJECT_TOKEN" --env QA_GITHUB_USERNAME="$QA_GITHUB_USERNAME" --env QA_SLOW_CONNECTION_THROUGHPUT_KBPS="$QA_SLOW_CONNECTION_THROUGHPUT_KBPS" --env QA_GITHUB_PASSWORD="$QA_GITHUB_PASSWORD" --env QA_ARTIFACTS_DIR="$QA_ARTIFACTS_DIR" --env QA_GITLAB_TLS_CERTIFICATE="$QA_GITLAB_TLS_CERTIFICATE" --env QA_RUN_TYPE="$QA_RUN_TYPE" --env QA_JIRA_ADMIN_PASSWORD="$QA_JIRA_ADMIN_PASSWORD" --env QA_GITHUB_OAUTH_APP_SECRET="$QA_GITHUB_OAUTH_APP_SECRET" --env QA_PATH="$QA_PATH" --env QA_JIRA_ADMIN_USERNAME="$QA_JIRA_ADMIN_USERNAME" --env QA_ADMIN_ACCESS_TOKEN="$QA_ADMIN_ACCESS_TOKEN" --env QA_COMMAND="$QA_COMMAND" --env QA_EE_LICENSE="$QA_EE_LICENSE" --env QA_1P_EMAIL="$QA_1P_EMAIL" --env QA_EE_ACTIVATION_CODE="$QA_EE_ACTIVATION_CODE" --env QA_GOOGLE_CLIENT_EMAIL="$QA_GOOGLE_CLIENT_EMAIL" --env QA_ALLURE_AWS_SECRET_ACCESS_KEY="$QA_ALLURE_AWS_SECRET_ACCESS_KEY" --env QA_GCS_BUCKET_NAME="$QA_GCS_BUCKET_NAME" --env QA_FACEBOOK_OAUTH_APP_SECRET="$QA_FACEBOOK_OAUTH_APP_SECRET" --env QA_GOOGLE_PROJECT="$QA_GOOGLE_PROJECT" --env QA_KNAPSACK_REPORT_GCS_CREDENTIALS="$QA_KNAPSACK_REPORT_GCS_CREDENTIALS" --env QA_AWS_S3_KEY_ID="$QA_AWS_S3_KEY_ID" --env QA_RUN_ALL_TESTS="$QA_RUN_ALL_TESTS" --env QA_GITLAB_CI_TOKEN="$QA_GITLAB_CI_TOKEN" --env QA_REMOTE_GRID_ACCESS_KEY="$QA_REMOTE_GRID_ACCESS_KEY" --env QA_FRAMEWORK_CHANGES="$QA_FRAMEWORK_CHANGES" --env QA_INTERCEPT_REQUESTS="$QA_INTERCEPT_REQUESTS" --env QA_INFLUXDB_URL="$QA_INFLUXDB_URL" --env QA_THIRD_PARTY_DOCKER_USER="$QA_THIRD_PARTY_DOCKER_USER" --env QA_THIRD_PARTY_DOCKER_PASSWORD="$QA_THIRD_PARTY_DOCKER_PASSWORD" --env QA_1P_SECRET="$QA_1P_SECRET" --env QA_AWS_S3_ACCESS_KEY="$QA_AWS_S3_ACCESS_KEY" --env QA_LOG_LEVEL="$QA_LOG_LEVEL" --env QA_GITHUB_OAUTH_APP_ID="$QA_GITHUB_OAUTH_APP_ID" --env QA_EXPORT_TEST_METRICS="$QA_EXPORT_TEST_METRICS" --env QA_GOOGLE_CDN_LB="$QA_GOOGLE_CDN_LB" --env QA_1P_GITHUB_UUID="$QA_1P_GITHUB_UUID" --env QA_FACEBOOK_PASSWORD="$QA_FACEBOOK_PASSWORD" --env QA_GCS_CDN_BUCKET_NAME="$QA_GCS_CDN_BUCKET_NAME" --env QA_SCENARIO="$QA_SCENARIO" --env QA_GOOGLE_JSON_KEY="$QA_GOOGLE_JSON_KEY" --env QA_TRIGGER_AUTO_QUARANTINE="$QA_TRIGGER_AUTO_QUARANTINE" --env QA_SUITES="$QA_SUITES" --env QA_RUN_ALL_E2E_LABEL="$QA_RUN_ALL_E2E_LABEL" --env QA_ALLURE_AWS_ACCESS_KEY_ID="$QA_ALLURE_AWS_ACCESS_KEY_ID" --env QA_AWS_S3_BUCKET_NAME="$QA_AWS_S3_BUCKET_NAME" --env QA_GENERATE_ALLURE_REPORT="$QA_GENERATE_ALLURE_REPORT" --env QA_CAN_TEST_PRAEFECT="$QA_CAN_TEST_PRAEFECT" --env QA_RUN_TESTS_ON_GDK="$QA_RUN_TESTS_ON_GDK" --env QA_INFLUXDB_TOKEN="$QA_INFLUXDB_TOKEN" --env QA_TEST_LICENSE_MODE="$QA_TEST_LICENSE_MODE" --env QA_TEST_SESSION_TOKEN="$QA_TEST_SESSION_TOKEN" --env QA_SLOW_CONNECTION_LATENCY_MS="$QA_SLOW_CONNECTION_LATENCY_MS" --env QA_RESULTS_ISSUE_PROJECT_TOKEN="$QA_RESULTS_ISSUE_PROJECT_TOKEN" --env QA_GITHUB_ACCESS_TOKEN="$QA_GITHUB_ACCESS_TOKEN" --env QA_FACEBOOK_USERNAME="$QA_FACEBOOK_USERNAME" --env QA_THIRD_PARTY_DOCKER_REPOSITORY="$QA_THIRD_PARTY_DOCKER_REPOSITORY" --env QA_SELENOID_BROWSER_VERSION="111.0" --env QA_VIDEO_RECORDER_IMAGE="presidenten/selenoid-manual-video-recorder" --env QA_VIDEO_RECORDER_VERSION="latest" --env QA_SELENOID_BROWSER_IMAGE="selenoid/chrome" --env GITLAB_QA_ADMIN_ACCESS_TOKEN="$GITLAB_QA_ADMIN_ACCESS_TOKEN" --env GITLAB_QA_PASSWORD_1="$GITLAB_QA_PASSWORD_1" --env GITLAB_QA_PASSWORD_2="$GITLAB_QA_PASSWORD_2" --env CI="$CI" --env CI_JOB_NAME="$CI_JOB_NAME" --env CI_JOB_NAME_SLUG="$CI_JOB_NAME_SLUG" --env CI_JOB_URL="$CI_JOB_URL" --env CI_JOB_TOKEN="$CI_JOB_TOKEN" --env CI_RUNNER_ID="$CI_RUNNER_ID" --env CI_SERVER_HOST="$CI_SERVER_HOST" --env CI_NODE_TOTAL="$CI_NODE_TOTAL" --env CI_PROJECT_NAME="$CI_PROJECT_NAME" --env CI_PROJECT_PATH="$CI_PROJECT_PATH" --env CI_PIPELINE_SOURCE="$CI_PIPELINE_SOURCE" --env CI_PIPELINE_URL="$CI_PIPELINE_URL" --env CI_PIPELINE_CREATED_AT="$CI_PIPELINE_CREATED_AT" --env GITLAB_CI="$GITLAB_CI" --env GITLAB_QA_USER_AGENT="$GITLAB_QA_USER_AGENT" --env GITLAB_INITIAL_ROOT_PASSWORD="5iveL!fe" --env COLORIZED_LOGS="$COLORIZED_LOGS" --env RELEASE="$RELEASE" --env RELEASE_REGISTRY_URL="registry.gitlab.com" --env RELEASE_REGISTRY_USERNAME="gitlab-ci-token" --env RELEASE_REGISTRY_PASSWORD="[MASKED]" --env SELENOID_DIRECTORY="/builds/gitlab-org/gitlab/gitlab-qa-run-2023-07-15-03-21-06-859725e3/selenoid" --env SCHEDULE_TYPE="$SCHEDULE_TYPE" --volume /builds/gitlab-org/gitlab/gitlab-qa-run-2023-07-15-03-21-06-859725e3/gitlab-ce-qa-60d4ea64:/home/gitlab/qa/tmp:z --volume /var/run/docker.sock:/var/run/docker.sock:z --name gitlab-ce-qa-60d4ea64 registry.gitlab.com/gitlab-org/gitlab/gitlab-ce-qa:a2b87e9110db59ac657374e5596d908371351a2b Test::Instance::All http://gitlab-gitaly-cluster.test -- --format QA::Support::JsonFormatter --out tmp/rspec-4659949946.json --format RspecJunitFormatter --out tmp/rspec-4659949946.xml --format html --out tmp/rspec-gitaly-cluster.htm --color --format documentation --tag gitaly_cluster`3262023-07-15 03:27:38 / CONF :: 327 ==> Base URL: http://gitlab-gitaly-cluster.test328 ==> Browser: #<Selenium::WebDriver::Chrome::Driver:0x00007f0654a879e0>329 ==> Libraries: Chemlab::Vendor330[Jul 15 2023 03:27:38 UTC (QA Tests)] INFO -- Caching token for username: root, last six chars of token:sixwPA331[Jul 15 2023 03:27:38 UTC (QA Tests)] INFO -- Browser: chrome332[Jul 15 2023 03:27:38 UTC (QA Tests)] INFO -- Performing sanity check for environment!333Run options:334 include {:gitaly_cluster=>true}335 exclude {:geo=>true, :requires_praefect=>true}336Randomized with seed 57545337Systems338 Gitaly distributed reads339[Jul 15 2023 03:27:39 UTC (QA Tests)] INFO -- Starting test: Systems Gitaly distributed reads reads from each node340[Jul 15 2023 03:27:39 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`341[Jul 15 2023 03:27:39 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""342`343[Jul 15 2023 03:27:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`344[Jul 15 2023 03:27:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`345[Jul 15 2023 03:27:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`346[Jul 15 2023 03:27:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`347[Jul 15 2023 03:27:40 UTC (QA Tests)] INFO -- Waiting for health check on praefect348[Jul 15 2023 03:27:40 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`349[Jul 15 2023 03:27:41 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1350[Jul 15 2023 03:27:41 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`351[Jul 15 2023 03:27:41 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""352`353[Jul 15 2023 03:27:42 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2354[Jul 15 2023 03:27:42 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`355[Jul 15 2023 03:27:42 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""356`357[Jul 15 2023 03:27:43 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3358[Jul 15 2023 03:27:43 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`359[Jul 15 2023 03:27:43 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""360`361[Jul 15 2023 03:27:44 UTC (QA Tests)] INFO -- Retrieved cached token for username: root, last six chars of token:sixwPA362[Jul 15 2023 03:27:44 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::PersonalAccessToken with name 'api-pat-root-hb0sw9b4' via cache in 0.0 seconds363[Jul 15 2023 03:27:45 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Sandbox with full_path 'gitlab-qa-sandbox-group-7' via api in 0.92 seconds364[Jul 15 2023 03:27:45 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Group with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f' via api in 1.9 seconds365[Jul 15 2023 03:27:48 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Project with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f/gitaly_cluster-acefbdbcb1d6d582' via api in 4.31 seconds366[Jul 15 2023 03:27:48 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue where state = 'ready' or state = 'in_progress';\""367`368[Jul 15 2023 03:27:48 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[1]"'`369[Jul 15 2023 03:28:18 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`370[Jul 15 2023 03:28:18 UTC (QA Tests)] INFO -- Reading from the repository371[Jul 15 2023 03:28:18 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`372[Jul 15 2023 03:28:24 UTC (QA Tests)] INFO -- Reading from the repository373[Jul 15 2023 03:28:24 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`374[Jul 15 2023 03:28:24 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`375 reads from each node376 when a node is unhealthy377[Jul 15 2023 03:28:24 UTC (QA Tests)] INFO -- Starting test: Systems Gitaly distributed reads when a node is unhealthy does not read from the unhealthy node378[Jul 15 2023 03:28:24 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`379[Jul 15 2023 03:28:25 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""380`381[Jul 15 2023 03:28:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`382[Jul 15 2023 03:28:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`383[Jul 15 2023 03:28:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`384[Jul 15 2023 03:28:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`385[Jul 15 2023 03:28:25 UTC (QA Tests)] INFO -- Waiting for health check on praefect386[Jul 15 2023 03:28:25 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`387[Jul 15 2023 03:28:26 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1388[Jul 15 2023 03:28:26 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`389[Jul 15 2023 03:28:26 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""390`391[Jul 15 2023 03:28:27 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2392[Jul 15 2023 03:28:27 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`393[Jul 15 2023 03:28:27 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""394`395[Jul 15 2023 03:28:28 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3396[Jul 15 2023 03:28:28 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`397[Jul 15 2023 03:28:28 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""398`399[Jul 15 2023 03:28:29 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Sandbox with full_path 'gitlab-qa-sandbox-group-7' via api in 0.19 seconds400[Jul 15 2023 03:28:29 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Group with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f' via api in 0.27 seconds401[Jul 15 2023 03:28:31 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Project with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f/gitaly_cluster-ae31dbbc0d9e3672' via api in 2.35 seconds402[Jul 15 2023 03:28:31 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue where state = 'ready' or state = 'in_progress';\""403`404[Jul 15 2023 03:28:31 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[2]"'`405[Jul 15 2023 03:29:00 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`406[Jul 15 2023 03:29:00 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly2`407[Jul 15 2023 03:29:01 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""408`409[Jul 15 2023 03:29:02 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""410`411[Jul 15 2023 03:29:03 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""412`413[Jul 15 2023 03:29:04 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""414`415[Jul 15 2023 03:29:05 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""416`417[Jul 15 2023 03:29:06 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""418`419[Jul 15 2023 03:29:07 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""420`421[Jul 15 2023 03:29:09 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""422`423[Jul 15 2023 03:29:10 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""424`425[Jul 15 2023 03:29:10 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`426[Jul 15 2023 03:29:10 UTC (QA Tests)] INFO -- Reading from the repository427[Jul 15 2023 03:29:14 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`428[Jul 15 2023 03:29:15 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`429[Jul 15 2023 03:29:16 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`430[Jul 15 2023 03:29:18 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`431[Jul 15 2023 03:29:19 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`432[Jul 15 2023 03:29:20 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`433[Jul 15 2023 03:29:21 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`434[Jul 15 2023 03:29:22 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`435[Jul 15 2023 03:29:23 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`436[Jul 15 2023 03:29:24 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`437[Jul 15 2023 03:29:24 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'curl -s http://localhost:9090/api/v1/query?query=gitaly_praefect_read_distribution'`438[Jul 15 2023 03:29:24 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`439[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly2`440[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly2`441 does not read from the unhealthy node442Systems443 Gitaly backend node recovery444[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Starting test: Systems Gitaly backend node recovery recovers from dataloss445[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`446[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""447`448[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`449[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`450[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`451[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`452[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Waiting for health check on praefect453[Jul 15 2023 03:29:25 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`454[Jul 15 2023 03:29:26 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1455[Jul 15 2023 03:29:26 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`456[Jul 15 2023 03:29:27 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""457`458[Jul 15 2023 03:29:27 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2459[Jul 15 2023 03:29:27 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`460[Jul 15 2023 03:29:28 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""461`462[Jul 15 2023 03:29:28 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3463[Jul 15 2023 03:29:28 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`464[Jul 15 2023 03:29:29 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""465`466[Jul 15 2023 03:29:29 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Sandbox with full_path 'gitlab-qa-sandbox-group-7' via api in 0.07 seconds467[Jul 15 2023 03:29:29 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Group with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f' via api in 0.2 seconds468[Jul 15 2023 03:29:30 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Project with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f/gitaly_cluster-823e95614c527c00' via api in 0.98 seconds469[Jul 15 2023 03:29:30 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue where state = 'ready' or state = 'in_progress';\""470`471[Jul 15 2023 03:29:30 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[3]"'`472[Jul 15 2023 03:29:59 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`473[Jul 15 2023 03:30:00 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly1`474[Jul 15 2023 03:30:00 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""475`476[Jul 15 2023 03:30:01 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""477`478[Jul 15 2023 03:30:02 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""479`480[Jul 15 2023 03:30:03 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""481`482[Jul 15 2023 03:30:04 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""483`484[Jul 15 2023 03:30:05 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""485`486[Jul 15 2023 03:30:07 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""487`488[Jul 15 2023 03:30:08 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""489`490[Jul 15 2023 03:30:09 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""491`492[Jul 15 2023 03:30:09 UTC (QA Tests)] INFO -- Waiting for health check failure on gitaly1493[Jul 15 2023 03:30:09 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""494`495[Jul 15 2023 03:30:11 UTC (QA Tests)] INFO -- QA::Resource::Project - wait_for_push with commit message "pushed after failover"496[Jul 15 2023 03:30:11 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Repository::ProjectPush via browser_ui in 2.12 seconds497[Jul 15 2023 03:30:11 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select job from replication_queue498where state = 'ready'499 and job ->> 'change' = 'update'500 and job ->> 'target_node_storage' = 'gitaly1';501\""502`503[Jul 15 2023 03:30:11 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`504[Jul 15 2023 03:30:12 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly1`505[Jul 15 2023 03:30:12 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly1`506[Jul 15 2023 03:30:12 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1507[Jul 15 2023 03:30:12 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`508[Jul 15 2023 03:30:13 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""509`510[Jul 15 2023 03:30:13 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2511[Jul 15 2023 03:30:13 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`512[Jul 15 2023 03:30:13 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""513`514[Jul 15 2023 03:30:14 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3515[Jul 15 2023 03:30:14 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`516[Jul 15 2023 03:30:14 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""517`518[Jul 15 2023 03:30:15 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue where state = 'ready' or state = 'in_progress';\""519`520[Jul 15 2023 03:30:15 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[3]"'`521[Jul 15 2023 03:30:44 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`522[Jul 15 2023 03:30:44 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly2`523[Jul 15 2023 03:30:45 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""524`525[Jul 15 2023 03:30:46 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""526`527[Jul 15 2023 03:30:47 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""528`529[Jul 15 2023 03:30:48 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""530`531[Jul 15 2023 03:30:49 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""532`533[Jul 15 2023 03:30:50 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""534`535[Jul 15 2023 03:30:51 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""536`537[Jul 15 2023 03:30:53 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""538`539[Jul 15 2023 03:30:54 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""540`541[Jul 15 2023 03:30:54 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`542[Jul 15 2023 03:30:54 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly3`543[Jul 15 2023 03:30:54 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""544`545[Jul 15 2023 03:30:55 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""546`547[Jul 15 2023 03:30:56 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""548`549[Jul 15 2023 03:30:58 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""550`551[Jul 15 2023 03:30:59 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""552`553[Jul 15 2023 03:31:00 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""554`555[Jul 15 2023 03:31:01 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""556`557[Jul 15 2023 03:31:02 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""558`559[Jul 15 2023 03:31:03 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""560`561[Jul 15 2023 03:31:04 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""562`563[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`564[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""565`566[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`567[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`568[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly2`569[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly2`570[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`571[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly3`572[Jul 15 2023 03:31:05 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly3`573[Jul 15 2023 03:31:06 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`574[Jul 15 2023 03:31:06 UTC (QA Tests)] INFO -- Waiting for health check on praefect575[Jul 15 2023 03:31:06 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`576[Jul 15 2023 03:31:06 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1577[Jul 15 2023 03:31:06 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`578[Jul 15 2023 03:31:07 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""579`580[Jul 15 2023 03:31:07 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2581[Jul 15 2023 03:31:07 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`582[Jul 15 2023 03:31:08 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""583`584[Jul 15 2023 03:31:08 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3585[Jul 15 2023 03:31:08 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`586[Jul 15 2023 03:31:09 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""587`588 recovers from dataloss589Systems590 Gitaly Cluster replication queue591[Jul 15 2023 03:31:09 UTC (QA Tests)] INFO -- Starting test: Systems Gitaly Cluster replication queue allows replication of different repository after interruption592[Jul 15 2023 03:31:09 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`593[Jul 15 2023 03:31:09 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""594`595[Jul 15 2023 03:31:09 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`596[Jul 15 2023 03:31:10 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`597[Jul 15 2023 03:31:10 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`598[Jul 15 2023 03:31:10 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`599[Jul 15 2023 03:31:10 UTC (QA Tests)] INFO -- Waiting for health check on praefect600[Jul 15 2023 03:31:10 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`601[Jul 15 2023 03:31:11 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1602[Jul 15 2023 03:31:11 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`603[Jul 15 2023 03:31:11 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""604`605[Jul 15 2023 03:31:12 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2606[Jul 15 2023 03:31:12 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`607[Jul 15 2023 03:31:12 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""608`609[Jul 15 2023 03:31:13 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3610[Jul 15 2023 03:31:13 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`611[Jul 15 2023 03:31:13 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""612`613[Jul 15 2023 03:31:13 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`614[Jul 15 2023 03:31:14 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly2`615[Jul 15 2023 03:31:14 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""616`617[Jul 15 2023 03:31:15 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""618`619[Jul 15 2023 03:31:16 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""620`621[Jul 15 2023 03:31:17 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""622`623[Jul 15 2023 03:31:18 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""624`625[Jul 15 2023 03:31:19 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""626`627[Jul 15 2023 03:31:20 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""628`629[Jul 15 2023 03:31:22 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""630`631[Jul 15 2023 03:31:23 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""632`633[Jul 15 2023 03:31:24 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""634`635[Jul 15 2023 03:31:24 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Sandbox with full_path 'gitlab-qa-sandbox-group-7' via api in 0.06 seconds636[Jul 15 2023 03:31:24 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Group with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f' via api in 0.12 seconds637[Jul 15 2023 03:31:25 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Project with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f/gitaly_cluster-4f28cac41abf0193' via api in 1.21 seconds638[Jul 15 2023 03:31:48 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`639[Jul 15 2023 03:31:48 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly2`640[Jul 15 2023 03:31:48 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly2`641[Jul 15 2023 03:31:48 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue_lock where acquired = 't';\""642`643[Jul 15 2023 03:31:48 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue_lock where acquired = 't';\""644`645[Jul 15 2023 03:31:48 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue_lock where acquired = 't';\""646`647[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue_lock where acquired = 't';\""648`649[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue_lock where acquired = 't';\""650`651[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue_lock where acquired = 't';\""652`653[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue_lock where acquired = 't';\""654`655[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`656[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Executing: `docker pause praefect`657[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Setting jobs in replication queue to `in_progress` and acquiring locks658[Jul 15 2023 03:31:49 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"update replication_queue set state = 'in_progress';659insert into replication_queue_job_lock (job_id, lock_id, triggered_at)660 select id, rq.lock_id, created_at from replication_queue rq661 left join replication_queue_job_lock rqjl on rq.id = rqjl.job_id662 where state = 'in_progress' and rqjl.job_id is null;663update replication_queue_lock set acquired = 't';664\""665`666[Jul 15 2023 03:31:50 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`667[Jul 15 2023 03:31:50 UTC (QA Tests)] INFO -- Executing: `docker unpause praefect`668[Jul 15 2023 03:31:50 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} praefect`669[Jul 15 2023 03:31:50 UTC (QA Tests)] INFO -- Waiting for health check on praefect670[Jul 15 2023 03:31:50 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`671[Jul 15 2023 03:31:51 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Sandbox with full_path 'gitlab-qa-sandbox-group-7' via api in 0.06 seconds672[Jul 15 2023 03:31:51 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Group with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f' via api in 0.12 seconds673[Jul 15 2023 03:31:53 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Project with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f/the_awesome_project-b1086b6e2c672294' via api in 2.05 seconds674[Jul 15 2023 03:31:53 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[5]"'`675[Jul 15 2023 03:32:22 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`676[Jul 15 2023 03:32:22 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""677`678[Jul 15 2023 03:32:23 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`679[Jul 15 2023 03:32:23 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`680[Jul 15 2023 03:32:23 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`681[Jul 15 2023 03:32:23 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`682[Jul 15 2023 03:32:23 UTC (QA Tests)] INFO -- Waiting for health check on praefect683[Jul 15 2023 03:32:23 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`684[Jul 15 2023 03:32:24 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1685[Jul 15 2023 03:32:24 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`686[Jul 15 2023 03:32:25 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""687`688[Jul 15 2023 03:32:25 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2689[Jul 15 2023 03:32:25 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`690[Jul 15 2023 03:32:25 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""691`692[Jul 15 2023 03:32:26 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3693[Jul 15 2023 03:32:26 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`694[Jul 15 2023 03:32:26 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""695`696[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Clearing the replication queue697[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"delete from replication_queue_job_lock;698delete from replication_queue_lock;699delete from replication_queue;700\""701`702 allows replication of different repository after interruption703Systems704 with Gitaly automatic failover and recovery705[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`706[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""707`708[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`709[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`710[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`711[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`712[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Waiting for health check on praefect713[Jul 15 2023 03:32:27 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`714[Jul 15 2023 03:32:28 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1715[Jul 15 2023 03:32:28 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`716[Jul 15 2023 03:32:29 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""717`718[Jul 15 2023 03:32:29 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2719[Jul 15 2023 03:32:29 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`720[Jul 15 2023 03:32:30 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""721`722[Jul 15 2023 03:32:30 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3723[Jul 15 2023 03:32:30 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`724[Jul 15 2023 03:32:31 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""725`726[Jul 15 2023 03:32:31 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Sandbox with full_path 'gitlab-qa-sandbox-group-7' via api in 0.06 seconds727[Jul 15 2023 03:32:31 UTC (QA Tests)] INFO -- ==> Retrieved a QA::Resource::Group with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f' via api in 0.11 seconds728[Jul 15 2023 03:32:33 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Project with full_path 'gitlab-qa-sandbox-group-7/qa-test-2023-07-15-03-27-44-fd9ff112c2ebb69f/gitaly_cluster-cfe025e115549c9d' via api in 2.11 seconds729[Jul 15 2023 03:32:33 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue where state = 'ready' or state = 'in_progress';\""730`731[Jul 15 2023 03:32:33 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[6]"'`732[Jul 15 2023 03:33:03 UTC (QA Tests)] INFO -- Starting test: Systems with Gitaly automatic failover and recovery automatically fails over733[Jul 15 2023 03:33:03 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`734[Jul 15 2023 03:33:03 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly2`735[Jul 15 2023 03:33:03 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""736`737[Jul 15 2023 03:33:04 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""738`739[Jul 15 2023 03:33:05 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""740`741[Jul 15 2023 03:33:07 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""742`743[Jul 15 2023 03:33:08 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""744`745[Jul 15 2023 03:33:09 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""746`747[Jul 15 2023 03:33:10 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""748`749[Jul 15 2023 03:33:11 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""750`751[Jul 15 2023 03:33:12 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""752`753[Jul 15 2023 03:33:13 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""754`755[Jul 15 2023 03:33:14 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`756[Jul 15 2023 03:33:14 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly3`757[Jul 15 2023 03:33:14 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""758`759[Jul 15 2023 03:33:15 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""760`761[Jul 15 2023 03:33:16 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""762`763[Jul 15 2023 03:33:17 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""764`765[Jul 15 2023 03:33:18 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""766`767[Jul 15 2023 03:33:19 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""768`769[Jul 15 2023 03:33:21 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""770`771[Jul 15 2023 03:33:22 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""772`773[Jul 15 2023 03:33:23 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""774`775[Jul 15 2023 03:33:24 UTC (QA Tests)] INFO -- QA::Resource::Project - wait_for_push with commit message "first_added_commit_message to primary gitaly node"776[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Repository::ProjectPush via browser_ui in 1.46 seconds777[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`778[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""779`780[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`781[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`782[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly2`783[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly2`784[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`785[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly3`786[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly3`787[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`788[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Waiting for health check on praefect789[Jul 15 2023 03:33:25 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`790[Jul 15 2023 03:33:26 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1791[Jul 15 2023 03:33:26 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`792[Jul 15 2023 03:33:27 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""793`794[Jul 15 2023 03:33:27 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2795[Jul 15 2023 03:33:27 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`796[Jul 15 2023 03:33:28 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""797`798[Jul 15 2023 03:33:28 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3799[Jul 15 2023 03:33:28 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`800[Jul 15 2023 03:33:29 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""801`802[Jul 15 2023 03:33:29 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"select count(*) from replication_queue where state = 'ready' or state = 'in_progress';\""803`804[Jul 15 2023 03:33:29 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[6]"'`805[Jul 15 2023 03:33:59 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`806[Jul 15 2023 03:33:59 UTC (QA Tests)] INFO -- Executing: `docker pause gitaly1`807[Jul 15 2023 03:33:59 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""808`809[Jul 15 2023 03:34:00 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""810`811[Jul 15 2023 03:34:01 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""812`813[Jul 15 2023 03:34:02 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""814`815[Jul 15 2023 03:34:04 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""816`817[Jul 15 2023 03:34:05 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""818`819[Jul 15 2023 03:34:06 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""820`821[Jul 15 2023 03:34:07 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""822`823[Jul 15 2023 03:34:08 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""824`825[Jul 15 2023 03:34:08 UTC (QA Tests)] INFO -- Waiting for health check failure on gitaly1826[Jul 15 2023 03:34:08 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""827`828[Jul 15 2023 03:34:09 UTC (QA Tests)] INFO -- ==> Built a QA::Resource::Repository::Commit via api in 0.6 seconds829 automatically fails over830 when recovering from dataloss after failover831[Jul 15 2023 03:34:09 UTC (QA Tests)] INFO -- Starting test: Systems with Gitaly automatic failover and recovery when recovering from dataloss after failover automatically reconciles832[Jul 15 2023 03:34:09 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`833[Jul 15 2023 03:34:09 UTC (QA Tests)] INFO -- Executing: `docker unpause gitaly1`834[Jul 15 2023 03:34:09 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Running}} gitaly1`835[Jul 15 2023 03:34:09 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1836[Jul 15 2023 03:34:09 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`837[Jul 15 2023 03:34:10 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""838`839[Jul 15 2023 03:34:10 UTC (QA Tests)] INFO -- Executing: `docker exec gitlab-gitaly-cluster bash -c 'gitlab-rake "gitlab:praefect:replicas[6]"'`840[Jul 15 2023 03:34:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} postgres`841[Jul 15 2023 03:34:40 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT 1 as healthy_database\""842`843[Jul 15 2023 03:34:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly1`844[Jul 15 2023 03:34:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly2`845[Jul 15 2023 03:34:40 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} gitaly3`846[Jul 15 2023 03:34:41 UTC (QA Tests)] INFO -- Executing: `docker inspect -f {{.State.Status}} praefect`847[Jul 15 2023 03:34:41 UTC (QA Tests)] INFO -- Waiting for health check on praefect848[Jul 15 2023 03:34:41 UTC (QA Tests)] INFO -- Executing: `docker exec praefect gitlab-ctl status praefect`849[Jul 15 2023 03:34:41 UTC (QA Tests)] INFO -- Waiting for health check on gitaly1850[Jul 15 2023 03:34:41 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly1 gitlab-ctl status gitaly`851[Jul 15 2023 03:34:42 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly1';\""852`853[Jul 15 2023 03:34:42 UTC (QA Tests)] INFO -- Waiting for health check on gitaly2854[Jul 15 2023 03:34:42 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly2 gitlab-ctl status gitaly`855[Jul 15 2023 03:34:43 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly2';\""856`857[Jul 15 2023 03:34:43 UTC (QA Tests)] INFO -- Waiting for health check on gitaly3858[Jul 15 2023 03:34:43 UTC (QA Tests)] INFO -- Executing: `docker exec gitaly3 gitlab-ctl status gitaly`859[Jul 15 2023 03:34:44 UTC (QA Tests)] INFO -- Executing: `docker exec --env PGPASSWORD=SQL_PASSWORD postgres bash -c "psql -U postgres -d praefect_production -h postgres.test -c \"SELECT count(*) FROM healthy_storages WHERE storage = 'gitaly3';\""860`861 automatically reconciles862Finished in 7 minutes 6 seconds (files took 2.7 seconds to load)8636 examples, 0 failures864Randomized with seed 57545865[Jul 15 2023 03:34:45 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitlab-gitaly-cluster bash -c "gitlab-psql -c 'select n_live_tup, n_dead_tup, relname from pg_stat_all_tables order by n_live_tup DESC, n_dead_tup DESC;'"`866[Jul 15 2023 03:34:45 UTC (Gitlab QA)] INFO -- Shell command: `docker exec gitlab-gitaly-cluster bash -c "gitlab-psql -c 'select * from pg_stat_user_tables;'"`867[Jul 15 2023 03:34:45 UTC (Gitlab QA)] INFO -- Shell command: `docker ps -f name=gitlab-gitaly-cluster`868[Jul 15 2023 03:34:45 UTC (Gitlab QA)] INFO -- Shell command: `docker rm -f gitlab-gitaly-cluster`870Running after script...871$ if [ "$CI_JOB_STATUS" == "failed" ]; then # collapsed multi-line command872$ export BUNDLE_PREFIX=$([ "$RUN_WITH_BUNDLE" != "true" ] || echo "bundle exec")873$ echo -e "\e[0Ksection_start:`date +%s`:report_results_section[collapsed=true]\r\e[0KReport results"897Not uploading cache qa-e2e-ruby-3.0-25fc54ff225c814107db3bf4a8c26e7a-16 due to policy899Uploading artifacts...900gitlab-qa-run-*: found 232 matching artifact files and directories 901Uploading artifacts as "archive" to coordinator... 201 Created id=4659949946 responseStatus=201 Created token=64_nK7Ly902Uploading artifacts...903gitlab-qa-run-*/**/rspec-*.xml: found 1 matching artifact files and directories 904Uploading artifacts as "junit" to coordinator... 201 Created id=4659949946 responseStatus=201 Created token=64_nK7Ly905Uploading artifacts...906/builds/gitlab-org/gitlab/suite_status.env: found 1 matching artifact files and directories 907Uploading artifacts as "dotenv" to coordinator... 201 Created id=4659949946 responseStatus=201 Created token=64_nK7Ly909Job succeeded