Moped, bson + Rubinius 2.2.0

[pkieltyka]

I was just trying to boot my Rails 4.0.1 app that uses mongoid/moped head with Rubinius 2.2.0 and ran into some issues..

Rails output:

Started GET "/api/sessions/current" for 127.0.0.1 at 2013-11-16 15:58:34 -0500
Processing by SessionsController#current as HTML
  MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} runtime: 6.8680ms
  MOPED: Retrying connection attempt 1 more time(s). runtime: n/a
  MOPED: 127.0.0.1:27017 COMMAND      database=admin command={:ismaster=>1} runtime: 7.9310ms
Could not connect to a primary node for replica set #<Moped::Cluster:323360 @seeds=[<Moped::Node resolved_address="127.0.0.1:27017">]>
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/cluster.rb:232:in `with_primary'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/read_preference/primary.rb:55:in `with_node'
kernel/bootstrap/proc.rb:20:in `call'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/read_preference/selectable.rb:65:in `with_retry'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/read_preference/selectable.rb:71:in `with_retry'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/read_preference/primary.rb:54:in `with_node'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/query.rb:116:in `first'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/mongoid-b91705b0ded8/lib/mongoid/contextual/mongo.rb:201:in `first'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/mongoid-b91705b0ded8/lib/mongoid/contextual/mongo.rb:537:in `with_sorting'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/mongoid-b91705b0ded8/lib/mongoid/contextual/mongo.rb:200:in `first'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/mongoid-b91705b0ded8/lib/mongoid/contextual/mongo.rb:449:in `try_cache'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/mongoid-b91705b0ded8/lib/mongoid/contextual/mongo.rb:199:in `first'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/mongoid-b91705b0ded8/lib/mongoid/contextual.rb:19:in `first'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/orm_adapter-0.5.0/lib/orm_adapter/adapters/mongoid.rb:22:in `get'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/devise-3.2.1/lib/devise/models/authenticatable.rb:208:in `serialize_from_session'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/devise-3.2.1/lib/devise.rb:462:in `configure_warden!'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/warden-1.2.3/lib/warden/session_serializer.rb:34:in `fetch'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/warden-1.2.3/lib/warden/proxy.rb:212:in `user'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/warden-1.2.3/lib/warden/proxy.rb:318:in `_perform_authentication'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/warden-1.2.3/lib/warden/proxy.rb:104:in `authenticate'
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/gems/devise-3.2.1/lib/devise/controllers/helpers.rb:58:in `current_user'

mongodb.log output:

Sat Nov 16 15:46:29.705 [initandlisten] connection accepted from 127.0.0.1:58202 #1 (1 connection now open)
Sat Nov 16 15:46:29.705 [conn1] Assertion: 10307:Client Error: bad object in message: bson length doesn't match what we found
0x105fce9f0 0x105fa29fa 0x105fa293c 0x105b4e0c3 0x105b4dcf7 0x105d117db 0x105af885e 0x105fc0fc7 0x106006921 0x7fff91ed6899 0x7fff91ed672a 0x7fff91edafc9 
 0   mongod                              0x0000000105fce9f0 _ZN5mongo15printStackTraceERSo + 64
 1   mongod                              0x0000000105fa29fa _ZN5mongo11msgassertedEiPKc + 186
 2   mongod                              0x0000000105fa293c _ZN5mongo11msgassertedEiRKSs + 12
 3   mongod                              0x0000000105b4e0c3 _ZN5mongo9DbMessage9nextJsObjEv + 531
 4   mongod                              0x0000000105b4dcf7 _ZN5mongo12QueryMessageC2ERNS_9DbMessageE + 151
 5   mongod                              0x0000000105d117db _ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE + 987
 6   mongod                              0x0000000105af885e _ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE + 158
 7   mongod                              0x0000000105fc0fc7 _ZN5mongo17PortMessageServer17handleIncomingMsgEPv + 1079
 8   mongod                              0x0000000106006921 thread_proxy + 177
 9   libsystem_pthread.dylib             0x00007fff91ed6899 _pthread_body + 138
 10  libsystem_pthread.dylib             0x00007fff91ed672a _pthread_struct_init + 0
 11  libsystem_pthread.dylib             0x00007fff91edafc9 thread_start + 13

i

[pkieltyka]

btw, this might be a bson issue, but I just tried running their specs with rubinius 2.2 and it worked fine

[brixen]

From the backtrace, looks like Mongo is using pthread internally. Hopefully, Mongo is not assuming that Ruby threads couldn't be running at the same time.

Does this happen deterministically? Any chance you application is open-source or can you extract something that repros this?

[quidproquo]

Any way to fix this issue?

[brndnblck]

Wrong repository for this request :)

The bson-ruby gem doesn't currently support rubinius, but we'd like to.

You should be reporting/requesting this support over here:
https://github.com/mongodb/bson-ruby

There's a ticket for this, but there's not been a lot of interest in it except for this thread. If you want to see it happen, feel free to vote up the ticket and let us know it's important to you. It's on my list to do, definitely, but low demand for it has made it sink to the bottom of the priority list.

https://jira.mongodb.org/browse/RUBY-591

[arthurnn]

thanks @brandonblack for the response.. I will be closing this issue in here, as this is a known issue on bson gem. I might take a look into that as soon as possible too.

thanks all.

[brndnblck]

No problem.

We actually plan to support Rubinius 2.0 and greater out of the gate in the new Ruby driver (which shares this same BSON implementation) but Moped is currently ahead of us in adoption of bson-ruby 2.0 and I don't think anyone on either team has had spare cycles to look into it.

We'd love to take a PR if any of you have a solid solution ready to go though. Feel free to ping me.

[brndnblck]

@pkieltyka quick question, what version of MongoDB was this error seen on?

[pkieltyka]

v2.4.8

Mon Nov 18 09:53:56.323 [initandlisten] build info: Darwin pak.local 13.0.2 Darwin Kernel Version 13.0.2: Sun Sep 29 19:38:57 PDT 2013; root:xnu-2422.75.4~1/RELEASE_X86_64 x86_64 BOOST_LIB_VERSION=1_49

On Nov 18, 2013, at 12:41 PM, Brandon Black notifications@github.com wrote:

@pkieltyka quick question, what version of MongoDB was this error seen on?

—
Reply to this email directly or view it on GitHub.

[brndnblck]

Great, thank you. We'll look into this.

[pkieltyka]

Thanks!

On Nov 18, 2013, at 12:43 PM, Brandon Black notifications@github.com wrote:

Great, thank you. We'll look into this.

—
Reply to this email directly or view it on GitHub.

[brixen]

@pkieltyka any chance you could extract a repro of this from your app? If you can, could you post it to the jira ticket listed above? If not, would you let me know under what conditions I could access your app to debug this? Feel free to email me.

[pkieltyka]

It’s a closed source project. But is Rbx2+mongoid-head+bson2 working for you guys? I just tried doing a simple Mongoid.default_session.command(ping: 1) and it simply can’t open a connection.. there isn’t anything special about the code wrt that.

Could not connect to a primary node for replica set #<Moped::Cluster:323316 @seeds=[<Moped::Node resolved_address="127.0.0.1:27017">]>
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/cluster.rb:232:in with_primary' /Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/read_preference/primary.rb:55:inwith_node'
kernel/bootstrap/proc.rb:20:in `call'

On Nov 18, 2013, at 12:54 PM, Brian Shirai notifications@github.com wrote:

@pkieltyka any chance you could extract a repro of this from your app? If you can, could you post it to the jira ticket listed above? If not, would you let me know under what conditions I could access your app to debug this? Feel free to email me.

—
Reply to this email directly or view it on GitHub.

[quidproquo]

Check your mongo logs

On Mon, Nov 18, 2013 at 1:03 PM, Peter Kieltyka notifications@github.comwrote:

It’s a closed source project. But is Rbx2+mongoid-head+bson2 working for
you guys? I just tried doing a simple Mongoid.default_session.command(ping:

1. and it simply can’t open a connection.. there isn’t anything special
   about the code wrt that.

Could not connect to a primary node for replica set
#<Moped::Cluster:323316 @seeds=[<Moped::Node resolved_address="
127.0.0.1:27017">]>
/Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/cluster.rb:232:in
with_primary' /Users/peter/.rbenv/versions/rbx-2.2.0/gems/bundler/gems/moped-cdf3a26fa324/lib/moped/read_preference/primary.rb:55:in with_node'
kernel/bootstrap/proc.rb:20:in `call'

On Nov 18, 2013, at 12:54 PM, Brian Shirai notifications@github.com
wrote:

@pkieltyka any chance you could extract a repro of this from your app?
If you can, could you post it to the jira ticket listed above? If not,
would you let me know under what conditions I could access your app to
debug this? Feel free to email me.

—
Reply to this email directly or view it on GitHub.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/231#issuecomment-28721977
.

[brixen]

@pkieltyka I don't use Mongo so I can't say. I just want to see if there's anything broken in Rubinius that I can fix. If someone can throw a simple app up on GitHub and link me, that would be a huge help and I'm happy to dig into it.

[pkieltyka]

Ah ok, that makes sense. I will put together a vanilla app in a few minutes then

On Nov 18, 2013, at 3:03 PM, Brian Shirai notifications@github.com wrote:

@pkieltyka I don't use Mongo so I can't say. I just want to see if there's anything broken in Rubinius that I can fix. If someone can throw a simple app up on GitHub and link me, that would be a huge help and I'm happy to dig into it.

—
Reply to this email directly or view it on GitHub.

[pkieltyka]

Here it is: https://github.com/pkieltyka/monrbx - just start it with bundle exec rails s, and hit localhost:3000/heartbeat .. try on both rbx and mri

[brixen]

@pkieltyka awesome, thank you! I'll see what I can discover.

[haifeng]

Is this related to encoding in rbx or when converting symbol to string? Here's the result I tried:

require "bson"
=> true
h = {:ismaster=>1}
=> {:ismaster=>1}
h.to_bson
=> "\x13\x00\x00\x00\x10ismaste\x00\x00\x01\x00\x00\x00\x00" <<< THIS IS WRONG, Missing 'r'
s = h.keys.first.to_s
=> "ismaster"
s.to_bson
=> "\t\x00\x00\x00ismaste\x00\x00" <<< THIS IS WRONG, Missing 'r'
str = "ismaster"
=> "ismaster"
str.to_bson
=> "\t\x00\x00\x00ismaster\x00" <<< THIS IS RIGHT
s == str
=> true
s.to_bson == str.to_bson
=> false
s.encoding
=> #Encoding:US-ASCII
str.encoding
=> #Encoding:UTF-8

[mrrooijen]

Any update on this? Or is Mongoid currently Rubinius-incompatible?

[brixen]

@meskyanichi I haven't had a chance to look into it yet, but thanks for the ping. I'll put it on the list this week.

[mrrooijen]

@brixen awesome, thanks a lot!

[yorickpeterse]

FYI Mongoid 3 is so far working fine here on Rbx 2.2. Both in terms of test suites and the actual runtime.

[pkieltyka]

I’ve been trying mongoid-head and moped-head with Rbx 2.2.1 and no luck

On Dec 17, 2013, at 7:58 AM, Yorick Peterse notifications@github.com wrote:

FYI Mongoid 3 is so far working fine here on Rbx 2.2.

—
Reply to this email directly or view it on GitHub.

[yorickpeterse]

Haven't tried the HEAD versions so far so can't speak for those. 3.0 series works here though, what errors are you getting?

[chamnap]

I'm having the same problem, rails 4 and mongoid 4.beta1.

Moped::Errors::ConnectionFailure:
       Could not connect to a primary node for replica set #<Moped::Cluster:261928 @seeds=[<Moped::Node resolved_address="127.0.0.1:27017">]>

I wish it will be fixed soon.

[maintux]

👍 I have the same problem with rails 4 and mongoid 4.beta1. Any hint to fix it?

[durran]

Mongoid does not currently support Rubinius, nor does Moped. Support is a very low priority at this point and would be the last thing we look at for the moment.

[yorickpeterse]

@durran Any particular reason for not supporting Rubinius?

[durran]

@yorickpeterse It was pretty much due to the fact that we did not consider Rubinius completely stable until 2.1, and keeping things working in it took too much time away from core issues. We will come back to it later, just won't be first priority. MRI and JRuby will always be top priority - but I would expect at least Rubinius 2.2 to be supported by the official Mongoid 4.0 release... Just will be the last thing we do. :)

[yorickpeterse]

@durran Ok, thanks for the heads up. If you folks need any help/info feel free to ask!

[brixen]

@durran can you say what sort of issues you're encountering with Rubinius relative to MRI?

[durran]

@brixen I'll make a list of outstanding stuff today and post it here.

[brixen]

@durran that's terrific, thanks!

[durran]

@brixen I'm having issues with my local env at the moment after a recent os upgrade so haven't gotten rbx installed again locally. But do note I switched the mongodb-ruby-driver build on master to include rbx and all is good there so far on 2.2.5. The master branch of that driver is Moped's upcoming replacement.

https://travis-ci.org/mongodb/mongo-ruby-driver/builds/18656988

https://github.com/mongodb/mongo-ruby-driver

[brixen]

@durran that's great to see! So, should I put any effort into getting Moped running on Rubinius?

[durran]

@brixen I'd say not to put any real effort into it, since it is getting replaced - unless maybe if it's a quick 1 liner then I see no harm.

[yorickpeterse]

kagaro on IRC mentioned this particular issue again and I did some quick peeking around. It looks like bson-ruby messes up encodings somewhere when running on Rbx. To give a quick example:

:ismaster.to_s.force_encoding('UTF-8').to_bson_key  # => "ismaster\x00"
:ismaster.to_s.force_encoding('BINARY').to_bson_key # => "ismaste\x00\x00"
:ismaster.to_bson_key                               # => "ismaste\x00\x00"

bson-ruby seems to convert everything to BINARY all over the place which for whatever reason results in the second value ("r" being dropped). According to kagaro the output should be ismaster\x00\x00.

[washu]

class String
def to_utf8_binary(encoded)
encoded << dup.encode('UTF-8').force_encoding('BINARY')
end
end

will fix the issue on rbx 2.2.5 and rails 4 with head mongoid and moped

[udipl]

on MRI 2.1.0:

irb(main):002:0> :ismaster.to_bson_key
=> "ismaster\x00"

on rbx 2.2.6:

irb(main):003:0> :ismaster.to_bson_key
=> "ismaste\x00\x00"

I'm happy to use the solution @washu suggested, but I'm concerned that there may be a deeper bug that may have other effects.

[yorickpeterse]

If there's a way to reproduce this error outside of Mongoid that would make it easier for us to find out what's going on with Rbx. I'm not familiar with the workings of to_bson_key so it's a bit hard to figure out what it does, why, etc.

[udipl]

@yorickpeterse , you don't need a full mongoid installation. The problem is with the bson gem, and is reproducible with one line in irb, as I illustrated above. (just require 'bson')

The problem seems to be in BSON::String.to_utf8_binary which is

    def to_utf8_binary(encoded)
      encoded << encode(UTF8).force_encoding(BINARY)
    end

where the encoded argument is a BINARY-encoded string.

BSON::String is included in ::String.

[kayakyakr]

Just wanted to update, in case anyone else runs across this thread. rbx is currently working with the following mongoid, moped, and bson versions:
mongoid (4.0.0.rc1)
moped (2.0.0.rc1)
bson (2.3.0)