Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

sanitize non printable chars #475

Merged
merged 5 commits into from
Jun 19, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
- [v4.5.0](#v450)
- [v4.4.1](#v441)
- [v4.4.0](#v440)
- [v4.3.0](#v430)
Expand Down Expand Up @@ -65,6 +66,13 @@
- [v1.1.0](#v110)
- [v1.0.0](#v100)

## v4.5.0

- The backend now automatically sanitizes non-printable characters and backslashes in log messages by converting them to
their hexadecimal representation. This feature ensures logs contain only safe, readable characters. You can customize
or disable this feature through the backend options by modifying the `check_printable_char` callback
in `BackendOptions`.

## v4.4.1

- Fixed multiple definitions of `quill::detail::get_error_message` ([#469](https://github.com/odygrd/quill/issues/469))
Expand Down
4 changes: 2 additions & 2 deletions quill/include/quill/Backend.h
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,8 @@ namespace quill
{
/** Version Info **/
constexpr uint32_t VersionMajor{4};
constexpr uint32_t VersionMinor{4};
constexpr uint32_t VersionPatch{1};
constexpr uint32_t VersionMinor{5};
constexpr uint32_t VersionPatch{0};
constexpr uint32_t Version{VersionMajor * 10000 + VersionMinor * 100 + VersionPatch};

class Backend
Expand Down
15 changes: 15 additions & 0 deletions quill/include/quill/backend/BackendOptions.h
Original file line number Diff line number Diff line change
Expand Up @@ -173,5 +173,20 @@ struct BackendOptions
* calls. Changing this value only affects the performance of the backend worker.
*/
std::chrono::milliseconds rdtsc_resync_interval = std::chrono::milliseconds{500};

/**
* This option enables a check that verifies the log message contains only printable characters
* before forwarding it to the sinks. This adds an extra layer of safety by filtering out
* non-printable characters from the log file. Any non-printable characters are converted to their
* equivalent hex value.
*
* The check applies only when at least one argument in a log statement is of type string.
*
* You can customize this callback to define your own range of printable characters if needed.
*
* To disable this check, you can provide:
* std::function<bool(char c)> check_printable_char = {}
*/
std::function<bool(char c)> check_printable_char = [](char c) { return c >= ' ' && c <= '~'; };
};
} // namespace quill
70 changes: 66 additions & 4 deletions quill/include/quill/backend/BackendWorker.h
Original file line number Diff line number Diff line change
Expand Up @@ -1172,13 +1172,14 @@ class BackendWorker
}

/**
* This function takes an `arg_store` containing multiple arguments and formats them into
* This function takes an `format_args_store` containing multiple arguments and formats them into
* a single string using a generated format string. Due to limitations in the ability to
* iterate and format each argument individually in libfmt, this approach is used.
* After formatting, the string is split to isolate each formatted value.
*/
static void _format_and_split_arguments(std::vector<std::pair<std::string, std::string>>& named_args,
DynamicFormatArgStore const& arg_store)
DynamicFormatArgStore const& format_args_store,
BackendOptions const& options)
{
// Generate a format string
std::string format_string;
Expand All @@ -1197,7 +1198,8 @@ class BackendWorker
std::string formatted_values_str;
fmtquill::vformat_to(
std::back_inserter(formatted_values_str), format_string,
fmtquill::basic_format_args<fmtquill::format_context>{arg_store.get_types(), arg_store.data()});
fmtquill::basic_format_args<fmtquill::format_context>{
format_args_store.get_types(), format_args_store.data()});

// Split the formatted_values to isolate each value
size_t start = 0;
Expand All @@ -1217,6 +1219,17 @@ class BackendWorker
{
named_args[idx].second = formatted_values_str.substr(start);
}

// We call sanitize_non_printable_chars for each value, because formatted_values_str already
// contains non-printable characters for the argument separation
if (options.check_printable_char && format_args_store.has_string_related_type())
{
// if non-printable chars check is configured or if any of the provided arguments are strings
for (size_t i = 0; i < named_args.size(); ++i)
{
sanitize_non_printable_chars(named_args[i].second, options);
}
}
}

void _populate_formatted_named_args(TransitEvent* transit_event, std::vector<std::string> const& arg_names)
Expand All @@ -1240,7 +1253,10 @@ class BackendWorker
}

// Then populate all the values of each arg
QUILL_TRY { _format_and_split_arguments(*transit_event->named_args, _format_args_store); }
QUILL_TRY
{
_format_and_split_arguments(*transit_event->named_args, _format_args_store, _options);
}
#if !defined(QUILL_NO_EXCEPTIONS)
QUILL_CATCH(std::exception const&)
{
Expand All @@ -1260,6 +1276,12 @@ class BackendWorker
fmtquill::vformat_to(std::back_inserter(transit_event->formatted_msg), message_format,
fmtquill::basic_format_args<fmtquill::format_context>{
_format_args_store.get_types(), _format_args_store.data()});

if (_options.check_printable_char && _format_args_store.has_string_related_type())
{
// if non-printable chars check is configured or if any of the provided arguments are strings
sanitize_non_printable_chars(transit_event->formatted_msg, _options);
}
}
#if !defined(QUILL_NO_EXCEPTIONS)
QUILL_CATCH(std::exception const& e)
Expand All @@ -1276,6 +1298,46 @@ class BackendWorker
#endif
}

template <typename TFormattedMsg>
static void sanitize_non_printable_chars(TFormattedMsg& formatted_msg, BackendOptions const& options)
{
// check for non printable characters in the formatted_msg
bool contains_non_printable_char{false};

for (char c : formatted_msg)
{
if (!options.check_printable_char(c))
{
contains_non_printable_char = true;
break;
}
}

if (contains_non_printable_char)
{
// in this rare event we will replace the non-printable chars with their hex values
std::string const formatted_msg_copy = {formatted_msg.data(), formatted_msg.size()};
formatted_msg.clear();

for (char c : formatted_msg_copy)
{
if (options.check_printable_char(c))
{
formatted_msg.append(std::string{c});
}
else
{
// convert non-printable character to hex
constexpr char hex[] = "0123456789ABCDEF";
formatted_msg.append(std::string{'\\'});
formatted_msg.append(std::string{'x'});
formatted_msg.append(std::string{hex[(c >> 4) & 0xF]});
formatted_msg.append(std::string{hex[c & 0xF]});
}
}
}
}

private:
ThreadContextManager& _thread_context_manager = ThreadContextManager::instance();
SinkManager& _sink_manager = SinkManager::instance();
Expand Down
13 changes: 13 additions & 0 deletions quill/include/quill/core/DynamicFormatArgStore.h
Original file line number Diff line number Diff line change
Expand Up @@ -62,6 +62,7 @@ class DynamicFormatArgStore
// Storage of arguments not fitting into basic_format_arg must grow
// without relocation because items in data_ refer to it.
DynamicArgList _dynamic_arg_list;
bool _has_string_related_type{false};

template <typename T>
void emplace_arg(T const& arg)
Expand Down Expand Up @@ -110,13 +111,25 @@ class DynamicFormatArgStore
{
emplace_arg(arg);
}

if constexpr (std::is_same_v<std::remove_cv_t<std::remove_reference_t<T>>, std::string_view> ||
(mapped_type == fmtquill::detail::type::cstring_type) ||
(mapped_type == fmtquill::detail::type::string_type) ||
(mapped_type == fmtquill::detail::type::custom_type) ||
(mapped_type == fmtquill::detail::type::char_type))
{
_has_string_related_type = true;
}
}

/** Erase all elements from the store */
void clear()
{
_data.clear();
_dynamic_arg_list = DynamicArgList{};
_has_string_related_type = false;
}

QUILL_NODISCARD bool has_string_related_type() const noexcept { return _has_string_related_type; }
};
} // namespace quill::detail
14 changes: 12 additions & 2 deletions quill/test/integration_tests/JsonFileLoggingTest.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -96,6 +96,11 @@ TEST_CASE("json_file_logging")
{
// 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)
Expand Down Expand Up @@ -132,8 +137,8 @@ TEST_CASE("json_file_logging")
std::vector<std::string> const file_contents = quill::testing::file_contents(json_filename);
std::vector<std::string> const file_contents_s = quill::testing::file_contents(filename);

REQUIRE_EQ(file_contents.size(), number_of_messages * number_of_threads + 2);
REQUIRE_EQ(file_contents_s.size(), number_of_messages * number_of_threads + 2);
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);

for (size_t i = 0; i < number_of_threads; ++i)
{
Expand Down Expand Up @@ -168,6 +173,11 @@ TEST_CASE("json_file_logging")
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_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 = "invalid format [{%f}]\", location: \"";
Expand Down
11 changes: 10 additions & 1 deletion quill/test/integration_tests/StringLoggingTest.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,9 @@ TEST_CASE("string_logging")
c_style_string_array_non_terminated[1] = 'B';
c_style_string_array_non_terminated[2] = 'C';

const char* npcs = "Example\u0003String\u0004";
LOG_INFO(logger, "non printable cs [{}]", npcs);

LOG_INFO(logger, "s [{}]", s);
LOG_INFO(logger, "scr [{}]", scr);
LOG_INFO(logger, "sr [{}]", sr);
Expand Down Expand Up @@ -107,7 +110,13 @@ TEST_CASE("string_logging")

// Read file and check
std::vector<std::string> const file_contents = quill::testing::file_contents(filename);
REQUIRE_EQ(file_contents.size(), number_of_messages + 14);
REQUIRE_EQ(file_contents.size(), number_of_messages + 15);

REQUIRE(quill::testing::file_contains(
file_contents, std::string{"LOG_INFO " + logger_name + " non printable cs [Example\\x03String\\x04]"}));

REQUIRE(quill::testing::file_contains(
file_contents, std::string{"LOG_INFO " + logger_name + " s [adipiscing]"}));

REQUIRE(quill::testing::file_contains(
file_contents, std::string{"LOG_INFO " + logger_name + " s [adipiscing]"}));
Expand Down