-
Type:
Bug
-
Resolution: Works as Designed
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.6.0
-
Component/s: Logging
-
None
-
ALL
-
None
-
3
-
None
-
None
-
None
-
None
-
None
-
None
In 3.4, a write command is logged like this:
2017-12-26T17:04:38.161-0500 D COMMAND [conn4] run command JavaDriverTest.$cmd { insert: "com.mongodb.operation.MixedBulkWriteOperationSpecification", ordered: true, documents: [ { _id: 1 } ] }
2017-12-26T17:04:38.165-0500 I COMMAND [conn4] command JavaDriverTest.com.mongodb.operation.MixedBulkWriteOperationSpecification command: insert { insert: "com.mongodb.operation.MixedBulkWriteOperationSpecification", ordered: true, documents: [ { _id: 1 } ] } ninserted:1 keysInserted:1 numYields:0 reslen:44 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 2, W: 1 } }, Collection: { acquireCount: { w: 2 } } } protocol:op_query 3ms
In 3.6 the same write command sent via OP_MSG (using message payloads) is logged like this:
2017-12-26T17:03:54.205-0500 D COMMAND [conn187] run command JavaDriverTest.$cmd { insert: "com.mongodb.operation.MixedBulkWriteOperationSpecification", ordered: true, $db: "JavaDriverTest", lsid: { id: UUID("a6d0bb55-ed4f-4643-8f21-75eb1ae00c91") } }
2017-12-26T17:03:54.206-0500 I COMMAND [conn187] command JavaDriverTest.com.mongodb.operation.MixedBulkWriteOperationSpecification command: insert { insert: "com.mongodb.operation.MixedBulkWriteOperationSpecification", ordered: true, $db: "JavaDriverTest", lsid: { id: UUID("a6d0bb55-ed4f-4643-8f21-75eb1ae00c91") } } ninserted:1 keysInserted:1 numYields:0 reslen:29 locks:{ Global: { acquireCount: { r: 5, w: 3 } }, Database: { acquireCount: { r: 1, w: 2, W: 1 } }, Collection: { acquireCount: { r: 1, w: 2 } } } protocol:op_msg 1ms
Since the OP_MSG payload is not logged, the document sequence is not included in the log message.
This may be considered a regression from the perspective of some log analysis tools (human or otherwise).