No suitable servers found (`serverSelectionTryOnce` set) when rs.initiate with localhost

Question

No suitable servers found (`serverSelectionTryOnce` set) when rs.initiate with localhost

Fallsleep opened this issue a year ago · 5 comments

Bug Report

I initiate a replica set of mongodb 6.0 server in Homestead for a Laravel project with follow shell:
mongosh --eval 'rs.initiate({"_id":"rs0","members":[{"_id":0,"host":"localhost:27017"},{"_id":1,"host":"localhost:27018"},{"_id":2,"host":"localhost:27019"}]})'
and install the mongodb extension for php with pecl:

pecl install mongodb-1.15.3

it work well when I start a session for transaction to mongodb://homestead:secret@192.168.10.10:27017,192.168.10.10:27018,192.168.10.10:27019/quanxueke_homestead?authSource=admin&replicaSet=rs0 just on Homestead(ip is 192.168.10.10) locally.

But when I run the code in the docker container of php:8.0.13-fpm-alpine3.15, it go in error with:
No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling hello on 'localhost:27017'] [connection refused calling hello on 'localhost:27018'] [connection refused calling hello on 'localhost:27019'].

I consider there's something wrong in my dockerfile for pecl install mongodb-1.15.3 at first.

But the code run ok when change 127.0.0.1 localhost to 192.168.10.10 localhost(Homestead's ip) in the hosts file.

And start a session in Navicat on the some uri with db.getMongo().startSession({retryWrites: true, causalConsistency: true}).getDatabase(db.getName()); is ok. So I think there's some bug with conncetion to the replica set init by localhost.

Environment

docker image
php:8.0.13-fpm-alpine3.15

MongoDB :
version: 6.0
replica set init:

rs.initiate({
    "_id":"rs0",
    "members":
    [
        {"_id":0,"host":"localhost:27017"},
        {"_id":1,"host":"localhost:27018"},
        {"_id":2,"host":"localhost:27019"}
    ]
})

driver info

libbson bundled version => 1.23.4
libmongoc bundled version => 1.23.4
libmongoc SSL => enabled
libmongoc SSL library => OpenSSL
libmongoc crypto => enabled
libmongoc crypto library => libcrypto
libmongoc crypto system profile => disabled
libmongoc SASL => disabled
libmongoc ICU => disabled
libmongoc compression => enabled
libmongoc compression snappy => disabled
libmongoc compression zlib => enabled
libmongoc compression zstd => disabled
libmongocrypt bundled version => 1.5.2
libmongocrypt crypto => enabled
libmongocrypt crypto library => libcrypto
mongodb.debug => no value => no value

php library :

name     : mongodb/mongodb
descrip. : MongoDB driver library
keywords : database, driver, mongodb, persistence
versions : * 1.15.0
type     : library
license  : Apache License 2.0 (Apache-2.0) (OSI approved) https://spdx.org/licenses/Apache-2.0.html#licenseText
homepage : https://jira.mongodb.org/browse/PHPLIB
source   : [git] https://github.com/mongodb/mongo-php-library.git 3a681a3b2f2c0ebac227a3b86bb9057d0e6eb8f8
dist     : [zip] https://api.github.com/repos/mongodb/mongo-php-library/zipball/3a681a3b2f2c0ebac227a3b86bb9057d0e6eb8f8 3a681a3b2f2c0ebac227a3b86bb9057d0e6eb8f8
path     : /home/vagrant/code/laravel/vendor/mongodb/mongodb
names    : mongodb/mongodb

support
issues : https://github.com/mongodb/mongo-php-library/issues
source : https://github.com/mongodb/mongo-php-library/tree/1.15.0

autoload
files
psr-4
MongoDB\ => src/

requires
ext-hash *
ext-json *
ext-mongodb ^1.15.0
jean85/pretty-package-versions ^1.2 || ^2.0.1
php ^7.2 || ^8.0
symfony/polyfill-php80 ^1.19

requires (dev)
doctrine/coding-standard ^9.0
squizlabs/php_codesniffer ^3.6
symfony/phpunit-bridge ^5.2
vimeo/psalm ^4.28

Test Script

$client = new \MongoDB\Client('mongodb://homestead:secret@192.168.10.10:27017,192.168.10.10:27018,192.168.10.10:27019/quanxueke_homestead?authSource=admin&replicaSet=rs0');
$client->startSession();

Expected and Actual Behavior

Expected :
session start well even if connection to unlocally replica set init with localhost.

Answer 1 · 2023-08-07T17:24:29.000Z

Please confirm whether I understand your issue correctly:

In the initial test, you are running a MongoDB replica set and PHP within the same Vagrant VM (using the Homestead package). The replica set is configured to identify hosts via localhost, but you use the VM's IP of 192.168.10.10 in the PHP connection string. Everything works as expected.
When running PHP within a php:8.0.13-fpm-alpine3.15 Docker container, PHP cannot connect using localhost in the connection string. You resolved that by mapping localhost to 192.168.10.10 in the container's /etc/hosts file.

I'm assuming that the replica set is always running within the VM as you didn't explicitly say you deployed it in the php:8.0.13-fpm-alpine3.15 container. In that case, I would not expect localhost to resolve properly from within the VM by default.

If you'd like to investigate this further, I'll need to see some diagnostic information from the Server Discovery and Monitoring (SDAM) component of the driver. The mongodb extension provides an SDAMSubscriber interface for this purpose, which applications and implement and register to receive events for internal state changes within the driver.

I just created mongodb/mongo-php-library#1142 to add an SDAM logger to the set of example scripts in the PHP library. You should be able to view the new sdam_logger.php file in that PR and adapt the code for this purpose. Alternatively, you can try running the sdam_logger.php script directly -- you'll just need to supply a connection string via the MONGODB_URI environment variable.

Answer 2 · 2023-08-08T06:59:39.000Z

yes
the php:8.0.13-fpm-alpine3.15 Docker container is running in the same Vagrant VM, and also use 192.168.10.10 in the PHP connection string. But throw connection refused calling hello on 'localhost:27017, I think the driver change 192.168.10.10 to localhost for sending hello message to the replica set, so I try to map localhost to 192.168.10.10 in the container's /etc/hosts file, then I can connect the replica set.

I'll try to get the log.

Answer 3 · 2023-08-08T07:32:16.000Z

Test code:

$client = new \MongoDB\Client('mongodb://homestead:secret@192.168.10.10:27017,192.168.10.10:27018,192.168.10.10:27019/quanxueke_homestead?authSource=admin&replicaSet=rs0');

$client->getManager()->addSubscriber(new SDAMLogger());
$client->startSession();

When map localhost to 127.0.0.1:

topologyOpening: 64d1ede91037cd635806a750 was opened

topologyChanged: 64d1ede91037cd635806a750 changed from Unknown to ReplicaSetNoPrimary

serverOpening: 192.168.10.10:27017 was added to topology 64d1ede91037cd635806a750

serverOpening: 192.168.10.10:27018 was added to topology 64d1ede91037cd635806a750

serverOpening: 192.168.10.10:27019 was added to topology 64d1ede91037cd635806a750

serverHeartbeatStarted: 192.168.10.10:27017 heartbeat started

serverHeartbeatStarted: 192.168.10.10:27018 heartbeat started

serverHeartbeatStarted: 192.168.10.10:27019 heartbeat started

serverHeartbeatSucceeded: 192.168.10.10:27017 heartbeat succeeded after 887µs
reply: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77a4955aa784dc52c" }, "counter" : 6 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : true, "secondary" : false, "primary" : "localhost:27017", "me" : "localhost:27017", "electionId" : { "$oid" : "7fffffff0000000000000007" }, "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:25:26Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:25:26Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:25:29.228Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 28, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "speculativeAuthenticate" : { "conversationId" : 1, "done" : false, "payload" : { "$binary" : { "base64" : "cj0zWldDQ2ExOW8wUjI1bG5PczVzYlB4R1BwVHM3bE5LdithSWx4b1hxMjc5SmtVblNEbysxQmFCMXQ0aWdzMlNNLHM9ajQxNEJ1bzVmcUE4NmtBbE5kRzhBZjA4RW1KQUxENUZqa29iVVE9PSxpPTE1MDAw", "subType" : "00" } } }, "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } } }

serverChanged: 192.168.10.10:27017 changed from Unknown to RSPrimary
previous hello response: { }
new hello response: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77a4955aa784dc52c" }, "counter" : 6 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : true, "secondary" : false, "primary" : "localhost:27017", "me" : "localhost:27017", "electionId" : { "$oid" : "7fffffff0000000000000007" }, "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:25:26Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:25:26Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:25:29.228Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 28, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479526, "i" : 1 } } }

serverOpening: localhost:27017 was added to topology 64d1ede91037cd635806a750

serverOpening: localhost:27018 was added to topology 64d1ede91037cd635806a750

serverOpening: localhost:27019 was added to topology 64d1ede91037cd635806a750

serverClosed: 192.168.10.10:27017 was removed from topology 64d1ede91037cd635806a750

serverClosed: 192.168.10.10:27018 was removed from topology 64d1ede91037cd635806a750

serverClosed: 192.168.10.10:27019 was removed from topology 64d1ede91037cd635806a750

topologyChanged: 64d1ede91037cd635806a750 changed from ReplicaSetNoPrimary to ReplicaSetNoPrimary

serverHeartbeatStarted: localhost:27017 heartbeat started

serverHeartbeatStarted: localhost:27018 heartbeat started

serverHeartbeatStarted: localhost:27019 heartbeat started

serverHeartbeatFailed: localhost:27017 heartbeat failed after 2845376756µs
error: MongoDB\Driver\Exception\RuntimeException(5): connection refused calling hello on 'localhost:27017'

serverChanged: localhost:27017 changed from Unknown to Unknown
previous hello response: { }
new hello response: { }

topologyChanged: 64d1ede91037cd635806a750 changed from ReplicaSetNoPrimary to ReplicaSetNoPrimary

serverHeartbeatFailed: localhost:27018 heartbeat failed after 2845377077µs
error: MongoDB\Driver\Exception\RuntimeException(5): connection refused calling hello on 'localhost:27018'

serverChanged: localhost:27018 changed from Unknown to Unknown
previous hello response: { }
new hello response: { }

topologyChanged: 64d1ede91037cd635806a750 changed from ReplicaSetNoPrimary to ReplicaSetNoPrimary

serverHeartbeatFailed: localhost:27019 heartbeat failed after 2845377357µs
error: MongoDB\Driver\Exception\RuntimeException(5): connection refused calling hello on 'localhost:27019'

serverChanged: localhost:27019 changed from Unknown to Unknown
previous hello response: { }
new hello response: { }

topologyChanged: 64d1ede91037cd635806a750 changed from ReplicaSetNoPrimary to ReplicaSetNoPrimary


   MongoDB\Driver\Exception\ConnectionTimeoutException

  No suitable servers found (`serverSelectionTryOnce` set): [connection refused calling hello on 'localhost:27017'] [connection refused calling hello on 'localhost:27018'] [connection refused calling hello on 'localhost:27019']

  at vendor/mongodb/mongodb/src/Client.php:366
    362▕      * @return Session
    363▕      */
    364▕     public function startSession(array $options = [])
    365▕     {
  ➜ 366▕         return $this->manager->startSession($options);
    367▕     }
    368▕
    369▕     /**
    370▕      * Create a change stream for watching changes to the cluster.

      +1 vendor frames
  2   app/Console/DevCommands/TestRunCommand.php:45
      MongoDB\Client::startSession()

      +13 vendor frames
  16  artisan:37
      Illuminate\Foundation\Console\Kernel::handle()

After mapping localhost to 192.168.10.10:

topologyOpening: 64d1ed6dcfc98637c20b9820 was opened

topologyChanged: 64d1ed6dcfc98637c20b9820 changed from Unknown to ReplicaSetNoPrimary

serverOpening: 192.168.10.10:27017 was added to topology 64d1ed6dcfc98637c20b9820

serverOpening: 192.168.10.10:27018 was added to topology 64d1ed6dcfc98637c20b9820

serverOpening: 192.168.10.10:27019 was added to topology 64d1ed6dcfc98637c20b9820

serverHeartbeatStarted: 192.168.10.10:27017 heartbeat started

serverHeartbeatStarted: 192.168.10.10:27018 heartbeat started

serverHeartbeatStarted: 192.168.10.10:27019 heartbeat started

serverHeartbeatSucceeded: 192.168.10.10:27017 heartbeat succeeded after 1084µs
reply: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77a4955aa784dc52c" }, "counter" : 6 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : true, "secondary" : false, "primary" : "localhost:27017", "me" : "localhost:27017", "electionId" : { "$oid" : "7fffffff0000000000000007" }, "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.020Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 26, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "speculativeAuthenticate" : { "conversationId" : 1, "done" : false, "payload" : { "$binary" : { "base64" : "cj1mb0JHakc2M0h4YlVpcFdUMTQyalMrY2hXdmhvNzBwZ21rUmJXbml6dlgwYmJMQkJtV211MXk0VGNsRytMcHIrLHM9ajQxNEJ1bzVmcUE4NmtBbE5kRzhBZjA4RW1KQUxENUZqa29iVVE9PSxpPTE1MDAw", "subType" : "00" } } }, "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

serverChanged: 192.168.10.10:27017 changed from Unknown to RSPrimary
previous hello response: { }
new hello response: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77a4955aa784dc52c" }, "counter" : 6 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : true, "secondary" : false, "primary" : "localhost:27017", "me" : "localhost:27017", "electionId" : { "$oid" : "7fffffff0000000000000007" }, "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.020Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 26, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

serverOpening: localhost:27017 was added to topology 64d1ed6dcfc98637c20b9820

serverOpening: localhost:27018 was added to topology 64d1ed6dcfc98637c20b9820

serverOpening: localhost:27019 was added to topology 64d1ed6dcfc98637c20b9820

serverClosed: 192.168.10.10:27017 was removed from topology 64d1ed6dcfc98637c20b9820

serverClosed: 192.168.10.10:27018 was removed from topology 64d1ed6dcfc98637c20b9820

serverClosed: 192.168.10.10:27019 was removed from topology 64d1ed6dcfc98637c20b9820

topologyChanged: 64d1ed6dcfc98637c20b9820 changed from ReplicaSetNoPrimary to ReplicaSetNoPrimary

serverHeartbeatStarted: localhost:27017 heartbeat started

serverHeartbeatStarted: localhost:27018 heartbeat started

serverHeartbeatStarted: localhost:27019 heartbeat started

serverHeartbeatSucceeded: localhost:27017 heartbeat succeeded after 873µs
reply: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77a4955aa784dc52c" }, "counter" : 6 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : true, "secondary" : false, "primary" : "localhost:27017", "me" : "localhost:27017", "electionId" : { "$oid" : "7fffffff0000000000000007" }, "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.023Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 27, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "speculativeAuthenticate" : { "conversationId" : 1, "done" : false, "payload" : { "$binary" : { "base64" : "cj0yRU0zeTlGUXh2Uzk1T3hDS2pZVjlrelRZdkdwbzl6Z0FPSXRidlpuSkd2TjZaelJCSnVIY2k2aEFRMGQyN3NsLHM9ajQxNEJ1bzVmcUE4NmtBbE5kRzhBZjA4RW1KQUxENUZqa29iVVE9PSxpPTE1MDAw", "subType" : "00" } } }, "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

serverChanged: localhost:27017 changed from Unknown to RSPrimary
previous hello response: { }
new hello response: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77a4955aa784dc52c" }, "counter" : 6 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : true, "secondary" : false, "primary" : "localhost:27017", "me" : "localhost:27017", "electionId" : { "$oid" : "7fffffff0000000000000007" }, "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.023Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 27, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

topologyChanged: 64d1ed6dcfc98637c20b9820 changed from ReplicaSetNoPrimary to ReplicaSetWithPrimary

serverHeartbeatSucceeded: localhost:27018 heartbeat succeeded after 2341µs
reply: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77f50b07859ee8841" }, "counter" : 4 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : false, "secondary" : true, "primary" : "localhost:27017", "me" : "localhost:27018", "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.023Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 28, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "speculativeAuthenticate" : { "conversationId" : 1, "done" : false, "payload" : { "$binary" : { "base64" : "cj1lTS9INU5nSXZ1dVhWZFdoa3FwQmtocW5KNjAwb1pOcWpaZ2p6b1dQR1NsNGdCM0NOUmJEOG1Tb1ZSekxpbXVULHM9ajQxNEJ1bzVmcUE4NmtBbE5kRzhBZjA4RW1KQUxENUZqa29iVVE9PSxpPTE1MDAw", "subType" : "00" } } }, "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

serverChanged: localhost:27018 changed from Unknown to RSSecondary
previous hello response: { }
new hello response: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d77f50b07859ee8841" }, "counter" : 4 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : false, "secondary" : true, "primary" : "localhost:27017", "me" : "localhost:27018", "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.023Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 28, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-256", "SCRAM-SHA-1" ], "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

topologyChanged: 64d1ed6dcfc98637c20b9820 changed from ReplicaSetWithPrimary to ReplicaSetWithPrimary

serverHeartbeatSucceeded: localhost:27019 heartbeat succeeded after 3816µs
reply: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d7481ab889b380bb4a" }, "counter" : 4 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : false, "secondary" : true, "primary" : "localhost:27017", "me" : "localhost:27019", "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.024Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 28, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-1", "SCRAM-SHA-256" ], "speculativeAuthenticate" : { "conversationId" : 1, "done" : false, "payload" : { "$binary" : { "base64" : "cj0rZktvYUJFK0s3MFhRRFZYY0Q4eDFTbk9lWkdwSmxiUUlqdlJpQ3RmamJhN3VTZ0paSVFkVE1KQi9YU0IwWDF5LHM9ajQxNEJ1bzVmcUE4NmtBbE5kRzhBZjA4RW1KQUxENUZqa29iVVE9PSxpPTE1MDAw", "subType" : "00" } } }, "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

serverChanged: localhost:27019 changed from Unknown to RSSecondary
previous hello response: { }
new hello response: { "helloOk" : true, "topologyVersion" : { "processId" : { "$oid" : "64d1e2d7481ab889b380bb4a" }, "counter" : 4 }, "hosts" : [ "localhost:27017", "localhost:27018", "localhost:27019" ], "setName" : "rs0", "setVersion" : 1, "ismaster" : false, "secondary" : true, "primary" : "localhost:27017", "me" : "localhost:27019", "lastWrite" : { "opTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "lastWriteDate" : { "$date" : "2023-08-08T07:23:16Z" }, "majorityOpTime" : { "ts" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "t" : 7 }, "majorityWriteDate" : { "$date" : "2023-08-08T07:23:16Z" } }, "maxBsonObjectSize" : 16777216, "maxMessageSizeBytes" : 48000000, "maxWriteBatchSize" : 100000, "localTime" : { "$date" : "2023-08-08T07:23:25.024Z" }, "logicalSessionTimeoutMinutes" : 30, "connectionId" : 28, "minWireVersion" : 0, "maxWireVersion" : 17, "readOnly" : false, "saslSupportedMechs" : [ "SCRAM-SHA-1", "SCRAM-SHA-256" ], "ok" : 1.0, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : 0 } }, "operationTime" : { "$timestamp" : { "t" : 1691479396, "i" : 1 } } }

topologyChanged: 64d1ed6dcfc98637c20b9820 changed from ReplicaSetWithPrimary to ReplicaSetWithPrimary

@jmikola

Answer 4 · 2023-08-08T17:23:59.000Z

@Fallsleep: thanks for following up. Based on the above logs, it looks like the PHP driver is behaving as expected. The hosts in the connection string serve as a seed list, which the driver uses to discover replica set members. Once the driver receives a hello response from the replica set primary, it will use the reported list of replica set hosts (from the RS configuration) to establish the permanent connections to use for subsequent monitoring and application usage.

Since the replica set configuration uses localhost, we see the driver initially connect to each IP address in the connection string and then remove those connections once an authoritative response from the primary is received. This is demonstrated in the following log output:

serverOpening: 192.168.10.10:27017 was added to topology
serverOpening: 192.168.10.10:27018 was added to topology
serverOpening: 192.168.10.10:27019 was added to topology

<hello response from primary is processed>

serverOpening: localhost:27017 was added to topology
serverOpening: localhost:27018 was added to topology
serverOpening: localhost:27019 was added to topology
serverClosed: 192.168.10.10:27017 was removed from topology
serverClosed: 192.168.10.10:27018 was removed from topology
serverClosed: 192.168.10.10:27019 was removed from topology

Note that even the primary itself is removed. Even when localhost is mapped to 192.168.10.10 and the application successfully connections, you're incurring the overhead of additional connection churn here.

Best practice dictates that your connection string and replica set configuration should use the same host names (or IP addresses). This is mentioned in the "Replica Set" tab in Connection String: Examples within the MongoDB manual:

For a replica set, specify the hostname(s) of the mongod instance(s) as listed in the replica set configuration.

In your case, I would suggest one of several options:

Reconfigure the replica set configuration to use IP addresses, and continue to use IP addresses in your connection string.
Create a new host name to use for both the replica set configuration and connection string (e.g. mongod.dev), and use that host name in both the configuration and connection string.

Mapping localhost in the Docker container to the IP address of the Vagrant VM seems like it could be problematic if anything beyond the PHP driver were to rely on that host name.

Note: If your cluster is using split horizon DNS, you must use host names instead of IP addresses unless disableSplitHorizonIPCheck is enabled. I don't think that applies in your situation, but I wanted to mention it for the benefit of other readers that might come across this issue down the line.

Answer 5 · 2023-08-09T07:13:15.000Z

@jmikola thanks.

I got the question when testing whether the driver is compiled correctlly in the docker image. In production environment, I'll use hostname for connection string.

I'll modify the replica set configure script for the develop and local testing environment