0

I'm working with a Rails 3.2 application that has a mysql database and a number of models that are being indexed in Solr.

Here's what's happening:

I am running the following command:

RAILS_ENV=development bundle exec rake sunspot:reindex[1000] --trace

After indexing about 12% of the 4 million records (although it's a different percentage every time), the process inevitably bombs out with the following error and stack trace:

rake aborted!
getaddrinfo: nodename nor servname provided, or not known
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/net/http.rb:762:in `initialize'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/net/http.rb:762:in `open'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/net/http.rb:762:in `block in connect'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/timeout.rb:54:in `timeout'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/timeout.rb:99:in `timeout'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/net/http.rb:762:in `connect'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/net/http.rb:755:in `do_start'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/net/http.rb:744:in `start'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/net/http.rb:1284:in `request'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rsolr-1.0.9/lib/rsolr/connection.rb:15:in `execute'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/solr_instrumentation.rb:14:in `block in execute_with_as_instrumentation'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/activesupport-3.2.13/lib/active_support/notifications.rb:123:in `block in instrument'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/activesupport-3.2.13/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/activesupport-3.2.13/lib/active_support/notifications.rb:123:in `instrument'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/solr_instrumentation.rb:12:in `execute_with_as_instrumentation'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rsolr-1.0.9/lib/rsolr/client.rb:167:in `execute'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rsolr-1.0.9/lib/rsolr/client.rb:161:in `send_and_receive'
(eval):2:in `post'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rsolr-1.0.9/lib/rsolr/client.rb:67:in `update'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rsolr-1.0.9/lib/rsolr/client.rb:87:in `add'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/indexer.rb:106:in `add_documents'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/indexer.rb:30:in `add'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/session.rb:91:in `index'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/session_proxy/abstract_session_proxy.rb:11:in `index'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/session_proxy/retry_5xx_session_proxy.rb:17:in `method_missing'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/session_proxy/abstract_session_proxy.rb:11:in `index'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot.rb:184:in `index'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/searchable.rb:261:in `block (2 levels) in solr_index'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/searchable.rb:365:in `solr_benchmark'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/searchable.rb:260:in `block in solr_index'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/relation/batches.rb:72:in `find_in_batches'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/querying.rb:8:in `find_in_batches'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/searchable.rb:259:in `solr_index'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/searchable.rb:203:in `solr_reindex'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/tasks.rb:64:in `block (3 levels) in <top (required)>'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/class_set.rb:16:in `each'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot-2.0.0/lib/sunspot/class_set.rb:16:in `each'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sunspot_rails-2.0.0/lib/sunspot/rails/tasks.rb:63:in `block (2 levels) in <top (required)>'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/task.rb:246:in `call'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/task.rb:246:in `block in execute'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/task.rb:241:in `each'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/task.rb:241:in `execute'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/task.rb:184:in `block in invoke_with_call_chain'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/task.rb:177:in `invoke_with_call_chain'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/task.rb:170:in `invoke'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:143:in `invoke_task'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:101:in `block (2 levels) in top_level'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:101:in `each'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:101:in `block in top_level'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:110:in `run_with_threads'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:95:in `top_level'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:73:in `block in run'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:160:in `standard_exception_handling'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/lib/rake/application.rb:70:in `run'
/Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rake-10.0.4/bin/rake:33:in `<top (required)>'
/Users/tchapin/.rbenv/versions/1.9.3-p392/bin/rake:23:in `load'
/Users/tchapin/.rbenv/versions/1.9.3-p392/bin/rake:23:in `<main>'

The app is running in development mode at localhost:3000, and solr is running at localhost:8982. Here's my solr.rake file:

Rake::Task['sunspot:reindex'].enhance ['sunspot:scope_models_for_index']
Rake::Task['sunspot:solr:reindex'].enhance ['sunspot:scope_models_for_index']

namespace 'sunspot' do
  task :scope_models_for_index => :environment do
    require 'rsolr/error'
    Dir.glob(Rails.root.join('app/models/**/*.rb')).each { |path| require path }

    # Add the GC
    commit_extension = Module.new do
      def commit
        GC.start
        super
      end
    end

    Sunspot.extend commit_extension

    # Set all the models default scopes the index scope
    Sunspot.searchable.each do |model|
      model.class_eval do
        default_scope ->{ sunspot_index } if model.respond_to?(:sunspot_index)
      end
    end
  end
end

Anyone know what might be causing this error, or how to fix it?

Tom Chapin
  • 3,276
  • 1
  • 29
  • 18

1 Answers1

1

Apparently the problem is due to an exception: SocketError.

The exception occurs in the file /Users/tchapin/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/rsolr-1.0.9/lib/rsolr/connection.rb:

  def execute client, request_context
    h = http request_context[:uri], request_context[:proxy], request_context[:read_timeout], request_context[:open_timeout]
    request = setup_raw_request request_context
    request.body = request_context[:data] if request_context[:method] == :post and request_context[:data]
    begin
      response = h.request request
      charset = response.type_params["charset"]
      {:status => response.code.to_i, :headers => response.to_hash, :body => force_charset(response.body, charset)}
    rescue Errno::ECONNREFUSED => e
      raise(Errno::ECONNREFUSED.new(request_context.inspect))
    # catch the undefined closed? exception -- this is a confirmed ruby bug
    rescue NoMethodError
      $!.message == "undefined method `closed?' for nil:NilClass" ?
        raise(Errno::ECONNREFUSED.new) :
        raise($!)
    end
  end

It's not the prettiest fix, and it's obviously not a solution for production code, but I was able to temporarily solve the problem by adding a rescue handler for the SocketError exception, like so:

  def execute client, request_context
    h = http request_context[:uri], request_context[:proxy], request_context[:read_timeout], request_context[:open_timeout]
    request = setup_raw_request request_context
    request.body = request_context[:data] if request_context[:method] == :post and request_context[:data]
    retries = 10
    begin
      response = h.request request
      charset = response.type_params["charset"]
      {:status => response.code.to_i, :headers => response.to_hash, :body => force_charset(response.body, charset)}
    rescue Errno::ECONNREFUSED => e
      raise(Errno::ECONNREFUSED.new(request_context.inspect))
    # catch the undefined closed? exception -- this is a confirmed ruby bug
    rescue NoMethodError
      $!.message == "undefined method `closed?' for nil:NilClass" ?
        raise(Errno::ECONNREFUSED.new) :
        raise($!)
    rescue SocketError => e
      puts e
      if retries > 0
        puts "SocketError! Retrying connection after 1 second..."
        retries -= 1
        sleep(1)
        retry
      else
        puts "SocketError: Not responding after 10 retries! Giving up!")
        exit
      end
    end
  end

Additionally, it looks like my local copy of Solr was having some issues with running out of memory. I solved the memory problem by updating my sunspot.yml file accordingly:

development:
  solr:
    hostname: 127.0.0.1
    port: 8982
    min_memory: 512M
    max_memory: 2G
    log_level: INFO
    # open_timeout: 3
    # read_timeout: 3
Tom Chapin
  • 3,276
  • 1
  • 29
  • 18
  • Wow, impressive find. My rsolr is raising Errno::ECONNREFUSED on another thread, and the request is failing. I cannot even capture it from my controller because it is raised on a different thread. I think the app should be more resilient and not raise an exception to the user just because Solr is down. Do you know how to capture that exception from the model callback that starts on another thread? – Chloe Mar 28 '14 at 04:06