rspec-ee system pg14 es8 8/14 timing out
In https://gitlab.com/gitlab-org/gitlab/-/jobs/7298165189, we see this test timing out:
# [RSpecRunTime] Starting example group ee/spec/features/admin/admin_settings_spec.rb. Expected to take 3 minutes 13.44 seconds.
Admin updates EE-only settings
enables external authentication
Geo settings
when the license has Geo feature
hides JS alert
renders JS form
# [RSpecRunTime] RSpec elapsed time: 7 minutes 52.07 seconds. Current RSS: ~1337M. Threads: 16. load average: 0.50 0.78 0.97 1/505 597
.
when the license does not have Geo feature
shows JS alert
# [RSpecRunTime] RSpec elapsed time: 7 minutes 53.2 seconds. Current RSS: ~1347M. Threads: 15. load average: 0.54 0.78 0.97 1/505 598
.
Elasticsearch settings
changes elasticsearch settings
WARNING: step_script could not run to completion because the timeout was exceeded. For more control over job and script timeouts see: https://docs.gitlab.com/ee/ci/runners/configure_runners.html#set-script-and-after_script-timeouts
ERROR: Job failed: execution took longer than 1h30m0s secondsI think I reproduced this on my system by enabling Elasticsearch, having < 10% disk space free on my system, and running:
bundle exec rspec ee/spec/features/admin/admin_settings_spec.rbI used lldb to attach to the Ruby process and issue a call (void) rb_backtrace():
from /Users/stanhu/.asdf/installs/ruby/3.2.3/bin/bundle:25:in `<main>'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/bin/bundle:25:in `load'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/exe/bundle:20:in `<top (required)>'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/exe/bundle:28:in `block in <top (required)>'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/cli.rb:29:in `start'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/vendor/thor/lib/thor/base.rb:584:in `start'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/cli.rb:35:in `dispatch'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/vendor/thor/lib/thor.rb:527:in `dispatch'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/vendor/thor/lib/thor/command.rb:28:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/cli.rb:455:in `exec'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/cli/exec.rb:23:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/cli/exec.rb:58:in `kernel_load'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/bundler-2.5.11/lib/bundler/cli/exec.rb:58:in `load'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/bin/rspec:25:in `<top (required)>'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/bin/rspec:25:in `load'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/exe/rspec:4:in `<top (required)>'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:45:in `invoke'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:71:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:89:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:115:in `run_specs'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/reporter.rb:74:in `report'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:116:in `block in run_specs'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/configuration.rb:2070:in `with_suite_hooks'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:121:in `block (2 levels) in run_specs'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:121:in `map'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/runner.rb:121:in `block (3 levels) in run_specs'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/example_group.rb:608:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/example_group.rb:608:in `map'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/example_group.rb:608:in `block in run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/example_group.rb:606:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/example_group.rb:552:in `run_before_context_hooks'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/memoized_helpers.rb:204:in `isolate_for_context_hook'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/memoized_helpers.rb:204:in `instance_exec'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/memoized_helpers.rb:208:in `block in isolate_for_context_hook'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/example_group.rb:553:in `block in run_before_context_hooks'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/hooks.rb:480:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/hooks.rb:528:in `run_owned_hooks_for'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/hooks.rb:528:in `each'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/hooks.rb:529:in `block in run_owned_hooks_for'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/hooks.rb:365:in `run'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/rspec-core-3.12.2/lib/rspec/core/hooks.rb:365:in `instance_exec'
from /Users/stanhu/gdk-ee/gitlab/ee/spec/support/elastic.rb:125:in `block (2 levels) in <main>'
from /Users/stanhu/gdk-ee/gitlab/ee/spec/support/elastic.rb:34:in `setup'
from /Users/stanhu/gdk-ee/gitlab/ee/spec/support/elastic.rb:75:in `benchmark'
from /Users/stanhu/gdk-ee/gitlab/ee/spec/support/elastic.rb:35:in `block in setup'
from /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:157:in `create_standalone_indices'
from /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:157:in `each_with_object'
from /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:157:in `each'
from /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:161:in `block in create_standalone_indices'
from /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:437:in `create_index'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/elasticsearch-api-7.13.3/lib/elasticsearch/api/actions/indices/create.rb:48:in `create'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/elasticsearch-api-7.13.3/lib/elasticsearch/api/namespace/common.rb:38:in `perform_request'
from /Users/stanhu/gdk-ee/gitlab/lib/gitlab/instrumentation/elasticsearch_transport.rb:12:in `perform_request'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/elasticsearch-transport-7.13.3/lib/elasticsearch/transport/client.rb:192:in `perform_request'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/elasticsearch-transport-7.13.3/lib/elasticsearch/transport/transport/http/faraday.rb:37:in `perform_request'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/elasticsearch-transport-7.13.3/lib/elasticsearch/transport/transport/base.rb:288:in `perform_request'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/elasticsearch-transport-7.13.3/lib/elasticsearch/transport/transport/http/faraday.rb:48:in `block in perform_request'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/faraday-1.10.3/lib/faraday/connection.rb:516:in `run_request'
from /Users/stanhu/.asdf/installs/ruby/3.2.3/lib/ruby/gems/3.2.0/gems/faraday-1.10.3/lib/faraday/rack_builder.rb:154:in `build_response'In my Elasticsearch logs, I see some indication that the request stalled out:
2024-07-09_15:58:22.98792 elasticsearch : [2024-07-09T08:58:22,987][WARN ][r.suppressed ] [jet-arm.local] path: /gitlab-test-migrations/_doc/20240626145458, params: {index=gitlab-test-migrations, id=20240626145458} org.elasticsearch.action.NoShardAvailableActionException: No shard available for [get [gitlab-test-migrations][20240626145458]: routing [null]]
2024-07-09_15:58:22.98794 elasticsearch : at org.elasticsearch.server@8.11.4/org.elasticsearch.action.support.single.shard.TransportSingleShardAction$AsyncSingleAction.perform(TransportSingleShardAction.java:210)
2024-07-09_15:58:22.98794 elasticsearch : at org.elasticsearch.server@8.11.4/org.elasticsearch.action.support.single.shard.TransportSingleShardAction$AsyncSingleAction.start(TransportSingleShardAction.java:187)
2024-07-09_15:58:22.98794 elasticsearch : at org.elasticsearch.server@8.11.4/org.elasticsearch.action.support.single.shard.TransportSingleShardAction.doExecute(TransportSingleShardAction.java:106)
2024-07-09_15:58:22.98796 elasticsearch : at org.elasticsearch.server@8.11.4/org.elasticsearch.action.support.single.shard.TransportSingleShardAction.doExecute(TransportSingleShardAction.java:53)
2024-07-09_15:58:22.98796 elasticsearch : at org.elasticsearch.server@8.11.4/org.elasticsearch.action.support.TransportAction$RequestFilterChain.proceed(TransportAction.java:87)
<snip>
2024-07-09_15:59:23.15813 elasticsearch : [2024-07-09T08:59:23,157][INFO ][o.e.c.m.MetadataCreateIndexService] [jet-arm.local] [gitlab-test-20240709-155923.021] creating index, cause [api], templates [], shards [5]/[0]
2024-07-09_15:59:48.88887 elasticsearch : [2024-07-09T08:59:48,888][WARN ][o.e.c.r.a.DiskThresholdMonitor] [jet-arm.local] high disk watermark [90%] exceeded on [l64s-0fUSYKuZBT_4FKRyQ][jet-arm.local][/Users/stanhu/gdk-ee/elasticsearch/data] free: 85.8gb[9.2%], shards will be relocated away from this node; currently relocating away shards totalling [0] bytes; the node is expected to continue to exceed the high disk watermark when these relocations are complete
2024-07-09_15:59:53.43302 elasticsearch : [2024-07-09T08:59:53,432][INFO ][o.e.c.m.MetadataCreateIndexService] [jet-arm.local] [gitlab-test-issues-20240709-155923.021] creating index, cause [api], templates [], shards [5]/[0]
2024-07-09_16:00:48.90564 elasticsearch : [2024-07-09T09:00:48,903][WARN ][o.e.c.r.a.DiskThresholdMonitor] [jet-arm.local] high disk watermark [90%] exceeded on [l64s-0fUSYKuZBT_4FKRyQ][jet-arm.local][/Users/stanhu/gdk-ee/elasticsearch/data] free: 85.8gb[9.2%], shards will be relocated away from this node; currently relocating away shards totalling [0] bytes; the node is expected to continue to exceed the high disk watermark when these relocations are complete
2024-07-09_16:01:48.91843 elasticsearch : [2024-07-09T09:01:48,917][WARN ][o.e.c.r.a.DiskThresholdMonitor] [jet-arm.local] high disk watermark [90%] exceeded on [l64s-0fUSYKuZBT_4FKRyQ][jet-arm.local][/Users/stanhu/gdk-ee/elasticsearch/data] free: 85.8gb[9.2%], shards will be relocated away from this node; currently relocating away shards totalling [0] bytes; the node is expected to continue to exceed the high disk watermark when these relocations are completeIf I add debugging in the test setup, I see that the Elasticsearch client used in the test helper may have an infinite request timeout:
(byebug) pp helper.client
#<Elasticsearch::Transport::Client:0x0000000303256f10
@api_key=nil,
@arguments=
{:adapter=>:typhoeus,
:urls=>[{:scheme=>"http", :host=>"localhost", :path=>"", :port=>9200, :protocol=>"http"}],
:transport_options=>{:request=>{:timeout=>nil, :open_timeout=>5},The client is created via:
(byebug) bt
--> #0 #<Class:Gitlab::Elastic::Client>.build(config#Hash) at /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/client.rb:21
#1 block in GemExtensions::Elasticsearch::Model::Client.block in client(_client#NilClass) at /Users/stanhu/gdk-ee/gitlab/ee/lib/gem_extensions/elasticsearch/model/client.rb:28
ͱ-- #2 Thread::Mutex.synchronize at /Users/stanhu/gdk-ee/gitlab/ee/lib/gem_extensions/elasticsearch/model/client.rb:23
#3 GemExtensions::Elasticsearch::Model::Client.client(_client#NilClass) at /Users/stanhu/gdk-ee/gitlab/ee/lib/gem_extensions/elasticsearch/model/client.rb:23
#4 Gitlab::Elastic::Helper.initialize(version#String, client#NilClass, target_name#NilClass) at /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:30
ͱ-- #5 Class.new(*args) at /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:41
#6 #<Class:Gitlab::Elastic::Helper>.default at /Users/stanhu/gdk-ee/gitlab/ee/lib/gitlab/elastic/helper.rb:41
#7 block (2 levels) in block (2 levels) in <top (required)> at /Users/stanhu/gdk-ee/gitlab/ee/spec/features/admin/admin_settings_spec.rb:16Edited by Stan Hu