Skip to content

Commit

Permalink
DRIVERS-1677, DRIVERS-1633: Add logging specification and command log…
Browse files Browse the repository at this point in the history 
…ging (#1303)

* Add new logging specification
* Add support for logging assertions to the unified test format
* Add command log messages and tests to the command monitoring (now command logging and monitoring or CLAM) specification
  • Loading branch information
@kmahar
kmahar committed Oct 14, 2022
1 parent 5f8d058 commit d4f83d8
Show file tree
Hide file tree
Showing 97 changed files with 6,447 additions and 79 deletions.
260 changes: 203 additions & 57 deletions ...command-monitoring/command-monitoring.rst → ...toring/command-logging-and-monitoring.rst
View file

Large diffs are not rendered by default.

60 changes: 60 additions & 0 deletions source/command-logging-and-monitoring/tests/README.rst
View file
@@ -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).

*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*

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.
213 changes: 213 additions & 0 deletions source/command-logging-and-monitoring/tests/logging/command.json
View file
@@ -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"
]
}
}
}
]
}
]
}
]
}
94 changes: 94 additions & 0 deletions source/command-logging-and-monitoring/tests/logging/command.yml
View file
@@ -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] }

1 comment on commit d4f83d8

@jmikola
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: the commit message should have referred to https://jira.mongodb.org/browse/DRIVERS-1673, not DRIVERS-1633.

Please sign in to comment.