From e21462963638c7124d756874d4d7ecaafbb2bdca Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Tue, 31 Dec 2024 08:53:09 -0800 Subject: [PATCH 01/23] structured logging json and truncation fixes, using the new mcommon_string APIs Adds the truncation marker, defines string limits carefully to avoid bson length overflow or int overflow --- .../doc/mongoc_structured_log_opts_new.rst | 2 +- .../mongoc/mongoc-structured-log-private.h | 12 ++ .../src/mongoc/mongoc-structured-log.c | 178 ++++++++++++++---- .../tests/test-mongoc-structured-log.c | 130 ++++++++----- 4 files changed, 236 insertions(+), 86 deletions(-) diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_new.rst b/src/libmongoc/doc/mongoc_structured_log_opts_new.rst index 78295e4fb94..89810b6ce3a 100644 --- a/src/libmongoc/doc/mongoc_structured_log_opts_new.rst +++ b/src/libmongoc/doc/mongoc_structured_log_opts_new.rst @@ -31,7 +31,7 @@ Environment Variables This is a full list of the captured environment variables. * ``MONGODB_LOG_MAX_DOCUMENT_LENGTH``: Maximum length for JSON-serialized documents that appear within a log message. - It may be a number, in bytes, or ``unlimited`` (case insensitive). + It may be a number, in bytes, or ``unlimited`` (case insensitive) to choose an implementation-specific value near the maximum representable length. By default, the limit is 1000 bytes. This limit affects interior documents like commands and replies, not the total length of a structured log message. diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log-private.h b/src/libmongoc/src/mongoc/mongoc-structured-log-private.h index 376a88a97dd..6b89e53bc34 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log-private.h +++ b/src/libmongoc/src/mongoc/mongoc-structured-log-private.h @@ -33,6 +33,18 @@ typedef struct mongoc_structured_log_instance_t mongoc_structured_log_instance_t #define MONGOC_STRUCTURED_LOG_DEFAULT_LEVEL MONGOC_STRUCTURED_LOG_LEVEL_WARNING #define MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH 1000 +/** + * @brief maximum possible value of the 'maximum document length' setting, enforced when reading settings from the + * environment. + * + * Maximum document length applies to a single serialized JSON document within the log. + * The overall log document, when serialized as BSON, will be subject to BSON_MAX_SIZE. + * At a minimum we should leave room for BSON headers and for the JSON truncation marker ("..."). + * Choose to leave a little more room, as it's more useful to truncate the huge document early + * rather than fail in bson_append_utf8(). + */ +#define MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH ((uint32_t) BSON_MAX_SIZE - 4096u) + /** * @brief Allocate a new instance of the structured logging system * @param opts Options, copied into the new instance. diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index aad46d3c349..d551e383a9a 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -16,6 +16,8 @@ #include "common-atomic-private.h" #include "common-oid-private.h" +#include "common-string-private.h" +#include "common-json-private.h" #include "common-thread-private.h" #include "mongoc-apm-private.h" #include "mongoc-error-private.h" @@ -55,7 +57,7 @@ struct mongoc_structured_log_opts_t { mongoc_structured_log_func_t handler_func; void *handler_user_data; mongoc_structured_log_level_t max_level_per_component[STRUCTURED_LOG_COMPONENT_TABLE_SIZE]; - int32_t max_document_length; + uint32_t max_document_length; char *default_handler_path; }; @@ -268,7 +270,7 @@ mongoc_structured_log_get_named_component (const char *name, mongoc_structured_l return false; } -static int32_t +static uint32_t _mongoc_structured_log_get_max_document_length_from_env (void) { const char *variable = "MONGODB_LOG_MAX_DOCUMENT_LENGTH"; @@ -279,13 +281,14 @@ _mongoc_structured_log_get_max_document_length_from_env (void) } if (!strcasecmp (max_length_str, "unlimited")) { - return BSON_MAX_LEN_UNLIMITED; + return MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH; } char *endptr; long int_value = strtol (max_length_str, &endptr, 10); - if (int_value >= 0 && int_value <= INT32_MAX && endptr != max_length_str && !*endptr) { - return (int32_t) int_value; + if (int_value >= 0 && int_value <= (long) MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH && + endptr != max_length_str && !*endptr) { + return (uint32_t) int_value; } // Only log the first instance of each error per process @@ -489,15 +492,123 @@ mongoc_structured_log_instance_destroy (mongoc_structured_log_instance_t *instan } } -static char * -_mongoc_structured_log_inner_document_to_json (const bson_t *document, - size_t *length, - const mongoc_structured_log_opts_t *opts) +static mcommon_string_t * +_mongoc_structured_log_append_json_truncation_marker (mcommon_string_append_t *append) { - bson_json_opts_t *json_opts = bson_json_opts_new (BSON_JSON_MODE_RELAXED, opts->max_document_length); - char *json = bson_as_json_with_opts (document, length, json_opts); - bson_json_opts_destroy (json_opts); - return json; + if (!mcommon_string_status_from_append (append)) { + mcommon_string_append_t marker_append; + mcommon_string_set_append (mcommon_string_from_append (append), &marker_append); + mcommon_string_append (&marker_append, "..."); + } + // Guaranteed due to choice of MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH + BSON_ASSERT (mcommon_strlen_from_append (append) <= (uint32_t) BSON_MAX_SIZE); + return mcommon_string_from_append (append); +} + +// Generic bson-to-json for documents that appear within a structured log message as truncated JSON +static mcommon_string_t * +_mongoc_structured_log_document_as_truncated_json (const bson_t *document, const mongoc_structured_log_opts_t *opts) +{ + // Use the bson_t document length as an initial buffer capacity guess + mcommon_string_append_t append; + mcommon_string_set_append_with_limit ( + mcommon_string_new_with_capacity ("", 0, document->len), &append, opts->max_document_length); + + if (mcommon_json_append_bson_document (&append, document, BSON_JSON_MODE_RELAXED, BSON_MAX_RECURSION)) { + return _mongoc_structured_log_append_json_truncation_marker (&append); + } else { + mcommon_string_from_append_destroy (&append); + return NULL; + } +} + +/** + * @brief Specialized bson-to-json conversion for mongoc_cmd_t + * @returns A new allocated mcommon_string_t, limited to the maximum document length from 'opts' plus the space for a + * possible truncation marker. Returns NULL if an invalid BSON document is encountered. This is equivalent to + * _mongoc_cmd_append_payload_as_array() combined with _mongoc_structured_log_document_as_truncated_json(), but it + * avoids ever assembling a BSON representation of the complete logged JSON document. Each payload is serialized + * separately using the mcommon_json_* functions. If we reach the maximum document length, unused portions of the input + * command will not be read. + */ +static mcommon_string_t * +_mongoc_structured_log_command_with_payloads_as_truncated_json (const mongoc_cmd_t *cmd, + const mongoc_structured_log_opts_t *opts) +{ + BSON_ASSERT_PARAM (cmd); + BSON_ASSERT (!bson_empty0 (cmd->command)); + BSON_ASSERT (cmd->payloads_count <= MONGOC_CMD_PAYLOADS_COUNT_MAX); + + // Use the bson length of the command itself as an initial buffer capacity guess. + bool invalid_document = false; + mcommon_string_append_t append; + mcommon_string_set_append_with_limit ( + mcommon_string_new_with_capacity ("", 0, cmd->command->len), &append, opts->max_document_length); + + if (!mcommon_string_append (&append, "{ ")) { + goto done; + } + + if (!mcommon_json_append_bson_values ( + &append, cmd->command, BSON_JSON_MODE_RELAXED, true, BSON_MAX_RECURSION - 1u)) { + invalid_document = true; + goto done; + } + + for (size_t i = 0; i < cmd->payloads_count; i++) { + const char *field_name = cmd->payloads[i].identifier; + BSON_ASSERT (field_name); + + // Each payload is an appended key containing a non-empty sequence of documents + if (!mcommon_json_append_separator (&append) || + !mcommon_json_append_key (&append, field_name, strlen (field_name)) || + !mcommon_string_append (&append, "[ ")) { + goto done; + } + + const uint8_t *doc_begin = cmd->payloads[i].documents; + BSON_ASSERT (doc_begin); + const uint8_t *doc_end = doc_begin + cmd->payloads[i].size; + BSON_ASSERT (doc_begin != doc_end); + + const uint8_t *doc_ptr = doc_begin; + int32_t doc_len; + + while (doc_ptr + sizeof doc_len <= doc_end) { + memcpy (&doc_len, doc_ptr, sizeof doc_len); + doc_len = BSON_UINT32_FROM_LE (doc_len); + + bson_t doc; + if (doc_len < 5 || (size_t) doc_len > (size_t) (doc_end - doc_ptr) || + !bson_init_static (&doc, doc_ptr, (size_t) doc_len)) { + invalid_document = true; + goto done; + } + + if (doc_ptr != doc_begin) { + mcommon_json_append_separator (&append); + } + if (!mcommon_json_append_bson_document (&append, &doc, BSON_JSON_MODE_RELAXED, BSON_MAX_RECURSION - 2u)) { + invalid_document = true; + goto done; + } + doc_ptr += doc_len; + } + + if (!mcommon_string_append (&append, " ]")) { + goto done; + } + } + + mcommon_string_append (&append, " }"); + +done: + if (invalid_document) { + mcommon_string_from_append_destroy (&append); + return NULL; + } else { + return _mongoc_structured_log_append_json_truncation_marker (&append); + } } const mongoc_structured_log_builder_stage_t * @@ -611,12 +722,13 @@ _mongoc_structured_log_append_bson_as_json (bson_t *bson, const bson_t *bson_or_null = stage->arg2.bson; if (key_or_null) { if (bson_or_null) { - size_t json_length; - char *json = _mongoc_structured_log_inner_document_to_json (bson_or_null, &json_length, opts); + mcommon_string_t *json = _mongoc_structured_log_document_as_truncated_json (bson_or_null, opts); if (json) { - bson_append_utf8 (bson, key_or_null, -1, json, json_length); - bson_free (json); + BSON_ASSERT (json->len <= (uint32_t) INT_MAX); + bson_append_utf8 (bson, key_or_null, -1, json->str, (int) json->len); + mcommon_string_destroy (json); } + // If invalid BSON was found in the input, the key is not logged. } else { bson_append_null (bson, key_or_null, -1); } @@ -646,27 +758,14 @@ _mongoc_structured_log_append_cmd (bson_t *bson, if (mongoc_apm_is_sensitive_command_message (cmd->command_name, cmd->command)) { BSON_APPEND_UTF8 (bson, "command", "{}"); } else { - bson_t *command_copy = NULL; - - if (cmd->payloads_count > 0) { - // @todo This is a performance bottleneck, we shouldn't be copying - // a potentially large command to serialize a potentially very - // small part of it. We should be appending JSON to a single buffer - // for all nesting levels, constrained by length limit, while visiting - // borrowed references to each command attribute and each payload. CDRIVER-4814 - command_copy = bson_copy (cmd->command); - _mongoc_cmd_append_payload_as_array (cmd, command_copy); - } - - size_t json_length; - char *json = _mongoc_structured_log_inner_document_to_json ( - command_copy ? command_copy : cmd->command, &json_length, opts); + mcommon_string_t *json = _mongoc_structured_log_command_with_payloads_as_truncated_json (cmd, opts); if (json) { const char *key = "command"; - bson_append_utf8 (bson, key, strlen (key), json, json_length); - bson_free (json); + BSON_ASSERT (json->len <= (uint32_t) INT_MAX); + bson_append_utf8 (bson, key, strlen (key), json->str, (int) json->len); + mcommon_string_destroy (json); } - bson_destroy (command_copy); + // If invalid BSON was found in the input, the key is not logged. } } @@ -682,13 +781,14 @@ _mongoc_structured_log_append_redacted_cmd_reply (bson_t *bson, if (is_sensitive) { BSON_APPEND_UTF8 (bson, "reply", "{}"); } else { - size_t json_length; - char *json = _mongoc_structured_log_inner_document_to_json (reply, &json_length, opts); + mcommon_string_t *json = _mongoc_structured_log_document_as_truncated_json (reply, opts); if (json) { const char *key = "reply"; - bson_append_utf8 (bson, key, strlen (key), json, json_length); - bson_free (json); + BSON_ASSERT (json->len <= (uint32_t) INT_MAX); + bson_append_utf8 (bson, key, strlen (key), json->str, (int) json->len); + mcommon_string_destroy (json); } + // If invalid BSON was found in the input, the key is not logged. } } diff --git a/src/libmongoc/tests/test-mongoc-structured-log.c b/src/libmongoc/tests/test-mongoc-structured-log.c index fa32b1d35c6..e18309c9a1c 100644 --- a/src/libmongoc/tests/test-mongoc-structured-log.c +++ b/src/libmongoc/tests/test-mongoc-structured-log.c @@ -466,52 +466,56 @@ test_structured_log_command (void) .expected_envelope.level = MONGOC_STRUCTURED_LOG_LEVEL_WARNING, .expected_envelope.component = MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, .expected_envelope.message = "Log entry with command and reply fields", - .expected_bson = BCON_NEW ("message", - BCON_UTF8 ("Log entry with command and reply fields"), - "commandName", - BCON_UTF8 ("Not a command"), - "databaseName", - BCON_UTF8 ("Some database"), - "commandName", - BCON_UTF8 ("Not a command"), - "operationId", - BCON_INT64 (0x12345678eeff0011), - "command", - BCON_UTF8 ("{ \"c\" : \"d\" }"), - "reply", // Un-redacted successful reply (not-a-command) - BCON_UTF8 ("{ \"r\" : \"s\", \"code\" : 1 }"), - "reply", // Un-redacted successful reply (ping) - BCON_UTF8 ("{ \"r\" : \"s\", \"code\" : 1 }"), - "reply", // Redacted successful reply (auth) - BCON_UTF8 ("{}"), - "failure", // Un-redacted server side error (not-a-command) - "{", - "r", - BCON_UTF8 ("s"), - "code", - BCON_INT32 (1), - "}", - "failure", // Un-redacted server side error (ping) - "{", - "r", - BCON_UTF8 ("s"), - "code", - BCON_INT32 (1), - "}", - "failure", // Redacted server side error (auth) - "{", - "code", - BCON_INT32 (1), - "}", - "failure", // Client side error - "{", - "code", - BCON_INT32 (123), - "domain", - BCON_INT32 (456), - "message", - BCON_UTF8 ("oh no"), - "}"), + .expected_bson = + BCON_NEW ("message", + BCON_UTF8 ("Log entry with command and reply fields"), + "commandName", + BCON_UTF8 ("Not a command"), + "databaseName", + BCON_UTF8 ("Some database"), + "commandName", + BCON_UTF8 ("Not a command"), + "operationId", + BCON_INT64 (0x12345678eeff0011), + "command", + BCON_UTF8 ("{ \"c\" : \"d\", \"first_payload\" : [ { \"i\" : 0, \"x\" : 0 }, { \"i\" : 0, \"x\" : 1 " + "}, { \"i\" : 0, \"x\" : 2 }, { \"i\" : 0, \"x\" : 3 }, { \"i\" : 0, \"x\" : 4 } ], " + "\"second_payload\" : [ { \"i\" : 1, \"x\" : 0 }, { \"i\" : 1, \"x\" : 1 }, { \"i\" : 1, " + "\"x\" : 2 }, { \"i\" : 1, \"x\" : 3 }, { \"i\" : 1, \"x\" : 4 } ] }"), + "reply", // Un-redacted successful reply (not-a-command) + BCON_UTF8 ("{ \"r\" : \"s\", \"code\" : 1 }"), + "reply", // Un-redacted successful reply (ping) + BCON_UTF8 ("{ \"r\" : \"s\", \"code\" : 1 }"), + "reply", // Redacted successful reply (auth) + BCON_UTF8 ("{}"), + "failure", // Un-redacted server side error (not-a-command) + "{", + "r", + BCON_UTF8 ("s"), + "code", + BCON_INT32 (1), + "}", + "failure", // Un-redacted server side error (ping) + "{", + "r", + BCON_UTF8 ("s"), + "code", + BCON_INT32 (1), + "}", + "failure", // Redacted server side error (auth) + "{", + "code", + BCON_INT32 (1), + "}", + "failure", // Client side error + "{", + "code", + BCON_INT32 (123), + "domain", + BCON_INT32 (456), + "message", + BCON_UTF8 ("oh no"), + "}"), .expected_calls = 1, }; @@ -529,13 +533,44 @@ test_structured_log_command (void) .message = "oh no", }; + // Current value of MONGOC_CMD_PAYLOADS_COUNT_MAX is 2. + // Write two payloads, each with multiple documents in sequence. + uint8_t *payload_buf[2] = {NULL, NULL}; + size_t payload_buflen[2] = {0, 0}; + bson_writer_t *payload_writer[2] = { + bson_writer_new (&payload_buf[0], &payload_buflen[0], 0, bson_realloc_ctx, NULL), + bson_writer_new (&payload_buf[1], &payload_buflen[1], 0, bson_realloc_ctx, NULL), + }; + for (unsigned x = 0; x < 5; x++) { + for (unsigned i = 0; i < sizeof payload_writer / sizeof payload_writer[0]; i++) { + bson_t *doc; + bson_writer_begin (payload_writer[i], &doc); + BCON_APPEND (doc, "i", BCON_INT32 (i), "x", BCON_INT32 (x)); + bson_writer_end (payload_writer[i]); + } + } + mongoc_cmd_t cmd = { .db_name = "Some database", .command_name = "Not a command", .operation_id = 0x12345678eeff0011, .command = cmd_doc, + .payloads = + { + {.identifier = "first_payload", + .documents = payload_buf[0], + .size = bson_writer_get_length (payload_writer[0])}, + {.identifier = "second_payload", + .documents = payload_buf[1], + .size = bson_writer_get_length (payload_writer[0])}, + }, + .payloads_count = 2, }; + for (unsigned i = 0; i < sizeof payload_writer / sizeof payload_writer[0]; i++) { + bson_writer_destroy (payload_writer[i]); + } + mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); @@ -562,6 +597,9 @@ test_structured_log_command (void) bson_destroy (assumption.expected_bson); bson_destroy (cmd_doc); bson_destroy (reply_doc); + for (unsigned i = 0; i < sizeof payload_buf / sizeof payload_buf[0]; i++) { + bson_free (payload_buf[i]); + } } void From c0ac63b86fc60190a17f3cfb670f78af41c0328e Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Tue, 14 Jan 2025 18:16:21 -0800 Subject: [PATCH 02/23] Add libmongoc API control for MONGODB_LOG_MAX_DOCUMENT_LENGTH setting --- ...tured_log_opts_get_max_document_length.rst | 27 +++++++++++++ ...tured_log_opts_set_max_document_length.rst | 34 ++++++++++++++++ ..._opts_set_max_document_length_from_env.rst | 34 ++++++++++++++++ .../doc/mongoc_structured_log_opts_t.rst | 3 ++ .../src/mongoc/mongoc-structured-log.c | 40 ++++++++++++++----- .../src/mongoc/mongoc-structured-log.h | 9 +++++ .../tests/test-mongoc-structured-log.c | 17 ++++++++ 7 files changed, 155 insertions(+), 9 deletions(-) create mode 100644 src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst create mode 100644 src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst create mode 100644 src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length_from_env.rst diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst b/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst new file mode 100644 index 00000000000..32bd4057a51 --- /dev/null +++ b/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst @@ -0,0 +1,27 @@ +:man_page: mongoc_structured_log_opts_get_max_document_length + +mongoc_structured_log_opts_get_max_document_length() +==================================================== + +Synopsis +-------- + +.. code-block:: c + + size_t + mongoc_structured_log_opts_get_max_document_length (const mongoc_structured_log_opts_t *opts); + +Parameters +---------- + +* ``opts``: Structured log options, allocated with :symbol:`mongoc_structured_log_opts_new`. + +Returns +------- + +Returns the current maximum document length set in ``opts``, as a ``size_t``. Always succeeds. +This may be the last value set with :symbol:`mongoc_structured_log_opts_set_max_document_length` or it may be an environment variable captured by :symbol:`mongoc_structured_log_opts_set_max_document_length_from_env` or :symbol:`mongoc_structured_log_opts_new`. + +.. seealso:: + + | :doc:`structured_log` diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst new file mode 100644 index 00000000000..64807e354b1 --- /dev/null +++ b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst @@ -0,0 +1,34 @@ +:man_page: :man_page: mongoc_structured_log_opts_set_max_document_length + +:man_page: mongoc_structured_log_opts_set_max_document_length() +=============================================================== + +Synopsis +-------- + +.. code-block:: c + + bool + mongoc_structured_log_opts_set_max_document_length (mongoc_structured_log_opts_t *opts, + size_t max_document_length); + +Sets a maximum length for BSON documents that appear serialized in JSON form as part of a structured log message. + +This setting is captured from the environment during :symbol:`mongoc_structured_log_opts_new` if a valid setting is found for the ``MONGODB_LOG_MAX_DOCUMENT_LENGTH`` environment variable. + +Serialized JSON will be truncated at this limit, interpreted as a count of UTF-8 encoded bytes. Truncation will be indicated with a ``...`` suffix, the length of which is not included in the max document length. If truncation at the exact indicated length would split a valid UTF-8 sequence, we instead truncate the document earlier at the nearest boundary between code points. + +Parameters +---------- + +* ``opts``: Structured log options, allocated with :symbol:`mongoc_structured_log_opts_new`. +* ``max_document_length``: Maximum length for each embedded JSON document, in bytes, not including an ellipsis (``...``) added to indicate truncation. Values near or above ``INT_MAX`` will be rejected. + +Returns +------- + +Returns ``true`` on success, or ``false`` if the supplied maximum length is too large. + +.. seealso:: + + | :doc:`structured_log` diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length_from_env.rst b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length_from_env.rst new file mode 100644 index 00000000000..7fe2eb09da7 --- /dev/null +++ b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length_from_env.rst @@ -0,0 +1,34 @@ +:man_page: mongoc_structured_log_opts_set_max_document_length_from_env + +mongoc_structured_log_opts_set_max_document_length_from_env() +============================================================= + +Synopsis +-------- + +.. code-block:: c + + bool + mongoc_structured_log_opts_set_max_document_length_from_env (mongoc_structured_log_opts_t *opts); + +Sets a maximum document length from the ``MONGODB_LOG_MAX_DOCUMENT_LENGTH`` environment variable, if a valid setting is found. +See :symbol:`mongoc_structured_log_opts_new` for a description of the supported environment variable formats. + +Parse errors may cause a warning message, delivered via unstructured logging. + +This happens automatically when :symbol:`mongoc_structured_log_opts_new` establishes defaults. +Any subsequent programmatic modifications to the :symbol:`mongoc_structured_log_opts_t` will override the environment variable settings. +For applications that desire the opposite behavior, where environment variables may override programmatic settings, they may call ``mongoc_structured_log_opts_set_max_document_length_from_env()`` after calling :symbol:`mongoc_structured_log_opts_set_max_document_length`. +This will process the environment a second time, allowing it to override customized defaults. + +Returns +------- + +Returns ``true`` on success: either a valid environment setting was found, or the value is unset and ``opts`` will not be modified. +If warnings are encountered in the environment, returns ``false`` and may log additional information to the unstructured logging facility. +Note that, by design, these errors are by default non-fatal. +When :symbol:`mongoc_structured_log_opts_new` internally calls this function, it ignores the return value. + +.. seealso:: + + | :doc:`structured_log` diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_t.rst b/src/libmongoc/doc/mongoc_structured_log_opts_t.rst index 414c24d804a..fbd7eb6714c 100644 --- a/src/libmongoc/doc/mongoc_structured_log_opts_t.rst +++ b/src/libmongoc/doc/mongoc_structured_log_opts_t.rst @@ -29,6 +29,9 @@ Functions mongoc_structured_log_opts_set_max_level_for_all_components mongoc_structured_log_opts_set_max_levels_from_env mongoc_structured_log_opts_get_max_level_for_component + mongoc_structured_log_opts_set_max_document_length + mongoc_structured_log_opts_set_max_document_length_from_env + mongoc_structured_log_opts_get_max_document_length .. seealso:: diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index d551e383a9a..06c30e701b8 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -270,25 +270,46 @@ mongoc_structured_log_get_named_component (const char *name, mongoc_structured_l return false; } -static uint32_t -_mongoc_structured_log_get_max_document_length_from_env (void) +size_t +mongoc_structured_log_opts_get_max_document_length (const mongoc_structured_log_opts_t *opts) { + return (size_t) opts->max_document_length; +} + +bool +mongoc_structured_log_opts_set_max_document_length (mongoc_structured_log_opts_t *opts, size_t max_document_length) +{ + if (max_document_length <= (size_t) MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH) { + opts->max_document_length = (uint32_t) max_document_length; + return true; + } else { + return false; + } +} + +bool +mongoc_structured_log_opts_set_max_document_length_from_env (mongoc_structured_log_opts_t *opts) +{ + BSON_ASSERT_PARAM (opts); + const char *variable = "MONGODB_LOG_MAX_DOCUMENT_LENGTH"; const char *max_length_str = getenv (variable); if (!max_length_str) { - return MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH; + return true; } if (!strcasecmp (max_length_str, "unlimited")) { - return MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH; + BSON_ASSERT ( + mongoc_structured_log_opts_set_max_document_length (opts, MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH)); + return true; } char *endptr; long int_value = strtol (max_length_str, &endptr, 10); - if (int_value >= 0 && int_value <= (long) MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH && - endptr != max_length_str && !*endptr) { - return (uint32_t) int_value; + if (int_value >= 0 && endptr != max_length_str && !*endptr && mcommon_in_range_signed (size_t, int_value) && + mongoc_structured_log_opts_set_max_document_length (opts, (size_t) int_value)) { + return true; } // Only log the first instance of each error per process @@ -296,7 +317,7 @@ _mongoc_structured_log_get_max_document_length_from_env (void) if (0 == mcommon_atomic_int_fetch_add (&err_count_atomic, 1, mcommon_memory_order_seq_cst)) { MONGOC_WARNING ("Invalid length '%s' read from environment variable %s. Ignoring it.", max_length_str, variable); } - return MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH; + return false; } bool @@ -422,7 +443,8 @@ mongoc_structured_log_opts_new (void) * If environment variables can't be parsed, warnings will be logged once but we must, by specification, * continue to provide structured logging using whatever valid or default settings remain. */ opts->default_handler_path = bson_strdup (getenv ("MONGODB_LOG_PATH")); - opts->max_document_length = _mongoc_structured_log_get_max_document_length_from_env (); + opts->max_document_length = MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH; + (void) mongoc_structured_log_opts_set_max_document_length_from_env (opts); (void) mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_DEFAULT_LEVEL); (void) mongoc_structured_log_opts_set_max_levels_from_env (opts); diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.h b/src/libmongoc/src/mongoc/mongoc-structured-log.h index 468e408d415..5bddc36ba24 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.h +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.h @@ -77,6 +77,15 @@ MONGOC_EXPORT (mongoc_structured_log_level_t) mongoc_structured_log_opts_get_max_level_for_component (const mongoc_structured_log_opts_t *opts, mongoc_structured_log_component_t component); +MONGOC_EXPORT (size_t) +mongoc_structured_log_opts_get_max_document_length (const mongoc_structured_log_opts_t *opts); + +MONGOC_EXPORT (bool) +mongoc_structured_log_opts_set_max_document_length_from_env (mongoc_structured_log_opts_t *opts); + +MONGOC_EXPORT (bool) +mongoc_structured_log_opts_set_max_document_length (mongoc_structured_log_opts_t *opts, size_t max_document_length); + MONGOC_EXPORT (bson_t *) mongoc_structured_log_entry_message_as_bson (const mongoc_structured_log_entry_t *entry); diff --git a/src/libmongoc/tests/test-mongoc-structured-log.c b/src/libmongoc/tests/test-mongoc-structured-log.c index e18309c9a1c..2af26ffc4ff 100644 --- a/src/libmongoc/tests/test-mongoc-structured-log.c +++ b/src/libmongoc/tests/test-mongoc-structured-log.c @@ -737,6 +737,22 @@ test_structured_log_component_names (void) ASSERT_CMPSTR (mongoc_structured_log_get_component_name (component), "connection"); } +void +test_structured_log_max_document_length (void) +{ + mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); + + // Test assumes no environment variable option is set + ASSERT_CMPINT ( + MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH, ==, mongoc_structured_log_opts_get_max_document_length (opts)); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 0)); + ASSERT (!mongoc_structured_log_opts_set_max_document_length (opts, INT_MAX)); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, INT_MAX / 2)); + ASSERT_CMPINT (INT_MAX / 2, ==, mongoc_structured_log_opts_get_max_document_length (opts)); + + mongoc_structured_log_opts_destroy (opts); +} + void test_structured_log_install (TestSuite *suite) { @@ -752,4 +768,5 @@ test_structured_log_install (TestSuite *suite) TestSuite_Add (suite, "/structured_log/duration", test_structured_log_duration); TestSuite_Add (suite, "/structured_log/level_names", test_structured_log_level_names); TestSuite_Add (suite, "/structured_log/component_names", test_structured_log_component_names); + TestSuite_Add (suite, "/structured_log/max_document_length", test_structured_log_max_document_length); } From ba40de323e2936df4bc37520cb328e2f37dbf92f Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Tue, 14 Jan 2025 18:24:30 -0800 Subject: [PATCH 03/23] Unified tests use the suggested max document length of 10000 from the spec --- src/libmongoc/tests/unified/entity-map.c | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/libmongoc/tests/unified/entity-map.c b/src/libmongoc/tests/unified/entity-map.c index 286c8136fe3..03f29d21065 100644 --- a/src/libmongoc/tests/unified/entity-map.c +++ b/src/libmongoc/tests/unified/entity-map.c @@ -600,6 +600,9 @@ entity_client_new (entity_map_t *em, bson_t *bson, bson_error_t *error) BSON_ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components ( log_opts, MONGOC_STRUCTURED_LOG_LEVEL_EMERGENCY)); mongoc_structured_log_opts_set_handler (log_opts, structured_log_cb, entity); + // From the Command Logging and Monitoring / Testing spec, unified tests MUST be run with their max + // document length set to "a large value e.g. 10,000". Note that the default setting is 1000. + mongoc_structured_log_opts_set_max_document_length (log_opts, 10000); }), visitEach ( if (not(type (utf8)), then (error ("Every value in 'observeLogMessages' must be a log level string"))), From f616c881c1f8dae128bec982b3a1ed3c74ec1271 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Tue, 14 Jan 2025 22:33:57 -0800 Subject: [PATCH 04/23] command-logging-and-monitoring prose tests --- src/libmongoc/CMakeLists.txt | 1 + src/libmongoc/tests/test-libmongoc-main.c | 1 + ...st-mongoc-command-logging-and-monitoring.c | 359 ++++++++++++++++++ 3 files changed, 361 insertions(+) create mode 100644 src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c diff --git a/src/libmongoc/CMakeLists.txt b/src/libmongoc/CMakeLists.txt index dab7ce87d1d..2343df2ed02 100644 --- a/src/libmongoc/CMakeLists.txt +++ b/src/libmongoc/CMakeLists.txt @@ -1096,6 +1096,7 @@ set (test-libmongoc-sources ${PROJECT_SOURCE_DIR}/tests/test-mongoc-collection-find-with-opts.c ${PROJECT_SOURCE_DIR}/tests/test-mongoc-collection-find.c ${PROJECT_SOURCE_DIR}/tests/test-mongoc-collection.c + ${PROJECT_SOURCE_DIR}/tests/test-mongoc-command-logging-and-monitoring.c ${PROJECT_SOURCE_DIR}/tests/test-mongoc-command-monitoring.c ${PROJECT_SOURCE_DIR}/tests/test-mongoc-connection-uri.c ${PROJECT_SOURCE_DIR}/tests/test-mongoc-counters.c diff --git a/src/libmongoc/tests/test-libmongoc-main.c b/src/libmongoc/tests/test-libmongoc-main.c index 20b25c40cfa..18fa2b820ee 100644 --- a/src/libmongoc/tests/test-libmongoc-main.c +++ b/src/libmongoc/tests/test-libmongoc-main.c @@ -70,6 +70,7 @@ main (int argc, char *argv[]) TEST_INSTALL (test_collection_find_install); TEST_INSTALL (test_collection_find_with_opts_install); TEST_INSTALL (test_connection_uri_install); + TEST_INSTALL (test_command_logging_and_monitoring_install); TEST_INSTALL (test_command_monitoring_install); TEST_INSTALL (test_cursor_install); TEST_INSTALL (test_database_install); diff --git a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c new file mode 100644 index 00000000000..8c5f72648f6 --- /dev/null +++ b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c @@ -0,0 +1,359 @@ +#include + +#include "test-libmongoc.h" +#include "test-conveniences.h" +#include "mongoc/mongoc-array-private.h" +#include "TestSuite.h" + +static void +stored_log_handler (const mongoc_structured_log_entry_t *entry, void *user_data) +{ + mongoc_array_t *log_array = (mongoc_array_t *) user_data; + bson_t *doc = mongoc_structured_log_entry_message_as_bson (entry); + MONGOC_DEBUG ("stored log: %s", tmp_json (doc)); + _mongoc_array_append_val (log_array, doc); +} + +static void +stored_log_clear (mongoc_array_t *log_array) +{ + for (size_t i = 0; i < log_array->len; i++) { + bson_t *doc = _mongoc_array_index (log_array, bson_t *, i); + bson_destroy (doc); + } + _mongoc_array_clear (log_array); +} + +/* specifications/source/command-logging-and-monitoring/tests/README.md + * Test 1: Default truncation limit */ +static void +prose_test_1 (void) +{ + // 1. Configure logging with a minimum severity level of "debug" for the "command" component. Do not explicitly + // configure the max document length. + mongoc_client_t *client = test_framework_new_default_client (); + mongoc_array_t stored_log; + _mongoc_array_init (&stored_log, sizeof (bson_t *)); + { + mongoc_structured_log_opts_t *log_opts = mongoc_structured_log_opts_new (); + + mongoc_structured_log_opts_set_max_level_for_component ( + log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG); + + mongoc_structured_log_opts_set_handler (log_opts, stored_log_handler, &stored_log); + + mongoc_client_set_structured_log_opts (client, log_opts); + mongoc_structured_log_opts_destroy (log_opts); + } + mongoc_collection_t *coll = mongoc_client_get_collection (client, "db", "coll"); + + // 2. Construct an array docs containing the document {"x" : "y"} repeated 100 times. + bson_t *docs[100]; + for (unsigned i = 0; i < sizeof docs / sizeof docs[0]; i++) { + docs[i] = tmp_bson (BSON_STR ({"x" : "y"})); + } + + // 3. Insert docs to a collection via insertMany. + bson_error_t error; + ASSERT_OR_PRINT ( + mongoc_collection_insert_many (coll, (const bson_t **) docs, sizeof docs / sizeof docs[0], NULL, NULL, &error), + error); + + // 4. Inspect the resulting "command started" log message and assert that the "command" value is a string of length + // 1000 + (length of trailing ellipsis). + { + ASSERT (stored_log.len >= 1); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 0); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command started"); + ASSERT (bson_iter_find (&iter, "command")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + uint32_t command_len; + const char *command = bson_iter_utf8 (&iter, &command_len); + ASSERT (command); + ASSERT_CMPUINT32 (command_len, ==, 1003); + } + + // 5. Inspect the resulting "command succeeded" log message and assert that the "reply" value is a string of length + // <= 1000 + (length of trailing ellipsis). + { + ASSERT (stored_log.len == 2); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 1); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command succeeded"); + ASSERT (bson_iter_find (&iter, "reply")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + uint32_t reply_len; + const char *reply = bson_iter_utf8 (&iter, &reply_len); + ASSERT (reply); + ASSERT_CMPUINT32 (reply_len, <=, 1003); + } + + // 6. Run find() on the collection where the document was inserted. + stored_log_clear (&stored_log); + mongoc_cursor_t *cursor = mongoc_collection_find_with_opts (coll, tmp_bson ("{}"), NULL, NULL); + ASSERT (cursor); + { + const bson_t *doc; + ASSERT (mongoc_cursor_next (cursor, &doc)); + } + + // 7. Inspect the resulting "command succeeded" log message and assert that the reply is a string of length 1000 + + // (length of trailing ellipsis). + { + ASSERT (stored_log.len >= 1); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 0); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command started"); + } + { + ASSERT (stored_log.len == 2); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 1); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command succeeded"); + ASSERT (bson_iter_find (&iter, "reply")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + uint32_t reply_len; + const char *reply = bson_iter_utf8 (&iter, &reply_len); + ASSERT (reply); + printf ("rep %s\n", reply); + ASSERT_CMPUINT32 (reply_len, ==, 1003); + } + + mongoc_cursor_destroy (cursor); + mongoc_collection_destroy (coll); + mongoc_client_destroy (client); + stored_log_clear (&stored_log); + _mongoc_array_destroy (&stored_log); +} + +/* Test 2: Explicitly configured truncation limit */ +static void +prose_test_2 (void) +{ + // 1. Configure logging with a minimum severity level of "debug" for the "command" component. Set the max document + // length to 5. + mongoc_client_t *client = test_framework_new_default_client (); + mongoc_array_t stored_log; + _mongoc_array_init (&stored_log, sizeof (bson_t *)); + { + mongoc_structured_log_opts_t *log_opts = mongoc_structured_log_opts_new (); + + mongoc_structured_log_opts_set_max_document_length (log_opts, 5); + mongoc_structured_log_opts_set_max_level_for_component ( + log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG); + + mongoc_structured_log_opts_set_handler (log_opts, stored_log_handler, &stored_log); + + mongoc_client_set_structured_log_opts (client, log_opts); + mongoc_structured_log_opts_destroy (log_opts); + } + + // 2. Run the command {"hello": true}. + { + bson_error_t error; + ASSERT_OR_PRINT ( + mongoc_client_command_simple (client, "db", tmp_bson (BSON_STR ({"hello" : true})), NULL, NULL, &error), + error); + } + + // 3. Inspect the resulting "command started" log message and assert that the "command" value is a string of length 5 + // + (length of trailing ellipsis). + { + ASSERT (stored_log.len >= 1); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 0); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command started"); + ASSERT (bson_iter_find (&iter, "command")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + uint32_t command_len; + const char *command = bson_iter_utf8 (&iter, &command_len); + ASSERT (command); + ASSERT_CMPUINT32 (command_len, ==, 5 + 3); + ASSERT_CMPSTR (command, "{ \"he..."); + } + + // 4. Inspect the resulting "command succeeded" log message and assert that the "reply" value is a string of length 5 + // + (length of trailing ellipsis). + { + ASSERT (stored_log.len == 2); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 1); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command succeeded"); + ASSERT (bson_iter_find (&iter, "reply")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + uint32_t reply_len; + const char *reply = bson_iter_utf8 (&iter, &reply_len); + ASSERT (reply); + ASSERT_CMPUINT32 (reply_len, ==, 5 + 3); + } + + // 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). + // + // This is not applicable to libmongoc. The spec allows flexible data type for "failure", and here we chose a + // document rather than a string. The document is not subject to truncation. + // + // While we're here, test that the proposed fake command itself is truncated as expected, and the "failure" is a + // document. + stored_log_clear (&stored_log); + ASSERT ( + !mongoc_client_command_simple (client, "db", tmp_bson (BSON_STR ({"notARealCommand" : true})), NULL, NULL, NULL)); + { + ASSERT (stored_log.len >= 1); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 0); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command started"); + ASSERT (bson_iter_find (&iter, "command")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + uint32_t command_len; + const char *command = bson_iter_utf8 (&iter, &command_len); + ASSERT (command); + ASSERT_CMPUINT32 (command_len, ==, 5 + 3); + ASSERT_CMPSTR (command, "{ \"no..."); + } + { + ASSERT (stored_log.len == 2); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 1); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command failed"); + ASSERT (bson_iter_find (&iter, "failure")); + ASSERT (BSON_ITER_HOLDS_DOCUMENT (&iter)); + } + + mongoc_client_destroy (client); + stored_log_clear (&stored_log); + _mongoc_array_destroy (&stored_log); +} + +/* Test 3: Truncation with multi-byte code points */ +static void +prose_test_3 (void) +{ + // "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." + // + // For libmongoc, our max length is in bytes and truncation will round lengths down if necessary to avoid splitting a + // valid UTF-8 sequence. This test repeatedly sends a fake command to the mock server using every possible maximum + // length, checking for the expected truncations. + + bson_t command = BSON_INITIALIZER; + BSON_APPEND_BOOL (&command, "notARealCommand", true); + BSON_APPEND_UTF8 (&command, "twoByteUtf8", "\xc2\xa9"); + BSON_APPEND_UTF8 (&command, "threeByteUtf8", "\xef\xbf\xbd"); + BSON_APPEND_UTF8 (&command, "fourByteUtf8", "\xf4\x8f\xbf\xbf"); + + // Stop testing after $db, before we reach lsid. The result will always be truncated. + const char *expected_json = "{ \"notARealCommand\" : true, \"twoByteUtf8\" : \"\xc2\xa9\", \"threeByteUtf8\" : " + "\"\xef\xbf\xbd\", \"fourByteUtf8\" : \"\xf4\x8f\xbf\xbf\", \"$db\" : \"db\""; + const int max_expected_length = strlen (expected_json); + + // List of lengths we expect not to see when trying every max_expected_length + static const int expect_missing_lengths[] = {46, 70, 71, 94, 95, 96}; + + mongoc_client_t *client = test_framework_new_default_client (); + + int expected_length = 0; + for (int test_length = 0; test_length <= max_expected_length; test_length++) { + MONGOC_DEBUG ("testing length %d of %d", test_length, max_expected_length); + + // Track the expected length of a serialized string with the max_document_length set to 'test_length'. + // When a length is mentioned in expect_missing_lengths, we let the expected_length lag behind the test_length. + // At this point, the ellipsis length is not included. + bool expect_missing = false; + if (test_length > max_expected_length) { + expect_missing = true; + } else { + for (int missing = 0; missing < sizeof expect_missing_lengths / sizeof expect_missing_lengths[0]; missing++) { + if (expect_missing_lengths[missing] == test_length) { + expect_missing = true; + break; + } + } + } + if (!expect_missing) { + expected_length = test_length; + } + + // Set up the log options for each command, to test this new max_document_length + mongoc_structured_log_opts_t *log_opts = mongoc_structured_log_opts_new (); + mongoc_structured_log_opts_set_max_document_length (log_opts, test_length); + mongoc_structured_log_opts_set_max_level_for_component ( + log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG); + + mongoc_array_t stored_log; + _mongoc_array_init (&stored_log, sizeof (bson_t *)); + mongoc_structured_log_opts_set_handler (log_opts, stored_log_handler, &stored_log); + mongoc_client_set_structured_log_opts (client, log_opts); + mongoc_structured_log_opts_destroy (log_opts); + + ASSERT (!mongoc_client_command_simple (client, "db", &command, NULL, NULL, NULL)); + + ASSERT (stored_log.len >= 1); + bson_t *log = _mongoc_array_index (&stored_log, bson_t *, 0); + bson_iter_t iter; + ASSERT (bson_iter_init (&iter, log)); + ASSERT (bson_iter_find (&iter, "message")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command started"); + ASSERT (bson_iter_find (&iter, "command")); + ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); + uint32_t command_len; + const char *command = bson_iter_utf8 (&iter, &command_len); + ASSERT (command); + ASSERT_CMPUINT32 (command_len, ==, expected_length + 3); + + // Note that here we do not use mcommon_string to truncate, just as a convenient way to represent the + // expected string with ellipsis for ASSERT_CMPSTR. (The code under test internally uses mcommon_string_append_t + // also.) + mcommon_string_append_t expected_json_truncated; + mcommon_string_new_as_append (&expected_json_truncated); + mcommon_string_append_bytes (&expected_json_truncated, expected_json, expected_length); + mcommon_string_append (&expected_json_truncated, "..."); + ASSERT_CMPSTR (command, mcommon_str_from_append (&expected_json_truncated)); + mcommon_string_from_append_destroy (&expected_json_truncated); + + mongoc_client_set_structured_log_opts (client, NULL); + stored_log_clear (&stored_log); + _mongoc_array_destroy (&stored_log); + } + + mongoc_client_destroy (client); + bson_destroy (&command); +} + +void +test_command_logging_and_monitoring_install (TestSuite *suite) +{ + TestSuite_Add (suite, "/command-logging-and-monitoring/logging/prose_test_1", prose_test_1); + TestSuite_Add (suite, "/command-logging-and-monitoring/logging/prose_test_2", prose_test_2); + TestSuite_Add (suite, "/command-logging-and-monitoring/logging/prose_test_3", prose_test_3); +} From c3869235af6a9bd1b8b4de83b3145fc11aea5041 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Wed, 15 Jan 2025 12:18:41 -0800 Subject: [PATCH 05/23] Remove extra :man_page: tag --- .../mongoc_structured_log_opts_set_max_document_length.rst | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst index 64807e354b1..29ee42ba1bf 100644 --- a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst +++ b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst @@ -1,7 +1,7 @@ -:man_page: :man_page: mongoc_structured_log_opts_set_max_document_length +:man_page: mongoc_structured_log_opts_set_max_document_length -:man_page: mongoc_structured_log_opts_set_max_document_length() -=============================================================== +mongoc_structured_log_opts_set_max_document_length() +==================================================== Synopsis -------- From 8bde27eba3ccd99d5c73f3c09d5718805d07d17b Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Wed, 15 Jan 2025 12:22:50 -0800 Subject: [PATCH 06/23] Mark prose tests as requiring a live server --- .../tests/test-mongoc-command-logging-and-monitoring.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c index 8c5f72648f6..6cf4fd253fc 100644 --- a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c +++ b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c @@ -353,7 +353,7 @@ prose_test_3 (void) void test_command_logging_and_monitoring_install (TestSuite *suite) { - TestSuite_Add (suite, "/command-logging-and-monitoring/logging/prose_test_1", prose_test_1); - TestSuite_Add (suite, "/command-logging-and-monitoring/logging/prose_test_2", prose_test_2); - TestSuite_Add (suite, "/command-logging-and-monitoring/logging/prose_test_3", prose_test_3); + TestSuite_AddLive (suite, "/command-logging-and-monitoring/logging/prose_test_1", prose_test_1); + TestSuite_AddLive (suite, "/command-logging-and-monitoring/logging/prose_test_2", prose_test_2); + TestSuite_AddLive (suite, "/command-logging-and-monitoring/logging/prose_test_3", prose_test_3); } From a940fc44dc222bd07431df7d1e15116fc3392e60 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Wed, 15 Jan 2025 12:54:39 -0800 Subject: [PATCH 07/23] Check more API return values in CLAM logging prose tests --- ...st-mongoc-command-logging-and-monitoring.c | 24 +++++++++---------- 1 file changed, 12 insertions(+), 12 deletions(-) diff --git a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c index 6cf4fd253fc..6af377e8716 100644 --- a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c +++ b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c @@ -37,12 +37,12 @@ prose_test_1 (void) { mongoc_structured_log_opts_t *log_opts = mongoc_structured_log_opts_new (); - mongoc_structured_log_opts_set_max_level_for_component ( - log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG); + ASSERT (mongoc_structured_log_opts_set_max_level_for_component ( + log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_opts_set_handler (log_opts, stored_log_handler, &stored_log); - mongoc_client_set_structured_log_opts (client, log_opts); + ASSERT (mongoc_client_set_structured_log_opts (client, log_opts)); mongoc_structured_log_opts_destroy (log_opts); } mongoc_collection_t *coll = mongoc_client_get_collection (client, "db", "coll"); @@ -151,13 +151,13 @@ prose_test_2 (void) { mongoc_structured_log_opts_t *log_opts = mongoc_structured_log_opts_new (); - mongoc_structured_log_opts_set_max_document_length (log_opts, 5); - mongoc_structured_log_opts_set_max_level_for_component ( - log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG); + ASSERT (mongoc_structured_log_opts_set_max_document_length (log_opts, 5)); + ASSERT (mongoc_structured_log_opts_set_max_level_for_component ( + log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_opts_set_handler (log_opts, stored_log_handler, &stored_log); - mongoc_client_set_structured_log_opts (client, log_opts); + ASSERT (mongoc_client_set_structured_log_opts (client, log_opts)); mongoc_structured_log_opts_destroy (log_opts); } @@ -305,14 +305,14 @@ prose_test_3 (void) // Set up the log options for each command, to test this new max_document_length mongoc_structured_log_opts_t *log_opts = mongoc_structured_log_opts_new (); - mongoc_structured_log_opts_set_max_document_length (log_opts, test_length); - mongoc_structured_log_opts_set_max_level_for_component ( - log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG); + ASSERT (mongoc_structured_log_opts_set_max_document_length (log_opts, test_length)); + ASSERT (mongoc_structured_log_opts_set_max_level_for_component ( + log_opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_array_t stored_log; _mongoc_array_init (&stored_log, sizeof (bson_t *)); mongoc_structured_log_opts_set_handler (log_opts, stored_log_handler, &stored_log); - mongoc_client_set_structured_log_opts (client, log_opts); + ASSERT (mongoc_client_set_structured_log_opts (client, log_opts)); mongoc_structured_log_opts_destroy (log_opts); ASSERT (!mongoc_client_command_simple (client, "db", &command, NULL, NULL, NULL)); @@ -341,7 +341,7 @@ prose_test_3 (void) ASSERT_CMPSTR (command, mcommon_str_from_append (&expected_json_truncated)); mcommon_string_from_append_destroy (&expected_json_truncated); - mongoc_client_set_structured_log_opts (client, NULL); + ASSERT (mongoc_client_set_structured_log_opts (client, NULL)); stored_log_clear (&stored_log); _mongoc_array_destroy (&stored_log); } From e58dc1e9930ed87ba2f67c2332bb704ab04151b9 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Wed, 15 Jan 2025 16:16:26 -0800 Subject: [PATCH 08/23] Update for compatibility with #1821 PR #1821, merged as commit d08d455fed4312cd785f614a49a1d7abb917193d, included a TODO for this truncation refactor. Updated to use the new internal function _mongoc_structured_log_document_as_truncated_json, and to ASSERT that the length is now guaranteed not to overflow on cast. --- src/libmongoc/src/mongoc/mongoc-structured-log.c | 15 +++++---------- 1 file changed, 5 insertions(+), 10 deletions(-) diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index d4c0c39b7a1..7067bb773ec 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -1019,18 +1019,13 @@ _mongoc_structured_log_append_topology_as_description_json (bson_t *bson, mc_shared_tpld td = mc_tpld_take_ref (topology_or_null); bson_t inner_bson = BSON_INITIALIZER; mongoc_topology_description_append_contents_to_bson (td.ptr, &inner_bson, td_flags, server_flags); - size_t json_length; - char *json = _mongoc_structured_log_inner_document_to_json (&inner_bson, &json_length, opts); - /* TODO: This will be replaced shortly with a spec compliant string truncation implementation. - * Note the INT_MAX size limit specific to bson_append_utf8(), vs the UINT32_MAX-1 internal limits. - * This check will move as part of centralizing truncation behavior, with the benefits of - * preserving UTF-8 sequence integrity and consistently inserting "..." when truncating. - */ + mcommon_string_t *json = _mongoc_structured_log_document_as_truncated_json (&inner_bson, opts); if (json) { - bson_append_utf8 ( - bson, key_or_null, -1, json, json_length > (size_t) INT_MAX ? INT_MAX : (int) json_length); - bson_free (json); + BSON_ASSERT (json->len <= (uint32_t) INT_MAX); + bson_append_utf8 (bson, key_or_null, -1, json->str, (int) json->len); + mcommon_string_destroy (json); } + // If invalid BSON was found in the input, the key is not logged. bson_destroy (&inner_bson); mc_tpld_drop_ref (&td); } else { From fe5f94848d983e421ab0b287a494f4d870a24dd3 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Wed, 15 Jan 2025 16:22:33 -0800 Subject: [PATCH 09/23] Rename local to avoid shadowing --- .../tests/test-mongoc-command-logging-and-monitoring.c | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c index 6af377e8716..399f0747f4c 100644 --- a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c +++ b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c @@ -326,10 +326,10 @@ prose_test_3 (void) ASSERT_CMPSTR (bson_iter_utf8 (&iter, NULL), "Command started"); ASSERT (bson_iter_find (&iter, "command")); ASSERT (BSON_ITER_HOLDS_UTF8 (&iter)); - uint32_t command_len; - const char *command = bson_iter_utf8 (&iter, &command_len); - ASSERT (command); - ASSERT_CMPUINT32 (command_len, ==, expected_length + 3); + uint32_t logged_command_len; + const char *logged_command_str = bson_iter_utf8 (&iter, &logged_command_len); + ASSERT (logged_command_str); + ASSERT_CMPUINT32 (logged_command_len, ==, expected_length + 3); // Note that here we do not use mcommon_string to truncate, just as a convenient way to represent the // expected string with ellipsis for ASSERT_CMPSTR. (The code under test internally uses mcommon_string_append_t @@ -338,7 +338,7 @@ prose_test_3 (void) mcommon_string_new_as_append (&expected_json_truncated); mcommon_string_append_bytes (&expected_json_truncated, expected_json, expected_length); mcommon_string_append (&expected_json_truncated, "..."); - ASSERT_CMPSTR (command, mcommon_str_from_append (&expected_json_truncated)); + ASSERT_CMPSTR (logged_command_str, mcommon_str_from_append (&expected_json_truncated)); mcommon_string_from_append_destroy (&expected_json_truncated); ASSERT (mongoc_client_set_structured_log_opts (client, NULL)); From 9bafef36c624562fe5cb645066cefd0b37b42508 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Thu, 16 Jan 2025 08:33:52 -0800 Subject: [PATCH 10/23] additional document sequence validation return an error in the event the sequence has < 4 bytes of unexpected data at the end. previously, this extra data was silently ignored. --- src/libmongoc/src/mongoc/mongoc-structured-log.c | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index 7067bb773ec..d81a93b34ad 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -617,6 +617,10 @@ _mongoc_structured_log_command_with_payloads_as_truncated_json (const mongoc_cmd } doc_ptr += doc_len; } + if (doc_ptr != doc_end) { + invalid_document = true; + goto done; + } if (!mcommon_string_append (&append, " ]")) { goto done; From 7333080cc980346e96ef702da4bf29c7547f87e2 Mon Sep 17 00:00:00 2001 From: mdbmes Date: Thu, 16 Jan 2025 11:29:58 -0800 Subject: [PATCH 11/23] Update src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst Co-authored-by: Ezra Chung <88335979+eramongodb@users.noreply.github.com> --- .../doc/mongoc_structured_log_opts_get_max_document_length.rst | 1 - 1 file changed, 1 deletion(-) diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst b/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst index 32bd4057a51..4ef52068e8c 100644 --- a/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst +++ b/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst @@ -20,7 +20,6 @@ Returns ------- Returns the current maximum document length set in ``opts``, as a ``size_t``. Always succeeds. -This may be the last value set with :symbol:`mongoc_structured_log_opts_set_max_document_length` or it may be an environment variable captured by :symbol:`mongoc_structured_log_opts_set_max_document_length_from_env` or :symbol:`mongoc_structured_log_opts_new`. .. seealso:: From 039a78a13b3859fbeaca93aa3b2ae9ec6ba9c505 Mon Sep 17 00:00:00 2001 From: mdbmes Date: Thu, 16 Jan 2025 11:30:21 -0800 Subject: [PATCH 12/23] Update src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst Co-authored-by: Ezra Chung <88335979+eramongodb@users.noreply.github.com> --- .../doc/mongoc_structured_log_opts_set_max_document_length.rst | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst index 29ee42ba1bf..a129787d2be 100644 --- a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst +++ b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst @@ -14,8 +14,6 @@ Synopsis Sets a maximum length for BSON documents that appear serialized in JSON form as part of a structured log message. -This setting is captured from the environment during :symbol:`mongoc_structured_log_opts_new` if a valid setting is found for the ``MONGODB_LOG_MAX_DOCUMENT_LENGTH`` environment variable. - Serialized JSON will be truncated at this limit, interpreted as a count of UTF-8 encoded bytes. Truncation will be indicated with a ``...`` suffix, the length of which is not included in the max document length. If truncation at the exact indicated length would split a valid UTF-8 sequence, we instead truncate the document earlier at the nearest boundary between code points. Parameters From 9e71dee2fc400398c9c015d53cb38910452b6de2 Mon Sep 17 00:00:00 2001 From: mdbmes Date: Thu, 16 Jan 2025 11:31:30 -0800 Subject: [PATCH 13/23] Update src/libmongoc/src/mongoc/mongoc-structured-log.c Co-authored-by: Ezra Chung <88335979+eramongodb@users.noreply.github.com> --- src/libmongoc/src/mongoc/mongoc-structured-log.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index d81a93b34ad..970226f467e 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -308,7 +308,7 @@ mongoc_structured_log_opts_set_max_document_length_from_env (mongoc_structured_l char *endptr; long int_value = strtol (max_length_str, &endptr, 10); - if (int_value >= 0 && endptr != max_length_str && !*endptr && mcommon_in_range_signed (size_t, int_value) && + if (int_value >= 0 && endptr != max_length_str && *endptr == '\0' && mcommon_in_range_signed (size_t, int_value) && mongoc_structured_log_opts_set_max_document_length (opts, (size_t) int_value)) { return true; } From c4f816735675dc5dba670bdc4abd55ac5a6c3440 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Thu, 16 Jan 2025 11:38:33 -0800 Subject: [PATCH 14/23] see also --- .../doc/mongoc_structured_log_opts_set_max_document_length.rst | 1 + 1 file changed, 1 insertion(+) diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst index a129787d2be..9c461e27b30 100644 --- a/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst +++ b/src/libmongoc/doc/mongoc_structured_log_opts_set_max_document_length.rst @@ -30,3 +30,4 @@ Returns ``true`` on success, or ``false`` if the supplied maximum length is too .. seealso:: | :doc:`structured_log` + | :symbol:`mongoc_structured_log_opts_set_max_document_length_from_env` From c4c6d16991aadd81bb9a6d8601b176ed0c04abfa Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Thu, 16 Jan 2025 12:41:44 -0800 Subject: [PATCH 15/23] Remove unintended printf --- src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c | 1 - 1 file changed, 1 deletion(-) diff --git a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c index 399f0747f4c..d530b276c6f 100644 --- a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c +++ b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c @@ -128,7 +128,6 @@ prose_test_1 (void) uint32_t reply_len; const char *reply = bson_iter_utf8 (&iter, &reply_len); ASSERT (reply); - printf ("rep %s\n", reply); ASSERT_CMPUINT32 (reply_len, ==, 1003); } From 90909e79780fca8484e1a5602ae5cb1e37a34877 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Thu, 16 Jan 2025 12:42:16 -0800 Subject: [PATCH 16/23] Replace counter with flag for env error guards Expect a very slight microarchitectural speed boost if this path is ever hot. --- src/libmongoc/src/mongoc/mongoc-structured-log.c | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index 970226f467e..bc332752ac2 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -192,7 +192,7 @@ _mongoc_structured_log_with_entry (const mongoc_structured_log_entry_t *entry) static bool _mongoc_structured_log_get_log_level_from_env (const char *variable, mongoc_structured_log_level_t *out, - int volatile *err_count_atomic) + int volatile *err_flag_atomic) { const char *level = getenv (variable); if (!level) { @@ -202,7 +202,7 @@ _mongoc_structured_log_get_log_level_from_env (const char *variable, return true; } // Only log the first instance of each error per process - if (0 == mcommon_atomic_int_fetch_add (err_count_atomic, 1, mcommon_memory_order_seq_cst)) { + if (0 == mcommon_atomic_int_compare_exchange_strong (err_flag_atomic, 0, 1, mcommon_memory_order_seq_cst)) { MONGOC_WARNING ("Invalid log level '%s' read from environment variable %s. Ignoring it.", level, variable); } return false; @@ -314,8 +314,8 @@ mongoc_structured_log_opts_set_max_document_length_from_env (mongoc_structured_l } // Only log the first instance of each error per process - static int err_count_atomic; - if (0 == mcommon_atomic_int_fetch_add (&err_count_atomic, 1, mcommon_memory_order_seq_cst)) { + static int err_flag_atomic; + if (0 == mcommon_atomic_int_compare_exchange_strong (&err_flag_atomic, 0, 1, mcommon_memory_order_seq_cst)) { MONGOC_WARNING ("Invalid length '%s' read from environment variable %s. Ignoring it.", max_length_str, variable); } return false; @@ -331,10 +331,10 @@ mongoc_structured_log_opts_set_max_levels_from_env (mongoc_structured_log_opts_t // Errors are not fatal by default; always reported by return value, and reported the first time only via a log // warning. - static int err_count_all_atomic; - static int err_count_per_component_atomic[STRUCTURED_LOG_COMPONENT_TABLE_SIZE]; + static int err_flag_all_atomic; + static int err_flag_per_component_atomic[STRUCTURED_LOG_COMPONENT_TABLE_SIZE]; - if (_mongoc_structured_log_get_log_level_from_env ("MONGODB_LOG_ALL", &level, &err_count_all_atomic)) { + if (_mongoc_structured_log_get_log_level_from_env ("MONGODB_LOG_ALL", &level, &err_flag_all_atomic)) { BSON_ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, level)); } else { all_ok = false; @@ -342,7 +342,7 @@ mongoc_structured_log_opts_set_max_levels_from_env (mongoc_structured_log_opts_t for (int component = 0; component < STRUCTURED_LOG_COMPONENT_TABLE_SIZE; component++) { if (_mongoc_structured_log_get_log_level_from_env ( - gStructuredLogComponentEnvVars[component], &level, &err_count_per_component_atomic[component])) { + gStructuredLogComponentEnvVars[component], &level, &err_flag_per_component_atomic[component])) { BSON_ASSERT (mongoc_structured_log_opts_set_max_level_for_component ( opts, (mongoc_structured_log_component_t) component, level)); } else { From c96b9d3893e1f41ca34e0077c3779f5a8ea1ee52 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Thu, 16 Jan 2025 12:50:45 -0800 Subject: [PATCH 17/23] Explicit requirement for unset env option --- src/libmongoc/tests/test-mongoc-structured-log.c | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/src/libmongoc/tests/test-mongoc-structured-log.c b/src/libmongoc/tests/test-mongoc-structured-log.c index 2af26ffc4ff..c24abee049a 100644 --- a/src/libmongoc/tests/test-mongoc-structured-log.c +++ b/src/libmongoc/tests/test-mongoc-structured-log.c @@ -742,9 +742,11 @@ test_structured_log_max_document_length (void) { mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); - // Test assumes no environment variable option is set - ASSERT_CMPINT ( - MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH, ==, mongoc_structured_log_opts_get_max_document_length (opts)); + // Test requires the environment variable option is unset, so we see the default. + ASSERT (getenv ("MONGODB_LOG_MAX_DOCUMENT_LENGTH") == NULL); + ASSERT_CMPINT (MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH, ==, 1000); + ASSERT_CMPINT (1000, ==, mongoc_structured_log_opts_get_max_document_length (opts)); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 0)); ASSERT (!mongoc_structured_log_opts_set_max_document_length (opts, INT_MAX)); ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, INT_MAX / 2)); From 7654e679927acacdb332917aeb55d65aad92b0af Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Thu, 16 Jan 2025 13:03:27 -0800 Subject: [PATCH 18/23] comment correction, not using the mock server --- .../tests/test-mongoc-command-logging-and-monitoring.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c index d530b276c6f..6121728b837 100644 --- a/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c +++ b/src/libmongoc/tests/test-mongoc-command-logging-and-monitoring.c @@ -261,7 +261,7 @@ prose_test_3 (void) // codepoint are handled gracefully." // // For libmongoc, our max length is in bytes and truncation will round lengths down if necessary to avoid splitting a - // valid UTF-8 sequence. This test repeatedly sends a fake command to the mock server using every possible maximum + // valid UTF-8 sequence. This test repeatedly sends a fake command to the server using every possible maximum // length, checking for the expected truncations. bson_t command = BSON_INITIALIZER; From 78634de5fb1b7e0e12bf483f5fbf1ca746ddb701 Mon Sep 17 00:00:00 2001 From: mdbmes Date: Thu, 16 Jan 2025 13:39:20 -0800 Subject: [PATCH 19/23] Update src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst Co-authored-by: Ezra Chung <88335979+eramongodb@users.noreply.github.com> --- .../doc/mongoc_structured_log_opts_get_max_document_length.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst b/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst index 4ef52068e8c..4990a9b1842 100644 --- a/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst +++ b/src/libmongoc/doc/mongoc_structured_log_opts_get_max_document_length.rst @@ -19,7 +19,7 @@ Parameters Returns ------- -Returns the current maximum document length set in ``opts``, as a ``size_t``. Always succeeds. +Returns the current maximum document length set in ``opts``, as a ``size_t``. .. seealso:: From b2f6d528be486ad4001bdffd4fd14b06cdeeea15 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Thu, 16 Jan 2025 14:30:27 -0800 Subject: [PATCH 20/23] getenv fixes, and skip testing env defaults when external values are set --- .../src/mongoc/mongoc-structured-log.c | 53 +++++++++------- src/libmongoc/tests/TestSuite.c | 2 +- src/libmongoc/tests/TestSuite.h | 2 + .../tests/test-mongoc-structured-log.c | 63 ++++++++++++++++++- 4 files changed, 94 insertions(+), 26 deletions(-) diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index bc332752ac2..2a25a5e8d2a 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -194,18 +194,19 @@ _mongoc_structured_log_get_log_level_from_env (const char *variable, mongoc_structured_log_level_t *out, int volatile *err_flag_atomic) { - const char *level = getenv (variable); + char *level = _mongoc_getenv (variable); if (!level) { return false; } - if (mongoc_structured_log_get_named_level (level, out)) { - return true; - } - // Only log the first instance of each error per process - if (0 == mcommon_atomic_int_compare_exchange_strong (err_flag_atomic, 0, 1, mcommon_memory_order_seq_cst)) { - MONGOC_WARNING ("Invalid log level '%s' read from environment variable %s. Ignoring it.", level, variable); + bool result = mongoc_structured_log_get_named_level (level, out); + if (!result) { + // Only log the first instance of each error per process + if (0 == mcommon_atomic_int_compare_exchange_strong (err_flag_atomic, 0, 1, mcommon_memory_order_seq_cst)) { + MONGOC_WARNING ("Invalid log level '%s' read from environment variable %s. Ignoring it.", level, variable); + } } - return false; + bson_free (level); + return result; } const char * @@ -294,31 +295,39 @@ mongoc_structured_log_opts_set_max_document_length_from_env (mongoc_structured_l BSON_ASSERT_PARAM (opts); const char *variable = "MONGODB_LOG_MAX_DOCUMENT_LENGTH"; - const char *max_length_str = getenv (variable); + char *max_length_str = _mongoc_getenv (variable); if (!max_length_str) { return true; } + bool result = false; + if (!strcasecmp (max_length_str, "unlimited")) { BSON_ASSERT ( mongoc_structured_log_opts_set_max_document_length (opts, MONGOC_STRUCTURED_LOG_MAXIMUM_MAX_DOCUMENT_LENGTH)); - return true; + result = true; + } else { + char *endptr; + long int_value = strtol (max_length_str, &endptr, 10); + if (int_value >= 0 && endptr != max_length_str && *endptr == '\0' && + mcommon_in_range_signed (size_t, int_value) && + mongoc_structured_log_opts_set_max_document_length (opts, (size_t) int_value)) { + result = true; + } } - char *endptr; - long int_value = strtol (max_length_str, &endptr, 10); - if (int_value >= 0 && endptr != max_length_str && *endptr == '\0' && mcommon_in_range_signed (size_t, int_value) && - mongoc_structured_log_opts_set_max_document_length (opts, (size_t) int_value)) { - return true; + if (!result) { + // Only log the first instance of each error per process + static int err_flag_atomic; + if (0 == mcommon_atomic_int_compare_exchange_strong (&err_flag_atomic, 0, 1, mcommon_memory_order_seq_cst)) { + MONGOC_WARNING ( + "Invalid length '%s' read from environment variable %s. Ignoring it.", max_length_str, variable); + } } - // Only log the first instance of each error per process - static int err_flag_atomic; - if (0 == mcommon_atomic_int_compare_exchange_strong (&err_flag_atomic, 0, 1, mcommon_memory_order_seq_cst)) { - MONGOC_WARNING ("Invalid length '%s' read from environment variable %s. Ignoring it.", max_length_str, variable); - } - return false; + bson_free (max_length_str); + return result; } bool @@ -443,7 +452,7 @@ mongoc_structured_log_opts_new (void) * Note that error return values from mongoc_structured_log_opts_set_* must be ignored here. * If environment variables can't be parsed, warnings will be logged once but we must, by specification, * continue to provide structured logging using whatever valid or default settings remain. */ - opts->default_handler_path = bson_strdup (getenv ("MONGODB_LOG_PATH")); + opts->default_handler_path = _mongoc_getenv ("MONGODB_LOG_PATH"); opts->max_document_length = MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH; (void) mongoc_structured_log_opts_set_max_document_length_from_env (opts); (void) mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_DEFAULT_LEVEL); diff --git a/src/libmongoc/tests/TestSuite.c b/src/libmongoc/tests/TestSuite.c index 0c5726e11f2..7605c897662 100644 --- a/src/libmongoc/tests/TestSuite.c +++ b/src/libmongoc/tests/TestSuite.c @@ -248,7 +248,7 @@ TestSuite_CheckMockServerAllowed (void) return 1; } -static void +void TestSuite_AddHelper (void *ctx) { ((TestFnCtx *) ctx)->test_fn (); diff --git a/src/libmongoc/tests/TestSuite.h b/src/libmongoc/tests/TestSuite.h index 4baaae8c921..8404f55794f 100644 --- a/src/libmongoc/tests/TestSuite.h +++ b/src/libmongoc/tests/TestSuite.h @@ -714,6 +714,8 @@ void _TestSuite_AddFull (TestSuite *suite, const char *name, TestFuncWC func, TestFuncDtor dtor, void *ctx, ...); void _TestSuite_TestFnCtxDtor (void *ctx); +void +TestSuite_AddHelper (void *ctx); #define TestSuite_AddFull(_suite, _name, _func, _dtor, _ctx, ...) \ _TestSuite_AddFull (_suite, _name, _func, _dtor, _ctx, __VA_ARGS__, NULL) #define TestSuite_AddFullWithTestFn(_suite, _name, _func, _dtor, _test_fn, ...) \ diff --git a/src/libmongoc/tests/test-mongoc-structured-log.c b/src/libmongoc/tests/test-mongoc-structured-log.c index c24abee049a..c810017df04 100644 --- a/src/libmongoc/tests/test-mongoc-structured-log.c +++ b/src/libmongoc/tests/test-mongoc-structured-log.c @@ -17,6 +17,7 @@ #include #include "mongoc/mongoc-structured-log-private.h" +#include "test-libmongoc.h" #include "TestSuite.h" typedef struct log_assumption { @@ -742,10 +743,7 @@ test_structured_log_max_document_length (void) { mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); - // Test requires the environment variable option is unset, so we see the default. - ASSERT (getenv ("MONGODB_LOG_MAX_DOCUMENT_LENGTH") == NULL); ASSERT_CMPINT (MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH, ==, 1000); - ASSERT_CMPINT (1000, ==, mongoc_structured_log_opts_get_max_document_length (opts)); ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 0)); ASSERT (!mongoc_structured_log_opts_set_max_document_length (opts, INT_MAX)); @@ -755,6 +753,59 @@ test_structured_log_max_document_length (void) mongoc_structured_log_opts_destroy (opts); } +int +check_test_structured_log_env_defaults (void) +{ + // Skip testing env defaults if any options have been set externally + const char *expected_unset[] = { + "MONGODB_LOG_MAX_DOCUMENT_LENGTH", + "MONGODB_LOG_COMMAND", + "MONGODB_LOG_TOPOLOGY", + "MONGODB_LOG_SERVER_SELECTION", + "MONGODB_LOG_CONNECTION", + "MONGODB_LOG_ALL", + }; + + for (size_t i = 0u; i < sizeof expected_unset / sizeof expected_unset[0]; i++) { + const char *var = expected_unset[i]; + char *value = test_framework_getenv (var); + bson_free (value); + if (value) { + MONGOC_DEBUG ("Skipping test because environment var '%s' is set", var); + return 0; + } + } + return 1; +} + +void +test_structured_log_env_defaults (void) +{ + mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); + + ASSERT_CMPINT ( + MONGOC_STRUCTURED_LOG_LEVEL_WARNING, + ==, + mongoc_structured_log_opts_get_max_level_for_component (opts, MONGOC_STRUCTURED_LOG_COMPONENT_COMMAND)); + ASSERT_CMPINT ( + MONGOC_STRUCTURED_LOG_LEVEL_WARNING, + ==, + mongoc_structured_log_opts_get_max_level_for_component (opts, MONGOC_STRUCTURED_LOG_COMPONENT_CONNECTION)); + ASSERT_CMPINT ( + MONGOC_STRUCTURED_LOG_LEVEL_WARNING, + ==, + mongoc_structured_log_opts_get_max_level_for_component (opts, MONGOC_STRUCTURED_LOG_COMPONENT_SERVER_SELECTION)); + ASSERT_CMPINT ( + MONGOC_STRUCTURED_LOG_LEVEL_WARNING, + ==, + mongoc_structured_log_opts_get_max_level_for_component (opts, MONGOC_STRUCTURED_LOG_COMPONENT_TOPOLOGY)); + + ASSERT_CMPINT ( + MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH, ==, mongoc_structured_log_opts_get_max_document_length (opts)); + + mongoc_structured_log_opts_destroy (opts); +} + void test_structured_log_install (TestSuite *suite) { @@ -771,4 +822,10 @@ test_structured_log_install (TestSuite *suite) TestSuite_Add (suite, "/structured_log/level_names", test_structured_log_level_names); TestSuite_Add (suite, "/structured_log/component_names", test_structured_log_component_names); TestSuite_Add (suite, "/structured_log/max_document_length", test_structured_log_max_document_length); + TestSuite_AddFullWithTestFn (suite, + "/structured_log/env_defaults", + TestSuite_AddHelper, + NULL, + test_structured_log_env_defaults, + check_test_structured_log_env_defaults); } From 989e2e4ee8d76a516784f156963538d50d647474 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Fri, 17 Jan 2025 08:35:25 -0800 Subject: [PATCH 21/23] Improved test skip for structured log env defaults, revert TestSuite API change --- src/libmongoc/tests/TestSuite.c | 2 +- src/libmongoc/tests/TestSuite.h | 2 -- .../tests/test-mongoc-structured-log.c | 19 +++++++++++-------- 3 files changed, 12 insertions(+), 11 deletions(-) diff --git a/src/libmongoc/tests/TestSuite.c b/src/libmongoc/tests/TestSuite.c index 7605c897662..0c5726e11f2 100644 --- a/src/libmongoc/tests/TestSuite.c +++ b/src/libmongoc/tests/TestSuite.c @@ -248,7 +248,7 @@ TestSuite_CheckMockServerAllowed (void) return 1; } -void +static void TestSuite_AddHelper (void *ctx) { ((TestFnCtx *) ctx)->test_fn (); diff --git a/src/libmongoc/tests/TestSuite.h b/src/libmongoc/tests/TestSuite.h index 8404f55794f..4baaae8c921 100644 --- a/src/libmongoc/tests/TestSuite.h +++ b/src/libmongoc/tests/TestSuite.h @@ -714,8 +714,6 @@ void _TestSuite_AddFull (TestSuite *suite, const char *name, TestFuncWC func, TestFuncDtor dtor, void *ctx, ...); void _TestSuite_TestFnCtxDtor (void *ctx); -void -TestSuite_AddHelper (void *ctx); #define TestSuite_AddFull(_suite, _name, _func, _dtor, _ctx, ...) \ _TestSuite_AddFull (_suite, _name, _func, _dtor, _ctx, __VA_ARGS__, NULL) #define TestSuite_AddFullWithTestFn(_suite, _name, _func, _dtor, _test_fn, ...) \ diff --git a/src/libmongoc/tests/test-mongoc-structured-log.c b/src/libmongoc/tests/test-mongoc-structured-log.c index c810017df04..51561a5e412 100644 --- a/src/libmongoc/tests/test-mongoc-structured-log.c +++ b/src/libmongoc/tests/test-mongoc-structured-log.c @@ -754,7 +754,7 @@ test_structured_log_max_document_length (void) } int -check_test_structured_log_env_defaults (void) +test_structured_log_skip_if_env_not_default (void) { // Skip testing env defaults if any options have been set externally const char *expected_unset[] = { @@ -779,8 +779,10 @@ check_test_structured_log_env_defaults (void) } void -test_structured_log_env_defaults (void) +test_structured_log_env_defaults (void *test_context) { + BSON_UNUSED (test_context); + mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); ASSERT_CMPINT ( @@ -822,10 +824,11 @@ test_structured_log_install (TestSuite *suite) TestSuite_Add (suite, "/structured_log/level_names", test_structured_log_level_names); TestSuite_Add (suite, "/structured_log/component_names", test_structured_log_component_names); TestSuite_Add (suite, "/structured_log/max_document_length", test_structured_log_max_document_length); - TestSuite_AddFullWithTestFn (suite, - "/structured_log/env_defaults", - TestSuite_AddHelper, - NULL, - test_structured_log_env_defaults, - check_test_structured_log_env_defaults); + TestSuite_AddFull (suite, + "/structured_log/env_defaults", + test_structured_log_env_defaults, + NULL, + NULL, + test_structured_log_skip_if_env_not_default, + NULL); } From fae30e3de5cd0b3058841bdd0bc75252fa9fcae5 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Fri, 17 Jan 2025 10:28:13 -0800 Subject: [PATCH 22/23] Avoid environment dependencies --- src/libmongoc/tests/test-mongoc-structured-log.c | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/src/libmongoc/tests/test-mongoc-structured-log.c b/src/libmongoc/tests/test-mongoc-structured-log.c index 51561a5e412..bbc8691f901 100644 --- a/src/libmongoc/tests/test-mongoc-structured-log.c +++ b/src/libmongoc/tests/test-mongoc-structured-log.c @@ -66,6 +66,7 @@ test_structured_log_opts (void) { mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); + ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_WARNING)); ASSERT_CMPINT ( MONGOC_STRUCTURED_LOG_LEVEL_WARNING, ==, @@ -89,7 +90,6 @@ test_structured_log_opts (void) ASSERT (!mongoc_structured_log_opts_set_max_level_for_all_components (opts, (mongoc_structured_log_level_t) -1)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_INFO)); - ASSERT_CMPINT ( MONGOC_STRUCTURED_LOG_LEVEL_INFO, ==, @@ -143,6 +143,7 @@ test_structured_log_plain (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -169,6 +170,7 @@ test_structured_log_plain_with_extra_data (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -223,6 +225,7 @@ test_structured_log_basic_data_types (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -275,6 +278,7 @@ test_structured_log_json (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -315,6 +319,7 @@ test_structured_log_oid (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -364,6 +369,7 @@ test_structured_log_error (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_INFO)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -436,6 +442,7 @@ test_structured_log_server_description (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -574,6 +581,7 @@ test_structured_log_command (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -629,6 +637,7 @@ test_structured_log_duration (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG)); mongoc_structured_log_instance_t *instance = mongoc_structured_log_instance_new (opts); @@ -829,6 +838,5 @@ test_structured_log_install (TestSuite *suite) test_structured_log_env_defaults, NULL, NULL, - test_structured_log_skip_if_env_not_default, - NULL); + test_structured_log_skip_if_env_not_default); } From aae1bc145afd25c3715eaf52cb069427119fecf0 Mon Sep 17 00:00:00 2001 From: Micah Scott Date: Fri, 17 Jan 2025 11:29:29 -0800 Subject: [PATCH 23/23] Add comment to explain where this max_document_length comes from --- src/libmongoc/tests/test-mongoc-structured-log.c | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/libmongoc/tests/test-mongoc-structured-log.c b/src/libmongoc/tests/test-mongoc-structured-log.c index bbc8691f901..9243a02d7f2 100644 --- a/src/libmongoc/tests/test-mongoc-structured-log.c +++ b/src/libmongoc/tests/test-mongoc-structured-log.c @@ -143,6 +143,11 @@ test_structured_log_plain (void) mongoc_structured_log_opts_t *opts = mongoc_structured_log_opts_new (); mongoc_structured_log_opts_set_handler (opts, structured_log_func, &assumption); + + /* Note about these max_document_length settings: We want a consistent value so the test is isolated from external + * environment variable settings. The default (MONGOC_STRUCTURED_LOG_DEFAULT_MAX_DOCUMENT_LENGTH) is verified as 1000 + * bytes elsewhere. The Command Logging and Monitoring spec recommends that tests run with a larger-than-default + * setting of 10000 bytes. We choose that value here, but it's really quite arbitrary. */ ASSERT (mongoc_structured_log_opts_set_max_document_length (opts, 10000)); ASSERT (mongoc_structured_log_opts_set_max_level_for_all_components (opts, MONGOC_STRUCTURED_LOG_LEVEL_DEBUG));