Details
-
Bug
-
Resolution: Won't Fix
-
Major - P3
-
None
-
4.2.10
-
None
-
None
-
ALL
-
Sharding 2020-12-14, Sharding 2020-12-28
Description
I made the following test program which drops the database, inserts a document and performs countdocuments on the database in question. Eventually this program will see the document count stay at 0 for several seconds after a successful insert, after which the count increases to 1.
To make this situation reproducible, I insert some more data prior to the drop to generate extra load, and I drop on only ~ 10% of the iterations.
require 'mongo'
|
require 'byebug'
|
|
|
Mongo::Logger.logger.level = 1
|
|
|
client = Mongo::Client.new(['localhost:14240', 'localhost:14241']).use('xxx')
|
db1 = client[:db1]
|
|
|
loop do
|
15.times do
|
db1.insert_many([{a: rand}]*5)
|
end
|
|
|
check = rand >= 0.9
|
|
|
if check
|
db1.database.drop
|
end
|
|
|
db1.insert_one(a: 1)
|
|
|
if check
|
v = db1.count_documents
|
if v != 1
|
p v
|
#byebug
|
1
|
loop do
|
v = db1.count_documents
|
if v != 1
|
p v
|
sleep 1
|
else
|
byebug
|
1
|
end
|
end
|
end
|
end
|
|
|
print('.')
|
end
|
Result:
serene% ruby test.rb
|
........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................0
|
0
|
0
|
0
|
0
|
|
|
[30, 39] in /home/w/apps/tests/shard-phantom/test.rb
|
30: if v != 1
|
31: p v
|
32: sleep 1
|
33: else
|
34: byebug
|
=> 35: 1
|
36: end
|
37: end
|
38: end
|
39: end
|
(byebug)
|
This issue originally appeared in the transactions example tests for the Ruby driver, where instead of doing a count a find was issued, and that find returned no results after the document to be found was inserted.
I tried setting read and write concerns to majority, which didn't fix the problem:
client = Mongo::Client.new(['localhost:14240', 'localhost:14241']).use('xxx').with(
|
read_concern: {level: :majority}, write_concern: {w: :majority})
|
In the Ruby driver test suite this condition persists for much longer than this reproduce case shows (potentially indefinitely). To get out of it I can insert another document into the collection in question. Note in the following example how the count jumps from 0 to 2 even though I only inserted one document:
(byebug) hr[:employees].count
|
D, [2020-11-21T04:45:16.374462 #427] DEBUG -- : MONGODB | localhost:27018 req:79 conn:1:1 sconn:22 | hr.count | STARTED | {"count"=>"employees", "query"=>{}, "readConcern"=>{"level"=>"majority"}, "$db"=>"hr", "$clusterTime"=>{"clusterTime"=>#<BSON::Timestamp:0x00007fbe5c090200 @seconds=1605933879, @increment=1>, "signature"=>{"hash"=><BSON::Binary:0x6960 type=generic dat...
|
D, [2020-11-21T04:45:16.379245 #427] DEBUG -- : MONGODB | localhost:27018 req:79 | hr.count | SUCCEEDED | 0.004s
|
0
|
(byebug) hr[:employees].insert_one(a:1)
|
D, [2020-11-21T04:45:20.533725 #427] DEBUG -- : MONGODB | localhost:27018 req:80 conn:1:1 sconn:22 | hr.insert | STARTED | {"insert"=>"employees", "ordered"=>true, "writeConcern"=>{"w"=>"majority"}, "documents"=>[{"a"=>1, "_id"=>BSON::ObjectId('5fb89b6094fbce01ab1bea0e')}], "$db"=>"hr", "$clusterTime"=>{"clusterTime"=>#<BSON::Timestamp:0x00007fbe5c0bea88 @seconds=16059339...
|
D, [2020-11-21T04:45:20.540557 #427] DEBUG -- : MONGODB | localhost:27018 req:80 | hr.insert | SUCCEEDED | 0.007s
|
#<Mongo::Operation::Insert::Result:0x7120 documents=[{"n"=>1, "ok"=>1.0, "operationTime"=>#<BSON::Timestamp:0x00007fbe5c0c4af0 @seconds=1605933920, @increment=4>, "$clusterTime"=>{"clusterTime"=>#<BSON::Timestamp:0x00007fbe5c0c4a00 @seconds=1605933920, @increment=4>, "signature"=>{"hash"=><BSON::Binary:0x7140 type=generic data=0x0000000000000000...>, "keyId"=>0}}}]>
|
(byebug) hr[:employees].count
|
D, [2020-11-21T04:45:21.510076 #427] DEBUG -- : MONGODB | localhost:27017 req:81 conn:1:1 sconn:28 | hr.count | STARTED | {"count"=>"employees", "query"=>{}, "readConcern"=>{"level"=>"majority"}, "$db"=>"hr", "$clusterTime"=>{"clusterTime"=>#<BSON::Timestamp:0x00007fbe5c0c4a00 @seconds=1605933920, @increment=4>, "signature"=>{"hash"=><BSON::Binary:0x7140 type=generic dat...
|
D, [2020-11-21T04:45:21.516207 #427] DEBUG -- : MONGODB | localhost:27017 req:81 | hr.count | SUCCEEDED | 0.005s
|
2
|
Note that even though in the above output the counts were sent to different mongoses, prior to insert both mongoses returned 0 and after the insert both returned 2.
This issue seems to only affect 4.2 sharded clusters.
Attachments
Issue Links
- related to
-
RUBY-2447 Fix intermittent transaction examples test failures
-
- Closed
-