[SERVER-46591] Find and update logs where we log a string Created: 03/Mar/20  Updated: 04/Oct/23

Status: Open
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 4.3 Desired

Type: Task Priority: Major - P3
Reporter: Elizabeth Roytburd Assignee: Backlog - Service Architecture
Resolution: Unresolved Votes: 0
Labels: sa-groomed
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Assigned Teams:
Service Arch
Sprint: Service Arch 2020-04-06, Service arch 2020-04-20, Service arch 2020-05-04, Service arch 2020-05-18, Service arch 2020-06-01
Participants:

 Description   

There are a handful of places where log message gets built, and then separately logged. Most commonly it's because the message is used for both logging and for creation of a Status. For example:

        std::stringstream ss;
        ss << "can't resize since we're using (" << used << ") "
           << "more than newSize(" << newSize << ")";
 
        std::string errmsg = ss.str();
        LOGV2(23120, "{errmsg}", "errmsg"_attr = errmsg);
        return Status(ErrorCodes::BadValue, errmsg);

We need to find these and fix the log statements such that the attributes get explicitly passed.



 Comments   
Comment by Billy Donahue [ 04/Oct/23 ]

If these strings are still around, I would say this ticket isn't really part of PM-2165 anymore.
They don't really have to do with removal of fmt-message strings, but more to do with legacy strings that need to be rephrased and broken down into structured fields.
That is, it's structured logging in general, rather than fmt-message related.

Comment by Matthew Tretin (Inactive) [ 20/Oct/20 ]

Since this is related to logging we think this is in the realm of security. 

Comment by Gabriel Russell (Inactive) [ 25/Mar/20 ]

I was able to run a fancy grep and find all of the places where we log a single attribute. I think there are two many to do in a single pass, so instead I'm recording the list here. 

src/mongo/util/stacktrace_threads.cpp: LOGV2_FATAL(
            31376,
            "{format_FMT_STRING_Failed_to_install_sigaction_for_signal_signal_strerror_savedErr}",
            "format_FMT_STRING_Failed_to_install_sigaction_for_signal_signal_strerror_savedErr"_attr =
                format(FMT_STRING("Failed to install sigaction for signal {} ({})"),
                       signal,
                       strerror(savedErr)));
src/mongo/platform/source_location_test.cpp: LOGV2(22616, "{inlineLocation1}", "inlineLocation1"_attr = inlineLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(22617, "{inlineLocation2}", "inlineLocation2"_attr = inlineLocation2);
src/mongo/platform/source_location_test.cpp: LOGV2(22618, "{inlineLocation3}", "inlineLocation3"_attr = inlineLocation3);
src/mongo/platform/source_location_test.cpp: LOGV2(22619, "{inlineLocation1}", "inlineLocation1"_attr = inlineLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(
        22620, "{localFunctionLocation1}", "localFunctionLocation1"_attr = localFunctionLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(
        22621, "{localFunctionLocation2}", "localFunctionLocation2"_attr = localFunctionLocation2);
src/mongo/platform/source_location_test.cpp: LOGV2(22622, "{inlineLocation1}", "inlineLocation1"_attr = inlineLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(22623, "{headerLocation1}", "headerLocation1"_attr = headerLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(22624, "{headerLocation2}", "headerLocation2"_attr = headerLocation2);
src/mongo/platform/source_location_test.cpp: LOGV2(22625, "{inlineLocation1}", "inlineLocation1"_attr = inlineLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(22626, "{kLocation}", "kLocation"_attr = kLocation);
src/mongo/platform/source_location_test.cpp: LOGV2(22627, "{inlineLocation1}", "inlineLocation1"_attr = inlineLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(22628, "{obj1_location}", "obj1_location"_attr = obj1.location);
src/mongo/platform/source_location_test.cpp: LOGV2(22629, "{obj2_location}", "obj2_location"_attr = obj2.location);
src/mongo/platform/source_location_test.cpp: LOGV2(22630, "{inlineLocation1}", "inlineLocation1"_attr = inlineLocation1);
src/mongo/platform/source_location_test.cpp: LOGV2(22631, "{inlineLocation2}", "inlineLocation2"_attr = inlineLocation2);
src/mongo/platform/random_test.cpp: LOGV2(22611,
                  "{format_FMT_STRING_4_count_4_dev_6f_i_hist_i_dev_std_string_hist_i_256}",
                  "format_FMT_STRING_4_count_4_dev_6f_i_hist_i_dev_std_string_hist_i_256"_attr =
                      format(FMT_STRING("  [{:4}] count:{:4}, dev:{:6f}, {}"),
                             i,
                             hist[i],
                             dev,
                             std::string(hist[i] / 256, '*')));
src/mongo/base/secure_allocator.cpp: LOGV2_WARNING(23704, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_WARNING(23705, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_WARNING(23706, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(40285, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(40286, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(28835, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(28828, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(28829, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(28830, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(23714, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(23715, "{str}", "str"_attr = str);
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(28833,
                    "{errnoWithPrefix_Failed_to_munlock}",
                    "errnoWithPrefix_Failed_to_munlock"_attr =
                        errnoWithPrefix("Failed to munlock"));
src/mongo/base/secure_allocator.cpp: LOGV2_FATAL(28834,
                    "{errnoWithPrefix_Failed_to_munmap}",
                    "errnoWithPrefix_Failed_to_munmap"_attr = errnoWithPrefix("Failed to munmap"));
src/mongo/shell/shell_utils_launcher.cpp: LOGV2(22810, "{ss_str}", "ss_str"_attr = ss.str());
src/mongo/dbtests/jsontests.cpp: LOGV2(22496, "{expected_hexDump}", "expected_hexDump"_attr = expected.hexDump());
src/mongo/dbtests/jsontests.cpp: LOGV2(22497, "{actual_hexDump}", "actual_hexDump"_attr = actual.hexDump());
src/mongo/dbtests/jsontests.cpp: LOGV2(22498, "{msg}", "msg"_attr = msg);
src/mongo/unittest/unittest.cpp: LOGV2(23055, "{line}", "line"_attr = line);
src/mongo/unittest/unittest.cpp: LOGV2(23065, "{totals}", "totals"_attr = totals.toString());
src/mongo/logv2/log_test_v2.cpp: LOGV2(4684000, "{vectorUInt32s}", "vectorUInt32s"_attr = vectorUInt32s);
src/mongo/logv2/log_test_v2.cpp: LOGV2(4684001, "{mapOfUInt32s}", "mapOfUInt32s"_attr = mapOfUInt32s);
src/mongo/util/heap_profiler.cpp: LOGV2(23157, "{msg}", "msg"_attr = msg);
src/mongo/db/db.cpp: LOGV2(20538, "{status}", "status"_attr = redact(status));
src/mongo/db/db_raii_test.cpp: LOGV2(20578, "{ex}", "ex"_attr = ex);
src/mongo/db/index_builds_coordinator.cpp: LOGV2(20661, "{msg}", "msg"_attr = msg);
src/mongo/db/catalog_raii_test.cpp: LOGV2(20396, "{ex}", "ex"_attr = ex);
src/mongo/db/repair_database_and_check_version.cpp: LOGV2_WARNING(21019,
                              "  {mod_getDescription}",
                              "mod_getDescription"_attr = mod.getDescription());
src/mongo/client/sdam/sdam_json_test_runner.cpp: LOGV2(20204,
                  "{emphasize_Phase_std_to_string_testPhase_getPhaseNum}",
                  "emphasize_Phase_std_to_string_testPhase_getPhaseNum"_attr =
                      emphasize("Phase " + std::to_string(testPhase.getPhaseNum())));
src/mongo/client/sdam/sdam_json_test_runner.cpp: LOGV2(20207,
              "{emphasize_Parsing_testFilePath_string}",
              "emphasize_Parsing_testFilePath_string"_attr =
                  emphasize("Parsing " + testFilePath.string()));
src/mongo/client/sdam/sdam_json_test_runner.cpp: LOGV2(20208,
                      "{emphasize_Executing_testCase_Name}",
                      "emphasize_Executing_testCase_Name"_attr =
                          emphasize("Executing " + testCase.Name()));
src/mongo/client/sdam/sdam_json_test_runner.cpp: LOGV2(20209,
                  "{emphasize_Failed_Test_Results}",
                  "emphasize_Failed_Test_Results"_attr = emphasize("Failed Test Results"));
src/mongo/client/sdam/sdam_json_test_runner.cpp: LOGV2(
                    20210, "{emphasize_testName}", "emphasize_testName"_attr = emphasize(testName));
src/mongo/s/commands/cluster_get_shard_version_cmd.cpp: LOGV2(22753, "{chunk}", "chunk"_attr = redact(chunk.toString()));
src/mongo/util/net/ssl_manager_windows.cpp: LOGV2_WARNING(23275, "{msg}", "msg"_attr = msg.ss.str());
src/mongo/util/net/ssl_manager_windows.cpp: LOGV2_WARNING(23276, "{msg}", "msg"_attr = msg.ss.str());
src/mongo/util/net/ssl_manager_windows.cpp: LOGV2_ERROR(23279, "{msg}", "msg"_attr = msg.ss.str());
src/mongo/util/net/ssl_manager_apple.cpp: LOGV2_WARNING(23211, "{msg}", "msg"_attr = msg);
src/mongo/util/net/ssl_manager_apple.cpp: LOGV2_ERROR(23213, "{msg}", "msg"_attr = msg);
src/mongo/util/net/ssl_manager_openssl.cpp: LOGV2_ERROR(23256,
                        "{error}",
                        "SSL peer certificate validation failed",
                        "error"_attr = msg.ss.str());
src/mongo/util/net/ssl_manager_openssl.cpp: LOGV2_WARNING(23238, "{msg}", "msg"_attr = msg);
src/mongo/util/net/ssl_manager_openssl.cpp: LOGV2_ERROR(23257, "{msg}", "msg"_attr = msg);
src/mongo/util/concurrency/ticketholder.cpp: LOGV2(23120, "{errmsg}", "errmsg"_attr = errmsg);
src/mongo/db/repl/topology_coordinator.cpp: LOGV2(
        21816, "{newMemberState}", "Changed member state", "newMemberState"_attr = newMemberState);
src/mongo/db/repl/bgsync.cpp: LOGV2_WARNING(
            21120, "{error}", "Fetcher returned error", "error"_attr = redact(fetcherReturnStatus));
src/mongo/s/client/version_manager.cpp: LOGV2(22746, "{error}", "setShardVersion failed", "error"_attr = error);
src/mongo/db/repl/topology_coordinator_v1_test.cpp: LOGV2(21843, "{rsStatus}", "rsStatus"_attr = rsStatus);
src/mongo/db/repl/topology_coordinator_v1_test.cpp: LOGV2(21844, "{rsStatus}", "rsStatus"_attr = rsStatus);
src/mongo/db/commands/dbcommands_d.cpp: LOGV2(20454, "{c_nextSafe}", "c_nextSafe"_attr = c->nextSafe());
src/mongo/db/commands/dbcommands.cpp: LOGV2_WARNING(
                23800, "{deprecationWarning}", "deprecationWarning"_attr = deprecationWarning);
src/mongo/db/query/query_planner_test_fixture.cpp: LOGV2(20985, "{std_string_ost}", "std_string_ost"_attr = std::string(ost));
src/mongo/db/repl/idempotency_test.cpp: LOGV2(21157,
          "{IdempotencyTest_getStatesString_state1_state2_ops}",
          "IdempotencyTest_getStatesString_state1_state2_ops"_attr =
              IdempotencyTest::getStatesString(state1, state2, ops));
src/mongo/db/repl/replication_coordinator_impl_test.cpp: LOGV2(21501, "{_0}", "_0"_attr = 0);
src/mongo/db/repl/replication_coordinator_impl_test.cpp: LOGV2(21502, "{_1}", "_1"_attr = 1);
src/mongo/db/repl/replication_coordinator_impl_test.cpp: LOGV2(21503, "{_2}", "_2"_attr = 2);
src/mongo/db/repl/replication_coordinator_impl_test.cpp: LOGV2(21504, "{_3}", "_3"_attr = 3);
src/mongo/db/repl/replication_coordinator_impl_test.cpp: LOGV2(21506, "{metadata}", "metadata"_attr = metadata);
src/mongo/db/repl/check_quorum_for_config_change.cpp: LOGV2_WARNING(23723, "{message}", "message"_attr = message);
src/mongo/db/repl/check_quorum_for_config_change.cpp: LOGV2_WARNING(23725, "{message}", "message"_attr = message);
src/mongo/db/repl/check_quorum_for_config_change.cpp: LOGV2_WARNING(23726, "{message}", "message"_attr = message);
src/mongo/db/storage/remove_saver.cpp: LOGV2_ERROR(23734, "{msg}", "msg"_attr = msg);
src/mongo/db/storage/remove_saver.cpp: LOGV2_ERROR(23735, "{msg}", "msg"_attr = msg);
src/mongo/db/storage/storage_engine_impl.cpp: LOGV2(22263,
                      "{Timestamp_monitor_is_stopping_due_to_ex_reason}",
                      "Timestamp_monitor_is_stopping_due_to_ex_reason"_attr =
                          "Timestamp monitor is stopping due to: " + ex.reason());
src/mongo/db/index/index_build_interceptor.cpp: LOGV2_WARNING(20692, "{message}", "message"_attr = message);
src/mongo/db/storage/storage_debug_util.cpp: LOGV2(51812, "{results_string}", "results_string"_attr = ss.str());
src/mongo/db/s/cleanup_orphaned_cmd.cpp: LOGV2(4416002, "{errMsg}", "errMsg"_attr = *errMsg);
src/mongo/db/s/cleanup_orphaned_cmd.cpp: LOGV2(21912, "{errMsg}", "errMsg"_attr = *errMsg);
src/mongo/db/s/cleanup_orphaned_cmd.cpp: LOGV2(21916, "{result_reason}", "result_reason"_attr = redact(result.reason()));
src/mongo/db/s/split_chunk_test.cpp: LOGV2(22106, "{whyMessage}", "whyMessage"_attr = whyMessage);
src/mongo/db/s/range_deletion_util.cpp: LOGV2(23765, "{msg}", "msg"_attr = msg);
src/mongo/db/s/range_deletion_util.cpp: LOGV2(23767, "{msg}", "msg"_attr = msg);
src/mongo/db/storage/storage_repair_observer_test.cpp: LOGV2(22292,
                      "  {mod_getDescription}",
                      "mod_getDescription"_attr = mod.getDescription());
src/mongo/db/s/transaction_coordinator_catalog.cpp: LOGV2(22443, "{ul}", "ul"_attr = _toString(ul));
src/mongo/db/catalog/collection_impl.cpp: LOGV2(20287, "{msg}", "msg"_attr = msg);
src/mongo/db/catalog/index_catalog_impl.cpp: LOGV2(20354, "{s}", "s"_attr = s);
src/mongo/db/catalog/validate_adaptor.cpp: LOGV2(20404, "{std_string_ss}", "std_string_ss"_attr = std::string(ss));
src/mongo/db/s/set_shard_version_command.cpp: LOGV2_WARNING(22058, "{errmsg}", "errmsg"_attr = errmsg);
src/mongo/db/s/set_shard_version_command.cpp: LOGV2_WARNING(22059, "{errmsg}", "errmsg"_attr = errmsg);
src/mongo/db/s/migration_destination_manager_legacy_commands.cpp: LOGV2(22014, "{status_reason}", "status_reason"_attr = status.reason());
src/mongo/db/s/migration_destination_manager_legacy_commands.cpp: LOGV2(22015, "{status_reason}", "status_reason"_attr = status.reason());
src/mongo/db/s/migration_destination_manager.cpp: LOGV2(21998, "{msg}", "msg"_attr = msg);
src/mongo/db/s/migration_destination_manager.cpp: LOGV2_WARNING(22010, "{msg}", "msg"_attr = msg);
src/mongo/db/s/migration_destination_manager.cpp: LOGV2_WARNING(22012,
                              "{errMsg}",
                              "errMsg"_attr = errMsg,
                              "migrationId"_attr = _enableResumableRangeDeleter
                                  ? _migrationId->toBSON()
                                  : BSONObj());
src/mongo/db/exec/document_value/document_value_test.cpp: LOGV2(20585, "{md_peek}", "md_peek"_attr = md.peek().toString());
src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp: LOGV2_FATAL_NOTRACE(50944, "{kWTRepairMsg}", "kWTRepairMsg"_attr = kWTRepairMsg);
src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp: LOGV2_FATAL_NOTRACE(50947,
                        "{Failed_to_salvage_WiredTiger_metadata_wtRCToStatus_ret_reason}",
                        "Failed_to_salvage_WiredTiger_metadata_wtRCToStatus_ret_reason"_attr =
                            "Failed to salvage WiredTiger metadata: " + wtRCToStatus(ret).reason());
src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp: LOGV2(22332,
          "{Renaming_data_file_identFilePath_string_to_temporary_file_tmpFile_string}",
          "Renaming_data_file_identFilePath_string_to_temporary_file_tmpFile_string"_attr =
              "Renaming data file " + identFilePath->string() + " to temporary file " +
              tmpFile.string());
src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp: LOGV2(22334,
          "{Moving_orphaned_data_file_back_as_identFilePath_string}",
          "Moving_orphaned_data_file_back_as_identFilePath_string"_attr =
              "Moving orphaned data file back as " + identFilePath->string());
src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp: LOGV2(22335,
          "{Salvaging_ident_ident}",
          "Salvaging_ident_ident"_attr = "Salvaging ident " + ident);
src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp: LOGV2_ERROR(22433, "{ex}", "ex"_attr = ex);
src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp: LOGV2_ERROR(22434, "{ex}", "ex"_attr = ex);
src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp: LOGV2_ERROR(22421, "{cursorErrMsg}", "cursorErrMsg"_attr = cursorErrMsg);
src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp: LOGV2_WARNING(22408, "{msg}", "msg"_attr = msg);
src/mongo/db/storage/wiredtiger/wiredtiger_record_store.cpp: LOGV2_ERROR(22409, "{msg}", "msg"_attr = msg);
src/mongo/db/storage/wiredtiger/wiredtiger_parameters.cpp: LOGV2_ERROR(22377, "{result}", "result"_attr = result);
src/mongo/db/storage/wiredtiger/wiredtiger_parameters.cpp: LOGV2_ERROR(22378, "{result}", "result"_attr = result);
src/mongo/db/storage/wiredtiger/wiredtiger_cursor.cpp: LOGV2_ERROR(23719, "{ex}", "ex"_attr = ex);
src/mongo/db/modules/enterprise/src/snmp/snmp.cpp: LOGV2_FATAL_CONTINUE(4615642, "{message}", "message"_attr = slm->msg);
src/mongo/db/modules/enterprise/src/snmp/snmp.cpp: LOGV2_ERROR(4615643, "{message}", "message"_attr = slm->msg);
src/mongo/db/modules/enterprise/src/snmp/snmp.cpp: LOGV2_WARNING(4615644, "{message}", "message"_attr = slm->msg);
src/mongo/db/modules/enterprise/src/snmp/snmp.cpp: LOGV2(4615646, "{message}", "message"_attr = slm->msg);
src/mongo/db/modules/enterprise/src/hot_backups/document_source_backup_cursor.cpp: LOGV2_FATAL(50909,
                    "{exc_toStatus_Error_closing_a_backup_cursor}",
                    "exc_toStatus_Error_closing_a_backup_cursor"_attr =
                        exc.toStatus("Error closing a backup cursor."));
src/mongo/db/modules/enterprise/src/sasl/cyrus_sasl_authentication_session.cpp: LOGV2_ERROR(24031, "{message}", "message"_attr = message);
src/mongo/db/modules/enterprise/src/sasl/cyrus_sasl_authentication_session.cpp: LOGV2_WARNING(24028, "{message}", "message"_attr = message);
src/mongo/db/modules/enterprise/src/sasl/cyrus_sasl_authentication_session.cpp: LOGV2(24025, "{message}", "message"_attr = message);
src/mongo/db/modules/enterprise/src/queryable/queryable_wt/blockstore_fs.cpp: LOGV2(24218,
              "{swBytesRead_getStatus_reason}",
              "swBytesRead_getStatus_reason"_attr = swBytesRead.getStatus().reason());

 

Generated at Thu Feb 08 05:11:54 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.