Проблема с использованием расширения PHP MongoDB для подключения по SSL / TLS: ConnectionTimeoutException: не найдено подходящих серверов (установлено `serverSelectionTryOnce`) - PullRequest
0 голосов
/ 07 июля 2019

У меня возникла проблема при попытке подключиться к серверу MongoDB, для которого требуется SSL / TLS, с использованием расширения PHP mongodb:

PHP Fatal error:  Uncaught MongoDB\Driver\Exception\ConnectionTimeoutException: No suitable servers found (`serverSelectionTryOnce` set): [Failed to receive length header from server. calling ismaster on 'mongodb.example.com:27017'] in /tmp/mongodb-test/vendor/mongodb/mongodb/src/Client.php:228

Я рассмотрел десятки подобных проблем в Интернете, и кажется, что это действительно общая ошибка расширения, когда возникают проблемы с соединением. Пока что я попробовал эти общие решения, но ни одно из них не помогло мне:

  1. Используйте IPv4-адрес вместо имени хоста (обычно это происходит, когда MongoDB работает локально, и localhost, что разрешается до ::1, когда IPv6 не включен в конфигурации MongoDB). Я также пытался поместить IPv4-адрес в мой / etc / hosts, тоже не помогло.
  2. setsebool -P httpd_can_network_connect on. Вызывается SELinux, который я не использую.
  3. Установите net.ssl.allowConnectionsWithoutCertificates на false. Похоже, это не актуально, но я все же проверил, но это не помогло.

Я использую строку подключения и просто, чтобы сделать вещи еще более странными, та же самая строка подключения прекрасно работает с mongo Shell, Compass и pymongo на одной машине, а также с PHP 7.3 с mongodb 1.5. 5 под macOS .

Вот некоторые подробности:

Я использую PHP 7.3.7 с mongodb 1.5.5 под Arch Linux (я также тестировал под Ubuntu, тот же симптом).

$ php --version
PHP 7.3.7 (cli) (built: Jul  3 2019 13:55:48) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.3.7, Copyright (c) 1998-2018 Zend Technologies
    with Xdebug v2.7.2, Copyright (c) 2002-2019, by Derick Rethans

$ php -i | grep -i mongo
MongoDB support => enabled
MongoDB extension version => 1.5.5
MongoDB extension stability => stable
libmongoc bundled version => 1.13.0
libmongoc SSL => enabled
libmongoc SSL library => OpenSSL
libmongoc crypto => enabled
libmongoc crypto library => libcrypto
libmongoc crypto system profile => disabled
libmongoc SASL => enabled
libmongoc ICU => enabled
libmongoc compression => enabled
libmongoc compression snappy => enabled
libmongoc compression zlib => enabled
mongodb.debug => stderr => stderr

Сервер MongoDB 4.0.10 и вот его /etc/mongodb.conf:

---
net:
  bindIpAll: true
  ipv6: true
  ssl:
    PEMKeyFile: /etc/ssl/mongodb.pem    # Let's Encrypt certificate
    mode: requireSSL
security:
  authorization: "enabled"
storage:
  dbPath: /var/lib/mongodb
systemLog:
  destination: file
  logAppend: true
  path: /var/log/mongodb/mongod.log
  quiet: false

Когда я запустил следующий скрипт

require 'vendor/autoload.php';

// I've also tried copying the URI parameters to the second argument, didn't work
// allow_invalid_hostname and weak_cert_validation didn't help, either
$client = new MongoDB\Client(
    'mongodb://frederick:password@mongodb.example.com/?ssl=true&authSource=admin'
);
var_dump( $client->listDatabases() );

... с ошибкой (полный журнал здесь , она слишком длинная и приводит к превышению длины этого сообщения)

_mongoc_socket_capture_errno():68 setting errno: 11 Resource temporarily unavailable
[2019-07-07T11:14:36.047790+00:00]     socket: TRACE   > TRACE: _mongoc_socket_errno_is_again():620 errno is: 11
[2019-07-07T11:14:36.047795+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_wait():148
[2019-07-07T11:14:36.047801+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_wait():243
[2019-07-07T11:14:36.047805+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1088
[2019-07-07T11:14:36.047828+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():162
[2019-07-07T11:14:36.047834+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():239 readv = 0x7fff8fef5eb0 [1]
[2019-07-07T11:14:36.047842+00:00]     stream: TRACE   > 00000:  17 03 03 00 fa                                    . . . . .
[2019-07-07T11:14:36.047847+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():242
[2019-07-07T11:14:36.047852+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():283
[2019-07-07T11:14:36.047857+00:00] stream-tls-openssl-bio: TRACE   >  EXIT: mongoc_stream_tls_openssl_bio_read():230
[2019-07-07T11:14:36.047863+00:00] stream-tls-openssl: TRACE   >  EXIT: _mongoc_stream_tls_openssl_readv():463
[2019-07-07T11:14:36.047868+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():242
[2019-07-07T11:14:36.047873+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():283
[2019-07-07T11:14:36.047878+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_try_append_from_stream():357
[2019-07-07T11:14:36.047884+00:00]     stream: TRACE   > ENTRY: mongoc_stream_failed():80
[2019-07-07T11:14:36.047892+00:00] stream-tls-openssl-bio: TRACE   > ENTRY: mongoc_stream_tls_openssl_bio_write():257
[2019-07-07T11:14:36.047899+00:00] stream-tls-openssl-bio: TRACE   > TRACE: mongoc_stream_tls_openssl_bio_write():274 mongoc_stream_writev is expected to write: 24
[2019-07-07T11:14:36.047904+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():152
[2019-07-07T11:14:36.047910+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():164 writev = 0x7fff8fef5030 [1]
[2019-07-07T11:14:36.047920+00:00]     stream: TRACE   > 00000:  17 03 03 00 13 f5 ec f9  74 9e 90 99 01 e7 46 48  . . . . . . . .  t . . . . . F H
[2019-07-07T11:14:36.047929+00:00]     stream: TRACE   > 00010:  ... lots of data ...
[2019-07-07T11:14:36.047934+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_writev():203
[2019-07-07T11:14:36.047938+00:00]     socket: TRACE   > ENTRY: mongoc_socket_sendv():1360
[2019-07-07T11:14:36.047944+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_try_sendv():1265
[2019-07-07T11:14:36.047948+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1271 sendbuf = 0x56300c145e10 [1]
[2019-07-07T11:14:36.047958+00:00]     socket: TRACE   > 00000:  17 03 03 00 13 f5 ec f9  74 9e 90 99 01 e7 46 48  . . . . . . . .  t . . . . . F H
[2019-07-07T11:14:36.047967+00:00]     socket: TRACE   > 00010:  ... lots of data ...
[2019-07-07T11:14:36.047980+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1291 Send 24 out of 24 bytes
[2019-07-07T11:14:36.047985+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_try_sendv():1321
[2019-07-07T11:14:36.047991+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1371 Sent 24 (of 24) out of iovcnt=1
[2019-07-07T11:14:36.047996+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1397 still got bytes left: sent -= iov_len: 24 -= 24
[2019-07-07T11:14:36.048000+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1408 Finished the iovecs
[2019-07-07T11:14:36.048005+00:00]     socket: TRACE   >  EXIT: mongoc_socket_sendv():1443
[2019-07-07T11:14:36.048009+00:00]     socket: TRACE   > TRACE: mongoc_socket_errno():595 Current errno: 11
[2019-07-07T11:14:36.048014+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_writev():209
[2019-07-07T11:14:36.048019+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():167
[2019-07-07T11:14:36.048024+00:00] stream-tls-openssl-bio: TRACE   > TRACE: mongoc_stream_tls_openssl_bio_write():282 Completed the 24
[2019-07-07T11:14:36.048028+00:00] stream-tls-openssl-bio: TRACE   >  EXIT: mongoc_stream_tls_openssl_bio_write():293
[2019-07-07T11:14:36.048066+00:00]     stream: TRACE   > ENTRY: mongoc_stream_destroy():104
[2019-07-07T11:14:36.048070+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_destroy():72
[2019-07-07T11:14:36.048073+00:00]     socket: TRACE   > ENTRY: mongoc_socket_close():779
[2019-07-07T11:14:36.048088+00:00]     socket: TRACE   >  EXIT: mongoc_socket_close():814
[2019-07-07T11:14:36.048092+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_destroy():86
[2019-07-07T11:14:36.048095+00:00]     stream: TRACE   >  EXIT: mongoc_stream_destroy():114
[2019-07-07T11:14:36.048557+00:00]     stream: TRACE   >  EXIT: mongoc_stream_failed():90
[2019-07-07T11:14:36.048563+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():513
[2019-07-07T11:14:36.048586+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():520
[2019-07-07T11:14:36.048592+00:00]     mongoc: TRACE   > TRACE: mongoc_topology_description_handle_ismaster():1953 No transition entry to Single for Unknown
[2019-07-07T11:14:36.048599+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():798
[2019-07-07T11:14:36.048602+00:00]     mongoc: TRACE   > TRACE: mongoc_topology_description_select():807 Topology type single, [mongodb.example.com:27017] is down
[2019-07-07T11:14:36.048605+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():808
PHP Fatal error:  Uncaught MongoDB\Driver\Exception\ConnectionTimeoutException: No suitable servers found (`serverSelectionTryOnce` set): [Failed to receive length header from server. calling ismaster on 'mongodb.example.com:27017'] in /tmp/mongodb-test/vendor/mongodb/mongodb/src/Client.php:228
Stack trace:
#0 /tmp/mongodb-test/vendor/mongodb/mongodb/src/Client.php(228): MongoDB\Driver\Manager->selectServer(Object(MongoDB\Driver\ReadPreference))
#1 /tmp/mongodb-test/test.php(9): MongoDB\Client->listDatabases()
#2 {main}
  thrown in /tmp/mongodb-test/vendor/mongodb/mongodb/src/Client.php on line 228
[2019-07-07T11:14:36.048728+00:00]     mongoc: DEBUG   > Not destroying persistent client for Manager

А журналы со стороны сервера:

2019-07-07T19:58:54.571+1000 D COMMAND  [conn1] run command admin.$cmd { isMaster: 1, client: { driver: { name: "mongoc / ext-mongodb:PHP", version: "1.13.0 / 1.5.5" }, os: { type: "Linux",
name: "Arch Linux", version: "rolling", architecture: "x86_64" }, platform: "cfg=0xd15ea8e9 posix=200809 stdc=201710 CC=GCC 9.1.0 CFLAGS="" LDFLAGS="" / PHP 7.3.7" }, compression: [], saslSu
pportedMechs: "admin.frederick", $readPreference: { mode: "secondaryPreferred" }, $db: "admin" }
2019-07-07T19:58:54.572+1000 I NETWORK  [conn1] received client metadata from x.x.x.x:35394 conn1: { driver: { name: "mongoc / ext-mongodb:PHP", version: "1.13.0 / 1.5.5" }, os: { type:
 "Linux", name: "Arch Linux", version: "rolling", architecture: "x86_64" }, platform: "cfg=0xd15ea8e9 posix=200809 stdc=201710 CC=GCC 9.1.0 CFLAGS="" LDFLAGS="" / PHP 7.3.7" }
2019-07-07T19:58:54.572+1000 D NETWORK  [conn1] Starting server-side compression negotiation
2019-07-07T19:58:54.572+1000 D NETWORK  [conn1] No compressors provided
2019-07-07T19:58:54.572+1000 D STORAGE  [conn1] NamespaceUUIDCache: registered namespace admin.system.users with UUID 4bb34abc-a662-424b-9c52-bf3947bb6006
2019-07-07T19:58:54.573+1000 D QUERY    [conn1] Beginning planning...
=============================
Options = INDEX_INTERSECTION SPLIT_LIMITED_SORT CANNOT_TRIM_IXISECT
Canonical query:
ns=admin.system.usersTree: $and
    db $eq "admin"
    user $eq "frederick"
Sort: {}
Proj: {}
=============================
2019-07-07T19:58:54.573+1000 D QUERY    [conn1] Index 0 is kp: { _id: 1 } unique name: '_id_' io: { v: 2, key: { _id: 1 }, name: "_id_", ns: "admin.system.users" }
2019-07-07T19:58:54.573+1000 D QUERY    [conn1] Index 1 is kp: { user: 1, db: 1 } unique name: 'user_1_db_1' io: { v: 2, unique: true, key: { user: 1, db: 1 }, name: "user_1_db_1", ns: "admi
n.system.users" }
2019-07-07T19:58:54.573+1000 D QUERY    [conn1] Predicate over field 'user'
2019-07-07T19:58:54.573+1000 D QUERY    [conn1] Predicate over field 'db'
2019-07-07T19:58:54.573+1000 D QUERY    [conn1] Relevant index 0 is kp: { user: 1, db: 1 } unique name: 'user_1_db_1' io: { v: 2, unique: true, key: { user: 1, db: 1 }, name: "user_1_db_1",
ns: "admin.system.users" }
2019-07-07T19:58:54.574+1000 D QUERY    [conn1] Rated tree:
$and
    db $eq "admin"  || First: notFirst: 0 full path: db
    user $eq "frederick"  || First: 0 notFirst: full path: user
2019-07-07T19:58:54.574+1000 D QUERY    [conn1] Tagging memoID 1
2019-07-07T19:58:54.574+1000 D QUERY    [conn1] Enumerator: memo just before moving:
[Node #1]: AND enumstate counter 0
        choice 0:
                subnodes:
                idx[0]
                        pos 0 pred user $eq "frederick"
                        pos 1 pred db $eq "admin"

2019-07-07T19:58:54.574+1000 D QUERY    [conn1] About to build solntree from tagged tree:
$and
    db $eq "admin"  || Selected Index #0 pos 1 combine 1
    user $eq "frederick"  || Selected Index #0 pos 0 combine 1
2019-07-07T19:58:54.574+1000 D QUERY    [conn1] Planner: adding solution:
FETCH
---fetched = 1
---sortedByDiskLoc = 1
---getSort = [{ db: 1 }, { user: 1 }, { user: 1, db: 1 }, ]
---Child:
------IXSCAN
---------indexName = user_1_db_1
keyPattern = { user: 1, db: 1 }
---------direction = 1
---------bounds = field #0['user']: ["frederick", "frederick"], field #1['db']: ["admin", "admin"]
---------fetched = 0
---------sortedByDiskLoc = 1
---------getSort = [{ db: 1 }, { user: 1 }, { user: 1, db: 1 }, ]
2019-07-07T19:58:54.574+1000 D QUERY    [conn1] Planner: outputted 1 indexed solutions.
2019-07-07T19:58:54.574+1000 D QUERY    [conn1] Only one plan is available; it will be run but will not be cached. query: { user: "frederick", db: "admin" } sort: {} projection: {}, planSummary: IXSCAN { user: 1, db: 1 }
2019-07-07T19:58:54.574+1000 D STORAGE  [conn1] WT begin_transaction for snapshot id 23
2019-07-07T19:58:54.575+1000 D STORAGE  [conn1] WT rollback_transaction for snapshot id 23
2019-07-07T19:58:54.576+1000 I COMMAND  [conn1] command admin.system.users command: isMaster { isMaster: 1, client: { driver: { name: "mongoc / ext-mongodb:PHP", version: "1.13.0 / 1.5.5" }, os: { type: "Linux", name: "Arch Linux", version: "rolling", architecture: "x86_64" }, platform: "cfg=0xd15ea8e9 posix=200809 stdc=201710 CC=GCC 9.1.0 CFLAGS="" LDFLAGS="" / PHP 7.3.7" }, compression: [], saslSupportedMechs: "admin.frederick", $readPreference: { mode: "secondaryPreferred" }, $db: "admin" } numYields:0 reslen:304 locks:{ Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } storage:{ data: { bytesRead: 114, timeReadingMicros: 10 } } protocol:op_query 4ms
2019-07-07T19:58:54.576+1000 D NETWORK  [conn1] Session from x.x.x.x:35394 encountered a network error during SourceMessage: HostUnreachable: Connection closed by peer
2019-07-07T19:58:54.576+1000 D NETWORK  [conn1] Cancelling outstanding I/O operations on connection to x.x.x.x:35394

Так что, похоже, ему удалось подключиться к серверу, но каким-то образом произошел сбой при errno: 11 Resource temporarily unavailable. И если я отключу SSL / TLS, проблема немедленно исчезнет, ​​не требуя каких-либо дальнейших изменений.

Я чувствую себя по-настоящему невежественным, поэтому, пожалуйста, пролите немного света на меня ... Спасибо.

...