代码之家  ›  专栏  ›  技术社区  ›  Frederick Zhang

使用PHP MongoDB扩展通过SSL/TLS连接时出现问题:ConnectionTimeoutException:找不到合适的服务器(`serverSelectionTryOnce`set)

  •  0
  • Frederick Zhang  · 技术社区  · 5 年前

    尝试使用PHP MongoDB扩展连接到MongoDB服务器时遇到问题,该服务器需要SSL/TLS:

    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 ,当MongoDB配置中未启用IPv6时)。我也试过把IPv4地址放在我的/etc/hosts中,也没用。
    2. setsebool -P httpd_can_network_connect on . 由SELinux引起的,我没用。
    3. net.ssl.allowConnectionsWithoutCertificates false . 它似乎不相关,但我测试了它,没有帮助。

    同一台机器上的mongoshell、Compass和pymongo,以及macOS下的php7.3w/mongodb1.5.5都可以完美地使用相同的连接字符串 .

    以下是一些细节:

    在Linux下测试了相同的症状。

    $ 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() );
    

    here ,太长,导致此帖子超出长度限制)

    _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

    0 回复  |  直到 5 年前