diff --git a/CHANGELOG.md b/CHANGELOG.md index 7b997e41..4a6c6570 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -94,6 +94,22 @@ - Fixed incorrect log level short codes introduced in v7 after adding NOTICE. Using `%(log_level_short_code)` in the formatter could incorrectly map `LOG_ERROR` to `"C"` and LOG_WARNING to `"E"`. ([#564](https://github.com/odygrd/quill/issues/564)) +- When the placeholder `%(named_args)` is enabled in the pattern formatter or when logging in JSON format, any extra + arguments passed in the log message without a key name will also be displayed in the JSON output with keys + corresponding to their positional indexes. This allows additional details to be included in the JSON while keeping the + log message clean. For example ([#563](https://github.com/odygrd/quill/discussions/563)): + + ```cpp + LOG_INFO(hybrid_logger, "Operation {name} completed with code {code}", "Update", 123, "Data synced successfully"); + ``` + This will output: + ``` + Operation Update completed with code 123 + ``` + And the corresponding JSON will be: + ``` + {"timestamp":"1726582319816776867","file_name":"json_file_logging.cpp","line":"71","thread_id":"25462","logger":"hybrid_logger","log_level":"INFO","message":"Operation {name} completed with code {code}","name":"Update","code":"123","_2":"Data synced successfully"} + ``` ## v7.1.0 diff --git a/examples/json_file_logging.cpp b/examples/json_file_logging.cpp index 73f2cb40..bb804f60 100644 --- a/examples/json_file_logging.cpp +++ b/examples/json_file_logging.cpp @@ -51,15 +51,23 @@ int main() auto json_sink_2 = quill::Frontend::get_sink("example_json.log"); auto console_sink = quill::Frontend::create_or_get_sink("console_sink_id_1"); - // We set a custom format pattern here to also include the named_args + // Define a custom format pattern for console logging, which includes named arguments in the output. + // If you prefer to omit named arguments from the log messages, you can remove the "[%(named_args)]" part. + quill::PatternFormatterOptions console_log_pattern = quill::PatternFormatterOptions{ + "%(time) [%(thread_id)] %(short_source_location:<28) LOG_%(log_level:<9) %(logger:<20) " + "%(message) [%(named_args)]"}; + + // Create a logger named "hybrid_logger" that writes to both a JSON sink and a console sink. + // Note: The JSON sink uses its own internal format, so the custom format defined here + // will only apply to the console output (via console_sink). quill::Logger* hybrid_logger = quill::Frontend::create_or_get_logger( - "hybrid_logger", {std::move(json_sink_2), std::move(console_sink)}, - quill::PatternFormatterOptions{ - "%(time) [%(thread_id)] %(short_source_location:<28) LOG_%(log_level:<9) %(logger:<20) " - "%(message) [%(named_args)]"}); + "hybrid_logger", {std::move(json_sink_2), std::move(console_sink)}, console_log_pattern); for (int i = 2; i < 4; ++i) { LOG_INFO(hybrid_logger, "{method} to {endpoint} took {elapsed} ms", "POST", "http://", 10 * i); } + + LOG_INFO(hybrid_logger, "Operation {name} completed with code {code}", "Update", 123, + "Data synced successfully"); } diff --git a/include/quill/backend/BackendWorker.h b/include/quill/backend/BackendWorker.h index 717f590f..dd451df1 100644 --- a/include/quill/backend/BackendWorker.h +++ b/include/quill/backend/BackendWorker.h @@ -1290,9 +1290,11 @@ class BackendWorker for (size_t i = 0; i < named_args.size(); ++i) { - // orig_arg_names[i].second is special format syntax for the named argument if provided, eg name:.2f - if (!orig_arg_names[i].second.empty()) + // We need an additional check here because named_args can have a size greater than orig_arg_names + // This is because we are adding the arguments without a name with a placeholder name + if ((i < orig_arg_names.size()) && !orig_arg_names[i].second.empty()) { + // orig_arg_names[i].second is special format syntax for the named argument if provided, eg name:.2f format_string += fmtquill::format("{{{}}}", orig_arg_names[i].second); } else @@ -1326,6 +1328,7 @@ class BackendWorker start = end + delimiter.length(); } + // last value if (idx < named_args.size()) { named_args[idx].second = formatted_values_str.substr(start); @@ -1360,6 +1363,13 @@ class BackendWorker (*transit_event->named_args)[i].first = arg_names[i].first; } + for (size_t i = arg_names.size(); i < static_cast(_format_args_store.size()); ++i) + { + // we do not have a named_arg for the argument value here so we just append its index as a placeholder + transit_event->named_args->push_back( + std::pair(fmtquill::format("_{}", i), std::string{})); + } + // Then populate all the values of each arg QUILL_TRY { diff --git a/test/integration_tests/JsonFileLoggingTest.cpp b/test/integration_tests/JsonFileLoggingTest.cpp index bcc37498..13b4cc82 100644 --- a/test/integration_tests/JsonFileLoggingTest.cpp +++ b/test/integration_tests/JsonFileLoggingTest.cpp @@ -93,17 +93,6 @@ TEST_CASE("json_file_logging") "%(time) [%(thread_id)] %(short_source_location:<28) LOG_%(log_level:<9) %(logger:<12) " "%(message) [%(named_args)]"}); - if (i == 0) - { - // log a message without any args, only from the first thread - LOG_INFO(logger, "Hello from thread"); - - // Log a message with non-printable chars - const char* npcs = "Example\u0003String\u0004"; - - LOG_INFO(logger, "contains non-printable {npcs}", npcs); - } - for (size_t j = 0; j < number_of_messages; ++j) { LOG_INFO(logger, @@ -114,8 +103,19 @@ TEST_CASE("json_file_logging") if (i == 0) { + // log a message without any args, only from the first thread + LOG_INFO(logger, "Hello from thread"); + + // Log a message with non-printable chars + const char* npcs = "Example\u0003String\u0004"; + + LOG_INFO(logger, "contains non-printable {npcs}", npcs); + // log an invalid format for testing, only from the first thread LOG_INFO(logger, "invalid format [{%f}]", 321.1); + + // json extras + LOG_INFO(logger, "A {name} with {type} extras", "message", "json", 1234, "json_extra"); } }); } @@ -139,8 +139,8 @@ TEST_CASE("json_file_logging") std::vector const file_contents = quill::testing::file_contents(json_filename); std::vector const file_contents_s = quill::testing::file_contents(filename); - REQUIRE_EQ(file_contents.size(), number_of_messages * number_of_threads + 3); - REQUIRE_EQ(file_contents_s.size(), number_of_messages * number_of_threads + 3); + REQUIRE_EQ(file_contents.size(), number_of_messages * number_of_threads + 4); + REQUIRE_EQ(file_contents_s.size(), number_of_messages * number_of_threads + 4); for (size_t i = 0; i < number_of_threads; ++i) { @@ -148,15 +148,14 @@ TEST_CASE("json_file_logging") for (size_t j = 0; j < number_of_messages; ++j) { // check json log - std::string expected_json_string = std::string{"\"logger\":\""} + logger_name_prefix + + std::string expected_json_string = std::string{R"("logger":")"} + logger_name_prefix + std::to_string(i) + std::string{ "\",\"log_level\":\"INFO\",\"message\":\"Hello from thread {thread_index} this is " "message {message_num} [{custom}, {double:.2f}]\","} + - std::string{"\"thread_index\":\""} + std::to_string(i) + - std::string{"\",\"message_num\":\""} + std::to_string(j) + - std::string{"\",\"custom\":\"i: "} + std::to_string(j) + ", s: " + std::to_string(j) + - std::string{"\",\"double\":\"3.17\""}; + std::string{R"("thread_index":")"} + std::to_string(i) + + std::string{R"(","message_num":")"} + std::to_string(j) + std::string{R"(","custom":"i: )"} + + std::to_string(j) + ", s: " + std::to_string(j) + std::string{R"(","double":"3.17")"}; REQUIRE(quill::testing::file_contains(file_contents, expected_json_string)); @@ -170,21 +169,27 @@ TEST_CASE("json_file_logging") REQUIRE(quill::testing::file_contains(file_contents_s, expected_string)); } - std::string expected_no_args_json = "\"log_level\":\"INFO\",\"message\":\"Hello from thread\""; + std::string expected_no_args_json = R"("log_level":"INFO","message":"Hello from thread")"; std::string expected_no_args_fmt = "Hello from thread"; REQUIRE(quill::testing::file_contains(file_contents, expected_no_args_json)); REQUIRE(quill::testing::file_contains(file_contents_s, expected_no_args_fmt)); - std::string expected_non_printable_json = "\"npcs\":\"Example\\x03String\\x04\""; + std::string expected_non_printable_json = R"("npcs":"Example\x03String\x04")"; std::string expected_non_printable_fmt = "contains non-printable Example\\x03String\\x04"; REQUIRE(quill::testing::file_contains(file_contents, expected_non_printable_json)); REQUIRE(quill::testing::file_contains(file_contents_s, expected_non_printable_fmt)); - std::string expected_invalid_fmt_json = - "\"log_level\":\"INFO\",\"message\":\"invalid format [{%f}]\""; + std::string expected_invalid_fmt_json = R"("log_level":"INFO","message":"invalid format [{%f}]")"; std::string expected_invalid_fmt = "invalid format [{%f}]\", location: \""; REQUIRE(quill::testing::file_contains(file_contents, expected_invalid_fmt_json)); REQUIRE(quill::testing::file_contains(file_contents_s, expected_invalid_fmt)); + + std::string expected_extras_json = + R"("message":"A {name} with {type} extras","name":"message","type":"json","_2":"1234","_3":"json_extra")"; + std::string expected_extras_fmt = + "A message with json extras [name: message, type: json, _2: 1234, _3: json_extra]"; + REQUIRE(quill::testing::file_contains(file_contents, expected_extras_json)); + REQUIRE(quill::testing::file_contains(file_contents_s, expected_extras_fmt)); } testing::remove_file(json_filename); diff --git a/test/integration_tests/JsonMultilineMetadataTest.cpp b/test/integration_tests/JsonMultilineMetadataTest.cpp index 3b894a29..c540426c 100644 --- a/test/integration_tests/JsonMultilineMetadataTest.cpp +++ b/test/integration_tests/JsonMultilineMetadataTest.cpp @@ -65,13 +65,13 @@ TEST_CASE("json_multi_line_metadata") "data1", "data2"); LOG_WARNING(logger_a, "Warning: Multiple issues detected:\n1. {val_1}.\n2. {val_2}.\n3. {val_3}.", "issue1", "issue2", "issue3"); - LOG_INFO(logger_a, "Another multiline info message.\nLine 2: {val_1}\n", "data1", "data2"); + LOG_INFO(logger_a, "Another multiline info message.\nLine 2: {val_1}\n", "data1"); LOG_INFO(logger_b, "This is a multiline info message.\nLine 2: {val_1}.\nLine 3: {val_2}.", "data3", "data4"); LOG_WARNING(logger_b, "Warning: Multiple issues detected:\n1. {val_1}.\n2. {val_2}.\n3. {val_3}.", "issue4", "issue5", "issue6"); - LOG_INFO(logger_b, "Another multiline info message.\nLine 2: {val_1}\n", "data1", "data2"); + LOG_INFO(logger_b, "Another multiline info message.\nLine 2: {val_1}\n", "data1"); logger_a->flush_log(); Frontend::remove_logger(logger_a); diff --git a/test/integration_tests/JsonVariedParamsLoggingTest.cpp b/test/integration_tests/JsonVariedParamsLoggingTest.cpp index 31248ae3..4414eda3 100644 --- a/test/integration_tests/JsonVariedParamsLoggingTest.cpp +++ b/test/integration_tests/JsonVariedParamsLoggingTest.cpp @@ -59,7 +59,7 @@ class CustomJsonFileSink : public JsonFileSink **/ TEST_CASE("json_varied_params_logging") { - static constexpr size_t number_of_messages = 128u; + static constexpr size_t number_of_messages = 127u; static constexpr char const* filename = "json_varied_params_logging.json"; // Start the logging backend thread