Re: PHP Connection over SSL

From: joe@xxxxxxxxxxxx
To: mongodb-user <mongodb-user@xxxxxxxxxxxxxxxx>
Date: Tue, 10 May 2016 08:44:23 -0700 (PDT)
Why ads?


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 <javascript:>> 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 

Thanks for the continued help on this, I really do appreciate it!

-- 
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/66674c07-a8fb-40bd-9f91-250d24419367%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
Why ads?