DRIVERS-1677, DRIVERS-1673: Add general logging specification and command logging #1303
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,60 @@ | ||
| .. role:: javascript(code) | ||
| :language: javascript | ||
|
|
||
| ============================== | ||
| Command Logging and Monitoring | ||
| ============================== | ||
|
|
||
| .. contents:: | ||
|
|
||
| -------- | ||
|
|
||
| Testing | ||
| ======= | ||
|
|
||
| Automated Tests | ||
| ^^^^^^^^^^^^^^^ | ||
| There are tests in the `Unified Test Format <../../unified-test-format/unified-test-format.rst>`__ for both logging and | ||
| monitoring in `/logging </logging>`_ and `/monitoring </monitoring>`_, respectively. Drivers MUST run the logging | ||
| tests with their max document length setting (as described in the | ||
| `logging specification <../../logging/logging.rst#truncation-of-large-documents>`__) set to a large value e.g. 10,000; | ||
| this is necessary in order for the driver to emit the full server reply (and to allow matching against that reply) on | ||
| certain MongoDB versions and topologies. | ||
|
|
||
| Prose Tests | ||
| ^^^^^^^^^^^ | ||
| Drivers MUST implement the following logging prose tests. These tests require the ability to capture log message data in a | ||
| structured form as described in the | ||
| `Unified Test Format specification <../../unified-test-format/unified-test-format.rst#expectedLogMessage>`__. | ||
|
|
||
| Note: the following tests mention string "length"; this refers to length in terms of whatever unit the driver has chosen | ||
| to support for specifying max document length as discussed in the | ||
| `logging specification <../../logging/logging.rst#truncation-of-large-documents>`__. | ||
|
|
||
| *Test 1: Default truncation limit* | ||
|
|
||
| 1. Configure logging with a minimum severity level of "debug" for the "command" component. Do not explicitly configure the max document length. | ||
| 2. Construct an array ``docs`` containing the document ``{"x" : "y"}`` repeated 100 times. | ||
| 3. Insert ``docs`` to a collection via ``insertMany``. | ||
| 4. Inspect the resulting "command started" log message and assert that the "command" value is a string of length 1000 + (length of trailing ellipsis). | ||
| 5. Inspect the resulting "command succeeded" log message and assert that the "reply" value is a string of length <= 1000 + (length of trailing ellipsis). | ||
| 6. Run ``find()`` on the collection where the document was inserted. | ||
| 7. Inspect the resulting "command succeeded" log message and assert that the reply is a string of length 1000 + (length of trailing ellipsis). | ||
|
There was a problem hiding this comment. minor: Is there a value in having the second test, as opposed to a parameterizing the first one? There was a problem hiding this comment. I think the differences in terms of the commands and assertions run are significant enough that it would not save us much text to try to combine them. |
||
|
|
||
| *Test 2: Explicitly configured truncation limit* | ||
|
|
||
| 1. Configure logging with a minimum severity level of "debug" for the "command" component. Set the max document length to 5. | ||
| 2. Run the command ``{"hello": true}``. | ||
| 3. Inspect the resulting "command started" log message and assert that the "command" value is a string of length 5 + (length of trailing ellipsis). | ||
| 4. Inspect the resulting "command succeeded" log message and assert that the "reply" value is a string of length 5 + (length of trailing ellipsis). | ||
| 5. If the driver attaches raw server responses to failures and can access these via log messages to assert on, run the command | ||
| ``{"notARealCommand": true}``. Inspect the resulting "command failed" log message and confirm that the server error is | ||
| a string of length 5 + (length of trailing ellipsis). | ||
|
|
||
| *Test 3: Truncation with multi-byte codepoints* | ||
kmahar marked this conversation as resolved.
Show resolved
Hide resolved
|
||
|
|
||
| A specific test case is not provided here due to the allowed variations in truncation logic as well as varying extended JSON whitespace usage. | ||
| Drivers MUST write language-specific tests that confirm truncation of commands, replies, and (if applicable) server responses included in error | ||
| messages work as expected when the data being truncated includes multi-byte Unicode codepoints. | ||
| If the driver uses anything other than Unicode codepoints as the unit for max document length, there also MUST be tests confirming that cases | ||
| where the max length falls in the middle of a multi-byte codepoint are handled gracefully. | ||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,213 @@ | ||
| { | ||
| "description": "command-logging", | ||
| "schemaVersion": "1.13", | ||
| "createEntities": [ | ||
| { | ||
| "client": { | ||
| "id": "client", | ||
| "observeLogMessages": { | ||
| "command": "debug" | ||
| } | ||
| } | ||
| }, | ||
| { | ||
| "database": { | ||
| "id": "database", | ||
| "client": "client", | ||
| "databaseName": "logging-tests" | ||
| } | ||
| }, | ||
| { | ||
| "collection": { | ||
| "id": "collection", | ||
| "database": "database", | ||
| "collectionName": "logging-tests-collection" | ||
| } | ||
| } | ||
| ], | ||
| "initialData": [ | ||
| { | ||
| "collectionName": "logging-tests-collection", | ||
| "databaseName": "logging-tests", | ||
| "documents": [ | ||
| { | ||
| "_id": 1, | ||
| "x": 11 | ||
| } | ||
| ] | ||
| } | ||
| ], | ||
| "tests": [ | ||
| { | ||
| "description": "A successful command", | ||
| "operations": [ | ||
| { | ||
| "name": "runCommand", | ||
| "object": "database", | ||
| "arguments": { | ||
| "command": { | ||
| "ping": 1 | ||
| }, | ||
| "commandName": "ping" | ||
| } | ||
| } | ||
| ], | ||
| "expectLogMessages": [ | ||
| { | ||
| "client": "client", | ||
| "messages": [ | ||
| { | ||
| "level": "debug", | ||
| "component": "command", | ||
| "data": { | ||
| "message": "Command started", | ||
| "databaseName": "logging-tests", | ||
| "commandName": "ping", | ||
| "command": { | ||
| "$$matchAsDocument": { | ||
| "$$matchAsRoot": { | ||
| "ping": 1, | ||
| "$db": "logging-tests" | ||
| } | ||
| } | ||
| }, | ||
| "requestId": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| }, | ||
| "serverHost": { | ||
| "$$type": "string" | ||
| }, | ||
| "serverPort": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| } | ||
| } | ||
| }, | ||
| { | ||
| "level": "debug", | ||
| "component": "command", | ||
| "data": { | ||
| "message": "Command succeeded", | ||
| "commandName": "ping", | ||
| "reply": { | ||
| "$$type": "string" | ||
| }, | ||
| "requestId": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| }, | ||
| "serverHost": { | ||
| "$$type": "string" | ||
| }, | ||
| "serverPort": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| }, | ||
| "durationMS": { | ||
| "$$type": [ | ||
| "double", | ||
| "int", | ||
| "long" | ||
| ] | ||
| } | ||
| } | ||
| } | ||
| ] | ||
| } | ||
| ] | ||
| }, | ||
| { | ||
| "description": "A failed command", | ||
| "operations": [ | ||
| { | ||
| "name": "find", | ||
| "object": "collection", | ||
| "arguments": { | ||
| "filter": { | ||
| "$or": true | ||
| } | ||
| }, | ||
| "expectError": { | ||
| "isClientError": false | ||
| } | ||
| } | ||
| ], | ||
| "expectLogMessages": [ | ||
| { | ||
| "client": "client", | ||
| "messages": [ | ||
| { | ||
| "level": "debug", | ||
| "component": "command", | ||
| "data": { | ||
| "message": "Command started", | ||
| "databaseName": "logging-tests", | ||
| "commandName": "find", | ||
| "command": { | ||
| "$$type": "string" | ||
| }, | ||
| "requestId": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| }, | ||
| "serverHost": { | ||
| "$$type": "string" | ||
| }, | ||
| "serverPort": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| } | ||
| } | ||
| }, | ||
| { | ||
| "level": "debug", | ||
| "component": "command", | ||
| "data": { | ||
| "message": "Command failed", | ||
| "commandName": "find", | ||
| "failure": { | ||
| "$$exists": true | ||
| }, | ||
| "requestId": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| }, | ||
| "serverHost": { | ||
| "$$type": "string" | ||
| }, | ||
| "serverPort": { | ||
| "$$type": [ | ||
| "int", | ||
| "long" | ||
| ] | ||
| }, | ||
| "durationMS": { | ||
| "$$type": [ | ||
| "double", | ||
| "int", | ||
| "long" | ||
| ] | ||
| } | ||
| } | ||
| } | ||
| ] | ||
| } | ||
| ] | ||
| } | ||
| ] | ||
| } |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,94 @@ | ||
| description: "command-logging" | ||
|
|
||
| schemaVersion: "1.13" | ||
|
|
||
| createEntities: | ||
| - client: | ||
| id: &client client | ||
| observeLogMessages: | ||
| command: debug | ||
| - database: | ||
| id: &database database | ||
| client: *client | ||
| databaseName: &databaseName logging-tests | ||
| - collection: | ||
| id: &collection collection | ||
| database: *database | ||
| collectionName: &collectionName logging-tests-collection | ||
|
|
||
| initialData: | ||
| - collectionName: *collectionName | ||
| databaseName: *databaseName | ||
| documents: | ||
| - { _id: 1, x: 11 } | ||
|
|
||
| tests: | ||
| - description: "A successful command" | ||
| operations: | ||
| - name: runCommand | ||
| object: *database | ||
| arguments: | ||
| command: { ping: 1 } | ||
| commandName: &commandName ping | ||
| expectLogMessages: | ||
| - client: *client | ||
| messages: | ||
| - level: debug | ||
| component: command | ||
| data: | ||
| message: "Command started" | ||
| databaseName: *databaseName | ||
| commandName: *commandName | ||
| command: | ||
| $$matchAsDocument: | ||
| $$matchAsRoot: | ||
| ping: 1 | ||
| $db: *databaseName | ||
| requestId: { $$type: [int, long] } | ||
| serverHost: { $$type: string } | ||
| serverPort: { $$type: [int, long] } | ||
|
|
||
| - level: debug | ||
| component: command | ||
| data: | ||
| message: "Command succeeded" | ||
| commandName: *commandName | ||
| reply: { $$type: string } | ||
| requestId: { $$type: [int, long] } | ||
| serverHost: { $$type: string } | ||
| serverPort: { $$type: [int, long] } | ||
| durationMS: { $$type: [double, int, long] } | ||
|
|
||
| - description: "A failed command" | ||
| operations: | ||
| - name: &commandName find | ||
| object: *collection | ||
| arguments: | ||
| filter: { $or: true } | ||
| expectError: | ||
| isClientError: false | ||
| expectLogMessages: | ||
| - client: *client | ||
| messages: | ||
| - level: debug | ||
| component: command | ||
| data: | ||
| message: "Command started" | ||
| databaseName: *databaseName | ||
| commandName: *commandName | ||
| command: { $$type: string } | ||
| requestId: { $$type: [int, long] } | ||
| serverHost: { $$type: string } | ||
| serverPort: { $$type: [int, long] } | ||
|
|
||
| - level: debug | ||
| component: command | ||
| data: | ||
| message: "Command failed" | ||
| commandName: *commandName | ||
| failure: { $$exists: true } | ||
| requestId: { $$type: [int, long] } | ||
| serverHost: { $$type: string } | ||
| serverPort: { $$type: [int, long] } | ||
| durationMS: { $$type: [double, int, long] } | ||
|
|
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Uh oh!
There was an error while loading. Please reload this page.