pat / thinking-sphinx

Sphinx/Manticore plugin for ActiveRecord/Rails
http://freelancing-gods.com/thinking-sphinx
MIT License
1.63k stars 469 forks source link

"ThinkingSphinx::SphinxError - unknown local index 'index_name' in search request" while indexing #1256

Open JasonBarnabe opened 8 months ago

JasonBarnabe commented 8 months ago

Sphinx 3.3.1 thinking-sphinx 5.5.1 Ruby 3.2.2 Rails 7.0.8

Not sure if this is a sphinx thing or just a "that's just how it works" thing...

I have a cron job that periodically updates some data and then runs rake ts:index. Sometimes when this runs, the searches on my site receive a ThinkingSphinx::SphinxError exception: unknown local index 'index_name' in search request. This seems to only last a second or two and then everything's back to normal.

Here's the log of my reindexing script:

Starting at Sat Dec 16 03:00:01 PM UTC 2023
Reindexing at Sat Dec 16 03:00:43 PM UTC 2023
(in /www/greasyfork/releases/20231214004847)
Generating configuration to /www/greasyfork/shared/config/production.sphinx.conf
Sphinx 3.3.1 (commit b72d67b)
Copyright (c) 2001-2020, Andrew Aksyonoff
Copyright (c) 2008-2016, Sphinx Technologies Inc (http://sphinxsearch.com)

using config file '/www/greasyfork/shared/config/production.sphinx.conf'...
indexing index 'script_core'...
collected 63851 docs, 34.8 MB
sorted 6.6 Mhits, 100.0% done
total 63851 docs, 34.77 Mb
total 7.0 sec, 4.933 Mb/sec, 9058 docs/sec
indexing index 'script_delta'...
collected 1 docs, 0.0 MB
sorted 0.0 Mhits, 100.0% done
total 1 docs, 2.0 Kb
total 0.0 sec, 460.0 Kb/sec, 225 docs/sec
skipping non-plain index 'script'...
rotating indices: successfully sent SIGHUP to searchd (pid=2226406).
Done at Sat Dec 16 03:00:52 PM UTC 2023

searchd.log from this time:

[Sat Dec 16 15:00:48.951 2023] [2226410] rotating index 'script_core': started
[Sat Dec 16 15:00:48.956 2023] [2226410] rotating index 'script_core': success

Stack trace of a search request:

Mysql2::Error: unknown local index 'script_core' in search request (Mysql2::Error)
  from mysql2 (0.5.5) lib/mysql2/client.rb:151:in `_query'
  from mysql2 (0.5.5) lib/mysql2/client.rb:151:in `block in query'
  from mysql2 (0.5.5) lib/mysql2/client.rb:150:in `handle_interrupt'
  from mysql2 (0.5.5) lib/mysql2/client.rb:150:in `query'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/mri.rb:22:in `results_for'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/client.rb:65:in `perform'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/client.rb:51:in `check_and_perform'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/client.rb:36:in `query_all'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search/batch_inquirer.rb:19:in `block in results'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection.rb:42:in `block in take'
  from innertube (1.1.0) lib/innertube.rb:138:in `take'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection.rb:40:in `take'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search/batch_inquirer.rb:18:in `results'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/inquirer.rb:11:in `block in call'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/logger.rb:5:in `log'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/inquirer.rb:10:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/geographer.rb:13:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/sphinxql.rb:16:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/valid_options.rb:9:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/stale_id_filter.rb:12:in `call'
  from middleware (0.1.0) lib/middleware/runner.rb:31:in `call'
  from middleware (0.1.0) lib/middleware/builder.rb:102:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search.rb:95:in `populate'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/active_record/base.rb:68:in `merge_search'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/active_record/base.rb:33:in `search'
  from app/controllers/concerns/script_listings.rb:309:in `load_scripts_for_index'
  from app/controllers/concerns/script_listings.rb:32:in `block (3 levels) in index'
  from app/controllers/concerns/page_cache.rb:17:in `block in cache_page'
  from activesupport (7.0.8) lib/active_support/cache.rb:809:in `block in save_block_result_to_cache'
  from activesupport (7.0.8) lib/active_support/cache.rb:783:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from activesupport (7.0.8) lib/active_support/cache.rb:783:in `instrument'
  from activesupport (7.0.8) lib/active_support/cache.rb:808:in `save_block_result_to_cache'
  from activesupport (7.0.8) lib/active_support/cache.rb:338:in `fetch'
  from app/controllers/concerns/page_cache.rb:15:in `cache_page'
  from app/controllers/concerns/script_listings.rb:28:in `block (2 levels) in index'
  from actionpack (7.0.8) lib/action_controller/metal/mime_responds.rb:214:in `respond_to'
  from app/controllers/concerns/script_listings.rb:25:in `index'
  from actionpack (7.0.8) lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
  from actionpack (7.0.8) lib/abstract_controller/base.rb:215:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/rendering.rb:165:in `process_action'
  from actionpack (7.0.8) lib/abstract_controller/callbacks.rb:234:in `block in process_action'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:118:in `block in run_callbacks'
  from actiontext (7.0.8) lib/action_text/rendering.rb:20:in `with_renderer'
  from actiontext (7.0.8) lib/action_text/engine.rb:69:in `block (4 levels) in <class:Engine>'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `instance_exec'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `block in run_callbacks'
  from sentry-rails (5.13.0) lib/sentry/rails/controller_transaction.rb:28:in `block in sentry_around_action'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:102:in `with_child_span'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:476:in `with_child_span'
  from sentry-rails (5.13.0) lib/sentry/rails/controller_transaction.rb:14:in `sentry_around_action'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `block in run_callbacks'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:138:in `run_callbacks'
  from actionpack (7.0.8) lib/abstract_controller/callbacks.rb:233:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/rescue.rb:23:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/instrumentation.rb:67:in `block in process_action'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from actionpack (7.0.8) lib/action_controller/metal/instrumentation.rb:66:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/params_wrapper.rb:259:in `process_action'
  from activerecord (7.0.8) lib/active_record/railties/controller_runtime.rb:27:in `process_action'
  from actionpack (7.0.8) lib/abstract_controller/base.rb:151:in `process'
  from actionview (7.0.8) lib/action_view/rendering.rb:39:in `process'
  from actionpack (7.0.8) lib/action_controller/metal.rb:188:in `dispatch'
  from actionpack (7.0.8) lib/action_controller/metal.rb:251:in `dispatch'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:32:in `serve'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:50:in `block in serve'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:32:in `each'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:32:in `serve'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:852:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/builder.rb:44:in `call'
  from rack-attack (6.6.1) lib/rack/attack.rb:127:in `call'
  from warden (1.2.9) lib/warden/manager.rb:36:in `block in call'
  from warden (1.2.9) lib/warden/manager.rb:34:in `catch'
  from warden (1.2.9) lib/warden/manager.rb:34:in `call'
  from rack (2.2.8) lib/rack/tempfile_reaper.rb:15:in `call'
  from rack (2.2.8) lib/rack/etag.rb:27:in `call'
  from rack (2.2.8) lib/rack/conditional_get.rb:27:in `call'
  from rack (2.2.8) lib/rack/head.rb:12:in `call'
  from actionpack (7.0.8) lib/action_dispatch/http/permissions_policy.rb:38:in `call'
  from actionpack (7.0.8) lib/action_dispatch/http/content_security_policy.rb:36:in `call'
  from rack (2.2.8) lib/rack/session/abstract/id.rb:266:in `context'
  from rack (2.2.8) lib/rack/session/abstract/id.rb:260:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/cookies.rb:704:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:99:in `run_callbacks'
  from actionpack (7.0.8) lib/action_dispatch/middleware/callbacks.rb:26:in `call'
  from sentry-rails (5.13.0) lib/sentry/rails/rescued_exception_interceptor.rb:12:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/debug_exceptions.rb:28:in `call'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:28:in `block (2 levels) in call'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:251:in `with_session_tracking'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:387:in `with_session_tracking'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:19:in `block in call'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:59:in `with_scope'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:367:in `with_scope'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:18:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/show_exceptions.rb:29:in `call'
  from railties (7.0.8) lib/rails/rack/logger.rb:40:in `call_app'
  from railties (7.0.8) lib/rails/rack/logger.rb:25:in `block in call'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:99:in `block in tagged'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:37:in `tagged'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:99:in `tagged'
  from railties (7.0.8) lib/rails/rack/logger.rb:25:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/remote_ip.rb:93:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/request_id.rb:26:in `call'
  from rack (2.2.8) lib/rack/method_override.rb:24:in `call'
  from rack (2.2.8) lib/rack/runtime.rb:22:in `call'
  from activesupport (7.0.8) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/executor.rb:14:in `call'
  from rack (2.2.8) lib/rack/sendfile.rb:110:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/host_authorization.rb:138:in `call'
  from railties (7.0.8) lib/rails/engine.rb:530:in `call'
  from puma (6.3.1) lib/puma/configuration.rb:270:in `call'
  from puma (6.3.1) lib/puma/request.rb:100:in `block in handle_request'
  from puma (6.3.1) lib/puma/thread_pool.rb:344:in `with_force_shutdown'
  from puma (6.3.1) lib/puma/request.rb:99:in `handle_request'
  from puma (6.3.1) lib/puma/server.rb:443:in `process_client'
  from puma (6.3.1) lib/puma/server.rb:245:in `block in run'
  from puma (6.3.1) lib/puma/thread_pool.rb:151:in `block in spawn_thread'

ThinkingSphinx::QueryExecutionError: unknown local index 'script_core' in search request - SELECT *, weight() myweight, LENGTH(site_application_id) AS site_count FROM `script_core`, `script_delta` WHERE `sensitive` = 1 AND `script_type` = 1 AND `locale` = 187 AND `site_application_id` = 39369 AND `available_as_js` = 1 AND `sphinx_deleted` = 0 ORDER BY `myweight` DESC, `daily_installs` DESC, `id` LIMIT 0, 50 OPTION cutoff=0, field_weights=(combined_text=10, author=5), ranker=expr('top(user_weight)'); SHOW META (ThinkingSphinx::QueryExecutionError)
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/client.rb:70:in `rescue in perform'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/client.rb:66:in `perform'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/client.rb:51:in `check_and_perform'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection/client.rb:36:in `query_all'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search/batch_inquirer.rb:19:in `block in results'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection.rb:42:in `block in take'
  from innertube (1.1.0) lib/innertube.rb:138:in `take'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection.rb:40:in `take'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search/batch_inquirer.rb:18:in `results'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/inquirer.rb:11:in `block in call'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/logger.rb:5:in `log'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/inquirer.rb:10:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/geographer.rb:13:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/sphinxql.rb:16:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/valid_options.rb:9:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/stale_id_filter.rb:12:in `call'
  from middleware (0.1.0) lib/middleware/runner.rb:31:in `call'
  from middleware (0.1.0) lib/middleware/builder.rb:102:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search.rb:95:in `populate'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/active_record/base.rb:68:in `merge_search'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/active_record/base.rb:33:in `search'
  from app/controllers/concerns/script_listings.rb:309:in `load_scripts_for_index'
  from app/controllers/concerns/script_listings.rb:32:in `block (3 levels) in index'
  from app/controllers/concerns/page_cache.rb:17:in `block in cache_page'
  from activesupport (7.0.8) lib/active_support/cache.rb:809:in `block in save_block_result_to_cache'
  from activesupport (7.0.8) lib/active_support/cache.rb:783:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from activesupport (7.0.8) lib/active_support/cache.rb:783:in `instrument'
  from activesupport (7.0.8) lib/active_support/cache.rb:808:in `save_block_result_to_cache'
  from activesupport (7.0.8) lib/active_support/cache.rb:338:in `fetch'
  from app/controllers/concerns/page_cache.rb:15:in `cache_page'
  from app/controllers/concerns/script_listings.rb:28:in `block (2 levels) in index'
  from actionpack (7.0.8) lib/action_controller/metal/mime_responds.rb:214:in `respond_to'
  from app/controllers/concerns/script_listings.rb:25:in `index'
  from actionpack (7.0.8) lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
  from actionpack (7.0.8) lib/abstract_controller/base.rb:215:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/rendering.rb:165:in `process_action'
  from actionpack (7.0.8) lib/abstract_controller/callbacks.rb:234:in `block in process_action'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:118:in `block in run_callbacks'
  from actiontext (7.0.8) lib/action_text/rendering.rb:20:in `with_renderer'
  from actiontext (7.0.8) lib/action_text/engine.rb:69:in `block (4 levels) in <class:Engine>'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `instance_exec'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `block in run_callbacks'
  from sentry-rails (5.13.0) lib/sentry/rails/controller_transaction.rb:28:in `block in sentry_around_action'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:102:in `with_child_span'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:476:in `with_child_span'
  from sentry-rails (5.13.0) lib/sentry/rails/controller_transaction.rb:14:in `sentry_around_action'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `block in run_callbacks'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:138:in `run_callbacks'
  from actionpack (7.0.8) lib/abstract_controller/callbacks.rb:233:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/rescue.rb:23:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/instrumentation.rb:67:in `block in process_action'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from actionpack (7.0.8) lib/action_controller/metal/instrumentation.rb:66:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/params_wrapper.rb:259:in `process_action'
  from activerecord (7.0.8) lib/active_record/railties/controller_runtime.rb:27:in `process_action'
  from actionpack (7.0.8) lib/abstract_controller/base.rb:151:in `process'
  from actionview (7.0.8) lib/action_view/rendering.rb:39:in `process'
  from actionpack (7.0.8) lib/action_controller/metal.rb:188:in `dispatch'
  from actionpack (7.0.8) lib/action_controller/metal.rb:251:in `dispatch'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:32:in `serve'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:50:in `block in serve'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:32:in `each'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:32:in `serve'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:852:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/builder.rb:44:in `call'
  from rack-attack (6.6.1) lib/rack/attack.rb:127:in `call'
  from warden (1.2.9) lib/warden/manager.rb:36:in `block in call'
  from warden (1.2.9) lib/warden/manager.rb:34:in `catch'
  from warden (1.2.9) lib/warden/manager.rb:34:in `call'
  from rack (2.2.8) lib/rack/tempfile_reaper.rb:15:in `call'
  from rack (2.2.8) lib/rack/etag.rb:27:in `call'
  from rack (2.2.8) lib/rack/conditional_get.rb:27:in `call'
  from rack (2.2.8) lib/rack/head.rb:12:in `call'
  from actionpack (7.0.8) lib/action_dispatch/http/permissions_policy.rb:38:in `call'
  from actionpack (7.0.8) lib/action_dispatch/http/content_security_policy.rb:36:in `call'
  from rack (2.2.8) lib/rack/session/abstract/id.rb:266:in `context'
  from rack (2.2.8) lib/rack/session/abstract/id.rb:260:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/cookies.rb:704:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:99:in `run_callbacks'
  from actionpack (7.0.8) lib/action_dispatch/middleware/callbacks.rb:26:in `call'
  from sentry-rails (5.13.0) lib/sentry/rails/rescued_exception_interceptor.rb:12:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/debug_exceptions.rb:28:in `call'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:28:in `block (2 levels) in call'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:251:in `with_session_tracking'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:387:in `with_session_tracking'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:19:in `block in call'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:59:in `with_scope'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:367:in `with_scope'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:18:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/show_exceptions.rb:29:in `call'
  from railties (7.0.8) lib/rails/rack/logger.rb:40:in `call_app'
  from railties (7.0.8) lib/rails/rack/logger.rb:25:in `block in call'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:99:in `block in tagged'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:37:in `tagged'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:99:in `tagged'
  from railties (7.0.8) lib/rails/rack/logger.rb:25:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/remote_ip.rb:93:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/request_id.rb:26:in `call'
  from rack (2.2.8) lib/rack/method_override.rb:24:in `call'
  from rack (2.2.8) lib/rack/runtime.rb:22:in `call'
  from activesupport (7.0.8) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/executor.rb:14:in `call'
  from rack (2.2.8) lib/rack/sendfile.rb:110:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/host_authorization.rb:138:in `call'
  from railties (7.0.8) lib/rails/engine.rb:530:in `call'
  from puma (6.3.1) lib/puma/configuration.rb:270:in `call'
  from puma (6.3.1) lib/puma/request.rb:100:in `block in handle_request'
  from puma (6.3.1) lib/puma/thread_pool.rb:344:in `with_force_shutdown'
  from puma (6.3.1) lib/puma/request.rb:99:in `handle_request'
  from puma (6.3.1) lib/puma/server.rb:443:in `process_client'
  from puma (6.3.1) lib/puma/server.rb:245:in `block in run'
  from puma (6.3.1) lib/puma/thread_pool.rb:151:in `block in spawn_thread'

Innertube::Pool::BadResource: Innertube::Pool::BadResource (Innertube::Pool::BadResource)
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection.rb:46:in `rescue in block in take'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection.rb:41:in `block in take'
  from innertube (1.1.0) lib/innertube.rb:138:in `take'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/connection.rb:40:in `take'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search/batch_inquirer.rb:18:in `results'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/inquirer.rb:11:in `block in call'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/logger.rb:5:in `log'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/inquirer.rb:10:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/geographer.rb:13:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/sphinxql.rb:16:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/valid_options.rb:9:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/middlewares/stale_id_filter.rb:12:in `call'
  from middleware (0.1.0) lib/middleware/runner.rb:31:in `call'
  from middleware (0.1.0) lib/middleware/builder.rb:102:in `call'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/search.rb:95:in `populate'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/active_record/base.rb:68:in `merge_search'
  from thinking-sphinx (5.5.1) lib/thinking_sphinx/active_record/base.rb:33:in `search'
  from app/controllers/concerns/script_listings.rb:309:in `load_scripts_for_index'
  from app/controllers/concerns/script_listings.rb:32:in `block (3 levels) in index'
  from app/controllers/concerns/page_cache.rb:17:in `block in cache_page'
  from activesupport (7.0.8) lib/active_support/cache.rb:809:in `block in save_block_result_to_cache'
  from activesupport (7.0.8) lib/active_support/cache.rb:783:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from activesupport (7.0.8) lib/active_support/cache.rb:783:in `instrument'
  from activesupport (7.0.8) lib/active_support/cache.rb:808:in `save_block_result_to_cache'
  from activesupport (7.0.8) lib/active_support/cache.rb:338:in `fetch'
  from app/controllers/concerns/page_cache.rb:15:in `cache_page'
  from app/controllers/concerns/script_listings.rb:28:in `block (2 levels) in index'
  from actionpack (7.0.8) lib/action_controller/metal/mime_responds.rb:214:in `respond_to'
  from app/controllers/concerns/script_listings.rb:25:in `index'
  from actionpack (7.0.8) lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
  from actionpack (7.0.8) lib/abstract_controller/base.rb:215:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/rendering.rb:165:in `process_action'
  from actionpack (7.0.8) lib/abstract_controller/callbacks.rb:234:in `block in process_action'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:118:in `block in run_callbacks'
  from actiontext (7.0.8) lib/action_text/rendering.rb:20:in `with_renderer'
  from actiontext (7.0.8) lib/action_text/engine.rb:69:in `block (4 levels) in <class:Engine>'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `instance_exec'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `block in run_callbacks'
  from sentry-rails (5.13.0) lib/sentry/rails/controller_transaction.rb:28:in `block in sentry_around_action'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:102:in `with_child_span'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:476:in `with_child_span'
  from sentry-rails (5.13.0) lib/sentry/rails/controller_transaction.rb:14:in `sentry_around_action'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:127:in `block in run_callbacks'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:138:in `run_callbacks'
  from actionpack (7.0.8) lib/abstract_controller/callbacks.rb:233:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/rescue.rb:23:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/instrumentation.rb:67:in `block in process_action'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `block in instrument'
  from activesupport (7.0.8) lib/active_support/notifications/instrumenter.rb:24:in `instrument'
  from activesupport (7.0.8) lib/active_support/notifications.rb:206:in `instrument'
  from actionpack (7.0.8) lib/action_controller/metal/instrumentation.rb:66:in `process_action'
  from actionpack (7.0.8) lib/action_controller/metal/params_wrapper.rb:259:in `process_action'
  from activerecord (7.0.8) lib/active_record/railties/controller_runtime.rb:27:in `process_action'
  from actionpack (7.0.8) lib/abstract_controller/base.rb:151:in `process'
  from actionview (7.0.8) lib/action_view/rendering.rb:39:in `process'
  from actionpack (7.0.8) lib/action_controller/metal.rb:188:in `dispatch'
  from actionpack (7.0.8) lib/action_controller/metal.rb:251:in `dispatch'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:32:in `serve'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:50:in `block in serve'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:32:in `each'
  from actionpack (7.0.8) lib/action_dispatch/journey/router.rb:32:in `serve'
  from actionpack (7.0.8) lib/action_dispatch/routing/route_set.rb:852:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:202:in `call!'
  from omniauth (2.1.1) lib/omniauth/strategy.rb:169:in `call'
  from omniauth (2.1.1) lib/omniauth/builder.rb:44:in `call'
  from rack-attack (6.6.1) lib/rack/attack.rb:127:in `call'
  from warden (1.2.9) lib/warden/manager.rb:36:in `block in call'
  from warden (1.2.9) lib/warden/manager.rb:34:in `catch'
  from warden (1.2.9) lib/warden/manager.rb:34:in `call'
  from rack (2.2.8) lib/rack/tempfile_reaper.rb:15:in `call'
  from rack (2.2.8) lib/rack/etag.rb:27:in `call'
  from rack (2.2.8) lib/rack/conditional_get.rb:27:in `call'
  from rack (2.2.8) lib/rack/head.rb:12:in `call'
  from actionpack (7.0.8) lib/action_dispatch/http/permissions_policy.rb:38:in `call'
  from actionpack (7.0.8) lib/action_dispatch/http/content_security_policy.rb:36:in `call'
  from rack (2.2.8) lib/rack/session/abstract/id.rb:266:in `context'
  from rack (2.2.8) lib/rack/session/abstract/id.rb:260:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/cookies.rb:704:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
  from activesupport (7.0.8) lib/active_support/callbacks.rb:99:in `run_callbacks'
  from actionpack (7.0.8) lib/action_dispatch/middleware/callbacks.rb:26:in `call'
  from sentry-rails (5.13.0) lib/sentry/rails/rescued_exception_interceptor.rb:12:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/debug_exceptions.rb:28:in `call'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:28:in `block (2 levels) in call'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:251:in `with_session_tracking'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:387:in `with_session_tracking'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:19:in `block in call'
  from sentry-ruby (5.13.0) lib/sentry/hub.rb:59:in `with_scope'
  from sentry-ruby (5.13.0) lib/sentry-ruby.rb:367:in `with_scope'
  from sentry-ruby (5.13.0) lib/sentry/rack/capture_exceptions.rb:18:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/show_exceptions.rb:29:in `call'
  from railties (7.0.8) lib/rails/rack/logger.rb:40:in `call_app'
  from railties (7.0.8) lib/rails/rack/logger.rb:25:in `block in call'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:99:in `block in tagged'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:37:in `tagged'
  from activesupport (7.0.8) lib/active_support/tagged_logging.rb:99:in `tagged'
  from railties (7.0.8) lib/rails/rack/logger.rb:25:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/remote_ip.rb:93:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/request_id.rb:26:in `call'
  from rack (2.2.8) lib/rack/method_override.rb:24:in `call'
  from rack (2.2.8) lib/rack/runtime.rb:22:in `call'
  from activesupport (7.0.8) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/executor.rb:14:in `call'
  from rack (2.2.8) lib/rack/sendfile.rb:110:in `call'
  from actionpack (7.0.8) lib/action_dispatch/middleware/host_authorization.rb:138:in `call'
  from railties (7.0.8) lib/rails/engine.rb:530:in `call'
  from puma (6.3.1) lib/puma/configuration.rb:270:in `call'
  from puma (6.3.1) lib/puma/request.rb:100:in `block in handle_request'
  from puma (6.3.1) lib/puma/thread_pool.rb:344:in `with_force_shutdown'
  from puma (6.3.1) lib/puma/request.rb:99:in `handle_request'
  from puma (6.3.1) lib/puma/server.rb:443:in `process_client'
  from puma (6.3.1) lib/puma/server.rb:245:in `block in run'
  from puma (6.3.1) lib/puma/thread_pool.rb:151:in `block in spawn_thread'

I would expect/hope that reindexing does not cause errors on things using the index.

pat commented 1 month ago

Hi Jason - I think frustratingly, this might be an issue with Sphinx itself. To be honest, I'm a little surprised - the whole point of rotating indexes should be how Sphinx steps around this (only switching from the old to the new when the new is ready - ideally with no gaps! And yet…)

I have checked locally, and I'm quite sure that when this error crops up Thinking Sphinx removes the current connection to Sphinx from the pool, and then retries again (up to three times) using fresh connections to Sphinx.

If you wanted to try something yourself, I would suggest adding some retry logic around your search calls - and perhaps, try adding ThinkingSphinx::Connection.pool.clear before retrying. This should ensure Thinking Sphinx doesn't hold onto any existing connections.