Details
-
Bug
-
Resolution: Unresolved
-
Major - P3
-
None
-
4.4.0, 4.2.10
-
None
-
None
-
Storage Execution
-
ALL
Description
I made the following test program which repeatedly drops a collection and inserts a document into it:
require 'mongo'
|
|
|
Mongo::Logger.logger.level = 1
|
|
|
client = Mongo::Client.new(['localhost:14440', 'localhost:14441'])
|
db1 = client[:db1]
|
|
|
loop do
|
db1.drop
|
db1.insert_one(a: 1)
|
print('.')
|
end
|
I ran this against 4.2 and 4.4 sharded clusters launched as follows:
serene% ./script/launch-4.2-sharded-multishard
|
Base port: 14240
|
Running mlaunch --replicaset --nodes 2 --sharded 2 --name ruby-driver-rs --mongos 2 --dir /mnt/zram/mongodb/4.2-scm --setParameter diagnosticDataCollectionEnabled=false --wiredTigerCacheSizeGB 0.25 --setParameter honorSystemUmask=true --wiredTigerEngineConfigString 'log=(prealloc=false,file_max=20MB),cache_size=256M' --networkMessageCompressors zstd,snappy,zlib --setParameter enableTestCommands=1 --filePermissions 0666 --binarypath /usr/local/m/versions/4.2 --port 14240
|
warning: ignoring unknown argument --wiredTigerEngineConfigString for /usr/local/m/versions/4.2/mongos
|
launching: "/usr/local/m/versions/4.2/mongod" on port 14242
|
launching: "/usr/local/m/versions/4.2/mongod" on port 14243
|
launching: "/usr/local/m/versions/4.2/mongod" on port 14244
|
launching: "/usr/local/m/versions/4.2/mongod" on port 14245
|
launching: config server on port 14246
|
replica set 'configRepl' initialized.
|
replica set 'shard01' initialized.
|
replica set 'shard02' initialized.
|
launching: /usr/local/m/versions/4.2/mongos on port 14240
|
launching: /usr/local/m/versions/4.2/mongos on port 14241
|
adding shards. can take up to 30 seconds...
|
|
|
serene% ./script/launch-4.4-sharded-multishard
|
Base port: 14440
|
Running mlaunch --replicaset --nodes 2 --sharded 2 --name ruby-driver-rs --mongos 2 --dir /mnt/zram/mongodb/4.4-scm --setParameter diagnosticDataCollectionEnabled=false --wiredTigerCacheSizeGB 0.25 --setParameter honorSystemUmask=true --wiredTigerEngineConfigString 'log=(prealloc=false,file_max=20MB),cache_size=256M' --networkMessageCompressors zstd,snappy,zlib --setParameter enableTestCommands=1 --filePermissions 0666 --binarypath /usr/local/m/versions/4.4 --port 14440
|
warning: ignoring unknown argument --wiredTigerEngineConfigString for /usr/local/m/versions/4.4/mongos
|
launching: "/usr/local/m/versions/4.4/mongod" on port 14442
|
launching: "/usr/local/m/versions/4.4/mongod" on port 14443
|
launching: "/usr/local/m/versions/4.4/mongod" on port 14444
|
launching: "/usr/local/m/versions/4.4/mongod" on port 14445
|
launching: config server on port 14446
|
replica set 'configRepl' initialized.
|
replica set 'shard01' initialized.
|
replica set 'shard02' initialized.
|
launching: /usr/local/m/versions/4.4/mongos on port 14440
|
launching: /usr/local/m/versions/4.4/mongos on port 14441
|
adding shards. can take up to 30 seconds...
|
In both cases, after some time, the config server runs out of open files.
Program output:
serene% ruby test.rb
|
.........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................Traceback (most recent call last):
|
20: from test.rb:8:in `<main>'
|
19: from test.rb:8:in `loop'
|
18: from test.rb:10:in `block in <main>'
|
17: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/collection.rb:546:in `insert_one'
|
16: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/client.rb:1018:in `with_session'
|
15: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/collection.rb:552:in `block in insert_one'
|
14: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/retryable.rb:220:in `write_with_retry'
|
13: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/collection.rb:563:in `block (2 levels) in insert_one'
|
12: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/write.rb:39:in `execute'
|
11: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/server.rb:425:in `with_connection'
|
10: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/server/connection_pool.rb:590:in `with_connection'
|
9: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/write.rb:50:in `block in execute'
|
8: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/response_handling.rb:26:in `validate_result'
|
7: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/response_handling.rb:82:in `unpin_maybe'
|
6: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/response_handling.rb:27:in `block in validate_result'
|
5: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/response_handling.rb:43:in `add_error_labels'
|
4: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/response_handling.rb:28:in `block (2 levels) in validate_result'
|
3: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/response_handling.rb:96:in `add_server_diagnostics'
|
2: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/shared/response_handling.rb:29:in `block (3 levels) in validate_result'
|
1: from /home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/result.rb:289:in `validate!'
|
/home/w/.rbenv/versions/2.7.2/lib/ruby/gems/2.7.0/gems/mongo-2.13.1/lib/mongo/operation/result.rb:321:in `raise_operation_failure': Connection closed by peer (6) (on localhost:14440, modern retry, attempt 1) (Mongo::Error::OperationFailure)
|
Server logs attached for 4.2.10 and 4.4.0.
Since I am operating on the same collection, I expect the server to be able to handle this workload without unbounded growth in open file count.
This condition, once encountered, appears to be persistent. If I now restart the crashed config server, I get one of two behaviors:
- The same failure happens much quicker (e.g. after ~15 iterations)
- The server doesn't come up at all due to exceeding open file limit
The second attached config server log file for 4.4 is with 3 attempts - one original as shown in the first file + two restarts.