Deprecated driver option throws misleading error

[timwhitlock]

Hi, just a comment really...

After upgrading an existing installation from 1.5.5. to 1.6.0 I started getting ConnectionTimeoutException immediately when selecting a server.

I eventually discovered it was due to specifying the deprecated allow_invalid_hostname driver option (when tlsAllowInvalidHostnames is absent). My own fault for not reading the release notes, but it seems like the error thrown could be less misleading.

Thanks.

[jmikola]

@timwhitlock Can you share the full exception message? ConnectionTimeoutException is thrown for both socket timeout and server selection failures, but a message related to failed server selection might specify a more specific reason. If not, enabling mongodb.debug to capture libmongoc trace logs might also reveal whether servers are being disregarded due to failed certificate validation. If so, those servers are removed from consideration which could leave none available for selection. FWIW, I realize that's not intuitive but we presently don't have a better way to provide insight into that apart from debug logs until we implement SDAM monitoring in PHPC-1150.

Assuming this is a certificate failure, I would be concerned if specifying allow_invalid_hostname suddenly stopped working for you after upgrading to 1.6.0. allow_invalid_hostname was deprecated in documentation only, so its value should still be respected if you're not using the new tlsAllowInvalidHostnames option. In fact, we have some tests that still make use of it (e.g. standalone-ssl-verify_cert-001.phpt).

[timwhitlock]

The exception message is as follows:

No suitable servers found (`serverSelectionTryOnce` set): 
[connection closed calling ismaster on 'localhost:27017']

In a replica set, the [connection closed ... ] part in square brackets repeats for all members.

mongo.debug trace here: https://pastebin.com/raw/05r3YU9a

[jmikola]

@timwhitlock I'm having trouble making sense of the trace logs. It looks as if the driver attempts to connect three times, and the second attempt successfully writes to the socket but fails to read anything (while also not ultimately failing due to the zero errno value). After the third attempt, it looks like the driver ends up in mongoc_topology_description_handle_ismaster.

At that point, there is no isMaster reply so I assume the handle function was invoked from either mongoc_topology_description_invalidate_server or _mongoc_topology_scanner_setup_err_cb. The latter method is more likely as that's a callback for TLS or DNS errors, and I also believe invalidation (the former method) would only apply if we previously connected to the node.

Could you provide a few things for us?

• Most basic script that can reproduce the error you're seeing. This might be as simple as constructing a Manager and executing a ping command. In this case, I'd also want to see all of the constructor arguments.
• Details on how you've configured the local server. Feel free to omit actual certificate files if needed, but it'd be good to share the mongod configuration file and/or command-line arguments. Since you're experiencing the same problem with both a standalone and replica set, I'd propose we stick with a standalone to keep things simple.
• Assuming the same script and server runs without error on a previous version of the driver (e.g. 1.5.5), please share that driver version and a corresponding mongo.debug trace from running with that version so we can compare.

[timwhitlock]

Most basic script that can reproduce the error you're seeing. This might be as simple as constructing a Manager and executing a ping command

    $uri = 'mongodb://localhost:27017';
    $uriOptions = [];
    $driverOptions = [
        'allow_invalid_hostname' => false,
    ];
    $manager = new MongoDB\Driver\Manager( $uri, $uriOptions, $driverOptions );
    $manager->executeReadCommand( 'foo', new MongoDB\Driver\Command(['ping'=>1]), [] );

• Any value for allow_invalid_hostname produces same result.
• Removing $driverOptions['allow_invalid_hostname'] fixes the problem.
• Adding $uriOptions['tlsAllowInvalidHostnames'] also fixes the problem.
• The error occurs regardless of whether the above code includes authentication options.

[timwhitlock]

Details on how you've configured the local server

I get the same error whether there's a server running or not. It seems that the error behaves as if there is no server, or that one cannot be contacted.

All I need to reproduce failure with 1.6.0 (and success with 1.5.5) is a simple command line server as follows: mongod --dbpath /data/mongodb

Same results with Mongo DB 4.0, 4.1 and 4.2.

[timwhitlock]

Assuming the same script and server runs without error on a previous version of the driver (e.g. 1.5.5), please share that driver version

It runs without error on 1.5.5. Trace here: https://pastebin.com/raw/z2sxUcq2

I get the same results with PHP 7.2 and 7.3.

MongoDB extension version => 1.5.5
MongoDB extension stability => stable
libbson bundled version => 1.13.0
libmongoc bundled version => 1.13.0
libmongoc SSL => enabled
libmongoc SSL library => Secure Transport
libmongoc crypto => enabled
libmongoc crypto library => Common Crypto
libmongoc crypto system profile => disabled
libmongoc SASL => enabled
libmongoc ICU => enabled
libmongoc compression => enabled
libmongoc compression snappy => disabled
libmongoc compression zlib => enable

Worth noting that all my tests are either directly on my dev host (Mac OS X) or in a virtual Linux machine on the same host. I've not tried to reproduce this on any other hardware, although as soon as my live servers are running 1.6.0 I will do so.

[jmikola]

@timwhitlock Thanks for the report. It wasn't immediately clear to me that your MongoDB deployment was not running with TLS. I'm confident at this point that the issue has nothing to do with certificate validation (as I originally suspected) but appears to be just a URI parsing issue.

Historically, libmongoc has had logic to enable TLS connections if any related URI option was specified (see: CDRIVER-2130). The PHP driver never documented those "ssl"-prefixed URI options (although they technically could always have been used), since we already provided the same options (and more) in the driver options argument. That said, our driver options never followed the same rules of enabling TLS if one or more TLS-related options were specified. In fact, I didn't even recall libmongoc's behavior before researching this issue.

In any event, some changes we recently made to unify URI options in PHPC-1288 means that our driver options now set the corresponding URI option. We do this before applying URI options to ensure that the driver option is respected as a fallback.

After investigating this further, I diagnosed it as two related, but distinct, issues:

• https://jira.mongodb.org/browse/PHPC-1446
• https://jira.mongodb.org/browse/CDRIVER-3369

The CDRIVER issues explains why a "tlsAllowInvalidHostnames" URI option did not cause the driver to enable a TLS connection (desired behavior in your situation), while "tlsallowinvalidhostnames" would have.

As an immediate work-around, I would suggest either of the following:

• Avoid specifying TLS-related options if you are not connecting to a TLS server
• Explicitly set the tls option to false in either the connection string or URI options

[jmikola]

Closing. Please follow the linked JIRA issues for updates. The PHPC ticket has already been resolved and will be included in the forthcoming 1.7.0 release.