Re: PHP Connection over SSL

From: Jeremy Mikola <jmikola@xxxxxxxxxxx>
To: mongodb-user@xxxxxxxxxxxxxxxx
Date: Tue, 10 May 2016 16:06:16 -0400
Why ads?
On Tue, May 10, 2016 at 11:44 AM, <joe@xxxxxxxxxxxx> wrote:



On Tuesday, May 10, 2016 at 10:09:43 AM UTC-5, Jeremy Mikola wrote:



On Mon, May 9, 2016 at 5:40 PM, <j...@xxxxxxxxxxxx> wrote:



On Monday, May 9, 2016 at 4:14:44 PM UTC-5, Jeremy Mikola wrote:



On Mon, May 9, 2016 at 2:32 PM, <j...@xxxxxxxxxxxx> wrote:


That's great, thank you for your help. I'm running into this now:

'No suitable servers found (`serverselectiontryonce` set): [connection
timeout calling ismaster on '192.168.10.251:27017']'

I can only seem to find issues relating to ipv6 and localhost with
this issue, but those look like they've been fixed (My PECL MongoDB
extension is 1.1.6). This is with the mongod.conf file set to 'requireSSL'.
With 'preferSSL', everything connects fine, though I am assuming without
SSL encryption.

Is there something else I should be looking at, or does this just seem
to indicate SSL issues?


That likely points to an SSL issue. Unfortunately, we don't yet have
visibility into the exact error on the client (this is pending
CDRIVER-841 <https://jira.mongodb.org/browse/CDRIVER-841>); however,
you may be able to correlate this with an error in the server logs, as was
done in that ticket.

Also, I just want to clarify that "sslAllowInvalidCertificates" (from
your original post) is not a supported URI option in our drivers. I assume
that was adapted from a command line option on various console clients that
ship with MongoDB (e.g. mongo, mongotop).

Sure, that makes sense. And the 'sslAllowInvalidCertificates' was just
stabbing in the dark...

So, server shows:

2016-05-09T16:37:50.562-0500 I NETWORK  [initandlisten] connection
accepted from 192.168.10.100:62899 #1 (1 connection now open)

2016-05-09T16:37:50.563-0500 D -        [conn1] User Assertion:
17189:The server is configured to only allow SSL connections

2016-05-09T16:37:50.563-0500 I NETWORK  [conn1] AssertionException
handling request, closing client connection: 17189 The server is configured
to only allow SSL connections

Which, I take to mean that the connection coming from PHP is not coming
over SSL. Would you all agree with that? I turned verbosity of system log
up to 3 and that's all I'm really seeing.


One more suggestion would be capturing the driver's internal activity via
the mongodb.debug <http://php.net/manual/en/mongodb.configuration.php>
INI option. You can either specify a directory, which the driver will use
to generate traces named by the process ID (useful for web SAPIs), or
"stderr", which may be more convenient for a PHP CLI script.

This should at least show us that the driver is attempting to setup SSL
and may hopefully capture some additional errors/warnings from libmongoc
that occur before the generic "No suitable servers found" exception is
thrown.


I set up the INI option as mentioned. Here's what I'm getting:

[2016-05-10T15:36:23+00:00]     PHONGO: DEBUG   > Connection string:
'mongodb://username:password@xxxxxxxxxxxxxxxxxxxx/request_log'
[2016-05-10T15:36:23+00:00]     PHONGO: TRACE   > ENTRY:
php_phongo_make_mongo_client():1878
[2016-05-10T15:36:23+00:00]     PHONGO: DEBUG   > Creating Manager,
phongo-1.1.6[stable] - mongoc-1.3.5(bundled), libbson-1.3.5(bundled),
php-5.6.10
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_topology_description_init():51
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_topology_description_init():68
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_server_description_init():87
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_server_description_init():123
[2016-05-10T15:36:23+00:00]    cluster: TRACE   > ENTRY:
mongoc_cluster_init():1597
[2016-05-10T15:36:23+00:00]    cluster: TRACE   >  EXIT:
mongoc_cluster_init():1620
[2016-05-10T15:36:23+00:00]     client: DEBUG   > Using custom stream
initiator.
[2016-05-10T15:36:23+00:00]     PHONGO: TRACE   >  EXIT:
php_phongo_make_mongo_client():1976
[2016-05-10T15:36:23+00:00] PHONGO-BSON: TRACE   > encoding document
[2016-05-10T15:36:23+00:00] PHONGO-BSON: TRACE   > Added new _id
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_bulk_operation_insert():205
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
_mongoc_write_command_init_insert():176
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
_mongoc_write_command_insert_append():72
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
_mongoc_write_command_insert_append():102
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
_mongoc_write_command_init_insert():192
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_bulk_operation_insert():227
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_bulk_operation_execute():372
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
_mongoc_write_result_init():1007
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
_mongoc_write_result_init():1017
[2016-05-10T15:36:23+00:00]    cluster: TRACE   > ENTRY:
_mongoc_cluster_stream_for_optype():1685
[2016-05-10T15:36:23+00:00]     PHONGO: TRACE   > ENTRY:
phongo_stream_initiator():1103
[2016-05-10T15:36:23+00:00]     PHONGO: DEBUG   > Connecting to
'db.internal-host.com:27017[mongodb://
username:password@xxxxxxxxxxxxxxxxxxxx/request_log]'
[2016-05-10T15:36:23+00:00]     PHONGO: DEBUG   > Created: RSRC#39 as
'db.internal-host.com:27017[mongodb://
username:password@xxxxxxxxxxxxxxxxxxxx/request_log]'
[2016-05-10T15:36:23+00:00]     PHONGO: TRACE   >  EXIT:
phongo_stream_initiator():1229
[2016-05-10T15:36:23+00:00]     stream: TRACE   > ENTRY:
mongoc_stream_writev():149
[2016-05-10T15:36:23+00:00]     stream: TRACE   > TRACE:
mongoc_stream_writev():161 writev = 0x104e41b00 [9]
[2016-05-10T15:36:23+00:00]     stream: TRACE   > 00000:  3a 00 00 00 01
00 00 00  00 00 00 00 d4 07 00 00  : . . . . . . .  . . . . ‘ . . .
[2016-05-10T15:36:23+00:00]     stream: TRACE   > 00010:  04 00 00 00 61
64 6d 69  6e 2e 24 63 6d 64 00 00  . . . . a d m i  n . $ c m d . .
[2016-05-10T15:36:23+00:00]     stream: TRACE   > 00020:  00 00 00 ff ff
ff ff 13  00 00 00 10 69 73 4d 61  . . . ˇ ˇ ˇ ˇ .  . . . . i s M a
[2016-05-10T15:36:23+00:00]     stream: TRACE   > 00030:  73 74 65 72 00
01 00 00  00 00                    s t e r . . . .  . .
[2016-05-10T15:36:23+00:00]     PHONGO: DEBUG   > Setting timeout to: 0
[2016-05-10T15:36:23+00:00]     stream: TRACE   >  EXIT:
mongoc_stream_writev():164
[2016-05-10T15:36:23+00:00]     stream: TRACE   > ENTRY:
mongoc_stream_failed():79
[2016-05-10T15:36:23+00:00]     PHONGO: DEBUG   > Destroying RSRC#39
[2016-05-10T15:36:23+00:00]     stream: TRACE   >  EXIT:
mongoc_stream_failed():89
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_server_description_handle_ismaster():383
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_server_description_handle_ismaster():389
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > TRACE:
mongoc_topology_description_handle_ismaster():1400 No transition entry to 4
for 0
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_topology_description_select():493
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_topology_description_select():507
[2016-05-10T15:36:23+00:00]    cluster: TRACE   >  EXIT:
_mongoc_cluster_stream_for_optype():1697
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_bulk_operation_execute():431
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_topology_description_destroy():89
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
mongoc_server_description_destroy():145
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_server_description_destroy():151
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
mongoc_topology_description_destroy():103
[2016-05-10T15:36:23+00:00]    cluster: TRACE   > ENTRY:
mongoc_cluster_destroy():1643
[2016-05-10T15:36:23+00:00]    cluster: TRACE   >  EXIT:
mongoc_cluster_destroy():1653
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
_mongoc_write_command_destroy():994
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
_mongoc_write_command_destroy():1000
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   > ENTRY:
_mongoc_write_result_destroy():1024
[2016-05-10T15:36:23+00:00]     mongoc: TRACE   >  EXIT:
_mongoc_write_result_destroy():1032

Nothing jumping out at me? I don't see any mention of SSL, but I do see
where it notes it's using a custom stream.

The interesting thing is that if I specify 'ssl' => true in the driver
options (which is currently just an empty array), or add '?ssl=true', I do
get a log line that specifically states 'Enabling SSL'. However, when I do
that, I also get errors to the console of:

dyld: lazy symbol binding failed: Symbol not found:
_php_mongo_asn1_time_to_time_t

  Referenced from:
/Applications/MAMP/bin/php/php5.6.10/lib/php/extensions/no-debug-non-zts-20131226/mongodb.so

  Expected in: flat namespace


dyld: Symbol not found: _php_mongo_asn1_time_to_time_t

  Referenced from:
/Applications/MAMP/bin/php/php5.6.10/lib/php/extensions/no-debug-non-zts-20131226/mongodb.so
  Expected in: flat namespace


It appears that the mongodb.so extension you're using was compiled against
a version of PHP without OpenSSL (i.e. the PHP environment whose phpize
binary was used when building). That resulted in those functions not being
defined during the build. At runtime, the extension is running with a
version of PHP that does have OpenSSL and we were blindly expecting those
functions to exist. I've opened PHPC-698
<https://jira.mongodb.org/browse/PHPC-698> to track the bug and implemented
a fix in PR #324 <https://github.com/mongodb/mongo-php-driver/pull/324>.

That said, the fix above is simply going to raise a meaningful exception in
your current scenario (in lieu of the undefined symbol error). You'll still
want to take some action to properly correct this on your end by doing one
of the following:

   - Disabling "verify_expiry" option in the SSL context options passed to
   MongoDB\Manager\Client. The default stream context (which we use if none is
   provided) enables this.
   - Rebuilding the extension with the "pecl" and/or "phpize" command that
   ships with MAMP.

Specifying SSL context options can be done like so:

$context = stream_context_create(['ssl' => ['verify_expiry' => false]]);
$manager = new MongoDB\Driver\Manager($uri, [], ['context' => $context]);

This uses the third $driverOptions argument to the Manager constructor (or
MongoDB\Client in the userland library). At present, the "mongodb"
extension does not have documentation for the SSL context options. I've
opened PHPC-700 <https://jira.mongodb.org/browse/PHPC-700> to track that.
The legacy driver documentation <http://php.net/manual/en/mongo.context.php>
does cover this and links to the relevant SSL context options (which is a
general PHP topic not specific to our driver) and can be referenced in a
pinch. Note that the custom "mongodb" context is not supported at all in
the new driver (that's specific to some stream logging features that only
exist in the legacy driver).

Let me know if you'd like me to clarify any of this further, and thanks for
your patience in the diagnosis.

-- 
You received this message because you are subscribed to the Google Groups "mongodb-user"
group.

For other MongoDB technical support options, see: https://docs.mongodb.org/manual/support/
--- 
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user+unsubscribe@xxxxxxxxxxxxxxxx.
To post to this group, send email to mongodb-user@xxxxxxxxxxxxxxxx.
Visit this group at https://groups.google.com/group/mongodb-user.
To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/CACypnJUFFQd%2B0J%3DQ4VbSz_4ZRNwhPeU8jev%3DEwYwXE6-Eh2QcQ%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.
Why ads?