Rack::Timeout::RequestTimeoutException when using search on gitlab.com
Summary
When using specific search request on a top-level group the customer is consistently getting 500 error.
Steps to reproduce
Follow the search links provided by the customer in Zendesk ticket #200243 (internal only).
Example Project
What is the current bug behavior?
4/8 times the search will return 500 w
What is the expected correct behavior?
Consistently get search results
Relevant logs and/or screenshots
The secific errors that the customer reported seems to lead to this correlation ID in Sentry: https://sentry.gitlab.net/gitlab/gitlabcom/issues/1529371/?query=correlation_id%3A01F12ZDZX0A9FHGXE94K9EDBHB
This is the backtrace that logs show:
"exception.backtrace": [
"lib/gitlab/instrumentation/elasticsearch_transport.rb:12:in `perform_request'",
"ee/lib/elastic/latest/git_class_proxy.rb:212:in `search_blob'",
"lib/gitlab/metrics/instrumentation.rb:160:in `block in search_blob'",
"lib/gitlab/metrics/method_call.rb:27:in `measure'",
"lib/gitlab/metrics/instrumentation.rb:160:in `search_blob'",
"ee/lib/elastic/latest/git_class_proxy.rb:21:in `elastic_search'",
"lib/gitlab/metrics/instrumentation.rb:160:in `block in elastic_search'",
"lib/gitlab/metrics/method_call.rb:27:in `measure'",
"lib/gitlab/metrics/instrumentation.rb:160:in `elastic_search'",
"ee/lib/elastic/latest/git_class_proxy.rb:220:in `elastic_search_and_wrap'",
"lib/gitlab/metrics/instrumentation.rb:160:in `block in elastic_search_and_wrap'",
"lib/gitlab/metrics/method_call.rb:27:in `measure'",
"lib/gitlab/metrics/instrumentation.rb:160:in `elastic_search_and_wrap'",
"ee/lib/elastic/latest/git_class_proxy.rb:34:in `elastic_search_as_found_blob'",
"lib/gitlab/metrics/instrumentation.rb:160:in `block in elastic_search_as_found_blob'",
"lib/gitlab/metrics/method_call.rb:27:in `measure'",
"lib/gitlab/metrics/instrumentation.rb:160:in `elastic_search_as_found_blob'",
"ee/lib/elastic/multi_version_util.rb:76:in `elastic_search_as_found_blob'",
"ee/lib/gitlab/elastic/search_results.rb:296:in `block in blobs'",
"lib/gitlab/utils/strong_memoize.rb:30:in `strong_memoize'",
"ee/lib/gitlab/elastic/search_results.rb:295:in `blobs'",
"lib/gitlab/metrics/instrumentation.rb:160:in `block in blobs'",
"lib/gitlab/metrics/method_call.rb:27:in `measure'",
"lib/gitlab/metrics/instrumentation.rb:160:in `blobs'",
"ee/lib/gitlab/elastic/search_results.rb:41:in `objects'",
"lib/gitlab/metrics/instrumentation.rb:160:in `block in objects'",
"lib/gitlab/metrics/method_call.rb:27:in `measure'",
"lib/gitlab/metrics/instrumentation.rb:160:in `objects'",
"app/services/search_service.rb:66:in `search_objects'",
"app/presenters/search_service_presenter.rb:19:in `search_objects'",
"app/controllers/search_controller.rb:40:in `show'",
"app/controllers/application_controller.rb:536:in `block in allow_gitaly_ref_name_caching'",
"lib/gitlab/gitaly_client.rb:341:in `allow_ref_name_caching'",
"app/controllers/application_controller.rb:535:in `allow_gitaly_ref_name_caching'",
"ee/lib/gitlab/ip_address_state.rb:10:in `with'",
"ee/app/controllers/ee/application_controller.rb:44:in `set_current_ip_address'",
"app/controllers/application_controller.rb:485:in `set_current_admin'",
"lib/gitlab/session.rb:11:in `with_session'",
"app/controllers/application_controller.rb:476:in `set_session_storage'",
"lib/gitlab/i18n.rb:73:in `with_locale'",
"lib/gitlab/i18n.rb:79:in `with_user_locale'",
"app/controllers/application_controller.rb:470:in `set_locale'",
"app/controllers/application_controller.rb:463:in `block in set_current_context'",
"lib/gitlab/application_context.rb:70:in `block in use'",
"lib/gitlab/application_context.rb:70:in `use'",
"lib/gitlab/application_context.rb:27:in `with_context'",
"app/controllers/application_controller.rb:454:in `set_current_context'",
"ee/lib/omni_auth/strategies/group_saml.rb:41:in `other_phase'",
"lib/gitlab/metrics/elasticsearch_rack_middleware.rb:16:in `call'",
"lib/gitlab/middleware/rails_queue_duration.rb:33:in `call'",
"lib/gitlab/metrics/rack_middleware.rb:16:in `block in call'",
"lib/gitlab/metrics/transaction.rb:56:in `run'",
"lib/gitlab/metrics/rack_middleware.rb:16:in `call'",
"lib/gitlab/request_profiler/middleware.rb:17:in `call'",
"ee/lib/gitlab/database/load_balancing/rack_middleware.rb:39:in `call'",
"lib/gitlab/jira/middleware.rb:19:in `call'",
"lib/gitlab/middleware/go.rb:20:in `call'",
"lib/gitlab/etag_caching/middleware.rb:21:in `call'",
"lib/gitlab/middleware/multipart.rb:172:in `call'",
"lib/gitlab/middleware/read_only/controller.rb:50:in `call'",
"lib/gitlab/middleware/read_only.rb:18:in `call'",
"lib/gitlab/middleware/same_site_cookies.rb:27:in `call'",
"lib/gitlab/middleware/handle_malformed_strings.rb:21:in `call'",
"lib/gitlab/middleware/basic_health_check.rb:25:in `call'",
"lib/gitlab/middleware/handle_ip_spoof_attack_error.rb:25:in `call'",
"lib/gitlab/middleware/request_context.rb:21:in `call'",
"config/initializers/fix_local_cache_middleware.rb:11:in `call'",
"lib/gitlab/metrics/requests_rack_middleware.rb:76:in `call'",
"lib/gitlab/middleware/release_env.rb:12:in `call'"
],
Output of checks
This bug happens on GitLab.com
Results of GitLab environment info
Expand for output related to GitLab environment info
(For installations with omnibus-gitlab package run and paste the output of: `sudo gitlab-rake gitlab:env:info`) (For installations from source run and paste the output of: `sudo -u git -H bundle exec rake gitlab:env:info RAILS_ENV=production`)
Results of GitLab application Check
Expand for output related to the GitLab application check
(For installations with omnibus-gitlab package run and paste the output of:
sudo gitlab-rake gitlab:check SANITIZE=true
)(For installations from source run and paste the output of:
sudo -u git -H bundle exec rake gitlab:check RAILS_ENV=production SANITIZE=true
)(we will only investigate if the tests are passing)
Possible fixes
Possibly we need to consider performance improvements of search