doctrine / mongodb-odm

The Official PHP MongoDB ORM/ODM
https://www.doctrine-project.org/projects/doctrine-mongodb-odm/en/latest/
MIT License
1.09k stars 504 forks source link

Drop a capped collection #1745

Closed acrozes closed 11 months ago

acrozes commented 6 years ago

Using drop functions from Doctrine\ODM\MongoDB\SchemaManager on a capped collection return now an error with mongoDB 3.6:

cannot remove from a capped collection: collectionName => drop collection

So how to remove a capped collection ? Thank you

malarzm commented 6 years ago

From what I see in MongoDB documentation drop() should work just fine with capped collections, can you please create a failing test case?

jmikola commented 6 years ago

As discussed in Document Deletion, individual documents cannot be removed but there should be no issue dropping the collection itself.

Best I can tell, when SchemaCollection drops a document collection, it ultimately invokes MongoCollection::drop() through Doctrine/MongoDB/Collection, which should still be compatible with MongoDB 3.6.

acrozes commented 6 years ago

Versions: php: 7.2 sf 3.4.4 mongodb/mongodb: 1.3.0 doctrine/mongodb-odm-bundle: 3.4.1 doctrine/mongodb-odm: 1.2.1 doctrine/mongodb: 1.6.1 alcaeus/mongo-php-adapter: 1.1.4

Document:

use Doctrine\ODM\MongoDB\Mapping\Annotations as MongoDB;

/**
 * @MongoDB\Document(
 *  collection={
 *   "name"="logs",
 *   "capped"=true,
 *   "size"=1073741824,
 *   "max"=3000000
 *  }
 * )
 */
class Log
{
    /**
     * @MongoDB\Id
     */
    protected $id;
[...]

The command I execute and that failed:

    protected function execute(InputInterface $input, OutputInterface $output): void
    {
        // TODO fix dropDocumentCollection for capped collection
        $this->dm->getSchemaManager()->dropDocumentCollection(Log::class);
        $this->dm->getSchemaManager()->dropDocumentDatabase(Log::class);
        $this->dm->getSchemaManager()->dropDatabases();
    }

The three called failed: dropDocumentCollection, dropDocumentDatabase or dropDatabases with message: cannot remove from a capped collection

jmikola commented 6 years ago

I'm unable to reproduce with the following environment and test case:

<?php

namespace Doctrine\ODM\MongoDB\Tests\Functional;

use Doctrine\ODM\MongoDB\Mapping\Annotations as ODM;

class GH1745Test extends \Doctrine\ODM\MongoDB\Tests\BaseTest
{
    public function testCreateCollectionsCapped()
    {
        $sm = $this->dm->getSchemaManager();
        $sm->dropDocumentCollection(GH1745Document::class);
        $sm->createDocumentCollection(GH1745Document::class);

        foreach (['a', 'b', 'c'] as $username) {
            $document = new GH1745Document;
            $document->username = $username;
            $this->dm->persist($document);
        }

        $this->dm->flush();

        $coll = $this->dm->getDocumentCollection(GH1745Document::class);
        $this->assertCount(3, $coll->find()->toArray());
exit;
        $this->dm->getSchemaManager()->dropDocumentCollection(GH1745Document::class);
        $this->dm->getSchemaManager()->dropDocumentDatabase(GH1745Document::class);
        $this->dm->getSchemaManager()->dropDatabases();
    }
}

/**
 * @ODM\Document(collection={
 *   "name"="GH1745Document",
 *   "capped"=true,
 *   "size"=1073741824,
 *   "max"=3000000
 * })
 */
class GH1745Document
{
    /** @ODM\Id */
    public $id;

    /** @ODM\Field(type="string") */
    public $username;
}

If I interrupt the script with exit() before invoking the drop methods on the SchemaManager, I can verify that the following capped collection exists on the server:

> db.getSiblingDB('doctrine_odm_tests').getCollectionInfos()
[
    {
        "name" : "GH1745Document",
        "type" : "collection",
        "options" : {
            "capped" : true,
            "size" : 1073741824,
            "max" : 3000000
        },
        "info" : {
            "readOnly" : false,
            "uuid" : UUID("8cd3b2a2-f270-4b8c-bfb7-bdffda197eaf")
        },
        "idIndex" : {
            "v" : 2,
            "key" : {
                "_id" : 1
            },
            "name" : "_id_",
            "ns" : "doctrine_odm_tests.GH1745Document"
        }
    }
]

The error message "cannot remove from a capped collection" evidently originates from the server and appears twice in its code base:

The message templating in collection_impl.cpp does not report the collection name after a colon (although the mongod logging on the preceding line does), so I assume this is originating from get_executor.cpp. Following the rabbit hole, getExecutorDelete() is called from three places:

write_commands.cpp relates to explaining a delete command, storage_interface_impl.cpp is related to internal replication, and find_and_modify.cpp is self-explanatory. I don't think these are relevant.

delete.cpp contains a helper function called deleteObjects(), which is used internally by replication (mostly to delete the "local.me" namespace from what I can tell). That leaves write_ops_exec.cpp, which is related to the code path of a delete command.

That said, I still see no evidence of delete being called in this issue, as the schema managers use drop commands.

The three called failed: dropDocumentCollection, dropDocumentDatabase or dropDatabases with message: cannot remove from a capped collection

What is the complete exception (message and integer code) and full back trace? On the off chance that contains some useful information, my next question is going to be why wasn't that included in the original post.

acrozes commented 6 years ago

Thank you for your work. I manualy drop the database and now I'm unable to reproduce it. Something more strange is that the collection was not capped in mongoDb, so the message was completly incomprehensible ! This is true that we can have defined a capped collection and when the collection is really created in mongoDb by default the collection is not capped ...

jmikola commented 6 years ago

Are you still able to share the complete exception and back trace, or are we never going to get to see that? I was very much looking forward to seeing that, as it'd have cleared up a lot of questions.

Something more strange is that the collection was not capped in mongoDb, so the message was completly incomprehensible !

If the MongoDB collection was not capped, I can think of no reason for "cannot remove from a capped collection" to appear. This issue is missing too many details.

It was helpful for you to provide version information in https://github.com/doctrine/mongodb-odm/issues/1745#issuecomment-368189467, but ideally that should appear in the original post. Additionally, you should provide details about the MongoDB deployment, connection URI/options, and above all else: the exception message and back trace. Please keep this in mind in the future.

This is true that we can have defined a capped collection and when the collection is really created in mongoDb by default the collection is not capped ...

AFAIK, the collection options in ODM are only used by the SchemaManager classes and it is your responsibility to run the schema commands.

If you create new objects for a model class that defines collection.capped=true and persist those with the DocumentManager, ODM will simply execute an insert operation as it has no way of knowing whether the collection exists or not. To that end, inserting a document into a non-existent collection will see MongoDB create a basic collection (standard behavior for the database).

While ODM theoretically could check for the existence of a collection (e.g. call the equivalent of getCollectionInfos() in the shell) and verify that its options match the metadata, doing this before write operations would incur significant overhead.

acrozes commented 6 years ago

I'm sorry, I haven't more logs when the erreur occur and the collection was drop with the database after I rename it and try again the command :( The collection was created on MongoDB 3.4 or maybe 3.2 and now I am on 3.6 so maybe the error is in link with changing version ... If that can help you, 2 more informations:

jmikola commented 6 years ago

According to printCollectionStats(), the acmonologlogs.ac_monolog_logs collection is not capped.

From the mongodb.debug trace logs, we see following commands run:

The trace cuts off before we see the response to the create command.

I have no idea what bin/console ac:monolog:create --env=prod is. I found no record of any collection management in the monolog repository. There is only a handler class responsible for inserting log entries. Assuming this is your custom console command alluded to in https://github.com/doctrine/mongodb-odm/issues/1745#issuecomment-368189467, the trace logs we see (drop followed by create) doesn't agree with the source you shared above.

Thinking ahead, it seems possible that you may be trying to manage the schema of this log collection from within the same app that is actively logging while doing so. If so, I'd suggest doing this outside of the application (e.g. use the MongoDB shell) or ensure that the console command in question disables logging completely. Considering Monolog uses the extension/library directly to insert log messages, mapping them in ODM sounds like over-architecting.

acrozes commented 6 years ago

The logs until the error:


[2018-02-28T02:32:05.621268+00:00]     PHONGO: DEBUG   > Connection string: 'mongodb://127.0.0.1:27017'
[2018-02-28T02:32:05.621339+00:00]     PHONGO: DEBUG   > Creating Manager, phongo-1.4.1[stable] - mongoc-1.9.2(bundled), libbson-1.9.2(bundled), php-7.2.1-dev
[2018-02-28T02:32:05.621386+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_init():75
[2018-02-28T02:32:05.630186+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_init():94
[2018-02-28T02:32:05.630310+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_init():104
[2018-02-28T02:32:05.630349+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_init():123
[2018-02-28T02:32:05.630407+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_init():1867
[2018-02-28T02:32:05.630446+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_init():1894
[2018-02-28T02:32:05.630483+00:00]     PHONGO: DEBUG   > Created client hash: a:4:{s:3:"pid";i:4128;s:3:"uri";s:25:"mongodb://127.0.0.1:27017";s:7:"options";a:0:{}s:13:"driverOptions";a:0:{}}

[2018-02-28T02:32:05.649817+00:00] topology_scanner: TRACE   > ENTRY: mongoc_topology_scanner_node_connect_tcp():468
[2018-02-28T02:32:05.649908+00:00]     socket: TRACE   > ENTRY: mongoc_socket_new():977
[2018-02-28T02:32:05.650388+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_setnodelay():556
[2018-02-28T02:32:05.650448+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_setnodelay():568
[2018-02-28T02:32:05.650470+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_setkeepalive():521
[2018-02-28T02:32:05.650503+00:00]     socket: TRACE   > TRACE: _mongoc_socket_setkeepalive():525 Setting SO_KEEPALIVE
[2018-02-28T02:32:05.650671+00:00]     socket: TRACE   > TRACE: _mongoc_socket_setkeepalive_windows():420 KeepAlive values updated
[2018-02-28T02:32:05.650721+00:00]     socket: TRACE   > TRACE: _mongoc_socket_setkeepalive_windows():421 KeepAliveTime: 300000
[2018-02-28T02:32:05.650758+00:00]     socket: TRACE   > TRACE: _mongoc_socket_setkeepalive_windows():422 KeepAliveInterval: 1000
[2018-02-28T02:32:05.650794+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_setkeepalive():537
[2018-02-28T02:32:05.650830+00:00]     socket: TRACE   >  EXIT: mongoc_socket_new():1009
[2018-02-28T02:32:05.650866+00:00]     socket: TRACE   > ENTRY: mongoc_socket_connect():840
[2018-02-28T02:32:05.651586+00:00]     socket: TRACE   > TRACE: _mongoc_socket_capture_errno():68 setting errno: 10035 Unknown error
[2018-02-28T02:32:05.651680+00:00]     socket: TRACE   > TRACE: _mongoc_socket_errno_is_again():617 errno is: 10035
[2018-02-28T02:32:05.651747+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_wait():148
[2018-02-28T02:32:05.651868+00:00]     socket: TRACE   >  EXIT: mongoc_socket_connect():865
[2018-02-28T02:32:05.651987+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_poll():223
[2018-02-28T02:32:05.652027+00:00]     socket: TRACE   > ENTRY: mongoc_socket_poll():283
[2018-02-28T02:32:05.652081+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_poll():249
[2018-02-28T02:32:05.652131+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():150
[2018-02-28T02:32:05.652177+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():162 writev = 0000000752C2BD50 [9]
[2018-02-28T02:32:05.652299+00:00]     stream: TRACE   > 00000:  50 01 00 00 01 00 00 00  00 00 00 00 d4 07 00 00  P . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.652428+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 . .
[2018-02-28T02:32:05.652547+00:00]     stream: TRACE   > 00020:  00 00 00 ff ff ff ff 29  01 00 00 10 69 73 4d 61  . . . . . . . )  . . . . i s M a
[2018-02-28T02:32:05.652657+00:00]     stream: TRACE   > 00030:  73 74 65 72 00 01 00 00  00 03 63 6c 69 65 6e 74  s t e r . . . .  . . c l i e n t
[2018-02-28T02:32:05.652771+00:00]     stream: TRACE   > 00040:  00 fc 00 00 00 03 64 72  69 76 65 72 00 43 00 00  . . . . . . d r  i v e r . C . .
[2018-02-28T02:32:05.652880+00:00]     stream: TRACE   > 00050:  00 02 6e 61 6d 65 00 19  00 00 00 6d 6f 6e 67 6f  . . n a m e . .  . . . m o n g o
[2018-02-28T02:32:05.653013+00:00]     stream: TRACE   > 00060:  63 20 2f 20 65 78 74 2d  6d 6f 6e 67 6f 64 62 3a  c   /   e x t -  m o n g o d b :
[2018-02-28T02:32:05.653131+00:00]     stream: TRACE   > 00070:  50 48 50 00 02 76 65 72  73 69 6f 6e 00 0e 00 00  P H P . . v e r  s i o n . . . .
[2018-02-28T02:32:05.653265+00:00]     stream: TRACE   > 00080:  00 31 2e 39 2e 32 20 2f  20 31 2e 34 2e 31 00 00  . 1 . 9 . 2   /    1 . 4 . 1 . .
[2018-02-28T02:32:05.653385+00:00]     stream: TRACE   > 00090:  03 6f 73 00 5a 00 00 00  02 74 79 70 65 00 08 00  . o s . Z . . .  . t y p e . . .
[2018-02-28T02:32:05.653516+00:00]     stream: TRACE   > 000a0:  00 00 57 69 6e 64 6f 77  73 00 02 6e 61 6d 65 00  . . W i n d o w  s . . n a m e .
[2018-02-28T02:32:05.653642+00:00]     stream: TRACE   > 000b0:  08 00 00 00 57 69 6e 64  6f 77 73 00 02 76 65 72  . . . . W i n d  o w s . . v e r
[2018-02-28T02:32:05.653767+00:00]     stream: TRACE   > 000c0:  73 69 6f 6e 00 0b 00 00  00 36 2e 33 20 28 39 36  s i o n . . . .  . 6 . 3   ( 9 6
[2018-02-28T02:32:05.653911+00:00]     stream: TRACE   > 000d0:  30 30 29 00 02 61 72 63  68 69 74 65 63 74 75 72  0 0 ) . . a r c  h i t e c t u r
[2018-02-28T02:32:05.654032+00:00]     stream: TRACE   > 000e0:  65 00 07 00 00 00 78 38  36 5f 36 34 00 00 02 70  e . . . . . x 8  6 _ 6 4 . . . p
[2018-02-28T02:32:05.654159+00:00]     stream: TRACE   > 000f0:  6c 61 74 66 6f 72 6d 00  40 00 00 00 63 66 67 3d  l a t f o r m .  @ . . . c f g =
[2018-02-28T02:32:05.654293+00:00]     stream: TRACE   > 00100:  30 78 34 30 32 61 30 65  39 20 43 43 3d 4d 53 56  0 x 4 0 2 a 0 e  9   C C = M S V
[2018-02-28T02:32:05.654425+00:00]     stream: TRACE   > 00110:  43 20 31 39 31 32 20 43  46 4c 41 47 53 3d 22 22  C   1 9 1 2   C  F L A G S = " "
[2018-02-28T02:32:05.654562+00:00]     stream: TRACE   > 00120:  20 4c 44 46 4c 41 47 53  3d 22 22 20 2f 20 50 48    L D F L A G S  = " "   /   P H
[2018-02-28T02:32:05.654693+00:00]     stream: TRACE   > 00130:  50 20 37 2e 32 2e 31 2d  64 65 76 00 00 04 63 6f  P   7 . 2 . 1 -  d e v . . . c o
[2018-02-28T02:32:05.654816+00:00]     stream: TRACE   > 00140:  6d 70 72 65 73 73 69 6f  6e 00 05 00 00 00 00 00  m p r e s s i o  n . . . . . . .
[2018-02-28T02:32:05.654868+00:00]     stream: TRACE   >
[2018-02-28T02:32:05.654912+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_writev():199
[2018-02-28T02:32:05.654953+00:00]     socket: TRACE   > ENTRY: mongoc_socket_sendv():1351
[2018-02-28T02:32:05.654994+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_try_sendv():1256
[2018-02-28T02:32:05.655039+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1262 sendbuf = 0000000752C13190 [9]
[2018-02-28T02:32:05.655146+00:00]     socket: TRACE   > 00000:  50 01 00 00 01 00 00 00  00 00 00 00 d4 07 00 00  P . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.655273+00:00]     socket: 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 . .
[2018-02-28T02:32:05.655390+00:00]     socket: TRACE   > 00020:  00 00 00 ff ff ff ff 29  01 00 00 10 69 73 4d 61  . . . . . . . )  . . . . i s M a
[2018-02-28T02:32:05.655515+00:00]     socket: TRACE   > 00030:  73 74 65 72 00 01 00 00  00 03 63 6c 69 65 6e 74  s t e r . . . .  . . c l i e n t
[2018-02-28T02:32:05.655639+00:00]     socket: TRACE   > 00040:  00 fc 00 00 00 03 64 72  69 76 65 72 00 43 00 00  . . . . . . d r  i v e r . C . .
[2018-02-28T02:32:05.655764+00:00]     socket: TRACE   > 00050:  00 02 6e 61 6d 65 00 19  00 00 00 6d 6f 6e 67 6f  . . n a m e . .  . . . m o n g o
[2018-02-28T02:32:05.655902+00:00]     socket: TRACE   > 00060:  63 20 2f 20 65 78 74 2d  6d 6f 6e 67 6f 64 62 3a  c   /   e x t -  m o n g o d b :
[2018-02-28T02:32:05.656027+00:00]     socket: TRACE   > 00070:  50 48 50 00 02 76 65 72  73 69 6f 6e 00 0e 00 00  P H P . . v e r  s i o n . . . .
[2018-02-28T02:32:05.656160+00:00]     socket: TRACE   > 00080:  00 31 2e 39 2e 32 20 2f  20 31 2e 34 2e 31 00 00  . 1 . 9 . 2   /    1 . 4 . 1 . .
[2018-02-28T02:32:05.656279+00:00]     socket: TRACE   > 00090:  03 6f 73 00 5a 00 00 00  02 74 79 70 65 00 08 00  . o s . Z . . .  . t y p e . . .
[2018-02-28T02:32:05.656406+00:00]     socket: TRACE   > 000a0:  00 00 57 69 6e 64 6f 77  73 00 02 6e 61 6d 65 00  . . W i n d o w  s . . n a m e .
[2018-02-28T02:32:05.656533+00:00]     socket: TRACE   > 000b0:  08 00 00 00 57 69 6e 64  6f 77 73 00 02 76 65 72  . . . . W i n d  o w s . . v e r
[2018-02-28T02:32:05.656665+00:00]     socket: TRACE   > 000c0:  73 69 6f 6e 00 0b 00 00  00 36 2e 33 20 28 39 36  s i o n . . . .  . 6 . 3   ( 9 6
[2018-02-28T02:32:05.656776+00:00]     socket: TRACE   > 000d0:  30 30 29 00 02 61 72 63  68 69 74 65 63 74 75 72  0 0 ) . . a r c  h i t e c t u r
[2018-02-28T02:32:05.656857+00:00]     socket: TRACE   > 000e0:  65 00 07 00 00 00 78 38  36 5f 36 34 00 00 02 70  e . . . . . x 8  6 _ 6 4 . . . p
[2018-02-28T02:32:05.656944+00:00]     socket: TRACE   > 000f0:  6c 61 74 66 6f 72 6d 00  40 00 00 00 63 66 67 3d  l a t f o r m .  @ . . . c f g =
[2018-02-28T02:32:05.657037+00:00]     socket: TRACE   > 00100:  30 78 34 30 32 61 30 65  39 20 43 43 3d 4d 53 56  0 x 4 0 2 a 0 e  9   C C = M S V
[2018-02-28T02:32:05.657126+00:00]     socket: TRACE   > 00110:  43 20 31 39 31 32 20 43  46 4c 41 47 53 3d 22 22  C   1 9 1 2   C  F L A G S = " "
[2018-02-28T02:32:05.657265+00:00]     socket: TRACE   > 00120:  20 4c 44 46 4c 41 47 53  3d 22 22 20 2f 20 50 48    L D F L A G S  = " "   /   P H
[2018-02-28T02:32:05.657922+00:00]     socket: TRACE   > 00130:  50 20 37 2e 32 2e 31 2d  64 65 76 00 00 04 63 6f  P   7 . 2 . 1 -  d e v . . . c o
[2018-02-28T02:32:05.658112+00:00]     socket: TRACE   > 00140:  6d 70 72 65 73 73 69 6f  6e 00 05 00 00 00 00 00  m p r e s s i o  n . . . . . . .
[2018-02-28T02:32:05.658247+00:00]     socket: TRACE   >
[2018-02-28T02:32:05.658971+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1270 WSASend sent: 336 (out of: 4), ret: 0
[2018-02-28T02:32:05.659413+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_try_sendv():1310
[2018-02-28T02:32:05.659542+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1363 Sent 336 (of 4) out of iovcnt=9
[2018-02-28T02:32:05.659590+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 336 -= 4
[2018-02-28T02:32:05.659633+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 332 -= 4
[2018-02-28T02:32:05.659677+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 328 -= 4
[2018-02-28T02:32:05.659716+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 324 -= 4
[2018-02-28T02:32:05.659754+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 320 -= 4
[2018-02-28T02:32:05.659794+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 316 -= 11
[2018-02-28T02:32:05.659832+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 305 -= 4
[2018-02-28T02:32:05.659871+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 301 -= 4
[2018-02-28T02:32:05.659910+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 297 -= 297
[2018-02-28T02:32:05.659947+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1399 Finished the iovecs
[2018-02-28T02:32:05.659988+00:00]     socket: TRACE   >  EXIT: mongoc_socket_sendv():1431
[2018-02-28T02:32:05.660029+00:00]     socket: TRACE   > TRACE: mongoc_socket_errno():592 Current errno: 10035
[2018-02-28T02:32:05.660062+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_writev():205
[2018-02-28T02:32:05.660099+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():165
[2018-02-28T02:32:05.660139+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_poll():223
[2018-02-28T02:32:05.660170+00:00]     socket: TRACE   > ENTRY: mongoc_socket_poll():283
[2018-02-28T02:32:05.660229+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_poll():249
[2018-02-28T02:32:05.660279+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_try_append_from_stream():336
[2018-02-28T02:32:05.660305+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:05.660339+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:05.660371+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:05.660405+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:05.660451+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:05.660485+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:05.660526+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066DAC0 [1]
[2018-02-28T02:32:05.660599+00:00]     stream: TRACE   > 00000:  cd 00 00 00                                       . . . .
[2018-02-28T02:32:05.660628+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:05.660659+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:05.660692+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_try_append_from_stream():368
[2018-02-28T02:32:05.660725+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_try_append_from_stream():336
[2018-02-28T02:32:05.660753+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:05.660788+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:05.660822+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:05.660857+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:05.660900+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:05.660933+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:05.660977+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066DAC0 [1]
[2018-02-28T02:32:05.661061+00:00]     stream: TRACE   > 00000:  bc cf 03 00 01 00 00 00  01 00 00 00 08 00 00 00  . . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.661136+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 00 00 00  00 00 00 00 01 00 00 00  . . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.661224+00:00]     stream: TRACE   > 00020:  a9 00 00 00 08 69 73 6d  61 73 74 65 72 00 01 10  . . . . . i s m  a s t e r . . .
[2018-02-28T02:32:05.661316+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
[2018-02-28T02:32:05.661400+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
[2018-02-28T02:32:05.661493+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 . . .
[2018-02-28T02:32:05.661683+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
[2018-02-28T02:32:05.661836+00:00]     stream: TRACE   > 00070:  65 00 a0 86 01 00 09 6c  6f 63 61 6c 54 69 6d 65  e . . . . . . l  o c a l T i m e
[2018-02-28T02:32:05.661966+00:00]     stream: TRACE   > 00080:  00 1b a7 40 da 61 01 00  00 10 6d 69 6e 57 69 72  . . . @ . a . .  . . m i n W i r
[2018-02-28T02:32:05.662093+00:00]     stream: TRACE   > 00090:  65 56 65 72 73 69 6f 6e  00 00 00 00 00 10 6d 61  e V e r s i o n  . . . . . . m a
[2018-02-28T02:32:05.662224+00:00]     stream: TRACE   > 000a0:  78 57 69 72 65 56 65 72  73 69 6f 6e 00 06 00 00  x W i r e V e r  s i o n . . . .
[2018-02-28T02:32:05.662349+00:00]     stream: TRACE   > 000b0:  00 08 72 65 61 64 4f 6e  6c 79 00 00 01 6f 6b 00  . . r e a d O n  l y . . . o k .
[2018-02-28T02:32:05.662459+00:00]     stream: TRACE   > 000c0:  00 00 00 00 00 00 f0 3f  00                       . . . . . . . ?  .
[2018-02-28T02:32:05.662506+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:05.662564+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:05.662613+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_try_append_from_stream():368
[2018-02-28T02:32:05.662683+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.662743+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.662804+00:00]     mongoc: TRACE   > TRACE: mongoc_topology_description_handle_ismaster():1955 No transition entry to Single for Standalone
[2018-02-28T02:32:05.662866+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():798
[2018-02-28T02:32:05.662906+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():805
[2018-02-28T02:32:05.662955+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.663007+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.663047+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.663088+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.663158+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.663214+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.663275+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.663315+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.663417+00:00]     client: TRACE   > ENTRY: _mongoc_client_command_with_opts():1724
[2018-02-28T02:32:05.663473+00:00]     mongoc: TRACE   > ENTRY: _mongoc_get_server_id_from_opts():268
[2018-02-28T02:32:05.663513+00:00]     mongoc: TRACE   >  EXIT: _mongoc_get_server_id_from_opts():291
[2018-02-28T02:32:05.663567+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1650
[2018-02-28T02:32:05.663651+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server():1591
[2018-02-28T02:32:05.663713+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.663767+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.663820+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server():1617
[2018-02-28T02:32:05.663861+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1667
[2018-02-28T02:32:05.663911+00:00]     mongoc: TRACE   > ENTRY: mongoc_cmd_parts_append_opts():119
[2018-02-28T02:32:05.663953+00:00]     mongoc: TRACE   >  EXIT: mongoc_cmd_parts_append_opts():202
[2018-02-28T02:32:05.664000+00:00]     client: TRACE   > ENTRY: _mongoc_client_command_with_stream():1603
[2018-02-28T02:32:05.664041+00:00]     mongoc: TRACE   > ENTRY: mongoc_cmd_parts_assemble():564
[2018-02-28T02:32:05.664084+00:00]     mongoc: TRACE   > TRACE: mongoc_cmd_parts_assemble():592 Preparing 'listCollections'
[2018-02-28T02:32:05.664153+00:00]     client: TRACE   > ENTRY: mongoc_client_start_session():1150
[2018-02-28T02:32:05.664193+00:00]     mongoc: TRACE   > ENTRY: _mongoc_topology_pop_server_session():1288
[2018-02-28T02:32:05.664244+00:00]     mongoc: TRACE   >  EXIT: _mongoc_topology_pop_server_session():1314
[2018-02-28T02:32:05.664292+00:00]     client: TRACE   >  EXIT: mongoc_client_start_session():1154
[2018-02-28T02:32:05.664331+00:00]     mongoc: TRACE   >  EXIT: mongoc_cmd_parts_assemble():704
[2018-02-28T02:32:05.664370+00:00]     client: TRACE   >  EXIT: _mongoc_client_command_with_stream():1617
[2018-02-28T02:32:05.664443+00:00]    cluster: TRACE   > TRACE: mongoc_cluster_run_opmsg():2561 Function 'listCollections' is compressible: -1
[2018-02-28T02:32:05.664486+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():502
[2018-02-28T02:32:05.664526+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():150
[2018-02-28T02:32:05.664576+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():162 writev = 0000000752C25940 [7]
[2018-02-28T02:32:05.664697+00:00]     stream: TRACE   > 00000:  77 00 00 00 02 00 00 00  00 00 00 00 dd 07 00 00  w . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.664826+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 62 00 00  00 10 6c 69 73 74 43 6f  . . . . . b . .  . . l i s t C o
[2018-02-28T02:32:05.664950+00:00]     stream: TRACE   > 00020:  6c 6c 65 63 74 69 6f 6e  73 00 01 00 00 00 02 24  l l e c t i o n  s . . . . . . $
[2018-02-28T02:32:05.665099+00:00]     stream: TRACE   > 00030:  64 62 00 0e 00 00 00 61  63 6d 6f 6e 6f 6c 6f 67  d b . . . . . a  c m o n o l o g
[2018-02-28T02:32:05.665232+00:00]     stream: TRACE   > 00040:  6c 6f 67 73 00 03 24 72  65 61 64 50 72 65 66 65  l o g s . . $ r  e a d P r e f e
[2018-02-28T02:32:05.665361+00:00]     stream: TRACE   > 00050:  72 65 6e 63 65 00 20 00  00 00 02 6d 6f 64 65 00  r e n c e .   .  . . . m o d e .
[2018-02-28T02:32:05.665493+00:00]     stream: TRACE   > 00060:  11 00 00 00 70 72 69 6d  61 72 79 50 72 65 66 65  . . . . p r i m  a r y P r e f e
[2018-02-28T02:32:05.665679+00:00]     stream: TRACE   > 00070:  72 72 65 64 00 00 00                              r r e d . . .
[2018-02-28T02:32:05.665761+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_writev():199
[2018-02-28T02:32:05.665874+00:00]     socket: TRACE   > ENTRY: mongoc_socket_sendv():1351
[2018-02-28T02:32:05.665920+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_try_sendv():1256
[2018-02-28T02:32:05.665967+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1262 sendbuf = 00000007526E8FC0 [7]
[2018-02-28T02:32:05.666079+00:00]     socket: TRACE   > 00000:  77 00 00 00 02 00 00 00  00 00 00 00 dd 07 00 00  w . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.666205+00:00]     socket: TRACE   > 00010:  00 00 00 00 00 62 00 00  00 10 6c 69 73 74 43 6f  . . . . . b . .  . . l i s t C o
[2018-02-28T02:32:05.666333+00:00]     socket: TRACE   > 00020:  6c 6c 65 63 74 69 6f 6e  73 00 01 00 00 00 02 24  l l e c t i o n  s . . . . . . $
[2018-02-28T02:32:05.666468+00:00]     socket: TRACE   > 00030:  64 62 00 0e 00 00 00 61  63 6d 6f 6e 6f 6c 6f 67  d b . . . . . a  c m o n o l o g
[2018-02-28T02:32:05.666603+00:00]     socket: TRACE   > 00040:  6c 6f 67 73 00 03 24 72  65 61 64 50 72 65 66 65  l o g s . . $ r  e a d P r e f e
[2018-02-28T02:32:05.666726+00:00]     socket: TRACE   > 00050:  72 65 6e 63 65 00 20 00  00 00 02 6d 6f 64 65 00  r e n c e .   .  . . . m o d e .
[2018-02-28T02:32:05.666853+00:00]     socket: TRACE   > 00060:  11 00 00 00 70 72 69 6d  61 72 79 50 72 65 66 65  . . . . p r i m  a r y P r e f e
[2018-02-28T02:32:05.666935+00:00]     socket: TRACE   > 00070:  72 72 65 64 00 00 00                              r r e d . . .
[2018-02-28T02:32:05.667138+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1270 WSASend sent: 119 (out of: 4), ret: 0
[2018-02-28T02:32:05.667189+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_try_sendv():1310
[2018-02-28T02:32:05.667235+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1363 Sent 119 (of 4) out of iovcnt=7
[2018-02-28T02:32:05.667285+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 119 -= 4
[2018-02-28T02:32:05.667333+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 115 -= 4
[2018-02-28T02:32:05.667379+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 111 -= 4
[2018-02-28T02:32:05.667428+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 107 -= 4
[2018-02-28T02:32:05.667472+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 103 -= 4
[2018-02-28T02:32:05.667517+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 99 -= 1
[2018-02-28T02:32:05.667567+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 98 -= 98
[2018-02-28T02:32:05.667652+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1399 Finished the iovecs
[2018-02-28T02:32:05.667700+00:00]     socket: TRACE   >  EXIT: mongoc_socket_sendv():1431
[2018-02-28T02:32:05.667743+00:00]     socket: TRACE   > TRACE: mongoc_socket_errno():592 Current errno: 0
[2018-02-28T02:32:05.667782+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_writev():205
[2018-02-28T02:32:05.667820+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():165
[2018-02-28T02:32:05.667862+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():509 writev returned: 119
[2018-02-28T02:32:05.667899+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():542
[2018-02-28T02:32:05.667938+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():191
[2018-02-28T02:32:05.667973+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:05.668012+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:05.668047+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:05.668088+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:05.668139+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:05.668180+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:05.668224+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066D1A0 [1]
[2018-02-28T02:32:05.668298+00:00]     stream: TRACE   > 00000:  53 01 00 00                                       S . . .
[2018-02-28T02:32:05.668344+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:05.668374+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:05.668416+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():230
[2018-02-28T02:32:05.668456+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():191
[2018-02-28T02:32:05.668493+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:05.668526+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:05.668569+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:05.668607+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:05.668652+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:05.668692+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:05.668735+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066D1A0 [1]
[2018-02-28T02:32:05.668846+00:00]     stream: TRACE   > 00000:  bd cf 03 00 02 00 00 00  dd 07 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.668970+00:00]     stream: TRACE   > 00010:  00 3e 01 00 00 03 63 75  72 73 6f 72 00 25 01 00  . > . . . . c u  r s o r . % . .
[2018-02-28T02:32:05.669086+00:00]     stream: TRACE   > 00020:  00 12 69 64 00 00 00 00  00 00 00 00 00 02 6e 73  . . i d . . . .  . . . . . . n s
[2018-02-28T02:32:05.669215+00:00]     stream: TRACE   > 00030:  00 23 00 00 00 61 63 6d  6f 6e 6f 6c 6f 67 6c 6f  . # . . . a c m  o n o l o g l o
[2018-02-28T02:32:05.669355+00:00]     stream: TRACE   > 00040:  67 73 2e 24 63 6d 64 2e  6c 69 73 74 43 6f 6c 6c  g s . $ c m d .  l i s t C o l l
[2018-02-28T02:32:05.669490+00:00]     stream: TRACE   > 00050:  65 63 74 69 6f 6e 73 00  04 66 69 72 73 74 42 61  e c t i o n s .  . f i r s t B a
[2018-02-28T02:32:05.669613+00:00]     stream: TRACE   > 00060:  74 63 68 00 dd 00 00 00  03 30 00 d5 00 00 00 02  t c h . . . . .  . 0 . . . . . .
[2018-02-28T02:32:05.669737+00:00]     stream: TRACE   > 00070:  6e 61 6d 65 00 10 00 00  00 61 63 5f 6d 6f 6e 6f  n a m e . . . .  . a c _ m o n o
[2018-02-28T02:32:05.669869+00:00]     stream: TRACE   > 00080:  6c 6f 67 5f 6c 6f 67 73  00 02 74 79 70 65 00 0b  l o g _ l o g s  . . t y p e . .
[2018-02-28T02:32:05.669991+00:00]     stream: TRACE   > 00090:  00 00 00 63 6f 6c 6c 65  63 74 69 6f 6e 00 03 6f  . . . c o l l e  c t i o n . . o
[2018-02-28T02:32:05.670118+00:00]     stream: TRACE   > 000a0:  70 74 69 6f 6e 73 00 25  00 00 00 08 63 61 70 70  p t i o n s . %  . . . . c a p p
[2018-02-28T02:32:05.670235+00:00]     stream: TRACE   > 000b0:  65 64 00 01 01 73 69 7a  65 00 00 00 00 00 00 00  e d . . . s i z  e . . . . . . .
[2018-02-28T02:32:05.670357+00:00]     stream: TRACE   > 000c0:  d0 41 10 6d 61 78 00 c0  c6 2d 00 00 03 69 6e 66  . A . m a x . .  . - . . . i n f
[2018-02-28T02:32:05.670480+00:00]     stream: TRACE   > 000d0:  6f 00 10 00 00 00 08 72  65 61 64 4f 6e 6c 79 00  o . . . . . . r  e a d O n l y .
[2018-02-28T02:32:05.670605+00:00]     stream: TRACE   > 000e0:  00 00 03 69 64 49 6e 64  65 78 00 54 00 00 00 10  . . . i d I n d  e x . T . . . .
[2018-02-28T02:32:05.670721+00:00]     stream: TRACE   > 000f0:  76 00 02 00 00 00 03 6b  65 79 00 0e 00 00 00 10  v . . . . . . k  e y . . . . . .
[2018-02-28T02:32:05.670840+00:00]     stream: TRACE   > 00100:  5f 69 64 00 01 00 00 00  00 02 6e 61 6d 65 00 05  _ i d . . . . .  . . n a m e . .
[2018-02-28T02:32:05.670962+00:00]     stream: TRACE   > 00110:  00 00 00 5f 69 64 5f 00  02 6e 73 00 1e 00 00 00  . . . _ i d _ .  . n s . . . . .
[2018-02-28T02:32:05.671095+00:00]     stream: TRACE   > 00120:  61 63 6d 6f 6e 6f 6c 6f  67 6c 6f 67 73 2e 61 63  a c m o n o l o  g l o g s . a c
[2018-02-28T02:32:05.671229+00:00]     stream: TRACE   > 00130:  5f 6d 6f 6e 6f 6c 6f 67  5f 6c 6f 67 73 00 00 00  _ m o n o l o g  _ l o g s . . .
[2018-02-28T02:32:05.671334+00:00]     stream: TRACE   > 00140:  00 00 01 6f 6b 00 00 00  00 00 00 00 f0 3f 00     . . . o k . . .  . . . . . ? .
[2018-02-28T02:32:05.671379+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:05.671414+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:05.671450+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():230
[2018-02-28T02:32:05.671513+00:00]     mongoc: TRACE   > ENTRY: _mongoc_cmd_check_ok():1089
[2018-02-28T02:32:05.671558+00:00]     mongoc: TRACE   >  EXIT: _mongoc_cmd_check_ok():1095
[2018-02-28T02:32:05.671608+00:00]     client: TRACE   >  GOTO: _mongoc_client_command_with_opts():1828 done
[2018-02-28T02:32:05.671648+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.671688+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.671728+00:00]     client: TRACE   >  EXIT: _mongoc_client_command_with_opts():1844
[2018-02-28T02:32:05.671796+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_new_with_opts():226
[2018-02-28T02:32:05.671843+00:00]     mongoc: TRACE   > ENTRY: _mongoc_get_server_id_from_opts():268
[2018-02-28T02:32:05.671884+00:00]     mongoc: TRACE   >  EXIT: _mongoc_get_server_id_from_opts():275
[2018-02-28T02:32:05.671926+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_new_with_opts():345
[2018-02-28T02:32:05.671974+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_init():365
[2018-02-28T02:32:05.672015+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_new():37
[2018-02-28T02:32:05.672054+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_new():44
[2018-02-28T02:32:05.672094+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_init():376
[2018-02-28T02:32:05.680043+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():1781
[2018-02-28T02:32:05.680112+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():1786 cursor_id(0)
[2018-02-28T02:32:05.680152+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():284
[2018-02-28T02:32:05.680189+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():150
[2018-02-28T02:32:05.680229+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():308 done
[2018-02-28T02:32:05.680263+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():336
[2018-02-28T02:32:05.680298+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1825
[2018-02-28T02:32:05.681769+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():1781
[2018-02-28T02:32:05.681821+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():1786 cursor_id(0)
[2018-02-28T02:32:05.681858+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():284
[2018-02-28T02:32:05.681895+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():150
[2018-02-28T02:32:05.681932+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():336
[2018-02-28T02:32:05.681968+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1825
[2018-02-28T02:32:05.682005+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error():1718
[2018-02-28T02:32:05.682039+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error():1720
[2018-02-28T02:32:05.682074+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error_document():1731
[2018-02-28T02:32:05.682107+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_error_document():1750
[2018-02-28T02:32:05.682146+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_error_document():1772
[2018-02-28T02:32:05.682180+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error_document():1741
[2018-02-28T02:32:05.682231+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_destroy():515
[2018-02-28T02:32:05.682263+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_destroy():53
[2018-02-28T02:32:05.682313+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_destroy():532
[2018-02-28T02:32:05.682350+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_destroy():577
[2018-02-28T02:32:05.682388+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_destroy():62
[2018-02-28T02:32:05.682423+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_destroy():525
[2018-02-28T02:32:05.706473+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():798
[2018-02-28T02:32:05.706554+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():805
[2018-02-28T02:32:05.706612+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.706673+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.706715+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.706759+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.706854+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_init():894
[2018-02-28T02:32:05.706897+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_init():904
[2018-02-28T02:32:05.706959+00:00]     mongoc: TRACE   > ENTRY: mongoc_bulk_operation_remove_many_with_opts():222
[2018-02-28T02:32:05.707003+00:00]     mongoc: TRACE   >  EXIT: mongoc_bulk_operation_remove_many_with_opts():237
[2018-02-28T02:32:05.707043+00:00]     mongoc: TRACE   > ENTRY: _mongoc_bulk_operation_remove_with_opts():148
[2018-02-28T02:32:05.707092+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_init_delete():240
[2018-02-28T02:32:05.707177+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_init_bulk():187
[2018-02-28T02:32:05.707282+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_init_bulk():203
[2018-02-28T02:32:05.707364+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_delete_append():149
[2018-02-28T02:32:05.707444+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append():134
[2018-02-28T02:32:05.707516+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append():163
[2018-02-28T02:32:05.708910+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_delete_append():177
[2018-02-28T02:32:05.709091+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_init_delete():249
[2018-02-28T02:32:05.709200+00:00]     mongoc: TRACE   >  EXIT: _mongoc_bulk_operation_remove_with_opts():169
[2018-02-28T02:32:05.709309+00:00]     mongoc: TRACE   > ENTRY: mongoc_bulk_operation_execute():678
[2018-02-28T02:32:05.709775+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1650
[2018-02-28T02:32:05.709864+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server():1591
[2018-02-28T02:32:05.709962+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.710053+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.710129+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server():1617
[2018-02-28T02:32:05.710199+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1667
[2018-02-28T02:32:05.710274+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_execute():781
[2018-02-28T02:32:05.710345+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_opmsg():413
[2018-02-28T02:32:05.710428+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_init():282
[2018-02-28T02:32:05.710530+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_init():304
[2018-02-28T02:32:05.710634+00:00]     mongoc: TRACE   > ENTRY: mongoc_cmd_parts_append_opts():119
[2018-02-28T02:32:05.710711+00:00]     mongoc: TRACE   >  EXIT: mongoc_cmd_parts_append_opts():202
[2018-02-28T02:32:05.710836+00:00]     mongoc: TRACE   > ENTRY: mongoc_cmd_parts_assemble():564
[2018-02-28T02:32:05.710941+00:00]     mongoc: TRACE   > TRACE: mongoc_cmd_parts_assemble():592 Preparing 'delete'
[2018-02-28T02:32:05.710990+00:00]     client: TRACE   > ENTRY: mongoc_client_start_session():1150
[2018-02-28T02:32:05.711027+00:00]     mongoc: TRACE   > ENTRY: _mongoc_topology_pop_server_session():1288
[2018-02-28T02:32:05.711066+00:00]     mongoc: TRACE   >  EXIT: _mongoc_topology_pop_server_session():1314
[2018-02-28T02:32:05.711103+00:00]     client: TRACE   >  EXIT: mongoc_client_start_session():1154
[2018-02-28T02:32:05.711141+00:00]     mongoc: TRACE   >  EXIT: mongoc_cmd_parts_assemble():704
[2018-02-28T02:32:05.711210+00:00]    cluster: TRACE   > TRACE: mongoc_cluster_run_opmsg():2561 Function 'delete' is compressible: -1
[2018-02-28T02:32:05.711248+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():502
[2018-02-28T02:32:05.711284+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():150
[2018-02-28T02:32:05.711328+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():162 writev = 0000000752C2BD50 [11]
[2018-02-28T02:32:05.711416+00:00]     stream: TRACE   > 00000:  96 00 00 00 04 00 00 00  00 00 00 00 dd 07 00 00  . . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.711508+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 5c 00 00  00 02 64 65 6c 65 74 65  . . . . . \ . .  . . d e l e t e
[2018-02-28T02:32:05.711658+00:00]     stream: TRACE   > 00020:  00 10 00 00 00 61 63 5f  6d 6f 6e 6f 6c 6f 67 5f  . . . . . a c _  m o n o l o g _
[2018-02-28T02:32:05.711908+00:00]     stream: TRACE   > 00030:  6c 6f 67 73 00 03 77 72  69 74 65 43 6f 6e 63 65  l o g s . . w r  i t e C o n c e
[2018-02-28T02:32:05.712088+00:00]     stream: TRACE   > 00040:  72 6e 00 0c 00 00 00 10  77 00 01 00 00 00 00 08  r n . . . . . .  w . . . . . . .
[2018-02-28T02:32:05.712240+00:00]     stream: TRACE   > 00050:  6f 72 64 65 72 65 64 00  01 02 24 64 62 00 0e 00  o r d e r e d .  . . $ d b . . .
[2018-02-28T02:32:05.712467+00:00]     stream: TRACE   > 00060:  00 00 61 63 6d 6f 6e 6f  6c 6f 67 6c 6f 67 73 00  . . a c m o n o  l o g l o g s .
[2018-02-28T02:32:05.712567+00:00]     stream: TRACE   > 00070:  00 01 24 00 00 00 64 65  6c 65 74 65 73 00 18 00  . . $ . . . d e  l e t e s . . .
[2018-02-28T02:32:05.712664+00:00]     stream: TRACE   > 00080:  00 00 03 71 00 05 00 00  00 00 10 6c 69 6d 69 74  . . . q . . . .  . . . l i m i t
[2018-02-28T02:32:05.712721+00:00]     stream: TRACE   > 00090:  00 00 00 00 00 00                                 . . . . . .
[2018-02-28T02:32:05.712752+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_writev():199
[2018-02-28T02:32:05.712789+00:00]     socket: TRACE   > ENTRY: mongoc_socket_sendv():1351
[2018-02-28T02:32:05.712824+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_try_sendv():1256
[2018-02-28T02:32:05.712878+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1262 sendbuf = 000000075266F6E0 [11]
[2018-02-28T02:32:05.712960+00:00]     socket: TRACE   > 00000:  96 00 00 00 04 00 00 00  00 00 00 00 dd 07 00 00  . . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.713043+00:00]     socket: TRACE   > 00010:  00 00 00 00 00 5c 00 00  00 02 64 65 6c 65 74 65  . . . . . \ . .  . . d e l e t e
[2018-02-28T02:32:05.713129+00:00]     socket: TRACE   > 00020:  00 10 00 00 00 61 63 5f  6d 6f 6e 6f 6c 6f 67 5f  . . . . . a c _  m o n o l o g _
[2018-02-28T02:32:05.713217+00:00]     socket: TRACE   > 00030:  6c 6f 67 73 00 03 77 72  69 74 65 43 6f 6e 63 65  l o g s . . w r  i t e C o n c e
[2018-02-28T02:32:05.713297+00:00]     socket: TRACE   > 00040:  72 6e 00 0c 00 00 00 10  77 00 01 00 00 00 00 08  r n . . . . . .  w . . . . . . .
[2018-02-28T02:32:05.713382+00:00]     socket: TRACE   > 00050:  6f 72 64 65 72 65 64 00  01 02 24 64 62 00 0e 00  o r d e r e d .  . . $ d b . . .
[2018-02-28T02:32:05.713486+00:00]     socket: TRACE   > 00060:  00 00 61 63 6d 6f 6e 6f  6c 6f 67 6c 6f 67 73 00  . . a c m o n o  l o g l o g s .
[2018-02-28T02:32:05.713575+00:00]     socket: TRACE   > 00070:  00 01 24 00 00 00 64 65  6c 65 74 65 73 00 18 00  . . $ . . . d e  l e t e s . . .
[2018-02-28T02:32:05.713680+00:00]     socket: TRACE   > 00080:  00 00 03 71 00 05 00 00  00 00 10 6c 69 6d 69 74  . . . q . . . .  . . . l i m i t
[2018-02-28T02:32:05.713748+00:00]     socket: TRACE   > 00090:  00 00 00 00 00 00                                 . . . . . .
[2018-02-28T02:32:05.713967+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1270 WSASend sent: 150 (out of: 4), ret: 0
[2018-02-28T02:32:05.714045+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_try_sendv():1310
[2018-02-28T02:32:05.714096+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1363 Sent 150 (of 4) out of iovcnt=11
[2018-02-28T02:32:05.714142+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 150 -= 4
[2018-02-28T02:32:05.714188+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 146 -= 4
[2018-02-28T02:32:05.714235+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 142 -= 4
[2018-02-28T02:32:05.714280+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 138 -= 4
[2018-02-28T02:32:05.714328+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 134 -= 4
[2018-02-28T02:32:05.714418+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 130 -= 1
[2018-02-28T02:32:05.714485+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 129 -= 92
[2018-02-28T02:32:05.714530+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 37 -= 1
[2018-02-28T02:32:05.714577+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 36 -= 4
[2018-02-28T02:32:05.714621+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 32 -= 8
[2018-02-28T02:32:05.714699+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 24 -= 24
[2018-02-28T02:32:05.714745+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1399 Finished the iovecs
[2018-02-28T02:32:05.714782+00:00]     socket: TRACE   >  EXIT: mongoc_socket_sendv():1431
[2018-02-28T02:32:05.714825+00:00]     socket: TRACE   > TRACE: mongoc_socket_errno():592 Current errno: 0
[2018-02-28T02:32:05.714867+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_writev():205
[2018-02-28T02:32:05.714906+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():165
[2018-02-28T02:32:05.714945+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():509 writev returned: 150
[2018-02-28T02:32:05.714980+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():542
[2018-02-28T02:32:05.715005+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():191
[2018-02-28T02:32:05.715033+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:05.715067+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:05.715101+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:05.715139+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:05.715190+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:05.715228+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:05.715268+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066D030 [1]
[2018-02-28T02:32:05.715324+00:00]     stream: TRACE   > 00000:  ae 00 00 00                                       . . . .
[2018-02-28T02:32:05.715357+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:05.715384+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:05.715417+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():230
[2018-02-28T02:32:05.715450+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():191
[2018-02-28T02:32:05.715480+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:05.715512+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:05.715545+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:05.715601+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:05.715642+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:05.715677+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:05.715718+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066D030 [1]
[2018-02-28T02:32:05.715801+00:00]     stream: TRACE   > 00000:  be cf 03 00 04 00 00 00  dd 07 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.715878+00:00]     stream: TRACE   > 00010:  00 99 00 00 00 10 6e 00  00 00 00 00 04 77 72 69  . . . . . . n .  . . . . . w r i
[2018-02-28T02:32:05.715963+00:00]     stream: TRACE   > 00020:  74 65 45 72 72 6f 72 73  00 74 00 00 00 03 30 00  t e E r r o r s  . t . . . . 0 .
[2018-02-28T02:32:05.716055+00:00]     stream: TRACE   > 00030:  6c 00 00 00 10 69 6e 64  65 78 00 00 00 00 00 10  l . . . . i n d  e x . . . . . .
[2018-02-28T02:32:05.716140+00:00]     stream: TRACE   > 00040:  63 6f 64 65 00 14 00 00  00 02 65 72 72 6d 73 67  c o d e . . . .  . . e r r m s g
[2018-02-28T02:32:05.716227+00:00]     stream: TRACE   > 00050:  00 46 00 00 00 63 61 6e  6e 6f 74 20 72 65 6d 6f  . F . . . c a n  n o t   r e m o
[2018-02-28T02:32:05.716317+00:00]     stream: TRACE   > 00060:  76 65 20 66 72 6f 6d 20  61 20 63 61 70 70 65 64  v e   f r o m    a   c a p p e d
[2018-02-28T02:32:05.716408+00:00]     stream: TRACE   > 00070:  20 63 6f 6c 6c 65 63 74  69 6f 6e 3a 20 61 63 6d    c o l l e c t  i o n :   a c m
[2018-02-28T02:32:05.716499+00:00]     stream: TRACE   > 00080:  6f 6e 6f 6c 6f 67 6c 6f  67 73 2e 61 63 5f 6d 6f  o n o l o g l o  g s . a c _ m o
[2018-02-28T02:32:05.716611+00:00]     stream: TRACE   > 00090:  6e 6f 6c 6f 67 5f 6c 6f  67 73 00 00 00 01 6f 6b  n o l o g _ l o  g s . . . . o k
[2018-02-28T02:32:05.716830+00:00]     stream: TRACE   > 000a0:  00 00 00 00 00 00 00 f0  3f 00                    . . . . . . . .  ? .
[2018-02-28T02:32:05.716916+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:05.716966+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:05.717004+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():230
[2018-02-28T02:32:05.717049+00:00]     mongoc: TRACE   > ENTRY: _mongoc_cmd_check_ok():1089
[2018-02-28T02:32:05.717088+00:00]     mongoc: TRACE   >  EXIT: _mongoc_cmd_check_ok():1095
[2018-02-28T02:32:05.717132+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_merge():1014
[2018-02-28T02:32:05.717169+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_merge_arrays():965
[2018-02-28T02:32:05.717200+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_merge_arrays():996
[2018-02-28T02:32:05.717230+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_merge():1108
[2018-02-28T02:32:05.717264+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_opmsg():588
[2018-02-28T02:32:05.717301+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_execute():873
[2018-02-28T02:32:05.717335+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.717372+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.717408+00:00]     mongoc: TRACE   >  GOTO: mongoc_bulk_operation_execute():766 cleanup
[2018-02-28T02:32:05.717442+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_complete():1197
[2018-02-28T02:32:05.717490+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_complete():1293
[2018-02-28T02:32:05.717522+00:00]     mongoc: TRACE   >  EXIT: mongoc_bulk_operation_execute():781
[2018-02-28T02:32:05.721574+00:00]     mongoc: TRACE   > ENTRY: mongoc_topology_description_select():798
[2018-02-28T02:32:05.721640+00:00]     mongoc: TRACE   >  EXIT: mongoc_topology_description_select():805
[2018-02-28T02:32:05.721690+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.721741+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.721784+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.721825+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.721881+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.721929+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.721992+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.722033+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.726163+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.726234+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.726296+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:05.726329+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:05.726404+00:00]     client: TRACE   > ENTRY: _mongoc_client_command_with_opts():1724
[2018-02-28T02:32:05.726434+00:00]     mongoc: TRACE   > ENTRY: _mongoc_get_server_id_from_opts():268
[2018-02-28T02:32:05.726472+00:00]     mongoc: TRACE   >  EXIT: _mongoc_get_server_id_from_opts():291
[2018-02-28T02:32:05.726510+00:00]    cluster: TRACE   > ENTRY: mongoc_cluster_stream_for_server():1650
[2018-02-28T02:32:05.726546+00:00]    cluster: TRACE   > ENTRY: _mongoc_cluster_stream_for_server():1591
[2018-02-28T02:32:05.726599+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_handle_ismaster():493
[2018-02-28T02:32:05.726639+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_handle_ismaster():654
[2018-02-28T02:32:05.726772+00:00]    cluster: TRACE   >  EXIT: _mongoc_cluster_stream_for_server():1617
[2018-02-28T02:32:05.726864+00:00]    cluster: TRACE   >  EXIT: mongoc_cluster_stream_for_server():1667
[2018-02-28T02:32:05.726912+00:00]     mongoc: TRACE   > ENTRY: mongoc_cmd_parts_append_opts():119
[2018-02-28T02:32:05.726957+00:00]     mongoc: TRACE   >  EXIT: mongoc_cmd_parts_append_opts():202
[2018-02-28T02:32:05.726995+00:00]     client: TRACE   > ENTRY: _mongoc_client_command_with_stream():1603
[2018-02-28T02:32:05.727028+00:00]     mongoc: TRACE   > ENTRY: mongoc_cmd_parts_assemble():564
[2018-02-28T02:32:05.727070+00:00]     mongoc: TRACE   > TRACE: mongoc_cmd_parts_assemble():592 Preparing 'drop'
[2018-02-28T02:32:05.727112+00:00]     client: TRACE   > ENTRY: mongoc_client_start_session():1150
[2018-02-28T02:32:05.727152+00:00]     mongoc: TRACE   > ENTRY: _mongoc_topology_pop_server_session():1288
[2018-02-28T02:32:05.727188+00:00]     mongoc: TRACE   >  EXIT: _mongoc_topology_pop_server_session():1314
[2018-02-28T02:32:05.727224+00:00]     client: TRACE   >  EXIT: mongoc_client_start_session():1154
[2018-02-28T02:32:05.727262+00:00]     mongoc: TRACE   >  EXIT: mongoc_cmd_parts_assemble():704
[2018-02-28T02:32:05.727294+00:00]     client: TRACE   >  EXIT: _mongoc_client_command_with_stream():1617
[2018-02-28T02:32:05.727352+00:00]    cluster: TRACE   > TRACE: mongoc_cluster_run_opmsg():2561 Function 'drop' is compressible: -1
[2018-02-28T02:32:05.727389+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_writev_full():502
[2018-02-28T02:32:05.727424+00:00]     stream: TRACE   > ENTRY: mongoc_stream_writev():150
[2018-02-28T02:32:05.727467+00:00]     stream: TRACE   > TRACE: mongoc_stream_writev():162 writev = 0000000752C2BD50 [7]
[2018-02-28T02:32:05.727559+00:00]     stream: TRACE   > 00000:  65 00 00 00 06 00 00 00  00 00 00 00 dd 07 00 00  e . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.727752+00:00]     stream: TRACE   > 00010:  00 00 00 00 00 50 00 00  00 02 64 72 6f 70 00 10  . . . . . P . .  . . d r o p . .
[2018-02-28T02:32:05.727932+00:00]     stream: TRACE   > 00020:  00 00 00 61 63 5f 6d 6f  6e 6f 6c 6f 67 5f 6c 6f  . . . a c _ m o  n o l o g _ l o
[2018-02-28T02:32:05.728073+00:00]     stream: TRACE   > 00030:  67 73 00 03 77 72 69 74  65 43 6f 6e 63 65 72 6e  g s . . w r i t  e C o n c e r n
[2018-02-28T02:32:05.728187+00:00]     stream: TRACE   > 00040:  00 0c 00 00 00 10 77 00  01 00 00 00 00 02 24 64  . . . . . . w .  . . . . . . $ d
[2018-02-28T02:32:05.728303+00:00]     stream: TRACE   > 00050:  62 00 0e 00 00 00 61 63  6d 6f 6e 6f 6c 6f 67 6c  b . . . . . a c  m o n o l o g l
[2018-02-28T02:32:05.728373+00:00]     stream: TRACE   > 00060:  6f 67 73 00 00                                    o g s . .
[2018-02-28T02:32:05.728412+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_writev():199
[2018-02-28T02:32:05.728447+00:00]     socket: TRACE   > ENTRY: mongoc_socket_sendv():1351
[2018-02-28T02:32:05.728483+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_try_sendv():1256
[2018-02-28T02:32:05.728527+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1262 sendbuf = 00000007526E9A40 [7]
[2018-02-28T02:32:05.728636+00:00]     socket: TRACE   > 00000:  65 00 00 00 06 00 00 00  00 00 00 00 dd 07 00 00  e . . . . . . .  . . . . . . . .
[2018-02-28T02:32:05.728748+00:00]     socket: TRACE   > 00010:  00 00 00 00 00 50 00 00  00 02 64 72 6f 70 00 10  . . . . . P . .  . . d r o p . .
[2018-02-28T02:32:05.728879+00:00]     socket: TRACE   > 00020:  00 00 00 61 63 5f 6d 6f  6e 6f 6c 6f 67 5f 6c 6f  . . . a c _ m o  n o l o g _ l o
[2018-02-28T02:32:05.729014+00:00]     socket: TRACE   > 00030:  67 73 00 03 77 72 69 74  65 43 6f 6e 63 65 72 6e  g s . . w r i t  e C o n c e r n
[2018-02-28T02:32:05.729127+00:00]     socket: TRACE   > 00040:  00 0c 00 00 00 10 77 00  01 00 00 00 00 02 24 64  . . . . . . w .  . . . . . . $ d
[2018-02-28T02:32:05.729255+00:00]     socket: TRACE   > 00050:  62 00 0e 00 00 00 61 63  6d 6f 6e 6f 6c 6f 67 6c  b . . . . . a c  m o n o l o g l
[2018-02-28T02:32:05.729331+00:00]     socket: TRACE   > 00060:  6f 67 73 00 00                                    o g s . .
[2018-02-28T02:32:05.729546+00:00]     socket: TRACE   > TRACE: _mongoc_socket_try_sendv():1270 WSASend sent: 101 (out of: 4), ret: 0
[2018-02-28T02:32:05.729626+00:00]     socket: TRACE   >  EXIT: _mongoc_socket_try_sendv():1310
[2018-02-28T02:32:05.729679+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1363 Sent 101 (of 4) out of iovcnt=7
[2018-02-28T02:32:05.729727+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 101 -= 4
[2018-02-28T02:32:05.729773+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 97 -= 4
[2018-02-28T02:32:05.729819+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 93 -= 4
[2018-02-28T02:32:05.729866+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 89 -= 4
[2018-02-28T02:32:05.729911+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 85 -= 4
[2018-02-28T02:32:05.729958+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 81 -= 1
[2018-02-28T02:32:05.730005+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1390 still got bytes left: sent -= iov_len: 80 -= 80
[2018-02-28T02:32:05.730049+00:00]     socket: TRACE   > TRACE: mongoc_socket_sendv():1399 Finished the iovecs
[2018-02-28T02:32:05.730091+00:00]     socket: TRACE   >  EXIT: mongoc_socket_sendv():1431
[2018-02-28T02:32:05.730135+00:00]     socket: TRACE   > TRACE: mongoc_socket_errno():592 Current errno: 0
[2018-02-28T02:32:05.730175+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_writev():205
[2018-02-28T02:32:05.730213+00:00]     stream: TRACE   >  EXIT: mongoc_stream_writev():165
[2018-02-28T02:32:05.730256+00:00]     stream: TRACE   > TRACE: _mongoc_stream_writev_full():509 writev returned: 101
[2018-02-28T02:32:05.730296+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_writev_full():542
[2018-02-28T02:32:05.730335+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():191
[2018-02-28T02:32:05.730369+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:05.730410+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:05.730448+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:05.730488+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:05.730548+00:00]     socket: TRACE   > TRACE: _mongoc_socket_capture_errno():68 setting errno: 10035 Unknown error
[2018-02-28T02:32:05.730623+00:00]     socket: TRACE   > TRACE: _mongoc_socket_errno_is_again():617 errno is: 10035
[2018-02-28T02:32:05.730671+00:00]     socket: TRACE   > ENTRY: _mongoc_socket_wait():148
[2018-02-28T02:32:07.265710+00:00]     socket: TRACE   >  GOTO: mongoc_socket_recv():1074 again
[2018-02-28T02:32:07.265803+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:07.265847+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:07.265892+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066D1A0 [1]
[2018-02-28T02:32:07.265962+00:00]     stream: TRACE   > 00000:  5d 00 00 00                                       ] . . .
[2018-02-28T02:32:07.266003+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:07.266035+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:07.266074+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():230
[2018-02-28T02:32:07.266111+00:00]     buffer: TRACE   > ENTRY: _mongoc_buffer_append_from_stream():191
[2018-02-28T02:32:07.266144+00:00]     stream: TRACE   > ENTRY: mongoc_stream_read():269
[2018-02-28T02:32:07.266183+00:00]     stream: TRACE   > ENTRY: mongoc_stream_readv():227
[2018-02-28T02:32:07.266221+00:00]     stream: TRACE   > ENTRY: _mongoc_stream_socket_readv():139
[2018-02-28T02:32:07.266260+00:00]     socket: TRACE   > ENTRY: mongoc_socket_recv():1055
[2018-02-28T02:32:07.266307+00:00]     socket: TRACE   >  EXIT: mongoc_socket_recv():1084
[2018-02-28T02:32:07.266346+00:00]     stream: TRACE   >  EXIT: _mongoc_stream_socket_readv():185
[2018-02-28T02:32:07.266391+00:00]     stream: TRACE   > TRACE: mongoc_stream_readv():237 readv = 000000075066D1A0 [1]
[2018-02-28T02:32:07.266506+00:00]     stream: TRACE   > 00000:  bf cf 03 00 06 00 00 00  dd 07 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
[2018-02-28T02:32:07.266628+00:00]     stream: TRACE   > 00010:  00 48 00 00 00 02 6e 73  00 1e 00 00 00 61 63 6d  . H . . . . n s  . . . . . a c m
[2018-02-28T02:32:07.266757+00:00]     stream: TRACE   > 00020:  6f 6e 6f 6c 6f 67 6c 6f  67 73 2e 61 63 5f 6d 6f  o n o l o g l o  g s . a c _ m o
[2018-02-28T02:32:07.266857+00:00]     stream: TRACE   > 00030:  6e 6f 6c 6f 67 5f 6c 6f  67 73 00 10 6e 49 6e 64  n o l o g _ l o  g s . . n I n d
[2018-02-28T02:32:07.266927+00:00]     stream: TRACE   > 00040:  65 78 65 73 57 61 73 00  07 00 00 00 01 6f 6b 00  e x e s W a s .  . . . . . o k .
[2018-02-28T02:32:07.266976+00:00]     stream: TRACE   > 00050:  00 00 00 00 00 00 f0 3f  00                       . . . . . . . ?  .
[2018-02-28T02:32:07.267003+00:00]     stream: TRACE   >  EXIT: mongoc_stream_readv():240
[2018-02-28T02:32:07.267020+00:00]     stream: TRACE   >  EXIT: mongoc_stream_read():281
[2018-02-28T02:32:07.267041+00:00]     buffer: TRACE   >  EXIT: _mongoc_buffer_append_from_stream():230
[2018-02-28T02:32:07.267074+00:00]     mongoc: TRACE   > ENTRY: _mongoc_cmd_check_ok():1089
[2018-02-28T02:32:07.267097+00:00]     mongoc: TRACE   >  EXIT: _mongoc_cmd_check_ok():1095
[2018-02-28T02:32:07.267134+00:00]     client: TRACE   >  GOTO: _mongoc_client_command_with_opts():1828 done
[2018-02-28T02:32:07.267160+00:00]     mongoc: TRACE   > ENTRY: mongoc_server_description_destroy():145
[2018-02-28T02:32:07.267180+00:00]     mongoc: TRACE   >  EXIT: mongoc_server_description_destroy():151
[2018-02-28T02:32:07.267202+00:00]     client: TRACE   >  EXIT: _mongoc_client_command_with_opts():1844
[2018-02-28T02:32:07.267263+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_new_with_opts():226
[2018-02-28T02:32:07.267294+00:00]     mongoc: TRACE   > ENTRY: _mongoc_get_server_id_from_opts():268
[2018-02-28T02:32:07.267318+00:00]     mongoc: TRACE   >  EXIT: _mongoc_get_server_id_from_opts():275
[2018-02-28T02:32:07.267344+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_new_with_opts():345
[2018-02-28T02:32:07.267369+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_init():365
[2018-02-28T02:32:07.267391+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_new():37
[2018-02-28T02:32:07.267418+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_new():44
[2018-02-28T02:32:07.267439+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_init():376
[2018-02-28T02:32:07.269885+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():1781
[2018-02-28T02:32:07.269953+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():1786 cursor_id(0)
[2018-02-28T02:32:07.269993+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():284
[2018-02-28T02:32:07.270028+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():150
[2018-02-28T02:32:07.270067+00:00] cursor-cursorid: TRACE   >  GOTO: _mongoc_cursor_cursorid_next():308 done
[2018-02-28T02:32:07.270100+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():336
[2018-02-28T02:32:07.270136+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1825
[2018-02-28T02:32:07.270203+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_next():1781
[2018-02-28T02:32:07.270234+00:00]     cursor: TRACE   > TRACE: mongoc_cursor_next():1786 cursor_id(0)
[2018-02-28T02:32:07.270270+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_next():284
[2018-02-28T02:32:07.270306+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_read_from_batch():150
[2018-02-28T02:32:07.270342+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_next():336
[2018-02-28T02:32:07.270378+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_next():1825
[2018-02-28T02:32:07.270410+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error():1718
[2018-02-28T02:32:07.270443+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error():1720
[2018-02-28T02:32:07.270476+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_error_document():1731
[2018-02-28T02:32:07.270509+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_error_document():1750
[2018-02-28T02:32:07.270544+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_error_document():1772
[2018-02-28T02:32:07.270581+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_error_document():1741
[2018-02-28T02:32:07.270623+00:00]     cursor: TRACE   > ENTRY: mongoc_cursor_destroy():515
[2018-02-28T02:32:07.270657+00:00] cursor-cursorid: TRACE   > ENTRY: _mongoc_cursor_cursorid_destroy():53
[2018-02-28T02:32:07.270695+00:00]     cursor: TRACE   > ENTRY: _mongoc_cursor_destroy():532
[2018-02-28T02:32:07.270737+00:00]     cursor: TRACE   >  EXIT: _mongoc_cursor_destroy():577
[2018-02-28T02:32:07.270774+00:00] cursor-cursorid: TRACE   >  EXIT: _mongoc_cursor_cursorid_destroy():62
[2018-02-28T02:32:07.270814+00:00]     cursor: TRACE   >  EXIT: mongoc_cursor_destroy():525
[2018-02-28T02:32:07.270944+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_command_destroy():880
[2018-02-28T02:32:07.270990+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_command_destroy():887
[2018-02-28T02:32:07.271030+00:00]     mongoc: TRACE   > ENTRY: _mongoc_write_result_destroy():911
[20 18-02-28T02:32:07.271068+00:00]     mongoc: TRACE   >  EXIT: _mongoc_write_result_destroy():919

I save logs directly from Monolog to MongoDB. The ACMonologBundle is to search and analyse logs already saved. The collection must be capped and by default it is not, so I create a command to drop and create the collection with the right schema ( bin/console ac:monolog:create --env=prod) It seems work very well for over 2 years, before the recents updates. This is maybe not a real bug but a very specific case ...

jmikola commented 6 years ago

Is ACMonologBundle an open-source package, or is this your private bundle?

The most recent mongodb.debug trace you've shared looks to be entirely different from the previous trace. In this new trace, you're running the following commands:

Assuming those three commands are all executed from a command class in ACMonologBundle, I don't understand why the code is attempting to delete documents before dropping the collection. Have you identified the source of this delete command?

Assuming the code example in https://github.com/doctrine/mongodb-odm/issues/1745#issuecomment-368189467 was taken from ACMonologBundle, I can tell you with certainty that none of the ODM SchemaManager methods should be executing a delete command. If that bundle is relying on ODM to create the capped collection based on document metadata for a "LogMessage" or similarly named class, the SchemaManager should still do nothing more than execute drop and create commands.

It seems work very well for over 2 years, before the recents updates.

Were you able to narrow down the break to a specific update of a single package/extension, or was this break only observed after updating multiple things in one shot?

malarzm commented 11 months ago

Closing as nothing happened here in 5 years 👼