diff --git a/build/generate-future-functions.py b/build/generate-future-functions.py index 7bacf2a1ee4..89f2658ea20 100644 --- a/build/generate-future-functions.py +++ b/build/generate-future-functions.py @@ -102,6 +102,8 @@ typedef("const_mongoc_read_prefs_ptr", "const mongoc_read_prefs_t *"), typedef("const_mongoc_write_concern_ptr", "const mongoc_write_concern_t *"), + typedef("const_mongoc_ss_log_context_ptr", + "const mongoc_ss_log_context_t *"), ] type_list = [T.name for T in typedef_list] @@ -453,6 +455,7 @@ "mongoc_topology_select", [param("mongoc_topology_ptr", "topology"), param("mongoc_ss_optype_t", "optype"), + param("const_mongoc_ss_log_context_ptr", "log_context"), param("const_mongoc_read_prefs_ptr", "read_prefs"), param("bool_ptr", "must_use_primary"), param("bson_error_ptr", "error")]), diff --git a/src/libmongoc/src/mongoc/mongoc-aggregate.c b/src/libmongoc/src/mongoc/mongoc-aggregate.c index fa9da681a90..31ae4e69983 100644 --- a/src/libmongoc/src/mongoc/mongoc-aggregate.c +++ b/src/libmongoc/src/mongoc/mongoc-aggregate.c @@ -295,7 +295,8 @@ _mongoc_aggregate (mongoc_client_t *client, cursor->is_aggr_with_write_stage = has_write_key; /* server id isn't enough. ensure we're connected & know wire version */ - server_stream = _mongoc_cursor_fetch_stream (cursor); + const mongoc_ss_log_context_t ss_log_context = {.operation = "aggregate"}; + server_stream = _mongoc_cursor_fetch_stream (cursor, &ss_log_context); if (!server_stream) { GOTO (done); } diff --git a/src/libmongoc/src/mongoc/mongoc-bulk-operation.c b/src/libmongoc/src/mongoc/mongoc-bulk-operation.c index 05b440ec98c..26028efc468 100644 --- a/src/libmongoc/src/mongoc/mongoc-bulk-operation.c +++ b/src/libmongoc/src/mongoc/mongoc-bulk-operation.c @@ -777,11 +777,16 @@ mongoc_bulk_operation_execute (mongoc_bulk_operation_t *bulk, /* IN */ } for (size_t i = 0u; i < bulk->commands.len; i++) { + command = &_mongoc_array_index (&bulk->commands, mongoc_write_command_t, i); + if (bulk->server_id) { server_stream = mongoc_cluster_stream_for_server ( cluster, bulk->server_id, true /* reconnect_ok */, bulk->session, reply, error); } else { - server_stream = mongoc_cluster_stream_for_writes (cluster, bulk->session, NULL, reply, error); + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_write_command_get_name (command), + .has_operation_id = true, + .operation_id = command->operation_id}; + server_stream = mongoc_cluster_stream_for_writes (cluster, &ss_log_context, bulk->session, NULL, reply, error); } if (!server_stream) { @@ -789,8 +794,6 @@ mongoc_bulk_operation_execute (mongoc_bulk_operation_t *bulk, /* IN */ RETURN (false); } - command = &_mongoc_array_index (&bulk->commands, mongoc_write_command_t, i); - _mongoc_write_command_execute (command, bulk->client, server_stream, diff --git a/src/libmongoc/src/mongoc/mongoc-bulkwrite.c b/src/libmongoc/src/mongoc/mongoc-bulkwrite.c index 201128f53de..30db093e765 100644 --- a/src/libmongoc/src/mongoc/mongoc-bulkwrite.c +++ b/src/libmongoc/src/mongoc/mongoc-bulkwrite.c @@ -1557,6 +1557,9 @@ mongoc_bulkwrite_execute (mongoc_bulkwrite_t *self, const mongoc_bulkwriteopts_t goto fail; } + const mongoc_ss_log_context_t ss_log_context = { + .operation = "bulkWrite", .has_operation_id = true, .operation_id = self->operation_id}; + // Select a stream. { bson_t reply; @@ -1566,7 +1569,7 @@ mongoc_bulkwrite_execute (mongoc_bulkwrite_t *self, const mongoc_bulkwriteopts_t &self->client->cluster, opts->serverid, true /* reconnect_ok */, self->session, &reply, &error); } else { ss = mongoc_cluster_stream_for_writes ( - &self->client->cluster, self->session, NULL /* deprioritized servers */, &reply, &error); + &self->client->cluster, &ss_log_context, self->session, NULL /* deprioritized servers */, &reply, &error); } if (!ss) { @@ -1814,8 +1817,12 @@ mongoc_bulkwrite_execute (mongoc_bulkwrite_t *self, const mongoc_bulkwriteopts_t bson_t reply; // Select a server and create a stream again. mongoc_server_stream_cleanup (ss); - ss = mongoc_cluster_stream_for_writes ( - &self->client->cluster, NULL /* session */, NULL /* deprioritized servers */, &reply, &error); + ss = mongoc_cluster_stream_for_writes (&self->client->cluster, + &ss_log_context, + NULL /* session */, + NULL /* deprioritized servers */, + &reply, + &error); if (ss) { parts.assembled.server_stream = ss; diff --git a/src/libmongoc/src/mongoc/mongoc-change-stream.c b/src/libmongoc/src/mongoc/mongoc-change-stream.c index 64df49fd0cc..5b9032f15b5 100644 --- a/src/libmongoc/src/mongoc/mongoc-change-stream.c +++ b/src/libmongoc/src/mongoc/mongoc-change-stream.c @@ -267,8 +267,9 @@ _make_cursor (mongoc_change_stream_t *stream) goto cleanup; } - server_stream = - mongoc_cluster_stream_for_reads (&stream->client->cluster, stream->read_prefs, cs, NULL, &reply, &stream->err); + const mongoc_ss_log_context_t ss_log_context = {.operation = "aggregate"}; + server_stream = mongoc_cluster_stream_for_reads ( + &stream->client->cluster, &ss_log_context, stream->read_prefs, cs, NULL, &reply, &stream->err); if (!server_stream) { bson_destroy (&stream->err_doc); bson_copy_to (&reply, &stream->err_doc); diff --git a/src/libmongoc/src/mongoc/mongoc-client-private.h b/src/libmongoc/src/mongoc/mongoc-client-private.h index ef88ea87c25..aa4776a0d60 100644 --- a/src/libmongoc/src/mongoc/mongoc-client-private.h +++ b/src/libmongoc/src/mongoc/mongoc-client-private.h @@ -193,7 +193,9 @@ _mongoc_client_command_with_opts (mongoc_client_t *client, bson_error_t *error); mongoc_server_session_t * -_mongoc_client_pop_server_session (mongoc_client_t *client, bson_error_t *error); +_mongoc_client_pop_server_session (mongoc_client_t *client, + const mongoc_ss_log_context_t *log_context, + bson_error_t *error); bool _mongoc_client_lookup_session (const mongoc_client_t *client, diff --git a/src/libmongoc/src/mongoc/mongoc-client-session.c b/src/libmongoc/src/mongoc/mongoc-client-session.c index 2b1de7d79d7..15515e0d6be 100644 --- a/src/libmongoc/src/mongoc/mongoc-client-session.c +++ b/src/libmongoc/src/mongoc/mongoc-client-session.c @@ -1036,8 +1036,9 @@ mongoc_client_session_start_transaction (mongoc_client_session_t *session, BSON_ASSERT (session); ret = true; + const mongoc_ss_log_context_t ss_log_context = {.operation = "mongoc_client_session_start_transaction"}; server_stream = mongoc_cluster_stream_for_writes ( - &session->client->cluster, session, NULL /* deprioritized servers */, NULL /* reply */, error); + &session->client->cluster, &ss_log_context, session, NULL /* deprioritized servers */, NULL /* reply */, error); if (!server_stream) { ret = false; GOTO (done); diff --git a/src/libmongoc/src/mongoc/mongoc-client.c b/src/libmongoc/src/mongoc/mongoc-client.c index f6ae2cb1fde..7ac9a301948 100644 --- a/src/libmongoc/src/mongoc/mongoc-client.c +++ b/src/libmongoc/src/mongoc/mongoc-client.c @@ -1239,7 +1239,8 @@ mongoc_client_start_session (mongoc_client_t *client, const mongoc_session_opt_t ENTRY; - ss = _mongoc_client_pop_server_session (client, error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "startSession"}; + ss = _mongoc_client_pop_server_session (client, &ss_log_context, error); if (!ss) { RETURN (NULL); } @@ -1661,8 +1662,13 @@ _mongoc_client_retryable_read_command_with_stream (mongoc_client_t *client, mongoc_deprioritized_servers_add_if_sharded (ds, server_stream->topology_type, server_stream->sd); } + const mongoc_ss_log_context_t ss_log_context = { + .operation = parts->assembled.command_name, + .has_operation_id = true, + .operation_id = parts->assembled.operation_id, + }; retry_server_stream = mongoc_cluster_stream_for_reads ( - &client->cluster, parts->read_prefs, parts->assembled.session, ds, NULL, &ignored_error); + &client->cluster, &ss_log_context, parts->read_prefs, parts->assembled.session, ds, NULL, &ignored_error); mongoc_deprioritized_servers_destroy (ds); } @@ -1761,7 +1767,8 @@ mongoc_client_command_simple (mongoc_client_t *client, * configuration. The generic command method SHOULD allow an optional read * preference argument." */ - server_stream = mongoc_cluster_stream_for_reads (cluster, read_prefs, NULL, NULL, reply, error); + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_get_command_name (command)}; + server_stream = mongoc_cluster_stream_for_reads (cluster, &ss_log_context, read_prefs, NULL, NULL, reply, error); if (server_stream) { ret = _mongoc_client_command_with_stream (client, &parts, read_prefs, server_stream, reply, error); @@ -1895,6 +1902,7 @@ _mongoc_client_command_with_opts (mongoc_client_t *client, prefs = NULL; } + const mongoc_ss_log_context_t ss_log_context = {.operation = command_name}; if (read_write_opts.serverId) { /* "serverId" passed in opts */ server_stream = mongoc_cluster_stream_for_server ( @@ -1904,9 +1912,9 @@ _mongoc_client_command_with_opts (mongoc_client_t *client, parts.user_query_flags |= MONGOC_QUERY_SECONDARY_OK; } } else if (parts.is_write_command) { - server_stream = mongoc_cluster_stream_for_writes (cluster, cs, NULL, reply_ptr, error); + server_stream = mongoc_cluster_stream_for_writes (cluster, &ss_log_context, cs, NULL, reply_ptr, error); } else { - server_stream = mongoc_cluster_stream_for_reads (cluster, prefs, cs, NULL, reply_ptr, error); + server_stream = mongoc_cluster_stream_for_reads (cluster, &ss_log_context, prefs, cs, NULL, reply_ptr, error); } if (!server_stream) { @@ -2691,7 +2699,8 @@ mongoc_client_select_server (mongoc_client_t *client, return NULL; } - sd = mongoc_topology_select (client->topology, optype, prefs, NULL /* chosen read mode */, error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "mongoc_client_select_server"}; + sd = mongoc_topology_select (client->topology, optype, &ss_log_context, prefs, NULL /* chosen read mode */, error); if (!sd) { return NULL; } @@ -2703,7 +2712,7 @@ mongoc_client_select_server (mongoc_client_t *client, /* check failed, retry once */ mongoc_server_description_destroy (sd); - sd = mongoc_topology_select (client->topology, optype, prefs, NULL /* chosen read mode */, error); + sd = mongoc_topology_select (client->topology, optype, &ss_log_context, prefs, NULL /* chosen read mode */, error); if (sd) { return sd; } @@ -2752,11 +2761,13 @@ mongoc_client_set_appname (mongoc_client_t *client, const char *appname) } mongoc_server_session_t * -_mongoc_client_pop_server_session (mongoc_client_t *client, bson_error_t *error) +_mongoc_client_pop_server_session (mongoc_client_t *client, + const mongoc_ss_log_context_t *log_context, + bson_error_t *error) { BSON_ASSERT_PARAM (client); - return _mongoc_topology_pop_server_session (client->topology, error); + return _mongoc_topology_pop_server_session (client->topology, log_context, error); } /* @@ -2845,8 +2856,15 @@ _mongoc_client_end_sessions (mongoc_client_t *client) while (!mongoc_server_session_pool_is_empty (t->session_pool)) { prefs = mongoc_read_prefs_new (MONGOC_READ_PRIMARY_PREFERRED); - server_id = mongoc_topology_select_server_id ( - t, MONGOC_SS_READ, prefs, NULL /* chosen read mode */, NULL /* deprioritized servers */, &error); + const mongoc_ss_log_context_t ss_log_context = { + .operation = "endSessions", .has_operation_id = true, .operation_id = 1 + cluster->operation_id}; + server_id = mongoc_topology_select_server_id (t, + MONGOC_SS_READ, + &ss_log_context, + prefs, + NULL /* chosen read mode */, + NULL /* deprioritized servers */, + &error); mongoc_read_prefs_destroy (prefs); if (!server_id) { diff --git a/src/libmongoc/src/mongoc/mongoc-cluster-private.h b/src/libmongoc/src/mongoc/mongoc-cluster-private.h index c72006bbd3f..a78828291c3 100644 --- a/src/libmongoc/src/mongoc/mongoc-cluster-private.h +++ b/src/libmongoc/src/mongoc/mongoc-cluster-private.h @@ -120,6 +120,7 @@ mongoc_cluster_try_recv (mongoc_cluster_t *cluster, */ mongoc_server_stream_t * mongoc_cluster_stream_for_reads (mongoc_cluster_t *cluster, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, mongoc_client_session_t *cs, const mongoc_deprioritized_servers_t *ds, @@ -139,6 +140,7 @@ mongoc_cluster_stream_for_reads (mongoc_cluster_t *cluster, */ mongoc_server_stream_t * mongoc_cluster_stream_for_writes (mongoc_cluster_t *cluster, + const mongoc_ss_log_context_t *log_context, mongoc_client_session_t *cs, const mongoc_deprioritized_servers_t *ds, bson_t *reply, @@ -158,6 +160,7 @@ mongoc_cluster_stream_for_writes (mongoc_cluster_t *cluster, */ mongoc_server_stream_t * mongoc_cluster_stream_for_aggr_with_write (mongoc_cluster_t *cluster, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, mongoc_client_session_t *cs, bson_t *reply, diff --git a/src/libmongoc/src/mongoc/mongoc-cluster.c b/src/libmongoc/src/mongoc/mongoc-cluster.c index eb5b408d923..0fd6a853ee8 100644 --- a/src/libmongoc/src/mongoc/mongoc-cluster.c +++ b/src/libmongoc/src/mongoc/mongoc-cluster.c @@ -2449,6 +2449,7 @@ static uint32_t _mongoc_cluster_select_server_id (mongoc_client_session_t *cs, mongoc_topology_t *topology, mongoc_ss_optype_t optype, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, bool *must_use_primary, const mongoc_deprioritized_servers_t *ds, @@ -2465,13 +2466,15 @@ _mongoc_cluster_select_server_id (mongoc_client_session_t *cs, if (_in_sharded_txn (cs)) { server_id = cs->server_id; if (!server_id) { - server_id = mongoc_topology_select_server_id (topology, optype, read_prefs, must_use_primary, ds, error); + server_id = + mongoc_topology_select_server_id (topology, optype, log_context, read_prefs, must_use_primary, ds, error); if (server_id) { _mongoc_client_session_pin (cs, server_id); } } } else { - server_id = mongoc_topology_select_server_id (topology, optype, read_prefs, must_use_primary, ds, error); + server_id = + mongoc_topology_select_server_id (topology, optype, log_context, read_prefs, must_use_primary, ds, error); /* Transactions Spec: Additionally, any non-transaction operation using a * pinned ClientSession MUST unpin the session and the operation MUST * perform normal server selection. */ @@ -2504,6 +2507,7 @@ _mongoc_cluster_select_server_id (mongoc_client_session_t *cs, static mongoc_server_stream_t * _mongoc_cluster_stream_for_optype (mongoc_cluster_t *cluster, mongoc_ss_optype_t optype, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, mongoc_client_session_t *cs, bool is_retryable, @@ -2526,7 +2530,8 @@ _mongoc_cluster_stream_for_optype (mongoc_cluster_t *cluster, BSON_ASSERT (cluster); - server_id = _mongoc_cluster_select_server_id (cs, topology, optype, read_prefs, &must_use_primary, ds, error); + server_id = + _mongoc_cluster_select_server_id (cs, topology, optype, log_context, read_prefs, &must_use_primary, ds, error); if (!server_id) { if (reply) { @@ -2538,7 +2543,8 @@ _mongoc_cluster_stream_for_optype (mongoc_cluster_t *cluster, if (!mongoc_cluster_check_interval (cluster, server_id)) { /* Server Selection Spec: try once more */ - server_id = _mongoc_cluster_select_server_id (cs, topology, optype, read_prefs, &must_use_primary, ds, error); + server_id = + _mongoc_cluster_select_server_id (cs, topology, optype, log_context, read_prefs, &must_use_primary, ds, error); if (!server_id) { if (reply) { @@ -2610,6 +2616,7 @@ _mongoc_cluster_stream_for_optype (mongoc_cluster_t *cluster, mongoc_server_stream_t * mongoc_cluster_stream_for_reads (mongoc_cluster_t *cluster, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, mongoc_client_session_t *cs, const mongoc_deprioritized_servers_t *ds, @@ -2626,11 +2633,12 @@ mongoc_cluster_stream_for_reads (mongoc_cluster_t *cluster, mongoc_uri_get_option_as_bool (cluster->uri, MONGOC_URI_RETRYREADS, MONGOC_DEFAULT_RETRYREADS); return _mongoc_cluster_stream_for_optype ( - cluster, MONGOC_SS_READ, prefs_override, cs, is_retryable, ds, reply, error); + cluster, MONGOC_SS_READ, log_context, prefs_override, cs, is_retryable, ds, reply, error); } mongoc_server_stream_t * mongoc_cluster_stream_for_writes (mongoc_cluster_t *cluster, + const mongoc_ss_log_context_t *log_context, mongoc_client_session_t *cs, const mongoc_deprioritized_servers_t *ds, bson_t *reply, @@ -2639,11 +2647,13 @@ mongoc_cluster_stream_for_writes (mongoc_cluster_t *cluster, const bool is_retryable = mongoc_uri_get_option_as_bool (cluster->uri, MONGOC_URI_RETRYWRITES, MONGOC_DEFAULT_RETRYWRITES); - return _mongoc_cluster_stream_for_optype (cluster, MONGOC_SS_WRITE, NULL, cs, is_retryable, ds, reply, error); + return _mongoc_cluster_stream_for_optype ( + cluster, MONGOC_SS_WRITE, log_context, NULL, cs, is_retryable, ds, reply, error); } mongoc_server_stream_t * mongoc_cluster_stream_for_aggr_with_write (mongoc_cluster_t *cluster, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, mongoc_client_session_t *cs, bson_t *reply, @@ -2656,7 +2666,7 @@ mongoc_cluster_stream_for_aggr_with_write (mongoc_cluster_t *cluster, mongoc_uri_get_option_as_bool (cluster->uri, MONGOC_URI_RETRYWRITES, MONGOC_DEFAULT_RETRYWRITES); return _mongoc_cluster_stream_for_optype ( - cluster, MONGOC_SS_AGGREGATE_WITH_WRITE, prefs_override, cs, is_retryable, NULL, reply, error); + cluster, MONGOC_SS_AGGREGATE_WITH_WRITE, log_context, prefs_override, cs, is_retryable, NULL, reply, error); } static bool @@ -3615,8 +3625,10 @@ mongoc_cluster_run_retryable_write (mongoc_cluster_t *cluster, // If talking to a sharded cluster, deprioritize the just-used mongos to prefer a new mongos for the retry. mongoc_deprioritized_servers_add_if_sharded (ds, cmd->server_stream->topology_type, cmd->server_stream->sd); - *retry_server_stream = - mongoc_cluster_stream_for_writes (cluster, cmd->session, ds, NULL /* reply */, &ignored_error); + const mongoc_ss_log_context_t ss_log_context = { + .operation = cmd->command_name, .has_operation_id = true, .operation_id = cmd->operation_id}; + *retry_server_stream = mongoc_cluster_stream_for_writes ( + cluster, &ss_log_context, cmd->session, ds, NULL /* reply */, &ignored_error); mongoc_deprioritized_servers_destroy (ds); } diff --git a/src/libmongoc/src/mongoc/mongoc-cmd.c b/src/libmongoc/src/mongoc/mongoc-cmd.c index 9817a8d493a..dac93d8bd0b 100644 --- a/src/libmongoc/src/mongoc/mongoc-cmd.c +++ b/src/libmongoc/src/mongoc/mongoc-cmd.c @@ -326,30 +326,13 @@ static void _mongoc_cmd_parts_add_read_prefs (bson_t *query, const mongoc_read_prefs_t *prefs) { bson_t child; - const char *mode_str; - const bson_t *tags; - int64_t stale; - const bson_t *hedge; - - mode_str = _mongoc_read_mode_as_str (mongoc_read_prefs_get_mode (prefs)); - tags = mongoc_read_prefs_get_tags (prefs); - stale = mongoc_read_prefs_get_max_staleness_seconds (prefs); - hedge = mongoc_read_prefs_get_hedge (prefs); bson_append_document_begin (query, "$readPreference", 15, &child); - bson_append_utf8 (&child, "mode", 4, mode_str, -1); - if (!bson_empty0 (tags)) { - bson_append_array (&child, "tags", 4, tags); - } - - if (stale != MONGOC_NO_MAX_STALENESS) { - bson_append_int64 (&child, "maxStalenessSeconds", 19, stale); - } - - if (!bson_empty0 (hedge)) { - bson_append_document (&child, "hedge", 5, hedge); - } - + mongoc_read_prefs_append_contents_to_bson ( + prefs, + &child, + MONGOC_READ_PREFS_CONTENT_FLAG_MODE | MONGOC_READ_PREFS_CONTENT_FLAG_TAGS | + MONGOC_READ_PREFS_CONTENT_FLAG_MAX_STALENESS_SECONDS | MONGOC_READ_PREFS_CONTENT_FLAG_HEDGE); bson_append_document_end (query, &child); } diff --git a/src/libmongoc/src/mongoc/mongoc-collection.c b/src/libmongoc/src/mongoc/mongoc-collection.c index ed62989862d..24b8729a673 100644 --- a/src/libmongoc/src/mongoc/mongoc-collection.c +++ b/src/libmongoc/src/mongoc/mongoc-collection.c @@ -60,7 +60,11 @@ _mongoc_collection_write_command_execute (mongoc_write_command_t *command, ENTRY; - server_stream = mongoc_cluster_stream_for_writes (&collection->client->cluster, cs, NULL, NULL, &result->error); + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_write_command_get_name (command), + .has_operation_id = true, + .operation_id = command->operation_id}; + server_stream = + mongoc_cluster_stream_for_writes (&collection->client->cluster, &ss_log_context, cs, NULL, NULL, &result->error); if (!server_stream) { /* result->error has been filled out */ @@ -94,8 +98,11 @@ _mongoc_collection_write_command_execute_idl (mongoc_write_command_t *command, ENTRY; + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_write_command_get_name (command), + .has_operation_id = true, + .operation_id = command->operation_id}; server_stream = mongoc_cluster_stream_for_writes ( - &collection->client->cluster, crud->client_session, NULL, &reply, &result->error); + &collection->client->cluster, &ss_log_context, crud->client_session, NULL, &reply, &result->error); if (!server_stream) { /* result->error and reply have been filled out */ @@ -1523,8 +1530,9 @@ mongoc_collection_create_index_with_opts (mongoc_collection_t *collection, bson_array_builder_append_document_end (ar, &doc); bson_append_array_builder_end (&cmd, ar); - server_stream = - mongoc_cluster_stream_for_writes (&collection->client->cluster, parsed.client_session, NULL, reply, error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "createIndexes"}; + server_stream = mongoc_cluster_stream_for_writes ( + &collection->client->cluster, &ss_log_context, parsed.client_session, NULL, reply, error); if (!server_stream) { reply_initialized = true; @@ -2081,8 +2089,11 @@ _mongoc_collection_update_or_replace (mongoc_collection_t *collection, command.flags.has_update_hint = true; } + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_write_command_get_name (&command), + .has_operation_id = true, + .operation_id = command.operation_id}; server_stream = mongoc_cluster_stream_for_writes ( - &collection->client->cluster, update_opts->crud.client_session, NULL, reply, error); + &collection->client->cluster, &ss_log_context, update_opts->crud.client_session, NULL, reply, error); if (!server_stream) { /* mongoc_cluster_stream_for_writes inits reply on error */ @@ -3120,7 +3131,9 @@ mongoc_collection_find_and_modify_with_opts (mongoc_collection_t *collection, GOTO (done); } - server_stream = mongoc_cluster_stream_for_writes (cluster, appended_opts.client_session, NULL, &ss_reply, error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "findAndModify"}; + server_stream = + mongoc_cluster_stream_for_writes (cluster, &ss_log_context, appended_opts.client_session, NULL, &ss_reply, error); if (!server_stream) { bson_concat (reply, &ss_reply); @@ -3413,7 +3426,9 @@ mongoc_collection_create_indexes_with_opts (mongoc_collection_t *collection, // Check for commitQuorum option. if (opts && bson_has_field (opts, "commitQuorum")) { + const mongoc_ss_log_context_t ss_log_context = {.operation = "createIndexes"}; server_stream = mongoc_cluster_stream_for_writes (&collection->client->cluster, + &ss_log_context, NULL /* mongoc_client_session_t */, NULL /* deprioritized servers */, reply_ptr, diff --git a/src/libmongoc/src/mongoc/mongoc-cursor-cmd.c b/src/libmongoc/src/mongoc/mongoc-cursor-cmd.c index fec43630b5c..39e95c91784 100644 --- a/src/libmongoc/src/mongoc/mongoc-cursor-cmd.c +++ b/src/libmongoc/src/mongoc/mongoc-cursor-cmd.c @@ -42,7 +42,9 @@ _getmore_type (mongoc_cursor_t *cursor) if (data->getmore_type != UNKNOWN) { return data->getmore_type; } - server_stream = _mongoc_cursor_fetch_stream (cursor); + const mongoc_ss_log_context_t ss_log_context = { + .operation = "getMore", .has_operation_id = true, .operation_id = cursor->operation_id}; + server_stream = _mongoc_cursor_fetch_stream (cursor, &ss_log_context); if (!server_stream) { return UNKNOWN; } diff --git a/src/libmongoc/src/mongoc/mongoc-cursor-find.c b/src/libmongoc/src/mongoc/mongoc-cursor-find.c index 2305df0fc7f..627ac060aaf 100644 --- a/src/libmongoc/src/mongoc/mongoc-cursor-find.c +++ b/src/libmongoc/src/mongoc/mongoc-cursor-find.c @@ -37,7 +37,9 @@ _prime (mongoc_cursor_t *cursor) data_find_t *data = (data_find_t *) cursor->impl.data; /* determine if this should be a command or op_query cursor. */ - server_stream = _mongoc_cursor_fetch_stream (cursor); + const mongoc_ss_log_context_t ss_log_context = { + .operation = "find", .has_operation_id = true, .operation_id = cursor->operation_id}; + server_stream = _mongoc_cursor_fetch_stream (cursor, &ss_log_context); if (!server_stream) { return DONE; } diff --git a/src/libmongoc/src/mongoc/mongoc-cursor-legacy.c b/src/libmongoc/src/mongoc/mongoc-cursor-legacy.c index 0b42c576654..2f0726fb99b 100644 --- a/src/libmongoc/src/mongoc/mongoc-cursor-legacy.c +++ b/src/libmongoc/src/mongoc/mongoc-cursor-legacy.c @@ -168,7 +168,9 @@ _mongoc_cursor_op_getmore (mongoc_cursor_t *cursor, mongoc_cursor_response_legac const int64_t started = bson_get_monotonic_time (); - mongoc_server_stream_t *const server_stream = _mongoc_cursor_fetch_stream (cursor); + const mongoc_ss_log_context_t ss_log_context = { + .operation = "getMore", .has_operation_id = true, .operation_id = cursor->operation_id}; + mongoc_server_stream_t *const server_stream = _mongoc_cursor_fetch_stream (cursor, &ss_log_context); if (!server_stream) { GOTO (done); @@ -543,7 +545,9 @@ _mongoc_cursor_op_query_find (mongoc_cursor_t *cursor, bson_t *filter, mongoc_cu bool ret = false; - mongoc_server_stream_t *const server_stream = _mongoc_cursor_fetch_stream (cursor); + const mongoc_ss_log_context_t ss_log_context = { + .operation = "find", .has_operation_id = true, .operation_id = cursor->operation_id}; + mongoc_server_stream_t *const server_stream = _mongoc_cursor_fetch_stream (cursor, &ss_log_context); if (!server_stream) { RETURN (false); diff --git a/src/libmongoc/src/mongoc/mongoc-cursor-private.h b/src/libmongoc/src/mongoc/mongoc-cursor-private.h index 5a791293964..12e38108e79 100644 --- a/src/libmongoc/src/mongoc/mongoc-cursor-private.h +++ b/src/libmongoc/src/mongoc/mongoc-cursor-private.h @@ -172,7 +172,7 @@ _mongoc_cursor_flags_to_opts (mongoc_query_flags_t qflags, bson_t *opts, bool *s bool _mongoc_cursor_translate_dollar_query_opts (const bson_t *query, bson_t *opts, bson_t *unwrapped, bson_error_t *error); mongoc_server_stream_t * -_mongoc_cursor_fetch_stream (mongoc_cursor_t *cursor); +_mongoc_cursor_fetch_stream (mongoc_cursor_t *cursor, const mongoc_ss_log_context_t *log_context); void _mongoc_cursor_collection (const mongoc_cursor_t *cursor, const char **collection, int *collection_len); bool diff --git a/src/libmongoc/src/mongoc/mongoc-cursor.c b/src/libmongoc/src/mongoc/mongoc-cursor.c index f891e854fb3..ba9a8e9f9e1 100644 --- a/src/libmongoc/src/mongoc/mongoc-cursor.c +++ b/src/libmongoc/src/mongoc/mongoc-cursor.c @@ -584,7 +584,7 @@ mongoc_cursor_destroy (mongoc_cursor_t *cursor) mongoc_server_stream_t * -_mongoc_cursor_fetch_stream (mongoc_cursor_t *cursor) +_mongoc_cursor_fetch_stream (mongoc_cursor_t *cursor, const mongoc_ss_log_context_t *log_context) { mongoc_server_stream_t *server_stream; bson_t reply; @@ -606,12 +606,20 @@ _mongoc_cursor_fetch_stream (mongoc_cursor_t *cursor) server_stream->must_use_primary = cursor->must_use_primary; } } else { - server_stream = - cursor->is_aggr_with_write_stage - ? mongoc_cluster_stream_for_aggr_with_write ( - &cursor->client->cluster, cursor->read_prefs, cursor->client_session, &reply, &cursor->error) - : mongoc_cluster_stream_for_reads ( - &cursor->client->cluster, cursor->read_prefs, cursor->client_session, NULL, &reply, &cursor->error); + server_stream = cursor->is_aggr_with_write_stage + ? mongoc_cluster_stream_for_aggr_with_write (&cursor->client->cluster, + log_context, + cursor->read_prefs, + cursor->client_session, + &reply, + &cursor->error) + : mongoc_cluster_stream_for_reads (&cursor->client->cluster, + log_context, + cursor->read_prefs, + cursor->client_session, + NULL, + &reply, + &cursor->error); if (server_stream) { /* Remember the selected server_id and whether primary read mode was @@ -912,7 +920,6 @@ _mongoc_cursor_run_command ( mongoc_server_stream_t *server_stream; bson_iter_t iter; mongoc_cmd_parts_t parts; - const char *cmd_name; bool is_primary; mongoc_read_prefs_t *prefs = NULL; char *db = NULL; @@ -922,11 +929,16 @@ _mongoc_cursor_run_command ( ENTRY; + const char *cmd_name = _mongoc_get_command_name (command); + mongoc_cmd_parts_init (&parts, cursor->client, db, MONGOC_QUERY_NONE, command); parts.is_read_command = true; parts.read_prefs = cursor->read_prefs; parts.assembled.operation_id = cursor->operation_id; - server_stream = _mongoc_cursor_fetch_stream (cursor); + + const mongoc_ss_log_context_t ss_log_context = { + .operation = cmd_name, .has_operation_id = true, .operation_id = parts.assembled.operation_id}; + server_stream = _mongoc_cursor_fetch_stream (cursor, &ss_log_context); if (!server_stream) { _mongoc_bson_init_if_set (reply); @@ -1008,7 +1020,6 @@ _mongoc_cursor_run_command ( * OP_QUERY we handle this by setting secondaryOk. here we use * $readPreference. */ - cmd_name = _mongoc_get_command_name (command); is_primary = !cursor->read_prefs || cursor->read_prefs->mode == MONGOC_READ_PRIMARY; if (strcmp (cmd_name, "getMore") != 0 && is_primary && parts.user_query_flags & MONGOC_QUERY_SECONDARY_OK) { @@ -1063,8 +1074,13 @@ _mongoc_cursor_run_command ( BSON_ASSERT (!cursor->is_aggr_with_write_stage && "Cannot attempt a retry on an aggregate operation that " "contains write stages"); - server_stream = mongoc_cluster_stream_for_reads ( - &cursor->client->cluster, cursor->read_prefs, cursor->client_session, ds, reply, &cursor->error); + server_stream = mongoc_cluster_stream_for_reads (&cursor->client->cluster, + &ss_log_context, + cursor->read_prefs, + cursor->client_session, + ds, + reply, + &cursor->error); mongoc_deprioritized_servers_destroy (ds); } @@ -1713,7 +1729,8 @@ _mongoc_cursor_prepare_getmore_command (mongoc_cursor_t *cursor, bson_t *command * * Since this function has no error reporting, we also no-op if we cannot * fetch a stream. */ - server_stream = _mongoc_cursor_fetch_stream (cursor); + const mongoc_ss_log_context_t ss_log_context = {.operation = "getMore"}; + server_stream = _mongoc_cursor_fetch_stream (cursor, &ss_log_context); if (server_stream != NULL && server_stream->sd->max_wire_version >= WIRE_VERSION_4_4) { bson_append_value (command, MONGOC_CURSOR_COMMENT, MONGOC_CURSOR_COMMENT_LEN, comment); diff --git a/src/libmongoc/src/mongoc/mongoc-database.c b/src/libmongoc/src/mongoc/mongoc-database.c index b93803d82fa..10efaedde94 100644 --- a/src/libmongoc/src/mongoc/mongoc-database.c +++ b/src/libmongoc/src/mongoc/mongoc-database.c @@ -1038,7 +1038,9 @@ create_collection_with_encryptedFields (mongoc_database_t *database, // Check the wire version to ensure server is 7.0.0 or newer. { + const mongoc_ss_log_context_t ss_log_context = {.operation = "createCollection"}; mongoc_server_stream_t *stream = mongoc_cluster_stream_for_writes (&database->client->cluster, + &ss_log_context, NULL /* client session */, NULL /* deprioritized servers */, NULL /* reply */, diff --git a/src/libmongoc/src/mongoc/mongoc-read-prefs-private.h b/src/libmongoc/src/mongoc/mongoc-read-prefs-private.h index 7b382de6dab..88567a3676a 100644 --- a/src/libmongoc/src/mongoc/mongoc-read-prefs-private.h +++ b/src/libmongoc/src/mongoc/mongoc-read-prefs-private.h @@ -63,6 +63,18 @@ assemble_query_result_cleanup (mongoc_assemble_query_result_t *result); bool _mongoc_read_prefs_validate (const mongoc_read_prefs_t *read_prefs, bson_error_t *error); +typedef enum { + MONGOC_READ_PREFS_CONTENT_FLAG_MODE = (1 << 0), + MONGOC_READ_PREFS_CONTENT_FLAG_TAGS = (1 << 1), + MONGOC_READ_PREFS_CONTENT_FLAG_MAX_STALENESS_SECONDS = (1 << 2), + MONGOC_READ_PREFS_CONTENT_FLAG_HEDGE = (1 << 3), +} mongoc_read_prefs_content_flags_t; + +bool +mongoc_read_prefs_append_contents_to_bson (const mongoc_read_prefs_t *read_prefs, + bson_t *bson, + mongoc_read_prefs_content_flags_t flags); + #define IS_PREF_PRIMARY(_pref) (!(_pref) || ((_pref)->mode == MONGOC_READ_PRIMARY)) BSON_END_DECLS diff --git a/src/libmongoc/src/mongoc/mongoc-read-prefs.c b/src/libmongoc/src/mongoc/mongoc-read-prefs.c index f4e5a3efcee..fbc5aec96de 100644 --- a/src/libmongoc/src/mongoc/mongoc-read-prefs.c +++ b/src/libmongoc/src/mongoc/mongoc-read-prefs.c @@ -226,7 +226,6 @@ _apply_read_preferences_mongos (const mongoc_read_prefs_t *read_prefs, mongoc_read_mode_t mode; const bson_t *tags = NULL; bson_t child; - const char *mode_str; int64_t max_staleness_seconds = MONGOC_NO_MAX_STALENESS; const bson_t *hedge = NULL; @@ -281,24 +280,55 @@ _apply_read_preferences_mongos (const mongoc_read_prefs_t *read_prefs, } bson_append_document_begin (result->assembled_query, "$readPreference", 15, &child); - mode_str = _mongoc_read_mode_as_str (mode); - bson_append_utf8 (&child, "mode", 4, mode_str, -1); - if (!bson_empty0 (tags)) { - bson_append_array (&child, "tags", 4, tags); - } + mongoc_read_prefs_append_contents_to_bson ( + read_prefs, + &child, + MONGOC_READ_PREFS_CONTENT_FLAG_MODE | MONGOC_READ_PREFS_CONTENT_FLAG_TAGS | + MONGOC_READ_PREFS_CONTENT_FLAG_MAX_STALENESS_SECONDS | MONGOC_READ_PREFS_CONTENT_FLAG_HEDGE); + bson_append_document_end (result->assembled_query, &child); + } +} - if (max_staleness_seconds != MONGOC_NO_MAX_STALENESS) { - bson_append_int64 (&child, "maxStalenessSeconds", 19, max_staleness_seconds); +bool +mongoc_read_prefs_append_contents_to_bson (const mongoc_read_prefs_t *read_prefs, + bson_t *bson, + mongoc_read_prefs_content_flags_t flags) +{ + BSON_OPTIONAL_PARAM (read_prefs); + BSON_ASSERT_PARAM (bson); + + if (flags & MONGOC_READ_PREFS_CONTENT_FLAG_MODE) { + // 'mode' will be Primary when read_prefs==NULL. + mongoc_read_mode_t mode = mongoc_read_prefs_get_mode (read_prefs); + const char *mode_str = _mongoc_read_mode_as_str (mode); + if (!BSON_APPEND_UTF8 (bson, "mode", mode_str)) { + return false; } + } + if (read_prefs) { + // Other content is only available for non-NULL read_prefs + int64_t max_staleness_seconds = mongoc_read_prefs_get_max_staleness_seconds (read_prefs); + const bson_t *hedge = mongoc_read_prefs_get_hedge (read_prefs); + const bson_t *tags = mongoc_read_prefs_get_tags (read_prefs); - if (!bson_empty0 (hedge)) { - bson_append_document (&child, "hedge", 5, hedge); + if ((flags & MONGOC_READ_PREFS_CONTENT_FLAG_TAGS) && !bson_empty (tags) && + !BSON_APPEND_ARRAY (bson, "tags", tags)) { + return false; + } + if ((flags & MONGOC_READ_PREFS_CONTENT_FLAG_MAX_STALENESS_SECONDS) && + max_staleness_seconds != MONGOC_NO_MAX_STALENESS && + !BSON_APPEND_INT64 (bson, "maxStalenessSeconds", max_staleness_seconds)) { + return false; + } + if ((flags & MONGOC_READ_PREFS_CONTENT_FLAG_HEDGE) && !bson_empty (hedge) && + !BSON_APPEND_DOCUMENT (bson, "hedge", hedge)) { + return false; } - - bson_append_document_end (result->assembled_query, &child); } + return true; } + /* *-------------------------------------------------------------------------- * diff --git a/src/libmongoc/src/mongoc/mongoc-server-description-private.h b/src/libmongoc/src/mongoc/mongoc-server-description-private.h index 125718b68c8..7954022e439 100644 --- a/src/libmongoc/src/mongoc/mongoc-server-description-private.h +++ b/src/libmongoc/src/mongoc/mongoc-server-description-private.h @@ -226,6 +226,8 @@ typedef enum { MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_SERVER_PORT = (1 << 1), MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_SERVER_CONNECTION_ID = (1 << 2), MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_SERVICE_ID = (1 << 3), + MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_TYPE = (1 << 4), + MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_ADDRESS = (1 << 5), } mongoc_server_description_content_flags_t; bool diff --git a/src/libmongoc/src/mongoc/mongoc-server-description.c b/src/libmongoc/src/mongoc/mongoc-server-description.c index 84a6c8babac..5722782811f 100644 --- a/src/libmongoc/src/mongoc/mongoc-server-description.c +++ b/src/libmongoc/src/mongoc/mongoc-server-description.c @@ -1239,6 +1239,10 @@ mongoc_server_description_append_contents_to_bson (const mongoc_server_descripti !BSON_APPEND_INT32 (bson, "serverPort", sd->host.port)) { return false; } + if ((flags & MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_ADDRESS) && + !BSON_APPEND_UTF8 (bson, "address", sd->host.host_and_port)) { + return false; + } if (flags & MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_SERVER_CONNECTION_ID) { int64_t server_connection_id = sd->server_connection_id; if (MONGOC_NO_SERVER_CONNECTION_ID != server_connection_id) { @@ -1256,5 +1260,9 @@ mongoc_server_description_append_contents_to_bson (const mongoc_server_descripti } } } + if ((flags & MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_TYPE) && + !BSON_APPEND_UTF8 (bson, "type", mongoc_server_description_type (sd))) { + return false; + } return true; } diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log-private.h b/src/libmongoc/src/mongoc/mongoc-structured-log-private.h index 376a88a97dd..7ed1cd7fd63 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log-private.h +++ b/src/libmongoc/src/mongoc/mongoc-structured-log-private.h @@ -24,6 +24,7 @@ #include "mongoc-cmd-private.h" #include "mongoc-error-private.h" #include "mongoc-server-description-private.h" +#include "mongoc-read-prefs-private.h" #include "mongoc-structured-log.h" BSON_BEGIN_DECLS @@ -181,6 +182,18 @@ mongoc_structured_log_instance_destroy (mongoc_structured_log_instance_t *instan #define _mongoc_structured_log_item_error(_key_or_null, _error_or_null) \ {.func = _mongoc_structured_log_append_error, .arg1.utf8 = (_key_or_null), .arg2.error = (_error_or_null)}, +/** + * @def read_prefs(key, value) + * @brief Structured log item, mongoc_read_prefs_t document + * + * @param key Key as a NUL-terminated const char * expression, or NULL to skip this item. + * @param value Value as a const mongoc_read_prefs_t * expression. NULL is equivalent to Primary read preference. + * */ +#define _mongoc_structured_log_item_read_prefs(_key_or_null, _value_read_prefs) \ + {.func = _mongoc_structured_log_append_read_prefs, \ + .arg1.utf8 = (_key_or_null), \ + .arg2.read_prefs = (_value_read_prefs)}, + /** * @def oid_as_hex(key, value) * @brief Structured log item, bson_oid_t converted to a hex string @@ -204,6 +217,18 @@ mongoc_structured_log_instance_destroy (mongoc_structured_log_instance_t *instan #define _mongoc_structured_log_item_bson_as_json(_key_or_null, _value_bson) \ {.func = _mongoc_structured_log_append_bson_as_json, .arg1.utf8 = (_key_or_null), .arg2.bson = (_value_bson)}, +/** + * @def topology_as_description_json(key, topology) + * @brief Structured log item, current description from a mongoc_topology_t serialized into a json string + * + * @param key Key as a NUL-terminated const char * expression, or NULL to skip this item. + * @param topology Topology as a const mongoc_topology_t * expression, or NULL for a null value. + */ +#define _mongoc_structured_log_item_topology_as_description_json(_key_or_null, _topology) \ + {.func = _mongoc_structured_log_append_topology_as_description_json, \ + .arg1.utf8 = (_key_or_null), \ + .arg2.topology = (_topology)}, + typedef enum { MONGOC_STRUCTURED_LOG_CMD_CONTENT_FLAG_COMMAND = (1 << 0), MONGOC_STRUCTURED_LOG_CMD_CONTENT_FLAG_DATABASE_NAME = (1 << 1), @@ -287,8 +312,8 @@ typedef enum { * @brief Structured log item, mongoc_server_description_t fields * * @param sd Borrowed server description reference, as a const mongoc_server_description_t * expression. Required. - * @param ... Fields to include. Order is not significant. Any of: SERVER_HOST, SERVER_PORT, SERVER_CONNECTION_ID, - * SERVICE_ID. + * @param ... Fields to include. Order is not significant. Any of: TYPE, ADDRESS, SERVER_HOST, SERVER_PORT, + * SERVER_CONNECTION_ID, SERVICE_ID. * */ #define _mongoc_structured_log_item_server_description(_server_description, ...) \ {.func = _mongoc_structured_log_append_server_description, \ @@ -332,11 +357,13 @@ struct mongoc_structured_log_builder_stage_t { const bson_error_t *error; const bson_t *bson; const char *utf8; + const mongoc_read_prefs_t *read_prefs; + const struct _mongoc_topology_t *topology; int32_t int32; int64_t int64; mongoc_error_content_flags_t error_flags; - mongoc_structured_log_cmd_content_flags_t cmd_flags; mongoc_server_description_content_flags_t server_description_flags; + mongoc_structured_log_cmd_content_flags_t cmd_flags; } arg2; // Avoid adding an arg3, prefer to use additional stages }; @@ -449,6 +476,16 @@ _mongoc_structured_log_append_server_description (bson_t *bson, const mongoc_structured_log_builder_stage_t *stage, const mongoc_structured_log_opts_t *opts); +const mongoc_structured_log_builder_stage_t * +_mongoc_structured_log_append_topology_as_description_json (bson_t *bson, + const mongoc_structured_log_builder_stage_t *stage, + const mongoc_structured_log_opts_t *opts); + +const mongoc_structured_log_builder_stage_t * +_mongoc_structured_log_append_read_prefs (bson_t *bson, + const mongoc_structured_log_builder_stage_t *stage, + const mongoc_structured_log_opts_t *opts); + BSON_END_DECLS #endif /* MONGOC_STRUCTURED_LOG_PRIVATE_H */ diff --git a/src/libmongoc/src/mongoc/mongoc-structured-log.c b/src/libmongoc/src/mongoc/mongoc-structured-log.c index aad46d3c349..d78f4fac655 100644 --- a/src/libmongoc/src/mongoc/mongoc-structured-log.c +++ b/src/libmongoc/src/mongoc/mongoc-structured-log.c @@ -20,6 +20,7 @@ #include "mongoc-apm-private.h" #include "mongoc-error-private.h" #include "mongoc-structured-log-private.h" +#include "mongoc-topology-private.h" #include "mongoc-structured-log.h" #include "mongoc-util-private.h" @@ -872,3 +873,69 @@ _mongoc_structured_log_append_server_description (bson_t *bson, mongoc_server_description_append_contents_to_bson (sd, bson, flags); return stage + 1; } + +const mongoc_structured_log_builder_stage_t * +_mongoc_structured_log_append_topology_as_description_json (bson_t *bson, + const mongoc_structured_log_builder_stage_t *stage, + const mongoc_structured_log_opts_t *opts) +{ + const mongoc_topology_description_content_flags_t td_flags = + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_TYPE | MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_SET_NAME | + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_MAX_ELECTION_ID | + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_MAX_SET_VERSION | MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_SERVERS | + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_STALE | MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_COMPATIBLE | + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_COMPATIBILITY_ERROR | + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_LOGICAL_SESSION_TIMEOUT_MINUTES; + + const mongoc_server_description_content_flags_t server_flags = + MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_TYPE | MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_ADDRESS; + + const char *key_or_null = stage->arg1.utf8; + const mongoc_topology_t *topology_or_null = stage->arg2.topology; + if (key_or_null) { + if (topology_or_null) { + 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. + */ + 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_destroy (&inner_bson); + mc_tpld_drop_ref (&td); + } else { + bson_append_null (bson, key_or_null, -1); + } + } + return stage + 1; +} + +const mongoc_structured_log_builder_stage_t * +_mongoc_structured_log_append_read_prefs (bson_t *bson, + const mongoc_structured_log_builder_stage_t *stage, + const mongoc_structured_log_opts_t *opts) +{ + BSON_UNUSED (opts); + const char *key_or_null = stage->arg1.utf8; + const mongoc_read_prefs_t *read_prefs = stage->arg2.read_prefs; + if (key_or_null) { + bson_t child; + if (BSON_APPEND_DOCUMENT_BEGIN (bson, key_or_null, &child)) { + mongoc_read_prefs_append_contents_to_bson ( + read_prefs, + &child, + MONGOC_READ_PREFS_CONTENT_FLAG_MODE | MONGOC_READ_PREFS_CONTENT_FLAG_TAGS | + MONGOC_READ_PREFS_CONTENT_FLAG_MAX_STALENESS_SECONDS | MONGOC_READ_PREFS_CONTENT_FLAG_HEDGE); + bson_append_document_end (bson, &child); + } + } + return stage + 1; +} diff --git a/src/libmongoc/src/mongoc/mongoc-topology-description-private.h b/src/libmongoc/src/mongoc/mongoc-topology-description-private.h index 12c5c125b86..b24438104ec 100644 --- a/src/libmongoc/src/mongoc/mongoc-topology-description-private.h +++ b/src/libmongoc/src/mongoc/mongoc-topology-description-private.h @@ -21,6 +21,7 @@ #include "mongoc-set-private.h" #include "mongoc-server-description.h" +#include "mongoc-server-description-private.h" #include "mongoc-array-private.h" #include "mongoc-topology-description.h" #include "mongoc-apm-private.h" @@ -66,6 +67,18 @@ struct _mongoc_topology_description_t { typedef enum { MONGOC_SS_READ, MONGOC_SS_WRITE, MONGOC_SS_AGGREGATE_WITH_WRITE } mongoc_ss_optype_t; +/** + * @brief Contextual information for logging during server selection + * + * Required to support the "common fields" defined in the Server Selection Logging specification. + * The 'operation' string is borrowed for the lifetime of the mongoc_ss_log_context_t. + */ +typedef struct _mongoc_ss_log_context_t { + const char *operation; // Required + int64_t operation_id; + bool has_operation_id; +} mongoc_ss_log_context_t; + void mongoc_topology_description_init (mongoc_topology_description_t *description, int64_t heartbeat_msec); @@ -180,4 +193,22 @@ mongoc_deprioritized_servers_add_if_sharded (mongoc_deprioritized_servers_t *ds, mongoc_topology_description_type_t topology_type, const mongoc_server_description_t *sd); +typedef enum { + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_TYPE = (1 << 0), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_SET_NAME = (1 << 1), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_MAX_ELECTION_ID = (1 << 2), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_MAX_SET_VERSION = (1 << 3), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_SERVERS = (1 << 4), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_STALE = (1 << 5), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_COMPATIBLE = (1 << 6), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_COMPATIBILITY_ERROR = (1 << 7), + MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_LOGICAL_SESSION_TIMEOUT_MINUTES = (1 << 8), +} mongoc_topology_description_content_flags_t; + +bool +mongoc_topology_description_append_contents_to_bson (const mongoc_topology_description_t *td, + bson_t *bson, + mongoc_topology_description_content_flags_t flags, + mongoc_server_description_content_flags_t servers_flags); + #endif /* MONGOC_TOPOLOGY_DESCRIPTION_PRIVATE_H */ diff --git a/src/libmongoc/src/mongoc/mongoc-topology-description.c b/src/libmongoc/src/mongoc/mongoc-topology-description.c index 3b33ba3704c..4a22d1b7df0 100644 --- a/src/libmongoc/src/mongoc/mongoc-topology-description.c +++ b/src/libmongoc/src/mongoc/mongoc-topology-description.c @@ -14,6 +14,7 @@ * limitations under the License. */ +#include "common-oid-private.h" #include "mongoc-array-private.h" #include "mongoc-error.h" #include "mongoc-server-description-private.h" @@ -2541,3 +2542,68 @@ mongoc_deprioritized_servers_add_if_sharded (mongoc_deprioritized_servers_t *ds, mongoc_deprioritized_servers_add (ds, sd); } } + +bool +mongoc_topology_description_append_contents_to_bson (const mongoc_topology_description_t *td, + bson_t *bson, + mongoc_topology_description_content_flags_t flags, + mongoc_server_description_content_flags_t servers_flags) +{ + // Follow the language-independent format from the SDAM spec. + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_TYPE) && + !BSON_APPEND_UTF8 (bson, "type", mongoc_topology_description_type (td))) { + return false; + } + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_SET_NAME) && td->set_name && + !BSON_APPEND_UTF8 (bson, "setName", td->set_name)) { + return false; + } + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_MAX_ELECTION_ID) && + !mcommon_oid_is_zero (&td->max_election_id) && !BSON_APPEND_OID (bson, "maxElectionId", &td->max_election_id)) { + return false; + } + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_MAX_SET_VERSION) && + MONGOC_NO_SET_VERSION != td->max_set_version && + !BSON_APPEND_INT64 (bson, "maxSetVersion", td->max_set_version)) { + return false; + } + if (flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_SERVERS) { + const mongoc_set_t *const set = mc_tpld_servers_const (BSON_ASSERT_PTR_INLINE (td)); + bson_array_builder_t *array; + if (BSON_APPEND_ARRAY_BUILDER_BEGIN (bson, "servers", &array)) { + bool ok = true; + for (size_t i = 0; ok && i < set->items_len; i++) { + const mongoc_server_description_t *sd = mongoc_set_get_item_const (set, i); + bson_t child; + if (!bson_array_builder_append_document_begin (array, &child)) { + ok = false; + } else { + ok &= mongoc_server_description_append_contents_to_bson (sd, &child, servers_flags); + ok &= bson_array_builder_append_document_end (array, &child); + } + } + if (!bson_append_array_builder_end (bson, array) || !ok) { + return false; + } + } else { + return false; + } + } + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_STALE) && !BSON_APPEND_BOOL (bson, "stale", td->stale)) { + return false; + } + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_COMPATIBLE) && + !BSON_APPEND_BOOL (bson, "compatible", td->compatibility_error.code == 0)) { + return false; + } + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_COMPATIBILITY_ERROR) && 0 != td->compatibility_error.code && + !BSON_APPEND_UTF8 (bson, "compatibilityError", td->compatibility_error.message)) { + return false; + } + if ((flags & MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_LOGICAL_SESSION_TIMEOUT_MINUTES) && + MONGOC_NO_SESSIONS != td->session_timeout_minutes && + !BSON_APPEND_INT64 (bson, "logicalSessionTimeoutMinutes", td->session_timeout_minutes)) { + return false; + } + return true; +} diff --git a/src/libmongoc/src/mongoc/mongoc-topology-private.h b/src/libmongoc/src/mongoc/mongoc-topology-private.h index 0ec05e1afb8..28a0fa2c0f8 100644 --- a/src/libmongoc/src/mongoc/mongoc-topology-private.h +++ b/src/libmongoc/src/mongoc/mongoc-topology-private.h @@ -30,7 +30,6 @@ #include "mongoc-ts-pool-private.h" #include "mongoc-shared-private.h" #include "mongoc-sleep.h" -#include "mongoc-structured-log-private.h" #include #define MONGOC_TOPOLOGY_MIN_HEARTBEAT_FREQUENCY_MS 500 @@ -56,6 +55,7 @@ typedef enum mongoc_topology_cse_state_t { struct _mongoc_background_monitor_t; struct _mongoc_client_pool_t; +struct mongoc_structured_log_instance_t; typedef enum { MONGOC_RR_SRV, MONGOC_RR_TXT } mongoc_rr_type_t; @@ -210,7 +210,7 @@ typedef struct _mongoc_topology_t { mongoc_set_t *rtt_monitors; bson_mutex_t apm_mutex; - mongoc_structured_log_instance_t *structured_log; + struct mongoc_structured_log_instance_t *structured_log; /* This is overridable for SRV polling tests to mock DNS records. */ _mongoc_rr_resolver_fn rr_resolver; @@ -266,6 +266,7 @@ mongoc_topology_compatible (const mongoc_topology_description_t *td, * * @param topology The topology to inspect and/or update. * @param optype The operation that is intended to be performed. + * @param log_context Additional contextual information used only to support standardized logging. * @param read_prefs The read preferences for the command. * @param must_use_primary An optional output parameter. Server selection might * need to override the caller's read preferences' read mode to 'primary'. @@ -282,6 +283,7 @@ mongoc_topology_compatible (const mongoc_topology_description_t *td, mongoc_server_description_t * mongoc_topology_select (mongoc_topology_t *topology, mongoc_ss_optype_t optype, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, bool *must_use_primary, bson_error_t *error); @@ -294,6 +296,7 @@ mongoc_topology_select (mongoc_topology_t *topology, * * @param topology The topology to inspect and/or update. * @param optype The operation that is intended to be performed. + * @param log_context Additional contextual information used only to support standardized logging. * @param read_prefs The read preferences for the command. * @param must_use_primary An optional output parameter. Server selection might * need to override the caller's read preferences' read mode to 'primary'. @@ -309,6 +312,7 @@ mongoc_topology_select (mongoc_topology_t *topology, uint32_t mongoc_topology_select_server_id (mongoc_topology_t *topology, mongoc_ss_optype_t optype, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, bool *must_use_primary, const mongoc_deprioritized_servers_t *ds, @@ -363,7 +367,9 @@ void _mongoc_topology_update_cluster_time (mongoc_topology_t *topology, const bson_t *reply); mongoc_server_session_t * -_mongoc_topology_pop_server_session (mongoc_topology_t *topology, bson_error_t *error); +_mongoc_topology_pop_server_session (mongoc_topology_t *topology, + const mongoc_ss_log_context_t *log_context, + bson_error_t *error); void _mongoc_topology_push_server_session (mongoc_topology_t *topology, mongoc_server_session_t *server_session); diff --git a/src/libmongoc/src/mongoc/mongoc-topology.c b/src/libmongoc/src/mongoc/mongoc-topology.c index 1546152f576..fa090759db8 100644 --- a/src/libmongoc/src/mongoc/mongoc-topology.c +++ b/src/libmongoc/src/mongoc/mongoc-topology.c @@ -32,6 +32,7 @@ #include "mongoc-error-private.h" #include "mongoc-topology-background-monitoring-private.h" #include "mongoc-read-prefs-private.h" +#include "mongoc-structured-log-private.h" #include "utlist.h" @@ -1033,11 +1034,13 @@ _mongoc_server_selection_error (const char *msg, const bson_error_t *scanner_err mongoc_server_description_t * mongoc_topology_select (mongoc_topology_t *topology, mongoc_ss_optype_t optype, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, bool *must_use_primary, bson_error_t *error) { - uint32_t server_id = mongoc_topology_select_server_id (topology, optype, read_prefs, must_use_primary, NULL, error); + uint32_t server_id = + mongoc_topology_select_server_id (topology, optype, log_context, read_prefs, must_use_primary, NULL, error); if (server_id) { /* new copy of the server description */ @@ -1140,6 +1143,7 @@ _mongoc_topology_select_server_id_loadbalanced (mongoc_topology_t *topology, bso uint32_t mongoc_topology_select_server_id (mongoc_topology_t *topology, mongoc_ss_optype_t optype, + const mongoc_ss_log_context_t *log_context, const mongoc_read_prefs_t *read_prefs, bool *must_use_primary, const mongoc_deprioritized_servers_t *ds, @@ -1154,6 +1158,7 @@ mongoc_topology_select_server_id (mongoc_topology_t *topology, bool try_once; int64_t sleep_usec; bool tried_once; + bool logged_waiting_for_suitable_server = false; bson_error_t scanner_error = {0}; int64_t heartbeat_msec; uint32_t server_id; @@ -1174,6 +1179,15 @@ mongoc_topology_select_server_id (mongoc_topology_t *topology, BSON_ASSERT (topology); ts = topology->scanner; + mongoc_structured_log (topology->structured_log, + MONGOC_STRUCTURED_LOG_LEVEL_DEBUG, + MONGOC_STRUCTURED_LOG_COMPONENT_SERVER_SELECTION, + "Server selection started", + read_prefs ("selector", read_prefs), + utf8 ("operation", log_context->operation), + int64 (log_context->has_operation_id ? "operationId" : NULL, log_context->operation_id), + topology_as_description_json ("topologyDescription", topology)); + if (!mongoc_topology_scanner_valid (ts)) { if (error) { mongoc_topology_scanner_get_error (ts, error); @@ -1233,6 +1247,19 @@ mongoc_topology_select_server_id (mongoc_topology_t *topology, server_id = 0; goto done; } + if (!logged_waiting_for_suitable_server) { + logged_waiting_for_suitable_server = true; + mongoc_structured_log ( + topology->structured_log, + MONGOC_STRUCTURED_LOG_LEVEL_INFO, + MONGOC_STRUCTURED_LOG_COMPONENT_SERVER_SELECTION, + "Waiting for suitable server to become available", + read_prefs ("selector", read_prefs), + utf8 ("operation", log_context->operation), + int64 (log_context->has_operation_id ? "operationId" : NULL, log_context->operation_id), + topology_as_description_json ("topologyDescription", topology), + int64 ("remainingTimeMS", (expire_at - loop_end) / 1000)); + } topology->usleep_fn (sleep_usec, topology->usleep_data); } @@ -1322,6 +1349,18 @@ mongoc_topology_select_server_id (mongoc_topology_t *topology, _mongoc_read_mode_as_str (mongoc_read_prefs_get_mode (read_prefs))); _mongoc_topology_request_scan (topology); + if (!logged_waiting_for_suitable_server) { + logged_waiting_for_suitable_server = true; + mongoc_structured_log (topology->structured_log, + MONGOC_STRUCTURED_LOG_LEVEL_INFO, + MONGOC_STRUCTURED_LOG_COMPONENT_SERVER_SELECTION, + "Waiting for suitable server to become available", + read_prefs ("selector", read_prefs), + utf8 ("operation", log_context->operation), + int64 (log_context->has_operation_id ? "operationId" : NULL, log_context->operation_id), + topology_as_description_json ("topologyDescription", topology), + int64 ("remainingTimeMS", (expire_at - loop_start) / 1000)); + } TRACE ("server selection about to wait for %" PRId64 "ms", (expire_at - loop_start) / 1000); r = mongoc_cond_timedwait ( &topology->cond_client, &topology->tpld_modification_mtx, (expire_at - loop_start) / 1000); @@ -1364,11 +1403,32 @@ mongoc_topology_select_server_id (mongoc_topology_t *topology, } done: - if (error && server_id == 0) { - /* server_id set to zero indicates that an error has occured and that `error` is initialized */ - if (error->domain == MONGOC_ERROR_SERVER_SELECTION) { + /* server_id set to zero indicates an error has occured and that `error` should be initialized */ + if (server_id == 0) { + if (error && error->domain == MONGOC_ERROR_SERVER_SELECTION) { _mongoc_error_append (error, mcommon_str_from_append (&topology_type)); } + mongoc_structured_log (topology->structured_log, + MONGOC_STRUCTURED_LOG_LEVEL_DEBUG, + MONGOC_STRUCTURED_LOG_COMPONENT_SERVER_SELECTION, + "Server selection failed", + read_prefs ("selector", read_prefs), + utf8 ("operation", log_context->operation), + int64 (log_context->has_operation_id ? "operationId" : NULL, log_context->operation_id), + topology_as_description_json ("topologyDescription", topology), + error ("failure", error)); + } else { + mongoc_structured_log ( + topology->structured_log, + MONGOC_STRUCTURED_LOG_LEVEL_DEBUG, + MONGOC_STRUCTURED_LOG_COMPONENT_SERVER_SELECTION, + "Server selection succeeded", + read_prefs ("selector", read_prefs), + utf8 ("operation", log_context->operation), + int64 (log_context->has_operation_id ? "operationId" : NULL, log_context->operation_id), + topology_as_description_json ("topologyDescription", topology), + server_description ( + mongoc_topology_description_server_by_id_const (td.ptr, server_id, NULL), SERVER_HOST, SERVER_PORT)); } mcommon_string_from_append_destroy (&topology_type); mc_tpld_drop_ref (&td); @@ -1554,7 +1614,9 @@ _mongoc_topology_update_cluster_time (mongoc_topology_t *topology, const bson_t */ mongoc_server_session_t * -_mongoc_topology_pop_server_session (mongoc_topology_t *topology, bson_error_t *error) +_mongoc_topology_pop_server_session (mongoc_topology_t *topology, + const mongoc_ss_log_context_t *log_context, + bson_error_t *error) { int64_t timeout; mongoc_server_session_t *ss = NULL; @@ -1572,6 +1634,7 @@ _mongoc_topology_pop_server_session (mongoc_topology_t *topology, bson_error_t * if (!mongoc_topology_description_has_data_node (td.ptr)) { if (!mongoc_topology_select_server_id (topology, MONGOC_SS_READ, + log_context, NULL /* read prefs */, NULL /* chosen read mode */, NULL /* deprioritized servers */, diff --git a/src/libmongoc/src/mongoc/mongoc-write-command-private.h b/src/libmongoc/src/mongoc/mongoc-write-command-private.h index 0dbc8ef5615..85dc7b19a20 100644 --- a/src/libmongoc/src/mongoc/mongoc-write-command-private.h +++ b/src/libmongoc/src/mongoc/mongoc-write-command-private.h @@ -181,6 +181,8 @@ _mongoc_write_command_execute_idl (mongoc_write_command_t *command, uint32_t offset, const struct _mongoc_crud_opts_t *crud, mongoc_write_result_t *result); +const char * +_mongoc_write_command_get_name (const mongoc_write_command_t *command); void _mongoc_write_result_init (mongoc_write_result_t *result); #define MONGOC_WRITE_RESULT_COMPLETE(_result, ...) _mongoc_write_result_complete (_result, __VA_ARGS__, NULL) diff --git a/src/libmongoc/src/mongoc/mongoc-write-command.c b/src/libmongoc/src/mongoc/mongoc-write-command.c index 476192d98f9..5b4363ff2f9 100644 --- a/src/libmongoc/src/mongoc/mongoc-write-command.c +++ b/src/libmongoc/src/mongoc/mongoc-write-command.c @@ -337,6 +337,15 @@ _mongoc_write_command_init_update_idl (mongoc_write_command_t *command, } +const char * +_mongoc_write_command_get_name (const mongoc_write_command_t *command) +{ + BSON_ASSERT_PARAM (command); + BSON_ASSERT (command->type >= 0 && command->type < (int) (sizeof gCommandNames / sizeof gCommandNames[0])); + return gCommandNames[command->type]; +} + + /* takes initialized bson_t *doc and begins formatting a write command */ void _mongoc_write_command_init (bson_t *doc, mongoc_write_command_t *command, const char *collection) @@ -347,7 +356,7 @@ _mongoc_write_command_init (bson_t *doc, mongoc_write_command_t *command, const EXIT; } - BSON_APPEND_UTF8 (doc, gCommandNames[command->type], collection); + BSON_APPEND_UTF8 (doc, _mongoc_write_command_get_name (command), collection); BSON_APPEND_BOOL (doc, "ordered", command->flags.ordered); if (command->flags.bypass_document_validation) { @@ -399,8 +408,11 @@ _empty_error (mongoc_write_command_t *command, bson_error_t *error) MONGOC_ERROR_COLLECTION_INSERT_FAILED, MONGOC_ERROR_COLLECTION_UPDATE_FAILED}; - bson_set_error ( - error, MONGOC_ERROR_COLLECTION, codes[command->type], "Cannot do an empty %s", gCommandNames[command->type]); + bson_set_error (error, + MONGOC_ERROR_COLLECTION, + codes[command->type], + "Cannot do an empty %s", + _mongoc_write_command_get_name (command)); } diff --git a/src/libmongoc/tests/json-test.c b/src/libmongoc/tests/json-test.c index 016f5a298ed..db81f900923 100644 --- a/src/libmongoc/tests/json-test.c +++ b/src/libmongoc/tests/json-test.c @@ -1154,7 +1154,9 @@ execute_test (const json_test_config_t *config, } /* Select a primary for testing */ - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "configureFailPoint"}; + server_id = + mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); json_test_ctx_init (&ctx, test, client, db, collection, config); @@ -1758,7 +1760,9 @@ run_json_general_test (const json_test_config_t *config) mongoc_uri_destroy (uri); /* clean up in case a previous test aborted */ - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "configureFailPoint"}; + server_id = mongoc_topology_select_server_id ( + client->topology, MONGOC_SS_WRITE, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); deactivate_fail_points (client, server_id); r = mongoc_client_command_with_opts ( diff --git a/src/libmongoc/tests/json/server_selection/in_window/equilibrium.json b/src/libmongoc/tests/json/server_selection/in_window/equilibrium.json new file mode 100644 index 00000000000..c5f177d49b9 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/equilibrium.json @@ -0,0 +1,46 @@ +{ + "description": "When in equilibrium selection is evenly distributed", + "topology_description": { + "type": "Sharded", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "c:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 5 + }, + { + "address": "b:27017", + "operation_count": 5 + }, + { + "address": "c:27017", + "operation_count": 5 + } + ], + "iterations": 2000, + "outcome": { + "tolerance": 0.05, + "expected_frequencies": { + "a:27017": 0.33, + "b:27017": 0.33, + "c:27017": 0.33 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/in_window/many-choices.json b/src/libmongoc/tests/json/server_selection/in_window/many-choices.json new file mode 100644 index 00000000000..7e940513ef6 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/many-choices.json @@ -0,0 +1,106 @@ +{ + "description": "Selections from many choices occur at correct frequencies", + "topology_description": { + "type": "Sharded", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "c:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "d:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "e:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "f:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "g:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "h:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "i:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 0 + }, + { + "address": "b:27017", + "operation_count": 5 + }, + { + "address": "c:27017", + "operation_count": 5 + }, + { + "address": "d:27017", + "operation_count": 10 + }, + { + "address": "e:27017", + "operation_count": 10 + }, + { + "address": "f:27017", + "operation_count": 20 + }, + { + "address": "g:27017", + "operation_count": 20 + }, + { + "address": "h:27017", + "operation_count": 50 + }, + { + "address": "i:27017", + "operation_count": 60 + } + ], + "iterations": 10000, + "outcome": { + "tolerance": 0.03, + "expected_frequencies": { + "a:27017": 0.22, + "b:27017": 0.18, + "c:27017": 0.18, + "d:27017": 0.125, + "e:27017": 0.125, + "f:27017": 0.074, + "g:27017": 0.074, + "h:27017": 0.0277, + "i:27017": 0 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/in_window/one-least-two-tied.json b/src/libmongoc/tests/json/server_selection/in_window/one-least-two-tied.json new file mode 100644 index 00000000000..ed7526e7166 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/one-least-two-tied.json @@ -0,0 +1,46 @@ +{ + "description": "Least operations gets most selections, two tied share the rest", + "topology_description": { + "type": "Sharded", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "c:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 16 + }, + { + "address": "b:27017", + "operation_count": 10 + }, + { + "address": "c:27017", + "operation_count": 16 + } + ], + "iterations": 2000, + "outcome": { + "tolerance": 0.05, + "expected_frequencies": { + "a:27017": 0.165, + "b:27017": 0.66, + "c:27017": 0.165 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/in_window/rs-equilibrium.json b/src/libmongoc/tests/json/server_selection/in_window/rs-equilibrium.json new file mode 100644 index 00000000000..61c6687e500 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/rs-equilibrium.json @@ -0,0 +1,46 @@ +{ + "description": "When in equilibrium selection is evenly distributed (replica set)", + "topology_description": { + "type": "ReplicaSetWithPrimary", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "RSPrimary" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "RSSecondary" + }, + { + "address": "c:27017", + "avg_rtt_ms": 35, + "type": "RSSecondary" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 6 + }, + { + "address": "b:27017", + "operation_count": 6 + }, + { + "address": "c:27017", + "operation_count": 6 + } + ], + "iterations": 2000, + "outcome": { + "tolerance": 0.05, + "expected_frequencies": { + "a:27017": 0.33, + "b:27017": 0.33, + "c:27017": 0.33 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/in_window/rs-three-choices.json b/src/libmongoc/tests/json/server_selection/in_window/rs-three-choices.json new file mode 100644 index 00000000000..3fdc15205ce --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/rs-three-choices.json @@ -0,0 +1,46 @@ +{ + "description": "Selections from three servers occur at proper distributions (replica set)", + "topology_description": { + "type": "ReplicaSetWithPrimary", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "RSPrimary" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "RSSecondary" + }, + { + "address": "c:27017", + "avg_rtt_ms": 35, + "type": "RSSecondary" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 3 + }, + { + "address": "b:27017", + "operation_count": 6 + }, + { + "address": "c:27017", + "operation_count": 20 + } + ], + "iterations": 2000, + "outcome": { + "tolerance": 0.05, + "expected_frequencies": { + "a:27017": 0.66, + "b:27017": 0.33, + "c:27017": 0 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/in_window/three-choices.json b/src/libmongoc/tests/json/server_selection/in_window/three-choices.json new file mode 100644 index 00000000000..7b5b414549d --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/three-choices.json @@ -0,0 +1,46 @@ +{ + "description": "Selections from three servers occur at proper distributions", + "topology_description": { + "type": "Sharded", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "c:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 3 + }, + { + "address": "b:27017", + "operation_count": 6 + }, + { + "address": "c:27017", + "operation_count": 20 + } + ], + "iterations": 2000, + "outcome": { + "tolerance": 0.05, + "expected_frequencies": { + "a:27017": 0.66, + "b:27017": 0.33, + "c:27017": 0 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/in_window/two-choices.json b/src/libmongoc/tests/json/server_selection/in_window/two-choices.json new file mode 100644 index 00000000000..2c7a605d8d7 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/two-choices.json @@ -0,0 +1,36 @@ +{ + "description": "Better of two choices always selected", + "topology_description": { + "type": "Sharded", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 0 + }, + { + "address": "b:27017", + "operation_count": 5 + } + ], + "iterations": 100, + "outcome": { + "tolerance": 0, + "expected_frequencies": { + "a:27017": 1, + "b:27017": 0 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/in_window/two-least.json b/src/libmongoc/tests/json/server_selection/in_window/two-least.json new file mode 100644 index 00000000000..73214fc6472 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/in_window/two-least.json @@ -0,0 +1,46 @@ +{ + "description": "Two tied for least operations share all selections", + "topology_description": { + "type": "Sharded", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "b:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + }, + { + "address": "c:27017", + "avg_rtt_ms": 35, + "type": "Mongos" + } + ] + }, + "mocked_topology_state": [ + { + "address": "a:27017", + "operation_count": 10 + }, + { + "address": "b:27017", + "operation_count": 10 + }, + { + "address": "c:27017", + "operation_count": 16 + } + ], + "iterations": 2000, + "outcome": { + "tolerance": 0.05, + "expected_frequencies": { + "a:27017": 0.5, + "b:27017": 0.5, + "c:27017": 0 + } + } +} diff --git a/src/libmongoc/tests/json/server_selection/logging/load-balanced.json b/src/libmongoc/tests/json/server_selection/logging/load-balanced.json new file mode 100644 index 00000000000..5855c4e991e --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/logging/load-balanced.json @@ -0,0 +1,107 @@ +{ + "description": "server-selection-logging", + "schemaVersion": "1.13", + "runOnRequirements": [ + { + "topologies": [ + "load-balanced" + ] + } + ], + "createEntities": [ + { + "client": { + "id": "client", + "uriOptions": { + "heartbeatFrequencyMS": 500 + }, + "observeLogMessages": { + "serverSelection": "debug" + }, + "observeEvents": [ + "serverDescriptionChangedEvent" + ] + } + }, + { + "database": { + "id": "database", + "client": "client", + "databaseName": "logging-tests" + } + }, + { + "collection": { + "id": "collection", + "database": "database", + "collectionName": "server-selection" + } + } + ], + "tests": [ + { + "description": "A successful operation - load balanced cluster", + "operations": [ + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "serverDescriptionChangedEvent": { + "newDescription": { + "type": "LoadBalancer" + } + } + }, + "count": 1 + } + }, + { + "name": "insertOne", + "object": "collection", + "arguments": { + "document": { + "x": 1 + } + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + } + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection succeeded", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + } + } + } + ] + } + ] + } + ] +} diff --git a/src/libmongoc/tests/json/server_selection/logging/operation-id.json b/src/libmongoc/tests/json/server_selection/logging/operation-id.json new file mode 100644 index 00000000000..72ebff60d80 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/logging/operation-id.json @@ -0,0 +1,418 @@ +{ + "description": "operation-id", + "schemaVersion": "1.14", + "runOnRequirements": [ + { + "topologies": [ + "single" + ] + } + ], + "createEntities": [ + { + "client": { + "id": "client", + "uriOptions": { + "retryWrites": false, + "heartbeatFrequencyMS": 500, + "appName": "loggingClient", + "serverSelectionTimeoutMS": 2000 + }, + "observeLogMessages": { + "serverSelection": "debug" + }, + "observeEvents": [ + "serverDescriptionChangedEvent", + "topologyDescriptionChangedEvent" + ] + } + }, + { + "database": { + "id": "database", + "client": "client", + "databaseName": "logging-tests" + } + }, + { + "collection": { + "id": "collection", + "database": "database", + "collectionName": "server-selection" + } + }, + { + "client": { + "id": "failPointClient" + } + } + ], + "_yamlAnchors": { + "namespace": "logging-tests.server-selection" + }, + "tests": [ + { + "description": "Successful bulkWrite operation: log messages have operationIds", + "operations": [ + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "topologyDescriptionChangedEvent": {} + }, + "count": 2 + } + }, + { + "name": "bulkWrite", + "object": "collection", + "arguments": { + "requests": [ + { + "insertOne": { + "document": { + "x": 1 + } + } + } + ] + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "insert" + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection succeeded", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "insert" + } + } + ] + } + ] + }, + { + "description": "Failed bulkWrite operation: log messages have operationIds", + "runOnRequirements": [ + { + "minServerVersion": "4.4" + } + ], + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": "alwaysOn", + "data": { + "failCommands": [ + "hello", + "ismaster" + ], + "appName": "loggingClient", + "closeConnection": true + } + } + } + }, + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "serverDescriptionChangedEvent": { + "newDescription": { + "type": "Unknown" + } + } + }, + "count": 1 + } + }, + { + "name": "bulkWrite", + "object": "collection", + "arguments": { + "requests": [ + { + "insertOne": { + "document": { + "x": 1 + } + } + } + ] + }, + "expectError": { + "isClientError": true + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "insert" + } + }, + { + "level": "info", + "component": "serverSelection", + "data": { + "message": "Waiting for suitable server to become available", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "insert" + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection failed", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "insert" + } + } + ] + } + ] + }, + { + "description": "Successful client bulkWrite operation: log messages have operationIds", + "runOnRequirements": [ + { + "minServerVersion": "8.0", + "serverless": "forbid" + } + ], + "operations": [ + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "topologyDescriptionChangedEvent": {} + }, + "count": 2 + } + }, + { + "name": "clientBulkWrite", + "object": "client", + "arguments": { + "models": [ + { + "insertOne": { + "namespace": "logging-tests.server-selection", + "document": { + "x": 1 + } + } + } + ] + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "bulkWrite" + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection succeeded", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "bulkWrite" + } + } + ] + } + ] + }, + { + "description": "Failed client bulkWrite operation: log messages have operationIds", + "runOnRequirements": [ + { + "minServerVersion": "8.0", + "serverless": "forbid" + } + ], + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": "alwaysOn", + "data": { + "failCommands": [ + "hello", + "ismaster" + ], + "appName": "loggingClient", + "closeConnection": true + } + } + } + }, + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "serverDescriptionChangedEvent": { + "newDescription": { + "type": "Unknown" + } + } + }, + "count": 1 + } + }, + { + "name": "clientBulkWrite", + "object": "client", + "arguments": { + "models": [ + { + "insertOne": { + "namespace": "logging-tests.server-selection", + "document": { + "x": 1 + } + } + } + ] + }, + "expectError": { + "isClientError": true + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "bulkWrite" + } + }, + { + "level": "info", + "component": "serverSelection", + "data": { + "message": "Waiting for suitable server to become available", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "bulkWrite" + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection failed", + "operationId": { + "$$type": [ + "int", + "long" + ] + }, + "operation": "bulkWrite" + } + } + ] + } + ] + } + ] +} diff --git a/src/libmongoc/tests/json/server_selection/logging/replica-set.json b/src/libmongoc/tests/json/server_selection/logging/replica-set.json new file mode 100644 index 00000000000..5eba784bf2a --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/logging/replica-set.json @@ -0,0 +1,228 @@ +{ + "description": "replica-set-logging", + "schemaVersion": "1.14", + "runOnRequirements": [ + { + "topologies": [ + "replicaset" + ] + } + ], + "createEntities": [ + { + "client": { + "id": "client", + "uriOptions": { + "retryWrites": false, + "heartbeatFrequencyMS": 500, + "serverSelectionTimeoutMS": 2000 + }, + "observeLogMessages": { + "serverSelection": "debug" + }, + "observeEvents": [ + "serverDescriptionChangedEvent", + "topologyDescriptionChangedEvent" + ] + } + }, + { + "database": { + "id": "database", + "client": "client", + "databaseName": "logging-tests" + } + }, + { + "collection": { + "id": "collection", + "database": "database", + "collectionName": "server-selection" + } + }, + { + "client": { + "id": "failPointClient" + } + }, + { + "collection": { + "id": "unsatisfiableRPColl", + "database": "database", + "collectionName": "unsatisfiableRPColl", + "collectionOptions": { + "readPreference": { + "mode": "Secondary", + "tagSets": [ + { + "nonexistenttag": "a" + } + ] + } + } + } + } + ], + "tests": [ + { + "description": "A successful operation", + "operations": [ + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "topologyDescriptionChangedEvent": {} + }, + "count": 4 + } + }, + { + "name": "insertOne", + "object": "collection", + "arguments": { + "document": { + "x": 1 + } + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + } + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection succeeded", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + }, + "serverHost": { + "$$type": "string" + }, + "serverPort": { + "$$type": [ + "int", + "long" + ] + } + } + } + ] + } + ] + }, + { + "description": "Server selection fails due to unsatisfiable read preference", + "runOnRequirements": [ + { + "minServerVersion": "4.0" + } + ], + "operations": [ + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "topologyDescriptionChangedEvent": {} + }, + "count": 4 + } + }, + { + "name": "find", + "object": "unsatisfiableRPColl", + "arguments": { + "filter": { + "x": 1 + } + }, + "expectError": { + "isClientError": true + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "selector": { + "$$exists": true + }, + "operation": "find", + "topologyDescription": { + "$$exists": true + } + } + }, + { + "level": "info", + "component": "serverSelection", + "data": { + "message": "Waiting for suitable server to become available", + "selector": { + "$$exists": true + }, + "operation": "find", + "topologyDescription": { + "$$exists": true + }, + "remainingTimeMS": { + "$$type": [ + "int", + "long" + ] + } + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection failed", + "selector": { + "$$exists": true + }, + "operation": "find", + "topologyDescription": { + "$$exists": true + }, + "failure": { + "$$exists": true + } + } + } + ] + } + ] + } + ] +} diff --git a/src/libmongoc/tests/json/server_selection/logging/sharded.json b/src/libmongoc/tests/json/server_selection/logging/sharded.json new file mode 100644 index 00000000000..d42fba91004 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/logging/sharded.json @@ -0,0 +1,237 @@ +{ + "description": "server-selection-logging", + "schemaVersion": "1.14", + "runOnRequirements": [ + { + "topologies": [ + "sharded" + ] + } + ], + "createEntities": [ + { + "client": { + "id": "client", + "uriOptions": { + "retryWrites": false, + "heartbeatFrequencyMS": 500, + "appName": "loggingClient", + "serverSelectionTimeoutMS": 2000 + }, + "observeLogMessages": { + "serverSelection": "debug" + }, + "observeEvents": [ + "serverDescriptionChangedEvent", + "topologyDescriptionChangedEvent" + ], + "useMultipleMongoses": false + } + }, + { + "database": { + "id": "database", + "client": "client", + "databaseName": "logging-tests" + } + }, + { + "collection": { + "id": "collection", + "database": "database", + "collectionName": "server-selection" + } + }, + { + "client": { + "id": "failPointClient", + "useMultipleMongoses": false + } + } + ], + "tests": [ + { + "description": "A successful operation", + "operations": [ + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "topologyDescriptionChangedEvent": {} + }, + "count": 2 + } + }, + { + "name": "insertOne", + "object": "collection", + "arguments": { + "document": { + "x": 1 + } + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + } + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection succeeded", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + }, + "serverHost": { + "$$type": "string" + }, + "serverPort": { + "$$type": [ + "int", + "long" + ] + } + } + } + ] + } + ] + }, + { + "description": "Failure due to unreachable server", + "runOnRequirements": [ + { + "minServerVersion": "4.4" + } + ], + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": "alwaysOn", + "data": { + "failCommands": [ + "hello", + "ismaster" + ], + "appName": "loggingClient", + "closeConnection": true + } + } + } + }, + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "serverDescriptionChangedEvent": { + "newDescription": { + "type": "Unknown" + } + } + }, + "count": 1 + } + }, + { + "name": "insertOne", + "object": "collection", + "arguments": { + "document": { + "x": 1 + } + }, + "expectError": { + "isClientError": true + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + } + } + }, + { + "level": "info", + "component": "serverSelection", + "data": { + "message": "Waiting for suitable server to become available", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + }, + "remainingTimeMS": { + "$$type": [ + "int", + "long" + ] + } + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection failed", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + }, + "failure": { + "$$exists": true + } + } + } + ] + } + ] + } + ] +} diff --git a/src/libmongoc/tests/json/server_selection/logging/standalone.json b/src/libmongoc/tests/json/server_selection/logging/standalone.json new file mode 100644 index 00000000000..3b3eddd841e --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/logging/standalone.json @@ -0,0 +1,235 @@ +{ + "description": "standalone-logging", + "schemaVersion": "1.14", + "runOnRequirements": [ + { + "topologies": [ + "single" + ] + } + ], + "createEntities": [ + { + "client": { + "id": "client", + "uriOptions": { + "retryWrites": false, + "heartbeatFrequencyMS": 500, + "appName": "loggingClient", + "serverSelectionTimeoutMS": 2000 + }, + "observeLogMessages": { + "serverSelection": "debug" + }, + "observeEvents": [ + "serverDescriptionChangedEvent", + "topologyDescriptionChangedEvent" + ] + } + }, + { + "database": { + "id": "database", + "client": "client", + "databaseName": "logging-tests" + } + }, + { + "collection": { + "id": "collection", + "database": "database", + "collectionName": "server-selection" + } + }, + { + "client": { + "id": "failPointClient" + } + } + ], + "tests": [ + { + "description": "A successful operation", + "operations": [ + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "topologyDescriptionChangedEvent": {} + }, + "count": 2 + } + }, + { + "name": "insertOne", + "object": "collection", + "arguments": { + "document": { + "x": 1 + } + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + } + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection succeeded", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + }, + "serverHost": { + "$$type": "string" + }, + "serverPort": { + "$$type": [ + "int", + "long" + ] + } + } + } + ] + } + ] + }, + { + "description": "Failure due to unreachable server", + "runOnRequirements": [ + { + "minServerVersion": "4.4" + } + ], + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": "alwaysOn", + "data": { + "failCommands": [ + "hello", + "ismaster" + ], + "appName": "loggingClient", + "closeConnection": true + } + } + } + }, + { + "name": "waitForEvent", + "object": "testRunner", + "arguments": { + "client": "client", + "event": { + "serverDescriptionChangedEvent": { + "newDescription": { + "type": "Unknown" + } + } + }, + "count": 1 + } + }, + { + "name": "insertOne", + "object": "collection", + "arguments": { + "document": { + "x": 1 + } + }, + "expectError": { + "isClientError": true + } + } + ], + "expectLogMessages": [ + { + "client": "client", + "messages": [ + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection started", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + } + } + }, + { + "level": "info", + "component": "serverSelection", + "data": { + "message": "Waiting for suitable server to become available", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + }, + "remainingTimeMS": { + "$$type": [ + "int", + "long" + ] + } + } + }, + { + "level": "debug", + "component": "serverSelection", + "data": { + "message": "Server selection failed", + "selector": { + "$$exists": true + }, + "operation": "insert", + "topologyDescription": { + "$$exists": true + }, + "failure": { + "$$exists": true + } + } + } + ] + } + ] + } + ] +} diff --git a/src/libmongoc/tests/json/server_selection/server_selection/Unknown/read/ghost.json b/src/libmongoc/tests/json/server_selection/server_selection/Unknown/read/ghost.json new file mode 100644 index 00000000000..76d3d774e8d --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/server_selection/Unknown/read/ghost.json @@ -0,0 +1,18 @@ +{ + "topology_description": { + "type": "Unknown", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 5, + "type": "RSGhost" + } + ] + }, + "operation": "read", + "read_preference": { + "mode": "Nearest" + }, + "suitable_servers": [], + "in_latency_window": [] +} diff --git a/src/libmongoc/tests/json/server_selection/server_selection/Unknown/write/ghost.json b/src/libmongoc/tests/json/server_selection/server_selection/Unknown/write/ghost.json new file mode 100644 index 00000000000..65caa4cd0a9 --- /dev/null +++ b/src/libmongoc/tests/json/server_selection/server_selection/Unknown/write/ghost.json @@ -0,0 +1,18 @@ +{ + "topology_description": { + "type": "Unknown", + "servers": [ + { + "address": "a:27017", + "avg_rtt_ms": 5, + "type": "RSGhost" + } + ] + }, + "operation": "write", + "read_preference": { + "mode": "Nearest" + }, + "suitable_servers": [], + "in_latency_window": [] +} diff --git a/src/libmongoc/tests/mock_server/future-functions.c b/src/libmongoc/tests/mock_server/future-functions.c index c9136fe81cb..f2c853fd9dc 100644 --- a/src/libmongoc/tests/mock_server/future-functions.c +++ b/src/libmongoc/tests/mock_server/future-functions.c @@ -1033,9 +1033,10 @@ BSON_THREAD_FUN (background_mongoc_topology_select, data) mongoc_topology_select ( future_value_get_mongoc_topology_ptr (future_get_param (future, 0)), future_value_get_mongoc_ss_optype_t (future_get_param (future, 1)), - future_value_get_const_mongoc_read_prefs_ptr (future_get_param (future, 2)), - future_value_get_bool_ptr (future_get_param (future, 3)), - future_value_get_bson_error_ptr (future_get_param (future, 4)) + future_value_get_const_mongoc_ss_log_context_ptr (future_get_param (future, 2)), + future_value_get_const_mongoc_read_prefs_ptr (future_get_param (future, 3)), + future_value_get_bool_ptr (future_get_param (future, 4)), + future_value_get_bson_error_ptr (future_get_param (future, 5)) )); future_resolve (future, return_value); @@ -2562,12 +2563,13 @@ future_t * future_topology_select ( mongoc_topology_ptr topology, mongoc_ss_optype_t optype, + const_mongoc_ss_log_context_ptr log_context, const_mongoc_read_prefs_ptr read_prefs, bool_ptr must_use_primary, bson_error_ptr error) { future_t *future = future_new (future_value_mongoc_server_description_ptr_type, - 5); + 6); future_value_set_mongoc_topology_ptr ( future_get_param (future, 0), topology); @@ -2575,14 +2577,17 @@ future_topology_select ( future_value_set_mongoc_ss_optype_t ( future_get_param (future, 1), optype); + future_value_set_const_mongoc_ss_log_context_ptr ( + future_get_param (future, 2), log_context); + future_value_set_const_mongoc_read_prefs_ptr ( - future_get_param (future, 2), read_prefs); + future_get_param (future, 3), read_prefs); future_value_set_bool_ptr ( - future_get_param (future, 3), must_use_primary); + future_get_param (future, 4), must_use_primary); future_value_set_bson_error_ptr ( - future_get_param (future, 4), error); + future_get_param (future, 5), error); future_start (future, background_mongoc_topology_select); return future; diff --git a/src/libmongoc/tests/mock_server/future-functions.h b/src/libmongoc/tests/mock_server/future-functions.h index 57adc7e3131..a3c6ab12b26 100644 --- a/src/libmongoc/tests/mock_server/future-functions.h +++ b/src/libmongoc/tests/mock_server/future-functions.h @@ -489,6 +489,7 @@ future_topology_select ( mongoc_topology_ptr topology, mongoc_ss_optype_t optype, + const_mongoc_ss_log_context_ptr log_context, const_mongoc_read_prefs_ptr read_prefs, bool_ptr must_use_primary, bson_error_ptr error diff --git a/src/libmongoc/tests/mock_server/future-value.c b/src/libmongoc/tests/mock_server/future-value.c index 189061429a3..8846f7a598a 100644 --- a/src/libmongoc/tests/mock_server/future-value.c +++ b/src/libmongoc/tests/mock_server/future-value.c @@ -601,3 +601,18 @@ future_value_get_const_mongoc_write_concern_ptr (future_value_t *future_value) BSON_ASSERT (future_value->type == future_value_const_mongoc_write_concern_ptr_type); return future_value->value.const_mongoc_write_concern_ptr_value; } + +void +future_value_set_const_mongoc_ss_log_context_ptr (future_value_t *future_value, const_mongoc_ss_log_context_ptr value) +{ + future_value->type = future_value_const_mongoc_ss_log_context_ptr_type; + future_value->value.const_mongoc_ss_log_context_ptr_value = value; +} + +const_mongoc_ss_log_context_ptr +future_value_get_const_mongoc_ss_log_context_ptr (future_value_t *future_value) +{ + BSON_ASSERT (future_value->type == future_value_const_mongoc_ss_log_context_ptr_type); + return future_value->value.const_mongoc_ss_log_context_ptr_value; +} + diff --git a/src/libmongoc/tests/mock_server/future-value.h b/src/libmongoc/tests/mock_server/future-value.h index 7412ff840aa..136a5445e6a 100644 --- a/src/libmongoc/tests/mock_server/future-value.h +++ b/src/libmongoc/tests/mock_server/future-value.h @@ -49,6 +49,7 @@ typedef const mongoc_find_and_modify_opts_t * const_mongoc_find_and_modify_opts_ typedef const mongoc_iovec_t * const_mongoc_iovec_ptr; typedef const mongoc_read_prefs_t * const_mongoc_read_prefs_ptr; typedef const mongoc_write_concern_t * const_mongoc_write_concern_ptr; +typedef const mongoc_ss_log_context_t * const_mongoc_ss_log_context_ptr; typedef enum { future_value_no_type = 0, @@ -93,6 +94,7 @@ typedef enum { future_value_const_mongoc_iovec_ptr_type, future_value_const_mongoc_read_prefs_ptr_type, future_value_const_mongoc_write_concern_ptr_type, + future_value_const_mongoc_ss_log_context_ptr_type, future_value_void_type, } future_value_type_t; @@ -142,6 +144,7 @@ typedef struct _future_value_t const_mongoc_iovec_ptr const_mongoc_iovec_ptr_value; const_mongoc_read_prefs_ptr const_mongoc_read_prefs_ptr_value; const_mongoc_write_concern_ptr const_mongoc_write_concern_ptr_value; + const_mongoc_ss_log_context_ptr const_mongoc_ss_log_context_ptr_value; } value; } future_value_t; @@ -527,6 +530,15 @@ const_mongoc_write_concern_ptr future_value_get_const_mongoc_write_concern_ptr ( future_value_t *future_value); +void +future_value_set_const_mongoc_ss_log_context_ptr( + future_value_t *future_value, + const_mongoc_ss_log_context_ptr value); + +const_mongoc_ss_log_context_ptr +future_value_get_const_mongoc_ss_log_context_ptr ( + future_value_t *future_value); + #ifdef __clang__ #pragma clang diagnostic pop diff --git a/src/libmongoc/tests/mock_server/future.c b/src/libmongoc/tests/mock_server/future.c index 91a47456bd1..418f78be83e 100644 --- a/src/libmongoc/tests/mock_server/future.c +++ b/src/libmongoc/tests/mock_server/future.c @@ -444,6 +444,16 @@ future_get_const_mongoc_write_concern_ptr (future_t *future) FUTURE_TIMEOUT_ABORT; } +const_mongoc_ss_log_context_ptr +future_get_const_mongoc_ss_log_context_ptr (future_t *future) +{ + if (future_wait (future)) { + return future_value_get_const_mongoc_ss_log_context_ptr (&future->return_value); + } + + FUTURE_TIMEOUT_ABORT; +} + future_t * future_new (future_value_type_t return_type, int argc) diff --git a/src/libmongoc/tests/mock_server/future.h b/src/libmongoc/tests/mock_server/future.h index bef82719d09..99b64630e4d 100644 --- a/src/libmongoc/tests/mock_server/future.h +++ b/src/libmongoc/tests/mock_server/future.h @@ -165,6 +165,9 @@ future_get_const_mongoc_read_prefs_ptr (future_t *future); const_mongoc_write_concern_ptr future_get_const_mongoc_write_concern_ptr (future_t *future); +const_mongoc_ss_log_context_ptr +future_get_const_mongoc_ss_log_context_ptr (future_t *future); + void future_destroy (future_t *future); diff --git a/src/libmongoc/tests/test-conveniences.h b/src/libmongoc/tests/test-conveniences.h index 355d90a5f11..4a165c65a69 100644 --- a/src/libmongoc/tests/test-conveniences.h +++ b/src/libmongoc/tests/test-conveniences.h @@ -293,4 +293,9 @@ semver_to_string (semver_t *str); #define TEST_ERROR_CODE 654321 #define test_set_error(error, ...) bson_set_error (error, TEST_ERROR_DOMAIN, TEST_ERROR_CODE, __VA_ARGS__) +/* An arbitrary traceable mongoc_ss_log_context_t for tests. + * Logs the function name and file:line as the "operation". */ +#define TEST_SS_LOG_CONTEXT \ + (&(mongoc_ss_log_context_t){.operation = tmp_str ("%s:%d: %s", __FILE__, (int) __LINE__, BSON_FUNC)}) + #endif /* TEST_CONVENIENCES_H */ diff --git a/src/libmongoc/tests/test-mongoc-bulk.c b/src/libmongoc/tests/test-mongoc-bulk.c index afcb2e42f1e..0e983c78549 100644 --- a/src/libmongoc/tests/test-mongoc-bulk.c +++ b/src/libmongoc/tests/test-mongoc-bulk.c @@ -3884,7 +3884,7 @@ server_id_for_read_mode (mongoc_client_t *client, mongoc_read_mode_t read_mode) ASSERT (client); prefs = mongoc_read_prefs_new (read_mode); - sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, prefs, NULL, &error); + sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, prefs, NULL, &error); ASSERT_OR_PRINT (sd, error); server_id = sd->id; diff --git a/src/libmongoc/tests/test-mongoc-client-session.c b/src/libmongoc/tests/test-mongoc-client-session.c index 85e61dc050b..5d6772ac626 100644 --- a/src/libmongoc/tests/test-mongoc-client-session.c +++ b/src/libmongoc/tests/test-mongoc-client-session.c @@ -195,7 +195,8 @@ _test_session_pool_timeout (bool pooled) /* * trigger discovery */ - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_READ, NULL, NULL, NULL, &error); + server_id = mongoc_topology_select_server_id ( + client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); /* diff --git a/src/libmongoc/tests/test-mongoc-client.c b/src/libmongoc/tests/test-mongoc-client.c index 29270e9257a..36259c51526 100644 --- a/src/libmongoc/tests/test-mongoc-client.c +++ b/src/libmongoc/tests/test-mongoc-client.c @@ -1873,7 +1873,8 @@ test_recovering (void *ctx) /* recovering member matches no read mode */ for (read_mode = MONGOC_READ_PRIMARY; read_mode <= MONGOC_READ_NEAREST; read_mode++) { mongoc_read_prefs_set_mode (prefs, read_mode); - BSON_ASSERT (!mongoc_topology_select (client->topology, MONGOC_SS_READ, prefs, NULL, &error)); + BSON_ASSERT ( + !mongoc_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, prefs, NULL, &error)); } mongoc_read_prefs_destroy (prefs); diff --git a/src/libmongoc/tests/test-mongoc-cluster.c b/src/libmongoc/tests/test-mongoc-cluster.c index c3a929dcf2d..789c1c02214 100644 --- a/src/libmongoc/tests/test-mongoc-cluster.c +++ b/src/libmongoc/tests/test-mongoc-cluster.c @@ -28,7 +28,7 @@ server_id_for_reads (mongoc_cluster_t *cluster) mongoc_server_stream_t *server_stream; uint32_t id; - server_stream = mongoc_cluster_stream_for_reads (cluster, NULL, NULL, NULL, NULL, &error); + server_stream = mongoc_cluster_stream_for_reads (cluster, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); id = server_stream->sd->id; @@ -1073,7 +1073,8 @@ future_command_private (mongoc_client_t *client) ASSERT (client); - server_stream = mongoc_cluster_stream_for_writes (&client->cluster, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "cmd"}; + server_stream = mongoc_cluster_stream_for_writes (&client->cluster, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); mongoc_cmd_parts_init (&parts, client, "test", MONGOC_QUERY_NONE, tmp_bson ("{'cmd': 1}")); @@ -1665,8 +1666,12 @@ test_cluster_stream_invalidation_single (void) /* Test "clearing the pool". This should invalidate existing server streams. */ - stream = mongoc_cluster_stream_for_writes ( - &client->cluster, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); + stream = mongoc_cluster_stream_for_writes (&client->cluster, + TEST_SS_LOG_CONTEXT, + NULL /* session */, + NULL /* deprioritized servers */, + NULL /* reply */, + &error); ASSERT_OR_PRINT (stream, error); BSON_ASSERT (mongoc_cluster_stream_valid (&client->cluster, stream)); tdmod = mc_tpld_modify_begin (client->topology); @@ -1677,8 +1682,12 @@ test_cluster_stream_invalidation_single (void) /* Test closing the connection. This should invalidate existing server * streams. */ - stream = mongoc_cluster_stream_for_writes ( - &client->cluster, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); + stream = mongoc_cluster_stream_for_writes (&client->cluster, + TEST_SS_LOG_CONTEXT, + NULL /* session */, + NULL /* deprioritized servers */, + NULL /* reply */, + &error); ASSERT_OR_PRINT (stream, error); BSON_ASSERT (mongoc_cluster_stream_valid (&client->cluster, stream)); mongoc_cluster_disconnect_node (&client->cluster, sd->id); @@ -1686,8 +1695,12 @@ test_cluster_stream_invalidation_single (void) mongoc_server_stream_cleanup (stream); /* Test that a new stream is considered valid. */ - stream = mongoc_cluster_stream_for_writes ( - &client->cluster, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); + stream = mongoc_cluster_stream_for_writes (&client->cluster, + TEST_SS_LOG_CONTEXT, + NULL /* session */, + NULL /* deprioritized servers */, + NULL /* reply */, + &error); ASSERT_OR_PRINT (stream, error); BSON_ASSERT (mongoc_cluster_stream_valid (&client->cluster, stream)); mongoc_server_stream_cleanup (stream); @@ -1715,8 +1728,12 @@ test_cluster_stream_invalidation_pooled (void) /* Test "clearing the pool". This should invalidate existing server streams. */ - stream = mongoc_cluster_stream_for_writes ( - &client->cluster, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); + stream = mongoc_cluster_stream_for_writes (&client->cluster, + TEST_SS_LOG_CONTEXT, + NULL /* session */, + NULL /* deprioritized servers */, + NULL /* reply */, + &error); ASSERT_OR_PRINT (stream, error); BSON_ASSERT (mongoc_cluster_stream_valid (&client->cluster, stream)); tdmod = mc_tpld_modify_begin (client->topology); @@ -1727,8 +1744,12 @@ test_cluster_stream_invalidation_pooled (void) /* Test closing the connection. This should invalidate existing server * streams. */ - stream = mongoc_cluster_stream_for_writes ( - &client->cluster, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); + stream = mongoc_cluster_stream_for_writes (&client->cluster, + TEST_SS_LOG_CONTEXT, + NULL /* session */, + NULL /* deprioritized servers */, + NULL /* reply */, + &error); ASSERT_OR_PRINT (stream, error); BSON_ASSERT (mongoc_cluster_stream_valid (&client->cluster, stream)); mongoc_cluster_disconnect_node (&client->cluster, sd->id); @@ -1736,8 +1757,12 @@ test_cluster_stream_invalidation_pooled (void) mongoc_server_stream_cleanup (stream); /* Test that a new stream is considered valid. */ - stream = mongoc_cluster_stream_for_writes ( - &client->cluster, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); + stream = mongoc_cluster_stream_for_writes (&client->cluster, + TEST_SS_LOG_CONTEXT, + NULL /* session */, + NULL /* deprioritized servers */, + NULL /* reply */, + &error); ASSERT_OR_PRINT (stream, error); BSON_ASSERT (mongoc_cluster_stream_valid (&client->cluster, stream)); mongoc_server_stream_cleanup (stream); diff --git a/src/libmongoc/tests/test-mongoc-cmd.c b/src/libmongoc/tests/test-mongoc-cmd.c index ad813351b47..6796b2e7fd5 100644 --- a/src/libmongoc/tests/test-mongoc-cmd.c +++ b/src/libmongoc/tests/test-mongoc-cmd.c @@ -105,8 +105,9 @@ test_cmd_with_two_payload1 (void *ctx) // Create the `mongoc_cmd_t`. mongoc_cmd_parts_t parts; mongoc_cmd_parts_init (&parts, client, "admin", MONGOC_QUERY_NONE, payload0); + const mongoc_ss_log_context_t ss_log_context = {.operation = "bulkWrite"}; mongoc_server_stream_t *server_stream = mongoc_cluster_stream_for_writes ( - cluster, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); + cluster, &ss_log_context, NULL /* session */, NULL /* deprioritized servers */, NULL /* reply */, &error); ASSERT_OR_PRINT (server_stream, error); bool ok = mongoc_cmd_parts_assemble (&parts, server_stream, &error); ASSERT_OR_PRINT (ok, error); diff --git a/src/libmongoc/tests/test-mongoc-cursor.c b/src/libmongoc/tests/test-mongoc-cursor.c index 1f48464adcf..56b07e023ab 100644 --- a/src/libmongoc/tests/test-mongoc-cursor.c +++ b/src/libmongoc/tests/test-mongoc-cursor.c @@ -936,11 +936,13 @@ _test_cursor_new_from_command (const char *cmd_json, const char *collection_name r = (0 != mongoc_bulk_operation_execute (bulk, NULL, &error)); ASSERT_OR_PRINT (r, error); - sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, NULL, NULL, &error); + const bson_t *cmd_bson = tmp_bson (cmd_json); + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_get_command_name (cmd_bson)}; + sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, &ss_log_context, NULL, NULL, &error); ASSERT_OR_PRINT (sd, error); server_id = sd->id; - mongoc_client_command_simple_with_server_id (client, "test", tmp_bson (cmd_json), NULL, server_id, &reply, &error); + mongoc_client_command_simple_with_server_id (client, "test", cmd_bson, NULL, server_id, &reply, &error); cmd_cursor = mongoc_cursor_new_from_command_reply_with_opts (client, &reply, tmp_bson ("{'serverId': %d}", server_id)); ASSERT_OR_PRINT (!mongoc_cursor_error (cmd_cursor, &error), error); @@ -1380,7 +1382,7 @@ server_id_for_read_mode (mongoc_client_t *client, mongoc_read_mode_t read_mode) uint32_t server_id; prefs = mongoc_read_prefs_new (read_mode); - sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, prefs, NULL, &error); + sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, prefs, NULL, &error); ASSERT_OR_PRINT (sd, error); server_id = sd->id; diff --git a/src/libmongoc/tests/test-mongoc-cyrus.c b/src/libmongoc/tests/test-mongoc-cyrus.c index e5388f6054b..bd8016b0b5c 100644 --- a/src/libmongoc/tests/test-mongoc-cyrus.c +++ b/src/libmongoc/tests/test-mongoc-cyrus.c @@ -20,6 +20,7 @@ #include "TestSuite.h" #include "test-libmongoc.h" +#include "test-conveniences.h" static void @@ -73,7 +74,7 @@ test_sasl_canonicalize_hostname (void *ctx) BSON_UNUSED (ctx); client = test_framework_new_default_client (); - ss = mongoc_cluster_stream_for_reads (&client->cluster, NULL, NULL, NULL, NULL, &error); + ss = mongoc_cluster_stream_for_reads (&client->cluster, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (ss, error); BSON_ASSERT (_mongoc_sasl_get_canonicalized_name (ss->stream, real_name, sizeof real_name)); diff --git a/src/libmongoc/tests/test-mongoc-max-staleness.c b/src/libmongoc/tests/test-mongoc-max-staleness.c index 10f67b120f3..f446c8c34d4 100644 --- a/src/libmongoc/tests/test-mongoc-max-staleness.c +++ b/src/libmongoc/tests/test-mongoc-max-staleness.c @@ -6,6 +6,7 @@ #include "TestSuite.h" #include "json-test.h" #include "test-libmongoc.h" +#include "test-conveniences.h" #include "mock_server/mock-server.h" #include "mock_server/future-functions.h" @@ -225,7 +226,7 @@ _test_last_write_date (bool pooled) ASSERT_OR_PRINT (r, error); _mongoc_usleep (1000 * 1000); - s0 = mongoc_topology_select (client->topology, MONGOC_SS_WRITE, NULL, NULL, &error); + s0 = mongoc_topology_select (client->topology, MONGOC_SS_WRITE, TEST_SS_LOG_CONTEXT, NULL, NULL, &error); ASSERT_OR_PRINT (s0, error); _mongoc_usleep (1000 * 1000); @@ -233,7 +234,7 @@ _test_last_write_date (bool pooled) ASSERT_OR_PRINT (r, error); _mongoc_usleep (1000 * 1000); - s1 = mongoc_topology_select (client->topology, MONGOC_SS_WRITE, NULL, NULL, &error); + s1 = mongoc_topology_select (client->topology, MONGOC_SS_WRITE, TEST_SS_LOG_CONTEXT, NULL, NULL, &error); ASSERT_OR_PRINT (s1, error); ASSERT_CMPINT64 (s1->last_write_date_ms, !=, (int64_t) -1); @@ -290,7 +291,7 @@ _test_last_write_date_absent (bool pooled) client = test_framework_new_default_client (); } - sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, NULL, NULL, &error); + sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, NULL, NULL, &error); ASSERT_OR_PRINT (sd, error); /* lastWriteDate absent */ diff --git a/src/libmongoc/tests/test-mongoc-primary-stepdown.c b/src/libmongoc/tests/test-mongoc-primary-stepdown.c index d9b663e8cd9..20ef8d5950d 100644 --- a/src/libmongoc/tests/test-mongoc-primary-stepdown.c +++ b/src/libmongoc/tests/test-mongoc-primary-stepdown.c @@ -154,6 +154,7 @@ test_getmore_iteration (mongoc_client_t *client) * connection counts. */ primary_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, + TEST_SS_LOG_CONTEXT, NULL /* read prefs */, NULL /* chosen read mode */, NULL /* deprioritized servers */, @@ -241,6 +242,7 @@ test_not_primary_keep_pool (mongoc_client_t *client) * connection counts. */ primary_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, + TEST_SS_LOG_CONTEXT, NULL /* read prefs */, NULL /* chosen read mode */, NULL /* deprioritized servers */, @@ -312,6 +314,7 @@ test_not_primary_reset_pool (mongoc_client_t *client) * connection counts. */ primary_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, + TEST_SS_LOG_CONTEXT, NULL /* read prefs */, NULL /* chosen read mode */, NULL /* deprioritized servers */, @@ -387,6 +390,7 @@ test_shutdown_reset_pool (mongoc_client_t *client) * connection counts. */ primary_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, + TEST_SS_LOG_CONTEXT, NULL /* read prefs */, NULL /* chosen read mode */, NULL /* deprioritized servers */, @@ -456,6 +460,7 @@ test_interrupted_shutdown_reset_pool (mongoc_client_t *client) * connection counts. */ primary_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, + TEST_SS_LOG_CONTEXT, NULL /* read prefs */, NULL /* chosen read mode */, NULL /* deprioritized servers */, diff --git a/src/libmongoc/tests/test-mongoc-retryable-reads.c b/src/libmongoc/tests/test-mongoc-retryable-reads.c index 5c15b96b6c2..c112f744da6 100644 --- a/src/libmongoc/tests/test-mongoc-retryable-reads.c +++ b/src/libmongoc/tests/test-mongoc-retryable-reads.c @@ -94,7 +94,9 @@ test_cmd_helpers (void *ctx) mongoc_uri_destroy (uri); /* clean up in case a previous test aborted */ - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "configureFailPoint"}; + server_id = + mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); deactivate_fail_points (client, server_id); @@ -163,7 +165,8 @@ test_cmd_helpers (void *ctx) /* read/write agnostic command_simple_with_server_id helper must not retry. */ - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + server_id = + mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); _set_failpoint (client); ASSERT (!mongoc_client_command_simple_with_server_id (client, "test", cmd, NULL, server_id, NULL, &error)); @@ -220,7 +223,9 @@ test_retry_reads_off (void *ctx) test_framework_set_ssl_opts (client); /* clean up in case a previous test aborted */ - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "configureFailPoint"}; + server_id = + mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); deactivate_fail_points (client, server_id); diff --git a/src/libmongoc/tests/test-mongoc-retryable-writes.c b/src/libmongoc/tests/test-mongoc-retryable-writes.c index b345ca8fedd..a8b04b57b17 100644 --- a/src/libmongoc/tests/test-mongoc-retryable-writes.c +++ b/src/libmongoc/tests/test-mongoc-retryable-writes.c @@ -143,7 +143,8 @@ test_command_with_opts (void *ctx) mongoc_uri_destroy (uri); /* clean up in case a previous test aborted */ - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + server_id = mongoc_topology_select_server_id ( + client->topology, MONGOC_SS_WRITE, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); deactivate_fail_points (client, server_id); @@ -582,7 +583,9 @@ set_up_original_error_test (mongoc_apm_callbacks_t *callbacks, ASSERT (client); // clean up in case a previous test aborted - server_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "configureFailPoint"}; + server_id = + mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_id, error); deactivate_fail_points (client, server_id); diff --git a/src/libmongoc/tests/test-mongoc-topology-reconcile.c b/src/libmongoc/tests/test-mongoc-topology-reconcile.c index 02276f47546..f1421310e85 100644 --- a/src/libmongoc/tests/test-mongoc-topology-reconcile.c +++ b/src/libmongoc/tests/test-mongoc-topology-reconcile.c @@ -69,7 +69,7 @@ selects_server (mongoc_client_t *client, mongoc_read_prefs_t *read_prefs, mock_s ASSERT (client); - sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, read_prefs, NULL, &error); + sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, read_prefs, NULL, &error); if (!sd) { fprintf (stderr, "%s\n", error.message); @@ -234,7 +234,8 @@ _test_topology_reconcile_sharded (bool pooled) } primary_read_prefs = mongoc_read_prefs_new (MONGOC_READ_PRIMARY); - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_read_prefs, NULL, &error); + future = + future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_read_prefs, NULL, &error); /* mongos */ request = mock_server_receives_any_hello (mongos); diff --git a/src/libmongoc/tests/test-mongoc-topology-scanner.c b/src/libmongoc/tests/test-mongoc-topology-scanner.c index 5a296375796..4830b7c4d31 100644 --- a/src/libmongoc/tests/test-mongoc-topology-scanner.c +++ b/src/libmongoc/tests/test-mongoc-topology-scanner.c @@ -173,7 +173,8 @@ test_topology_scanner_discovery (void) client = test_framework_client_new (uri_str, NULL); secondary_pref = mongoc_read_prefs_new (MONGOC_READ_SECONDARY_PREFERRED); - future = future_topology_select (client->topology, MONGOC_SS_READ, secondary_pref, NULL, &error); + future = + future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, secondary_pref, NULL, &error); /* a single scan discovers *and* checks the secondary */ request = mock_server_receives_any_hello (primary); @@ -247,7 +248,7 @@ test_topology_scanner_oscillate (void) primary_pref = mongoc_read_prefs_new (MONGOC_READ_PRIMARY); BSON_ASSERT (!scanner->async->ncmds); - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); /* a single scan discovers servers 0 and 1 */ request = mock_server_receives_any_hello (server0); diff --git a/src/libmongoc/tests/test-mongoc-topology.c b/src/libmongoc/tests/test-mongoc-topology.c index 0e38db11e1e..39070105bc0 100644 --- a/src/libmongoc/tests/test-mongoc-topology.c +++ b/src/libmongoc/tests/test-mongoc-topology.c @@ -181,7 +181,8 @@ test_topology_client_creation (void) BSON_ASSERT (topology_a->scanner_state == MONGOC_TOPOLOGY_SCANNER_OFF); /* ensure that we are sharing streams with the client */ - server_stream = mongoc_cluster_stream_for_reads (&client_a->cluster, NULL, NULL, NULL, NULL, &error); + server_stream = + mongoc_cluster_stream_for_reads (&client_a->cluster, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); node = mongoc_topology_scanner_get_node (client_a->topology->scanner, server_stream->sd->id); @@ -361,7 +362,7 @@ _test_server_selection (bool try_once) primary_pref = mongoc_read_prefs_new (MONGOC_READ_PRIMARY); /* no primary, selection fails after one try */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); request = mock_server_receives_any_hello (server); BSON_ASSERT (request); reply_to_request_simple (request, secondary_response); @@ -391,7 +392,7 @@ _test_server_selection (bool try_once) _mongoc_usleep (510 * 1000); /* one heartbeat, plus a few milliseconds */ /* second selection, now we try hello again */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); request = mock_server_receives_any_hello (server); BSON_ASSERT (request); @@ -480,7 +481,8 @@ _test_topology_invalidate_server (bool pooled) } /* call explicitly */ - server_stream = mongoc_cluster_stream_for_reads (&client->cluster, NULL, NULL, NULL, NULL, &error); + server_stream = + mongoc_cluster_stream_for_reads (&client->cluster, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); sd = server_stream->sd; id = server_stream->sd->id; @@ -582,7 +584,8 @@ test_invalid_cluster_node (void *ctx) cluster = &client->cluster; /* load stream into cluster */ - server_stream = mongoc_cluster_stream_for_reads (&client->cluster, NULL, NULL, NULL, NULL, &error); + server_stream = + mongoc_cluster_stream_for_reads (&client->cluster, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); id = server_stream->sd->id; mongoc_server_stream_cleanup (server_stream); @@ -647,7 +650,8 @@ test_max_wire_version_race_condition (void *ctx) client = mongoc_client_pool_pop (pool); /* load stream into cluster */ - server_stream = mongoc_cluster_stream_for_reads (&client->cluster, NULL, NULL, NULL, NULL, &error); + server_stream = + mongoc_cluster_stream_for_reads (&client->cluster, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); id = server_stream->sd->id; mongoc_server_stream_cleanup (server_stream); @@ -689,7 +693,7 @@ test_cooldown_standalone (void) primary_pref = mongoc_read_prefs_new (MONGOC_READ_PRIMARY); /* first hello fails, selection fails */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); request = mock_server_receives_any_hello (server); BSON_ASSERT (request); reply_to_request_with_hang_up (request); @@ -699,7 +703,7 @@ test_cooldown_standalone (void) /* second selection doesn't try to call hello: we're in cooldown */ start = bson_get_monotonic_time (); - sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + sd = mongoc_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); BSON_ASSERT (!sd); /* waited less than 500ms (minHeartbeatFrequencyMS), in fact * didn't wait at all since all nodes are in cooldown */ @@ -712,7 +716,7 @@ test_cooldown_standalone (void) _mongoc_usleep (1000 * 1000); /* 1 second */ /* third selection doesn't try to call hello: we're still in cooldown */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); mock_server_set_request_timeout_msec (server, 100); BSON_ASSERT (!mock_server_receives_any_hello (server)); /* no hello call */ BSON_ASSERT (!future_get_mongoc_server_description_ptr (future)); @@ -725,7 +729,7 @@ test_cooldown_standalone (void) _mongoc_usleep (5100 * 1000); /* 5.1 seconds */ /* cooldown ends, now we try hello again, this time succeeding */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); request = mock_server_receives_any_hello (server); /* not in cooldown now */ BSON_ASSERT (request); reply_to_request_simple (request, @@ -809,7 +813,7 @@ test_cooldown_rs (void) mock_server_get_port (servers[1])); /* server 0 is a secondary. */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); request = mock_server_receives_any_hello (servers[0]); BSON_ASSERT (request); @@ -829,7 +833,7 @@ test_cooldown_rs (void) _mongoc_usleep (1000 * 1000); /* 1 second */ /* second selection doesn't try hello on server 1: it's in cooldown */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); request = mock_server_receives_any_hello (servers[0]); BSON_ASSERT (request); @@ -847,7 +851,7 @@ test_cooldown_rs (void) _mongoc_usleep (5100 * 1000); /* 5.1 seconds. longer than 5 sec cooldown. */ /* cooldown ends, now we try hello on server 1, this time succeeding */ - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); request = mock_server_receives_any_hello (servers[1]); BSON_ASSERT (request); @@ -891,7 +895,7 @@ test_cooldown_retry (void) client = test_framework_client_new_from_uri (uri, NULL); primary_pref = mongoc_read_prefs_new (MONGOC_READ_PRIMARY); - future = future_topology_select (client->topology, MONGOC_SS_READ, primary_pref, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, primary_pref, NULL, &error); /* first hello fails */ request = mock_server_receives_any_hello (server); @@ -986,7 +990,7 @@ _test_select_succeed (bool try_once) /* start waiting for a primary (NULL read pref) */ start = bson_get_monotonic_time (); - future = future_topology_select (client->topology, MONGOC_SS_READ, NULL, NULL, &error); + future = future_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, NULL, NULL, &error); /* selection succeeds */ sd = future_get_mongoc_server_description_ptr (future); @@ -2003,7 +2007,8 @@ test_last_server_removed_warning (void) mock_server_get_port (server)); capture_logs (true); - description = mongoc_topology_select (client->topology, MONGOC_SS_READ, read_prefs, NULL, &error); + description = + mongoc_topology_select (client->topology, MONGOC_SS_READ, TEST_SS_LOG_CONTEXT, read_prefs, NULL, &error); ASSERT_CAPTURED_LOG ("topology", MONGOC_LOG_LEVEL_WARNING, "Last server removed from topology"); capture_logs (false); diff --git a/src/libmongoc/tests/test-mongoc-transactions.c b/src/libmongoc/tests/test-mongoc-transactions.c index 96b91c8349a..4c11f6d79a2 100644 --- a/src/libmongoc/tests/test-mongoc-transactions.c +++ b/src/libmongoc/tests/test-mongoc-transactions.c @@ -857,7 +857,8 @@ test_selected_server_is_pinned_to_mongos (void *ctx) ASSERT_OR_PRINT (r, error); BSON_ASSERT (0 == mongoc_client_session_get_server_id (session)); - expected_id = mongoc_topology_select_server_id (client->topology, MONGOC_SS_WRITE, NULL, NULL, NULL, &error); + expected_id = mongoc_topology_select_server_id ( + client->topology, MONGOC_SS_WRITE, TEST_SS_LOG_CONTEXT, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (expected_id, error); /* session should still be unpinned */ diff --git a/src/libmongoc/tests/test-mongoc-write-commands.c b/src/libmongoc/tests/test-mongoc-write-commands.c index 29e9143222e..8be99a07bef 100644 --- a/src/libmongoc/tests/test-mongoc-write-commands.c +++ b/src/libmongoc/tests/test-mongoc-write-commands.c @@ -53,7 +53,10 @@ test_split_insert (void) _mongoc_write_command_insert_append (&command, docs[i]); } - server_stream = mongoc_cluster_stream_for_writes (&client->cluster, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_write_command_get_name (&command), + .has_operation_id = true, + .operation_id = command.operation_id}; + server_stream = mongoc_cluster_stream_for_writes (&client->cluster, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); _mongoc_write_command_execute ( &command, client, server_stream, collection->db, collection->collection, NULL, 0, NULL, &result); @@ -110,7 +113,10 @@ test_invalid_write_concern (void) _mongoc_write_command_init_insert (&command, doc, NULL, write_flags, ++client->cluster.operation_id); _mongoc_write_result_init (&result); - server_stream = mongoc_cluster_stream_for_writes (&client->cluster, NULL, NULL, NULL, &error); + const mongoc_ss_log_context_t ss_log_context = {.operation = _mongoc_write_command_get_name (&command), + .has_operation_id = true, + .operation_id = command.operation_id}; + server_stream = mongoc_cluster_stream_for_writes (&client->cluster, &ss_log_context, NULL, NULL, NULL, &error); ASSERT_OR_PRINT (server_stream, error); _mongoc_write_command_execute ( &command, client, server_stream, collection->db, collection->collection, write_concern, 0, NULL, &result); diff --git a/src/libmongoc/tests/unified/entity-map.c b/src/libmongoc/tests/unified/entity-map.c index 286c8136fe3..9b7d68a84bb 100644 --- a/src/libmongoc/tests/unified/entity-map.c +++ b/src/libmongoc/tests/unified/entity-map.c @@ -114,7 +114,7 @@ uri_apply_options (mongoc_uri_t *uri, bson_t *opts, bson_error_t *error) mongoc_uri_set_option_as_int64 (uri, key, bson_iter_int64 (&iter)); } else if (mongoc_uri_option_is_bool (key)) { mongoc_uri_set_option_as_bool (uri, key, bson_iter_bool (&iter)); - } else if (0 == strcmp ("appname", key)) { + } else if (0 == bson_strcasecmp ("appname", key)) { mongoc_uri_set_appname (uri, bson_iter_utf8 (&iter, NULL)); } else { test_set_error (error, "Unimplemented test runner support for URI option: %s", key); @@ -387,19 +387,50 @@ server_changed (const mongoc_apm_server_changed_t *changed) mongoc_apm_server_changed_get_topology_id (changed, &topology_id); bson_t *serialized = bson_new (); + const mongoc_server_description_t *previous_sd = mongoc_apm_server_changed_get_previous_description (changed); + const mongoc_server_description_t *new_sd = mongoc_apm_server_changed_get_new_description (changed); + + // Limited to fields defined in the unified test schema + mongoc_server_description_content_flags_t sd_flags = MONGOC_SERVER_DESCRIPTION_CONTENT_FLAG_TYPE; bsonBuildAppend ( *serialized, - kv ("address", cstr (mongoc_apm_server_changed_get_host (changed)->host_and_port)), - kv ("topologyId", oid (&topology_id)), - kv ("previousDescription", - bson ( - *mongoc_server_description_hello_response (mongoc_apm_server_changed_get_previous_description (changed)))), + kv ("previousDescription", doc (do ({ + mongoc_server_description_append_contents_to_bson (previous_sd, bsonBuildContext.doc, sd_flags); + }))), kv ("newDescription", - bson (*mongoc_server_description_hello_response (mongoc_apm_server_changed_get_new_description (changed))))); + doc (do ({ mongoc_server_description_append_contents_to_bson (new_sd, bsonBuildContext.doc, sd_flags); })))); event_store_or_destroy (entity, event_new ("serverDescriptionChangedEvent", serialized, false)); } +static void +topology_changed (const mongoc_apm_topology_changed_t *changed) +{ + entity_t *entity = (entity_t *) mongoc_apm_topology_changed_get_context (changed); + bson_oid_t topology_id; + mongoc_apm_topology_changed_get_topology_id (changed, &topology_id); + + bson_t *serialized = bson_new (); + const mongoc_topology_description_t *previous_td = mongoc_apm_topology_changed_get_previous_description (changed); + const mongoc_topology_description_t *new_td = mongoc_apm_topology_changed_get_new_description (changed); + + // Limited to fields defined in the unified test schema + mongoc_topology_description_content_flags_t td_flags = MONGOC_TOPOLOGY_DESCRIPTION_CONTENT_FLAG_TYPE; + mongoc_server_description_content_flags_t sd_flags = 0; + bsonBuildAppend (*serialized, + kv ("previousDescription", doc (do ({ + mongoc_topology_description_append_contents_to_bson ( + previous_td, bsonBuildContext.doc, td_flags, sd_flags); + }))), + kv ("newDescription", doc (do ({ + mongoc_topology_description_append_contents_to_bson ( + new_td, bsonBuildContext.doc, td_flags, sd_flags); + })))); + + event_store_or_destroy (entity, event_new ("topologyDescriptionChangedEvent", serialized, false)); +} + + static void set_command_started_cb (mongoc_apm_callbacks_t *callbacks) { @@ -424,6 +455,12 @@ set_server_changed_cb (mongoc_apm_callbacks_t *callbacks) mongoc_apm_set_server_changed_cb (callbacks, server_changed); } +static void +set_topology_changed_cb (mongoc_apm_callbacks_t *callbacks) +{ + mongoc_apm_set_topology_changed_cb (callbacks, topology_changed); +} + /* Set a callback for the indicated event type in a mongoc_apm_callbacks_t. * Safe to call multiple times for the same event: callbacks for a specific * event type are always the same. Returns 'true' if the event is known and @@ -444,6 +481,7 @@ set_event_callback (mongoc_apm_callbacks_t *callbacks, const char *type) {.type = "commandFailedEvent", .set = set_command_failed_cb}, {.type = "commandSucceededEvent", .set = set_command_succeeded_cb}, {.type = "serverDescriptionChangedEvent", .set = set_server_changed_cb}, + {.type = "topologyDescriptionChangedEvent", .set = set_topology_changed_cb}, {.type = NULL, .set = NULL}, }; diff --git a/src/libmongoc/tests/unified/operation.c b/src/libmongoc/tests/unified/operation.c index 039b49eab61..677246d9a82 100644 --- a/src/libmongoc/tests/unified/operation.c +++ b/src/libmongoc/tests/unified/operation.c @@ -3916,7 +3916,11 @@ operation_wait_for_event (test_t *test, operation_t *op, result_t *result, bson_ { mongoc_client_t *mc_client = entity_map_get_client (test->entity_map, client_id, error); if (mc_client) { - mongoc_topology_select_server_id (mc_client->topology, MONGOC_SS_READ, NULL, NULL, NULL, error); + const mongoc_ss_log_context_t ss_log_context = {.operation = "waitForEvent"}; + test_begin_suppressing_structured_logs (); + mongoc_topology_select_server_id ( + mc_client->topology, MONGOC_SS_READ, &ss_log_context, NULL, NULL, NULL, error); + test_end_suppressing_structured_logs (); } } } diff --git a/src/libmongoc/tests/unified/runner.c b/src/libmongoc/tests/unified/runner.c index d484c352275..70a9b91f5c5 100644 --- a/src/libmongoc/tests/unified/runner.c +++ b/src/libmongoc/tests/unified/runner.c @@ -985,6 +985,11 @@ test_run_operations (test_t *test, bson_error_t *error) static bool test_check_event (test_t *test, bson_t *expected, event_t *actual, bson_error_t *error) { + /* Note: With events serialized into the same format as the 'expected' documents, + * this test is effectively the same as a single top-level entity_map_match but with + * somewhat more verbose error messages. If this becomes too much of a maintenance + * burden, consider replacing it with a single match. */ + bool ret = false; bson_iter_t iter; bson_t expected_bson; @@ -996,6 +1001,8 @@ test_check_event (test_t *test, bson_t *expected, event_t *actual, bson_error_t bson_t *expected_reply = NULL; bool *expected_has_service_id = NULL; bool *expected_has_server_connection_id = NULL; + bson_t *expected_previous_description = NULL; + bson_t *expected_new_description = NULL; BSON_ASSERT_PARAM (test); BSON_ASSERT_PARAM (expected); @@ -1028,6 +1035,8 @@ test_check_event (test_t *test, bson_t *expected, event_t *actual, bson_error_t bson_parser_doc_optional (bp, "reply", &expected_reply); bson_parser_bool_optional (bp, "hasServiceId", &expected_has_service_id); bson_parser_bool_optional (bp, "hasServerConnectionId", &expected_has_server_connection_id); + bson_parser_doc_optional (bp, "previousDescription", &expected_previous_description); + bson_parser_doc_optional (bp, "newDescription", &expected_new_description); if (!bson_parser_parse (bp, &expected_bson, error)) { goto done; } @@ -1145,6 +1154,44 @@ test_check_event (test_t *test, bson_t *expected, event_t *actual, bson_error_t } } + if (expected_previous_description) { + if (!bson_iter_init_find (&iter, actual->serialized, "previousDescription")) { + test_set_error (error, "event.previousDescription expected but missing"); + goto done; + } + if (!BSON_ITER_HOLDS_DOCUMENT (&iter)) { + test_set_error (error, "Unexpected type for event.previousDescription, should be document"); + goto done; + } + bson_val_t *expected_val = bson_val_from_bson (expected_previous_description); + bson_val_t *actual_val = bson_val_from_iter (&iter); + bool is_match = entity_map_match (test->entity_map, expected_val, actual_val, false, error); + bson_val_destroy (expected_val); + bson_val_destroy (actual_val); + if (!is_match) { + goto done; + } + } + + if (expected_new_description) { + if (!bson_iter_init_find (&iter, actual->serialized, "newDescription")) { + test_set_error (error, "event.newDescription expected but missing"); + goto done; + } + if (!BSON_ITER_HOLDS_DOCUMENT (&iter)) { + test_set_error (error, "Unexpected type for event.newDescription, should be document"); + goto done; + } + bson_val_t *expected_val = bson_val_from_bson (expected_new_description); + bson_val_t *actual_val = bson_val_from_iter (&iter); + bool is_match = entity_map_match (test->entity_map, expected_val, actual_val, false, error); + bson_val_destroy (expected_val); + bson_val_destroy (actual_val); + if (!is_match) { + goto done; + } + } + ret = true; done: bson_parser_destroy_with_parsed_fields (bp); @@ -2081,4 +2128,6 @@ test_install_unified (TestSuite *suite) run_unified_tests (suite, JSON_DIR, "index-management"); run_unified_tests (suite, JSON_DIR, "command-logging-and-monitoring"); + + run_unified_tests (suite, JSON_DIR, "server_selection/logging"); }