bson_ext がロード済みだと Timecop で BSON::ObjectId の creation timestamp を制御できない

MongoDB のドキュメントは ObjectId 型の _id というフィールドを持つ。 ObjectId の先頭 4 バイトはその ObjectId が生成された UNIX timestamp を表現しているので、 ObjectId をアルファベット昇順でソートすると生成時刻の古い順に並ぶ。
http://docs.mongodb.org/manual/reference/object-id/

```ruby
require 'bson'
a = BSON::ObjectId.new # => BSON::ObjectId('531029d64b656ea1f4000000')
sleep 1
b = BSON::ObjectId.new # => BSON::ObjectId('531029d74b656ea1f4010000')
p [b, a].sort          # => [BSON::ObjectId('531029d64b656ea1f4000000'), BSON::ObjectId('531029d74b656ea1f4010000')]
```

MongoMapper や Mongoid のような O/R Mapper を使って has_many な association を定義する場合、一貫した並び順を維持するために以下のように書きたくなるだろう。

```ruby
require 'mongo_mapper'

MongoMapper.database = 'testing'

class User
  include MongoMapper::Document
  many :bookmarks, order: :id
end

class Bookmark
  include MongoMapper::Document
  key :name, String
  belongs_to :user
end

user = User.create
user.bookmarks.create(name: "Bookmark 1") # => #<Bookmark _id: BSON::ObjectId('53102d7d421cdcba65000002'), name: "Bookmark 1", user_id: BSON::ObjectId('53102d7d421cdcba65000001')>
sleep 1
user.bookmarks.create(name: "Bookmark 2") # => #<Bookmark _id: BSON::ObjectId('53102d7e421cdcba65000003'), name: "Bookmark 2", user_id: BSON::ObjectId('53102d7d421cdcba65000001')>

user.bookmarks # => [#<Bookmark _id: BSON::ObjectId('53102d7d421cdcba65000002'), name: "Bookmark 1", user_id: BSON::ObjectId('53102d7d421cdcba65000001')>, #<Bookmark _id: BSON::ObjectId('53102d7e421cdcba65000003'), name: "Bookmark 2", user_id: BSON::ObjectId('53102d7d421cdcba65000001')>]
```

ならばテストコードで以下のように書きたくなることもまた自然だ。しかしこれは期待どおりに動かないことがある。

```ruby
require 'mongo_mapper'
require 'rspec'
require 'timecop'

MongoMapper.database = 'testing'

class User
  include MongoMapper::Document
  many :bookmarks, order: :id
end

class Bookmark
  include MongoMapper::Document
  key :name, String
  belongs_to :user
end

describe "sort order" do
  it "should be sorted by :id.asc" do
    user = User.create

    Timecop.travel(Time.now + 86400)
    bookmark1 = user.bookmarks.create(name: "Bookmark 1")
    Timecop.return
    bookmark2 = user.bookmarks.create(name: "Bookmark 2")

    expect(bookmark1.id.generation_time).to be > bookmark2.id.generation_time
  end
end
```

```

sort order
  should be sorted by :id.asc (FAILED - 1)

Failures:

  1) sort order should be sorted by :id.asc
     Failure/Error: expect(bookmark1.id.generation_time).to be > bookmark2.id.generation_time
       expected: > 2014-02-28 06:58:55 UTC
            got:   2014-02-28 06:58:55 UTC
     # ./mm_spec.rb:27:in `block (2 levels) in <top (required)>'

Finished in 0.02526 seconds
1 example, 1 failure

Failed examples:

rspec ./mm_spec.rb:19 # sort order should be sorted by :id.asc
```

Timecop は Time.now, Time.new メソッドを上書きするが、 bson のC拡張実装である bson_ext がロードされていると BSON::ObjectId#generate メソッドがC実装の関数で上書きされるため、 Time.new を呼び出さなくなるためである。
https://github.com/mongodb/mongo-ruby-driver/blob/1.x-stable/ext/cbson/cbson.c#L1176
https://github.com/mongodb/mongo-ruby-driver/blob/1.x-stable/ext/cbson/cbson.c#L1070

BSON::ObjectId#generate の Ruby 実装は Time.new を呼び出しているので、 bson_ext がロードされていない場合は Timecop による制御が期待どおり動く。
https://github.com/mongodb/mongo-ruby-driver/blob/1.x-stable/lib/bson/types/object_id.rb#L202

BSON_EXT_DISABLED 環境変数を定義することで明示的に bson_ext のロードを抑制できるので、 bson_ext がロード済みか否かによって BSON::ObjectId#generate の呼び出し時にCとRubyどちらの実装が使われているかを調べることができる。

```bson_ruby.rb
ENV.update({ "BSON_EXT_DISABLED" => "1" })
gem 'bson', '1.9.2'
require 'bson'

set_trace_func proc { |*args|
  p args
}
BSON::ObjectId.new
```

```
 ** Notice: The native BSON extension was not loaded. **

      For optimal performance, use of the BSON extension is recommended.

      To enable the extension make sure ENV['BSON_EXT_DISABLED'] is not set
      and run the following command:

        gem install bson_ext

      If you continue to receive this message after installing, make sure that
      the bson_ext gem is in your load path.
["c-return", "bson_ruby.rb", 5, :set_trace_func, #<Binding:0x007fcd3a092a68>, Kernel]
["line", "bson_ruby.rb", 8, nil, #<Binding:0x007fcd3a0924f0>, nil]
["c-call", "bson_ruby.rb", 8, :new, #<Binding:0x007fcd3a092090>, Class]
["call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 43, :initialize, #<Binding:0x007fcd3a091b18>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 44, :initialize, #<Binding:0x007fcd3a0916e0>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 47, :initialize, #<Binding:0x007fcd3a091230>, BSON::ObjectId]
["call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 198, :generate, #<Binding:0x007fcd3a090e20>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 199, :generate, #<Binding:0x007fcd3a090948>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 202, :generate, #<Binding:0x007fcd3a090420>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :generate, #<Binding:0x007fcd3a092680>, BSON::ObjectId]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :new, #<Binding:0x007fcd3a08bd80>, Class]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :initialize, #<Binding:0x007fcd3a08b7b8>, Time]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :+, #<Binding:0x007fcd3a08b358>, Fixnum]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :+, #<Binding:0x007fcd3a08ad68>, Fixnum]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :initialize, #<Binding:0x007fcd3a08a958>, Time]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :new, #<Binding:0x007fcd3a08a098>, Class]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :to_i, #<Binding:0x007fcd3a089c38>, Time]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :divmod, #<Binding:0x007fcd3a089828>, Fixnum]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :divmod, #<Binding:0x007fcd3a089468>, Fixnum]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 205, :to_i, #<Binding:0x007fcd3a088fb8>, Time]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 207, :generate, #<Binding:0x007fcd3a088c20>, BSON::ObjectId]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 207, :pack, #<Binding:0x007fcd3a0885e0>, Array]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 207, :pack, #<Binding:0x007fcd3a088248>, Array]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 210, :generate, #<Binding:0x007fcd3a0887e8>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 213, :generate, #<Binding:0x007fcd3987fc90>, BSON::ObjectId]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 213, :pid, #<Binding:0x007fcd3987f830>, Process]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 213, :pid, #<Binding:0x007fcd3987f470>, Process]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 213, :pack, #<Binding:0x007fcd3987eea8>, Array]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 213, :pack, #<Binding:0x007fcd3987e9d0>, Array]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 216, :generate, #<Binding:0x007fcd3987e548>, BSON::ObjectId]
["call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 221, :get_inc, #<Binding:0x007fcd3987e0c0>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 222, :get_inc, #<Binding:0x007fcd3987db20>, BSON::ObjectId]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 222, :synchronize, #<Binding:0x007fcd3987d788>, Mutex]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 223, :get_inc, #<Binding:0x007fcd3987d2b0>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 223, :get_inc, #<Binding:0x007fcd3987cce8>, BSON::ObjectId]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 222, :synchronize, #<Binding:0x007fcd3987c928>, Mutex]
["return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 225, :get_inc, #<Binding:0x007fcd3987c3b0>, BSON::ObjectId]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 216, :pack, #<Binding:0x007fcd3987d918>, Array]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 216, :pack, #<Binding:0x007fcd3987fce0>, Array]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 216, :[], #<Binding:0x007fcd39877b08>, String]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 216, :[], #<Binding:0x007fcd39877720>, String]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 218, :generate, #<Binding:0x007fcd39877180>, BSON::ObjectId]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 218, :unpack, #<Binding:0x007fcd39876d20>, String]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 218, :unpack, #<Binding:0x007fcd39876988>, String]
["return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 219, :generate, #<Binding:0x007fcd39876460>, BSON::ObjectId]
["return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 48, :initialize, #<Binding:0x007fcd398760a0>, BSON::ObjectId]
["c-return", "bson_ruby.rb", 8, :new, #<Binding:0x007fcd39875b78>, Class]
```

```ruby
gem 'bson', '1.9.2'
require 'bson'

set_trace_func proc { |*args|
  p args
}
BSON::ObjectId.new
```

```
["c-return", "bson_ext.rb", 4, :set_trace_func, #<Binding:0x007fe614093178>, Kernel]
["line", "bson_ext.rb", 7, nil, #<Binding:0x007fe614092a48>, nil]
["c-call", "bson_ext.rb", 7, :new, #<Binding:0x007fe614092458>, Class]
["call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 43, :initialize, #<Binding:0x007fe614091eb8>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 44, :initialize, #<Binding:0x007fe6140919e0>, BSON::ObjectId]
["line", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 47, :initialize, #<Binding:0x007fe614091468>, BSON::ObjectId]
["c-call", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 47, :generate, #<Binding:0x007fe614090e50>, BSON::ObjectId]
["c-return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 47, :generate, #<Binding:0x007fe614090568>, BSON::ObjectId]
["return", "/Users/kyanny/.gem/ruby/2.1.0/gems/bson-1.9.2/lib/bson/types/object_id.rb", 48, :initialize, #<Binding:0x007fe614090068>, BSON::ObjectId]
["c-return", "bson_ext.rb", 7, :new, #<Binding:0x007fe6150336f0>, Class]
```

結論: MySQL の auto_increment 的に id の昇順で並ぶことを期待するのはやめよう。一貫した並び順を維持したいならそれ用のフィールドを定義しよう。どうしても id 順に並ばせたい場合は諦めてテストコードの中で sleep 1 しよう。