pat / thinking-sphinx

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

ERROR: section 'course_core_0' (type='source') already exists in /home/user/project/config/test.sphinx.conf line 249 col 1. #1191

Closed thebravoman closed 3 years ago

thebravoman commented 3 years ago

The following error occurred with system specs.

 1) /search?search={...} search doesn't show content that has no image
     Failure/Error: ThinkingSphinx::Test.start_with_autostop

     Riddle::CommandFailedError:
       Sphinx command failed to execute

     # /home/user/.rvm/gems/ruby-2.6.5/gems/riddle-2.4.2/lib/riddle/execute_command.rb:25:in `call'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/riddle-2.4.2/lib/riddle/execute_command.rb:7:in `call'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/riddle-2.4.2/lib/riddle/controller.rb:33:in `index'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/thinking-sphinx-5.1.0/lib/thinking_sphinx/test.rb:11:in `start'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/thinking-sphinx-5.1.0/lib/thinking_sphinx/test.rb:17:in `start_with_autostop'
     # ./spec/support/sphinx_helpers.rb:8:in `start'
     # ./spec/system/search_spec.rb:18:in `block (2 levels) in <top (required)>'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:318:in `load'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:318:in `block in load'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:291:in `load_dependency'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:318:in `load'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/spring-commands-rspec-1.0.4/lib/spring/commands/rspec.rb:18:in `call'
     # -e:1:in `<main>'

I've tracked it down to:

$ indexer --config "/home/user/project/config/test.sphinx.conf" --all --verbose
Sphinx 2.2.11-id64-release (95ae9a6)
Copyright (c) 2001-2016, Andrew Aksyonoff
Copyright (c) 2008-2016, Sphinx Technologies Inc (http://sphinxsearch.com)

using config file '/home/user/project/config/test.sphinx.conf'...
ERROR: section 'course_core_0' (type='source') already exists in /home/user/project/config/test.sphinx.conf line 249 col 1.
FATAL: failed to parse config file '/home/user/project/config/test.sphinx.conf'

At the same tame:

$ RAILS_ENV=test bundle exec rake ts:restart
Sphinx 2.2.11-id64-release (95ae9a6)
Copyright (c) 2001-2016, Andrew Aksyonoff
Copyright (c) 2008-2016, Sphinx Technologies Inc (http://sphinxsearch.com)

using config file '/home/user/project/config/test.sphinx.conf'...
ERROR: section 'course_core_0' (type='source') already exists in /home/user/project/config/test.sphinx.conf line 249 col 1.
FATAL: failed to parse config file '/home/user/project/config/test.sphinx.conf'

The Sphinx stop command failed:
  Command: searchd --pidfile --config "/home/user/project/config/test.sphinx.conf" --stopwait
  Status:  1
  Output:  See above

while at the same time indexing is successful

$ RAILS_ENV=test bundle exec rake ts:index
Sphinx 2.2.11-id64-release (95ae9a6)
Copyright (c) 2001-2016, Andrew Aksyonoff
Copyright (c) 2008-2016, Sphinx Technologies Inc (http://sphinxsearch.com)

using config file '/home/user/project/config/test.sphinx.conf'...
indexing index 'course_core'...
collected 688 docs, 0.0 MB
collected 588 attr values
sorted 0.0 Mvalues, 100.0% done
sorted 0.0 Mhits, 100.0% done
total 688 docs, 16585 bytes
total 0.045 sec, 361360 bytes/sec, 14990.41 docs/sec
indexing index 'course_section_core'...
collected 596 docs, 0.0 MB
collected 312 attr values
sorted 0.0 Mvalues, 100.0% done
sorted 0.0 Mhits, 100.0% done
total 596 docs, 8288 bytes
total 0.028 sec, 285921 bytes/sec, 20560.94 docs/sec
indexing index 'episode_core'...
collected 822 docs, 0.0 MB
collected 794 attr values
sorted 0.0 Mvalues, 100.0% done
sorted 0.0 Mhits, 100.0% done
total 822 docs, 21930 bytes
total 0.050 sec, 438468 bytes/sec, 16435.06 docs/sec
indexing index 'material_core'...
collected 806 docs, 0.0 MB
collected 2434 attr values
sorted 0.0 Mvalues, 100.0% done
sorted 0.0 Mhits, 100.0% done
total 806 docs, 22803 bytes
total 0.067 sec, 335436 bytes/sec, 11856.42 docs/sec
indexing index 'nonreusable_content_core'...
collected 40 docs, 0.0 MB
sorted 0.0 Mhits, 100.0% done
total 40 docs, 2491 bytes
total 0.016 sec, 150850 bytes/sec, 2422.33 docs/sec
indexing index 'program_core'...
collected 183 docs, 0.1 MB
collected 151 attr values
sorted 0.0 Mvalues, 100.0% done
sorted 0.0 Mhits, 100.0% done
total 183 docs, 90471 bytes
total 0.039 sec, 2263246 bytes/sec, 4577.97 docs/sec
indexing index 'task_core'...
collected 180 docs, 0.0 MB
collected 180 attr values
sorted 0.0 Mvalues, 100.0% done
sorted 0.0 Mhits, 100.0% done
total 180 docs, 3643 bytes
total 0.017 sec, 211335 bytes/sec, 10442.04 docs/sec
skipping non-plain index 'course'...
skipping non-plain index 'course_section'...
skipping non-plain index 'episode'...
skipping non-plain index 'material'...
skipping non-plain index 'nonreusable_content'...
skipping non-plain index 'program'...
skipping non-plain index 'task'...
total 14186 reads, 0.019 sec, 0.0 kb/call avg, 0.0 msec/call avg
total 96 writes, 0.006 sec, 14.1 kb/call avg, 0.0 msec/call avg
rotating indices: successfully sent SIGHUP to searchd (pid=246579).

I am not sure how to even track it. Where could I start with?

pat commented 3 years ago

Hmm, this problem has been reported a couple of times in the past (#764 and #523), but I'm not sure I've found a reliable solution. Essentially, it seems that indices are being defined more than once.

In terms of debugging - can you check how many times the your index definition files are being loaded by Ruby (perhaps just by adding a puts line at the top of them)? And also, maybe check if setting cache_classes to either true or false (whatever is different to the current setting) helps?

Also: which versions of Ruby/Rails/Sphinx are being used? Is there anything particularly custom with your index definitions? i.e. are they dynamically generated? Can you share the definitions? (at least for the Course index, given that seems to be where things aren't going to plan)

thebravoman commented 3 years ago

Rails 6.0.3.5 Ruby 2.6.5 thinking-sphinx (5.1.0)

Nothing custom. Here is the definition

ThinkingSphinx::Index.define :course, :with => :active_record do
  #fields
  indexes translations.title, as: :title, facet: true
  indexes [translations.description, translations.long_description], as: :description, facet: true

  has published_at

  has id, :as => :course_id
  has translations(:id), as: :translation_id

  has '0', as: :episode_id, type: :integer
  has '0', as: :program_id, type: :integer
  has '0', as: :material_id, type: :integer
  has '0', as: :coursesection_id, type: :integer
  has '0', as: :nonreusablecontent_id, type: :integer
  has '0', as: :task_id, type: :integer
end

Running when spring is loaded the indices definition files are loaded once. I've added 'puts "LOADING COURSE_INDEX"' at the top and it is printed. Running the system specs the first time and they pass. Running the spec a second time and they fail.

$ bin/rspec spec/system/search_spec.rb 
Running via Spring preloader in process 302063

Randomized with seed 46623

/search?search={...}
LOADING COURSE_INDEX
  search doesn't show content that has no image

Finished in 18.4 seconds (files took 0.94126 seconds to load)
1 example, 0 failures

Randomized with seed 46623

$ bin/rspec spec/system/search_spec.rb 
Running via Spring preloader in process 302407

Randomized with seed 32703

/search?search={...}
LOADING COURSE_INDEX
Exception occured in example '/search?search={...} search doesn't show content that has no image'. This is the content of the page:
/home/user/project/tmp/capybara/capybara-202102230823136505183262.html
/home/user/project/tmp/capybara/capybara-202102230823137810118429.png
  search doesn't show content that has no image (FAILED - 1)

Failures:

  1) /search?search={...} search doesn't show content that has no image
     Failure/Error: ThinkingSphinx::Test.start_with_autostop

     Riddle::CommandFailedError:
       Sphinx command failed to execute

     [Screenshot]: /home/user/project/tmp/screenshots/failures_r_spec_example_groups_search_search_search_doesn_t_show_content_that_has_no_image_879.png

     # /home/user/.rvm/gems/ruby-2.6.5/gems/riddle-2.4.2/lib/riddle/execute_command.rb:25:in `call'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/riddle-2.4.2/lib/riddle/execute_command.rb:7:in `call'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/riddle-2.4.2/lib/riddle/controller.rb:33:in `index'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/thinking-sphinx-5.1.0/lib/thinking_sphinx/test.rb:11:in `start'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/thinking-sphinx-5.1.0/lib/thinking_sphinx/test.rb:17:in `start_with_autostop'
     # ./spec/support/sphinx_helpers.rb:8:in `start'
     # ./spec/system/search_spec.rb:18:in `block (2 levels) in <top (required)>'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:318:in `load'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:318:in `block in load'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:291:in `load_dependency'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/activesupport-6.0.3.5/lib/active_support/dependencies.rb:318:in `load'
     # /home/user/.rvm/gems/ruby-2.6.5/gems/spring-commands-rspec-1.0.4/lib/spring/commands/rspec.rb:18:in `call'
     # -e:1:in `<main>'

Finished in 2.29 seconds (files took 0.87395 seconds to load)
1 example, 1 failure

Failed examples:

rspec ./spec/system/search_spec.rb:22 # /search?search={...} search doesn't show content that has no image

Probably they are not cleared?

Here is the spec


  before do
    login_as user

    FactoryBot.create(:...)

    SphinxHelpers.start
    SphinxHelpers.index
  end

  scenario "search doesn't show content that has no image", js: :true do
    ThinkingSphinx::Test.run do
      visit "/search?search=#{title_part}"

      expect(page).to have_text program_with_pic.title
      expect(page).not_to have_text program_no_pic.title
    end
  end

Where SphinxHelpers are

module SphinxHelpers
  def self.start
    # Ensure sphinx directories exist for the test environment
    ThinkingSphinx::Test.init

    # Configure and start Sphinx, and automatically
    # stop Sphinx at the end of the test suite.
    ThinkingSphinx::Test.start_with_autostop
  end

  def self.index
    ThinkingSphinx::Test.index

    # Wait for Sphinx to finish loading in the new index files.
    sleep 0.25 until SphinxHelpers::index_finished?
  end

  def self.index_finished?
    Dir[Rails.root.join(ThinkingSphinx::Test.config.indices_location, '*.{new,tmp}*')].empty?
  end
end
pat commented 3 years ago

Just to confirm: if you stop Spring before the second run of tests, do they pass? (I'm expecting that's the case, but good to be sure.)

Wondering why this hasn't cropped up elsewhere before… can you share the contents of your bin/rspec file? I want to make sure I'm testing locally in the same way.

thebravoman commented 3 years ago

Just to confirm: if you stop Spring before the second run of tests, do they pass? (I'm expecting that's the case, but good to be sure.)

No. This does not seem to be the case. Stop spring, start spring, sometimes it passes like once every 10 times, most of the time it does not. I can't find a pattern. I have tried many times with spring. Many times without spring. With and without.

bin/rspec is

#!/usr/bin/env ruby
begin
  load File.expand_path('../spring', __FILE__)
rescue LoadError => e
  raise unless e.message.include?('spring')
end
require 'bundler/setup'
load Gem.bin_path('rspec-core', 'rspec')
pat commented 3 years ago

Thanks for that binstub. I've run some Sphinx specs in a local project using Spring, and they're consistently green.

I do hate to ask this - because I realise it's not an easy thing to do - but are you able to create an example Rails app that reproduces the problem on your machine, and then share it in a public repo? I definitely want to get to the bottom of this problem, but it's close to impossible without being able to see it happen locally.

thebravoman commented 3 years ago

What If we schedule a meeting and we spend some time looking at it together?

On Sat, Mar 20, 2021, 06:58 Pat Allan @.***> wrote:

Thanks for that binstub. I've run some Sphinx specs in a local project using Spring, and they're consistently green.

I do hate to ask this - because I realise it's not an easy thing to do - but are you able to create an example Rails app that reproduces the problem on your machine, and then share it in a public repo? I definitely want to get to the bottom of this problem, but it's close to impossible without being able to see it happen locally.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/pat/thinking-sphinx/issues/1191#issuecomment-803249531, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAKAGBNP7B2LEE2LFUSQ4EDTEQTOLANCNFSM4X7M2CIA .