-
Type:
Bug
-
Resolution: Gone away
-
Priority:
Major - P3
-
None
-
Affects Version/s: 4.4.0, 4.2.10
-
Component/s: None
-
None
-
Storage Execution
-
ALL
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.