Rails 6 test issue

[atomical]

An error occurred in a `before(:suite)` hook.
Failure/Error: ThinkingSphinx::Test.start_with_autostop

Riddle::CommandFailedError:
  Sphinx command failed to execute

I'm seeing this after our Rails 6 upgrade. I'm wondering if this deprecation warning finally turned into an error?

#1165

[pat]

My initial guess is that the issues aren't related - I wouldn't expect callbacks to be involved when starting Sphinx.

Is this issue just in the test environment? i.e. do TS/Sphinx work fine in dev (i.e. using the standard rake tasks, etc)?

[atomical]

It's just in the test environment. Starting sphinx in development works. I just rebuilt and got some errors:

ERROR: index 'wireless_module_core': sql_range_query: Unknown column 'pcms_wireless_modules.id' in 'field list'

wireless module model has:

  has_one :pcm

There isn't a pcms_wireless_modules table. I'm looking to see if there was a change to has_one in rails 6.

[pat]

What does the index definition for the WirelessModule model look like?

[atomical]

has pcm(:id), as: :pcm_id
has pcm(:serial_number), as: :pcm

[pat]

Hmm… I've no idea if this is related, and the syntax you've got should still work. But also, you can use the method notation rather than arguments without any issues (it was only a problem back before TS v3 and MRI 1.9):

has pcm.id, as: :pcm_id
has pcm.serial_number, as: :pcm

[atomical]

Tried that in no luck. I commented out the offending lines in the indexes but I'm still seeing the error in rspec unfortunately.

[atomical]

Weird, when I'm running rake db:test:prepare I'm getting:

ActiveRecord::StatementInvalid: Mysql2::Error: Row size too large. The maximum row size for the used table type, not counting BLOBs, is 65535. This includes storage overhead, check the manual. You have to change some columns to TEXT or BLOBs

[atomical]

<Riddle::CommandResult:0x00007fb5d0dd0580 @output="Sphinx 2.2.11-id64-release (95ae9a6)\nCopyright (c) 2001-2016, Andrew Aksyonoff\nCopyright (c) 2008-2016, Sphinx Technologies Inc (http://sphinxsearch.com)\n\nusing config file 'config/test.sphinx.conf'...\nERROR: section 'activation_description_core_0' (type='source') already exists in config/test.sphinx.conf line 5670 col 1.\nFATAL: failed to parse config file 'config/test.sphinx.conf'\n", @status=1, @command="indexer --config \"config/test.sphinx.conf\" --all", @successful=false>

[atomical]

I had to comment out some indexes. And fix some other issues. I'll follow up when I'm more sure about the cause.

[pat]

ERROR: section 'activation_description_core_0' (type='source') already exists in config/test.sphinx.conf

This part of the output you shared makes me wonder if it's actually the same issue as #1191 - which I still haven't had the chance to look into deeply (sorry @thebravoman!). But it's good to know that this seems to have started with your Rails 6 upgrade, and it looks like you're perhaps both using SQL-backed indices rather than real-time indices (which is maybe why I've not seen it in my own apps, but helps narrow down the focus).

Something seems to be evaluating index definitions multiple times… no idea if it's thread-related. Perhaps that helps your own debugging, but I'll try to get a test app set up soon and see if I can reproduce with SQL-backed indices + Rails 6 + test environment.

[thebravoman]

My offer for reproducing it on my machine and getting together over a video call still stands, if this could help you narrow It down.

…

On Tue, Jun 8, 2021, 07:42 Pat Allan ***@***.***> wrote: ERROR: section 'activation_description_core_0' (type='source') already exists in config/test.sphinx.conf This part of the output you shared makes me wonder if it's actually the same issue as #1191 <#1191> - which I still haven't had the chance to look into deeply (sorry @thebravoman <https://github.com/thebravoman>!). But it's good to know that this seems to have started with your Rails 6 upgrade, and it looks like you're perhaps both using SQL-backed indices rather than real-time indices (which is maybe why I've not seen it in my own apps, but helps narrow down the focus). Something seems to be evaluating index definitions multiple times… no idea if it's thread-related. Perhaps that helps your own debugging, but I'll try to get a test app set up soon and see if I can reproduce with SQL-backed indices + Rails 6 + test environment. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#1195 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAKAGBOYX7ZFQRGJ7GYT5ADTRWNTLANCNFSM4546YFJA> .

[pat]

Appreciated! Let me try and reproduce within a test app first - I'm hoping that would at least help give me a bit more context so any video calls are more productive :)

[pat]

Just thought of another question for you both: are you using the old-style classic loader, or Zeitwork's new approach?

[pat]

Oh, and: how are your index files named? e.g. app/indices/article_index.rb containing the index for the Article model - or a different pattern?

[atomical]

Oh, and: how are your index files named? e.g. app/indices/article_index.rb containing the index for the Article model - or a different pattern?

Exactly that.

[atomical]

I commented out a line in our code that calls ThinkingSphinx::Configuration.instance.indices thinking maybe it could be responsible. No luck. I'll keep working with it.

I also added a puts "ABC" in one of our indexes. It's being loaded twice. I'm going to check the configuration files and see if we're doing anything we shouldn't be in rails 6. Autoload maybe? Hrm.

[pat]

If you feel comfortable diving into the TS code: it might be worth looking at how the preload_indices and preload_index methods are behaving.

And I'm not sure if it's related, but the mutex (since Rails 5.1.5) is not a standard Ruby one, but rather something custom for Rails/Active Suppoort, that permits dependency loading while locked (see #1132).

With both of those things in mind, I'm wondering if shifting @preloaded_indices = true from line 96 up to 88 could help? Thus even if preload_indices is being invoked more than once, the second call should stop at the boolean check on line 87. Also, maybe within that method it's worth resetting the sources/indices (which are initially set in the superclass, Riddle::Configuration)… so:

def preload_indices
  @@mutex.synchronize do
    return if @preloaded_indices
    @preloaded_indices = true

    @indices = []
    @sources = []

    index_paths.each do |path|
      Dir["#{path}/**/*.rb"].sort.each { |file| preload_index file }
    end

    normalise
    verify
  end
end

(For what it's worth: I tried creating a sample app using Rails 6 and SQL-backed indices, and the super simple test suite was fine… also: it's interesting to note that this sounds like it's a consistent problem for @atomical, but intermittent for @thebravoman 🤔 - I'm really hoping it's the same cause though!)

[thebravoman]

are you using the old-style classic loader, or Zeitwork's new approach?

config/application.rb:    config.autoloader = :classic

how are your index files named? e.g. app/indices/article_index.rb containing the index for the Article model - or a different pattern?

The model is app/models/course.rb

$ tree app/indices/
app/indices/
├── course_index.rb

[atomical]

It loads the indexes twice when config.eager_load = true in config/environments/test.rb

What I mean by that is if I put a puts statement in one of the index files it prints twice. And then I get an error for duplicate index in the configuration file.

I put a debugger statement in preload_indices and it's only being called once. Which is strange.

[atomical]

Should an index file be require'd by Rails before Sphinx loads it with preload_index()? Would that be a problem?

[atomical]

@thebravoman Try modifying this method in lib/thinking_sphinx/configuration.rb

  def preload_index(file)
    return if ActiveSupport::Dependencies.loaded.include?(file.split(".rb").first)
    if ActiveRecord::VERSION::MAJOR <= 5
      ActiveSupport::Dependencies.require_or_load file
    else
      load file
    end
  end

I think I've got it working.

[pat]

Thanks so much for that debugging! With those clues, I was able to reproduce the problem in my test app, with eager_load set to true and using the classic autoloader (either scenario separately is fine, though).

The fix I've added to my test app is putting the following line in config/application.rb:

config.eager_load_paths.reject! { |path| path == Rails.root.join("app", "indices").to_s }

I'll look into making Thinking Sphinx do this automatically (and thus, we don't need that check against which files are loaded).

@thebravoman: would love to know if this also fixes things for you? The fact that your issue has been intermittent makes me unsure if this is the exact same issue, but perhaps it's related?

[thebravoman]

Thanks @pat

$ bin/rspec spec/system/search_spec.rb 

/search
    search doesn't show content that has no image

Finished in 3.62 seconds (files took 0.9671 seconds to load)
1 example, 0 failures

Tests passed on my side. My current rails is 6.1 just to let you know.

[pat]

Just pushed a fix via 02bbb50 - if either/both of you are able to confirm the latest in develop works well in your apps, that'd be great, and I'll get a new release cut shortly.

gem "thinking-sphinx",
  :git    => "https://github.com/pat/thinking-sphinx.git",
  :branch => "develop"

[thebravoman]

All good on my side.

The gitrepo has a typo - it should be thinking-sphinx and not thinking-sphinix.

[pat]

My laptop keyboard is a little flaky :/ fixed - and especially, thank you for testing!

[thebravoman]

I just thought of something.

I have a rails engine and it is located in

gems/my-engine/

There I have a model

gems/my-engine/app/models/user.rb

Currently my indices are in

app/indices/user_index.rb

but I would like to move them to

gems/my-engine/app/indices/user_index.rb

My point is - is it possible to have inidices in many folders, not only app/indices but also gems/my-engine/app/indices and if it is should this be taken into account with the recent change?

[pat]

Indices in engines should get picked up automatically, provided they're in the engine's app/indices folder. If you find that's not the case, happy to discuss further, but perhaps in a separate issue :)

[thebravoman]

Of course. I will try it and if there are issues I will open a separate issue here. I just wanted to make sure the case of engines (as it is supported) is not forgotten with this change.

[pat]

Ah… I guess that depends on whether Rails adds an engine's app/* directories to eager_load_paths 🤔 I look forward to hearing what you discover!

[pat]

Just released v5.2.0 which includes this fix (and a further improvement that should ensure engine app/indices paths are also removed from eager_load_paths). So, I think this issue is all resolved - certainly, feel free to re-open the issue if I've got that wrong!