The format of the query log line will differ based on whether the query was delivered using the 3.0-and-earlier OP_QUERY/OP_GET_MORE find protocol or using the find/getMore commands. Consider the following example query:
db.collection.find({a: {$gt: 3}}, {_id: 0, a: 1, b: 1}).sort({b: 1}).skip(11).limit(12);
If this query is delivered to a version 3.2 mongod using OP_QUERY/OP_GET_MORE wire protocol reads, the resulting log line will look something like this:
2015-09-23T14:39:21.452-0400 I QUERY [conn1] query test.collection query: { query: { a: { $gt: 3.0 } }, orderby: { b: 1.0 } } planSummary: COLLSCAN, COLLSCAN ntoreturn:12 ntoskip:11 keysExamined:0 docsExamined:4 hasSortStage:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:20 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } 0ms
In contrast, if the query is delivered to a version 3.2 mongod using the find command, the log line will be:
2015-09-23T14:40:21.901-0400 I COMMAND [conn2] command test.collection command: find { find: "collection", filter: { a: { $gt: 3.0 } }, skip: 11.0, limit: 12.0, singleBatch: false, sort: { b: 1.0 }, projection: { _id: 0.0, a: 1.0, b: 1.0 } } planSummary: COLLSCAN keysExamined:0 docsExamined:2 hasSortStage:1 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:106 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_command 0ms
The differences between the two formats are:
- OP_QUERY/OP_GET_MORE diagnostic log entries begin with the word query and list the query predicate and other modifiers after "query:". Like all other commands, the find command log line instead begins with the word command and lists the command parameters object after "command:".
- The find command log lines omit the ntoreturn and ntoskip information, since this is redundant with the find command parameters. The find command has parameters named skip, limit, and batchSize which contain this information.
Similarly, a getMore command will be logged just like any other command, and not like an OP_GET_MORE wire protocol message:
2015-09-23T15:13:27.141-0400 I COMMAND [conn2] command test.collection command: getMore { getMore: 17696123619, collection: "collection", batchSize: 2.0 } ntoreturn:1 ntoskip:0 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:123 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_command 0ms
- is documented by
-
DOCS-6259 Doc changes to query log entries for the find command in 3.2 release notes
- Closed
- is duplicated by
-
SERVER-20107 Update query log line format for find and getMore commands
- Closed