Bad file descriptor in threaded send_message_on_socket (jruby)

[David Tollmyr]

Hey!

I have a jruby application that reads messages from a rabbitmq queue
containing timespans. From these timespans i build a mongo query and
fetch data that needs to be processed.

The mongo connection is initialized on application start, and when i
try to access it in the rabbitmq thread i get the following exception:
Errno::EBADF: Bad file descriptor - Bad file descriptor
close at org/jruby/RubyIO.java:1982
close at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/util/
pool.rb:51
each at org/jruby/RubyArray.java:1602
close at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/util/
pool.rb:49
close at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
connection.rb:561
send_message_on_socket at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
connection.rb:855
receive_message at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
connection.rb:483
receive_message at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
connection.rb:482
send_initial_query at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
cursor.rb:407
instrument at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
connection.rb:609
send_initial_query at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
cursor.rb:406
refresh at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
cursor.rb:371
next_document at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
cursor.rb:87
each at /Users/david/.rvm/gems/
jruby-1.6.2@rich_collection/gems/mongo-1.3.1/lib/../lib/mongo/
cursor.rb:248
each_exposure at /Users/david/Documents/src/rich_collection/
lib/rich_collection/batch/meta_mixer.rb:20
each at /Users/david/Documents/src/rich_collection/
lib/rich_collection/batch/batch_consumer.rb:34
call at org/jruby/RubyProc.java:256

Here's the relevant code:
BatchConsumer
def initialize(queue_handle)
@queue_handle = queue_handle
@mixer =
MetaMixer.new(Mongo::Connection.new.db("complete", :pool_size => 5))
end

def start
@subscription ||= @queue_handle.subscribe(:ack => true)
end

def each
@subscription.each(:blocking => false) do |headers,
encoded_message|
message = decode_message(encoded_message)
@mixer.each_exposure(message) do | exp |
yield exp
end
headers.ack
end
end

MetaMixer
def initialize(complete_db, meta_db)
@complete_db = complete_db
end

def each_exposure(span)
if span["start"] && span["end"]
cursor = @complete_db.collection(:exposures).find({"_id" =>
"BLA"})

cursor.each do |e|
# Stuff
yield exposure
end
end
end

If i initialize the connection in the rabbitmq thread (just before
"cursor = ..." above) everything works fine, so i assume something
happens in the thread handling that screws up the connection. Changing
pool_size doesn't help.

[Kyle Banker]

I'm not 100% certain that this is the problem, but you're initiating
the DB object incorrectly. You must set :pool_size on the Connection
constructor, like this:

Connection.new('localhost', 27017, :pool_size => 5)

Are you sending the Connection object to lots of threads? Looks like
there might be a race condition on the connection pool. Will look into
it, but can you try properly setting the pool size?

[David Tollmyr]

This was not related, merely a copy-paste error. I did try out a
number of different pool_sizes but no change.

This specific issue turned out to be caused by thread closing to
early, shutting down the mongoconnection but keeping the rabbitMQ
connection alive. So when a message arrived it tried to access mongo
through a closed connection.

Still seem to get this problem on some other places at times though,
but it's probably caused by something similar.

[Kyle Banker]

Just created an issue for this. I believe I know what's happening
here:
https://jira.mongodb.org/browse/RUBY-285

Feel free to add comments. I'll have a fix for the 1.4.0 release.

Kyle