search

mongodb / mongo-php-driver

The Official MongoDB PHP driver
https://pecl.php.net/package/mongodb
Apache License 2.0
882 stars 200 forks source link

No suitable servers found (`serverselectiontryonce` set): [connection error calling ismaster on '114.225.125.126:27017'] #374

Closed xywenke closed 7 years ago

xywenke commented 8 years ago

My mongodb version is 3.2.7, I opened ipv6 in mongod config file by set net.ipv6: true

Although I know

net.ipv6
Type: boolean

Default: False

Removed in version 3.0.

Enable or disable IPv6 support and allows mongos or mongod to connect to the MongoDB instance using an IPv6 network. Prior to MongoDB 3.0, you had to specify net.ipv6 to use IPv6. In MongoDB 3.0 and later, IPv6 is always enabled.

But the error still occurred accidentally，I have no idea about this, I need your help, thank you.

derickr commented 8 years ago

I am not sure how IPv6 comes into play here, as the error message indicates connecting to an IPv4 address and port. So I have some questions:

Which version of the PHP driver are you using?

What is your connection string?

xywenke commented 8 years ago

@derickr I have upgrade my driver to the latest version. My connect string is mongodb://admin:admin_password@114.115.153.126:27017/test Is there some error?

moderndeveloperllc commented 8 years ago

@WenXuanYuan Can you please provide the PHP code you are using to connect? Also note that the /test database you are using in the URI is the authentication database you would like to use.

xywenke commented 8 years ago

@moderndeveloperllc I configured a class to handle connection .

use MongoDB\Client;
class MongoDBManager {
    /**
     * mongodb config
     * @var array
     */
    private $_config = array(
        'host' => '114.115.153.126',
        'port' => '27017',
        'user' => 'admin',
        'pwd' => 'admin_password',
        'name' => 'test'
    );
public function __construct ($config) {
        $this -> _config = array_merge($this -> _config, $config);
        try {
            $this -> _client = new Client('mongodb://' . $this -> _config['user'] . ':' . $this -> _config['pwd'] . '@' . $this -> _config['host'] . ':' . $this -> _config['port'] . '/' . $this -> _config['name']
                // ['connectTimeoutMS' => 500, 'socketTimeoutMS' => 10000]
            );
            $this -> _db = $this -> _client -> selectDatabase($this -> _config['name']);
            // ExceptionLog::hereLog(true);
        } catch (Exception $e) {
            throw new WebException(ExceptionCode::$MONGODB_SYSTEM_ERROR, $e -> getMessage());
        }
    }

The MongoDB\Client is the mongo-php-driver, I am sure the database is existed and the user and password for authentication is right, because the connection string is work, I find the error occurred sometimes, not always.

derickr commented 8 years ago

The error message says '114.225.125.126:33608, but the port you use in your connection string is 27017. That makes little sense.

If you run just the following script, does it work then:

<?php
$m = new \MongoDB\Driver\Manager("mongodb://admn:admin_password@114.115.153.126/test");
$command = new \MongoDB\Driver\Command(['ping' => 1]);
$cursor = $manager->executeCommand('admin', $command);
?>
xywenke commented 8 years ago

I got this

object(MongoDB\Driver\Cursor)#8 (2) {
  ["cursor"]=>
  array(17) {
    ["stamp"]=> int(0)
    ["is_command"]=> bool(true)
    ["sent"]=> bool(true)
    ["done"]=> bool(false)
    ["end_of_event"]=> bool(false)
    ["in_exhaust"]=> bool(false)
    ["has_fields"]=> bool(false)
    ["query"]=> object(stdClass)#9 (1) {
      ["ping"]=> int(1)
    }
    ["fields"]=> object(stdClass)#10 (0) { }
    ["read_preference"]=> array(2) {
      ["mode"]=> int(1)
      ["tags"]=> array(0) { }
    }
    ["flags"]=> int(0)
    ["skip"]=> int(0)
    ["limit"]=> int(1)
    ["count"]=> int(1)
    ["batch_size"]=> int(0)
    ["ns"]=> string(10) "admin.$cmd"
    ["current_doc"]=> object(stdClass)#11 (1) {
      ["ok"]=> float(1)
    }
  }
  ["server_id"]=> int(1)
}

My command is

$m = new \MongoDB\Driver\Manager("mongodb://admn:admin_password@114.115.153.126/test");
$command = new \MongoDB\Driver\Command(['ping' => 1]);
$cursor = $m -> executeCommand('admin', $command);
 var_dump($cursor);

Is there anything wrong?

xywenke commented 8 years ago

@derickr I am sorry, Because I can't find the problem, so I changed the port to default yesterday, but it's not work, the error also occurred sometimes, I have changed the title.

In mongo client connection, I find we can set ipv6 options, is there any way to set this in php connection?

  --version                           show version information
  --verbose                           increase verbosity
  --ipv6                              enable IPv6 support (disabled by default)
  --disableJavaScriptJIT              disable the Javascript Just In Time

This issues is about this https://github.com/mongodb/mongo-php-driver/issues/133

xywenke commented 8 years ago

@bjori Would you help solve this problem? Thank you!

bjori commented 8 years ago

@WenXuanYuan your message on https://github.com/mongodb/mongo-php-driver/issues/374#issuecomment-242321725 indicates that it successfully connected and executed the command on the server.

If you can provide a debug trace log of the script that is failing, then maybe we can see something there.

$ cat test.php
<?php

$manager = new MongoDB\Driver\Manager("mongodb://admn:admin_password@114.115.153.126/test");
$command = new \MongoDB\Driver\Command(["ping" => 1]);
$cursor  = $manager->executeCommand("admin", $command);
$reply   = $cursor->toArray()[0];
var_dump($reply);

Then on the command line, run it like so:

$ php -dmongodb.debug=stderr test.php 2>php.log

You should see printed out:

object(stdClass)#4 (1) {
  ["ok"]=>
  float(1)
}

If you do, then everything is working perfectly and the error you originally got is somehow related to your actual script -- in which case you should try to trim your script a littlebit and see where the problem is, or run it with mongod.debug=stderr like we did above. If you don't see the above output, then the php.log is going to contain a lot of details on what was happening. If you can attach this log somewhere or add the contents here, it would tell us what is going on.

xywenke commented 8 years ago

@bjori I got the error first time, But when I run second, I got this the expected result. ????

xywenke commented 8 years ago

I can't find the error occurred rules.

jmikola commented 8 years ago

I can't find the error occurred rules.

@WenXuanYuan: can you rephrase this sentence?

In mongo client connection, I find we can set ipv6 options, is there any way to set this in php connection?

There isn't a driver option for this. PHP will connect with IPv4 or IPv6 based on the address in the URI or what a given hostname resolves to based on your DNS. IIRC, #133 was related to resolution of "localhost", as it some systems resolved it to an IPv6 loopback address instead of the IPv4 loopback (i.e. 127.0.0.1).

AFAIK, MongoDB still listens on IPv4 regardless of whether it is configured to listen on IPv6. A connection error for 114.225.125.126:27017 would lead me to assume that there simply isn't any server listening on that machine/port unless the IPv4 traffic is being filtered in some way.

xywenke commented 8 years ago

@jmikola In this https://github.com/mongodb/mongo-php-driver/issues/374#issuecomment-242477632, I means it seems that the error occurred randomly and have no regularity. I still not find the solution. ( >﹏<。)

derickr commented 8 years ago

I am thinking that IPv4 vs IPv6 is not a problem here. I think the problem is that you have high network latency, and that is why the connection sometimes gets made, and sometimes not.

Can you try playing with the connectTimeoutMS connection option (https://docs.mongodb.com/manual/reference/connection-string/#connection-options), to see whether increasing it fixes the problem?

You can set it in PHP through http://docs.php.net/manual/en/mongodb-driver-manager.construct.php#mongodb-driver-manager.construct-options

xywenke commented 8 years ago

@derickr I set connectTimeoutMS like this, https://github.com/mongodb/mongo-php-driver/issues/374#issuecomment-242316235, now the value is

$this -> _client = new Client('mongodb://' . $this -> _config['user'] . ':' . $this -> _config['pwd'] . '@' . $this -> _config['host'] . ':' . $this -> _config['port'] . '/' . $this -> _config['name']
                , ['connectTimeoutMS' => 300000, 'socketTimeoutMS' => 30000]
);

But it still give the error sometimes

No suitable servers found (`serverselectiontryonce` set): [connection timeout calling ismaster on '114.225.125.126:27017']
Error occurred at:
FILE: /Users/wen/Documents/SDE/server/vendor/mongodb/mongodb/src/Database.php 　LINE: 240

I find is this function

public function listCollections(array $options = [])
    {
        $operation = new ListCollections($this->databaseName, $options);
        $server = $this->manager->selectServer(new ReadPreference(ReadPreference::RP_PRIMARY));
        return $operation->execute($server);
    }

(; ′⌒`)

xywenke commented 8 years ago

@bjori When I run the php code in my terminal, I got the correct result every time. Maybe something wrong in php code.

bjori commented 8 years ago

Configure your webserver to dump the debug logs into a directory, and then restart the webserver:

$ mkdir /tmp/mongo-debug
$ echo "mongodb.debug=/tmp/mongo-debug/" >> /path/to/your/php.ini
$ restart nginx/httpd/...

Then load the page several times until it starts failing. When it fails, then do

$ grep -l "No suitable servers found" /tmp/mongo-debug/*

That will return you the filename of the logfile that contains the error. Please upload that log file somewhere or paste it here.

xywenke commented 8 years ago

@bjori I can`t get words like "No suitable servers found" in log file, I only get this when error occurred

[2016-08-27T05:09:29+00:00]     PHONGO: DEBUG   > Connection string: 'mongodb://admin:admin_password@114.225.125.126:27017/test'
[2016-08-27T05:09:29+00:00]     PHONGO: TRACE   > ENTRY: php_phongo_make_mongo_client():1924
[2016-08-27T05:09:29+00:00]     PHONGO: DEBUG   > Creating Manager, phongo-1.1.8[stable] - mongoc-1.3.5(bundled), libbson-1.3.5(bundled), php-7.0.9
[2016-08-27T05:09:29+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_init():51
[2016-08-27T05:09:29+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_init():68
[2016-08-27T05:09:29+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_init():87
[2016-08-27T05:09:29+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_init():123
[2016-08-27T05:09:29+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_init():1597
[2016-08-27T05:09:29+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_init():1620
[2016-08-27T05:09:29+00:00]     client: DEBUG   > Using custom stream initiator.
[2016-08-27T05:09:29+00:00]     PHONGO: TRACE   >  EXIT: php_phongo_make_mongo_client():2025
[2016-08-27T05:09:29+00:00]     PHONGO: TRACE   > ENTRY: phongo_stream_initiator():1143
[2016-08-27T05:09:29+00:00]     PHONGO: DEBUG   > Connecting to '114.225.125.126:27017[mongodb://admin:admin_password@114.225.125.126:27017/test]'
[2016-08-27T05:09:29+00:00]     PHONGO: DEBUG   > Created: RSRC#50 as '114.225.125.126:27017[mongodb://admin:admin_password@114.225.125.126:27017/test]'
[2016-08-27T05:09:29+00:00]     PHONGO: TRACE   >  EXIT: phongo_stream_initiator():1273
[2016-08-27T05:09:29+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:09:29+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f10cb00 [9]
[2016-08-27T05:09:29+00:00]     stream: TRACE   > 00000:  3a 00 00 00 01 00 00 00  00 00 00 00 d4 07 00 00  : . . . . . . .  . . . . Ô . . .
[2016-08-27T05:09:29+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-08-27T05:09:29+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-08-27T05:09:29+00:00]     stream: TRACE   > 00030:  73 74 65 72 00 01 00 00  00 00                    s t e r . . . .  . .
[2016-08-27T05:09:29+00:00]     PHONGO: DEBUG   > Setting timeout to: 0
[2016-08-27T05:09:29+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164

I still don`t know where is the problem. ‘(>﹏<)′

xywenke commented 8 years ago

When no error occurred, I find the log content has more line with once visit.

[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Connection string: 'mongodb://admin:admin_password@114.225.125.126:27017/test'
[2016-08-27T05:22:31+00:00]     PHONGO: TRACE   > ENTRY: php_phongo_make_mongo_client():1924
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Creating Manager, phongo-1.1.8[stable] - mongoc-1.3.5(bundled), libbson-1.3.5(bundled), php-7.0.9
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_init():51
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_init():68
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_init():87
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_init():123
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_init():1597
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_init():1620
[2016-08-27T05:22:31+00:00]     client: DEBUG   > Using custom stream initiator.
[2016-08-27T05:22:31+00:00]     PHONGO: TRACE   >  EXIT: php_phongo_make_mongo_client():2025
[2016-08-27T05:22:31+00:00]     PHONGO: TRACE   > ENTRY: phongo_stream_initiator():1143
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Connecting to '114.225.125.126:27017[mongodb://admin:admin_password@114.225.125.126:27017/test]'
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Created: RSRC#50 as '114.225.125.126:27017[mongodb://admin:admin_password@114.225.125.126:27017/test]'
[2016-08-27T05:22:31+00:00]     PHONGO: TRACE   >  EXIT: phongo_stream_initiator():1273
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f10cb00 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  3a 00 00 00 01 00 00 00  00 00 00 00 d4 07 00 00  : . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+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-08-27T05:22:31+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-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  73 74 65 72 00 01 00 00  00 00                    s t e r . . . .  . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 0
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_try_append_from_stream():293
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 0
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 0
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9968 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c2 00 00 00                                       Â . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_try_append_from_stream():323
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_try_append_from_stream():293
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 0
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 190 wanted: 0
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9968 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c1 09 00 00 01 00 00 00  01 00 00 00 08 00 00 00  Á . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  9e 00 00 00 08 69 73 6d  61 73 74 65 72 00 01 10  . . . . . i s m  a s t e r . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  6d 61 78 42 73 6f 6e 4f  62 6a 65 63 74 53 69 7a  m a x B s o n O  b j e c t S i z
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  65 00 00 00 00 01 10 6d  61 78 4d 65 73 73 61 67  e . . . . . . m  a x M e s s a g
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  65 53 69 7a 65 42 79 74  65 73 00 00 6c dc 02 10  e S i z e B y t  e s . . l Ü . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  6d 61 78 57 72 69 74 65  42 61 74 63 68 53 69 7a  m a x W r i t e  B a t c h S i z
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  65 00 e8 03 00 00 09 6c  6f 63 61 6c 54 69 6d 65  e . è . . . . l  o c a l T i m e
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  00 79 07 73 ca 56 01 00  00 10 6d 61 78 57 69 72  . y . s Ê V . .  . . m a x W i r
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  65 56 65 72 73 69 6f 6e  00 04 00 00 00 10 6d 69  e V e r s i o n  . . . . . . m i
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  6e 57 69 72 65 56 65 72  73 69 6f 6e 00 00 00 00  n W i r e V e r  s i o n . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  00 01 6f 6b 00 00 00 00  00 00 00 f0 3f 00        . . o k . . . .  . . . ð ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_try_append_from_stream():323
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > TRACE: mongoc_topology_description_handle_ismaster():1400 No transition entry to 4 for 1
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():505
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_new():85
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_new():235
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_next():1025
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_initial_query():346
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_fetch_stream():305
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1411
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server_description():1353
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_auth_node():1096
[2016-08-27T05:22:31+00:00]    cluster: INFO    > SCRAM: authenticating "admin" (step 1)
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_run_command_rpc():142
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1c5800 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  aa 00 00 00 01 00 00 00  00 00 00 00 d4 07 00 00  ª . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 ff ff ff ff 7d 00 00  $ c m d . . . .  . ÿ ÿ ÿ ÿ } . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 10 73 61 73 6c 53 74  61 72 74 00 01 00 00 00  . . s a s l S t  a r t . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  02 6d 65 63 68 61 6e 69  73 6d 00 0c 00 00 00 53  . m e c h a n i  s m . . . . . S
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  43 52 41 4d 2d 53 48 41  2d 31 00 05 70 61 79 6c  C R A M - S H A  - 1 . . p a y l
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  6f 61 64 00 2d 00 00 00  00 6e 2c 2c 6e 3d 77 65  o a d . - . . .  . n , , n = w e
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  6e 6b 65 2c 72 3d 55 52  68 5a 39 34 69 44 76 4a  n k e , r = U R  h Z 9 4 i D v J
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  54 35 70 4f 30 32 6d 43  72 35 6c 64 4f 44 59 67  T 5 p O 0 2 m C  r 5 l d O D Y g
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  33 36 76 4d 43 76 10 61  75 74 6f 41 75 74 68 6f  3 6 v M C v . a  u t o A u t h o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  72 69 7a 65 00 01 00 00  00 00                    r i z e . . . .  . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 170
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd7e38 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c3 00 00 00                                       Ã . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 191 wanted: 191
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd7e38 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c2 09 00 00 01 00 00 00  01 00 00 00 08 00 00 00  Â . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  9f 00 00 00 10 63 6f 6e  76 65 72 73 61 74 69 6f  . . . . . c o n  v e r s a t i o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  6e 49 64 00 01 00 00 00  08 64 6f 6e 65 00 00 05  n I d . . . . .  . d o n e . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  70 61 79 6c 6f 61 64 00  65 00 00 00 00 72 3d 55  p a y l o a d .  e . . . . r = U
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  52 68 5a 39 34 69 44 76  4a 54 35 70 4f 30 32 6d  R h Z 9 4 i D v  J T 5 p O 0 2 m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  43 72 35 6c 64 4f 44 59  67 33 36 76 4d 43 76 6e  C r 5 l d O D Y  g 3 6 v M C v n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  70 53 54 44 77 51 58 33  64 37 49 32 64 54 42 64  p S T D w Q X 3  d 7 I 2 d T B d
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  54 64 4c 48 67 33 37 47  46 54 48 53 34 35 76 2c  T d L H g 3 7 G  F T H S 4 5 v ,
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  73 3d 35 64 49 50 76 54  6b 53 61 72 4b 5a 70 61  s = 5 d I P v T  k S a r K Z p a
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  68 69 72 32 53 64 45 51  3d 3d 2c 69 3d 31 30 30  h i r 2 S d E Q  = = , i = 1 0 0
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  30 30 01 6f 6b 00 00 00  00 00 00 00 f0 3f 00     0 0 . o k . . .  . . . . ð ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command_rpc():217
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command():296
[2016-08-27T05:22:31+00:00]    cluster: INFO    > SCRAM: authenticating "admin" (step 2)
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_run_command_rpc():142
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f10cb00 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  ce 00 00 00 02 00 00 00  00 00 00 00 d4 07 00 00  Î . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 ff ff ff ff a1 00 00  $ c m d . . . .  . ÿ ÿ ÿ ÿ ¡ . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 10 73 61 73 6c 43 6f  6e 74 69 6e 75 65 00 01  . . s a s l C o  n t i n u e . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  00 00 00 10 63 6f 6e 76  65 72 73 61 74 69 6f 6e  . . . . c o n v  e r s a t i o n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  49 64 00 01 00 00 00 05  70 61 79 6c 6f 61 64 00  I d . . . . . .  p a y l o a d .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  68 00 00 00 00 63 3d 62  69 77 73 2c 72 3d 55 52  h . . . . c = b  i w s , r = U R
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  68 5a 39 34 69 44 76 4a  54 35 70 4f 30 32 6d 43  h Z 9 4 i D v J  T 5 p O 0 2 m C
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  72 35 6c 64 4f 44 59 67  33 36 76 4d 43 76 6e 70  r 5 l d O D Y g  3 6 v M C v n p
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  53 54 44 77 51 58 33 64  37 49 32 64 54 42 64 54  S T D w Q X 3 d  7 I 2 d T B d T
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  64 4c 48 67 33 37 47 46  54 48 53 34 35 76 2c 70  d L H g 3 7 G F  T H S 4 5 v , p
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  3d 68 65 61 65 36 6d 66  4c 35 74 79 64 67 57 74  = h e a e 6 m f  L 5 t y d g W t
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000c0:  6a 2f 52 70 6f 73 62 64  50 46 56 63 3d 00        j / R p o s b d  P F V c = .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 206
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd7e38 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  7c 00 00 00                                       | . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 120 wanted: 120
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd7e38 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c3 09 00 00 02 00 00 00  01 00 00 00 08 00 00 00  Ã . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  58 00 00 00 10 63 6f 6e  76 65 72 73 61 74 69 6f  X . . . . c o n  v e r s a t i o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  6e 49 64 00 01 00 00 00  08 64 6f 6e 65 00 00 05  n I d . . . . .  . d o n e . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  70 61 79 6c 6f 61 64 00  1e 00 00 00 00 76 3d 6f  p a y l o a d .  . . . . . v = o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  48 56 43 65 2b 50 4d 72  43 78 6d 67 7a 59 42 65  H V C e + P M r  C x m g z Y B e
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  69 46 5a 65 62 6e 76 58  38 6b 3d 01 6f 6b 00 00  i F Z e b n v X  8 k = . o k . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  00 00 00 00 00 f0 3f 00                           . . . . . ð ? . 
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command_rpc():217
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command():296
[2016-08-27T05:22:31+00:00]    cluster: INFO    > SCRAM: authenticating "admin" (step 3)
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_run_command_rpc():142
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1c5900 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  66 00 00 00 03 00 00 00  00 00 00 00 d4 07 00 00  f . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 ff ff ff ff 39 00 00  $ c m d . . . .  . ÿ ÿ ÿ ÿ 9 . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 10 73 61 73 6c 43 6f  6e 74 69 6e 75 65 00 01  . . s a s l C o  n t i n u e . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  00 00 00 10 63 6f 6e 76  65 72 73 61 74 69 6f 6e  . . . . c o n v  e r s a t i o n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  49 64 00 01 00 00 00 05  70 61 79 6c 6f 61 64 00  I d . . . . . .  p a y l o a d .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  00 00 00 00 00 00                                 . . . . . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 102
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd7e38 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  5e 00 00 00                                       ^ . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 90 wanted: 90
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd7e38 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c4 09 00 00 03 00 00 00  01 00 00 00 08 00 00 00  Ä . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  3a 00 00 00 10 63 6f 6e  76 65 72 73 61 74 69 6f  : . . . . c o n  v e r s a t i o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  6e 49 64 00 01 00 00 00  08 64 6f 6e 65 00 01 05  n I d . . . . .  . d o n e . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  70 61 79 6c 6f 61 64 00  00 00 00 00 00 01 6f 6b  p a y l o a d .  . . . . . . o k
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  00 00 00 00 00 00 00 f0  3f 00                    . . . . . . . ð  ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command_rpc():217
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command():296
[2016-08-27T05:22:31+00:00]    cluster: INFO    > SCRAM: "admin" authenticated
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > TRACE: _mongoc_cluster_auth_node():1159 Authentication succeeded
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_auth_node():1162
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server_description():1377
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1433
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_fetch_stream():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_op_query():395
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_preferences():254
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_preferences():307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_sendv_to_server():2157
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1c5900 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  47 00 00 00 04 00 00 00  00 00 00 00 d4 07 00 00  G . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 01 00 00 00 1a 00 00  $ c m d . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 10 6c 69 73 74 43 6f  6c 6c 65 63 74 69 6f 6e  . . l i s t C o  l l e c t i o n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  73 00 01 00 00 00 00                              s . . . . . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 71
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_sendv_to_server():2268
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_try_recv():2307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > TRACE: mongoc_cluster_try_recv():2316 Waiting for reply from server_id "1"
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd97b8 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  60 01 00 00                                       ` . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 348 wanted: 348
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd97b8 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c5 09 00 00 04 00 00 00  01 00 00 00 08 00 00 00  Å . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  3c 01 00 00 03 63 75 72  73 6f 72 00 23 01 00 00  < . . . . c u r  s o r . # . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  12 69 64 00 00 00 00 00  00 00 00 00 02 6e 73 00  . i d . . . . .  . . . . . n s .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  21 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  ! . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  24 63 6d 64 2e 6c 69 73  74 43 6f 6c 6c 65 63 74  $ c m d . l i s  t C o l l e c t
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  69 6f 6e 73 00 04 66 69  72 73 74 42 61 74 63 68  i o n s . . f i  r s t B a t c h
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  00 dd 00 00 00 03 30 00  27 00 00 00 02 6e 61 6d  . Ý . . . . 0 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  65 00 0a 00 00 00 75 73  65 72 5f 77 6f 72 6b 00  e . . . . . u s  e r _ w o r k .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  31 00 1f 00 00 00 02 6e  61 6d 65 00 02 00 00 00  1 . . . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  74 00 03 6f 70 74 69 6f  6e 73 00 05 00 00 00 00  t . . o p t i o  n s . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000c0:  00 03 32 00 31 00 00 00  02 6e 61 6d 65 00 14 00  . . 2 . 1 . . .  . n a m e . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000d0:  00 00 77 61 72 65 5f 74  79 70 65 5f 74 61 67 5f  . . w a r e _ t  y p e _ t a g _
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000e0:  76 61 6c 75 65 00 03 6f  70 74 69 6f 6e 73 00 05  v a l u e . . o  p t i o n s . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000f0:  00 00 00 00 00 03 33 00  27 00 00 00 02 6e 61 6d  . . . . . . 3 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00100:  65 00 0a 00 00 00 77 61  72 65 5f 74 79 70 65 00  e . . . . . w a  r e _ t y p e .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00110:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00120:  34 00 2b 00 00 00 02 6e  61 6d 65 00 0e 00 00 00  4 . + . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00130:  77 61 72 65 5f 74 79 70  65 5f 74 61 67 00 03 6f  w a r e _ t y p  e _ t a g . . o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00140:  70 74 69 6f 6e 73 00 05  00 00 00 00 00 00 00 01  p t i o n s . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00150:  6f 6b 00 00 00 00 00 00  00 f0 3f 00              o k . . . . . .  . ð ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_try_recv():2374
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_prefs_result_cleanup():314
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_prefs_result_cleanup():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_op_query():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_initial_query():382
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_next():1079
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_init():289
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_new():36
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_new():40
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_init():299
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error():923
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_error():941
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_error():954
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error():933
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_destroy():242
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_destroy():47
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_destroy():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_destroy():296
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_destroy():52
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_destroy():252
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():505
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_new():85
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_new():235
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_next():1025
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_initial_query():346
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_fetch_stream():305
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1411
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server_description():1353
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server_description():1377
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1433
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_fetch_stream():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_op_query():395
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_preferences():254
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_preferences():307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_sendv_to_server():2157
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1c5900 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  47 00 00 00 05 00 00 00  00 00 00 00 d4 07 00 00  G . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 01 00 00 00 1a 00 00  $ c m d . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 10 6c 69 73 74 43 6f  6c 6c 65 63 74 69 6f 6e  . . l i s t C o  l l e c t i o n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  73 00 01 00 00 00 00                              s . . . . . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 71
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_sendv_to_server():2268
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_try_recv():2307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > TRACE: mongoc_cluster_try_recv():2316 Waiting for reply from server_id "1"
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd97b8 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  60 01 00 00                                       ` . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 348 wanted: 348
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd97b8 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c6 09 00 00 05 00 00 00  01 00 00 00 08 00 00 00  Æ . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  3c 01 00 00 03 63 75 72  73 6f 72 00 23 01 00 00  < . . . . c u r  s o r . # . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  12 69 64 00 00 00 00 00  00 00 00 00 02 6e 73 00  . i d . . . . .  . . . . . n s .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  21 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  ! . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  24 63 6d 64 2e 6c 69 73  74 43 6f 6c 6c 65 63 74  $ c m d . l i s  t C o l l e c t
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  69 6f 6e 73 00 04 66 69  72 73 74 42 61 74 63 68  i o n s . . f i  r s t B a t c h
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  00 dd 00 00 00 03 30 00  27 00 00 00 02 6e 61 6d  . Ý . . . . 0 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  65 00 0a 00 00 00 75 73  65 72 5f 77 6f 72 6b 00  e . . . . . u s  e r _ w o r k .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  31 00 1f 00 00 00 02 6e  61 6d 65 00 02 00 00 00  1 . . . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  74 00 03 6f 70 74 69 6f  6e 73 00 05 00 00 00 00  t . . o p t i o  n s . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000c0:  00 03 32 00 31 00 00 00  02 6e 61 6d 65 00 14 00  . . 2 . 1 . . .  . n a m e . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000d0:  00 00 77 61 72 65 5f 74  79 70 65 5f 74 61 67 5f  . . w a r e _ t  y p e _ t a g _
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000e0:  76 61 6c 75 65 00 03 6f  70 74 69 6f 6e 73 00 05  v a l u e . . o  p t i o n s . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000f0:  00 00 00 00 00 03 33 00  27 00 00 00 02 6e 61 6d  . . . . . . 3 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00100:  65 00 0a 00 00 00 77 61  72 65 5f 74 79 70 65 00  e . . . . . w a  r e _ t y p e .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00110:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00120:  34 00 2b 00 00 00 02 6e  61 6d 65 00 0e 00 00 00  4 . + . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00130:  77 61 72 65 5f 74 79 70  65 5f 74 61 67 00 03 6f  w a r e _ t y p  e _ t a g . . o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00140:  70 74 69 6f 6e 73 00 05  00 00 00 00 00 00 00 01  p t i o n s . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00150:  6f 6b 00 00 00 00 00 00  00 f0 3f 00              o k . . . . . .  . ð ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_try_recv():2374
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_prefs_result_cleanup():314
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_prefs_result_cleanup():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_op_query():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_initial_query():382
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_next():1079
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_init():289
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_new():36
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_new():40
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_init():299
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error():923
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_error():941
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_error():954
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error():933
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_destroy():242
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_destroy():47
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_destroy():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_destroy():296
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_destroy():52
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_destroy():252
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():505
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00] PHONGO-BSON: TRACE   > encoding document
[2016-08-27T05:22:31+00:00] collection: TRACE   > ENTRY: _mongoc_collection_new():170
[2016-08-27T05:22:31+00:00] collection: TRACE   >  EXIT: _mongoc_collection_new():199
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_new():85
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_new():235
[2016-08-27T05:22:31+00:00] collection: TRACE   > ENTRY: mongoc_collection_destroy():223
[2016-08-27T05:22:31+00:00] collection: TRACE   >  EXIT: mongoc_collection_destroy():248
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_next():1025
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_initial_query():346
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_fetch_stream():305
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1411
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server_description():1353
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server_description():1377
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1433
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_fetch_stream():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_find_command():774
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_init():289
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_new():36
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_new():40
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_init():299
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_refresh_from_command():65
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_run_command():516
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_fetch_stream():305
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1411
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server_description():1353
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server_description():1377
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1433
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_fetch_stream():322
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_preferences():254
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_preferences():307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_run_command_rpc():142
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1d4100 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  7d 00 00 00 06 00 00 00  00 00 00 00 d4 07 00 00  } . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 ff ff ff ff 50 00 00  $ c m d . . . .  . ÿ ÿ ÿ ÿ P . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 02 66 69 6e 64 00 0a  00 00 00 75 73 65 72 5f  . . f i n d . .  . . . u s e r _
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  77 6f 72 6b 00 03 66 69  6c 74 65 72 00 14 00 00  w o r k . . f i  l t e r . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  00 02 75 73 65 72 5f 69  64 00 02 00 00 00 31 00  . . u s e r _ i  d . . . . . 1 .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  00 03 70 72 6f 6a 65 63  74 69 6f 6e 00 0f 00 00  . . p r o j e c  t i o n . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  00 10 74 79 70 65 00 01  00 00 00 00 00           . . t y p e . .  . . . . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 125
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9598 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  bf 00 00 00                                       ¿ . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 187 wanted: 187
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9598 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c7 09 00 00 06 00 00 00  01 00 00 00 08 00 00 00  Ç . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  9b 00 00 00 12 77 61 69  74 65 64 4d 53 00 00 00  . . . . . w a i  t e d M S . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 00 00 00 00 00 03 63  75 72 73 6f 72 00 70 00  . . . . . . . c  u r s o r . p .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  00 00 04 66 69 72 73 74  42 61 74 63 68 00 35 00  . . . f i r s t  B a t c h . 5 .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  00 00 03 30 00 2d 00 00  00 07 5f 69 64 00 57 c1  . . . 0 . - . .  . . _ i d . W Á
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  1f 6f 88 95 ba 02 32 22  87 b1 02 74 79 70 65 00  . o . . º . 2 "  . ± . t y p e .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  0d 00 00 00 67 6f 6f 64  73 50 75 62 6c 69 73 68  . . . . g o o d  s P u b l i s h
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  00 00 00 12 69 64 00 00  00 00 00 00 00 00 00 02  . . . . i d . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  6e 73 00 16 00 00 00 74  65 73 74 5f 71 66 70 6c  n s . . . . . t  e s t _ q f p l
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  61 6e 2e 75 73 65 72 5f  77 6f 72 6b 00 00 01 6f  a n . u s e r _  w o r k . . . o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  6b 00 00 00 00 00 00 00  f0 3f 00                 k . . . . . . .  ð ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command_rpc():217
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_prefs_result_cleanup():314
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_prefs_result_cleanup():322
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_refresh_from_command():93
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_find_command():786
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_initial_query():382
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_next():1079
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error():923
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_error():941
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_error():954
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error():933
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_destroy():242
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_destroy():47
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_destroy():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_destroy():296
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_destroy():52
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_destroy():252
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():505
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_new():85
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_new():235
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_next():1025
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_initial_query():346
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_fetch_stream():305
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1411
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server_description():1353
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server_description():1377
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1433
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_fetch_stream():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_op_query():395
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_preferences():254
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_preferences():307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_sendv_to_server():2157
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1c5900 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  47 00 00 00 07 00 00 00  00 00 00 00 d4 07 00 00  G . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 01 00 00 00 1a 00 00  $ c m d . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 10 6c 69 73 74 43 6f  6c 6c 65 63 74 69 6f 6e  . . l i s t C o  l l e c t i o n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  73 00 01 00 00 00 00                              s . . . . . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 71
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_sendv_to_server():2268
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_try_recv():2307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > TRACE: mongoc_cluster_try_recv():2316 Waiting for reply from server_id "1"
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9868 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  60 01 00 00                                       ` . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 348 wanted: 348
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9868 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c8 09 00 00 07 00 00 00  01 00 00 00 08 00 00 00  È . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  3c 01 00 00 03 63 75 72  73 6f 72 00 23 01 00 00  < . . . . c u r  s o r . # . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  12 69 64 00 00 00 00 00  00 00 00 00 02 6e 73 00  . i d . . . . .  . . . . . n s .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  21 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  ! . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  24 63 6d 64 2e 6c 69 73  74 43 6f 6c 6c 65 63 74  $ c m d . l i s  t C o l l e c t
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  69 6f 6e 73 00 04 66 69  72 73 74 42 61 74 63 68  i o n s . . f i  r s t B a t c h
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  00 dd 00 00 00 03 30 00  27 00 00 00 02 6e 61 6d  . Ý . . . . 0 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  65 00 0a 00 00 00 75 73  65 72 5f 77 6f 72 6b 00  e . . . . . u s  e r _ w o r k .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  31 00 1f 00 00 00 02 6e  61 6d 65 00 02 00 00 00  1 . . . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  74 00 03 6f 70 74 69 6f  6e 73 00 05 00 00 00 00  t . . o p t i o  n s . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000c0:  00 03 32 00 31 00 00 00  02 6e 61 6d 65 00 14 00  . . 2 . 1 . . .  . n a m e . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000d0:  00 00 77 61 72 65 5f 74  79 70 65 5f 74 61 67 5f  . . w a r e _ t  y p e _ t a g _
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000e0:  76 61 6c 75 65 00 03 6f  70 74 69 6f 6e 73 00 05  v a l u e . . o  p t i o n s . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000f0:  00 00 00 00 00 03 33 00  27 00 00 00 02 6e 61 6d  . . . . . . 3 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00100:  65 00 0a 00 00 00 77 61  72 65 5f 74 79 70 65 00  e . . . . . w a  r e _ t y p e .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00110:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00120:  34 00 2b 00 00 00 02 6e  61 6d 65 00 0e 00 00 00  4 . + . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00130:  77 61 72 65 5f 74 79 70  65 5f 74 61 67 00 03 6f  w a r e _ t y p  e _ t a g . . o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00140:  70 74 69 6f 6e 73 00 05  00 00 00 00 00 00 00 01  p t i o n s . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00150:  6f 6b 00 00 00 00 00 00  00 f0 3f 00              o k . . . . . .  . ð ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_try_recv():2374
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_prefs_result_cleanup():314
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_prefs_result_cleanup():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_op_query():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_initial_query():382
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_next():1079
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_init():289
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_new():36
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_new():40
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_init():299
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error():923
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_error():941
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_error():954
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error():933
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_destroy():242
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_destroy():47
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_destroy():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_destroy():296
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_destroy():52
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_destroy():252
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():505
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_new():85
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_new():235
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_next():1025
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_initial_query():346
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_fetch_stream():305
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1411
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server_description():1353
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server_description():1377
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1433
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_fetch_stream():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_op_query():395
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_preferences():254
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_preferences():307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_sendv_to_server():2157
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1c5900 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  47 00 00 00 08 00 00 00  00 00 00 00 d4 07 00 00  G . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  04 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 01 00 00 00 1a 00 00  $ c m d . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 10 6c 69 73 74 43 6f  6c 6c 65 63 74 69 6f 6e  . . l i s t C o  l l e c t i o n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  73 00 01 00 00 00 00                              s . . . . . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 71
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_sendv_to_server():2268
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_try_recv():2307
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > TRACE: mongoc_cluster_try_recv():2316 Waiting for reply from server_id "1"
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9868 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  60 01 00 00                                       ` . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 348 wanted: 348
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9868 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  c9 09 00 00 08 00 00 00  01 00 00 00 08 00 00 00  É . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  3c 01 00 00 03 63 75 72  73 6f 72 00 23 01 00 00  < . . . . c u r  s o r . # . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  12 69 64 00 00 00 00 00  00 00 00 00 02 6e 73 00  . i d . . . . .  . . . . . n s .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  21 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  ! . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  24 63 6d 64 2e 6c 69 73  74 43 6f 6c 6c 65 63 74  $ c m d . l i s  t C o l l e c t
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  69 6f 6e 73 00 04 66 69  72 73 74 42 61 74 63 68  i o n s . . f i  r s t B a t c h
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  00 dd 00 00 00 03 30 00  27 00 00 00 02 6e 61 6d  . Ý . . . . 0 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  65 00 0a 00 00 00 75 73  65 72 5f 77 6f 72 6b 00  e . . . . . u s  e r _ w o r k .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  31 00 1f 00 00 00 02 6e  61 6d 65 00 02 00 00 00  1 . . . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  74 00 03 6f 70 74 69 6f  6e 73 00 05 00 00 00 00  t . . o p t i o  n s . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000c0:  00 03 32 00 31 00 00 00  02 6e 61 6d 65 00 14 00  . . 2 . 1 . . .  . n a m e . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000d0:  00 00 77 61 72 65 5f 74  79 70 65 5f 74 61 67 5f  . . w a r e _ t  y p e _ t a g _
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000e0:  76 61 6c 75 65 00 03 6f  70 74 69 6f 6e 73 00 05  v a l u e . . o  p t i o n s . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000f0:  00 00 00 00 00 03 33 00  27 00 00 00 02 6e 61 6d  . . . . . . 3 .  ' . . . . n a m
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00100:  65 00 0a 00 00 00 77 61  72 65 5f 74 79 70 65 00  e . . . . . w a  r e _ t y p e .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00110:  03 6f 70 74 69 6f 6e 73  00 05 00 00 00 00 00 03  . o p t i o n s  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00120:  34 00 2b 00 00 00 02 6e  61 6d 65 00 0e 00 00 00  4 . + . . . . n  a m e . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00130:  77 61 72 65 5f 74 79 70  65 5f 74 61 67 00 03 6f  w a r e _ t y p  e _ t a g . . o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00140:  70 74 69 6f 6e 73 00 05  00 00 00 00 00 00 00 01  p t i o n s . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00150:  6f 6b 00 00 00 00 00 00  00 f0 3f 00              o k . . . . . .  . ð ? .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_try_recv():2374
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: apply_read_prefs_result_cleanup():314
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: apply_read_prefs_result_cleanup():322
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_op_query():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_initial_query():382
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_next():1079
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_init():289
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_new():36
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_new():40
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_init():299
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():235 done
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():964
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():969 cursor_id(0)
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():216
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():116
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1000
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error():923
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_error():941
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_error():954
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error():933
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_destroy():242
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_destroy():47
[2016-08-27T05:22:31+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_destroy():259
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_destroy():296
[2016-08-27T05:22:31+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_destroy():52
[2016-08-27T05:22:31+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_destroy():252
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():505
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00] PHONGO-BSON: TRACE   > encoding ObjectId
[2016-08-27T05:22:31+00:00] PHONGO-BSON: TRACE   > encoding document
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_bulk_operation_update_one():331
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_init_update():228
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_update_append():116
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_update_append():136
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_init_update():242
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_bulk_operation_update_one():356
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_bulk_operation_execute():372
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_init():1007
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_init():1017
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1411
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():383
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():493
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server_description():1353
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server_description():1377
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1433
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_execute():949
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command():805
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_run_command_rpc():142
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():480
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():149
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():161 writev = 0x10f1d4c00 [9]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  0a 01 00 00 09 00 00 00  00 00 00 00 d4 07 00 00  . . . . . . . .  . . . . Ô . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 74 65 73 74  5f 71 66 70 6c 61 6e 2e  . . . . t e s t  _ q f p l a n .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  24 63 6d 64 00 00 00 00  00 ff ff ff ff dd 00 00  $ c m d . . . .  . ÿ ÿ ÿ ÿ Ý . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  00 02 75 70 64 61 74 65  00 0a 00 00 00 75 73 65  . . u p d a t e  . . . . . u s e
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  72 5f 77 6f 72 6b 00 03  77 72 69 74 65 43 6f 6e  r _ w o r k . .  w r i t e C o n
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00050:  63 65 72 6e 00 05 00 00  00 00 08 6f 72 64 65 72  c e r n . . . .  . . . o r d e r
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00060:  65 64 00 01 04 75 70 64  61 74 65 73 00 9c 00 00  e d . . . u p d  a t e s . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00070:  00 03 30 00 94 00 00 00  03 71 00 3c 00 00 00 07  . . 0 . . . . .  . q . < . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00080:  5f 69 64 00 57 c0 98 fa  88 95 ba 02 92 7c 23 e2  _ i d . W À . ú  . . º . . | # â
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00090:  02 75 73 65 72 5f 69 64  00 02 00 00 00 31 00 02  . u s e r _ i d  . . . . . 1 . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000a0:  74 79 70 65 00 0d 00 00  00 67 6f 6f 64 73 50 75  t y p e . . . .  . g o o d s P u
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000b0:  62 6c 69 73 68 00 00 03  75 00 3c 00 00 00 03 24  b l i s h . . .  u . < . . . . $
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000c0:  73 65 74 00 31 00 00 00  02 69 6d 61 67 65 2e 31  s e t . 1 . . .  . i m a g e . 1
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000d0:  00 1f 00 00 00 32 30 31  36 2d 30 38 2d 32 37 2f  . . . . . 2 0 1  6 - 0 8 - 2 7 /
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000e0:  35 37 63 31 32 33 39 37  61 61 38 38 39 37 39 2e  5 7 c 1 2 3 9 7  a a 8 8 9 7 9 .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 000f0:  6a 70 67 00 00 00 08 75  70 73 65 72 74 00 00 08  j p g . . . . u  p s e r t . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00100:  6d 75 6c 74 69 00 00 00  00 00                    m u l t i . . .  . .
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():164
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():487 writev returned: 266
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():511
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 4 wanted: 4
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9618 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  47 00 00 00                                       G . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():150
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():268
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():226
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Setting timeout to: 300000
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Reading got: 67 wanted: 67
[2016-08-27T05:22:31+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():236 readv = 0x7fff51fd9618 [1]
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00000:  ca 09 00 00 09 00 00 00  01 00 00 00 08 00 00 00  Ê . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00020:  23 00 00 00 10 6f 6b 00  01 00 00 00 10 6e 4d 6f  # . . . . o k .  . . . . . n M o
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00030:  64 69 66 69 65 64 00 00  00 00 00 10 6e 00 00 00  d i f i e d . .  . . . . n . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   > 00040:  00 00 00                                          . . .
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():239
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():280
[2016-08-27T05:22:31+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():186
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command_rpc():217
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_rpc_parse_error():788
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_rpc_parse_error():815
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_run_command():296
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_merge():1298
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_merge():1407
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command():935
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_execute():987
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_complete():1487
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_complete():1526
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_bulk_operation_execute():456
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_destroy():994
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_destroy():1000
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_destroy():1024
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_destroy():1032
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_destroy():89
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2016-08-27T05:22:31+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_destroy():103
[2016-08-27T05:22:31+00:00]     stream: TRACE   > ENTRY: mongoc_stream_destroy():103
[2016-08-27T05:22:31+00:00]     PHONGO: DEBUG   > Not destroying RSRC#-1
[2016-08-27T05:22:31+00:00]     stream: TRACE   >  EXIT: mongoc_stream_destroy():111
[2016-08-27T05:22:31+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_destroy():1643
[2016-08-27T05:22:31+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_destroy():1653
TheHett commented 8 years ago

We has it error sometimes. Tell me please, does the driver persistant connection as old MongoClient ? (when used php-fpm pool) I look many CLOSE_WAIT connections to mongodb server from php-side. It says that connection often reopens.

jmikola commented 8 years ago

Tell me please, does the driver persistant connection as old MongoClient ? (when used php-fpm pool) I look many CLOSE_WAIT connections to mongodb server from php-side. It says that connection often reopens.

Connection persistence in the legacy driver is documented here, so you can compare with the following explanation.

Versions of the driver in 1.1.x and early rely on PHP to persist the socket (akin to pfsockopen() based on the host, port, and URI string. This was handled through our integration with PHP's streams API, which is why the traces include "Using custom stream initiator." and reference a phongo_stream_initiator() function.

In 1.1.8, we disabled socket persistence for SSL connections as a quick fix for PHPC-720.

In 1.2.0, we're removing our reliance on PHP streams and will start having libmongoc manage all socket communication. Rather than persist sockets, we'll persist the libmongoc client object, which will have the added benefit of persisting established SSL channels and the topology state. The relevant tickets for this are PHPC-605 (already merged to master) and PHPC-433 (currently being reviewed in https://github.com/mongodb/mongo-php-driver/pull/376).

We'll also aim to get all of this behavior documented soon on PHP.net (PHPC-780).

TheHett commented 8 years ago

oops, sorry, just now I saw this release note:

  • PHPC-720: Do not persist SSL streams to avoid SSL reinitialization errors

Waiting updates, thanks!

derickr commented 8 years ago

@TheHett: That's been addressed in https://github.com/mongodb/mongo-php-driver/pull/376 — which is close to being merged.

jmikola commented 8 years ago

1.2.0alpha2 has been released, which includes significant changes to our connection handling and persistence. We've entirely dropped PHP's streams API and now rely on libmongoc for all socket communication, which I expect may resolve a number of outstanding connection handling and timeout issues.

@WenXuanYuan: Please attempt reproducing your original problem with 1.2.0alpha2 and let us know if the issue persists. Thanks!

hasansy commented 8 years ago

@jmikola I have the same issue as @WenXuanYuan and I tried using 1.2.0alpha2 but its still the same.

the error shows randomly, so I thought it maybe a connection problem so I tried to add the connection in a loop, it works fine and connect every time but it take long time to connect. it fails to connect 3 times but the forth one it connect, below what I did.

for ($i = 0; $i < 10; $i++) {
    try {
        $this->manager = new Manager($uri, $uriOptions, $driverOptions);
        $command=new Command(array('ping'=>1));
        $this->manager->executeCommand('db',$command);
    } catch (ConnectionTimeoutException $e) {
        if ($i==10) { echo "Error:", $e->getMessage(), "\n"; }
    }
}
udoless commented 7 years ago

I have the same issue, and I use retry to avoid this problem temporarily. Waiting the solution!😫

The code:

$options = [
    'connectTimeoutMS' => 2000,
    'socketTimeoutMSG' => 3000,
    'readPreference'   => MongoDB\Driver\ReadPreference::RP_SECONDARY_PREFERRED
];
$manager = new MongoDB\Driver\Manager("mongodb://10.77.48.48:27001,10.77.48.49:27001,10.77.48.26:27001,10.77.48.27:27001", $options);
$where   = [
    'user_id' => 1242369332
];
$options = [
    'projection' => [
        'user_id'        => 1,
        'fans_num'       => 1,
        'ugc_follow_num' => 1,
        'pgc_follow_num' => 1,
        '_id'            => 0
    ],
    'limit'      => 1
];
$query   = new MongoDB\Driver\Query($where, $options);
$cursor  = $manager->executeQuery("ugc_user_relation.user_follow_stat", $query);
$cursor->setTypeMap(['root' => 'array']);
var_dump($cursorArray = $cursor->toArray());

The exception(randomly)

No suitable servers found (`serverselectiontryonce` set): [connection error calling ismaster on '10.77.48.48:27001'] [connection error calling ismaster on '10.77.48.49:27001'] [connection error calling ismaster on '10.77.48.27:27001'] [connection error calling ismaster on '10.77.48.47:27001'] [Failed connecting to '10.110.36.24:27001': Connection timed out]

I am also confusing why it call ismaster method and so many times?

jmikola commented 7 years ago

the error shows randomly, so I thought it maybe a connection problem so I tried to add the connection in a loop, it works fine and connect every time but it take long time to connect. it fails to connect 3 times but the forth one it connect, below what I did.

@hasansy: in your code example, you're constructing the a Manager with the same constructor arguments in a loop. In 1.2.0alpha2, each of these Manager instances is going to use the same libmongoc client (which does the actual server communication) and sockets. It would make more sense to issue the ping command in a loop, since that is where the exception would arise.

I don't understand how you can say "it works fine and connect every time but it take long time to connect" and then "it fails to connect 3 times but the forth one it connect". Those statements appear to conflict.

The "connection error calling ismaster" error message is very generic, so we can't be sure that you are experiencing the same exact problem as the OP. Please open a new issue using the template and attempt to provide all of the requested information about your problem. Additionally, feel free to respond to my above comments in your new issue.

@udoless: I would also suggest you open a new issue and fill out the report template. To quickly answer your last question, libmongoc's topology scanner (the component responsible for monitoring all nodes replica set) includes errors for all nodes when reporting its error higher up the chain (e.g. to the PHP driver). You're seeing multiple "ismaster" errors because the driver is unable to connect to each of the four nodes in your connection URI. Expanding your exception message to multiple lines:

No suitable servers found (`serverselectiontryonce` set):
[connection error calling ismaster on '10.77.48.48:27001']
[connection error calling ismaster on '10.77.48.49:27001']
[connection error calling ismaster on '10.77.48.27:27001']
[connection error calling ismaster on '10.77.48.47:27001']
[Failed connecting to '10.110.36.24:27001': Connection timed out]

I have no idea where 10.110.36.24:27001 is coming from, but that's something to discuss in your own GitHub issue.

dwoon commented 7 years ago

I has same problem,No suitable servers found (serverselectiontryonce set). when restart php-fpm it can work well in period of time, then become random appear the error. But when i change php7 to php5, it alway work well . ( version mongodb 1.18 to 1.2.0alpha3 has same problem) ,who can solve the problem? is there persist connect mongdb server that not release? @bjori

dwoon commented 7 years ago

when the error occur, the debug info as below:

[2016-09-27T01:39:39+00:00] socket: TRACE > TRACE: mongoc_socket_sendv():1134 Finished the iovecs [2016-09-27T01:39:39+00:00] socket: TRACE > EXIT: mongoc_socket_sendv():1165 [2016-09-27T01:39:39+00:00] socket: TRACE > TRACE: mongoc_socket_errno():307 Current errno: 0 [2016-09-27T01:39:39+00:00] stream: TRACE > EXIT: _mongoc_stream_socket_writev():208 [2016-09-27T01:39:39+00:00] stream: TRACE > EXIT: mongoc_stream_writev():164 [2016-09-27T01:39:39+00:00] stream: TRACE > ENTRY: _mongoc_stream_socket_poll():226 [2016-09-27T01:39:39+00:00] socket: TRACE > ENTRY: mongoc_socket_poll():217 [2016-09-27T01:39:39+00:00] stream: TRACE > EXIT: _mongoc_stream_socket_poll():252 [2016-09-27T01:39:39+00:00] stream: TRACE > ENTRY: mongoc_stream_failed():79 [2016-09-27T01:39:39+00:00] stream: TRACE > ENTRY: _mongoc_stream_socket_failed():89 [2016-09-27T01:39:39+00:00] stream: TRACE > ENTRY: _mongoc_stream_socket_destroy():71 [2016-09-27T01:39:39+00:00] socket: TRACE > ENTRY: mongoc_socket_close():531 [2016-09-27T01:39:39+00:00] socket: TRACE > EXIT: mongoc_socket_close():556 [2016-09-27T01:39:39+00:00] stream: TRACE > EXIT: _mongoc_stream_socket_destroy():82 [2016-09-27T01:39:39+00:00] stream: TRACE > EXIT: _mongoc_stream_socket_failed():93 [2016-09-27T01:39:39+00:00] stream: TRACE > EXIT: mongoc_stream_failed():89 [2016-09-27T01:39:39+00:00] mongoc: TRACE > ENTRY: mongoc_server_description_handle_ismaster():472 [2016-09-27T01:39:39+00:00] mongoc: TRACE > EXIT: mongoc_server_description_handle_ismaster():478 [2016-09-27T01:39:39+00:00] mongoc: TRACE > TRACE: mongoc_topology_description_handle_ismaster():1648 No transition entry to Single for Unknown [2016-09-27T01:39:39+00:00] mongoc: TRACE > ENTRY: mongoc_topology_description_select():669 [2016-09-27T01:39:39+00:00] mongoc: TRACE > EXIT: mongoc_topology_description_select():682 [2016-09-27T01:39:39+00:00] cluster: TRACE > EXIT: _mongoc_cluster_stream_for_optype():1817 [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: _mongoc_cursor_fetch_stream():543 [2016-09-27T01:39:39+00:00] cursor: TRACE > GOTO: _mongoc_cursor_initial_query():574 done [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: _mongoc_cursor_initial_query():603 [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: _mongoc_cursor_next():1734 [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: mongoc_cursor_next():1653 [2016-09-27T01:39:39+00:00] cursor: TRACE > ENTRY: mongoc_cursor_error():1568 [2016-09-27T01:39:39+00:00] cursor: TRACE > ENTRY: _mongoc_cursor_error():1586 [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: _mongoc_cursor_error():1596 [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: mongoc_cursor_error():1578 [2016-09-27T01:39:39+00:00] cursor: TRACE > ENTRY: mongoc_cursor_destroy():463 [2016-09-27T01:39:39+00:00] cursor: TRACE > ENTRY: _mongoc_cursor_destroy():480 [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: _mongoc_cursor_destroy():517 [2016-09-27T01:39:39+00:00] cursor: TRACE > EXIT: mongoc_cursor_destroy():473 [2016-09-27T01:39:39+00:00] mongoc: DEBUG > Not destroying persistent client for Manager

dwoon commented 7 years ago

below picture,left is the error debug info , right is correct debug info ! Is the pfm save the connect to mongodb service? can support the public api to manager ,which can close connected tcp .

1

udoless commented 7 years ago

@jmikola I don't set replicaSet parameter, why libmongoc's topology scanner calls ismaster as well?

Or can I disable this feature(scan nodes)?

jmikola commented 7 years ago

@dwoon: I just asked two other folks to open separate issues instead of piling onto this ticket. Please do the same and copy the information in your previous comments over to that new issue. The exception message in this issue ("No suitable servers found") is very generic and can encompass a range of network issues.

@udoless: isMaster is a generic command used to obtain information about a mongod instance. It is the primary command used for all monitoring purposes (standalone, replica set, and sharding). Monitoring (i.e. SDAM) is a required component of the driver and cannot be disabled.

If you are actually connecting to a replica set, you should absolutely be using the replicaSet parameter. It is not required in the new driver but it is strongly encouraged. This hints to libmongoc that we're expecting a replica set topology (although it can determine that on its own after talking to some seed list members) but more importantly enforces an expected replica set name, which libmongoc will use to restrict the nodes that it communicates with. The restriction benefit is important if you inadvertently had nodes from the different replica sets in the same seedlist or encountered a network misconfiguration down the line that caused the driver to pick up another replica set's member by mistake.

jmikola commented 7 years ago

Note: we've just released 1.1.9, which includes a back-ported fix (in libmongoc) for spurious timeouts ""No suitable servers found" exceptions when one or more replica sets nodes were inaccessible. The bug was specific to the PHP stream API integration, so it does not apply to version 1.2.0alpha2 and later.

Since this issue has been sitting for some time without confirmation, I'm going to close it out. Feel free to follow-up here or open a new issue as needed.

slav123 commented 7 years ago

bit late, but in my case helped when I extended $options = ['ssl' => true]; $manager = new MongoDB\Driver\Manager("mongodb://...", $options);

djordn commented 7 years ago

Hi, everyone!

@slav123, that tip was so useful. But for me, use false in SSL option fixed the issue.

$options = ['ssl' => false ];

I didn't see that message anymore.

colorvamp commented 6 years ago

I suffer from this too randomly in a local connection

No suitable servers found (serverSelectionTryOnce set): [connection timeout calling ismaster on 'localhost:27021']

I have a pure mongo database in ram (dbpath = /dev/shm/mongo) so I think io should not be the problem, and the mongo %cpu when it occurs is negligible. I use nginx and fpm-prefork.

The solution proposed from @djordn unfortunately doesnt work for me. I was a big fan of mongo, the old driver worked like a charm, but as time goes on I am increasingly disappointed with the new one. IMHO the lost of the connection pool the old driver implemented was a big loss.

derickr commented 6 years ago

@sombra2eternity — Please open a new ticket, and we'd be happy to have a look. As a note though, the PHP driver never had a (working) connection pool.

zhaowynn commented 5 years ago

Personally, its best to restart httpserver after mongodb upgrade or restart.

Synida commented 4 years ago

I had the same issue, then I followed the description, and seached for other sollutions too, but the problem stayed the same. Since this was the first page poped up in google I have to leave the solution here for my case: sudo setsebool -P httpd_can_network_connect on I hope it will help on someone

kushank1207 commented 2 years ago

(https://stackoverflow.com/posts/67327137/timeline)

It is because your IP address is not whitelisted . Go to network access in your mongodb atlas in your project and ADD IP ADDRESS. to test just add access from anywhere option there you go get back and try again with the connection string. This worked for me.