Inifinite loop problem with DRb server

Hi all,

We’re attempting to use Ferret with the DRb server at the moment, and
it doesn’t work, at all…

= Executive Summary

The DRb server process keeps on calling the remote index to the DRb
server process… Which means DRb is calling itself, and itself, and
itself, until Ruby kills the Thread with a SystemStackLevel error.

= The excruciating details…

Mongrel is started using:

mongrel_rails start --port 6543 --environment development --daemonize
2>&1

config/ferret_server.yml

development:
host: 127.0.0.1
port: 3000
pid_file: log/ferret.3000.pid

Ferret’s DRb server is started using:

script/runner -e development
vendor/plugins/acts_as_ferret/script/ferret_start

app/models/email.rb:

class Email < ActiveRecord::Base
acts_as_ferret :store_class_name => true, :remote => true,
:fields => (self.content_columns.map(&:name) rescue []) +
%w(main_identifier party_display_name)
end

app/controllers/search_controller.rb

class SearchController < ApplicationController
def quick
@results = Email.id_multi_search(params[:q], %w(Contact Company))
end
end

Backtrace

stack level too deep

(druby://127.0.0.1:3000) /usr/local/lib/ruby/1.8/drb/drb.rb:1649:in
current_server' (druby://127.0.0.1:3000) /usr/local/lib/ruby/1.8/drb/drb.rb:1704:in to_obj’
(druby://127.0.0.1:3000) /usr/local/lib/ruby/1.8/drb/drb.rb:1079:in
method_missing' (druby://127.0.0.1:3000) /home/francois/src/xlsuite.org/vendor/plugins/acts_as_ferret/lib/remote_index.rb:25:in id_multi_search’
(druby://127.0.0.1:3000)
/home/francois/src/xlsuite.org/vendor/plugins/acts_as_ferret/lib/ferret_server.rb:69:in
send' (druby://127.0.0.1:3000) /home/francois/src/xlsuite.org/vendor/plugins/acts_as_ferret/lib/ferret_server.rb:69:in method_missing’
/home/francois/src/xlsuite.org/vendor/plugins/acts_as_ferret/lib/remote_index.rb:25:in
id_multi_search' /home/francois/src/xlsuite.org/vendor/plugins/acts_as_ferret/lib/class_methods.rb:117:in id_multi_search’
/home/francois/src/xlsuite.org/app/controllers/search_controller.rb:9:in
`quick’

$ rake log:clear && sleep 50 && du -h log/ferret*
(in /home/francois/src/xlsuite.org)
4.0K log/ferret.3000.pid
0 log/ferret_index.log
229M log/ferret_server.log
4.0K log/ferret_server.out

There’s nothing really useful in ferret_server.log: only the same
backtrace that I showed above.

module ActsAsFerret
module Remote
class Server
# vendor/plugins/acts_as_ferret/lib/ferret_server.rb:65
def method_missing(name, *args)
clazz = args.shift.constantize
begin
@logger.debug “call index method: #{name} with
#{args.inspect}”
clazz.aaf_index.send name, *args
rescue NoMethodError
@logger.debug “no luck, trying to call class method instead”
clazz.send name, *args
end
rescue
@logger.error “ferret server error #{$!}\n#{$!.backtrace.join
‘\n’}”
raise
end
end
end
end

When I change the logging statement inside the first begin/rescue clause
of:
http://projects.jkraemer.net/acts_as_ferret/browser/trunk/plugin/acts_as_ferret/lib/ferret_server.rb#L68

I get this (see patch at end of message):
ActsAsFerret::Server#method_missing calling:
Email.id_multi_search([“position”, [“Contact”, “Company”, “Email”],
{}])
ActsAsFerret::Server#method_missing calling:
Email.id_multi_search([“position”, [“Contact”, “Company”, “Email”],
{}])
ActsAsFerret::Server#method_missing calling:
Email.id_multi_search([“position”, [“Contact”, “Company”, “Email”],
{}])
ActsAsFerret::Server#method_missing calling:
Email.id_multi_search([“position”, [“Contact”, “Company”, “Email”],
{}])

In total, there are 816 calls to #method_missing before Ruby gives up
and raises.

From my limited understanding of the code, it looks like the Ferret
DRb server is using a remote index instead of a local one.

This is all using the Rails 1.2 stable branch with r179 of the
acts_as_ferret plugin and the Ferret gem at 0.11.3.

So, what have we configured wrong ?

Thanks !

François Beausoleil
http://blog.teksol.info/
http://piston.rubyforge.org/

$ svn diff vendor/plugins/acts_as_ferret/
Index: vendor/plugins/acts_as_ferret/lib/ferret_server.rb

— vendor/plugins/acts_as_ferret/lib/ferret_server.rb (revision 179)
+++ vendor/plugins/acts_as_ferret/lib/ferret_server.rb (working copy)
@@ -65,7 +65,8 @@
def method_missing(name, *args)
clazz = args.shift.constantize
begin

  •    @logger.debug "call index method: #{name} with #{args.inspect}"
    
  •    @logger.debug "ActsAsFerret::Server\#method_missing calling:
    

#{clazz.name}.#{name}(#{args.inspect})"

  •    #raise "auto block"
       clazz.aaf_index.send name, *args
     rescue NoMethodError
       @logger.debug "no luck, trying to call class method instead"
    

On Tue, Apr 03, 2007 at 03:34:11PM -0400, François Beausoleil wrote:

[…]

From my limited understanding of the code, it looks like the Ferret
DRb server is using a remote index instead of a local one.

I’d guess that’s the problem. The decision what indexer to use is made
in act_methods.rb, line 62, depending on the state of
ActsAsFerret::Remote::Server.running

So if the acts_as_ferret method would be called before the DRb server is
up and running what you describe could happen. Maybe there’s some code
in your environment.rb that causes the loading of your model classes by
script/runner before the server gets a chance to start up?

As I think of it now, the way how this is done might not be the ideal
solution to the problem of deciding whether acts_as_ferret is called in
the DRb-server or not - an environment variable set when
starting the server and checking this in act_methods.rb instead of the
server’s running method might help:

IS_SERVER=true script/runner -e development
vendor/plugins/acts_as_ferret/script/ferret_start

and in act_methods line 62:

options.delete(:remote) if ENV[‘IS_SERVER’]

Jens


Jens Krämer
webit! Gesellschaft für neue Medien mbH
Schnorrstraße 76 | 01069 Dresden
Telefon +49 351 46766-0 | Telefax +49 351 46766-66
[email protected] | www.webit.de

Amtsgericht Dresden | HRB 15422
GF Sven Haubold, Hagen Malessa

François Beausoleil wrote:

2007/4/4, Jens K. [email protected]:

On Tue, Apr 03, 2007 at 03:34:11PM -0400, François Beausoleil wrote:

The DRb server process keeps on calling the remote index to the DRb
server process… Which means DRb is calling itself, and itself, and
itself, until Ruby kills the Thread with a SystemStackLevel error.

[…]

I’d guess that’s the problem. The decision what indexer to use is made
in act_methods.rb, line 62, depending on the state of
ActsAsFerret::Remote::Server.running

Yup, you hit the nail on the head. I require app/models/*.rb at the
end of config/environment.rb. I can’t test this right now, but I’ll
try it when I get back to my office.

I had the same problem, with acts_as_ferret’s ferret_server.log being
around 101 MB for every DRb request that resulted with
“SystemStackError: stack level too deep”.

Removing the lines that required the models from my environment.rb
definitely did the trick.

Hello Jens,

2007/4/4, Jens K. [email protected]:

On Tue, Apr 03, 2007 at 03:34:11PM -0400, François Beausoleil wrote:

The DRb server process keeps on calling the remote index to the DRb
server process… Which means DRb is calling itself, and itself, and
itself, until Ruby kills the Thread with a SystemStackLevel error.

[…]

I’d guess that’s the problem. The decision what indexer to use is made
in act_methods.rb, line 62, depending on the state of
ActsAsFerret::Remote::Server.running

Yup, you hit the nail on the head. I require app/models/*.rb at the
end of config/environment.rb. I can’t test this right now, but I’ll
try it when I get back to my office.

Your idea of using an ENV variable is probably a good idea.

I’ll see about creating a patch for that.

Thanks !

François Beausoleil
http://blog.teksol.info/
http://piston.rubyforge.org/

Hi !

2007/4/4, Jens K. [email protected]:

As I think of it now, the way how this is done might not be the ideal
solution to the problem of deciding whether acts_as_ferret is called in
the DRb-server or not - an environment variable set when
starting the server and checking this in act_methods.rb instead of the
server’s running method might help:

I changed Ferret’s implementation with this patch:

$ svn diff vendor/plugins
Index: vendor/plugins/acts_as_ferret/lib/ferret_server.rb

— vendor/plugins/acts_as_ferret/lib/ferret_server.rb (revision 4125)
+++ vendor/plugins/acts_as_ferret/lib/ferret_server.rb (working copy)
@@ -63,9 +63,9 @@
# TODO: rebuild indexes in separate directory so no lock errors in
these
# cases.
def method_missing(name, *args)

  •  @logger.debug "\#method_missing(#{name.inspect}, 
    

#{args.inspect})"
clazz = args.shift.constantize
begin

  •    @logger.debug "call index method: #{name} with #{args.inspect}"
       clazz.aaf_index.send name, *args
     rescue NoMethodError
       @logger.debug "no luck, trying to call class method instead"
    

Index: vendor/plugins/acts_as_ferret/lib/act_methods.rb

— vendor/plugins/acts_as_ferret/lib/act_methods.rb (revision 4125)
+++ vendor/plugins/acts_as_ferret/lib/act_methods.rb (working copy)
@@ -59,11 +59,15 @@

   # force local mode if running *inside* the Ferret server - 

somewhere the
# real indexing has to be done after all :slight_smile:

  •  options.delete(:remote) if ActsAsFerret::Remote::Server.running
    
  •  logger.debug {"Asked for a remote server ?
    

#{options[:remote].inspect}, ENV["FERRET_USE_LOCAL_INDEX"] is
#{ENV[“FERRET_USE_LOCAL_INDEX”].inspect}, server is
#{ActsAsFerret::Remote::Server.running ? :running : :not_running}"}

  •  options.delete(:remote) if ENV["FERRET_USE_LOCAL_INDEX"] ||
    

ActsAsFerret::Remote::Server.running

   if options[:remote] && options[:remote] !~ /^druby/
     # read server location from config/ferret_server.yml
     options[:remote] =

ActsAsFerret::Remote::Config.load(“#{RAILS_ROOT}/config/ferret_server.yml”)[:uri]

  •    logger.debug {"Will use a remote index server which should be
    

available at #{options[:remote]}"}

  •  else
    
  •    logger.debug {"Will use a local index"}
     end
    

That resolved my problem when I start the DRb server using:
$ FERRET_USE_LOCAL_INDEX=1 script/runner -e development
vendor/plugins/acts_as_ferret/script/ferret_start

BTW, my models are loaded because I have AR observers.

Thanks !

François Beausoleil
http://blog.teksol.info/
http://piston.rubyforge.org/

On Thu, Apr 05, 2007 at 05:15:51PM -0400, François Beausoleil wrote:

Hi !

2007/4/4, Jens K. [email protected]:

As I think of it now, the way how this is done might not be the ideal
solution to the problem of deciding whether acts_as_ferret is called in
the DRb-server or not - an environment variable set when
starting the server and checking this in act_methods.rb instead of the
server’s running method might help:

I changed Ferret’s implementation with this patch:
[…]

Thanks, this is now part of trunk.

Jens


Jens Krämer
webit! Gesellschaft für neue Medien mbH
Schnorrstraße 76 | 01069 Dresden
Telefon +49 351 46766-0 | Telefax +49 351 46766-66
[email protected] | www.webit.de

Amtsgericht Dresden | HRB 15422
GF Sven Haubold, Hagen Malessa